[<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