* 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).