[debbugs-tracker] bug#30993: closed (OpenSSH sshd killed by Shepherd 0.4.0)

[GNU bug Tracking System]

Your message dated Tue, 14 May 2019 14:21:06 -0400
with message-id <address@hidden>
and subject line Re: bug#30993: OpenSSH sshd killed by Shepherd 0.4.0
has caused the debbugs.gnu.org bug report #30993,
regarding OpenSSH sshd killed by Shepherd 0.4.0
to be marked as done.

(If you believe you have received this mail in error, please contact
address@hidden)


-- 
30993: http://debbugs.gnu.org/cgi/bugreport.cgi?bug=30993
GNU Bug Tracking System
Contact address@hidden with problems

--- Begin Message --- Subject: OpenSSH sshd killed by Shepherd 0.4.0 Date: Thu, 29 Mar 2018 16:08:03 -0400 User-agent: Mutt/1.9.3 (2018-01-21)

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.).

One interesting tidbit is that the PID file '/var/run/sshd.pid' is not
created anymore. And if I create an empty PID file by hand, it is
removed after trying to start the ssh-daemon service. Also, the sshd
user's home '/var/run/sshd' does not exist, and is similarly removed if
it does exist.

I ran the OpenSSH system test `make check-system TESTS=openssh` and it
failed when it could not find the PID file. It passed on another
non-GuixSD machine. The failing machine is relatively slow and lacks
KVM: a ThinkPad x200s.

After boot, trying to start the service again with `herd start
ssh-daemon` gives the same result.

I modified the sshd invocation to print some debug output ('-d -E
/tmp/sshd.log') and this is what it shows:

------
debug1: sshd version OpenSSH_7.6, OpenSSL 1.0.2o  27 Mar 2018
debug1: private host key #0: ssh-rsa SHA256:REDACTED
debug1: private host key #1: ssh-dss SHA256:REDACTED
debug1: private host key #2: ecdsa-sha2-nistp256 SHA256:REDACTED
debug1: private host key #3: ssh-ed25519 SHA256:REDACTED
debug1: 
rexec_argv[0]='/gnu/store/az7vib8gk16fybhshh5xpkljmgxyrs4k-openssh-7.6p1/sbin/sshd'
debug1: rexec_argv[1]='-D'
debug1: rexec_argv[2]='-d'
debug1: rexec_argv[3]='-E'
debug1: rexec_argv[4]='/tmp/sshd.log'
debug1: rexec_argv[5]='-f'
debug1: rexec_argv[6]='/gnu/store/miy7xg5j4fg3mn04mcl27awmcl6s97ss-sshd_config'
debug1: Set /proc/self/oom_score_adj from 0 to -1000
debug1: Bind to port 22 on 0.0.0.0.
Server listening on 0.0.0.0 port 22.
debug1: Bind to port 22 on ::.
Server listening on :: port 22.
Received signal 15; terminating.
------

My system configuration file, the shepherd log messages, and the OpenSSH
system test logs are attached. Any ideas?

shepherd.log
Description: Text document

system.scm
Description: Text document

check.log
Description: Text document

signature.asc
Description: PGP signature

--- End Message ---

--- Begin Message --- Subject: Re: bug#30993: OpenSSH sshd killed by Shepherd 0.4.0 Date: Tue, 14 May 2019 14:21:06 -0400 User-agent: Mutt/1.11.4 (2019-03-13)

On Tue, May 14, 2019 at 03:33:59PM +0200, Ludovic Courtès wrote:
> There are reasons to believe that this issue is fixed by the Shepherd 0.6.1:
> 
>   https://issues.guix.info/issue/35550
> 
> Could you check somehow if the bug shows up again?

The bug disappeared for me a couple of reboots after reinstalling the
Guix System on my affected machine. That reinstallation provided
Shepherd 0.5, although 0.5 was also tested unsuccessfully before
reinstalling.

The issue does not manifest for me with Shepherd 0.6, 0.6.1 or Guix 1.0.

So... I think the bug was probably some kind of race condition or TOCTOU
problem that went away with a less fragmented or full filesystem (I was
really pushing the limits in that regard).

It's great that Shepherd 0.6.1 improved the PID file handling, assuming
that was the culprit.

I am closing this bug, but we can reopen it later if necessary.

signature.asc
Description: PGP signature

--- End Message ---