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

DEBUG: config flag: /etc/botanist/config.json DEBUG: waiting for "summary.json" 2019/04/15 15:11:20 attempting to send <<netboot>>cmdline... 2019/04/15 15:11:20 done 2019/04/15 15:11:20 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 0x7ffff000 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.212] 00000.00000> timer features: constant_tsc 1 invariant_tsc 1 tsc_deadline 1 [00020.212] 00000.00000> Using TSC as wallclock [00020.212] 00000.00000> initializing kernel [00020.212] 00000.00000> initializing mp [00020.212] 00000.00000> initializing timers [00020.212] 00000.00000> INIT: cpu 0, calling hook 0xffffffff0013c578 (debuglog) at level 0x7ffff, flags 0x1 [00020.212] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00195518 (thread_set_priority_experiment) at level 0x7ffff, flags 0x1 [00020.212] 00000.00000> thread set priority experiment is : ENABLED [00020.212] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001aa67c (global_prng_thread_safe) at level 0x7ffff, flags 0x1 [00020.212] 00000.00000> creating bootstrap completion thread [00020.554] 00000.00000> top of bootstrap2() [00020.554] 00000.00000> INIT: cpu 0, calling hook 0xffffffff0013151c (dpc) at level 0x80000, flags 0x1 [00020.568] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00152978 (libobject) at level 0x80000, flags 0x1 [00020.568] 00000.00000> OOM: started thread [00020.581] 00000.00000> Processor Model Info: type 0 family 0x6 model 0xe stepping 0x9 [00020.581] 00000.00000> display_family 0x6 display_model 0x8e [00020.581] 00000.00000> Vendor: Intel [00020.581] 00000.00000> Microarch: Kaby Lake [00020.581] 00000.00000> F/M/S: 6/8e/9 [00020.581] 00000.00000> Brand: Intel(R) Core(TM) i5-7300U CPU @ 2.60GHz [00020.581] 00000.00000> Features: fpu sse sse2 sse3 ssse3 sse4.1 sse4.2 mmx avx avx2 fxsr pcid xsave mon aesni clflush [00020.581] 00000.00000> clflushopt fsgsbase tsc_adj smep smap erms rdrand rdseed syscall nx huge rdtscp [00020.581] 00000.00000> invar_tsc tsc_deadline x2apic vmx pt hwp [00020.581] 00000.00000> initializing platform [00020.581] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001101f4 (x86_perfmon) at level 0x90000, flags 0x1 [00020.581] 00000.00000> PMU: version 4 [00020.581] 00000.00000> UART: started IRQ driven RX [00020.581] 00000.00000> UART: started IRQ driven TX [00020.581] 00000.00000> cpu topology: [00020.581] 00000.00000> 0: apic id 0x0 package 0 node 0 core 0 smt 0 BSP [00020.581] 00000.00000> 1: apic id 0x2 package 0 node 0 core 1 smt 0 [00020.581] 00000.00000> 2: apic id 0x1 package 0 node 0 core 0 smt 1 [00020.581] 00000.00000> 3: apic id 0x3 package 0 node 0 core 1 smt 1 [00020.581] 00000.00000> Found 4 cpus [00020.581] 00000.00000> booting apic ids: 0x2 0x1 0x3 [00020.597] 00000.00000> entering scheduler on cpu 2 [00020.598] 00000.00000> entering scheduler on cpu 1 [00020.598] 00000.00000> entering scheduler on cpu 3 [00020.601] 00000.00000> smbios: manufacturer="Intel Corporation" product="NUC7i5DNKE" [00020.601] 00000.00000> initializing target [00020.601] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001053a0 (x86_pcie_init) at level 0xa0000, flags 0x1 [00020.601] 00000.00000> moving to last init level [00020.601] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00144140 (ktrace) at level 0xc0000, flags 0x1 [00020.605] 00000.00000> ktrace: buffer at 0xffffff94cb498000 (33554432 bytes) [00020.605] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00147ab4 (userboot) at level 0xc0000, flags 0x1 [00020.605] 00000.00000> userboot: ramdisk 0x10ad000 @ 0xffffff80012f2000 [00020.605] 00000.00000> userboot: userboot rodata 0 @ [0x5b601a5f0000,0x5b601a5f3000) [00020.605] 00000.00000> userboot: userboot code 0x3000 @ [0x5b601a5f3000,0x5b601a5fe000) [00020.605] 00000.00000> userboot: vdso/full rodata 0 @ [0x5b601a5fe000,0x5b601a605000) [00020.605] 00000.00000> userboot: vdso/full code 0x7000 @ [0x5b601a605000,0x5b601a606000) [00020.605] 00000.00000> userboot: entry point @ 0x5b601a5f3c10 [00020.605] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001aa030 (kernel_shell) at level 0xc0000, flags 0x1 [00020.605] 01036.01043> userboot: option "netsvc.disable=true" [00020.605] 01036.01043> userboot: option "zircon.system.disable-automount=true" [00020.605] 01036.01043> userboot: option "zircon.autorun.boot=/boot/infra/setup" [00020.605] 01036.01043> userboot: option "kernel.serial=legacy" [00020.605] 01036.01043> userboot: option "http://192.168.42.1/multiboot/d4%3A5d%3Adf%3A07%3A59%3Ac7=" [00020.605] 01036.01043> userboot: option "multiboot.boot_loader_name=iPXE+1.0.0++(d2063)" [00020.644] 01036.01043> userboot: searching bootfs for 'bin/bootsvc' [00020.644] 01036.01043> userboot: 'bin/bootsvc' has PT_INTERP "lib/ld.so.1" [00020.644] 01036.01043> userboot: searching bootfs for 'lib/ld.so.1' [00020.644] 01036.01043> userboot: userboot: loaded lib/ld.so.1 at 0x71fb9d62b000, entry point 0x71fb9d6b10d3 [00020.644] 01036.01043> userboot: userboot: loaded vDSO at 0x5d59ac062000, entry point 0x0 [00020.644] 01036.01043> userboot: process bin/bootsvc started. [00020.644] 01036.01043> userboot: waiting for loader-service requests... [00020.644] 01036.01043> userboot: searching bootfs for 'lib/libasync-default.so' [00020.644] 01036.01043> userboot: searching bootfs for 'lib/libfdio.so' [00020.644] 01036.01043> userboot: searching bootfs for 'lib/liblaunchpad.so' [00020.644] 01036.01043> userboot: searching bootfs for 'lib/libtrace-engine.so' [00020.644] 01050.01053> {{{reset}}} [00020.644] 01050.01053> {{{module:0:<application>:elf:18de7d58f51e8ba5c4f6afdd0cc8440f482c2b45}}} [00020.644] 01050.01053> {{{mmap:0x82457c6f000:0x2e000:load:0:rx:0}}} [00020.644] 01050.01053> {{{mmap:0x82457c9d000:0x4000:load:0:rw:0x2e000}}} [00020.644] 01050.01053> dso: id=18de7d58f51e8ba5c4f6afdd0cc8440f482c2b45 base=0x0000082457c6f000 name=<application> [00020.644] 01050.01053> {{{module:0x3:libasync-default.so:elf:c189f51f19d10785d93b5235ad1b46dca4451b00}}} [00020.644] 01050.01053> {{{mmap:0x5eabe8c10000:0x1000:load:0x3:rx:0}}} [00020.644] 01050.01053> {{{mmap:0x5eabe8c11000:0x1000:load:0x3:rw:0x1000}}} [00020.644] 01050.01053> dso: id=c189f51f19d10785d93b5235ad1b46dca4451b00 base=0x00005eabe8c10000 name=libasync-default.so [00020.644] 01050.01053> {{{module:0x2:<vDSO>:elf:40ab5fa3b61f12fef4a44477a687f608661cd450}}} [00020.644] 01050.01053> {{{mmap:0x5d59ac062000:0x7000:load:0x2:r:0}}} [00020.644] 01050.01053> {{{mmap:0x5d59ac069000:0x1000:load:0x2:rx:0x7000}}} [00020.644] 01050.01053> dso: id=40ab5fa3b61f12fef4a44477a687f608661cd450 base=0x00005d59ac062000 name=<vDSO> [00020.644] 01050.01053> {{{module:0x1:libc.so:elf:67a12284bce140fc32aaaeac223e0e8f85cb5085}}} [00020.644] 01050.01053> {{{mmap:0x71fb9d62b000:0xcb000:load:0x1:rx:0}}} [00020.645] 01050.01053> {{{mmap:0x71fb9d6f7000:0x6000:load:0x1:rw:0xcc000}}} [00020.645] 01050.01053> dso: id=67a12284bce140fc32aaaeac223e0e8f85cb5085 base=0x000071fb9d62b000 name=libc.so [00020.645] 01050.01053> {{{module:0x4:libfdio.so:elf:27787977e95f3b9563c9e0bd4d34ec92b7e9ad88}}} [00020.645] 01050.01053> {{{mmap:0x177c676d3000:0x24000:load:0x4:rx:0}}} [00020.645] 01050.01053> {{{mmap:0x177c676f8000:0x4000:load:0x4:rw:0x25000}}} [00020.645] 01050.01053> dso: id=27787977e95f3b9563c9e0bd4d34ec92b7e9ad88 base=0x0000177c676d3000 name=libfdio.so [00020.645] 01050.01053> {{{module:0x5:liblaunchpad.so:elf:6fc2232dc8c1bc5c6adb8ad50ca794b5a260ee4f}}} [00020.645] 01050.01053> {{{mmap:0x4bee023eb000:0x7000:load:0x5:rx:0}}} [00020.645] 01050.01053> {{{mmap:0x4bee023f2000:0x2000:load:0x5:rw:0x7000}}} [00020.645] 01050.01053> dso: id=6fc2232dc8c1bc5c6adb8ad50ca794b5a260ee4f base=0x00004bee023eb000 name=liblaunchpad.so [00020.645] 01050.01053> {{{module:0x6:libtrace-engine.so:elf:c9042b83fe01206008fcefb16395238417248169}}} [00020.645] 01050.01053> {{{mmap:0x6beab3d71000:0x9000:load:0x6:rx:0}}} [00020.645] 01050.01053> {{{mmap:0x6beab3d7a000:0x2000:load:0x6:rw:0x9000}}} [00020.645] 01050.01053> dso: id=c9042b83fe01206008fcefb16395238417248169 base=0x00006beab3d71000 name=libtrace-engine.so [00020.645] 01050.01053> bootsvc: Starting... [00020.645] 01036.01043> userboot: loader-service channel peer closed [00020.645] 01036.01043> userboot: finished! [00020.645] 01050.01053> bootsvc: Creating bootfs service... [00020.645] 01050.01053> bootsvc: Processing bootdata... [00020.645] 01050.01053> bootsvc: Loading boot cmdline overrides... [00020.645] 01050.01053> bootsvc: Loading kernel VMOs... [00020.645] 01050.01053> bootsvc: Creating loader service... [00020.645] 01050.01053> bootsvc: Launching next process... [00020.646] 01050.01096> bootsvc: launched bin/devmgr [00020.646] 01104.01117> devmgr: main() [00020.646] 01104.01117> cmdline: netsvc.disable=true [00020.646] 01104.01117> cmdline: zircon.system.disable-automount=true [00020.646] 01104.01117> cmdline: zircon.autorun.boot=/boot/infra/setup [00020.646] 01104.01117> cmdline: kernel.serial=legacy [00020.646] 01104.01117> cmdline: http://192.168.42.1/multiboot/d4%3A5d%3Adf%3A07%3A59%3Ac7= [00020.646] 01104.01117> cmdline: multiboot.boot_loader_name=iPXE+1.0.0++(d2063) [00020.646] 01104.01117> devmgr: coordinator_init() [00020.646] 01104.01117> devmgr: init [00020.646] 01104.01117> devmgr: svc init [00020.646] 01104.01117> devmgr: launch /boot/bin/svchost (svchost) OK [00020.646] 01104.01117> devmgr: vfs init [00020.647] 01104.01117> devmgr: launch /boot/bin/fshost (fshost) OK [00020.647] 01104.01222> devmgr: shell startup [00020.648] 01182.01202> fshost: started. [00020.649] 01104.01213> devmgr: launch /boot/bin/pwrbtn-monitor (pwrbtn-monitor) OK [00020.649] 01104.01232> devmgr: launch /boot/bin/virtual-console (virtual-console) OK [00020.649] 01104.01232> zircon.autorun.boot: starting '/boot/infra/setup'... [00020.650] 01104.01232> devmgr: launch /boot/infra/setup (autorun:boot) OK [00020.652] 01104.01117> devcoord: launch devhost 'devhost:sys': pid=2049 [00020.653] 01104.01117> devcoord: launch devhost 'devhost:test': pid=2082 [00020.653] 01104.01117> devcoord: launch devhost 'devhost:root': pid=2114 [00020.653] 01104.01117> devcoord: launch devhost 'devhost:misc': pid=2171 [00020.654] 02049.02073> devhost: trace provider registry begun [00020.655] 02114.02154> devhost: trace provider registry begun [00020.655] 02082.02105> devhost: trace provider registry begun [00020.656] 02171.02224> devhost: trace provider registry begun [00020.658] 01104.01222> devmgr: launch /boot/bin/sh (sh:console) OK [00020.714] 02049.02073> acpi-bus: not using IOMMU [00020.718] 02049.02073> acpi-pwrbtn: initialized [00020.724] 02049.02073> WARNING: ACPI found bad _CRS address entry [00020.730] 02049.02073> WARNING: ACPI found bad _CRS address entry [00020.741] 02049.02073> acpi: published device pci(0xecb28ca5200), parent=proxy(0xecb28ca1540), handle=0xecb28cddc30 [00020.742] 02049.02073> acpi: published device rtc(0xecb28ca0080), parent=acpi(0xecb28ca1780), handle=0xecb28cf65b0 [00020.743] 02049.02073> acpi-ec: initialized [00020.744] 02049.02073> acpi: failed to create NHLT VMO (res -10) [00020.744] 02049.02073> acpi: failed to publish NHLT metadata [00020.747] 02049.02073> [sysmem_init 28] async_get_default_dispatcher(): 0xecb28c940a0 [00020.747] 02049.02073> [sysmem_bind 40] sysmem_bind() [00020.747] 02049.02073> acpi-bus: sysmem_register_protocol() intentionally ignored for now. [00020.747] 02049.02073> PMU: 7 arch events [00020.747] 02049.02073> PMU: arch event id range: 1-7 [00020.747] 02049.02073> PMU: 102 model events [00020.747] 02049.02073> PMU: model event id range: 1-241 [00020.747] 02049.02073> Intel Processor Trace configuration for this chipset: [00020.747] 02049.02073> mtc_freq_mask: 0x249 [00020.747] 02049.02073> cyc_thresh_mask: 0x3fff [00020.747] 02049.02073> psb_freq_mask: 0x3f [00020.747] 02049.02073> num addr ranges: 2 [00020.747] 01104.01117> devcoord: launch devhost 'devhost:pci#1:8086:5916': pid=2842 [00020.747] 01104.01117> devcoord: launch devhost 'devhost:pci#3:8086:9d2f': pid=2889 [00020.748] 01104.01117> devcoord: launch devhost 'devhost:pci#5:8086:9d60': pid=2950 [00020.748] 02842.02865> devhost: trace provider registry begun [00020.749] 01104.01117> devcoord: launch devhost 'devhost:pci#6:8086:9d61': pid=3017 [00020.749] 02889.02923> devhost: trace provider registry begun [00020.749] 01104.01117> devcoord: launch devhost 'devhost:pci#9:8086:9d03': pid=3115 [00020.750] 03017.03073> devhost: trace provider registry begun [00020.750] 02950.02990> devhost: trace provider registry begun [00020.750] 01104.01117> devcoord: launch devhost 'devhost:pci#14:8086:9d71': pid=3226 [00020.751] 01104.01117> devcoord: launch devhost 'devhost:pci#16:8086:156f': pid=3320 [00020.751] 03115.03168> devhost: trace provider registry begun [00020.752] 03115.03168> ahci: using MSI interrupt [00020.753] 03226.03301> devhost: trace provider registry begun [00020.753] 02950.02990> initialized intel serialio i2c driver, reg=0x622395bbf000 regsize=4096 [00020.753] 03017.03073> initialized intel serialio i2c driver, reg=0x5e74a1a01000 regsize=4096 [00020.754] 03320.03368> devhost: trace provider registry begun [00020.769] 02889.03658> * found USB device (0x18d1:0xa002, USB 2.0) config 1 [00020.770] 01241.01570> vc: new input device /dev/class/input/000 [00020.770] 03226.03301> [IHDA DSP 00:1f.3] Failed to fetch NHLT (res -25) [00020.770] 03226.03301> devhost[00:1f.3/intel-hda-000/intel-sst-dsp-000] bind driver '/boot/driver/dsp.so' failed: -25 [00020.770] 01104.01117> devcoord: rpc: bind-driver 'intel-sst-dsp-000' status -25 [00020.778] 02889.03658> * found USB device (0x18d1:0xa003, USB 3.0) config 1 [00020.859] 01241.01570> vc: new display device /dev/class/display-controller/000/virtcon [00020.904] 03017.03477> i2c: tx abort detected: 0x05001000 [00020.904] 03017.03073> intel-i2c-controller: intel_serialio_i2c_slave_transfer: -40 [00020.904] 03017.03073> i2c-hid: could not read HID descriptor: 0 [00020.904] 03017.03073> devhost[00:15.1/i2c-bus-9d61/004c] bind driver '/boot/driver/i2c-hid.so' failed: -2 [00020.904] 01104.01117> devcoord: rpc: bind-driver '004c' status -2 [00020.999] 02842.04144> i915: MST not supported [00021.499] 02842.04144> i915: Found DP monitor [00021.499] 02842.04144> i915: Display 1 connected [00021.576] 01241.01570> vc: Successfully attached to display 1 [00022.240] 02889.03658> * found USB device (0x0781:0x5571, USB 2.0) config 1 [00022.241] 02889.02923> UMS: parent: 'ifc-000' [00022.241] 02889.02923> UMS:Max lun is: 0 [00022.491] 02889.03658> * found USB device (0x8087:0x0a2b, USB 2.0) config 1 [00022.492] 02889.02923> devhost[00:14.0/xhci/usb-bus/002/002/ifc-001] bind driver '/boot/driver/bt-transport-usb.so' failed: -2 [00022.492] 01104.01117> devcoord: rpc: bind-driver 'ifc-001' status -2 [00022.768] 02950.02990> intel-i2c-controller: intel_serialio_i2c_slave_transfer: -21 [00022.768] 02950.02990> i2c-hid: could not read HID descriptor: 0 [00022.768] 02950.02990> devhost[00:15.0/i2c-bus-9d60/0020] bind driver '/boot/driver/i2c-hid.so' failed: -2 [00022.768] 01104.01117> devcoord: rpc: bind-driver '0020' status -2 [00022.771] 03115.03663> sata2: dev info [00022.771] 03115.03663> serial=715400411011 4 [00022.771] 03115.03663> firmware rev=1P11A1E_ [00022.771] 03115.03663> model id=IBIW NSS D [00022.771] 03115.03663> major=0x3f0 ACS2 DMA 32 commands [00022.771] 03115.03663> LBA48 250069680 sectors, sector size=512 [00022.772] 04417.04431> paver:[InitializeGpt] Located GPT is invalid; Attempting to initialize [00022.773] 01104.01117> devcoord: dc_bind_device() '/boot/driver/gpt.so' [00022.773] 03115.03168> gpt: device_get_metadata failed (-25) [00022.774] 04417.04431> paver:[Initialize] Successfully initialized EFI Device Partitioner [00022.774] 01104.01117> devcoord: dc_bind_device() '' [00022.775] 01182.01202> devmgr: /dev/class/block/000: GPT? [00022.775] 01104.01117> devcoord: dc_bind_device() '/boot/driver/gpt.so' [00022.775] 03115.03168> gpt: device_get_metadata failed (-25) [00022.777] 04572.04589> 34+0 records in [00022.777] 04572.04589> 34+0 records out [00022.777] 04572.04589> 17408 bytes copied [00022.780] 04678.04692> 34+0 records in [00022.780] 04678.04692> 34+0 records out [00022.780] 04678.04692> 17408 bytes copied [00022.781] 04782.04796> netifc: ? /dev/class/ethernet/000 [00022.781] 04782.04796> netifc: create 512 eth buffers [00022.781] 04782.04796> macaddr: d4:5d:df:07:59:c7 [00022.781] 04782.04796> ip6addr: fe80::d65d:df4d:fe07:59c7 [00022.781] 04782.04796> snmaddr: ff02::1:ff07:59c7 [00022.781] 04782.04796> netsvc: using /dev/class/ethernet/000 [00022.781] 04782.04796> _ _ _ [00022.781] 04782.04796> | | | | | [00022.781] 04782.04796> _______ __| | |__ ___ ___ | |_ [00022.781] 04782.04796> |_ / _ \/ _` | '_ \ / _ \ / _ \| __| [00022.781] 04782.04796> / / __/ (_| | |_) | (_) | (_) | |_ [00022.781] 04782.04796> /___\___|\__,_|_.__/ \___/ \___/ \__| [00022.781] 04782.04796> [00022.781] 04782.04796> [00022.781] 04782.04796> zedboot: version: 0.7.13 [00022.781] 04782.04796> [00022.781] 04782.04796> netsvc: nodename='viral-jolly-clock-gloss' [00022.781] 04782.04796> netsvc: will not advertise [00022.781] 04782.04796> netsvc: start [00023.243] 02889.04250> UMS: block size is: 0x00000200 [00023.243] 02889.04250> UMS: total blocks is: 15630336 [00023.243] 02889.04250> UMS: total size is: 8002732032 [00023.243] 02889.04250> UMS: read-only: 0 removable: 1 [00023.244] 01182.01202> devmgr: /dev/class/block/001: MBR? [00023.244] 01104.01117> devcoord: dc_bind_device() '/boot/driver/mbr.so' [00023.247] 01182.01202> devmgr: /dev/class/block/003: MBR? [00023.247] 01104.01117> devcoord: dc_bind_device() '/boot/driver/mbr.so' [01901.055] 04782.04796> netsvc: handling tftp request failed (file might not exist) [01901.055] 04782.04796> netsvc: close, but no open file [01901.055] 04782.04796> netsvc: metrics: {"inorderblks": 0,"oooblks": 0,"ack": 0,"nack": 0,"timeouts": 0,"sas": 0,"inorderbytes": 0} [01901.056] 04782.04796> netsvc: tftp write of file <<netboot>>cmdline completed [01901.056] 04782.04796> netsvc: metrics: {"inorderblks": 1,"oooblks": 0,"ack": 1,"nack": 0,"timeouts": 0,"sas": 0,"inorderbytes": 55} [01901.056] 04782.04796> netsvc: Running FVM Paver [01901.059] 04782.04970> paver:[InitializeGpt] Located GPT is invalid; Attempting to initialize [01901.060] 01104.01117> devcoord: dc_bind_device() '' [01901.060] 01104.01117> devcoord: dc_bind_device() '/boot/driver/gpt.so' [01901.060] 03115.03168> gpt: device_get_metadata failed (-25) [01901.060] 01182.01202> devmgr: /dev/class/block/000: GPT? [01901.060] 01104.01117> devcoord: dc_bind_device() '/boot/driver/gpt.so' [01901.060] 03115.03168> devhost: rpc:bind-device failed: -20 [01901.060] 04782.04970> paver:[Initialize] Successfully initialized EFI Device Partitioner [01901.060] 04782.04970> paver:[PartitionPave] Paving partition. [01901.060] 04782.04970> paver:[FindFirstFit] Looking for space [01901.060] 04782.04970> paver:[FindFirstFit] Sorting [01901.060] 04782.04970> paver:[FindFirstFit] Partition[0] From Block [0, 34) ... (next partition starts at block 250069646) [01901.060] 04782.04970> paver:[FindFirstFit] There are 250069612 free blocks (16777216 requested) [01901.060] 04782.04970> paver:[AddPartition] Found space in GPT - OK 250069612 @ 34 [01901.060] 04782.04970> paver:[AddPartition] Final space in GPT - OK 16777216 @ 34 [01901.061] 04782.04970> paver:[AddPartition] Added partition, waiting for bind [01901.061] 01104.01117> devcoord: dc_bind_device() '' [01901.061] 01182.01202> devmgr: /dev/class/block/000: GPT? [01901.061] 01104.01117> devcoord: dc_bind_device() '/boot/driver/gpt.so' [01901.061] 03115.03168> gpt: device_get_metadata failed (-25) [01901.061] 04782.04970> paver:[AddPartition] Added partition, waiting for bind - OK [01901.061] 04782.04970> paver:[PartitionPave] Streaming partitions... [01901.061] 04950.04964> Found compressed file [01901.061] 04782.04970> paver:[FvmStreamPartitions] Header Validated - OK [01901.062] 04782.04970> paver:[FvmPartitionFormat] Initializing partition as FVM [01901.064] 01104.01117> devcoord: dc_bind_device() '/boot/driver/fvm.so' [01902.066] 04782.04970> paver:[FvmStreamPartitions] Partitions pre-validated successfully: Enough space exists to pave. [01902.066] 04782.04970> paver:[AllocatePartitions] Allocating partition blobfs consisting of 1 slices [01902.069] 04782.04970> paver:[AllocatePartitions] Allocating partition minfs consisting of 1 slices [01902.071] 04782.04970> paver:[AllocatePartitions] Creating zxcrypt volume [01902.072] 03115.03168> devhost_get_handles(0x499e42d409c0:block) open path='zxcrypt/block', r=-2 [01902.072] 01104.01117> devcoord: dc_bind_device() '/boot/driver/zxcrypt.so' [01902.072] 03115.03168> devhost_get_handles(0x499e42d409c0:block) open path='zxcrypt', r=-2 [01902.076] 04782.04970> paver:[FvmStreamPartitions] Partition space pre-allocated successfully. [01902.076] 04782.04970> paver:[FvmStreamPartitions] Streaming partition 0 [01902.076] 04782.04970> paver:[StreamFvmPartition] Writing extent 0... [01902.076] 04782.04976> netsvc: paver write progress 0.1% [01902.077] 04782.04970> paver:[StreamFvmPartition] 8192 bytes written, 8380416 zeroes left [01902.128] 04782.04970> paver:[StreamFvmPartition] Writing extent 1... [01902.129] 04782.04970> paver:[StreamFvmPartition] 8192 bytes written, 8380416 zeroes left [01902.183] 04782.04970> paver:[StreamFvmPartition] Writing extent 2... [01902.197] 04782.04970> paver:[StreamFvmPartition] 2097152 bytes written, 6291456 zeroes left [01902.237] 04782.04970> paver:[StreamFvmPartition] Writing extent 3... [01902.251] 04782.04970> paver:[StreamFvmPartition] 2097152 bytes written, 6291456 zeroes left [01902.292] 04782.04970> paver:[StreamFvmPartition] Writing extent 4... [01903.081] 04782.04976> netsvc: paver write progress 35.5% [01904.086] 04782.04976> netsvc: paver write progress 78.7% 2019/04/15 15:11:23 done 2019/04/15 15:11:23 attempting to send <<image>>efi.img... 2019/04/15 15:11:23 target is busy, retrying in one second [01904.348] 04782.04796> netsvc: tftp write of file <<image>>sparse.fvm completed [01904.348] 04782.04796> netsvc: metrics: {"inorderblks": 306454,"oooblks": 50,"ack": 1197,"nack": 50,"timeouts": 0,"sas": 0,"inorderbytes": 313808304} [01904.552] 04782.04970> paver:[StreamFvmPartition] 341630976 bytes written, 2301952 zeroes left [01904.567] 04782.04970> paver:[FvmStreamPartitions] Done streaming partition 0 [01904.567] 04782.04970> paver:[FvmStreamPartitions] Done flushing partition 0 [01904.567] 04782.04970> paver:[FvmStreamPartitions] Streaming partition 1 [01904.567] 04782.04970> paver:[StreamFvmPartition] Writing extent 0... [01904.569] 04782.04970> paver:[StreamFvmPartition] 8192 bytes written, 8380416 zeroes left [01904.623] 04782.04970> paver:[StreamFvmPartition] Writing extent 1... [01904.624] 04782.04970> paver:[StreamFvmPartition] 65536 bytes written, 8323072 zeroes left [01904.678] 04782.04970> paver:[StreamFvmPartition] Writing extent 2... [01904.679] 04782.04970> paver:[StreamFvmPartition] 65536 bytes written, 8323072 zeroes left [01904.732] 04782.04970> paver:[StreamFvmPartition] Writing extent 3... [01904.787] 04782.04970> paver:[StreamFvmPartition] Writing extent 4... [01904.801] 04782.04970> paver:[StreamFvmPartition] 2097152 bytes written, 14680064 zeroes left [01904.896] 04782.04970> paver:[StreamFvmPartition] Writing extent 5... [01904.898] 04782.04970> paver:[StreamFvmPartition] 57344 bytes written, 8331264 zeroes left [01904.951] 04782.04970> paver:[FvmStreamPartitions] Done streaming partition 1 [01904.951] 04782.04970> paver:[FvmStreamPartitions] Done flushing partition 1 [01904.953] 04950.04964> Reading FVM from compressed file: true [01904.953] 04950.04964> Remaining bytes read into compression buffer: 0 [01904.953] 04950.04964> Remaining bytes written to decompression buffer: 0 [01904.953] 04950.04964> Time reading bytes from sparse FVM file: 157496946 (0 s) [01904.953] 04950.04964> Time reading bytes AND decompressing them: 347200306 (0 s) [01904.953] 04782.04970> paver:[PartitionPave] Completed successfully 2019/04/15 15:11:24 attempting to send <<image>>efi.img... 2019/04/15 15:11:24 done 2019/04/15 15:11:24 attempting to send <<image>>kernc.img... 2019/04/15 15:11:24 target is busy, retrying in one second [01905.349] 04782.04796> netsvc: Running EFI Paver [01905.352] 04782.05846> paver:[Initialize] Successfully initialized EFI Device Partitioner [01905.352] 04782.05846> paver:[PartitionPave] Paving partition. [01905.352] 04782.05846> paver:[FindFirstFit] Looking for space [01905.352] 04782.05846> paver:[FindFirstFit] Partition seen with start 34, end 16777249 (length 16777216) [01905.352] 04782.05846> paver:[FindFirstFit] Sorting [01905.352] 04782.05846> paver:[FindFirstFit] Partition[0] From Block [0, 34) ... (next partition starts at block 34) [01905.352] 04782.05846> paver:[FindFirstFit] There are 0 free blocks (40960 requested) [01905.352] 04782.05846> paver:[FindFirstFit] Partition[1] From Block [34, 16777250) ... (next partition starts at block 250069646) [01905.352] 04782.05846> paver:[FindFirstFit] There are 233292396 free blocks (40960 requested) [01905.352] 04782.05846> paver:[AddPartition] Found space in GPT - OK 233292396 @ 16777250 [01905.352] 04782.05846> paver:[AddPartition] Final space in GPT - OK 40960 @ 16777250 [01905.353] 04782.05846> paver:[AddPartition] Added partition, waiting for bind [01905.353] 03115.03168> block: Joining un-closed FIFO server [01905.353] 03115.03168> block: Joining un-closed FIFO server [01905.353] 01104.01117> devcoord: dc_bind_device() '' [01905.353] 01182.01202> devmgr: /dev/class/block/000: GPT? [01905.353] 01104.01117> devcoord: dc_bind_device() '/boot/driver/gpt.so' [01905.354] 03115.03168> gpt: device_get_metadata failed (-25) [01905.354] 01182.01202> devmgr: /dev/class/block/008: FVM? [01905.354] 01104.01117> devcoord: dc_bind_device() '/boot/driver/fvm.so' [01905.354] 04782.05846> paver:[AddPartition] Added partition, waiting for bind - OK [01905.367] 04782.04796> netsvc: tftp write of file <<image>>efi.img completed [01905.367] 04782.04796> netsvc: metrics: {"inorderblks": 1093,"oooblks": 0,"ack": 5,"nack": 0,"timeouts": 0,"sas": 0,"inorderbytes": 1118208} [01905.370] 04782.05846> paver:[PartitionPave] Completed successfully 2019/04/15 15:11:25 attempting to send <<image>>kernc.img... [01906.368] 04782.04796> netsvc: Running KERN-C Paver [01906.371] 04782.06101> paver:[Initialize] Successfully initialized EFI Device Partitioner [01906.371] 04782.06101> paver:[RealMain] SKIPPING KERNC install on non-CROS device, pass --force if desired. 2019/04/15 15:11:26 done 2019/04/15 15:11:26 attempting to send <<image>>zircona.img... 2019/04/15 15:11:26 target is busy, retrying in one second [01906.502] 04782.04796> netsvc: tftp write of file <<image>>kernc.img completed [01906.502] 04782.04796> netsvc: metrics: {"inorderblks": 11605,"oooblks": 0,"ack": 46,"nack": 0,"timeouts": 0,"sas": 0,"inorderbytes": 11882496} 2019/04/15 15:11:27 attempting to send <<image>>zircona.img... [01907.503] 04782.04796> netsvc: Running ZIRCON-A Paver [01907.506] 04782.06230> paver:[Initialize] Successfully initialized EFI Device Partitioner [01907.506] 04782.06230> paver:[PartitionPave] Paving partition. [01907.506] 04782.06230> paver:[FindFirstFit] Looking for space [01907.506] 04782.06230> paver:[FindFirstFit] Partition seen with start 34, end 16777249 (length 16777216) [01907.506] 04782.06230> paver:[FindFirstFit] Partition seen with start 16777250, end 16818209 (length 40960) [01907.506] 04782.06230> paver:[FindFirstFit] Sorting [01907.506] 04782.06230> paver:[FindFirstFit] Partition[0] From Block [0, 34) ... (next partition starts at block 34) [01907.506] 04782.06230> paver:[FindFirstFit] There are 0 free blocks (32768 requested) [01907.506] 04782.06230> paver:[FindFirstFit] Partition[1] From Block [34, 16777250) ... (next partition starts at block 16777250) [01907.506] 04782.06230> paver:[FindFirstFit] There are 0 free blocks (32768 requested) [01907.506] 04782.06230> paver:[FindFirstFit] Partition[2] From Block [16777250, 16818210) ... (next partition starts at block 250069646) [01907.506] 04782.06230> paver:[FindFirstFit] There are 233251436 free blocks (32768 requested) [01907.506] 04782.06230> paver:[AddPartition] Found space in GPT - OK 233251436 @ 16818210 [01907.506] 04782.06230> paver:[AddPartition] Final space in GPT - OK 32768 @ 16818210 [01907.507] 04782.06230> paver:[AddPartition] Added partition, waiting for bind [01907.507] 03115.03168> block: Joining un-closed FIFO server [01907.507] 01104.01117> devcoord: dc_bind_device() '' [01907.507] 01182.01202> devmgr: /dev/class/block/000: GPT? [01907.507] 01104.01117> devcoord: dc_bind_device() '/boot/driver/gpt.so' [01907.507] 03115.03168> gpt: device_get_metadata failed (-25) [01907.508] 01182.01202> devmgr: /dev/class/block/012: FVM? [01907.508] 01104.01117> devcoord: dc_bind_device() '/boot/driver/fvm.so' [01907.508] 04782.06230> paver:[AddPartition] Added partition, waiting for bind - OK 2019/04/15 15:11:27 done 2019/04/15 15:11:27 attempting to send <<image>>zirconr.img... 2019/04/15 15:11:27 target is busy, retrying in one second [01907.640] 04782.04796> netsvc: tftp write of file <<image>>zircona.img completed [01907.640] 04782.04796> netsvc: metrics: {"inorderblks": 11526,"oooblks": 0,"ack": 46,"nack": 0,"timeouts": 0,"sas": 0,"inorderbytes": 11801880} [01907.710] 04782.06230> paver:[PartitionPave] Completed successfully 2019/04/15 15:11:28 attempting to send <<image>>zirconr.img... [01908.640] 04782.04796> netsvc: Running ZIRCON-R Paver [01908.644] 04782.06507> paver:[Initialize] Successfully initialized EFI Device Partitioner [01908.644] 04782.06507> paver:[PartitionPave] Paving partition. [01908.644] 04782.06507> paver:[FindFirstFit] Looking for space [01908.644] 04782.06507> paver:[FindFirstFit] Partition seen with start 34, end 16777249 (length 16777216) [01908.644] 04782.06507> paver:[FindFirstFit] Partition seen with start 16777250, end 16818209 (length 40960) [01908.644] 04782.06507> paver:[FindFirstFit] Partition seen with start 16818210, end 16850977 (length 32768) [01908.644] 04782.06507> paver:[FindFirstFit] Sorting [01908.644] 04782.06507> paver:[FindFirstFit] Partition[0] From Block [0, 34) ... (next partition starts at block 34) [01908.644] 04782.06507> paver:[FindFirstFit] There are 0 free blocks (49152 requested) [01908.644] 04782.06507> paver:[FindFirstFit] Partition[1] From Block [34, 16777250) ... (next partition starts at block 16777250) [01908.644] 04782.06507> paver:[FindFirstFit] There are 0 free blocks (49152 requested) [01908.644] 04782.06507> paver:[FindFirstFit] Partition[2] From Block [16777250, 16818210) ... (next partition starts at block 16818210) [01908.644] 04782.06507> paver:[FindFirstFit] There are 0 free blocks (49152 requested) [01908.644] 04782.06507> paver:[FindFirstFit] Partition[3] From Block [16818210, 16850978) ... (next partition starts at block 250069646) [01908.644] 04782.06507> paver:[FindFirstFit] There are 233218668 free blocks (49152 requested) [01908.644] 04782.06507> paver:[AddPartition] Found space in GPT - OK 233218668 @ 16850978 [01908.644] 04782.06507> paver:[AddPartition] Final space in GPT - OK 49152 @ 16850978 [01908.644] 04782.06507> paver:[AddPartition] Added partition, waiting for bind [01908.644] 03115.03168> block: Joining un-closed FIFO server [01908.645] 01104.01117> devcoord: dc_bind_device() '' [01908.645] 01182.01202> devmgr: /dev/class/block/000: GPT? [01908.645] 01104.01117> devcoord: dc_bind_device() '/boot/driver/gpt.so' [01908.645] 03115.03168> gpt: device_get_metadata failed (-25) [01908.645] 01182.01202> devmgr: /dev/class/block/017: FVM? [01908.645] 01104.01117> devcoord: dc_bind_device() '/boot/driver/fvm.so' [01908.646] 04782.06507> paver:[AddPartition] Added partition, waiting for bind - OK 2019/04/15 15:11:28 done 2019/04/15 15:11:28 attempting to send <<image>>authorized_keys... 2019/04/15 15:11:28 target is busy, retrying in one second [01908.765] 04782.04796> netsvc: tftp write of file <<image>>zirconr.img completed [01908.765] 04782.04796> netsvc: metrics: {"inorderblks": 10285,"oooblks": 0,"ack": 41,"nack": 0,"timeouts": 0,"sas": 0,"inorderbytes": 10531280} [01908.826] 04782.06507> paver:[PartitionPave] Completed successfully 2019/04/15 15:11:29 attempting to send <<image>>authorized_keys... 2019/04/15 15:11:29 done 2019/04/15 15:11:29 attempting to send <<netboot>>kernel.bin... 2019/04/15 15:11:29 target is busy, retrying in one second [01909.766] 04782.04796> netsvc: Installing SSH authorized_keys [01909.766] 04782.04796> netsvc: tftp write of file <<image>>authorized_keys completed [01909.766] 04782.04796> netsvc: metrics: {"inorderblks": 1,"oooblks": 0,"ack": 1,"nack": 0,"timeouts": 0,"sas": 0,"inorderbytes": 806} [01909.769] 04782.06801> paver:[Initialize] Successfully initialized EFI Device Partitioner [01909.769] 01104.01117> devcoord: dc_bind_device() '/boot/driver/zxcrypt.so' [01909.770] 03115.03168> devhost_get_handles(0x499e42d40840:block) open path='zxcrypt', r=-2 [01909.795] 04782.06801> paver:[DataFilePave] Wrote ssh/authorized_keys 2019/04/15 15:11:30 attempting to send <<netboot>>kernel.bin... 2019/04/15 15:11:30 done [00000.000] 00000.00000> zbi: @ 0xffffff8006703000 (10300592 bytes) [00000.000] 00000.00000> UART: FIFO depth 16 [00000.000] 00000.00000> PMM: boot reserve add [0x100000, 0x2f8fff] [00000.000] 00000.00000> PMM: boot reserve add [0x6703000, 0x70d5fff] [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 0x7ffff000 size 0x1000 [00000.000] 00000.00000> PMM: boot reserve marking WIRED [0x100000, 0x2f8fff] [00000.000] 00000.00000> PMM: boot reserve marking WIRED [0x6703000, 0x70d5fff] [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 0xffffffff00114e28 (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 [0x70d6000, 0x70d6100) [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001221d8 (elf_build_id) at level 0x4fffe, flags 0x1 [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00122364 (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-ffcb6d1f8cbf2b55c9f418dfb55a70261eb40a64-dirty [00000.000] 00000.00000> ELF build ID: 2d5bfaecf22c0263818c24a75224a3d3bb1da19b [00000.000] 00000.00000> initializing heap [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00101fc0 (console) at level 0x50000, flags 0x1 [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00181928 (x86_resource_init) at level 0x50000, flags 0x1 [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff002065f4 (percpu_heap_init) at level 0x50000, flags 0x1 [00000.000] 00000.00000> initializing vm [00000.000] 00000.00000> VM: reserving kernel region [0xffffffff00100000, 0xffffffff00216000) flags 0x28 name 'kernel_code' [00000.000] 00000.00000> VM: reserving kernel region [0xffffffff00216000, 0xffffffff00266000) flags 0x8 name 'kernel_rodata' [00000.000] 00000.00000> VM: reserving kernel region [0xffffffff00266000, 0xffffffff0026e000) flags 0x18 name 'kernel_data' [00000.000] 00000.00000> VM: reserving kernel region [0xffffffff0026e000, 0xffffffff002f9000) flags 0x18 name 'kernel_bss' [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001825ec (display_memtype) at level 0x60001, flags 0x1 [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00185654 (acpi_tables) at level 0x60001, flags 0x1 [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff0018072c (hpet) at level 0x60002, flags 0x1 [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00180aec (apic) at level 0x60002, flags 0x1 [00000.000] 00000.00000> x2APIC enabled [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00184c44 (timer) at level 0x60003, flags 0x1 [00000.000] 00000.00000> HPET frequency: 23999 ticks/ms [00000.000] 00000.00000> TSC frequency: 2712000 ticks/ms [01911.192] 00000.00000> timer features: constant_tsc 1 invariant_tsc 1 tsc_deadline 1 [01911.192] 00000.00000> Using TSC as wallclock [01911.192] 00000.00000> initializing kernel [01911.192] 00000.00000> initializing mp [01911.192] 00000.00000> INIT: cpu 0, calling hook 0xffffffff0011507c (global_prng_thread_safe) at level 0x7ffff, flags 0x1 [01911.192] 00000.00000> creating bootstrap completion thread [01911.192] 00000.00000> top of bootstrap2() [01911.192] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00130fec (libobject) at level 0x80000, flags 0x1 [01911.192] 00000.00000> OOM: started thread [01911.192] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00203600 (dpc) at level 0x80000, flags 0x1 [01911.192] 00000.00000> Processor Model Info: type 0 family 0x6 model 0xe stepping 0x9 [01911.192] 00000.00000> display_family 0x6 display_model 0x8e [01911.192] 00000.00000> Vendor: Intel [01911.192] 00000.00000> Microarch: Kaby Lake [01911.192] 00000.00000> F/M/S: 6/8e/9 [01911.192] 00000.00000> patch_level: 8e [01911.192] 00000.00000> Brand: Intel(R) Core(TM) i5-7300U CPU @ 2.60GHz [01911.192] 00000.00000> Features: fpu sse sse2 sse3 ssse3 sse4.1 sse4.2 mmx avx avx2 fxsr pcid xsave mon aesni clflush [01911.192] 00000.00000> clflushopt fsgsbase tsc_adj smep smap erms rdrand rdseed syscall nx huge rdtscp [01911.192] 00000.00000> invar_tsc tsc_deadline x2apic vmx pt hwp [01911.192] 00000.00000> Properties: meltdown l1tf pcid_good [01911.192] 00000.00000> initializing platform [01911.192] 00000.00000> INIT: cpu 0, calling hook 0xffffffff0019e760 (x86_perfmon) at level 0x90000, flags 0x1 [01911.192] 00000.00000> PMU: version 4 [01911.192] 00000.00000> UART: started IRQ driven RX [01911.192] 00000.00000> UART: started IRQ driven TX [01911.192] 00000.00000> cpu topology: [01911.192] 00000.00000> 0: apic id 0x0 package 0 node 0 core 0 smt 0 BSP [01911.192] 00000.00000> 1: apic id 0x2 package 0 node 0 core 1 smt 0 [01911.192] 00000.00000> 2: apic id 0x1 package 0 node 0 core 0 smt 1 [01911.192] 00000.00000> 3: apic id 0x3 package 0 node 0 core 1 smt 1 [01911.192] 00000.00000> Found 4 cpus [01911.192] 00000.00000> booting apic ids: 0x2 0x1 0x3 [01911.207] 00000.00000> entering scheduler on cpu 2 [01911.208] 00000.00000> entering scheduler on cpu 3 [01911.208] 00000.00000> entering scheduler on cpu 1 [01911.210] 00000.00000> smbios: manufacturer="Intel Corporation" product="NUC7i5DNKE" [01911.210] 00000.00000> initializing target [01911.210] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00183ef4 (x86_pcie_init) at level 0xa0000, flags 0x1 [01911.210] 00000.00000> moving to last init level [01911.210] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00121430 (debuglog) at level 0xb0000, flags 0x1 [01911.210] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00102ae8 (kernel_shell) at level 0xc0000, flags 0x1 [01911.210] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001fea20 (ktrace) at level 0xc0000, flags 0x1 [01911.214] 00000.00000> ktrace: buffer at 0xffffff946a4f5000 (33554432 bytes) [01911.214] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00212cdc (userboot) at level 0xc0000, flags 0x1 [01911.214] 00000.00000> userboot: ramdisk 0x9d3000 @ 0xffffff8006703000 [01911.215] 00000.00000> userboot: userboot rodata 0 @ [0x35f93af3b000,0x35f93af3e000) [01911.215] 00000.00000> userboot: userboot code 0x3000 @ [0x35f93af3e000,0x35f93af49000) [01911.215] 00000.00000> userboot: vdso/full rodata 0 @ [0x35f93af49000,0x35f93af50000) [01911.215] 00000.00000> userboot: vdso/full code 0x7000 @ [0x35f93af50000,0x35f93af51000) [01911.215] 00000.00000> userboot: entry point @ 0x35f93af3ec90 [01911.215] 01036.01043> userboot: option "zircon.autorun.system=/boot/bin/sh+/boot/infra/runcmds" [01911.238] 01036.01043> userboot: searching bootfs for 'bin/bootsvc' [01911.238] 01036.01043> userboot: 'bin/bootsvc' has PT_INTERP "lib/ld.so.1" [01911.238] 01036.01043> userboot: searching bootfs for 'lib/ld.so.1' [01911.238] 01036.01043> userboot: userboot: loaded lib/ld.so.1 at 0x76b2d5658000, entry point 0x76b2d5676080 [01911.238] 01036.01043> userboot: userboot: loaded vDSO at 0x419986e4c000, entry point 0x419986e538fa [01911.238] 01036.01043> userboot: process bin/bootsvc started. [01911.238] 01036.01043> userboot: waiting for loader-service requests... [01911.239] 01036.01043> userboot: searching bootfs for 'lib/libasync-default.so' [01911.239] 01036.01043> userboot: searching bootfs for 'lib/libfdio.so' [01911.239] 01036.01043> userboot: searching bootfs for 'lib/libtrace-engine.so' [01911.239] 01036.01043> userboot: searching bootfs for 'lib/liblaunchpad.so' [01911.239] 01050.01053> {{{reset}}} [01911.239] 01050.01053> {{{module:0:<application>:elf:f6bdbf7056dde8e6a9907572eb5e6984ca2c2371}}} [01911.239] 01050.01053> {{{mmap:0x6c22dd0b4000:0x3a000:load:0:rx:0}}} [01911.239] 01050.01053> {{{mmap:0x6c22dd0ef000:0x4000:load:0:rw:0x3b000}}} [01911.239] 01050.01053> dso: id=f6bdbf7056dde8e6a9907572eb5e6984ca2c2371 base=0x00006c22dd0b4000 name=<application> [01911.239] 01050.01053> {{{module:0x2:<vDSO>:elf:15141ceb8a2b3abed705662b340c7e5081a1437c}}} [01911.239] 01050.01053> {{{mmap:0x419986e4c000:0x7000:load:0x2:r:0}}} [01911.239] 01050.01053> {{{mmap:0x419986e53000:0x1000:load:0x2:rx:0x7000}}} [01911.239] 01050.01053> dso: id=15141ceb8a2b3abed705662b340c7e5081a1437c base=0x0000419986e4c000 name=<vDSO> [01911.239] 01050.01053> {{{module:0x3:libasync-default.so:elf:ccf2d57accbeadcde5f232066f19b5141d22232c}}} [01911.239] 01050.01053> {{{mmap:0x68c8e9570000:0x1000:load:0x3:rx:0}}} [01911.239] 01050.01053> {{{mmap:0x68c8e9571000:0x1000:load:0x3:rw:0x1000}}} [01911.239] 01050.01053> dso: id=ccf2d57accbeadcde5f232066f19b5141d22232c base=0x000068c8e9570000 name=libasync-default.so [01911.239] 01050.01053> {{{module:0x4:libfdio.so:elf:0ef9225cf8664a743fa342cf9d5b9b7b99a2f799}}} [01911.239] 01050.01053> {{{mmap:0x5ede6bf25000:0x32000:load:0x4:rx:0}}} [01911.239] 01050.01053> {{{mmap:0x5ede6bf58000:0x4000:load:0x4:rw:0x33000}}} [01911.239] 01050.01053> dso: id=0ef9225cf8664a743fa342cf9d5b9b7b99a2f799 base=0x00005ede6bf25000 name=libfdio.so [01911.239] 01050.01053> {{{module:0x5:libtrace-engine.so:elf:658796558b49a428513d7cb2fb165ad7d4460058}}} [01911.239] 01050.01053> {{{mmap:0x41d30b1b9000:0x9000:load:0x5:rx:0}}} [01911.239] 01050.01053> {{{mmap:0x41d30b1c2000:0x2000:load:0x5:rw:0x9000}}} [01911.239] 01050.01053> dso: id=658796558b49a428513d7cb2fb165ad7d4460058 base=0x000041d30b1b9000 name=libtrace-engine.so [01911.239] 01050.01053> {{{module:0x6:liblaunchpad.so:elf:b2751d96ee9c4424d2d34fe14a1838336283099a}}} [01911.239] 01050.01053> {{{mmap:0x5963b9447000:0x7000:load:0x6:rx:0}}} [01911.239] 01050.01053> {{{mmap:0x5963b944e000:0x2000:load:0x6:rw:0x7000}}} [01911.239] 01050.01053> dso: id=b2751d96ee9c4424d2d34fe14a1838336283099a base=0x00005963b9447000 name=liblaunchpad.so [01911.239] 01050.01053> {{{module:0x1:libc.so:elf:6f37cb554576f71fe653f0798150b51029c00c98}}} [01911.239] 01050.01053> {{{mmap:0x76b2d5658000:0xa5000:load:0x1:rx:0}}} [01911.239] 01050.01053> {{{mmap:0x76b2d56fe000:0x5000:load:0x1:rw:0xa6000}}} [01911.239] 01050.01053> dso: id=6f37cb554576f71fe653f0798150b51029c00c98 base=0x000076b2d5658000 name=libc.so [01911.239] 01050.01053> bootsvc: Starting... [01911.239] 01036.01043> userboot: loader-service channel peer closed [01911.239] 01036.01043> userboot: finished! [01911.239] 01050.01053> bootsvc: Creating bootfs service... [01911.240] 01050.01053> bootsvc: Retrieving boot image... [01911.240] 01050.01053> bootsvc: Decommitted BOOTDATA VMO from 0 to 0x9d2000 [01911.240] 01050.01053> bootsvc: Loading boot arguments... [01911.240] 01050.01053> bootsvc: Creating svcfs service... [01911.240] 01050.01053> bootsvc: Loading kernel VMOs... [01911.240] 01050.01053> bootsvc: Creating loader service... [01911.240] 01050.01053> bootsvc: Launching next process... [01911.240] 01050.01108> bootsvc: Launched bin/devcoordinator [01911.241] 01115.01130> devcoordinator: launch /boot/bin/svchost (svchost) OK [01911.242] 01115.01130> devcoordinator: launch /boot/bin/fshost (fshost) OK [01911.245] 01115.01321> devcoordinator: launch /boot/bin/pwrbtn-monitor (pwrbtn-monitor) OK [01911.245] 01115.01344> devcoordinator: launch /boot/bin/netsvc (netsvc) OK [01911.246] 01115.01344> devcoordinator: launch /boot/bin/virtual-console (virtual-console) OK [01911.249] 01115.01130> devcoordinator: full system required, ignoring fallback drivers until /system is loaded [01911.249] 01115.01130> devcoordinator: launch devhost 'devhost:sys': pid=2189 [01911.249] 01115.01130> devcoordinator: launch devhost 'devhost:test': pid=2221 [01911.250] 01115.01130> devcoordinator: launch devhost 'devhost:root': pid=2270 [01911.250] 02189.02203> devhost: trace provider registry begun [01911.250] 01115.01130> devcoordinator: launch devhost 'devhost:misc': pid=2353 [01911.250] 02221.02243> devhost: trace provider registry begun [01911.252] 02270.02316> devhost: trace provider registry begun [01911.252] 02353.02396> devhost: trace provider registry begun [01911.261] 01115.01333> devcoordinator: launch /boot/bin/sh (sh:console) OK [01911.340] 02189.02203> acpi-bus: not using IOMMU [01911.347] 02189.02203> PMU: 7 arch events [01911.347] 02189.02203> PMU: arch event id range: 1-7 [01911.347] 02189.02203> PMU: 102 arch events [01911.347] 02189.02203> PMU: arch event id range: 1-241 [01911.347] 02189.02203> Intel Processor Trace configuration for this chipset: [01911.347] 02189.02203> mtc_freq_mask: 0x249 [01911.347] 02189.02203> cyc_thresh_mask: 0x3fff [01911.347] 02189.02203> psb_freq_mask: 0x3f [01911.347] 02189.02203> num addr ranges: 2 [01911.347] 02189.02203> [sysmem_init 28] async_get_default_dispatcher(): 0x14b19dfa0250 [01911.347] 02189.02203> [sysmem_bind 40] sysmem_bind() [01911.347] 02189.02883> acpi-pwrbtn: initialized [01911.357] 02189.02883> WARNING: ACPI found bad _CRS address entry [01911.358] 01749.01782> vc: new input device /dev/class/input/000 [01911.367] 02189.02883> WARNING: ACPI found bad _CRS address entry [01911.378] 02189.02883> acpi: published device pci(0x14b0de003a70), parent=sys(0x14b21df98a10), handle=0x14b09dfad890 [01911.379] 01115.01130> devcoordinator: launch devhost 'devhost:pci#1:8086:5916': pid=2979 [01911.379] 01115.01130> devcoordinator: launch devhost 'devhost:pci#3:8086:9d2f': pid=3037 [01911.380] 02979.02993> devhost: trace provider registry begun [01911.380] 01115.01130> devcoordinator: launch devhost 'devhost:pci#5:8086:9d60': pid=3141 [01911.381] 01115.01130> devcoordinator: launch devhost 'devhost:pci#6:8086:9d61': pid=3224 [01911.381] 03037.03062> devhost: trace provider registry begun [01911.382] 03141.03166> devhost: trace provider registry begun [01911.382] 01115.01130> devcoordinator: launch devhost 'devhost:pci#9:8086:9d03': pid=3327 [01911.382] 02189.02883> acpi: published device rtc(0x14b0ddfbe0b0), parent=acpi(0x14b21df98010), handle=0x14b09dfd3a90 [01911.383] 03224.03250> devhost: trace provider registry begun [01911.383] 01115.01130> devcoordinator: launch devhost 'devhost:pci#14:8086:9d71': pid=3479 [01911.384] 03327.03367> devhost: trace provider registry begun [01911.384] 01115.01130> devcoordinator: launch devhost 'devhost:pci#16:8086:156f': pid=3569 [01911.384] 02189.02883> acpi-ec: initialized [01911.387] 02189.02883> acpi: failed to create NHLT VMO (res -10) [01911.387] 02189.02883> acpi: failed to publish NHLT metadata [01911.391] 03141.03166> initialized intel serialio i2c driver, reg=0x2eefec387000 regsize=4096 [01911.392] 03327.03367> ahci: using MSI interrupt [01911.393] 03479.03500> devhost: trace provider registry begun [01911.393] 03224.03250> initialized intel serialio i2c driver, reg=0x3a644ae99000 regsize=4096 [01911.394] 03569.03597> devhost: trace provider registry begun [01911.397] 03037.03954> * found USB device (0x18d1:0xa002, USB 2.0) config 1 [01911.397] 03037.03954> * found USB device (0x18d1:0xa003, USB 3.0) config 1 [01911.398] 03479.03500> [IHDA DSP 00:1f.3] Failed to fetch NHLT (res -25) [01911.398] 03479.03500> [IHDA Controller 00:1f.3] Failed to initialize DSP device (res = -25) [01911.469] 01658.01686> netifc: ? /dev/class/ethernet/000 [01911.469] 01658.01686> netifc: create 512 eth buffers [01911.469] 01658.01686> macaddr: d4:5d:df:07:59:c7 [01911.469] 01658.01686> ip6addr: fe80::d65d:df4d:fe07:59c7 [01911.469] 01658.01686> snmaddr: ff02::1:ff07:59c7 [01911.469] 01658.01686> netsvc: using /dev/class/ethernet/000 [01911.469] 01658.01686> netsvc: nodename='viral-jolly-clock-gloss' [01911.469] 01658.01686> netsvc: start [01911.500] 01749.01782> vc: new display device /dev/class/display-controller/000/virtcon [01911.540] 02979.04247> i915: MST not supported [01911.888] 02979.04247> i915: Found DP monitor [01911.888] 02979.04247> i915: Display 1 connected [01912.026] 03224.03755> i2c: tx abort detected: 0x05001000 [01912.026] 03224.03250> intel-i2c-controller: intel_serialio_i2c_slave_transfer: -40 [01912.026] 03224.03250> i2c-hid: could not read HID descriptor: 0 [01912.026] 03224.03250> devhost[00:15.1/i2c-bus-9d61/004c] bind driver '/boot/driver/i2c-hid.so' failed: -2 [01912.026] 01115.01130> devcoordinator: rpc: bind-driver '004c' status -2 [01912.296] 01749.01782> vc: Successfully attached to display 1 [01912.860] 03037.03954> * found USB device (0x0781:0x5571, USB 2.0) config 1 [01913.110] 03037.03954> * found USB device (0x8087:0x0a2b, USB 2.0) config 1 [01913.396] 03141.03166> intel-i2c-controller: intel_serialio_i2c_slave_transfer: -21 [01913.396] 03141.03166> i2c-hid: could not read HID descriptor: 0 [01913.396] 03141.03166> devhost[00:15.0/i2c-bus-9d60/0020] bind driver '/boot/driver/i2c-hid.so' failed: -2 [01913.396] 01115.01130> devcoordinator: rpc: bind-driver '0020' status -2 [01913.407] 03327.03845> sata2: dev info [01913.407] 03327.03845> serial=715400411011 4 [01913.407] 03327.03845> firmware rev=1P11A1E_ [01913.407] 03327.03845> model id=IBIW NSS D [01913.407] 03327.03845> major=0x3f0 ACS2 DMA 32 commands [01913.407] 03327.03845> LBA48 250069680 sectors, sector size=512 [01913.407] 01299.01313> fshost: /dev/class/block/000: GPT? [01913.408] 03327.03367> gpt: device_get_metadata failed (-25) [01913.408] 01299.01313> fshost: /dev/class/block/001: FVM? [01913.409] 01299.01313> fshost: not automounting efi [01913.411] 01299.01313> devcoordinator: launch /boot/bin/blobfs (blobfs:/blob) OK [01913.549] 01299.01313> fshost: starting 'bin/pkgsvr' '871f274185ec9d2c89feee3e84f8d6d9d258f62b7ecd8061cba5530e954496f9'... [01913.556] 01299.01313> devcoordinator: launch bin/pkgsvr (pkgfs) OK [01913.568] 04670.04874> pkgsvr: system: will be served from 871f274185ec9d2c89feee3e84f8d6d9d258f62b7ecd8061cba5530e954496f9 [01913.568] 04670.04874> pkgsvr: pkgfs serving index /data/pkgfs_index from blobfs /blob [01913.569] 01299.01313> fshost: /dev/class/block/006: zxcrypt? [01913.569] 03327.03367> devhost_get_handles(0x20dbd7644a10:block) open path='zxcrypt', r=-2 [01913.572] 01299.01313> fshost: mounting minfs [01913.573] 01299.01313> devcoordinator: launch /boot/bin/minfs (minfs:/data) OK [01913.576] 01115.01792> devcoordinator: launch /system/bin/appmgr (appmgr) OK [01913.576] 01115.01792> autorun: starting '/boot/bin/sh' '/boot/infra/runcmds'... [01913.576] 01115.01792> devcoordinator: launch /boot/bin/sh (autorun:system) OK [01913.597] 01115.04925> devcoordinator: adding system driver 'gpu' '/system/driver/libmsd_intel.so' [01913.605] 01115.04925> devcoordinator: adding system driver 'usb_video' '/system/driver/usb_video.so' [01913.618] 01115.04925> devcoordinator: adding system driver 'virtual_audio' '/system/driver/virtual_audio_driver.so' [01913.623] 01115.04925> devcoordinator: adding system driver 'wlan' '/system/driver/wlanphy.so' [01913.627] 01115.04925> devcoordinator: adding system driver 'brcmfmac' '/system/driver/brcmfmac.so' [01913.631] 01115.04925> devcoordinator: adding system driver 'bt_hci_atheros' '/system/driver/bt-hci-atheros.so' [01913.635] 01115.04925> devcoordinator: adding system driver 'bt_hci_intel' '/system/driver/bt-hci-intel.so' [01913.637] 01115.04925> devcoordinator: adding system driver 'iwlwifi_pci' '/system/driver/iwlwifi.so' [01913.638] 01115.04925> devcoordinator: adding system driver 'bt_hog' '/system/driver/bt-hog.so' [01913.641] 01115.04925> devcoordinator: adding system driver 'wlan' '/system/driver/wlanif.so' [01913.643] 01115.04925> devcoordinator: adding system driver 'ath10k_pci' '/system/driver/ath10k.so' [01913.646] 01115.04925> devcoordinator: adding system driver 'rtl88xx' '/system/driver/rtl88xx.so' [01913.659] 01115.04925> devcoordinator: adding system driver 'bt_host' '/system/driver/bt-host.so' [01913.664] 01115.04925> devcoordinator: adding system driver 'qmi_usb' '/system/driver/qmi-transport.so' [01913.665] 01115.04925> devcoordinator: adding system driver 'bt_hci_passthrough' '/system/driver/bt-hci-passthrough.so' [01913.669] 01115.04925> devcoordinator: adding system driver 'bt_hci_fake' '/system/driver/bt-hci-fake.so' [01913.671] 01115.04925> devcoordinator: adding system driver 'qmi_fake' '/system/driver/qmi-fake.so' [01913.692] 01115.04925> devcoordinator: adding system driver 'wlan' '/system/driver/wlan.so' [01913.693] 01115.04925> devcoordinator: adding system driver 'mt8167s_gpu' '/system/driver/libmsd_img_rgx_mtk.so' [01913.713] 01115.04925> devcoordinator: adding system driver 'ralink' '/system/driver/ralink.so' [01913.718] 01115.04925> devcoordinator: adding system driver 'virtual_camera' '/system/driver/virtual_camera_driver.so' [01913.719] 01115.01130> devcoordinator: driver 'ralink' added [01913.719] 01115.01130> devcoordinator: driver 'mt8167s_gpu' added [01913.719] 01115.01130> devcoordinator: driver 'wlan' added [01913.719] 01115.01130> devcoordinator: driver 'qmi_fake' added [01913.719] 01115.01130> devcoordinator: driver 'bt_hci_fake' added [01913.719] 01115.01130> devcoordinator: driver 'qmi_usb' added [01913.719] 01115.01130> devcoordinator: driver 'bt_host' added [01913.719] 01115.01130> devcoordinator: driver 'rtl88xx' added [01913.719] 01115.01130> devcoordinator: driver 'ath10k_pci' added [01913.719] 01115.01130> devcoordinator: driver 'wlan' added [01913.719] 01115.01130> devcoordinator: driver 'bt_hog' added [01913.719] 01115.01130> devcoordinator: driver 'iwlwifi_pci' added [01913.719] 01115.01130> devcoordinator: driver 'bt_hci_intel' added [01913.719] 01115.01130> devcoordinator: driver 'bt_hci_atheros' added [01913.719] 01115.01130> devcoordinator: driver 'brcmfmac' added [01913.719] 01115.01130> devcoordinator: driver 'wlan' added [01913.719] 01115.01130> devcoordinator: driver 'usb_video' added [01913.719] 01115.01130> devcoordinator: driver 'gpu' added [01913.719] 01115.01130> devcoordinator: driver 'bt_hci_passthrough' added [01913.719] 01115.01130> devcoordinator: fallback driver 'usb_composite' is available [01913.719] 01115.01130> devcoordinator: driver 'usb_composite' added [01913.719] 01115.01130> devcoordinator: fallback driver 'intel_disp' is available [01913.719] 01115.01130> devcoordinator: driver 'intel_disp' added [01913.722] 03037.03062> UMS: parent: 'ifc-000' [01913.722] 03037.03062> UMS:Max lun is: 0 [01913.722] 03037.03062> devhost[00:14.0/xhci/usb-bus/002/002/ifc-001] bind driver '/boot/driver/bt-transport-usb.so' failed: -2 [01913.722] 01115.01130> devcoordinator: rpc: bind-driver 'ifc-001' status -2 [01913.724] 05180.05197> [INFO:namespace_builder.cc(93)] config-data for sysmgr [01913.724] 03037.05919> UMS: block size is: 0x00000200 [01913.724] 03037.05919> UMS: total blocks is: 15630336 [01913.724] 03037.05919> UMS: total size is: 8002732032 [01913.724] 03037.05919> UMS: read-only: 0 removable: 1 [01913.757] 06046.06095> [ERROR:garnet/bin/sysmgr/app.cc(150)] Could not serve fuchsia.amber.Control: 0 [01913.757] 06046.06095> [ERROR:garnet/bin/sysmgr/app.cc(150)] Could not serve fuchsia.amber.Events: 0 [01913.757] 06046.06095> [ERROR:garnet/bin/sysmgr/app.cc(150)] Could not serve fuchsia.net.policy.Observer: 0 [01913.757] 06046.06095> [ERROR:garnet/bin/sysmgr/app.cc(150)] Could not serve fuchsia.mdns.Controller: 0 [01913.757] 06046.06095> [ERROR:garnet/bin/sysmgr/app.cc(150)] Could not serve fuchsia.netstack.Netstack: 0 [01913.757] 06046.06095> [ERROR:garnet/bin/sysmgr/app.cc(150)] Could not serve fuchsia.wlan.service.Wlan: 0 [01913.762] 03037.06226> btintel: firmware already loaded [01913.762] 03037.06235> hci_read_thread: failed to read from command channel ZX_ERR_PEER_CLOSED [01913.762] 03037.06235> hci_read_thread: failed to read from ACL channel ZX_ERR_PEER_CLOSED [01913.762] 03037.06235> bt-transport-usb: all channels closed - exiting [01913.762] 03037.06427> [INFO:command_channel.cc(149)] hci: initialized [01913.763] 01299.01313> fshost: /dev/class/block/008: MBR? [01913.766] 01299.01313> fshost: /dev/class/block/010: MBR? [01913.783] 03037.06427> [INFO:acl_data_channel.cc(91)] hci: initialized [01913.809] 05180.05197> [INFO:namespace_builder.cc(93)] config-data for amber [01913.859] 05180.05197> [INFO:namespace_builder.cc(93)] config-data for pkg_resolver [01913.921] 08084.08096> [INFO:cobalt_main.cc(217)] 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 [01913.921] 08084.08096> kfill_days=2, start_event_aggregator_worker=1. [01913.992] 05180.05197> [INFO:namespace_builder.cc(93)] config-data for wlancfg [01914.087] 05180.05197> [INFO:namespace_builder.cc(93)] config-data for crashpad_agent [01914.132] 11340.11354> [INFO:main.cc(35)] Trace Manager starting with config: /pkg/data/tracing.config [01914.132] 10067.10079> [INFO:system_metrics_main.cc(23)] Cobalt SystemMetricsDaemon: System metrics daemon created. [01914.136] 03037.06427> [WARN:bredr_discovery_manager.cc(482)] gap-bredr: write inquiry scan activity failed: [status: invalid HCI command parameters (HCI 0x12)] [01914.159] 11761.11773> wlanstack2 [I]: Starting [01914.237] 05180.05197> [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 [01914.237] 05180.05197> is not present in the component's sandbox. [01914.237] 05180.05197> Refer to https://fuchsia.googlesource.com/fuchsia/+/master/docs/the-book/sandboxing.md#services for more information. [01914.244] 10956.10970> [INFO:benchmarks.cc(24)] Graphics performance tests disabled [01914.244] 10956.10970> [INFO:benchmarking.cc(173)] writing summary.json to /tmp/infra-test-output/summary.json [01915.137] 08794.08806> Starting mDNS on interface ethp001f6 192.168.42.112 [01915.138] 08794.08806> [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 [01915.138] 08794.08806> Starting mDNS on interface ethp001f6 [80fe::5dd6:ffdf:7fe:c759] [01915.138] 08794.08806> [WARNING:garnet/bin/mdns/service/mdns_interface_transceiver_v6.cc(29)] NET-291 IPV6_MULTICAST_LOOP not supported (ENOPROTOOPT), continuing anyway [01915.138] 08794.08806> [WARNING:garnet/bin/mdns/service/mdns_interface_transceiver_v6.cc(50)] NET-2180 IPV6_JOIN_GROUP returned ENODEV, mDNS will not communicate via IPV6 [01915.138] 08794.08806> mDNS: Verifying uniqueness of host name viral-jolly-clock-gloss.local. [01915.946] 08794.08806> mDNS: Using unique host name viral-jolly-clock-gloss.local. DEBUG: reading "summary.json" DEBUG: copying test output DEBUG: tarring test output... [01961.056] 01658.01686> netsvc: tftp read of file /tmp/infra-test-output/summary.json completed [01961.056] 01658.01686> netsvc: metrics: {"inorderblks": 0,"oooblks": 0,"ack": 0,"nack": 0,"timeouts": 0,"sas": 0,"inorderbytes": 0}