* bug#34333: Docker daemon failing to start on boot @ 2019-02-05 11:29 allan 2019-02-08 21:55 ` Ludovic Courtès 0 siblings, 1 reply; 24+ messages in thread From: allan @ 2019-02-05 11:29 UTC (permalink / raw) To: 34333 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 started. Feb 5 10:16:49 localhost vmunix: [ 0.358275] Yama: becoming mindful. Feb 5 10:16:49 localhost vmunix: [ 0.358571] AppArmor: AppArmor initialized Feb 5 10:16:49 localhost vmunix: [ 0.365111] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes) Feb 5 10:16:49 localhost vmunix: [ 0.367155] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes) Feb 5 10:16:49 localhost vmunix: [ 0.367706] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes) Feb 5 10:16:49 localhost vmunix: [ 0.368222] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes) Feb 5 10:16:49 localhost vmunix: [ 0.369143] mce: CPU supports 0 MCE banks Feb 5 10:16:49 localhost vmunix: [ 0.369521] Last level iTLB entries: 4KB 64, 2MB 8, 4MB 8 Feb 5 10:16:49 localhost vmunix: [ 0.369949] Last level dTLB entries: 4KB 64, 2MB 0, 4MB 0, 1GB 4 Feb 5 10:16:49 localhost vmunix: [ 0.370431] Spectre V2 : Mitigation: Full generic retpoline Feb 5 10:16:49 localhost vmunix: [ 0.370872] Spectre V2 : Spectre v2 / SpectreRSB mitigation: Filling RSB on context switch Feb 5 10:16:49 localhost vmunix: [ 0.371589] Speculative Store Bypass: Vulnerable Feb 5 10:16:49 localhost vmunix: [ 0.372180] Freeing SMP alternatives memory: 28K Feb 5 10:16:49 localhost vmunix: [ 0.377043] smpboot: CPU0: Intel(R) Core(TM) i7-7500U CPU @ 2.70GHz (family: 0x6, model: 0x8e, stepping: 0x9) Feb 5 10:16:49 localhost shepherd[1]: Service term-auto could not be started. Feb 5 10:16:49 localhost vmunix: [ 0.377043] Performance Events: unsupported p6 CPU model 142 no PMU driver, software events only. Feb 5 10:16:49 localhost vmunix: [ 0.377043] rcu: Hierarchical SRCU implementation. Feb 5 10:16:49 localhost vmunix: [ 0.377043] NMI watchdog: Perf NMI watchdog permanently disabled Feb 5 10:16:49 localhost vmunix: [ 0.377043] smp: Bringing up secondary CPUs ... Feb 5 10:16:49 localhost vmunix: [ 0.377141] x86: Booting SMP configuration: Feb 5 10:16:49 localhost vmunix: [ 0.377549] .... node #0, CPUs: #1 Feb 5 10:16:49 localhost vmunix: [ 0.069599] kvm-clock: cpu 1, msr 13a574041, secondary cpu clock Feb 5 10:16:49 localhost vmunix: [ 0.069599] mce: CPU supports 0 MCE banks Feb 5 10:16:49 localhost vmunix: [ 0.379916] smp: Brought up 1 node, 2 CPUs Feb 5 10:16:49 localhost vmunix: [ 0.381049] smpboot: Max logical packages: 1 Feb 5 10:16:49 localhost vmunix: [ 0.381467] smpboot: Total of 2 processors activated (11616.01 BogoMIPS) Feb 5 10:16:49 localhost vmunix: [ 0.382274] devtmpfs: initialized Feb 5 10:16:49 localhost vmunix: [ 0.382274] x86/mm: Memory block size: 128MB Feb 5 10:16:49 localhost vmunix: [ 0.385115] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns Feb 5 10:16:49 localhost vmunix: [ 0.385820] futex hash table entries: 512 (order: 3, 32768 bytes) Feb 5 10:16:49 localhost vmunix: [ 0.386292] pinctrl core: initialized pinctrl subsystem Feb 5 10:16:49 localhost shepherd[1]: Service console-font-tty1 has been started. Feb 5 10:16:49 localhost vmunix: [ 0.386775] RTC time: 9:16:41, date: 02/05/19 Feb 5 10:16:49 localhost vmunix: [ 0.387249] NET: Registered protocol family 16 Feb 5 10:16:49 localhost vmunix: [ 0.387715] audit: initializing netlink subsys (disabled) Feb 5 10:16:49 localhost vmunix: [ 0.388115] audit: type=2000 audit(1549358208.770:1): state=initialized audit_enabled=0 res=1 Feb 5 10:16:49 localhost vmunix: [ 0.389051] cpuidle: using governor ladder Feb 5 10:16:49 localhost vmunix: [ 0.389415] cpuidle: using governor menu Feb 5 10:16:50 localhost vmunix: [ 0.389781] ACPI: bus type PCI registered Feb 5 10:16:50 localhost vmunix: [ 0.390114] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 Feb 5 10:16:50 localhost vmunix: [ 0.390665] PCI: Using configuration type 1 for base access Feb 5 10:16:50 localhost vmunix: [ 0.393093] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages Feb 5 10:16:50 localhost vmunix: [ 0.393603] ACPI: Added _OSI(Module Device) Feb 5 10:16:50 localhost vmunix: [ 0.393603] ACPI: Added _OSI(Processor Device) Feb 5 10:16:50 localhost vmunix: [ 0.394103] ACPI: Added _OSI(3.0 _SCP Extensions) Feb 5 10:16:50 localhost vmunix: [ 0.394500] ACPI: Added _OSI(Processor Aggregator Device) Feb 5 10:16:50 localhost vmunix: [ 0.394936] ACPI: Added _OSI(Linux-Dell-Video) Feb 5 10:16:50 localhost vmunix: [ 0.395317] ACPI: Added _OSI(Linux-Lenovo-NV-HDMI-Audio) Feb 5 10:16:50 localhost shepherd[1]: Service console-font-tty2 has been started. Feb 5 10:16:50 localhost vmunix: [ 0.398388] ACPI: 2 ACPI AML tables successfully acquired and loaded Feb 5 10:16:50 localhost vmunix: [ 0.401220] ACPI: Interpreter enabled Feb 5 10:16:50 localhost vmunix: [ 0.401530] ACPI: (supports S0 S5) Feb 5 10:16:50 localhost vmunix: [ 0.401834] ACPI: Using IOAPIC for interrupt routing Feb 5 10:16:50 localhost vmunix: [ 0.402377] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug Feb 5 10:16:50 localhost vmunix: [ 0.403123] ACPI: Enabled 2 GPEs in block 00 to 07 Feb 5 10:16:50 localhost vmunix: [ 0.409628] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) Feb 5 10:16:50 localhost vmunix: [ 0.410161] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI] Feb 5 10:16:50 localhost vmunix: [ 0.410635] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI] Feb 5 10:16:50 localhost vmunix: [ 0.411299] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. Feb 5 10:16:50 localhost vmunix: [ 0.412482] PCI host bridge to bus 0000:00 Feb 5 10:16:50 localhost vmunix: [ 0.412836] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] Feb 5 10:16:50 localhost vmunix: [ 0.413043] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] Feb 5 10:16:50 localhost shepherd[1]: Service console-font-tty3 has been started. Feb 5 10:16:50 localhost vmunix: [ 0.413049] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] Feb 5 10:16:50 localhost vmunix: [ 0.413711] pci_bus 0000:00: root bus resource [mem 0xe0000000-0xfdffffff window] Feb 5 10:16:50 localhost vmunix: [ 0.414343] pci_bus 0000:00: root bus resource [bus 00-ff] Feb 5 10:16:50 localhost vmunix: [ 0.419482] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] Feb 5 10:16:50 localhost vmunix: [ 0.420020] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6] Feb 5 10:16:50 localhost vmunix: [ 0.420503] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] Feb 5 10:16:50 localhost vmunix: [ 0.421065] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376] Feb 5 10:16:50 localhost shepherd[1]: Service console-font-tty4 has been started. Feb 5 10:16:50 localhost vmunix: [ 0.499981] pci 0000:00:07.0: quirk: [io 0x4000-0x403f] claimed by PIIX4 ACPI Feb 5 10:16:50 localhost vmunix: [ 0.500561] pci 0000:00:07.0: quirk: [io 0x4100-0x410f] claimed by PIIX4 SMB Feb 5 10:16:50 localhost shepherd[1]: Service console-font-tty5 has been started. Feb 5 10:16:50 localhost vmunix: [ 0.530275] ACPI: PCI Interrupt Link [LNKA] (IRQs 5 9 10 *11) Feb 5 10:16:50 localhost vmunix: [ 0.530994] ACPI: PCI Interrupt Link [LNKB] (IRQs 5 9 *10 11) Feb 5 10:16:50 localhost vmunix: [ 0.531493] ACPI: PCI Interrupt Link [LNKC] (IRQs 5 *9 10 11) Feb 5 10:16:50 localhost vmunix: [ 0.531983] ACPI: PCI Interrupt Link [LNKD] (IRQs 5 9 10 *11) Feb 5 10:16:50 localhost vmunix: [ 0.533199] pci 0000:00:02.0: vgaarb: setting as boot VGA device Feb 5 10:16:50 localhost vmunix: [ 0.533453] pci 0000:00:02.0: vgaarb: VGA device added: decodes=io+mem,owns=io+mem,locks=none Feb 5 10:16:50 localhost vmunix: [ 0.534028] pci 0000:00:02.0: vgaarb: bridge control possible Feb 5 10:16:50 localhost vmunix: [ 0.534402] vgaarb: loaded Feb 5 10:16:50 localhost vmunix: [ 0.534809] SCSI subsystem initialized Feb 5 10:16:50 localhost vmunix: [ 0.535115] ACPI: bus type USB registered Feb 5 10:16:50 localhost vmunix: [ 0.535115] usbcore: registered new interface driver usbfs Feb 5 10:16:50 localhost vmunix: [ 0.535115] usbcore: registered new interface driver hub Feb 5 10:16:50 localhost vmunix: [ 0.535115] usbcore: registered new device driver usb Feb 5 10:16:50 localhost vmunix: [ 0.535115] EDAC MC: Ver: 3.0.0 Feb 5 10:16:50 localhost shepherd[1]: Service console-font-tty6 has been started. Feb 5 10:16:50 localhost vmunix: [ 0.537261] PCI: Using ACPI for IRQ routing Feb 5 10:16:50 localhost vmunix: [ 0.537893] NetLabel: Initializing Feb 5 10:16:50 localhost vmunix: [ 0.538243] NetLabel: domain hash size = 128 Feb 5 10:16:50 localhost vmunix: [ 0.538600] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO Feb 5 10:16:50 localhost vmunix: [ 0.539052] NetLabel: unlabeled traffic allowed by default Feb 5 10:16:50 localhost vmunix: [ 0.539494] clocksource: Switched to clocksource kvm-clock Feb 5 10:16:50 localhost vmunix: [ 0.552438] VFS: Disk quotas dquot_6.6.0 Feb 5 10:16:50 localhost vmunix: [ 0.553250] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) Feb 5 10:16:50 localhost vmunix: [ 0.554025] AppArmor: AppArmor Filesystem Enabled Feb 5 10:16:50 localhost vmunix: [ 0.554564] pnp: PnP ACPI init Feb 5 10:16:50 localhost vmunix: [ 0.556077] pnp: PnP ACPI: found 2 devices Feb 5 10:16:50 localhost vmunix: [ 0.567704] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns Feb 5 10:16:50 localhost vmunix: [ 0.568592] NET: Registered protocol family 2 Feb 5 10:16:50 localhost vmunix: [ 0.569232] tcp_listen_portaddr_hash hash table entries: 4096 (order: 4, 65536 bytes) Feb 5 10:16:50 localhost vmunix: [ 0.569931] TCP established hash table entries: 65536 (order: 7, 524288 bytes) Feb 5 10:16:50 localhost vmunix: [ 0.570685] TCP bind hash table entries: 65536 (order: 8, 1048576 bytes) Feb 5 10:16:50 localhost vmunix: [ 0.571780] TCP: Hash tables configured (established 65536 bind 65536) Feb 5 10:16:50 localhost vmunix: [ 0.572322] UDP hash table entries: 4096 (order: 5, 131072 bytes) Feb 5 10:16:50 localhost vmunix: [ 0.573193] UDP-Lite hash table entries: 4096 (order: 5, 131072 bytes) Feb 5 10:16:50 localhost vmunix: [ 0.574090] NET: Registered protocol family 1 Feb 5 10:16:50 localhost vmunix: [ 0.574647] pci 0000:00:00.0: Limiting direct PCI/PCI transfers Feb 5 10:16:50 localhost vmunix: [ 0.575307] pci 0000:00:01.0: Activating ISA DMA hang workarounds Feb 5 10:16:50 localhost vmunix: [ 0.576041] pci 0000:00:02.0: Video device with shadowed ROM at [mem 0x000c0000-0x000dffff] Feb 5 10:16:50 localhost vmunix: [ 0.578641] Trying to unpack rootfs image as initramfs... Feb 5 10:16:50 localhost vmunix: [ 0.847453] Freeing initrd memory: 11068K Feb 5 10:16:50 localhost vmunix: [ 0.847852] PCI-DMA: Using software bounce buffering for IO (SWIOTLB) Feb 5 10:16:50 localhost vmunix: [ 0.848343] software IO TLB: mapped [mem 0xdbff0000-0xdfff0000] (64MB) Feb 5 10:16:50 localhost vmunix: [ 0.849014] RAPL PMU: API unit is 2^-32 Joules, 5 fixed counters, 10737418240 ms ovfl timer Feb 5 10:16:50 localhost vmunix: [ 0.849771] RAPL PMU: hw unit of domain pp0-core 2^-0 Joules Feb 5 10:16:50 localhost vmunix: [ 0.850223] RAPL PMU: hw unit of domain package 2^-0 Joules Feb 5 10:16:50 localhost vmunix: [ 0.850671] RAPL PMU: hw unit of domain dram 2^-0 Joules Feb 5 10:16:50 localhost vmunix: [ 0.851183] RAPL PMU: hw unit of domain pp1-gpu 2^-0 Joules Feb 5 10:16:50 localhost vmunix: [ 0.851891] RAPL PMU: hw unit of domain psys 2^-0 Joules Feb 5 10:16:50 localhost vmunix: [ 0.852582] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x29dc09beef1, max_idle_ns: 440795310252 ns Feb 5 10:16:50 localhost vmunix: [ 0.854294] platform rtc_cmos: registered platform RTC device (no PNP device found) Feb 5 10:16:50 localhost vmunix: [ 0.855341] check: Scanning for low memory corruption every 60 seconds Feb 5 10:16:50 localhost vmunix: [ 0.857333] Initialise system trusted keyrings Feb 5 10:16:50 localhost vmunix: [ 0.858137] workingset: timestamp_bits=40 max_order=21 bucket_order=0 Feb 5 10:16:50 localhost vmunix: [ 0.861513] zbud: loaded Feb 5 10:16:50 localhost vmunix: [ 0.863142] Allocating IMA blacklist keyring. Feb 5 10:16:50 localhost vmunix: [ 0.874094] Key type asymmetric registered Feb 5 10:16:50 localhost vmunix: [ 0.874687] Asymmetric key parser 'x509' registered Feb 5 10:16:50 localhost vmunix: [ 0.875318] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247) Feb 5 10:16:50 localhost vmunix: [ 0.876302] io scheduler noop registered Feb 5 10:16:50 localhost vmunix: [ 0.876689] io scheduler deadline registered (default) Feb 5 10:16:50 localhost vmunix: [ 0.877228] io scheduler cfq registered Feb 5 10:16:50 localhost vmunix: [ 0.877952] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 Feb 5 10:16:50 localhost vmunix: [ 0.878929] ACPI: AC Adapter [AC] (on-line) Feb 5 10:16:50 localhost vmunix: [ 0.879528] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 Feb 5 10:16:50 localhost vmunix: [ 0.880267] ACPI: Power Button [PWRF] Feb 5 10:16:50 localhost vmunix: [ 0.880745] input: Sleep Button as /devices/LNXSYSTM:00/LNXSLPBN:00/input/input1 Feb 5 10:16:50 localhost vmunix: [ 0.881488] ACPI: Sleep Button [SLPF] Feb 5 10:16:50 localhost vmunix: [ 0.883491] battery: ACPI: Battery Slot [BAT0] (battery present) Feb 5 10:16:50 localhost vmunix: [ 0.884195] Serial: 8250/16550 driver, 32 ports, IRQ sharing enabled Feb 5 10:16:50 localhost vmunix: [ 0.889728] Linux agpgart interface v0.103 Feb 5 10:16:50 localhost vmunix: [ 0.896488] brd: module loaded Feb 5 10:16:50 localhost vmunix: [ 0.898376] loop: module loaded Feb 5 10:16:50 localhost vmunix: [ 0.899528] scsi host0: ata_piix Feb 5 10:16:50 localhost vmunix: [ 0.899962] scsi host1: ata_piix Feb 5 10:16:50 localhost vmunix: [ 0.900270] ata1: PATA max UDMA/33 cmd 0x1f0 ctl 0x3f6 bmdma 0xd000 irq 14 Feb 5 10:16:50 localhost vmunix: [ 0.900711] ata2: PATA max UDMA/33 cmd 0x170 ctl 0x376 bmdma 0xd008 irq 15 Feb 5 10:16:50 localhost vmunix: [ 0.901310] libphy: Fixed MDIO Bus: probed Feb 5 10:16:50 localhost vmunix: [ 0.901660] tun: Universal TUN/TAP device driver, 1.6 Feb 5 10:16:50 localhost vmunix: [ 0.902349] PPP generic driver version 2.4.2 Feb 5 10:16:50 localhost vmunix: [ 0.902820] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver Feb 5 10:16:50 localhost vmunix: [ 0.903352] ehci-pci: EHCI PCI platform driver Feb 5 10:16:50 localhost vmunix: [ 0.903776] ehci-platform: EHCI generic platform driver Feb 5 10:16:50 localhost vmunix: [ 0.904235] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver Feb 5 10:16:50 localhost vmunix: [ 0.904755] ohci-pci: OHCI PCI platform driver Feb 5 10:16:50 localhost vmunix: [ 0.905173] ohci-platform: OHCI generic platform driver Feb 5 10:16:50 localhost vmunix: [ 0.905651] uhci_hcd: USB Universal Host Controller Interface driver Feb 5 10:16:50 localhost vmunix: [ 0.906899] xhci_hcd 0000:00:0c.0: xHCI Host Controller Feb 5 10:16:50 localhost vmunix: [ 0.907321] xhci_hcd 0000:00:0c.0: new USB bus registered, assigned bus number 1 Feb 5 10:16:50 localhost vmunix: [ 0.910017] xhci_hcd 0000:00:0c.0: hcc params 0x04000000 hci version 0x100 quirks 0x000000000000b930 Feb 5 10:16:50 localhost vmunix: [ 0.911469] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 4.20 Feb 5 10:16:50 localhost vmunix: [ 0.912472] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1 Feb 5 10:16:50 localhost vmunix: [ 0.913928] usb usb1: Product: xHCI Host Controller Feb 5 10:16:50 localhost vmunix: [ 0.914497] usb usb1: Manufacturer: Linux 4.20.6-gnu xhci-hcd Feb 5 10:16:50 localhost vmunix: [ 0.915120] usb usb1: SerialNumber: 0000:00:0c.0 Feb 5 10:16:50 localhost vmunix: [ 0.916083] hub 1-0:1.0: USB hub found Feb 5 10:16:50 localhost vmunix: [ 0.916694] hub 1-0:1.0: 8 ports detected Feb 5 10:16:50 localhost vmunix: [ 0.917871] xhci_hcd 0000:00:0c.0: xHCI Host Controller Feb 5 10:16:50 localhost vmunix: [ 0.918541] xhci_hcd 0000:00:0c.0: new USB bus registered, assigned bus number 2 Feb 5 10:16:50 localhost vmunix: [ 0.919467] xhci_hcd 0000:00:0c.0: Host supports USB 3.0 SuperSpeed Feb 5 10:16:50 localhost vmunix: [ 0.920491] usb usb2: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 4.20 Feb 5 10:16:50 localhost vmunix: [ 0.921264] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1 Feb 5 10:16:50 localhost vmunix: [ 0.922201] usb usb2: Product: xHCI Host Controller Feb 5 10:16:50 localhost vmunix: [ 0.922676] usb usb2: Manufacturer: Linux 4.20.6-gnu xhci-hcd Feb 5 10:16:50 localhost vmunix: [ 0.923221] usb usb2: SerialNumber: 0000:00:0c.0 Feb 5 10:16:50 localhost vmunix: [ 0.923891] hub 2-0:1.0: USB hub found Feb 5 10:16:50 localhost vmunix: [ 0.924384] hub 2-0:1.0: 6 ports detected Feb 5 10:16:50 localhost vmunix: [ 0.925270] i8042: PNP: PS/2 Controller [PNP0303:PS2K,PNP0f03:PS2M] at 0x60,0x64 irq 1,12 Feb 5 10:16:50 localhost vmunix: [ 0.926755] serio: i8042 KBD port at 0x60,0x64 irq 1 Feb 5 10:16:50 localhost vmunix: [ 0.927148] serio: i8042 AUX port at 0x60,0x64 irq 12 Feb 5 10:16:50 localhost vmunix: [ 0.927694] mousedev: PS/2 mouse device common for all mice Feb 5 10:16:50 localhost vmunix: [ 0.928456] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input2 Feb 5 10:16:50 localhost vmunix: [ 0.929615] rtc_cmos rtc_cmos: registered as rtc0 Feb 5 10:16:50 localhost vmunix: [ 0.930001] rtc_cmos rtc_cmos: alarms up to one day, 114 bytes nvram Feb 5 10:16:50 localhost vmunix: [ 0.930429] i2c /dev entries driver Feb 5 10:16:50 localhost vmunix: [ 0.930773] device-mapper: uevent: version 1.0.3 Feb 5 10:16:50 localhost vmunix: [ 0.931232] device-mapper: ioctl: 4.39.0-ioctl (2018-04-03) initialised: dm-devel@redhat.com Feb 5 10:16:50 localhost vmunix: [ 0.931882] ledtrig-cpu: registered to indicate activity on CPUs Feb 5 10:16:50 localhost vmunix: [ 0.932486] NET: Registered protocol family 10 Feb 5 10:16:50 localhost vmunix: [ 0.933083] Segment Routing with IPv6 Feb 5 10:16:50 localhost vmunix: [ 0.933386] NET: Registered protocol family 17 Feb 5 10:16:50 localhost vmunix: [ 0.934017] Key type dns_resolver registered Feb 5 10:16:50 localhost vmunix: [ 0.934640] sched_clock: Marking stable (868984986, 65599564)->(1043027987, -108443437) Feb 5 10:16:50 localhost vmunix: [ 0.936118] registered taskstats version 1 Feb 5 10:16:50 localhost vmunix: [ 0.936585] Loading compiled-in X.509 certificates Feb 5 10:16:50 localhost vmunix: [ 0.937112] zswap: loaded using pool lzo/zbud Feb 5 10:16:50 localhost vmunix: [ 0.939407] Key type big_key registered Feb 5 10:16:50 localhost vmunix: [ 0.940375] Key type trusted registered Feb 5 10:16:50 localhost vmunix: [ 0.941493] Key type encrypted registered Feb 5 10:16:50 localhost vmunix: [ 0.941961] AppArmor: AppArmor sha1 policy hashing enabled Feb 5 10:16:50 localhost vmunix: [ 0.942404] ima: No TPM chip found, activating TPM-bypass! Feb 5 10:16:50 localhost vmunix: [ 0.942836] ima: Allocated hash algorithm: sha1 Feb 5 10:16:50 localhost vmunix: [ 0.943235] evm: Initialising EVM extended attributes: Feb 5 10:16:50 localhost vmunix: [ 0.943631] evm: security.selinux Feb 5 10:16:50 localhost vmunix: [ 0.943940] evm: security.SMACK64 Feb 5 10:16:50 localhost vmunix: [ 0.944247] evm: security.SMACK64EXEC Feb 5 10:16:50 localhost vmunix: [ 0.944573] evm: security.SMACK64TRANSMUTE Feb 5 10:16:50 localhost vmunix: [ 0.944896] evm: security.SMACK64MMAP Feb 5 10:16:50 localhost vmunix: [ 0.945198] evm: security.apparmor Feb 5 10:16:50 localhost vmunix: [ 0.945517] evm: security.ima Feb 5 10:16:50 localhost vmunix: [ 0.945791] evm: security.capability Feb 5 10:16:50 localhost vmunix: [ 0.946113] evm: HMAC attrs: 0x1 Feb 5 10:16:50 localhost vmunix: [ 0.946622] Magic number: 7:23:272 Feb 5 10:16:50 localhost vmunix: [ 0.947003] rtc_cmos rtc_cmos: setting system clock to 2019-02-05 09:16:41 UTC (1549358201) Feb 5 10:16:50 localhost vmunix: [ 1.061992] ata1.00: ATA-6: VBOX HARDDISK, 1.0, max UDMA/133 Feb 5 10:16:50 localhost vmunix: [ 1.062963] ata1.00: 209715200 sectors, multi 128: LBA Feb 5 10:16:50 localhost vmunix: [ 1.064886] scsi 0:0:0:0: Direct-Access ATA VBOX HARDDISK 1.0 PQ: 0 ANSI: 5 Feb 5 10:16:50 localhost vmunix: [ 1.070972] sd 0:0:0:0: [sda] 209715200 512-byte logical blocks: (107 GB/100 GiB) Feb 5 10:16:50 localhost vmunix: [ 1.072394] sd 0:0:0:0: Attached scsi generic sg0 type 0 Feb 5 10:16:50 localhost vmunix: [ 1.073474] sd 0:0:0:0: [sda] Write Protect is off Feb 5 10:16:50 localhost vmunix: [ 1.074379] sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA Feb 5 10:16:50 localhost vmunix: [ 1.077753] sda: sda1 Feb 5 10:16:50 localhost vmunix: [ 1.079051] sd 0:0:0:0: [sda] Attached SCSI disk Feb 5 10:16:50 localhost vmunix: [ 1.083128] Freeing unused kernel image memory: 1836K Feb 5 10:16:50 localhost vmunix: [ 1.111282] Write protecting the kernel read-only data: 18432k Feb 5 10:16:50 localhost vmunix: [ 1.112585] Freeing unused kernel image memory: 2032K Feb 5 10:16:50 localhost vmunix: [ 1.113227] Freeing unused kernel image memory: 112K Feb 5 10:16:50 localhost vmunix: [ 1.113734] Run /init as init process Feb 5 10:16:50 localhost vmunix: [ 1.225875] usbcore: registered new interface driver usb-storage Feb 5 10:16:50 localhost vmunix: [ 1.229518] usbcore: registered new interface driver uas Feb 5 10:16:50 localhost vmunix: [ 1.231779] hidraw: raw HID events driver (C) Jiri Kosina Feb 5 10:16:50 localhost vmunix: [ 1.232798] usbcore: registered new interface driver usbhid Feb 5 10:16:50 localhost vmunix: [ 1.233195] usbhid: USB HID core driver Feb 5 10:16:50 localhost vmunix: [ 1.254221] isci: Intel(R) C600 SAS Controller Driver - version 1.2.0 Feb 5 10:16:50 localhost vmunix: [ 1.257325] usb 1-1: new full-speed USB device number 2 using xhci_hcd Feb 5 10:16:50 localhost vmunix: [ 1.290864] EXT4-fs (sda1): mounted filesystem with ordered data mode. Opts: (null) Feb 5 10:16:50 localhost vmunix: [ 1.516923] random: fast init done Feb 5 10:16:50 localhost vmunix: [ 1.517375] usb 1-1: New USB device found, idVendor=80ee, idProduct=0021, bcdDevice= 1.00 Feb 5 10:16:50 localhost vmunix: [ 1.518137] usb 1-1: New USB device strings: Mfr=1, Product=3, SerialNumber=0 Feb 5 10:16:50 localhost vmunix: [ 1.518702] usb 1-1: Product: USB Tablet Feb 5 10:16:50 localhost vmunix: [ 1.519119] usb 1-1: Manufacturer: VirtualBox Feb 5 10:16:50 localhost vmunix: [ 1.520842] input: VirtualBox USB Tablet as /devices/pci0000:00/0000:00:0c.0/usb1/1-1/1-1:1.0/0003:80EE:0021.0001/input/input4 Feb 5 10:16:50 localhost vmunix: [ 1.522214] hid-generic 0003:80EE:0021.0001: input,hidraw0: USB HID v1.10 Mouse [VirtualBox USB Tablet] on usb-0000:00:0c.0-1/input0 Feb 5 10:16:50 localhost vmunix: [ 1.573552] usb 2-1: new SuperSpeed Gen 1 USB device number 2 using xhci_hcd Feb 5 10:16:50 localhost vmunix: [ 1.596234] usb 2-1: New USB device found, idVendor=0bc2, idProduct=ab2d, bcdDevice= 1.00 Feb 5 10:16:50 localhost vmunix: [ 1.597055] usb 2-1: New USB device strings: Mfr=2, Product=3, SerialNumber=1 Feb 5 10:16:50 localhost vmunix: [ 1.598054] usb 2-1: Product: Ultra Slim MT Feb 5 10:16:50 localhost vmunix: [ 1.598518] usb 2-1: Manufacturer: Seagate Feb 5 10:16:50 localhost vmunix: [ 1.598950] usb 2-1: SerialNumber: NA95GN93 Feb 5 10:16:50 localhost vmunix: [ 1.615725] usb 2-1: USB controller 0000:00:0c.0 does not support streams, which are required by the UAS driver. Feb 5 10:16:50 localhost vmunix: [ 1.616432] usb 2-1: Please try an other USB controller if you wish to use UAS. Feb 5 10:16:50 localhost vmunix: [ 1.616972] usb-storage 2-1:1.0: USB Mass Storage device detected Feb 5 10:16:50 localhost vmunix: [ 1.617945] scsi host2: usb-storage 2-1:1.0 Feb 5 10:16:50 localhost vmunix: [ 1.915360] random: shepherd: uninitialized urandom read (4096 bytes read) Feb 5 10:16:50 localhost vmunix: [ 2.112226] shepherd[1]: Service root has been started. Feb 5 10:16:50 localhost vmunix: [ 2.574825] shepherd[1]: starting services... Feb 5 10:16:50 localhost vmunix: [ 2.577239] shepherd[1]: Service root-file-system has been started. Feb 5 10:16:50 localhost vmunix: [ 2.579486] shepherd[1]: Service user-file-systems has been started. Feb 5 10:16:50 localhost vmunix: [ 2.597269] shepherd[1]: waiting for udevd... Feb 5 10:16:50 localhost vmunix: [ 2.626323] scsi 2:0:0:0: Direct-Access Seagate Ultra Slim MT 0304 PQ: 0 ANSI: 6 Feb 5 10:16:50 localhost vmunix: [ 2.627181] sd 2:0:0:0: Attached scsi generic sg1 type 0 Feb 5 10:16:50 localhost vmunix: [ 2.628647] sd 2:0:0:0: [sdb] 3907029167 512-byte logical blocks: (2.00 TB/1.82 TiB) Feb 5 10:16:50 localhost vmunix: [ 2.630651] sd 2:0:0:0: [sdb] Write Protect is off Feb 5 10:16:50 localhost vmunix: [ 2.632262] sd 2:0:0:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA Feb 5 10:16:50 localhost vmunix: [ 2.644218] udevd[226]: starting version 3.2.5 Feb 5 10:16:50 localhost vmunix: [ 2.651929] random: udevd: uninitialized urandom read (16 bytes read) Feb 5 10:16:50 localhost vmunix: [ 2.652967] random: udevd: uninitialized urandom read (16 bytes read) Feb 5 10:16:50 localhost vmunix: [ 2.658355] sdb: sdb1 Feb 5 10:16:50 localhost vmunix: [ 2.662893] sd 2:0:0:0: [sdb] Attached SCSI disk Feb 5 10:16:50 localhost vmunix: [ 2.711145] udevd[226]: starting eudev-3.2.5 Feb 5 10:16:50 localhost vmunix: [ 3.100347] urandom_read: 3 callbacks suppressed Feb 5 10:16:50 localhost vmunix: [ 3.100348] random: udevd: uninitialized urandom read (16 bytes read) Feb 5 10:16:50 localhost vmunix: [ 3.101328] random: udevd: uninitialized urandom read (16 bytes read) Feb 5 10:16:50 localhost vmunix: [ 3.101954] random: udevd: uninitialized urandom read (16 bytes read) Feb 5 10:16:50 localhost vmunix: [ 3.115850] udevd[226]: no sender credentials received, message ignored Feb 5 10:16:50 localhost vmunix: [ 3.223838] ACPI: Video Device [GFX0] (multi-head: yes rom: no post: no) Feb 5 10:16:50 localhost vmunix: [ 3.225554] piix4_smbus 0000:00:07.0: SMBus Host Controller at 0x4100, revision 0 Feb 5 10:16:50 localhost vmunix: [ 3.226881] input: Video Bus as /devices/LNXSYSTM:00/LNXSYBUS:00/PNP0A03:00/LNXVIDEO:00/input/input5 Feb 5 10:16:50 localhost vmunix: [ 3.231807] e1000: Intel(R) PRO/1000 Network Driver - version 7.3.21-k8-NAPI Feb 5 10:16:50 localhost vmunix: [ 3.232591] e1000: Copyright (c) 1999-2006 Intel Corporation. Feb 5 10:16:50 localhost vmunix: [ 3.236849] vboxguest: host-version: 5.2.22r126460 0x1 Feb 5 10:16:50 localhost vmunix: [ 3.257490] vbg_heartbeat_init: Setting up heartbeat to trigger every 2000 milliseconds Feb 5 10:16:50 localhost vmunix: [ 3.261704] input: VirtualBox mouse integration as /devices/pci0000:00/0000:00:04.0/input/input6 Feb 5 10:16:50 localhost vmunix: [ 3.269374] vboxguest: misc device minor 55, IRQ 20, I/O port d020, MMIO at 0x00000000f0400000 (size 0x0000000000400000) Feb 5 10:16:50 localhost vmunix: [ 3.331752] input: PC Speaker as /devices/platform/pcspkr/input/input8 Feb 5 10:16:50 localhost vmunix: [ 3.360607] Error: Driver 'pcspkr' is already registered, aborting... Feb 5 10:16:50 localhost vmunix: [ 3.381988] vboxvideo: module is from the staging directory, the quality is unknown, you have been warned. Feb 5 10:16:50 localhost vmunix: [ 3.396850] [drm] VRAM 08000000 Feb 5 10:16:50 localhost vmunix: [ 3.405888] [TTM] Zone kernel: Available graphics memory: 3052792 kiB Feb 5 10:16:50 localhost vmunix: [ 3.406651] [TTM] Zone dma32: Available graphics memory: 2097152 kiB Feb 5 10:16:50 localhost vmunix: [ 3.407376] [TTM] Initializing pool allocator Feb 5 10:16:50 localhost vmunix: [ 3.407955] [TTM] Initializing DMA pool allocator Feb 5 10:16:50 localhost vmunix: [ 3.413515] fbcon: vboxdrmfb (fb0) is primary device Feb 5 10:16:50 localhost vmunix: [ 3.435817] Console: switching to colour frame buffer device 100x37 Feb 5 10:16:50 localhost vmunix: [ 3.441896] cryptd: max_cpu_qlen set to 1000 Feb 5 10:16:50 localhost vmunix: [ 3.444636] vboxvideo 0000:00:02.0: fb0: vboxdrmfb frame buffer device Feb 5 10:16:50 localhost vmunix: [ 3.473380] [drm] Initialized vboxvideo 1.0.0 20130823 for 0000:00:02.0 on minor 0 Feb 5 10:16:50 localhost vmunix: [ 3.547752] input: ImExPS/2 Generic Explorer Mouse as /devices/platform/i8042/serio1/input/input7 Feb 5 10:16:50 localhost vmunix: [ 3.603503] random: crng init done Feb 5 10:16:50 localhost vmunix: [ 3.603534] random: 1 urandom warning(s) missed due to ratelimiting Feb 5 10:16:50 localhost vmunix: [ 3.621045] AVX2 version of gcm_enc/dec engaged. Feb 5 10:16:50 localhost vmunix: [ 3.621068] AES CTR mode by8 optimization enabled Feb 5 10:16:50 localhost vmunix: [ 3.698176] Error: Driver 'pcspkr' is already registered, aborting... Feb 5 10:16:50 localhost vmunix: [ 5.234134] e1000 0000:00:03.0 eth0: (PCI:33MHz:32-bit) 08:00:27:05:e5:16 Feb 5 10:16:50 localhost vmunix: [ 5.234186] e1000 0000:00:03.0 eth0: Intel(R) PRO/1000 Network Connection Feb 5 10:16:50 localhost vmunix: [ 6.359585] e1000 0000:00:03.0 enp0s3: renamed from eth0 Feb 5 10:16:50 localhost vmunix: [ 6.717424] snd_intel8x0 0000:00:05.0: intel8x0_measure_ac97_clock: measured 289540 usecs (32768 samples) Feb 5 10:16:50 localhost vmunix: [ 6.718057] snd_intel8x0 0000:00:05.0: measured clock 113172 rejected Feb 5 10:16:50 localhost vmunix: [ 7.111538] snd_intel8x0 0000:00:05.0: intel8x0_measure_ac97_clock: measured 62702 usecs (52800 samples) Feb 5 10:16:50 localhost vmunix: [ 7.112731] snd_intel8x0 0000:00:05.0: measured clock 842078 rejected Feb 5 10:16:50 localhost vmunix: [ 7.554863] snd_intel8x0 0000:00:05.0: intel8x0_measure_ac97_clock: measured 63241 usecs (52800 samples) Feb 5 10:16:50 localhost vmunix: [ 7.555534] snd_intel8x0 0000:00:05.0: measured clock 834901 rejected Feb 5 10:16:50 localhost vmunix: [ 7.555923] snd_intel8x0 0000:00:05.0: clocking to 48000 Feb 5 10:16:50 localhost vmunix: [ 7.614123] shepherd[1]: Service udev has been started. Feb 5 10:16:50 localhost vmunix: [ 7.620079] shepherd[1]: Service file-system-/dev/pts has been started. Feb 5 10:16:50 localhost vmunix: [ 7.624460] shepherd[1]: Service file-system-/dev/shm has been started. Feb 5 10:16:50 localhost vmunix: [ 7.627768] shepherd[1]: Service file-system-/gnu/store has been started. Feb 5 10:16:50 localhost vmunix: [ 7.632415] shepherd[1]: Service file-system-/run/systemd has been started. Feb 5 10:16:50 localhost vmunix: [ 7.637661] shepherd[1]: Service file-system-/run/user has been started. Feb 5 10:16:50 localhost vmunix: [ 7.642228] shepherd[1]: Service file-system-/sys/fs/cgroup has been started. Feb 5 10:16:50 localhost vmunix: [ 7.645880] shepherd[1]: Service file-system-/sys/fs/cgroup/elogind has been started. Feb 5 10:16:50 localhost vmunix: [ 7.650668] shepherd[1]: Service file-system-/sys/fs/cgroup/cpuset has been started. Feb 5 10:16:50 localhost vmunix: [ 7.656170] shepherd[1]: Service file-system-/sys/fs/cgroup/cpu has been started. Feb 5 10:16:50 localhost vmunix: [ 7.660985] shepherd[1]: Service file-system-/sys/fs/cgroup/cpuacct has been started. Feb 5 10:16:50 localhost vmunix: [ 7.668727] shepherd[1]: Service file-system-/sys/fs/cgroup/memory has been started. Feb 5 10:16:50 localhost vmunix: [ 7.672988] shepherd[1]: Service file-system-/sys/fs/cgroup/devices has been started. Feb 5 10:16:50 localhost vmunix: [ 7.677617] shepherd[1]: Service file-system-/sys/fs/cgroup/freezer has been started. Feb 5 10:16:50 localhost vmunix: [ 7.683015] shepherd[1]: Service file-system-/sys/fs/cgroup/blkio has been started. Feb 5 10:16:50 localhost vmunix: [ 7.686707] shepherd[1]: Service file-system-/sys/fs/cgroup/perf_event has been started. Feb 5 10:16:50 localhost vmunix: [ 7.689707] shepherd[1]: Service file-systems has been started. Feb 5 10:16:50 localhost vmunix: [ 7.705657] shepherd[1]: Service urandom-seed has been started. Feb 5 10:16:50 localhost vmunix: [ 7.708740] shepherd[1]: Service user-processes has been started. Feb 5 10:16:50 localhost vmunix: [ 7.712567] shepherd[1]: Service host-name has been started. Feb 5 10:16:50 localhost vmunix: [ 7.722636] shepherd[1]: Service user-homes could not be started. Feb 5 10:16:50 localhost vmunix: [ 8.888557] shepherd[1]: Service nscd has been started. Feb 5 10:16:50 localhost vmunix: [ 8.895107] shepherd[1]: Service guix-daemon has been started. Feb 5 10:16:50 localhost shepherd[1]: Service dbus-system has been started. Feb 5 10:16:50 localhost shepherd[1]: Service wpa-supplicant has been started. Feb 5 10:16:50 localhost shepherd[1]: Service networking has been started. Feb 5 10:16:50 localhost shepherd[1]: Service ntpd has been started. Feb 5 10:16:50 localhost shepherd[1]: Service elogind has been started. Feb 5 10:16:50 localhost shepherd[1]: Service upower-daemon has been started. Feb 5 10:16:51 localhost avahi-daemon[359]: Found user 'avahi' (UID 994) and group 'avahi' (GID 979). Feb 5 10:16:51 localhost avahi-daemon[359]: Successfully dropped root privileges. Feb 5 10:16:51 localhost avahi-daemon[359]: avahi-daemon 0.7 starting up. Feb 5 10:16:51 localhost avahi-daemon[359]: WARNING: No NSS support for mDNS detected, consider installing nss-mdns! Feb 5 10:16:51 localhost avahi-daemon[359]: Successfully called chroot(). Feb 5 10:16:51 localhost avahi-daemon[359]: Successfully dropped remaining capabilities. Feb 5 10:16:51 localhost avahi-daemon[359]: Loading service file /services/sftp-ssh.service. Feb 5 10:16:51 localhost avahi-daemon[359]: Loading service file /services/ssh.service. Feb 5 10:16:51 localhost avahi-daemon[359]: Network interface enumeration completed. Feb 5 10:16:51 localhost avahi-daemon[359]: Server startup complete. Host name is guixsd.local. Local service cookie is 1225535440. Feb 5 10:16:51 localhost avahi-daemon[359]: Service "guixsd" (/services/ssh.service) successfully established. Feb 5 10:16:51 localhost avahi-daemon[359]: Service "guixsd" (/services/sftp-ssh.service) successfully established. Feb 5 10:16:51 localhost shepherd[1]: Service avahi-daemon has been started. Feb 5 10:16:51 localhost shepherd[1]: Service xorg-server has been started. Feb 5 10:16:51 localhost ntpd[354]: ntpd 4.2.8p12@1.3728-o Mon Dec 3 15:10:30 UTC 2018 (1): Starting Feb 5 10:16:51 localhost ntpd[354]: Command line: /gnu/store/wcsjiw5nfv861ysnv00m2hj9fil3h51k-ntp-4.2.8p12/bin/ntpd -n -c /gnu/store/1l1yf5dss8r9pqxklaax32s6bkah09c6-ntpd.conf -u ntpd Feb 5 10:16:51 localhost shepherd[1]: Service containerd has been started. Feb 5 10:16:51 localhost ntpd[354]: proto: precision = 0.155 usec (-23) Feb 5 10:16:51 localhost ntpd[354]: restrict default: KOD does nothing without LIMITED. Feb 5 10:16:51 localhost ntpd[354]: restrict ::: KOD does nothing without LIMITED. Feb 5 10:16:51 localhost ntpd[354]: Listen and drop on 0 v6wildcard [::]:123 Feb 5 10:16:51 localhost ntpd[354]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Feb 5 10:16:51 localhost ntpd[354]: Listen normally on 2 lo 127.0.0.1:123 Feb 5 10:16:51 localhost ntpd[354]: Listen normally on 3 lo [::1]:123 Feb 5 10:16:51 localhost ntpd[354]: Listening on routing socket on fd #20 for interface updates Feb 5 10:16:51 localhost ntpd[354]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Feb 5 10:16:51 localhost ntpd[354]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.3005] NetworkManager (version 1.8.4) is starting... (for the first time) Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.3006] Read config: /gnu/store/3cp48fvxfivj2255bbxj7363qj33ajs9-NetworkManager.conf Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.3243] manager[0x121d0c0]: monitoring kernel firmware directory '/lib/firmware'. Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.3291] policy: hostname management mode: default Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.3309] dns-mgr[0x1229160]: init: dns=default, rc-manager=symlink Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.3329] manager[0x121d0c0]: rfkill: WiFi hardware radio set enabled Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.3331] manager[0x121d0c0]: rfkill: WWAN hardware radio set enabled Feb 5 10:16:51 localhost dbus-daemon[350]: [system] Activating service name='org.freedesktop.nm_dispatcher' requested by ':1.4' (uid=0 pid=353 comm="/gnu/store/yccciw23f76dpfnm0f2d7kzxlb2h973c-networ") (using servicehelper) Feb 5 10:16:51 localhost dbus-daemon[350]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher' Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.4106] settings: loaded plugin keyfile: (c) 2007 - 2016 Red Hat, Inc. To report bugs please use the NetworkManager mailing list. Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.4427] keyfile: new connection /etc/NetworkManager/system-connections/Tenda_2F20A0 (dafd4a72-d2d2-48e4-a2f0-36b6d632a0c5,"Tenda_2F20A0") Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.4500] settings: hostname: couldn't get property from hostnamed Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.4634] dhcp-init: Using DHCP client 'dhclient' Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.4636] manager: rfkill: WiFi enabled by radio killswitch; enabled by state file Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.4636] manager: rfkill: WWAN enabled by radio killswitch; enabled by state file Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.4651] manager: Networking is enabled by state file Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.4673] Loaded device plugin: NMBondDeviceFactory (internal) Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.4675] Loaded device plugin: NMBridgeDeviceFactory (internal) Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.4676] Loaded device plugin: NMDummyDeviceFactory (internal) Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.4695] Loaded device plugin: NMEthernetDeviceFactory (internal) Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.4696] Loaded device plugin: NMInfinibandDeviceFactory (internal) Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.4699] Loaded device plugin: NMIPTunnelDeviceFactory (internal) Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.4705] Loaded device plugin: NMMacsecDeviceFactory (internal) Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.4706] Loaded device plugin: NMMacvlanDeviceFactory (internal) Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.4713] Loaded device plugin: NMTunDeviceFactory (internal) Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.4714] Loaded device plugin: NMVethDeviceFactory (internal) Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.4715] Loaded device plugin: NMVlanDeviceFactory (internal) Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.4716] Loaded device plugin: NMVxlanDeviceFactory (internal) Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.4763] Loaded device plugin: NMAtmManager (/gnu/store/yccciw23f76dpfnm0f2d7kzxlb2h973c-network-manager-1.8.4/lib/NetworkManager/libnm-device-plugin-adsl.so) Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.4840] Loaded device plugin: NMWifiFactory (/gnu/store/yccciw23f76dpfnm0f2d7kzxlb2h973c-network-manager-1.8.4/lib/NetworkManager/libnm-device-plugin-wifi.so) Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.5339] Loaded device plugin: NMBluezManager (/gnu/store/yccciw23f76dpfnm0f2d7kzxlb2h973c-network-manager-1.8.4/lib/NetworkManager/libnm-device-plugin-bluetooth.so) Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.5402] Loaded device plugin: NMWwanFactory (/gnu/store/yccciw23f76dpfnm0f2d7kzxlb2h973c-network-manager-1.8.4/lib/NetworkManager/libnm-device-plugin-wwan.so) Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.5440] device (lo): link connected Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.5458] manager: (lo): new Generic device (/org/freedesktop/NetworkManager/Devices/1) Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.5480] manager: (enp0s3): new Ethernet device (/org/freedesktop/NetworkManager/Devices/2) Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.5542] keyfile: add connection in-memory (82fc517c-d2f9-34d7-b457-6a76d13e294a,"Wired connection 1") Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.5635] settings: (enp0s3): created default wired connection 'Wired connection 1' Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.5827] device (enp0s3): state change: unmanaged -> unavailable (reason 'managed', internal state 'external') Feb 5 10:16:51 localhost vmunix: [ 11.031113] IPv6: ADDRCONF(NETDEV_UP): enp0s3: link is not ready Feb 5 10:16:51 localhost vmunix: [ 11.038770] IPv6: ADDRCONF(NETDEV_UP): enp0s3: link is not ready Feb 5 10:16:51 localhost vmunix: [ 11.042373] e1000: enp0s3 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: RX Feb 5 10:16:51 localhost vmunix: [ 11.043277] IPv6: ADDRCONF(NETDEV_CHANGE): enp0s3: link becomes ready Feb 5 10:16:51 localhost dbus-daemon[350]: [system] Activating service name='org.freedesktop.PolicyKit1' requested by ':1.4' (uid=0 pid=353 comm="/gnu/store/yccciw23f76dpfnm0f2d7kzxlb2h973c-networ") (using servicehelper) Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.6635] device (enp0s3): link connected Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.6656] device (enp0s3): state change: unavailable -> disconnected (reason 'carrier-changed', internal state 'managed') Feb 5 10:16:51 localhost NetworkManager[353]: <warn> [1549358211.6753] error poking ModemManager: GDBus.Error:org.freedesktop.DBus.Error.ServiceUnknown: The name org.freedesktop.ModemManager1 was not provided by any .service files Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.6758] policy: auto-activating connection 'Wired connection 1' Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.6899] device (enp0s3): Activation: starting connection 'Wired connection 1' (82fc517c-d2f9-34d7-b457-6a76d13e294a) Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.6906] device (enp0s3): state change: disconnected -> prepare (reason 'none', internal state 'managed') Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.6908] manager: NetworkManager state is now CONNECTING Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.6914] device (enp0s3): state change: prepare -> config (reason 'none', internal state 'managed') Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.6927] device (enp0s3): state change: config -> ip-config (reason 'none', internal state 'managed') Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.6956] dhcp4 (enp0s3): activation: beginning transaction (timeout in 45 seconds) Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.7144] dhcp4 (enp0s3): dhclient started with pid 400 Feb 5 10:16:51 localhost avahi-daemon[359]: Joining mDNS multicast group on interface enp0s3.IPv6 with address fe80::e882:9a4a:3a68:9d76. Feb 5 10:16:51 localhost avahi-daemon[359]: New relevant interface enp0s3.IPv6 for mDNS. Feb 5 10:16:51 localhost avahi-daemon[359]: Registering new address record for fe80::e882:9a4a:3a68:9d76 on enp0s3.*. Feb 5 10:16:51 localhost polkitd[396]: Started polkitd version 0.115 Feb 5 10:16:51 localhost dhclient: DHCPREQUEST for 10.0.2.15 on enp0s3 to 255.255.255.255 port 67 Feb 5 10:16:51 localhost dhclient: DHCPACK of 10.0.2.15 from 10.0.2.2 Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.8439] dhcp4 (enp0s3): address 10.0.2.15 Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.8440] dhcp4 (enp0s3): plen 24 (255.255.255.0) Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.8441] dhcp4 (enp0s3): gateway 10.0.2.2 Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.8441] dhcp4 (enp0s3): lease time 86400 Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.8441] dhcp4 (enp0s3): nameserver '172.16.0.26' Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.8441] dhcp4 (enp0s3): nameserver '172.16.0.25' Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.8441] dhcp4 (enp0s3): domain name 'oslo.geodata.no' Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.8441] dhcp4 (enp0s3): state changed unknown -> bound Feb 5 10:16:51 localhost avahi-daemon[359]: Joining mDNS multicast group on interface enp0s3.IPv4 with address 10.0.2.15. Feb 5 10:16:51 localhost avahi-daemon[359]: New relevant interface enp0s3.IPv4 for mDNS. Feb 5 10:16:51 localhost avahi-daemon[359]: Registering new address record for 10.0.2.15 on enp0s3.IPv4. Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.8521] device (enp0s3): state change: ip-config -> ip-check (reason 'none', internal state 'managed') Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.8602] device (enp0s3): state change: ip-check -> secondaries (reason 'none', internal state 'managed') Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.8614] device (enp0s3): state change: secondaries -> activated (reason 'none', internal state 'managed') Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.8630] manager: NetworkManager state is now CONNECTED_LOCAL Feb 5 10:16:51 localhost dhclient: bound to 10.0.2.15 -- renewal in 34812 seconds. Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.8850] manager: NetworkManager state is now CONNECTED_SITE Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.8852] policy: set 'Wired connection 1' (enp0s3) as default for IPv4 routing and DNS Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.9000] device (enp0s3): Activation: successful, device activated. Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.9005] manager: startup complete Feb 5 10:16:51 localhost nscd: 320 monitored file `/etc/resolv.conf` was moved into place, adding watch Feb 5 10:16:51 localhost NetworkManager[353]: <info> [1549358211.9031] manager: NetworkManager state is now CONNECTED_GLOBAL Feb 5 10:16:52 localhost dbus-daemon[350]: [system] Successfully activated service 'org.freedesktop.PolicyKit1' Feb 5 10:16:54 localhost ntpd[354]: Listen normally on 4 enp0s3 10.0.2.15:123 Feb 5 10:16:54 localhost ntpd[354]: Listen normally on 5 enp0s3 [fe80::e882:9a4a:3a68:9d76%2]:123 Feb 5 10:16:56 localhost shepherd[1]: Service dockerd could not be started. Feb 5 10:16:56 localhost shepherd[1]: Service console-keymap has been started. Feb 5 10:17:00 localhost dbus-daemon[452]: [session uid=1000 pid=450] Activating service name='org.gtk.vfs.Daemon' requested by ':1.2' (uid=1000 pid=442 comm="/gnu/store/dlmbp3cx7qpvshswz726yp2kq13cizcm-gnome-") Feb 5 10:17:00 localhost dbus-daemon[452]: [session uid=1000 pid=450] Successfully activated service 'org.gtk.vfs.Daemon' Feb 5 10:17:01 localhost vmunix: [ 20.501520] fuse init (API version 7.28) Feb 5 10:17:01 localhost gnome-keyring-daemon[482]: couldn't access control socket: /run/user/1000/keyring/control: No such file or directory Feb 5 10:17:01 localhost gnome-keyring-daemon[481]: couldn't access control socket: /run/user/1000/keyring/control: No such file or directory Feb 5 10:17:01 localhost dbus-daemon[452]: [session uid=1000 pid=450] Activating service name='org.a11y.Bus' requested by ':1.8' (uid=1000 pid=489 comm="/gnu/store/is5qsnj1n8rjfiwgsa21m2fxza61y13j-gnome-") Feb 5 10:17:01 localhost dbus-daemon[452]: [session uid=1000 pid=450] Successfully activated service 'org.a11y.Bus' Feb 5 10:17:02 localhost pulseaudio[510]: [pulseaudio] alsa-util.c: Disabling timer-based scheduling because running inside a VM. Feb 5 10:17:02 localhost pulseaudio[510]: [pulseaudio] alsa-util.c: Disabling timer-based scheduling because running inside a VM. Feb 5 10:17:02 localhost pulseaudio[510]: [alsa-sink-Intel ICH] alsa-sink.c: ALSA woke us up to write new data to the device, but there was actually nothing to write. Feb 5 10:17:02 localhost pulseaudio[510]: [alsa-sink-Intel ICH] alsa-sink.c: Most likely this is a bug in the ALSA driver 'snd_intel8x0'. Please report this issue to the ALSA developers. Feb 5 10:17:02 localhost pulseaudio[510]: [alsa-sink-Intel ICH] alsa-sink.c: We were woken up with POLLOUT set -- however a subsequent snd_pcm_avail() returned 0 or another value < min_avail. Feb 5 10:17:03 localhost pulseaudio[510]: [pulseaudio] bluez5-util.c: GetManagedObjects() failed: org.freedesktop.DBus.Error.ServiceUnknown: The name org.bluez was not provided by any .service files Feb 5 10:17:04 localhost dbus-daemon[452]: [session uid=1000 pid=450] Activating service name='org.gnome.Shell.CalendarServer' requested by ':1.7' (uid=1000 pid=489 comm="/gnu/store/is5qsnj1n8rjfiwgsa21m2fxza61y13j-gnome-") Feb 5 10:17:04 localhost dbus-daemon[452]: [session uid=1000 pid=450] Activated service 'org.gnome.Shell.CalendarServer' failed: Process org.gnome.Shell.CalendarServer exited with status 1 Feb 5 10:17:04 localhost dbus-daemon[350]: [system] Activating service name='org.freedesktop.Accounts' requested by ':1.11' (uid=1000 pid=489 comm="/gnu/store/is5qsnj1n8rjfiwgsa21m2fxza61y13j-gnome-") (using servicehelper) Feb 5 10:17:04 localhost accounts-daemon[534]: started daemon version 0.6.50 Feb 5 10:17:04 localhost dbus-daemon[350]: [system] Successfully activated service 'org.freedesktop.Accounts' Feb 5 10:17:04 localhost dbus-daemon[350]: [system] Activating service name='org.freedesktop.GeoClue2' requested by ':1.11' (uid=1000 pid=489 comm="/gnu/store/is5qsnj1n8rjfiwgsa21m2fxza61y13j-gnome-") (using servicehelper) Feb 5 10:17:04 localhost dbus-daemon[452]: [session uid=1000 pid=450] Activating service name='ca.desrt.dconf' requested by ':1.7' (uid=1000 pid=489 comm="/gnu/store/is5qsnj1n8rjfiwgsa21m2fxza61y13j-gnome-") Feb 5 10:17:04 localhost dbus-daemon[452]: [session uid=1000 pid=450] Successfully activated service 'ca.desrt.dconf' Feb 5 10:17:04 localhost dbus-daemon[350]: [system] Successfully activated service 'org.freedesktop.GeoClue2' Feb 5 10:17:05 localhost dbus-daemon[452]: [session uid=1000 pid=450] Activating service name='org.gtk.vfs.UDisks2VolumeMonitor' requested by ':1.7' (uid=1000 pid=489 comm="/gnu/store/is5qsnj1n8rjfiwgsa21m2fxza61y13j-gnome-") Feb 5 10:17:05 localhost dbus-daemon[350]: [system] Activating service name='org.freedesktop.UDisks2' requested by ':1.37' (uid=1000 pid=549 comm="/gnu/store/dlz15s83xkf1bk9m8qx8r7f94xqnxkz7-gvfs-1") (using servicehelper) Feb 5 10:17:05 localhost dbus-daemon[350]: [system] Successfully activated service 'org.freedesktop.UDisks2' Feb 5 10:17:05 localhost dbus-daemon[452]: [session uid=1000 pid=450] Successfully activated service 'org.gtk.vfs.UDisks2VolumeMonitor' Feb 5 10:17:05 localhost dbus-daemon[452]: [session uid=1000 pid=450] Activating service name='org.gtk.vfs.GPhoto2VolumeMonitor' requested by ':1.7' (uid=1000 pid=489 comm="/gnu/store/is5qsnj1n8rjfiwgsa21m2fxza61y13j-gnome-") Feb 5 10:17:05 localhost dbus-daemon[452]: [session uid=1000 pid=450] Successfully activated service 'org.gtk.vfs.GPhoto2VolumeMonitor' Feb 5 10:17:05 localhost dbus-daemon[452]: [session uid=1000 pid=450] Activating service name='org.gtk.vfs.MTPVolumeMonitor' requested by ':1.7' (uid=1000 pid=489 comm="/gnu/store/is5qsnj1n8rjfiwgsa21m2fxza61y13j-gnome-") Feb 5 10:17:05 localhost dbus-daemon[452]: [session uid=1000 pid=450] Successfully activated service 'org.gtk.vfs.MTPVolumeMonitor' Feb 5 10:17:08 localhost dbus-daemon[350]: [system] Activating service name='org.freedesktop.ColorManager' requested by ':1.43' (uid=1000 pid=585 comm="/gnu/store/97fg4ncq5f7d2ldx4qiyjkpcpvspl1ll-gnome-") (using servicehelper) Feb 5 10:17:08 localhost colord: Using mapping database file /var/lib/colord/mapping.db Feb 5 10:17:08 localhost colord: Using device database file /var/lib/colord/storage.db Feb 5 10:17:08 localhost colord: loaded plugin libcd_plugin_scanner.so Feb 5 10:17:08 localhost colord: loaded plugin libcd_plugin_sane.so Feb 5 10:17:08 localhost colord: loaded plugin libcd_plugin_camera.so Feb 5 10:17:08 localhost colord: Daemon ready for requests Feb 5 10:17:08 localhost dbus-daemon[350]: [system] Successfully activated service 'org.freedesktop.ColorManager' Feb 5 10:17:08 localhost colord: Profile added: icc-06b14b003d198ad249bbe13463e7c4e0 Feb 5 10:17:08 localhost colord: Profile added: icc-3b6c50986651e0a8a606a9189110b31e Feb 5 10:17:09 localhost colord: Automatic metadata add icc-06b14b003d198ad249bbe13463e7c4e0 to xrandr-Undefined-VBOX monitor-70780800 Feb 5 10:17:09 localhost colord: Device added: xrandr-Undefined-VBOX monitor-70780800 Feb 5 10:18:50 localhost dbus-daemon[452]: [session uid=1000 pid=450] Activating service name='org.gnome.Terminal' requested by ':1.42' (uid=1000 pid=1014 comm="/gnu/store/1119fvj0ys11389ybyvkazp02ywl7l8h-gnome-") Feb 5 10:18:51 localhost dbus-daemon[452]: [session uid=1000 pid=450] Successfully activated service 'org.gnome.Terminal' Feb 5 10:19:44 localhost shepherd[1]: Service dockerd could not be started. Feb 5 10:25:00 localhost vmunix: [ 497.738320] usb 2-1: USB disconnect, device number 2 Feb 5 10:25:00 localhost vmunix: [ 497.743558] sd 2:0:0:0: [sdb] Synchronizing SCSI cache Feb 5 10:25:00 localhost vmunix: [ 497.743777] sd 2:0:0:0: [sdb] Synchronize Cache(10) failed: Result: hostbyte=DID_NO_CONNECT driverbyte=DRIVER_OK Feb 5 10:25:04 localhost vmunix: [ 501.766506] usb 2-1: new SuperSpeed Gen 1 USB device number 3 using xhci_hcd Feb 5 10:25:04 localhost vmunix: [ 501.787826] usb 2-1: New USB device found, idVendor=0bc2, idProduct=ab2d, bcdDevice= 1.00 Feb 5 10:25:04 localhost vmunix: [ 501.787830] usb 2-1: New USB device strings: Mfr=2, Product=3, SerialNumber=1 Feb 5 10:25:04 localhost vmunix: [ 501.787832] usb 2-1: Product: Ultra Slim MT Feb 5 10:25:04 localhost vmunix: [ 501.787834] usb 2-1: Manufacturer: Seagate Feb 5 10:25:04 localhost vmunix: [ 501.787836] usb 2-1: SerialNumber: NA95GN93 Feb 5 10:25:04 localhost vmunix: [ 501.798611] usb 2-1: USB controller 0000:00:0c.0 does not support streams, which are required by the UAS driver. Feb 5 10:25:04 localhost vmunix: [ 501.798615] usb 2-1: Please try an other USB controller if you wish to use UAS. Feb 5 10:25:04 localhost vmunix: [ 501.798617] usb-storage 2-1:1.0: USB Mass Storage device detected Feb 5 10:25:04 localhost vmunix: [ 501.801157] scsi host2: usb-storage 2-1:1.0 Feb 5 10:25:04 localhost mtp-probe: checking bus 2, device 3: "/sys/devices/pci0000:00/0000:00:0c.0/usb2/2-1" Feb 5 10:25:04 localhost mtp-probe: bus: 2, device: 3 was not an MTP device Feb 5 10:25:04 localhost mtp-probe: checking bus 2, device 3: "/sys/devices/pci0000:00/0000:00:0c.0/usb2/2-1" Feb 5 10:25:04 localhost mtp-probe: bus: 2, device: 3 was not an MTP device Feb 5 10:25:05 localhost vmunix: [ 502.818935] scsi 2:0:0:0: Direct-Access Seagate Ultra Slim MT 0304 PQ: 0 ANSI: 6 Feb 5 10:25:05 localhost vmunix: [ 502.819242] sd 2:0:0:0: Attached scsi generic sg1 type 0 Feb 5 10:25:05 localhost vmunix: [ 502.823116] sd 2:0:0:0: [sdb] Spinning up disk... Feb 5 10:25:07 localhost vmunix: [ 503.865399] ..ready Feb 5 10:25:07 localhost vmunix: [ 504.902878] sd 2:0:0:0: [sdb] 3907029167 512-byte logical blocks: (2.00 TB/1.82 TiB) Feb 5 10:25:07 localhost vmunix: [ 505.091798] sd 2:0:0:0: [sdb] Write Protect is off Feb 5 10:25:07 localhost vmunix: [ 505.092838] sd 2:0:0:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA Feb 5 10:25:07 localhost vmunix: [ 505.201622] sdb: sdb1 Feb 5 10:25:07 localhost vmunix: [ 505.223886] sd 2:0:0:0: [sdb] Attached SCSI disk Feb 5 10:25:16 localhost vmunix: [ 514.200281] NET: Registered protocol family 38 Feb 5 10:25:17 localhost vmunix: [ 515.126966] EXT4-fs (dm-0): mounted filesystem with ordered data mode. Opts: (null) Feb 5 10:25:17 localhost dbus-daemon[452]: [session uid=1000 pid=450] Activating service name='org.gnome.Shell.HotplugSniffer' requested by ':1.7' (uid=1000 pid=489 comm="/gnu/store/is5qsnj1n8rjfiwgsa21m2fxza61y13j-gnome-") Feb 5 10:25:17 localhost dbus-daemon[452]: [session uid=1000 pid=450] Successfully activated service 'org.gnome.Shell.HotplugSniffer' Feb 5 10:25:40 localhost ntpd[354]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Feb 5 10:36:51 localhost -- MARK -- Feb 5 10:55:01 localhost nscd: 320 monitored file `/etc/hosts` was deleted, removing watch Feb 5 10:55:01 localhost nscd: 320 monitored file `/etc/hosts` was created, adding watch Feb 5 10:55:01 localhost nscd: 320 monitored file `/etc/hosts` was written to Feb 5 10:55:01 localhost nscd: 320 monitored file `/etc/services` was deleted, removing watch Feb 5 10:55:01 localhost nscd: 320 monitored file `/etc/services` was created, adding watch Feb 5 10:55:01 localhost nscd: 320 monitored file `/etc/services` was written to Feb 5 10:55:01 localhost NetworkManager[353]: <info> [1549360501.7877] settings: hostname changed from (none) to "guixsd" Feb 5 10:55:02 localhost shepherd[1]: Evaluating user expression (let* ((services (map primitive-load (?))) # ?) ?). Feb 5 10:55:03 localhost shepherd[1]: Service user-homes could not be started. Feb 5 10:55:03 localhost shepherd[1]: Service term-auto could not be started. Feb 5 10:55:03 localhost shepherd[1]: Service dockerd has been started. Feb 5 10:55:03 localhost vmunix: [ 2301.432366] 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:55:03 localhost vmunix: [ 2301.434033] Bridge firewalling registered Feb 5 10:55:04 localhost vmunix: [ 2302.168789] Initializing XFRM netlink socket Feb 5 10:55:04 localhost NetworkManager[353]: <info> [1549360504.6193] manager: (docker0): new Bridge device (/org/freedesktop/NetworkManager/Devices/3) Feb 5 10:55:04 localhost NetworkManager[353]: <info> [1549360504.8436] device (docker0): state change: unmanaged -> unavailable (reason 'connection-assumed', internal state 'external') Feb 5 10:55:04 localhost NetworkManager[353]: <info> [1549360504.8457] keyfile: add connection in-memory (599906c3-5c6b-4e6b-be3f-83eea3fb862f,"docker0") Feb 5 10:55:04 localhost avahi-daemon[359]: Joining mDNS multicast group on interface docker0.IPv4 with address 172.17.0.1. Feb 5 10:55:04 localhost NetworkManager[353]: <info> [1549360504.8484] device (docker0): state change: unavailable -> disconnected (reason 'connection-assumed', internal state 'external') Feb 5 10:55:04 localhost NetworkManager[353]: <info> [1549360504.8513] device (docker0): Activation: starting connection 'docker0' (599906c3-5c6b-4e6b-be3f-83eea3fb862f) Feb 5 10:55:04 localhost vmunix: [ 2302.435597] IPv6: ADDRCONF(NETDEV_UP): docker0: link is not ready Feb 5 10:55:04 localhost avahi-daemon[359]: New relevant interface docker0.IPv4 for mDNS. Feb 5 10:55:04 localhost avahi-daemon[359]: Registering new address record for 172.17.0.1 on docker0.IPv4. Feb 5 10:55:04 localhost NetworkManager[353]: <info> [1549360504.8649] device (docker0): state change: disconnected -> prepare (reason 'none', internal state 'external') Feb 5 10:55:04 localhost NetworkManager[353]: <info> [1549360504.8670] device (docker0): state change: prepare -> config (reason 'none', internal state 'external') Feb 5 10:55:04 localhost NetworkManager[353]: <info> [1549360504.8676] device (docker0): state change: config -> ip-config (reason 'none', internal state 'external') Feb 5 10:55:04 localhost NetworkManager[353]: <warn> [1549360504.8814] arping[0x12f5780,3]: arping could not be found; no ARPs will be sent Feb 5 10:55:04 localhost NetworkManager[353]: <info> [1549360504.8814] device (docker0): state change: ip-config -> ip-check (reason 'none', internal state 'external') Feb 5 10:55:04 localhost NetworkManager[353]: <info> [1549360504.8818] device (docker0): state change: ip-check -> secondaries (reason 'none', internal state 'external') Feb 5 10:55:04 localhost NetworkManager[353]: <info> [1549360504.8821] device (docker0): state change: secondaries -> activated (reason 'none', internal state 'external') Feb 5 10:55:04 localhost NetworkManager[353]: <info> [1549360504.8961] device (docker0): Activation: successful, device activated. Feb 5 10:55:07 localhost NetworkManager[353]: <warn> [1549360507.4710] arping[0x12f5780,3]: arping could not be found; no ARPs will be sent Feb 5 11:16:52 localhost -- MARK -- ^ permalink raw reply [flat|nested] 24+ messages in thread
* bug#34333: Docker daemon failing to start on boot 2019-02-05 11:29 bug#34333: Docker daemon failing to start on boot allan @ 2019-02-08 21:55 ` Ludovic Courtès 2019-02-11 10:46 ` Danny Milosavljevic 0 siblings, 1 reply; 24+ messages in thread From: Ludovic Courtès @ 2019-02-08 21:55 UTC (permalink / raw) To: allan; +Cc: 34333 Hello, allan@adair.io skribis: > 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". [...] > 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. This is what happens at boot time: > Feb 5 10:16:51 localhost shepherd[1]: Service containerd has been [...] > Feb 5 10:16:51 localhost NetworkManager[353]: <info> > [1549358211.3005] NetworkManager (version 1.8.4) is starting... (for > the first time) [...] > [1549358211.9031] manager: NetworkManager state is now > CONNECTED_GLOBAL > Feb 5 10:16:52 localhost dbus-daemon[350]: [system] Successfully > activated service 'org.freedesktop.PolicyKit1' > Feb 5 10:16:54 localhost ntpd[354]: Listen normally on 4 enp0s3 > 10.0.2.15:123 > Feb 5 10:16:54 localhost ntpd[354]: Listen normally on 5 enp0s3 > [fe80::e882:9a4a:3a68:9d76%2]:123 > Feb 5 10:16:56 localhost shepherd[1]: Service dockerd could not be > started. Danny, could it be that the ‘docker’ service should depend on ‘networking’? FWIW, “make check-system TESTS=docker” passes for me. Thanks, Ludo’. ^ permalink raw reply [flat|nested] 24+ messages in thread
* bug#34333: Docker daemon failing to start on boot 2019-02-08 21:55 ` Ludovic Courtès @ 2019-02-11 10:46 ` Danny Milosavljevic 2019-02-11 13:11 ` Allan Adair 2019-02-11 17:31 ` Danny Milosavljevic 0 siblings, 2 replies; 24+ messages in thread From: Danny Milosavljevic @ 2019-02-11 10:46 UTC (permalink / raw) To: allan; +Cc: 34333 [-- Attachment #1: Type: text/plain, Size: 398 bytes --] On Fri, 08 Feb 2019 22:55:48 +0100 Ludovic Courtès <ludo@gnu.org> wrote: > Danny, could it be that the ‘docker’ service should depend on > ‘networking’? 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? [-- Attachment #2: OpenPGP digital signature --] [-- Type: application/pgp-signature, Size: 488 bytes --] ^ permalink raw reply [flat|nested] 24+ messages in thread
* bug#34333: Docker daemon failing to start on boot 2019-02-11 10:46 ` Danny Milosavljevic @ 2019-02-11 13:11 ` Allan Adair 2019-02-11 14:24 ` Danny Milosavljevic 2019-02-11 17:31 ` Danny Milosavljevic 1 sibling, 1 reply; 24+ messages in thread From: Allan Adair @ 2019-02-11 13:11 UTC (permalink / raw) To: Danny Milosavljevic; +Cc: 34333 On 2019-02-11 10:46, Danny Milosavljevic wrote: > On Fri, 08 Feb 2019 22:55:48 +0100 > Ludovic Courtès <ludo@gnu.org> wrote: > >> Danny, could it be that the ‘docker’ service should depend on >> ‘networking’? > > 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? 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 http://allan.adair.io ^ permalink raw reply [flat|nested] 24+ messages in thread
* bug#34333: Docker daemon failing to start on boot 2019-02-11 13:11 ` Allan Adair @ 2019-02-11 14:24 ` Danny Milosavljevic 0 siblings, 0 replies; 24+ messages in thread From: Danny Milosavljevic @ 2019-02-11 14:24 UTC (permalink / raw) To: Allan Adair; +Cc: 34333 [-- Attachment #1: Type: text/plain, Size: 268 bytes --] On Mon, 11 Feb 2019 13:11:33 +0000 Allan Adair <allan@adair.io> wrote: > I guix pulled and guix system reconfigured. After a successful > reconfigure and reboot, the service was still not started. Hmm, is the "containerd" process running? (pidof containerd) [-- Attachment #2: OpenPGP digital signature --] [-- Type: application/pgp-signature, Size: 488 bytes --] ^ permalink raw reply [flat|nested] 24+ messages in thread
* bug#34333: Docker daemon failing to start on boot 2019-02-11 10:46 ` Danny Milosavljevic 2019-02-11 13:11 ` Allan Adair @ 2019-02-11 17:31 ` Danny Milosavljevic 2019-02-12 9:05 ` Allan Adair 1 sibling, 1 reply; 24+ messages in thread From: Danny Milosavljevic @ 2019-02-11 17:31 UTC (permalink / raw) To: allan; +Cc: 34333 [-- Attachment #1: Type: text/plain, Size: 132 bytes --] Hi Allan, I've added some more requirements--let's see. Can you guix pull and guix reconfigure and then try again once more? [-- Attachment #2: OpenPGP digital signature --] [-- Type: application/pgp-signature, Size: 488 bytes --] ^ permalink raw reply [flat|nested] 24+ messages in thread
* bug#34333: Docker daemon failing to start on boot 2019-02-11 17:31 ` Danny Milosavljevic @ 2019-02-12 9:05 ` Allan Adair 2019-02-12 17:45 ` Danny Milosavljevic 0 siblings, 1 reply; 24+ messages in thread From: Allan Adair @ 2019-02-12 9:05 UTC (permalink / raw) To: Danny Milosavljevic; +Cc: 34333 On 2019-02-11 17:31, Danny Milosavljevic wrote: > Hi Allan, > > I've added some more requirements--let's see. > > Can you guix pull and guix reconfigure and then try again once more? Still no luck. Do you face the same issue? -- Allan Adair +47 468 12 135 allan@adair.io http://allan.adair.io ^ permalink raw reply [flat|nested] 24+ messages in thread
* bug#34333: Docker daemon failing to start on boot 2019-02-12 9:05 ` Allan Adair @ 2019-02-12 17:45 ` Danny Milosavljevic 2019-02-27 14:17 ` Allan Adair 0 siblings, 1 reply; 24+ messages in thread From: Danny Milosavljevic @ 2019-02-12 17:45 UTC (permalink / raw) To: Allan Adair; +Cc: 34333 [-- Attachment #1: Type: text/plain, Size: 445 bytes --] Hi Allan, On Tue, 12 Feb 2019 09:05:10 +0000 Allan Adair <allan@adair.io> wrote: > On 2019-02-11 17:31, Danny Milosavljevic wrote: > > Hi Allan, > > > > I've added some more requirements--let's see. > > > > Can you guix pull and guix reconfigure and then try again once more? > > Still no luck. Do you face the same issue? I don't know since my machine has not finished updating after the recent staging to master merge. [-- Attachment #2: OpenPGP digital signature --] [-- Type: application/pgp-signature, Size: 488 bytes --] ^ permalink raw reply [flat|nested] 24+ messages in thread
* bug#34333: Docker daemon failing to start on boot 2019-02-12 17:45 ` Danny Milosavljevic @ 2019-02-27 14:17 ` Allan Adair 2019-02-27 15:53 ` Björn Höfling 0 siblings, 1 reply; 24+ messages in thread From: Allan Adair @ 2019-02-27 14:17 UTC (permalink / raw) To: Danny Milosavljevic; +Cc: 34333, Allan Adair 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: > Hi Allan, > > On Tue, 12 Feb 2019 09:05:10 +0000 > Allan Adair <allan@adair.io> wrote: > >> On 2019-02-11 17:31, Danny Milosavljevic wrote: >> > Hi Allan, >> > >> > I've added some more requirements--let's see. >> > >> > Can you guix pull and guix reconfigure and then try again once more? >> >> Still no luck. Do you face the same issue? > > I don't know since my machine has not finished updating after the > recent staging to master merge. -- Allan Adair http://allan.adair.io ^ permalink raw reply [flat|nested] 24+ messages in thread
* bug#34333: Docker daemon failing to start on boot 2019-02-27 14:17 ` Allan Adair @ 2019-02-27 15:53 ` Björn Höfling 2019-02-27 16:31 ` Andreas Enge 0 siblings, 1 reply; 24+ messages in thread From: Björn Höfling @ 2019-02-27 15:53 UTC (permalink / raw) To: Allan Adair; +Cc: 34333 [-- Attachment #1: Type: text/plain, Size: 595 bytes --] On Wed, 27 Feb 2019 15:17:14 +0100 Allan Adair <allan@adair.io> wrote: > 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. I can confirm this behaviour, though I haven't yet investigated it further. Björn [-- Attachment #2: OpenPGP digital signature --] [-- Type: application/pgp-signature, Size: 195 bytes --] ^ permalink raw reply [flat|nested] 24+ messages in thread
* bug#34333: Docker daemon failing to start on boot 2019-02-27 15:53 ` Björn Höfling @ 2019-02-27 16:31 ` Andreas Enge 2019-03-01 8:58 ` Allan Adair 0 siblings, 1 reply; 24+ messages in thread From: Andreas Enge @ 2019-02-27 16:31 UTC (permalink / raw) To: Björn Höfling; +Cc: 34333, Allan Adair On Wed, Feb 27, 2019 at 04:53:27PM +0100, Björn Höfling wrote: > > 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. > > I can confirm this behaviour, though I haven't yet investigated it > further. Could this be yet another manifestation of https://debbugs.gnu.org/cgi/bugreport.cgi?bug=34580 ? Services not started on boot? Andreas ^ permalink raw reply [flat|nested] 24+ messages in thread
* bug#34333: Docker daemon failing to start on boot 2019-02-27 16:31 ` Andreas Enge @ 2019-03-01 8:58 ` Allan Adair 2019-03-01 13:09 ` Andreas Enge 0 siblings, 1 reply; 24+ messages in thread From: Allan Adair @ 2019-03-01 8:58 UTC (permalink / raw) To: Andreas Enge; +Cc: 34333, Allan Adair Andreas Enge writes: > On Wed, Feb 27, 2019 at 04:53:27PM +0100, Björn Höfling wrote: >> > 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. >> >> I can confirm this behaviour, though I haven't yet investigated it >> further. > > Could this be yet another manifestation of > https://debbugs.gnu.org/cgi/bugreport.cgi?bug=34580 ? > Services not started on boot? > > Andreas I'm not so sure. One thing that I am unable to do is "herd start dockerd". -- Allan Adair http://allan.adair.io ^ permalink raw reply [flat|nested] 24+ messages in thread
* bug#34333: Docker daemon failing to start on boot 2019-03-01 8:58 ` Allan Adair @ 2019-03-01 13:09 ` Andreas Enge 2019-03-01 13:43 ` Björn Höfling 0 siblings, 1 reply; 24+ messages in thread From: Andreas Enge @ 2019-03-01 13:09 UTC (permalink / raw) To: Allan Adair; +Cc: 34333 On Fri, Mar 01, 2019 at 09:58:20AM +0100, Allan Adair wrote: > >> > I am however able to execute "sudo herd start > >> > dockerd" after booting > > I'm not so sure. One thing that I am unable to do is "herd start > dockerd". 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 ^ permalink raw reply [flat|nested] 24+ messages in thread
* bug#34333: Docker daemon failing to start on boot 2019-03-01 13:09 ` Andreas Enge @ 2019-03-01 13:43 ` Björn Höfling 2019-03-01 13:50 ` Allan Adair 0 siblings, 1 reply; 24+ messages in thread From: Björn Höfling @ 2019-03-01 13:43 UTC (permalink / raw) To: Andreas Enge; +Cc: 34333, Allan Adair [-- Attachment #1: Type: text/plain, Size: 693 bytes --] On Fri, 1 Mar 2019 14:09:32 +0100 Andreas Enge <andreas@enge.fr> wrote: > On Fri, Mar 01, 2019 at 09:58:20AM +0100, Allan Adair wrote: > > >> > I am however able to execute "sudo herd start > > >> > dockerd" after booting > > > > I'm not so sure. One thing that I am unable to do is "herd start > > dockerd". > > 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. 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 [-- Attachment #2: OpenPGP digital signature --] [-- Type: application/pgp-signature, Size: 195 bytes --] ^ permalink raw reply [flat|nested] 24+ messages in thread
* bug#34333: Docker daemon failing to start on boot 2019-03-01 13:43 ` Björn Höfling @ 2019-03-01 13:50 ` Allan Adair 2019-03-01 18:00 ` Danny Milosavljevic 0 siblings, 1 reply; 24+ messages in thread From: Allan Adair @ 2019-03-01 13:50 UTC (permalink / raw) To: Björn Höfling; +Cc: 34333, Allan Adair Björn Höfling writes: > On Fri, 1 Mar 2019 14:09:32 +0100 > Andreas Enge <andreas@enge.fr> wrote: > >> On Fri, Mar 01, 2019 at 09:58:20AM +0100, Allan Adair wrote: >> > >> > I am however able to execute "sudo herd start >> > >> > dockerd" after booting >> > >> > I'm not so sure. One thing that I am unable to do is "herd start >> > dockerd". >> >> 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. > > 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 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 http://allan.adair.io ^ permalink raw reply [flat|nested] 24+ messages in thread
* bug#34333: Docker daemon failing to start on boot 2019-03-01 13:50 ` Allan Adair @ 2019-03-01 18:00 ` Danny Milosavljevic 2019-03-11 8:59 ` Allan Adair 0 siblings, 1 reply; 24+ messages in thread From: Danny Milosavljevic @ 2019-03-01 18:00 UTC (permalink / raw) To: Allan Adair; +Cc: 34333 [-- Attachment #1: Type: text/plain, Size: 1135 bytes --] Hi, On Fri, 01 Mar 2019 14:50:39 +0100 Allan Adair <allan@adair.io> wrote: > 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 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 [-- Attachment #2: OpenPGP digital signature --] [-- Type: application/pgp-signature, Size: 488 bytes --] ^ permalink raw reply [flat|nested] 24+ messages in thread
* bug#34333: Docker daemon failing to start on boot 2019-03-01 18:00 ` Danny Milosavljevic @ 2019-03-11 8:59 ` Allan Adair 2019-03-12 19:47 ` Danny Milosavljevic 0 siblings, 1 reply; 24+ messages in thread From: Allan Adair @ 2019-03-11 8:59 UTC (permalink / raw) To: Danny Milosavljevic; +Cc: 34333, Allan Adair 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: > Hi, > > On Fri, 01 Mar 2019 14:50:39 +0100 > Allan Adair <allan@adair.io> wrote: > >> 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 > > 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 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 OUTPUT -m addrtype --dst-type LOCAL -j DOCKER ! --dst 127.0.0.0/8] DEBU[2019-03-11T09:56:05.036877981+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t filter -C FORWARD -o docker0 -j DOCKER] DEBU[2019-03-11T09:56:05.039792718+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t filter -C FORWARD -o docker0 -j DOCKER] DEBU[2019-03-11T09:56:05.040859429+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t filter -C FORWARD -o docker0 -m conntrack --ctstate RELATED,ESTABLISHED -j ACCEPT] DEBU[2019-03-11T09:56:05.047794509+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t filter -C FORWARD -o docker0 -m conntrack --ctstate RELATED,ESTABLISHED -j ACCEPT] DEBU[2019-03-11T09:56:05.049226971+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t filter -C FORWARD -j DOCKER-ISOLATION-STAGE-1] DEBU[2019-03-11T09:56:05.050449463+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -D FORWARD -j DOCKER-ISOLATION-STAGE-1] DEBU[2019-03-11T09:56:05.051363751+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -I FORWARD -j DOCKER-ISOLATION-STAGE-1] DEBU[2019-03-11T09:56:05.052266252+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t filter -C DOCKER-ISOLATION-STAGE-1 -i docker0 ! -o docker0 -j DOCKER-ISOLATION-STAGE-2] DEBU[2019-03-11T09:56:05.053132407+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t filter -I DOCKER-ISOLATION-STAGE-1 -i docker0 ! -o docker0 -j DOCKER-ISOLATION-STAGE-2] DEBU[2019-03-11T09:56:05.053985383+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t filter -C DOCKER-ISOLATION-STAGE-2 -o docker0 -j DROP] DEBU[2019-03-11T09:56:05.054843200+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t filter -I DOCKER-ISOLATION-STAGE-2 -o docker0 -j DROP] DEBU[2019-03-11T09:56:05.055860619+01:00] Network (fc0c79f) restored DEBU[2019-03-11T09:56:05.056667771+01:00] Allocating IPv4 pools for network bridge (fc0c79f3077bdfc4591c9436bf25a63668ce8961b9a4f9c98c7bfffa3d5b64ae) DEBU[2019-03-11T09:56:05.056692562+01:00] RequestPool(LocalDefault, 172.17.0.0/16, , map[], false) DEBU[2019-03-11T09:56:05.056717170+01:00] RequestAddress(LocalDefault/172.17.0.0/16, 172.17.0.1, map[RequestAddressType:com.docker.network.gateway]) DEBU[2019-03-11T09:56:05.056735157+01:00] Request address PoolID:172.17.0.0/16 App: ipam/default/data, ID: LocalDefault/172.17.0.0/16, DBIndex: 0x0, Bits: 65536, Unselected: 65534, Sequence: (0x80000000, 1)->(0x0, 2046)->(0x1, 1)->end Curr:0 Serial:false PrefAddress:172.17.0.1 DEBU[2019-03-11T09:56:05.061383675+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.066264415+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t nat -D POSTROUTING -s 172.17.0.0/16 ! -o docker0 -j MASQUERADE] DEBU[2019-03-11T09:56:05.067406630+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.068682521+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t nat -D DOCKER -i docker0 -j RETURN] DEBU[2019-03-11T09:56:05.079741812+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.081703363+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -D FORWARD -i docker0 -o docker0 -j ACCEPT] DEBU[2019-03-11T09:56:05.083899704+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.085111824+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -D FORWARD -i docker0 ! -o docker0 -j ACCEPT] DEBU[2019-03-11T09:56:05.086383289+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t filter -C FORWARD -o docker0 -j DOCKER] DEBU[2019-03-11T09:56:05.090421950+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t filter -C FORWARD -o docker0 -j DOCKER] DEBU[2019-03-11T09:56:05.092871348+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -D FORWARD -o docker0 -j DOCKER] DEBU[2019-03-11T09:56:05.093983550+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t filter -C FORWARD -o docker0 -m conntrack --ctstate RELATED,ESTABLISHED -j ACCEPT] DEBU[2019-03-11T09:56:05.095048444+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t filter -C FORWARD -o docker0 -m conntrack --ctstate RELATED,ESTABLISHED -j ACCEPT] DEBU[2019-03-11T09:56:05.096757981+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -D FORWARD -o docker0 -m conntrack --ctstate RELATED,ESTABLISHED -j ACCEPT] DEBU[2019-03-11T09:56:05.104180706+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t filter -C DOCKER-ISOLATION-STAGE-1 -i docker0 ! -o docker0 -j DOCKER-ISOLATION-STAGE-2] DEBU[2019-03-11T09:56:05.105653091+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t filter -D DOCKER-ISOLATION-STAGE-1 -i docker0 ! -o docker0 -j DOCKER-ISOLATION-STAGE-2] DEBU[2019-03-11T09:56:05.106740616+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t filter -C DOCKER-ISOLATION-STAGE-2 -o docker0 -j DROP] DEBU[2019-03-11T09:56:05.107648681+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t filter -D DOCKER-ISOLATION-STAGE-2 -o docker0 -j DROP] DEBU[2019-03-11T09:56:05.112100198+01:00] releasing IPv4 pools from network bridge (fc0c79f3077bdfc4591c9436bf25a63668ce8961b9a4f9c98c7bfffa3d5b64ae) DEBU[2019-03-11T09:56:05.112124776+01:00] ReleaseAddress(LocalDefault/172.17.0.0/16, 172.17.0.1) DEBU[2019-03-11T09:56:05.112165328+01:00] Released address PoolID:LocalDefault/172.17.0.0/16, Address:172.17.0.1 Sequence:App: ipam/default/data, ID: LocalDefault/172.17.0.0/16, DBIndex: 0x0, Bits: 65536, Unselected: 65533, Sequence: (0xc0000000, 1)->(0x0, 2046)->(0x1, 1)->end Curr:0 DEBU[2019-03-11T09:56:05.112177220+01:00] ReleasePool(LocalDefault/172.17.0.0/16) DEBU[2019-03-11T09:56:05.113131674+01:00] cleanupServiceDiscovery for network:fc0c79f3077bdfc4591c9436bf25a63668ce8961b9a4f9c98c7bfffa3d5b64ae INFO[2019-03-11T09:56:05.116621811+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 DEBU[2019-03-11T09:56:05.116670253+01:00] Allocating IPv4 pools for network bridge (0e4a0a76c4327334b79e6fc5120f1e27fe76d4ff937f2d65452edb40d031aef6) DEBU[2019-03-11T09:56:05.116685066+01:00] RequestPool(LocalDefault, 172.17.0.0/16, , map[], false) DEBU[2019-03-11T09:56:05.116731043+01:00] RequestAddress(LocalDefault/172.17.0.0/16, 172.17.0.1, map[RequestAddressType:com.docker.network.gateway]) DEBU[2019-03-11T09:56:05.116754437+01:00] Request address PoolID:172.17.0.0/16 App: ipam/default/data, ID: LocalDefault/172.17.0.0/16, DBIndex: 0x0, Bits: 65536, Unselected: 65534, Sequence: (0x80000000, 1)->(0x0, 2046)->(0x1, 1)->end Curr:0 Serial:false PrefAddress:172.17.0.1 DEBU[2019-03-11T09:56:05.116896722+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.118093964+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t nat -I POSTROUTING -s 172.17.0.0/16 ! -o docker0 -j MASQUERADE] DEBU[2019-03-11T09:56:05.120892409+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.123980225+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.125095277+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.126053056+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.129446914+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -I FORWARD -i docker0 -o docker0 -j ACCEPT] DEBU[2019-03-11T09:56:05.130617732+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.131819595+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -I FORWARD -i docker0 ! -o docker0 -j ACCEPT] DEBU[2019-03-11T09:56:05.133531836+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.134836717+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.135958264+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.136897795+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.137818895+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t filter -C FORWARD -o docker0 -j DOCKER] DEBU[2019-03-11T09:56:05.138822793+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -I FORWARD -o docker0 -j DOCKER] DEBU[2019-03-11T09:56:05.144482765+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t filter -C FORWARD -o docker0 -m conntrack --ctstate RELATED,ESTABLISHED -j ACCEPT] DEBU[2019-03-11T09:56:05.145490809+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -I FORWARD -o docker0 -m conntrack --ctstate RELATED,ESTABLISHED -j ACCEPT] DEBU[2019-03-11T09:56:05.147825467+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t filter -C FORWARD -j DOCKER-ISOLATION-STAGE-1] DEBU[2019-03-11T09:56:05.149141820+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -D FORWARD -j DOCKER-ISOLATION-STAGE-1] DEBU[2019-03-11T09:56:05.151024113+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -I FORWARD -j DOCKER-ISOLATION-STAGE-1] DEBU[2019-03-11T09:56:05.152118528+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t filter -C DOCKER-ISOLATION-STAGE-1 -i docker0 ! -o docker0 -j DOCKER-ISOLATION-STAGE-2] DEBU[2019-03-11T09:56:05.153027534+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t filter -I DOCKER-ISOLATION-STAGE-1 -i docker0 ! -o docker0 -j DOCKER-ISOLATION-STAGE-2] DEBU[2019-03-11T09:56:05.153891349+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t filter -C DOCKER-ISOLATION-STAGE-2 -o docker0 -j DROP] DEBU[2019-03-11T09:56:05.154736895+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t filter -I DOCKER-ISOLATION-STAGE-2 -o docker0 -j DROP] DEBU[2019-03-11T09:56:05.160349501+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t filter -n -L DOCKER-USER] DEBU[2019-03-11T09:56:05.161355036+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t filter -C DOCKER-USER -j RETURN] DEBU[2019-03-11T09:56:05.162196782+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -t filter -C FORWARD -j DOCKER-USER] DEBU[2019-03-11T09:56:05.163157424+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -D FORWARD -j DOCKER-USER] DEBU[2019-03-11T09:56:05.164843322+01:00] /gnu/store/5g8j76dqjafmah82kd30fc1d1bf74zib-iptables-1.6.2/sbin/iptables, [--wait -I FORWARD -j DOCKER-USER] INFO[2019-03-11T09:56:05.185317037+01:00] Loading containers: done. WARN[2019-03-11T09:56:05.185758060+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:56:05.204626551+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:56:05.204981256+01:00] failed to retrieve docker-init version: exec: "docker-init": executable file not found in $PATH INFO[2019-03-11T09:56:05.238740939+01:00] Docker daemon commit=v18.09.2 graphdriver(s)=overlay2 version=dev INFO[2019-03-11T09:56:05.238804379+01:00] Daemon has completed initialization DEBU[2019-03-11T09:56:05.239601830+01:00] Registering routers DEBU[2019-03-11T09:56:05.239615931+01:00] Registering GET, /containers/{name:.*}/checkpoints DEBU[2019-03-11T09:56:05.239751496+01:00] Registering POST, /containers/{name:.*}/checkpoints DEBU[2019-03-11T09:56:05.239837149+01:00] Registering DELETE, /containers/{name}/checkpoints/{checkpoint} DEBU[2019-03-11T09:56:05.239916627+01:00] Registering HEAD, /containers/{name:.*}/archive DEBU[2019-03-11T09:56:05.239970120+01:00] Registering GET, /containers/json DEBU[2019-03-11T09:56:05.240008458+01:00] Registering GET, /containers/{name:.*}/export DEBU[2019-03-11T09:56:05.240056898+01:00] Registering GET, /containers/{name:.*}/changes DEBU[2019-03-11T09:56:05.240104048+01:00] Registering GET, /containers/{name:.*}/json DEBU[2019-03-11T09:56:05.240150451+01:00] Registering GET, /containers/{name:.*}/top DEBU[2019-03-11T09:56:05.240198551+01:00] Registering GET, /containers/{name:.*}/logs DEBU[2019-03-11T09:56:05.240247455+01:00] Registering GET, /containers/{name:.*}/stats DEBU[2019-03-11T09:56:05.240312135+01:00] Registering GET, /containers/{name:.*}/attach/ws DEBU[2019-03-11T09:56:05.240360983+01:00] Registering GET, /exec/{id:.*}/json DEBU[2019-03-11T09:56:05.240405360+01:00] Registering GET, /containers/{name:.*}/archive DEBU[2019-03-11T09:56:05.240453006+01:00] Registering POST, /containers/create DEBU[2019-03-11T09:56:05.240491285+01:00] Registering POST, /containers/{name:.*}/kill DEBU[2019-03-11T09:56:05.240537431+01:00] Registering POST, /containers/{name:.*}/pause DEBU[2019-03-11T09:56:05.240585640+01:00] Registering POST, /containers/{name:.*}/unpause DEBU[2019-03-11T09:56:05.240634290+01:00] Registering POST, /containers/{name:.*}/restart DEBU[2019-03-11T09:56:05.240709020+01:00] Registering POST, /containers/{name:.*}/start DEBU[2019-03-11T09:56:05.240761143+01:00] Registering POST, /containers/{name:.*}/stop DEBU[2019-03-11T09:56:05.240808995+01:00] Registering POST, /containers/{name:.*}/wait DEBU[2019-03-11T09:56:05.240856588+01:00] Registering POST, /containers/{name:.*}/resize DEBU[2019-03-11T09:56:05.240905251+01:00] Registering POST, /containers/{name:.*}/attach DEBU[2019-03-11T09:56:05.240952570+01:00] Registering POST, /containers/{name:.*}/copy DEBU[2019-03-11T09:56:05.240997749+01:00] Registering POST, /containers/{name:.*}/exec DEBU[2019-03-11T09:56:05.241042573+01:00] Registering POST, /exec/{name:.*}/start DEBU[2019-03-11T09:56:05.241085715+01:00] Registering POST, /exec/{name:.*}/resize DEBU[2019-03-11T09:56:05.241127943+01:00] Registering POST, /containers/{name:.*}/rename DEBU[2019-03-11T09:56:05.241176123+01:00] Registering POST, /containers/{name:.*}/update DEBU[2019-03-11T09:56:05.241222739+01:00] Registering POST, /containers/prune DEBU[2019-03-11T09:56:05.241263538+01:00] Registering POST, /commit DEBU[2019-03-11T09:56:05.241294588+01:00] Registering PUT, /containers/{name:.*}/archive DEBU[2019-03-11T09:56:05.241341631+01:00] Registering DELETE, /containers/{name:.*} DEBU[2019-03-11T09:56:05.241387679+01:00] Registering GET, /images/json DEBU[2019-03-11T09:56:05.241420575+01:00] Registering GET, /images/search DEBU[2019-03-11T09:56:05.241453852+01:00] Registering GET, /images/get DEBU[2019-03-11T09:56:05.241484575+01:00] Registering GET, /images/{name:.*}/get DEBU[2019-03-11T09:56:05.241529872+01:00] Registering GET, /images/{name:.*}/history DEBU[2019-03-11T09:56:05.241573162+01:00] Registering GET, /images/{name:.*}/json DEBU[2019-03-11T09:56:05.241618221+01:00] Registering POST, /images/load DEBU[2019-03-11T09:56:05.241666228+01:00] Registering POST, /images/create DEBU[2019-03-11T09:56:05.241700468+01:00] Registering POST, /images/{name:.*}/push DEBU[2019-03-11T09:56:05.241745795+01:00] Registering POST, /images/{name:.*}/tag DEBU[2019-03-11T09:56:05.241791610+01:00] Registering POST, /images/prune DEBU[2019-03-11T09:56:05.241826390+01:00] Registering DELETE, /images/{name:.*} DEBU[2019-03-11T09:56:05.241870105+01:00] Registering OPTIONS, /{anyroute:.*} DEBU[2019-03-11T09:56:05.241912413+01:00] Registering GET, /_ping DEBU[2019-03-11T09:56:05.241943268+01:00] Registering GET, /events DEBU[2019-03-11T09:56:05.241971721+01:00] Registering GET, /info DEBU[2019-03-11T09:56:05.242000845+01:00] Registering GET, /version DEBU[2019-03-11T09:56:05.242029998+01:00] Registering GET, /system/df DEBU[2019-03-11T09:56:05.242060342+01:00] Registering POST, /auth DEBU[2019-03-11T09:56:05.242090422+01:00] Registering GET, /volumes DEBU[2019-03-11T09:56:05.242123192+01:00] Registering GET, /volumes/{name:.*} DEBU[2019-03-11T09:56:05.242170321+01:00] Registering POST, /volumes/create DEBU[2019-03-11T09:56:05.242204144+01:00] Registering POST, /volumes/prune DEBU[2019-03-11T09:56:05.242236013+01:00] Registering DELETE, /volumes/{name:.*} DEBU[2019-03-11T09:56:05.242280422+01:00] Registering POST, /build DEBU[2019-03-11T09:56:05.242310670+01:00] Registering POST, /build/prune DEBU[2019-03-11T09:56:05.242343048+01:00] Registering POST, /build/cancel DEBU[2019-03-11T09:56:05.242378602+01:00] Registering POST, /session DEBU[2019-03-11T09:56:05.242407127+01:00] Registering POST, /swarm/init DEBU[2019-03-11T09:56:05.242436591+01:00] Registering POST, /swarm/join DEBU[2019-03-11T09:56:05.242467910+01:00] Registering POST, /swarm/leave DEBU[2019-03-11T09:56:05.242501294+01:00] Registering GET, /swarm DEBU[2019-03-11T09:56:05.242529999+01:00] Registering GET, /swarm/unlockkey DEBU[2019-03-11T09:56:05.242564600+01:00] Registering POST, /swarm/update DEBU[2019-03-11T09:56:05.242606914+01:00] Registering POST, /swarm/unlock DEBU[2019-03-11T09:56:05.242644206+01:00] Registering GET, /services DEBU[2019-03-11T09:56:05.242677944+01:00] Registering GET, /services/{id} DEBU[2019-03-11T09:56:05.242720635+01:00] Registering POST, /services/create DEBU[2019-03-11T09:56:05.242756024+01:00] Registering POST, /services/{id}/update DEBU[2019-03-11T09:56:05.242805262+01:00] Registering DELETE, /services/{id} DEBU[2019-03-11T09:56:05.242847943+01:00] Registering GET, /services/{id}/logs DEBU[2019-03-11T09:56:05.242895927+01:00] Registering GET, /nodes DEBU[2019-03-11T09:56:05.242927053+01:00] Registering GET, /nodes/{id} DEBU[2019-03-11T09:56:05.242968719+01:00] Registering DELETE, /nodes/{id} DEBU[2019-03-11T09:56:05.243009400+01:00] Registering POST, /nodes/{id}/update DEBU[2019-03-11T09:56:05.243058816+01:00] Registering GET, /tasks DEBU[2019-03-11T09:56:05.243087847+01:00] Registering GET, /tasks/{id} DEBU[2019-03-11T09:56:05.243128386+01:00] Registering GET, /tasks/{id}/logs DEBU[2019-03-11T09:56:05.243173892+01:00] Registering GET, /secrets DEBU[2019-03-11T09:56:05.243205081+01:00] Registering POST, /secrets/create DEBU[2019-03-11T09:56:05.243240435+01:00] Registering DELETE, /secrets/{id} DEBU[2019-03-11T09:56:05.243284390+01:00] Registering GET, /secrets/{id} DEBU[2019-03-11T09:56:05.243327275+01:00] Registering POST, /secrets/{id}/update DEBU[2019-03-11T09:56:05.243375740+01:00] Registering GET, /configs DEBU[2019-03-11T09:56:05.243407034+01:00] Registering POST, /configs/create DEBU[2019-03-11T09:56:05.243440639+01:00] Registering DELETE, /configs/{id} DEBU[2019-03-11T09:56:05.243487942+01:00] Registering GET, /configs/{id} DEBU[2019-03-11T09:56:05.243530162+01:00] Registering POST, /configs/{id}/update DEBU[2019-03-11T09:56:05.243660746+01:00] Registering GET, /plugins DEBU[2019-03-11T09:56:05.243790291+01:00] Registering GET, /plugins/{name:.*}/json DEBU[2019-03-11T09:56:05.243877110+01:00] Registering GET, /plugins/privileges DEBU[2019-03-11T09:56:05.243946888+01:00] Registering DELETE, /plugins/{name:.*} DEBU[2019-03-11T09:56:05.244027824+01:00] Registering POST, /plugins/{name:.*}/enable DEBU[2019-03-11T09:56:05.244107744+01:00] Registering POST, /plugins/{name:.*}/disable DEBU[2019-03-11T09:56:05.244186568+01:00] Registering POST, /plugins/pull DEBU[2019-03-11T09:56:05.244260064+01:00] Registering POST, /plugins/{name:.*}/push DEBU[2019-03-11T09:56:05.244340238+01:00] Registering POST, /plugins/{name:.*}/upgrade DEBU[2019-03-11T09:56:05.244420921+01:00] Registering POST, /plugins/{name:.*}/set DEBU[2019-03-11T09:56:05.244500333+01:00] Registering POST, /plugins/create DEBU[2019-03-11T09:56:05.244583012+01:00] Registering GET, /distribution/{name:.*}/json DEBU[2019-03-11T09:56:05.244670955+01:00] Registering GET, /networks DEBU[2019-03-11T09:56:05.253950824+01:00] Registering GET, /networks/ DEBU[2019-03-11T09:56:05.254002638+01:00] Registering GET, /networks/{id:.+} DEBU[2019-03-11T09:56:05.254058192+01:00] Registering POST, /networks/create DEBU[2019-03-11T09:56:05.254093998+01:00] Registering POST, /networks/{id:.*}/connect DEBU[2019-03-11T09:56:05.254145047+01:00] Registering POST, /networks/{id:.*}/disconnect DEBU[2019-03-11T09:56:05.254194317+01:00] Registering POST, /networks/prune DEBU[2019-03-11T09:56:05.254228838+01:00] Registering DELETE, /networks/{id:.*} INFO[2019-03-11T09:56:05.254548687+01:00] API listen on /var/run/docker.sock ^CINFO[2019-03-11T09:56:24.712622167+01:00] Processing signal 'interrupt' DEBU[2019-03-11T09:56:24.712740386+01:00] daemon configured with a 15 seconds minimum shutdown timeout DEBU[2019-03-11T09:56:24.712773797+01:00] start clean shutdown of all containers with a 15 seconds timeout... DEBU[2019-03-11T09:56:24.713084718+01:00] Unix socket /run/docker/libnetwork/74a62366b867f7c576588ffac87c8889da1664e046021b79cea815474a27fe5b.sock doesn't exist. cannot accept client connections DEBU[2019-03-11T09:56:24.713135141+01:00] Cleaning up old mountid : start. INFO[2019-03-11T09:56:24.713178134+01:00] stopping event stream following graceful shutdown error="<nil>" module=libcontainerd namespace=moby DEBU[2019-03-11T09:56:24.713306418+01:00] Cleaning up old mountid : done. DEBU[2019-03-11T09:56:24.713393116+01:00] Clean shutdown succeeded allana@guixsd ~$ -- Allan Adair http://allan.adair.io ^ permalink raw reply [flat|nested] 24+ messages in thread
* bug#34333: Docker daemon failing to start on boot 2019-03-11 8:59 ` Allan Adair @ 2019-03-12 19:47 ` Danny Milosavljevic 2019-03-18 10:23 ` Allan Adair 0 siblings, 1 reply; 24+ messages in thread From: Danny Milosavljevic @ 2019-03-12 19:47 UTC (permalink / raw) To: Allan Adair; +Cc: 34333 [-- Attachment #1: Type: text/plain, Size: 400 bytes --] Hi Allan, On Mon, 11 Mar 2019 09:59:19 +0100 Allan Adair <allan@adair.io> wrote: > Sorry for the late response. I was offline for the last week or so. No problem! > > I ended up having to repeat the first command with sudo > privileges. Please see below. 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) ? [-- Attachment #2: OpenPGP digital signature --] [-- Type: application/pgp-signature, Size: 488 bytes --] ^ permalink raw reply [flat|nested] 24+ messages in thread
* bug#34333: Docker daemon failing to start on boot 2019-03-12 19:47 ` Danny Milosavljevic @ 2019-03-18 10:23 ` Allan Adair 2019-03-18 10:53 ` Danny Milosavljevic 0 siblings, 1 reply; 24+ messages in thread From: Allan Adair @ 2019-03-18 10:23 UTC (permalink / raw) To: Danny Milosavljevic; +Cc: 34333, Allan Adair Hi Danny. Danny Milosavljevic writes: > Hi Allan, > > On Mon, 11 Mar 2019 09:59:19 +0100 > Allan Adair <allan@adair.io> wrote: > >> Sorry for the late response. I was offline for the last week or so. > > No problem! > >> >> I ended up having to repeat the first command with sudo >> privileges. Please see below. > > 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) ? 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 http://allan.adair.io ^ permalink raw reply [flat|nested] 24+ messages in thread
* bug#34333: Docker daemon failing to start on boot 2019-03-18 10:23 ` Allan Adair @ 2019-03-18 10:53 ` Danny Milosavljevic 2019-03-18 11:05 ` Danny Milosavljevic 2019-03-18 13:47 ` Allan Adair 0 siblings, 2 replies; 24+ messages in thread From: Danny Milosavljevic @ 2019-03-18 10:53 UTC (permalink / raw) To: Allan Adair; +Cc: 34333 [-- Attachment #1: Type: text/plain, Size: 1597 bytes --] 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. [-- Attachment #2: OpenPGP digital signature --] [-- Type: application/pgp-signature, Size: 488 bytes --] ^ permalink raw reply [flat|nested] 24+ messages in thread
* bug#34333: Docker daemon failing to start on boot 2019-03-18 10:53 ` Danny Milosavljevic @ 2019-03-18 11:05 ` Danny Milosavljevic 2019-03-18 13:47 ` Allan Adair 1 sibling, 0 replies; 24+ messages in thread From: Danny Milosavljevic @ 2019-03-18 11:05 UTC (permalink / raw) To: Allan Adair; +Cc: 34333 [-- Attachment #1: Type: text/plain, Size: 261 bytes --] 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 [-- Attachment #2: OpenPGP digital signature --] [-- Type: application/pgp-signature, Size: 488 bytes --] ^ permalink raw reply [flat|nested] 24+ messages in thread
* bug#34333: Docker daemon failing to start on boot 2019-03-18 10:53 ` Danny Milosavljevic 2019-03-18 11:05 ` Danny Milosavljevic @ 2019-03-18 13:47 ` Allan Adair 2019-03-25 21:46 ` Danny Milosavljevic 1 sibling, 1 reply; 24+ messages in thread From: Allan Adair @ 2019-03-18 13:47 UTC (permalink / raw) To: Danny Milosavljevic; +Cc: 34333, Allan Adair 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: > 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. -- Allan Adair http://allan.adair.io ^ permalink raw reply [flat|nested] 24+ messages in thread
* bug#34333: Docker daemon failing to start on boot 2019-03-18 13:47 ` Allan Adair @ 2019-03-25 21:46 ` Danny Milosavljevic 2019-03-26 14:15 ` Allan Adair 0 siblings, 1 reply; 24+ messages in thread From: Danny Milosavljevic @ 2019-03-25 21:46 UTC (permalink / raw) To: Allan Adair; +Cc: 34333 [-- Attachment #1: Type: text/plain, Size: 161 bytes --] 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? [-- Attachment #2: OpenPGP digital signature --] [-- Type: application/pgp-signature, Size: 488 bytes --] ^ permalink raw reply [flat|nested] 24+ messages in thread
* bug#34333: Docker daemon failing to start on boot 2019-03-25 21:46 ` Danny Milosavljevic @ 2019-03-26 14:15 ` Allan Adair 0 siblings, 0 replies; 24+ messages in thread From: Allan Adair @ 2019-03-26 14:15 UTC (permalink / raw) To: Danny Milosavljevic; +Cc: 34333, Allan Adair Danny Milosavljevic writes: > 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? Success! Thank you very much. -- Allan Adair http://allan.adair.io ^ permalink raw reply [flat|nested] 24+ messages in thread
end of thread, other threads:[~2019-03-26 14:16 UTC | newest] Thread overview: 24+ messages (download: mbox.gz follow: Atom feed -- links below jump to the message on this page -- 2019-02-05 11:29 bug#34333: Docker daemon failing to start on boot allan 2019-02-08 21:55 ` Ludovic Courtès 2019-02-11 10:46 ` Danny Milosavljevic 2019-02-11 13:11 ` Allan Adair 2019-02-11 14:24 ` Danny Milosavljevic 2019-02-11 17:31 ` Danny Milosavljevic 2019-02-12 9:05 ` Allan Adair 2019-02-12 17:45 ` Danny Milosavljevic 2019-02-27 14:17 ` Allan Adair 2019-02-27 15:53 ` Björn Höfling 2019-02-27 16:31 ` Andreas Enge 2019-03-01 8:58 ` Allan Adair 2019-03-01 13:09 ` Andreas Enge 2019-03-01 13:43 ` Björn Höfling 2019-03-01 13:50 ` Allan Adair 2019-03-01 18:00 ` Danny Milosavljevic 2019-03-11 8:59 ` Allan Adair 2019-03-12 19:47 ` Danny Milosavljevic 2019-03-18 10:23 ` Allan Adair 2019-03-18 10:53 ` Danny Milosavljevic 2019-03-18 11:05 ` Danny Milosavljevic 2019-03-18 13:47 ` Allan Adair 2019-03-25 21:46 ` Danny Milosavljevic 2019-03-26 14:15 ` Allan Adair
Code repositories for project(s) associated with this external index https://git.savannah.gnu.org/cgit/guix.git This is an external index of several public inboxes, see mirroring instructions on how to clone and mirror all data and code used by this external index.