bug#30993: OpenSSH sshd killed by Shepherd 0.4.0

[Ludovic Courtès]

Hi Leo,

Leo Famulari <address@hidden> skribis:

> Since the update to Shepherd 0.4.0, I've found that OpenSSH's sshd is
> killed almost immediately after it starts with signal 15. I confirmed
> the issue started with the Shepherd upgrade by bisecting our Git
> history.
>
> I can reproduce the issue from commit
> b6beda1d6b9093a8493b5c3cde33ed522242c451 (gnu: Add botan.).

I’m “happy” to say that I experienced this on a server—not having ssh
access to a remote server is fairly annoying, I definitely sympathize…

What I see is this:

--8<---------------cut here---------------start------------->8---
Aug  6 07:56:40 localhost shepherd[1]: Service loopback has been started. 

[...]

Aug  6 07:56:51 localhost sshd[606]: Server listening on 0.0.0.0 port 22.

[...]

Aug  6 07:57:05 localhost shepherd[1]: Service ssh-daemon could not be started. 

[...]

Aug  6 07:57:46 localhost vmunix: [   10.049791] random: ssh-keygen: 
uninitialized urandom read (32 bytes read)
--8<---------------cut here---------------end--------------->8---

(Note that the last message was pulled from /dev/kmsg by syslogd, but
it’s about an event that actually occurred before the first message.)

It waited for ~15 seconds, although ‘%pid-file-timeout’ in (shepherd
service) is only 5 seconds.

The SIGTERM you were seeing very likely comes from this bit:

--8<---------------cut here---------------start------------->8---
      (match (read-pid-file pid-file
                            #:max-delay pid-file-timeout)
        (#f
         (catch-system-error (kill pid SIGTERM))
         #f)
        ((? integer? pid)
         pid))
--8<---------------cut here---------------end--------------->8---

On another machine:

--8<---------------cut here---------------start------------->8---
Aug 28 09:10:49 localhost sshd[435]: Server listening on 0.0.0.0 port 22.
Aug 28 09:10:49 localhost sshd[435]: Server listening on :: port 22.

[...]

Aug 28 09:10:50 localhost shepherd[1]: Service ssh-daemon has been started. 
--8<---------------cut here---------------end--------------->8---

I wonder if this has to do with IPv6 (the failing case lacks the “Server
listening on ::” line), or if it’s just sshd occasionally taking a long
time to start.

Is it easily reproducible for you?  Did you eventually gather more
details?

Thanks,
Ludo’.