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>] [day] [month] [year] [list] 
Message-ID: <20170321045224.GB23490@yexl-desktop>
Date:   Tue, 21 Mar 2017 12:52:24 +0800
From:   kernel test robot <xiaolong.ye@...el.com>
To:     Peter Zijlstra <peterz@...radead.org>
Cc:     Ingo Molnar <mingo@...nel.org>,
        Chris Wilson <chris@...is-wilson.co.uk>,
        Andrew Morton <akpm@...ux-foundation.org>,
        Linus Torvalds <torvalds@...ux-foundation.org>,
        "Paul E. McKenney" <paulmck@...ux.vnet.ibm.com>,
        Thomas Gleixner <tglx@...utronix.de>,
        LKML <linux-kernel@...r.kernel.org>,
        Stephen Rothwell <sfr@...b.auug.org.au>, lkp@...org
Subject: [lkp-robot] [locking/ww_mutex]  bf7b3ac2e3:
 INFO:task_blocked_for_more_than#seconds


FYI, we noticed the following commit:

commit: bf7b3ac2e36ac054f93e5dd8d85dfd754b5e1c09 ("locking/ww_mutex: Improve test to cover acquire context changes")
https://git.kernel.org/cgit/linux/kernel/git/next/linux-next.git master

in testcase: boot

on test machine: qemu-system-x86_64 -enable-kvm -cpu host -smp 2 -m 2G

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


+--------------------------------------------------+------------+------------+
|                                                  | 383776fa75 | bf7b3ac2e3 |
+--------------------------------------------------+------------+------------+
| boot_successes                                   | 18         | 3          |
| boot_failures                                    | 0          | 15         |
| INFO:task_blocked_for_more_than#seconds          | 0          | 15         |
| Kernel_panic-not_syncing:hung_task:blocked_tasks | 0          | 15         |
| calltrace:debug_show_all_locks                   | 0          | 6          |
+--------------------------------------------------+------------+------------+



[  248.961691] INFO: task swapper:1 blocked for more than 120 seconds.
[  248.961691] INFO: task swapper:1 blocked for more than 120 seconds.
[  249.009818]       Not tainted 4.11.0-rc2-00010-gbf7b3ac #1
[  249.009818]       Not tainted 4.11.0-rc2-00010-gbf7b3ac #1
[  249.038399] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  249.038399] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  249.083512] swapper         D11856     1      0 0x00000000
[  249.083512] swapper         D11856     1      0 0x00000000
[  249.113610] Call Trace:
[  249.113610] Call Trace:
[  249.140090]  __schedule+0x4c2/0x520
[  249.140090]  __schedule+0x4c2/0x520
[  249.161677]  ? ___preempt_schedule+0x16/0x18
[  249.161677]  ? ___preempt_schedule+0x16/0x18
[  249.210605]  schedule+0x26/0x3b
[  249.210605]  schedule+0x26/0x3b
[  249.229561]  schedule_timeout+0x2b/0x2bc
[  249.229561]  schedule_timeout+0x2b/0x2bc
[  249.257556]  wait_for_common+0x11e/0x1b5
[  249.257556]  wait_for_common+0x11e/0x1b5
[  249.279561]  ? try_to_wake_up+0x19f/0x19f
[  249.279561]  ? try_to_wake_up+0x19f/0x19f
[  249.319167]  wait_for_completion+0x18/0x1a
[  249.319167]  wait_for_completion+0x18/0x1a
[  249.341751]  flush_workqueue+0x2ac/0x5c9
[  249.341751]  flush_workqueue+0x2ac/0x5c9
[  249.384465]  ? flush_workqueue+0xa7/0x5c9
[  249.384465]  ? flush_workqueue+0xa7/0x5c9
[  249.406499]  ? _raw_spin_unlock_irqrestore+0x49/0x5d
[  249.406499]  ? _raw_spin_unlock_irqrestore+0x49/0x5d
[  249.436407]  ? _raw_spin_unlock+0x3f/0x43
[  249.436407]  ? _raw_spin_unlock+0x3f/0x43
[  249.458614]  ? __queue_work+0x2c1/0x2d0
[  249.458614]  ? __queue_work+0x2c1/0x2d0
[  249.485798]  ? get_random_order+0x7e/0x7e
[  249.485798]  ? get_random_order+0x7e/0x7e
[  249.511661]  ? get_random_order+0x7e/0x7e
[  249.511661]  ? get_random_order+0x7e/0x7e
[  249.533689]  stress+0x1a0/0x1d4
[  249.533689]  stress+0x1a0/0x1d4
[  249.551804]  test_ww_mutex_init+0x28a/0x2ce
[  249.551804]  test_ww_mutex_init+0x28a/0x2ce
[  249.590171]  ? proc_create_data+0xa1/0xbc
[  249.590171]  ? proc_create_data+0xa1/0xbc
[  249.613023]  ? lock_torture_init+0x59b/0x59b
[  249.613023]  ? lock_torture_init+0x59b/0x59b
[  249.639818]  do_one_initcall+0x86/0x155
[  249.639818]  do_one_initcall+0x86/0x155
[  249.661813]  kernel_init_freeable+0x110/0x19a
[  249.661813]  kernel_init_freeable+0x110/0x19a
[  249.696422]  ? kernel_init_freeable+0x19a/0x19a
[  249.696422]  ? kernel_init_freeable+0x19a/0x19a
[  249.728401]  ? rest_init+0xbf/0xbf
[  249.728401]  ? rest_init+0xbf/0xbf
[  249.755948]  kernel_init+0x9/0xf3
[  249.755948]  kernel_init+0x9/0xf3
[  249.771735]  ret_from_fork+0x2c/0x40
[  249.771735]  ret_from_fork+0x2c/0x40
[  249.793736] 
[  249.793736] Showing all locks held in the system:
[  249.793736] 
[  249.793736] Showing all locks held in the system:
[  249.831650] 2 locks held by khungtaskd/15:
[  249.831650] 2 locks held by khungtaskd/15:
[  249.851454]  #0:  (rcu_read_lock){......}, at: [<ffffffff8111f204>] watchdog+0x96/0x352
[  249.851454]  #0:  (rcu_read_lock){......}, at: [<ffffffff8111f204>] watchdog+0x96/0x352
[  249.885734]  #1:  (tasklist_lock){......}, at: [<ffffffff810e757b>] debug_show_all_locks+0x52/0x193
[  249.885734]  #1:  (tasklist_lock){......}, at: [<ffffffff810e757b>] debug_show_all_locks+0x52/0x193
[  249.923459] 
[  249.923459] 
[  249.929288] =============================================
[  249.929288] 
[  249.929288] =============================================
[  249.929288] 
[  249.969510] NMI backtrace for cpu 0
[  249.969510] NMI backtrace for cpu 0
[  249.985283] CPU: 0 PID: 15 Comm: khungtaskd Not tainted 4.11.0-rc2-00010-gbf7b3ac #1
[  249.985283] CPU: 0 PID: 15 Comm: khungtaskd Not tainted 4.11.0-rc2-00010-gbf7b3ac #1
[  250.019213] Call Trace:
[  250.019213] Call Trace:
[  250.030263]  dump_stack+0x19/0x1b
[  250.030263]  dump_stack+0x19/0x1b
[  250.045041]  nmi_cpu_backtrace+0x7e/0x8f
[  250.045041]  nmi_cpu_backtrace+0x7e/0x8f
[  250.062538]  ? hw_nmi_get_sample_period+0x1a/0x1a
[  250.062538]  ? hw_nmi_get_sample_period+0x1a/0x1a
[  250.082901]  nmi_trigger_cpumask_backtrace+0x6d/0xee
[  250.082901]  nmi_trigger_cpumask_backtrace+0x6d/0xee
[  250.104805]  arch_trigger_cpumask_backtrace+0x14/0x16
[  250.104805]  arch_trigger_cpumask_backtrace+0x14/0x16
[  250.127415]  watchdog+0x2c0/0x352
[  250.127415]  watchdog+0x2c0/0x352
[  250.142257]  ? watchdog+0x96/0x352
[  250.142257]  ? watchdog+0x96/0x352
[  250.157658]  ? reset_hung_task_detector+0x14/0x14
[  250.157658]  ? reset_hung_task_detector+0x14/0x14
[  250.178488]  ? reset_hung_task_detector+0x14/0x14
[  250.178488]  ? reset_hung_task_detector+0x14/0x14
[  250.199652]  kthread+0x117/0x11f
[  250.199652]  kthread+0x117/0x11f
[  250.214069]  ? kthreadd+0x158/0x158
[  250.214069]  ? kthreadd+0x158/0x158


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.11.0-rc2-00010-gbf7b3ac" of type "text/plain" (98724 bytes)

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

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

Powered by blists - more mailing lists

Powered by Openwall GNU/*/Linux Powered by OpenVZ