Back to build
Raw log | Switch to full mode | Login

DEBUG: config flag: /etc/botanist/config.json DEBUG: waiting for "summary.json" 2019/04/19 18:52:45 attempting to send <<netboot>>cmdline... 2019/04/19 18:52:45 done 2019/04/19 18:52:45 attempting to send <<image>>sparse.fvm... [00000.000] 00000.00000> zbi: @ 0xffffff80012f2000 (17482848 bytes) [00000.000] 00000.00000> UART: FIFO depth 16 [00000.000] 00000.00000> PMM: boot reserve add [0x100000, 0x2c5fff] [00000.000] 00000.00000> PMM: boot reserve add [0x12f2000, 0x239efff] [00000.000] 00000.00000> PMM: arena too small to be useful (size 4096) [00000.000] 00000.00000> PMM: pmm_add_arena failed to initialize arena [00000.000] 00000.00000> MEM: Failed to add pmm range at 0x8afff000 size 0x1000 [00000.000] 00000.00000> PMM: boot reserve marking WIRED [0x100000, 0x2c5fff] [00000.000] 00000.00000> PMM: boot reserve marking WIRED [0x12f2000, 0x239efff] [00000.000] 00000.00000> [00000.000] 00000.00000> welcome to Zircon [00000.000] 00000.00000> [00000.000] 00000.00000> KASLR: .text section at 0xffffffff00100000 [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001aa428 (global_prng_seed) at level 0x30000, flags 0x1 [00000.000] 00000.00000> initializing vm pre-heap [00000.000] 00000.00000> VM: marking boot alloc used range [0x239f000, 0x239f100) [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00147abc (elf_build_id) at level 0x4fffe, flags 0x1 [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00147c48 (version) at level 0x4ffff, flags 0x1 [00000.000] 00000.00000> version: [00000.000] 00000.00000> arch: x86 [00000.000] 00000.00000> platform: pc [00000.000] 00000.00000> target: pc [00000.000] 00000.00000> project: x64 [00000.000] 00000.00000> buildid: git-13ee3dc5e4c46bf127977ad28645c47442ec517d [00000.000] 00000.00000> ELF build ID: 5f3e39bd4ed89d3b8122947842f1eac846a04683 [00000.000] 00000.00000> initializing heap [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00102e1c (x86_resource_init) at level 0x50000, flags 0x1 [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001a9630 (console) at level 0x50000, flags 0x1 [00000.000] 00000.00000> initializing vm [00000.000] 00000.00000> VM: reserving kernel region [0xffffffff00100000, 0xffffffff001ee000) flags 0x28 name 'kernel_code' [00000.000] 00000.00000> VM: reserving kernel region [0xffffffff001ee000, 0xffffffff00232000) flags 0x8 name 'kernel_rodata' [00000.000] 00000.00000> VM: reserving kernel region [0xffffffff00232000, 0xffffffff00242000) flags 0x18 name 'kernel_data' [00000.000] 00000.00000> VM: reserving kernel region [0xffffffff00242000, 0xffffffff002c6000) flags 0x18 name 'kernel_bss' [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00103ae0 (display_memtype) at level 0x60001, flags 0x1 [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00138fa0 (acpi_tables) at level 0x60001, flags 0x1 [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00101c40 (hpet) at level 0x60002, flags 0x1 [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00102000 (apic) at level 0x60002, flags 0x1 [00000.000] 00000.00000> x2APIC enabled [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001061b4 (timer) at level 0x60003, flags 0x1 [00000.000] 00000.00000> HPET frequency: 23999 ticks/ms [00000.000] 00000.00000> TSC frequency: 2712000 ticks/ms [00020.126] 00000.00000> timer features: constant_tsc 1 invariant_tsc 1 tsc_deadline 1 [00020.126] 00000.00000> Using TSC as wallclock [00020.126] 00000.00000> initializing kernel [00020.126] 00000.00000> initializing mp [00020.126] 00000.00000> initializing timers [00020.127] 00000.00000> INIT: cpu 0, calling hook 0xffffffff0013c578 (debuglog) at level 0x7ffff, flags 0x1 [00020.127] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00195518 (thread_set_priority_experiment) at level 0x7ffff, flags 0x1 [00020.127] 00000.00000> thread set priority experiment is : ENABLED [00020.127] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001aa67c (global_prng_thread_safe) at level 0x7ffff, flags 0x1 [00020.127] 00000.00000> creating bootstrap completion thread [00020.471] 00000.00000> top of bootstrap2() [00020.471] 00000.00000> INIT: cpu 0, calling hook 0xffffffff0013151c (dpc) at level 0x80000, flags 0x1 [00020.484] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00152978 (libobject) at level 0x80000, flags 0x1 [00020.484] 00000.00000> OOM: started thread [00020.498] 00000.00000> Processor Model Info: type 0 family 0x6 model 0xe stepping 0x9 [00020.498] 00000.00000> display_family 0x6 display_model 0x8e [00020.498] 00000.00000> Vendor: Intel [00020.498] 00000.00000> Microarch: Kaby Lake [00020.498] 00000.00000> F/M/S: 6/8e/9 [00020.498] 00000.00000> Brand: Intel(R) Core(TM) i5-7300U CPU @ 2.60GHz [00020.498] 00000.00000> Features: fpu sse sse2 sse3 ssse3 sse4.1 sse4.2 mmx avx avx2 fxsr pcid xsave mon aesni clflush [00020.498] 00000.00000> clflushopt fsgsbase tsc_adj smep smap erms rdrand rdseed syscall nx huge rdtscp [00020.498] 00000.00000> invar_tsc tsc_deadline x2apic vmx pt hwp [00020.498] 00000.00000> initializing platform [00020.498] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001101f4 (x86_perfmon) at level 0x90000, flags 0x1 [00020.498] 00000.00000> PMU: version 4 [00020.498] 00000.00000> UART: started IRQ driven RX [00020.498] 00000.00000> UART: started IRQ driven TX [00020.498] 00000.00000> cpu topology: [00020.498] 00000.00000> 0: apic id 0x0 package 0 node 0 core 0 smt 0 BSP [00020.498] 00000.00000> 1: apic id 0x2 package 0 node 0 core 1 smt 0 [00020.498] 00000.00000> 2: apic id 0x1 package 0 node 0 core 0 smt 1 [00020.498] 00000.00000> 3: apic id 0x3 package 0 node 0 core 1 smt 1 [00020.498] 00000.00000> Found 4 cpus [00020.498] 00000.00000> booting apic ids: 0x2 0x1 0x3 [00020.513] 00000.00000> entering scheduler on cpu 2 [00020.514] 00000.00000> entering scheduler on cpu 3 [00020.514] 00000.00000> entering scheduler on cpu 1 [00020.517] 00000.00000> smbios: manufacturer="Intel Corporation" product="NUC7i5DNKE" [00020.517] 00000.00000> initializing target [00020.517] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001053a0 (x86_pcie_init) at level 0xa0000, flags 0x1 [00020.517] 00000.00000> moving to last init level [00020.517] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00144140 (ktrace) at level 0xc0000, flags 0x1 [00020.521] 00000.00000> ktrace: buffer at 0xffffff9788e10000 (33554432 bytes) [00020.521] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00147ab4 (userboot) at level 0xc0000, flags 0x1 [00020.521] 00000.00000> userboot: ramdisk 0x10ad000 @ 0xffffff80012f2000 [00020.521] 00000.00000> userboot: userboot rodata 0 @ [0x2ec9d7929000,0x2ec9d792c000) [00020.521] 00000.00000> userboot: userboot code 0x3000 @ [0x2ec9d792c000,0x2ec9d7937000) [00020.521] 00000.00000> userboot: vdso/full rodata 0 @ [0x2ec9d7937000,0x2ec9d793e000) [00020.521] 00000.00000> userboot: vdso/full code 0x7000 @ [0x2ec9d793e000,0x2ec9d793f000) [00020.521] 00000.00000> userboot: entry point @ 0x2ec9d792cc10 [00020.521] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001aa030 (kernel_shell) at level 0xc0000, flags 0x1 [00020.521] 01036.01043> userboot: option "netsvc.disable=true" [00020.521] 01036.01043> userboot: option "zircon.system.disable-automount=true" [00020.521] 01036.01043> userboot: option "zircon.autorun.boot=/boot/infra/setup" [00020.521] 01036.01043> userboot: option "kernel.serial=legacy" [00020.521] 01036.01043> userboot: option "http://192.168.42.1/multiboot/d4%3A5d%3Adf%3A07%3A5e%3A3f=" [00020.521] 01036.01043> userboot: option "multiboot.boot_loader_name=iPXE+1.0.0++(d2063)" [00020.560] 01036.01043> userboot: searching bootfs for 'bin/bootsvc' [00020.560] 01036.01043> userboot: 'bin/bootsvc' has PT_INTERP "lib/ld.so.1" [00020.560] 01036.01043> userboot: searching bootfs for 'lib/ld.so.1' [00020.560] 01036.01043> userboot: userboot: loaded lib/ld.so.1 at 0x4d4f1906b000, entry point 0x4d4f190f10d3 [00020.560] 01036.01043> userboot: userboot: loaded vDSO at 0x7f7cc01e4000, entry point 0x0 [00020.560] 01036.01043> userboot: process bin/bootsvc started. [00020.560] 01036.01043> userboot: waiting for loader-service requests... [00020.561] 01036.01043> userboot: searching bootfs for 'lib/libasync-default.so' [00020.561] 01036.01043> userboot: searching bootfs for 'lib/libfdio.so' [00020.561] 01036.01043> userboot: searching bootfs for 'lib/liblaunchpad.so' [00020.561] 01036.01043> userboot: searching bootfs for 'lib/libtrace-engine.so' [00020.561] 01050.01053> {{{reset}}} [00020.561] 01050.01053> {{{module:0:<application>:elf:18de7d58f51e8ba5c4f6afdd0cc8440f482c2b45}}} [00020.561] 01050.01053> {{{mmap:0x7811326ce000:0x2e000:load:0:rx:0}}} [00020.561] 01050.01053> {{{mmap:0x7811326fc000:0x4000:load:0:rw:0x2e000}}} [00020.561] 01050.01053> dso: id=18de7d58f51e8ba5c4f6afdd0cc8440f482c2b45 base=0x00007811326ce000 name=<application> [00020.561] 01050.01053> {{{module:0x3:libasync-default.so:elf:c189f51f19d10785d93b5235ad1b46dca4451b00}}} [00020.561] 01050.01053> {{{mmap:0x163980e96000:0x1000:load:0x3:rx:0}}} [00020.561] 01050.01053> {{{mmap:0x163980e97000:0x1000:load:0x3:rw:0x1000}}} [00020.561] 01050.01053> dso: id=c189f51f19d10785d93b5235ad1b46dca4451b00 base=0x0000163980e96000 name=libasync-default.so [00020.561] 01050.01053> {{{module:0x2:<vDSO>:elf:40ab5fa3b61f12fef4a44477a687f608661cd450}}} [00020.561] 01050.01053> {{{mmap:0x7f7cc01e4000:0x7000:load:0x2:r:0}}} [00020.561] 01050.01053> {{{mmap:0x7f7cc01eb000:0x1000:load:0x2:rx:0x7000}}} [00020.561] 01050.01053> dso: id=40ab5fa3b61f12fef4a44477a687f608661cd450 base=0x00007f7cc01e4000 name=<vDSO> [00020.561] 01050.01053> {{{module:0x1:libc.so:elf:67a12284bce140fc32aaaeac223e0e8f85cb5085}}} [00020.561] 01050.01053> {{{mmap:0x4d4f1906b000:0xcb000:load:0x1:rx:0}}} [00020.561] 01050.01053> {{{mmap:0x4d4f19137000:0x6000:load:0x1:rw:0xcc000}}} [00020.561] 01050.01053> dso: id=67a12284bce140fc32aaaeac223e0e8f85cb5085 base=0x00004d4f1906b000 name=libc.so [00020.561] 01050.01053> {{{module:0x4:libfdio.so:elf:27787977e95f3b9563c9e0bd4d34ec92b7e9ad88}}} [00020.561] 01050.01053> {{{mmap:0x5968db4ff000:0x24000:load:0x4:rx:0}}} [00020.561] 01050.01053> {{{mmap:0x5968db524000:0x4000:load:0x4:rw:0x25000}}} [00020.561] 01050.01053> dso: id=27787977e95f3b9563c9e0bd4d34ec92b7e9ad88 base=0x00005968db4ff000 name=libfdio.so [00020.561] 01050.01053> {{{module:0x5:liblaunchpad.so:elf:6fc2232dc8c1bc5c6adb8ad50ca794b5a260ee4f}}} [00020.561] 01050.01053> {{{mmap:0x50dba0bb5000:0x7000:load:0x5:rx:0}}} [00020.561] 01050.01053> {{{mmap:0x50dba0bbc000:0x2000:load:0x5:rw:0x7000}}} [00020.561] 01050.01053> dso: id=6fc2232dc8c1bc5c6adb8ad50ca794b5a260ee4f base=0x000050dba0bb5000 name=liblaunchpad.so [00020.561] 01050.01053> {{{module:0x6:libtrace-engine.so:elf:c9042b83fe01206008fcefb16395238417248169}}} [00020.561] 01050.01053> {{{mmap:0x261e04637000:0x9000:load:0x6:rx:0}}} [00020.561] 01050.01053> {{{mmap:0x261e04640000:0x2000:load:0x6:rw:0x9000}}} [00020.561] 01050.01053> dso: id=c9042b83fe01206008fcefb16395238417248169 base=0x0000261e04637000 name=libtrace-engine.so [00020.561] 01050.01053> bootsvc: Starting... [00020.561] 01036.01043> userboot: loader-service channel peer closed [00020.561] 01036.01043> userboot: finished! [00020.561] 01050.01053> bootsvc: Creating bootfs service... [00020.562] 01050.01053> bootsvc: Processing bootdata... [00020.562] 01050.01053> bootsvc: Loading boot cmdline overrides... [00020.562] 01050.01053> bootsvc: Loading kernel VMOs... [00020.562] 01050.01053> bootsvc: Creating loader service... [00020.562] 01050.01053> bootsvc: Launching next process... [00020.562] 01050.01096> bootsvc: launched bin/devmgr [00020.562] 01104.01117> devmgr: main() [00020.562] 01104.01117> cmdline: netsvc.disable=true [00020.562] 01104.01117> cmdline: zircon.system.disable-automount=true [00020.562] 01104.01117> cmdline: zircon.autorun.boot=/boot/infra/setup [00020.562] 01104.01117> cmdline: kernel.serial=legacy [00020.562] 01104.01117> cmdline: http://192.168.42.1/multiboot/d4%3A5d%3Adf%3A07%3A5e%3A3f= [00020.562] 01104.01117> cmdline: multiboot.boot_loader_name=iPXE+1.0.0++(d2063) [00020.563] 01104.01117> devmgr: coordinator_init() [00020.563] 01104.01117> devmgr: init [00020.563] 01104.01117> devmgr: svc init [00020.563] 01104.01117> devmgr: launch /boot/bin/svchost (svchost) OK [00020.563] 01104.01117> devmgr: vfs init [00020.563] 01104.01117> devmgr: launch /boot/bin/fshost (fshost) OK [00020.563] 01104.01222> devmgr: shell startup [00020.564] 01182.01202> fshost: started. [00020.565] 01104.01213> devmgr: launch /boot/bin/pwrbtn-monitor (pwrbtn-monitor) OK [00020.566] 01104.01235> devmgr: launch /boot/bin/virtual-console (virtual-console) OK [00020.566] 01104.01235> zircon.autorun.boot: starting '/boot/infra/setup'... [00020.566] 01104.01235> devmgr: launch /boot/infra/setup (autorun:boot) OK [00020.569] 01104.01117> devcoord: launch devhost 'devhost:sys': pid=2049 [00020.569] 01104.01117> devcoord: launch devhost 'devhost:test': pid=2082 [00020.569] 01104.01117> devcoord: launch devhost 'devhost:root': pid=2114 [00020.569] 01104.01117> devcoord: launch devhost 'devhost:misc': pid=2171 [00020.570] 02049.02073> devhost: trace provider registry begun [00020.570] 02082.02105> devhost: trace provider registry begun [00020.573] 02171.02208> devhost: trace provider registry begun [00020.573] 02114.02156> devhost: trace provider registry begun [00020.581] 01104.01222> devmgr: launch /boot/bin/sh (sh:console) OK [00020.629] 02049.02073> acpi-bus: not using IOMMU [00020.633] 02049.02073> acpi-pwrbtn: initialized [00020.656] 02049.02073> acpi: published device pci(0x1b53721b5200), parent=proxy(0x1b53721b1540), handle=0x1b53721edc30 [00020.657] 02049.02073> acpi: published device rtc(0x1b53721b0080), parent=acpi(0x1b53721b1780), handle=0x1b53722065b0 [00020.658] 02049.02073> acpi-ec: initialized [00020.660] 02049.02073> acpi: failed to create NHLT VMO (res -10) [00020.660] 02049.02073> acpi: failed to publish NHLT metadata [00020.662] 02049.02073> [sysmem_init 28] async_get_default_dispatcher(): 0x1b53721a40a0 [00020.662] 02049.02073> [sysmem_bind 40] sysmem_bind() [00020.662] 02049.02073> acpi-bus: sysmem_register_protocol() intentionally ignored for now. [00020.662] 02049.02073> PMU: 7 arch events [00020.662] 02049.02073> PMU: arch event id range: 1-7 [00020.662] 02049.02073> PMU: 102 model events [00020.662] 02049.02073> PMU: model event id range: 1-241 [00020.662] 02049.02073> Intel Processor Trace configuration for this chipset: [00020.662] 02049.02073> mtc_freq_mask: 0x249 [00020.662] 02049.02073> cyc_thresh_mask: 0x3fff [00020.662] 02049.02073> psb_freq_mask: 0x3f [00020.662] 02049.02073> num addr ranges: 2 [00020.663] 01104.01117> devcoord: launch devhost 'devhost:pci#1:8086:5916': pid=2839 [00020.663] 01104.01117> devcoord: launch devhost 'devhost:pci#3:8086:9d2f': pid=2881 [00020.663] 01104.01117> devcoord: launch devhost 'devhost:pci#5:8086:9d60': pid=2946 [00020.664] 02839.02862> devhost: trace provider registry begun [00020.664] 01104.01117> devcoord: launch devhost 'devhost:pci#6:8086:9d61': pid=3007 [00020.664] 02881.02917> devhost: trace provider registry begun [00020.665] 01104.01117> devcoord: launch devhost 'devhost:pci#9:8086:9d03': pid=3111 [00020.665] 02946.02980> devhost: trace provider registry begun [00020.665] 01104.01117> devcoord: launch devhost 'devhost:pci#14:8086:9d71': pid=3227 [00020.666] 03007.03081> devhost: trace provider registry begun [00020.666] 01104.01117> devcoord: launch devhost 'devhost:pci#16:8086:156f': pid=3301 [00020.666] 03111.03164> devhost: trace provider registry begun [00020.667] 03007.03081> initialized intel serialio i2c driver, reg=0x7d8109fb1000 regsize=4096 [00020.668] 02946.02980> initialized intel serialio i2c driver, reg=0x38f2e99f6000 regsize=4096 [00020.669] 03111.03164> ahci: using MSI interrupt [00020.670] 03301.03355> devhost: trace provider registry begun [00020.670] 03227.03281> devhost: trace provider registry begun [00020.681] 03227.03281> [IHDA DSP 00:1f.3] Failed to fetch NHLT (res -25) [00020.681] 03227.03281> devhost[00:1f.3/intel-hda-000/intel-sst-dsp-000] bind driver '/boot/driver/dsp.so' failed: -25 [00020.682] 01104.01117> devcoord: rpc: bind-driver 'intel-sst-dsp-000' status -25 [00020.682] 01245.01555> vc: new input device /dev/class/input/000 [00020.701] 02881.03634> * found USB device (0x18d1:0xa002, USB 2.0) config 1 [00020.701] 02881.03634> * found USB device (0x18d1:0xa003, USB 3.0) config 1 [00020.773] 01245.01555> vc: new display device /dev/class/display-controller/000/virtcon [00020.913] 02839.04144> i915: Found DP monitor [00020.913] 02839.04144> i915: Display 1 connected [00020.913] 02839.04144> i915: MST not supported [00021.972] 01245.01555> vc: Successfully attached to display 1 [00022.163] 02881.03634> * found USB device (0x0781:0x5571, USB 2.0) config 1 [00022.164] 02881.02917> UMS: parent: 'ifc-000' [00022.164] 02881.02917> UMS:Max lun is: 0 [00022.414] 02881.03634> * found USB device (0x8087:0x0a2b, USB 2.0) config 1 [00022.416] 02881.02917> devhost[00:14.0/xhci/usb-bus/002/002/ifc-001] bind driver '/boot/driver/bt-transport-usb.so' failed: -2 [00022.416] 01104.01117> devcoord: rpc: bind-driver 'ifc-001' status -2 [00022.670] 03007.03081> intel-i2c-controller: intel_serialio_i2c_slave_transfer: -21 [00022.670] 03007.03081> i2c-hid: could not read HID descriptor: 0 [00022.670] 03007.03081> devhost[00:15.1/i2c-bus-9d61/004c] bind driver '/boot/driver/i2c-hid.so' failed: -2 [00022.670] 01104.01117> devcoord: rpc: bind-driver '004c' status -2 [00022.670] 02946.02980> intel-i2c-controller: intel_serialio_i2c_slave_transfer: -21 [00022.670] 02946.02980> i2c-hid: could not read HID descriptor: 0 [00022.670] 02946.02980> devhost[00:15.0/i2c-bus-9d60/0020] bind driver '/boot/driver/i2c-hid.so' failed: -2 [00022.670] 01104.01117> devcoord: rpc: bind-driver '0020' status -2 [00022.694] 03111.03552> sata2: dev info [00022.694] 03111.03552> serial=715400411010 2 [00022.694] 03111.03552> firmware rev=1P11A1E_ [00022.694] 03111.03552> model id=IBIW NSS D [00022.694] 03111.03552> major=0x3f0 ACS2 DMA 32 commands [00022.694] 03111.03552> LBA48 250069680 sectors, sector size=512 [00022.694] 01182.01202> devmgr: /dev/class/block/000: GPT? [00022.694] 01104.01117> devcoord: dc_bind_device() '/boot/driver/gpt.so' [00022.695] 03111.03164> gpt: device_get_metadata failed (-25) [00022.696] 01182.01202> devmgr: /dev/class/block/001: FVM? [00022.696] 01104.01117> devcoord: dc_bind_device() '/boot/driver/fvm.so' [00022.699] 04424.04445> paver:[Initialize] Successfully initialized EFI Device Partitioner [00022.701] 04424.04445> paver:[WipePartitions] Immediate reboot strongly recommended [00022.701] 03111.03164> block: Joining un-closed FIFO server [00022.701] 03111.03164> block: Joining un-closed FIFO server [00022.701] 03111.03164> block: Joining un-closed FIFO server [00022.701] 01104.01117> devcoord: dc_bind_device() '' [00022.701] 01182.01202> devmgr: /dev/class/block/000: GPT? [00022.701] 01104.01117> devcoord: dc_bind_device() '/boot/driver/gpt.so' [00022.701] 03111.03164> gpt: device_get_metadata failed (-25) [00022.704] 04717.04733> 34+0 records in [00022.704] 04717.04733> 34+0 records out [00022.704] 04717.04733> 17408 bytes copied [00022.706] 04822.04836> 34+0 records in [00022.706] 04822.04836> 34+0 records out [00022.706] 04822.04836> 17408 bytes copied [00022.707] 04926.04940> netifc: ? /dev/class/ethernet/000 [00022.707] 04926.04940> netifc: create 512 eth buffers [00022.707] 04926.04940> macaddr: d4:5d:df:07:5e:3f [00022.707] 04926.04940> ip6addr: fe80::d65d:df4d:fe07:5e3f [00022.707] 04926.04940> snmaddr: ff02::1:ff07:5e3f [00022.708] 04926.04940> netsvc: using /dev/class/ethernet/000 [00022.708] 04926.04940> _ _ _ [00022.708] 04926.04940> | | | | | [00022.708] 04926.04940> _______ __| | |__ ___ ___ | |_ [00022.708] 04926.04940> |_ / _ \/ _` | '_ \ / _ \ / _ \| __| [00022.708] 04926.04940> / / __/ (_| | |_) | (_) | (_) | |_ [00022.708] 04926.04940> /___\___|\__,_|_.__/ \___/ \___/ \__| [00022.708] 04926.04940> [00022.708] 04926.04940> [00022.708] 04926.04940> zedboot: version: 0.7.13 [00022.708] 04926.04940> [00022.708] 04926.04940> netsvc: nodename='upper-aroma-clock-plot' [00022.708] 04926.04940> netsvc: will not advertise [00022.708] 04926.04940> netsvc: start [00023.167] 02881.04248> UMS: block size is: 0x00000200 [00023.167] 02881.04248> UMS: total blocks is: 15630336 [00023.167] 02881.04248> UMS: total size is: 8002732032 [00023.167] 02881.04248> UMS: read-only: 0 removable: 1 [00023.168] 01182.01202> devmgr: /dev/class/block/006: MBR? [00023.168] 01104.01117> devcoord: dc_bind_device() '/boot/driver/mbr.so' [00023.170] 01182.01202> devmgr: /dev/class/block/008: MBR? [00023.170] 01104.01117> devcoord: dc_bind_device() '/boot/driver/mbr.so' [01965.741] 04926.04940> netsvc: handling tftp request failed (file might not exist) [01965.741] 04926.04940> netsvc: close, but no open file [01965.741] 04926.04940> netsvc: metrics: {"inorderblks": 0,"oooblks": 0,"ack": 0,"nack": 0,"timeouts": 0,"sas": 0,"inorderbytes": 0} [01965.742] 04926.04940> netsvc: tftp write of file <<netboot>>cmdline completed [01965.742] 04926.04940> netsvc: metrics: {"inorderblks": 1,"oooblks": 0,"ack": 1,"nack": 0,"timeouts": 0,"sas": 0,"inorderbytes": 55} [01965.742] 04926.04940> netsvc: Running FVM Paver [01965.744] 04926.05114> paver:[InitializeGpt] Located GPT is invalid; Attempting to initialize [01965.745] 01104.01117> devcoord: dc_bind_device() '' [01965.745] 01104.01117> devcoord: dc_bind_device() '/boot/driver/gpt.so' [01965.745] 03111.03164> gpt: device_get_metadata failed (-25) [01965.745] 01182.01202> devmgr: /dev/class/block/000: GPT? [01965.745] 01104.01117> devcoord: dc_bind_device() '/boot/driver/gpt.so' [01965.745] 03111.03164> devhost: rpc:bind-device failed: -20 [01965.746] 04926.05114> paver:[Initialize] Successfully initialized EFI Device Partitioner [01965.746] 04926.05114> paver:[PartitionPave] Paving partition. [01965.746] 04926.05114> paver:[FindFirstFit] Looking for space [01965.746] 04926.05114> paver:[FindFirstFit] Sorting [01965.746] 04926.05114> paver:[FindFirstFit] Partition[0] From Block [0, 34) ... (next partition starts at block 250069646) [01965.746] 04926.05114> paver:[FindFirstFit] There are 250069612 free blocks (16777216 requested) [01965.746] 04926.05114> paver:[AddPartition] Found space in GPT - OK 250069612 @ 34 [01965.746] 04926.05114> paver:[AddPartition] Final space in GPT - OK 16777216 @ 34 [01965.746] 04926.05114> paver:[AddPartition] Added partition, waiting for bind [01965.746] 01104.01117> devcoord: dc_bind_device() '' [01965.746] 01182.01202> devmgr: /dev/class/block/000: GPT? [01965.746] 01104.01117> devcoord: dc_bind_device() '/boot/driver/gpt.so' [01965.746] 03111.03164> gpt: device_get_metadata failed (-25) [01965.747] 04926.05114> paver:[AddPartition] Added partition, waiting for bind - OK [01965.747] 04926.05114> paver:[PartitionPave] Streaming partitions... [01965.747] 05094.05108> Found compressed file [01965.747] 04926.05114> paver:[FvmStreamPartitions] Header Validated - OK [01965.747] 04926.05114> paver:[FvmPartitionFormat] Initializing partition as FVM [01965.749] 01104.01117> devcoord: dc_bind_device() '/boot/driver/fvm.so' [01966.751] 04926.05114> paver:[FvmStreamPartitions] Partitions pre-validated successfully: Enough space exists to pave. [01966.751] 04926.05114> paver:[AllocatePartitions] Allocating partition blobfs consisting of 1 slices [01966.755] 04926.05114> paver:[AllocatePartitions] Allocating partition minfs consisting of 1 slices [01966.756] 04926.05114> paver:[AllocatePartitions] Creating zxcrypt volume [01966.757] 03111.03164> devhost_get_handles(0x940dcdfc900:block) open path='zxcrypt/block', r=-2 [01966.757] 01104.01117> devcoord: dc_bind_device() '/boot/driver/zxcrypt.so' [01966.757] 03111.03164> devhost_get_handles(0x940dcdfc900:block) open path='zxcrypt', r=-2 [01966.763] 04926.05114> paver:[FvmStreamPartitions] Partition space pre-allocated successfully. [01966.763] 04926.05114> paver:[FvmStreamPartitions] Streaming partition 0 [01966.763] 04926.05114> paver:[StreamFvmPartition] Writing extent 0... [01966.763] 04926.05120> netsvc: paver write progress 0.1% [01966.764] 04926.05114> paver:[StreamFvmPartition] 8192 bytes written, 8380416 zeroes left [01966.815] 04926.05114> paver:[StreamFvmPartition] Writing extent 1... [01966.816] 04926.05114> paver:[StreamFvmPartition] 8192 bytes written, 8380416 zeroes left [01966.869] 04926.05114> paver:[StreamFvmPartition] Writing extent 2... [01966.883] 04926.05114> paver:[StreamFvmPartition] 2097152 bytes written, 6291456 zeroes left [01966.923] 04926.05114> paver:[StreamFvmPartition] Writing extent 3... [01966.936] 04926.05114> paver:[StreamFvmPartition] 2097152 bytes written, 6291456 zeroes left [01966.976] 04926.05114> paver:[StreamFvmPartition] Writing extent 4... [01967.764] 04926.05120> netsvc: paver write progress 35.1% 2019/04/19 18:52:48 done 2019/04/19 18:52:48 attempting to send <<image>>bootloader.img... 2019/04/19 18:52:48 target is busy, retrying in one second [01968.766] 04926.05120> netsvc: paver write progress 80.9% [01968.808] 04926.04940> netsvc: tftp write of file <<image>>sparse.fvm completed [01968.808] 04926.04940> netsvc: metrics: {"inorderblks": 300813,"oooblks": 0,"ack": 1176,"nack": 0,"timeouts": 0,"sas": 0,"inorderbytes": 308032048} [01969.149] 04926.05114> paver:[StreamFvmPartition] 336199680 bytes written, 7733248 zeroes left [01969.201] 04926.05114> paver:[FvmStreamPartitions] Done streaming partition 0 [01969.201] 04926.05114> paver:[FvmStreamPartitions] Done flushing partition 0 [01969.201] 04926.05114> paver:[FvmStreamPartitions] Streaming partition 1 [01969.201] 04926.05114> paver:[StreamFvmPartition] Writing extent 0... [01969.202] 04926.05114> paver:[StreamFvmPartition] 8192 bytes written, 8380416 zeroes left [01969.256] 04926.05114> paver:[StreamFvmPartition] Writing extent 1... [01969.258] 04926.05114> paver:[StreamFvmPartition] 65536 bytes written, 8323072 zeroes left [01969.312] 04926.05114> paver:[StreamFvmPartition] Writing extent 2... [01969.313] 04926.05114> paver:[StreamFvmPartition] 65536 bytes written, 8323072 zeroes left [01969.367] 04926.05114> paver:[StreamFvmPartition] Writing extent 3... [01969.423] 04926.05114> paver:[StreamFvmPartition] Writing extent 4... [01969.437] 04926.05114> paver:[StreamFvmPartition] 2097152 bytes written, 14680064 zeroes left [01969.531] 04926.05114> paver:[StreamFvmPartition] Writing extent 5... [01969.532] 04926.05114> paver:[StreamFvmPartition] 57344 bytes written, 8331264 zeroes left [01969.584] 04926.05114> paver:[FvmStreamPartitions] Done streaming partition 1 [01969.584] 04926.05114> paver:[FvmStreamPartitions] Done flushing partition 1 [01969.586] 05094.05108> Reading FVM from compressed file: true [01969.586] 05094.05108> Remaining bytes read into compression buffer: 0 [01969.586] 05094.05108> Remaining bytes written to decompression buffer: 0 [01969.586] 05094.05108> Time reading bytes from sparse FVM file: 148445346 (0 s) [01969.586] 05094.05108> Time reading bytes AND decompressing them: 333483781 (0 s) [01969.586] 04926.05114> paver:[PartitionPave] Completed successfully 2019/04/19 18:52:49 attempting to send <<image>>bootloader.img... 2019/04/19 18:52:49 done 2019/04/19 18:52:49 attempting to send <<image>>zircona.img... [01969.809] 04926.04940> netsvc: Running BOOTLOADER Paver [01969.812] 04926.05988> paver:[Initialize] Successfully initialized EFI Device Partitioner [01969.812] 04926.05988> paver:[RealMain] SKIPPING BOOTLOADER install on x64 device, pass --force if desired. [01969.825] 04926.04940> netsvc: tftp write of file <<image>>bootloader.img completed [01969.825] 04926.04940> netsvc: metrics: {"inorderblks": 1093,"oooblks": 0,"ack": 5,"nack": 0,"timeouts": 0,"sas": 0,"inorderbytes": 1118208} [01969.825] 04926.04940> netsvc: Running ZIRCON-A Paver [01969.828] 04926.06117> paver:[Initialize] Successfully initialized EFI Device Partitioner [01969.828] 04926.06117> paver:[PartitionPave] Paving partition. [01969.828] 04926.06117> paver:[FindFirstFit] Looking for space [01969.828] 04926.06117> paver:[FindFirstFit] Partition seen with start 34, end 16777249 (length 16777216) [01969.828] 04926.06117> paver:[FindFirstFit] Sorting [01969.828] 04926.06117> paver:[FindFirstFit] Partition[0] From Block [0, 34) ... (next partition starts at block 34) [01969.828] 04926.06117> paver:[FindFirstFit] There are 0 free blocks (32768 requested) [01969.828] 04926.06117> paver:[FindFirstFit] Partition[1] From Block [34, 16777250) ... (next partition starts at block 250069646) [01969.828] 04926.06117> paver:[FindFirstFit] There are 233292396 free blocks (32768 requested) [01969.828] 04926.06117> paver:[AddPartition] Found space in GPT - OK 233292396 @ 16777250 [01969.828] 04926.06117> paver:[AddPartition] Final space in GPT - OK 32768 @ 16777250 [01969.829] 03111.03164> block: Joining un-closed FIFO server [01969.829] 03111.03164> block: Joining un-closed FIFO server [01969.829] 04926.06117> paver:[AddPartition] Added partition, waiting for bind [01969.829] 01104.01117> devcoord: dc_bind_device() '' [01969.829] 01182.01202> devmgr: /dev/class/block/000: GPT? [01969.829] 01104.01117> devcoord: dc_bind_device() '/boot/driver/gpt.so' [01969.829] 03111.03164> gpt: device_get_metadata failed (-25) [01969.830] 01182.01202> devmgr: /dev/class/block/013: FVM? [01969.830] 01104.01117> devcoord: dc_bind_device() '/boot/driver/fvm.so' [01969.830] 04926.06117> paver:[AddPartition] Added partition, waiting for bind - OK 2019/04/19 18:52:50 done 2019/04/19 18:52:50 attempting to send <<image>>zirconr.img... 2019/04/19 18:52:50 target is busy, retrying in one second [01969.949] 04926.04940> netsvc: tftp write of file <<image>>zircona.img completed [01969.949] 04926.04940> netsvc: metrics: {"inorderblks": 11733,"oooblks": 0,"ack": 46,"nack": 0,"timeouts": 0,"sas": 0,"inorderbytes": 12013680} [01970.020] 04926.06117> paver:[PartitionPave] Completed successfully 2019/04/19 18:52:51 attempting to send <<image>>zirconr.img... [01970.950] 04926.04940> netsvc: Running ZIRCON-R Paver [01970.953] 04926.06377> paver:[Initialize] Successfully initialized EFI Device Partitioner [01970.953] 04926.06377> paver:[PartitionPave] Paving partition. [01970.953] 04926.06377> paver:[FindFirstFit] Looking for space [01970.953] 04926.06377> paver:[FindFirstFit] Partition seen with start 34, end 16777249 (length 16777216) [01970.953] 04926.06377> paver:[FindFirstFit] Partition seen with start 16777250, end 16810017 (length 32768) [01970.953] 04926.06377> paver:[FindFirstFit] Sorting [01970.953] 04926.06377> paver:[FindFirstFit] Partition[0] From Block [0, 34) ... (next partition starts at block 34) [01970.953] 04926.06377> paver:[FindFirstFit] There are 0 free blocks (49152 requested) [01970.953] 04926.06377> paver:[FindFirstFit] Partition[1] From Block [34, 16777250) ... (next partition starts at block 16777250) [01970.953] 04926.06377> paver:[FindFirstFit] There are 0 free blocks (49152 requested) [01970.953] 04926.06377> paver:[FindFirstFit] Partition[2] From Block [16777250, 16810018) ... (next partition starts at block 250069646) [01970.953] 04926.06377> paver:[FindFirstFit] There are 233259628 free blocks (49152 requested) [01970.953] 04926.06377> paver:[AddPartition] Found space in GPT - OK 233259628 @ 16810018 [01970.953] 04926.06377> paver:[AddPartition] Final space in GPT - OK 49152 @ 16810018 [01970.954] 04926.06377> paver:[AddPartition] Added partition, waiting for bind [01970.954] 03111.03164> block: Joining un-closed FIFO server [01970.954] 01104.01117> devcoord: dc_bind_device() '' [01970.955] 01182.01202> devmgr: /dev/class/block/000: GPT? [01970.955] 01104.01117> devcoord: dc_bind_device() '/boot/driver/gpt.so' [01970.955] 03111.03164> gpt: device_get_metadata failed (-25) [01970.955] 01182.01202> devmgr: /dev/class/block/017: FVM? [01970.955] 01104.01117> devcoord: dc_bind_device() '/boot/driver/fvm.so' [01970.955] 04926.06377> paver:[AddPartition] Added partition, waiting for bind - OK 2019/04/19 18:52:51 done 2019/04/19 18:52:51 attempting to send <<image>>authorized_keys... 2019/04/19 18:52:51 target is busy, retrying in one second [01971.080] 04926.04940> netsvc: tftp write of file <<image>>zirconr.img completed [01971.080] 04926.04940> netsvc: metrics: {"inorderblks": 10436,"oooblks": 0,"ack": 41,"nack": 0,"timeouts": 0,"sas": 0,"inorderbytes": 10685864} [01971.142] 04926.06377> paver:[PartitionPave] Completed successfully 2019/04/19 18:52:52 attempting to send <<image>>authorized_keys... 2019/04/19 18:52:52 done 2019/04/19 18:52:52 attempting to send <<netboot>>kernel.bin... 2019/04/19 18:52:52 target is busy, retrying in one second [01972.081] 04926.04940> netsvc: Installing SSH authorized_keys [01972.081] 04926.04940> netsvc: tftp write of file <<image>>authorized_keys completed [01972.082] 04926.04940> netsvc: metrics: {"inorderblks": 1,"oooblks": 0,"ack": 1,"nack": 0,"timeouts": 0,"sas": 0,"inorderbytes": 806} [01972.084] 04926.06654> paver:[Initialize] Successfully initialized EFI Device Partitioner [01972.085] 01104.01117> devcoord: dc_bind_device() '/boot/driver/zxcrypt.so' [01972.085] 03111.03164> devhost_get_handles(0x940dcdfc900:block) open path='zxcrypt', r=-2 [01972.110] 04926.06654> paver:[DataFilePave] Wrote ssh/authorized_keys 2019/04/19 18:52:53 attempting to send <<netboot>>kernel.bin... 2019/04/19 18:52:53 done [00000.000] 00000.00000> zbi: @ 0xffffff80066e7000 (10491616 bytes) [00000.000] 00000.00000> UART: FIFO depth 16 [00000.000] 00000.00000> PMM: boot reserve add [0x100000, 0x2fefff] [00000.000] 00000.00000> PMM: boot reserve add [0x66e7000, 0x70e8fff] [00000.000] 00000.00000> PMM: arena too small to be useful (size 4096) [00000.000] 00000.00000> PMM: pmm_add_arena failed to initialize arena [00000.000] 00000.00000> MEM: Failed to add pmm range at 0x8afff000 size 0x1000 [00000.000] 00000.00000> PMM: boot reserve marking WIRED [0x100000, 0x2fefff] [00000.000] 00000.00000> PMM: boot reserve marking WIRED [0x66e7000, 0x70e8fff] [00000.000] 00000.00000> [00000.000] 00000.00000> welcome to Zircon [00000.000] 00000.00000> [00000.000] 00000.00000> KASLR: .text section at 0xffffffff00100000 [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00114e2c (global_prng_seed) at level 0x30000, flags 0x1 [00000.000] 00000.00000> initializing vm pre-heap [00000.000] 00000.00000> VM: marking boot alloc used range [0x70e9000, 0x70e9100) [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001221dc (elf_build_id) at level 0x4fffe, flags 0x1 [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00122368 (version) at level 0x4ffff, flags 0x1 [00000.000] 00000.00000> version: [00000.000] 00000.00000> arch: x86 [00000.000] 00000.00000> platform: XXX [00000.000] 00000.00000> target: XXX [00000.000] 00000.00000> project: x64 [00000.000] 00000.00000> buildid: git-1fd4ec2f02fc15f15eb764f03bcf7db389dc96bc-dirty [00000.000] 00000.00000> ELF build ID: 4509097a37eee281eef64c27c281aa301f843e13 [00000.000] 00000.00000> initializing heap [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00101fc4 (console) at level 0x50000, flags 0x1 [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff0018262c (x86_resource_init) at level 0x50000, flags 0x1 [00000.000] 00000.00000> initializing vm [00000.000] 00000.00000> VM: reserving kernel region [0xffffffff00100000, 0xffffffff0021b000) flags 0x28 name 'kernel_code' [00000.000] 00000.00000> VM: reserving kernel region [0xffffffff0021b000, 0xffffffff0026b000) flags 0x8 name 'kernel_rodata' [00000.000] 00000.00000> VM: reserving kernel region [0xffffffff0026b000, 0xffffffff00273000) flags 0x18 name 'kernel_data' [00000.000] 00000.00000> VM: reserving kernel region [0xffffffff00273000, 0xffffffff002ff000) flags 0x18 name 'kernel_bss' [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001832f0 (display_memtype) at level 0x60001, flags 0x1 [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00186780 (acpi_tables) at level 0x60001, flags 0x1 [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00181430 (hpet) at level 0x60002, flags 0x1 [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001817f0 (apic) at level 0x60002, flags 0x1 [00000.000] 00000.00000> x2APIC enabled [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001a7dd4 (system_topology_init) at level 0x60002, flags 0x1 [00000.000] 00000.00000> WARNING: more than 1000 levels of cache, couldn't find highest. [00000.000] 00000.00000> WARNING: unable to find any cache levels. [00000.000] 00000.00000> Could not find SRAT table. ACPICA returned: 5 [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00185d70 (timer) at level 0x60003, flags 0x1 [00000.000] 00000.00000> HPET frequency: 23999 ticks/ms [00000.000] 00000.00000> TSC frequency: 2712000 ticks/ms [01973.488] 00000.00000> timer features: constant_tsc 1 invariant_tsc 1 tsc_deadline 1 [01973.488] 00000.00000> Using TSC as wallclock [01973.488] 00000.00000> INIT: cpu 0, calling hook 0xffffffff002085fc (percpu_heap_init) at level 0x60003, flags 0x1 [01973.488] 00000.00000> initializing kernel [01973.488] 00000.00000> initializing mp [01973.488] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00115080 (global_prng_thread_safe) at level 0x7ffff, flags 0x1 [01973.488] 00000.00000> creating bootstrap completion thread [01973.488] 00000.00000> top of bootstrap2() [01973.488] 00000.00000> INIT: cpu 0, calling hook 0xffffffff0013169c (libobject) at level 0x80000, flags 0x1 [01973.488] 00000.00000> OOM: started thread [01973.488] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00205568 (dpc) at level 0x80000, flags 0x1 [01973.488] 00000.00000> Processor Model Info: type 0 family 0x6 model 0xe stepping 0x9 [01973.488] 00000.00000> display_family 0x6 display_model 0x8e [01973.488] 00000.00000> Vendor: Intel [01973.488] 00000.00000> Microarch: Kaby Lake [01973.488] 00000.00000> F/M/S: 6/8e/9 [01973.488] 00000.00000> patch_level: 8e [01973.488] 00000.00000> Brand: Intel(R) Core(TM) i5-7300U CPU @ 2.60GHz [01973.488] 00000.00000> Features: fpu sse sse2 sse3 ssse3 sse4.1 sse4.2 mmx avx avx2 fxsr pcid xsave mon aesni clflush [01973.488] 00000.00000> clflushopt fsgsbase tsc_adj smep smap erms rdrand rdseed syscall nx huge rdtscp [01973.488] 00000.00000> invar_tsc tsc_deadline x2apic vmx pt hwp [01973.488] 00000.00000> Properties: meltdown l1tf pcid_good [01973.488] 00000.00000> initializing platform [01973.488] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001a14e4 (x86_perfmon) at level 0x90000, flags 0x1 [01973.488] 00000.00000> PMU: version 4 [01973.488] 00000.00000> UART: started IRQ driven RX [01973.488] 00000.00000> UART: started IRQ driven TX [01973.488] 00000.00000> cpu topology: [01973.488] 00000.00000> 0: apic id 0x0 BSP [01973.488] 00000.00000> 1: apic id 0x1 [01973.488] 00000.00000> 2: apic id 0x2 [01973.488] 00000.00000> 3: apic id 0x3 [01973.488] 00000.00000> Found 4 cpus [01973.488] 00000.00000> booting apic ids: 0x1 0x2 0x3 [01973.503] 00000.00000> entering scheduler on cpu 1 [01973.504] 00000.00000> entering scheduler on cpu 3 [01973.504] 00000.00000> entering scheduler on cpu 2 [01973.507] 00000.00000> smbios: manufacturer="Intel Corporation" product="NUC7i5DNKE" [01973.507] 00000.00000> initializing target [01973.507] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00185020 (x86_pcie_init) at level 0xa0000, flags 0x1 [01973.507] 00000.00000> moving to last init level [01973.507] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00121434 (debuglog) at level 0xb0000, flags 0x1 [01973.507] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00174ca8 (kcounters) at level 0xb0000, flags 0x1 [01973.507] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00102aec (kernel_shell) at level 0xc0000, flags 0x1 [01973.507] 00000.00000> INIT: cpu 0, calling hook 0xffffffff002027a0 (ktrace) at level 0xc0000, flags 0x1 [01973.510] 00000.00000> ktrace: buffer at 0xffffff9b3e6eb000 (33554432 bytes) [01973.510] 00000.00000> INIT: cpu 0, calling hook 0xffffffff002181d0 (userboot) at level 0xc0000, flags 0x1 [01973.510] 00000.00000> userboot: ramdisk 0xa02000 @ 0xffffff80066e7000 [01973.511] 00000.00000> userboot: userboot rodata 0 @ [0x36fe16c44000,0x36fe16c47000) [01973.511] 00000.00000> userboot: userboot code 0x3000 @ [0x36fe16c47000,0x36fe16c52000) [01973.511] 00000.00000> userboot: vdso/full rodata 0 @ [0x36fe16c52000,0x36fe16c59000) [01973.511] 00000.00000> userboot: vdso/full code 0x7000 @ [0x36fe16c59000,0x36fe16c5a000) [01973.511] 00000.00000> userboot: entry point @ 0x36fe16c47c90 [01973.511] 01036.01043> userboot: option "zircon.autorun.system=/boot/bin/sh+/boot/infra/runcmds" [01973.534] 01036.01043> userboot: searching bootfs for 'bin/bootsvc' [01973.534] 01036.01043> userboot: 'bin/bootsvc' has PT_INTERP "lib/ld.so.1" [01973.534] 01036.01043> userboot: searching bootfs for 'lib/ld.so.1' [01973.535] 01036.01043> userboot: userboot: loaded lib/ld.so.1 at 0x608f4f69f000, entry point 0x608f4f6bd3d0 [01973.535] 01036.01043> userboot: userboot: loaded vDSO at 0x6462a2bae000, entry point 0x6462a2bb58fa [01973.535] 01036.01043> userboot: process bin/bootsvc started. [01973.535] 01036.01043> userboot: waiting for loader-service requests... [01973.535] 01036.01043> userboot: searching bootfs for 'lib/libasync-default.so' [01973.535] 01036.01043> userboot: searching bootfs for 'lib/libfdio.so' [01973.535] 01036.01043> userboot: searching bootfs for 'lib/libtrace-engine.so' [01973.535] 01036.01043> userboot: searching bootfs for 'lib/liblaunchpad.so' [01973.535] 01050.01053> {{{reset}}} [01973.535] 01050.01053> {{{module:0:<application>:elf:4562ed08a01a412e6b7e76b7ee9f8a5bd0904dbb}}} [01973.535] 01050.01053> {{{mmap:0x610522f7a000:0x3a000:load:0:rx:0}}} [01973.535] 01050.01053> {{{mmap:0x610522fb4000:0x4000:load:0:rw:0x3a000}}} [01973.535] 01050.01053> dso: id=4562ed08a01a412e6b7e76b7ee9f8a5bd0904dbb base=0x0000610522f7a000 name=<application> [01973.535] 01050.01053> {{{module:0x2:<vDSO>:elf:ea0dfec464c2dc7856e31bb691e2ffe7bae2bda5}}} [01973.535] 01050.01053> {{{mmap:0x6462a2bae000:0x7000:load:0x2:r:0}}} [01973.535] 01050.01053> {{{mmap:0x6462a2bb5000:0x1000:load:0x2:rx:0x7000}}} [01973.535] 01050.01053> dso: id=ea0dfec464c2dc7856e31bb691e2ffe7bae2bda5 base=0x00006462a2bae000 name=<vDSO> [01973.535] 01050.01053> {{{module:0x3:libasync-default.so:elf:8c511b4202cf569c8fdde14ca97222102ba3a9e0}}} [01973.535] 01050.01053> {{{mmap:0x791b32486000:0x1000:load:0x3:rx:0}}} [01973.535] 01050.01053> {{{mmap:0x791b32487000:0x1000:load:0x3:rw:0x1000}}} [01973.535] 01050.01053> dso: id=8c511b4202cf569c8fdde14ca97222102ba3a9e0 base=0x0000791b32486000 name=libasync-default.so [01973.535] 01050.01053> {{{module:0x4:libfdio.so:elf:eec568ecb043a004f1c6db8d5f091fe3a49de221}}} [01973.535] 01050.01053> {{{mmap:0x4cb427a87000:0x32000:load:0x4:rx:0}}} [01973.535] 01050.01053> {{{mmap:0x4cb427aba000:0x4000:load:0x4:rw:0x33000}}} [01973.535] 01050.01053> dso: id=eec568ecb043a004f1c6db8d5f091fe3a49de221 base=0x00004cb427a87000 name=libfdio.so [01973.535] 01050.01053> {{{module:0x5:libtrace-engine.so:elf:b82e75659fdaaa34e91100dc98d0a90f14f77ded}}} [01973.535] 01050.01053> {{{mmap:0x16595bcd4000:0x9000:load:0x5:rx:0}}} [01973.535] 01050.01053> {{{mmap:0x16595bcdd000:0x2000:load:0x5:rw:0x9000}}} [01973.535] 01050.01053> dso: id=b82e75659fdaaa34e91100dc98d0a90f14f77ded base=0x000016595bcd4000 name=libtrace-engine.so [01973.535] 01050.01053> {{{module:0x6:liblaunchpad.so:elf:92e47a1f2729d76d9db7aa559442851234aa01a2}}} [01973.535] 01050.01053> {{{mmap:0x66ed4d775000:0x7000:load:0x6:rx:0}}} [01973.535] 01050.01053> {{{mmap:0x66ed4d77c000:0x2000:load:0x6:rw:0x7000}}} [01973.535] 01050.01053> dso: id=92e47a1f2729d76d9db7aa559442851234aa01a2 base=0x000066ed4d775000 name=liblaunchpad.so [01973.535] 01050.01053> {{{module:0x1:libc.so:elf:5d417db61b3a48a58a8fa1ffbfc2e71b830e0857}}} [01973.535] 01050.01053> {{{mmap:0x608f4f69f000:0xa6000:load:0x1:rx:0}}} [01973.535] 01050.01053> {{{mmap:0x608f4f745000:0x5000:load:0x1:rw:0xa6000}}} [01973.535] 01050.01053> dso: id=5d417db61b3a48a58a8fa1ffbfc2e71b830e0857 base=0x0000608f4f69f000 name=libc.so [01973.535] 01050.01053> bootsvc: Starting... [01973.535] 01036.01043> userboot: loader-service channel peer closed [01973.535] 01036.01043> userboot: finished! [01973.535] 01050.01053> bootsvc: Creating bootfs service... [01973.536] 01050.01053> bootsvc: Retrieving boot image... [01973.536] 01050.01053> bootsvc: Decommitted BOOTDATA VMO from 0 to 0xa01000 [01973.536] 01050.01053> bootsvc: Loading boot arguments... [01973.536] 01050.01053> bootsvc: Creating svcfs service... [01973.536] 01050.01053> bootsvc: Loading kernel VMOs... [01973.536] 01050.01053> bootsvc: Creating loader service... [01973.536] 01050.01053> bootsvc: Launching next process... [01973.536] 01050.01108> bootsvc: Launched bin/devcoordinator [01973.537] 01115.01130> devcoordinator: launch /boot/bin/svchost (svchost) OK [01973.538] 01115.01130> devcoordinator: launch /boot/bin/fshost (fshost) OK [01973.540] 01115.01323> devcoordinator: launch /boot/bin/pwrbtn-monitor (pwrbtn-monitor) OK [01973.540] 01115.01354> devcoordinator: launch /boot/bin/netsvc (netsvc) OK [01973.541] 01115.01354> devcoordinator: launch /boot/bin/virtual-console (virtual-console) OK [01973.544] 01115.01130> devcoordinator: full system required, ignoring fallback drivers until /system is loaded [01973.544] 01115.01130> devcoordinator: launch devhost 'devhost:sys': pid=2194 [01973.545] 01115.01130> devcoordinator: launch devhost 'devhost:test': pid=2226 [01973.545] 01115.01130> devcoordinator: launch devhost 'devhost:root': pid=2279 [01973.546] 01115.01130> devcoordinator: launch devhost 'devhost:misc': pid=2332 [01973.546] 02194.02208> devhost: trace provider registry begun [01973.547] 02226.02248> devhost: trace provider registry begun [01973.547] 02279.02310> devhost: trace provider registry begun [01973.548] 02332.02397> devhost: trace provider registry begun [01973.549] 01115.01335> devcoordinator: launch /boot/bin/sh (sh:console) OK [01973.633] 02194.02208> acpi-bus: not using IOMMU [01973.640] 02194.02208> PMU: 7 arch events [01973.640] 02194.02208> PMU: arch event id range: 1-7 [01973.640] 02194.02208> PMU: 102 arch events [01973.640] 02194.02208> PMU: arch event id range: 1-241 [01973.640] 02194.02208> Intel Processor Trace configuration for this chipset: [01973.640] 02194.02208> mtc_freq_mask: 0x249 [01973.640] 02194.02208> cyc_thresh_mask: 0x3fff [01973.640] 02194.02208> psb_freq_mask: 0x3f [01973.640] 02194.02208> num addr ranges: 2 [01973.641] 02194.02208> [sysmem_init 28] async_get_default_dispatcher(): 0x75f9195f2f10 [01973.641] 02194.02208> [sysmem_bind 40] sysmem_bind() [01973.641] 02194.02888> acpi-pwrbtn: initialized [01973.644] 01706.01750> vc: new input device /dev/class/input/000 [01973.672] 02194.02888> acpi: published device pci(0x75f85964aeb0), parent=sys(0x75f9995f1c10), handle=0x75f819604610 [01973.672] 01115.01130> devcoordinator: launch devhost 'devhost:pci#1:8086:5916': pid=2984 [01973.673] 01115.01130> devcoordinator: launch devhost 'devhost:pci#3:8086:9d2f': pid=3037 [01973.673] 02984.02998> devhost: trace provider registry begun [01973.674] 01115.01130> devcoordinator: launch devhost 'devhost:pci#5:8086:9d60': pid=3160 [01973.674] 03037.03060> devhost: trace provider registry begun [01973.675] 01115.01130> devcoordinator: launch devhost 'devhost:pci#6:8086:9d61': pid=3252 [01973.675] 02194.02888> acpi: published device rtc(0x75f859607050), parent=acpi(0x75f9995f1910), handle=0x75f81962a050 [01973.675] 03160.03174> devhost: trace provider registry begun [01973.676] 02194.02888> acpi-ec: initialized [01973.677] 03252.03273> devhost: trace provider registry begun [01973.677] 01115.01130> devcoordinator: launch devhost 'devhost:pci#9:8086:9d03': pid=3416 [01973.677] 01115.01130> devcoordinator: launch devhost 'devhost:pci#14:8086:9d71': pid=3523 [01973.678] 03416.03437> devhost: trace provider registry begun [01973.678] 01115.01130> devcoordinator: launch devhost 'devhost:pci#16:8086:156f': pid=3600 [01973.680] 02194.02888> acpi: failed to create NHLT VMO (res -10) [01973.680] 02194.02888> acpi: failed to publish NHLT metadata [01973.681] 03160.03174> initialized intel serialio i2c driver, reg=0x6f65067e5000 regsize=4096 [01973.682] 03523.03544> devhost: trace provider registry begun [01973.682] 03600.03639> devhost: trace provider registry begun [01973.685] 03416.03437> ahci: using MSI interrupt [01973.686] 03252.03273> initialized intel serialio i2c driver, reg=0x3e7b86d2b000 regsize=4096 [01973.688] 03037.03921> * found USB device (0x18d1:0xa002, USB 2.0) config 1 [01973.688] 03037.03921> * found USB device (0x18d1:0xa003, USB 3.0) config 1 [01973.689] 03523.03544> [IHDA DSP 00:1f.3] Failed to fetch NHLT (res -25) [01973.689] 03523.03544> [IHDA Controller 00:1f.3] Failed to initialize DSP device (res = -25) [01973.761] 01618.01644> netifc: ? /dev/class/ethernet/000 [01973.761] 01618.01644> netifc: create 512 eth buffers [01973.761] 01618.01644> macaddr: d4:5d:df:07:5e:3f [01973.761] 01618.01644> ip6addr: fe80::d65d:df4d:fe07:5e3f [01973.761] 01618.01644> snmaddr: ff02::1:ff07:5e3f [01973.761] 01618.01644> netsvc: using /dev/class/ethernet/000 [01973.762] 01618.01644> netsvc: nodename='upper-aroma-clock-plot' [01973.762] 01618.01644> netsvc: start [01973.788] 01706.01750> vc: new display device /dev/class/display-controller/000 [01973.828] 02984.04252> i915: Found DP monitor [01973.828] 02984.04252> i915: Display 1 connected [01973.829] 02984.04252> i915: MST not supported [01974.887] 01706.01750> vc: Successfully attached to display 1 [01975.151] 03037.03921> * found USB device (0x0781:0x5571, USB 2.0) config 1 [01975.401] 03037.03921> * found USB device (0x8087:0x0a2b, USB 2.0) config 1 [01975.688] 03160.03174> intel-i2c-controller: intel_serialio_i2c_slave_transfer: -21 [01975.688] 03160.03174> i2c-hid: could not read HID descriptor: 0 [01975.688] 03160.03174> devhost[00:15.0/i2c-bus-9d60/0020] bind driver '/boot/driver/i2c-hid.so' failed: -2 [01975.688] 01115.01130> devcoordinator: rpc: bind-driver '0020' status -2 [01975.688] 03252.03273> intel-i2c-controller: intel_serialio_i2c_slave_transfer: -21 [01975.688] 03252.03273> i2c-hid: could not read HID descriptor: 0 [01975.688] 03252.03273> devhost[00:15.1/i2c-bus-9d61/004c] bind driver '/boot/driver/i2c-hid.so' failed: -2 [01975.689] 01115.01130> devcoordinator: rpc: bind-driver '004c' status -2 [01975.699] 03416.03910> sata2: dev info [01975.699] 03416.03910> serial=715400411010 2 [01975.699] 03416.03910> firmware rev=1P11A1E_ [01975.700] 03416.03910> model id=IBIW NSS D [01975.700] 03416.03910> major=0x3f0 ACS2 DMA 32 commands [01975.700] 03416.03910> LBA48 250069680 sectors, sector size=512 [01975.700] 01301.01315> fshost: /dev/class/block/000: GPT? [01975.700] 03416.03437> gpt: device_get_metadata failed (-25) [01975.701] 01301.01315> fshost: /dev/class/block/001: FVM? [01975.704] 01301.01315> devcoordinator: launch /boot/bin/blobfs (blobfs:/blob) OK [01975.842] 01301.01315> fshost: starting 'bin/pkgsvr' '5095c5f7760713e79a1baca58fdd836e7c65d30362f6b56214d40f9647ecce31'... [01975.849] 01301.01315> devcoordinator: launch bin/pkgsvr (pkgfs) OK [01975.861] 04662.04872> pkgsvr: system: will be served from 5095c5f7760713e79a1baca58fdd836e7c65d30362f6b56214d40f9647ecce31 [01975.861] 04662.04872> pkgsvr: pkgfs serving index /data/pkgfs_index from blobfs /blob [01975.861] 01301.01315> fshost: /dev/class/block/005: zxcrypt? [01975.861] 03416.03437> devhost_get_handles(0x37b4c3b29410:block) open path='zxcrypt', r=-2 [01975.864] 01301.01315> fshost: mounting minfs [01975.867] 01115.01756> devcoordinator: launch /system/bin/appmgr (appmgr) OK [01975.867] 01115.01756> autorun: starting '/boot/bin/sh' '/boot/infra/runcmds'... [01975.887] 01115.04917> devcoordinator: adding system driver 'ralink' '/system/driver/ralink.so' [01975.888] 01115.01756> devcoordinator: launch /boot/bin/sh (autorun:system) OK [01975.893] 01115.04917> devcoordinator: adding system driver 'magma_pdev_gpu' '/system/driver/libmsd_arm.so' [01975.897] 01301.01315> devcoordinator: launch /boot/bin/minfs (minfs:/data) OK [01975.914] 01115.04917> devcoordinator: adding system driver 'qmi_usb' '/system/driver/qmi-transport.so' [01975.931] 01115.04917> devcoordinator: adding system driver 'usb_video' '/system/driver/usb_video.so' [01975.939] 01115.04917> devcoordinator: adding system driver 'wlan' '/system/driver/wlanphy.so' [01975.944] 01115.04917> devcoordinator: adding system driver 'bt_hci_fake' '/system/driver/bt-hci-fake.so' [01975.949] 01115.04917> devcoordinator: adding system driver 'bt_hci_intel' '/system/driver/bt-hci-intel.so' [01975.951] 01115.04917> devcoordinator: adding system driver 'ath10k_pci' '/system/driver/ath10k.so' [01975.955] 01115.04917> devcoordinator: adding system driver 'bt_hci_atheros' '/system/driver/bt-hci-atheros.so' [01975.977] 01115.04917> devcoordinator: adding system driver 'wlan' '/system/driver/wlan.so' [01975.980] 01115.04917> devcoordinator: adding system driver 'rtl88xx' '/system/driver/rtl88xx.so' [01975.985] 01115.04917> devcoordinator: adding system driver 'virtual_camera' '/system/driver/virtual_camera_driver.so' [01975.989] 01115.04917> devcoordinator: adding system driver 'brcmfmac' '/system/driver/brcmfmac.so' [01976.002] 01115.04917> devcoordinator: adding system driver 'bt_host' '/system/driver/bt-host.so' [01976.005] 01115.04917> devcoordinator: adding system driver 'qmi_fake' '/system/driver/qmi-fake.so' [01976.006] 01115.04917> devcoordinator: adding system driver 'bt_hog' '/system/driver/bt-hog.so' [01976.010] 05077.05091> [INFO:namespace_builder.cc(93)] config-data for sysmgr [01976.018] 01115.04917> devcoordinator: adding system driver 'mt8167s_gpu' '/system/driver/libmsd_img_rgx_mtk.so' [01976.019] 01115.04917> devcoordinator: adding system driver 'bt_hci_passthrough' '/system/driver/bt-hci-passthrough.so' [01976.022] 01115.04917> devcoordinator: adding system driver 'wlan' '/system/driver/wlanif.so' [01976.023] 01115.04917> devcoordinator: adding system driver 'iwlwifi_pci' '/system/driver/iwlwifi.so' [01976.028] 01115.04917> devcoordinator: adding system driver 'gpu' '/system/driver/libmsd_intel.so' [01976.032] 01115.04917> devcoordinator: adding system driver 'virtual_audio' '/system/driver/virtual_audio_driver.so' [01976.033] 01115.01130> devcoordinator: driver 'gpu' added [01976.033] 01115.01130> devcoordinator: driver 'iwlwifi_pci' added [01976.033] 01115.01130> devcoordinator: driver 'wlan' added [01976.033] 01115.01130> devcoordinator: driver 'mt8167s_gpu' added [01976.033] 01115.01130> devcoordinator: driver 'bt_hog' added [01976.033] 01115.01130> devcoordinator: driver 'qmi_fake' added [01976.033] 01115.01130> devcoordinator: driver 'bt_host' added [01976.033] 01115.01130> devcoordinator: driver 'brcmfmac' added [01976.033] 01115.01130> devcoordinator: driver 'rtl88xx' added [01976.033] 01115.01130> devcoordinator: driver 'wlan' added [01976.033] 01115.01130> devcoordinator: driver 'bt_hci_atheros' added [01976.033] 01115.01130> devcoordinator: driver 'ath10k_pci' added [01976.033] 01115.01130> devcoordinator: driver 'bt_hci_intel' added [01976.033] 01115.01130> devcoordinator: driver 'bt_hci_fake' added [01976.033] 01115.01130> devcoordinator: driver 'wlan' added [01976.033] 01115.01130> devcoordinator: driver 'usb_video' added [01976.033] 01115.01130> devcoordinator: driver 'qmi_usb' added [01976.033] 01115.01130> devcoordinator: driver 'magma_pdev_gpu' added [01976.033] 01115.01130> devcoordinator: driver 'ralink' added [01976.033] 01115.01130> devcoordinator: driver 'bt_hci_passthrough' added [01976.033] 01115.01130> devcoordinator: fallback driver 'usb_composite' is available [01976.033] 01115.01130> devcoordinator: driver 'usb_composite' added [01976.033] 01115.01130> devcoordinator: fallback driver 'intel_disp' is available [01976.033] 01115.01130> devcoordinator: driver 'intel_disp' added [01976.036] 03037.03060> UMS: parent: 'ifc-000' [01976.036] 03037.03060> UMS:Max lun is: 0 [01976.037] 03037.03060> devhost[00:14.0/xhci/usb-bus/002/002/ifc-001] bind driver '/boot/driver/bt-transport-usb.so' failed: -2 [01976.037] 01115.01130> devcoordinator: rpc: bind-driver 'ifc-001' status -2 [01976.038] 03037.06120> UMS: block size is: 0x00000200 [01976.038] 03037.06120> UMS: total blocks is: 15630336 [01976.038] 03037.06120> UMS: total size is: 8002732032 [01976.038] 03037.06120> UMS: read-only: 0 removable: 1 [01976.074] 03037.06426> btintel: firmware already loaded [01976.074] 03037.06435> hci_read_thread: failed to read from command channel ZX_ERR_PEER_CLOSED [01976.074] 03037.06435> hci_read_thread: failed to read from ACL channel ZX_ERR_PEER_CLOSED [01976.074] 03037.06435> bt-transport-usb: all channels closed - exiting [01976.074] 03037.06611> [INFO:command_channel.cc(149)] hci: initialized [01976.075] 01301.01315> fshost: /dev/class/block/007: MBR? [01976.078] 01301.01315> fshost: /dev/class/block/009: MBR? [01976.095] 03037.06611> [INFO:acl_data_channel.cc(91)] hci: initialized [01976.097] 05077.05091> [INFO:namespace_builder.cc(93)] config-data for amber [01976.144] 05077.05091> [INFO:namespace_builder.cc(93)] config-data for pkg_resolver [01976.210] 08351.08363> [INFO:cobalt_main.cc(219)] Cobalt is starting with the following parameters: schedule_interval=3600 seconds, min_interval=10 seconds, initial_interval=60 seconds, max_bytes_per_observation_store=1048576, event_aggregator_bac [01976.210] 08351.08363> kfill_days=2, start_event_aggregator_worker=1. [01976.237] 05077.05091> [INFO:namespace_builder.cc(93)] config-data for mdns [01976.278] 05077.05091> [INFO:namespace_builder.cc(93)] config-data for wlancfg [01976.384] 05077.05091> [INFO:namespace_builder.cc(93)] config-data for crashpad_agent [01976.415] 09798.09810> [INFO:system_metrics_main.cc(23)] Cobalt SystemMetricsDaemon: System metrics daemon created. [01976.418] 11289.11301> [INFO:main.cc(35)] Trace Manager starting with config: /pkg/data/tracing.config [01976.433] 03037.06611> [WARN:bredr_discovery_manager.cc(482)] gap-bredr: write inquiry scan activity failed: [status: invalid HCI command parameters (HCI 0x12)] [01976.471] 11956.11973> wlanstack2 [I]: Starting [01976.502] 08885.08897> Starting mDNS on interface ethp001f6 [80fe::5dd6:ffdf:7fe:3f5e] [01976.503] 08885.08897> [WARNING:garnet/bin/mdns/service/mdns_interface_transceiver_v6.cc(29)] NET-291 IPV6_MULTICAST_LOOP not supported (ENOPROTOOPT), continuing anyway [01976.503] 08885.08897> [WARNING:garnet/bin/mdns/service/mdns_interface_transceiver_v6.cc(50)] NET-2180 IPV6_JOIN_GROUP returned ENODEV, mDNS will not communicate via IPV6 [01976.558] 05077.05091> [WARNING:garnet/bin/appmgr/service_provider_dir_impl.cc(127)] Component fuchsia-pkg://fuchsia.com/vulkan_is_supported#meta/vulkan_is_supported.cmx is not allowed to connect to fuchsia.tracelink.Registry because this service [01976.558] 05077.05091> is not present in the component's sandbox. [01976.558] 05077.05091> Refer to https://fuchsia.googlesource.com/fuchsia/+/master/docs/the-book/sandboxing.md#services for more information. [01976.559] 08885.08897> Starting mDNS on interface ethp001f6 192.168.42.118 [01976.560] 08885.08897> [WARNING:garnet/bin/mdns/service/mdns_interface_transceiver_v4.cc(68)] NET-2177 IP_TTL not supported (ENOPROTOOPT), continuing anyway. May cause spurious IP traffic [01976.560] 08885.08897> Starting mDNS on interface ethp001f6 [80fe::5dd6:ffdf:7fe:3f5e] [01976.565] 08885.08897> [WARNING:garnet/bin/mdns/service/mdns_interface_transceiver_v6.cc(29)] NET-291 IPV6_MULTICAST_LOOP not supported (ENOPROTOOPT), continuing anyway [01976.565] 08885.08897> [WARNING:garnet/bin/mdns/service/mdns_interface_transceiver_v6.cc(50)] NET-2180 IPV6_JOIN_GROUP returned ENODEV, mDNS will not communicate via IPV6 [01976.565] 08885.08897> mDNS: Verifying uniqueness of host name upper-aroma-clock-plot.local. [01976.568] 10908.10922> [INFO:benchmarks.cc(24)] Graphics performance tests disabled [01976.568] 10908.10922> [INFO:benchmarking.cc(173)] writing summary.json to /tmp/infra-test-output/summary.json [01977.497] 08885.08897> mDNS: Using unique host name upper-aroma-clock-plot.local. DEBUG: reading "summary.json" DEBUG: copying test output DEBUG: tarring test output... [02025.743] 01618.01644> netsvc: tftp read of file /tmp/infra-test-output/summary.json completed [02025.743] 01618.01644> netsvc: metrics: {"inorderblks": 0,"oooblks": 0,"ack": 0,"nack": 0,"timeouts": 0,"sas": 0,"inorderbytes": 0}