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

Powered by Openwall GNU/*/Linux Powered by OpenVZ