automount subprocesses accumulate

automount subprocesses accumulate

[Cyril B.]

Hello,

I've been using autofs for a long time to mount NFS servers under /nfs, 
and recently started using it for mounting /home subdirectories as well 
(which point on /nfs/).

Since I've started automounting /home, I have automount subprocesses 
accumulating and never exiting:

root 1761264 0.0 0.0 205416 1478 ? Ssl 14:06 0:00 /usr/sbin/automount 
--pid-file /var/run/autofs.pid
root 1966587 0.0 0.0 209816 1564 ? S 14:45 0:00 \_ /usr/sbin/automount 
--pid-file /var/run/autofs.pid
root 2023507 0.0 0.0 209816 1652 ? S 15:00 0:00 \_ /usr/sbin/automount 
--pid-file /var/run/autofs.pid
root 2203212 0.0 0.0 215100 1900 ? S 15:45 0:00 \_ /usr/sbin/automount 
--pid-file /var/run/autofs.pid

My main automount was started at 14:06, and all subprocesses are stuck in a:

futex(0x56122035a5a0, FUTEX_WAIT_PRIVATE, 2, NULL

(same futex address for all of them).

There are typically a few new subprocesses each hour. I've already seen 
up to 20/25 subprocesses before I had to restart automount and kill them 
manually.

I have a lot of users on this server, so automount is serving many 
requests. Especially at round times (14:00, 14:15, 14:30, etc.), when 
cron starts many user processes. According to automount debug logs, up 
to 20 new home subdirectories can be mounted every second.

I'm using autofs 5.1.1 on Linux 4.1.4. My config:

/etc/auto.master:
--
/nfs program:/etc/auto.nfs
/home program:/etc/auto.home
--

/etc/auto.nfs is pretty standard, has been working fine for ages. It's 
basically returning:

-fstype=nfs4,noatime,nosuid,_netdev,soft,intr,timeo=1000 $1:/

/etc/auto.home:
--
#!/bin/sh

if [ ! -h /var/home/$1 ]
then
   exit 1
fi

echo -fstype=bind :$(readlink --no-newline /var/home/$1)
--

So for instance, /var/home/foo would be a symlink pointing to 
/nfs/serverX/foo.

autofs is compiled with --disable-mount-locking as recursive mounting 
wouldn't work otherwise.

Thanks!

-- 
Cyril B.
--
To unsubscribe from this list: send the line "unsubscribe autofs" in

Re: automount subprocesses accumulate

[Ian Kent]

On Thu, 2015-09-10 at 16:43 +0200, Cyril B. wrote:
> Hello,
> 
> I've been using autofs for a long time to mount NFS servers under /nfs, 
> and recently started using it for mounting /home subdirectories as well 
> (which point on /nfs/).
> 
> Since I've started automounting /home, I have automount subprocesses 
> accumulating and never exiting:
> 
> root 1761264 0.0 0.0 205416 1478 ? Ssl 14:06 0:00 /usr/sbin/automount 
> --pid-file /var/run/autofs.pid
> root 1966587 0.0 0.0 209816 1564 ? S 14:45 0:00 \_ /usr/sbin/automount 
> --pid-file /var/run/autofs.pid
> root 2023507 0.0 0.0 209816 1652 ? S 15:00 0:00 \_ /usr/sbin/automount 
> --pid-file /var/run/autofs.pid
> root 2203212 0.0 0.0 215100 1900 ? S 15:45 0:00 \_ /usr/sbin/automount 
> --pid-file /var/run/autofs.pid

Yeah, that's odd.

> 
> My main automount was started at 14:06, and all subprocesses are stuck in a:
> 
> futex(0x56122035a5a0, FUTEX_WAIT_PRIVATE, 2, NULL
> 
> (same futex address for all of them).

Can you get a meaningful (that is with symbols, line numbers etc.) of
each of these processes and post it.

> 
> There are typically a few new subprocesses each hour. I've already seen 
> up to 20/25 subprocesses before I had to restart automount and kill them 
> manually.
> 
> I have a lot of users on this server, so automount is serving many 
> requests. Especially at round times (14:00, 14:15, 14:30, etc.), when 
> cron starts many user processes. According to automount debug logs, up 
> to 20 new home subdirectories can be mounted every second.

Yeah, that's quite a few, maybe your triggering a race with the thread
creation. I've spent a lot of time on that and thought it worked ok ...

Do you have reports from users of mounts hanging on access?

> 
> I'm using autofs 5.1.1 on Linux 4.1.4. My config:
> 
> /etc/auto.master:
> --
> /nfs program:/etc/auto.nfs
> /home program:/etc/auto.home
> --
> 
> /etc/auto.nfs is pretty standard, has been working fine for ages. It's 
> basically returning:
> 
> -fstype=nfs4,noatime,nosuid,_netdev,soft,intr,timeo=1000 $1:/
> 
> /etc/auto.home:
> --
> #!/bin/sh
> 
> if [ ! -h /var/home/$1 ]
> then
>    exit 1
> fi
> 
> echo -fstype=bind :$(readlink --no-newline /var/home/$1)
> --
> 
> So for instance, /var/home/foo would be a symlink pointing to 
> /nfs/serverX/foo.

So your bind mounting to an automounted nfs mount.
Not sure that's wise but probably should be ok.

I guess we need to look at the full debug log.
Can you post it somewhere or mail it to me privately please.

Ian

--
To unsubscribe from this list: send the line "unsubscribe autofs" in

Re: automount subprocesses accumulate

[Cyril B.]

Hello Ian,

Thanks for the quick response. I was able to reliably reproduce the 
deadlock on a test server with a test script that triggers many 
simultaneous mounts. On this setup /home is replaced with /mnt.

Ian Kent wrote:
> Can you get a meaningful (that is with symbols, line numbers etc.) of
> each of these processes and post it.

root     17937  0.5  0.0 1068324 3172 pts/0    Sl+  17:04   0:00  | 
   \_ /root/autofs/install/usr/sbin/automount -f -d
root     18503  0.0  0.0 1068308 1688 pts/0    S+   17:04   0:00  | 
       \_ /root/autofs/install/usr/sbin/automount -f -d

PID 17937:

#0  do_sigwait (set=<optimized out>, sig=0x7ffdf4e414fc) at 
../nptl/sysdeps/unix/sysv/linux/../../../../../sysdeps/unix/sysv/linux/sigwait.c:63
#1  0x00007fda9c209693 in __sigwait (set=0x7ffdf4e41500, sig=0x0) at 
../nptl/sysdeps/unix/sysv/linux/../../../../../sysdeps/unix/sysv/linux/sigwait.c:97
#2  0x00007fda9c6478a9 in statemachine (arg=0x0) at automount.c:1430
#3  0x00007fda9c6499d4 in main (argc=0, argv=0x7ffdf4e41750) at 
automount.c:2419

PID 18503:

#0  __lll_lock_wait () at 
../nptl/sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:135
#1  0x00007fda9c2044b9 in _L_lock_909 () from 
/lib/x86_64-linux-gnu/libpthread.so.0
#2  0x00007fda9c2042e0 in __GI___pthread_mutex_lock 
(mutex=0x7fda9c88d8e0 <conf_mutex>) at ../nptl/pthread_mutex_lock.c:79
#3  0x00007fda9c66dfb0 in defaults_mutex_lock () at defaults.c:178
#4  0x00007fda9c670442 in conf_get_yesno (section=0x7fda9c67f454 
"autofs", name=0x7fda9c67fba0 "force_standard_program_map_env") at 
defaults.c:1202
#5  0x00007fda9c6706fa in defaults_force_std_prog_map_env () at 
defaults.c:1598
#6  0x00007fda9b00a4e6 in lookup_one (ap=0x7fda9d547790, 
name=0x7fda60000b00 "agloper", name_len=7, ctxt=0x7fda8c000950) at 
lookup_program.c:184
#7  0x00007fda9b00adce in match_key (ap=0x7fda9d547790, 
source=0x7fda9d5478a0, name=0x7fda98b59ef0 "agloper", name_len=7, 
mapent=0x7fda98b58b58,
     ctxt=0x7fda8c000950) at lookup_program.c:432
#8  0x00007fda9b00b672 in lookup_mount (ap=0x7fda9d547790, 
name=0x7fda98b59ef0 "agloper", name_len=7, context=0x7fda8c000950) at 
lookup_program.c:621
#9  0x00007fda9c656101 in do_lookup_mount (ap=0x7fda9d547790, 
map=0x7fda9d5478a0, name=0x7fda98b59ef0 "agloper", name_len=7) at 
lookup.c:800
#10 0x00007fda9c656800 in do_name_lookup_mount (ap=0x7fda9d547790, 
map=0x7fda9d5478a0, name=0x7fda98b59ef0 "agloper", name_len=7) at 
lookup.c:960
#11 0x00007fda9c656e8a in lookup_nss_mount (ap=0x7fda9d547790, 
source=0x0, name=0x7fda98b59ef0 "agloper", name_len=7) at lookup.c:1136
#12 0x00007fda9c64bf1e in do_mount_indirect (arg=0x7fda8c003ce0) at 
indirect.c:772
#13 0x00007fda9c2020a4 in start_thread (arg=0x7fda98b5b700) at 
pthread_create.c:309
#14 0x00007fda9bb1b04d in clone () at 
../sysdeps/unix/sysv/linux/x86_64/clone.S:111

I can still mount new user directories at this point (cd /mnt/foo works 
fine).

> Do you have reports from users of mounts hanging on access?

At one point trying to mount any new user directory would just freeze. 
I'm not sure that's related.


> I guess we need to look at the full debug log.
> Can you post it somewhere or mail it to me privately please.

I'll send you a link privately.

Thanks again.

-- 
Cyril B.
--
To unsubscribe from this list: send the line "unsubscribe autofs" in

Re: automount subprocesses accumulate

[Ian Kent]

On Fri, 2015-09-11 at 17:14 +0200, Cyril B. wrote:
> Hello Ian,
> 
> Thanks for the quick response. I was able to reliably reproduce the 
> deadlock on a test server with a test script that triggers many 
> simultaneous mounts. On this setup /home is replaced with /mnt.

Yes, it's a puzzle.

The default.c module looks like there's no possibility of a deadlock.
It's fairly simple and there is no place where the mutex isn't released
before return and there are no other calls are made that could take
other locks that could introduce a deadlock.

It occurred to me that the call to force_standard_program_map_env() is
out probably out of order.

It's made after the fork() that's used to exec the program map code.

I think the child is seeing the state of the mutex at the time of the
fork and if the mutex was locked at that time the child process will
never see it unlocked since the forked process copy will not see that
change.

That's just a guess, so let me put together a patch for you to try.
Are you in a position to be able to apply and build autofs to test?

> 
> Ian Kent wrote:
> > Can you get a meaningful (that is with symbols, line numbers etc.) of
> > each of these processes and post it.
> 
> root     17937  0.5  0.0 1068324 3172 pts/0    Sl+  17:04   0:00  | 
>    \_ /root/autofs/install/usr/sbin/automount -f -d
> root     18503  0.0  0.0 1068308 1688 pts/0    S+   17:04   0:00  | 
>        \_ /root/autofs/install/usr/sbin/automount -f -d
> 
> PID 17937:
> 
> #0  do_sigwait (set=<optimized out>, sig=0x7ffdf4e414fc) at 
> ../nptl/sysdeps/unix/sysv/linux/../../../../../sysdeps/unix/sysv/linux/sigwait.c:63
> #1  0x00007fda9c209693 in __sigwait (set=0x7ffdf4e41500, sig=0x0) at 
> ../nptl/sysdeps/unix/sysv/linux/../../../../../sysdeps/unix/sysv/linux/sigwait.c:97
> #2  0x00007fda9c6478a9 in statemachine (arg=0x0) at automount.c:1430
> #3  0x00007fda9c6499d4 in main (argc=0, argv=0x7ffdf4e41750) at 
> automount.c:2419
> 
> PID 18503:
> 
> #0  __lll_lock_wait () at 
> ../nptl/sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:135
> #1  0x00007fda9c2044b9 in _L_lock_909 () from 
> /lib/x86_64-linux-gnu/libpthread.so.0
> #2  0x00007fda9c2042e0 in __GI___pthread_mutex_lock 
> (mutex=0x7fda9c88d8e0 <conf_mutex>) at ../nptl/pthread_mutex_lock.c:79
> #3  0x00007fda9c66dfb0 in defaults_mutex_lock () at defaults.c:178
> #4  0x00007fda9c670442 in conf_get_yesno (section=0x7fda9c67f454 
> "autofs", name=0x7fda9c67fba0 "force_standard_program_map_env") at 
> defaults.c:1202
> #5  0x00007fda9c6706fa in defaults_force_std_prog_map_env () at 
> defaults.c:1598
> #6  0x00007fda9b00a4e6 in lookup_one (ap=0x7fda9d547790, 
> name=0x7fda60000b00 "agloper", name_len=7, ctxt=0x7fda8c000950) at 
> lookup_program.c:184
> #7  0x00007fda9b00adce in match_key (ap=0x7fda9d547790, 
> source=0x7fda9d5478a0, name=0x7fda98b59ef0 "agloper", name_len=7, 
> mapent=0x7fda98b58b58,
>      ctxt=0x7fda8c000950) at lookup_program.c:432
> #8  0x00007fda9b00b672 in lookup_mount (ap=0x7fda9d547790, 
> name=0x7fda98b59ef0 "agloper", name_len=7, context=0x7fda8c000950) at 
> lookup_program.c:621
> #9  0x00007fda9c656101 in do_lookup_mount (ap=0x7fda9d547790, 
> map=0x7fda9d5478a0, name=0x7fda98b59ef0 "agloper", name_len=7) at 
> lookup.c:800
> #10 0x00007fda9c656800 in do_name_lookup_mount (ap=0x7fda9d547790, 
> map=0x7fda9d5478a0, name=0x7fda98b59ef0 "agloper", name_len=7) at 
> lookup.c:960
> #11 0x00007fda9c656e8a in lookup_nss_mount (ap=0x7fda9d547790, 
> source=0x0, name=0x7fda98b59ef0 "agloper", name_len=7) at lookup.c:1136
> #12 0x00007fda9c64bf1e in do_mount_indirect (arg=0x7fda8c003ce0) at 
> indirect.c:772
> #13 0x00007fda9c2020a4 in start_thread (arg=0x7fda98b5b700) at 
> pthread_create.c:309
> #14 0x00007fda9bb1b04d in clone () at 
> ../sysdeps/unix/sysv/linux/x86_64/clone.S:111
> 
> I can still mount new user directories at this point (cd /mnt/foo works 
> fine).
> 
> > Do you have reports from users of mounts hanging on access?
> 
> At one point trying to mount any new user directory would just freeze. 
> I'm not sure that's related.
> 
> 
> > I guess we need to look at the full debug log.
> > Can you post it somewhere or mail it to me privately please.
> 
> I'll send you a link privately.
> 
> Thanks again.
> 


--
To unsubscribe from this list: send the line "unsubscribe autofs" in

Re: automount subprocesses accumulate

[Cyril B.]

Ian Kent wrote:
> On Fri, 2015-09-11 at 17:14 +0200, Cyril B. wrote:
>> >  Hello Ian,
>> >
>> >  Thanks for the quick response. I was able to reliably reproduce the
>> >  deadlock on a test server with a test script that triggers many
>> >  simultaneous mounts. On this setup /home is replaced with /mnt.
>
> Yes, it's a puzzle.
>
> The default.c module looks like there's no possibility of a deadlock.
> It's fairly simple and there is no place where the mutex isn't released
> before return and there are no other calls are made that could take
> other locks that could introduce a deadlock.
>
> It occurred to me that the call to force_standard_program_map_env() is
> out probably out of order.
>
> It's made after the fork() that's used to exec the program map code.
>
> I think the child is seeing the state of the mutex at the time of the
> fork and if the mutex was locked at that time the child process will
> never see it unlocked since the forked process copy will not see that
> change.
>
> That's just a guess, so let me put together a patch for you to try.
> Are you in a position to be able to apply and build autofs to test?

Sure, I can test as much as I want. I guess I could probably even setup 
a test VM that reproduces the issue and give you root credentials if it 
helps.

-- 
Cyril B.
--
To unsubscribe from this list: send the line "unsubscribe autofs" in

Re: automount subprocesses accumulate

[Ian Kent]

On Sun, 2015-09-13 at 13:20 +0200, Cyril B. wrote:
> Ian Kent wrote:
> > On Fri, 2015-09-11 at 17:14 +0200, Cyril B. wrote:
> >> >  Hello Ian,
> >> >
> >> >  Thanks for the quick response. I was able to reliably reproduce the
> >> >  deadlock on a test server with a test script that triggers many
> >> >  simultaneous mounts. On this setup /home is replaced with /mnt.
> >
> > Yes, it's a puzzle.
> >
> > The default.c module looks like there's no possibility of a deadlock.
> > It's fairly simple and there is no place where the mutex isn't released
> > before return and there are no other calls are made that could take
> > other locks that could introduce a deadlock.
> >
> > It occurred to me that the call to force_standard_program_map_env() is
> > out probably out of order.
> >
> > It's made after the fork() that's used to exec the program map code.
> >
> > I think the child is seeing the state of the mutex at the time of the
> > fork and if the mutex was locked at that time the child process will
> > never see it unlocked since the forked process copy will not see that
> > change.
> >
> > That's just a guess, so let me put together a patch for you to try.
> > Are you in a position to be able to apply and build autofs to test?
> 
> Sure, I can test as much as I want. I guess I could probably even setup 
> a test VM that reproduces the issue and give you root credentials if it 
> helps.
> 

OK, see if you can apply this patch.
The CHANGELOG hunk won't apply, of course, so just ignore the reject or
delete the hunk from the patch before applying it.

Umm ... now I see I need to fix a couple of spelling mistakes as
well, ;)

autofs-5.1.1 - fix out of order call in program map lookup

From: Ian Kent <raven@themaw.net>

Commit 91e42e58b4 fixed a problem with program map environment variable
nameing and commit 743deb0e4e added a configuration option to force use
of the old environment names for those who need it and are sure it is
safe to continue to use them.

But the call to get the configuration entry was placed after a fork()
so the state of the mutex used when querying the configuration is
undefined and can lead to a dedlock.

Signed-off-by: Ian Kent <raven@themaw.net>
---
 CHANGELOG                |    1 +
 modules/lookup_program.c |   20 ++++++++++----------
 2 files changed, 11 insertions(+), 10 deletions(-)

diff --git a/CHANGELOG b/CHANGELOG
index 4430c39..357d201 100644
--- a/CHANGELOG
+++ b/CHANGELOG
@@ -1,6 +1,7 @@
 ??/??/2015 autofs-5.1.2
 =======================
 - fix left mount count return from umount_multi_triggers().
+- fix out of order call in program map lookup.
 
 21/04/2015 autofs-5.1.1
 =======================
diff --git a/modules/lookup_program.c b/modules/lookup_program.c
index a3a7e98..67d4c47 100644
--- a/modules/lookup_program.c
+++ b/modules/lookup_program.c
@@ -139,6 +139,16 @@ static char *lookup_one(struct autofs_point *ap,
 	}
 
 	/*
+	 * By default use a prefix with standard environment
+	 * variables to prevent system subversion by interpreted
+	 * languages.
+	 */
+	if (defaults_force_std_prog_map_env())
+		prefix = NULL;
+	else
+		prefix = "AUTOFS_";
+
+	/*
 	 * We don't use popen because we don't want to run /bin/sh plus we
 	 * want to send stderr to the syslog, and we don't use spawnl()
 	 * because we need the pipe hooks
@@ -177,16 +187,6 @@ static char *lookup_one(struct autofs_point *ap,
 			     ap->path, ctxt->mapname);
 
 		/*
-		 * By default use a prefix with standard environment
-		 * variables to prevent system subversion by interpreted
-		 * languages.
-		 */
-		if (defaults_force_std_prog_map_env())
-			prefix = NULL;
-		else
-			prefix = "AUTOFS_";
-
-		/*
 		 * MAPFMT_DEFAULT must be "sun" for ->parse_init() to have setup
 		 * the macro table.
 		 */


--
To unsubscribe from this list: send the line "unsubscribe autofs" in

Re: automount subprocesses accumulate

[Cyril B.]

Ian Kent wrote:
> OK, see if you can apply this patch.
> The CHANGELOG hunk won't apply, of course, so just ignore the reject or
> delete the hunk from the patch before applying it.
>
> Umm ... now I see I need to fix a couple of spelling mistakes as
> well,;)


It looks like it fixes the bug indeed! At least I'm unable to reproduce 
it on my test environment.

I'll deploy that version on my production server today, I'll let you 
know how it goes.

Thank you!

-- 
Cyril B.
--
To unsubscribe from this list: send the line "unsubscribe autofs" in

Re: automount subprocesses accumulate

[Cyril B.]

Cyril B. wrote:
> I'll deploy that version on my production server today, I'll let you
> know how it goes.

It's been running for several hours with no problem. Your patch 
definitely fixed the deadlock.

-- 
Cyril B.
--
To unsubscribe from this list: send the line "unsubscribe autofs" in

Re: automount subprocesses accumulate

[Ian Kent]

On Sun, 2015-09-13 at 14:05 +0200, Cyril B. wrote:
> Ian Kent wrote:
> > OK, see if you can apply this patch.
> > The CHANGELOG hunk won't apply, of course, so just ignore the reject or
> > delete the hunk from the patch before applying it.
> >
> > Umm ... now I see I need to fix a couple of spelling mistakes as
> > well,;)
> 
> 
> It looks like it fixes the bug indeed! At least I'm unable to reproduce 
> it on my test environment.

Sounds promising.

> 
> I'll deploy that version on my production server today, I'll let you 
> know how it goes.

OK, assuming it goes well, I have a bunch of other patches but I'm still
not sure they're ready to be committed upstream. I'll work through those
to work out what I can commit so I can make those (including this)
available in the repo and as a patch on kernel.org.

> 
> Thank you!
> 

My pleasure.
Ian

--
To unsubscribe from this list: send the line "unsubscribe autofs" in