lists.openwall.net   lists  /  announce  owl-users  owl-dev  john-users  john-dev  passwdqc-users  yescrypt  popa3d-users  /  oss-security  kernel-hardening  musl  sabotage  tlsify  passwords  /  crypt-dev  xvendor  /  Bugtraq  Full-Disclosure  linux-kernel  linux-netdev  linux-ext4  linux-hardening  linux-cve-announce  PHC 
Open Source and information security mailing list archives
 
Hash Suite: Windows password security audit tool. GUI, reports in PDF.
[<prev] [next>] [thread-next>] [day] [month] [year] [list]
Message-ID: <20170707020916.GH5222@yexl-desktop>
Date:   Fri, 7 Jul 2017 10:09:16 +0800
From:   kernel test robot <xiaolong.ye@...el.com>
To:     Wanpeng Li <wanpeng.li@...mail.com>
Cc:     Ingo Molnar <mingo@...nel.org>,
        Thomas Gleixner <tglx@...utronix.de>,
        Luiz Capitulino <lcapitulino@...hat.com>,
        Frederic Weisbecker <fweisbec@...il.com>,
        Rik van Riel <riel@...hat.com>,
        Linus Torvalds <torvalds@...ux-foundation.org>,
        Peter Zijlstra <peterz@...radead.org>,
        Wanpeng Li <kernellwp@...il.com>,
        LKML <linux-kernel@...r.kernel.org>,
        "H. Peter Anvin" <hpa@...or.com>, tipbuild@...or.com, lkp@...org
Subject: [lkp-robot] [sched/cputime]  2a42eb9594:
 BUG:using_smp_processor_id()in_preemptible


FYI, we noticed the following commit:

commit: 2a42eb9594a1480b4ead9e036e06ee1290e5fa6d ("sched/cputime: Accumulate vtime on top of nsec clocksource")
https://git.kernel.org/cgit/linux/kernel/git/tip/tip.git sched/urgent

in testcase: boot

on test machine: qemu-system-x86_64 -enable-kvm -cpu Haswell,+smep,+smap -smp 2 -m 512M

caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):


+--------------------------------------------+------------+------------+
|                                            | bac5b6b6b1 | 2a42eb9594 |
+--------------------------------------------+------------+------------+
| boot_successes                             | 8          | 2          |
| boot_failures                              | 0          | 6          |
| BUG:kernel_hang_in_test_stage              | 0          | 2          |
| BUG:using_smp_processor_id()in_preemptible | 0          | 4          |
+--------------------------------------------+------------+------------+



[   55.289944] BUG: using smp_processor_id() in preemptible [00000000] code: 99-trinity/181
[   55.302094] caller is debug_smp_processor_id+0x17/0x19
[   55.313831] CPU: 0 PID: 181 Comm: 99-trinity Not tainted 4.12.0-01059-g2a42eb9 #1
[   55.324812] Call Trace:
[   55.328601]  dump_stack+0x82/0xb8
[   55.333467]  check_preemption_disabled+0xd1/0xe3
[   55.340370]  debug_smp_processor_id+0x17/0x19
[   55.346815]  vtime_delta+0xd/0x2c
[   55.352843]  task_cputime+0x89/0xdb
[   55.358026]  thread_group_cputime+0x11b/0x1ed
[   55.364517]  thread_group_cputime_adjusted+0x1f/0x47
[   55.371895]  wait_consider_task+0x2a9/0xaf9
[   55.378025]  ? lock_acquire+0x97/0xa4
[   55.383463]  do_wait+0xdf/0x1f4
[   55.388199]  SYSC_wait4+0x8e/0xb5
[   55.393219]  ? list_add+0x34/0x34
[   55.398317]  SyS_wait4+0x9/0xb
[   55.403401]  do_syscall_64+0x70/0x82
[   55.408977]  entry_SYSCALL64_slow_path+0x25/0x25
[   55.409006] RIP: 0033:0x7ff2f15c3c3e
[   55.409032] RSP: 002b:00007ffd3e91eab0 EFLAGS: 00000246 ORIG_RAX: 000000000000003d
[   55.409064] RAX: ffffffffffffffda RBX: 00007ff2f1f0b6a0 RCX: 00007ff2f15c3c3e
[   55.409070] RDX: 0000000000000001 RSI: 00007ffd3e91eb18 RDI: ffffffffffffffff
[   55.409075] RBP: 0000000000000001 R08: 0000000000000000 R09: 0000000000000000
[   55.409101] R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
[   55.409106] R13: 0000000000000000 R14: 0000000000000001 R15: 0000000000000000
[   55.550819] random: trinity: uninitialized urandom read (4 bytes read)
mountall: Event failed
[   55.947396] random: mountall: uninitialized urandom read (12 bytes read)
[   56.044974] BUG: using smp_processor_id() in preemptible [00000000] code: mountall/194
[   56.057287] caller is debug_smp_processor_id+0x17/0x19
[   56.066939] CPU: 1 PID: 194 Comm: mountall Not tainted 4.12.0-01059-g2a42eb9 #1
[   56.078248] Call Trace:
[   56.082297]  dump_stack+0x82/0xb8
[   56.087256]  check_preemption_disabled+0xd1/0xe3
[   56.093512]  debug_smp_processor_id+0x17/0x19
[   56.099800]  vtime_delta+0xd/0x2c
[   56.105862]  task_cputime+0x89/0xdb
[   56.111237]  thread_group_cputime+0x11b/0x1ed
[   56.117693]  thread_group_cputime_adjusted+0x1f/0x47
[   56.125298]  wait_consider_task+0x2a9/0xaf9
[   56.131983]  ? do_raw_read_lock+0x39/0x3c
[   56.138293]  do_wait+0xdf/0x1f4
[   56.143000]  SyS_waitid+0xac/0x1e3
[   56.148566]  ? list_add+0x34/0x34
[   56.153694]  do_syscall_64+0x70/0x82
[   56.159267]  entry_SYSCALL64_slow_path+0x25/0x25
[   56.166324] RIP: 0033:0x7fdc9c642d2f
[   56.171770] RSP: 002b:00007ffe6f4dda30 EFLAGS: 00000246 ORIG_RAX: 00000000000000f7
[   56.181888] RAX: ffffffffffffffda RBX: 0000560f25433d70 RCX: 00007fdc9c642d2f
[   56.192353] RDX: 00007ffe6f4dda78 RSI: 00000000000000c7 RDI: 0000000000000001
[   56.203076] RBP: 0000560f2543bf20 R08: 0000000000000000 R09: 0000000000000020
[   56.212903] R10: 0000000000000004 R11: 0000000000000246 R12: 0000560f25439be0
[   56.223108] R13: 00000000000000c7 R14: 00000000000000c7 R15: 0000560f25222c1f
[   56.522906] init: Failed to create pty - disabling logging for job
[   56.535738] init: Temporary process spawn error: No such file or directory
[   56.769705] init: Failed to create pty - disabling logging for job
[   56.781761] init: Temporary process spawn error: No such file or directory
[   57.258638] init: Failed to create pty - disabling logging for job
[   57.271867] init: Temporary process spawn error: No such file or directory
[   57.318928] init: Failed to create pty - disabling logging for job
[   57.340639] init: Temporary process spawn error: No such file or directory
[   57.499535] BUG: using smp_processor_id() in preemptible [00000000] code: sh/217
[   57.529507] caller is debug_smp_processor_id+0x17/0x19
[   57.537158] CPU: 1 PID: 217 Comm: sh Not tainted 4.12.0-01059-g2a42eb9 #1
[   57.547065] Call Trace:
[   57.550929]  dump_stack+0x82/0xb8
[   57.555948]  check_preemption_disabled+0xd1/0xe3
[   57.562849]  debug_smp_processor_id+0x17/0x19
[   57.569263]  vtime_delta+0xd/0x2c
[   57.574940]  task_cputime+0x89/0xdb
[   57.580121]  thread_group_cputime+0x11b/0x1ed
[   57.586382]  thread_group_cputime_adjusted+0x1f/0x47
[   57.593636]  wait_consider_task+0x2a9/0xaf9
[   57.599761]  ? lock_acquire+0x97/0xa4
[   57.605076]  do_wait+0xdf/0x1f4
[   57.609778]  SYSC_wait4+0x8e/0xb5
[   57.614704]  ? list_add+0x34/0x34
[   57.619688]  SyS_wait4+0x9/0xb
[   57.624194]  do_syscall_64+0x70/0x82
[   57.629635]  entry_SYSCALL64_slow_path+0x25/0x25
[   57.636279] RIP: 0033:0x7fe6bd468c3e
[   57.641598] RSP: 002b:00007ffff94e6070 EFLAGS: 00000246 ORIG_RAX: 000000000000003d
[   57.652428] RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007fe6bd468c3e
[   57.662665] RDX: 0000000000000000 RSI: 00007ffff94e60d8 RDI: ffffffffffffffff
[   57.672870] RBP: 00000000006fb900 R08: 00000000006fb9c8 R09: 0000000000000000
[   57.683111] R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000001
[   57.693517] R13: 0000000000000000 R14: 0000000000000000 R15: 00000000ffffffff

Elapsed time: 70

initrds=(
	/osimage/quantal/quantal-core-x86_64.cgz
	/lkp/scheduled/vm-lkp-wsx03-quantal-x86_64-26/boot-1-quantal-core-x86_64.cgz-2a42eb9594a1480b4ead9e036e06ee1290e5fa6d-20170707-60633-3jiqpp-0.cgz
	/lkp/lkp/lkp-x86_64.cgz
)

cat "${initrds[@]}" > /fs/sdc1/initrd-vm-lkp-wsx03-quantal-x86_64-26

kvm=(


To reproduce:

        git clone https://github.com/01org/lkp-tests.git
        cd lkp-tests
        bin/lkp qemu -k <bzImage> job-script  # job-script is attached in this email



Thanks,
Xiaolong

View attachment "config-4.12.0-01059-g2a42eb9" of type "text/plain" (95259 bytes)

View attachment "job-script" of type "text/plain" (3983 bytes)

Download attachment "dmesg.xz" of type "application/octet-stream" (14452 bytes)

Powered by blists - more mailing lists

Powered by Openwall GNU/*/Linux Powered by OpenVZ