Bug 757452

Summary: nfsd fails without logging when launched from nfs-server
Product: [Fedora] Fedora Reporter: bob mckay <urilabob>
Component: nfs-utilsAssignee: Steve Dickson <steved>
Status: CLOSED ERRATA QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: medium Docs Contact:
Priority: unspecified    
Version: 16CC: bfields, dwmw2, jlayton, steved, tgl
Target Milestone: ---   
Target Release: ---   
Hardware: x86_64   
OS: Linux   
Fixed In Version: nfs-utils-1.2.5-14.fc17 Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2012-03-23 20:26:27 EDT Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---

Description bob mckay 2011-11-27 02:33:27 EST
Description of problem:
If nfsd fails because of any configuration problems, in default configuration, no logging occurs either in systemctl status or /var/log/messages.

Version-Release number of selected component (if applicable):
1:1.2.5-3.fc16 x86_64 (but I assume not specific to this version)

How reproducible:

Steps to Reproduce:
1. In Fedora 15, make any changes to /etc/sysconfig/nfs
2. Upgrade (which results in valid configuration being written to /etc/sysconfig/nfs.rpmnew, leaving an invalid configuration in /etc/sysconfig/nfs)
3. systemctl restart nfs-server
Actual results:
nfs, nfs-acl and nlockmgr fail to start (fair enough, there is an invalid config file). 
However nothing is logged in /var/log/messages, and from systemctl we get:
service nfs-server status
Redirecting to /bin/systemctl  status nfs-server.service
nfs-server.service - NFS Server
	  Loaded: loaded (/lib/systemd/system/nfs-server.service; enabled)
	  Active: active (running) since Sun, 27 Nov 2011 13:22:30 +0900; 51min ago
	 Process: 17929 ExecStopPost=/usr/sbin/exportfs -f (code=exited, status=0/SUCCESS)
	 Process: 17927 ExecStop=/usr/sbin/rpc.nfsd 0 (code=exited, status=0/SUCCESS)
	 Process: 17939 ExecStartPost=/usr/lib/nfs-utils/scripts/nfs-server.postconfig (code=exited, status=0/SUCCESS)
	 Process: 17937 ExecStartPost=/usr/sbin/rpc.mountd $RPCMOUNTDOPTS (code=exited, status=0/SUCCESS)
	 Process: 17936 ExecStart=/usr/sbin/rpc.nfsd $RPCNFSDARGS ${RPCNFSDCOUNT} (code=exited, status=0/SUCCESS)
	 Process: 17935 ExecStartPre=/usr/sbin/exportfs -r (code=exited, status=0/SUCCESS)
	 Process: 17933 ExecStartPre=/usr/sbin/rpc.rquotad $RPCRQUOTADOPTS (code=exited, status=0/SUCCESS)
	 Process: 17931 ExecStartPre=/usr/lib/nfs-utils/scripts/nfs-server.preconfig (code=exited, status=0/SUCCESS)
	Main PID: 17934 (rpc.rquotad)
	  CGroup: name=systemd:/system/nfs-server.service
		  \u251c 17934 /usr/sbin/rpc.rquotad
		  \u2514 17938 /usr/sbin/rpc.mountd

i.e. everything _looks_ hunky dory, but nfs doesn't work. 

Expected results:
systemctl reports failure, and in default configuration, errors are logged to /var/log/messages. 

Additional comments:
Basically, something went badly wrong here, yet the error logging mechanisms in their default configuration give no hint of it. The problem is compounded by F16 documentation that suggests (correctly) that there have been major changes to nfs-server, without clarifying what (from the user perspective) the changes are. This means that it's unclear whether nfs documentation from previous versions is relevant. For example, the only way I figured out that nfs, nfs-acl and nlockmgr _should_ still be appearing in rpcinfo was by doing a complete install on a clean system and checking there.
Comment 1 Steve Dickson 2011-11-28 09:31:43 EST
Is there a /etc/sysconfig/nfs.rpmnew file? 

If so, please merge the nfs.rpmnew file with the nfs
file, making sure the RPCNFSDCOUNT variable is uncommented
and has a valid value (8). 

With the new systemd init scripts, the RPCNFSDCOUNT has to be
set or the server will not come up. In the older version of
/etc/sysconfig/nfs file the RPCNFSDCOUNT was not set.
In the newer version it needs to be set.

To verify the server did come up use the following command:
# ps ax | grep nfsd
 2540 ?        S<     0:00 [nfsd4]
 2541 ?        S<     0:00 [nfsd4_callbacks]
 2542 ?        S      0:00 [nfsd]
 2543 ?        S      0:00 [nfsd]
 2544 ?        S      0:00 [nfsd]
 2545 ?        S      0:00 [nfsd]
 2546 ?        S      0:00 [nfsd]
 2547 ?        S      0:00 [nfsd]
 2548 ?        S      0:00 [nfsd]
 2549 ?        S      0:00 [nfsd]
 2555 pts/2    S+     0:00 grep nfsd
Comment 2 bob mckay 2011-11-28 11:47:52 EST
Hi Steve and thanks for your comments. I need to apologise for the obscurity of my writing. Actually, I had realised (after a lot of hard work) that I needed to fix my /etc/sysconfig/nfs file, and my system is now working fine. I don't think it's a bug that using the old nfs configuration file failed. That is reasonable behaviour - just deserts for not checking for rpmnews 8^). What I think _is_ a bug is that there was zero logging of the failure, either through 'systemctl status' or through /var/log/messages.
Comment 3 Steve Dickson 2011-11-29 10:51:14 EST
(In reply to comment #2)
> What Ithink _is_ a bug is that there was zero logging of the failure, either 
> through 'systemctl status' or through /var/log/messages.
I agree its frustrating when errors and warnings are not logged but 
unfortunately not giving rpc.nfsd a proc count appears not to be
an error. Although the rpc.nfsd(8) man page states a count should
be given.

Looking at the code, when rpc.nfsd is not given a count, it defaults
to 1 nfsd proc. So in theory the server should have come up, but
running with one nfsd proc is by no means a good idea.

So I will look into bumping up that default and logging a warning 
when the default is used instead of a given count... Hopefully
that will help...
Comment 4 bob mckay 2011-11-29 20:45:06 EST
Hi Steve; until I fixed /etc/sysconfig/nfs, the server was  not coming up at all: rpcinfo -p showed nfs, nfs-acl and nlockmgr all missing, they appeared as soon as I fixed the config file. This was repeated on three different machines with different versions of /etc/sysconfig/nfs, so it wasn't the particular contents of /etc/sysconfig/nfs that was causing it to fail to start.

Logging a warning would be great news. I'm sure it will save a lot of trouble for users. Thank you.
Comment 5 Tom Lane 2011-12-27 17:42:33 EST
This (failure to set RPCNFSDCOUNT) bit me too ... better logging would be nice.
Comment 6 Fedora Update System 2012-03-16 11:21:52 EDT
nfs-utils-1.2.5-5.fc16 has been submitted as an update for Fedora 16.
Comment 7 Fedora Update System 2012-03-16 11:24:19 EDT
nfs-utils-1.2.5-13.fc17 has been submitted as an update for Fedora 17.
Comment 8 Fedora Update System 2012-03-22 20:41:09 EDT
Package nfs-utils-1.2.5-13.fc17:
* should fix your issue,
* was pushed to the Fedora 17 testing repository,
* should be available at your local mirror within two days.
Update it with:
# su -c 'yum update --enablerepo=updates-testing nfs-utils-1.2.5-13.fc17'
as soon as you are able to.
Please go to the following url:
then log in and leave karma (feedback).
Comment 9 Steve Dickson 2012-03-23 10:43:35 EDT
*** Bug 772090 has been marked as a duplicate of this bug. ***
Comment 10 Fedora Update System 2012-03-23 20:26:27 EDT
nfs-utils-1.2.5-5.fc16 has been pushed to the Fedora 16 stable repository.  If problems still persist, please make note of it in this bug report.
Comment 11 Fedora Update System 2012-05-08 00:11:37 EDT
nfs-utils-1.2.5-14.fc17 has been pushed to the Fedora 17 stable repository.  If problems still persist, please make note of it in this bug report.