futex strangeness in 2.6.23-mm1/UML

futex strangeness in 2.6.23-mm1/UML

[Miklos Szeredi]

I'm getting a process stuck in pthread_rwlock_wrlock(), even though it
looks like the lock is not held by anybody.

I think the last -mm was OK.  Any ideas?

If not, I'll go searching for the offending patch.

Thanks,
Miklos

Re: futex strangeness in 2.6.23-mm1/UML

[Rik van Riel]

On Mon, 22 Oct 2007 19:29:07 +0200
Miklos Szeredi <miklos@szeredi.hu> wrote:

> I'm getting a process stuck in pthread_rwlock_wrlock(), even though it
> looks like the lock is not held by anybody.
> 
> I think the last -mm was OK.  Any ideas?
> 
> If not, I'll go searching for the offending patch.

I wonder if that's the same bug that's breaking autofs for me.

Oct 22 14:39:01 kenny automount[2299]: cache_readlock: mapent cache
rwlock lock failed
Oct 22 14:39:01 kenny automount[2299]: unexpected pthreads error: 11 at
65 in cache.c

I'm bisecting 2.6.23-mm1 today to find the problem patch, with
some luck I'll have it this afternoon.

With the series applied up to whitespace-fixes-task-exit-handling.patch
things work.

It breaks before kswapd-should-only-wait-on-io-if-there-is-io.patch

That leaves only about 60-80 patches to look at :)

-- 
"Debugging is twice as hard as writing the code in the first place.
Therefore, if you write the code as cleverly as possible, you are,
by definition, not smart enough to debug it." - Brian W. Kernighan

Re: futex strangeness in 2.6.23-mm1/UML

[Miklos Szeredi]

> > I'm getting a process stuck in pthread_rwlock_wrlock(), even though it
> > looks like the lock is not held by anybody.
> > 
> > I think the last -mm was OK.  Any ideas?
> > 
> > If not, I'll go searching for the offending patch.
> 
> I wonder if that's the same bug that's breaking autofs for me.

Probably.

> Oct 22 14:39:01 kenny automount[2299]: cache_readlock: mapent cache
> rwlock lock failed
> Oct 22 14:39:01 kenny automount[2299]: unexpected pthreads error: 11 at
> 65 in cache.c
> 
> I'm bisecting 2.6.23-mm1 today to find the problem patch, with
> some luck I'll have it this afternoon.
> 
> With the series applied up to whitespace-fixes-task-exit-handling.patch
> things work.
> 
> It breaks before kswapd-should-only-wait-on-io-if-there-is-io.patch
> 
> That leaves only about 60-80 patches to look at :)

OK, the first patch that breaks something for me is:

  pid-namespaces-move-alloc_pid-lower-in-copy_process.patch

Miklos

Re: futex strangeness in 2.6.23-mm1/UML

[Rik van Riel]

On Mon, 22 Oct 2007 22:48:51 +0200
Miklos Szeredi <miklos@szeredi.hu> wrote:

> > > I'm getting a process stuck in pthread_rwlock_wrlock(), even
> > > though it looks like the lock is not held by anybody.
> > > 
> > > I think the last -mm was OK.  Any ideas?
> > > 
> > > If not, I'll go searching for the offending patch.
> > 
> > I wonder if that's the same bug that's breaking autofs for me.
> 
> Probably.
> 
> > Oct 22 14:39:01 kenny automount[2299]: cache_readlock: mapent cache
> > rwlock lock failed
> > Oct 22 14:39:01 kenny automount[2299]: unexpected pthreads error:
> > 11 at 65 in cache.c
> > 
> > I'm bisecting 2.6.23-mm1 today to find the problem patch, with
> > some luck I'll have it this afternoon.
> > 
> > With the series applied up to
> > whitespace-fixes-task-exit-handling.patch things work.
> > 
> > It breaks before kswapd-should-only-wait-on-io-if-there-is-io.patch
> > 
> > That leaves only about 60-80 patches to look at :)
> 
> OK, the first patch that breaks something for me is:
> 
>   pid-namespaces-move-alloc_pid-lower-in-copy_process.patch

Confirmed.  That same patch is the point where the bisect
here starts breaking autofs.

Ian, it looks like the autofs code is innocent :)

-- 
"Debugging is twice as hard as writing the code in the first place.
Therefore, if you write the code as cleverly as possible, you are,
by definition, not smart enough to debug it." - Brian W. Kernighan

Re: futex strangeness in 2.6.23-mm1/UML

[Rik van Riel]

On Mon, 22 Oct 2007 17:29:26 -0400
Rik van Riel <riel@redhat.com> wrote:

> On Mon, 22 Oct 2007 22:48:51 +0200
> Miklos Szeredi <miklos@szeredi.hu> wrote:
> 
> > > > I'm getting a process stuck in pthread_rwlock_wrlock(), even
> > > > though it looks like the lock is not held by anybody.
> > > > 
> > > > I think the last -mm was OK.  Any ideas?
> > > > 
> > > > If not, I'll go searching for the offending patch.
> > > 
> > > I wonder if that's the same bug that's breaking autofs for me.
> > 
> > Probably.
> > 
> > > Oct 22 14:39:01 kenny automount[2299]: cache_readlock: mapent
> > > cache rwlock lock failed
> > > Oct 22 14:39:01 kenny automount[2299]: unexpected pthreads error:
> > > 11 at 65 in cache.c
> > > 
> > > I'm bisecting 2.6.23-mm1 today to find the problem patch, with
> > > some luck I'll have it this afternoon.
> > > 
> > > With the series applied up to
> > > whitespace-fixes-task-exit-handling.patch things work.
> > > 
> > > It breaks before
> > > kswapd-should-only-wait-on-io-if-there-is-io.patch
> > > 
> > > That leaves only about 60-80 patches to look at :)
> > 
> > OK, the first patch that breaks something for me is:
> > 
> >   pid-namespaces-move-alloc_pid-lower-in-copy_process.patch
> 
> Confirmed.  That same patch is the point where the bisect
> here starts breaking autofs.

Oww man.  Getting into heisenbug territory now :(

I bisected down to the point where I had these two patches between
good and bad:

# GOOD
pid-namespaces-move-alloc_pid-lower-in-copy_process.patch
pid-namespaces-make-proc-have-multiple-superblocks-one-for-each-namespace.patch
# BAD

Applying them one by one and rebuilding the kernel after each one
gave me a working kernel, though!

Bisecting them from the top (quilt pop) resulted in a broken kernel,
bisecting from the bottom (quilt push) results in a working one.

I have no idea what is going on any more...

-- 
"Debugging is twice as hard as writing the code in the first place.
Therefore, if you write the code as cleverly as possible, you are,
by definition, not smart enough to debug it." - Brian W. Kernighan

Re: futex strangeness in 2.6.23-mm1/UML

[Andrew Morton]

On Mon, 22 Oct 2007 20:07:42 -0400
Rik van Riel <riel@redhat.com> wrote:

> On Mon, 22 Oct 2007 17:29:26 -0400
> Rik van Riel <riel@redhat.com> wrote:
> 
> > On Mon, 22 Oct 2007 22:48:51 +0200
> > Miklos Szeredi <miklos@szeredi.hu> wrote:
> > 
> > > > > I'm getting a process stuck in pthread_rwlock_wrlock(), even
> > > > > though it looks like the lock is not held by anybody.
> > > > > 
> > > > > I think the last -mm was OK.  Any ideas?
> > > > > 
> > > > > If not, I'll go searching for the offending patch.
> > > > 
> > > > I wonder if that's the same bug that's breaking autofs for me.
> > > 
> > > Probably.
> > > 
> > > > Oct 22 14:39:01 kenny automount[2299]: cache_readlock: mapent
> > > > cache rwlock lock failed
> > > > Oct 22 14:39:01 kenny automount[2299]: unexpected pthreads error:
> > > > 11 at 65 in cache.c
> > > > 
> > > > I'm bisecting 2.6.23-mm1 today to find the problem patch, with
> > > > some luck I'll have it this afternoon.
> > > > 
> > > > With the series applied up to
> > > > whitespace-fixes-task-exit-handling.patch things work.
> > > > 
> > > > It breaks before
> > > > kswapd-should-only-wait-on-io-if-there-is-io.patch
> > > > 
> > > > That leaves only about 60-80 patches to look at :)
> > > 
> > > OK, the first patch that breaks something for me is:
> > > 
> > >   pid-namespaces-move-alloc_pid-lower-in-copy_process.patch
> > 
> > Confirmed.  That same patch is the point where the bisect
> > here starts breaking autofs.
> 
> Oww man.  Getting into heisenbug territory now :(
> 
> I bisected down to the point where I had these two patches between
> good and bad:
> 
> # GOOD
> pid-namespaces-move-alloc_pid-lower-in-copy_process.patch
> pid-namespaces-make-proc-have-multiple-superblocks-one-for-each-namespace.patch
> # BAD
> 
> Applying them one by one and rebuilding the kernel after each one
> gave me a working kernel, though!
> 
> Bisecting them from the top (quilt pop) resulted in a broken kernel,
> bisecting from the bottom (quilt push) results in a working one.
> 
> I have no idea what is going on any more...
> 

I guess we can debug it in the old-fashioned ways.  The first of which is
to palm the problem off on Pavel ;)

I don't recall seeing a simple step-by-step way by which others can
reproduce this?

Re: futex strangeness in 2.6.23-mm1/UML

[Rik van Riel]

On Mon, 22 Oct 2007 17:16:24 -0700
Andrew Morton <akpm@linux-foundation.org> wrote:

> > > > > Oct 22 14:39:01 kenny automount[2299]: cache_readlock: mapent
> > > > > cache rwlock lock failed
> > > > > Oct 22 14:39:01 kenny automount[2299]: unexpected pthreads
> > > > > error: 11 at 65 in cache.c

> I guess we can debug it in the old-fashioned ways.  The first of
> which is to palm the problem off on Pavel ;)
> 
> I don't recall seeing a simple step-by-step way by which others can
> reproduce this?

I have my systems set up to automount my home directory over
NFS when I log in.  When trying to log in to the system with
2.6.23-mm1, I get the messages from above in my syslog, and
the NFS filesystem is not automounted.

I am thinking something in autofs or the pid-namespace* patches
does not match up and uses a wrong PID number or process pointer
when trying to lock things.

Which code is at fault I have no idea...

-- 
"Debugging is twice as hard as writing the code in the first place.
Therefore, if you write the code as cleverly as possible, you are,
by definition, not smart enough to debug it." - Brian W. Kernighan

Re: futex strangeness in 2.6.23-mm1/UML

[Rik van Riel]

On Mon, 22 Oct 2007 21:11:43 -0400
Rik van Riel <riel@redhat.com> wrote:

> I have my systems set up to automount my home directory over
> NFS when I log in.  When trying to log in to the system with
> 2.6.23-mm1, I get the messages from above in my syslog, and
> the NFS filesystem is not automounted.
> 
> I am thinking something in autofs or the pid-namespace* patches
> does not match up and uses a wrong PID number or process pointer
> when trying to lock things.
> 
> Which code is at fault I have no idea...

I still do not know for sure, but I have found some code that
puzzles me.

At fork() time, task->pid is set to task->pid->numbers[0].nr

On the other hand, fork() returns to the parent process:

task->pid[PIDTYPE_PID]->numbers[task->pid->level].nr

I have not unravelled the code enough yet to be sure whether
this is always the same number, but having a wrong PID number
somewhere could certainly explain these autofs4 errors:

Oct 22 14:39:01 kenny automount[2299]: cache_readlock: mapent cache
rwlock lock failed
Oct 22 14:39:01 kenny automount[2299]: unexpected pthreads error: 11 at
65 in cache.c

After all, autofs4 puts various kinds of PID information of the
daemon into the autofs4 waitqueue:

fs/autofs4/waitq.c:296:
                wq->uid = current->uid;
                wq->gid = current->gid;
                wq->pid = current->pid;
                wq->tgid = current->tgid;

Could this be related?

Wrt. the UML failures that Miklos is seeing, I imagine UML needs
to do some similar tricks.

-- 
"Debugging is twice as hard as writing the code in the first place.
Therefore, if you write the code as cleverly as possible, you are,
by definition, not smart enough to debug it." - Brian W. Kernighan

Re: futex strangeness in 2.6.23-mm1/UML

[Ian Kent]

On Mon, 2007-10-22 at 21:38 -0400, Rik van Riel wrote:
> On Mon, 22 Oct 2007 21:11:43 -0400
> Rik van Riel <riel@redhat.com> wrote:
> 
> > I have my systems set up to automount my home directory over
> > NFS when I log in.  When trying to log in to the system with
> > 2.6.23-mm1, I get the messages from above in my syslog, and
> > the NFS filesystem is not automounted.
> > 
> > I am thinking something in autofs or the pid-namespace* patches
> > does not match up and uses a wrong PID number or process pointer
> > when trying to lock things.
> > 
> > Which code is at fault I have no idea...
> 
> I still do not know for sure, but I have found some code that
> puzzles me.
> 
> At fork() time, task->pid is set to task->pid->numbers[0].nr
> 
> On the other hand, fork() returns to the parent process:
> 
> task->pid[PIDTYPE_PID]->numbers[task->pid->level].nr
> 
> I have not unravelled the code enough yet to be sure whether
> this is always the same number, but having a wrong PID number
> somewhere could certainly explain these autofs4 errors:
> 
> Oct 22 14:39:01 kenny automount[2299]: cache_readlock: mapent cache
> rwlock lock failed
> Oct 22 14:39:01 kenny automount[2299]: unexpected pthreads error: 11 at
> 65 in cache.c
> 
> After all, autofs4 puts various kinds of PID information of the
> daemon into the autofs4 waitqueue:
> 
> fs/autofs4/waitq.c:296:
>                 wq->uid = current->uid;
>                 wq->gid = current->gid;
>                 wq->pid = current->pid;
>                 wq->tgid = current->tgid;
> 
> Could this be related?

Probably not wrt the pthreads lock fail.
The value passed to the daemon are used for information purposes.

The pid is used only to log who is asking for the mount.
The uid and gid are used to find user name and group name and the four
bits of user information are used to set values in the environment for
use as macros within the map.

If the values in the wait request are wrong then we probably wouldn't
even know as few people will be even aware they are available.

Ian

Re: futex strangeness in 2.6.23-mm1/UML

[Jeff Dike]

On Mon, Oct 22, 2007 at 09:38:12PM -0400, Rik van Riel wrote:
> Wrt. the UML failures that Miklos is seeing, I imagine UML needs
> to do some similar tricks.

UML is just an architecture - it has no need of such tricks (although
it does need to keep track of host pids, but these are in architecture
data, invisible to the rest of the kernel).

				Jeff

-- 
Work email - jdike at linux dot intel dot com

Re: futex strangeness in 2.6.23-mm1/UML

[Miklos Szeredi]

> I guess we can debug it in the old-fashioned ways.  The first of which is
> to palm the problem off on Pavel ;)
> 
> I don't recall seeing a simple step-by-step way by which others can
> reproduce this?

My method is this:

- enable CONFIG_FUSE_FS
- compile fuse from CVS:
 cvs -d:pserver:anonymous@fuse.cvs.sourceforge.net:/cvsroot/fuse co -P fuse
 cd fuse
 ./makeconf.sh
 ./configure
 make
 make -C test

- in one shell:
 mkdir /tmp/fuse
 example/fusexmp_fh -d /tmp/fuse

- in another shell:
 mkdir /tmp/test
 test/test /tmp/fuse/tmp/test

The result is normally a completed run with "1 tests failed".  On
2.6.23-mm1, it just hangs after the first test.

I've only tried under UML, but since Rick is seeing it on real HW, I
guess this method may work there as well.

Miklos

Re: futex strangeness in 2.6.23-mm1/UML

[Pavel Emelyanov]

Miklos Szeredi wrote:
>> I guess we can debug it in the old-fashioned ways.  The first of which is
>> to palm the problem off on Pavel ;)

I look at the 2.6.23-mm1 and see that there's one hunk lost. This
is the one Oleg re-sent some days ago (the mail thread subject was
2.6.23-mm1 thread exit_group issue). Here it is (sent 13 oct 2007):

--- kernel/fork.c~	2007-10-13 15:41:35.000000000 +0400
+++ kernel/fork.c	2007-10-13 15:41:41.000000000 +0400
@@ -1443,6 +1443,9 @@ long do_fork(unsigned long clone_flags,
 			task_pid_nr_ns(p, current->nsproxy->pid_ns) :
 				task_pid_vnr(p);
 
+		if (clone_flags & CLONE_PARENT_SETTID)
+			put_user(nr, parent_tidptr);
+
 		if (clone_flags & CLONE_VFORK) {
 			p->vfork_done = &vfork;
 			init_completion(&vfork);

Please, try with this patch.

>> I don't recall seeing a simple step-by-step way by which others can
>> reproduce this?
> 
> My method is this:
> 
> - enable CONFIG_FUSE_FS
> - compile fuse from CVS:
>  cvs -d:pserver:anonymous@fuse.cvs.sourceforge.net:/cvsroot/fuse co -P fuse
>  cd fuse
>  ./makeconf.sh
>  ./configure
>  make
>  make -C test
> 
> - in one shell:
>  mkdir /tmp/fuse
>  example/fusexmp_fh -d /tmp/fuse
> 
> - in another shell:
>  mkdir /tmp/test
>  test/test /tmp/fuse/tmp/test
> 
> The result is normally a completed run with "1 tests failed".  On
> 2.6.23-mm1, it just hangs after the first test.
> 
> I've only tried under UML, but since Rick is seeing it on real HW, I
> guess this method may work there as well.
> 
> Miklos
> -
> 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/
> 

Re: futex strangeness in 2.6.23-mm1/UML

[Miklos Szeredi]

> >> I guess we can debug it in the old-fashioned ways.  The first of which is
> >> to palm the problem off on Pavel ;)
> 
> I look at the 2.6.23-mm1 and see that there's one hunk lost. This
> is the one Oleg re-sent some days ago (the mail thread subject was
> 2.6.23-mm1 thread exit_group issue). Here it is (sent 13 oct 2007):
> 
> --- kernel/fork.c~	2007-10-13 15:41:35.000000000 +0400
> +++ kernel/fork.c	2007-10-13 15:41:41.000000000 +0400
> @@ -1443,6 +1443,9 @@ long do_fork(unsigned long clone_flags,
>  			task_pid_nr_ns(p, current->nsproxy->pid_ns) :
>  				task_pid_vnr(p);
>  
> +		if (clone_flags & CLONE_PARENT_SETTID)
> +			put_user(nr, parent_tidptr);
> +
>  		if (clone_flags & CLONE_VFORK) {
>  			p->vfork_done = &vfork;
>  			init_completion(&vfork);
> 
> Please, try with this patch.

Thanks.  This patch does indeed seem to solve the problem.

Miklos

Re: futex strangeness in 2.6.23-mm1/UML

[Rik van Riel]

On Tue, 23 Oct 2007 12:55:44 +0400
Pavel Emelyanov <xemul@openvz.org> wrote:

> I look at the 2.6.23-mm1 and see that there's one hunk lost. This
> is the one Oleg re-sent some days ago (the mail thread subject was
> 2.6.23-mm1 thread exit_group issue). Here it is (sent 13 oct 2007):
> 
> --- kernel/fork.c~	2007-10-13 15:41:35.000000000 +0400
> +++ kernel/fork.c	2007-10-13 15:41:41.000000000 +0400
> @@ -1443,6 +1443,9 @@ long do_fork(unsigned long clone_flags,
>  			task_pid_nr_ns(p, current->nsproxy->pid_ns) :
>  				task_pid_vnr(p);
>  
> +		if (clone_flags & CLONE_PARENT_SETTID)
> +			put_user(nr, parent_tidptr);
> +
>  		if (clone_flags & CLONE_VFORK) {
>  			p->vfork_done = &vfork;
>  			init_completion(&vfork);
> 
> Please, try with this patch.

The patch above fixes the issue for me.

Autofs works again as expected.

-- 
"Debugging is twice as hard as writing the code in the first place.
Therefore, if you write the code as cleverly as possible, you are,
by definition, not smart enough to debug it." - Brian W. Kernighan

Re: futex strangeness in 2.6.23-mm1/UML

[Andrew Morton]

On Tue, 23 Oct 2007 09:52:08 -0400 Rik van Riel <riel@redhat.com> wrote:

> On Tue, 23 Oct 2007 12:55:44 +0400
> Pavel Emelyanov <xemul@openvz.org> wrote:
> 
> > I look at the 2.6.23-mm1 and see that there's one hunk lost. This
> > is the one Oleg re-sent some days ago (the mail thread subject was
> > 2.6.23-mm1 thread exit_group issue). Here it is (sent 13 oct 2007):
> > 
> > --- kernel/fork.c~	2007-10-13 15:41:35.000000000 +0400
> > +++ kernel/fork.c	2007-10-13 15:41:41.000000000 +0400
> > @@ -1443,6 +1443,9 @@ long do_fork(unsigned long clone_flags,
> >  			task_pid_nr_ns(p, current->nsproxy->pid_ns) :
> >  				task_pid_vnr(p);
> >  
> > +		if (clone_flags & CLONE_PARENT_SETTID)
> > +			put_user(nr, parent_tidptr);
> > +
> >  		if (clone_flags & CLONE_VFORK) {
> >  			p->vfork_done = &vfork;
> >  			init_completion(&vfork);
> > 
> > Please, try with this patch.
> 
> The patch above fixes the issue for me.
> 
> Autofs works again as expected.

argh.  Sorry guys, I'd completely forgotten that that bug was present in
-mm1 and I didn't upload the fix into hot-fixes/.  Bad me.