Greetings, 0day kernel testing robot got the below dmesg and the first bad commit is git://git.kernel.org/pub/scm/linux/kernel/git/peterz/queue.git locking/core commit b7e4888bad0c84db587a2beae72dcf1c40ec0e52 Author: Waiman Long AuthorDate: Mon Jun 23 14:25:00 2014 -0400 Commit: Peter Zijlstra CommitDate: Tue Jun 24 16:39:40 2014 +0200 lockdep: restrict the use of recursive read_lock with qrwlock Unlike the original unfair rwlock implementation, queued rwlock will grant lock according to the chronological sequence of the lock requests except when the lock requester is in the interrupt context. Consequently, recursive read_lock calls will now hang the process if there is a write_lock call somewhere in between the read_lock calls. This patch updates the lockdep implementation to look for recursive read_lock calls when queued rwlock is being used. A new read state (3) is used to mark those read_lock call that cannot be recursively called except in the interrupt context. The new read state does exhaust the 2 bits available in held_lock:read bit field. The addition of any new read state in the future may require a redesign of how all those bits are squeezed together in the held_lock structure. Cc: Scott J Norton Cc: Ingo Molnar Signed-off-by: Waiman Long Signed-off-by: Peter Zijlstra Link: http://lkml.kernel.org/r/1403547900-40658-2-git-send-email-Waiman.Long(a)hp.com +----------------------------------------------------+------------+------------+------------+ | | 6cc620bc8e | b7e4888bad | 5fe00a37f7 | +----------------------------------------------------+------------+------------+------------+ | boot_successes | 60 | 0 | 0 | | boot_failures | 0 | 20 | 13 | | BUG:unexpected_failures(out_of)-debugging_disabled | 0 | 20 | 13 | +----------------------------------------------------+------------+------------+------------+ [ 0.000000] -------------------------------------------------------------------------- [ 0.000000] A-A deadlock: ok | ok |FAILED| [ 0.000000] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 3.16.0-rc1-00024-gb7e4888 #12 [ 0.000000] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2011 [ 0.000000] 00000000 00000000 c1633f8c c141223b 00000001 c1633fb4 c141248b c159ffe8 [ 0.000000] c140fce6 00000000 00000004 00000002 c16bf390 00020800 c1844800 c1633fc8 [ 0.000000] c121fe62 c15a01b7 c15a01aa 00000780 c1633fe8 c1688a0d 000000ea ffffffff [ 0.000000] Call Trace: [ 0.000000] [] dump_stack+0x48/0x60 [ 0.000000] [] dotest+0x58/0x4bc [ 0.000000] [] ? printk+0x38/0x3a [ 0.000000] [] locking_selftest+0xd4/0x1ddb [ 0.000000] [] start_kernel+0x2e5/0x3a1 [ 0.000000] [] ? set_init_arg+0x49/0x49 [ 0.000000] [] i386_start_kernel+0x79/0x7d [ 0.000000] ok | ok | ok | [ 0.000000] A-B-B-A deadlock: ok | ok |FAILED| [ 0.000000] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 3.16.0-rc1-00024-gb7e4888 #12 [ 0.000000] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2011 [ 0.000000] 00000000 00000000 c1633f8c c141223b 00000001 c1633fb4 c141248b c159ffe8 [ 0.000000] c140fce6 00000000 00000004 00000002 c16bf390 00020800 c1844800 c1633fc8 [ 0.000000] c121feeb c15a01b7 c15a01bd 00000780 c1633fe8 c1688a0d 000000ea ffffffff [ 0.000000] Call Trace: [ 0.000000] [] dump_stack+0x48/0x60 [ 0.000000] [] dotest+0x58/0x4bc [ 0.000000] [] ? printk+0x38/0x3a [ 0.000000] [] locking_selftest+0x15d/0x1ddb [ 0.000000] [] start_kernel+0x2e5/0x3a1 [ 0.000000] [] ? set_init_arg+0x49/0x49 [ 0.000000] [] i386_start_kernel+0x79/0x7d [ 0.000000] ok | ok | ok | [ 0.000000] A-B-B-C-C-A deadlock: ok | ok |FAILED| [ 0.000000] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 3.16.0-rc1-00024-gb7e4888 #12 [ 0.000000] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2011 [ 0.000000] 00000000 00000000 c1633f8c c141223b 00000001 c1633fb4 c141248b c159ffe8 [ 0.000000] c140fce6 00000000 00000004 00000002 c16bf390 00020800 c1844800 c1633fc8 [ 0.000000] c121ff74 c15a01b7 c15a01ce 00000780 c1633fe8 c1688a0d 000000ea ffffffff [ 0.000000] Call Trace: [ 0.000000] [] dump_stack+0x48/0x60 [ 0.000000] [] dotest+0x58/0x4bc [ 0.000000] [] ? printk+0x38/0x3a [ 0.000000] [] locking_selftest+0x1e6/0x1ddb [ 0.000000] [] start_kernel+0x2e5/0x3a1 [ 0.000000] [] ? set_init_arg+0x49/0x49 [ 0.000000] [] i386_start_kernel+0x79/0x7d [ 0.000000] ok | ok | ok | [ 0.000000] A-B-C-A-B-C deadlock: ok | ok |FAILED| [ 0.000000] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 3.16.0-rc1-00024-gb7e4888 #12 [ 0.000000] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2011 [ 0.000000] 00000000 00000000 c1633f8c c141223b 00000001 c1633fb4 c141248b c159ffe8 [ 0.000000] c140fce6 00000000 00000004 00000002 c16bf390 00020800 c1844800 c1633fc8 [ 0.000000] c121fffd c15a01b7 c15a01e3 00000780 c1633fe8 c1688a0d 000000ea ffffffff [ 0.000000] Call Trace: [ 0.000000] [] dump_stack+0x48/0x60 [ 0.000000] [] dotest+0x58/0x4bc [ 0.000000] [] ? printk+0x38/0x3a [ 0.000000] [] locking_selftest+0x26f/0x1ddb [ 0.000000] [] start_kernel+0x2e5/0x3a1 [ 0.000000] [] ? set_init_arg+0x49/0x49 [ 0.000000] [] i386_start_kernel+0x79/0x7d [ 0.000000] ok | ok | ok | [ 0.000000] A-B-B-C-C-D-D-A deadlock: ok | ok |FAILED| [ 0.000000] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 3.16.0-rc1-00024-gb7e4888 #12 [ 0.000000] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2011 [ 0.000000] 00000000 00000000 c1633f8c c141223b 00000001 c1633fb4 c141248b c159ffe8 [ 0.000000] c140fce6 00000000 00000004 00000002 c16bf390 00020800 c1844800 c1633fc8 [ 0.000000] c1220086 c15a01b7 c15a01f8 00000780 c1633fe8 c1688a0d 000000ea ffffffff [ 0.000000] Call Trace: [ 0.000000] [] dump_stack+0x48/0x60 [ 0.000000] [] dotest+0x58/0x4bc [ 0.000000] [] ? printk+0x38/0x3a [ 0.000000] [] locking_selftest+0x2f8/0x1ddb [ 0.000000] [] start_kernel+0x2e5/0x3a1 [ 0.000000] [] ? set_init_arg+0x49/0x49 [ 0.000000] [] i386_start_kernel+0x79/0x7d [ 0.000000] ok | ok | ok | [ 0.000000] A-B-C-D-B-D-D-A deadlock: ok | ok |FAILED| [ 0.000000] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 3.16.0-rc1-00024-gb7e4888 #12 [ 0.000000] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2011 [ 0.000000] 00000000 00000000 c1633f8c c141223b 00000001 c1633fb4 c141248b c159ffe8 [ 0.000000] c140fce6 00000000 00000004 00000002 c16bf390 00020800 c1844800 c1633fc8 [ 0.000000] c122010f c15a01b7 c15a0211 00000780 c1633fe8 c1688a0d 000000ea ffffffff [ 0.000000] Call Trace: [ 0.000000] [] dump_stack+0x48/0x60 [ 0.000000] [] dotest+0x58/0x4bc [ 0.000000] [] ? printk+0x38/0x3a [ 0.000000] [] locking_selftest+0x381/0x1ddb [ 0.000000] [] start_kernel+0x2e5/0x3a1 [ 0.000000] [] ? set_init_arg+0x49/0x49 [ 0.000000] [] i386_start_kernel+0x79/0x7d [ 0.000000] ok | ok | ok | [ 0.000000] A-B-C-D-B-C-D-A deadlock: ok | ok |FAILED| [ 0.000000] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 3.16.0-rc1-00024-gb7e4888 #12 [ 0.000000] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2011 [ 0.000000] 00000000 00000000 c1633f8c c141223b 00000001 c1633fb4 c141248b c159ffe8 [ 0.000000] c140fce6 00000000 00000004 00000002 c16bf390 00020800 c1844800 c1633fc8 [ 0.000000] c1220198 c15a01b7 c15a022a 00000780 c1633fe8 c1688a0d 000000ea ffffffff [ 0.000000] Call Trace: [ 0.000000] [] dump_stack+0x48/0x60 [ 0.000000] [] dotest+0x58/0x4bc [ 0.000000] [] ? printk+0x38/0x3a [ 0.000000] [] locking_selftest+0x40a/0x1ddb [ 0.000000] [] start_kernel+0x2e5/0x3a1 [ 0.000000] [] ? set_init_arg+0x49/0x49 [ 0.000000] [] i386_start_kernel+0x79/0x7d [ 0.000000] ok | ok | ok | [ 0.000000] double unlock: ok | ok | ok | ok | ok | ok | [ 0.000000] initialize held: ok | ok | ok | ok | ok | ok | git bisect start 5fe00a37f7eb81f306abdffbf4d7093da51b8ccc a497c3ba1d97fc69c1e78e7b96435ba8c2cb42ee -- git bisect bad f07035a109af7964e8446cb7ffc1721a1c2ce43c # 23:40 0- 20 Merge 'peterz-queue/locking/core' into devel-lkp-hsx01-i386-201406242318 git bisect good 4dda92923e85460ff9299b486176f09cc25ca104 # 23:56 20+ 0 Merge 'amirv/for-net' into devel-lkp-hsx01-i386-201406242318 git bisect good 5054910c90f25564062e9a1c78e4d37a51077955 # 00:18 20+ 0 Merge 'amirv/for-netdev' into devel-lkp-hsx01-i386-201406242318 git bisect good 88f2b4c15e561bb5c28709d666364f273bf54b98 # 00:51 20+ 0 rtmutex: Simplify rtmutex_slowtrylock() git bisect good a57594a13a446d1a6ab1dcd48339f799ce586843 # 01:01 20+ 0 rtmutex: Clarify the boost/deboost part git bisect good 6cc620bc8e9b521e61f04eefbec0c41c01fb03b9 # 01:09 20+ 0 rtmutex: Make the rtmutex tester depend on BROKEN git bisect bad b7e4888bad0c84db587a2beae72dcf1c40ec0e52 # 01:13 0- 20 lockdep: restrict the use of recursive read_lock with qrwlock # first bad commit: [b7e4888bad0c84db587a2beae72dcf1c40ec0e52] lockdep: restrict the use of recursive read_lock with qrwlock git bisect good 6cc620bc8e9b521e61f04eefbec0c41c01fb03b9 # 01:16 60+ 0 rtmutex: Make the rtmutex tester depend on BROKEN git bisect bad 5fe00a37f7eb81f306abdffbf4d7093da51b8ccc # 01:16 0- 13 0day head guard for 'devel-lkp-hsx01-i386-201406242318' git bisect good 8b8f5d9715845f9ae2b89ce406e71877965b29ca # 01:20 60+ 0 Merge tag 'compress-3.16-rc3' of git://git.kernel.org/pub/scm/linux/kernel/git/gregkh/driver-core git bisect good 3ab63dc6b2912b76632e34889ec26355096aaead # 01:21 60+ 63 Add linux-next specific files for 20140624 This script may reproduce the error. ----------------------------------------------------------------------------- #!/bin/bash kernel=$1 initrd=quantal-core-i386.cgz wget --no-clobber https://github.com/fengguang/reproduce-kernel-bug/blob/master/initrd/$initrd kvm=( qemu-system-x86_64 -cpu kvm64 -enable-kvm -kernel $kernel -initrd $initrd -smp 2 -m 256M -net nic,vlan=0,macaddr=00:00:00:00:00:00,model=virtio -net user,vlan=0 -net nic,vlan=1,model=e1000 -net user,vlan=1 -boot order=nc -no-reboot -watchdog i6300esb -serial stdio -display none -monitor null ) append=( debug sched_debug apic=debug ignore_loglevel sysrq_always_enabled panic=10 prompt_ramdisk=0 earlyprintk=ttyS0,115200 console=ttyS0,115200 console=tty0 vga=normal root=/dev/ram0 rw ) "${kvm[@]}" --append "${append[*]}" ----------------------------------------------------------------------------- Thanks, Fengguang _______________________________________________ LKP mailing list LKP(a)linux.intel.com