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-prev] [thread-next>] [day] [month] [year] [list]
Message-ID: <20170310025649.s6cbhe3gpyn3psky@wfg-t540p.sh.intel.com>
Date:   Fri, 10 Mar 2017 10:56:49 +0800
From:   Fengguang Wu <fengguang.wu@...el.com>
To:     Boqun Feng <boqun.feng@...il.com>
Cc:     Ingo Molnar <mingo@...nel.org>,
        "Peter Zijlstra (Intel)" <peterz@...radead.org>,
        chris@...is-wilson.co.uk, linux-kernel@...r.kernel.org,
        LKP <lkp@...org>
Subject: [locking/ww_mutex] 857811a371 INFO: task swapper/0:1 blocked for
 more than 120 seconds.

Hi Boqun,

FYI here is another bisect result. I report it once again since the
attached reproduce-* may be more handy for debug. :)

7fb4a2cea6  locking/lockdep: Add nest_lock integrity test
857811a371  locking/ww_mutex: Adjust the lock number for stress test
+-----------------------------------------------------+------------+------------+
|                                                     | 7fb4a2cea6 | 857811a371 |
+-----------------------------------------------------+------------+------------+
| boot_successes                                      | 0          | 0          |
| boot_failures                                       | 46         | 11         |
| WARNING:at_kernel/locking/lockdep.c:#__lock_acquire | 46         |            |
| Kernel_panic-not_syncing:softlockup:hung_tasks      | 43         |            |
| INFO:task_blocked_for_more_than#seconds             | 0          | 11         |
| calltrace:debug_show_all_locks                      | 0          | 5          |
| calltrace:stress_reorder_work                       | 0          | 1          |
| Kernel_panic-not_syncing:hung_task:blocked_tasks    | 0          | 11         |
| calltrace:stress_inorder_work                       | 0          | 1          |
+-----------------------------------------------------+------------+------------+

[   10.971791] CPU feature 'AVX registers' is not supported.
[   10.973857] CPU feature 'AVX registers' is not supported.
[   10.975118] CPU feature 'AVX registers' is not supported.
[   10.975985] AVX2 or AES-NI instructions are not detected.
[   10.977218] AVX2 instructions are not detected.
[  246.755202] INFO: task swapper/0:1 blocked for more than 120 seconds.
[  246.757677]       Not tainted 4.10.0-11078-g857811a #1
[  246.758549] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  246.759806] swapper/0       D    0     1      0 0x00000000
[  246.760795] Call Trace:
[  246.761290]  __schedule+0xf11/0x102d
[  246.761878]  schedule+0x8c/0xc2
[  246.762446]  schedule_timeout+0x3c/0xb2e
[  246.763139]  ? ftrace_likely_update+0x26f/0x291
[  246.763862]  ? mark_held_locks+0x30/0x84
[  246.764547]  ? _raw_spin_unlock_irq+0x2c/0x3d
[  246.765304]  ? trace_hardirqs_on_caller+0x225/0x26c
[  246.766135]  wait_for_common+0x286/0x3d0
[  246.766767]  ? wait_for_common+0x286/0x3d0
[  246.767465]  ? do_task_dead+0x63/0x63
[  246.768117]  wait_for_completion+0x1d/0x1f
[  246.768776]  flush_workqueue+0x70d/0x122a
[  246.769468]  ? wake_up_process+0x15/0x17
[  246.770153]  stress+0x28d/0x365
[  246.770671]  ? stress+0x28d/0x365
[  246.771277]  test_ww_mutex_init+0x309/0x34f
[  246.771951]  ? lockdep_proc_init+0x5f/0x5f
[  246.772659]  do_one_initcall+0xe7/0x24a
[  246.773336]  kernel_init_freeable+0x1b5/0x2c0
[  246.774095]  ? rest_init+0x1a7/0x1a7
[  246.774684]  kernel_init+0x13/0x224
[  246.775305]  ? rest_init+0x1a7/0x1a7
[  246.775889]  ret_from_fork+0x31/0x40
[  246.776509] 
[  246.776509] Showing all locks held in the system:
[  246.777557] 2 locks held by khungtaskd/25:
[  246.778279]  #0:  (rcu_read_lock){......}, at: [<ffffffff8129b4ed>] check_hung_uninterruptible_tasks+0x6d/0xc06
[  246.779924]  #1:  (tasklist_lock){.+.+..}, at: [<ffffffff811e0021>] debug_show_all_locks+0x58/0x1ab
[  246.781424] 4 locks held by kworker/u4:3/70:
[  246.782158]  #0:  ("test-ww_mutex"){++++.+}, at: [<ffffffff8115b321>] process_one_work+0x5a6/0x12e6
[  246.783633]  #1:  ((&stress->work)){+.+.+.}, at: [<ffffffff8115b321>] process_one_work+0x5a6/0x12e6
[  246.785121]  #2:  (ww_class_acquire){+.+...}, at: [<ffffffff8115b771>] process_one_work+0x9f6/0x12e6
[  246.786621]  #3:  (ww_class_mutex){+.+...}, at: [<ffffffff811e8b79>] stress_inorder_work+0x1ae/0x64f
[  246.788122] 
[  246.788388] =============================================
[  246.788388] 
[  246.789506] NMI backtrace for cpu 1
[  246.790136] CPU: 1 PID: 25 Comm: khungtaskd Not tainted 4.10.0-11078-g857811a #1
[  246.791092] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.9.3-20161025_171302-gandalf 04/01/2014
[  246.791092] Call Trace:
[  246.791092]  dump_stack+0x133/0x1c1
[  246.791092]  nmi_cpu_backtrace+0x1e0/0x2da
[  246.791092]  ? irq_force_complete_move+0x3e4/0x3e4
[  246.791092]  nmi_trigger_cpumask_backtrace+0x2a9/0x3dd
[  246.791092]  arch_trigger_cpumask_backtrace+0x19/0x1b
[  246.791092]  check_hung_uninterruptible_tasks+0xb2f/0xc06
[  246.791092]  watchdog+0xdb/0x100
[  246.791092]  kthread+0x25e/0x26e
[  246.791092]  ? check_hung_uninterruptible_tasks+0xc06/0xc06
[  246.791092]  ? __kthread_bind_mask+0xda/0xda
[  246.791092]  ret_from_fork+0x31/0x40
[  246.800910] Sending NMI from CPU 1 to CPUs 0:
[  246.802022] NMI backtrace for cpu 0
[  246.802022] CPU: 0 PID: 72 Comm: kworker/u4:5 Not tainted 4.10.0-11078-g857811a #1
[  246.802022] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.9.3-20161025_171302-gandalf 04/01/2014
[  246.802022] Workqueue: test-ww_mutex stress_reorder_work
[  246.802022] task: ffff88001f826240 task.stack: ffff88001f840000
[  246.802022] RIP: 0010:match_held_lock+0x1/0x234
[  246.802022] RSP: 0000:ffff88001f847ba0 EFLAGS: 00000046
[  246.802022] RAX: 0000000000000000 RBX: ffff88001f826240 RCX: ffff88001f826d60
[  246.802022] RDX: ffff88001f826d58 RSI: ffff88001fa80530 RDI: ffff88001f826d60
[  246.802022] RBP: ffff88001f847c20 R08: fffffbfff07bcddf R09: 0000000000000000
[  246.802022] R10: fffffbfff07bcddf R11: ffffffff83de6ef7 R12: 0000000000000003
[  246.802022] R13: 0000000000000003 R14: ffff88001fa80530 R15: ffffffff82ce9f36
[  246.802022] FS:  0000000000000000(0000) GS:ffff880019200000(0000) knlGS:0000000000000000
[  246.802022] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  246.802022] CR2: 0000000000000000 CR3: 0000000003a13000 CR4: 00000000000006b0
[  246.802022] Call Trace:
[  246.802022]  ? lock_release+0x38f/0x632
[  246.802022]  ? ftrace_likely_update+0x26f/0x291
[  246.802022]  ? do_raw_spin_unlock+0x1bb/0x1c9
[  246.802022]  __mutex_unlock_slowpath+0x3a/0x6d0
[  246.802022]  ? __hrtimer_run_queues+0x105/0x105
[  246.802022]  ? ftrace_likely_update+0x26f/0x291
[  246.802022]  mutex_unlock+0x12/0x14
[  246.802022]  ww_mutex_unlock+0x1fb/0x208
[  246.802022]  stress_reorder_work+0x660/0x7f3
[  246.802022]  process_one_work+0x9f6/0x12e6
[  246.802022]  worker_thread+0x96c/0xc69
[  246.802022]  kthread+0x25e/0x26e
[  246.802022]  ? process_scheduled_works+0x43/0x43
[  246.802022]  ? __kthread_bind_mask+0xda/0xda
[  246.802022]  ret_from_fork+0x31/0x40
[  246.802022] Code: 48 83 c4 28 5b 41 5c 41 5d 41 5e 41 5f 5d c3 55 48 89 d1 41 b8 01 00 00 00 48 c7 c2 ba 94 1d 81 48 89 e5 e8 03 fd ff ff 5d c3 55 <48> 89 e5 41 57 41 56 41 55 49 89 fd 41 54 48 8d 7f 10 53 49 89 
[  246.802664] Kernel panic - not syncing: hung_task: blocked tasks
[  246.802678] CPU: 1 PID: 25 Comm: khungtaskd Not tainted 4.10.0-11078-g857811a #1
[  246.802685] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.9.3-20161025_171302-gandalf 04/01/2014
[  246.802689] Call Trace:
[  246.802703]  dump_stack+0x133/0x1c1
[  246.802716]  panic+0x190/0x41d
[  246.802730]  ? irq_force_complete_move+0x3e4/0x3e4
[  246.802743]  ? printk_safe_flush+0x156/0x1d1
[  246.802758]  check_hung_uninterruptible_tasks+0xb42/0xc06
[  246.802772]  watchdog+0xdb/0x100
[  246.802784]  kthread+0x25e/0x26e
[  246.802798]  ? check_hung_uninterruptible_tasks+0xc06/0xc06
[  246.802810]  ? __kthread_bind_mask+0xda/0xda
[  246.802822]  ret_from_fork+0x31/0x40
[  246.803018] Kernel Offset: disabled


                                                          # HH:MM RESULT GOOD BAD GOOD_BUT_DIRTY DIRTY_NOT_BAD
git bisect start 5cf564fa3a1d825e8ad57ac4ffb27fb36bfd512a c1ae3cfa0e89fa1a7ecc4c99031f5e9ae99d9201 --
git bisect  bad 0d3f99f9de53871acc15dfd1f61bb98453629039  # 17:12  B      0     5   15   0  Merge 'linux-review/Madhavan-Srinivasan/powerpc-perf-Export-memory-hierarchy-level/20170308-084323' into devel-spot-201703081732
git bisect  bad f1ede449d5276a38b92a97e5aa02d3022c28b50f  # 17:36  B      0     1   11   0  Merge 'linux-review/Pierre-Louis-Bossart/MinnowBoard-MAX-support-for-DA7212/20170308-144239' into devel-spot-201703081732
git bisect  bad 852e39a80c5ac670c670d5679c1b016e024c33ba  # 17:55  B      0     3   13   0  Merge 'linux-review/Adrian-Hunter/mmc-Add-Command-Queue-support/20170308-161308' into devel-spot-201703081732
git bisect good 77efdeceb17242246c3a43fe68e5bc2778f514f4  # 18:38  G     11     0   11  11  Merge 'staging/staging-linus' into devel-spot-201703081732
git bisect  bad e6d6d13bb74c19f3d766a0cec94b28a1c23b2484  # 18:54  B      0     8   18   0  Merge 'crypto/linus' into devel-spot-201703081732
git bisect  bad 55c8f110636e842b792bfc64ae45e20810f805e8  # 19:13  B      0     5   15   0  Merge 'tip/master' into devel-spot-201703081732
git bisect good 90ec5e89e393c76e19afc845d8f88a5dc8315919  # 19:47  G     11     0   11  13  kretprobes: Ensure probe location is at function entry
git bisect good 84e5b549214f2160c12318aac549de85f600c79a  # 20:06  G     11     0   11  11  Merge tag 'perf-core-for-mingo-4.11-20170306' of git://git.kernel.org/pub/scm/linux/kernel/git/acme/linux into perf/core
git bisect  bad 3bd78eb3f8b479d3872bf139e841d77550a3b564  # 20:39  B      0    11   21   0  Merge branch 'locking/urgent'
git bisect good 44cf150fc2572435e6951cba9b3d83fdc9b5356c  # 20:57  G     11     0   11  11  Merge branch 'irq/urgent'
git bisect good 2b232e0c3b3a09f3e33750aa20e314f1b80e5361  # 21:28  G     11     0   11  11  locking/ww_mutex: Replace cpu_relax() with cond_resched() for tests
git bisect  bad 857811a37129f5d2ba162d7be3986eff44724014  # 21:43  B      0    11   21   0  locking/ww_mutex: Adjust the lock number for stress test
git bisect good 7fb4a2cea6b18dab56d609530d077f168169ed6b  # 22:02  G     10     0   10  10  locking/lockdep: Add nest_lock integrity test
# first bad commit: [857811a37129f5d2ba162d7be3986eff44724014] locking/ww_mutex: Adjust the lock number for stress test
git bisect good 7fb4a2cea6b18dab56d609530d077f168169ed6b  # 22:10  G     34     0   34  44  locking/lockdep: Add nest_lock integrity test
# extra tests with CONFIG_DEBUG_INFO_REDUCED
git bisect  bad 857811a37129f5d2ba162d7be3986eff44724014  # 22:25  B      0    11   21   0  locking/ww_mutex: Adjust the lock number for stress test
# extra tests on HEAD of linux-devel/devel-spot-201703081732
git bisect  bad 5cf564fa3a1d825e8ad57ac4ffb27fb36bfd512a  # 22:25  B      0    14   27   0  0day head guard for 'devel-spot-201703081732'
# extra tests on tree/branch linus/master
git bisect  bad ea6200e84182989a3cce9687cf79a23ac44ec4db  # 22:50  B      0     6   16   0  Merge branch 'core-urgent-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
# extra tests with first bad commit reverted
git bisect good 0980a5a454400570f2d9bee07bdaa4fb9031b0bc  # 23:16  G     11     0   11  11  Revert "locking/ww_mutex: Adjust the lock number for stress test"
# extra tests on tree/branch linux-next/master
git bisect  bad 2e62da1e534da571ffa99cfe36eed5b1eba8c598  # 23:37  B      0     5   15   0  Add linux-next specific files for 20170309

---
0-DAY kernel test infrastructure                Open Source Technology Center
https://lists.01.org/pipermail/lkp                          Intel Corporation

Download attachment "dmesg-quantal-ivb41-85:20170309214327:x86_64-randconfig-it0-03081800:4.10.0-11078-g857811a:1.gz" of type "application/gzip" (10681 bytes)

Download attachment "dmesg-quantal-ivb41-101:20170309220922:x86_64-randconfig-it0-03081800:4.10.0-11077-g7fb4a2c:1.gz" of type "application/gzip" (12457 bytes)

View attachment "reproduce-quantal-ivb41-85:20170309214327:x86_64-randconfig-it0-03081800:4.10.0-11078-g857811a:1" of type "text/plain" (888 bytes)

View attachment "config-4.10.0-11078-g857811a" of type "text/plain" (101177 bytes)

Powered by blists - more mailing lists

Powered by Openwall GNU/*/Linux Powered by OpenVZ