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  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]
Date:	Mon, 10 Mar 2014 10:45:59 +0800
From:	Fengguang Wu <fengguang.wu@...el.com>
To:	Kees Cook <keescook@...omium.org>
Cc:	"H. Peter Anvin" <hpa@...ux.intel.com>,
	Andy Honig <ahonig@...gle.com>, linux-kernel@...r.kernel.org
Subject: [x86, kaslr] INFO: possible circular locking dependency detected

Hi Kees,

I got the below dmesg and the first bad commit is

git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip.git x86/kaslr
commit e2b32e6785138d92d2a40e0d0473575c8c7310a2
Author:     Kees Cook <keescook@...omium.org>
AuthorDate: Tue Feb 25 16:59:17 2014 -0800
Commit:     H. Peter Anvin <hpa@...ux.intel.com>
CommitDate: Tue Feb 25 17:07:26 2014 -0800

    x86, kaslr: randomize module base load address
    
+----------------------------------------------------+-----------+------------+---------------+
|                                                    | v3.14-rc4 | e2b32e6785 | next-20140307 |
+----------------------------------------------------+-----------+------------+---------------+
| boot_successes                                     | 86        | 9          | 5             |
| boot_failures                                      | 4         | 21         | 14            |
| BUG:kernel_boot_hang                               | 4         | 1          |               |
| INFO:possible_circular_locking_dependency_detected | 0         | 20         | 13            |
| backtrace:register_kprobe                          | 0         | 20         | 13            |
| backtrace:init_test_probes                         | 0         | 20         | 13            |
| backtrace:init_kprobes                             | 0         | 20         | 13            |
| backtrace:kernel_init_freeable                     | 0         | 20         | 13            |
| backtrace:kprobe_optimizer                         | 0         | 20         | 13            |
| BUG:kernel_test_crashed                            | 0         | 0          | 1             |
+----------------------------------------------------+-----------+------------+---------------+

[    0.489404] Kprobe smoke test started
[    0.514663] 
[    0.515287] ======================================================
[    0.515561] [ INFO: possible circular locking dependency detected ]
[    0.515561] 3.14.0-rc5-next-20140307-07129-g1b0a7e3 #1 Not tainted
[    0.515561] -------------------------------------------------------
[    0.515561] kworker/0:1/25 is trying to acquire lock:
[    0.515561]  (text_mutex){+.+.+.}, at: [<ffffffff855c2531>] kprobe_optimizer+0x121/0x23c
[    0.515561] 
[    0.515561] but task is already holding lock:
[    0.515561]  (module_mutex){+.+...}, at: [<ffffffff855c2435>] kprobe_optimizer+0x25/0x23c
[    0.515561] 
[    0.515561] which lock already depends on the new lock.
[    0.515561] 
[    0.515561] 
[    0.515561] the existing dependency chain (in reverse order) is:
[    0.515561] 
-> #2 (module_mutex){+.+...}:
[    0.515561]        [<ffffffff850b3a65>] __lock_acquire+0x910/0xa03
[    0.515561]        [<ffffffff850b4043>] lock_acquire+0xa4/0xc4
[    0.515561]        [<ffffffff855ba2fe>] mutex_lock_nested+0x65/0x34a
[    0.515561]        [<ffffffff8502f954>] module_alloc+0x42/0xb5
[    0.515561]        [<ffffffff850db8e5>] alloc_insn_page+0xe/0x10
[    0.515561]        [<ffffffff855c272c>] __get_insn_slot+0xe0/0x165
[    0.515561]        [<ffffffff855bfa73>] arch_prepare_kprobe+0x36/0xb7
[    0.515561]        [<ffffffff855c3401>] register_kprobe+0x330/0x490
[    0.515561]        [<ffffffff850d6ff2>] init_test_probes+0x4e/0x489
[    0.515561]        [<ffffffff85b7017c>] init_kprobes+0x17b/0x189
[    0.515561]        [<ffffffff850020fb>] do_one_initcall+0x9f/0x135
[    0.515561]        [<ffffffff85b54f65>] kernel_init_freeable+0x104/0x196
[    0.515561]        [<ffffffff855adbe9>] kernel_init+0x9/0xd5
[    0.515561]        [<ffffffff855c3c8c>] ret_from_fork+0x7c/0xb0
[    0.515561] 
-> #1 (kprobe_insn_slots.mutex){+.+.+.}:
[    0.515561]        [<ffffffff850b3a65>] __lock_acquire+0x910/0xa03
[    0.515561]        [<ffffffff850b4043>] lock_acquire+0xa4/0xc4
[    0.515561]        [<ffffffff855ba2fe>] mutex_lock_nested+0x65/0x34a
[    0.515561]        [<ffffffff855c2668>] __get_insn_slot+0x1c/0x165
[    0.515561]        [<ffffffff855bfa73>] arch_prepare_kprobe+0x36/0xb7
[    0.515561]        [<ffffffff855c3401>] register_kprobe+0x330/0x490
[    0.515561]        [<ffffffff850d6ff2>] init_test_probes+0x4e/0x489
[    0.515561]        [<ffffffff85b7017c>] init_kprobes+0x17b/0x189
[    0.515561]        [<ffffffff850020fb>] do_one_initcall+0x9f/0x135
[    0.515561]        [<ffffffff85b54f65>] kernel_init_freeable+0x104/0x196
[    0.515561]        [<ffffffff855adbe9>] kernel_init+0x9/0xd5
[    0.515561]        [<ffffffff855c3c8c>] ret_from_fork+0x7c/0xb0
[    0.515561] 
-> #0 (text_mutex){+.+.+.}:
[    0.515561]        [<ffffffff850b0e0f>] validate_chain.isra.20+0x8cf/0xf2e
[    0.515561]        [<ffffffff850b3a65>] __lock_acquire+0x910/0xa03
[    0.515561]        [<ffffffff850b4043>] lock_acquire+0xa4/0xc4
[    0.515561]        [<ffffffff855ba2fe>] mutex_lock_nested+0x65/0x34a
[    0.515561]        [<ffffffff855c2531>] kprobe_optimizer+0x121/0x23c
[    0.515561]        [<ffffffff8508dfc4>] process_one_work+0x237/0x3db
[    0.515561]        [<ffffffff8508edc2>] worker_thread+0x1cb/0x2c4
[    0.515561]        [<ffffffff8509498b>] kthread+0xf1/0xf9
[    0.515561]        [<ffffffff855c3c8c>] ret_from_fork+0x7c/0xb0
[    0.515561] 
[    0.515561] other info that might help us debug this:
[    0.515561] 
[    0.515561] Chain exists of:
  text_mutex --> kprobe_insn_slots.mutex --> module_mutex

[    0.515561]  Possible unsafe locking scenario:
[    0.515561] 
[    0.515561]        CPU0                    CPU1
[    0.515561]        ----                    ----
[    0.515561]   lock(module_mutex);
[    0.515561]                                lock(kprobe_insn_slots.mutex);
[    0.515561]                                lock(module_mutex);
[    0.515561]   lock(text_mutex);
[    0.515561] 
[    0.515561]  *** DEADLOCK ***
[    0.515561] 
[    0.515561] 4 locks held by kworker/0:1/25:
[    0.515561]  #0:  ("events"){.+.+..}, at: [<ffffffff8508df5e>] process_one_work+0x1d1/0x3db
[    0.515561]  #1:  ((optimizing_work).work){+.+...}, at: [<ffffffff8508df5e>] process_one_work+0x1d1/0x3db
[    0.515561]  #2:  (kprobe_mutex){+.+.+.}, at: [<ffffffff855c2427>] kprobe_optimizer+0x17/0x23c
[    0.515561]  #3:  (module_mutex){+.+...}, at: [<ffffffff855c2435>] kprobe_optimizer+0x25/0x23c
[    0.515561] 
[    0.515561] stack backtrace:
[    0.515561] CPU: 0 PID: 25 Comm: kworker/0:1 Not tainted 3.14.0-rc5-next-20140307-07129-g1b0a7e3 #1
[    0.515561] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2011
[    0.515561] Workqueue: events kprobe_optimizer
[    0.515561]  0000000000000000 ffff8800137e3b60 ffffffff855b5b1d ffffffff86069110
[    0.515561]  ffff8800137e3ba0 ffffffff855b2850 ffff8800137e4650 ffff8800137e5318
[    0.515561]  ffff8800137e4650 ffff8800137e5318 0000000000000004 ffff8800137e52f0
[    0.515561] Call Trace:
[    0.515561]  [<ffffffff855b5b1d>] dump_stack+0x4d/0x66
[    0.515561]  [<ffffffff855b2850>] print_circular_bug+0x2b4/0x2c2
[    0.515561]  [<ffffffff850b0e0f>] validate_chain.isra.20+0x8cf/0xf2e
[    0.515561]  [<ffffffff850b3a65>] __lock_acquire+0x910/0xa03
[    0.515561]  [<ffffffff850b4043>] lock_acquire+0xa4/0xc4
[    0.515561]  [<ffffffff855c2531>] ? kprobe_optimizer+0x121/0x23c
[    0.515561]  [<ffffffff855ba2fe>] mutex_lock_nested+0x65/0x34a
[    0.515561]  [<ffffffff855c2531>] ? kprobe_optimizer+0x121/0x23c
[    0.515561]  [<ffffffff850b1d8d>] ? trace_hardirqs_on+0xd/0xf
[    0.515561]  [<ffffffff855c2531>] kprobe_optimizer+0x121/0x23c
[    0.515561]  [<ffffffff8508dfc4>] process_one_work+0x237/0x3db
[    0.515561]  [<ffffffff8508df5e>] ? process_one_work+0x1d1/0x3db
[    0.515561]  [<ffffffff8508edc2>] worker_thread+0x1cb/0x2c4
[    0.515561]  [<ffffffff8508ebf7>] ? rescuer_thread+0x29b/0x29b
[    0.515561]  [<ffffffff8509498b>] kthread+0xf1/0xf9
[    0.515561]  [<ffffffff8509489a>] ? kthread_stop+0x5a/0x5a
[    0.515561]  [<ffffffff855c3c8c>] ret_from_fork+0x7c/0xb0
[    0.515561]  [<ffffffff8509489a>] ? kthread_stop+0x5a/0x5a
[    0.679517] Kprobe smoke test passed successfully
[    0.681393] bounce pool size: 64 pages
[    0.682499] HugeTLB registered 2 MB page size, pre-allocated 0 pages

git bisect start 56032fc504c9ce9dd6fd697e4687441a7d0ea4a2 v3.13 --
git bisect good 7df4d0c9784117f7bbaec17e9ac7f6545049b56d  # 18:32     25+      2  Merge tag 'spi-v3.14-rc2' of git://git.kernel.org/pub/scm/linux/kernel/git/broonie/spi
git bisect good b338b822eba2fdcbad7aa4149899fb734f9f16ec  # 18:45     25+      0  Merge remote-tracking branch 'input-current/for-linus'
git bisect good 992670b5cd97fdc97e9fe15c3f8c16c218749c96  # 18:58     25+      0  Merge remote-tracking branch 'net-next/master'
git bisect good 8b42ab5d6c5140cad34957a32fa6bdf43e7e0303  # 19:14     25+      0  Merge remote-tracking branch 'spi/for-next'
git bisect  bad 25ec37d3e3bf1f9efec6f05d79fd976bff4624cd  # 19:33      2-      8  Merge remote-tracking branch 'staging/staging-next'
git bisect  bad d2d275f41085c59209725f813c243d318f185d36  # 19:55      0-      2  Merge remote-tracking branch 'workqueues/for-next'
git bisect  bad e88f8465cfcce042e48ff38e796b64df973c7048  # 20:07      0-      4  Merge remote-tracking branch 'ftrace/for-next'
git bisect  bad f4f48a2692f9de0d1ebbeee7ba192a99e86d1773  # 20:24      0-      1  Merge remote-tracking branch 'tip/auto-latest'
git bisect good c149ec107189eeaa818dff7d97e6fe74b0d61bc2  # 20:49     25+      2  Merge branch 'perf/core'
git bisect good d27c8438eeedb6e1367b592c101e3c87cca0b50f  # 21:17     25+      0  Merge branch 'timers/core' into sched/idle
git bisect good abb27428861a8e3fb90c063e2f2c3cdf8e20b1b7  # 21:31     25+      0  Merge branch 'x86/asmlinkage'
git bisect  bad 1a1985d4555edb30b8d807046c7c6f3ca9221217  # 21:41      0-      1  Merge branch 'x86/mm'
git bisect good 957d31ef264d0c8012dcb4a47543987bbdf2c184  # 21:50     25+      0  Merge branch 'x86/cpu'
git bisect good ea4b5c80da79debb2d29e8c27a19a7579d2867c3  # 22:09     25+      0  Merge branch 'x86/cpufeature'
git bisect  bad d6e451515a6167b63e79612c7c107d0916d7f2b2  # 22:18      1-      1  Merge branch 'x86/kaslr'
git bisect  bad e2b32e6785138d92d2a40e0d0473575c8c7310a2  # 22:25      1-      4  x86, kaslr: randomize module base load address
# first bad commit: [e2b32e6785138d92d2a40e0d0473575c8c7310a2] x86, kaslr: randomize module base load address
git bisect good cfbf8d4857c26a8a307fb7cd258074c9dcd8c691  # 22:55     90+      4  Linux 3.14-rc4
git bisect  bad 1b0a7e3263168a06d3858798e48c5a21d1c78d3c  # 22:55      0-     14  Add linux-next specific files for 20140307
git bisect good ca62eec4e524591b82d9edf7a18e3ae6b691517d  # 23:39     90+      1  Merge branch 'for-3.14-fixes' of git://git.kernel.org/pub/scm/linux/kernel/git/tj/cgroup
git bisect  bad 1b0a7e3263168a06d3858798e48c5a21d1c78d3c  # 23:39      0-     14  Add linux-next specific files for 20140307

Thanks,
Fengguang

View attachment "dmesg-yocto-ivytown2-24:20140309134424:x86_64-randconfig-r5-03091328:3.14.0-rc5-next-20140307-07129-g1b0a7e3:1" of type "text/plain" (53761 bytes)

Download attachment "x86_64-randconfig-r5-03091328-1b0a7e3263168a06d3858798e48c5a21d1c78d3c-INFO:-possible-circular-locking-dependency-detected-34643.log" of type "application/octet-stream" (99669 bytes)

View attachment "config-3.14.0-rc5-next-20140307-07129-g1b0a7e3" of type "text/plain" (85211 bytes)

_______________________________________________
LKP mailing list
LKP@...ux.intel.com

Powered by blists - more mailing lists