Intermittent autofs nfs mount failures

Issue

The workstation has recently been upgraded from RHEL 5.5 to 6.1. The following behavior was NOT observed in RHEL 5.5

A cron job runs every 10 minutes. It tests that 69 nfs mountable filesystems are available. It first checks that the appropriate nfs host IP address responds to ping; if it does, a check is made that a specific file is accessible.

Sometimes one or more filesystems fail(s) this test but the next test (10 minutes later) succeeds. Note that failures involve different filesystems and different nfs servers. (All servers offer nfs v3 and run RHEL 5.7.)

When logged in at the time of a failure, mount confirms that the filesystem is NOT mounted. Therefore suspect that automount
is failing to mount the filesystem(s).

The failure occurs with the version of /etc/sysconfig/autofs supplied with 6.1. Below are the options:

  MOUNT_WAIT=180
  BROWSE_MODE="yes"
  MOUNT_NFS_DEFAULT_PROTOCOL=3
  LOGGING="debug"
  OPTIONS="-d"

It may be helpful to look at one instance. The test of filesystem known to the client as /disk/pemccd failed at Jan 15 15:20

Automount information is

# ypcat -k auto.master | grep ^/disk
/disk auto.resource

# ypcat -k auto.resource | grep ^pemccd
pemccd -nfsvers=3,tcp,rw,noatime,nodiratime,nosuid,_netfs,nodev,fsc,rsize=1048576,wsize=1048576,acregmin=10,acregmax=120,acdirmax=120,timeo=600,retry=1,lock,hard,intr  server01:/stage/pemccd

The cron job failed to access /disk/pemccd at 15:20. I shall attach a fragment of /var/log/messages from around this time and a sosreport shortly. The former shows automount DOES attempt the mount at 15:20.

Extract of /var/log/messages from the SERVER (greped for the client and filesystem name). Note that the 15:20 mount attempt is NOT logged by the server. (The 15:23 mount is an additional manual test by me.)

Jan 15 14:30:02 client01 mountd[26510]: authenticated mount request from server01:974 for /stage/pemccd (/stage/pemccd)
Jan 15 14:35:29 client01 mountd[26504]: authenticated unmount request from server01:844 for /stage/pemccd (/stage/pemccd)
Jan 15 14:40:04 client01 mountd[26541]: authenticated mount request from server01:765 for /stage/pemccd (/stage/pemccd)
Jan 15 14:45:44 client01 mountd[26544]: authenticated unmount request from server01:798 for /stage/pemccd (/stage/pemccd)
Jan 15 14:50:02 client01 mountd[26489]: authenticated mount request from server01:735 for /stage/pemccd (/stage/pemccd)
Jan 15 14:55:59 client01 mountd[26539]: authenticated unmount request from server01:902 for /stage/pemccd (/stage/pemccd)
Jan 15 15:00:02 client01 mountd[26502]: authenticated mount request from server01:670 for /stage/pemccd (/stage/pemccd)
Jan 15 15:06:12 client01 mountd[26486]: authenticated unmount request from server01:1015 for /stage/pemccd (/stage/pemccd)
Jan 15 15:10:02 client01 mountd[26508]: authenticated mount request from server01:902 for /stage/pemccd (/stage/pemccd)
Jan 15 15:15:08 client01 mountd[26523]: authenticated unmount request from server01:884 for /stage/pemccd (/stage/pemccd)
Jan 15 15:23:23 client01 mountd[26485]: authenticated mount request from server01:962 for /stage/pemccd (/stage/pemccd)
Jan 15 15:30:01 client01 mountd[26543]: authenticated mount request from server01:679 for /stage/pemccd (/stage/pemccd)
Jan 15 15:35:33 client01 mountd[26532]: authenticated unmount request from server01:868 for /stage/pemccd (/stage/pemccd)
Jan 15 15:40:02 client01 mountd[26505]: authenticated mount request from server01:778 for /stage/pemccd (/stage/pemccd)
Jan 15 15:45:44 client01 mountd[26479]: authenticated unmount request from server01:830 for /stage/pemccd (/stage/pemccd)