3.3.7 lockdep report from jbd.

From: Dave Jones
Date: Tue May 29 2012 - 22:37:48 EST


Just saw this on my backup server during an rsync.
I'll see if I can reproduce it in 3.4 later.

Dave


=========================================================
[ INFO: possible irq lock inversion dependency detected ]
3.3.7-1.fc16.x86_64.debug #1 Not tainted
---------------------------------------------------------
kswapd0/37 just changed the state of lock:
(jbd2_handle){+.+.-.}, at: [<ffffffff8128b457>] start_this_handle+0x507/0x700
but this lock took another, RECLAIM_FS-unsafe lock in the past:
(&isec->lock){+.+.+.}

and interrupts could create inverse lock ordering between them.


other info that might help us debug this:
Possible interrupt unsafe locking scenario:

CPU0 CPU1
---- ----
lock(&isec->lock);
local_irq_disable();
lock(jbd2_handle);
lock(&isec->lock);
<Interrupt>
lock(jbd2_handle);

*** DEADLOCK ***

2 locks held by kswapd0/37:
#0: (shrinker_rwsem){++++..}, at: [<ffffffff8116304c>] shrink_slab+0x3c/0x4b0
#1: (&type->s_umount_key#20){++++..}, at: [<ffffffff811bf654>] grab_super_passive+0x44/0x90

the shortest dependencies between 2nd lock and 1st lock:
-> (&isec->lock){+.+.+.} ops: 582449 {
HARDIRQ-ON-W at:
[<ffffffff810cbf69>] __lock_acquire+0x619/0x1c20
[<ffffffff810cdc5d>] lock_acquire+0x9d/0x200
[<ffffffff8169ef94>] mutex_lock_nested+0x74/0x3a0
[<ffffffff812c68e2>] inode_doinit_with_dentry+0xc2/0x650
[<ffffffff812c6e8c>] selinux_d_instantiate+0x1c/0x20
[<ffffffff812bd75b>] security_d_instantiate+0x1b/0x30
[<ffffffff811d4081>] d_instantiate+0x61/0x80
[<ffffffff811d69d3>] d_alloc_root+0x43/0x50
[<ffffffff81237f62>] sysfs_mount+0x182/0x220
[<ffffffff811bffe3>] mount_fs+0x43/0x1b0
[<ffffffff811dd7f2>] vfs_kern_mount+0x72/0x100
[<ffffffff811dd899>] kern_mount_data+0x19/0x30
[<ffffffff81ef30b2>] sysfs_init+0x5a/0xb5
[<ffffffff81ef1862>] mnt_init+0xa1/0x181
[<ffffffff81ef14fc>] vfs_caches_init+0xfb/0x10c
[<ffffffff81ecebf3>] start_kernel+0x3b5/0x3fc
[<ffffffff81ece346>] x86_64_start_reservations+0x131/0x135
[<ffffffff81ece44c>] x86_64_start_kernel+0x102/0x111
SOFTIRQ-ON-W at:
[<ffffffff810cbf98>] __lock_acquire+0x648/0x1c20
[<ffffffff810cdc5d>] lock_acquire+0x9d/0x200
[<ffffffff8169ef94>] mutex_lock_nested+0x74/0x3a0
[<ffffffff812c68e2>] inode_doinit_with_dentry+0xc2/0x650
[<ffffffff812c6e8c>] selinux_d_instantiate+0x1c/0x20
[<ffffffff812bd75b>] security_d_instantiate+0x1b/0x30
[<ffffffff811d4081>] d_instantiate+0x61/0x80
[<ffffffff811d69d3>] d_alloc_root+0x43/0x50
[<ffffffff81237f62>] sysfs_mount+0x182/0x220
[<ffffffff811bffe3>] mount_fs+0x43/0x1b0
[<ffffffff811dd7f2>] vfs_kern_mount+0x72/0x100
[<ffffffff811dd899>] kern_mount_data+0x19/0x30
[<ffffffff81ef30b2>] sysfs_init+0x5a/0xb5
[<ffffffff81ef1862>] mnt_init+0xa1/0x181
[<ffffffff81ef14fc>] vfs_caches_init+0xfb/0x10c
[<ffffffff81ecebf3>] start_kernel+0x3b5/0x3fc
[<ffffffff81ece346>] x86_64_start_reservations+0x131/0x135
[<ffffffff81ece44c>] x86_64_start_kernel+0x102/0x111
RECLAIM_FS-ON-W at:
[<ffffffff810ce626>] mark_held_locks+0x86/0x150
[<ffffffff810cedb1>] lockdep_trace_alloc+0x71/0xd0
[<ffffffff811591d6>] __alloc_pages_nodemask+0x86/0xa90
[<ffffffff81194063>] alloc_pages_current+0xa3/0x110
[<ffffffff81154b94>] __get_free_pages+0x14/0x50
[<ffffffff812c6b4b>] inode_doinit_with_dentry+0x32b/0x650
[<ffffffff812c6f56>] sb_finish_set_opts+0xc6/0x260
[<ffffffff812c753c>] selinux_set_mnt_opts+0x32c/0x540
[<ffffffff812c77b0>] superblock_doinit+0x60/0xc0
[<ffffffff812c78f0>] delayed_superblock_init+0x10/0x20
[<ffffffff811bfa41>] iterate_supers+0xf1/0x100
[<ffffffff812cae13>] selinux_complete_init+0x33/0x40
[<ffffffff812da95b>] security_load_policy+0x35b/0x4e0
[<ffffffff812ccb6f>] sel_write_load+0x9f/0x790
[<ffffffff811bb506>] vfs_write+0xb6/0x180
[<ffffffff811bb82d>] sys_write+0x4d/0x90
[<ffffffff816abc29>] system_call_fastpath+0x16/0x1b
INITIAL USE at:
[<ffffffff810cbc70>] __lock_acquire+0x320/0x1c20
[<ffffffff810cdc5d>] lock_acquire+0x9d/0x200
[<ffffffff8169ef94>] mutex_lock_nested+0x74/0x3a0
[<ffffffff812c68e2>] inode_doinit_with_dentry+0xc2/0x650
[<ffffffff812c6e8c>] selinux_d_instantiate+0x1c/0x20
[<ffffffff812bd75b>] security_d_instantiate+0x1b/0x30
[<ffffffff811d4081>] d_instantiate+0x61/0x80
[<ffffffff811d69d3>] d_alloc_root+0x43/0x50
[<ffffffff81237f62>] sysfs_mount+0x182/0x220
[<ffffffff811bffe3>] mount_fs+0x43/0x1b0
[<ffffffff811dd7f2>] vfs_kern_mount+0x72/0x100
[<ffffffff811dd899>] kern_mount_data+0x19/0x30
[<ffffffff81ef30b2>] sysfs_init+0x5a/0xb5
[<ffffffff81ef1862>] mnt_init+0xa1/0x181
[<ffffffff81ef14fc>] vfs_caches_init+0xfb/0x10c
[<ffffffff81ecebf3>] start_kernel+0x3b5/0x3fc
[<ffffffff81ece346>] x86_64_start_reservations+0x131/0x135
[<ffffffff81ece44c>] x86_64_start_kernel+0x102/0x111
}
... key at: [<ffffffff829db510>] __key.51824+0x0/0x8
... acquired at:
[<ffffffff810cdc5d>] lock_acquire+0x9d/0x200
[<ffffffff8169ef94>] mutex_lock_nested+0x74/0x3a0
[<ffffffff812c68e2>] inode_doinit_with_dentry+0xc2/0x650
[<ffffffff812c6e8c>] selinux_d_instantiate+0x1c/0x20
[<ffffffff812bd75b>] security_d_instantiate+0x1b/0x30
[<ffffffff811d4081>] d_instantiate+0x61/0x80
[<ffffffff812510b6>] ext4_add_nondir+0x76/0x80
[<ffffffff812531b6>] ext4_symlink+0x1a6/0x330
[<ffffffff811ca2d9>] vfs_symlink+0x99/0x100
[<ffffffff811cdb73>] sys_symlinkat+0xb3/0xd0
[<ffffffff811cdba6>] sys_symlink+0x16/0x20
[<ffffffff816abc29>] system_call_fastpath+0x16/0x1b

-> (jbd2_handle){+.+.-.} ops: 20071115 {
HARDIRQ-ON-W at:
[<ffffffff810cbf69>] __lock_acquire+0x619/0x1c20
[<ffffffff810cdc5d>] lock_acquire+0x9d/0x200
[<ffffffff8128b486>] start_this_handle+0x536/0x700
[<ffffffff8128b77a>] jbd2__journal_start+0x12a/0x1a0
[<ffffffff8128b803>] jbd2_journal_start+0x13/0x20
[<ffffffff81266cde>] ext4_journal_start_sb+0x7e/0x2a0
[<ffffffff81252907>] ext4_unlink+0x67/0x4b0
[<ffffffff811c9bdf>] vfs_unlink+0x9f/0x110
[<ffffffff811ccf43>] do_unlinkat+0x183/0x1c0
[<ffffffff811cda82>] sys_unlinkat+0x22/0x40
[<ffffffff816abc29>] system_call_fastpath+0x16/0x1b
SOFTIRQ-ON-W at:
[<ffffffff810cbf98>] __lock_acquire+0x648/0x1c20
[<ffffffff810cdc5d>] lock_acquire+0x9d/0x200
[<ffffffff8128b486>] start_this_handle+0x536/0x700
[<ffffffff8128b77a>] jbd2__journal_start+0x12a/0x1a0
[<ffffffff8128b803>] jbd2_journal_start+0x13/0x20
[<ffffffff81266cde>] ext4_journal_start_sb+0x7e/0x2a0
[<ffffffff81252907>] ext4_unlink+0x67/0x4b0
[<ffffffff811c9bdf>] vfs_unlink+0x9f/0x110
[<ffffffff811ccf43>] do_unlinkat+0x183/0x1c0
[<ffffffff811cda82>] sys_unlinkat+0x22/0x40
[<ffffffff816abc29>] system_call_fastpath+0x16/0x1b
IN-RECLAIM_FS-W at:
[<ffffffff810cbee0>] __lock_acquire+0x590/0x1c20
[<ffffffff810cdc5d>] lock_acquire+0x9d/0x200
[<ffffffff8128b486>] start_this_handle+0x536/0x700
[<ffffffff8128b77a>] jbd2__journal_start+0x12a/0x1a0
[<ffffffff8128b803>] jbd2_journal_start+0x13/0x20
[<ffffffff81266cde>] ext4_journal_start_sb+0x7e/0x2a0
[<ffffffff8124bfb9>] ext4_evict_inode+0x1a9/0x620
[<ffffffff811d91d3>] evict+0xa3/0x1b0
[<ffffffff811d93e5>] iput+0x105/0x200
[<ffffffff811d3bb8>] dentry_iput+0xa8/0x100
[<ffffffff811d53a0>] shrink_dentry_list+0x280/0x4c0
[<ffffffff811d64eb>] prune_dcache_sb+0x15b/0x190
[<ffffffff811bf7d0>] prune_super+0x130/0x1a0
[<ffffffff81163185>] shrink_slab+0x175/0x4b0
[<ffffffff8116762a>] balance_pgdat+0x52a/0x720
[<ffffffff811679c1>] kswapd+0x1a1/0x5b0
[<ffffffff8108b927>] kthread+0xb7/0xc0
[<ffffffff816ad074>] kernel_thread_helper+0x4/0x10
INITIAL USE at:
[<ffffffff810cbc70>] __lock_acquire+0x320/0x1c20
[<ffffffff810cdc5d>] lock_acquire+0x9d/0x200
[<ffffffff8128b486>] start_this_handle+0x536/0x700
[<ffffffff8128b77a>] jbd2__journal_start+0x12a/0x1a0
[<ffffffff8128b803>] jbd2_journal_start+0x13/0x20
[<ffffffff81266cde>] ext4_journal_start_sb+0x7e/0x2a0
[<ffffffff81252907>] ext4_unlink+0x67/0x4b0
[<ffffffff811c9bdf>] vfs_unlink+0x9f/0x110
[<ffffffff811ccf43>] do_unlinkat+0x183/0x1c0
[<ffffffff811cda82>] sys_unlinkat+0x22/0x40
[<ffffffff816abc29>] system_call_fastpath+0x16/0x1b
}
... key at: [<ffffffff829cff00>] jbd2_handle_key+0x0/0x8
... acquired at:
[<ffffffff810cae1b>] check_usage_forwards+0x11b/0x150
[<ffffffff810cb7f8>] mark_lock+0x198/0x2f0
[<ffffffff810cbee0>] __lock_acquire+0x590/0x1c20
[<ffffffff810cdc5d>] lock_acquire+0x9d/0x200
[<ffffffff8128b486>] start_this_handle+0x536/0x700
[<ffffffff8128b77a>] jbd2__journal_start+0x12a/0x1a0
[<ffffffff8128b803>] jbd2_journal_start+0x13/0x20
[<ffffffff81266cde>] ext4_journal_start_sb+0x7e/0x2a0
[<ffffffff8124bfb9>] ext4_evict_inode+0x1a9/0x620
[<ffffffff811d91d3>] evict+0xa3/0x1b0
[<ffffffff811d93e5>] iput+0x105/0x200
[<ffffffff811d3bb8>] dentry_iput+0xa8/0x100
[<ffffffff811d53a0>] shrink_dentry_list+0x280/0x4c0
[<ffffffff811d64eb>] prune_dcache_sb+0x15b/0x190
[<ffffffff811bf7d0>] prune_super+0x130/0x1a0
[<ffffffff81163185>] shrink_slab+0x175/0x4b0
[<ffffffff8116762a>] balance_pgdat+0x52a/0x720
[<ffffffff811679c1>] kswapd+0x1a1/0x5b0
[<ffffffff8108b927>] kthread+0xb7/0xc0
[<ffffffff816ad074>] kernel_thread_helper+0x4/0x10


stack backtrace:
Pid: 37, comm: kswapd0 Not tainted 3.3.7-1.fc16.x86_64.debug #1
Call Trace:
[<ffffffff810cacf8>] print_irq_inversion_bug.part.19+0x1e8/0x1f0
[<ffffffff810cae1b>] check_usage_forwards+0x11b/0x150
[<ffffffff810cb7f8>] mark_lock+0x198/0x2f0
[<ffffffff810cad00>] ? print_irq_inversion_bug.part.19+0x1f0/0x1f0
[<ffffffff810cbee0>] __lock_acquire+0x590/0x1c20
[<ffffffff8128b6d9>] ? jbd2__journal_start+0x89/0x1a0
[<ffffffff81022023>] ? native_sched_clock+0x13/0x80
[<ffffffff810a3dc5>] ? sched_clock_local+0x25/0x90
[<ffffffff810a3f58>] ? sched_clock_cpu+0xa8/0x110
[<ffffffff810c815d>] ? trace_hardirqs_off+0xd/0x10
[<ffffffff810cdc5d>] lock_acquire+0x9d/0x200
[<ffffffff8128b457>] ? start_this_handle+0x507/0x700
[<ffffffff8128b486>] start_this_handle+0x536/0x700
[<ffffffff8128b457>] ? start_this_handle+0x507/0x700
[<ffffffff811a1c2b>] ? kmem_cache_alloc+0x19b/0x280
[<ffffffff8128b6d9>] ? jbd2__journal_start+0x89/0x1a0
[<ffffffff8128b77a>] jbd2__journal_start+0x12a/0x1a0
[<ffffffff8124bfb9>] ? ext4_evict_inode+0x1a9/0x620
[<ffffffff8128b803>] jbd2_journal_start+0x13/0x20
[<ffffffff81266cde>] ext4_journal_start_sb+0x7e/0x2a0
[<ffffffff8121ec90>] ? __dquot_initialize+0x30/0x180
[<ffffffff811d91c1>] ? evict+0x91/0x1b0
[<ffffffff8124bfb9>] ext4_evict_inode+0x1a9/0x620
[<ffffffff811d91d3>] evict+0xa3/0x1b0
[<ffffffff811d93e5>] iput+0x105/0x200
[<ffffffff811d3bb8>] dentry_iput+0xa8/0x100
[<ffffffff811d53a0>] shrink_dentry_list+0x280/0x4c0
[<ffffffff811d53d0>] ? shrink_dentry_list+0x2b0/0x4c0
[<ffffffff811d64eb>] prune_dcache_sb+0x15b/0x190
[<ffffffff811bf7d0>] prune_super+0x130/0x1a0
[<ffffffff81163185>] shrink_slab+0x175/0x4b0
[<ffffffff811ae776>] ? mem_cgroup_iter+0xf6/0x340
[<ffffffff8116762a>] balance_pgdat+0x52a/0x720
[<ffffffff811679c1>] kswapd+0x1a1/0x5b0
[<ffffffff8108c580>] ? __init_waitqueue_head+0x60/0x60
[<ffffffff81167820>] ? balance_pgdat+0x720/0x720
[<ffffffff8108b927>] kthread+0xb7/0xc0
[<ffffffff816ad074>] kernel_thread_helper+0x4/0x10
[<ffffffff816a3374>] ? retint_restore_args+0x13/0x13
[<ffffffff8108b870>] ? __init_kthread_worker+0x70/0x70
[<ffffffff816ad070>] ? gs_change+0x13/0x13

--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/