Bug 727

Summary: kernel 2.6.18.2: possible recursive locking detected
Product: XFS Reporter: Ernest ter Kuile <ejwtk06>
Component: XFS kernel codeAssignee: XFS power people <xfs-masters>
Status: RESOLVED FIXED QA Contact:
Severity: normal    
Priority: P2 CC: hch, thlarsen
Version: unspecified   
Target Milestone: ---   
Hardware: PC   
OS: Linux   
Whiteboard:

Description Ernest ter Kuile 2006-11-19 11:03:11 CST
Seen at first only when running dpkg, the debian the package manager (so I
thought it was dpkg related) later also seen with an other program (ncftp).

Kernel is pristine 2.6.18.2 with debug lock checking switched on.

uname: Linux terkuile 2.6.18.2 #34 PREEMPT Thu Nov 16 14:20:25 CET 2006 x86_64
GNU/Linux

Maybe not xfs related. But xfs appears prominently with output below.

=============================================
[ INFO: possible recursive locking detected ]
---------------------------------------------
dpkg/2725 is trying to acquire lock:
 (&(&ip->i_lock)->mr_lock){----}, at: [<ffffffff88135760>] xfs_ilock+0x58/0x7b [xfs]

but task is already holding lock:
 (&(&ip->i_lock)->mr_lock){----}, at: [<ffffffff88135760>] xfs_ilock+0x58/0x7b [xfs]

other info that might help us debug this:
3 locks held by dpkg/2725:
 #0:  (&inode->i_mutex/1){--..}, at: [<ffffffff8023c557>] do_unlinkat+0x7e/0x175
 #1:  (&inode->i_mutex){--..}, at: [<ffffffff80262765>] mutex_lock+0x25/0x2a
 #2:  (&(&ip->i_lock)->mr_lock){----}, at: [<ffffffff88135760>]
xfs_ilock+0x58/0x7b [xfs]

stack backtrace:

Call Trace:
 [<ffffffff802936a5>] __lock_acquire+0x146/0xa49
 [<ffffffff80264110>] _spin_unlock_irq+0x2b/0x57
 [<ffffffff88135760>] :xfs:xfs_ilock+0x58/0x7b
 [<ffffffff80294023>] lock_acquire+0x7b/0xa1
 [<ffffffff88135760>] :xfs:xfs_ilock+0x58/0x7b
 [<ffffffff80290f0d>] down_write+0x36/0x42
 [<ffffffff88135760>] :xfs:xfs_ilock+0x58/0x7b
 [<ffffffff8814e42a>] :xfs:xfs_lock_dir_and_entry+0x8b/0xc6
 [<ffffffff88151614>] :xfs:xfs_remove+0x1c0/0x3c1
 [<ffffffff8815a135>] :xfs:xfs_vn_unlink+0x26/0x60
 [<ffffffff8026270f>] __mutex_lock_slowpath+0x241/0x272
 [<ffffffff80239f02>] debug_mutex_free_waiter+0x52/0x56
 [<ffffffff80262733>] __mutex_lock_slowpath+0x265/0x272
 [<ffffffff8024a040>] vfs_unlink+0xcd/0x114
 [<ffffffff8023c5a0>] do_unlinkat+0xc7/0x175
 [<ffffffff802635b9>] trace_hardirqs_on_thunk+0x35/0x37
 [<ffffffff802931fb>] trace_hardirqs_on+0x107/0x131
 [<ffffffff802635b9>] trace_hardirqs_on_thunk+0x35/0x37
 [<ffffffff802b55c4>] sys_unlink+0x11/0x13
 [<ffffffff8025d38e>] system_call+0x7e/0x83



XFS related kernel config is:
CONFIG_XFS_FS=m
CONFIG_XFS_QUOTA=y
CONFIG_XFS_SECURITY=y
CONFIG_XFS_POSIX_ACL=y
# CONFIG_XFS_RT is not set

#
# Kernel hacking
#
CONFIG_TRACE_IRQFLAGS_SUPPORT=y
# CONFIG_PRINTK_TIME is not set
CONFIG_MAGIC_SYSRQ=y
# CONFIG_UNUSED_SYMBOLS is not set
CONFIG_DEBUG_KERNEL=y
CONFIG_LOG_BUF_SHIFT=14
CONFIG_DETECT_SOFTLOCKUP=y
CONFIG_SCHEDSTATS=y
# CONFIG_DEBUG_SLAB is not set
# CONFIG_DEBUG_PREEMPT is not set
# CONFIG_DEBUG_RT_MUTEXES is not set
# CONFIG_RT_MUTEX_TESTER is not set
CONFIG_DEBUG_SPINLOCK=y
CONFIG_DEBUG_MUTEXES=y
CONFIG_DEBUG_RWSEMS=y
CONFIG_DEBUG_LOCK_ALLOC=y
CONFIG_PROVE_LOCKING=y
CONFIG_LOCKDEP=y
CONFIG_DEBUG_LOCKDEP=y
CONFIG_TRACE_IRQFLAGS=y
CONFIG_DEBUG_SPINLOCK_SLEEP=y
CONFIG_DEBUG_LOCKING_API_SELFTESTS=y
CONFIG_STACKTRACE=y
# CONFIG_DEBUG_KOBJECT is not set
# CONFIG_DEBUG_INFO is not set
# CONFIG_DEBUG_FS is not set
# CONFIG_DEBUG_VM is not set
CONFIG_FRAME_POINTER=y
# CONFIG_UNWIND_INFO is not set
# CONFIG_FORCED_INLINING is not set
# CONFIG_RCU_TORTURE_TEST is not set
# CONFIG_DEBUG_RODATA is not set
# CONFIG_IOMMU_DEBUG is not set
# CONFIG_DEBUG_STACKOVERFLOW is not set
CONFIG_DEBUG_STACK_USAGE=y

the rest on request.
Comment 1 Ernest ter Kuile 2007-01-07 13:56:11 CST
Potential recursive locking is still reported for latest stable kernel.

=============================================
[ INFO: possible recursive locking detected ]
2.6.19.1 #1
---------------------------------------------
dpkg/2607 is trying to acquire lock:
 (&(&ip->i_lock)->mr_lock){----}, at: [<ffffffff8032fb1a>] xfs_ilock+0x56/0x7a

but task is already holding lock:
 (&(&ip->i_lock)->mr_lock){----}, at: [<ffffffff8032fb1a>] xfs_ilock+0x56/0x7a

other info that might help us debug this:
3 locks held by dpkg/2607:
 #0:  (&inode->i_mutex/1){--..}, at: [<ffffffff80239fdc>] do_unlinkat+0x80/0x14
 #1:  (&inode->i_mutex){--..}, at: [<ffffffff8025fe23>] mutex_lock+0x23/0x27
 #2:  (&(&ip->i_lock)->mr_lock){----}, at: [<ffffffff8032fb1a>] xfs_ilock+0x56/

stack backtrace:

Call Trace:
 [<ffffffff802927c1>] __lock_acquire+0x37f/0xb0c
 [<ffffffff8032fb1a>] xfs_ilock+0x56/0x7a
 [<ffffffff8029343f>] lock_acquire+0x7c/0xa0
 [<ffffffff8032fb1a>] xfs_ilock+0x56/0x7a
 [<ffffffff8028f0e9>] down_write+0x33/0x3f
 [<ffffffff8032fb1a>] xfs_ilock+0x56/0x7a
 [<ffffffff8034ac13>] xfs_lock_dir_and_entry+0x8b/0xc6
 [<ffffffff8034ae58>] xfs_remove+0x20a/0x429
 [<ffffffff80292ef6>] __lock_acquire+0xab4/0xb0c
 [<ffffffff80354f21>] xfs_vn_unlink+0x26/0x60
 [<ffffffff8025fdcf>] __mutex_lock_slowpath+0x245/0x276
 [<ffffffff802379cd>] debug_mutex_free_waiter+0x50/0x55
 [<ffffffff8025fdf3>] __mutex_lock_slowpath+0x269/0x276
 [<ffffffff802479f7>] vfs_unlink+0xcd/0xfd
 [<ffffffff8023a027>] do_unlinkat+0xcb/0x144
 [<ffffffff80261212>] trace_hardirqs_on_thunk+0x35/0x37
 [<ffffffff80291f70>] trace_hardirqs_on+0xfd/0x127
 [<ffffffff80261212>] trace_hardirqs_on_thunk+0x35/0x37
 [<ffffffff802b84d0>] sys_unlink+0x11/0x13
 [<ffffffff8025b01e>] system_call+0x7e/0x83
Comment 2 Christoph Hellwig 2008-12-26 14:00:44 CST
*** Bug 778 has been marked as a duplicate of this bug. ***
Comment 3 Christoph Hellwig 2008-12-30 15:24:06 CST
This is a lockdep false positive.  But we're looking into ways to teach lockdep
about this locking scheme.
Comment 4 Christoph Hellwig 2009-08-09 21:41:54 CDT
Actually we fixes this by adding the proper lockdep annotation long ago, closing.