Docker daemon failing to start on boot

Hi, I am having an issue with the docker daemon as a service in guixsd.

It seems that dockerd will not start on boot, but it will successfully

start after running "guix system reconfigure".

Here is my config.scm:

(use-modules (gnu)

(gnu system nss)

(gnu services)

(gnu services docker))

(use-service-modules desktop)

(use-package-modules certs gnome)

(operating-system

(host-name "guixsd")

(timezone "Europe/Oslo")

(locale "en_US.utf8")

(bootloader (bootloader-configuration

(bootloader grub-bootloader)

(target "/dev/sda")))

(file-systems (cons (file-system

(device (file-system-label "my-root"))

(mount-point "/")

(type "ext4"))

%base-file-systems))

(users (cons (user-account

(name "allana")

(group "users")

(supplementary-groups '("wheel" "docker" "netdev"

"audio" "video"))

(home-directory "/home/allana"))

%base-user-accounts))

;; This is where we specify system-wide packages.

(packages (cons* nss-certs ;for HTTPS access

gvfs ;for user mounts

%base-packages))

(services (cons* (console-keymap-service "no-latin1")

(gnome-desktop-service)

(service docker-service-type)

%desktop-services))

;; Allow resolution of '.local' host names with mDNS.

(name-service-switch %mdns-host-lookup-nss))

After booting:

allana@guixsd ~$ docker ps

Cannot connect to the Docker daemon at unix:///var/run/docker.sock. Is

the docker daemon running?

allana@guixsd ~$ sudo herd status dockerd

Password:

Status of dockerd:

It is stopped.

It is enabled.

Provides (dockerd).

Requires (containerd 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).

Conflicts with ().

Will be respawned.

allana@guixsd ~$ sudo herd start dockerd

Service dockerd could not be started.

herd: failed to start service dockerd

But if I run:

allana@guixsd ~$ sudo guix reconfigure config.scm

...

allana@guixsd ~$ docker ps

CONTAINER ID IMAGE COMMAND CREATED

STATUS PORTS NAMES

allana@guixsd ~$ sudo herd status dockerd

Password:

Status of dockerd:

It is started.

Running value is 2123.

It is enabled.

Provides (dockerd).

Requires (containerd 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).

Conflicts with ().

Will be respawned.

Dump from /var/log/messages:

Feb 5 10:06:37 localhost -- MARK --

Feb 5 10:15:47 localhost nscd: 319 monitored file `/etc/hosts` was

deleted, removing watch

Feb 5 10:15:47 localhost nscd: 319 monitored file `/etc/hosts` was

created, adding watch

Feb 5 10:15:47 localhost nscd: 319 monitored file `/etc/hosts` was

written to

Feb 5 10:15:47 localhost nscd: 319 monitored file `/etc/services` was

deleted, removing watch

Feb 5 10:15:47 localhost nscd: 319 monitored file `/etc/services` was

created, adding watch

Feb 5 10:15:47 localhost nscd: 319 monitored file `/etc/services` was

written to

Feb 5 10:15:47 localhost NetworkManager[355]: <info> [1549358147.5315]

settings: hostname changed from (none) to "guixsd"

Feb 5 10:15:48 localhost shepherd[1]: Evaluating user expression (let*

((services (map primitive-load (?))) # ?) ?).

Feb 5 10:15:48 localhost shepherd[1]: Service user-homes could not be

started.

Feb 5 10:15:48 localhost shepherd[1]: Service term-auto could not be

started.

Feb 5 10:15:49 localhost vmunix: [ 2965.192083] bridge: filtering via

arp/ip/ip6tables is no longer available by default. Update your scripts

to load br_netfilter if you need this.

Feb 5 10:15:49 localhost vmunix: [ 2965.194289] Bridge firewalling

registered

Feb 5 10:15:49 localhost vmunix: [ 2965.405743] Initializing XFRM

netlink socket

Feb 5 10:15:49 localhost NetworkManager[355]: <info> [1549358149.2361]

manager: (docker0): new Bridge device

(/org/freedesktop/NetworkManager/Devices/3)

Feb 5 10:15:49 localhost avahi-daemon[361]: Joining mDNS multicast

group on interface docker0.IPv4 with address 172.17.0.1.

Feb 5 10:15:49 localhost NetworkManager[355]: <info> [1549358149.3174]

device (docker0): state change: unmanaged -> unavailable (reason

'connection-assumed', internal state 'external')

Feb 5 10:15:49 localhost vmunix: [ 2965.500493] IPv6:

ADDRCONF(NETDEV_UP): docker0: link is not ready

Feb 5 10:15:49 localhost avahi-daemon[361]: New relevant interface

docker0.IPv4 for mDNS.

Feb 5 10:15:49 localhost NetworkManager[355]: <info> [1549358149.3195]

keyfile: add connection in-memory

(33e2c9e2-62a1-4439-8fb5-be99034ffc7b,"docker0")

Feb 5 10:15:49 localhost avahi-daemon[361]: Registering new address

record for 172.17.0.1 on docker0.IPv4.

Feb 5 10:15:49 localhost NetworkManager[355]: <info> [1549358149.3203]

device (docker0): state change: unavailable -> disconnected (reason

'connection-assumed', internal state 'external')

Feb 5 10:15:49 localhost NetworkManager[355]: <info> [1549358149.3223]

device (docker0): Activation: starting connection 'docker0'

(33e2c9e2-62a1-4439-8fb5-be99034ffc7b)

Feb 5 10:15:49 localhost NetworkManager[355]: <info> [1549358149.3236]

device (docker0): state change: disconnected -> prepare (reason 'none',

internal state 'external')

Feb 5 10:15:49 localhost NetworkManager[355]: <info> [1549358149.3243]

device (docker0): state change: prepare -> config (reason 'none',

internal state 'external')

Feb 5 10:15:49 localhost NetworkManager[355]: <info> [1549358149.3247]

device (docker0): state change: config -> ip-config (reason 'none',

internal state 'external')

Feb 5 10:15:49 localhost NetworkManager[355]: <warn> [1549358149.3321]

arping[0x82cc80,3]: arping could not be found; no ARPs will be sent

Feb 5 10:15:49 localhost NetworkManager[355]: <info> [1549358149.3322]

device (docker0): state change: ip-config -> ip-check (reason 'none',

internal state 'external')

Feb 5 10:15:49 localhost NetworkManager[355]: <info> [1549358149.3462]

device (docker0): state change: ip-check -> secondaries (reason 'none',

internal state 'external')

Feb 5 10:15:49 localhost NetworkManager[355]: <info> [1549358149.3508]

device (docker0): state change: secondaries -> activated (reason 'none',

internal state 'external')

Feb 5 10:15:49 localhost NetworkManager[355]: <info> [1549358149.3528]

device (docker0): Activation: successful, device activated.

Feb 5 10:15:49 localhost shepherd[1]: Service dockerd has been started.

Feb 5 10:15:51 localhost NetworkManager[355]: <warn> [1549358151.9250]

arping[0x82cc80,3]: arping could not be found; no ARPs will be sent

Feb 5 10:16:10 localhost shepherd[1]: Exiting shepherd...

Feb 5 10:16:10 localhost ntpd[356]: ntpd exiting on signal 15

(Terminated)

Feb 5 10:16:10 localhost ntpd[356]: 80.89.32.122 local addr 10.0.2.15

-> <null>

Feb 5 10:16:10 localhost ntpd[356]: 31.185.27.200 local addr 10.0.2.15

-> <null>

Feb 5 10:16:10 localhost ntpd[356]: 92.62.34.78 local addr 10.0.2.15 ->

<null>

Feb 5 10:16:10 localhost syslogd: exiting on signal 15

Feb 5 10:16:49 localhost syslogd (GNU inetutils 1.9.4): restart

Feb 5 10:16:49 localhost vmunix: [ 0.000000] Linux version

4.20.6-gnu (nixbld@) (gcc version 7.4.0 (GCC)) #1 SMP 1

Feb 5 10:16:49 localhost vmunix: [ 0.000000] Command line:

BOOT_IMAGE=/gnu/store/fnpq4ndcjyai0rqlgj8x02qwlm88fc9d-linux-libre-4.20.6/bzImage

--root=my-root

--system=/gnu/store/b93pw0x9z120bilhiicics30f5y8fgj6-system

--load=/gnu/store/b93pw0x9z120bilhiicics30f5y8fgj6-system/boot

Feb 5 10:16:49 localhost vmunix: [ 0.000000] KERNEL supported cpus:

Feb 5 10:16:49 localhost vmunix: [ 0.000000] Intel GenuineIntel

Feb 5 10:16:49 localhost vmunix: [ 0.000000] AMD AuthenticAMD

Feb 5 10:16:49 localhost vmunix: [ 0.000000] Hygon HygonGenuine

Feb 5 10:16:49 localhost vmunix: [ 0.000000] Centaur CentaurHauls

Feb 5 10:16:49 localhost vmunix: [ 0.000000] x86/fpu: Supporting

XSAVE feature 0x001: 'x87 floating point registers'

Feb 5 10:16:49 localhost vmunix: [ 0.000000] x86/fpu: Supporting

XSAVE feature 0x002: 'SSE registers'

Feb 5 10:16:49 localhost vmunix: [ 0.000000] x86/fpu: Supporting

XSAVE feature 0x004: 'AVX registers'

Feb 5 10:16:49 localhost vmunix: [ 0.000000] x86/fpu:

xstate_offset[2]: 576, xstate_sizes[2]: 256

Feb 5 10:16:49 localhost vmunix: [ 0.000000] x86/fpu: Enabled xstate

features 0x7, context size is 832 bytes, using 'standard' format.

Feb 5 10:16:49 localhost vmunix: [ 0.000000] BIOS-provided physical

RAM map:

Feb 5 10:16:49 localhost vmunix: [ 0.000000] BIOS-e820: [mem

0x0000000000000000-0x000000000009fbff] usable

Feb 5 10:16:49 localhost vmunix: [ 0.000000] BIOS-e820: [mem

0x000000000009fc00-0x000000000009ffff] reserved

Feb 5 10:16:49 localhost vmunix: [ 0.000000] BIOS-e820: [mem

0x00000000000f0000-0x00000000000fffff] reserved

Feb 5 10:16:49 localhost vmunix: [ 0.000000] BIOS-e820: [mem

0x0000000000100000-0x00000000dffeffff] usable

Feb 5 10:16:49 localhost vmunix: [ 0.000000] BIOS-e820: [mem

0x00000000dfff0000-0x00000000dfffffff] ACPI data

Feb 5 10:16:49 localhost vmunix: [ 0.000000] BIOS-e820: [mem

0x00000000fec00000-0x00000000fec00fff] reserved

Feb 5 10:16:49 localhost vmunix: [ 0.000000] BIOS-e820: [mem

0x00000000fee00000-0x00000000fee00fff] reserved

Feb 5 10:16:49 localhost vmunix: [ 0.000000] BIOS-e820: [mem

0x00000000fffc0000-0x00000000ffffffff] reserved

Feb 5 10:16:49 localhost vmunix: [ 0.000000] BIOS-e820: [mem

0x0000000100000000-0x000000019fffffff] usable

Feb 5 10:16:49 localhost vmunix: [ 0.000000] NX (Execute Disable)

protection: active

Feb 5 10:16:49 localhost vmunix: [ 0.000000] SMBIOS 2.5 present.

Feb 5 10:16:49 localhost vmunix: [ 0.000000] DMI: innotek GmbH

VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006

Feb 5 10:16:49 localhost vmunix: [ 0.000000] Hypervisor detected:

KVM

Feb 5 10:16:49 localhost vmunix: [ 0.000000] kvm-clock: Using msrs

4b564d01 and 4b564d00

Feb 5 10:16:49 localhost shepherd[1]: Service syslogd has been started.

Feb 5 10:16:49 localhost vmunix: [ 0.000001] kvm-clock: cpu 0, msr

13a574001, primary cpu clock

Feb 5 10:16:49 localhost vmunix: [ 0.000001] kvm-clock: using sched

offset of 5879650815 cycles

Feb 5 10:16:49 localhost vmunix: [ 0.000006] clocksource: kvm-clock:

mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns:

881590591483 ns

Feb 5 10:16:49 localhost vmunix: [ 0.000012] tsc: Detected 2904.004

MHz processor

Feb 5 10:16:49 localhost vmunix: [ 0.004133] last_pfn = 0x1a0000

max_arch_pfn = 0x400000000

Feb 5 10:16:49 localhost vmunix: [ 0.004164] Disabled

Feb 5 10:16:49 localhost vmunix: [ 0.004167] x86/PAT: MTRRs

disabled, skipping PAT initialization too.

Feb 5 10:16:49 localhost vmunix: [ 0.004174] CPU MTRRs all blank -

virtualized system.

Feb 5 10:16:49 localhost vmunix: [ 0.004182] x86/PAT: Configuration

[0-7]: WB WT UC- UC WB WT UC- UC

Feb 5 10:16:49 localhost vmunix: [ 0.004192] last_pfn = 0xdfff0

max_arch_pfn = 0x400000000

Feb 5 10:16:49 localhost shepherd[1]: Service loopback has been

started.

Feb 5 10:16:49 localhost vmunix: [ 0.004273] found SMP MP-table at

[mem 0x0009fff0-0x0009ffff] mapped at [(____ptrval____)]

Feb 5 10:16:49 localhost vmunix: [ 0.140871] check: Scanning 1 areas

for low memory corruption

Feb 5 10:16:49 localhost vmunix: [ 0.141648] RAMDISK: [mem

0x36a51000-0x3751ffff]

Feb 5 10:16:49 localhost vmunix: [ 0.141660] ACPI: Early table

checksum verification disabled

Feb 5 10:16:49 localhost vmunix: [ 0.141686] ACPI: RSDP

0x00000000000E0000 000024 (v02 VBOX )

Feb 5 10:16:49 localhost shepherd[1]: Service virtual-terminal has been

started.

Feb 5 10:16:49 localhost vmunix: [ 0.141695] ACPI: XSDT

0x00000000DFFF0030 00003C (v01 VBOX VBOXXSDT 00000001 ASL 00000061)

Feb 5 10:16:49 localhost vmunix: [ 0.141702] ACPI: FACP

0x00000000DFFF00F0 0000F4 (v04 VBOX VBOXFACP 00000001 ASL 00000061)

Feb 5 10:16:49 localhost vmunix: [ 0.141708] ACPI: DSDT

0x00000000DFFF0470 0021FF (v02 VBOX VBOXBIOS 00000002 INTL 20100528)

Feb 5 10:16:49 localhost vmunix: [ 0.141712] ACPI: FACS

0x00000000DFFF0200 000040

Feb 5 10:16:49 localhost vmunix: [ 0.141716] ACPI: FACS

0x00000000DFFF0200 000040

Feb 5 10:16:49 localhost vmunix: [ 0.141719] ACPI: APIC

0x00000000DFFF0240 00005C (v02 VBOX VBOXAPIC 00000001 ASL 00000061)

Feb 5 10:16:49 localhost vmunix: [ 0.141723] ACPI: SSDT

0x00000000DFFF02A0 0001CC (v01 VBOX VBOXCPUT 00000002 INTL 20100528)

Feb 5 10:16:49 localhost vmunix: [ 0.141963] No NUMA configuration

found

Feb 5 10:16:49 localhost vmunix: [ 0.141966] Faking a node at [mem

0x0000000000000000-0x000000019fffffff]

Feb 5 10:16:49 localhost vmunix: [ 0.141970] NODE_DATA(0) allocated

[mem 0x19fffa000-0x19fffdfff]

Feb 5 10:16:49 localhost vmunix: [ 0.142680] Zone ranges:

Feb 5 10:16:49 localhost vmunix: [ 0.142684] DMA32 [mem

0x0000000000001000-0x00000000ffffffff]

Feb 5 10:16:49 localhost shepherd[1]: Service term-tty6 has been

started.

Feb 5 10:16:49 localhost vmunix: [ 0.142686] Normal [mem

0x0000000100000000-0x000000019fffffff]

Feb 5 10:16:49 localhost vmunix: [ 0.142688] Device empty

Feb 5 10:16:49 localhost vmunix: [ 0.142690] Movable zone start for

each node

Feb 5 10:16:49 localhost vmunix: [ 0.142692] Early memory node

ranges

Feb 5 10:16:49 localhost vmunix: [ 0.142694] node 0: [mem

0x0000000000001000-0x000000000009efff]

Feb 5 10:16:49 localhost vmunix: [ 0.142695] node 0: [mem

0x0000000000100000-0x00000000dffeffff]

Feb 5 10:16:49 localhost vmunix: [ 0.142697] node 0: [mem

0x0000000100000000-0x000000019fffffff]

Feb 5 10:16:49 localhost vmunix: [ 0.143870] Zeroed struct page in

unavailable ranges: 114 pages

Feb 5 10:16:49 localhost vmunix: [ 0.143873] Initmem setup node 0

[mem 0x0000000000001000-0x000000019fffffff]

Feb 5 10:16:49 localhost vmunix: [ 0.225477] ACPI: PM-Timer IO Port:

0x4008

Feb 5 10:16:49 localhost shepherd[1]: Service term-tty5 has been

started.

Feb 5 10:16:49 localhost vmunix: [ 0.225571] IOAPIC[0]: apic_id 2,

version 32, address 0xfec00000, GSI 0-23

Feb 5 10:16:49 localhost vmunix: [ 0.225576] ACPI: INT_SRC_OVR (bus

0 bus_irq 0 global_irq 2 dfl dfl)

Feb 5 10:16:49 localhost vmunix: [ 0.225578] ACPI: INT_SRC_OVR (bus

0 bus_irq 9 global_irq 9 low level)

Feb 5 10:16:49 localhost vmunix: [ 0.225585] Using ACPI (MADT) for

SMP configuration information

Feb 5 10:16:49 localhost vmunix: [ 0.225593] smpboot: Allowing 2

CPUs, 0 hotplug CPUs

Feb 5 10:16:49 localhost vmunix: [ 0.225614] PM: Registered nosave

memory: [mem 0x00000000-0x00000fff]

Feb 5 10:16:49 localhost vmunix: [ 0.225617] PM: Registered nosave

memory: [mem 0x0009f000-0x0009ffff]

Feb 5 10:16:49 localhost vmunix: [ 0.225619] PM: Registered nosave

memory: [mem 0x000a0000-0x000effff]

Feb 5 10:16:49 localhost vmunix: [ 0.225621] PM: Registered nosave

memory: [mem 0x000f0000-0x000fffff]

Feb 5 10:16:49 localhost vmunix: [ 0.225623] PM: Registered nosave

memory: [mem 0xdfff0000-0xdfffffff]

Feb 5 10:16:49 localhost vmunix: [ 0.225625] PM: Registered nosave

memory: [mem 0xe0000000-0xfebfffff]

Feb 5 10:16:49 localhost vmunix: [ 0.225627] PM: Registered nosave

memory: [mem 0xfec00000-0xfec00fff]

Feb 5 10:16:49 localhost shepherd[1]: Service term-tty4 has been

started.

Feb 5 10:16:49 localhost vmunix: [ 0.225629] PM: Registered nosave

memory: [mem 0xfec01000-0xfedfffff]

Feb 5 10:16:49 localhost vmunix: [ 0.225631] PM: Registered nosave

memory: [mem 0xfee00000-0xfee00fff]

Feb 5 10:16:49 localhost vmunix: [ 0.225633] PM: Registered nosave

memory: [mem 0xfee01000-0xfffbffff]

Feb 5 10:16:49 localhost vmunix: [ 0.225635] PM: Registered nosave

memory: [mem 0xfffc0000-0xffffffff]

Feb 5 10:16:49 localhost vmunix: [ 0.225638] [mem

0xe0000000-0xfebfffff] available for PCI devices

Feb 5 10:16:49 localhost vmunix: [ 0.225640] Booting paravirtualized

kernel on KVM

Feb 5 10:16:49 localhost vmunix: [ 0.225645] clocksource:

refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns:

7645519600211568 ns

Feb 5 10:16:49 localhost vmunix: [ 0.225656] random:

get_random_bytes called from start_kernel+0x99/0x51c with crng_init=0

Feb 5 10:16:49 localhost vmunix: [ 0.225662] setup_percpu:

NR_CPUS:256 nr_cpumask_bits:256 nr_cpu_ids:2 nr_node_ids:1

Feb 5 10:16:49 localhost vmunix: [ 0.226183] percpu: Embedded 45

pages/cpu @(____ptrval____) s146840 r8192 d29288 u1048576

Feb 5 10:16:49 localhost shepherd[1]: Service term-tty3 has been

started.

Feb 5 10:16:49 localhost vmunix: [ 0.226218] PV qspinlock hash table

entries: 256 (order: 0, 4096 bytes)

Feb 5 10:16:49 localhost vmunix: [ 0.226224] Built 1 zonelists,

mobility grouping on. Total pages: 1548154

Feb 5 10:16:49 localhost vmunix: [ 0.226226] Policy zone: Normal

Feb 5 10:16:49 localhost vmunix: [ 0.226229] Kernel command line:

BOOT_IMAGE=/gnu/store/fnpq4ndcjyai0rqlgj8x02qwlm88fc9d-linux-libre-4.20.6/bzImage

--root=my-root

--system=/gnu/store/b93pw0x9z120bilhiicics30f5y8fgj6-system

--load=/gnu/store/b93pw0x9z120bilhiicics30f5y8fgj6-system/boot

Feb 5 10:16:49 localhost vmunix: [ 0.252611] Memory:

6090508K/6291000K available (12293K kernel code, 1470K rwdata, 3984K

rodata, 1836K init, 2724K bss, 200492K reserved, 0K cma-reserved)

Feb 5 10:16:49 localhost vmunix: [ 0.253199] SLUB: HWalign=64,

Order=0-3, MinObjects=0, CPUs=2, Nodes=1

Feb 5 10:16:49 localhost vmunix: [ 0.253218] Kernel/User page tables

isolation: enabled

Feb 5 10:16:49 localhost vmunix: [ 0.253238] ftrace: allocating

39556 entries in 155 pages

Feb 5 10:16:49 localhost vmunix: [ 0.286687] rcu: Hierarchical RCU

implementation.

Feb 5 10:16:49 localhost shepherd[1]: Service term-tty2 has been

started.

Feb 5 10:16:49 localhost vmunix: [ 0.286691] rcu: RCU restricting

CPUs from NR_CPUS=256 to nr_cpu_ids=2.

Feb 5 10:16:49 localhost vmunix: [ 0.286694] rcu: RCU calculated

value of scheduler-enlistment delay is 25 jiffies.

Feb 5 10:16:49 localhost vmunix: [ 0.286695] rcu: Adjusting geometry

for rcu_fanout_leaf=16, nr_cpu_ids=2

Feb 5 10:16:49 localhost vmunix: [ 0.291153] NR_IRQS: 16640,

nr_irqs: 440, preallocated irqs: 16

Feb 5 10:16:49 localhost vmunix: [ 0.306506] Console: colour VGA+

80x25

Feb 5 10:16:49 localhost vmunix: [ 0.351776] printk: console [tty0]

enabled

Feb 5 10:16:49 localhost vmunix: [ 0.352163] ACPI: Core revision

20181003

Feb 5 10:16:49 localhost vmunix: [ 0.352640] APIC: Switch to

symmetric I/O mode setup

Feb 5 10:16:49 localhost vmunix: [ 0.353395] x2apic enabled

Feb 5 10:16:49 localhost vmunix: [ 0.354008] Switched APIC routing

to physical x2apic.

Feb 5 10:16:49 localhost vmunix: [ 0.355939] ..TIMER: vector=0x30

apic1=0 pin1=2 apic2=-1 pin2=-1

Feb 5 10:16:49 localhost vmunix: [ 0.356365] clocksource: tsc-early:

mask: 0xffffffffffffffff max_cycles: 0x29dc09beef1, max_idle_ns:

440795310252 ns

Feb 5 10:16:49 localhost vmunix: [ 0.357056] Calibrating delay loop

(skipped) preset value.. 5808.00 BogoMIPS (lpj=11616016)

Feb 5 10:16:49 localhost vmunix: [ 0.357657] pid_max: default: 32768

minimum: 301

Feb 5 10:16:49 localhost vmunix: [ 0.357979] LSM: Security Framework

initializing

Feb 5 10:16:49 localhost shepherd[1]: Service term-tty1 has been

starte

Hello,

allan@adair.io skribis:

[...]

This is what happens at boot time:

[...]

[...]

Danny, could it be that the ‘docker’ service should depend on

‘networking’?

FWIW, “make check-system TESTS=docker” passes for me.

Thanks,

Ludo’.

On Fri, 08 Feb 2019 22:55:48 +0100

Ludovic Courtès <ludo@gnu.org> wrote:

Might be the case. They certainly muck around a lot with networking,

so it can't hurt to wait until host networking is set up.

I've added it--let's see.

Allan, can you guix pull and guix reconfigure and then try again?

On 2019-02-11 10:46, Danny Milosavljevic wrote:

I guix pulled and guix system reconfigured. After a successful

reconfigure and reboot, the service was still not started.

--

Allan Adair

+47 468 12 135

allan@adair.io

On Mon, 11 Feb 2019 13:11:33 +0000

Allan Adair <allan@adair.io> wrote:

Hmm, is the "containerd" process running? (pidof containerd)

Hi Allan,

I've added some more requirements--let's see.

Can you guix pull and guix reconfigure and then try again once more?

On 2019-02-11 17:31, Danny Milosavljevic wrote:

Still no luck. Do you face the same issue?

--

Allan Adair

+47 468 12 135

allan@adair.io

Hi Allan,

On Tue, 12 Feb 2019 09:05:10 +0000

Allan Adair <allan@adair.io> wrote:

I don't know since my machine has not finished updating after the

recent staging to master merge.

Hey Danny.

I'm curious to know if the dockerd service type works for you. It does

not work for me, but maybe I am doing something wrong. Below is my

current config.scm:

(use-modules (gnu)

(gnu system nss)

(gnu services))

(use-service-modules desktop docker)

(use-package-modules certs gnome)

(operating-system

(host-name "guixsd")

(timezone "Europe/Oslo")

(locale "en_US.utf8")

(bootloader (bootloader-configuration

(bootloader grub-bootloader)

(target "/dev/sda")))

(file-systems (cons (file-system

(device (file-system-label "my-root"))

(mount-point "/")

(type "ext4"))

%base-file-systems))

(users (cons (user-account

(name "allana")

(group "users")

(supplementary-groups '("wheel"

"docker"

"netdev"

"audio"

"video"))

(home-directory "/home/allana"))

%base-user-accounts))

;; This is where we specify system-wide packages.

(packages (cons* nss-certs ;for HTTPS access

gvfs ;for user mounts

%base-packages))

(services (cons* (console-keymap-service "no-latin1")

(gnome-desktop-service)

(service docker-service-type)

%desktop-services))

;; Allow resolution of '.local' host names with mDNS.

(name-service-switch %mdns-host-lookup-nss))

After a "guix system reconfigure", it works -- meaning that the dockerd

service starts. But when booting in the future, the dockerd

daemon never starts. I am however able to execute "sudo herd start

dockerd" after booting because I have included dockerd in my user

profile. I can also "guix system reconfigure" at this point to start

the dockerd service, but then at the next boot it will still not start.

Danny Milosavljevic writes:

--

Allan Adair

On Wed, 27 Feb 2019 15:17:14 +0100

Allan Adair <allan@adair.io> wrote:

I can confirm this behaviour, though I haven't yet investigated it

further.

Björn

On Wed, Feb 27, 2019 at 04:53:27PM +0100, Bjï¿œrn Hï¿œfling wrote:

Could this be yet another manifestation of

https://debbugs.gnu.org/cgi/bugreport.cgi?bug=34580?

Services not started on boot?

Andreas

Andreas Enge writes:

I'm not so sure. One thing that I am unable to do is "herd start

dockerd".

--

Allan Adair

On Fri, Mar 01, 2019 at 09:58:20AM +0100, Allan Adair wrote:

You mean, you are not able to start it via

sudo su -

herd start dockerd

?

It is normal that you cannot start services as a normal user.

Andreas

On Fri, 1 Mar 2019 14:09:32 +0100

Andreas Enge <andreas@enge.fr> wrote:

I wondered about that too.

For me, a "sudo herd start dockerd" works. After that, I can use the

docker-cli tools to work with docker images and containers. They deploy

and run fine.

Björn

Björn Höfling writes:

After a fresh boot:

allana@guixsd ~$ docker ps

Cannot connect to the Docker daemon at unix:///var/run/docker.sock. Is the docker daemon running?

allana@guixsd ~$ 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 networking udev).

Conflicts with ().

Will be respawned.

allana@guixsd ~$ sudo herd start dockerd

Service dockerd could not be started.

herd: failed to start service dockerd

--

Allan Adair

Hi,

On Fri, 01 Mar 2019 14:50:39 +0100

Allan Adair <allan@adair.io> wrote:

In a way that's good that this failure is reproducible so well.

"herd start dockerd" would do:

$(guix build docker)/bin/dockerd -p /var/run/docker.pid

For debugging, can you please try invoking the latter instead

of "herd start dockerd" ?

After that, please try

$(guix build docker)/bin/dockerd -p /var/run/docker.pid -D

Hi Danny.

Sorry for the late response. I was offline for the last week or so.

I ended up having to repeat the first command with sudo

privileges. Please see below.

Danny Milosavljevic writes:

allana@guixsd ~$ $(guix build docker)/bin/dockerd -p /var/run/docker.pid

substitute: updating substitutes from 'https://ci.guix.info'... 100.0%

substitute: updating substitutes from 'https://ci.guix.info'... 100.0%

substitute: updating substitutes from 'https://ci.guix.info'... 100.0%

substitute: updating substitutes from 'https://ci.guix.info'... 100.0%

93.1 MB will be downloaded:

/gnu/store/fqzdfac28a7h0wsxz6wdgjym491klbqh-docker-18.09.2

/gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2

/gnu/store/cqd3yimzpj0r29l3dyh8xcqbx70cbanc-xfsprogs-4.20.0

/gnu/store/hz2mq9wpddaifn2sij5msswhzzf8136b-iproute2-4.20.0

/gnu/store/pg3jsf0sp6p66lr6r0bfyz1lx2n6jb2b-containerd-1.2.4

The following graft will be made:

/gnu/store/a9frz994s0qiq6iay6yhfii8swvz6yyp-docker-18.09.2.drv

substituting /gnu/store/pg3jsf0sp6p66lr6r0bfyz1lx2n6jb2b-containerd-1.2.4...

downloading from https://ci.guix.info/nar/gzip/pg3jsf0sp6p66lr6r0bfyz1lx2n6jb2b-containerd-1.2.4...

containerd-1.2.4 35.5MiB 1.5MiB/s 00:23 [##################] 100.0%

substituting /gnu/store/y3zh0rhc25vakfl4q49sxs8kzcqm8bhi-libnftnl-1.1.2...

downloading from https://ci.guix.info/nar/gzip/y3zh0rhc25vakfl4q49sxs8kzcqm8bhi-libnftnl-1.1.2...

libnftnl-1.1.2 85KiB 1.8MiB/s 00:00 [##################] 100.0%

substituting /gnu/store/cqd3yimzpj0r29l3dyh8xcqbx70cbanc-xfsprogs-4.20.0...

downloading from https://ci.guix.info/nar/gzip/cqd3yimzpj0r29l3dyh8xcqbx70cbanc-xfsprogs-4.20.0...

xfsprogs-4.20.0 2.3MiB 1.4MiB/s 00:02 [##################] 100.0%

substituting /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2...

downloading from https://ci.guix.info/nar/gzip/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2...

iptables-1.6.2 555KiB 2.4MiB/s 00:00 [##################] 100.0%

substituting /gnu/store/hz2mq9wpddaifn2sij5msswhzzf8136b-iproute2-4.20.0...

downloading from https://ci.guix.info/nar/gzip/hz2mq9wpddaifn2sij5msswhzzf8136b-iproute2-4.20.0...

iproute2-4.20.0 1.0MiB 3.3MiB/s 00:00 [##################] 100.0%

substituting /gnu/store/fqzdfac28a7h0wsxz6wdgjym491klbqh-docker-18.09.2...

downloading from https://ci.guix.info/nar/gzip/fqzdfac28a7h0wsxz6wdgjym491klbqh-docker-18.09.2...

docker-18.09.2 49.5MiB 1.5MiB/s 00:33 [##################] 100.0%

applying 1 graft for /gnu/store/a9frz994s0qiq6iay6yhfii8swvz6yyp-docker-18.09.2.drv...

grafting '/gnu/store/fqzdfac28a7h0wsxz6wdgjym491klbqh-docker-18.09.2' -> '/gnu/store/2vf8f8bky5jlifghqgl92n7a3vx6icid-docker-18.09.2'...

successfully built /gnu/store/a9frz994s0qiq6iay6yhfii8swvz6yyp-docker-18.09.2.drv

chmod /var/lib/docker: operation not permitted

allana@guixsd ~$ sudo $(guix build docker)/bin/dockerd -p /var/run/docker.pid

Password:

INFO[2019-03-11T09:55:18.870049018+01:00] parsed scheme: "unix" module=grpc

INFO[2019-03-11T09:55:18.870157978+01:00] scheme "unix" not registered, fallback to default scheme module=grpc

INFO[2019-03-11T09:55:18.870220789+01:00] parsed scheme: "unix" module=grpc

INFO[2019-03-11T09:55:18.870263818+01:00] scheme "unix" not registered, fallback to default scheme module=grpc

INFO[2019-03-11T09:55:18.870988104+01:00] ccResolverWrapper: sending new addresses to cc: [{unix:///run/containerd/containerd.sock 0 <nil>}] module=grpc

INFO[2019-03-11T09:55:18.871011336+01:00] ClientConn switching balancer to "pick_first" module=grpc

INFO[2019-03-11T09:55:18.871121368+01:00] ccResolverWrapper: sending new addresses to cc: [{unix:///run/containerd/containerd.sock 0 <nil>}] module=grpc

INFO[2019-03-11T09:55:18.871135562+01:00] ClientConn switching balancer to "pick_first" module=grpc

INFO[2019-03-11T09:55:18.871191852+01:00] pickfirstBalancer: HandleSubConnStateChange: 0xc00094bd80, CONNECTING module=grpc

INFO[2019-03-11T09:55:18.871490772+01:00] pickfirstBalancer: HandleSubConnStateChange: 0xc00094bd80, READY module=grpc

INFO[2019-03-11T09:55:18.872052533+01:00] pickfirstBalancer: HandleSubConnStateChange: 0xc0007aa120, CONNECTING module=grpc

INFO[2019-03-11T09:55:18.872637966+01:00] pickfirstBalancer: HandleSubConnStateChange: 0xc0007aa120, READY module=grpc

INFO[2019-03-11T09:55:18.956930716+01:00] [graphdriver] using prior storage driver: overlay2

INFO[2019-03-11T09:55:19.446624398+01:00] Graph migration to content-addressability took 0.00 seconds

WARN[2019-03-11T09:55:19.446793841+01:00] Your kernel does not support swap memory limit

WARN[2019-03-11T09:55:19.446839108+01:00] Your kernel does not support cgroup rt period

WARN[2019-03-11T09:55:19.446851151+01:00] Your kernel does not support cgroup rt runtime

WARN[2019-03-11T09:55:19.446944180+01:00] mountpoint for pids not found

INFO[2019-03-11T09:55:19.447094857+01:00] Loading containers: start.

INFO[2019-03-11T09:55:19.806237867+01:00] Default bridge (docker0) is assigned with an IP address 172.17.0.0/16. Daemon option --bip can be used to set a preferred IP address

INFO[2019-03-11T09:55:19.879444062+01:00] Loading containers: done.

WARN[2019-03-11T09:55:19.879977264+01:00] Could not get operating system name: Error opening /usr/lib/os-release: open /usr/lib/os-release: no such file or directory

WARN[2019-03-11T09:55:19.959765663+01:00] failed to retrieve /gnu/store/l6nqfq4vyzaxjk8xygm4vr203p04430g-runc-1.0.0-rc6/sbin/runc version: unknown output format: runc version 1.0.0-rc6

spec: 1.0.1-dev

WARN[2019-03-11T09:55:19.960225775+01:00] failed to retrieve docker-init version: exec: "docker-init": executable file not found in $PATH

INFO[2019-03-11T09:55:20.010894492+01:00] Docker daemon commit=v18.09.2 graphdriver(s)=overlay2 version=dev

INFO[2019-03-11T09:55:20.011355589+01:00] Daemon has completed initialization

INFO[2019-03-11T09:55:20.047488136+01:00] API listen on /var/run/docker.sock

^CINFO[2019-03-11T09:55:37.423979436+01:00] Processing signal 'interrupt'

INFO[2019-03-11T09:55:37.424612060+01:00] stopping event stream following graceful shutdown error="<nil>" module=libcontainerd namespace=moby

allana@guixsd ~$ sudo $(guix build docker)/bin/dockerd -p /var/run/docker.pid -D

DEBU[2019-03-11T09:56:04.702178848+01:00] Listener created for HTTP on unix (/var/run/docker.sock)

DEBU[2019-03-11T09:56:04.705370926+01:00] Golang's threads limit set to 42750

INFO[2019-03-11T09:56:04.705630548+01:00] parsed scheme: "unix" module=grpc

INFO[2019-03-11T09:56:04.705647118+01:00] scheme "unix" not registered, fallback to default scheme module=grpc

INFO[2019-03-11T09:56:04.705671668+01:00] parsed scheme: "unix" module=grpc

INFO[2019-03-11T09:56:04.705728970+01:00] scheme "unix" not registered, fallback to default scheme module=grpc

DEBU[2019-03-11T09:56:04.705848912+01:00] Using default logging driver json-file

DEBU[2019-03-11T09:56:04.705997733+01:00] [graphdriver] priority list: [btrfs zfs overlay2 aufs overlay devicemapper vfs]

INFO[2019-03-11T09:56:04.706176881+01:00] ccResolverWrapper: sending new addresses to cc: [{unix:///run/containerd/containerd.sock 0 <nil>}] module=grpc

INFO[2019-03-11T09:56:04.706204607+01:00] ClientConn switching balancer to "pick_first" module=grpc

INFO[2019-03-11T09:56:04.706358229+01:00] pickfirstBalancer: HandleSubConnStateChange: 0xc000476fa0, CONNECTING module=grpc

INFO[2019-03-11T09:56:04.706883252+01:00] ccResolverWrapper: sending new addresses to cc: [{unix:///run/containerd/containerd.sock 0 <nil>}] module=grpc

INFO[2019-03-11T09:56:04.706955511+01:00] ClientConn switching balancer to "pick_first" module=grpc

INFO[2019-03-11T09:56:04.707033402+01:00] pickfirstBalancer: HandleSubConnStateChange: 0xc00012f890, CONNECTING module=grpc

INFO[2019-03-11T09:56:04.707276723+01:00] pickfirstBalancer: HandleSubConnStateChange: 0xc00012f890, READY module=grpc

DEBU[2019-03-11T09:56:04.707364455+01:00] processing event stream module=libcontainerd namespace=plugins.moby

INFO[2019-03-11T09:56:04.707645989+01:00] pickfirstBalancer: HandleSubConnStateChange: 0xc000476fa0, READY module=grpc

DEBU[2019-03-11T09:56:04.709345382+01:00] backingFs=extfs, projectQuotaSupported=false, indexOff="index=off," storage-driver=overlay2

INFO[2019-03-11T09:56:04.709365553+01:00] [graphdriver] using prior storage driver: overlay2

DEBU[2019-03-11T09:56:04.709375543+01:00] Initialized graph driver overlay2

INFO[2019-03-11T09:56:04.869373608+01:00] Graph migration to content-addressability took 0.00 seconds

WARN[2019-03-11T09:56:04.869724040+01:00] Your kernel does not support swap memory limit

WARN[2019-03-11T09:56:04.869848963+01:00] Your kernel does not support cgroup rt period

WARN[2019-03-11T09:56:04.869913102+01:00] Your kernel does not support cgroup rt runtime

WARN[2019-03-11T09:56:04.870102948+01:00] mountpoint for pids not found

DEBU[2019-03-11T09:56:04.870502775+01:00] Max Concurrent Downloads: 3

DEBU[2019-03-11T09:56:04.870602223+01:00] Max Concurrent Uploads: 5

INFO[2019-03-11T09:56:04.870689021+01:00] Loading containers: start.

DEBU[2019-03-11T09:56:04.870793282+01:00] processing event stream module=libcontainerd namespace=moby

DEBU[2019-03-11T09:56:04.872062033+01:00] Loaded container 3299a646cd8ce704ac633a8abc327c0b725091a6ad7a8a9aebb115b5c8da3dfb, isRunning: false

DEBU[2019-03-11T09:56:04.872517168+01:00] Loaded container 4823ba5ae65285c6820904400dd9ee266c215de2ee4bb8feb2ffd171decbc3a8, isRunning: false

DEBU[2019-03-11T09:56:04.872936548+01:00] Loaded container 91db42839d8c3af7d4a839b4857d5a5f2cd2ef281439441b9a3dbd8d75c58d23, isRunning: false

DEBU[2019-03-11T09:56:04.873289969+01:00] Loaded container 9a3a0a12f5b253b4f6bc033dd5742c59d916be86d453b01b4fb9bd1f748c6109, isRunning: false

DEBU[2019-03-11T09:56:04.873710129+01:00] Loaded container b5c9f1544e61a6c3d5352e4c17627a078962dc94db80c10f401daa2b1b1f04f7, isRunning: false

DEBU[2019-03-11T09:56:04.874190948+01:00] Loaded container b9492761f66d0b43f183539b2f4d81bde8062380265d12e99e62f466d16cef37, isRunning: false

DEBU[2019-03-11T09:56:04.874801472+01:00] Loaded container c03032427b791f5c7f2ee05f305a3732dcc40e6c60738152dd3dcca20ac567dd, isRunning: false

DEBU[2019-03-11T09:56:04.875312431+01:00] Loaded container d6de99424c3b1ebf55dd2442f2826cbca46ce0c9d691ee625fb69264d1ac2671, isRunning: false

DEBU[2019-03-11T09:56:04.875981166+01:00] Loaded container f06e122ebd9b3743af1731ccb1414f6a2dbd14819c7686b17ec7f9ded58f2ea0, isRunning: false

DEBU[2019-03-11T09:56:04.927687231+01:00] restoring container container=b5c9f1544e61a6c3d5352e4c17627a078962dc94db80c10f401daa2b1b1f04f7 paused=false running=false

DEBU[2019-03-11T09:56:04.928733975+01:00] restoring container container=91db42839d8c3af7d4a839b4857d5a5f2cd2ef281439441b9a3dbd8d75c58d23 paused=false running=false

DEBU[2019-03-11T09:56:04.931705005+01:00] restoring container container=9a3a0a12f5b253b4f6bc033dd5742c59d916be86d453b01b4fb9bd1f748c6109 paused=false running=false

DEBU[2019-03-11T09:56:04.933856231+01:00] restoring container container=b9492761f66d0b43f183539b2f4d81bde8062380265d12e99e62f466d16cef37 paused=false running=false

DEBU[2019-03-11T09:56:04.934503968+01:00] restoring container container=c03032427b791f5c7f2ee05f305a3732dcc40e6c60738152dd3dcca20ac567dd paused=false running=false

DEBU[2019-03-11T09:56:04.937068955+01:00] restoring container container=f06e122ebd9b3743af1731ccb1414f6a2dbd14819c7686b17ec7f9ded58f2ea0 paused=false running=false

DEBU[2019-03-11T09:56:04.942464745+01:00] restoring container container=3299a646cd8ce704ac633a8abc327c0b725091a6ad7a8a9aebb115b5c8da3dfb paused=false running=false

DEBU[2019-03-11T09:56:04.948944968+01:00] restoring container container=d6de99424c3b1ebf55dd2442f2826cbca46ce0c9d691ee625fb69264d1ac2671 paused=false running=false

DEBU[2019-03-11T09:56:04.950749457+01:00] restoring container container=4823ba5ae65285c6820904400dd9ee266c215de2ee4bb8feb2ffd171decbc3a8 paused=false running=false

DEBU[2019-03-11T09:56:04.951138869+01:00] Option Experimental: false

DEBU[2019-03-11T09:56:04.951152892+01:00] Option DefaultDriver: bridge

DEBU[2019-03-11T09:56:04.951158162+01:00] Option DefaultNetwork: bridge

DEBU[2019-03-11T09:56:04.951194917+01:00] Network Control Plane MTU: 1500

DEBU[2019-03-11T09:56:04.959536156+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t filter -C FORWARD -j DOCKER-ISOLATION]

DEBU[2019-03-11T09:56:04.960569108+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t nat -D PREROUTING -m addrtype --dst-type LOCAL -j DOCKER]

DEBU[2019-03-11T09:56:04.961665409+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t nat -D OUTPUT -m addrtype --dst-type LOCAL ! --dst 127.0.0.0/8 -j DOCKER]

DEBU[2019-03-11T09:56:04.962715498+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t nat -D OUTPUT -m addrtype --dst-type LOCAL -j DOCKER]

DEBU[2019-03-11T09:56:04.966849058+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t nat -D PREROUTING]

DEBU[2019-03-11T09:56:04.968037631+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t nat -D OUTPUT]

DEBU[2019-03-11T09:56:04.969116145+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t nat -F DOCKER]

DEBU[2019-03-11T09:56:04.970012713+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t nat -X DOCKER]

DEBU[2019-03-11T09:56:04.970911109+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t filter -F DOCKER]

DEBU[2019-03-11T09:56:04.972030220+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t filter -X DOCKER]

DEBU[2019-03-11T09:56:04.972975967+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t filter -F DOCKER-ISOLATION-STAGE-1]

DEBU[2019-03-11T09:56:04.974045262+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t filter -X DOCKER-ISOLATION-STAGE-1]

DEBU[2019-03-11T09:56:04.974939961+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t filter -F DOCKER-ISOLATION-STAGE-2]

DEBU[2019-03-11T09:56:04.976123301+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t filter -X DOCKER-ISOLATION-STAGE-2]

DEBU[2019-03-11T09:56:04.977345385+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t filter -F DOCKER-ISOLATION]

DEBU[2019-03-11T09:56:04.993484633+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t filter -X DOCKER-ISOLATION]

DEBU[2019-03-11T09:56:04.995181775+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t nat -n -L DOCKER]

DEBU[2019-03-11T09:56:04.999757355+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t nat -N DOCKER]

DEBU[2019-03-11T09:56:05.003280086+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t filter -n -L DOCKER]

DEBU[2019-03-11T09:56:05.004359235+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t filter -n -L DOCKER-ISOLATION-STAGE-1]

DEBU[2019-03-11T09:56:05.005306171+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t filter -n -L DOCKER-ISOLATION-STAGE-2]

DEBU[2019-03-11T09:56:05.011943772+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t filter -N DOCKER-ISOLATION-STAGE-2]

DEBU[2019-03-11T09:56:05.016422142+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t filter -C DOCKER-ISOLATION-STAGE-1 -j RETURN]

DEBU[2019-03-11T09:56:05.017549657+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -A DOCKER-ISOLATION-STAGE-1 -j RETURN]

DEBU[2019-03-11T09:56:05.018632139+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t filter -C DOCKER-ISOLATION-STAGE-2 -j RETURN]

DEBU[2019-03-11T09:56:05.019744902+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -A DOCKER-ISOLATION-STAGE-2 -j RETURN]

DEBU[2019-03-11T09:56:05.024866513+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t nat -C POSTROUTING -s 172.17.0.0/16 ! -o docker0 -j MASQUERADE]

DEBU[2019-03-11T09:56:05.025760898+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t nat -C DOCKER -i docker0 -j RETURN]

DEBU[2019-03-11T09:56:05.026629780+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t nat -I DOCKER -i docker0 -j RETURN]

DEBU[2019-03-11T09:56:05.027509122+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -D FORWARD -i docker0 -o docker0 -j DROP]

DEBU[2019-03-11T09:56:05.028412371+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t filter -C FORWARD -i docker0 -o docker0 -j ACCEPT]

DEBU[2019-03-11T09:56:05.029256644+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t filter -C FORWARD -i docker0 ! -o docker0 -j ACCEPT]

DEBU[2019-03-11T09:56:05.030148988+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t nat -C PREROUTING -m addrtype --dst-type LOCAL -j DOCKER]

DEBU[2019-03-11T09:56:05.033882184+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t nat -A PREROUTING -m addrtype --dst-type LOCAL -j DOCKER]

DEBU[2019-03-11T09:56:05.034894476+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t nat -C OUTPUT -m addrtype --dst-type LOCAL -j DOCKER ! --dst 127.0.0.0/8]

DEBU[2019-03-11T09:56:05.035926698+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t nat -A O

Hi Allan,

On Mon, 11 Mar 2019 09:59:19 +0100

Allan Adair <allan@adair.io> wrote:

No problem!

Yes, so that looks as if it works fine. What's the difference to a failed start by herd (log file in /var/log/docker.log) ?

Hi Danny.

Danny Milosavljevic writes:

I have never actually been able to start the dockerd service using herd

explicitly. After booting:

allana@guixsd ~$ docker ps

Cannot connect to the Docker daemon at unix:///var/run/docker.sock. Is the docker daemon running?

allana@guixsd ~$ cat /var/log/docker.log

time="2019-03-18T10:23:30.462181353+01:00" level=warning msg="Error while setting daemon root propagation, this is not generally critical but may cause some functionality to not work or fallback to less desirable behavior" dir=/var/lib/docker error="error writing file to signal mount cleanup on shutdown: open /var/run/docker/unmount-on-shutdown: no such file or directory"

time="2019-03-18T10:23:30.465999919+01:00" level=info msg="parsed scheme: \"unix\"" module=grpc

time="2019-03-18T10:23:30.466019010+01:00" level=info msg="scheme \"unix\" not registered, fallback to default scheme" module=grpc

time="2019-03-18T10:23:30.466291192+01:00" level=info msg="ccResolverWrapper: sending new addresses to cc: [{unix:///run/containerd/containerd.sock 0 <nil>}]" module=grpc

time="2019-03-18T10:23:30.466315303+01:00" level=info msg="ClientConn switching balancer to \"pick_first\"" module=grpc

time="2019-03-18T10:23:30.466349982+01:00" level=info msg="pickfirstBalancer: HandleSubConnStateChange: 0xc00012d090, CONNECTING" module=grpc

time="2019-03-18T10:23:30.467362222+01:00" level=info msg="pickfirstBalancer: HandleSubConnStateChange: 0xc00012d090, READY" module=grpc

time="2019-03-18T10:23:30.467531354+01:00" level=info msg="parsed scheme: \"unix\"" module=grpc

time="2019-03-18T10:23:30.467544289+01:00" level=info msg="scheme \"unix\" not registered, fallback to default scheme" module=grpc

time="2019-03-18T10:23:30.467972429+01:00" level=info msg="ccResolverWrapper: sending new addresses to cc: [{unix:///run/containerd/containerd.sock 0 <nil>}]" module=grpc

time="2019-03-18T10:23:30.467991848+01:00" level=info msg="ClientConn switching balancer to \"pick_first\"" module=grpc

time="2019-03-18T10:23:30.468161326+01:00" level=info msg="pickfirstBalancer: HandleSubConnStateChange: 0xc00012d380, CONNECTING" module=grpc

time="2019-03-18T10:23:30.468444097+01:00" level=info msg="pickfirstBalancer: HandleSubConnStateChange: 0xc00012d380, READY" module=grpc

time="2019-03-18T10:23:30.471722313+01:00" level=error msg="'overlay' not found as a supported filesystem on this host. Please ensure kernel is new enough and has overlay support loaded." storage-driver=overlay2

time="2019-03-18T10:23:30.471762928+01:00" level=error msg="[graphdriver] prior storage driver overlay2 failed: driver not supported"

Error starting daemon: error initializing graphdriver: driver not supported

The service does start after a guix system reconfigure:

allana@guixsd ~$ sudo guix system reconfigure /etc/config.scm > /dev/null 2>&1

Password:

allana@guixsd ~$ docker ps

CONTAINER ID IMAGE COMMAND CREATED STATUS PORTS NAMES

allana@guixsd ~$ cat /var/log/docker.log

time="2019-03-18T11:04:08.548958068+01:00" level=info msg="parsed scheme: \"unix\"" module=grpc

time="2019-03-18T11:04:08.549060661+01:00" level=info msg="scheme \"unix\" not registered, fallback to default scheme" module=grpc

time="2019-03-18T11:04:08.549129691+01:00" level=info msg="parsed scheme: \"unix\"" module=grpc

time="2019-03-18T11:04:08.549145165+01:00" level=info msg="scheme \"unix\" not registered, fallback to default scheme" module=grpc

time="2019-03-18T11:04:08.549194625+01:00" level=info msg="ccResolverWrapper: sending new addresses to cc: [{unix:///run/containerd/containerd.sock 0 <nil>}]" module=grpc

time="2019-03-18T11:04:08.549225327+01:00" level=info msg="ClientConn switching balancer to \"pick_first\"" module=grpc

time="2019-03-18T11:04:08.549295334+01:00" level=info msg="pickfirstBalancer: HandleSubConnStateChange: 0xc0007c8730, CONNECTING" module=grpc

time="2019-03-18T11:04:08.549428581+01:00" level=info msg="pickfirstBalancer: HandleSubConnStateChange: 0xc0007c8730, READY" module=grpc

time="2019-03-18T11:04:08.549823791+01:00" level=info msg="ccResolverWrapper: sending new addresses to cc: [{unix:///run/containerd/containerd.sock 0 <nil>}]" module=grpc

time="2019-03-18T11:04:08.549852586+01:00" level=info msg="ClientConn switching balancer to \"pick_first\"" module=grpc

time="2019-03-18T11:04:08.549895079+01:00" level=info msg="pickfirstBalancer: HandleSubConnStateChange: 0xc00048c190, CONNECTING" module=grpc

time="2019-03-18T11:04:08.550230781+01:00" level=info msg="pickfirstBalancer: HandleSubConnStateChange: 0xc00048c190, READY" module=grpc

time="2019-03-18T11:04:08.563100196+01:00" level=info msg="[graphdriver] using prior storage driver: overlay2"

time="2019-03-18T11:04:08.649791498+01:00" level=info msg="Graph migration to content-addressability took 0.00 seconds"

time="2019-03-18T11:04:08.649963115+01:00" level=warning msg="Your kernel does not support swap memory limit"

time="2019-03-18T11:04:08.650005407+01:00" level=warning msg="Your kernel does not support cgroup rt period"

time="2019-03-18T11:04:08.650018501+01:00" level=warning msg="Your kernel does not support cgroup rt runtime"

time="2019-03-18T11:04:08.650029780+01:00" level=warning msg="Your kernel does not support cgroup blkio weight"

time="2019-03-18T11:04:08.650040103+01:00" level=warning msg="Your kernel does not support cgroup blkio weight_device"

time="2019-03-18T11:04:08.650127344+01:00" level=warning msg="mountpoint for pids not found"

time="2019-03-18T11:04:08.650316692+01:00" level=info msg="Loading containers: start."

time="2019-03-18T11:04:09.231485582+01:00" level=info msg="Default bridge (docker0) is assigned with an IP address 172.17.0.0/16. Daemon option --bip can be used to set a preferred IP address"

time="2019-03-18T11:04:09.381248432+01:00" level=info msg="Loading containers: done."

time="2019-03-18T11:04:09.381974297+01:00" level=warning msg="Could not get operating system name: Error opening /usr/lib/os-release: open /usr/lib/os-release: no such file or directory"

time="2019-03-18T11:04:09.388621054+01:00" level=warning msg="failed to retrieve /gnu/store/fxmfknby00xva6jlz3m4pjj2jyj2xxiw-runc-1.0.0-rc6/sbin/runc version: unknown output format: runc version 1.0.0-rc6\nspec: 1.0.1-dev\n"

time="2019-03-18T11:04:09.388997410+01:00" level=warning msg="failed to retrieve docker-init version: exec: \"docker-init\": executable file not found in $PATH"

time="2019-03-18T11:04:10.926517059+01:00" level=info msg="Docker daemon" commit=v18.09.3 graphdriver(s)=overlay2 version=dev

time="2019-03-18T11:04:10.926776715+01:00" level=info msg="Daemon has completed initialization"

time="2019-03-18T11:04:10.941524868+01:00" level=info msg="API listen on /var/run/docker.sock"

--

Allan Adair

Hi Allan,

thanks for the logs!

I've found the problem now.

daemon/graphdriver/overlay2/overlay.go:

func supportsOverlay() error {

// We can try to modprobe overlay first before looking at

// proc/filesystems for when overlay is supported

exec.Command("modprobe", "overlay").Run()

f, err := os.Open("/proc/filesystems")

if err != nil {

return err

}

defer f.Close()

s := bufio.NewScanner(f)

for s.Scan() {

if s.Text() == "nodev\toverlay" {

return nil

}

}

logrus.WithField("storage-driver", "overlay2").Error("'overlay' not found as a supported filesystem on this host. Please ensure kernel is new enough and has overlay support loaded.")

return graphdriver.ErrNotSupported

}

We don't load "overlay" explicitly. The above is some weird contraption--loading kernel modules from random user space programs. Seriously?

And I suspect that modprobe is not found in your system profile.

As a workaround, try adding "kmod" to the list of packages in your operating-system in your system configuration and reconfigure.

But the real fix is for Docker to stop doing this weird thing in the first place. Nowadays, modules are autoloaded when someone is accessing the thing (by udev, or just by using it etc).

In this case, they do

if err := mount("overlay", mountTarget, "overlay", 0, mountData); err != nil {

later on. And that's how it should have been detecting it, too.

For our own reference:

# lsmod |grep overlay

# mkdir -p /b

# mount -t overlay none /b

mount: /b: wrong fs type, bad option, bad superblock on /a, missing codepage or helper program, or other error.

# lsmod |grep overlay

overlay 110592 0

Hi Danny. With great excitement I edited my config.scm to include kmod,

ran guix system reconfigure, and rebooted my machine. Unfortunately my

changes did not seem to fix the issue. I hope the session below can help

us further. Thanks so much for working on this issue.

allana@guixsd ~$ docker ps

Cannot connect to the Docker daemon at unix:///var/run/docker.sock. Is the docker daemon running?

allana@guixsd ~$ cat /var/log/docker.log

time="2019-03-18T14:39:59.788932321+01:00" level=warning msg="Error while setting daemon root propagation, this is not generally critical but may cause some functionality to not work or fallback to less desirable behavior" dir=/var/lib/docker error="error writing file to signal mount cleanup on shutdown: open /var/run/docker/unmount-on-shutdown: no such file or directory"

time="2019-03-18T14:39:59.797964377+01:00" level=info msg="parsed scheme: \"unix\"" module=grpc

time="2019-03-18T14:39:59.797982675+01:00" level=info msg="scheme \"unix\" not registered, fallback to default scheme" module=grpc

time="2019-03-18T14:39:59.798127164+01:00" level=info msg="ccResolverWrapper: sending new addresses to cc: [{unix:///run/containerd/containerd.sock 0 <nil>}]" module=grpc

time="2019-03-18T14:39:59.798220831+01:00" level=info msg="ClientConn switching balancer to \"pick_first\"" module=grpc

time="2019-03-18T14:39:59.798291248+01:00" level=info msg="pickfirstBalancer: HandleSubConnStateChange: 0xc000771980, CONNECTING" module=grpc

time="2019-03-18T14:39:59.800603937+01:00" level=info msg="pickfirstBalancer: HandleSubConnStateChange: 0xc000771980, READY" module=grpc

time="2019-03-18T14:39:59.801234292+01:00" level=info msg="parsed scheme: \"unix\"" module=grpc

time="2019-03-18T14:39:59.801254794+01:00" level=info msg="scheme \"unix\" not registered, fallback to default scheme" module=grpc

time="2019-03-18T14:39:59.801329244+01:00" level=info msg="ccResolverWrapper: sending new addresses to cc: [{unix:///run/containerd/containerd.sock 0 <nil>}]" module=grpc

time="2019-03-18T14:39:59.801366954+01:00" level=info msg="ClientConn switching balancer to \"pick_first\"" module=grpc

time="2019-03-18T14:39:59.801507445+01:00" level=info msg="pickfirstBalancer: HandleSubConnStateChange: 0xc0000d79d0, CONNECTING" module=grpc

time="2019-03-18T14:39:59.802331100+01:00" level=info msg="pickfirstBalancer: HandleSubConnStateChange: 0xc0000d79d0, READY" module=grpc

time="2019-03-18T14:39:59.815614194+01:00" level=error msg="'overlay' not found as a supported filesystem on this host. Please ensure kernel is new enough and has overlay support loaded." storage-driver=overlay2

time="2019-03-18T14:39:59.815664314+01:00" level=error msg="[graphdriver] prior storage driver overlay2 failed: driver not supported"

Error starting daemon: error initializing graphdriver: driver not supported

allana@guixsd ~$ cat /etc/config.scm

(use-modules (gnu)

(gnu system nss)

(gnu services))

(use-service-modules desktop docker)

(use-package-modules certs gnome linux)

(operating-system

(host-name "guixsd")

(timezone "Europe/Oslo")

(locale "en_US.utf8")

(bootloader (bootloader-configuration

(bootloader grub-bootloader)

(target "/dev/sda")))

(file-systems (cons (file-system

(device (file-system-label "my-root"))

(mount-point "/")

(type "ext4"))

%base-file-systems))

(users (cons (user-account

(name "allana")

(group "users")

(supplementary-groups '("wheel"

"docker"

"netdev"

"audio"

"video"))

(home-directory "/home/allana"))

%base-user-accounts))

;; This is where we specify system-wide packages.

(packages (cons* nss-certs ;for HTTPS access

gvfs ;for user mounts

kmod ;for modprobe/dockerd

%base-packages))

(services (cons* (console-keymap-service "no-latin1")

(gnome-desktop-service)

(service docker-service-type)

%desktop-services))

;; Allow resolution of '.local' host names with mDNS.

(name-service-switch %mdns-host-lookup-nss))

allana@guixsd ~$ sudo herd start dockerd

Password:

Service dockerd could not be started.

herd: failed to start service dockerd

allana@guixsd ~$ sudo guix system reconfigure /etc/config.scm > /dev/null 2>&1

allana@guixsd ~$ docker ps

CONTAINER ID IMAGE COMMAND CREATED STATUS PORTS NAMES

allana@guixsd ~$ cat /var/log/docker.log

time="2019-03-18T14:43:00.850449641+01:00" level=info msg="parsed scheme: \"unix\"" module=grpc

time="2019-03-18T14:43:00.850524161+01:00" level=info msg="scheme \"unix\" not registered, fallback to default scheme" module=grpc

time="2019-03-18T14:43:00.850623186+01:00" level=info msg="parsed scheme: \"unix\"" module=grpc

time="2019-03-18T14:43:00.850638306+01:00" level=info msg="scheme \"unix\" not registered, fallback to default scheme" module=grpc

time="2019-03-18T14:43:00.850682621+01:00" level=info msg="ccResolverWrapper: sending new addresses to cc: [{unix:///run/containerd/containerd.sock 0 <nil>}]" module=grpc

time="2019-03-18T14:43:00.850705685+01:00" level=info msg="ClientConn switching balancer to \"pick_first\"" module=grpc

time="2019-03-18T14:43:00.850749857+01:00" level=info msg="pickfirstBalancer: HandleSubConnStateChange: 0xc0000496e0, CONNECTING" module=grpc

time="2019-03-18T14:43:00.850880352+01:00" level=info msg="pickfirstBalancer: HandleSubConnStateChange: 0xc0000496e0, READY" module=grpc

time="2019-03-18T14:43:00.851069787+01:00" level=info msg="ccResolverWrapper: sending new addresses to cc: [{unix:///run/containerd/containerd.sock 0 <nil>}]" module=grpc

time="2019-03-18T14:43:00.851088244+01:00" level=info msg="ClientConn switching balancer to \"pick_first\"" module=grpc

time="2019-03-18T14:43:00.851153314+01:00" level=info msg="pickfirstBalancer: HandleSubConnStateChange: 0xc0000499d0, CONNECTING" module=grpc

time="2019-03-18T14:43:00.851266607+01:00" level=info msg="pickfirstBalancer: HandleSubConnStateChange: 0xc0000499d0, READY" module=grpc

time="2019-03-18T14:43:00.874110624+01:00" level=info msg="[graphdriver] using prior storage driver: overlay2"

time="2019-03-18T14:43:01.002014039+01:00" level=info msg="Graph migration to content-addressability took 0.00 seconds"

time="2019-03-18T14:43:01.002217610+01:00" level=warning msg="Your kernel does not support swap memory limit"

time="2019-03-18T14:43:01.002293632+01:00" level=warning msg="Your kernel does not support cgroup rt period"

time="2019-03-18T14:43:01.002307271+01:00" level=warning msg="Your kernel does not support cgroup rt runtime"

time="2019-03-18T14:43:01.002318768+01:00" level=warning msg="Your kernel does not support cgroup blkio weight"

time="2019-03-18T14:43:01.002328780+01:00" level=warning msg="Your kernel does not support cgroup blkio weight_device"

time="2019-03-18T14:43:01.002447782+01:00" level=warning msg="mountpoint for pids not found"

time="2019-03-18T14:43:01.002919567+01:00" level=info msg="Loading containers: start."

time="2019-03-18T14:43:01.596297744+01:00" level=info msg="Default bridge (docker0) is assigned with an IP address 172.17.0.0/16. Daemon option --bip can be used to set a preferred IP address"

time="2019-03-18T14:43:01.664423600+01:00" level=info msg="Loading containers: done."

time="2019-03-18T14:43:01.672193823+01:00" level=warning msg="Could not get operating system name: Error opening /usr/lib/os-release: open /usr/lib/os-release: no such file or directory"

time="2019-03-18T14:43:01.735588173+01:00" level=warning msg="failed to retrieve /gnu/store/fxmfknby00xva6jlz3m4pjj2jyj2xxiw-runc-1.0.0-rc6/sbin/runc version: unknown output format: runc version 1.0.0-rc6\nspec: 1.0.1-dev\n"

time="2019-03-18T14:43:01.747943901+01:00" level=warning msg="failed to retrieve docker-init version: exec: \"docker-init\": executable file not found in $PATH"

time="2019-03-18T14:43:01.901777278+01:00" level=info msg="Docker daemon" commit=v18.09.3 graphdriver(s)=overlay2 version=dev

time="2019-03-18T14:43:01.911529576+01:00" level=info msg="Daemon has completed initialization"

time="2019-03-18T14:43:01.918913081+01:00" level=info msg="API listen on /var/run/docker.sock"

Danny Milosavljevic writes:

--

Allan Adair

Hi Allan,

I've pushed a new way to get rid of this bug to guix master.

Could you try

guix pull

and then

guix reconfigure

and report back?

Danny Milosavljevic writes:

Success! Thank you very much.

--

Allan Adair

close 34333