[<prev] [next>] [thread-next>] [day] [month] [year] [list]
Message-ID: <20170227051409.zbqwtekoa3hvggta@wfg-t540p.sh.intel.com>
Date: Mon, 27 Feb 2017 13:14:09 +0800
From: Fengguang Wu <fengguang.wu@...el.com>
To: Nicolai Hähnle <Nicolai.Haehnle@....com>,
Chris Wilson <chris@...is-wilson.co.uk>,
"Peter Zijlstra (Intel)" <peterz@...radead.org>
Cc: Ingo Molnar <mingo@...nel.org>, linux-kernel@...r.kernel.org,
LKP <lkp@...org>
Subject: [locking/ww_mutex] 2a0c112828 WARNING: CPU: 0 PID: 18 at
kernel/locking/mutex.c:305 __ww_mutex_wakeup_for_backoff
Hello,
This bisect result is not satisfactory, however the bug is very
reproducible and looks still alive in mainline&linux-next. You may
try the attached reproduce-* script to debug it.
https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git master
commit 2a0c11282881875dc44f166a20eedf0d866dd0ef
Author: Chris Wilson <chris@...is-wilson.co.uk>
AuthorDate: Thu Dec 1 11:47:10 2016 +0000
Commit: Ingo Molnar <mingo@...nel.org>
CommitDate: Sat Jan 14 11:37:17 2017 +0100
locking/ww_mutex: Add kselftests for ww_mutex stress
Signed-off-by: Chris Wilson <chris@...is-wilson.co.uk>
Signed-off-by: Peter Zijlstra (Intel) <peterz@...radead.org>
Cc: Andrew Morton <akpm@...ux-foundation.org>
Cc: Linus Torvalds <torvalds@...ux-foundation.org>
Cc: Maarten Lankhorst <dev@...ankhorst.nl>
Cc: Nicolai Hähnle <nhaehnle@...il.com>
Cc: Paul E. McKenney <paulmck@...ux.vnet.ibm.com>
Cc: Peter Zijlstra <peterz@...radead.org>
Cc: Thomas Gleixner <tglx@...utronix.de>
Link: http://lkml.kernel.org/r/20161201114711.28697-8-chris@chris-wilson.co.uk
Signed-off-by: Ingo Molnar <mingo@...nel.org>
d1b42b800e locking/ww_mutex: Add kselftests for resolving ww_mutex cyclic deadlocks
2a0c112828 locking/ww_mutex: Add kselftests for ww_mutex stress
+-------------------------------------------------------------------------+------------+------------+
| | d1b42b800e | 2a0c112828 |
+-------------------------------------------------------------------------+------------+------------+
| boot_successes | 0 | 0 |
| boot_failures | 65 | 99 |
| WARNING:at_kernel/locking/mutex.c:#__ww_mutex_wakeup_for_backoff | 65 | 99 |
| WARNING:CPU:#PID:#at_kernel/locking/mutex.c:#__ww_mutex_wakeup_for_back | 0 | 1 |
| WARNING:CPU:#PID:#at_kernel/ | 0 | 1 |
| WARNING:CPU:#PID:#at/kbuild/src/r | 0 | 1 |
+-------------------------------------------------------------------------+------------+------------+
[ 1.057727] Freeing initrd memory: 3276K
[ 1.059257] The force parameter has not been set to 1. The Iris poweroff handler will not be installed.
[ 1.060266] NatSemi SCx200 Driver
[ 1.299666] random: fast init done
[ 1.568992] ------------[ cut here ]------------
[ 1.569656] WARNING: CPU: 0 PID: 18 at kernel/locking/mutex.c:305 __ww_mutex_wakeup_for_backoff+0x31/0x7a
[ 1.571194] CPU: 0 PID: 18 Comm: kworker/0:1 Not tainted 4.10.0-rc3-00155-g2a0c112 #1
[ 1.572259] Workqueue: events test_abba_work
[ 1.572833] Call Trace:
[ 1.573167] dump_stack+0x16/0x18
[ 1.573617] __warn+0xa0/0xb7
[ 1.574017] ? __ww_mutex_wakeup_for_backoff+0x31/0x7a
[ 1.574705] warn_slowpath_null+0x11/0x16
[ 1.575238] __ww_mutex_wakeup_for_backoff+0x31/0x7a
[ 1.575897] __ww_mutex_lock+0x2f3/0xb63
[ 1.576559] ? wake_up_q+0x25/0x40
[ 1.577012] ? __might_sleep+0x6c/0x73
[ 1.577518] ww_mutex_lock+0x34/0x3b
[ 1.577996] ? test_abba_work+0x109/0x182
[ 1.578535] test_abba_work+0x109/0x182
[ 1.579046] process_one_work+0x1c0/0x33a
[ 1.579585] ? process_one_work+0x168/0x33a
[ 1.580138] worker_thread+0x22f/0x315
[ 1.580643] kthread+0xed/0xf2
[ 1.581049] ? process_scheduled_works+0x24/0x24
[ 1.581666] ? __kthread_create_on_node+0x11f/0x11f
[ 1.582312] ret_from_fork+0x19/0x30
[ 1.582793] ---[ end trace ef3591d92cac5abf ]---
[ 1.584236] ------------[ cut here ]------------
[ 1.584236] ------------[ cut here ]------------
[ 1.584891] WARNING: CPU: 0 PID: 24 at kernel/locking/mutex.c:305 __ww_mutex_wakeup_for_backoff+0x31/0x7a
[ 1.586444] CPU: 0 PID: 24 Comm: kworker/u2:1 Tainted: G W 4.10.0-rc3-00155-g2a0c112 #1
[ 1.587693] Workqueue: test-ww_mutex test_cycle_work
[ 1.588357] Call Trace:
[ 1.588691] dump_stack+0x16/0x18
[ 1.589133] __warn+0xa0/0xb7
[ 1.589539] ? __ww_mutex_wakeup_for_backoff+0x31/0x7a
[ 1.590218] warn_slowpath_null+0x11/0x16
[ 1.590756] __ww_mutex_wakeup_for_backoff+0x31/0x7a
[ 1.591417] __ww_mutex_lock+0x2f3/0xb63
[ 1.592070] ? wake_up_q+0x25/0x40
[ 1.592531] ? __might_sleep+0x6c/0x73
[ 1.593032] ww_mutex_lock+0x34/0x3b
[ 1.593514] ? test_cycle_work+0xf7/0x170
[ 1.594046] test_cycle_work+0xf7/0x170
[ 1.594560] process_one_work+0x1c0/0x33a
[ 1.595099] ? process_one_work+0x168/0x33a
[ 1.595659] worker_thread+0x22f/0x315
[ 1.596157] kthread+0xed/0xf2
[ 1.596572] ? process_scheduled_works+0x24/0x24
[ 1.597183] ? __kthread_create_on_node+0x11f/0x11f
[ 1.597833] ret_from_fork+0x19/0x30
[ 1.598311] ---[ end trace ef3591d92cac5ac0 ]---
[ 1.603651] ------------[ cut here ]------------
[ 1.603651] ------------[ cut here ]------------
[ 1.604299] WARNING: CPU: 0 PID: 25 at kernel/locking/mutex.c:305 __ww_mutex_wakeup_for_backoff+0x31/0x7a
[ 1.605848] CPU: 0 PID: 25 Comm: kworker/u2:2 Tainted: G W 4.10.0-rc3-00155-g2a0c112 #1
[ 1.607086] Workqueue: test-ww_mutex stress_inorder_work
[ 1.607829] Call Trace:
[ 1.608161] dump_stack+0x16/0x18
[ 1.608616] __warn+0xa0/0xb7
[ 1.609013] ? __ww_mutex_wakeup_for_backoff+0x31/0x7a
[ 1.609691] warn_slowpath_null+0x11/0x16
[ 1.610222] __ww_mutex_wakeup_for_backoff+0x31/0x7a
[ 1.610882] __ww_mutex_lock+0x2f3/0xb63
[ 1.611542] ? ww_mutex_unlock+0x66/0x72
[ 1.612061] ? __might_sleep+0x6c/0x73
[ 1.612564] ww_mutex_lock+0x34/0x3b
[ 1.613038] ? stress_inorder_work+0xbf/0x218
[ 1.613619] stress_inorder_work+0xbf/0x218
[ 1.614170] process_one_work+0x1c0/0x33a
[ 1.614704] ? process_one_work+0x168/0x33a
[ 1.615254] worker_thread+0x22f/0x315
[ 1.615757] kthread+0xed/0xf2
[ 1.616165] ? process_scheduled_works+0x24/0x24
[ 1.616774] ? __kthread_create_on_node+0x11f/0x11f
[ 1.617422] ret_from_fork+0x19/0x30
[ 1.617898] ---[ end trace ef3591d92cac5ac1 ]---
[ 1.627667] ------------[ cut here ]------------
[ 1.627667] ------------[ cut here ]------------
[ 1.628328] WARNING: CPU: 0 PID: 24 at kernel/locking/mutex.c:305 __ww_mutex_wakeup_for_backoff+0x31/0x7a
[ 1.629883] CPU: 0 PID: 24 Comm: kworker/u2:1 Tainted: G W 4.10.0-rc3-00155-g2a0c112 #1
[ 1.631129] Workqueue: test-ww_mutex stress_inorder_work
[ 1.631871] Call Trace:
[ 1.632205] dump_stack+0x16/0x18
[ 1.632652] __warn+0xa0/0xb7
[ 1.633048] ? __ww_mutex_wakeup_for_backoff+0x31/0x7a
[ 1.633728] warn_slowpath_null+0x11/0x16
[ 1.634256] __ww_mutex_wakeup_for_backoff+0x31/0x7a
[ 1.634915] __ww_mutex_lock+0x2f3/0xb63
[ 1.635574] ? ww_mutex_unlock+0x66/0x72
[ 1.636092] ? __might_sleep+0x6c/0x73
[ 1.636595] ww_mutex_lock+0x34/0x3b
[ 1.637070] ? stress_inorder_work+0xbf/0x218
[ 1.637651] stress_inorder_work+0xbf/0x218
[ 1.638203] process_one_work+0x1c0/0x33a
[ 1.638736] ? process_one_work+0x168/0x33a
[ 1.639294] worker_thread+0x22f/0x315
[ 1.639791] kthread+0xed/0xf2
[ 1.640198] ? process_scheduled_works+0x24/0x24
[ 1.640814] ? __kthread_create_on_node+0x11f/0x11f
[ 1.641460] ret_from_fork+0x19/0x30
[ 1.641933] ---[ end trace ef3591d92cac5ac2 ]---
[ 1.651655] ------------[ cut here ]------------
[ 1.651655] ------------[ cut here ]------------
[ 1.652181] WARNING: CPU: 0 PID: 25 at kernel/locking/mutex.c:305 __ww_mutex_wakeup_for_backoff+0x31/0x7a
[ 1.653261] CPU: 0 PID: 25 Comm: kworker/u2:2 Tainted: G W 4.10.0-rc3-00155-g2a0c112 #1
[ 1.654165] Workqueue: test-ww_mutex stress_inorder_work
[ 1.654666] Call Trace:
[ 1.654938] dump_stack+0x16/0x18
[ 1.655247] __warn+0xa0/0xb7
[ 1.655534] ? __ww_mutex_wakeup_for_backoff+0x31/0x7a
[ 1.656063] warn_slowpath_null+0x11/0x16
[ 1.656441] __ww_mutex_wakeup_for_backoff+0x31/0x7a
[ 1.657092] __ww_mutex_lock+0x2f3/0xb63
[ 1.657670] ? ww_mutex_unlock+0x66/0x72
[ 1.658024] ? __might_sleep+0x6c/0x73
[ 1.658370] ww_mutex_lock+0x34/0x3b
[ 1.658694] ? stress_inorder_work+0xbf/0x218
[ 1.659123] stress_inorder_work+0xbf/0x218
[ 1.659505] process_one_work+0x1c0/0x33a
[ 1.659900] ? process_one_work+0x168/0x33a
[ 1.660289] worker_thread+0x22f/0x315
[ 1.660628] kthread+0xed/0xf2
[ 1.660906] ? process_scheduled_works+0x24/0x24
[ 1.661337] ? __kthread_create_on_node+0x11f/0x11f
[ 1.661807] ret_from_fork+0x19/0x30
[ 1.662138] ---[ end trace ef3591d92cac5ac3 ]---
[ 1.671663] ------------[ cut here ]------------
[ 1.671663] ------------[ cut here ]------------
[ 1.672440] WARNING: CPU: 0 PID: 24 at kernel/locking/mutex.c:305 __ww_mutex_wakeup_for_backoff+0x31/0x7a
[ 1.673872] CPU: 0 PID: 24 Comm: kworker/u2:1 Tainted: G W 4.10.0-rc3-00155-g2a0c112 #1
[ 1.674747] Workqueue: test-ww_mutex stress_inorder_work
[ 1.675340] Call Trace:
[ 1.675628] dump_stack+0x16/0x18
[ 1.675933] __warn+0xa0/0xb7
[ 1.676205] ? __ww_mutex_wakeup_for_backoff+0x31/0x7a
[ 1.676691] warn_slowpath_null+0x11/0x16
[ 1.677053] __ww_mutex_wakeup_for_backoff+0x31/0x7a
[ 1.677511] __ww_mutex_lock+0x2f3/0xb63
[ 1.677997] ? ww_mutex_unlock+0x66/0x72
[ 1.678366] ? __might_sleep+0x6c/0x73
[ 1.678702] ww_mutex_lock+0x34/0x3b
[ 1.679074] ? stress_inorder_work+0xbf/0x218
[ 1.679471] stress_inorder_work+0xbf/0x218
[ 1.679882] process_one_work+0x1c0/0x33a
[ 1.680266] ? process_one_work+0x168/0x33a
[ 1.680655] worker_thread+0x22f/0x315
[ 1.680991] kthread+0xed/0xf2
[ 1.681270] ? process_scheduled_works+0x24/0x24
[ 1.681726] ? __kthread_create_on_node+0x11f/0x11f
[ 1.682158] ret_from_fork+0x19/0x30
[ 1.682526] ---[ end trace ef3591d92cac5ac4 ]---
[ 1.691670] ------------[ cut here ]------------
[ 1.691670] ------------[ cut here ]------------
[ 1.692169] WARNING: CPU: 0 PID: 25 at kernel/locking/mutex.c:305 __ww_mutex_wakeup_for_backoff+0x31/0x7a
[ 1.693249] CPU: 0 PID: 25 Comm: kworker/u2:2 Tainted: G W 4.10.0-rc3-00155-g2a0c112 #1
[ 1.694232] Workqueue: test-ww_mutex stress_inorder_work
[ 1.694732] Call Trace:
[ 1.694969] dump_stack+0x16/0x18
[ 1.695287] __warn+0xa0/0xb7
[ 1.695625] ? __ww_mutex_wakeup_for_backoff+0x31/0x7a
[ 1.696096] warn_slowpath_null+0x11/0x16
[ 1.696471] __ww_mutex_wakeup_for_backoff+0x31/0x7a
[ 1.696914] __ww_mutex_lock+0x2f3/0xb63
[ 1.697363] ? ww_mutex_unlock+0x66/0x72
[ 1.697720] ? __might_sleep+0x6c/0x73
[ 1.698063] ww_mutex_lock+0x34/0x3b
[ 1.698393] ? stress_inorder_work+0xbf/0x218
[ 1.698790] stress_inorder_work+0xbf/0x218
[ 1.699173] process_one_work+0x1c0/0x33a
[ 1.699543] ? process_one_work+0x168/0x33a
[ 1.699964] worker_thread+0x22f/0x315
[ 1.700363] kthread+0xed/0xf2
[ 1.700643] ? process_scheduled_works+0x24/0x24
[ 1.701055] ? __kthread_create_on_node+0x11f/0x11f
[ 1.701497] ret_from_fork+0x19/0x30
[ 1.701826] ---[ end trace ef3591d92cac5ac5 ]---
[ 1.711724] ------------[ cut here ]------------
[ 1.711724] ------------[ cut here ]------------
[ 1.712468] WARNING: CPU: 0 PID: 24 at kernel/locking/mutex.c:305 __ww_mutex_wakeup_for_backoff+0x31/0x7a
[ 1.714139] CPU: 0 PID: 24 Comm: kworker/u2:1 Tainted: G W 4.10.0-rc3-00155-g2a0c112 #1
[ 1.715528] Workqueue: test-ww_mutex stress_inorder_work
[ 1.716336] Call Trace:
[ 1.716712] dump_stack+0x16/0x18
[ 1.717190] __warn+0xa0/0xb7
[ 1.717618] ? __ww_mutex_wakeup_for_backoff+0x31/0x7a
[ 1.718330] warn_slowpath_null+0x11/0x16
[ 1.718693] __ww_mutex_wakeup_for_backoff+0x31/0x7a
[ 1.719169] __ww_mutex_lock+0x2f3/0xb63
[ 1.719631] ? ww_mutex_unlock+0x66/0x72
[ 1.719995] ? __might_sleep+0x6c/0x73
[ 1.720339] ww_mutex_lock+0x34/0x3b
[ 1.720659] ? stress_inorder_work+0xbf/0x218
[ 1.721046] stress_inorder_work+0xbf/0x218
[ 1.721424] process_one_work+0x1c0/0x33a
[ 1.721781] ? process_one_work+0x168/0x33a
[ 1.722156] worker_thread+0x22f/0x315
[ 1.722498] kthread+0xed/0xf2
[ 1.722772] ? process_scheduled_works+0x24/0x24
[ 1.723219] ? __kthread_create_on_node+0x11f/0x11f
[ 1.723702] ret_from_fork+0x19/0x30
[ 1.724023] ---[ end trace ef3591d92cac5ac6 ]---
[ 1.731646] ------------[ cut here ]------------
[ 1.731646] ------------[ cut here ]------------
[ 1.732125] WARNING: CPU: 0 PID: 25 at kernel/locking/mutex.c:305 __ww_mutex_wakeup_for_backoff+0x31/0x7a
[ 1.733224] CPU: 0 PID: 25 Comm: kworker/u2:2 Tainted: G W 4.10.0-rc3-00155-g2a0c112 #1
[ 1.734111] Workqueue: test-ww_mutex stress_inorder_work
[ 1.734602] Call Trace:
git bisect start 1ae7fb468b3c12e4f6c93b0e79cb494f5efd0bb3 c470abd4fde40ea6a0846a2beab642a578c0b8cd --
git bisect bad ab4b5e1e2c5bbac4536be13f47478d6d2cc3a2ed # 16:48 0- 3 Merge 'linux-review/Codrut-Grosu/ASoC-tegra-Remove-unnecessary-Block-comments-should-align-the-on-each-line-message/20170226-025607' into devel-catchup-201702260319
git bisect bad 67f64eddcbb18b0fb5880be1b573ca84bcaf2df4 # 17:30 0- 43 Merge 'linux-review/Codrut-Grosu/ASoC-tegra-Add-blank-line-after-declarations/20170226-031128' into devel-catchup-201702260319
git bisect good 588a60439eca8c4eb2d397ccc15150483f1aab74 # 17:53 20+ 0 0day base guard for 'devel-catchup-201702260319'
git bisect bad 1317f81ef9b04b37aeb74f70797adaa042829da0 # 18:09 0- 25 Merge 'linux-review/Hans-de-Goede/Allow-setting-dmi-product-name-on-the-cmdline-dmi-sdhci-quirk/20170226-012824' into devel-catchup-201702260319
git bisect bad 9c4713701c01e4cef6e2315c2818abc919ffb0de # 18:32 0- 24 bpf: Fix bpf_xdp_event_output
git bisect bad ff58d005cd10fcd372787cceac547e11cf706ff6 # 18:40 0- 25 Merge tag 'media/v4.11-1' of git://git.kernel.org/pub/scm/linux/kernel/git/mchehab/linux-media
git bisect bad 2bfe01eff4307409b95859e860261d0907149b61 # 18:48 0- 8 Merge branch 'for-next' of git://git.samba.org/sfrench/cifs-2.6
git bisect good 828cad8ea05d194d8a9452e0793261c2024c23a2 # 19:00 20+ 0 Merge branch 'sched-core-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
git bisect bad f790bd9c8e826434ab6c326b225276ed0f73affe # 19:10 0- 12 Merge tag 'regulator-v4.11' of git://git.kernel.org/pub/scm/linux/kernel/git/broonie/regulator
git bisect bad 937b5b5ddd2f685b4962ec19502e641bb5741c12 # 19:21 0- 19 Merge tag 'm68k-for-v4.11-tag1' of git://git.kernel.org/pub/scm/linux/kernel/git/geert/linux-m68k
git bisect bad 8a9365a4725a4d6265a416dd63bff937e300308e # 19:28 0- 16 Merge branch 'x86-cpufeature-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
git bisect bad 85b36c931ff328297572a3e6136fac573795ad79 # 19:42 0- 21 jump_labels: Move header guard #endif down where it belongs
git bisect good 25f13b4040b68dfc5a2a22e7234894e718e3f4c5 # 21:11 21+ 0 locking/ww_mutex: Re-check ww->ctx in the inner optimistic spin loop
git bisect good d1b42b800e5d09dcee52812b4396aca3a3696ba9 # 21:25 21+ 43 locking/ww_mutex: Add kselftests for resolving ww_mutex cyclic deadlocks
git bisect bad bdfafc4ffdd24e491119d81f85ddc4393fa49803 # 21:32 0- 30 locking/atomic, kref: Kill kref_sub()
git bisect bad 2b0b211134a65401ed874ce0d5d48844f4f6f341 # 01:14 0- 47 locking/ww_mutex: Add ww_mutex to tools/testing/selftests
git bisect bad 2a0c11282881875dc44f166a20eedf0d866dd0ef # 08:32 0- 15 locking/ww_mutex: Add kselftests for ww_mutex stress
# first bad commit: [2a0c11282881875dc44f166a20eedf0d866dd0ef] locking/ww_mutex: Add kselftests for ww_mutex stress
git bisect good d1b42b800e5d09dcee52812b4396aca3a3696ba9 # 08:57 60+ 64 locking/ww_mutex: Add kselftests for resolving ww_mutex cyclic deadlocks
# extra tests on HEAD of linux-devel/devel-catchup-201702260319
git bisect bad 1ae7fb468b3c12e4f6c93b0e79cb494f5efd0bb3 # 09:19 0- 1 0day head guard for 'devel-catchup-201702260319'
# extra tests on tree/branch linus/master
git bisect bad e5d56efc97f8240d0b5d66c03949382b6d7e5570 # 09:19 0- 10 Merge tag 'watchdog-for-linus-v4.11' of git://git.kernel.org/pub/scm/linux/kernel/git/groeck/linux-staging
# extra tests with first bad commit reverted
git bisect good b7a91e31244bfcf708bf26b40f191ec795c4d20b # 09:53 60+ 0 Revert "locking/ww_mutex: Add kselftests for ww_mutex stress"
# extra tests on tree/branch linux-next/master
git bisect bad 3e7350242c6f3d41d28e03418bd781cc1b7bad5f # 10:14 0- 3 Add linux-next specific files for 20170224
---
0-DAY kernel test infrastructure Open Source Technology Center
https://lists.01.org/pipermail/lkp Intel Corporation
Download attachment "dmesg-yocto-vp-95:20170227020243:i386-randconfig-s0-201709:4.10.0-rc3-00155-g2a0c112:1.gz" of type "application/gzip" (187408 bytes)
Download attachment "dmesg-vm-ivb41-yocto-ia32-13:20170227084746:i386-randconfig-s0-201709:4.10.0-rc3-00154-gd1b42b8:1.gz" of type "application/gzip" (151795 bytes)
View attachment "reproduce-yocto-vp-95:20170227020243:i386-randconfig-s0-201709:4.10.0-rc3-00155-g2a0c112:1" of type "text/plain" (905 bytes)
View attachment "config-4.10.0-rc3-00155-g2a0c112" of type "text/plain" (93448 bytes)
Powered by blists - more mailing lists