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

{ "445120414e0d1210": { "output": "2 files remaining...\n0 files remaining...\nDEBUG: config flag: /etc/botanist/config.json\n2019/04/20 01:15:52 attempting to send <<netboot>>cmdline...\nDEBUG: executing command: \"/etc/connectivity/host_cmds.sh\"\nenvironment of subprocess:\n[]\n2019/04/20 01:15:52 attempting to send <<netboot>>cmdline...\n2019/04/20 01:15:52 done\n2019/04/20 01:15:52 attempting to send <<image>>sparse.fvm...\n2019/04/20 01:15:52 done\n2019/04/20 01:15:52 attempting to send <<image>>sparse.fvm...\n[00000.000] 00000.00000> zbi: @ 0xffffff80012f2000 (17482848 bytes)\n[00000.000] 00000.00000> UART: FIFO depth 16\n[00000.000] 00000.00000> PMM: boot reserve add [0x100000, 0x2c5fff]\n[00000.000] 00000.00000> PMM: boot reserve add [0x12f2000, 0x239efff]\n[00000.000] 00000.00000> PMM: arena too small to be useful (size 4096)\n[00000.000] 00000.00000> PMM: pmm_add_arena failed to initialize arena\n[00000.000] 00000.00000> MEM: Failed to add pmm range at 0x7ffff000 size 0x1000\n[00000.000] 00000.00000> PMM: boot reserve marking WIRED [0x100000, 0x2c5fff]\n[00000.000] 00000.00000> PMM: boot reserve marking WIRED [0x12f2000, 0x239efff]\n[00000.000] 00000.00000> \n[00000.000] 00000.00000> welcome to Zircon\n[00000.000] 00000.00000> \n[00000.000] 00000.00000> KASLR: .text section at 0xffffffff00100000\n[00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001aa428 (global_prng_seed) at level 0x30000, flags 0x1\n[00000.000] 00000.00000> initializing vm pre-heap\n[00000.000] 00000.00000> VM: marking boot alloc used range [0x239f000, 0x239f100)\n[00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00147abc (elf_build_id) at level 0x4fffe, flags 0x1\n[00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00147c48 (version) at level 0x4ffff, flags 0x1\n[00000.000] 00000.00000> version:\n[00000.000] 00000.00000> \tarch: x86\n[00000.000] 00000.00000> \tplatform: pc\n[00000.000] 00000.00000> \ttarget: pc\n[00000.000] 00000.00000> \tproject: x64\n[00000.000] 00000.00000> \tbuildid: git-13ee3dc5e4c46bf127977ad28645c47442ec517d\n[00000.000] 00000.00000> \tELF build ID: 5f3e39bd4ed89d3b8122947842f1eac846a04683\n[00000.000] 00000.00000> initializing heap\n[00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00102e1c (x86_resource_init) at level 0x50000, flags 0x1\n[00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001a9630 (console) at level 0x50000, flags 0x1\n[00000.000] 00000.00000> initializing vm\n[00000.000] 00000.00000> VM: reserving kernel region [0xffffffff00100000, 0xffffffff001ee000) flags 0x28 name 'kernel_code'\n[00000.000] 00000.00000> VM: reserving kernel region [0xffffffff001ee000, 0xffffffff00232000) flags 0x8 name 'kernel_rodata'\n[00000.000] 00000.00000> VM: reserving kernel region [0xffffffff00232000, 0xffffffff00242000) flags 0x18 name 'kernel_data'\n[00000.000] 00000.00000> VM: reserving kernel region [0xffffffff00242000, 0xffffffff002c6000) flags 0x18 name 'kernel_bss'\n[00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00103ae0 (display_memtype) at level 0x60001, flags 0x1\n[00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00138fa0 (acpi_tables) at level 0x60001, flags 0x1\n[00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00101c40 (hpet) at level 0x60002, flags 0x1\n[00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00102000 (apic) at level 0x60002, flags 0x1\n[00000.000] 00000.00000> x2APIC enabled\n[00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001061b4 (timer) at level 0x60003, flags 0x1\n[00000.000] 00000.00000> HPET frequency: 23999 ticks/ms\n[00000.000] 00000.00000> TSC frequency: 2712000 ticks/ms\n[00034.643] 00000.00000> timer features: constant_tsc 1 invariant_tsc 1 tsc_deadline 1\n[00034.643] 00000.00000> Using TSC as wallclock\n[00034.643] 00000.00000> initializing kernel\n[00034.643] 00000.00000> initializing mp\n[00034.643] 00000.00000> initializing timers\n[00034.643] 00000.00000> INIT: cpu 0, calling hook 0xffffffff0013c578 (debuglog) at level 0x7ffff, flags 0x1\n[00034.643] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00195518 (thread_set_priority_experiment) at level 0x7ffff, flags 0x1\n[00034.643] 00000.00000> thread set priority experiment is : ENABLED\n[00034.643] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001aa67c (global_prng_thread_safe) at level 0x7ffff, flags 0x1\n[00034.643] 00000.00000> creating bootstrap completion thread\n[00034.985] 00000.00000> top of bootstrap2()\n[00034.985] 00000.00000> INIT: cpu 0, calling hook 0xffffffff0013151c (dpc) at level 0x80000, flags 0x1\n[00034.998] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00152978 (libobject) at level 0x80000, flags 0x1\n[00034.998] 00000.00000> OOM: started thread\n[00035.011] 00000.00000> Processor Model Info: type 0 family 0x6 model 0xe stepping 0x9\n[00035.011] 00000.00000> \tdisplay_family 0x6 display_model 0x8e\n[00035.011] 00000.00000> Vendor: Intel\n[00035.011] 00000.00000> Microarch: Kaby Lake\n[00035.011] 00000.00000> F/M/S: 6/8e/9\n[00035.011] 00000.00000> Brand: Intel(R) Core(TM) i5-7300U CPU @ 2.60GHz\n[00035.011] 00000.00000> Features: fpu sse sse2 sse3 ssse3 sse4.1 sse4.2 mmx avx avx2 fxsr pcid xsave mon aesni clflush \n[00035.011] 00000.00000> clflushopt fsgsbase tsc_adj smep smap erms rdrand rdseed syscall nx huge rdtscp \n[00035.011] 00000.00000> invar_tsc tsc_deadline x2apic vmx pt hwp \n[00035.011] 00000.00000> initializing platform\n[00035.011] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001101f4 (x86_perfmon) at level 0x90000, flags 0x1\n[00035.011] 00000.00000> PMU: version 4\n[00035.011] 00000.00000> UART: started IRQ driven RX\n[00035.011] 00000.00000> UART: started IRQ driven TX\n[00035.011] 00000.00000> cpu topology:\n[00035.011] 00000.00000> \t0: apic id 0x0 package 0 node 0 core 0 smt 0 BSP\n[00035.011] 00000.00000> \t1: apic id 0x2 package 0 node 0 core 1 smt 0\n[00035.011] 00000.00000> \t2: apic id 0x1 package 0 node 0 core 0 smt 1\n[00035.011] 00000.00000> \t3: apic id 0x3 package 0 node 0 core 1 smt 1\n[00035.011] 00000.00000> Found 4 cpus\n[00035.011] 00000.00000> booting apic ids: 0x2 0x1 0x3 \n[00035.027] 00000.00000> entering scheduler on cpu 2\n[00035.028] 00000.00000> entering scheduler on cpu 3\n[00035.028] 00000.00000> entering scheduler on cpu 1\n[00035.031] 00000.00000> smbios: manufacturer=\"Intel Corporation\" product=\"NUC7i5DNHE\"\n[00035.031] 00000.00000> initializing target\n[00035.031] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001053a0 (x86_pcie_init) at level 0xa0000, flags 0x1\n[00035.031] 00000.00000> moving to last init level\n[00035.031] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00144140 (ktrace) at level 0xc0000, flags 0x1\n[00035.034] 00000.00000> ktrace: buffer at 0xffffff9cd4587000 (33554432 bytes)\n[00035.034] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00147ab4 (userboot) at level 0xc0000, flags 0x1\n[00035.034] 00000.00000> userboot: ramdisk 0x10ad000 @ 0xffffff80012f2000\n[00035.035] 00000.00000> userboot: userboot rodata 0 @ [0xd9032b9a000,0xd9032b9d000)\n[00035.035] 00000.00000> userboot: userboot code 0x3000 @ [0xd9032b9d000,0xd9032ba8000)\n[00035.035] 00000.00000> userboot: vdso/full rodata 0 @ [0xd9032ba8000,0xd9032baf000)\n[00035.035] 00000.00000> userboot: vdso/full code 0x7000 @ [0xd9032baf000,0xd9032bb0000)\n[00035.035] 00000.00000> userboot: entry point @ 0xd9032b9dc10\n[00035.035] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001aa030 (kernel_shell) at level 0xc0000, flags 0x1\n[00035.035] 01036.01043> userboot: option \"netsvc.disable=true\"\n[00035.035] 01036.01043> userboot: option \"zircon.system.disable-automount=true\"\n[00035.035] 01036.01043> userboot: option \"zircon.autorun.boot=/boot/infra/setup\"\n[00035.035] 01036.01043> userboot: option \"kernel.serial=legacy\"\n[00035.035] 01036.01043> userboot: option \"http://192.168.42.1/multiboot/d4%3A5d%3Adf%3A1a%3A42%3A86=\"\n[00035.035] 01036.01043> userboot: option \"multiboot.boot_loader_name=iPXE+1.0.0++(d2063)\"\n[00035.073] 01036.01043> userboot: searching bootfs for 'bin/bootsvc'\n[00035.074] 01036.01043> userboot: 'bin/bootsvc' has PT_INTERP \"lib/ld.so.1\"\n[00035.074] 01036.01043> userboot: searching bootfs for 'lib/ld.so.1'\n[00035.074] 01036.01043> userboot: userboot: loaded lib/ld.so.1 at 0x628990242000, entry point 0x6289902c80d3\n[00035.074] 01036.01043> userboot: userboot: loaded vDSO at 0x544471d53000, entry point 0x0\n[00035.074] 01036.01043> userboot: process bin/bootsvc started.\n[00035.074] 01036.01043> userboot: waiting for loader-service requests...\n[00035.074] 01036.01043> userboot: searching bootfs for 'lib/libasync-default.so'\n[00035.074] 01036.01043> userboot: searching bootfs for 'lib/libfdio.so'\n[00035.074] 01036.01043> userboot: searching bootfs for 'lib/liblaunchpad.so'\n[00035.074] 01036.01043> userboot: searching bootfs for 'lib/libtrace-engine.so'\n[00035.074] 01050.01053> {{{reset}}}\n[00035.074] 01050.01053> {{{module:0:<application>:elf:18de7d58f51e8ba5c4f6afdd0cc8440f482c2b45}}}\n[00035.074] 01050.01053> {{{mmap:0xf053816f000:0x2e000:load:0:rx:0}}}\n[00035.074] 01050.01053> {{{mmap:0xf053819d000:0x4000:load:0:rw:0x2e000}}}\n[00035.074] 01050.01053> dso: id=18de7d58f51e8ba5c4f6afdd0cc8440f482c2b45 base=0x00000f053816f000 name=<application>\n[00035.074] 01050.01053> {{{module:0x3:libasync-default.so:elf:c189f51f19d10785d93b5235ad1b46dca4451b00}}}\n[00035.074] 01050.01053> {{{mmap:0x2fb0309e7000:0x1000:load:0x3:rx:0}}}\n[00035.074] 01050.01053> {{{mmap:0x2fb0309e8000:0x1000:load:0x3:rw:0x1000}}}\n[00035.074] 01050.01053> dso: id=c189f51f19d10785d93b5235ad1b46dca4451b00 base=0x00002fb0309e7000 name=libasync-default.so\n[00035.074] 01050.01053> {{{module:0x2:<vDSO>:elf:40ab5fa3b61f12fef4a44477a687f608661cd450}}}\n[00035.074] 01050.01053> {{{mmap:0x544471d53000:0x7000:load:0x2:r:0}}}\n[00035.074] 01050.01053> {{{mmap:0x544471d5a000:0x1000:load:0x2:rx:0x7000}}}\n[00035.074] 01050.01053> dso: id=40ab5fa3b61f12fef4a44477a687f608661cd450 base=0x0000544471d53000 name=<vDSO>\n[00035.074] 01050.01053> {{{module:0x1:libc.so:elf:67a12284bce140fc32aaaeac223e0e8f85cb5085}}}\n[00035.074] 01050.01053> {{{mmap:0x628990242000:0xcb000:load:0x1:rx:0}}}\n[00035.074] 01050.01053> {{{mmap:0x62899030e000:0x6000:load:0x1:rw:0xcc000}}}\n[00035.074] 01050.01053> dso: id=67a12284bce140fc32aaaeac223e0e8f85cb5085 base=0x0000628990242000 name=libc.so\n[00035.074] 01050.01053> {{{module:0x4:libfdio.so:elf:27787977e95f3b9563c9e0bd4d34ec92b7e9ad88}}}\n[00035.074] 01050.01053> {{{mmap:0x1e28d9b3f000:0x24000:load:0x4:rx:0}}}\n[00035.074] 01050.01053> {{{mmap:0x1e28d9b64000:0x4000:load:0x4:rw:0x25000}}}\n[00035.074] 01050.01053> dso: id=27787977e95f3b9563c9e0bd4d34ec92b7e9ad88 base=0x00001e28d9b3f000 name=libfdio.so\n[00035.074] 01050.01053> {{{module:0x5:liblaunchpad.so:elf:6fc2232dc8c1bc5c6adb8ad50ca794b5a260ee4f}}}\n[00035.074] 01050.01053> {{{mmap:0x76de0ee64000:0x7000:load:0x5:rx:0}}}\n[00035.074] 01050.01053> {{{mmap:0x76de0ee6b000:0x2000:load:0x5:rw:0x7000}}}\n[00035.074] 01050.01053> dso: id=6fc2232dc8c1bc5c6adb8ad50ca794b5a260ee4f base=0x000076de0ee64000 name=liblaunchpad.so\n[00035.074] 01050.01053> {{{module:0x6:libtrace-engine.so:elf:c9042b83fe01206008fcefb16395238417248169}}}\n[00035.074] 01050.01053> {{{mmap:0x23474d6c2000:0x9000:load:0x6:rx:0}}}\n[00035.074] 01050.01053> {{{mmap:0x23474d6cb000:0x2000:load:0x6:rw:0x9000}}}\n[00035.074] 01050.01053> dso: id=c9042b83fe01206008fcefb16395238417248169 base=0x000023474d6c2000 name=libtrace-engine.so\n[00035.074] 01050.01053> bootsvc: Starting...\n[00035.074] 01036.01043> userboot: loader-service channel peer closed\n[00035.074] 01036.01043> userboot: finished!\n[00035.074] 01050.01053> bootsvc: Creating bootfs service...\n[00035.075] 01050.01053> bootsvc: Processing bootdata...\n[00035.075] 01050.01053> bootsvc: Loading boot cmdline overrides...\n[00035.075] 01050.01053> bootsvc: Loading kernel VMOs...\n[00035.075] 01050.01053> bootsvc: Creating loader service...\n[00035.075] 01050.01053> bootsvc: Launching next process...\n[00035.075] 01050.01096> bootsvc: launched bin/devmgr\n[00035.076] 01104.01117> devmgr: main()\n[00035.076] 01104.01117> cmdline: netsvc.disable=true\n[00035.076] 01104.01117> cmdline: zircon.system.disable-automount=true\n[00035.076] 01104.01117> cmdline: zircon.autorun.boot=/boot/infra/setup\n[00035.076] 01104.01117> cmdline: kernel.serial=legacy\n[00035.076] 01104.01117> cmdline: http://192.168.42.1/multiboot/d4%3A5d%3Adf%3A1a%3A42%3A86=\n[00035.076] 01104.01117> cmdline: multiboot.boot_loader_name=iPXE+1.0.0++(d2063)\n[00035.076] 01104.01117> devmgr: coordinator_init()\n[00035.076] 01104.01117> devmgr: init\n[00035.076] 01104.01117> devmgr: svc init\n[00035.076] 01104.01117> devmgr: launch /boot/bin/svchost (svchost) OK\n[00035.076] 01104.01117> devmgr: vfs init\n[00035.076] 01104.01117> devmgr: launch /boot/bin/fshost (fshost) OK\n[00035.076] 01104.01221> devmgr: shell startup\n[00035.077] 01182.01202> fshost: started.\n[00035.078] 01104.01212> devmgr: launch /boot/bin/pwrbtn-monitor (pwrbtn-monitor) OK\n[00035.078] 01104.01230> devmgr: launch /boot/bin/virtual-console (virtual-console) OK\n[00035.078] 01104.01230> zircon.autorun.boot: starting '/boot/infra/setup'...\n[00035.079] 01104.01230> devmgr: launch /boot/infra/setup (autorun:boot) OK\n[00035.082] 01104.01117> devcoord: launch devhost 'devhost:sys': pid=2049\n[00035.082] 01104.01117> devcoord: launch devhost 'devhost:test': pid=2082\n[00035.082] 01104.01117> devcoord: launch devhost 'devhost:root': pid=2115\n[00035.083] 01104.01117> devcoord: launch devhost 'devhost:misc': pid=2170\n[00035.083] 02049.02073> devhost: trace provider registry begun\n[00035.084] 02082.02105> devhost: trace provider registry begun\n[00035.086] 02115.02152> devhost: trace provider registry begun\n[00035.086] 02170.02203> devhost: trace provider registry begun\n[00035.088] 01104.01221> devmgr: launch /boot/bin/sh (sh:console) OK\n[00035.153] 02049.02073> acpi-bus: not using IOMMU\n[00035.158] 02049.02073> acpi-pwrbtn: initialized\n[00035.164] 02049.02073> WARNING: ACPI found bad _CRS address entry\n[00035.170] 02049.02073> WARNING: ACPI found bad _CRS address entry\n[00035.181] 02049.02073> acpi: published device pci(0x678bd8c76200), parent=proxy(0x678bd8c72540), handle=0x678bd8cae750\n[00035.183] 02049.02073> acpi: published device rtc(0x678bd8c71080), parent=acpi(0x678bd8c72780), handle=0x678bd8ccd330\n[00035.184] 02049.02073> acpi-ec: initialized\n[00035.185] 02049.02073> acpi: failed to create NHLT VMO (res -10)\n[00035.185] 02049.02073> acpi: failed to publish NHLT metadata\n[00035.188] 02049.02073> [sysmem_init 28] async_get_default_dispatcher(): 0x678bd8c650a0\n[00035.188] 02049.02073> [sysmem_bind 40] sysmem_bind()\n[00035.188] 02049.02073> acpi-bus: sysmem_register_protocol() intentionally ignored for now.\n[00035.188] 02049.02073> PMU: 7 arch events\n[00035.188] 02049.02073> PMU: arch event id range: 1-7\n[00035.188] 02049.02073> PMU: 102 model events\n[00035.188] 02049.02073> PMU: model event id range: 1-241\n[00035.188] 02049.02073> Intel Processor Trace configuration for this chipset:\n[00035.188] 02049.02073> mtc_freq_mask: 0x249\n[00035.188] 02049.02073> cyc_thresh_mask: 0x3fff\n[00035.188] 02049.02073> psb_freq_mask: 0x3f\n[00035.188] 02049.02073> num addr ranges: 2\n[00035.189] 01104.01117> devcoord: launch devhost 'devhost:pci#1:8086:5916': pid=2979\n[00035.189] 01245.01560> vc: new input device /dev/class/input/000\n[00035.189] 01104.01117> devcoord: launch devhost 'devhost:pci#3:8086:9d2f': pid=3078\n[00035.190] 01104.01117> devcoord: launch devhost 'devhost:pci#5:8086:9d60': pid=3145\n[00035.191] 01104.01117> devcoord: launch devhost 'devhost:pci#6:8086:9d61': pid=3210\n[00035.191] 02979.03042> devhost: trace provider registry begun\n[00035.191] 01104.01117> devcoord: launch devhost 'devhost:pci#9:8086:9d03': pid=3313\n[00035.192] 03078.03117> devhost: trace provider registry begun\n[00035.192] 01104.01117> devcoord: launch devhost 'devhost:pci#14:8086:9d71': pid=3416\n[00035.193] 01104.01117> devcoord: launch devhost 'devhost:pci#16:8086:156f': pid=3480\n[00035.193] 03145.03189> devhost: trace provider registry begun\n[00035.194] 03210.03264> devhost: trace provider registry begun\n[00035.195] 03145.03189> initialized intel serialio i2c driver, reg=0x21cdcfaea000 regsize=4096\n[00035.196] 03416.03456> devhost: trace provider registry begun\n[00035.196] 03480.03525> devhost: trace provider registry begun\n[00035.196] 03313.03362> devhost: trace provider registry begun\n[00035.197] 03210.03264> initialized intel serialio i2c driver, reg=0x70a0f62e2000 regsize=4096\n[00035.198] 03313.03362> ahci: using MSI interrupt\n[00035.207] 03416.03456> [IHDA DSP 00:1f.3] Failed to fetch NHLT (res -25)\n[00035.207] 03416.03456> devhost[00:1f.3/intel-hda-000/intel-sst-dsp-000] bind driver '/boot/driver/dsp.so' failed: -25\n[00035.207] 01104.01117> devcoord: rpc: bind-driver 'intel-sst-dsp-000' status -25\n[00035.216] 03078.03787> * found USB device (0x18d1:0xa002, USB 2.0) config 1\n[00035.216] 03078.03787> * found USB device (0x18d1:0xa003, USB 3.0) config 1\n[00035.298] 01245.01560> vc: new display device /dev/class/display-controller/000/virtcon\n[00035.439] 02979.04139> i915: MST not supported\n[00035.929] 03078.03787> * found USB device (0x0781:0x5583, USB 3.0) config 1\n[00035.929] 03078.03117> UMS: parent: 'ifc-000'\n[00035.929] 03078.03117> UMS:Max lun is: 0\n[00035.943] 02979.04139> i915: MST not supported\n[00036.679] 03078.03787> * found USB device (0x0cf3:0xe300, USB 2.1) config 1\n[00036.681] 03078.03117> devhost[00:14.0/xhci/usb-bus/002/002/ifc-001] bind driver '/boot/driver/bt-transport-usb.so' failed: -2\n[00036.681] 01104.01117> devcoord: rpc: bind-driver 'ifc-001' status -2\n[00036.932] 03078.04226> UMS: block size is: 0x00000200\n[00036.932] 03078.04226> UMS: total blocks is: 30031250\n[00036.932] 03078.04226> UMS: total size is: 15376000000\n[00036.932] 03078.04226> UMS: read-only: 0 removable: 1\n[00036.933] 01182.01202> devmgr: /dev/class/block/000: MBR?\n[00036.933] 01104.01117> devcoord: dc_bind_device() '/boot/driver/mbr.so'\n[00036.936] 01182.01202> devmgr: /dev/class/block/002: MBR?\n[00036.936] 01104.01117> devcoord: dc_bind_device() '/boot/driver/mbr.so'\n[00036.990] 02979.04139> i915: No displays detected\n[00037.198] 03145.03189> intel-i2c-controller: intel_serialio_i2c_slave_transfer: -21\n[00037.198] 03145.03189> i2c-hid: could not read HID descriptor: 0\n[00037.198] 03145.03189> devhost[00:15.0/i2c-bus-9d60/0020] bind driver '/boot/driver/i2c-hid.so' failed: -2\n[00037.198] 01104.01117> devcoord: rpc: bind-driver '0020' status -2\n[00037.198] 03210.03264> intel-i2c-controller: intel_serialio_i2c_slave_transfer: -21\n[00037.198] 03210.03264> i2c-hid: could not read HID descriptor: 0\n[00037.198] 03210.03264> devhost[00:15.1/i2c-bus-9d61/004c] bind driver '/boot/driver/i2c-hid.so' failed: -2\n[00037.198] 01104.01117> devcoord: rpc: bind-driver '004c' status -2\n[00037.212] 03313.03920> sata2: dev info\n[00037.212] 03313.03920> serial=711430953015 6 \n[00037.212] 03313.03920> firmware rev=1Q01A7 0\n[00037.212] 03313.03920> model id=IBIW NSS D \n[00037.212] 03313.03920> major=0x3f0 ACS2 DMA 32 commands\n[00037.212] 03313.03920> LBA48 234441648 sectors, sector size=512\n[00037.215] 04480.04494> paver:[InitializeGpt] Located GPT is invalid; Attempting to initialize\n[00037.215] 01104.01117> devcoord: dc_bind_device() '/boot/driver/gpt.so'\n[00037.215] 03313.03362> gpt: device_get_metadata failed (-25)\n[00037.216] 04480.04494> paver:[Initialize] Successfully initialized EFI Device Partitioner\n[00037.217] 01104.01117> devcoord: dc_bind_device() ''\n[00037.217] 01182.01202> devmgr: /dev/class/block/003: GPT?\n[00037.217] 01104.01117> devcoord: dc_bind_device() '/boot/driver/gpt.so'\n[00037.217] 03313.03362> gpt: device_get_metadata failed (-25)\n[00037.219] 04638.04662> 34+0 records in\n[00037.219] 04638.04662> 34+0 records out\n[00037.219] 04638.04662> 17408 bytes copied\n[00037.220] 04753.04767> Failed to seek on output\n[00037.220] 04753.04767> 0+0 records in\n[00037.220] 04753.04767> 0+0 records out\n[00037.220] 04753.04767> 0 bytes copied\n[00037.221] 04823.04837> netifc: ? /dev/class/ethernet/000\n[00037.221] 04823.04837> netifc: create 512 eth buffers\n[00037.221] 04823.04837> macaddr: d4:5d:df:1a:42:86\n[00037.221] 04823.04837> ip6addr: fe80::d65d:df4d:fe1a:4286\n[00037.221] 04823.04837> snmaddr: ff02::1:ff1a:4286\n[00037.222] 04823.04837> netsvc: using /dev/class/ethernet/000\n[00037.222] 04823.04837> _ _ _ \n[00037.222] 04823.04837> | | | | | \n[00037.222] 04823.04837> _______ __| | |__ ___ ___ | |_ \n[00037.222] 04823.04837> |_ / _ \\/ _` | '_ \\ / _ \\ / _ \\| __|\n[00037.222] 04823.04837> / / __/ (_| | |_) | (_) | (_) | |_ \n[00037.222] 04823.04837> /___\\___|\\__,_|_.__/ \\___/ \\___/ \\__|\n[00037.222] 04823.04837> \n[00037.222] 04823.04837> \n[00037.222] 04823.04837> zedboot: version: 0.7.13\n[00037.222] 04823.04837> \n[00037.222] 04823.04837> netsvc: nodename='ocean-drank-wick-plug'\n[00037.222] 04823.04837> netsvc: will not advertise\n[00037.222] 04823.04837> netsvc: start\n[00566.484] 04823.04837> netsvc: tftp write of file <<netboot>>cmdline completed\n[00566.484] 04823.04837> netsvc: metrics: {\"inorderblks\": 1,\"oooblks\": 0,\"ack\": 1,\"nack\": 0,\"timeouts\": 0,\"sas\": 0,\"inorderbytes\": 55}\n[00566.484] 04823.04837> netsvc: Running FVM Paver\n[00566.486] 04823.04931> paver:[InitializeGpt] Located GPT is invalid; Attempting to initialize\n[00566.486] 01104.01117> devcoord: dc_bind_device() ''\n[00566.486] 01104.01117> devcoord: dc_bind_device() '/boot/driver/gpt.so'\n[00566.486] 03313.03362> gpt: device_get_metadata failed (-25)\n[00566.487] 01182.01202> devmgr: /dev/class/block/003: GPT?\n[00566.487] 01104.01117> devcoord: dc_bind_device() '/boot/driver/gpt.so'\n[00566.487] 03313.03362> devhost: rpc:bind-device failed: -20\n[00566.488] 04823.04931> paver:[Initialize] Successfully initialized EFI Device Partitioner\n[00566.488] 04823.04931> paver:[PartitionPave] Paving partition.\n[00566.488] 04823.04931> paver:[FindFirstFit] Looking for space\n[00566.488] 04823.04931> paver:[FindFirstFit] Sorting\n[00566.488] 04823.04931> paver:[FindFirstFit] Partition[0] From Block [0, 34) ... (next partition starts at block 234441614)\n[00566.488] 04823.04931> paver:[FindFirstFit] There are 234441580 free blocks (16777216 requested)\n[00566.488] 04823.04931> paver:[AddPartition] Found space in GPT - OK 234441580 @ 34\n[00566.488] 04823.04931> paver:[AddPartition] Final space in GPT - OK 16777216 @ 34\n[00566.488] 04823.04931> paver:[AddPartition] Added partition, waiting for bind\n[00566.488] 01104.01117> devcoord: dc_bind_device() ''\n[00566.489] 01182.01202> devmgr: /dev/class/block/003: GPT?\n[00566.489] 01104.01117> devcoord: dc_bind_device() '/boot/driver/gpt.so'\n[00566.489] 03313.03362> gpt: device_get_metadata failed (-25)\n[00566.490] 04823.04931> paver:[AddPartition] Added partition, waiting for bind - OK\n[00566.490] 04823.04931> paver:[PartitionPave] Streaming partitions...\n[00566.490] 04911.04925> Found compressed file\n[00566.490] 04823.04931> paver:[FvmStreamPartitions] Header Validated - OK\n[00566.490] 04823.04931> paver:[FvmPartitionFormat] Initializing partition as FVM\n[00566.493] 01104.01117> devcoord: dc_bind_device() '/boot/driver/fvm.so'\n[00567.495] 04823.04931> paver:[FvmStreamPartitions] Partitions pre-validated successfully: Enough space exists to pave.\n[00567.495] 04823.04931> paver:[AllocatePartitions] Allocating partition blobfs consisting of 1 slices\n[00567.498] 04823.04931> paver:[AllocatePartitions] Allocating partition minfs consisting of 1 slices\n[00567.500] 04823.04931> paver:[AllocatePartitions] Creating zxcrypt volume\n[00567.501] 03313.03362> devhost_get_handles(0x32252f7cc9c0:block) open path='zxcrypt/block', r=-2\n[00567.501] 01104.01117> devcoord: dc_bind_device() '/boot/driver/zxcrypt.so'\n[00567.502] 03313.03362> devhost_get_handles(0x32252f7cc9c0:block) open path='zxcrypt', r=-2\n[00567.505] 04823.04931> paver:[FvmStreamPartitions] Partition space pre-allocated successfully.\n[00567.506] 04823.04931> paver:[FvmStreamPartitions] Streaming partition 0\n[00567.506] 04823.04931> paver:[StreamFvmPartition] Writing extent 0... \n[00567.506] 04823.04937> netsvc: paver write progress 0.2%\n[00567.506] 04823.04931> paver:[StreamFvmPartition] 8192 bytes written, 8380416 zeroes left\n[00567.526] 04823.04931> paver:[StreamFvmPartition] Writing extent 1... \n[00567.526] 04823.04931> paver:[StreamFvmPartition] 8192 bytes written, 8380416 zeroes left\n[00567.543] 04823.04931> paver:[StreamFvmPartition] Writing extent 2... \n[00567.548] 04823.04931> paver:[StreamFvmPartition] 2097152 bytes written, 6291456 zeroes left\n[00567.564] 04823.04931> paver:[StreamFvmPartition] Writing extent 3... \n[00567.569] 04823.04931> paver:[StreamFvmPartition] 2097152 bytes written, 6291456 zeroes left\n[00567.581] 04823.04931> paver:[StreamFvmPartition] Writing extent 4... \n[00568.506] 04823.04937> netsvc: paver write progress 12.8%\n[00569.506] 04823.04937> netsvc: paver write progress 19.4%\n[00000.000] 00000.00000> VM: marking boot alloc used range [0x239f000, 0x239f100)\n[00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00147abc (elf_build_id) at level 0x4fffe, flags 0x1\n[00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00147c48 (version) at level 0x4ffff, flags 0x1\n[00000.000] 00000.00000> version:\n[00000.000] 00000.00000> \tarch: x86\n[00000.000] 00000.00000> \tplatform: pc\n[00000.000] 00000.00000> \ttarget: pc\n[00000.000] 00000.00000> \tproject: x64\n[00000.000] 00000.00000> \tbuildid: git-13ee3dc5e4c46bf127977ad28645c47442ec517d\n[00000.000] 00000.00000> \tELF build ID: 5f3e39bd4ed89d3b8122947842f1eac846a04683\n[00000.000] 00000.00000> initializing heap\n[00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00102e1c (x86_resource_init) at level 0x50000, flags 0x1\n[00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001a9630 (console) at level 0x50000, flags 0x1\n[00000.000] 00000.00000> initializing vm\n[00000.000] 00000.00000> VM: reserving kernel region [0xffffffff00100000, 0xffffffff001ee000) flags 0x28 name 'kernel_code'\n[00000.000] 00000.00000> VM: reserving kernel region [0xffffffff001ee000, 0xffffffff00232000) flags 0x8 name 'kernel_rodata'\n[00000.000] 00000.00000> VM: reserving kernel region [0xffffffff00232000, 0xffffffff00242000) flags 0x18 name 'kernel_data'\n[00000.000] 00000.00000> VM: reserving kernel region [0xffffffff00242000, 0xffffffff002c6000) flags 0x18 name 'kernel_bss'\n[00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00103ae0 (display_memtype) at level 0x60001, flags 0x1\n[00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00138fa0 (acpi_tables) at level 0x60001, flags 0x1\n[00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00101c40 (hpet) at level 0x60002, flags 0x1\n[00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00102000 (apic) at level 0x60002, flags 0x1\n[00000.000] 00000.00000> x2APIC enabled\n[00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001061b4 (timer) at level 0x60003, flags 0x1\n[00000.000] 00000.00000> HPET frequency: 23999 ticks/ms\n[00000.000] 00000.00000> TSC frequency: 2712000 ticks/ms\n[00021.436] 00000.00000> timer features: constant_tsc 1 invariant_tsc 1 tsc_deadline 1\n[00021.436] 00000.00000> Using TSC as wallclock\n[00021.436] 00000.00000> initializing kernel\n[00021.436] 00000.00000> initializing mp\n[00021.436] 00000.00000> initializing timers\n[00021.436] 00000.00000> INIT: cpu 0, calling hook 0xffffffff0013c578 (debuglog) at level 0x7ffff, flags 0x1\n[00021.436] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00195518 (thread_set_priority_experiment) at level 0x7ffff, flags 0x1\n[00021.436] 00000.00000> thread set priority experiment is : ENABLED\n[00021.436] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001aa67c (global_prng_thread_safe) at level 0x7ffff, flags 0x1\n[00021.436] 00000.00000> creating bootstrap completion thread\n[00021.779] 00000.00000> top of bootstrap2()\n[00021.779] 00000.00000> INIT: cpu 0, calling hook 0xffffffff0013151c (dpc) at level 0x80000, flags 0x1\n[00021.792] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00152978 (libobject) at level 0x80000, flags 0x1\n[00021.792] 00000.00000> OOM: started thread\n[00021.806] 00000.00000> Processor Model Info: type 0 family 0x6 model 0xe stepping 0x9\n[00021.806] 00000.00000> \tdisplay_family 0x6 display_model 0x8e\n[00021.806] 00000.00000> Vendor: Intel\n[00021.806] 00000.00000> Microarch: Kaby Lake\n[00021.806] 00000.00000> F/M/S: 6/8e/9\n[00021.806] 00000.00000> Brand: Intel(R) Core(TM) i5-7300U CPU @ 2.60GHz\n[00021.806] 00000.00000> Features: fpu sse sse2 sse3 ssse3 sse4.1 sse4.2 mmx avx avx2 fxsr pcid xsave mon aesni clflush \n[00021.806] 00000.00000> clflushopt fsgsbase tsc_adj smep smap erms rdrand rdseed syscall nx huge rdtscp \n[00021.806] 00000.00000> invar_tsc tsc_deadline x2apic vmx pt hwp \n[00021.806] 00000.00000> initializing platform\n[00021.806] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001101f4 (x86_perfmon) at level 0x90000, flags 0x1\n[00021.806] 00000.00000> PMU: version 4\n[00021.806] 00000.00000> UART: started IRQ driven RX\n[00021.806] 00000.00000> UART: started IRQ driven TX\n[00021.806] 00000.00000> cpu topology:\n[00021.806] 00000.00000> \t0: apic id 0x0 package 0 node 0 core 0 smt 0 BSP\n[00021.806] 00000.00000> \t1: apic id 0x2 package 0 node 0 core 1 smt 0\n[00021.806] 00000.00000> \t2: apic id 0x1 package 0 node 0 core 0 smt 1\n[00021.806] 00000.00000> \t3: apic id 0x3 package 0 node 0 core 1 smt 1\n[00021.806] 00000.00000> Found 4 cpus\n[00021.806] 00000.00000> booting apic ids: 0x2 0x1 0x3 \n[00021.822] 00000.00000> entering scheduler on cpu 2\n[00021.823] 00000.00000> entering scheduler on cpu 3\n[00021.823] 00000.00000> entering scheduler on cpu 1\n[00021.826] 00000.00000> smbios: manufacturer=\"Intel Corporation\" product=\"NUC7i5DNHE\"\n[00021.826] 00000.00000> initializing target\n[00021.826] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001053a0 (x86_pcie_init) at level 0xa0000, flags 0x1\n[00021.826] 00000.00000> moving to last init level\n[00021.826] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00144140 (ktrace) at level 0xc0000, flags 0x1\n[00021.829] 00000.00000> ktrace: buffer at 0xffffff9877ace000 (33554432 bytes)\n[00021.829] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00147ab4 (userboot) at level 0xc0000, flags 0x1\n[00021.829] 00000.00000> userboot: ramdisk 0x10ad000 @ 0xffffff80012f2000\n[00021.830] 00000.00000> userboot: userboot rodata 0 @ [0x1194ac047000,0x1194ac04a000)\n[00021.830] 00000.00000> userboot: userboot code 0x3000 @ [0x1194ac04a000,0x1194ac055000)\n[00021.830] 00000.00000> userboot: vdso/full rodata 0 @ [0x1194ac055000,0x1194ac05c000)\n[00021.830] 00000.00000> userboot: vdso/full code 0x7000 @ [0x1194ac05c000,0x1194ac05d000)\n[00021.830] 00000.00000> userboot: entry point @ 0x1194ac04ac10\n[00021.830] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001aa030 (kernel_shell) at level 0xc0000, flags 0x1\n[00021.830] 01036.01043> userboot: option \"netsvc.disable=true\"\n[00021.830] 01036.01043> userboot: option \"zircon.system.disable-automount=true\"\n[00021.830] 01036.01043> userboot: option \"zircon.autorun.boot=/boot/infra/setup\"\n[00021.830] 01036.01043> userboot: option \"kernel.serial=legacy\"\n[00021.830] 01036.01043> userboot: option \"http://192.168.42.1/multiboot/d4%3A5d%3Adf%3A1a%3A43%3A25=\"\n[00021.830] 01036.01043> userboot: option \"multiboot.boot_loader_name=iPXE+1.0.0++(d2063)\"\n[00021.869] 01036.01043> userboot: searching bootfs for 'bin/bootsvc'\n[00021.869] 01036.01043> userboot: 'bin/bootsvc' has PT_INTERP \"lib/ld.so.1\"\n[00021.869] 01036.01043> userboot: searching bootfs for 'lib/ld.so.1'\n[00021.869] 01036.01043> userboot: userboot: loaded lib/ld.so.1 at 0x4e901e0cd000, entry point 0x4e901e1530d3\n[00021.869] 01036.01043> userboot: userboot: loaded vDSO at 0x4479dad8c000, entry point 0x0\n[00021.869] 01036.01043> userboot: process bin/bootsvc started.\n[00021.869] 01036.01043> userboot: waiting for loader-service requests...\n[00021.869] 01036.01043> userboot: searching bootfs for 'lib/libasync-default.so'\n[00021.869] 01036.01043> userboot: searching bootfs for 'lib/libfdio.so'\n[00021.869] 01036.01043> userboot: searching bootfs for 'lib/liblaunchpad.so'\n[00021.869] 01036.01043> userboot: searching bootfs for 'lib/libtrace-engine.so'\n[00021.870] 01050.01053> {{{reset}}}\n[00021.870] 01050.01053> {{{module:0:<application>:elf:18de7d58f51e8ba5c4f6afdd0cc8440f482c2b45}}}\n[00021.870] 01050.01053> {{{mmap:0x36233ba7b000:0x2e000:load:0:rx:0}}}\n[00021.870] 01050.01053> {{{mmap:0x36233baa9000:0x4000:load:0:rw:0x2e000}}}\n[00021.870] 01050.01053> dso: id=18de7d58f51e8ba5c4f6afdd0cc8440f482c2b45 base=0x000036233ba7b000 name=<application>\n[00021.870] 01050.01053> {{{module:0x3:libasync-default.so:elf:c189f51f19d10785d93b5235ad1b46dca4451b00}}}\n[00021.870] 01050.01053> {{{mmap:0x59946c50f000:0x1000:load:0x3:rx:0}}}\n[00021.870] 01050.01053> {{{mmap:0x59946c510000:0x1000:load:0x3:rw:0x1000}}}\n[00021.870] 01050.01053> dso: id=c189f51f19d10785d93b5235ad1b46dca4451b00 base=0x000059946c50f000 name=libasync-default.so\n[00021.870] 01050.01053> {{{module:0x2:<vDSO>:elf:40ab5fa3b61f12fef4a44477a687f608661cd450}}}\n[00021.870] 01050.01053> {{{mmap:0x4479dad8c000:0x7000:load:0x2:r:0}}}\n[00021.870] 01050.01053> {{{mmap:0x4479dad93000:0x1000:load:0x2:rx:0x7000}}}\n[00021.870] 01050.01053> dso: id=40ab5fa3b61f12fef4a44477a687f608661cd450 base=0x00004479dad8c000 name=<vDSO>\n[00021.870] 01050.01053> {{{module:0x1:libc.so:elf:67a12284bce140fc32aaaeac223e0e8f85cb5085}}}\n[00021.870] 01050.01053> {{{mmap:0x4e901e0cd000:0xcb000:load:0x1:rx:0}}}\n[00021.870] 01050.01053> {{{mmap:0x4e901e199000:0x6000:load:0x1:rw:0xcc000}}}\n[00021.870] 01050.01053> dso: id=67a12284bce140fc32aaaeac223e0e8f85cb5085 base=0x00004e901e0cd000 name=libc.so\n[00021.870] 01050.01053> {{{module:0x4:libfdio.so:elf:27787977e95f3b9563c9e0bd4d34ec92b7e9ad88}}}\n[00021.870] 01050.01053> {{{mmap:0x20985eb80000:0x24000:load:0x4:rx:0}}}\n[00021.870] 01050.01053> {{{mmap:0x20985eba5000:0x4000:load:0x4:rw:0x25000}}}\n[00021.870] 01050.01053> dso: id=27787977e95f3b9563c9e0bd4d34ec92b7e9ad88 base=0x000020985eb80000 name=libfdio.so\n[00021.870] 01050.01053> {{{module:0x5:liblaunchpad.so:elf:6fc2232dc8c1bc5c6adb8ad50ca794b5a260ee4f}}}\n[00021.870] 01050.01053> {{{mmap:0x49baacda3000:0x7000:load:0x5:rx:0}}}\n[00021.870] 01050.01053> {{{mmap:0x49baacdaa000:0x2000:load:0x5:rw:0x7000}}}\n[00021.870] 01050.01053> dso: id=6fc2232dc8c1bc5c6adb8ad50ca794b5a260ee4f base=0x000049baacda3000 name=liblaunchpad.so\n[00021.870] 01050.01053> {{{module:0x6:libtrace-engine.so:elf:c9042b83fe01206008fcefb16395238417248169}}}\n[00021.870] 01050.01053> {{{mmap:0x149c19482000:0x9000:load:0x6:rx:0}}}\n[00021.870] 01050.01053> {{{mmap:0x149c1948b000:0x2000:load:0x6:rw:0x9000}}}\n[00021.870] 01050.01053> dso: id=c9042b83fe01206008fcefb16395238417248169 base=0x0000149c19482000 name=libtrace-engine.so\n[00021.870] 01050.01053> bootsvc: Starting...\n[00021.870] 01036.01043> userboot: loader-service channel peer closed\n[00021.870] 01036.01043> userboot: finished!\n[00021.870] 01050.01053> bootsvc: Creating bootfs service...\n[00021.870] 01050.01053> bootsvc: Processing bootdata...\n[00021.870] 01050.01053> bootsvc: Loading boot cmdline overrides...\n[00021.870] 01050.01053> bootsvc: Loading kernel VMOs...\n[00021.870] 01050.01053> bootsvc: Creating loader service...\n[00021.870] 01050.01053> bootsvc: Launching next process...\n[00021.871] 01050.01096> bootsvc: launched bin/devmgr\n[00021.871] 01104.01117> devmgr: main()\n[00021.871] 01104.01117> cmdline: netsvc.disable=true\n[00021.871] 01104.01117> cmdline: zircon.system.disable-automount=true\n[00021.871] 01104.01117> cmdline: zircon.autorun.boot=/boot/infra/setup\n[00021.871] 01104.01117> cmdline: kernel.serial=legacy\n[00021.871] 01104.01117> cmdline: http://192.168.42.1/multiboot/d4%3A5d%3Adf%3A1a%3A43%3A25=\n[00021.871] 01104.01117> cmdline: multiboot.boot_loader_name=iPXE+1.0.0++(d2063)\n[00021.871] 01104.01117> devmgr: coordinator_init()\n[00021.871] 01104.01117> devmgr: init\n[00021.871] 01104.01117> devmgr: svc init\n[00021.871] 01104.01117> devmgr: launch /boot/bin/svchost (svchost) OK\n[00021.871] 01104.01117> devmgr: vfs init\n[00021.872] 01104.01117> devmgr: launch /boot/bin/fshost (fshost) OK\n[00021.872] 01104.01222> devmgr: shell startup\n[00021.873] 01182.01202> fshost: started.\n[00021.874] 01104.01212> devmgr: launch /boot/bin/pwrbtn-monitor (pwrbtn-monitor) OK\n[00021.874] 01104.01231> devmgr: launch /boot/bin/virtual-console (virtual-console) OK\n[00021.874] 01104.01231> zircon.autorun.boot: starting '/boot/infra/setup'...\n[00021.875] 01104.01231> devmgr: launch /boot/infra/setup (autorun:boot) OK\n[00021.877] 01104.01117> devcoord: launch devhost 'devhost:sys': pid=2049\n[00021.878] 01104.01117> devcoord: launch devhost 'devhost:test': pid=2082\n[00021.878] 01104.01117> devcoord: launch devhost 'devhost:root': pid=2115\n[00021.878] 01104.01117> devcoord: launch devhost 'devhost:misc': pid=2170\n[00021.879] 02049.02073> devhost: trace provider registry begun\n[00021.879] 02082.02106> devhost: trace provider registry begun\n[00021.881] 02115.02156> devhost: trace provider registry begun\n[00021.881] 02170.02218> devhost: trace provider registry begun\n[00021.883] 01104.01222> devmgr: launch /boot/bin/sh (sh:console) OK\n[00021.948] 02049.02073> acpi-bus: not using IOMMU\n[00021.952] 02049.02073> acpi-pwrbtn: initialized\n[00021.958] 02049.02073> WARNING: ACPI found bad _CRS address entry\n[00021.964] 02049.02073> WARNING: ACPI found bad _CRS address entry\n[00021.975] 02049.02073> acpi: published device pci(0x28e9f78d3200), parent=proxy(0x28e9f78cf540), handle=0x28e9f790b750\n[00021.976] 02049.02073> acpi: published device rtc(0x28e9f78ce080), parent=acpi(0x28e9f78cf780), handle=0x28e9f792a330\n[00021.977] 02049.02073> acpi-ec: initialized\n[00021.978] 02049.02073> acpi: failed to create NHLT VMO (res -10)\n[00021.978] 02049.02073> acpi: failed to publish NHLT metadata\n[00021.981] 02049.02073> [sysmem_init 28] async_get_default_dispatcher(): 0x28e9f78c20a0\n[00021.981] 02049.02073> [sysmem_bind 40] sysmem_bind()\n[00021.981] 02049.02073> acpi-bus: sysmem_register_protocol() intentionally ignored for now.\n[00021.981] 02049.02073> PMU: 7 arch events\n[00021.981] 02049.02073> PMU: arch event id range: 1-7\n[00021.981] 02049.02073> PMU: 102 model events\n[00021.981] 02049.02073> PMU: model event id range: 1-241\n[00021.981] 02049.02073> Intel Processor Trace configuration for this chipset:\n[00021.981] 02049.02073> mtc_freq_mask: 0x249\n[00021.981] 02049.02073> cyc_thresh_mask: 0x3fff\n[00021.981] 02049.02073> psb_freq_mask: 0x3f\n[00021.981] 02049.02073> num addr ranges: 2\n[00021.982] 01242.01554> vc: new input device /dev/class/input/000\n[00021.982] 01104.01117> devcoord: launch devhost 'devhost:pci#1:8086:5916': pid=3012\n[00021.983] 01104.01117> devcoord: launch devhost 'devhost:pci#3:8086:9d2f': pid=3074\n[00021.984] 01104.01117> devcoord: launch devhost 'devhost:pci#5:8086:9d60': pid=3155\n[00021.984] 03012.03048> devhost: trace provider registry begun\n[00021.984] 03074.03132> devhost: trace provider registry begun\n[00021.984] 01104.01117> devcoord: launch devhost 'devhost:pci#6:8086:9d61': pid=3235\n[00021.985] 01104.01117> devcoord: launch devhost 'devhost:pci#9:8086:9d03': pid=3337\n[00021.985] 03155.03208> devhost: trace provider registry begun\n[00021.986] 01104.01117> devcoord: launch devhost 'devhost:pci#14:8086:9d71': pid=3425\n[00021.986] 03235.03301> devhost: trace provider registry begun\n[00021.986] 01104.01117> devcoord: launch devhost 'devhost:pci#16:8086:156f': pid=3515\n[00021.987] 03337.03376> devhost: trace provider registry begun\n[00021.988] 03337.03376> ahci: using MSI interrupt\n[00021.988] 03155.03208> initialized intel serialio i2c driver, reg=0x244f3641b000 regsize=4096\n[00021.988] 03515.03556> devhost: trace provider registry begun\n[00021.988] 03425.03483> devhost: trace provider registry begun\n[00021.990] 03235.03301> initialized intel serialio i2c driver, reg=0x7d59bcd85000 regsize=4096\n[00021.993] 03074.03848> * found USB device (0x18d1:0xa002, USB 2.0) config 1\n[00022.000] 03074.03848> * found USB device (0x18d1:0xa003, USB 3.0) config 1\n[00022.000] 03425.03483> [IHDA DSP 00:1f.3] Failed to fetch NHLT (res -25)\n[00022.000] 03425.03483> devhost[00:1f.3/intel-hda-000/intel-sst-dsp-000] bind driver '/boot/driver/dsp.so' failed: -25\n[00022.000] 01104.01117> devcoord: rpc: bind-driver 'intel-sst-dsp-000' status -25\n[00022.092] 01242.01554> vc: new display device /dev/class/display-controller/000/virtcon\n[00022.233] 03012.04139> i915: MST not supported\n[00022.712] 03074.03848> * found USB device (0x0781:0x5583, USB 3.0) config 1\n[00022.713] 03074.03132> UMS: parent: 'ifc-000'\n[00022.713] 03074.03132> UMS:Max lun is: 0\n[00022.737] 03012.04139> i915: MST not supported\n[00023.463] 03074.03848> * found USB device (0x0cf3:0xe300, USB 2.1) config 1\n[00023.464] 03074.03132> devhost[00:14.0/xhci/usb-bus/002/002/ifc-001] bind driver '/boot/driver/bt-transport-usb.so' failed: -2\n[00023.464] 01104.01117> devcoord: rpc: bind-driver 'ifc-001' status -2\n[00023.700] 03012.04139> i915: No displays detected\n[00023.716] 03074.04226> UMS: block size is: 0x00000200\n[00023.716] 03074.04226> UMS: total blocks is: 30031250\n[00023.716] 03074.04226> UMS: total size is: 15376000000\n[00023.716] 03074.04226> UMS: read-only: 0 removable: 1\n[00023.718] 01182.01202> devmgr: /dev/class/block/000: MBR?\n[00023.718] 01104.01117> devcoord: dc_bind_device() '/boot/driver/mbr.so'\n[00023.720] 01182.01202> devmgr: /dev/class/block/002: MBR?\n[00023.720] 01104.01117> devcoord: dc_bind_device() '/boot/driver/mbr.so'\n[00023.991] 03155.03208> intel-i2c-controller: intel_serialio_i2c_slave_transfer: -21\n[00023.991] 03155.03208> i2c-hid: could not read HID descriptor: 0\n[00023.991] 03155.03208> devhost[00:15.0/i2c-bus-9d60/0020] bind driver '/boot/driver/i2c-hid.so' failed: -2\n[00023.991] 01104.01117> devcoord: rpc: bind-driver '0020' status -2\n[00023.991] 03235.03301> intel-i2c-controller: intel_serialio_i2c_slave_transfer: -21\n[00023.991] 03235.03301> i2c-hid: could not read HID descriptor: 0\n[00023.991] 03235.03301> devhost[00:15.1/i2c-bus-9d61/004c] bind driver '/boot/driver/i2c-hid.so' failed: -2\n[00023.991] 01104.01117> devcoord: rpc: bind-driver '004c' status -2\n[00024.005] 03337.03802> sata2: dev info\n[00024.005] 03337.03802> serial=711430953055 2 \n[00024.005] 03337.03802> firmware rev=1Q01A7 0\n[00024.005] 03337.03802> model id=IBIW NSS D \n[00024.005] 03337.03802> major=0x3f0 ACS2 DMA 32 commands\n[00024.005] 03337.03802> LBA48 234441648 sectors, sector size=512\n[00024.006] 01182.01202> devmgr: /dev/class/block/003: GPT?\n[00024.007] 01104.01117> devcoord: dc_bind_device() '/boot/driver/gpt.so'\n[00024.007] 03337.03376> gpt: device_get_metadata failed (-25)\n[00024.008] 01182.01202> devmgr: /dev/class/block/004: FVM?\n[00024.008] 01104.01117> devcoord: dc_bind_device() '/boot/driver/fvm.so'\n[00024.010] 04480.04494> paver:[Initialize] Successfully initialized EFI Device Partitioner\n[00024.012] 04480.04494> paver:[WipePartitions] Immediate reboot strongly recommended\n[00024.012] 03337.03376> block: Joining un-closed FIFO server\n[00024.012] 03337.03376> block: Joining un-closed FIFO server\n[00024.012] 03337.03376> block: Joining un-closed FIFO server\n[00024.012] 01104.01117> devcoord: dc_bind_device() ''\n[00024.013] 01182.01202> devmgr: /dev/class/block/003: GPT?\n[00024.013] 01104.01117> devcoord: dc_bind_device() '/boot/driver/gpt.so'\n[00024.013] 03337.03376> gpt: device_get_metadata failed (-25)\n[00024.016] 04799.04813> 34+0 records in\n[00024.016] 04799.04813> 34+0 records out\n[00024.016] 04799.04813> 17408 bytes copied\n[00024.016] 04917.04931> Failed to seek on output\n[00024.016] 04917.04931> 0+0 records in\n[00024.016] 04917.04931> 0+0 records out\n[00024.016] 04917.04931> 0 bytes copied\n[00024.017] 04987.05001> netifc: ? /dev/class/ethernet/000\n[00024.018] 04987.05001> netifc: create 512 eth buffers\n[00024.018] 04987.05001> macaddr: d4:5d:df:1a:43:25\n[00024.018] 04987.05001> ip6addr: fe80::d65d:df4d:fe1a:4325\n[00024.018] 04987.05001> snmaddr: ff02::1:ff1a:4325\n[00024.018] 04987.05001> netsvc: using /dev/class/ethernet/000\n[00024.018] 04987.05001> _ _ _ \n[00024.018] 04987.05001> | | | | | \n[00024.018] 04987.05001> _______ __| | |__ ___ ___ | |_ \n[00024.018] 04987.05001> |_ / _ \\/ _` | '_ \\ / _ \\ / _ \\| __|\n[00024.018] 04987.05001> / / __/ (_| | |_) | (_) | (_) | |_ \n[00024.018] 04987.05001> /___\\___|\\__,_|_.__/ \\___/ \\___/ \\__|\n[00024.018] 04987.05001> \n[00024.018] 04987.05001> \n[00024.018] 04987.05001> zedboot: version: 0.7.13\n[00024.018] 04987.05001> \n[00024.018] 04987.05001> netsvc: nodename='siren-bats-wick-hasty'\n[00024.018] 04987.05001> netsvc: will not advertise\n[00024.018] 04987.05001> netsvc: start\n[00869.020] 04987.05001> netsvc: tftp write of file <<netboot>>cmdline completed\n[00869.020] 04987.05001> netsvc: metrics: {\"inorderblks\": 1,\"oooblks\": 0,\"ack\": 1,\"nack\": 0,\"timeouts\": 0,\"sas\": 0,\"inorderbytes\": 55}\n[00869.020] 04987.05001> netsvc: Running FVM Paver\n[00869.022] 04987.05095> paver:[InitializeGpt] Located GPT is invalid; Attempting to initialize\n[00869.023] 01104.01117> devcoord: dc_bind_device() ''\n[00869.023] 01104.01117> devcoord: dc_bind_device() '/boot/driver/gpt.so'\n[00869.023] 03337.03376> gpt: device_get_metadata failed (-25)\n[00869.024] 01182.01202> devmgr: /dev/class/block/003: GPT?\n[00869.024] 01104.01117> devcoord: dc_bind_device() '/boot/driver/gpt.so'\n[00869.024] 03337.03376> devhost: rpc:bind-device failed: -20\n[00869.025] 04987.05095> paver:[Initialize] Successfully initialized EFI Device Partitioner\n[00869.025] 04987.05095> paver:[PartitionPave] Paving partition.\n[00869.025] 04987.05095> paver:[FindFirstFit] Looking for space\n[00869.025] 04987.05095> paver:[FindFirstFit] Sorting\n[00869.025] 04987.05095> paver:[FindFirstFit] Partition[0] From Block [0, 34) ... (next partition starts at block 234441614)\n[00869.025] 04987.05095> paver:[FindFirstFit] There are 234441580 free blocks (16777216 requested)\n[00869.025] 04987.05095> paver:[AddPartition] Found space in GPT - OK 234441580 @ 34\n[00869.025] 04987.05095> paver:[AddPartition] Final space in GPT - OK 16777216 @ 34\n[00869.025] 04987.05095> paver:[AddPartition] Added partition, waiting for bind\n[00869.025] 01104.01117> devcoord: dc_bind_device() ''\n[00869.026] 01182.01202> devmgr: /dev/class/block/003: GPT?\n[00869.026] 01104.01117> devcoord: dc_bind_device() '/boot/driver/gpt.so'\n[00869.026] 03337.03376> gpt: device_get_metadata failed (-25)\n[00869.026] 04987.05095> paver:[AddPartition] Added partition, waiting for bind - OK\n[00869.026] 04987.05095> paver:[PartitionPave] Streaming partitions...\n[00869.026] 05075.05089> Found compressed file\n[00869.026] 04987.05095> paver:[FvmStreamPartitions] Header Validated - OK\n[00869.027] 04987.05095> paver:[FvmPartitionFormat] Initializing partition as FVM\n[00869.029] 01104.01117> devcoord: dc_bind_device() '/boot/driver/fvm.so'\n[00870.031] 04987.05095> paver:[FvmStreamPartitions] Partitions pre-validated successfully: Enough space exists to pave.\n[00870.031] 04987.05095> paver:[AllocatePartitions] Allocating partition blobfs consisting of 1 slices\n[00870.034] 04987.05095> paver:[AllocatePartitions] Allocating partition minfs consisting of 1 slices\n[00870.035] 04987.05095> paver:[AllocatePartitions] Creating zxcrypt volume\n[00870.037] 03337.03376> devhost_get_handles(0x335ab613d900:block) open path='zxcrypt/block', r=-2\n[00870.037] 01104.01117> devcoord: dc_bind_device() '/boot/driver/zxcrypt.so'\n[00870.038] 03337.03376> devhost_get_handles(0x335ab613d900:block) open path='zxcrypt', r=-2\n[00870.041] 04987.05095> paver:[FvmStreamPartitions] Partition space pre-allocated successfully.\n[00870.042] 04987.05095> paver:[FvmStreamPartitions] Streaming partition 0\n[00870.042] 04987.05095> paver:[StreamFvmPartition] Writing extent 0... \n[00870.042] 04987.05101> netsvc: paver write progress 0.2%\n[00870.042] 04987.05095> paver:[StreamFvmPartition] 8192 bytes written, 8380416 zeroes left\n[00870.062] 04987.05095> paver:[StreamFvmPartition] Writing extent 1... \n[00870.062] 04987.05095> paver:[StreamFvmPartition] 8192 bytes written, 8380416 zeroes left\n[00870.079] 04987.05095> paver:[StreamFvmPartition] Writing extent 2... \n[00870.084] 04987.05095> paver:[StreamFvmPartition] 2097152 bytes written, 6291456 zeroes left\n[00870.100] 04987.05095> paver:[StreamFvmPartition] Writing extent 3... \n[00870.105] 04987.05095> paver:[StreamFvmPartition] 2097152 bytes written, 6291456 zeroes left\n[00870.117] 04987.05095> paver:[StreamFvmPartition] Writing extent 4... \n[00871.042] 04987.05101> netsvc: paver write progress 33.3%\n[00872.042] 04987.05101> netsvc: paver write progress 51.3%\n[00873.042] 04987.05101> netsvc: paver write progress 67.2%\n[00570.506] 04823.04937> netsvc: paver write progress 25.9%\n[00874.042] 04987.05101> netsvc: paver write progress 80.2%\n[00571.506] 04823.04937> netsvc: paver write progress 32.4%\n[00875.043] 04987.05101> netsvc: paver write progress 93.1%\n[00572.506] 04823.04937> netsvc: paver write progress 38.9%\n2019/04/20 01:15:58 done\n2019/04/20 01:15:58 attempting to send <<image>>bootloader.img...\n2019/04/20 01:15:58 target is busy, retrying in one second\n[00875.576] 04987.05001> netsvc: tftp write of file <<image>>sparse.fvm completed\n[00875.576] 04987.05001> netsvc: metrics: {\"inorderblks\": 165704,\"oooblks\": 0,\"ack\": 648,\"nack\": 0,\"timeouts\": 0,\"sas\": 0,\"inorderbytes\": 169680087}\n[00875.577] 04987.05095> paver:[StreamFvmPartition] 182943744 bytes written, 1605632 zeroes left\n[00875.580] 04987.05095> paver:[FvmStreamPartitions] Done streaming partition 0\n[00875.580] 04987.05095> paver:[FvmStreamPartitions] Done flushing partition 0\n[00875.580] 04987.05095> paver:[FvmStreamPartitions] Streaming partition 1\n[00875.580] 04987.05095> paver:[StreamFvmPartition] Writing extent 0... \n[00875.580] 04987.05095> paver:[StreamFvmPartition] 8192 bytes written, 8380416 zeroes left\n[00875.623] 04987.05095> paver:[StreamFvmPartition] Writing extent 1... \n[00875.623] 04987.05095> paver:[StreamFvmPartition] 65536 bytes written, 8323072 zeroes left\n[00875.661] 04987.05095> paver:[StreamFvmPartition] Writing extent 2... \n[00875.662] 04987.05095> paver:[StreamFvmPartition] 65536 bytes written, 8323072 zeroes left\n[00875.700] 04987.05095> paver:[StreamFvmPartition] Writing extent 3... \n[00875.738] 04987.05095> paver:[StreamFvmPartition] Writing extent 4... \n[00875.747] 04987.05095> paver:[StreamFvmPartition] 2097152 bytes written, 14680064 zeroes left\n[00875.816] 04987.05095> paver:[StreamFvmPartition] Writing extent 5... \n[00875.816] 04987.05095> paver:[StreamFvmPartition] 57344 bytes written, 8331264 zeroes left\n[00875.852] 04987.05095> paver:[FvmStreamPartitions] Done streaming partition 1\n[00875.852] 04987.05095> paver:[FvmStreamPartitions] Done flushing partition 1\n[00875.853] 05075.05089> Reading FVM from compressed file: true\n[00875.853] 05075.05089> Remaining bytes read into compression buffer: 0\n[00875.853] 05075.05089> Remaining bytes written to decompression buffer: 0\n[00875.853] 05075.05089> Time reading bytes from sparse FVM file: 13714200538 (5 s)\n[00875.853] 05075.05089> Time reading bytes AND decompressing them: 13803348970 (5 s)\n[00875.853] 04987.05095> paver:[PartitionPave] Completed successfully\n[00573.506] 04823.04937> netsvc: paver write progress 45.4%\n2019/04/20 01:15:59 attempting to send <<image>>bootloader.img...\n2019/04/20 01:15:59 done\n2019/04/20 01:15:59 attempting to send <<image>>zircona.img...\n[00876.580] 04987.05001> netsvc: Running BOOTLOADER Paver\n[00876.583] 04987.05829> paver:[Initialize] Successfully initialized EFI Device Partitioner\n[00876.583] 04987.05829> paver:[RealMain] SKIPPING BOOTLOADER install on x64 device, pass --force if desired.\n[00876.627] 04987.05001> netsvc: tftp write of file <<image>>bootloader.img completed\n[00876.627] 04987.05001> netsvc: metrics: {\"inorderblks\": 1093,\"oooblks\": 0,\"ack\": 5,\"nack\": 0,\"timeouts\": 0,\"sas\": 0,\"inorderbytes\": 1118208}\n[00876.629] 04987.05001> netsvc: Running ZIRCON-A Paver\n[00876.632] 04987.05970> paver:[Initialize] Successfully initialized EFI Device Partitioner\n[00876.632] 04987.05970> paver:[PartitionPave] Paving partition.\n[00876.632] 04987.05970> paver:[FindFirstFit] Looking for space\n[00876.632] 04987.05970> paver:[FindFirstFit] Partition seen with start 34, end 16777249 (length 16777216)\n[00876.632] 04987.05970> paver:[FindFirstFit] Sorting\n[00876.632] 04987.05970> paver:[FindFirstFit] Partition[0] From Block [0, 34) ... (next partition starts at block 34)\n[00876.632] 04987.05970> paver:[FindFirstFit] There are 0 free blocks (32768 requested)\n[00876.632] 04987.05970> paver:[FindFirstFit] Partition[1] From Block [34, 16777250) ... (next partition starts at block 234441614)\n[00876.632] 04987.05970> paver:[FindFirstFit] There are 217664364 free blocks (32768 requested)\n[00876.632] 04987.05970> paver:[AddPartition] Found space in GPT - OK 217664364 @ 16777250\n[00876.632] 04987.05970> paver:[AddPartition] Final space in GPT - OK 32768 @ 16777250\n[00876.632] 04987.05970> paver:[AddPartition] Added partition, waiting for bind\n[00876.632] 03337.03376> block: Joining un-closed FIFO server\n[00876.632] 03337.03376> block: Joining un-closed FIFO server\n[00876.633] 01104.01117> devcoord: dc_bind_device() ''\n[00876.633] 01182.01202> devmgr: /dev/class/block/003: GPT?\n[00876.633] 01104.01117> devcoord: dc_bind_device() '/boot/driver/gpt.so'\n[00876.633] 03337.03376> gpt: device_get_metadata failed (-25)\n[00876.634] 01182.01202> devmgr: /dev/class/block/013: FVM?\n[00876.634] 01104.01117> devcoord: dc_bind_device() '/boot/driver/fvm.so'\n[00876.634] 04987.05970> paver:[AddPartition] Added partition, waiting for bind - OK\n[00574.506] 04823.04937> netsvc: paver write progress 52.0%\n2019/04/20 01:16:00 done\n2019/04/20 01:16:00 attempting to send <<image>>zirconr.img...\n2019/04/20 01:16:00 target is busy, retrying in one second\n[00877.283] 04987.05001> netsvc: tftp write of file <<image>>zircona.img completed\n[00877.283] 04987.05001> netsvc: metrics: {\"inorderblks\": 13900,\"oooblks\": 0,\"ack\": 55,\"nack\": 0,\"timeouts\": 0,\"sas\": 0,\"inorderbytes\": 14233280}\n[00877.316] 04987.05970> paver:[PartitionPave] Completed successfully\n[00575.506] 04823.04937> netsvc: paver write progress 58.6%\n2019/04/20 01:16:01 attempting to send <<image>>zirconr.img...\n[00878.285] 04987.05001> netsvc: Running ZIRCON-R Paver\n[00878.289] 04987.06243> paver:[Initialize] Successfully initialized EFI Device Partitioner\n[00878.289] 04987.06243> paver:[PartitionPave] Paving partition.\n[00878.289] 04987.06243> paver:[FindFirstFit] Looking for space\n[00878.289] 04987.06243> paver:[FindFirstFit] Partition seen with start 34, end 16777249 (length 16777216)\n[00878.289] 04987.06243> paver:[FindFirstFit] Partition seen with start 16777250, end 16810017 (length 32768)\n[00878.289] 04987.06243> paver:[FindFirstFit] Sorting\n[00878.289] 04987.06243> paver:[FindFirstFit] Partition[0] From Block [0, 34) ... (next partition starts at block 34)\n[00878.289] 04987.06243> paver:[FindFirstFit] There are 0 free blocks (49152 requested)\n[00878.289] 04987.06243> paver:[FindFirstFit] Partition[1] From Block [34, 16777250) ... (next partition starts at block 16777250)\n[00878.289] 04987.06243> paver:[FindFirstFit] There are 0 free blocks (49152 requested)\n[00878.289] 04987.06243> paver:[FindFirstFit] Partition[2] From Block [16777250, 16810018) ... (next partition starts at block 234441614)\n[00878.289] 04987.06243> paver:[FindFirstFit] There are 217631596 free blocks (49152 requested)\n[00878.289] 04987.06243> paver:[AddPartition] Found space in GPT - OK 217631596 @ 16810018\n[00878.289] 04987.06243> paver:[AddPartition] Final space in GPT - OK 49152 @ 16810018\n[00878.289] 04987.06243> paver:[AddPartition] Added partition, waiting for bind\n[00878.289] 03337.03376> block: Joining un-closed FIFO server\n[00878.289] 01104.01117> devcoord: dc_bind_device() ''\n[00878.290] 01182.01202> devmgr: /dev/class/block/003: GPT?\n[00878.290] 01104.01117> devcoord: dc_bind_device() '/boot/driver/gpt.so'\n[00878.290] 03337.03376> gpt: device_get_metadata failed (-25)\n[00878.291] 01182.01202> devmgr: /dev/class/block/017: FVM?\n[00878.291] 01104.01117> devcoord: dc_bind_device() '/boot/driver/fvm.so'\n[00878.291] 04987.06243> paver:[AddPartition] Added partition, waiting for bind - OK\n2019/04/20 01:16:01 done\n2019/04/20 01:16:01 attempting to send <<image>>authorized_keys...\n2019/04/20 01:16:01 target is busy, retrying in one second\n[00878.874] 04987.05001> netsvc: tftp write of file <<image>>zirconr.img completed\n[00878.874] 04987.05001> netsvc: metrics: {\"inorderblks\": 12589,\"oooblks\": 0,\"ack\": 50,\"nack\": 0,\"timeouts\": 0,\"sas\": 0,\"inorderbytes\": 12890296}\n[00878.905] 04987.06243> paver:[PartitionPave] Completed successfully\n[00576.506] 04823.04937> netsvc: paver write progress 65.1%\n2019/04/20 01:16:02 attempting to send <<image>>authorized_keys...\n2019/04/20 01:16:02 done\n2019/04/20 01:16:02 attempting to send <<netboot>>kernel.bin...\n2019/04/20 01:16:02 target is busy, retrying in one second\n[00879.879] 04987.05001> netsvc: Installing SSH authorized_keys\n[00879.882] 04987.06533> paver:[Initialize] Successfully initialized EFI Device Partitioner\n[00879.882] 04987.05001> netsvc: tftp write of file <<image>>authorized_keys completed\n[00879.882] 04987.05001> netsvc: metrics: {\"inorderblks\": 1,\"oooblks\": 0,\"ack\": 1,\"nack\": 0,\"timeouts\": 0,\"sas\": 0,\"inorderbytes\": 725}\n[00879.882] 01104.01117> devcoord: dc_bind_device() '/boot/driver/zxcrypt.so'\n[00879.882] 03337.03376> devhost_get_handles(0x335ab613d900:block) open path='zxcrypt', r=-2\n[00879.911] 04987.06533> paver:[DataFilePave] Wrote ssh/authorized_keys\n[00577.506] 04823.04937> netsvc: paver write progress 71.8%\n2019/04/20 01:16:03 attempting to send <<netboot>>kernel.bin...\n[00578.506] 04823.04937> netsvc: paver write progress 78.4%\n2019/04/20 01:16:04 done\n[00579.506] 04823.04937> netsvc: paver write progress 84.9%\n[00580.506] 04823.04937> netsvc: paver write progress 91.5%\n[00581.506] 04823.04937> netsvc: paver write progress 98.1%\n2019/04/20 01:16:07 done\n2019/04/20 01:16:07 attempting to send <<image>>bootloader.img...\n2019/04/20 01:16:07 target is busy, retrying in one second\n[00581.782] 04823.04931> paver:[StreamFvmPartition] 182943744 bytes written, 1605632 zeroes left\n[00581.785] 04823.04837> netsvc: tftp write of file <<image>>sparse.fvm completed\n[00581.785] 04823.04837> netsvc: metrics: {\"inorderblks\": 165704,\"oooblks\": 0,\"ack\": 648,\"nack\": 0,\"timeouts\": 0,\"sas\": 0,\"inorderbytes\": 169680087}\n[00581.792] 04823.04931> paver:[FvmStreamPartitions] Done streaming partition 0\n[00581.792] 04823.04931> paver:[FvmStreamPartitions] Done flushing partition 0\n[00581.793] 04823.04931> paver:[FvmStreamPartitions] Streaming partition 1\n[00581.793] 04823.04931> paver:[StreamFvmPartition] Writing extent 0... \n[00581.793] 04823.04931> paver:[StreamFvmPartition] 8192 bytes written, 8380416 zeroes left\n[00581.831] 04823.04931> paver:[StreamFvmPartition] Writing extent 1... \n[00581.832] 04823.04931> paver:[StreamFvmPartition] 65536 bytes written, 8323072 zeroes left\n[00581.870] 04823.04931> paver:[StreamFvmPartition] Writing extent 2... \n[00581.870] 04823.04931> paver:[StreamFvmPartition] 65536 bytes written, 8323072 zeroes left\n[00581.907] 04823.04931> paver:[StreamFvmPartition] Writing extent 3... \n[00581.945] 04823.04931> paver:[StreamFvmPartition] Writing extent 4... \n[00581.954] 04823.04931> paver:[StreamFvmPartition] 2097152 bytes written, 14680064 zeroes left\n[00582.020] 04823.04931> paver:[StreamFvmPartition] Writing extent 5... \n[00582.021] 04823.04931> paver:[StreamFvmPartition] 57344 bytes written, 8331264 zeroes left\n[00582.059] 04823.04931> paver:[FvmStreamPartitions] Done streaming partition 1\n[00582.059] 04823.04931> paver:[FvmStreamPartitions] Done flushing partition 1\n[00582.060] 04911.04925> Reading FVM from compressed file: true\n[00582.060] 04911.04925> Remaining bytes read into compression buffer: 0\n[00582.060] 04911.04925> Remaining bytes written to decompression buffer: 0\n[00582.060] 04911.04925> Time reading bytes from sparse FVM file: 37436323556 (13 s)\n[00582.060] 04911.04925> Time reading bytes AND decompressing them: 37519912428 (13 s)\n[00582.060] 04823.04931> paver:[PartitionPave] Completed successfully\n2019/04/20 01:16:08 attempting to send <<image>>bootloader.img...\n[00582.787] 04823.04837> netsvc: Running BOOTLOADER Paver\n[00582.790] 04823.05667> paver:[Initialize] Successfully initialized EFI Device Partitioner\n[00582.790] 04823.05667> paver:[RealMain] SKIPPING BOOTLOADER install on x64 device, pass --force if desired.\n2019/04/20 01:16:08 done\n2019/04/20 01:16:08 attempting to send <<image>>zircona.img...\n[00582.887] 04823.04837> netsvc: tftp write of file <<image>>bootloader.img completed\n[00582.887] 04823.04837> netsvc: metrics: {\"inorderblks\": 1093,\"oooblks\": 0,\"ack\": 5,\"nack\": 0,\"timeouts\": 0,\"sas\": 0,\"inorderbytes\": 1118208}\n[00582.887] 04823.04837> netsvc: Running ZIRCON-A Paver\n[00582.890] 04823.05808> paver:[Initialize] Successfully initialized EFI Device Partitioner\n[00582.890] 04823.05808> paver:[PartitionPave] Paving partition.\n[00582.890] 04823.05808> paver:[FindFirstFit] Looking for space\n[00582.890] 04823.05808> paver:[FindFirstFit] Partition seen with start 34, end 16777249 (length 16777216)\n[00582.890] 04823.05808> paver:[FindFirstFit] Sorting\n[00582.890] 04823.05808> paver:[FindFirstFit] Partition[0] From Block [0, 34) ... (next partition starts at block 34)\n[00582.890] 04823.05808> paver:[FindFirstFit] There are 0 free blocks (32768 requested)\n[00582.890] 04823.05808> paver:[FindFirstFit] Partition[1] From Block [34, 16777250) ... (next partition starts at block 234441614)\n[00582.890] 04823.05808> paver:[FindFirstFit] There are 217664364 free blocks (32768 requested)\n[00582.890] 04823.05808> paver:[AddPartition] Found space in GPT - OK 217664364 @ 16777250\n[00582.890] 04823.05808> paver:[AddPartition] Final space in GPT - OK 32768 @ 16777250\n[00582.891] 03313.03362> block: Joining un-closed FIFO server\n[00582.891] 04823.05808> paver:[AddPartition] Added partition, waiting for bind\n[00582.891] 03313.03362> block: Joining un-closed FIFO server\n[00582.891] 01104.01117> devcoord: dc_bind_device() ''\n[00582.892] 01182.01202> devmgr: /dev/class/block/003: GPT?\n[00582.892] 01104.01117> devcoord: dc_bind_device() '/boot/driver/gpt.so'\n[00582.892] 03313.03362> gpt: device_get_metadata failed (-25)\n[00582.893] 01182.01202> devmgr: /dev/class/block/008: FVM?\n[00582.893] 01104.01117> devcoord: dc_bind_device() '/boot/driver/fvm.so'\n[00582.893] 04823.05808> paver:[AddPartition] Added partition, waiting for bind - OK\n[00583.888] 04823.05814> netsvc: paver write progress 79.4%\n2019/04/20 01:16:09 done\n2019/04/20 01:16:09 attempting to send <<image>>zirconr.img...\n2019/04/20 01:16:09 target is busy, retrying in one second\n[00584.147] 04823.04837> netsvc: tftp write of file <<image>>zircona.img completed\n[00584.147] 04823.04837> netsvc: metrics: {\"inorderblks\": 13900,\"oooblks\": 0,\"ack\": 55,\"nack\": 0,\"timeouts\": 0,\"sas\": 0,\"inorderbytes\": 14233280}\n[00584.176] 04823.05808> paver:[PartitionPave] Completed successfully\n2019/04/20 01:16:10 attempting to send <<image>>zirconr.img...\n[00585.149] 04823.04837> netsvc: Running ZIRCON-R Paver\n[00585.152] 04823.06081> paver:[Initialize] Successfully initialized EFI Device Partitioner\n[00585.152] 04823.06081> paver:[PartitionPave] Paving partition.\n[00585.152] 04823.06081> paver:[FindFirstFit] Looking for space\n[00585.152] 04823.06081> paver:[FindFirstFit] Partition seen with start 34, end 16777249 (length 16777216)\n[00585.152] 04823.06081> paver:[FindFirstFit] Partition seen with start 16777250, end 16810017 (length 32768)\n[00585.152] 04823.06081> paver:[FindFirstFit] Sorting\n[00585.152] 04823.06081> paver:[FindFirstFit] Partition[0] From Block [0, 34) ... (next partition starts at block 34)\n[00585.152] 04823.06081> paver:[FindFirstFit] There are 0 free blocks (49152 requested)\n[00585.152] 04823.06081> paver:[FindFirstFit] Partition[1] From Block [34, 16777250) ... (next partition starts at block 16777250)\n[00585.152] 04823.06081> paver:[FindFirstFit] There are 0 free blocks (49152 requested)\n[00585.152] 04823.06081> paver:[FindFirstFit] Partition[2] From Block [16777250, 16810018) ... (next partition starts at block 234441614)\n[00585.152] 04823.06081> paver:[FindFirstFit] There are 217631596 free blocks (49152 requested)\n[00585.152] 04823.06081> paver:[AddPartition] Found space in GPT - OK 217631596 @ 16810018\n[00585.152] 04823.06081> paver:[AddPartition] Final space in GPT - OK 49152 @ 16810018\n[00585.153] 04823.06081> paver:[AddPartition] Added partition, waiting for bind\n[00585.153] 03313.03362> block: Joining un-closed FIFO server\n[00585.153] 01104.01117> devcoord: dc_bind_device() ''\n[00585.154] 01182.01202> devmgr: /dev/class/block/003: GPT?\n[00585.154] 01104.01117> devcoord: dc_bind_device() '/boot/driver/gpt.so'\n[00585.154] 03313.03362> gpt: device_get_metadata failed (-25)\n[00585.155] 01182.01202> devmgr: /dev/class/block/012: FVM?\n[00585.155] 01104.01117> devcoord: dc_bind_device() '/boot/driver/fvm.so'\n[00585.155] 04823.06081> paver:[AddPartition] Added partition, waiting for bind - OK\n[00586.149] 04823.06087> netsvc: paver write progress 87.7%\n2019/04/20 01:16:11 done\n2019/04/20 01:16:11 attempting to send <<image>>authorized_keys...\n2019/04/20 01:16:11 target is busy, retrying in one second\n[00586.289] 04823.04837> netsvc: tftp write of file <<image>>zirconr.img completed\n[00586.289] 04823.04837> netsvc: metrics: {\"inorderblks\": 12589,\"oooblks\": 0,\"ack\": 50,\"nack\": 0,\"timeouts\": 0,\"sas\": 0,\"inorderbytes\": 12890296}\n[00586.323] 04823.06081> paver:[PartitionPave] Completed successfully\n2019/04/20 01:16:12 attempting to send <<image>>authorized_keys...\n2019/04/20 01:16:12 done\n2019/04/20 01:16:12 attempting to send <<netboot>>kernel.bin...\n2019/04/20 01:16:12 target is busy, retrying in one second\n[00587.290] 04823.04837> netsvc: Installing SSH authorized_keys\n[00587.291] 04823.04837> netsvc: tftp write of file <<image>>authorized_keys completed\n[00587.291] 04823.04837> netsvc: metrics: {\"inorderblks\": 1,\"oooblks\": 0,\"ack\": 1,\"nack\": 0,\"timeouts\": 0,\"sas\": 0,\"inorderbytes\": 725}\n[00587.293] 04823.06371> paver:[Initialize] Successfully initialized EFI Device Partitioner\n[00587.294] 01104.01117> devcoord: dc_bind_device() '/boot/driver/zxcrypt.so'\n[00587.294] 03313.03362> devhost_get_handles(0x32252f7cc9c0:block) open path='zxcrypt', r=-2\n[00587.323] 04823.06371> paver:[DataFilePave] Wrote ssh/authorized_keys\n[00000.000] 00000.00000> zbi: @ 0xffffff800793b000 (12706992 bytes)\n[00000.000] 00000.00000> UART: FIFO depth 16\n[00000.000] 00000.00000> PMM: boot reserve add [0x100000, 0x2fffff]\n[00000.000] 00000.00000> PMM: boot reserve add [0x793b000, 0x8559fff]\n[00000.000] 00000.00000> PMM: arena too small to be useful (size 4096)\n[00000.000] 00000.00000> PMM: pmm_add_arena failed to initialize arena\n[00000.000] 00000.00000> MEM: Failed to add pmm range at 0x7ffff000 size 0x1000\n[00000.000] 00000.00000> PMM: boot reserve marking WIRED [0x100000, 0x2fffff]\n[00000.000] 00000.00000> PMM: boot reserve marking WIRED [0x793b000, 0x8559fff]\n[00000.000] 00000.00000> \n[00000.000] 00000.00000> welcome to Zircon\n[00000.000] 00000.00000> \n[00000.000] 00000.00000> KASLR: .text section at 0xffffffff00100000\n[00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00114ec4 (global_prng_seed) at level 0x30000, flags 0x1\n[00000.000] 00000.00000> initializing vm pre-heap\n[00000.000] 00000.00000> VM: marking boot alloc used range [0x855a000, 0x855a100)\n[00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00122274 (elf_build_id) at level 0x4fffe, flags 0x1\n[00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00122400 (version) at level 0x4ffff, flags 0x1\n[00000.000] 00000.00000> version:\n[00000.000] 00000.00000> \tarch: x86\n[00000.000] 00000.00000> \tplatform: XXX\n[00000.000] 00000.00000> \ttarget: XXX\n[00000.000] 00000.00000> \tproject: x64\n[00000.000] 00000.00000> \tbuildid: git-17be8c71407840286428893a9fef5413787a4f1e-dirty\n[00000.000] 00000.00000> \tELF build ID: 9479db0fa44323b047af5e057e5eb85b6ed3461b\n[00000.000] 00000.00000> initializing heap\n[00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00101fc4 (console) at level 0x50000, flags 0x1\n[00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001826c4 (x86_resource_init) at level 0x50000, flags 0x1\n[00000.000] 00000.00000> initializing vm\n[00000.000] 00000.00000> VM: reserving kernel region [0xffffffff00100000, 0xffffffff0021b000) flags 0x28 name 'kernel_code'\n[00000.000] 00000.00000> VM: reserving kernel region [0xffffffff0021b000, 0xffffffff0026c000) flags 0x8 name 'kernel_rodata'\n[00000.000] 00000.00000> VM: reserving kernel region [0xffffffff0026c000, 0xffffffff00274000) flags 0x18 name 'kernel_data'\n[00000.000] 00000.00000> VM: reserving kernel region [0xffffffff00274000, 0xffffffff00300000) flags 0x18 name 'kernel_bss'\n[00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00183388 (display_memtype) at level 0x60001, flags 0x1\n[00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00186818 (acpi_tables) at level 0x60001, flags 0x1\n[00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001814c8 (hpet) at level 0x60002, flags 0x1\n[00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00181888 (apic) at level 0x60002, flags 0x1\n[00000.000] 00000.00000> x2APIC enabled\n[00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001a7e6c (system_topology_init) at level 0x60002, flags 0x1\n[00000.000] 00000.00000> WARNING: more than 1000 levels of cache, couldn't find highest.\n[00000.000] 00000.00000> WARNING: unable to find any cache levels.\n[00000.000] 00000.00000> Could not find SRAT table. ACPICA returned: 5\n[00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00185e08 (timer) at level 0x60003, flags 0x1\n[00000.000] 00000.00000> HPET frequency: 23999 ticks/ms\n[00000.000] 00000.00000> TSC frequency: 2712000 ticks/ms\n[00881.688] 00000.00000> timer features: constant_tsc 1 invariant_tsc 1 tsc_deadline 1\n[00881.688] 00000.00000> Using TSC as wallclock\n[00881.688] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00208930 (percpu_heap_init) at level 0x60003, flags 0x1\n[00881.688] 00000.00000> initializing kernel\n[00881.688] 00000.00000> initializing mp\n[00881.688] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00115118 (global_prng_thread_safe) at level 0x7ffff, flags 0x1\n[00881.688] 00000.00000> creating bootstrap completion thread\n[00881.688] 00000.00000> top of bootstrap2()\n[00881.688] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00131734 (libobject) at level 0x80000, flags 0x1\n[00881.688] 00000.00000> OOM: started thread\n[00881.688] 00000.00000> INIT: cpu 0, calling hook 0xffffffff0020589c (dpc) at level 0x80000, flags 0x1\n[00881.688] 00000.00000> Processor Model Info: type 0 family 0x6 model 0xe stepping 0x9\n[00881.688] 00000.00000> \tdisplay_family 0x6 display_model 0x8e\n[00881.688] 00000.00000> Vendor: Intel\n[00881.688] 00000.00000> Microarch: Kaby Lake\n[00881.688] 00000.00000> F/M/S: 6/8e/9\n[00881.688] 00000.00000> patch_level: 84\n[00881.688] 00000.00000> Brand: Intel(R) Core(TM) i5-7300U CPU @ 2.60GHz\n[00881.688] 00000.00000> Features: fpu sse sse2 sse3 ssse3 sse4.1 sse4.2 mmx avx avx2 fxsr pcid xsave mon aesni clflush \n[00881.688] 00000.00000> clflushopt fsgsbase tsc_adj smep smap erms rdrand rdseed syscall nx huge rdtscp \n[00881.688] 00000.00000> invar_tsc tsc_deadline x2apic vmx pt hwp \n[00881.688] 00000.00000> Properties: meltdown l1tf pcid_good \n[00881.688] 00000.00000> initializing platform\n[00881.688] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001a157c (x86_perfmon) at level 0x90000, flags 0x1\n[00881.688] 00000.00000> PMU: version 4\n[00881.688] 00000.00000> UART: started IRQ driven RX\n[00881.688] 00000.00000> UART: started IRQ driven TX\n[00881.688] 00000.00000> cpu topology:\n[00881.688] 00000.00000> \t0: apic id 0x0 BSP\n[00881.688] 00000.00000> \t1: apic id 0x1 \n[00881.688] 00000.00000> \t2: apic id 0x2 \n[00881.688] 00000.00000> \t3: apic id 0x3 \n[00881.688] 00000.00000> Found 4 cpus\n[00881.688] 00000.00000> booting apic ids: 0x1 0x2 0x3 \n[00881.703] 00000.00000> entering scheduler on cpu 1\n[00881.704] 00000.00000> entering scheduler on cpu 2\n[00881.704] 00000.00000> entering scheduler on cpu 3\n[00881.707] 00000.00000> smbios: manufacturer=\"Intel Corporation\" product=\"NUC7i5DNHE\"\n[00881.707] 00000.00000> initializing target\n[00881.707] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001850b8 (x86_pcie_init) at level 0xa0000, flags 0x1\n[00881.707] 00000.00000> moving to last init level\n[00881.707] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001214cc (debuglog) at level 0xb0000, flags 0x1\n[00881.707] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00174d40 (kcounters) at level 0xb0000, flags 0x1\n[00881.707] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00102aec (kernel_shell) at level 0xc0000, flags 0x1\n[00881.707] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00202ad4 (ktrace) at level 0xc0000, flags 0x1\n[00881.710] 00000.00000> ktrace: buffer at 0xffffff9d6badb000 (33554432 bytes)\n[00881.710] 00000.00000> INIT: cpu 0, calling hook 0xffffffff002184f8 (userboot) at level 0xc0000, flags 0x1\n[00881.710] 00000.00000> userboot: ramdisk 0xc1f000 @ 0xffffff800793b000\n[00881.711] 00000.00000> userboot: userboot rodata 0 @ [0x74c9ab0e000,0x74c9ab11000)\n[00881.711] 00000.00000> userboot: userboot code 0x3000 @ [0x74c9ab11000,0x74c9ab1c000)\n[00881.711] 00000.00000> userboot: vdso/full rodata 0 @ [0x74c9ab1c000,0x74c9ab23000)\n[00881.711] 00000.00000> userboot: vdso/full code 0x7000 @ [0x74c9ab23000,0x74c9ab24000)\n[00881.711] 00000.00000> userboot: entry point @ 0x74c9ab11c90\n[00881.711] 01036.01043> userboot: option \"zircon.autorun.system=/boot/bin/sh+/boot/infra/runcmds\"\n[00881.741] 01036.01043> userboot: searching bootfs for 'bin/bootsvc'\n[00881.741] 01036.01043> userboot: 'bin/bootsvc' has PT_INTERP \"lib/ld.so.1\"\n[00881.741] 01036.01043> userboot: searching bootfs for 'lib/ld.so.1'\n[00881.741] 01036.01043> userboot: userboot: loaded lib/ld.so.1 at 0x51c41b5b9000, entry point 0x51c41b5d73d0\n[00881.741] 01036.01043> userboot: userboot: loaded vDSO at 0x79076c33e000, entry point 0x79076c3458fa\n[00881.741] 01036.01043> userboot: process bin/bootsvc started.\n[00881.741] 01036.01043> userboot: waiting for loader-service requests...\n[00881.741] 01036.01043> userboot: searching bootfs for 'lib/libasync-default.so'\n[00881.741] 01036.01043> userboot: searching bootfs for 'lib/libfdio.so'\n[00881.741] 01036.01043> userboot: searching bootfs for 'lib/libtrace-engine.so'\n[00881.741] 01036.01043> userboot: searching bootfs for 'lib/liblaunchpad.so'\n[00881.741] 01050.01053> {{{reset}}}\n[00881.741] 01050.01053> {{{module:0:<application>:elf:367d3374904876b8f143f2ed5e4dfb0248fef748}}}\n[00881.741] 01050.01053> {{{mmap:0x2941a61ed000:0x3a000:load:0:rx:0}}}\n[00881.741] 01050.01053> {{{mmap:0x2941a6227000:0x4000:load:0:rw:0x3a000}}}\n[00881.741] 01050.01053> dso: id=367d3374904876b8f143f2ed5e4dfb0248fef748 base=0x00002941a61ed000 name=<application>\n[00881.741] 01050.01053> {{{module:0x2:<vDSO>:elf:71712e0a455898a51e34d40a4013786ab1fa5335}}}\n[00881.741] 01050.01053> {{{mmap:0x79076c33e000:0x7000:load:0x2:r:0}}}\n[00881.741] 01050.01053> {{{mmap:0x79076c345000:0x1000:load:0x2:rx:0x7000}}}\n[00881.741] 01050.01053> dso: id=71712e0a455898a51e34d40a4013786ab1fa5335 base=0x000079076c33e000 name=<vDSO>\n[00881.741] 01050.01053> {{{module:0x3:libasync-default.so:elf:8c511b4202cf569c8fdde14ca97222102ba3a9e0}}}\n[00881.741] 01050.01053> {{{mmap:0x9c5b3a06000:0x1000:load:0x3:rx:0}}}\n[00881.741] 01050.01053> {{{mmap:0x9c5b3a07000:0x1000:load:0x3:rw:0x1000}}}\n[00881.741] 01050.01053> dso: id=8c511b4202cf569c8fdde14ca97222102ba3a9e0 base=0x000009c5b3a06000 name=libasync-default.so\n[00881.741] 01050.01053> {{{module:0x4:libfdio.so:elf:3efa72b2e3bd2e4271f835d34a81d9719d6e08a7}}}\n[00881.741] 01050.01053> {{{mmap:0x306bda879000:0x32000:load:0x4:rx:0}}}\n[00881.741] 01050.01053> {{{mmap:0x306bda8ac000:0x4000:load:0x4:rw:0x33000}}}\n[00881.741] 01050.01053> dso: id=3efa72b2e3bd2e4271f835d34a81d9719d6e08a7 base=0x0000306bda879000 name=libfdio.so\n[00881.741] 01050.01053> {{{module:0x5:libtrace-engine.so:elf:95bc229c3cf2ab8a51f12c33a311105ff8976120}}}\n[00881.741] 01050.01053> {{{mmap:0x1a6fb0b40000:0x9000:load:0x5:rx:0}}}\n[00881.741] 01050.01053> {{{mmap:0x1a6fb0b49000:0x2000:load:0x5:rw:0x9000}}}\n[00881.741] 01050.01053> dso: id=95bc229c3cf2ab8a51f12c33a311105ff8976120 base=0x00001a6fb0b40000 name=libtrace-engine.so\n[00881.741] 01050.01053> {{{module:0x6:liblaunchpad.so:elf:5b0854856213eae6bab93c982f39551f8f9591c5}}}\n[00881.741] 01050.01053> {{{mmap:0x283222c1e000:0x7000:load:0x6:rx:0}}}\n[00881.741] 01050.01053> {{{mmap:0x283222c25000:0x2000:load:0x6:rw:0x7000}}}\n[00881.741] 01050.01053> dso: id=5b0854856213eae6bab93c982f39551f8f9591c5 base=0x0000283222c1e000 name=liblaunchpad.so\n[00881.741] 01050.01053> {{{module:0x1:libc.so:elf:5d417db61b3a48a58a8fa1ffbfc2e71b830e0857}}}\n[00881.741] 01050.01053> {{{mmap:0x51c41b5b9000:0xa6000:load:0x1:rx:0}}}\n[00881.741] 01050.01053> {{{mmap:0x51c41b65f000:0x5000:load:0x1:rw:0xa6000}}}\n[00881.741] 01050.01053> dso: id=5d417db61b3a48a58a8fa1ffbfc2e71b830e0857 base=0x000051c41b5b9000 name=libc.so\n[00881.741] 01050.01053> bootsvc: Starting...\n[00881.741] 01036.01043> userboot: loader-service channel peer closed\n[00881.741] 01036.01043> userboot: finished!\n[00881.741] 01050.01053> bootsvc: Creating bootfs service...\n[00881.742] 01050.01053> bootsvc: Retrieving boot image...\n[00881.742] 01050.01053> bootsvc: Decommitted BOOTDATA VMO from 0 to 0xc1e000\n[00881.742] 01050.01053> bootsvc: Loading boot arguments...\n[00881.742] 01050.01053> bootsvc: Creating svcfs service...\n[00881.742] 01050.01053> bootsvc: Loading kernel VMOs...\n[00881.742] 01050.01053> bootsvc: Creating loader service...\n[00881.742] 01050.01053> bootsvc: Launching next process...\n[00881.742] 01050.01108> bootsvc: Launched bin/devcoordinator\n[00881.743] 01115.01130> devcoordinator: launch /boot/bin/svchost (svchost) OK\n[00881.744] 01115.01130> devcoordinator: launch /boot/bin/fshost (fshost) OK\n[00881.746] 01115.01321> devcoordinator: launch /boot/bin/pwrbtn-monitor (pwrbtn-monitor) OK\n[00881.747] 01115.01349> devcoordinator: launch /boot/bin/netsvc (netsvc) OK\n[00881.747] 01115.01349> devcoordinator: launch /boot/bin/virtual-console (virtual-console) OK\n[00881.750] 01115.01130> devcoordinator: full system required, ignoring fallback drivers until /system is loaded\n[00881.751] 01115.01130> devcoordinator: launch devhost 'devhost:sys': pid=2187\n[00881.751] 01115.01130> devcoordinator: launch devhost 'devhost:test': pid=2219\n[00881.751] 01115.01130> devcoordinator: launch devhost 'devhost:root': pid=2272\n[00881.752] 01115.01130> devcoordinator: launch devhost 'devhost:misc': pid=2349\n[00881.752] 02187.02201> devhost: trace provider registry begun\n[00881.753] 02219.02241> devhost: trace provider registry begun\n[00881.754] 02272.02303> devhost: trace provider registry begun\n[00881.754] 02349.02378> devhost: trace provider registry begun\n[00881.755] 01115.01333> devcoordinator: launch /boot/bin/sh (sh:console) OK\n[00881.838] 02187.02201> acpi-bus: not using IOMMU\n[00881.845] 02187.02201> PMU: 7 arch events\n[00881.845] 02187.02201> PMU: arch event id range: 1-7\n[00881.845] 02187.02201> PMU: 102 arch events\n[00881.845] 02187.02201> PMU: arch event id range: 1-241\n[00881.845] 02187.02201> Intel Processor Trace configuration for this chipset:\n[00881.845] 02187.02201> mtc_freq_mask: 0x249\n[00881.845] 02187.02201> cyc_thresh_mask: 0x3fff\n[00881.845] 02187.02201> psb_freq_mask: 0x3f\n[00881.845] 02187.02201> num addr ranges: 2\n[00881.845] 02187.02201> [sysmem_init 28] async_get_default_dispatcher(): 0x640fdab52310\n[00881.845] 02187.02201> [sysmem_bind 40] sysmem_bind()\n[00881.846] 02187.02876> acpi-pwrbtn: initialized\n[00881.849] 01723.01762> vc: new input device /dev/class/input/000\n[00881.855] 02187.02876> WARNING: ACPI found bad _CRS address entry\n[00881.865] 02187.02876> WARNING: ACPI found bad _CRS address entry\n[00881.877] 02187.02876> acpi: published device pci(0x640f1ab75bf0), parent=sys(0x64105ab54c10), handle=0x640edab6a4d0\n[00881.877] 01115.01130> devcoordinator: launch devhost 'devhost:pci#1:8086:5916': pid=2972\n[00881.878] 02972.02986> devhost: trace provider registry begun\n[00881.880] 01115.01130> devcoordinator: launch devhost 'devhost:pci#3:8086:9d2f': pid=3076\n[00881.880] 02187.02876> acpi: published device rtc(0x640f1ab76310), parent=acpi(0x64105ab54810), handle=0x640edab92610\n[00881.881] 03076.03090> devhost: trace provider registry begun\n[00881.882] 01115.01130> devcoordinator: launch devhost 'devhost:pci#5:8086:9d60': pid=3193\n[00881.882] 02187.02876> acpi-ec: initialized\n[00881.882] 01115.01130> devcoordinator: launch devhost 'devhost:pci#6:8086:9d61': pid=3251\n[00881.883] 03193.03207> devhost: trace provider registry begun\n[00881.883] 01115.01130> devcoordinator: launch devhost 'devhost:pci#9:8086:9d03': pid=3363\n[00881.884] 01115.01130> devcoordinator: launch devhost 'devhost:pci#14:8086:9d71': pid=3472\n[00881.884] 03251.03274> devhost: trace provider registry begun\n[00881.884] 03363.03383> devhost: trace provider registry begun\n[00881.885] 03472.03506> devhost: trace provider registry begun\n[00881.886] 02187.02876> acpi: failed to create NHLT VMO (res -10)\n[00881.886] 02187.02876> acpi: failed to publish NHLT metadata\n[00881.887] 01115.01130> devcoordinator: launch devhost 'devhost:pci#16:8086:156f': pid=3660\n[00881.889] 03251.03274> initialized intel serialio i2c driver, reg=0x374c6fc87000 regsize=4096\n[00881.889] 03193.03207> initialized intel serialio i2c driver, reg=0x3c58260fe000 regsize=4096\n[00881.889] 03660.03674> devhost: trace provider registry begun\n[00881.893] 03363.03383> ahci: using MSI interrupt\n[00881.894] 03472.03506> [IHDA DSP 00:1f.3] Failed to fetch NHLT (res -25)\n[00881.894] 03472.03506> [IHDA Controller 00:1f.3] Failed to initialize DSP device (res = -25)\n[00881.895] 03076.04015> * found USB device (0x18d1:0xa002, USB 2.0) config 1\n[00881.895] 03076.04015> * found USB device (0x18d1:0xa003, USB 3.0) config 1\n[00881.966] 01621.01660> netifc: ? /dev/class/ethernet/000\n[00881.966] 01621.01660> netifc: create 512 eth buffers\n[00881.966] 01621.01660> macaddr: d4:5d:df:1a:43:25\n[00881.966] 01621.01660> ip6addr: fe80::d65d:df4d:fe1a:4325\n[00881.966] 01621.01660> snmaddr: ff02::1:ff1a:4325\n[00881.966] 01621.01660> netsvc: using /dev/class/ethernet/000\n[00881.966] 01621.01660> netsvc: nodename='siren-bats-wick-hasty'\n[00881.966] 01621.01660> netsvc: start\n[00881.996] 01723.01762> vc: new display device /dev/class/display-controller/000\n[00882.036] 02972.04240> i915: MST not supported\n[00882.540] 02972.04240> i915: MST not supported\n[00882.608] 03076.04015> * found USB device (0x0781:0x5583, USB 3.0) config 1\n[00883.358] 03076.04015> * found USB device (0x0cf3:0xe300, USB 2.1) config 1\n[00883.474] 02972.04240> i915: No displays detected\n[00883.894] 03251.03274> intel-i2c-controller: intel_serialio_i2c_slave_transfer: -21\n[00883.894] 03251.03274> i2c-hid: could not read HID descriptor: 0\n[00883.894] 03251.03274> devhost[00:15.1/i2c-bus-9d61/004c] bind driver '/boot/driver/i2c-hid.so' failed: -2\n[00883.894] 01115.01130> devcoordinator: rpc: bind-driver '004c' status -2\n[00883.894] 03193.03207> intel-i2c-controller: intel_serialio_i2c_slave_transfer: -21\n[00883.894] 03193.03207> i2c-hid: could not read HID descriptor: 0\n[00883.894] 03193.03207> devhost[00:15.0/i2c-bus-9d60/0020] bind driver '/boot/driver/i2c-hid.so' failed: -2\n[00883.894] 01115.01130> devcoordinator: rpc: bind-driver '0020' status -2\n[00883.908] 03363.03882> sata2: dev info\n[00883.908] 03363.03882> serial=711430953055 2 \n[00883.908] 03363.03882> firmware rev=1Q01A7 0\n[00883.908] 03363.03882> model id=IBIW NSS D \n[00883.908] 03363.03882> major=0x3f0 ACS2 DMA 32 commands\n[00883.908] 03363.03882> LBA48 234441648 sectors, sector size=512\n[00883.909] 01299.01313> fshost: /dev/class/block/000: GPT?\n[00883.909] 03363.03383> gpt: device_get_metadata failed (-25)\n[00883.910] 01299.01313> fshost: /dev/class/block/001: FVM?\n[00883.913] 01299.01313> devcoordinator: launch /boot/bin/blobfs (blobfs:/blob) OK\n[00884.057] 01299.01313> fshost: starting 'bin/pkgsvr' '025c9db410155e9d20d519a3c41624bbf5102857731ed156aa6173c5ca4f6238'...\n[00884.063] 01299.01313> devcoordinator: launch bin/pkgsvr (pkgfs) OK\n[00884.073] 04631.04842> pkgsvr: system: will be served from 025c9db410155e9d20d519a3c41624bbf5102857731ed156aa6173c5ca4f6238\n[00884.073] 04631.04842> pkgsvr: pkgfs serving index /data/pkgfs_index from blobfs /blob\n[00884.073] 01299.01313> fshost: /dev/class/block/005: zxcrypt?\n[00884.073] 03363.03383> devhost_get_handles(0x53e023235c10:block) open path='zxcrypt', r=-2\n[00884.080] 01299.01313> fshost: mounting minfs\n[00884.080] 01299.01313> devcoordinator: launch /boot/bin/minfs (minfs:/data) OK\n[00884.152] 01115.04886> devcoordinator: adding system driver 'ralink' '/system/driver/ralink.so'\n[00884.153] 01115.01774> devcoordinator: launch /system/bin/appmgr (appmgr) OK\n[00884.153] 01115.01774> autorun: starting '/boot/bin/sh' '/boot/infra/runcmds'...\n[00884.153] 01115.01774> devcoordinator: launch /boot/bin/sh (autorun:system) OK\n[00884.164] 01115.04886> devcoordinator: adding system driver 'bt_hci_fake' '/system/driver/bt-hci-fake.so'\n[00884.168] 01115.04886> devcoordinator: adding system driver 'bt_hci_passthrough' '/system/driver/bt-hci-passthrough.so'\n[00884.186] 01115.04886> devcoordinator: adding system driver 'usb_video' '/system/driver/usb_video.so'\n[00884.205] 01115.04886> devcoordinator: adding system driver 'mt8167s_gpu' '/system/driver/libmsd_img_rgx_mtk.so'\n[00884.213] 01115.04886> devcoordinator: adding system driver 'virtual_audio' '/system/driver/virtual_audio_driver.so'\n[00884.221] 01115.04886> devcoordinator: adding system driver 'brcmfmac' '/system/driver/brcmfmac.so'\n[00884.223] 01115.04886> devcoordinator: adding system driver 'iwlwifi_pci' '/system/driver/iwlwifi.so'\n[00884.231] 01115.04886> devcoordinator: adding system driver 'rtl88xx' '/system/driver/rtl88xx.so'\n[00884.233] 01115.04886> devcoordinator: adding system driver 'bt_hog' '/system/driver/bt-hog.so'\n[00884.289] 01115.04886> devcoordinator: adding system driver 'wlan' '/system/driver/wlan.so'\n[00884.299] 01115.04886> devcoordinator: adding system driver 'wlan' '/system/driver/wlanif.so'\n[00884.324] 01115.04886> devcoordinator: adding system driver 'bt_hci_atheros' '/system/driver/bt-hci-atheros.so'\n[00884.334] 01115.04886> devcoordinator: adding system driver 'qmi_usb' '/system/driver/qmi-transport.so'\n[00884.339] 01115.04886> devcoordinator: adding system driver 'ath10k_pci' '/system/driver/ath10k.so'\n[00884.363] 01115.04886> devcoordinator: adding system driver 'bt_hci_intel' '/system/driver/bt-hci-intel.so'\n[00884.377] 01115.04886> devcoordinator: adding system driver 'virtual_camera' '/system/driver/virtual_camera_driver.so'\n[00884.386] 01115.04886> devcoordinator: adding system driver 'magma_pdev_gpu' '/system/driver/libmsd_arm.so'\n[00884.390] 01115.04886> devcoordinator: adding system driver 'qmi_fake' '/system/driver/qmi-fake.so'\n[00884.402] 05181.05202> [INFO:namespace_builder.cc(93)] config-data for sysmgr\n[00884.431] 01115.04886> devcoordinator: adding system driver 'bt_host' '/system/driver/bt-host.so'\n[00884.441] 01115.04886> devcoordinator: adding system driver 'gpu' '/system/driver/libmsd_intel.so'\n[00884.453] 01115.04886> devcoordinator: adding system driver 'wlan' '/system/driver/wlanphy.so'\n[00884.453] 01115.01130> devcoordinator: driver 'wlan' added\n[00884.453] 01115.01130> devcoordinator: driver 'gpu' added\n[00884.453] 01115.01130> devcoordinator: driver 'bt_host' added\n[00884.453] 01115.01130> devcoordinator: driver 'qmi_fake' added\n[00884.453] 01115.01130> devcoordinator: driver 'magma_pdev_gpu' added\n[00884.453] 01115.01130> devcoordinator: driver 'bt_hci_intel' added\n[00884.453] 01115.01130> devcoordinator: driver 'ath10k_pci' added\n[00884.454] 01115.01130> devcoordinator: launch devhost 'devhost:pci#11:168c:003e': pid=5947\n[00884.454] 01115.01130> devcoordinator: driver 'qmi_usb' added\n[00884.454] 01115.01130> devcoordinator: driver 'bt_hci_atheros' added\n[00884.454] 01115.01130> devcoordinator: driver 'wlan' added\n[00884.454] 01115.01130> devcoordinator: driver 'wlan' added\n[00884.454] 01115.01130> devcoordinator: driver 'bt_hog' added\n[00884.454] 01115.01130> devcoordinator: driver 'rtl88xx' added\n[00884.454] 01115.01130> devcoordinator: driver 'iwlwifi_pci' added\n[00884.454] 01115.01130> devcoordinator: driver 'brcmfmac' added\n[00884.454] 01115.01130> devcoordinator: driver 'mt8167s_gpu' added\n[00884.454] 01115.01130> devcoordinator: driver 'usb_video' added\n[00884.454] 01115.01130> devcoordinator: driver 'bt_hci_fake' added\n[00884.454] 01115.01130> devcoordinator: driver 'ralink' added\n[00884.454] 01115.01130> devcoordinator: driver 'bt_hci_passthrough' added\n[00884.454] 01115.01130> devcoordinator: fallback driver 'usb_composite' is available\n[00884.454] 01115.01130> devcoordinator: driver 'usb_composite' added\n[00884.454] 01115.01130> devcoordinator: fallback driver 'intel_disp' is available\n[00884.454] 01115.01130> devcoordinator: driver 'intel_disp' added\n[00884.456] 05947.05972> devhost: trace provider registry begun\n[00884.456] 05947.05972> ath10k: Probed chip QCA6174 ver: 2.1\n[00884.457] 03076.03090> UMS: parent: 'ifc-000'\n[00884.458] 03076.03090> UMS:Max lun is: 0\n[00884.458] 03076.03090> devhost[00:14.0/xhci/usb-bus/002/002/ifc-001] bind driver '/boot/driver/bt-transport-usb.so' failed: -2\n[00884.458] 01115.01130> devcoordinator: rpc: bind-driver 'ifc-001' status -2\n[00884.461] 03076.06399> UMS: block size is: 0x00000200\n[00884.461] 03076.06399> UMS: total blocks is: 30031250\n[00884.461] 03076.06399> UMS: total size is: 15376000000\n[00884.461] 03076.06399> UMS: read-only: 0 removable: 1\n[00884.498] 03076.09496> btatheros: Making visible\n[00884.498] 03076.09496> btatheros: loaded successfully\n[00884.500] 03076.09619> [INFO:command_channel.cc(149)] hci: initialized\n[00884.501] 01299.01313> fshost: /dev/class/block/007: MBR?\n[00884.506] 01299.01313> fshost: /dev/class/block/009: MBR?\n[00884.565] 03076.09619> [WARN:adapter.cc(274)] gap: controller is using legacy HCI version 4.1\n[00884.569] 05181.05202> [INFO:namespace_builder.cc(93)] config-data for amber\n[00884.571] 03076.09619> [INFO:acl_data_channel.cc(91)] hci: initialized\n[00884.625] 05181.05202> [INFO:namespace_builder.cc(93)] config-data for pkg_resolver\n[00884.757] 13668.13680> [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\n[00884.757] 13668.13680> kfill_days=2, start_event_aggregator_worker=1.\n[00884.833] 05947.13591> devhost: rpc:load-firmware failed: -25\n[00884.833] 05947.13591> devhost: rpc:load-firmware failed: -25\n[00884.835] 05181.05202> [INFO:namespace_builder.cc(93)] config-data for mdns\n[00884.883] 05181.05202> [INFO:namespace_builder.cc(93)] config-data for wlancfg\n[00885.076] 05181.05202> [INFO:namespace_builder.cc(93)] config-data for crashpad_agent\n[00885.116] 16728.16740> [INFO:main.cc(35)] Trace Manager starting with config: /pkg/data/tracing.config\n[00885.147] 15408.15420> [INFO:system_metrics_main.cc(23)] Cobalt SystemMetricsDaemon: System metrics daemon created.\n[00885.248] 17188.17200> wlanstack2 [I]: Starting\n[00885.525] 05947.12823> ath10k: Unknown eventid: 0x1d019\n[00885.528] 05947.12823> ath10k: Unknown eventid: 0x16006\n[00885.533] 05947.05972> wlanphy: event loop started\n[00885.533] 05947.05972> wlanphy_bind\n[00885.533] 17188.17200> wlanstack2::device [I]: new phy #0: /dev/sys/pci/01:00.0/ath10k-wlanphy/wlanphy\n[00885.534] 14983.14996> wlancfg got event: OnPhyAdded { phy_id: 0 }\n[00885.534] 14983.14996> wlancfg: phy 0 added\n[00885.534] 17188.17200> wlanstack2::service [I]: query_phy(id = 0)\n[00885.534] 17188.17200> wlanstack2::service [I]: query_phy(id = 0): received a 'QueryResult' from device\n[00885.535] 14983.14996> wlancfg: received a PhyInfo from phy #0: path is /dev/sys/pci/01:00.0/ath10k-wlanphy/wlanphy\n[00885.535] 14983.14996> using default wlan config entry for phy\n[00885.535] 14983.14996> wlancfg: Creating Client iface for phy 0\n[00885.540] 05947.05972> wlan_bind\n[00885.542] 05947.05972> ath10k: adding a station interface (vdev_id=0) ...\n[00885.544] 05947.05972> wlan: [I] Initialize a client MLME.\n[00885.544] 05947.18041> wlan: [I] starting MainLoop\n[00885.545] 05947.05972> wlan: [I] channel opened\n[00885.545] 17188.17200> wlanstack2::device [I]: new iface #0 with role 'Client': /dev/sys/pci/01:00.0/ath10k-wlanphy/ath10k-wlanmac/wlan\n[00885.546] 14983.14996> wlancfg got event: OnIfaceAdded { iface_id: 0 }\n[00885.546] 14983.14996> wlancfg: new iface 0 added successfully\n[00885.547] 14983.14996> wlancfg: Starting auto-connect loop with 0 saved networks\n[00886.202] 14467.14479> Starting mDNS on interface ethp001f6 [80fe::5dd6:ffdf:1afe:2543]\n[00886.202] 14467.14479> [WARNING:garnet/bin/mdns/service/mdns_interface_transceiver_v6.cc(29)] NET-291 IPV6_MULTICAST_LOOP not supported (ENOPROTOOPT), continuing anyway\n[00886.202] 14467.14479> [WARNING:garnet/bin/mdns/service/mdns_interface_transceiver_v6.cc(50)] NET-2180 IPV6_JOIN_GROUP returned ENODEV, mDNS will not communicate via IPV6\n[00889.711] 14467.14479> Starting mDNS on interface ethp001f6 192.168.42.102\n[00889.711] 14467.14479> [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\n[00889.711] 14467.14479> Starting mDNS on interface ethp001f6 [80fe::5dd6:ffdf:1afe:2543]\n[00889.712] 14467.14479> [WARNING:garnet/bin/mdns/service/mdns_interface_transceiver_v6.cc(29)] NET-291 IPV6_MULTICAST_LOOP not supported (ENOPROTOOPT), continuing anyway\n[00889.712] 14467.14479> [WARNING:garnet/bin/mdns/service/mdns_interface_transceiver_v6.cc(50)] NET-2180 IPV6_JOIN_GROUP returned ENODEV, mDNS will not communicate via IPV6\n[00889.712] 14467.14479> mDNS: Verifying uniqueness of host name siren-bats-wick-hasty.local.\n2019/04/20 01:16:13 attempting to send <<netboot>>kernel.bin...\n2019/04/20 01:16:15 done\n[00890.635] 14467.14479> mDNS: Using unique host name siren-bats-wick-hasty.local.\n[00000.000] 00000.00000> zbi: @ 0xffffff800695c000 (12706992 bytes)\n[00000.000] 00000.00000> UART: FIFO depth 16\n[00000.000] 00000.00000> PMM: boot reserve add [0x100000, 0x2fffff]\n[00000.000] 00000.00000> PMM: boot reserve add [0x695c000, 0x757afff]\n[00000.000] 00000.00000> PMM: arena too small to be useful (size 4096)\n[00000.000] 00000.00000> PMM: pmm_add_arena failed to initialize arena\n[00000.000] 00000.00000> MEM: Failed to add pmm range at 0x7ffff000 size 0x1000\n[00000.000] 00000.00000> PMM: boot reserve marking WIRED [0x100000, 0x2fffff]\n[00000.000] 00000.00000> PMM: boot reserve marking WIRED [0x695c000, 0x757afff]\n[00000.000] 00000.00000> \n[00000.000] 00000.00000> welcome to Zircon\n[00000.000] 00000.00000> \n[00000.000] 00000.00000> KASLR: .text section at 0xffffffff00100000\n[00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00114ec4 (global_prng_seed) at level 0x30000, flags 0x1\n[00000.000] 00000.00000> initializing vm pre-heap\n[00000.000] 00000.00000> VM: marking boot alloc used range [0x757b000, 0x757b100)\n[00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00122274 (elf_build_id) at level 0x4fffe, flags 0x1\n[00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00122400 (version) at level 0x4ffff, flags 0x1\n[00000.000] 00000.00000> version:\n[00000.000] 00000.00000> \tarch: x86\n[00000.000] 00000.00000> \tplatform: XXX\n[00000.000] 00000.00000> \ttarget: XXX\n[00000.000] 00000.00000> \tproject: x64\n[00000.000] 00000.00000> \tbuildid: git-17be8c71407840286428893a9fef5413787a4f1e-dirty\n[00000.000] 00000.00000> \tELF build ID: 9479db0fa44323b047af5e057e5eb85b6ed3461b\n[00000.000] 00000.00000> initializing heap\n[00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00101fc4 (console) at level 0x50000, flags 0x1\n[00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001826c4 (x86_resource_init) at level 0x50000, flags 0x1\n[00000.000] 00000.00000> initializing vm\n[00000.000] 00000.00000> VM: reserving kernel region [0xffffffff00100000, 0xffffffff0021b000) flags 0x28 name 'kernel_code'\n[00000.000] 00000.00000> VM: reserving kernel region [0xffffffff0021b000, 0xffffffff0026c000) flags 0x8 name 'kernel_rodata'\n[00000.000] 00000.00000> VM: reserving kernel region [0xffffffff0026c000, 0xffffffff00274000) flags 0x18 name 'kernel_data'\n[00000.000] 00000.00000> VM: reserving kernel region [0xffffffff00274000, 0xffffffff00300000) flags 0x18 name 'kernel_bss'\n[00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00183388 (display_memtype) at level 0x60001, flags 0x1\n[00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00186818 (acpi_tables) at level 0x60001, flags 0x1\n[00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001814c8 (hpet) at level 0x60002, flags 0x1\n[00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00181888 (apic) at level 0x60002, flags 0x1\n[00000.000] 00000.00000> x2APIC enabled\n[00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001a7e6c (system_topology_init) at level 0x60002, flags 0x1\n[00000.000] 00000.00000> WARNING: more than 1000 levels of cache, couldn't find highest.\n[00000.000] 00000.00000> WARNING: unable to find any cache levels.\n[00000.000] 00000.00000> Could not find SRAT table. ACPICA returned: 5\n[00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00185e08 (timer) at level 0x60003, flags 0x1\n[00000.000] 00000.00000> HPET frequency: 23999 ticks/ms\n[00000.000] 00000.00000> TSC frequency: 2712000 ticks/ms\n[00589.824] 00000.00000> timer features: constant_tsc 1 invariant_tsc 1 tsc_deadline 1\n[00589.824] 00000.00000> Using TSC as wallclock\n[00589.824] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00208930 (percpu_heap_init) at level 0x60003, flags 0x1\n[00589.824] 00000.00000> initializing kernel\n[00589.824] 00000.00000> initializing mp\n[00589.824] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00115118 (global_prng_thread_safe) at level 0x7ffff, flags 0x1\n[00589.824] 00000.00000> creating bootstrap completion thread\n[00589.824] 00000.00000> top of bootstrap2()\n[00589.824] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00131734 (libobject) at level 0x80000, flags 0x1\n[00589.824] 00000.00000> OOM: started thread\n[00589.824] 00000.00000> INIT: cpu 0, calling hook 0xffffffff0020589c (dpc) at level 0x80000, flags 0x1\n[00589.824] 00000.00000> Processor Model Info: type 0 family 0x6 model 0xe stepping 0x9\n[00589.824] 00000.00000> \tdisplay_family 0x6 display_model 0x8e\n[00589.824] 00000.00000> Vendor: Intel\n[00589.824] 00000.00000> Microarch: Kaby Lake\n[00589.824] 00000.00000> F/M/S: 6/8e/9\n[00589.824] 00000.00000> patch_level: 84\n[00589.824] 00000.00000> Brand: Intel(R) Core(TM) i5-7300U CPU @ 2.60GHz\n[00589.824] 00000.00000> Features: fpu sse sse2 sse3 ssse3 sse4.1 sse4.2 mmx avx avx2 fxsr pcid xsave mon aesni clflush \n[00589.824] 00000.00000> clflushopt fsgsbase tsc_adj smep smap erms rdrand rdseed syscall nx huge rdtscp \n[00589.824] 00000.00000> invar_tsc tsc_deadline x2apic vmx pt hwp \n[00589.824] 00000.00000> Properties: meltdown l1tf pcid_good \n[00589.824] 00000.00000> initializing platform\n[00589.824] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001a157c (x86_perfmon) at level 0x90000, flags 0x1\n[00589.824] 00000.00000> PMU: version 4\n[00589.824] 00000.00000> UART: started IRQ driven RX\n[00589.824] 00000.00000> UART: started IRQ driven TX\n[00589.824] 00000.00000> cpu topology:\n[00589.824] 00000.00000> \t0: apic id 0x0 BSP\n[00589.824] 00000.00000> \t1: apic id 0x1 \n[00589.824] 00000.00000> \t2: apic id 0x2 \n[00589.824] 00000.00000> \t3: apic id 0x3 \n[00589.824] 00000.00000> Found 4 cpus\n[00589.824] 00000.00000> booting apic ids: 0x1 0x2 0x3 \n[00589.838] 00000.00000> entering scheduler on cpu 1\n[00589.840] 00000.00000> entering scheduler on cpu 3\n[00589.840] 00000.00000> entering scheduler on cpu 2\n[00589.843] 00000.00000> smbios: manufacturer=\"Intel Corporation\" product=\"NUC7i5DNHE\"\n[00589.843] 00000.00000> initializing target\n[00589.843] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001850b8 (x86_pcie_init) at level 0xa0000, flags 0x1\n[00589.843] 00000.00000> moving to last init level\n[00589.843] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001214cc (debuglog) at level 0xb0000, flags 0x1\n[00589.843] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00174d40 (kcounters) at level 0xb0000, flags 0x1\n[00589.843] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00102aec (kernel_shell) at level 0xc0000, flags 0x1\n[00589.843] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00202ad4 (ktrace) at level 0xc0000, flags 0x1\n[00589.846] 00000.00000> ktrace: buffer at 0xffffff96c4b7e000 (33554432 bytes)\n[00589.846] 00000.00000> INIT: cpu 0, calling hook 0xffffffff002184f8 (userboot) at level 0xc0000, flags 0x1\n[00589.846] 00000.00000> userboot: ramdisk 0xc1f000 @ 0xffffff800695c000\n[00589.846] 00000.00000> userboot: userboot rodata 0 @ [0x4ad9542ba000,0x4ad9542bd000)\n[00589.846] 00000.00000> userboot: userboot code 0x3000 @ [0x4ad9542bd000,0x4ad9542c8000)\n[00589.846] 00000.00000> userboot: vdso/full rodata 0 @ [0x4ad9542c8000,0x4ad9542cf000)\n[00589.846] 00000.00000> userboot: vdso/full code 0x7000 @ [0x4ad9542cf000,0x4ad9542d0000)\n[00589.846] 00000.00000> userboot: entry point @ 0x4ad9542bdc90\n[00589.846] 01036.01043> userboot: option \"zircon.autorun.system=/boot/bin/sh+/boot/infra/runcmds\"\n[00589.877] 01036.01043> userboot: searching bootfs for 'bin/bootsvc'\n[00589.877] 01036.01043> userboot: 'bin/bootsvc' has PT_INTERP \"lib/ld.so.1\"\n[00589.877] 01036.01043> userboot: searching bootfs for 'lib/ld.so.1'\n[00589.877] 01036.01043> userboot: userboot: loaded lib/ld.so.1 at 0x4795cfdbb000, entry point 0x4795cfdd93d0\n[00589.877] 01036.01043> userboot: userboot: loaded vDSO at 0x5e49c9972000, entry point 0x5e49c99798fa\n[00589.877] 01036.01043> userboot: process bin/bootsvc started.\n[00589.877] 01036.01043> userboot: waiting for loader-service requests...\n[00589.877] 01036.01043> userboot: searching bootfs for 'lib/libasync-default.so'\n[00589.877] 01036.01043> userboot: searching bootfs for 'lib/libfdio.so'\n[00589.877] 01036.01043> userboot: searching bootfs for 'lib/libtrace-engine.so'\n[00589.877] 01036.01043> userboot: searching bootfs for 'lib/liblaunchpad.so'\n[00589.877] 01050.01053> {{{reset}}}\n[00589.877] 01050.01053> {{{module:0:<application>:elf:367d3374904876b8f143f2ed5e4dfb0248fef748}}}\n[00589.877] 01050.01053> {{{mmap:0x43493f178000:0x3a000:load:0:rx:0}}}\n[00589.877] 01050.01053> {{{mmap:0x43493f1b2000:0x4000:load:0:rw:0x3a000}}}\n[00589.877] 01050.01053> dso: id=367d3374904876b8f143f2ed5e4dfb0248fef748 base=0x000043493f178000 name=<application>\n[00589.877] 01050.01053> {{{module:0x2:<vDSO>:elf:71712e0a455898a51e34d40a4013786ab1fa5335}}}\n[00589.877] 01050.01053> {{{mmap:0x5e49c9972000:0x7000:load:0x2:r:0}}}\n[00589.877] 01050.01053> {{{mmap:0x5e49c9979000:0x1000:load:0x2:rx:0x7000}}}\n[00589.877] 01050.01053> dso: id=71712e0a455898a51e34d40a4013786ab1fa5335 base=0x00005e49c9972000 name=<vDSO>\n[00589.877] 01050.01053> {{{module:0x3:libasync-default.so:elf:8c511b4202cf569c8fdde14ca97222102ba3a9e0}}}\n[00589.877] 01050.01053> {{{mmap:0x3b36e4334000:0x1000:load:0x3:rx:0}}}\n[00589.877] 01050.01053> {{{mmap:0x3b36e4335000:0x1000:load:0x3:rw:0x1000}}}\n[00589.877] 01050.01053> dso: id=8c511b4202cf569c8fdde14ca97222102ba3a9e0 base=0x00003b36e4334000 name=libasync-default.so\n[00589.877] 01050.01053> {{{module:0x4:libfdio.so:elf:3efa72b2e3bd2e4271f835d34a81d9719d6e08a7}}}\n[00589.877] 01050.01053> {{{mmap:0x67b4075b5000:0x32000:load:0x4:rx:0}}}\n[00589.877] 01050.01053> {{{mmap:0x67b4075e8000:0x4000:load:0x4:rw:0x33000}}}\n[00589.877] 01050.01053> dso: id=3efa72b2e3bd2e4271f835d34a81d9719d6e08a7 base=0x000067b4075b5000 name=libfdio.so\n[00589.877] 01050.01053> {{{module:0x5:libtrace-engine.so:elf:95bc229c3cf2ab8a51f12c33a311105ff8976120}}}\n[00589.877] 01050.01053> {{{mmap:0x3e5e3e9a1000:0x9000:load:0x5:rx:0}}}\n[00589.877] 01050.01053> {{{mmap:0x3e5e3e9aa000:0x2000:load:0x5:rw:0x9000}}}\n[00589.877] 01050.01053> dso: id=95bc229c3cf2ab8a51f12c33a311105ff8976120 base=0x00003e5e3e9a1000 name=libtrace-engine.so\n[00589.877] 01050.01053> {{{module:0x6:liblaunchpad.so:elf:5b0854856213eae6bab93c982f39551f8f9591c5}}}\n[00589.877] 01050.01053> {{{mmap:0x1698a4e35000:0x7000:load:0x6:rx:0}}}\n[00589.877] 01050.01053> {{{mmap:0x1698a4e3c000:0x2000:load:0x6:rw:0x7000}}}\n[00589.877] 01050.01053> dso: id=5b0854856213eae6bab93c982f39551f8f9591c5 base=0x00001698a4e35000 name=liblaunchpad.so\n[00589.877] 01050.01053> {{{module:0x1:libc.so:elf:5d417db61b3a48a58a8fa1ffbfc2e71b830e0857}}}\n[00589.877] 01050.01053> {{{mmap:0x4795cfdbb000:0xa6000:load:0x1:rx:0}}}\n[00589.877] 01050.01053> {{{mmap:0x4795cfe61000:0x5000:load:0x1:rw:0xa6000}}}\n[00589.877] 01050.01053> dso: id=5d417db61b3a48a58a8fa1ffbfc2e71b830e0857 base=0x00004795cfdbb000 name=libc.so\n[00589.877] 01050.01053> bootsvc: Starting...\n[00589.877] 01036.01043> userboot: loader-service channel peer closed\n[00589.877] 01036.01043> userboot: finished!\n[00589.877] 01050.01053> bootsvc: Creating bootfs service...\n[00589.878] 01050.01053> bootsvc: Retrieving boot image...\n[00589.878] 01050.01053> bootsvc: Decommitted BOOTDATA VMO from 0 to 0xc1e000\n[00589.878] 01050.01053> bootsvc: Loading boot arguments...\n[00589.878] 01050.01053> bootsvc: Creating svcfs service...\n[00589.878] 01050.01053> bootsvc: Loading kernel VMOs...\n[00589.878] 01050.01053> bootsvc: Creating loader service...\n[00589.878] 01050.01053> bootsvc: Launching next process...\n[00589.878] 01050.01108> bootsvc: Launched bin/devcoordinator\n[00589.879] 01115.01130> devcoordinator: launch /boot/bin/svchost (svchost) OK\n[00589.880] 01115.01130> devcoordinator: launch /boot/bin/fshost (fshost) OK\n[00589.882] 01115.01321> devcoordinator: launch /boot/bin/pwrbtn-monitor (pwrbtn-monitor) OK\n[00589.882] 01115.01349> devcoordinator: launch /boot/bin/netsvc (netsvc) OK\n[00589.883] 01115.01349> devcoordinator: launch /boot/bin/virtual-console (virtual-console) OK\n[00589.887] 01115.01130> devcoordinator: full system required, ignoring fallback drivers until /system is loaded\n[00589.887] 01115.01130> devcoordinator: launch devhost 'devhost:sys': pid=2187\n[00589.887] 01115.01130> devcoordinator: launch devhost 'devhost:test': pid=2219\n[00589.887] 01115.01130> devcoordinator: launch devhost 'devhost:root': pid=2263\n[00589.888] 01115.01130> devcoordinator: launch devhost 'devhost:misc': pid=2329\n[00589.888] 02187.02201> devhost: trace provider registry begun\n[00589.889] 02219.02239> devhost: trace provider registry begun\n[00589.890] 02263.02288> devhost: trace provider registry begun\n[00589.890] 02329.02371> devhost: trace provider registry begun\n[00589.891] 01115.01333> devcoordinator: launch /boot/bin/sh (sh:console) OK\n[00589.974] 02187.02201> acpi-bus: not using IOMMU\n[00589.982] 02187.02201> PMU: 7 arch events\n[00589.982] 02187.02201> PMU: arch event id range: 1-7\n[00589.982] 02187.02201> PMU: 102 arch events\n[00589.982] 02187.02201> PMU: arch event id range: 1-241\n[00589.982] 02187.02201> Intel Processor Trace configuration for this chipset:\n[00589.982] 02187.02201> mtc_freq_mask: 0x249\n[00589.982] 02187.02201> cyc_thresh_mask: 0x3fff\n[00589.982] 02187.02201> psb_freq_mask: 0x3f\n[00589.982] 02187.02201> num addr ranges: 2\n[00589.982] 02187.02201> [sysmem_init 28] async_get_default_dispatcher(): 0x5d5ac7e45850\n[00589.982] 02187.02201> [sysmem_bind 40] sysmem_bind()\n[00589.982] 02187.02876> acpi-pwrbtn: initialized\n[00589.982] 01718.01764> vc: new input device /dev/class/input/000\n[00589.992] 02187.02876> WARNING: ACPI found bad _CRS address entry\n[00590.001] 02187.02876> WARNING: ACPI found bad _CRS address entry\n[00590.013] 02187.02876> acpi: published device pci(0x5d5a07e5a310), parent=sys(0x5d5b47e41710), handle=0x5d59c7e5e590\n[00590.014] 01115.01130> devcoordinator: launch devhost 'devhost:pci#1:8086:5916': pid=2972\n[00590.014] 01115.01130> devcoordinator: launch devhost 'devhost:pci#3:8086:9d2f': pid=3022\n[00590.014] 01115.01130> devcoordinator: launch devhost 'devhost:pci#5:8086:9d60': pid=3090\n[00590.015] 01115.01130> devcoordinator: launch devhost 'devhost:pci#6:8086:9d61': pid=3174\n[00590.016] 03022.03042> devhost: trace provider registry begun\n[00590.016] 03090.03112> devhost: trace provider registry begun\n[00590.016] 01115.01130> devcoordinator: launch devhost 'devhost:pci#9:8086:9d03': pid=3280\n[00590.017] 02187.02876> acpi: published device rtc(0x5d5a07e59ad0), parent=acpi(0x5d5b47e41310), handle=0x5d59c7e86450\n[00590.017] 01115.01130> devcoordinator: launch devhost 'devhost:pci#14:8086:9d71': pid=3434\n[00590.018] 03174.03204> devhost: trace provider registry begun\n[00590.018] 01115.01130> devcoordinator: launch devhost 'devhost:pci#16:8086:156f': pid=3514\n[00590.018] 03280.03308> devhost: trace provider registry begun\n[00590.018] 02187.02876> acpi-ec: initialized\n[00590.019] 02972.02986> devhost: trace provider registry begun\n[00590.020] 03280.03308> ahci: using MSI interrupt\n[00590.021] 03090.03112> initialized intel serialio i2c driver, reg=0x120527f86000 regsize=4096\n[00590.022] 02187.02876> acpi: failed to create NHLT VMO (res -10)\n[00590.022] 02187.02876> acpi: failed to publish NHLT metadata\n[00590.023] 03434.03471> devhost: trace provider registry begun\n[00590.023] 03514.03552> devhost: trace provider registry begun\n[00590.028] 03174.03204> initialized intel serialio i2c driver, reg=0x5302e06c9000 regsize=4096\n[00590.028] 03022.03862> * found USB device (0x18d1:0xa002, USB 2.0) config 1\n[00590.028] 03022.03862> * found USB device (0x18d1:0xa003, USB 3.0) config 1\n[00590.030] 03434.03471> [IHDA DSP 00:1f.3] Failed to fetch NHLT (res -25)\n[00590.030] 03434.03471> [IHDA Controller 00:1f.3] Failed to initialize DSP device (res = -25)\n[00590.099] 01622.01643> netifc: ? /dev/class/ethernet/000\n[00590.100] 01622.01643> netifc: create 512 eth buffers\n[00590.100] 01622.01643> macaddr: d4:5d:df:1a:42:86\n[00590.100] 01622.01643> ip6addr: fe80::d65d:df4d:fe1a:4286\n[00590.100] 01622.01643> snmaddr: ff02::1:ff1a:4286\n[00590.100] 01622.01643> netsvc: using /dev/class/ethernet/000\n[00590.100] 01622.01643> netsvc: nodename='ocean-drank-wick-plug'\n[00590.100] 01622.01643> netsvc: start\n[00590.129] 01718.01764> vc: new display device /dev/class/display-controller/000\n[00590.170] 02972.04240> i915: MST not supported\n[00590.674] 02972.04240> i915: MST not supported\n[00590.741] 03022.03862> * found USB device (0x0781:0x5583, USB 3.0) config 1\n[00591.491] 03022.03862> * found USB device (0x0cf3:0xe300, USB 2.1) config 1\n[00591.721] 02972.04240> i915: No displays detected\n[00592.030] 03090.03112> intel-i2c-controller: intel_serialio_i2c_slave_transfer: -21\n[00592.030] 03090.03112> i2c-hid: could not read HID descriptor: 0\n[00592.030] 03090.03112> devhost[00:15.0/i2c-bus-9d60/0020] bind driver '/boot/driver/i2c-hid.so' failed: -2\n[00592.030] 01115.01130> devcoordinator: rpc: bind-driver '0020' status -2\n[00592.030] 03174.03204> intel-i2c-controller: intel_serialio_i2c_slave_transfer: -21\n[00592.030] 03174.03204> i2c-hid: could not read HID descriptor: 0\n[00592.030] 03174.03204> devhost[00:15.1/i2c-bus-9d61/004c] bind driver '/boot/driver/i2c-hid.so' failed: -2\n[00592.030] 01115.01130> devcoordinator: rpc: bind-driver '004c' status -2\n[00592.037] 03280.03794> sata2: dev info\n[00592.037] 03280.03794> serial=711430953015 6 \n[00592.037] 03280.03794> firmware rev=1Q01A7 0\n[00592.037] 03280.03794> model id=IBIW NSS D \n[00592.037] 03280.03794> major=0x3f0 ACS2 DMA 32 commands\n[00592.037] 03280.03794> LBA48 234441648 sectors, sector size=512\n[00592.038] 01299.01313> fshost: /dev/class/block/000: GPT?\n[00592.038] 03280.03308> gpt: device_get_metadata failed (-25)\n[00592.039] 01299.01313> fshost: /dev/class/block/001: FVM?\n[00592.042] 01299.01313> devcoordinator: launch /boot/bin/blobfs (blobfs:/blob) OK\n[00592.188] 01299.01313> fshost: starting 'bin/pkgsvr' '025c9db410155e9d20d519a3c41624bbf5102857731ed156aa6173c5ca4f6238'...\n[00592.195] 01299.01313> devcoordinator: launch bin/pkgsvr (pkgfs) OK\n[00592.205] 04631.04842> pkgsvr: system: will be served from 025c9db410155e9d20d519a3c41624bbf5102857731ed156aa6173c5ca4f6238\n[00592.205] 04631.04842> pkgsvr: pkgfs serving index /data/pkgfs_index from blobfs /blob\n[00592.205] 01299.01313> fshost: /dev/class/block/005: zxcrypt?\n[00592.206] 03280.03308> devhost_get_handles(0x7c74e62be910:block) open path='zxcrypt', r=-2\n[00592.207] 01299.01313> fshost: mounting minfs\n[00592.208] 01299.01313> devcoordinator: launch /boot/bin/minfs (minfs:/data) OK\n[00592.244] 01115.04886> devcoordinator: adding system driver 'wlan' '/system/driver/wlanif.so'\n[00592.245] 01115.01783> devcoordinator: launch /system/bin/appmgr (appmgr) OK\n[00592.245] 01115.01783> autorun: starting '/boot/bin/sh' '/boot/infra/runcmds'...\n[00592.254] 01115.04886> devcoordinator: adding system driver 'magma_pdev_gpu' '/system/driver/libmsd_arm.so'\n[00592.256] 01115.04886> devcoordinator: adding system driver 'iwlwifi_pci' '/system/driver/iwlwifi.so'\n[00592.256] 01115.01783> devcoordinator: launch /boot/bin/sh (autorun:system) OK\n[00592.273] 01115.04886> devcoordinator: adding system driver 'qmi_usb' '/system/driver/qmi-transport.so'\n[00592.284] 01115.04886> devcoordinator: adding system driver 'brcmfmac' '/system/driver/brcmfmac.so'\n[00592.293] 01115.04886> devcoordinator: adding system driver 'gpu' '/system/driver/libmsd_intel.so'\n[00592.304] 01115.04886> devcoordinator: adding system driver 'usb_video' '/system/driver/usb_video.so'\n[00592.306] 01115.04886> devcoordinator: adding system driver 'bt_hci_passthrough' '/system/driver/bt-hci-passthrough.so'\n[00592.319] 01115.04886> devcoordinator: adding system driver 'wlan' '/system/driver/wlanphy.so'\n[00592.348] 01115.04886> devcoordinator: adding system driver 'bt_host' '/system/driver/bt-host.so'\n[00592.352] 01115.04886> devcoordinator: adding system driver 'qmi_fake' '/system/driver/qmi-fake.so'\n[00592.360] 01115.04886> devcoordinator: adding system driver 'rtl88xx' '/system/driver/rtl88xx.so'\n[00592.417] 01115.04886> devcoordinator: adding system driver 'ralink' '/system/driver/ralink.so'\n[00592.426] 01115.04886> devcoordinator: adding system driver 'virtual_audio' '/system/driver/virtual_audio_driver.so'\n[00592.430] 01115.04886> devcoordinator: adding system driver 'ath10k_pci' '/system/driver/ath10k.so'\n[00592.442] 01115.04886> devcoordinator: adding system driver 'bt_hci_fake' '/system/driver/bt-hci-fake.so'\n[00592.444] 01115.04886> devcoordinator: adding system driver 'bt_hog' '/system/driver/bt-hog.so'\n[00592.456] 05181.05200> [INFO:namespace_builder.cc(93)] config-data for sysmgr\n[00592.481] 01115.04886> devcoordinator: adding system driver 'bt_hci_intel' '/system/driver/bt-hci-intel.so'\n[00592.498] 01115.04886> devcoordinator: adding system driver 'mt8167s_gpu' '/system/driver/libmsd_img_rgx_mtk.so'\n[00592.523] 01115.04886> devcoordinator: adding system driver 'bt_hci_atheros' '/system/driver/bt-hci-atheros.so'\n[00592.537] 01115.04886> devcoordinator: adding system driver 'virtual_camera' '/system/driver/virtual_camera_driver.so'\n[00592.593] 01115.04886> devcoordinator: adding system driver 'wlan' '/system/driver/wlan.so'\n[00592.594] 01115.01130> devcoordinator: driver 'wlan' added\n[00592.594] 01115.01130> devcoordinator: driver 'bt_hci_atheros' added\n[00592.594] 01115.01130> devcoordinator: driver 'mt8167s_gpu' added\n[00592.594] 01115.01130> devcoordinator: driver 'bt_hci_intel' added\n[00592.594] 01115.01130> devcoordinator: driver 'bt_hog' added\n[00592.594] 01115.01130> devcoordinator: driver 'bt_hci_fake' added\n[00592.594] 01115.01130> devcoordinator: driver 'ath10k_pci' added\n[00592.595] 01115.01130> devcoordinator: launch devhost 'devhost:pci#11:168c:003e': pid=5940\n[00592.595] 01115.01130> devcoordinator: driver 'ralink' added\n[00592.595] 01115.01130> devcoordinator: driver 'rtl88xx' added\n[00592.595] 01115.01130> devcoordinator: driver 'qmi_fake' added\n[00592.595] 01115.01130> devcoordinator: driver 'bt_host' added\n[00592.595] 01115.01130> devcoordinator: driver 'wlan' added\n[00592.595] 01115.01130> devcoordinator: driver 'usb_video' added\n[00592.595] 01115.01130> devcoordinator: driver 'gpu' added\n[00592.595] 01115.01130> devcoordinator: driver 'brcmfmac' added\n[00592.595] 01115.01130> devcoordinator: driver 'qmi_usb' added\n[00592.595] 01115.01130> devcoordinator: driver 'iwlwifi_pci' added\n[00592.595] 01115.01130> devcoordinator: driver 'magma_pdev_gpu' added\n[00592.595] 01115.01130> devcoordinator: driver 'wlan' added\n[00592.595] 01115.01130> devcoordinator: driver 'bt_hci_passthrough' added\n[00592.595] 01115.01130> devcoordinator: fallback driver 'usb_composite' is available\n[00592.595] 01115.01130> devcoordinator: driver 'usb_composite' added\n[00592.596] 01115.01130> devcoordinator: fallback driver 'intel_disp' is available\n[00592.596] 01115.01130> devcoordinator: driver 'intel_disp' added\n[00592.597] 05940.05974> devhost: trace provider registry begun\n[00592.597] 05940.05974> ath10k: Probed chip QCA6174 ver: 2.1\n[00592.598] 03022.03042> UMS: parent: 'ifc-000'\n[00592.598] 03022.03042> UMS:Max lun is: 0\n[00592.599] 03022.03042> devhost[00:14.0/xhci/usb-bus/002/002/ifc-001] bind driver '/boot/driver/bt-transport-usb.so' failed: -2\n[00592.599] 01115.01130> devcoordinator: rpc: bind-driver 'ifc-001' status -2\n[00592.604] 03022.06419> UMS: block size is: 0x00000200\n[00592.604] 03022.06419> UMS: total blocks is: 30031250\n[00592.604] 03022.06419> UMS: total size is: 15376000000\n[00592.604] 03022.06419> UMS: read-only: 0 removable: 1\n[00592.625] 03022.08891> btatheros: Making visible\n[00592.625] 03022.08891> btatheros: loaded successfully\n[00592.628] 03022.09164> [INFO:command_channel.cc(149)] hci: initialized\n[00592.629] 01299.01313> fshost: /dev/class/block/007: MBR?\n[00592.634] 01299.01313> fshost: /dev/class/block/009: MBR?\n[00592.684] 05181.05200> [INFO:namespace_builder.cc(93)] config-data for amber\n[00592.693] 03022.09164> [WARN:adapter.cc(274)] gap: controller is using legacy HCI version 4.1\n[00592.701] 03022.09164> [INFO:acl_data_channel.cc(91)] hci: initialized\n[00592.747] 05181.05200> [INFO:namespace_builder.cc(93)] config-data for pkg_resolver\n[00592.863] 13659.13671> [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\n[00592.863] 13659.13671> kfill_days=2, start_event_aggregator_worker=1.\n[00592.924] 05181.05200> [INFO:namespace_builder.cc(93)] config-data for wlancfg\n[00592.953] 05181.05200> [INFO:namespace_builder.cc(93)] config-data for mdns\n[00592.971] 05940.13579> devhost: rpc:load-firmware failed: -25\n[00592.971] 05940.13579> devhost: rpc:load-firmware failed: -25\n[00593.181] 05181.05200> [INFO:namespace_builder.cc(93)] config-data for crashpad_agent\n[00593.208] 16648.16662> [INFO:main.cc(35)] Trace Manager starting with config: /pkg/data/tracing.config\n[00593.227] 15045.15057> [INFO:system_metrics_main.cc(23)] Cobalt SystemMetricsDaemon: System metrics daemon created.\n[00593.317] 17161.17173> wlanstack2 [I]: Starting\n[00593.678] 05940.13161> ath10k: Unknown eventid: 0x1d019\n[00593.682] 05940.13161> ath10k: Unknown eventid: 0x16006\n[00593.686] 05940.05974> wlanphy: event loop started\n[00593.687] 05940.05974> wlanphy_bind\n[00593.687] 17161.17173> wlanstack2::device [I]: new phy #0: /dev/sys/pci/01:00.0/ath10k-wlanphy/wlanphy\n[00593.687] 14276.14288> wlancfg got event: OnPhyAdded { phy_id: 0 }\n[00593.687] 14276.14288> wlancfg: phy 0 added\n[00593.687] 17161.17173> wlanstack2::service [I]: query_phy(id = 0)\n[00593.688] 17161.17173> wlanstack2::service [I]: query_phy(id = 0): received a 'QueryResult' from device\n[00593.688] 14276.14288> wlancfg: received a PhyInfo from phy #0: path is /dev/sys/pci/01:00.0/ath10k-wlanphy/wlanphy\n[00593.688] 14276.14288> using default wlan config entry for phy\n[00593.688] 14276.14288> wlancfg: Creating Client iface for phy 0\n[00593.694] 05940.05974> wlan_bind\n[00593.696] 05940.05974> ath10k: adding a station interface (vdev_id=0) ...\n[00593.697] 05940.05974> wlan: [I] Initialize a client MLME.\n[00593.698] 05940.18039> wlan: [I] starting MainLoop\n[00593.698] 05940.05974> wlan: [I] channel opened\n[00593.699] 17161.17173> wlanstack2::device [I]: new iface #0 with role 'Client': /dev/sys/pci/01:00.0/ath10k-wlanphy/ath10k-wlanmac/wlan\n[00593.699] 14276.14288> wlancfg got event: OnIfaceAdded { iface_id: 0 }\n[00593.700] 14276.14288> wlancfg: new iface 0 added successfully\n[00593.700] 14276.14288> wlancfg: Starting auto-connect loop with 0 saved networks\n[00611.195] 14457.14474> Starting mDNS on interface ethp001f6 [80fe::5dd6:ffdf:1afe:8642]\n[00611.195] 14457.14474> [WARNING:garnet/bin/mdns/service/mdns_interface_transceiver_v6.cc(29)] NET-291 IPV6_MULTICAST_LOOP not supported (ENOPROTOOPT), continuing anyway\n[00611.195] 14457.14474> [WARNING:garnet/bin/mdns/service/mdns_interface_transceiver_v6.cc(50)] NET-2180 IPV6_JOIN_GROUP returned ENODEV, mDNS will not communicate via IPV6\n[00615.262] 14457.14474> Starting mDNS on interface ethp001f6 192.168.42.101\n[00615.262] 14457.14474> [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\n[00615.262] 14457.14474> Starting mDNS on interface ethp001f6 [80fe::5dd6:ffdf:1afe:8642]\n[00615.263] 14457.14474> [WARNING:garnet/bin/mdns/service/mdns_interface_transceiver_v6.cc(29)] NET-291 IPV6_MULTICAST_LOOP not supported (ENOPROTOOPT), continuing anyway\n[00615.263] 14457.14474> [WARNING:garnet/bin/mdns/service/mdns_interface_transceiver_v6.cc(50)] NET-2180 IPV6_JOIN_GROUP returned ENODEV, mDNS will not communicate via IPV6\n[00615.263] 14457.14474> mDNS: Verifying uniqueness of host name ocean-drank-wick-plug.local.\n[00616.172] 14457.14474> mDNS: Using unique host name ocean-drank-wick-plug.local.\nRunning tests sequentially.\n[tb] 2019-04-20 01:16:53.591 \u001b[22mINFO\u001b[0m [SshConnection | 192.168.42.101] Starting master ssh connection. [connection.py:setup_master_ssh:141]\n[00628.125] 23410.23422> setsockopt IP_TOS 32: Protocol not available:\n[tb] 2019-04-20 01:16:53.812 \u001b[22mINFO\u001b[0m [SshConnection | 192.168.42.101] Starting master ssh connection. [connection.py:setup_master_ssh:141]\n[00628.350] 23984.23997> setsockopt IP_TOS 32: Protocol not available:\n[tb] 2019-04-20 01:16:55.039 \u001b[22mINFO\u001b[0m [SshConnection | 192.168.42.101] Starting master ssh connection. [connection.py:setup_master_ssh:141]\n[00629.560] 25033.25048> setsockopt IP_TOS 32: Protocol not available:\n[tb] 2019-04-20 01:16:55.281 \u001b[22mINFO\u001b[0m [SshConnection | 192.168.42.102] Starting master ssh connection. [connection.py:setup_master_ssh:141]\n[00932.363] 23331.23343> setsockopt IP_TOS 32: Protocol not available:\n[tb] 2019-04-20 01:16:55.511 \u001b[22mINFO\u001b[0m [SshConnection | 192.168.42.102] Starting master ssh connection. [connection.py:setup_master_ssh:141]\n[00932.579] 23908.23923> setsockopt IP_TOS 32: Protocol not available:\n[tb] 2019-04-20 01:16:56.730 \u001b[22mINFO\u001b[0m [SshConnection | 192.168.42.102] Starting master ssh connection. [connection.py:setup_master_ssh:141]\n[00933.792] 24952.24965> setsockopt IP_TOS 32: Protocol not available:\n[tb] 2019-04-20 01:16:56.952 \u001b[22mINFO\u001b[0m Controller FuchsiaDevice: [{'ip': '192.168.42.101'}, {'ip': '192.168.42.102'}] [base_test.py:register_controller:396]\n[tb] 2019-04-20 01:16:56.953 \u001b[22mINFO\u001b[0m ==========> Sl4fSanityTest <========== [base_test.py:run:967]\n[tb] 2019-04-20 01:16:56.954 \u001b[22mINFO\u001b[0m Congratulations! Fuchsia controllers have been initialized successfully! [Sl4fSanityTest.py:setup_class:41]\n[tb] 2019-04-20 01:16:56.954 \u001b[22mINFO\u001b[0m [Test Case] test_example [base_test.py:exec_one_testcase:662]\n[tb] 2019-04-20 01:16:56.955 \u001b[22mINFO\u001b[0m Congratulations! You've run your first test. [Sl4fSanityTest.py:test_example:46]\n[tb] 2019-04-20 01:16:56.956 \u001b[22mINFO\u001b[0m [Test Case] test_example PASS [base_test.py:_on_pass:542]\n[tb] 2019-04-20 01:16:56.957 \u001b[22mINFO\u001b[0m Summary for test class Sl4fSanityTest: ControllerInfo {'FuchsiaDevice': [{'ip': '192.168.42.101'}, {'ip': '192.168.42.102'}]}, Requested 1, Executed 1, Passed 1, Failed 0, Skipped 0, Blocked 0, Unknown 0, Errors 0 [base_test.py:run:1027]\n[tb] 2019-04-20 01:16:56.959 \u001b[22mINFO\u001b[0m [SshConnection | 192.168.42.101] Starting master ssh connection. [connection.py:setup_master_ssh:141]\n[00631.477] 25601.25615> setsockopt IP_TOS 32: Protocol not available:\n[tb] 2019-04-20 01:16:57.187 \u001b[22mINFO\u001b[0m [SshConnection | 192.168.42.101] Starting master ssh connection. [connection.py:setup_master_ssh:141]\n[00631.732] 26192.26205> setsockopt IP_TOS 32: Protocol not available:\n[tb] 2019-04-20 01:16:58.412 \u001b[22mINFO\u001b[0m [SshConnection | 192.168.42.101] Starting master ssh connection. [connection.py:setup_master_ssh:141]\n[00632.933] 27252.27267> setsockopt IP_TOS 32: Protocol not available:\n[tb] 2019-04-20 01:16:58.641 \u001b[22mINFO\u001b[0m [SshConnection | 192.168.42.102] Starting master ssh connection. [connection.py:setup_master_ssh:141]\n[00935.716] 25520.25533> setsockopt IP_TOS 32: Protocol not available:\n[tb] 2019-04-20 01:16:58.865 \u001b[22mINFO\u001b[0m [SshConnection | 192.168.42.102] Starting master ssh connection. [connection.py:setup_master_ssh:141]\n[00935.946] 26110.26123> setsockopt IP_TOS 32: Protocol not available:\n[tb] 2019-04-20 01:17:00.092 \u001b[22mINFO\u001b[0m [SshConnection | 192.168.42.102] Starting master ssh connection. [connection.py:setup_master_ssh:141]\n[00937.172] 27167.27180> setsockopt IP_TOS 32: Protocol not available:\n[tb] 2019-04-20 01:17:00.318 \u001b[22mINFO\u001b[0m Controller FuchsiaDevice: [{'ip': '192.168.42.101'}, {'ip': '192.168.42.102'}] [base_test.py:register_controller:396]\n[tb] 2019-04-20 01:17:00.319 \u001b[22mINFO\u001b[0m Running testbed setup with two fuchsia devices [BleFuchsiaTest.py:__init__:38]\n[tb] 2019-04-20 01:17:00.320 \u001b[22mINFO\u001b[0m ==========> BleFuchsiaTest <========== [base_test.py:run:967]\n[tb] 2019-04-20 01:17:00.321 \u001b[22mINFO\u001b[0m [Test Case] test_fuchsia_gatt_fuchsia_periph [base_test.py:exec_one_testcase:662]\n[00634.858] 03022.03042> bt-transport-usb: timed out: ZX_ERR_TIMED_OUT\n[tb] 2019-04-20 01:17:00.466 \u001b[22mINFO\u001b[0m Publish result: {'result': None, 'error': None, 'id': '0'} [BleFuchsiaTest.py:test_fuchsia_gatt_fuchsia_periph:93]\n[tb] 2019-04-20 01:17:00.477 \u001b[22mINFO\u001b[0m Fuchsia advertising name: testADV1234 [BleFuchsiaTest.py:test_fuchsia_gatt_fuchsia_periph:102]\n[00937.553] 03076.03090> bt-transport-usb: timed out: ZX_ERR_TIMED_OUT\n[00937.618] 03076.09619> [INFO:low_energy_discovery_manager.cc(91)] gap-le: start discovery\n[tb] 2019-04-20 01:17:02.642 \u001b[22mINFO\u001b[0m Successfully found advertisement! name, id: testADV1234, 5c624a74a0b05537 [bt_test_utils.py:le_scan_for_device_by_name:43]\n[00939.670] 03076.09619> [INFO:low_energy_connection_manager.cc(751)] gap-le: new connection (LE link - handle: 0x0002, role: master, address: (LE rand) 49:64:9B:41:AF:B2, interval: 45.00 ms, latency: 0.00 ms, timeout: 420 ms)\n[tb] 2019-04-20 01:17:02.673 \u001b[22mINFO\u001b[0m Connecting returned status: {'result': None, 'error': None, 'id': '4'} [BleFuchsiaTest.py:test_fuchsia_gatt_fuchsia_periph:115]\n[tb] 2019-04-20 01:17:03.017 \u001b[22mINFO\u001b[0m Listing services returned: {'result': [{'primary': True, 'id': 1, 'uuid_type': '00001801-0000-1000-8000-00805f9b34fb'}, {'primary': True, 'id': 5, 'uuid_type': '0000180f-0000-1000-8000-00805fffffff'}], 'error': None, 'id': '5'} [BleFuchsiaTest.py:test_fuchsia_gatt_fuchsia_periph:118]\n[tb] 2019-04-20 01:17:03.024 \u001b[22mINFO\u001b[0m Disconnect status: {'result': None, 'error': None, 'id': '6'} [BleFuchsiaTest.py:test_fuchsia_gatt_fuchsia_periph:121]\n[00637.491] 03022.09164> [INFO:low_energy_connection_manager.cc(590)] gap-le: all refs dropped on connection: (LE link - handle: 0x0002, role: slave, address: (LE publ) 00:0E:8E:89:3F:A6, interval: 45.00 ms, latency: 0.00 ms, timeout: 420 ms)\n[tb] 2019-04-20 01:17:03.045 \u001b[22mINFO\u001b[0m [Test Case] test_fuchsia_gatt_fuchsia_periph PASS [base_test.py:_on_pass:542]\n[tb] 2019-04-20 01:17:03.047 \u001b[22mINFO\u001b[0m [Test Case] test_fuchsia_publish_service [base_test.py:exec_one_testcase:662]\n[tb] 2019-04-20 01:17:03.054 \u001b[22mINFO\u001b[0m Publish result: {'result': None, 'error': None, 'id': '3'} [BleFuchsiaTest.py:test_fuchsia_publish_service:56]\n[tb] 2019-04-20 01:17:03.067 \u001b[22mINFO\u001b[0m [Test Case] test_fuchsia_publish_service PASS [base_test.py:_on_pass:542]\n[tb] 2019-04-20 01:17:03.068 \u001b[22mINFO\u001b[0m [Test Case] test_fuchsia_scan_fuchsia_adv [base_test.py:exec_one_testcase:662]\n[00940.021] 03076.09619> [INFO:low_energy_connection_manager.cc(590)] gap-le: all refs dropped on connection: (LE link - handle: 0x0002, role: master, address: (LE rand) 49:64:9B:41:AF:B2, interval: 45.00 ms, latency: 0.00 ms, timeout: 420 ms)\n[00940.065] 03076.09619> [INFO:low_energy_connection_manager.cc(848)] gap-le: link disconnected - status: \"success\", handle: 0x0002, reason: 0x16\n[tb] 2019-04-20 01:17:03.077 \u001b[22mINFO\u001b[0m Fuchsia advertising name: testADV1234 [BleFuchsiaTest.py:test_fuchsia_scan_fuchsia_adv:69]\n[00637.521] 03022.09194> [WARN:acl_data_channel.cc(243)] hci: controller reported sent packets on unknown connection handle!\n[00637.527] 03022.09164> [INFO:low_energy_connection_manager.cc(848)] gap-le: link disconnected - status: \"success\", handle: 0x0002, reason: 0x16\n[00940.080] 03076.09619> [INFO:low_energy_discovery_manager.cc(91)] gap-le: start discovery\n[tb] 2019-04-20 01:17:05.113 \u001b[22mINFO\u001b[0m Successfully found advertisement! name, id: testADV1234, 5c624a74a0b05537 [bt_test_utils.py:le_scan_for_device_by_name:43]\n[tb] 2019-04-20 01:17:05.139 \u001b[22mINFO\u001b[0m [Test Case] test_fuchsia_scan_fuchsia_adv PASS [base_test.py:_on_pass:542]\n[tb] 2019-04-20 01:17:05.141 \u001b[22mINFO\u001b[0m Summary for test class BleFuchsiaTest: ControllerInfo {'FuchsiaDevice': [{'ip': '192.168.42.101'}, {'ip': '192.168.42.102'}]}, Requested 3, Executed 3, Passed 3, Failed 0, Skipped 0, Blocked 0, Unknown 0, Errors 0 [base_test.py:run:1027]\n[tb] 2019-04-20 01:17:05.143 \u001b[22mINFO\u001b[0m Summary for test run tb@2019-04-20_01-16-52-125: ControllerInfo {'FuchsiaDevice': [{'ip': '192.168.42.101'}, {'ip': '192.168.42.102'}]}, Requested 4, Executed 4, Passed 4, Failed 0, Skipped 0, Blocked 0, Unknown 0, Errors 0\n/etc/connectivity/acts/tools/test/connectivity/acts/framework/acts/controllers/buds_lib/test_actions/bt_utils.py:201: SyntaxWarning: assertion is always true, perhaps remove parentheses?\n assert (True is pri_device.droid.bluetoothUnbond(target_address),\nCommand succeeded!\n[00000.000] 00000.00000> zbi: @ 0xffffff80012f2000 (17482848 bytes)\n[00000.000] 00000.00000> UART: FIFO depth 16\n[00000.000] 00000.00000> PMM: boot reserve add [0x100000, 0x2c5fff]\n[00000.000] 00000.00000> PMM: boot reserve add [0x12f2000, 0x239efff]\n[00000.000] 00000.00000> PMM: arena too small to be useful (size 4096)\n[00000.000] 00000.00000> PMM: pmm_add_arena failed to initialize arena\n[00000.000] 00000.00000> MEM: Failed to add pmm range at 0x7ffff000 size 0x1000\n[00000.000] 00000.00000> PMM: boot reserve marking WIRED [0x100000, 0x2c5fff]\n[00000.000] 00000.00000> PMM: boot reserve marking WIRED [0x12f2000, 0x239efff]\n[00000.000] 00000.00000> \n[00000.000] 00000.00000> welcome to Zircon\n[00000.000] 00000.00000> \n[00000.000] 00000.00000> KASLR: .text section at 0xffffffff00100000\n[00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001aa428 (global_prng_seed) at level 0x30000, flags 0x1\n[00000.000] 00000.00000> initializing vm pre-heap\n", "outputs": [ "out.tar" ], "results": { "bot_dimensions": [ { "key": "device_type", "value": [ "Intel NUC Kit NUC7i5DNHE" ] }, { "key": "host_cpu", "value": [ "x64", "x86", "x86-64-avx2", "x86-64-i7-8559U" ] }, { "key": "host_os", "value": [ "Debian", "Debian-9.8", "Linux" ] }, { "key": "id", "value": [ "fuchsia946-row3-rack8-server-1--teststation-13" ] }, { "key": "pool", "value": [ "fuchsia.tests.connectivity" ] }, { "key": "server_version", "value": [ "4267-53b17d5" ] }, { "key": "testbed", "value": [ "bt_rf_chamber_nuc_nuc" ] }, { "key": "zone", "value": [ "cloud" ] } ], "bot_id": "fuchsia946-row3-rack8-server-1--teststation-13", "bot_version": "bd68e04e43fc4d1b7b5b65890a29c5d5bae55ab1423851733f92abd7e13dda14", "cipd_pins": { "client_package": { "package_name": "infra/tools/cipd/linux-amd64", "version": "nFftZl2kFquaI2EUmPGwzbc5sIbCocl9L55UeASqlLsC" }, "packages": [ { "package_name": "fuchsia/tools/botanist/linux-amd64", "path": ".", "version": "UKxkEVGmq0NiYbOjB0eSh6K_lJJ4_Mmm4BAi94owjbMC" } ] }, "completed_ts": "2019-04-20T01:17:56.226685", "costs_usd": [ 0.01634429884087666 ], "created_ts": "2019-04-20T01:14:04.470144", "duration": 123.66214895248413, "modified_ts": "2019-04-20T01:17:56.226685", "name": "all tests", "outputs_ref": { "isolated": "cd55008a449442c4a77e9fff0a39f67419fb8d30", "isolatedserver": "https://isolateserver.appspot.com", "namespace": "default-gzip" }, "run_id": "445120414e0d1211", "server_versions": [ "4267-53b17d5" ], "started_ts": "2019-04-20T01:14:19.055856", "state": "COMPLETED", "tags": [ "device_type:Intel NUC Kit NUC7i5DNHE", "pool:fuchsia.tests.connectivity", "priority:200", "service_account:none", "swarming.pool.template:none", "swarming.pool.version:b0a6cb78cd34832b49b843b36f65ec5a7a568a79", "testbed:bt_rf_chamber_nuc_nuc", "user:None" ], "task_id": "445120414e0d1210", "try_number": "1" } } }