Bug 1171603

I ran into a similar Problem and was about to file a bug and then found this one.

For me the nfs-server.service startup succeeds but only after a 60 seconds delay.
This is what appears in the logs:

Jun 18 19:00:58 test systemd: Starting NFS Mount Daemon...
...
Jun 18 19:01:58 test rpc.mountd[2021]: Failed to unregister program
100005, version 1

I noticed that this delay does not occur when I manually start rpcbind.service first.

With the above information I copied nfs-server.service to /etc/systemd/system and replaced the two occurrences of rpcbind.target with rpcbind.service.
After that the delay when starting nfs-server.service is gone and I no longer see any failures in the log.

*** Bug 1203765 has been marked as a duplicate of this bug. ***

FYI in order to really fix this in a pacemaker cluster context I had to also modify the nfs-lock.service and rpc-statd.service files in order to get rid of the delay problem.

And rpc-rquotad.service also requires rpcbind.target.  Should that also be changed?

(In reply to Andrew J. Schorr from comment #8)
> And rpc-rquotad.service also requires rpcbind.target.  Should that also be
> changed?
Note, rpc-rquotad.service is no longer part of nfs-utils package
it was moved to the qouta package.

(In reply to Dennis Jacobfeuerborn from comment #7)
> FYI in order to really fix this in a pacemaker cluster context I had to also
> modify the nfs-lock.service and rpc-statd.service files in order to get rid
> of the delay problem.

Why and how? Please open another bz if needed... This one is done! ;-)

So what was the actual fix in this case? While while changing rpcbind.target to rpcbind.service makes things work it doesn't look like an appropriate fix. The question is what is rpcbind.target supposed to accomplish? If its inclusion was a mistake then the target itself and all its references would need to be removed for a proper fix but if it is still used for some reason than all references still need to checked to see if they are correct or need to be changed.

In summary I don't think this bug is properly fixed yet if only the reference in nfs-server.service was changed.

Looking in beta package nfs-utils-1.3.0-0.17.el7, yes, only nfs-server.service was changed so far. In that package alone, rpc-statd.service also needs this change as it still reads:

systemd/rpc-statd.service:Requires=nss-lookup.target rpcbind.target
systemd/rpc-statd.service:After=network.target nss-lookup.target rpcbind.target

My user definitely will need a fix in rpc-statd.service as well, as that's the daemon having trouble in their case. Manually editing rpc-statd.service to change rpcbind.target to rpcbind.service works.

The correct fix is to fix all these references, as they are all incorrect. There exists no rpcbind.target anywhere; it's only named rpcbind.service.

(Other bugs may need to be opened to fix this elsewhere, e.g. in the quota package's rpc-rquotad.service which was noted as broken above.)

(In reply to Todd Vierling from comment #12)
> Looking in beta package nfs-utils-1.3.0-0.17.el7, yes, only
> nfs-server.service was changed so far. In that package alone,
> rpc-statd.service also needs this change as it still reads:
> 
> systemd/rpc-statd.service:Requires=nss-lookup.target rpcbind.target
> systemd/rpc-statd.service:After=network.target nss-lookup.target
> rpcbind.target
> 
Hi Todd,
Maybe it's better to open another bug for rpc-statd.service (or nfs-lock.service) according to Comment 10.
Then we can trace the issue easier on it. Thanks.

> My user definitely will need a fix in rpc-statd.service as well, as that's
> the daemon having trouble in their case. Manually editing rpc-statd.service
> to change rpcbind.target to rpcbind.service works.
> 
And please help to provide the user reproducer.
I can't trigger the rpc-statd.service issue using the Description's steps.
It seems has no difference using "rpcbind.service" or "rpcbind.target".

[root@hp-dl580g7-03 ~]# cat /usr/lib/systemd/system/rpc-statd.service | grep rpcbind
Requires=nss-lookup.target rpcbind.target
After=network.target nss-lookup.target rpcbind.target
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ using rpcbind.target
[root@hp-dl580g7-03 ~]# systemctl daemon-reload
[root@hp-dl580g7-03 ~]# service rpcbind stop; service rpcbind stop
Redirecting to /bin/systemctl stop  rpcbind.service
Warning: Stopping rpcbind.service, but it can still be activated by:
  rpcbind.socket
Redirecting to /bin/systemctl stop  rpcbind.service
Warning: Stopping rpcbind.service, but it can still be activated by:
  rpcbind.socket
[root@hp-dl580g7-03 ~]# service rpcbind status
Redirecting to /bin/systemctl status  rpcbind.service
● rpcbind.service - RPC bind service
   Loaded: loaded (/usr/lib/systemd/system/rpcbind.service; indirect; vendor preset: enabled)
   Active: inactive (dead) since Sat 2015-09-12 13:07:59 CST; 5s ago
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ stop the rpcbind.service
 Main PID: 13180 (code=exited, status=0/SUCCESS)

Sep 12 13:06:53 hp-dl580g7-03.rhts.eng.nay.redhat.com systemd[1]: Starting RPC bind service...
Sep 12 13:06:53 hp-dl580g7-03.rhts.eng.nay.redhat.com systemd[1]: Started RPC bind service.
Sep 12 13:07:59 hp-dl580g7-03.rhts.eng.nay.redhat.com systemd[1]: Stopping RPC bind service...
Sep 12 13:07:59 hp-dl580g7-03.rhts.eng.nay.redhat.com systemd[1]: Stopped RPC bind service.
Sep 12 13:07:59 hp-dl580g7-03.rhts.eng.nay.redhat.com systemd[1]: Stopped RPC bind service.
[root@hp-dl580g7-03 ~]# service rpc-statd restart; service rpc-statd status
Redirecting to /bin/systemctl restart  rpc-statd.service
Redirecting to /bin/systemctl status  rpc-statd.service
● rpc-statd.service - NFS status monitor for NFSv2/3 locking.
   Loaded: loaded (/usr/lib/systemd/system/rpc-statd.service; static; vendor preset: disabled)
   Active: active (running) since Sat 2015-09-12 13:08:25 CST; 26ms ago
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ start rpc-statd successfully
  Process: 13274 ExecStart=/usr/sbin/rpc.statd --no-notify $STATDARGS (code=exited, status=0/SUCCESS)
 Main PID: 13275 (rpc.statd)
   CGroup: /system.slice/rpc-statd.service
           └─13275 /usr/sbin/rpc.statd --no-notify

Sep 12 13:08:25 hp-dl580g7-03.rhts.eng.nay.redhat.com systemd[1]: Starting NFS status monitor for NFSv2/3 loc.....
Sep 12 13:08:25 hp-dl580g7-03.rhts.eng.nay.redhat.com rpc.statd[13275]: Version 1.3.0 starting
Sep 12 13:08:25 hp-dl580g7-03.rhts.eng.nay.redhat.com rpc.statd[13275]: Flags: TI-RPC
Sep 12 13:08:25 hp-dl580g7-03.rhts.eng.nay.redhat.com systemd[1]: Started NFS status monitor for NFSv2/3 locking..
Hint: Some lines were ellipsized, use -l to show in full.
[root@hp-dl580g7-03 ~]# 

[root@hp-dl580g7-03 system]# cat rpc-statd.service | grep rpcbind
Requires=nss-lookup.target rpcbind.service
After=network.target nss-lookup.target rpcbind.service
[root@hp-dl580g7-03 system]# systemctl daemon-reload
[root@hp-dl580g7-03 system]# service rpcbind stop; service rpcbind stop
Redirecting to /bin/systemctl stop  rpcbind.service
Warning: Stopping rpcbind.service, but it can still be activated by:
  rpcbind.socket
Redirecting to /bin/systemctl stop  rpcbind.service
Warning: Stopping rpcbind.service, but it can still be activated by:
  rpcbind.socket
[root@hp-dl580g7-03 system]# service rpcbind status
Redirecting to /bin/systemctl status  rpcbind.service
● rpcbind.service - RPC bind service
   Loaded: loaded (/usr/lib/systemd/system/rpcbind.service; indirect; vendor preset: enabled)
   Active: inactive (dead) since Sat 2015-09-12 13:06:41 CST; 5s ago
 Main PID: 13084 (code=exited, status=0/SUCCESS)

Sep 12 13:03:31 hp-dl580g7-03.rhts.eng.nay.redhat.com systemd[1]: Starting RPC bind service...
Sep 12 13:03:31 hp-dl580g7-03.rhts.eng.nay.redhat.com systemd[1]: Started RPC bind service.
Sep 12 13:06:41 hp-dl580g7-03.rhts.eng.nay.redhat.com systemd[1]: Stopping RPC bind service...
Sep 12 13:06:41 hp-dl580g7-03.rhts.eng.nay.redhat.com systemd[1]: Stopped RPC bind service.
Sep 12 13:06:41 hp-dl580g7-03.rhts.eng.nay.redhat.com systemd[1]: Stopped RPC bind service.
[root@hp-dl580g7-03 system]# service rpc-statd restart
Redirecting to /bin/systemctl restart  rpc-statd.service
[root@hp-dl580g7-03 system]# service rpc-statd status
Redirecting to /bin/systemctl status  rpc-statd.service
● rpc-statd.service - NFS status monitor for NFSv2/3 locking.
   Loaded: loaded (/usr/lib/systemd/system/rpc-statd.service; static; vendor preset: disabled)
   Active: active (running) since Sat 2015-09-12 13:06:54 CST; 3s ago
  Process: 13181 ExecStart=/usr/sbin/rpc.statd --no-notify $STATDARGS (code=exited, status=0/SUCCESS)
 Main PID: 13182 (rpc.statd)
   CGroup: /system.slice/rpc-statd.service
           └─13182 /usr/sbin/rpc.statd --no-notify

Sep 12 13:06:53 hp-dl580g7-03.rhts.eng.nay.redhat.com systemd[1]: Starting NFS status monitor for NFSv2/3 locking....
Sep 12 13:06:53 hp-dl580g7-03.rhts.eng.nay.redhat.com rpc.statd[13182]: Version 1.3.0 starting
Sep 12 13:06:53 hp-dl580g7-03.rhts.eng.nay.redhat.com rpc.statd[13182]: Flags: TI-RPC
Sep 12 13:06:54 hp-dl580g7-03.rhts.eng.nay.redhat.com systemd[1]: Started NFS status monitor for NFSv2/3 locking..
[root@hp-dl580g7-03 system]#

(In reply to Yongcheng Yang from comment #13)
> (In reply to Todd Vierling from comment #12)
> > Looking in beta package nfs-utils-1.3.0-0.17.el7, yes, only
> > nfs-server.service was changed so far. In that package alone,
> > rpc-statd.service also needs this change as it still reads:
> > 
> > systemd/rpc-statd.service:Requires=nss-lookup.target rpcbind.target
> > systemd/rpc-statd.service:After=network.target nss-lookup.target
> > rpcbind.target
> > 
> Hi Todd,
> Maybe it's better to open another bug for rpc-statd.service (or
> nfs-lock.service) according to Comment 10.
> Then we can trace the issue easier on it. Thanks.

...Huh? Did I stutter?

It's the same package and the same issue and the same fix, just a different file. This bug is only half-fixed as of this writing.

===

> > My user definitely will need a fix in rpc-statd.service as well, as that's
> > the daemon having trouble in their case. Manually editing rpc-statd.service
> > to change rpcbind.target to rpcbind.service works.
> > 
> And please help to provide the user reproducer.

I can't provide access to their systems, but why is a reliable reproducer needed? Simple logic can explain why it's still a bug in rpc-statd.service: there is *no* rpcbind.target anywhere in the systemd configuration, but rpc-statd.service is depending on it. This is an obvious bug.

How is this so difficult to understand? It's two tiny tweaks that are dead simple: change "rpcbind.target", which doesn't exist, to "rpcbind.service", which does exist, on two lines of rpc-statd.service.

===

> I can't trigger the rpc-statd.service issue using the Description's steps.
> It seems has no difference using "rpcbind.service" or "rpcbind.target".

systemd by its nature starts up services in parallel, and because of that, reproducers for dependency errors are often difficult to come by. It's a race condition.

The whole point is that systemd *requires working dependencies*. "rpcbind.target" is not a working dependency because that target doesn't exist.

This is NOT rocket science. It's a typo with a known fix. Just fix it.

Hell, just call up Lennart and ask. He will tell you the same thing, this is an obvious typo in rpc-statd.service, and no reproducer is needed.

Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://rhn.redhat.com/errata/RHBA-2015-2196.html

*** Bug 1209213 has been marked as a duplicate of this bug. ***