* ext4 lockdep trace (3.1.0rc3)
@ 2011-08-26 21:49 Dave Jones
2011-08-29 20:47 ` Christian Kujau
2011-08-29 20:48 ` Dave Jones
0 siblings, 2 replies; 6+ messages in thread
From: Dave Jones @ 2011-08-26 21:49 UTC (permalink / raw)
To: Linux Kernel
just hit this while building a kernel. Laptop wedged for a few seconds
during the final link, and this was in the log when it unwedged.
Dave
=================================
[ INFO: inconsistent lock state ]
3.1.0-rc3+ #148
---------------------------------
inconsistent {RECLAIM_FS-ON-W} -> {IN-RECLAIM_FS-W} usage.
kswapd0/32 [HC0[0]:SC0[0]:HE1:SE1] takes:
(&sb->s_type->i_mutex_key#14){+.+.?.}, at: [<ffffffff811cea13>] ext4_evict_inode+0x76/0x33c
{RECLAIM_FS-ON-W} state was registered at:
[<ffffffff810913fe>] mark_held_locks+0x6d/0x95
[<ffffffff81091a19>] lockdep_trace_alloc+0x9f/0xc2
[<ffffffff811333b0>] slab_pre_alloc_hook+0x1e/0x4f
[<ffffffff81136d89>] kmem_cache_alloc+0x29/0x15a
[<ffffffff8115aa00>] __d_alloc+0x26/0x168
[<ffffffff8115ad5c>] d_alloc+0x1f/0x62
[<ffffffff81150de6>] d_alloc_and_lookup+0x2c/0x6b
[<ffffffff81151c2d>] walk_component+0x215/0x3e8
[<ffffffff811524b8>] link_path_walk+0x189/0x43b
[<ffffffff81152b12>] path_lookupat+0x5a/0x2af
[<ffffffff81152d8f>] do_path_lookup+0x28/0x97
[<ffffffff81152f73>] user_path_at+0x59/0x96
[<ffffffff8114b8e6>] vfs_fstatat+0x44/0x6e
[<ffffffff8114b94b>] vfs_stat+0x1b/0x1d
[<ffffffff8114ba4a>] sys_newstat+0x1a/0x33
[<ffffffff814f1e42>] system_call_fastpath+0x16/0x1b
irq event stamp: 671039
hardirqs last enabled at (671039): [<ffffffff810c8130>] __call_rcu+0x18c/0x19d
hardirqs last disabled at (671038): [<ffffffff810c8026>] __call_rcu+0x82/0x19d
softirqs last enabled at (670754): [<ffffffff8106481f>] __do_softirq+0x1fd/0x257
softirqs last disabled at (670749): [<ffffffff814f413c>] call_softirq+0x1c/0x30
other info that might help us debug this:
Possible unsafe locking scenario:
CPU0
----
lock(&sb->s_type->i_mutex_key);
<Interrupt>
lock(&sb->s_type->i_mutex_key);
*** DEADLOCK ***
2 locks held by kswapd0/32:
#0: (shrinker_rwsem){++++..}, at: [<ffffffff8110626b>] shrink_slab+0x39/0x2ef
#1: (&type->s_umount_key#21){++++..}, at: [<ffffffff8114a251>] grab_super_passive+0x57/0x7b
stack backtrace:
Pid: 32, comm: kswapd0 Tainted: G W 3.1.0-rc3+ #148
Call Trace:
[<ffffffff810810a1>] ? up+0x39/0x3e
[<ffffffff814e1151>] print_usage_bug+0x1e7/0x1f8
[<ffffffff8101bb8d>] ? save_stack_trace+0x2c/0x49
[<ffffffff8108f6ca>] ? print_irq_inversion_bug.part.19+0x1a0/0x1a0
[<ffffffff8108fdf8>] mark_lock+0x106/0x220
[<ffffffff810902a6>] __lock_acquire+0x394/0xcf7
[<ffffffff8101bb8d>] ? save_stack_trace+0x2c/0x49
[<ffffffff8108d0b0>] ? __bfs+0x137/0x1c7
[<ffffffff811cea13>] ? ext4_evict_inode+0x76/0x33c
[<ffffffff810910ff>] lock_acquire+0xf3/0x13e
[<ffffffff811cea13>] ? ext4_evict_inode+0x76/0x33c
[<ffffffff814e9ed5>] ? __mutex_lock_common+0x3d/0x44a
[<ffffffff814ea3dd>] ? mutex_lock_nested+0x3b/0x40
[<ffffffff811cea13>] ? ext4_evict_inode+0x76/0x33c
[<ffffffff814e9efd>] __mutex_lock_common+0x65/0x44a
[<ffffffff811cea13>] ? ext4_evict_inode+0x76/0x33c
[<ffffffff810820bf>] ? local_clock+0x35/0x4c
[<ffffffff8115ce19>] ? evict+0x8b/0x153
[<ffffffff8108d88a>] ? put_lock_stats+0xe/0x29
[<ffffffff8108df0e>] ? lock_release_holdtime.part.10+0x59/0x62
[<ffffffff8115ce19>] ? evict+0x8b/0x153
[<ffffffff814ea3dd>] mutex_lock_nested+0x3b/0x40
[<ffffffff811cea13>] ext4_evict_inode+0x76/0x33c
[<ffffffff8115ce27>] evict+0x99/0x153
[<ffffffff8115d0ad>] dispose_list+0x32/0x43
[<ffffffff8115dd43>] prune_icache_sb+0x257/0x266
[<ffffffff8114a34f>] prune_super+0xda/0x145
[<ffffffff811063d0>] shrink_slab+0x19e/0x2ef
[<ffffffff811093fe>] balance_pgdat+0x2e7/0x57e
[<ffffffff811099ce>] kswapd+0x339/0x392
[<ffffffff8107c56c>] ? __init_waitqueue_head+0x4b/0x4b
[<ffffffff81109695>] ? balance_pgdat+0x57e/0x57e
[<ffffffff8107bcf1>] kthread+0xa8/0xb0
[<ffffffff814eed1e>] ? sub_preempt_count+0xa1/0xb4
[<ffffffff814f4044>] kernel_thread_helper+0x4/0x10
[<ffffffff814ec1b8>] ? retint_restore_args+0x13/0x13
[<ffffffff8107bc49>] ? __init_kthread_worker+0x5a/0x5a
[<ffffffff814f4040>] ? gs_change+0x13/0x13
^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: ext4 lockdep trace (3.1.0rc3)
2011-08-26 21:49 ext4 lockdep trace (3.1.0rc3) Dave Jones
@ 2011-08-29 20:47 ` Christian Kujau
2011-08-29 20:48 ` Dave Jones
1 sibling, 0 replies; 6+ messages in thread
From: Christian Kujau @ 2011-08-29 20:47 UTC (permalink / raw)
To: Dave Jones; +Cc: Linux Kernel, linux-ext4
On Fri, 26 Aug 2011 at 17:49, Dave Jones wrote:
> just hit this while building a kernel. Laptop wedged for a few seconds
> during the final link, and this was in the log when it unwedged.
Though I did not notice the "wedged" phase (wasn't around all the time
when this powerpc laptop was doing lots of disk i/o), this happened here
too with -rc4:
http://nerdbynature.de/bits/3.1-rc4/lockdep/
Thanks,
Christian.
[ 846.243801] =================================
[ 846.246812] [ INFO: inconsistent lock state ]
[ 846.248299] 3.1.0-rc4-dirty #1
[ 846.249753] ---------------------------------
[ 846.251196] inconsistent {RECLAIM_FS-ON-W} -> {IN-RECLAIM_FS-W} usage.
[ 846.252656] kswapd0/17 [HC0[0]:SC0[0]:HE1:SE1] takes:
[ 846.254096] (&sb->s_type->i_mutex_key#4){+.+.?.}, at: [<c013854c>] ext4_evict_inode+0x2c/0x3e8
[ 846.255624] {RECLAIM_FS-ON-W} state was registered at:
[ 846.257094] [<c0069dd0>] lockdep_trace_alloc+0xac/0xe4
[ 846.258589] [<c00bed40>] kmem_cache_alloc+0x44/0x134
[ 846.260088] [<c00dcdac>] __d_alloc+0x3c/0x16c
[ 846.261570] [<c00dcf94>] d_alloc+0x24/0x8c
[ 846.263045] [<c00cf7dc>] d_alloc_and_lookup+0x30/0x90
[ 846.264533] [<c00cfdec>] do_lookup+0x2c4/0x398
[ 846.266010] [<c00d1b24>] path_lookupat+0x19c/0x818
[ 846.267493] [<c00d21d4>] do_path_lookup+0x34/0xac
[ 846.268944] [<c00d2454>] kern_path+0x2c/0x58
[ 846.270365] [<c00e6038>] do_mount+0xfc/0x7a0
[ 846.271766] [<c00e677c>] sys_mount+0xa0/0xf8
[ 846.273154] [<c02b9f84>] devtmpfs_mount+0x50/0xc0
[ 846.274496] [<c0515f20>] prepare_namespace+0x170/0x1ac
[ 846.275796] [<c0515234>] kernel_init+0x114/0x134
[ 846.277075] [<c000f850>] kernel_thread+0x4c/0x68
[ 846.278339] irq event stamp: 1233731
[ 846.279554] hardirqs last enabled at (1233731): [<c0090330>] free_hot_cold_page+0x12c/0x254
[ 846.280821] hardirqs last disabled at (1233730): [<c0090294>] free_hot_cold_page+0x90/0x254
[ 846.282083] softirqs last enabled at (1233144): [<c000f34c>] call_do_softirq+0x14/0x24
[ 846.283330] softirqs last disabled at (1233129): [<c000f34c>] call_do_softirq+0x14/0x24
[ 846.284535]
[ 846.284537] other info that might help us debug this:
[ 846.286914] Possible unsafe locking scenario:
[ 846.286917]
[ 846.289328] CPU0
[ 846.290526] ----
[ 846.291715] lock(&sb->s_type->i_mutex_key);
[ 846.292928] <Interrupt>
[ 846.294082] lock(&sb->s_type->i_mutex_key);
[ 846.295248]
[ 846.295250] *** DEADLOCK ***
[ 846.295253]
[ 846.298561] 2 locks held by kswapd0/17:
[ 846.299655] #0: (shrinker_rwsem){++++..}, at: [<c0099350>] shrink_slab+0x78/0x2b0
[ 846.300820] #1: (&type->s_umount_key#26){+++++.}, at: [<c00c6a58>] grab_super_passive+0x5c/0xdc
[ 846.302019]
[ 846.302021] stack backtrace:
[ 846.304264] Call Trace:
[ 846.305388] [ef8fdbf0] [c0009360] show_stack+0x70/0x1bc (unreliable)
[ 846.306541] [ef8fdc30] [c00694a0] print_usage_bug+0x224/0x2b8
[ 846.307678] [ef8fdc60] [c0069a88] mark_lock+0x554/0x678
[ 846.308800] [ef8fdc90] [c006bfec] __lock_acquire+0x72c/0x18a0
[ 846.309907] [ef8fdd40] [c006d700] lock_acquire+0x50/0x70
[ 846.311017] [ef8fdd60] [c03fe700] mutex_lock_nested+0x68/0x2bc
[ 846.312131] [ef8fddb0] [c013854c] ext4_evict_inode+0x2c/0x3e8
[ 846.313250] [ef8fddd0] [c00e0038] evict+0xc0/0x1a8
[ 846.314369] [ef8fddf0] [c00e06fc] dispose_list+0x44/0x64
[ 846.315492] [ef8fde00] [c00e0874] prune_icache_sb+0x158/0x330
[ 846.316614] [ef8fde40] [c00c6c20] prune_super+0x148/0x1ac
[ 846.317738] [ef8fde60] [c00994b4] shrink_slab+0x1dc/0x2b0
[ 846.318865] [ef8fdec0] [c009a12c] kswapd+0x578/0x8e0
[ 846.319998] [ef8fdf90] [c0052d2c] kthread+0x84/0x88
--
BOFH excuse #15:
temporary routing anomaly
^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: ext4 lockdep trace (3.1.0rc3)
2011-08-26 21:49 ext4 lockdep trace (3.1.0rc3) Dave Jones
2011-08-29 20:47 ` Christian Kujau
@ 2011-08-29 20:48 ` Dave Jones
2011-08-29 20:54 ` Dave Jones
1 sibling, 1 reply; 6+ messages in thread
From: Dave Jones @ 2011-08-29 20:48 UTC (permalink / raw)
To: Linux Kernel; +Cc: tytso, adilger.kernel
On Fri, Aug 26, 2011 at 05:49:30PM -0400, Dave Jones wrote:
> just hit this while building a kernel. Laptop wedged for a few seconds
> during the final link, and this was in the log when it unwedged.
I still see this in rc4, and can reproduce it reliably every time I build.
It only started happening in the last week. I don't see any ext4 or vfs commits
within a few days of that, so I'm not sure why it only just begun
(I do daily builds, and the 26th was the first time I saw it appear)
Given the lack of obvious commits in that timeframe, I'm not sure a bisect is
going to be particularly fruitful. It might just be that my IO patterns changed ?
(I did do some ccache changes around then).
Dave
> =================================
> [ INFO: inconsistent lock state ]
> 3.1.0-rc3+ #148
> ---------------------------------
> inconsistent {RECLAIM_FS-ON-W} -> {IN-RECLAIM_FS-W} usage.
> kswapd0/32 [HC0[0]:SC0[0]:HE1:SE1] takes:
> (&sb->s_type->i_mutex_key#14){+.+.?.}, at: [<ffffffff811cea13>] ext4_evict_inode+0x76/0x33c
> {RECLAIM_FS-ON-W} state was registered at:
> [<ffffffff810913fe>] mark_held_locks+0x6d/0x95
> [<ffffffff81091a19>] lockdep_trace_alloc+0x9f/0xc2
> [<ffffffff811333b0>] slab_pre_alloc_hook+0x1e/0x4f
> [<ffffffff81136d89>] kmem_cache_alloc+0x29/0x15a
> [<ffffffff8115aa00>] __d_alloc+0x26/0x168
> [<ffffffff8115ad5c>] d_alloc+0x1f/0x62
> [<ffffffff81150de6>] d_alloc_and_lookup+0x2c/0x6b
> [<ffffffff81151c2d>] walk_component+0x215/0x3e8
> [<ffffffff811524b8>] link_path_walk+0x189/0x43b
> [<ffffffff81152b12>] path_lookupat+0x5a/0x2af
> [<ffffffff81152d8f>] do_path_lookup+0x28/0x97
> [<ffffffff81152f73>] user_path_at+0x59/0x96
> [<ffffffff8114b8e6>] vfs_fstatat+0x44/0x6e
> [<ffffffff8114b94b>] vfs_stat+0x1b/0x1d
> [<ffffffff8114ba4a>] sys_newstat+0x1a/0x33
> [<ffffffff814f1e42>] system_call_fastpath+0x16/0x1b
> irq event stamp: 671039
> hardirqs last enabled at (671039): [<ffffffff810c8130>] __call_rcu+0x18c/0x19d
> hardirqs last disabled at (671038): [<ffffffff810c8026>] __call_rcu+0x82/0x19d
> softirqs last enabled at (670754): [<ffffffff8106481f>] __do_softirq+0x1fd/0x257
> softirqs last disabled at (670749): [<ffffffff814f413c>] call_softirq+0x1c/0x30
>
> other info that might help us debug this:
> Possible unsafe locking scenario:
>
> CPU0
> ----
> lock(&sb->s_type->i_mutex_key);
> <Interrupt>
> lock(&sb->s_type->i_mutex_key);
>
> *** DEADLOCK ***
>
> 2 locks held by kswapd0/32:
> #0: (shrinker_rwsem){++++..}, at: [<ffffffff8110626b>] shrink_slab+0x39/0x2ef
> #1: (&type->s_umount_key#21){++++..}, at: [<ffffffff8114a251>] grab_super_passive+0x57/0x7b
>
> stack backtrace:
> Pid: 32, comm: kswapd0 Tainted: G W 3.1.0-rc3+ #148
> Call Trace:
> [<ffffffff810810a1>] ? up+0x39/0x3e
> [<ffffffff814e1151>] print_usage_bug+0x1e7/0x1f8
> [<ffffffff8101bb8d>] ? save_stack_trace+0x2c/0x49
> [<ffffffff8108f6ca>] ? print_irq_inversion_bug.part.19+0x1a0/0x1a0
> [<ffffffff8108fdf8>] mark_lock+0x106/0x220
> [<ffffffff810902a6>] __lock_acquire+0x394/0xcf7
> [<ffffffff8101bb8d>] ? save_stack_trace+0x2c/0x49
> [<ffffffff8108d0b0>] ? __bfs+0x137/0x1c7
> [<ffffffff811cea13>] ? ext4_evict_inode+0x76/0x33c
> [<ffffffff810910ff>] lock_acquire+0xf3/0x13e
> [<ffffffff811cea13>] ? ext4_evict_inode+0x76/0x33c
> [<ffffffff814e9ed5>] ? __mutex_lock_common+0x3d/0x44a
> [<ffffffff814ea3dd>] ? mutex_lock_nested+0x3b/0x40
> [<ffffffff811cea13>] ? ext4_evict_inode+0x76/0x33c
> [<ffffffff814e9efd>] __mutex_lock_common+0x65/0x44a
> [<ffffffff811cea13>] ? ext4_evict_inode+0x76/0x33c
> [<ffffffff810820bf>] ? local_clock+0x35/0x4c
> [<ffffffff8115ce19>] ? evict+0x8b/0x153
> [<ffffffff8108d88a>] ? put_lock_stats+0xe/0x29
> [<ffffffff8108df0e>] ? lock_release_holdtime.part.10+0x59/0x62
> [<ffffffff8115ce19>] ? evict+0x8b/0x153
> [<ffffffff814ea3dd>] mutex_lock_nested+0x3b/0x40
> [<ffffffff811cea13>] ext4_evict_inode+0x76/0x33c
> [<ffffffff8115ce27>] evict+0x99/0x153
> [<ffffffff8115d0ad>] dispose_list+0x32/0x43
> [<ffffffff8115dd43>] prune_icache_sb+0x257/0x266
> [<ffffffff8114a34f>] prune_super+0xda/0x145
> [<ffffffff811063d0>] shrink_slab+0x19e/0x2ef
> [<ffffffff811093fe>] balance_pgdat+0x2e7/0x57e
> [<ffffffff811099ce>] kswapd+0x339/0x392
> [<ffffffff8107c56c>] ? __init_waitqueue_head+0x4b/0x4b
> [<ffffffff81109695>] ? balance_pgdat+0x57e/0x57e
> [<ffffffff8107bcf1>] kthread+0xa8/0xb0
> [<ffffffff814eed1e>] ? sub_preempt_count+0xa1/0xb4
> [<ffffffff814f4044>] kernel_thread_helper+0x4/0x10
> [<ffffffff814ec1b8>] ? retint_restore_args+0x13/0x13
> [<ffffffff8107bc49>] ? __init_kthread_worker+0x5a/0x5a
> [<ffffffff814f4040>] ? gs_change+0x13/0x13
>
> --
> To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at http://vger.kernel.org/majordomo-info.html
> Please read the FAQ at http://www.tux.org/lkml/
---end quoted text---
^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: ext4 lockdep trace (3.1.0rc3)
2011-08-29 20:48 ` Dave Jones
@ 2011-08-29 20:54 ` Dave Jones
2011-08-30 10:23 ` Tao Ma
2011-08-30 12:30 ` Josh Boyer
0 siblings, 2 replies; 6+ messages in thread
From: Dave Jones @ 2011-08-29 20:54 UTC (permalink / raw)
To: Linux Kernel, tytso, adilger.kernel
On Mon, Aug 29, 2011 at 04:48:30PM -0400, Dave Jones wrote:
> On Fri, Aug 26, 2011 at 05:49:30PM -0400, Dave Jones wrote:
> > just hit this while building a kernel. Laptop wedged for a few seconds
> > during the final link, and this was in the log when it unwedged.
>
> I still see this in rc4, and can reproduce it reliably every time I build.
> It only started happening in the last week. I don't see any ext4 or vfs commits
> within a few days of that, so I'm not sure why it only just begun
> (I do daily builds, and the 26th was the first time I saw it appear)
>
> Given the lack of obvious commits in that timeframe, I'm not sure a bisect is
> going to be particularly fruitful. It might just be that my IO patterns changed ?
also a second variant with a different trace.
Dave
=======================================================
[ INFO: possible circular locking dependency detected ]
3.1.0-rc3+ #151
-------------------------------------------------------
gnome-settings-/2037 is trying to acquire lock:
(&sb->s_type->i_mutex_key#14){+.+.+.}, at: [<ffffffff811cee83>] ext4_evict_inode+0x76/0x33c
but task is already holding lock:
(&mm->mmap_sem){++++++}, at: [<ffffffff8111ba13>] sys_munmap+0x3b/0x60
which lock already depends on the new lock.
the existing dependency chain (in reverse order) is:
-> #1 (&mm->mmap_sem){++++++}:
[<ffffffff81091251>] lock_acquire+0xf3/0x13e
[<ffffffff8111499a>] might_fault+0x80/0xa3
[<ffffffff811570ef>] filldir+0x6f/0xc7
[<ffffffff811c5c3f>] call_filldir+0x96/0xc0
[<ffffffff811c5f78>] ext4_readdir+0x1bd/0x548
[<ffffffff81157344>] vfs_readdir+0x7b/0xb4
[<ffffffff81157463>] sys_getdents+0x7e/0xd1
[<ffffffff814f2342>] system_call_fastpath+0x16/0x1b
-> #0 (&sb->s_type->i_mutex_key#14){+.+.+.}:
[<ffffffff81090a71>] __lock_acquire+0xa2f/0xd0c
[<ffffffff81091251>] lock_acquire+0xf3/0x13e
[<ffffffff814ea40d>] __mutex_lock_common+0x65/0x44a
[<ffffffff814ea8ed>] mutex_lock_nested+0x3b/0x40
[<ffffffff811cee83>] ext4_evict_inode+0x76/0x33c
[<ffffffff8115d2a5>] evict+0x98/0x152
[<ffffffff8115d4f0>] iput+0x191/0x199
[<ffffffff8115a0f2>] dentry_kill+0x123/0x145
[<ffffffff8115a4fc>] dput+0xf2/0x102
[<ffffffff8114948a>] fput+0x1d8/0x1f0
[<ffffffff8111a6bd>] remove_vma+0x51/0x82
[<ffffffff8111b8a0>] do_munmap+0x2f2/0x30b
[<ffffffff8111ba21>] sys_munmap+0x49/0x60
[<ffffffff814f2342>] system_call_fastpath+0x16/0x1b
other info that might help us debug this:
Possible unsafe locking scenario:
CPU0 CPU1
---- ----
lock(&mm->mmap_sem);
lock(&sb->s_type->i_mutex_key);
lock(&mm->mmap_sem);
lock(&sb->s_type->i_mutex_key);
*** DEADLOCK ***
1 lock held by gnome-settings-/2037:
#0: (&mm->mmap_sem){++++++}, at: [<ffffffff8111ba13>] sys_munmap+0x3b/0x60
stack backtrace:
Pid: 2037, comm: gnome-settings- Not tainted 3.1.0-rc3+ #151
Call Trace:
[<ffffffff810811d1>] ? up+0x39/0x3e
[<ffffffff814e1469>] print_circular_bug+0x1f8/0x209
[<ffffffff81090a71>] __lock_acquire+0xa2f/0xd0c
[<ffffffff810821ef>] ? local_clock+0x35/0x4c
[<ffffffff8108fe4f>] ? mark_lock+0x2d/0x220
[<ffffffff811cee83>] ? ext4_evict_inode+0x76/0x33c
[<ffffffff81091251>] lock_acquire+0xf3/0x13e
[<ffffffff811cee83>] ? ext4_evict_inode+0x76/0x33c
[<ffffffff814ea3e5>] ? __mutex_lock_common+0x3d/0x44a
[<ffffffff814ea8ed>] ? mutex_lock_nested+0x3b/0x40
[<ffffffff811cee83>] ? ext4_evict_inode+0x76/0x33c
[<ffffffff814ea40d>] __mutex_lock_common+0x65/0x44a
[<ffffffff811cee83>] ? ext4_evict_inode+0x76/0x33c
[<ffffffff810821ef>] ? local_clock+0x35/0x4c
[<ffffffff8115d297>] ? evict+0x8a/0x152
[<ffffffff8108d9ba>] ? put_lock_stats+0xe/0x29
[<ffffffff8108e03e>] ? lock_release_holdtime.part.10+0x59/0x62
[<ffffffff8115d297>] ? evict+0x8a/0x152
[<ffffffff814ea8ed>] mutex_lock_nested+0x3b/0x40
[<ffffffff811cee83>] ext4_evict_inode+0x76/0x33c
[<ffffffff8115d2a5>] evict+0x98/0x152
[<ffffffff8115d4f0>] iput+0x191/0x199
[<ffffffff8115a0f2>] dentry_kill+0x123/0x145
[<ffffffff8115a4fc>] dput+0xf2/0x102
[<ffffffff8114948a>] fput+0x1d8/0x1f0
[<ffffffff8111a6bd>] remove_vma+0x51/0x82
[<ffffffff8111b8a0>] do_munmap+0x2f2/0x30b
[<ffffffff8111ba21>] sys_munmap+0x49/0x60
[<ffffffff814f2342>] system_call_fastpath+0x16/0x1b
^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: ext4 lockdep trace (3.1.0rc3)
2011-08-29 20:54 ` Dave Jones
@ 2011-08-30 10:23 ` Tao Ma
2011-08-30 12:30 ` Josh Boyer
1 sibling, 0 replies; 6+ messages in thread
From: Tao Ma @ 2011-08-30 10:23 UTC (permalink / raw)
To: Dave Jones, Linux Kernel, tytso, adilger.kernel
Hi Dave,
On 08/30/2011 04:54 AM, Dave Jones wrote:
> On Mon, Aug 29, 2011 at 04:48:30PM -0400, Dave Jones wrote:
> > On Fri, Aug 26, 2011 at 05:49:30PM -0400, Dave Jones wrote:
> > > just hit this while building a kernel. Laptop wedged for a few seconds
> > > during the final link, and this was in the log when it unwedged.
> >
> > I still see this in rc4, and can reproduce it reliably every time I build.
> > It only started happening in the last week. I don't see any ext4 or vfs commits
> > within a few days of that, so I'm not sure why it only just begun
> > (I do daily builds, and the 26th was the first time I saw it appear)
> >
> > Given the lack of obvious commits in that timeframe, I'm not sure a bisect is
> > going to be particularly fruitful. It might just be that my IO patterns changed ?
>
> also a second variant with a different trace.
Ted has sent out a fix in the ext4 mailist. Please search for the subject:
[URGENT PATCH] ext4: fix potential deadlock in ext4_evict_inode()
Thanks
Tao
>
> Dave
>
>
> =======================================================
> [ INFO: possible circular locking dependency detected ]
> 3.1.0-rc3+ #151
> -------------------------------------------------------
> gnome-settings-/2037 is trying to acquire lock:
> (&sb->s_type->i_mutex_key#14){+.+.+.}, at: [<ffffffff811cee83>] ext4_evict_inode+0x76/0x33c
>
> but task is already holding lock:
> (&mm->mmap_sem){++++++}, at: [<ffffffff8111ba13>] sys_munmap+0x3b/0x60
>
> which lock already depends on the new lock.
>
>
> the existing dependency chain (in reverse order) is:
>
> -> #1 (&mm->mmap_sem){++++++}:
> [<ffffffff81091251>] lock_acquire+0xf3/0x13e
> [<ffffffff8111499a>] might_fault+0x80/0xa3
> [<ffffffff811570ef>] filldir+0x6f/0xc7
> [<ffffffff811c5c3f>] call_filldir+0x96/0xc0
> [<ffffffff811c5f78>] ext4_readdir+0x1bd/0x548
> [<ffffffff81157344>] vfs_readdir+0x7b/0xb4
> [<ffffffff81157463>] sys_getdents+0x7e/0xd1
> [<ffffffff814f2342>] system_call_fastpath+0x16/0x1b
>
> -> #0 (&sb->s_type->i_mutex_key#14){+.+.+.}:
> [<ffffffff81090a71>] __lock_acquire+0xa2f/0xd0c
> [<ffffffff81091251>] lock_acquire+0xf3/0x13e
> [<ffffffff814ea40d>] __mutex_lock_common+0x65/0x44a
> [<ffffffff814ea8ed>] mutex_lock_nested+0x3b/0x40
> [<ffffffff811cee83>] ext4_evict_inode+0x76/0x33c
> [<ffffffff8115d2a5>] evict+0x98/0x152
> [<ffffffff8115d4f0>] iput+0x191/0x199
> [<ffffffff8115a0f2>] dentry_kill+0x123/0x145
> [<ffffffff8115a4fc>] dput+0xf2/0x102
> [<ffffffff8114948a>] fput+0x1d8/0x1f0
> [<ffffffff8111a6bd>] remove_vma+0x51/0x82
> [<ffffffff8111b8a0>] do_munmap+0x2f2/0x30b
> [<ffffffff8111ba21>] sys_munmap+0x49/0x60
> [<ffffffff814f2342>] system_call_fastpath+0x16/0x1b
>
> other info that might help us debug this:
>
> Possible unsafe locking scenario:
>
> CPU0 CPU1
> ---- ----
> lock(&mm->mmap_sem);
> lock(&sb->s_type->i_mutex_key);
> lock(&mm->mmap_sem);
> lock(&sb->s_type->i_mutex_key);
>
> *** DEADLOCK ***
>
> 1 lock held by gnome-settings-/2037:
> #0: (&mm->mmap_sem){++++++}, at: [<ffffffff8111ba13>] sys_munmap+0x3b/0x60
>
> stack backtrace:
> Pid: 2037, comm: gnome-settings- Not tainted 3.1.0-rc3+ #151
> Call Trace:
> [<ffffffff810811d1>] ? up+0x39/0x3e
> [<ffffffff814e1469>] print_circular_bug+0x1f8/0x209
> [<ffffffff81090a71>] __lock_acquire+0xa2f/0xd0c
> [<ffffffff810821ef>] ? local_clock+0x35/0x4c
> [<ffffffff8108fe4f>] ? mark_lock+0x2d/0x220
> [<ffffffff811cee83>] ? ext4_evict_inode+0x76/0x33c
> [<ffffffff81091251>] lock_acquire+0xf3/0x13e
> [<ffffffff811cee83>] ? ext4_evict_inode+0x76/0x33c
> [<ffffffff814ea3e5>] ? __mutex_lock_common+0x3d/0x44a
> [<ffffffff814ea8ed>] ? mutex_lock_nested+0x3b/0x40
> [<ffffffff811cee83>] ? ext4_evict_inode+0x76/0x33c
> [<ffffffff814ea40d>] __mutex_lock_common+0x65/0x44a
> [<ffffffff811cee83>] ? ext4_evict_inode+0x76/0x33c
> [<ffffffff810821ef>] ? local_clock+0x35/0x4c
> [<ffffffff8115d297>] ? evict+0x8a/0x152
> [<ffffffff8108d9ba>] ? put_lock_stats+0xe/0x29
> [<ffffffff8108e03e>] ? lock_release_holdtime.part.10+0x59/0x62
> [<ffffffff8115d297>] ? evict+0x8a/0x152
> [<ffffffff814ea8ed>] mutex_lock_nested+0x3b/0x40
> [<ffffffff811cee83>] ext4_evict_inode+0x76/0x33c
> [<ffffffff8115d2a5>] evict+0x98/0x152
> [<ffffffff8115d4f0>] iput+0x191/0x199
> [<ffffffff8115a0f2>] dentry_kill+0x123/0x145
> [<ffffffff8115a4fc>] dput+0xf2/0x102
> [<ffffffff8114948a>] fput+0x1d8/0x1f0
> [<ffffffff8111a6bd>] remove_vma+0x51/0x82
> [<ffffffff8111b8a0>] do_munmap+0x2f2/0x30b
> [<ffffffff8111ba21>] sys_munmap+0x49/0x60
> [<ffffffff814f2342>] system_call_fastpath+0x16/0x1b
>
> --
> To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at http://vger.kernel.org/majordomo-info.html
> Please read the FAQ at http://www.tux.org/lkml/
^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: ext4 lockdep trace (3.1.0rc3)
2011-08-29 20:54 ` Dave Jones
2011-08-30 10:23 ` Tao Ma
@ 2011-08-30 12:30 ` Josh Boyer
1 sibling, 0 replies; 6+ messages in thread
From: Josh Boyer @ 2011-08-30 12:30 UTC (permalink / raw)
To: Dave Jones, Linux Kernel, tytso, adilger.kernel
On Mon, Aug 29, 2011 at 4:54 PM, Dave Jones <davej@redhat.com> wrote:
> On Mon, Aug 29, 2011 at 04:48:30PM -0400, Dave Jones wrote:
> > On Fri, Aug 26, 2011 at 05:49:30PM -0400, Dave Jones wrote:
> > > just hit this while building a kernel. Laptop wedged for a few seconds
> > > during the final link, and this was in the log when it unwedged.
> >
> > I still see this in rc4, and can reproduce it reliably every time I build.
> > It only started happening in the last week. I don't see any ext4 or vfs commits
> > within a few days of that, so I'm not sure why it only just begun
> > (I do daily builds, and the 26th was the first time I saw it appear)
> >
> > Given the lack of obvious commits in that timeframe, I'm not sure a bisect is
> > going to be particularly fruitful. It might just be that my IO patterns changed ?
>
> also a second variant with a different trace.
That one has been reported for a while. See RH bug 732572
josh
^ permalink raw reply [flat|nested] 6+ messages in thread
end of thread, other threads:[~2011-08-30 12:30 UTC | newest]
Thread overview: 6+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2011-08-26 21:49 ext4 lockdep trace (3.1.0rc3) Dave Jones
2011-08-29 20:47 ` Christian Kujau
2011-08-29 20:48 ` Dave Jones
2011-08-29 20:54 ` Dave Jones
2011-08-30 10:23 ` Tao Ma
2011-08-30 12:30 ` Josh Boyer
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox