At work, we have a Netgear ReadyNAS 1100. It’s a 4TB NAS appliance, a cute little 1U half-depth Linux box with 4 SATA disks, a RAID controller, and some firmware to do a whole bunch of fancy stuff (mainly geared towards consumers and very small shops – all configuration is point-and-click web UI). We’ve been using it for storing archived log data and low-priority backups. At the beginning of this problem, it was running RAIDiator 4.1.6 firmware since December of last year (over 6 months), and hadn’t had any configuration changes in at least 4 months.
Last week, I had to power off the unit and remove the power cables for some rack maintenance. I went through the usual full shutdown procedure in the web UI, and also told it to `fsck` the volumes, as that hadn’t been done in quite some time. Unfortunately, when the unit came back up, even after I could log into the web UI, I couldn’t mount the NFS shares on my backup server. I kept getting messages like:
[root@backup-server ~]# mount -a mount: mount to NFS server 'css-readynas' failed: RPC Error: Program not registered. |
so my next step was to check RPC status of the readynas, from the client. That was also a bit of a surprise:
[root@backup-server ~]# rpcinfo -p css-readynas program vers proto port 100000 2 tcp 111 portmapper 100000 2 udp 111 portmapper 100011 1 udp 620 rquotad 100011 2 udp 620 rquotad 100011 1 tcp 623 rquotad 100011 2 tcp 623 rquotad 100024 1 udp 32765 status 100024 1 tcp 32765 status 100005 1 udp 2051 mountd 100005 1 tcp 3006 mountd 100005 2 udp 2051 mountd 100005 2 tcp 3006 mountd 100005 3 udp 2051 mountd 100005 3 tcp 3006 mountd |
Somewhere in that list is supposed to be nfsd, listening on port 2049. Next, I did an nmap (port scan) of the readynas:
[root@backup-server ~]# nmap -sU -p2047-2050 css-readynas Starting Nmap 4.11 ( http://www.insecure.org/nmap/ ) at 2011-06-23 15:21 EDT Interesting ports on css-readynas.rutgers.edu (172.16.25.108): PORT STATE SERVICE 2047/udp closed dls 2048/udp closed dls-monitor 2049/udp open|filtered nfs 2050/udp closed unknown |
Interesting. The port scan shows that something is listening on port 2049. But rpcinfo doesn’t seem to recognize it as a NFS server.
At this point, through FrontView (the web UI) I backed up the configuration and went through a few reboot cycles, with no change. I then started tweaking everything I could that I thought would restart the NFS server – I added and removed allowed hosts for the NFS share, enabled and disabled sync mode, etc. I started searching the ReadyNAS Forum and found a post that reported a very similar problem – upnpd grabbing nfsd port. The user reported that he was getting the same “RPC Error: Program not registered” message, and in daemon.log on the ReadyNAS, found a line including “storage nfsd[1087]: nfssvc: Address already in use”. I remembered that I’d setup the ReadyNAS to forward all logs to our central syslog server and, sure enough, found an identical message that something had already bound to UDP port 2049 when NFS was starting. I tried confirming that upnpd was disabled and rebooting, but that didn’t help. Grepping my logs for “nfs” returned:
daemon.log:Jun 23 12:43:43 css-readynas nfsd[2331]: nfssvc: Address already in use daemon.log:Jun 23 15:26:33 css-readynas nfsd[2724]: nfssvc: Address already in use kern.log:Jun 23 11:35:29 css-readynas kernel: Installing knfsd (copyright (C) 1996 okir@monad.swb.de). kern.log:Jun 23 12:43:43 css-readynas kernel: NFSD: Using /var/lib/nfs/v4recovery as the NFSv4 state recovery directory kern.log:Jun 23 12:43:43 css-readynas kernel: NFSD: starting 90-second grace period kern.log:Jun 23 14:56:20 css-readynas kernel: Installing knfsd (copyright (C) 1996 okir@monad.swb.de). kern.log:Jun 23 15:12:41 css-readynas kernel: NFSD: starting 90-second grace period kern.log:Jun 23 15:26:33 css-readynas kernel: NFSD: Using /var/lib/nfs/v4recovery as the NFSv4 state recovery directory kern.log:Jun 23 15:26:33 css-readynas kernel: NFSD: starting 90-second grace period |
My next step was a few more reboots, with no change. I then upgraded the RAIDiator firmware to the latest, 4.1.7. Still no luck. I installed the Enable root SSH addon, and that’s when things became very clear:
css-readynas:/var/log# netstat -unlp Active Internet connections (only servers) Proto Recv-Q Send-Q Local Address Foreign Address State PID/Program name udp 0 0 0.0.0.0:2049 0.0.0.0:* 794/snmpd udp 0 0 0.0.0.0:514 0.0.0.0:* 673/syslogd udp 0 0 172.16.25.108:137 0.0.0.0:* 1672/nmbd udp 0 0 0.0.0.0:137 0.0.0.0:* 1672/nmbd udp 0 0 172.16.25.108:138 0.0.0.0:* 1672/nmbd udp 0 0 0.0.0.0:138 0.0.0.0:* 1672/nmbd udp 0 0 0.0.0.0:161 0.0.0.0:* 794/snmpd udp 0 0 0.0.0.0:162 0.0.0.0:* 802/snmptrapd udp 0 0 0.0.0.0:2086 0.0.0.0:* 1565/rpc.mountd udp 0 0 127.0.0.1:22081 0.0.0.0:* 1599/raidard udp 0 0 172.16.25.108:22081 0.0.0.0:* 1599/raidard udp 0 0 0.0.0.0:22081 0.0.0.0:* 1599/raidard udp 0 0 0.0.0.0:988 0.0.0.0:* 819/rpc.rquotad udp 0 0 0.0.0.0:5353 0.0.0.0:* 729/avahi-daemon: r udp 0 0 0.0.0.0:111 0.0.0.0:* 666/portmap udp 0 0 0.0.0.0:881 0.0.0.0:* 1553/rpc.statd udp 0 0 0.0.0.0:32765 0.0.0.0:* 1553/rpc.statd |
For some very strange reason, snmpd had bound to port 2049 (the nfs port) instead of 161. That left no port for nfs to bind to.
Solution:
css-readynas:/var/log# /etc/init.d/snmpd stop Stopping network management services: snmpd snmptrapd readynas-agent. css-readynas:/var/log# /etc/init.d/nfs-kernel-server start Exporting directories for NFS kernel daemon...done. Starting NFS kernel daemon:mount: nfsd already mounted or /proc/fs/nfsd/ busy mount: according to mtab, nfsd is mounted on /proc/fs/nfsd statd nfsd mountd. css-readynas:/var/log# /etc/init.d/snmpd start Starting network management services: snmpd snmptrapd readynas-agent. |
Stop snmpd, restart nfs-kernel-server so that it grabs port 2049 like it should, and then start snmpd back up. If all went well, nfsd should now be listening on UDP 2049, and snmpd should be listening on UDP 161 like it should. To confirm:
css-readynas:/var/log# netstat -unlp Active Internet connections (only servers) Proto Recv-Q Send-Q Local Address Foreign Address State PID/Program name udp 0 0 0.0.0.0:2049 0.0.0.0:* - udp 0 0 0.0.0.0:514 0.0.0.0:* 673/syslogd udp 0 0 172.16.25.108:137 0.0.0.0:* 1672/nmbd udp 0 0 0.0.0.0:137 0.0.0.0:* 1672/nmbd udp 0 0 172.16.25.108:138 0.0.0.0:* 1672/nmbd udp 0 0 0.0.0.0:138 0.0.0.0:* 1672/nmbd udp 0 0 0.0.0.0:161 0.0.0.0:* 26161/snmpd udp 0 0 0.0.0.0:162 0.0.0.0:* 26163/snmptrapd udp 0 0 0.0.0.0:2086 0.0.0.0:* 1565/rpc.mountd udp 0 0 127.0.0.1:22081 0.0.0.0:* 1599/raidard udp 0 0 172.16.25.108:22081 0.0.0.0:* 1599/raidard udp 0 0 0.0.0.0:22081 0.0.0.0:* 1599/raidard udp 0 0 0.0.0.0:988 0.0.0.0:* 819/rpc.rquotad udp 0 0 0.0.0.0:5353 0.0.0.0:* 729/avahi-daemon: r udp 0 0 0.0.0.0:2158 0.0.0.0:* - udp 0 0 0.0.0.0:111 0.0.0.0:* 666/portmap udp 0 0 0.0.0.0:2160 0.0.0.0:* 26161/snmpd udp 0 0 0.0.0.0:881 0.0.0.0:* 1553/rpc.statd udp 0 0 0.0.0.0:32765 0.0.0.0:* 1553/rpc.statd |
All is well. Now to confirm this from the client machine:
[root@backup-server ~]# rpcinfo -p css-readynas program vers proto port 100000 2 tcp 111 portmapper 100000 2 udp 111 portmapper 100011 1 udp 988 rquotad 100011 2 udp 988 rquotad 100011 1 tcp 991 rquotad 100011 2 tcp 991 rquotad 100024 1 udp 32765 status 100024 1 tcp 32765 status 100005 1 udp 2086 mountd 100005 1 tcp 3131 mountd 100005 2 udp 2086 mountd 100005 2 tcp 3131 mountd 100005 3 udp 2086 mountd 100005 3 tcp 3131 mountd 100003 2 udp 2049 nfs 100003 3 udp 2049 nfs 100003 4 udp 2049 nfs 100003 2 tcp 2049 nfs 100003 3 tcp 2049 nfs 100003 4 tcp 2049 nfs 100021 1 udp 2158 nlockmgr 100021 3 udp 2158 nlockmgr 100021 4 udp 2158 nlockmgr 100021 1 tcp 4189 nlockmgr 100021 3 tcp 4189 nlockmgr 100021 4 tcp 4189 nlockmgr |
Ok, NFS is now there. It all looks good, and re-running mount -a on the client successfully mounts the NFS share.
We’ll see what happens next time I have to reboot the ReadyNAS. In the mean time, I’m going to try to bring this to the attention of Netgear support and hope they do something about it.
Jason,
That article was *extremely* helpful! Slightly different fail for me, nfds was not started at all but no-one was on its port either. My other peeve is Netgear did not have the ssh addon placed properly, just x86 and Sparc (I needed ARM). A google search found a ReadyNas forum link to it.
I will need to triage why the ReadyNas did not automatically start the nfsd. Still, I am up and thats 100% better than where I was! tnx again!