* 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 public inbox
https://git.savannah.gnu.org/cgit/guix.git
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for read-only IMAP folder(s) and NNTP newsgroup(s).