possible recursive locking detected - while running fs operations in loops - 2.6.18-rc2-git5

possible recursive locking detected - while running fs operations in loops - 2.6.18-rc2-git5

[Jesper Juhl]

Hi,

I just got this from the lock validator :

=============================================
[ INFO: possible recursive locking detected ]
---------------------------------------------
rm/2498 is trying to acquire lock:
 (&inode->i_mutex){--..}, at: [<c031c3ac>] mutex_lock+0x1c/0x20

but task is already holding lock:
 (&inode->i_mutex){--..}, at: [<c031c3ac>] mutex_lock+0x1c/0x20

other info that might help us debug this:
2 locks held by rm/2498:
 #0:  (&inode->i_mutex/1){--..}, at: [<c017b6f3>] do_rmdir+0x73/0xe0
 #1:  (&inode->i_mutex){--..}, at: [<c031c3ac>] mutex_lock+0x1c/0x20

stack backtrace:
 [<c0103faa>] show_trace_log_lvl+0x12a/0x150
 [<c0103fe2>] show_trace+0x12/0x20
 [<c01040f9>] dump_stack+0x19/0x20
 [<c0138a19>] print_deadlock_bug+0xb9/0xd0
 [<c0138a9b>] check_deadlock+0x6b/0x80
 [<c013a344>] __lock_acquire+0x354/0x990
 [<c013b0a5>] lock_acquire+0x75/0xa0
 [<c031c430>] __mutex_lock_slowpath+0x70/0x2a0
 [<c031c3ac>] mutex_lock+0x1c/0x20
 [<c01ac8b3>] reiserfs_delete_inode+0x63/0xd0
 [<c01854e1>] generic_delete_inode+0x61/0xe0
 [<c01856af>] generic_drop_inode+0xf/0x20
 [<c0185716>] iput+0x56/0x80
 [<c01826de>] dentry_iput+0x5e/0xc0
 [<c01827e8>] dput+0xa8/0x170
 [<c0182c0b>] prune_one_dentry+0x6b/0x80
 [<c0182d7b>] prune_dcache+0x15b/0x170
 [<c0182ff0>] shrink_dcache_parent+0x10/0x20
 [<c017b55a>] dentry_unhash+0x5a/0xc0
 [<c017b61f>] vfs_rmdir+0x5f/0xc0
 [<c017b74d>] do_rmdir+0xcd/0xe0
 [<c017b770>] sys_rmdir+0x10/0x20
 [<c010304b>] syscall_call+0x7/0xb
 [<b7e79d7d>] 0xb7e79d7d


What I did to provoke it was to run 6 different xterms (with a bash
shell) with the following loops in them in a test directory that was
initially empty :

xterm1:   while true; do mkdir a; done
xterm2:   while true; do rmdir a; done
xterm3:   while true; do touch a/foo; done
xterm4:   while true; do find .; done
xterm5:   while true; do sync; sleep 1; done
xterm6:   while true; do rm -r a; done

I then left that alone for ~15 minutes and then lockdep complained.

This was on a reiserfs 3.6 filesystem.
My kernel version is 2.6.18-rc2-git5 (i386 build, not x86_64)
The CPU is a Athlon64 X2 4400+

Some details :

$ uname -a
Linux dragon 2.6.18-rc2-git5 #1 SMP PREEMPT Tue Jul 25 22:58:52 CEST
2006 i686 athlon-4 i386 GNU/Linux

juhl@dragon:~/download/kernel/linux-2.6.18-rc2-git5$ scripts/ver_linux
If some fields are empty or look unusual you may have an old version.
Compare to the current minimal requirements in Documentation/Changes.

Linux dragon 2.6.18-rc2-git5 #1 SMP PREEMPT Tue Jul 25 22:58:52 CEST
2006 i686 athlon-4 i386 GNU/Linux

Gnu C                  3.4.6
Gnu make               3.81
binutils               2.15.92.0.2
util-linux             2.12r
mount                  2.12r
module-init-tools      3.2.2
e2fsprogs              1.39
reiserfsprogs          3.6.19
quota-tools            3.13.
PPP                    2.4.4b1
Linux C Library        2.3.6
Dynamic linker (ldd)   2.3.6
Linux C++ Library      6.0.3
Procps                 3.2.7
Net-tools              1.60
Kbd                    1.12
Sh-utils               5.97
udev                   071
Modules Loaded         snd_seq_oss snd_seq_midi_event snd_seq
snd_pcm_oss snd_mixer_oss uhci_hcd usbcore snd_emu10k1 snd_rawmidi
snd_ac97_codec snd_ac97_bus snd_pcm snd_seq_device snd_timer
snd_page_alloc snd_util_mem snd_hwdep snd agpgart

If more info is needed then just ask and I'll be happy to provide what I can.

-- 
Jesper Juhl <jesper.juhl@gmail.com>
Don't top-post  http://www.catb.org/~esr/jargon/html/T/top-post.html
Plain text mails only, please      http://www.expita.com/nomime.html

Re: possible recursive locking detected - while running fs operations in loops - 2.6.18-rc2-git5

[Andreas Dilger]

On Jul 26, 2006  00:16 +0200, Jesper Juhl wrote:
> What I did to provoke it was to run 6 different xterms (with a bash
> shell) with the following loops in them in a test directory that was
> initially empty :
> 
> xterm1:   while true; do mkdir a; done
> xterm2:   while true; do rmdir a; done
> xterm3:   while true; do touch a/foo; done
> xterm4:   while true; do find .; done
> xterm5:   while true; do sync; sleep 1; done
> xterm6:   while true; do rm -r a; done

See racer test at ftp.lustre.org/pub/benchmarks/racer-lustre.tar.gz

It does the above, but a bunch more things and is a truly pathalogical
test script that does lots of "stupid user tricks", unlike normal tests
which are only doing operations that expect to be successful.

PS - during the racer.sh test run "rm" is known to segfault after hitting
     an internal assertion, nobody is sure why.
PPS- I don't know who wrote this program, it was originally posted by
     someone not the author to linux-fsdevel or something.

Cheers, Andreas
--
Andreas Dilger
Principal Software Engineer
Cluster File Systems, Inc.

Re: possible recursive locking detected - while running fs operations in loops - 2.6.18-rc2-git5

[Andrew Morton]

On Wed, 26 Jul 2006 00:16:42 +0200
"Jesper Juhl" <jesper.juhl@gmail.com> wrote:

> I just got this from the lock validator :
> 
> =============================================
> [ INFO: possible recursive locking detected ]
> ---------------------------------------------
> rm/2498 is trying to acquire lock:
>  (&inode->i_mutex){--..}, at: [<c031c3ac>] mutex_lock+0x1c/0x20
> 
> but task is already holding lock:
>  (&inode->i_mutex){--..}, at: [<c031c3ac>] mutex_lock+0x1c/0x20
> 
> other info that might help us debug this:
> 2 locks held by rm/2498:
>  #0:  (&inode->i_mutex/1){--..}, at: [<c017b6f3>] do_rmdir+0x73/0xe0
>  #1:  (&inode->i_mutex){--..}, at: [<c031c3ac>] mutex_lock+0x1c/0x20
> 
> stack backtrace:
>  [<c0103faa>] show_trace_log_lvl+0x12a/0x150
>  [<c0103fe2>] show_trace+0x12/0x20
>  [<c01040f9>] dump_stack+0x19/0x20
>  [<c0138a19>] print_deadlock_bug+0xb9/0xd0
>  [<c0138a9b>] check_deadlock+0x6b/0x80
>  [<c013a344>] __lock_acquire+0x354/0x990
>  [<c013b0a5>] lock_acquire+0x75/0xa0
>  [<c031c430>] __mutex_lock_slowpath+0x70/0x2a0
>  [<c031c3ac>] mutex_lock+0x1c/0x20
>  [<c01ac8b3>] reiserfs_delete_inode+0x63/0xd0
>  [<c01854e1>] generic_delete_inode+0x61/0xe0
>  [<c01856af>] generic_drop_inode+0xf/0x20
>  [<c0185716>] iput+0x56/0x80
>  [<c01826de>] dentry_iput+0x5e/0xc0
>  [<c01827e8>] dput+0xa8/0x170
>  [<c0182c0b>] prune_one_dentry+0x6b/0x80
>  [<c0182d7b>] prune_dcache+0x15b/0x170
>  [<c0182ff0>] shrink_dcache_parent+0x10/0x20
>  [<c017b55a>] dentry_unhash+0x5a/0xc0
>  [<c017b61f>] vfs_rmdir+0x5f/0xc0
>  [<c017b74d>] do_rmdir+0xcd/0xe0
>  [<c017b770>] sys_rmdir+0x10/0x20
>  [<c010304b>] syscall_call+0x7/0xb
>  [<b7e79d7d>] 0xb7e79d7d

The VFS takes the directory i_mutex and reiserfs_delete_inode() takes the
to-be-deleted file's i_mutex.

That's notabug and lockdep will need to be taught about it.

That being said, the reiserfs locking appears to be unneeded - this inode
is going down and nobody else can look it up, so what is to be locked
against?

[patch] lockdep: annotate vfs_rmdir for filesystems that take i_mutex in delete_inode

[Arjan van de Ven]

> The VFS takes the directory i_mutex and reiserfs_delete_inode() takes the
> to-be-deleted file's i_mutex.
> 
> That's notabug and lockdep will need to be taught about it.

Actually the annotation is in vfs_rmdir() since that is where the parent
is taken (this may sound odd but the I_MUTEX_* ordering rules require
the parent taking to be annotated rather than the child)

Signed-off-by: Arjan van de Ven <arjan@linux.intel.com>

Index: linux-2.6.18-rc2-git5/fs/namei.c
===================================================================
--- linux-2.6.18-rc2-git5.orig/fs/namei.c
+++ linux-2.6.18-rc2-git5/fs/namei.c
@@ -1967,7 +1967,7 @@ int vfs_rmdir(struct inode *dir, struct 
 
 	DQUOT_INIT(dir);
 
-	mutex_lock(&dentry->d_inode->i_mutex);
+	mutex_lock_nested(&dentry->d_inode->i_mutex, I_MUTEX_PARENT);
 	dentry_unhash(dentry);
 	if (d_mountpoint(dentry))
 		error = -EBUSY;

Re: [patch] lockdep: annotate vfs_rmdir for filesystems that take i_mutex in delete_inode

[Arjan van de Ven]

On Wed, 2006-07-26 at 08:32 +0200, Arjan van de Ven wrote:
> > The VFS takes the directory i_mutex and reiserfs_delete_inode() takes the
> > to-be-deleted file's i_mutex.
> > 
> > That's notabug and lockdep will need to be taught about it.
> 
> Actually the annotation is in vfs_rmdir() since that is where the parent
> is taken (this may sound odd but the I_MUTEX_* ordering rules require
> the parent taking to be annotated rather than the child)


Ignore this; this one is wrong, more later

[patch] lockdep: annotate vfs_rmdir for filesystems that take i_mutex in delete_inode

[Arjan van de Ven]

On Tue, 2006-07-25 at 22:33 -0700, Andrew Morton wrote:
> On Wed, 26 Jul 2006 00:16:42 +0200
> The VFS takes the directory i_mutex and reiserfs_delete_inode() takes the
> to-be-deleted file's i_mutex.
> 
> That's notabug and lockdep will need to be taught about it.

[2nd try, now with coffee]

This is another 3 level locking ordering:
do_rmdir takes the mutex of the parent directory
vfs_rmdir takes the mutex of the victim
shrink_dcache_parent ends up in the reiser delete_inode which takes the
mutex of dead children of the victim

the I_MUTEX ordering rules are

I_MUTEX_PARENT -> I_MUTEX_CHILD -> <normal>

do_rmdir already has I_MUTEX_PARENT, delete_inode does <normal> so
vfs_rmdir needs I_MUTEX_CHILD (which is also logical)

Signed-off-by: Arjan van de Ven <arjan@linux.intel.com>

Index: linux-2.6.18-rc2-git5/fs/namei.c
===================================================================
--- linux-2.6.18-rc2-git5.orig/fs/namei.c
+++ linux-2.6.18-rc2-git5/fs/namei.c
@@ -1967,7 +1967,7 @@ int vfs_rmdir(struct inode *dir, struct 
 
 	DQUOT_INIT(dir);
 
-	mutex_lock(&dentry->d_inode->i_mutex);
+	mutex_lock_nested(&dentry->d_inode->i_mutex, I_MUTEX_CHILD);
 	dentry_unhash(dentry);
 	if (d_mountpoint(dentry))
 		error = -EBUSY;

Re: [patch] lockdep: annotate vfs_rmdir for filesystems that take i_mutex in delete_inode

[Andrew Morton]

On Wed, 26 Jul 2006 08:47:21 +0200
Arjan van de Ven <arjan@linux.intel.com> wrote:

> On Tue, 2006-07-25 at 22:33 -0700, Andrew Morton wrote:
> > On Wed, 26 Jul 2006 00:16:42 +0200
> > The VFS takes the directory i_mutex and reiserfs_delete_inode() takes the
> > to-be-deleted file's i_mutex.
> > 
> > That's notabug and lockdep will need to be taught about it.
> 
> [2nd try, now with coffee]
> 
> This is another 3 level locking ordering:
> do_rmdir takes the mutex of the parent directory
> vfs_rmdir takes the mutex of the victim
> shrink_dcache_parent ends up in the reiser delete_inode which takes the
> mutex of dead children of the victim
> 
> the I_MUTEX ordering rules are
> 
> I_MUTEX_PARENT -> I_MUTEX_CHILD -> <normal>
> 
> do_rmdir already has I_MUTEX_PARENT, delete_inode does <normal> so
> vfs_rmdir needs I_MUTEX_CHILD (which is also logical)
> 
> Signed-off-by: Arjan van de Ven <arjan@linux.intel.com>
> 
> Index: linux-2.6.18-rc2-git5/fs/namei.c
> ===================================================================
> --- linux-2.6.18-rc2-git5.orig/fs/namei.c
> +++ linux-2.6.18-rc2-git5/fs/namei.c
> @@ -1967,7 +1967,7 @@ int vfs_rmdir(struct inode *dir, struct 
>  
>  	DQUOT_INIT(dir);
>  
> -	mutex_lock(&dentry->d_inode->i_mutex);
> +	mutex_lock_nested(&dentry->d_inode->i_mutex, I_MUTEX_CHILD);
>  	dentry_unhash(dentry);
>  	if (d_mountpoint(dentry))
>  		error = -EBUSY;

If there's a reason why a filesystem shuld take an i_mutex under
vfs_rmdir() then fine.  But I don't think there is, in which case the
warning can be kept.

Can a reiserfs person please comment?

Re: possible recursive locking detected - while running fs operations in loops - 2.6.18-rc2-git5

[Jesper Juhl]

On 26/07/06, Andreas Dilger <adilger@clusterfs.com> wrote:
> On Jul 26, 2006  00:16 +0200, Jesper Juhl wrote:
> > What I did to provoke it was to run 6 different xterms (with a bash
> > shell) with the following loops in them in a test directory that was
> > initially empty :
> >
> > xterm1:   while true; do mkdir a; done
> > xterm2:   while true; do rmdir a; done
> > xterm3:   while true; do touch a/foo; done
> > xterm4:   while true; do find .; done
> > xterm5:   while true; do sync; sleep 1; done
> > xterm6:   while true; do rm -r a; done
>
> See racer test at ftp.lustre.org/pub/benchmarks/racer-lustre.tar.gz
>
> It does the above, but a bunch more things and is a truly pathalogical
> test script that does lots of "stupid user tricks", unlike normal tests
> which are only doing operations that expect to be successful.
>
> PS - during the racer.sh test run "rm" is known to segfault after hitting
>      an internal assertion, nobody is sure why.
> PPS- I don't know who wrote this program, it was originally posted by
>      someone not the author to linux-fsdevel or something.
>

Thanks. That's a nice little test suite.

-- 
Jesper Juhl <jesper.juhl@gmail.com>
Don't top-post  http://www.catb.org/~esr/jargon/html/T/top-post.html
Plain text mails only, please      http://www.expita.com/nomime.html

Re: possible recursive locking detected - while running fs operations in loops - 2.6.18-rc2-git5

[Hans Reiser]

Jesper Juhl wrote:

>
> Thanks. That's a nice little test suite.
>
Yes, it is quite useful, our developers have added it to the regression
suite....

Hans

Re: possible recursive locking detected - while running fs operations in loops - 2.6.18-rc2-git5

[Hans Reiser]

Jesper Juhl wrote:

> On 30/07/06, Hans Reiser <reiser@namesys.com> wrote:
>
>> Jesper Juhl wrote:
>>
>> >
>> > Thanks. That's a nice little test suite.
>> >
>> Yes, it is quite useful, our developers have added it to the regression
>> suite....
>>
> That's nice.
>
> Now how about that lock validator message I managed to tease out?
>
> Akpm said "... the reiserfs locking appears to be unneeded - this inode
> is going down and nobody else can look it up, so what is to be locked
> against?" - can you comment on that?
>
>
Err, how about Zam handles all locking issues and this is Sunday with
the family?  I know, lame, but he'll answer you on Monday Russian
time.....;-)

Re: possible recursive locking detected - while running fs operations in loops - 2.6.18-rc2-git5

[Jesper Juhl]

On 30/07/06, Hans Reiser <reiser@namesys.com> wrote:
> Jesper Juhl wrote:
>
> >
> > Thanks. That's a nice little test suite.
> >
> Yes, it is quite useful, our developers have added it to the regression
> suite....
>
That's nice.

Now how about that lock validator message I managed to tease out?

Akpm said "... the reiserfs locking appears to be unneeded - this inode
is going down and nobody else can look it up, so what is to be locked
against?" - can you comment on that?


-- 
Jesper Juhl <jesper.juhl@gmail.com>
Don't top-post  http://www.catb.org/~esr/jargon/html/T/top-post.html
Plain text mails only, please      http://www.expita.com/nomime.html

Re: possible recursive locking detected - while running fs operations in loops - 2.6.18-rc2-git5

[Jesper Juhl]

On 30/07/06, Hans Reiser <reiser@namesys.com> wrote:
> Jesper Juhl wrote:
>
> > On 30/07/06, Hans Reiser <reiser@namesys.com> wrote:
> >
> >> Jesper Juhl wrote:
> >>
> >> >
> >> > Thanks. That's a nice little test suite.
> >> >
> >> Yes, it is quite useful, our developers have added it to the regression
> >> suite....
> >>
> > That's nice.
> >
> > Now how about that lock validator message I managed to tease out?
> >
> > Akpm said "... the reiserfs locking appears to be unneeded - this inode
> > is going down and nobody else can look it up, so what is to be locked
> > against?" - can you comment on that?
> >
> >
> Err, how about Zam handles all locking issues and this is Sunday with
> the family?  I know, lame, but he'll answer you on Monday Russian
> time.....;-)
>
:-) Not a problem at all.

-- 
Jesper Juhl <jesper.juhl@gmail.com>
Don't top-post  http://www.catb.org/~esr/jargon/html/T/top-post.html
Plain text mails only, please      http://www.expita.com/nomime.html

Re: possible recursive locking detected - while running fs operations in loops - 2.6.18-rc2-git5

[Alexander Zarochentsev]

Hello,

On Sunday 30 July 2006 10:17, Jesper Juhl wrote:
> On 30/07/06, Hans Reiser <reiser@namesys.com> wrote:
> > Jesper Juhl wrote:
> > > Thanks. That's a nice little test suite.
> >
> > Yes, it is quite useful, our developers have added it to the
> > regression suite....
>
> That's nice.
>
> Now how about that lock validator message I managed to tease out?
>
> Akpm said "... the reiserfs locking appears to be unneeded - this
> inode is going down and nobody else can look it up, so what is to be
> locked against?" - can you comment on that?

Thanks. it is correct.
Andrew, please apply the following patch: 

i_mutex does not need to be locked in reiserfs_delete_inode.

Signed-off-by: Alexander Zarochentsev <zam@namesys.com>

fs/reiserfs/inode.c |   12 ++----------
 1 files changed, 2 insertions(+), 10 deletions(-)

Index: linux-2.6-git/fs/reiserfs/inode.c
===================================================================
--- linux-2.6-git.orig/fs/reiserfs/inode.c
+++ linux-2.6-git/fs/reiserfs/inode.c
@@ -37,14 +37,10 @@ void reiserfs_delete_inode(struct inode 
 
 	/* The = 0 happens when we abort creating a new inode for some reason like lack of space.. */
 	if (!(inode->i_state & I_NEW) && INODE_PKEY(inode)->k_objectid != 0) {	/* also handles bad_inode case */
-		mutex_lock(&inode->i_mutex);
-
 		reiserfs_delete_xattrs(inode);
 
-		if (journal_begin(&th, inode->i_sb, jbegin_count)) {
-			mutex_unlock(&inode->i_mutex);
+		if (journal_begin(&th, inode->i_sb, jbegin_count))
 			goto out;
-		}
 		reiserfs_update_inode_transaction(inode);
 
 		err = reiserfs_delete_object(&th, inode);
@@ -55,12 +51,8 @@ void reiserfs_delete_inode(struct inode 
 		if (!err) 
 			DQUOT_FREE_INODE(inode);
 
-		if (journal_end(&th, inode->i_sb, jbegin_count)) {
-			mutex_unlock(&inode->i_mutex);
+		if (journal_end(&th, inode->i_sb, jbegin_count))
 			goto out;
-		}
-
-		mutex_unlock(&inode->i_mutex);
 
 		/* check return value from reiserfs_delete_object after
 		 * ending the transaction