Messages in this thread | | | Date | Thu, 23 Apr 1998 17:36:26 +1000 | From | Bradley Baetz <> | Subject | Autofs bug |
| |
Yesterday my autofs system blew up:
Apr 22 18:17:29 onion automount[2405]: attempting to mount entry /mnt/dos Apr 22 18:17:33 onion automount[2405]: attempting to mount entry /mnt/dos Apr 22 18:17:33 onion automount[2657]: expired /mnt/dos Apr 22 18:18:10 onion automount[2405]: attempting to mount entry /mnt/dos Apr 22 18:18:10 onion automount[2662]: >> mount: /dev/hda1 already mounted or /mnt/dos busy Apr 22 18:18:10 onion kernel: autofs warning: lookup failure on existing dentry, status = -2, name = dos Apr 22 18:18:10 onion automount[2662]: >> mount: according to mtab, /dev/hda1 is already mounted on /mnt/dos Apr 22 18:18:10 onion automount[2662]: mount(generic): failed to mount /dev/hda1 (type vfat) on /mnt/dos Apr 22 18:18:10 onion kernel: autofs warning: lookup failure on existing dentry, status = -2, name = dos Apr 22 18:18:10 onion automount[2405]: attempting to mount entry /mnt/dos Apr 22 18:18:10 onion automount[2664]: >> mount: /dev/hda1 already mounted or /mnt/dos busy Apr 22 18:18:10 onion automount[2664]: >> mount: according to mtab, /dev/hda1 is already mounted on /mnt/dos Apr 22 18:18:10 onion automount[2664]: mount(generic): failed to mount /dev/hda1 (type vfat) on /mnt/dos
These kept repeating everytime I tried to access /mnt/dos until I restarted the system. Trying to stop the automounter through the rc scripts failed, saying that /mnt/dos was mounted. However, noticing the 2nd mount attempt happened _before_ the expiration of the first, I logged the daemon debugging messages, and tried to get it to repeat:
~# cat /mnt/dos/test; usleep 3600000; cat /mnt/dos/test
Apr 23 10:40:20 onion automount[516]: attempting to mount entry /mnt/dos Apr 23 10:40:20 onion automount[565]: lookup(file): looking up dos Apr 23 10:40:20 onion automount[565]: lookup(file): dos -> -fstype=vfat,umask=000^I:/dev/hda1 Apr 23 10:40:20 onion automount[565]: expanded entry: -fstype=vfat,umask=000^I:/dev/hda1 Apr 23 10:40:20 onion automount[565]: parse(sun): gathered options: fstype=vfat,umask=000 Apr 23 10:40:20 onion automount[565]: parse(sun): core of entry: /dev/hda1 Apr 23 10:40:20 onion automount[565]: do_mount /dev/hda1 /mnt/dos type vfat options umask=000 using module generic Apr 23 10:40:20 onion automount[565]: mount(generic): calling mkdir /mnt/dos Apr 23 10:40:20 onion automount[565]: mount(generic): calling mount -t vfat -s -o umask=000 /dev/hda1 /mnt/dos Apr 23 10:40:21 onion automount[565]: mount(generic): mounted /dev/hda1 type vfat on /mnt/dos Apr 23 10:40:24 onion automount[568]: running expiration on path /mnt Apr 23 10:40:24 onion automount[516]: attempting to mount entry /mnt/dos Apr 23 10:40:24 onion automount[571]: lookup(file): looking up dos Apr 23 10:40:24 onion automount[571]: lookup(file): dos -> -fstype=vfat,umask=000^I:/dev/hda1 Apr 23 10:40:24 onion automount[571]: expanded entry: -fstype=vfat,umask=000^I:/dev/hda1 Apr 23 10:40:24 onion automount[571]: parse(sun): gathered options: fstype=vfat,umask=000 Apr 23 10:40:24 onion automount[571]: parse(sun): core of entry: /dev/hda1 Apr 23 10:40:24 onion automount[571]: do_mount /dev/hda1 /mnt/dos type vfat options umask=000 using module generic Apr 23 10:40:24 onion automount[571]: mount(generic): calling mkdir /mnt/dos Apr 23 10:40:24 onion automount[571]: mount(generic): calling mount -t vfat -s -o umask=000 /dev/hda1 /mnt/dos Apr 23 10:40:24 onion automount[568]: expired /mnt/dos Apr 23 10:40:24 onion automount[571]: >> mount: mount point /mnt/dos does not exist Apr 23 10:40:24 onion automount[571]: mount(generic): failed to mount /dev/hda1 (type vfat) on /mnt/dos Apr 23 10:40:24 onion automount[516]: attempting to mount entry /mnt/dos Apr 23 10:40:24 onion automount[573]: lookup(file): looking up dos Apr 23 10:40:24 onion automount[573]: lookup(file): dos -> -fstype=vfat,umask=000^I:/dev/hda1 Apr 23 10:40:24 onion automount[573]: expanded entry: -fstype=vfat,umask=000^I:/dev/hda1 Apr 23 10:40:24 onion automount[573]: parse(sun): gathered options: fstype=vfat,umask=000 Apr 23 10:40:24 onion automount[573]: parse(sun): core of entry: /dev/hda1 Apr 23 10:40:24 onion automount[573]: do_mount /dev/hda1 /mnt/dos type vfat options umask=000 using module generic Apr 23 10:40:24 onion automount[573]: mount(generic): calling mkdir /mnt/dos
The automount process, pid 573 hung in a D state, until I pressed Ctrl-C, when it continued normally, but without printing the contests of the test file.
Apr 23 10:44:48 onion automount[573]: mount(generic): calling mount -t vfat -s -o umask=000 /dev/hda1 /mnt/dos Apr 23 10:44:48 onion automount[573]: mount(generic): mounted /dev/hda1 type vfat on /mnt/dos Apr 23 10:44:51 onion automount[608]: running expiration on path /mnt Apr 23 10:44:51 onion automount[608]: expired /mnt/dos
~# cd /mnt/dos
Apr 23 10:45:11 onion automount[516]: attempting to mount entry /mnt/dos Apr 23 10:45:11 onion automount[610]: lookup(file): looking up dos Apr 23 10:45:11 onion automount[610]: lookup(file): dos -> -fstype=vfat,umask=000^I:/dev/hda1 Apr 23 10:45:11 onion automount[610]: expanded entry: -fstype=vfat,umask=000^I:/dev/hda1 Apr 23 10:45:11 onion automount[610]: parse(sun): gathered options: fstype=vfat,umask=000 Apr 23 10:45:11 onion automount[610]: parse(sun): core of entry: /dev/hda1 Apr 23 10:45:11 onion automount[610]: do_mount /dev/hda1 /mnt/dos type vfat options umask=000 using module generic Apr 23 10:45:11 onion automount[610]: mount(generic): calling mkdir /mnt/dos Apr 23 10:45:11 onion automount[610]: mount(generic): calling mount -t vfat -s -o umask=000 /dev/hda1 /mnt/dos Apr 23 10:45:12 onion automount[610]: mount(generic): mounted /dev/hda1 type vfat on /mnt/dos Apr 23 10:45:15 onion automount[613]: running expiration on path /mnt Apr 23 10:45:15 onion automount[613]: >> umount: /mnt/dos: device is busy Apr 23 10:45:18 onion automount[615]: running expiration on path /mnt Apr 23 10:45:18 onion automount[615]: expired /mnt/dos
The amount for the udelay doesn't appear to be constant - I had to adjust it by looking at the logs and reducing/increasing the value so that they overlapped to get this to happen. As well, I'd tried this value before, and nothing happened then. This is on an unloaded system. Of interest is the fact that the automount daemon has running expiration, attempting mount, _then_ expired /mnt/dos. It shouldn't be doing this, should it? This time, I could continue automounting /mnt/dos as normal.
However, looking through my logs, similar events (ie mounting before expiry) have happened before, sometimes with a corresponding loss in data in my rc5 buffers, which are symlinked from /usr/local/rc5des to /mnt/dos/rc5des, and, according to my rc5 logs, state that, from about 20 blocks, they now have none. This has been happeneing for a while.
Automount version was 3.1.1, and kernel version was 2.1.95 for the yesterday's results, and 2.1.97 for todays. Timeout in /etc/auto.master was set to 3 seconds.
Hope this helps,
Bradley
PS I am only subscribed to the digest, so please mail me direct if you want further information. Thanks
- To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to majordomo@vger.rutgers.edu
| |