Subject: Re: bug#39708: nfs-service-type broken: rpc.mountd respawns too quickly

From: Maxim Cournoyer <[email-masked]>
Date: Sat, 07 Mar 2020 22:19:35 -0500

Hello Ludovic!

Ludovic Courtès <[email-masked]> writes:

> Hi,
>
> Maxim Cournoyer <[email-masked]> skribis:
>
>> The rpc.mountd service, one of the required services for
>> nfs-service-type, respawns the process quickly until disabled.
>
> Does /var/log/messages contain hints?

 herd restart nfs
Service nfs has been stopped.
Service rpc.mountd is currently disabled.
Service nfs depends on rpc.mountd.
Service nfs could not be started.
root@hurd ~# herd stop rpc.mountd
root@hurd ~# herd enable rpc.mountd
Enabled service rpc.mountd.
root@hurd ~# herd status rpc.mountd
Status of rpc.mountd:
  It is stopped.
  It is enabled.
  Provides (rpc.mountd).
  Requires (rpc.statd).
  Conflicts with ().
  Will be respawned.
  Last respawned on Sat Mar 07 21:56:43-0500 2020.
root@hurd ~# herd restart nfs
Service nfs is not running.
Service rpc.mountd has been started.
Service nfs has been started.

And then, in /var/log/messages:

Mar  7 21:56:4--8<---------------cut here---------------start------------->8---
Mar  7 22:06:45 localhost shepherd[1]: Service nfs has been stopped. 
Mar  7 22:06:45 localhost shepherd[1]: Service rpc.mountd is currently disabled. 
Mar  7 22:06:45 localhost shepherd[1]: Service nfs depends on rpc.mountd. 
Mar  7 22:06:45 localhost shepherd[1]: Service nfs could not be started. 
Mar  7 22:07:05 localhost shepherd[1]: Enabled service rpc.mountd. 
Mar  7 22:07:15 localhost shepherd[1]: Service nfs is not running. 
Mar  7 22:07:15 localhost shepherd[1]: Service rpc.mountd has been started. 
Mar  7 22:07:15 localhost shepherd[1]: Service nfs has been started. 
Mar  7 22:07:15 localhost rpc.mountd[25270]: Version 2.4.2 starting
Mar  7 22:07:15 localhost shepherd[1]: Respawning rpc.mountd. 
Mar  7 22:07:15 localhost shepherd[1]: Service rpc.mountd has been started. 
Mar  7 22:07:15 localhost rpc.mountd[25272]: Version 2.4.2 starting
Mar  7 22:07:15 localhost shepherd[1]: Respawning rpc.mountd. 
Mar  7 22:07:15 localhost shepherd[1]: Service rpc.mountd has been started. 
Mar  7 22:07:15 localhost rpc.mountd[25274]: Version 2.4.2 starting
Mar  7 22:07:15 localhost shepherd[1]: Respawning rpc.mountd. 
Mar  7 22:07:15 localhost shepherd[1]: Service rpc.mountd has been started. 
Mar  7 22:07:15 localhost rpc.mountd[25276]: Version 2.4.2 starting
Mar  7 22:07:15 localhost shepherd[1]: Respawning rpc.mountd. 
Mar  7 22:07:15 localhost shepherd[1]: Service rpc.mountd has been started. 
Mar  7 22:07:15 localhost rpc.mountd[25278]: Version 2.4.2 starting
Mar  7 22:07:15 localhost shepherd[1]: Respawning rpc.mountd. 
Mar  7 22:07:15 localhost shepherd[1]: Service rpc.mountd has been started. 
Mar  7 22:07:15 localhost rpc.mountd[25280]: Version 2.4.2 starting
Mar  7 22:07:15 localhost shepherd[1]: Service rpc.mountd has been disabled. 
Mar  7 22:07:15 localhost shepherd[1]:   (Respawning too fast.)
--8<---------------cut here---------------end--------------->8---

>  Is rpc.statd running?

herd status rpc.statd
Status of rpc.statd:
  It is started.
  Running value is 348.
  It is enabled.
  Provides (rpc.statd).
  Requires (rpcbind-daemon).
  Conflicts with ().
  Will be respawned.

root@hurd ~# pidof rpc.statd
348

So, yes :-)

> Could it be that all these services need to depend on ‘loopback’?

I don't think so, because attempting to restart those services in a
state where the network is live and a loopback interface exists
(127.0.0.1 pings) doesn't change the outcome.  Or am I misunderstanding
something?

An interesting fact is that every time 'herd restart rpc.mountd' is run,
the number of running processes of rpc.mountd goes up:

--8<---------------cut here---------------start------------->8---
herd enable rpc.mountd && herd start rpc.mountd && pidof rpc.mountd | wc -w
Enabled service rpc.mountd.
Service rpc.mountd has been started.
6
root@hurd ~# herd enable rpc.mountd && herd start rpc.mountd && pidof rpc.mountd | wc -w
Enabled service rpc.mountd.
Service rpc.mountd has been started.
12
root@hurd ~# herd enable rpc.mountd && herd start rpc.mountd && pidof rpc.mountd | wc -w
Enabled service rpc.mountd.
Service rpc.mountd has been started.
13
root@hurd ~# herd enable rpc.mountd && herd start rpc.mountd && pidof rpc.mountd | wc -w
Enabled service rpc.mountd.
Service rpc.mountd has been started.
19
root@hurd ~# herd enable rpc.mountd && herd start rpc.mountd && pidof rpc.mountd | wc -w
Enabled service rpc.mountd.
Service rpc.mountd has been started.
20
root@hurd ~# herd enable rpc.mountd && herd start rpc.mountd && pidof rpc.mountd | wc -w
Enabled service rpc.mountd.
Service rpc.mountd has been started.
26
--8<---------------cut here---------------end--------------->8---

So, to me it seems to be a problem with Shepherd: it erroneously thinks
the process has died and restart it, while in reality it is still
running fine.

Running the rpc.mountd command manually doesn't exhibit any issue, as I
mentioned in my original report.

Thanks for the help!

Maxim