--- Begin Message ---
|
Subject: |
Service ssh-daemon could not be started |
|
Date: |
Tue, 19 Feb 2019 22:21:26 +0100 |
|
User-agent: |
Mutt/1.11.2 (2019-01-07) |
Hello,
twice in a row at work (on harbourfront) and now twice in a row at home
(on dover) I am in a situation where sshd does not start on Guix machines.
Networking is available (the machines can be pinged), and I have to log
in via a console and execute "herd start ssh-daemon" by hand.
Here is the relevant portion of /var/log/messages for dover:
Feb 19 22:02:23 localhost vmunix: [ 108.990196] ipmi_si e0010000.kcs: There
appears to be no BMC at this location
Feb 19 22:02:23 localhost vmunix: [ 109.021176] shepherd[1]: Service udev has
been started.
Feb 19 22:02:23 localhost vmunix: [ 109.026910] Adding 467648k swap on
/dev/sda4. Priority:-2 extents:1 across:467648k FS
Feb 19 22:02:23 localhost vmunix: [ 109.037138] shepherd[1]: Service
swap-/dev/sda4 has been started.
Feb 19 22:02:23 localhost vmunix: [ 109.045502] shepherd[1]: Service
user-file-systems has been started.
Feb 19 22:02:23 localhost vmunix: [ 109.229105] shepherd[1]: Service
file-system-/boot/efi has been started.
Feb 19 22:02:23 localhost vmunix: [ 109.238721] shepherd[1]: Service
file-system-/dev/pts has been started.
Feb 19 22:02:23 localhost vmunix: [ 109.248214] shepherd[1]: Service
file-system-/dev/shm has been started.
Feb 19 22:02:24 localhost vmunix: [ 109.257629] shepherd[1]: Service
file-system-/gnu/store has been started.
Feb 19 22:02:06 localhost ntpd[354]: Command line:
/gnu/store/rgj9dvakw960p0p44cq6kfwk9a4pzcmw-ntp-4.2.8p12/bin/ntpd -n -c
/gnu/store/1l1yf5dss8r9pqxklaax32s6bkah09c6-ntpd.conf -u ntpd
Feb 19 22:02:24 localhost vmunix: [ 109.266692] shepherd[1]: Service
file-systems has been started.
Feb 19 22:02:24 localhost vmunix: [ 109.284615] shepherd[1]: Service
urandom-seed has been started.
Feb 19 22:02:24 localhost vmunix: [ 109.292825] shepherd[1]: Service
user-processes has been started.
Feb 19 22:02:24 localhost vmunix: [ 109.301269] shepherd[1]: Service host-name
has been started.
Feb 19 22:02:24 localhost vmunix: [ 109.318409] shepherd[1]: Service
user-homes could not be started.
Feb 19 22:02:24 localhost vmunix: [ 110.331371] shepherd[1]: Service nscd has
been started.
Feb 19 22:02:24 localhost vmunix: [ 110.343051] shepherd[1]: Service
guix-daemon has been started.
Feb 19 22:02:24 localhost vmunix: [ 116.296395] sky2 0000:02:00.0 enp2s0:
enabling interface
Feb 19 22:02:24 localhost vmunix: [ 116.301800] IPv6: ADDRCONF(NETDEV_UP):
enp2s0: link is not ready
Feb 19 22:02:24 localhost vmunix: [ 118.611449] sky2 0000:02:00.0 enp2s0: Link
is up at 1000 Mbps, full duplex, flow control rx
Feb 19 22:02:25 localhost vmunix: [ 118.619821] IPv6: ADDRCONF(NETDEV_CHANGE):
enp2s0: link becomes ready
Feb 19 22:02:25 localhost shepherd[1]: Service mcron has been started.
Feb 19 22:02:08 localhost dhclient: DHCPACK of 192.168.1.113 from 192.168.1.1
Feb 19 22:02:10 localhost sshd[359]: Server listening on 0.0.0.0 port 22.
Feb 19 22:02:12 localhost nscd: 314 monitored file `/etc/resolv.conf` was moved
into place, adding watch
Feb 19 22:02:12 localhost dhclient: bound to 192.168.1.113 -- renewal in 19054
seconds.
Feb 19 22:02:25 localhost shepherd[1]: Service ssh-daemon could not be started.
Feb 19 22:02:17 localhost ntpd[354]: Listen and drop on 1 v4wildcard 0.0.0.0:123
Feb 19 22:02:20 localhost ntpd[354]: Listen normally on 3 enp2s0
192.168.1.113:123
Feb 19 22:02:20 localhost ntpd[354]: Listen normally on 4 lo [::1]:123
Feb 19 22:02:21 localhost ntpd[354]: Listen normally on 5 enp2s0
[fda3:5c49:ae85:0:e2ff:f7ff:fe00:20b3]:123
Feb 19 22:02:23 localhost ntpd[354]: Listen normally on 6 enp2s0
[2001:910:103f:0:e2ff:f7ff:fe00:20b3]:123
Feb 19 22:02:24 localhost ntpd[354]: Listen normally on 7 enp2s0
[fe80::e2ff:f7ff:fe00:20b3%2]:123
Feb 19 22:02:25 localhost ntpd[354]: Listening on routing socket on fd #24 for
interface updates
Feb 19 22:02:25 localhost ntpd[354]: kernel reports TIME_ERROR: 0x41: Clock
Unsynchronized
Feb 19 22:02:25 localhost ntpd[354]: kernel reports TIME_ERROR: 0x41: Clock
Unsynchronized
Feb 19 22:03:26 localhost shepherd[1]: Respawning term-ttyAMA0.
Feb 19 22:03:26 localhost shepherd[1]: Service term-ttyAMA0 has been started.
Feb 19 22:03:48 localhost sshd[380]: Server listening on 0.0.0.0 port 22.
Feb 19 22:03:48 localhost sshd[380]: Server listening on :: port 22.
Feb 19 22:03:48 localhost shepherd[1]: Service ssh-daemon has been started.
Besides the notice that "Service ssh-daemon could not be started" I do not see
much information. The second time corresponds to the starting by hand.
Maybe it is a problem that " sshd[359]: Server listening on 0.0.0.0 port 22."
at 22:02:10 before the IP address arrives via dhcp 2 seconds later?
Andreas
--- 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 ---