Hi Zhiguo, I got the below dmesg and the first bad commit is git://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git master commit 2c575026fae6e63771bd2a4c1d407214a8096a89 Author: Hong Zhiguo AuthorDate: Wed Nov 20 10:35:05 2013 -0700 Commit: Jens Axboe CommitDate: Wed Nov 20 15:33:04 2013 -0700 Update of blkg_stat and blkg_rwstat may happen in bh context. While u64_stats_fetch_retry is only preempt_disable on 32bit UP system. This is not enough to avoid preemption by bh and may read strange 64 bit value. Signed-off-by: Hong Zhiguo Acked-by: Tejun Heo Cc: stable@kernel.org Signed-off-by: Jens Axboe +-----------------------------------------------------------+------------+------------+ | | 82023bb7f7 | 2c575026fa | +-----------------------------------------------------------+------------+------------+ | boot_successes | 47 | 0 | | boot_failures | 13 | 20 | | BUG:kernel_boot_hang | 13 | 5 | | inconsistent_IN-SOFTIRQ-W-SOFTIRQ-ON-W_usage | 0 | 15 | | backtrace:smpboot_thread_fn | 0 | 15 | | backtrace:vfs_read | 0 | 9 | | backtrace:SyS_read | 0 | 9 | | WARNING:CPU:PID:at_kernel/softirq.c:_local_bh_enable_ip() | 0 | 7 | | BUG:spinlock_lockup_suspected_on_CPU | 0 | 1 | | backtrace:do_mount | 0 | 6 | | backtrace:SyS_mount | 0 | 6 | | backtrace:async_run_entry_fn | 0 | 0 | +-----------------------------------------------------------+------------+------------+ [ 12.318816] WARNING: CPU: 0 PID: 300 at kernel/softirq.c:156 _local_bh_enable_ip+0x34/0x97() [ 12.320012] CPU: 0 PID: 300 Comm: mount Not tainted 3.12.0-10878-g2c57502 #1 [ 12.320012] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2011 [ 12.320012] 00000000 00000000 d0017b58 c0a2b528 d0017b70 c025daed c026085e c04efc4a [ 12.320012] d1ff5044 d0017bdc d0017b80 c025db8a 00000009 00000000 d0017b8c c026085e [ 12.320012] d0017bbc d0017b94 c02608cc d0017ba8 c04efc4a d1061140 d1ff4e10 d10242b0 [ 12.320012] Call Trace: [ 12.320012] [] dump_stack+0x16/0x18 [ 12.320012] [] warn_slowpath_common+0x50/0x67 [ 12.320012] [] ? _local_bh_enable_ip+0x34/0x97 [ 12.320012] [] ? blkg_rwstat_read+0x1d/0x24 [ 12.320012] [] warn_slowpath_null+0xf/0x13 [ 12.320012] [] _local_bh_enable_ip+0x34/0x97 [ 12.320012] [] local_bh_enable+0xb/0xd [ 12.320012] [] blkg_rwstat_read+0x1d/0x24 [ 12.320012] [] __cfq_set_active_queue+0x6b/0x188 [ 12.320012] [] ? cfq_resort_rr_list+0x1f/0x23 [ 12.320012] [] ? __arch_hweight32+0x8/0xa [ 12.320012] [] ? cfq_update_idle_window.isra.80+0x7d/0xe4 [ 12.320012] [] ? kvm_clock_read+0x14/0x1d [ 12.320012] [] ? paravirt_sched_clock+0x9/0xd [ 12.320012] [] ? sched_clock+0x9/0xc [ 12.320012] [] ? sched_clock_local.constprop.3+0xe/0x106 [ 12.320012] [] cfq_dispatch_requests+0x528/0x7a8 [ 12.320012] [] ? paravirt_sched_clock+0x9/0xd [ 12.320012] [] ? sched_clock+0x9/0xc [ 12.320012] [] ? cfq_insert_request+0x18d/0x323 [ 12.320012] [] ? sched_clock_cpu+0xb8/0xc6 [ 12.320012] [] ? trace_hardirqs_on+0xb/0xd [ 12.320012] [] ? _raw_spin_unlock_irq+0x27/0x30 [ 12.320012] [] ? trace_hardirqs_off+0xb/0xd [ 12.320012] [] blk_peek_request+0x57/0x180 [ 12.320012] [] scsi_request_fn+0x38/0x42f [ 12.320012] [] __blk_run_queue_uncond+0x21/0x2a [ 12.320012] [] __blk_run_queue+0x13/0x15 [ 12.320012] [] blk_queue_bio+0x1c7/0x1da [ 12.320012] [] generic_make_request+0x7f/0xb4 [ 12.320012] [] submit_bio+0xd5/0x107 [ 12.320012] [] ? bio_alloc_bioset+0xb7/0x139 [ 12.320012] [] _submit_bh+0x139/0x154 [ 12.320012] [] submit_bh+0xa/0xc [ 12.320012] [] __bread+0x3e/0x59 [ 12.320012] [] ext4_fill_super+0x1c0/0x24d2 [ 12.320012] [] ? string.isra.4+0x2d/0x92 [ 12.320012] [] ? disk_name+0x20/0x65 [ 12.320012] [] ? ext4_calculate_overhead+0x2df/0x2df [ 12.320012] [] mount_bdev+0x12a/0x183 [ 12.320012] [] ? ext4_calculate_overhead+0x2df/0x2df [ 12.320012] [] ? __kmalloc_track_caller+0x81/0xe2 [ 12.320012] [] ? alloc_vfsmnt+0xe9/0x10f [ 12.320012] [] ext4_mount+0x10/0x12 [ 12.320012] [] ? ext4_calculate_overhead+0x2df/0x2df [ 12.320012] [] mount_fs+0xe/0x96 [ 12.320012] [] vfs_kern_mount+0x40/0x9e [ 12.320012] [] do_mount+0x611/0x6f6 [ 12.320012] [] ? strndup_user+0x2c/0x3d [ 12.320012] [] SyS_mount+0x71/0xa0 [ 12.320012] [] syscall_call+0x7/0xb [ 12.320012] ---[ end trace 1790dec9013df875 ]--- [ 12.320012] [ 12.320012] ================================= [ 12.320012] [ INFO: inconsistent lock state ] [ 12.320012] 3.12.0-10878-g2c57502 #1 Tainted: G W [ 12.320012] --------------------------------- [ 12.320012] inconsistent {IN-SOFTIRQ-W} -> {SOFTIRQ-ON-W} usage. [ 12.320012] mount/300 [HC0[0]:SC0[0]:HE1:SE1] takes: [ 12.320012] (&(&q->__queue_lock)->rlock){+.?...}, at: [] blk_queue_bio+0x1a6/0x1da [ 12.320012] {IN-SOFTIRQ-W} state was registered at: [ 12.320012] [] __lock_acquire+0x27d/0xbfe [ 12.320012] [] lock_acquire+0x56/0x72 [ 12.320012] [] _raw_spin_lock+0x24/0x54 [ 12.320012] [] scsi_device_unbusy+0x5b/0x7e [ 12.320012] [] scsi_finish_command+0x1d/0xc7 [ 12.320012] [] scsi_softirq_done+0xd6/0xde [ 12.320012] [] blk_done_softirq+0x6e/0x77 [ 12.320012] [] __do_softirq+0x94/0x16d [ 12.320012] [] run_ksoftirqd+0x1e/0x54 [ 12.320012] [] smpboot_thread_fn+0x102/0x116 [ 12.320012] [] kthread+0xa0/0xa5 [ 12.320012] [] ret_from_kernel_thread+0x1b/0x28 [ 12.320012] irq event stamp: 2146 [ 12.320012] hardirqs last enabled at (2143): [] _raw_spin_unlock_irq+0x22/0x30 [ 12.320012] hardirqs last disabled at (2144): [] _raw_spin_lock_irq+0x11/0x5e [ 12.320012] softirqs last enabled at (2146): [] blkg_rwstat_read+0x1d/0x24 [ 12.320012] softirqs last disabled at (2145): [] blkg_rwstat_read+0x11/0x24 [ 12.320012] [ 12.320012] other info that might help us debug this: [ 12.320012] Possible unsafe locking scenario: [ 12.320012] [ 12.320012] CPU0 [ 12.320012] ---- [ 12.320012] lock(&(&q->__queue_lock)->rlock); [ 12.320012] [ 12.320012] lock(&(&q->__queue_lock)->rlock); [ 12.320012] [ 12.320012] *** DEADLOCK *** [ 12.320012] [ 12.320012] 2 locks held by mount/300: [ 12.320012] #0: (&type->s_umount_key#17/1){+.+.+.}, at: [] sget+0x1e4/0x355 [ 12.320012] #1: (&(&q->__queue_lock)->rlock){+.?...}, at: [] blk_queue_bio+0x1a6/0x1da [ 12.320012] [ 12.320012] stack backtrace: [ 12.320012] CPU: 0 PID: 300 Comm: mount Tainted: G W 3.12.0-10878-g2c57502 #1 [ 12.320012] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2011 [ 12.320012] 00000000 d00935c0 d0017af4 c0a2b528 d0017b20 c0a27d03 c0d35294 c0d35193 [ 12.320012] c0d3515b c0d3517a c0d35184 c0d36010 d0093a44 c0281162 00000010 d0017b48 [ 12.320012] c028172e 00000006 00000000 d00935c0 00000004 00000006 d0093a44 d00935c0 [ 12.320012] Call Trace: [ 12.320012] [] dump_stack+0x16/0x18 [ 12.320012] [] print_usage_bug+0x180/0x18d [ 12.320012] [] ? print_shortest_lock_dependencies+0x13c/0x13c [ 12.320012] [] mark_lock+0xf7/0x1df [ 12.320012] [] mark_held_locks+0x5b/0x72 [ 12.320012] [] ? _local_bh_enable_ip+0x8f/0x97 [ 12.320012] [] trace_hardirqs_on_caller+0x14b/0x165 [ 12.320012] [] ? blkg_rwstat_read+0x1d/0x24 [ 12.320012] [] trace_hardirqs_on+0xb/0xd [ 12.320012] [] _local_bh_enable_ip+0x8f/0x97 [ 12.320012] [] local_bh_enable+0xb/0xd [ 12.320012] [] blkg_rwstat_read+0x1d/0x24 [ 12.320012] [] __cfq_set_active_queue+0x6b/0x188 [ 12.320012] [] ? cfq_resort_rr_list+0x1f/0x23 [ 12.320012] [] ? __arch_hweight32+0x8/0xa [ 12.320012] [] ? cfq_update_idle_window.isra.80+0x7d/0xe4 [ 12.320012] [] ? kvm_clock_read+0x14/0x1d [ 12.320012] [] ? paravirt_sched_clock+0x9/0xd [ 12.320012] [] ? sched_clock+0x9/0xc [ 12.320012] [] ? sched_clock_local.constprop.3+0xe/0x106 [ 12.320012] [] cfq_dispatch_requests+0x528/0x7a8 [ 12.320012] [] ? paravirt_sched_clock+0x9/0xd [ 12.320012] [] ? sched_clock+0x9/0xc [ 12.320012] [] ? cfq_insert_request+0x18d/0x323 [ 12.320012] [] ? sched_clock_cpu+0xb8/0xc6 [ 12.320012] [] ? trace_hardirqs_on+0xb/0xd [ 12.320012] [] ? _raw_spin_unlock_irq+0x27/0x30 [ 12.320012] [] ? trace_hardirqs_off+0xb/0xd [ 12.320012] [] blk_peek_request+0x57/0x180 [ 12.320012] [] scsi_request_fn+0x38/0x42f [ 12.320012] [] __blk_run_queue_uncond+0x21/0x2a [ 12.320012] [] __blk_run_queue+0x13/0x15 [ 12.320012] [] blk_queue_bio+0x1c7/0x1da [ 12.320012] [] generic_make_request+0x7f/0xb4 [ 12.320012] [] submit_bio+0xd5/0x107 [ 12.320012] [] ? bio_alloc_bioset+0xb7/0x139 [ 12.320012] [] _submit_bh+0x139/0x154 [ 12.320012] [] submit_bh+0xa/0xc [ 12.320012] [] __bread+0x3e/0x59 [ 12.320012] [] ext4_fill_super+0x1c0/0x24d2 [ 12.320012] [] ? string.isra.4+0x2d/0x92 [ 12.320012] [] ? disk_name+0x20/0x65 [ 12.320012] [] ? ext4_calculate_overhead+0x2df/0x2df [ 12.320012] [] mount_bdev+0x12a/0x183 [ 12.320012] [] ? ext4_calculate_overhead+0x2df/0x2df [ 12.320012] [] ? __kmalloc_track_caller+0x81/0xe2 [ 12.320012] [] ? alloc_vfsmnt+0xe9/0x10f [ 12.320012] [] ext4_mount+0x10/0x12 [ 12.320012] [] ? ext4_calculate_overhead+0x2df/0x2df [ 12.320012] [] mount_fs+0xe/0x96 [ 12.320012] [] vfs_kern_mount+0x40/0x9e [ 12.320012] [] do_mount+0x611/0x6f6 [ 12.320012] [] ? strndup_user+0x2c/0x3d [ 12.320012] [] SyS_mount+0x71/0xa0 [ 12.320012] [] syscall_call+0x7/0xb git bisect start v3.13 v3.12 -- git bisect good 3bad8bb5cd3048a67df43ac6b1e2f191f19d9ff0 # 15:26 20+ 9 Merge branch 'for-next' of git://git.samba.org/sfrench/cifs-2.6 git bisect bad 843f4f4bb1a2c4c196a1af1d18bb6477a580ac78 # 15:33 0- 12 Merge tag 'trace-fixes-3.13-rc2' of git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-trace git bisect good a45299e72737c528975546a0680cace5d7364d27 # 15:57 20+ 3 Merge branch 'irq-urgent-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip git bisect good 09759d1e13e06c2f6346b1b3285fbde2c1e794c6 # 16:14 20+ 1 Merge tag 'sound-3.13-rc3' of git://git.kernel.org/pub/scm/linux/kernel/git/tiwai/sound git bisect bad b52b342d31fecfeab0e2a256dfd84ea84954a8d3 # 16:20 0- 7 Merge branch 'stable' of git://git.kernel.org/pub/scm/linux/kernel/git/cmetcalf/linux-tile git bisect good ef1e4e32d595d3e6c9a6d3d2956f087d5886c5e5 # 16:36 20+ 6 Merge tag 'for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/mason/linux-btrfs git bisect good 29be6345bbaec8502a70c4e2204d5818b48c4e8f # 16:53 20+ 4 Merge tag 'nfs-for-3.13-3' of git://git.linux-nfs.org/projects/trondmy/linux-nfs git bisect bad 5ee540613db504a10e15fafaf4c08cac96aa1823 # 17:00 0- 6 Merge branch 'for-linus' of git://git.kernel.dk/linux-block git bisect bad e345d767f6530ec9cb0aabab7ea248072a9c6975 # 17:08 0- 5 Merge branch 'stable/for-jens-3.13-take-two' of git://git.kernel.org/pub/scm/linux/kernel/git/xen/tip into for-linus git bisect bad c170bbb45febc03ac4d34ba2b8bb55e06104b7e7 # 17:12 0- 1 block: submit_bio_wait() conversions git bisect bad 2c575026fae6e63771bd2a4c1d407214a8096a89 # 17:21 0- 12 Update of blkg_stat and blkg_rwstat may happen in bh context. While u64_stats_fetch_retry is only preempt_disable on 32bit UP system. This is not enough to avoid preemption by bh and may read strange 64 bit value. # first bad commit: [2c575026fae6e63771bd2a4c1d407214a8096a89] Update of blkg_stat and blkg_rwstat may happen in bh context. While u64_stats_fetch_retry is only preempt_disable on 32bit UP system. This is not enough to avoid preemption by bh and may read strange 64 bit value. git bisect good 82023bb7f75b0052f40d3e74169d191c3e4e6286 # 17:42 60+ 13 Merge tag 'pm+acpi-2-3.13-rc1' of git://git.kernel.org/pub/scm/linux/kernel/git/rafael/linux-pm git bisect bad 36efbdff85370263b2262022687c19ac7e7fe83e # 17:42 0- 13 Add linux-next specific files for 20140417 git bisect bad ebfc45ee7004088d610cd399d2dee6d95f87199b # 17:50 0- 10 Merge git://git.kernel.org/pub/scm/linux/kernel/git/davem/net git bisect bad 36efbdff85370263b2262022687c19ac7e7fe83e # 17:50 0- 13 Add linux-next specific files for 20140417 This script may reproduce the error. ----------------------------------------------------------------------------- #!/bin/bash kernel=$1 initrd=yocto-minimal-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[*]}" ----------------------------------------------------------------------------- Attached dmesg for the parent commit, too, to help confirm whether it is a noise error. Thanks, Jet