You were never here, you didn't see anything..

NFS[ERROR]


On my home network I use NFS to access shares on my server. What right minded fella wouldn’t right? Well recently for some reason on boot up my desktop system would spew an error about the NFS start up. dmesg showed nothing so I turned to /var/log/messages for more detail and found the following:

Oct 29 23:25:57 ion dhcpcd: wlan0: carrier acquired
Oct 29 23:25:57 ion dhcpcd: wlan0: rebinding lease of 10.2.2.49
Oct 29 23:25:58 ion dhcpcd: wlan0: acknowledged 10.2.2.49 from 10.2.2.7
Oct 29 23:25:58 ion dhcpcd: wlan0: checking for 10.2.2.49
Oct 29 23:25:58 ion slim: slim: Stale lockfile found, removing it
Oct 29 23:25:59 ion rpc.statd[961]: Version 1.1.6 Starting
Oct 29 23:25:59 ion sm-notify[962]: Already notifying clients; Exiting!
Oct 29 23:25:59 ion rpc.statd[961]: Unable to read state from '/var/lib/nfs/state': errno 0 (Success)
Oct 29 23:25:59 ion nfs: mount.nfs: DNS resolution failed for 10.2.2.4: Name or service not known
Oct 29 23:26:00 ion nfs: mount.nfs: DNS resolution failed for 10.2.2.4: Name or service not known

It looks like the network comes up and then it tries to start up NFS and mount the network shares, failing due to DNS resolution. Why on earth would it do this with the network up? Got me. Running the NFS script with restart yielded properly mounted NFS shares so something just wasn’t meshing well. This got me thinking along the lines of timing, but this was not occurring before a few days back.

A bit of googling turned up an important detail, by default dhcpcd would fork to the background and let the boot process drive on. Well, looking closely at the log data shows that while it had started the DHCP negotiations it was not done. The complete process looks like this:

Oct 29 23:45:14 ion dhcpcd: wlan0: carrier acquired
Oct 29 23:45:14 ion dhcpcd: wlan0: rebinding lease of 10.2.2.49
Oct 29 23:45:15 ion dhcpcd: wlan0: acknowledged 10.2.2.49 from 10.2.2.7
Oct 29 23:45:15 ion dhcpcd: wlan0: checking for 10.2.2.49
Oct 29 23:45:20 ion dhcpcd: wlan0: leased 10.2.2.49 for 86400 seconds
Oct 29 23:45:20 ion dhcpcd: forking to background

The key line containing “leased 10.2.2.49”. from the above you can see it took 5 second to complete. The first log snipping showed NFS starting up and trying to mount at 2 second after it checks for the IP. Talk about small margins of error…

For me the solution was simple. Crux uses very simple scripts for its start up. In fact the network script is pretty much what one would use to start it via cli manually. Since this is the case I simply added the “-w” option to the dhcpcd line which tells it to wait for the address to be assigned before forking to the background. Now it all works like a champ once more. It slowed my boot to login times by about one to two seconds, which puts me at a whopping 13 seconds or so. I think I can live with that… 😉

Have any Question or Comment?

Leave a Reply

Your email address will not be published. Required fields are marked *

*

This blog is kept spam free by WP-SpamFree.

Most who fail…

Most who fail have yet to really try!