Bug 128981

Summary: autofs in 10.0 hangs trying to mount NFS volume. Error: aquire_lock: can't lock lock file timed out: /var/lock/autofs
Product: [openSUSE] SUSE LINUX 10.0 Reporter: Rainer Krienke <krienke>
Component: BasesystemAssignee: Chris L Mason <mason>
Status: RESOLVED INVALID QA Contact: E-mail List <qa-bugs>
Severity: Critical    
Priority: P5 - None    
Version: Final   
Target Milestone: ---   
Hardware: 32bit   
OS: SuSE Linux 10.0   
Whiteboard:
Found By: System Test Services Priority:
Business Priority: Blocker: ---
Marketing QA Status: --- IT Deployment: ---

Description Rainer Krienke 2005-10-18 10:58:54 UTC
Using the autofs package from suse10.0 (autofs-4.1.4-6.i586.rpm; autofs4  
kernel module) NFS mounts of user directories fail when using indirect mounts.  
The maps are taken from   
NIS. To mount a users directory via NFS eg. /home/krienke on a client entries 
from the NIS-maps auto.home and auto.vol are used.  auto.master is   
configured like this:   
   
/home auto.home         -intr   
/import auto.vol        -intr   
   
In auto.home there is this entry for each user like "krienke":   
   
krienke localhost:/import/user2/krienke   
   
In auto.vol you find another entry to handle the "user2" key starting 
at /import from above:   
   
user2 nfssrv2:/export/user2   
   
nfssrv2 ist one of our NFS servers for home directories. So basically we nfs 
mount a volume containing all the users on the client   
in /import/user2 and then we mount /home/krienke on /import/user2/krienke on   
the client (the advantage of this indirect 2 layer mount is that we avoid 
problems with too many mounts for users on one client since bind mounts are 
used for the users home). This mount was (up to 9.3) automatically mounted as 
a bind mount by automount. Up to suse9.3 this worked without problems and if I 
replace the suse10 autofs rpm by the suse9.3 autofs4 rpm it again does work. I 
can also manuall yissue the mount command logged by atomunt below (mount -t 
nfs -s  -o intr nfssrv2:/export/user2 /import/user2) and it works without any 
problems.  
    
When trying to mount a user like "krienke" the following log appears  
in /var/log/messages /autmount is running with -d -v):  
  
Oct 18 12:41:59 rzinstal1 automount[16770]: handle_packet: type = 0  
Oct 18 12:41:59 rzinstal1 automount[16770]: handle_packet_missing: token 49,  
name krienke  
Oct 18 12:41:59 rzinstal1 automount[16770]: attempting to mount  
entry /home/krienke  
Oct 18 12:41:59 rzinstal1 automount[16791]: lookup(yp): looking up krienke  
Oct 18 12:41:59 rzinstal1 automount[16791]: ret = 1  
Oct 18 12:41:59 rzinstal1 automount[16791]: lookup(yp): krienke ->  
localhost:/import/user2/krienke  
Oct 18 12:41:59 rzinstal1 automount[16791]: parse(sun): expanded entry:  
localhost:/import/user2/krienke  
Oct 18 12:41:59 rzinstal1 automount[16791]: parse(sun): gathered options: intr  
Oct 18 12:41:59 rzinstal1 automount[16791]: parse(sun):  
dequote("localhost:/import/user2/krienke") -> localhost:/import/user2/krienke  
Oct 18 12:41:59 rzinstal1 automount[16791]: parse(sun): core of entry:  
options=intr, loc=localhost:/import/user2/krienke  
Oct 18 12:41:59 rzinstal1 automount[16791]: parse(sun): mounting root /home,  
mountpoint krienke, what localhost:/import/user2/krienke, fstype nfs,  
Oct 18 12:41:59 rzinstal1 automount[16791]: mount(nfs): root=/home  
name=krienke what=localhost:/import/user2/krienke, fstype=nfs, options=intr  
Oct 18 12:41:59 rzinstal1 automount[16791]: mount(nfs): nfs options="intr",  
nosymlink=0, ro=0  
Oct 18 12:41:59 rzinstal1 automount[16791]: mount(nfs): winner = localhost  
local = 1  
Oct 18 12:41:59 rzinstal1 automount[16791]: mount(nfs): from  
localhost:/import/user2/krienke elected /import/user2/krienke  
Oct 18 12:41:59 rzinstal1 automount[16791]: mount(nfs): krienke is local,  
doing bind  
Oct 18 12:41:59 rzinstal1 automount[16791]: mount(bind): calling  
mkdir_path /home/krienke  
Oct 18 12:41:59 rzinstal1 automount[16791]: mount(bind): calling mount --bind  
-s  -o defaults /import/user2/krienke /home/krienke  
Oct 18 12:41:59 rzinstal1 automount[16772]: handle_packet: type = 0  
Oct 18 12:41:59 rzinstal1 automount[16772]: handle_packet_missing: token 50,  
name user2  
Oct 18 12:41:59 rzinstal1 automount[16772]: attempting to mount  
entry /import/user2  
Oct 18 12:41:59 rzinstal1 automount[16793]: lookup(yp): looking up user2  
Oct 18 12:41:59 rzinstal1 automount[16793]: ret = 1  
Oct 18 12:41:59 rzinstal1 automount[16793]: lookup(yp): user2 ->  
nfssrv2:/export/user2  
Oct 18 12:41:59 rzinstal1 automount[16793]: parse(sun): expanded entry:  
nfssrv2:/export/user2  
Oct 18 12:41:59 rzinstal1 automount[16793]: parse(sun): gathered options: intr  
Oct 18 12:41:59 rzinstal1 automount[16793]: parse(sun):  
dequote("nfssrv2:/export/user2") -> nfssrv2:/export/user2  
Oct 18 12:41:59 rzinstal1 automount[16793]: parse(sun): core of entry:  
options=intr, loc=nfssrv2:/export/user2  
Oct 18 12:41:59 rzinstal1 automount[16793]: parse(sun): mounting root /import,  
mountpoint user2, what nfssrv2:/export/user2, fstype nfs, options intr  
Oct 18 12:41:59 rzinstal1 automount[16793]: mount(nfs): root=/import  
name=user2 what=nfssrv2:/export/user2, fstype=nfs, options=intr  
Oct 18 12:41:59 rzinstal1 automount[16793]: mount(nfs): nfs options="intr",  
nosymlink=0, ro=0  
Oct 18 12:41:59 rzinstal1 automount[16793]: mount(nfs): winner = nfssrv2 local  
= 0  
Oct 18 12:41:59 rzinstal1 automount[16793]: mount(nfs): from  
nfssrv2:/export/user2 elected nfssrv2:/export/user2  
Oct 18 12:41:59 rzinstal1 automount[16793]: mount(nfs): calling  
mkdir_path /import/user2  
Oct 18 12:41:59 rzinstal1 automount[16793]: mount(nfs): calling mount -t nfs  
-s  -o intr nfssrv2:/export/user2 /import/user2  
Oct 18 12:42:30 rzinstal1 automount[16793]: aquire_lock: can't lock lock file  
timed out: /var/lock/autofs  
Oct 18 12:42:30 rzinstal1 automount[16793]: mount(nfs): nfs: mount failure  
nfssrv2:/export/user2 on /import/user2  
Oct 18 12:42:30 rzinstal1 automount[16793]: failed to mount /import/user2  
Oct 18 12:42:30 rzinstal1 automount[16793]: umount_multi: path=/import/user2  
incl=1  
Oct 18 12:42:30 rzinstal1 automount[16793]: umount_multi: no mounts found  
under /import/user2  
Oct 18 12:42:30 rzinstal1 automount[16772]: handle_child: got pid 16793, sig 0  
(0), stat 1  
Oct 18 12:42:30 rzinstal1 automount[16772]: sig_child: found pending iop pid  
16793: signalled 0 (sig 0), exit status 1  
Oct 18 12:42:30 rzinstal1 automount[16772]: send_fail: token=50  
  
Then after 2 more retries to mount /import/user2 the whole mount fails.  
  
Oct 18 12:44:04 rzinstal1 automount[16798]: aquire_lock: can't lock lock file  
timed out: /var/lock/autofs  
Oct 18 12:44:04 rzinstal1 automount[16798]: mount(nfs): nfs: mount failure  
nfssrv2:/export/user2 on /import/user2  
Oct 18 12:44:04 rzinstal1 automount[16798]: failed to mount /import/user2  
Oct 18 12:44:04 rzinstal1 automount[16798]: umount_multi: path=/import/user2  
incl=1  
Oct 18 12:44:04 rzinstal1 automount[16798]: umount_multi: no mounts found  
under /import/user2  
Oct 18 12:44:04 rzinstal1 automount[16772]: handle_child: got pid 16798, sig 0  
(0), stat 1  
Oct 18 12:44:04 rzinstal1 automount[16772]: sig_child: found pending iop pid  
16798: signalled 0 (sig 0), exit status 1  
Oct 18 12:44:04 rzinstal1 automount[16772]: send_fail: token=54  
Oct 18 12:44:04 rzinstal1 automount[16795]: >> mount: special  
device /import/user2/krienke does not exist  
Oct 18 12:44:04 rzinstal1 automount[16795]: failed to mount /home/krienke  
Oct 18 12:44:04 rzinstal1 automount[16795]: umount_multi: path=/home/krienke  
incl=1  
Oct 18 12:44:04 rzinstal1 automount[16795]: umount_multi: no mounts found  
under /home/krienke  
Oct 18 12:44:04 rzinstal1 automount[16770]: handle_child: got pid 16795, sig 0  
(0), stat 1  
Oct 18 12:44:04 rzinstal1 automount[16770]: sig_child: found pending iop pid  
16795: signalled 0 (sig 0), exit status 1  
Oct 18 12:44:04 rzinstal1 automount[16770]: send_fail: token=52
Comment 1 Aart de Vries 2005-10-19 21:52:45 UTC
I don't know for sure, but maybe this is due to the nfs file locking problem already identified in bug 128784. Neil Brown (nfbrown@novell.com) is already on that one, but his first patch did introduce a nfsd crash due to a NULL pointer exception.
Comment 2 Rainer Krienke 2005-10-20 06:19:01 UTC
I posted this bug description as well in the autofs mailinglist and got two replies. One from Ian Kent and one from Jim Carter. The key part of the answer is that this is due to a change in the internal locking system of autofs in 4.1.4. The locking now works better and this causes the touble in this case:
Citing Jim Carter, this happens:

-----Jim:-----------
Now that's a very neat solution to the problem of too many incoming / 
outgoing mounts.  But unfortunately you're doing the following sequence:

User refers to /home/krienke
Autofs starts to mount /import/homesite/fsys/krienke, stats 
/import/homesite/fsys
second autofs thread starts to mount homesite:/export/fsys
Oops, an autofs thread has the lock, 2nd thread either blocks
waiting for the lock, or dies.  (The latter, judging from
timestamps.)
----------------------

At the moment its unclear if this sort of hierachical mounts will be supported or not. I still hope they will ...

Rainer
Comment 3 Greg Kroah-Hartman 2006-08-14 07:07:25 UTC
Closed due to inactivity.