From debbugs-submit-bounces@debbugs.gnu.org Thu Sep 05 09:18:56 2019 Received: (at submit) by debbugs.gnu.org; 5 Sep 2019 13:18:56 +0000 Received: from localhost ([127.0.0.1]:34922 helo=debbugs.gnu.org) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1i5rf5-0003Qf-Pl for submit@debbugs.gnu.org; Thu, 05 Sep 2019 09:18:56 -0400 Received: from lists.gnu.org ([209.51.188.17]:50547) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1i5rf1-0003QW-QK for submit@debbugs.gnu.org; Thu, 05 Sep 2019 09:18:54 -0400 Received: from eggs.gnu.org ([2001:470:142:3::10]:45472) by lists.gnu.org with esmtp (Exim 4.90_1) (envelope-from ) id 1i5rez-0006Um-Q2 for bug-guix@gnu.org; Thu, 05 Sep 2019 09:18:51 -0400 X-Spam-Checker-Version: SpamAssassin 3.3.2 (2011-06-06) on eggs.gnu.org X-Spam-Level: X-Spam-Status: No, score=0.8 required=5.0 tests=BAYES_50,URIBL_BLOCKED autolearn=disabled version=3.3.2 Received: from Debian-exim by eggs.gnu.org with spam-scanned (Exim 4.71) (envelope-from ) id 1i5rex-000427-JW for bug-guix@gnu.org; Thu, 05 Sep 2019 09:18:49 -0400 Received: from ns13.heimat.it ([46.4.214.66]:40692) by eggs.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1i5rex-000416-81 for bug-guix@gnu.org; Thu, 05 Sep 2019 09:18:47 -0400 Received: from localhost (ip6-localhost [127.0.0.1]) by ns13.heimat.it (Postfix) with ESMTP id E5102300673 for ; Thu, 5 Sep 2019 13:18:45 +0000 (UTC) X-Virus-Scanned: Debian amavisd-new at ns13.heimat.it Received: from ns13.heimat.it ([127.0.0.1]) by localhost (ns13.heimat.it [127.0.0.1]) (amavisd-new, port 10024) with ESMTP id 4p-P2zBJr97c for ; Thu, 5 Sep 2019 13:18:26 +0000 (UTC) Received: from bourrache.mug.xelera.it (unknown [93.56.161.211]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (Client did not present a certificate) by ns13.heimat.it (Postfix) with ESMTPSA id F216C30056B for ; Thu, 5 Sep 2019 13:18:25 +0000 (UTC) Received: from roquette.mug.biscuolo.net (roquette.mug.biscuolo.net [10.38.2.14]) by bourrache.mug.xelera.it (Postfix) with SMTP id 50E59300A06 for ; Thu, 5 Sep 2019 15:18:25 +0200 (CEST) Received: (nullmailer pid 9197 invoked by uid 1000); Thu, 05 Sep 2019 13:18:24 -0000 From: Giovanni Biscuolo To: bug-guix@gnu.org Subject: =?utf-8?B?4oCYc3NoLWRhZW1vbuKAmQ==?= service fails to start at boot In-Reply-To: <20190828181141.GA27765@jurong> Organization: Xelera.eu References: <87k1da6fdb.fsf@roquette.mug.biscuolo.net> <87y315t3hw.fsf@roquette.mug.biscuolo.net> <87tvbhra2v.fsf@roquette.mug.biscuolo.net> <87imrvhhpy.fsf@cbaines.net> <874l3crjqr.fsf@roquette.mug.biscuolo.net> <87k1c6p914.fsf@roquette.mug.biscuolo.net> <20190817152031.GA3191@jurong> <87pnkuyac0.fsf_-_@gnu.org> <20190828181141.GA27765@jurong> Date: Thu, 05 Sep 2019 15:18:24 +0200 Message-ID: <87ef0u2867.fsf@roquette.mug.biscuolo.net> MIME-Version: 1.0 Content-Type: multipart/signed; boundary="=-=-=" X-detected-operating-system: by eggs.gnu.org: GNU/Linux 2.2.x-3.x [generic] X-Received-From: 46.4.214.66 X-Spam-Score: -1.4 (-) X-Debbugs-Envelope-To: submit X-BeenThere: debbugs-submit@debbugs.gnu.org X-Mailman-Version: 2.1.18 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: debbugs-submit-bounces@debbugs.gnu.org Sender: "Debbugs-submit" X-Spam-Score: -2.4 (--) --=-=-= Content-Type: text/plain; charset=utf-8 Content-Disposition: inline Hi, following a recent discussion on guix-sysadmin I have to confirm the ssh-daemon issue since it is still happening on some of the machines I administer Previous possibly related bug reports are https://issues.guix.gnu.org/issue/30993 and https://issues.guix.gnu.org/issue/32197 Unfortunately this issue is *not* well reproducible, it depends on some mysterious (to me) timing factor; AFAIU it does *not* depend on the shepherd version, probably it depends on "something" related to IPv6 (read below the details) Andreas Enge writes: [...] > My impression is that the problem is still there. I am quite certain it > happened when I rebooted dover, since I had to connect on the serial console > to manually restart the ssh service. I'm sure it happened when milano-guix-1 was rebooted due to data centre maintenance and happened yesterday to one of my personal Guix machines at office [...] My situation is similar to the one observed by Andreas > Well, it is in /var/log/messages: > Aug 3 21:11:38 localhost sshd[360]: Server listening on 0.0.0.0 port 22. > Aug 3 21:11:55 localhost shepherd[1]: Service ssh-daemon could not be started. --8<---------------cut here---------------start------------->8--- [...] Sep 4 21:46:02 localhost shepherd[1]: Service syslogd has been started. [...] Sep 4 21:46:03 localhost shepherd[1]: Service loopback has been started. [...] Sep 4 21:46:22 localhost vmunix: [ 0.226337] PCI: Using configuration type 1 for base access Sep 4 21:46:09 localhost dhclient: DHCPREQUEST for 10.38.2.16 on eno1 to 255.255.255.255 port 67 [...] Sep 4 21:46:24 localhost shepherd[1]: Service networking has been started. [...] Sep 4 21:46:12 localhost sshd[577]: Server listening on 0.0.0.0 port 22. [...] Sep 4 21:46:30 localhost vmunix: [ 0.250107] ACPI: PCI Interrupt Link [LNKA] (IRQs 3 4 5 6 10 *11 12 14 15) Sep 4 21:46:13 localhost dhclient: DHCPREQUEST for 10.38.2.16 on eno1 to 255.255.255.255 port 67 [...] Sep 4 21:46:16 localhost dhclient: DHCPACK of 10.38.2.16 from 10.38.2.1 [...] Sep 4 21:46:33 localhost shepherd[1]: Service ssh-daemon could not be started. [...] Sep 4 21:46:47 localhost vmunix: [ 0.731142] Segment Routing with IPv6 --8<---------------cut here---------------end--------------->8--- Please note the timing of the dhclient and the sshd processes: I inserted them as printed in /var/log/messages but they are not time-sequential: does it means something or is irrelevant? So the sshd process started (as far as I cen see there is no trace it was stopped) and pretty soon shepherd noticed ssh-daemon was not started. Logging in from the console I see the ssh-daemon is stopped but enabled: --8<---------------cut here---------------start------------->8--- Status of ssh-daemon: It is stopped. It is enabled. Provides (ssh-daemon). Requires (syslogd loopback). Conflicts with (). Will be respawned. --8<---------------cut here---------------end--------------->8--- [...] If I start it via `sudo herd start ssh-daemon` it immediatly starts, like in Andreas experience: > Aug 3 21:13:10 localhost sshd[385]: Server listening on 0.0.0.0 port 22. > Aug 3 21:13:10 localhost sshd[385]: Server listening on :: port 22. > Aug 3 21:13:11 localhost shepherd[1]: Service ssh-daemon has been started. --8<---------------cut here---------------start------------->8--- Sep 5 13:38:55 localhost sshd[745]: Server listening on 0.0.0.0 port 22. Sep 5 13:38:55 localhost sshd[745]: Server listening on :: port 22. Sep 5 13:38:55 localhost shepherd[1]: Service ssh-daemon has been started. --8<---------------cut here---------------end--------------->8--- Please notice the difference from above: this time the sshd server is also listening on the IPv6 address :: while in the above log it was only listening on the 0.0.0.0 IPv4 address Does the failure have something to do with IPv6 not available when sshd starts for the first time after a reboot? Please have a look at the following /var/log/message excerpt from my system after a succesfull ssh-daemon start soon after a reboot (no "manual" intervention): --8<---------------cut here---------------start------------->8--- Sep 5 14:45:00 localhost vmunix: [ 0.247544] pci 0000:00:14.0: reg 0x10: [mem 0xf7c20000-0xf7c2ffff 64bit] Sep 5 14:44:45 localhost sshd[574]: Server listening on 0.0.0.0 port 22. [...] Sep 5 14:44:47 localhost sshd[574]: Server listening on :: port 22. [...] Sep 5 14:45:05 localhost shepherd[1]: Service ssh-daemon has been started. --8<---------------cut here---------------end--------------->8--- Bingo? This time ssh was started also on :: and it works right after a reboot. It really seems it has something to do with IPv6 but I cannot understand exactly what :-S (do I have to disable IPv6 in my configs?) For completeness, I have to say that the issue happened yesterday after a `guix system reconfigure`, this is my current system generation: --8<---------------cut here---------------start------------->8--- Generation 8 Sep 04 2019 17:19:08 (current) file name: /var/guix/profiles/system-8-link canonical file name: /gnu/store/iw2ayn696f8ipmd5gzw9fxljf9h8w4pr-system label: GNU with Linux-Libre 5.2.11 bootloader: grub-efi root device: UUID: 26bd54ec-4e74-4b3a-96ff-58f2f34e4a1a kernel: /gnu/store/xgl60ivx8p5p79zjbf08p4x09881wf4s-linux-libre-5.2.11/bzImage --8<---------------cut here---------------end--------------->8--- Reconfigured with this guix version: --8<---------------cut here---------------start------------->8--- g@batondor ~$ sudo -i guix describe Generation 6 Sep 04 2019 17:17:02 (current) guix 5ee1c04 repository URL: https://git.savannah.gnu.org/git/guix.git branch: master commit: 5ee1c0459eebdd3b7771abaeab0f0b52ff86fdd5 --8<---------------cut here---------------end--------------->8--- This is the shepherd version: --8<---------------cut here---------------start------------->8--- g@batondor ~$ shepherd --version shepherd (GNU Shepherd) 0.6.1 --8<---------------cut here---------------end--------------->8--- Thanks! Gio' -- Giovanni Biscuolo Xelera IT Infrastructures --=-=-= Content-Type: application/pgp-signature; name=signature.asc Content-Transfer-Encoding: base64 LS0tLS1CRUdJTiBQR1AgU0lHTkFUVVJFLS0tLS0KCmlRSXpCQUVCQ2dBZEZpRUVSY3hqdUZKWXlk VmZOTEk1MDMwT3A4N01PUklGQWwxeENBVUFDZ2tRMDMwT3A4N00KT1JMMFF4QUFtaDJvc2dtU2tB bkJraXhuOUE4dGVtUlI3QlpwNStMSGZDNUxHZS81eDBTd3Fhd2YwMVFHQW5udwpuRGpkRDdXZFdx Z0lKSHBabjNoZWJRTFZWWVZHRm5BUDZza0Q0QUczK1lRM29sRTZnaXM0OFRNdlFRNXZVT2gwCkFn UXZpV2pOc3p1Q3NHN3BpWlZvQnM2OCtOZjZteXlKOFZJcVF1S0ZPaEFkQ2E5V1ZLVlFjNGtWdDZO UVZpSEoKVldyZ3F1c1U4eXRXajJnczVyeUtSR1dUeGQwVDRncWU1YVg1WUgrTjNoamkxNnEzOUxR VWxjMzhNZUdxV0tXdwpJaHh5eklmTzZudU43WnBqQzdvc1ZPSSt5TngzSDFSRk9VQjZVeWRhRVQ5 WkxXQks2QjdaVVEvemtPM09POENwCmdNMnY3U1ovSGxJZ2pGeWNvNXNYeTl3YURIU21ZRlFLMWZH TUtXRyswc29pTllCUXNRa2d5N0hFcVNCZ3ROVGMKdVAzdms0bFNFQVF0NklFQW5VTHRZeTBWRUFL OGZxOS80alIzemM1MVZnUTV1K3U3VkNMdEROa25oNmFCRy8rQgpaSEdZL3pWRU83VXVmc3djMjkx MW1BUjU2TUpWM0g2UnR2VjRCem96QVFaUHNkSEVoaXZnMGJUUkdBcWFVMGlQCmF3Y3d3UmE2Mk9Q NkcwRlhPNyt4bDh3d1ZrV3VOSi9PZkg3MUhaMXV1WDAwZWNUdHdoMHZNb0FJWU1CMy9ZSDQKSUx6 c0VscXV3aEgvczhGcVFxNFdNcEVVbGJ4RHdEdVJVejJsdG9ITG40azRhVlkvNkNmenRSRG5pOUZr OGM5UwpBZUNKd3dlOXhmazNSOGFWT3V0ekRNc0FhZ0hHMWhrQTdhczZLNFVYSURWbjZtNHFDRFU9 Cj1hZjVMCi0tLS0tRU5EIFBHUCBTSUdOQVRVUkUtLS0tLQ== --=-=-=--