GNU bug report logs - #38432
dockerd is not started automatically

Previous Next

Package: guix;

Reported by: andreoss <at> SDF.ORG

Date: Fri, 29 Nov 2019 23:15:02 UTC

Severity: normal

Merged with 55936

Done: Maxim Cournoyer <maxim.cournoyer <at> gmail.com>

Bug is archived. No further changes may be made.

To add a comment to this bug, you must first unarchive it, by sending
a message to control AT debbugs.gnu.org, with unarchive 38432 in the body.
You can then email your comments to 38432 AT debbugs.gnu.org in the normal way.

Toggle the display of automated, internal messages from the tracker.

View this report as an mbox folder, status mbox, maintainer mbox


Report forwarded to bug-guix <at> gnu.org:
bug#38432; Package guix. (Fri, 29 Nov 2019 23:15:02 GMT) Full text and rfc822 format available.

Acknowledgement sent to andreoss <at> SDF.ORG:
New bug report received and forwarded. Copy sent to bug-guix <at> gnu.org. (Fri, 29 Nov 2019 23:15:02 GMT) Full text and rfc822 format available.

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

From: andreoss <at> SDF.ORG
To: bug-guix <at> gnu.org
Subject: dockerd is not started automatically
Date: Fri, 29 Nov 2019 22:06:10 +0000
When defined in /etc/config.scm as the manual suggests[1]
>    (service docker-service-type)

dockerd is not started with other services.
It could be started manually by
$ herd start dockerd

[1] https://guix.gnu.org/manual/en/html_node/Miscellaneous-Services.html




Information forwarded to bug-guix <at> gnu.org:
bug#38432; Package guix. (Thu, 28 May 2020 13:26:01 GMT) Full text and rfc822 format available.

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

From: Maxim Cournoyer <maxim.cournoyer <at> gmail.com>
To: andreoss <at> SDF.ORG
Cc: 38432 <at> debbugs.gnu.org
Subject: Re: bug#38432: dockerd is not started automatically
Date: Thu, 28 May 2020 09:24:58 -0400
Hello!

andreoss <at> SDF.ORG writes:

> When defined in /etc/config.scm as the manual suggests[1]
>>    (service docker-service-type)
>
> dockerd is not started with other services.
> It could be started manually by
> $ herd start dockerd
>
> [1] https://guix.gnu.org/manual/en/html_node/Miscellaneous-Services.html

FWIW, I started experimenting the same on my Guix System after a recent
guix pull & guix system reconfigure.

Maxim




Information forwarded to bug-guix <at> gnu.org:
bug#38432; Package guix. (Thu, 28 May 2020 13:43:01 GMT) Full text and rfc822 format available.

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

From: Danny Milosavljevic <dannym <at> scratchpost.org>
To: Maxim Cournoyer <maxim.cournoyer <at> gmail.com>
Cc: andreoss <at> SDF.ORG, 38432 <at> debbugs.gnu.org
Subject: Re: bug#38432: dockerd is not started automatically
Date: Thu, 28 May 2020 15:42:02 +0200
[Message part 1 (text/plain, inline)]
Hi Maxim,

On Thu, 28 May 2020 09:24:58 -0400
Maxim Cournoyer <maxim.cournoyer <at> gmail.com> wrote:

> FWIW, I started experimenting the same on my Guix System after a recent
> guix pull & guix system reconfigure.

Really?  Back then I've fixed and replaced a lot of the modprobe stuff in
docker upstream--so now it should start up much more reliably on Guix.

I don't know what could be up with it now.  Could you please check logs
in /var/log/containerd.log and /var/log/docker.log (without
manually starting docker beforehand).
[Message part 2 (application/pgp-signature, inline)]

Information forwarded to bug-guix <at> gnu.org:
bug#38432; Package guix. (Mon, 01 Jun 2020 03:28:01 GMT) Full text and rfc822 format available.

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

From: Maxim Cournoyer <maxim.cournoyer <at> gmail.com>
To: Danny Milosavljevic <dannym <at> scratchpost.org>
Cc: andreoss <at> SDF.ORG, 38432 <at> debbugs.gnu.org
Subject: Re: bug#38432: dockerd is not started automatically
Date: Sun, 31 May 2020 23:27:30 -0400
Hello Danny,

Sorry for the delay.

Danny Milosavljevic <dannym <at> scratchpost.org> writes:

> Hi Maxim,
>
> On Thu, 28 May 2020 09:24:58 -0400
> Maxim Cournoyer <maxim.cournoyer <at> gmail.com> wrote:
>
>> FWIW, I started experimenting the same on my Guix System after a recent
>> guix pull & guix system reconfigure.
>
> Really?  Back then I've fixed and replaced a lot of the modprobe stuff in
> docker upstream--so now it should start up much more reliably on Guix.

Really! :-/. I've reconfigured earlier and just rebooted now, and
dockerd was stopped:

--8<---------------cut here---------------start------------->8---
$ sudo herd status dockerd
Password: 
Status of dockerd:
  It is stopped.
  It is enabled.
  Provides (dockerd).
  Requires (containerd dbus-system elogind file-system-/sys/fs/cgroup/blkio file-system-/sys/fs/cgroup/cpu file-system-/sys/fs/cgroup/cpuset file-system-/sys/fs/cgroup/devices file-system-/sys/fs/cgroup/memory file-system-/sys/fs/cgroup/pids networking udev).
  Conflicts with ().
  Will be respawned.
--8<---------------cut here---------------end--------------->8---

> I don't know what could be up with it now.  Could you please check logs
> in /var/log/containerd.log and /var/log/docker.log (without
> manually starting docker beforehand).

Something interesting from containerd.log:

--8<---------------cut here---------------start------------->8---
time="2020-05-31T22:28:15.863091224-04:00" level=info msg="starting containerd" revision=.m version= 
time="2020-05-31T22:28:15.883644866-04:00" level=info msg="loading plugin "io.containerd.content.v1.content"..." type=io.containerd.content.v1 
time="2020-05-31T22:28:15.883714657-04:00" level=info msg="loading plugin "io.containerd.snapshotter.v1.btrfs"..." type=io.containerd.snapshotter.v1 
time="2020-05-31T22:28:15.883975218-04:00" level=info msg="loading plugin "io.containerd.snapshotter.v1.aufs"..." type=io.containerd.snapshotter.v1 
time="2020-05-31T22:28:15.885343166-04:00" level=warning msg="failed to load plugin io.containerd.snapshotter.v1.aufs" error="modprobe aufs failed: "modprobe: FATAL: Module aufs not found in directory /lib/modules/5.4.43-gnu\n": exit status 1" 
time="2020-05-31T22:28:15.885391522-04:00" level=info msg="loading plugin "io.containerd.snapshotter.v1.native"..." type=io.containerd.snapshotter.v1 
time="2020-05-31T22:28:15.885483513-04:00" level=info msg="loading plugin "io.containerd.snapshotter.v1.overlayfs"..." type=io.containerd.snapshotter.v1 
time="2020-05-31T22:28:15.885632392-04:00" level=info msg="loading plugin "io.containerd.snapshotter.v1.zfs"..." type=io.containerd.snapshotter.v1 
time="2020-05-31T22:28:15.885850392-04:00" level=warning msg="failed to load plugin io.containerd.snapshotter.v1.zfs" error="path /var/lib/containerd/io.containerd.snapshotter.v1.zfs must be a zfs filesystem to be used with the zfs snapshotter" 
time="2020-05-31T22:28:15.885871090-04:00" level=info msg="loading plugin "io.containerd.metadata.v1.bolt"..." type=io.containerd.metadata.v1 
time="2020-05-31T22:28:15.885918881-04:00" level=warning msg="could not use snapshotter aufs in metadata plugin" error="modprobe aufs failed: "modprobe: FATAL: Module aufs not found in directory /lib/modules/5.4.43-gnu\n": exit status 1" 
time="2020-05-31T22:28:15.885937520-04:00" level=warning msg="could not use snapshotter zfs in metadata plugin" error="path /var/lib/containerd/io.containerd.snapshotter.v1.zfs must be a zfs filesystem to be used with the zfs snapshotter" 
time="2020-05-31T22:28:15.911651119-04:00" level=info msg="loading plugin "io.containerd.differ.v1.walking"..." type=io.containerd.differ.v1 
time="2020-05-31T22:28:15.911693576-04:00" level=info msg="loading
plugin "io.containerd.gc.v1.scheduler"..." type=io.containerd.gc.v1
--8<---------------cut here---------------end--------------->8---

The only new lines to appear in docker.log following my last reboot are:

--8<---------------cut here---------------start------------->8---
time="2020-05-31T22:28:13.579626539-04:00" level=info msg="Starting up"
failed to start containerd: exec: "containerd": executable file not found in $PATH
--8<---------------cut here---------------end--------------->8---

So, it seems the failure is related to kernel modules not being found
where they are looked for?

I think there were some changes recently in this area, but I haven't
followed closely.

Maxim




Information forwarded to bug-guix <at> gnu.org:
bug#38432; Package guix. (Mon, 01 Jun 2020 12:25:01 GMT) Full text and rfc822 format available.

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

From: Danny Milosavljevic <dannym <at> scratchpost.org>
To: Maxim Cournoyer <maxim.cournoyer <at> gmail.com>
Cc: andreoss <at> SDF.ORG, 38432 <at> debbugs.gnu.org
Subject: Re: bug#38432: dockerd is not started automatically
Date: Mon, 1 Jun 2020 14:24:54 +0200
[Message part 1 (text/plain, inline)]
Hi Maxim,

On Sun, 31 May 2020 23:27:30 -0400
Maxim Cournoyer <maxim.cournoyer <at> gmail.com> wrote:

> time="2020-05-31T22:28:15.885343166-04:00" level=warning msg="failed to load plugin io.containerd.snapshotter.v1.aufs" error="modprobe aufs failed: "modprobe: FATAL: Module aufs not found in directory /lib/modules/5.4.43-gnu\n": exit status 1" 

We don't have aufs, but it's not mandatory anyway.

> The only new lines to appear in docker.log following my last reboot are:
> 
> --8<---------------cut here---------------start------------->8---
> time="2020-05-31T22:28:13.579626539-04:00" level=info msg="Starting up"
> failed to start containerd: exec: "containerd": executable file not found in $PATH
> --8<---------------cut here---------------end--------------->8---
> 
> So, it seems the failure is related to kernel modules not being found
> where they are looked for?

I don't think so this time, at least according to these logs.

Could it be that containerd takes too long to start up or something?  And then it
tries to start it on its own?

To find out, try adding sleep to gnu/services/docker.scm docker-shepherd-service
before make-forkexec-constructor, to make it read

 #~(begin
     (sleep 2)
     (make-forkexec-constructor ....
[Message part 2 (application/pgp-signature, inline)]

Information forwarded to bug-guix <at> gnu.org:
bug#38432; Package guix. (Tue, 02 Jun 2020 01:00:02 GMT) Full text and rfc822 format available.

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

From: Maxim Cournoyer <maxim.cournoyer <at> gmail.com>
To: Danny Milosavljevic <dannym <at> scratchpost.org>
Cc: andreoss <at> SDF.ORG, 38432 <at> debbugs.gnu.org
Subject: Re: bug#38432: dockerd is not started automatically
Date: Mon, 01 Jun 2020 20:59:50 -0400
[Message part 1 (text/plain, inline)]
Hi Danny!

Danny Milosavljevic <dannym <at> scratchpost.org> writes:

> Hi Maxim,
>
> On Sun, 31 May 2020 23:27:30 -0400
> Maxim Cournoyer <maxim.cournoyer <at> gmail.com> wrote:
>
>> time="2020-05-31T22:28:15.885343166-04:00" level=warning msg="failed
>> to load plugin io.containerd.snapshotter.v1.aufs" error="modprobe
>> aufs failed: "modprobe: FATAL: Module aufs not found in directory
>> /lib/modules/5.4.43-gnu\n": exit status 1"
>
> We don't have aufs, but it's not mandatory anyway.
>
>> The only new lines to appear in docker.log following my last reboot are:
>> 
>> --8<---------------cut here---------------start------------->8---
>> time="2020-05-31T22:28:13.579626539-04:00" level=info msg="Starting up"
>> failed to start containerd: exec: "containerd": executable file not found in $PATH
>> --8<---------------cut here---------------end--------------->8---
>> 
>> So, it seems the failure is related to kernel modules not being found
>> where they are looked for?
>
> I don't think so this time, at least according to these logs.
>
> Could it be that containerd takes too long to start up or something?  And then it
> tries to start it on its own?
>
> To find out, try adding sleep to gnu/services/docker.scm docker-shepherd-service
> before make-forkexec-constructor, to make it read
>
>  #~(begin
>      (sleep 2)
>      (make-forkexec-constructor ....

It looks like this! Which is weird, because containerd doesn't take much
time to start, even when networking is not yet functional (I suspected
something like this at first).

I wonder what we can do here... looks like we need to poll containerd to
know when it's ready in the start procedure of dockerd (unless I'm
missing something fancier that Shepherd would allow doing).  Else we
could let dockerd spawn its own containerd daemon, which it can do if we
tell it where it is.

Thoughts?

I've made the following changes while troubleshooting this.  It only
printed a couple more lines, but I guess it's nice to have:

[0001-gnu-services-docker-Add-a-debug-parameter.patch (text/x-patch, attachment)]
[Message part 3 (text/plain, inline)]
Maxim

Information forwarded to bug-guix <at> gnu.org:
bug#38432; Package guix. (Tue, 02 Jun 2020 12:12:02 GMT) Full text and rfc822 format available.

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

From: Maxim Cournoyer <maxim.cournoyer <at> gmail.com>
To: Danny Milosavljevic <dannym <at> scratchpost.org>
Cc: andreoss <at> SDF.ORG, 38432 <at> debbugs.gnu.org
Subject: Re: bug#38432: dockerd is not started automatically
Date: Tue, 02 Jun 2020 08:11:48 -0400
Hello Danny!

The service definition here:
https://github.com/containerd/containerd/blob/master/containerd.service
uses the systemd notify mechanism to allow the application (containerd)
to message the init (systemd) that it is ready.

leoprikler on #guix had the idea to patch this away and replace it by
some code that'd write a PID file.  That's an interesting idea!  Even
nicer would be to have Shepherd listen on the socket that the sd_notify
mechanism relies on and natively support the systemd notify thing :-).

Food for thoughts...

Maxim




Merged 38432 55936. Request was from Maxim Cournoyer <maxim.cournoyer <at> gmail.com> to control <at> debbugs.gnu.org. (Fri, 24 Jun 2022 05:09:02 GMT) Full text and rfc822 format available.

Merged 38432 55936. Request was from Oleg Pykhalov <go.wigust <at> gmail.com> to control <at> debbugs.gnu.org. (Sat, 02 Jul 2022 11:41:02 GMT) Full text and rfc822 format available.

bug archived. Request was from Debbugs Internal Request <help-debbugs <at> gnu.org> to internal_control <at> debbugs.gnu.org. (Sat, 13 Aug 2022 11:24:05 GMT) Full text and rfc822 format available.

This bug report was last modified 1 year and 250 days ago.

Previous Next


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