Why rpcbind.socket does not restart when rpcbind.service is already running ?

Solution Verified - Updated -

Environment

  • Red Hat Enterprise Linux
  • NFS
  • rpcbind-0.2.0-44.el7.x86_64

Issue

  • rpcbind.socket and rpcbind.service are not starting in order and gives below error
May 29 02:26:49 rhel7 systemd: Socket service rpcbind.service already active, refusing.
May 29 02:26:49 rhel7 systemd: Failed to listen on RPCbind Server Activation Socket.

Resolution

  • Restart rpcbind.service instead of rpcbind.socket or downgrade to rpc version 0.2.0-42.el7.x86_64.

Root Cause

  • Starting 'rpcbind.service' also starts 'rpcbind.socket'. This is because of dependency added. This was not there in 0.2.0-42.el7.x86_64.
cat /usr/lib/systemd/system/rpcbind.service 
[Unit]
Description=RPC bind service
DefaultDependencies=no

# Make sure we use the IP addresses listed for
# rpcbind.socket, no matter how this unit is started.
Wants=rpcbind.socket                                   
After=rpcbind.socket 
After=systemd-tmpfiles-setup.service

[Service]
Type=forking
EnvironmentFile=/etc/sysconfig/rpcbind
ExecStart=/sbin/rpcbind -w $RPCBIND_ARGS

[Install]
WantedBy=multi-user.target

Diagnostic Steps

  • Analyse the logs
May 24 12:41:04 rhel7 systemd: Reloading.
May 24 12:41:04 rhel7 systemd: Socket service rpcbind.service already active, refusing.
May 24 12:41:04 rhel7 systemd: Failed to listen on RPCbind Server Activation Socket.
May 24 12:41:04 rhel7 puppet-agent[15922]: Systemd start for rpcbind.socket failed!
May 24 12:41:04 rhel7 puppet-agent[15922]: journalctl log for rpcbind.socket:
May 24 12:41:04 rhel7 puppet-agent[15922]: -- Logs begin at Thu 2018-05-24 12:35:04 CEST, end at Thu 2018-05-24 12:41:04 CEST. --
May 24 12:41:04 rhel7 puppet-agent[15922]: May 24 12:38:45 rhel7.redhat.com systemd[1]: Stopping RPCbind Server Activation Socket.
May 24 12:41:04 rhel7 puppet-agent[15922]: May 24 12:38:45 rhel7.redhat.com systemd[1]: Socket service rpcbind.service already active, refusing.
May 24 12:41:04 rhel7 puppet-agent[15922]: (/Stage[base]/Nfs::Service/Service[rpcbind.socket]/ensure) change from stopped to running failed: Systemd start for rpcbind.socket failed!
May 24 12:41:04 rhel7 puppet-agent[15922]: (/Stage[base]/Nfs::Service/Service[rpcbind.socket]/ensure) journalctl log for rpcbind.socket:
May 24 12:41:04 rhel7 puppet-agent[15922]: (/Stage[base]/Nfs::Service/Service[rpcbind.socket]/ensure) -- Logs begin at Thu 2018-05-24 12:35:04 CEST, end at Thu 2018-05-24 12:41:04 CEST. --
May 24 12:41:04 rhel7 puppet-agent[15922]: (/Stage[base]/Nfs::Service/Service[rpcbind.socket]/ensure) May 24 12:38:45 rhel7.redhat.com systemd[1]: Stopping RPCbind Server Activation Socket.
  • It seems puppet agent is trying to restart rpcbind.socket which will fail due to dependency involved.

This solution is part of Red Hat’s fast-track publication program, providing a huge library of solutions that Red Hat engineers have created while supporting our customers. To give you the knowledge you need the instant it becomes available, these articles may be presented in a raw and unedited form.