Subject : 2.6.29-git12 : lockdep warning Submitter : Sachin Sant <sachinp@in.ibm.com> Date : 2009-04-05 12:37 References : http://marc.info/?l=linux-kernel&m=123893439229272&w=4 This entry is being used for tracking a regression from 2.6.29. Please don't close it until the problem is fixed in the mainline.
On Sunday 19 April 2009, Sachin Sant wrote: > Rafael J. Wysocki wrote: > > Bug-Entry : http://bugzilla.kernel.org/show_bug.cgi?id=13068 > > Subject : Lockdep warining in inotify_dev_queue_event > > Submitter : Sachin Sant <sachinp@in.ibm.com> > > Date : 2009-04-05 12:37 (12 days old) > > References : http://marc.info/?l=linux-kernel&m=123893439229272&w=4 > > > I can recreate this with latest kernel. Easiest way is to use the LTP mm > tests (runltp -f mm ) > > ================================= > [ INFO: inconsistent lock state ] > 2.6.30-rc2-git4 #4 > --------------------------------- > inconsistent {RECLAIM_FS-ON-W} -> {IN-RECLAIM_FS-W} usage. > kswapd0/334 [HC0[0]:SC0[0]:HE1:SE1] takes: > (&inode->inotify_mutex){+.+.?.}, at: [<c000000000166cc0>] > .inotify_inode_is_dead+0x38/0xc8 > {RECLAIM_FS-ON-W} state was registered at: > [<c000000000098d74>] .lockdep_trace_alloc+0xc4/0xf4 > [<c000000000122128>] .__kmalloc+0x100/0x274 > [<c0000000001682fc>] .kernel_event+0xb8/0x154 > [<c0000000001684b8>] .inotify_dev_queue_event+0x120/0x1cc > [<c000000000166b2c>] .inotify_inode_queue_event+0xf0/0x160 > [<c000000000139c08>] .vfs_create+0x170/0x1dc > [<c00000000013d5c0>] .do_filp_open+0x25c/0x964 > [<c00000000012b414>] .do_sys_open+0x80/0x140 > [<c00000000012b2f0>] .SyS_creat+0x18/0x2c > [<c000000000008554>] syscall_exit+0x0/0x40 > irq event stamp: 75815 > hardirqs last enabled at (75815): [<c0000000000cb824>] > .__call_rcu+0x128/0x15c > hardirqs last disabled at (75814): [<c0000000000cb748>] > .__call_rcu+0x4c/0x15c > softirqs last enabled at (73084): [<c00000000002be8c>] > .call_do_softirq+0x14/0x24 > softirqs last disabled at (73071): [<c00000000002be8c>] > .call_do_softirq+0x14/0x24 > > other info that might help us debug this: > 2 locks held by kswapd0/334: > #0: (shrinker_rwsem){++++..}, at: [<c0000000000f57c8>] > .shrink_slab+0x5c/0x228 > #1: (&type->s_umount_key#15){++++..}, at: [<c000000000142f00>] > .shrink_dcache_memory+0xfc/0x244 > > stack backtrace: > Call Trace: > [c00000004473b440] [c000000000011a54] .show_stack+0x6c/0x16c (unreliable) > [c00000004473b4f0] [c0000000000984d8] .print_usage_bug+0x1c0/0x1f4 > [c00000004473b5b0] [c00000000009888c] .mark_lock+0x380/0x6e4 > [c00000004473b660] [c00000000009a99c] .__lock_acquire+0x7a8/0x17b4 > [c00000004473b760] [c00000000009bab0] .lock_acquire+0x108/0x154 > [c00000004473b820] [c0000000005a8bac] .mutex_lock_nested+0x88/0x460 > [c00000004473b920] [c000000000166cc0] .inotify_inode_is_dead+0x38/0xc8 > [c00000004473b9d0] [c0000000001427f4] .dentry_iput+0xa0/0x128 > [c00000004473ba60] [c0000000001429f0] .d_kill+0x5c/0xa0 > [c00000004473baf0] [c000000000142d38] .__shrink_dcache_sb+0x304/0x3d0 > [c00000004473bbd0] [c000000000142f48] .shrink_dcache_memory+0x144/0x244 > [c00000004473bcb0] [c0000000000f58c8] .shrink_slab+0x15c/0x228 > [c00000004473bd70] [c0000000000f61a4] .kswapd+0x4c0/0x678 > [c00000004473bf00] [c000000000088ba4] .kthread+0x80/0xcc > [c00000004473bf90] [c00000000002c194] .kernel_thread+0x54/0x70
On Wednesday 22 April 2009, you wrote: > Rafael J. Wysocki wrote: > > This message has been generated automatically as a part of a report > > of recent regressions. > > > > The following bug entry is on the current list of known regressions > > from 2.6.29. Please verify if it still should be listed and let me know > > (either way). > > > > > > Bug-Entry : http://bugzilla.kernel.org/show_bug.cgi?id=13068 > > Subject : Lockdep warining in inotify_dev_queue_event > > Submitter : Sachin Sant <sachinp@in.ibm.com> > > Date : 2009-04-05 12:37 (12 days old) > > References : http://marc.info/?l=linux-kernel&m=123893439229272&w=4 > I can recreate this with 2.6.30-rc3 as well. > > ================================= > [ INFO: inconsistent lock state ] > 2.6.30-rc3 #1 > --------------------------------- > inconsistent {IN-RECLAIM_FS-W} -> {RECLAIM_FS-ON-W} usage. > inotify02/31550 [HC0[0]:SC0[0]:HE1:SE1] takes: > (&inode->inotify_mutex){+.+.?.}, at: [<c0000000001668ec>] > .inotify_inode_queue_event+0x6c/0x160 > {IN-RECLAIM_FS-W} state was registered at: > [<c00000000009bb1c>] .lock_acquire+0x108/0x154 > [<c0000000005a8be4>] .mutex_lock_nested+0x88/0x460 > [<c000000000166b04>] .inotify_inode_is_dead+0x38/0xc8 > [<c000000000142708>] .dentry_iput+0xa0/0x128 > [<c000000000142904>] .d_kill+0x5c/0xa0 > [<c000000000142c4c>] .__shrink_dcache_sb+0x304/0x3d0 > [<c000000000142e5c>] .shrink_dcache_memory+0x144/0x244 > [<c0000000000f580c>] .shrink_slab+0x15c/0x228 > [<c0000000000f60f8>] .kswapd+0x4c4/0x67c > [<c000000000088ba4>] .kthread+0x80/0xcc > [<c00000000002c194>] .kernel_thread+0x54/0x70 > irq event stamp: 2267 > hardirqs last enabled at (2267): [<c000000000120490>] > .kmem_cache_alloc+0xec/0x1b4 > hardirqs last disabled at (2266): [<c000000000120418>] > .kmem_cache_alloc+0x74/0x1b4 > softirqs last enabled at (1654): [<c00000000002be8c>] > .call_do_softirq+0x14/0x24 > softirqs last disabled at (1639): [<c00000000002be8c>] > .call_do_softirq+0x14/0x24 > > other info that might help us debug this: > 4 locks held by inotify02/31550: > #0: (&type->i_mutex_dir_key#4){+.+.+.}, at: [<c00000000013d41c>] > .do_filp_open+0x1a4/0x964 > #1: (&inode->inotify_mutex){+.+.?.}, at: [<c0000000001668ec>] > .inotify_inode_queue_event+0x6c/0x160 > #2: (&ih->mutex){+.+...}, at: [<c000000000166920>] > .inotify_inode_queue_event+0xa0/0x160 > #3: (&dev->ev_mutex){+.+...}, at: [<c00000000016822c>] > .inotify_dev_queue_event+0x50/0x1cc > > stack backtrace: > Call Trace: > [c00000001816b4b0] [c000000000011a54] .show_stack+0x6c/0x16c (unreliable) > [c00000001816b560] [c000000000098544] .print_usage_bug+0x1c0/0x1f4 > [c00000001816b620] [c0000000000988f8] .mark_lock+0x380/0x6e4 > [c00000001816b6d0] [c000000000098cd0] .mark_held_locks+0x74/0xc0 > [c00000001816b770] [c000000000098de0] .lockdep_trace_alloc+0xc4/0xf4 > [c00000001816b7f0] [c000000000122090] .__kmalloc+0x100/0x274 > [c00000001816b8a0] [c000000000168140] .kernel_event+0xb8/0x154 > [c00000001816b940] [c0000000001682fc] .inotify_dev_queue_event+0x120/0x1cc > [c00000001816b9f0] [c000000000166970] .inotify_inode_queue_event+0xf0/0x160 > [c00000001816bac0] [c000000000139acc] .vfs_create+0x170/0x1dc > [c00000001816bb60] [c00000000013d4d4] .do_filp_open+0x25c/0x964 > [c00000001816bd10] [c00000000012b37c] .do_sys_open+0x80/0x140 > [c00000001816bdc0] [c00000000012b258] .SyS_creat+0x18/0x2c > [c00000001816be30] [c000000000008554] syscall_exit+0x0/0x40
On Wednesday 29 April 2009, Sachin Sant wrote: > Rafael J. Wysocki wrote: > > This message has been generated automatically as a part of a report > > of recent regressions. > > > > The following bug entry is on the current list of known regressions > > from 2.6.29. Please verify if it still should be listed and let me know > > (either way). > > > > > > Bug-Entry : http://bugzilla.kernel.org/show_bug.cgi?id=13068 > > Subject : Lockdep warining in inotify_dev_queue_event > > Submitter : Sachin Sant <sachinp@in.ibm.com> > > Date : 2009-04-05 12:37 (21 days old) > > References : http://marc.info/?l=linux-kernel&m=123893439229272&w=4 > > > > > > > I have not been able to recreate this problem with recent > kernels(rc3-git's).
On Wednesday 29 April 2009, you wrote: > Rafael J. Wysocki pisze: > > On Wednesday 29 April 2009, Sachin Sant wrote: > >> Rafael J. Wysocki wrote: > >>> This message has been generated automatically as a part of a report > >>> of recent regressions. > >>> > >>> The following bug entry is on the current list of known regressions > >>> from 2.6.29. Please verify if it still should be listed and let me know > >>> (either way). > >>> > >>> > >>> Bug-Entry : http://bugzilla.kernel.org/show_bug.cgi?id=13068 > >>> Subject : Lockdep warining in inotify_dev_queue_event > >>> Submitter : Sachin Sant <sachinp@in.ibm.com> > >>> Date : 2009-04-05 12:37 (21 days old) > >>> References : > http://marc.info/?l=linux-kernel&m=123893439229272&w=4 > >>> > >>> > >>> > >> I have not been able to recreate this problem with recent > >> kernels(rc3-git's). > > > > Thanks, I've closed the bug. > > Was it really fixed? I'm on 56a50adda49b2020156616c4eb15353e0f9ad7de and > still seeing this warning. > > [ 2771.164306] > [ 2771.164309] ================================= > [ 2771.164323] [ INFO: inconsistent lock state ] > [ 2771.164329] 2.6.30-rc3-mod-56a50adda #121 > [ 2771.164333] --------------------------------- > [ 2771.164338] inconsistent {IN-RECLAIM_FS-W} -> {RECLAIM_FS-ON-W} usage. > [ 2771.164344] emerge/14418 [HC0[0]:SC0[0]:HE1:SE1] takes: > [ 2771.164349] (&inode->inotify_mutex){+.+.?.}, at: [<ffffffff802c2d25>] > inotify_inode_queue_event+0x4f/0xe0 > [ 2771.164367] {IN-RECLAIM_FS-W} state was registered at: > [ 2771.164371] [<ffffffff80254f5f>] __lock_acquire+0x618/0x7b1 > [ 2771.164382] [<ffffffff802551e7>] lock_acquire+0xef/0x111 > [ 2771.164390] [<ffffffff805beef7>] mutex_lock_nested+0x5a/0x2da > [ 2771.164399] [<ffffffff802c2e19>] inotify_inode_is_dead+0x29/0x8f > [ 2771.164407] [<ffffffff802a9bdd>] dentry_iput+0x7c/0xbb > [ 2771.164416] [<ffffffff802a9d01>] d_kill+0x41/0x62 > [ 2771.164423] [<ffffffff802a9f2e>] __shrink_dcache_sb+0x20c/0x2af > [ 2771.164433] [<ffffffff802aa0de>] shrink_dcache_memory+0xfe/0x18e > [ 2771.164440] [<ffffffff8027db03>] shrink_slab+0xe2/0x176 > [ 2771.164448] [<ffffffff8027e2e5>] kswapd+0x35c/0x542 > [ 2771.164455] [<ffffffff80245550>] kthread+0x50/0x7c > [ 2771.164465] [<ffffffff8020bd6a>] child_rip+0xa/0x20 > [ 2771.164473] [<ffffffffffffffff>] 0xffffffffffffffff > [ 2771.164481] irq event stamp: 5964095 > [ 2771.164484] hardirqs last enabled at (5964095): [<ffffffff80296ef7>] > kmem_cache_alloc+0x9a/0x138 > [ 2771.164495] hardirqs last disabled at (5964094): [<ffffffff80296a30>] > __slab_alloc+0x349/0x5c6 > [ 2771.164504] softirqs last enabled at (5962724): [<ffffffff80236ac6>] > __do_softirq+0x1be/0x1ca > [ 2771.164514] softirqs last disabled at (5962715): [<ffffffff8020be6a>] > call_softirq+0x1a/0x24 > [ 2771.164522] > [ 2771.164523] other info that might help us debug this: > [ 2771.164529] 4 locks held by emerge/14418: > [ 2771.164533] #0: (&type->i_mutex_dir_key#2){+.+.+.}, at: > [<ffffffff802a60ce>] do_filp_open+0x183/0x7d0 > [ 2771.164550] #1: (&inode->inotify_mutex){+.+.?.}, at: > [<ffffffff802c2d25>] inotify_inode_queue_event+0x4f/0xe0 > [ 2771.164567] #2: (&ih->mutex){+.+...}, at: [<ffffffff802c2d53>] > inotify_inode_queue_event+0x7d/0xe0 > [ 2771.164582] #3: (&dev->ev_mutex){+.+...}, at: [<ffffffff802c3d7c>] > inotify_dev_queue_event+0x36/0x15b > [ 2771.164598] > [ 2771.164599] stack backtrace: > [ 2771.164606] Pid: 14418, comm: emerge Not tainted 2.6.30-rc3-mod-56a50adda > #121 > [ 2771.164611] Call Trace: > [ 2771.164617] [<ffffffff8025233e>] print_usage_bug+0x1b8/0x1c9 > [ 2771.164623] [<ffffffff80253574>] ? check_usage_backwards+0x0/0x9f > [ 2771.164629] [<ffffffff80252632>] mark_lock+0x2e3/0x546 > [ 2771.164635] [<ffffffff802528e2>] mark_held_locks+0x4d/0x6a > [ 2771.164641] [<ffffffff80252df6>] lockdep_trace_alloc+0xa6/0xbf > [ 2771.164647] [<ffffffff802c3cdc>] ? kernel_event+0xa9/0x113 > [ 2771.164653] [<ffffffff8029826a>] __kmalloc+0xc2/0x1db > [ 2771.164660] [<ffffffff802c3cdc>] kernel_event+0xa9/0x113 > [ 2771.164666] [<ffffffff802c3e26>] inotify_dev_queue_event+0xe0/0x15b > [ 2771.164673] [<ffffffff802c2d81>] inotify_inode_queue_event+0xab/0xe0 > [ 2771.164679] [<ffffffff802a3655>] vfs_create+0xf6/0x119 > [ 2771.164685] [<ffffffff802b1fca>] ? mnt_want_write+0x26/0xa4 > [ 2771.164691] [<ffffffff802a618c>] do_filp_open+0x241/0x7d0 > [ 2771.164697] [<ffffffff802aeaa6>] ? alloc_fd+0xfe/0x10d > [ 2771.164704] [<ffffffff8022c2bf>] ? sub_preempt_count+0xa0/0xbd > [ 2771.164710] [<ffffffff805c0f03>] ? _spin_unlock+0x30/0x49 > [ 2771.164716] [<ffffffff80299282>] do_sys_open+0x53/0xda > [ 2771.164722] [<ffffffff80299332>] sys_open+0x1b/0x1d > [ 2771.164728] [<ffffffff8020ae68>] system_call_fastpath+0x16/0x1b
Notify-Also : Marcin Slusarz <marcin.slusarz@gmail.com>
On Wednesday 06 May 2009, Németh Márton wrote: > Hi, > > I get this error recently while I was compiling kernel on ext3 fs. The kernel > was running on a Clevo D410J laptop. > > I don't know whether this is reproducible or not, but maybe this info is > enough > for somebody. I can send the full dmesg/.config or anything which is needed. > > [ 1771.878353] > [ 1771.878358] ================================= > [ 1771.878364] [ INFO: inconsistent lock state ] > [ 1771.878369] 2.6.30-rc4 #1 > [ 1771.878372] --------------------------------- > [ 1771.878376] inconsistent {RECLAIM_FS-ON-W} -> {IN-RECLAIM_FS-W} usage. > [ 1771.878381] kswapd0/183 [HC0[0]:SC0[0]:HE1:SE1] takes: > [ 1771.878385] (&inode->inotify_mutex){+.+.?.}, at: [<c01cc03b>] > inotify_inode_is_dead+0x1b/0x80 > [ 1771.878399] {RECLAIM_FS-ON-W} state was registered at: > [ 1771.878402] [<c014b7d2>] mark_held_locks+0x62/0x80 > [ 1771.878410] [<c014b8b5>] lockdep_trace_alloc+0xc5/0xd0 > [ 1771.878415] [<c019caf0>] __kmalloc+0x70/0x230 > [ 1771.878422] [<c01ccfa7>] kernel_event+0x87/0x130 > [ 1771.878427] [<c01cd0cf>] inotify_dev_queue_event+0x7f/0x180 > [ 1771.878432] [<c01cbf53>] inotify_inode_queue_event+0xa3/0xe0 > [ 1771.878437] [<c01a900a>] vfs_create+0xba/0x100 > [ 1771.878443] [<c01ac14d>] do_filp_open+0x6dd/0x810 > [ 1771.878449] [<c019e339>] do_sys_open+0x59/0xf0 > [ 1771.878454] [<c019e439>] sys_open+0x29/0x40 > [ 1771.878459] [<c0102e84>] sysenter_do_call+0x12/0x32 > [ 1771.878465] [<ffffffff>] 0xffffffff > [ 1771.878490] irq event stamp: 315803 > [ 1771.878493] hardirqs last enabled at (315803): [<c016ae34>] > call_rcu+0xb4/0xe0 > [ 1771.878501] hardirqs last disabled at (315802): [<c016ad9e>] > call_rcu+0x1e/0xe0 > [ 1771.878508] softirqs last enabled at (315442): [<c012b80f>] > __do_softirq+0x15f/0x1e0 > [ 1771.878516] softirqs last disabled at (315435): [<c012b8ed>] > do_softirq+0x5d/0x70 > [ 1771.878522] > [ 1771.878523] other info that might help us debug this: > [ 1771.878527] 2 locks held by kswapd0/183: > [ 1771.878530] #0: (shrinker_rwsem){++++..}, at: [<c0182bf4>] > shrink_slab+0x24/0x1a0 > [ 1771.878540] #1: (&type->s_umount_key#16){++++..}, at: [<c01b0553>] > shrink_dcache_memory+0x103/0x1b0 > [ 1771.878551] > [ 1771.878552] stack backtrace: > [ 1771.878556] Pid: 183, comm: kswapd0 Not tainted 2.6.30-rc4 #1 > [ 1771.878559] Call Trace: > [ 1771.878566] [<c0364305>] ? printk+0x18/0x1b > [ 1771.878570] [<c014b0c7>] print_usage_bug+0x167/0x1c0 > [ 1771.878576] [<c014b570>] mark_lock+0x450/0x650 > [ 1771.878580] [<c014bef0>] ? check_usage_forwards+0x0/0xb0 > [ 1771.878586] [<c014cc5a>] __lock_acquire+0x3ca/0x18a0 > [ 1771.878591] [<c014c9dc>] ? __lock_acquire+0x14c/0x18a0 > [ 1771.878596] [<c01cc03b>] ? inotify_inode_is_dead+0x1b/0x80 > [ 1771.878601] [<c014e1ff>] lock_acquire+0xcf/0xf0 > [ 1771.878606] [<c01cc03b>] ? inotify_inode_is_dead+0x1b/0x80 > [ 1771.878611] [<c01cc03b>] ? inotify_inode_is_dead+0x1b/0x80 > [ 1771.878616] [<c0365968>] mutex_lock_nested+0x58/0x350 > [ 1771.878621] [<c01cc03b>] ? inotify_inode_is_dead+0x1b/0x80 > [ 1771.878626] [<c01cc03b>] inotify_inode_is_dead+0x1b/0x80 > [ 1771.878632] [<c01b003c>] dentry_iput+0x9c/0xc0 > [ 1771.878637] [<c01b0146>] d_kill+0x36/0x60 > [ 1771.878643] [<c01b0385>] __shrink_dcache_sb+0x215/0x2e0 > [ 1771.878649] [<c01b0585>] shrink_dcache_memory+0x135/0x1b0 > [ 1771.878654] [<c0182cd5>] shrink_slab+0x105/0x1a0 > [ 1771.878660] [<c0183213>] kswapd+0x4a3/0x5d0 > [ 1771.878666] [<c0180c20>] ? isolate_pages_global+0x0/0x200 > [ 1771.878672] [<c013b6c0>] ? autoremove_wake_function+0x0/0x50 > [ 1771.878678] [<c0182d70>] ? kswapd+0x0/0x5d0 > [ 1771.878683] [<c013b373>] kthread+0x43/0x80 > [ 1771.878687] [<c013b330>] ? kthread+0x0/0x80 > [ 1771.878692] [<c010372b>] kernel_thread_helper+0x7/0x1c > > Maybe related to http://bugzilla.kernel.org/show_bug.cgi?id=13068 ?
On Sunday 17 May 2009, Sachin Sant wrote: > Ingo Molnar wrote: > > i think this might be fixed by: > > > > 381a80e: inotify: use GFP_NOFS in kernel_event() to work around a lockdep > false-positive > > > > already in -rc6. > > > Haven't seen this issue with rc6.