GNU bug report logs - #30993
'ssh-daemon' fails to start

Previous Next

Full log

Message #58 received at 30993 <at> debbugs.gnu.org (full text, mbox):

From: ludo <at> gnu.org (Ludovic Courtès)
To: Leo Famulari <leo <at> famulari.name>
Cc: 30993 <at> debbugs.gnu.org
Subject: Re: bug#30993: OpenSSH sshd killed by Shepherd 0.4.0
Date: Tue, 28 Aug 2018 11:47:12 +0200

Hi Leo,

Leo Famulari <leo <at> famulari.name> 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’.

Previous Next

GNU bug tracking system
Copyright (C) 1999 Darren O. Benham, 1997,2003 nCipher Corporation Ltd, 1994-97 Ian Jackson.