@@@STEP_TEXT@1 out of 8 aggregated steps failed: Swarming task failed: 2019/04/21 06:01:20 attempting to send <>sparse.fvm... [00000.000] 00000.00000> zbi: @ 0xffffff80012f2000 (17482848 bytes) [00000.000] 00000.00000> UART: FIFO depth 16 [00000.000] 00000.00000> PMM: boot reserve add [0x100000, 0x2c5fff] [00000.000] 00000.00000> PMM: boot reserve add [0x12f2000, 0x239efff] [00000.000] 00000.00000> PMM: arena too small to be useful (size 4096) [00000.000] 00000.00000> PMM: pmm_add_arena failed to initialize arena [00000.000] 00000.00000> MEM: Failed to add pmm range at 0x7ffff000 size 0x1000 [00000.000] 00000.00000> PMM: boot reserve marking WIRED [0x100000, 0x2c5fff] [00000.000] 00000.00000> PMM: boot reserve marking WIRED [0x12f2000, 0x239efff] [00000.000] 00000.00000> [00000.000] 00000.00000> welcome to Zircon [00000.000] 00000.00000> [00000.000] 00000.00000> KASLR: .text section at 0xffffffff00100000 [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001aa428 (global_prng_seed) at level 0x30000, flags 0x1 [00000.000] 00000.00000> initializing vm pre-heap [00000.000] 00000.00000> VM: marking boot alloc used range [0x239f000, 0x239f100) [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00147abc (elf_build_id) at level 0x4fffe, flags 0x1 [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00147c48 (version) at level 0x4ffff, flags 0x1 [00000.000] 00000.00000> version: [00000.000] 00000.00000> arch: x86 [00000.000] 00000.00000> platform: pc [00000.000] 00000.00000> target: pc [00000.000] 00000.00000> project: x64 [00000.000] 00000.00000> buildid: git-13ee3dc5e4c46bf127977ad28645c47442ec517d [00000.000] 00000.00000> ELF build ID: 5f3e39bd4ed89d3b8122947842f1eac846a04683 [00000.000] 00000.00000> initializing heap [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00102e1c (x86_resource_init) at level 0x50000, flags 0x1 [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001a9630 (console) at level 0x50000, flags 0x1 [00000.000] 00000.00000> initializing vm [00000.000] 00000.00000> VM: reserving kernel region [0xffffffff00100000, 0xffffffff001ee000) flags 0x28 name 'kernel_code' [00000.000] 00000.00000> VM: reserving kernel region [0xffffffff001ee000, 0xffffffff00232000) flags 0x8 name 'kernel_rodata' [00000.000] 00000.00000> VM: reserving kernel region [0xffffffff00232000, 0xffffffff00242000) flags 0x18 name 'kernel_data' [00000.000] 00000.00000> VM: reserving kernel region [0xffffffff00242000, 0xffffffff002c6000) flags 0x18 name 'kernel_bss' [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00103ae0 (display_memtype) at level 0x60001, flags 0x1 [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00138fa0 (acpi_tables) at level 0x60001, flags 0x1 [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00101c40 (hpet) at level 0x60002, flags 0x1 [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00102000 (apic) at level 0x60002, flags 0x1 [00000.000] 00000.00000> x2APIC enabled [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001061b4 (timer) at level 0x60003, flags 0x1 [00000.000] 00000.00000> HPET frequency: 23999 ticks/ms [00000.000] 00000.00000> TSC frequency: 2712000 ticks/ms [00020.160] 00000.00000> timer features: constant_tsc 1 invariant_tsc 1 tsc_deadline 1 [00020.160] 00000.00000> Using TSC as wallclock [00020.160] 00000.00000> initializing kernel [00020.160] 00000.00000> initializing mp [00020.160] 00000.00000> initializing timers [00020.160] 00000.00000> INIT: cpu 0, calling hook 0xffffffff0013c578 (debuglog) at level 0x7ffff, flags 0x1 [00020.160] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00195518 (thread_set_priority_experiment) at level 0x7ffff, flags 0x1 [00020.160] 00000.00000> thread set priority experiment is : ENABLED [00020.160] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001aa67c (global_prng_thread_safe) at level 0x7ffff, flags 0x1 [00020.160] 00000.00000> creating bootstrap completion thread [00020.502] 00000.00000> top of bootstrap2() [00020.502] 00000.00000> INIT: cpu 0, calling hook 0xffffffff0013151c (dpc) at level 0x80000, flags 0x1 [00020.515] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00152978 (libobject) at level 0x80000, flags 0x1 [00020.515] 00000.00000> OOM: started thread [00020.529] 00000.00000> Processor Model Info: type 0 family 0x6 model 0xe stepping 0x9 [00020.529] 00000.00000> display_family 0x6 display_model 0x8e [00020.529] 00000.00000> Vendor: Intel [00020.529] 00000.00000> Microarch: Kaby Lake [00020.529] 00000.00000> F/M/S: 6/8e/9 [00020.529] 00000.00000> Brand: Intel(R) Core(TM) i5-7300U CPU @ 2.60GHz [00020.529] 00000.00000> Features: fpu sse sse2 sse3 ssse3 sse4.1 sse4.2 mmx avx avx2 fxsr pcid xsave mon aesni clflush [00020.529] 00000.00000> clflushopt fsgsbase tsc_adj smep smap erms rdrand rdseed syscall nx huge rdtscp [00020.529] 00000.00000> invar_tsc tsc_deadline x2apic vmx pt hwp [00020.529] 00000.00000> initializing platform [00020.529] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001101f4 (x86_perfmon) at level 0x90000, flags 0x1 [00020.529] 00000.00000> PMU: version 4 [00020.529] 00000.00000> UART: started IRQ driven RX [00020.529] 00000.00000> UART: started IRQ driven TX [00020.529] 00000.00000> cpu topology: [00020.529] 00000.00000> 0: apic id 0x0 package 0 node 0 core 0 smt 0 BSP [00020.529] 00000.00000> 1: apic id 0x2 package 0 node 0 core 1 smt 0 [00020.529] 00000.00000> 2: apic id 0x1 package 0 node 0 core 0 smt 1 [00020.529] 00000.00000> 3: apic id 0x3 package 0 node 0 core 1 smt 1 [00020.529] 00000.00000> Found 4 cpus [00020.529] 00000.00000> booting apic ids: 0x2 0x1 0x3 [00020.544] 00000.00000> entering scheduler on cpu 2 [00020.546] 00000.00000> entering scheduler on cpu 1 [00020.546] 00000.00000> entering scheduler on cpu 3 [00020.548] 00000.00000> smbios: manufacturer="Intel Corporation" product="NUC7i5DNKE" [00020.548] 00000.00000> initializing target [00020.548] 00000.00000> INIT: cpu 3, calling hook 0xffffffff001053a0 (x86_pcie_init) at level 0xa0000, flags 0x1 [00020.548] 00000.00000> moving to last init level [00020.548] 00000.00000> INIT: cpu 3, calling hook 0xffffffff00144140 (ktrace) at level 0xc0000, flags 0x1 [00020.552] 00000.00000> ktrace: buffer at 0xffffff947f903000 (33554432 bytes) [00020.552] 00000.00000> INIT: cpu 3, calling hook 0xffffffff00147ab4 (userboot) at level 0xc0000, flags 0x1 [00020.552] 00000.00000> userboot: ramdisk 0x10ad000 @ 0xffffff80012f2000 [00020.552] 00000.00000> userboot: userboot rodata 0 @ [0xdaaaed7000,0xdaaaeda000) [00020.552] 00000.00000> userboot: userboot code 0x3000 @ [0xdaaaeda000,0xdaaaee5000) [00020.552] 00000.00000> userboot: vdso/full rodata 0 @ [0xdaaaee5000,0xdaaaeec000) [00020.552] 00000.00000> userboot: vdso/full code 0x7000 @ [0xdaaaeec000,0xdaaaeed000) [00020.552] 00000.00000> userboot: entry point @ 0xdaaaedac10 [00020.552] 00000.00000> INIT: cpu 3, calling hook 0xffffffff001aa030 (kernel_shell) at level 0xc0000, flags 0x1 [00020.552] 01036.01043> userboot: option "netsvc.disable=true" [00020.552] 01036.01043> userboot: option "zircon.system.disable-automount=true" [00020.552] 01036.01043> userboot: option "zircon.autorun.boot=/boot/infra/setup" [00020.552] 01036.01043> userboot: option "kernel.serial=legacy" [00020.552] 01036.01043> userboot: option "http://192.168.42.1/multiboot/d4%3A5d%3Adf%3A1a%3A34%3A01=" [00020.552] 01036.01043> userboot: option "multiboot.boot_loader_name=iPXE+1.0.0++(d2063)" [00020.591] 01036.01043> userboot: searching bootfs for 'bin/bootsvc' [00020.591] 01036.01043> userboot: 'bin/bootsvc' has PT_INTERP "lib/ld.so.1" [00020.591] 01036.01043> userboot: searching bootfs for 'lib/ld.so.1' [00020.591] 01036.01043> userboot: userboot: loaded lib/ld.so.1 at 0x6ba6685b2000, entry point 0x6ba6686380d3 [00020.591] 01036.01043> userboot: userboot: loaded vDSO at 0x6e94e8b33000, entry point 0x0 [00020.591] 01036.01043> userboot: process bin/bootsvc started. [00020.591] 01036.01043> userboot: waiting for loader-service requests... [00020.592] 01036.01043> userboot: searching bootfs for 'lib/libasync-default.so' [00020.592] 01036.01043> userboot: searching bootfs for 'lib/libfdio.so' [00020.592] 01036.01043> userboot: searching bootfs for 'lib/liblaunchpad.so' [00020.592] 01036.01043> userboot: searching bootfs for 'lib/libtrace-engine.so' [00020.592] 01050.01053> {{{reset}}} [00020.592] 01050.01053> {{{module:0::elf:18de7d58f51e8ba5c4f6afdd0cc8440f482c2b45}}} [00020.592] 01050.01053> {{{mmap:0x6ff0aa135000:0x2e000:load:0:rx:0}}} [00020.592] 01050.01053> {{{mmap:0x6ff0aa163000:0x4000:load:0:rw:0x2e000}}} [00020.592] 01050.01053> dso: id=18de7d58f51e8ba5c4f6afdd0cc8440f482c2b45 base=0x00006ff0aa135000 name= [00020.592] 01050.01053> {{{module:0x3:libasync-default.so:elf:c189f51f19d10785d93b5235ad1b46dca4451b00}}} [00020.592] 01050.01053> {{{mmap:0x75416a6c7000:0x1000:load:0x3:rx:0}}} [00020.592] 01050.01053> {{{mmap:0x75416a6c8000:0x1000:load:0x3:rw:0x1000}}} [00020.592] 01050.01053> dso: id=c189f51f19d10785d93b5235ad1b46dca4451b00 base=0x000075416a6c7000 name=libasync-default.so [00020.592] 01050.01053> {{{module:0x2::elf:40ab5fa3b61f12fef4a44477a687f608661cd450}}} [00020.592] 01050.01053> {{{mmap:0x6e94e8b33000:0x7000:load:0x2:r:0}}} [00020.592] 01050.01053> {{{mmap:0x6e94e8b3a000:0x1000:load:0x2:rx:0x7000}}} [00020.592] 01050.01053> dso: id=40ab5fa3b61f12fef4a44477a687f608661cd450 base=0x00006e94e8b33000 name= [00020.592] 01050.01053> {{{module:0x1:libc.so:elf:67a12284bce140fc32aaaeac223e0e8f85cb5085}}} [00020.592] 01050.01053> {{{mmap:0x6ba6685b2000:0xcb000:load:0x1:rx:0}}} [00020.592] 01050.01053> {{{mmap:0x6ba66867e000:0x6000:load:0x1:rw:0xcc000}}} [00020.592] 01050.01053> dso: id=67a12284bce140fc32aaaeac223e0e8f85cb5085 base=0x00006ba6685b2000 name=libc.so [00020.592] 01050.01053> {{{module:0x4:libfdio.so:elf:27787977e95f3b9563c9e0bd4d34ec92b7e9ad88}}} [00020.592] 01050.01053> {{{mmap:0x609f0764c000:0x24000:load:0x4:rx:0}}} [00020.592] 01050.01053> {{{mmap:0x609f07671000:0x4000:load:0x4:rw:0x25000}}} [00020.592] 01050.01053> dso: id=27787977e95f3b9563c9e0bd4d34ec92b7e9ad88 base=0x0000609f0764c000 name=libfdio.so [00020.592] 01050.01053> {{{module:0x5:liblaunchpad.so:elf:6fc2232dc8c1bc5c6adb8ad50ca794b5a260ee4f}}} [00020.592] 01050.01053> {{{mmap:0x1caf2a4d9000:0x7000:load:0x5:rx:0}}} [00020.592] 01050.01053> {{{mmap:0x1caf2a4e0000:0x2000:load:0x5:rw:0x7000}}} [00020.592] 01050.01053> dso: id=6fc2232dc8c1bc5c6adb8ad50ca794b5a260ee4f base=0x00001caf2a4d9000 name=liblaunchpad.so [00020.592] 01050.01053> {{{module:0x6:libtrace-engine.so:elf:c9042b83fe01206008fcefb16395238417248169}}} [00020.592] 01050.01053> {{{mmap:0x1c38e586a000:0x9000:load:0x6:rx:0}}} [00020.592] 01050.01053> {{{mmap:0x1c38e5873000:0x2000:load:0x6:rw:0x9000}}} [00020.592] 01050.01053> dso: id=c9042b83fe01206008fcefb16395238417248169 base=0x00001c38e586a000 name=libtrace-engine.so [00020.592] 01050.01053> bootsvc: Starting... [00020.592] 01036.01043> userboot: loader-service channel peer closed [00020.592] 01036.01043> userboot: finished! [00020.592] 01050.01053> bootsvc: Creating bootfs service... [00020.593] 01050.01053> bootsvc: Processing bootdata... [00020.593] 01050.01053> bootsvc: Loading boot cmdline overrides... [00020.593] 01050.01053> bootsvc: Loading kernel VMOs... [00020.593] 01050.01053> bootsvc: Creating loader service... [00020.593] 01050.01053> bootsvc: Launching next process... [00020.593] 01050.01096> bootsvc: launched bin/devmgr [00020.594] 01104.01117> devmgr: main() [00020.594] 01104.01117> cmdline: netsvc.disable=true [00020.594] 01104.01117> cmdline: zircon.system.disable-automount=true [00020.594] 01104.01117> cmdline: zircon.autorun.boot=/boot/infra/setup [00020.594] 01104.01117> cmdline: kernel.serial=legacy [00020.594] 01104.01117> cmdline: http://192.168.42.1/multiboot/d4%3A5d%3Adf%3A1a%3A34%3A01= [00020.594] 01104.01117> cmdline: multiboot.boot_loader_name=iPXE+1.0.0++(d2063) [00020.594] 01104.01117> devmgr: coordinator_init() [00020.594] 01104.01117> devmgr: init [00020.594] 01104.01117> devmgr: svc init [00020.594] 01104.01117> devmgr: launch /boot/bin/svchost (svchost) OK [00020.594] 01104.01117> devmgr: vfs init [00020.594] 01104.01117> devmgr: launch /boot/bin/fshost (fshost) OK [00020.594] 01104.01221> devmgr: shell startup [00020.595] 01182.01202> fshost: started. [00020.596] 01104.01213> devmgr: launch /boot/bin/pwrbtn-monitor (pwrbtn-monitor) OK [00020.596] 01104.01229> devmgr: launch /boot/bin/virtual-console (virtual-console) OK [00020.596] 01104.01229> zircon.autorun.boot: starting '/boot/infra/setup'... [00020.597] 01104.01229> devmgr: launch /boot/infra/setup (autorun:boot) OK [00020.600] 01104.01117> devcoord: launch devhost 'devhost:sys': pid=2049 [00020.600] 01104.01117> devcoord: launch devhost 'devhost:test': pid=2082 [00020.600] 01104.01117> devcoord: launch devhost 'devhost:root': pid=2115 [00020.600] 01104.01117> devcoord: launch devhost 'devhost:misc': pid=2170 [00020.601] 02082.02106> devhost: trace provider registry begun [00020.602] 02049.02073> devhost: trace provider registry begun [00020.603] 02115.02155> devhost: trace provider registry begun [00020.603] 02170.02204> devhost: trace provider registry begun [00020.612] 01104.01221> devmgr: launch /boot/bin/sh (sh:console) OK [00020.660] 02049.02073> acpi-bus: not using IOMMU [00020.665] 02049.02073> acpi-pwrbtn: initialized [00020.671] 02049.02073> WARNING: ACPI found bad _CRS address entry [00020.677] 02049.02073> WARNING: ACPI found bad _CRS address entry [00020.687] 02049.02073> acpi: published device pci(0x75a7f485e200), parent=proxy(0x75a7f485a540), handle=0x75a7f4896c30 [00020.689] 02049.02073> acpi: published device rtc(0x75a7f4859080), parent=acpi(0x75a7f485a780), handle=0x75a7f48af5b0 [00020.690] 02049.02073> acpi-ec: initialized [00020.691] 02049.02073> acpi: failed to create NHLT VMO (res -10) [00020.691] 02049.02073> acpi: failed to publish NHLT metadata [00020.693] 02049.02073> [sysmem_init 28] async_get_default_dispatcher(): 0x75a7f484d0a0 [00020.694] 02049.02073> [sysmem_bind 40] sysmem_bind() [00020.694] 02049.02073> acpi-bus: sysmem_register_protocol() intentionally ignored for now. [00020.694] 02049.02073> PMU: 7 arch events [00020.694] 02049.02073> PMU: arch event id range: 1-7 [00020.694] 02049.02073> PMU: 102 model events [00020.694] 02049.02073> PMU: model event id range: 1-241 [00020.694] 02049.02073> Intel Processor Trace configuration for this chipset: [00020.694] 02049.02073> mtc_freq_mask: 0x249 [00020.694] 02049.02073> cyc_thresh_mask: 0x3fff [00020.694] 02049.02073> psb_freq_mask: 0x3f [00020.694] 02049.02073> num addr ranges: 2 [00020.694] 01104.01117> devcoord: launch devhost 'devhost:pci#1:8086:5916': pid=2840 [00020.694] 01104.01117> devcoord: launch devhost 'devhost:pci#3:8086:9d2f': pid=2887 [00020.695] 01104.01117> devcoord: launch devhost 'devhost:pci#5:8086:9d60': pid=2947 [00020.695] 01104.01117> devcoord: launch devhost 'devhost:pci#6:8086:9d61': pid=3007 [00020.695] 02840.02863> devhost: trace provider registry begun [00020.696] 01104.01117> devcoord: launch devhost 'devhost:pci#9:8086:9d03': pid=3083 [00020.696] 02887.02920> devhost: trace provider registry begun [00020.696] 01104.01117> devcoord: launch devhost 'devhost:pci#14:8086:9d71': pid=3165 [00020.698] 02947.02983> devhost: trace provider registry begun [00020.698] 03007.03043> devhost: trace provider registry begun [00020.698] 01104.01117> devcoord: launch devhost 'devhost:pci#16:8086:156f': pid=3259 [00020.700] 02947.02983> initialized intel serialio i2c driver, reg=0x101da745c000 regsize=4096 [00020.700] 03007.03043> initialized intel serialio i2c driver, reg=0x7bdef97e3000 regsize=4096 [00020.700] 03083.03118> devhost: trace provider registry begun [00020.701] 03165.03226> devhost: trace provider registry begun [00020.701] 03259.03341> devhost: trace provider registry begun [00020.702] 03083.03118> ahci: using MSI interrupt [00020.714] 02887.03659> * found USB device (0x18d1:0xa002, USB 2.0) config 1 [00020.714] 01235.01560> vc: new input device /dev/class/input/000 [00020.714] 02887.03659> * found USB device (0x18d1:0xa003, USB 3.0) config 1 [00020.733] 03165.03226> [IHDA DSP 00:1f.3] Failed to fetch NHLT (res -25) [00020.733] 03165.03226> devhost[00:1f.3/intel-hda-000/intel-sst-dsp-000] bind driver '/boot/driver/dsp.so' failed: -25 [00020.733] 01104.01117> devcoord: rpc: bind-driver 'intel-sst-dsp-000' status -25 [00020.804] 01235.01560> vc: new display device /dev/class/display-controller/000/virtcon [00020.944] 02840.04142> i915: MST not supported [00021.444] 02840.04142> i915: Found DP monitor [00021.444] 02840.04142> i915: Display 1 connected [00022.004] 01235.01560> vc: Successfully attached to display 1 [00022.176] 02887.03659> * found USB device (0x0781:0x5571, USB 2.0) config 1 [00022.177] 02887.02920> UMS: parent: 'ifc-000' [00022.177] 02887.02920> UMS:Max lun is: 0 [00022.427] 02887.03659> * found USB device (0x8087:0x0a2b, USB 2.0) config 1 [00022.429] 02887.02920> devhost[00:14.0/xhci/usb-bus/002/002/ifc-001] bind driver '/boot/driver/bt-transport-usb.so' failed: -2 [00022.429] 01104.01117> devcoord: rpc: bind-driver 'ifc-001' status -2 [00022.703] 03007.03043> intel-i2c-controller: intel_serialio_i2c_slave_transfer: -21 [00022.703] 03007.03043> i2c-hid: could not read HID descriptor: 0 [00022.703] 03007.03043> devhost[00:15.1/i2c-bus-9d61/004c] bind driver '/boot/driver/i2c-hid.so' failed: -2 [00022.703] 01104.01117> devcoord: rpc: bind-driver '004c' status -2 [00022.704] 02947.02983> intel-i2c-controller: intel_serialio_i2c_slave_transfer: -21 [00022.704] 02947.02983> i2c-hid: could not read HID descriptor: 0 [00022.704] 02947.02983> devhost[00:15.0/i2c-bus-9d60/0020] bind driver '/boot/driver/i2c-hid.so' failed: -2 [00022.704] 01104.01117> devcoord: rpc: bind-driver '0020' status -2 [00022.726] 03083.03718> sata2: dev info [00022.726] 03083.03718> serial=711430951080 3 [00022.726] 03083.03718> firmware rev=1Q01A7 0 [00022.726] 03083.03718> model id=IBIW NSS D [00022.726] 03083.03718> major=0x3f0 ACS2 DMA 32 commands [00022.726] 03083.03718> LBA48 234441648 sectors, sector size=512 [00022.728] 04413.04427> paver:[InitializeGpt] Located GPT is invalid; Attempting to initialize [00022.728] 01104.01117> devcoord: dc_bind_device() '/boot/driver/gpt.so' [00022.728] 03083.03118> gpt: device_get_metadata failed (-25) [00022.730] 04413.04427> paver:[Initialize] Successfully initialized EFI Device Partitioner [00022.730] 01104.01117> devcoord: dc_bind_device() '' [00022.730] 01182.01202> devmgr: /dev/class/block/000: GPT? [00022.730] 01104.01117> devcoord: dc_bind_device() '/boot/driver/gpt.so' [00022.730] 03083.03118> gpt: device_get_metadata failed (-25) [00022.732] 04569.04584> 34+0 records in [00022.732] 04569.04584> 34+0 records out [00022.732] 04569.04584> 17408 bytes copied [00022.733] 04674.04688> Failed to seek on output [00022.733] 04674.04688> 0+0 records in [00022.733] 04674.04688> 0+0 records out [00022.733] 04674.04688> 0 bytes copied [00022.734] 04744.04758> netifc: ? /dev/class/ethernet/000 [00022.734] 04744.04758> netifc: create 512 eth buffers [00022.734] 04744.04758> macaddr: d4:5d:df:1a:34:01 [00022.734] 04744.04758> ip6addr: fe80::d65d:df4d:fe1a:3401 [00022.734] 04744.04758> snmaddr: ff02::1:ff1a:3401 [00022.735] 04744.04758> netsvc: using /dev/class/ethernet/000 [00022.735] 04744.04758> _ _ _ [00022.735] 04744.04758> | | | | | [00022.735] 04744.04758> _______ __| | |__ ___ ___ | |_ [00022.735] 04744.04758> |_ / _ \/ _` | '_ \ / _ \ / _ \| __| [00022.735] 04744.04758> / / __/ (_| | |_) | (_) | (_) | |_ [00022.735] 04744.04758> /___\___|\__,_|_.__/ \___/ \___/ \__| [00022.735] 04744.04758> [00022.735] 04744.04758> [00022.735] 04744.04758> zedboot: version: 0.7.13 [00022.735] 04744.04758> [00022.735] 04744.04758> netsvc: nodename='wake-dug-sky-amend' [00022.735] 04744.04758> netsvc: will not advertise [00022.735] 04744.04758> netsvc: start [00023.179] 02887.04246> UMS: block size is: 0x00000200 [00023.179] 02887.04246> UMS: total blocks is: 15630336 [00023.179] 02887.04246> UMS: total size is: 8002732032 [00023.179] 02887.04246> UMS: read-only: 0 removable: 1 [00023.181] 01182.01202> devmgr: /dev/class/block/001: MBR? [00023.181] 01104.01117> devcoord: dc_bind_device() '/boot/driver/mbr.so' [00023.183] 01182.01202> devmgr: /dev/class/block/003: MBR? [00023.183] 01104.01117> devcoord: dc_bind_device() '/boot/driver/mbr.so' [07613.821] 04744.04758> netsvc: Running FVM Paver [07613.823] 04744.04926> paver:[InitializeGpt] Located GPT is invalid; Attempting to initialize [07613.823] 01104.01117> devcoord: dc_bind_device() '' [07613.823] 01104.01117> devcoord: dc_bind_device() '/boot/driver/gpt.so' [07613.823] 03083.03118> gpt: device_get_metadata failed (-25) [07613.824] 01182.01202> devmgr: /dev/class/block/000: GPT? [07613.824] 01104.01117> devcoord: dc_bind_device() '/boot/driver/gpt.so' [07613.824] 03083.03118> devhost: rpc:bind-device failed: -20 [07613.825] 04744.04926> paver:[Initialize] Successfully initialized EFI Device Partitioner [07613.825] 04744.04926> paver:[PartitionPave] Paving partition. [07613.825] 04744.04926> paver:[FindFirstFit] Looking for space [07613.825] 04744.04926> paver:[FindFirstFit] Sorting [07613.825] 04744.04926> paver:[FindFirstFit] Partition[0] From Block [0, 34) ... (next partition starts at block 234441614) [07613.825] 04744.04926> paver:[FindFirstFit] There are 234441580 free blocks (16777216 requested) [07613.825] 04744.04926> paver:[AddPartition] Found space in GPT - OK 234441580 @ 34 [07613.825] 04744.04926> paver:[AddPartition] Final space in GPT - OK 16777216 @ 34 [07613.825] 04744.04926> paver:[AddPartition] Added partition, waiting for bind [07613.825] 01104.01117> devcoord: dc_bind_device() '' [07613.826] 01182.01202> devmgr: /dev/class/block/000: GPT? [07613.826] 01104.01117> devcoord: dc_bind_device() '/boot/driver/gpt.so' [07613.826] 03083.03118> gpt: device_get_metadata failed (-25) [07613.827] 04744.04926> paver:[AddPartition] Added partition, waiting for bind - OK [07613.827] 04744.04926> paver:[PartitionPave] Streaming partitions... [07613.827] 04906.04920> Found compressed file [07613.827] 04744.04926> paver:[FvmStreamPartitions] Header Validated - OK [07613.827] 04744.04926> paver:[FvmPartitionFormat] Initializing partition as FVM [07613.829] 01104.01117> devcoord: dc_bind_device() '/boot/driver/fvm.so' [07614.831] 04744.04926> paver:[FvmStreamPartitions] Partitions pre-validated successfully: Enough space exists to pave. [07614.831] 04744.04926> paver:[AllocatePartitions] Allocating partition blobfs consisting of 1 slices [07614.835] 04744.04926> paver:[AllocatePartitions] Allocating partition minfs consisting of 1 slices [07614.836] 04744.04926> paver:[AllocatePartitions] Creating zxcrypt volume [07614.837] 03083.03118> devhost_get_handles(0x503c35a0f9c0:block) open path='zxcrypt/block', r=-2 [07614.837] 01104.01117> devcoord: dc_bind_device() '/boot/driver/zxcrypt.so' [07614.838] 03083.03118> devhost_get_handles(0x503c35a0f9c0:block) open path='zxcrypt', r=-2 [07614.841] 04744.04926> paver:[FvmStreamPartitions] Partition space pre-allocated successfully. [07614.842] 04744.04926> paver:[FvmStreamPartitions] Streaming partition 0 [07614.842] 04744.04926> paver:[StreamFvmPartition] Writing extent 0... [07614.842] 04744.04932> netsvc: paver write progress 0.0% [07614.842] 04744.04926> paver:[StreamFvmPartition] 8192 bytes written, 8380416 zeroes left [07614.859] 04744.04926> paver:[StreamFvmPartition] Writing extent 1... [07614.859] 04744.04926> paver:[StreamFvmPartition] 16384 bytes written, 8372224 zeroes left [07614.885] 04744.04926> paver:[StreamFvmPartition] Writing extent 2... [07614.890] 04744.04926> paver:[StreamFvmPartition] 2097152 bytes written, 6291456 zeroes left [07614.903] 04744.04926> paver:[StreamFvmPartition] Writing extent 3... [07614.907] 04744.04926> paver:[StreamFvmPartition] 2097152 bytes written, 6291456 zeroes left [07614.923] 04744.04926> paver:[StreamFvmPartition] Writing extent 4... [07615.842] 04744.04932> netsvc: paver write progress 32.9% [07616.842] 04744.04932> netsvc: paver write progress 49.3% [07617.842] 04744.04932> netsvc: paver write progress 65.8% [07618.842] 04744.04932> netsvc: paver write progress 82.2% [07619.842] 04744.04932> netsvc: paver write progress 98.7% 2019/04/21 06:01:26 done 2019/04/21 06:01:26 attempting to send <>bootloader.img... 2019/04/21 06:01:26 target is busy, retrying in one second [07619.919] 04744.04758> netsvc: tftp write of file <>sparse.fvm completed [07619.919] 04744.04758> netsvc: metrics: {"inorderblks": 595042,"oooblks": 0,"ack": 2325,"nack": 0,"timeouts": 0,"sas": 0,"inorderbytes": 609322997} [07619.921] 04744.04926> paver:[StreamFvmPartition] 652238848 bytes written, 2072576 zeroes left [07619.925] 04744.04926> paver:[FvmStreamPartitions] Done streaming partition 0 [07619.925] 04744.04926> paver:[FvmStreamPartitions] Done flushing partition 0 [07619.925] 04744.04926> paver:[FvmStreamPartitions] Streaming partition 1 [07619.925] 04744.04926> paver:[StreamFvmPartition] Writing extent 0... [07619.925] 04744.04926> paver:[StreamFvmPartition] 8192 bytes written, 8380416 zeroes left [07619.964] 04744.04926> paver:[StreamFvmPartition] Writing extent 1... [07619.964] 04744.04926> paver:[StreamFvmPartition] 65536 bytes written, 8323072 zeroes left [07620.005] 04744.04926> paver:[StreamFvmPartition] Writing extent 2... [07620.006] 04744.04926> paver:[StreamFvmPartition] 65536 bytes written, 8323072 zeroes left [07620.041] 04744.04926> paver:[StreamFvmPartition] Writing extent 3... [07620.086] 04744.04926> paver:[StreamFvmPartition] Writing extent 4... [07620.095] 04744.04926> paver:[StreamFvmPartition] 2097152 bytes written, 14680064 zeroes left [07620.158] 04744.04926> paver:[StreamFvmPartition] Writing extent 5... [07620.158] 04744.04926> paver:[StreamFvmPartition] 57344 bytes written, 8331264 zeroes left [07620.198] 04744.04926> paver:[FvmStreamPartitions] Done streaming partition 1 [07620.198] 04744.04926> paver:[FvmStreamPartitions] Done flushing partition 1 [07620.199] 04906.04920> Reading FVM from compressed file: true [07620.199] 04906.04920> Remaining bytes read into compression buffer: 0 [07620.199] 04906.04920> Remaining bytes written to decompression buffer: 0 [07620.199] 04906.04920> Time reading bytes from sparse FVM file: 9557534824 (3 s) [07620.199] 04906.04920> Time reading bytes AND decompressing them: 9854242517 (3 s) [07620.199] 04744.04926> paver:[PartitionPave] Completed successfully 2019/04/21 06:01:27 attempting to send <>bootloader.img... 2019/04/21 06:01:27 done 2019/04/21 06:01:27 attempting to send <>zircona.img... [07620.920] 04744.04758> netsvc: Running BOOTLOADER Paver [07620.924] 04744.06098> paver:[Initialize] Successfully initialized EFI Device Partitioner [07620.924] 04744.06098> paver:[RealMain] SKIPPING BOOTLOADER install on x64 device, pass --force if desired. [07620.940] 04744.04758> netsvc: tftp write of file <>bootloader.img completed [07620.940] 04744.04758> netsvc: metrics: {"inorderblks": 1093,"oooblks": 0,"ack": 5,"nack": 0,"timeouts": 0,"sas": 0,"inorderbytes": 1118208} [07620.940] 04744.04758> netsvc: Running ZIRCON-A Paver [07620.943] 04744.06227> paver:[Initialize] Successfully initialized EFI Device Partitioner [07620.943] 04744.06227> paver:[PartitionPave] Paving partition. [07620.943] 04744.06227> paver:[FindFirstFit] Looking for space [07620.943] 04744.06227> paver:[FindFirstFit] Partition seen with start 34, end 16777249 (length 16777216) [07620.943] 04744.06227> paver:[FindFirstFit] Sorting [07620.943] 04744.06227> paver:[FindFirstFit] Partition[0] From Block [0, 34) ... (next partition starts at block 34) [07620.943] 04744.06227> paver:[FindFirstFit] There are 0 free blocks (32768 requested) [07620.943] 04744.06227> paver:[FindFirstFit] Partition[1] From Block [34, 16777250) ... (next partition starts at block 234441614) [07620.943] 04744.06227> paver:[FindFirstFit] There are 217664364 free blocks (32768 requested) [07620.943] 04744.06227> paver:[AddPartition] Found space in GPT - OK 217664364 @ 16777250 [07620.943] 04744.06227> paver:[AddPartition] Final space in GPT - OK 32768 @ 16777250 [07620.944] 04744.06227> paver:[AddPartition] Added partition, waiting for bind [07620.944] 03083.03118> block: Joining un-closed FIFO server [07620.944] 03083.03118> block: Joining un-closed FIFO server [07620.944] 01104.01117> devcoord: dc_bind_device() '' [07620.955] 01182.01202> devmgr: /dev/class/block/000: GPT? [07620.955] 01104.01117> devcoord: dc_bind_device() '/boot/driver/gpt.so' [07620.955] 03083.03118> gpt: device_get_metadata failed (-25) [07620.956] 01182.01202> devmgr: /dev/class/block/008: FVM? [07620.956] 01104.01117> devcoord: dc_bind_device() '/boot/driver/fvm.so' [07620.956] 04744.06227> paver:[AddPartition] Added partition, waiting for bind - OK 2019/04/21 06:01:28 done 2019/04/21 06:01:28 attempting to send <>zirconr.img... 2019/04/21 06:01:28 target is busy, retrying in one second [07621.071] 04744.04758> netsvc: tftp write of file <>zircona.img completed [07621.071] 04744.04758> netsvc: metrics: {"inorderblks": 11739,"oooblks": 0,"ack": 46,"nack": 0,"timeouts": 0,"sas": 0,"inorderbytes": 12019760} [07621.179] 04744.06227> paver:[PartitionPave] Completed successfully 2019/04/21 06:01:29 attempting to send <>zirconr.img... [07622.072] 04744.04758> netsvc: Running ZIRCON-R Paver [07622.077] 04744.06487> paver:[Initialize] Successfully initialized EFI Device Partitioner [07622.077] 04744.06487> paver:[PartitionPave] Paving partition. [07622.077] 04744.06487> paver:[FindFirstFit] Looking for space [07622.077] 04744.06487> paver:[FindFirstFit] Partition seen with start 34, end 16777249 (length 16777216) [07622.077] 04744.06487> paver:[FindFirstFit] Partition seen with start 16777250, end 16810017 (length 32768) [07622.077] 04744.06487> paver:[FindFirstFit] Sorting [07622.077] 04744.06487> paver:[FindFirstFit] Partition[0] From Block [0, 34) ... (next partition starts at block 34) [07622.077] 04744.06487> paver:[FindFirstFit] There are 0 free blocks (49152 requested) [07622.077] 04744.06487> paver:[FindFirstFit] Partition[1] From Block [34, 16777250) ... (next partition starts at block 16777250) [07622.077] 04744.06487> paver:[FindFirstFit] There are 0 free blocks (49152 requested) [07622.077] 04744.06487> paver:[FindFirstFit] Partition[2] From Block [16777250, 16810018) ... (next partition starts at block 234441614) [07622.077] 04744.06487> paver:[FindFirstFit] There are 217631596 free blocks (49152 requested) [07622.077] 04744.06487> paver:[AddPartition] Found space in GPT - OK 217631596 @ 16810018 [07622.077] 04744.06487> paver:[AddPartition] Final space in GPT - OK 49152 @ 16810018 [07622.078] 04744.06487> paver:[AddPartition] Added partition, waiting for bind [07622.078] 03083.03118> block: Joining un-closed FIFO server [07622.078] 01104.01117> devcoord: dc_bind_device() '' [07622.090] 01182.01202> devmgr: /dev/class/block/000: GPT? [07622.090] 01104.01117> devcoord: dc_bind_device() '/boot/driver/gpt.so' [07622.090] 03083.03118> gpt: device_get_metadata failed (-25) [07622.091] 01182.01202> devmgr: /dev/class/block/012: FVM? [07622.091] 01104.01117> devcoord: dc_bind_device() '/boot/driver/fvm.so' [07622.091] 04744.06487> paver:[AddPartition] Added partition, waiting for bind - OK 2019/04/21 06:01:29 done 2019/04/21 06:01:29 attempting to send <>authorized_keys... 2019/04/21 06:01:29 target is busy, retrying in one second [07622.196] 04744.04758> netsvc: tftp write of file <>zirconr.img completed [07622.196] 04744.04758> netsvc: metrics: {"inorderblks": 10430,"oooblks": 0,"ack": 41,"nack": 0,"timeouts": 0,"sas": 0,"inorderbytes": 10679824} [07622.679] 04744.06487> paver:[PartitionPave] Completed successfully 2019/04/21 06:01:30 attempting to send <>authorized_keys... 2019/04/21 06:01:30 done 2019/04/21 06:01:30 attempting to send <>kernel.bin... 2019/04/21 06:01:30 target is busy, retrying in one second [07623.196] 04744.04758> netsvc: Installing SSH authorized_keys [07623.197] 04744.04758> netsvc: tftp write of file <>authorized_keys completed [07623.197] 04744.04758> netsvc: metrics: {"inorderblks": 1,"oooblks": 0,"ack": 1,"nack": 0,"timeouts": 0,"sas": 0,"inorderbytes": 806} [07623.202] 04744.06764> paver:[Initialize] Successfully initialized EFI Device Partitioner [07623.202] 01104.01117> devcoord: dc_bind_device() '/boot/driver/zxcrypt.so' [07623.203] 03083.03118> devhost_get_handles(0x503c35a0f9c0:block) open path='zxcrypt', r=-2 [07623.232] 04744.06764> paver:[DataFilePave] Wrote ssh/authorized_keys 2019/04/21 06:01:31 attempting to send <>kernel.bin... 2019/04/21 06:01:31 done [00000.000] 00000.00000> zbi: @ 0xffffff80066d9000 (10493384 bytes) [00000.000] 00000.00000> UART: FIFO depth 16 [00000.000] 00000.00000> PMM: boot reserve add [0x100000, 0x2fffff] [00000.000] 00000.00000> PMM: boot reserve add [0x66d9000, 0x70dafff] [00000.000] 00000.00000> PMM: arena too small to be useful (size 4096) [00000.000] 00000.00000> PMM: pmm_add_arena failed to initialize arena [00000.000] 00000.00000> MEM: Failed to add pmm range at 0x7ffff000 size 0x1000 [00000.000] 00000.00000> PMM: boot reserve marking WIRED [0x100000, 0x2fffff] [00000.000] 00000.00000> PMM: boot reserve marking WIRED [0x66d9000, 0x70dafff] [00000.000] 00000.00000> [00000.000] 00000.00000> welcome to Zircon [00000.000] 00000.00000> [00000.000] 00000.00000> KASLR: .text section at 0xffffffff00100000 [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00114ec4 (global_prng_seed) at level 0x30000, flags 0x1 [00000.000] 00000.00000> initializing vm pre-heap [00000.000] 00000.00000> VM: marking boot alloc used range [0x70db000, 0x70db100) [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00122274 (elf_build_id) at level 0x4fffe, flags 0x1 [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00122400 (version) at level 0x4ffff, flags 0x1 [00000.000] 00000.00000> version: [00000.000] 00000.00000> arch: x86 [00000.000] 00000.00000> platform: XXX [00000.000] 00000.00000> target: XXX [00000.000] 00000.00000> project: x64 [00000.000] 00000.00000> buildid: git-bf26263e2dcfffb700fa66cb73c06dfecdffe39c-dirty [00000.000] 00000.00000> ELF build ID: efa22948616c1106517d3cdd3aacbee41c5d80e0 [00000.000] 00000.00000> initializing heap [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00101fc4 (console) at level 0x50000, flags 0x1 [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001826c4 (x86_resource_init) at level 0x50000, flags 0x1 [00000.000] 00000.00000> initializing vm [00000.000] 00000.00000> VM: reserving kernel region [0xffffffff00100000, 0xffffffff0021b000) flags 0x28 name 'kernel_code' [00000.000] 00000.00000> VM: reserving kernel region [0xffffffff0021b000, 0xffffffff0026c000) flags 0x8 name 'kernel_rodata' [00000.000] 00000.00000> VM: reserving kernel region [0xffffffff0026c000, 0xffffffff00274000) flags 0x18 name 'kernel_data' [00000.000] 00000.00000> VM: reserving kernel region [0xffffffff00274000, 0xffffffff00300000) flags 0x18 name 'kernel_bss' [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00183388 (display_memtype) at level 0x60001, flags 0x1 [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00186818 (acpi_tables) at level 0x60001, flags 0x1 [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001814c8 (hpet) at level 0x60002, flags 0x1 [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00181888 (apic) at level 0x60002, flags 0x1 [00000.000] 00000.00000> x2APIC enabled [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001a7e6c (system_topology_init) at level 0x60002, flags 0x1 [00000.000] 00000.00000> WARNING: more than 1000 levels of cache, couldn't find highest. [00000.000] 00000.00000> WARNING: unable to find any cache levels. [00000.000] 00000.00000> Could not find SRAT table. ACPICA returned: 5 [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00185e08 (timer) at level 0x60003, flags 0x1 [00000.000] 00000.00000> HPET frequency: 23999 ticks/ms [00000.000] 00000.00000> TSC frequency: 2712000 ticks/ms [07624.615] 00000.00000> timer features: constant_tsc 1 invariant_tsc 1 tsc_deadline 1 [07624.615] 00000.00000> Using TSC as wallclock [07624.615] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00208930 (percpu_heap_init) at level 0x60003, flags 0x1 [07624.615] 00000.00000> initializing kernel [07624.615] 00000.00000> initializing mp [07624.615] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00115118 (global_prng_thread_safe) at level 0x7ffff, flags 0x1 [07624.615] 00000.00000> creating bootstrap completion thread [07624.615] 00000.00000> top of bootstrap2() [07624.615] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00131734 (libobject) at level 0x80000, flags 0x1 [07624.615] 00000.00000> OOM: started thread [07624.615] 00000.00000> INIT: cpu 0, calling hook 0xffffffff0020589c (dpc) at level 0x80000, flags 0x1 [07624.615] 00000.00000> Processor Model Info: type 0 family 0x6 model 0xe stepping 0x9 [07624.615] 00000.00000> display_family 0x6 display_model 0x8e [07624.615] 00000.00000> Vendor: Intel [07624.615] 00000.00000> Microarch: Kaby Lake [07624.615] 00000.00000> F/M/S: 6/8e/9 [07624.615] 00000.00000> patch_level: 8e [07624.615] 00000.00000> Brand: Intel(R) Core(TM) i5-7300U CPU @ 2.60GHz [07624.615] 00000.00000> Features: fpu sse sse2 sse3 ssse3 sse4.1 sse4.2 mmx avx avx2 fxsr pcid xsave mon aesni clflush [07624.615] 00000.00000> clflushopt fsgsbase tsc_adj smep smap erms rdrand rdseed syscall nx huge rdtscp [07624.615] 00000.00000> invar_tsc tsc_deadline x2apic vmx pt hwp [07624.615] 00000.00000> Properties: meltdown l1tf pcid_good [07624.615] 00000.00000> initializing platform [07624.615] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001a157c (x86_perfmon) at level 0x90000, flags 0x1 [07624.615] 00000.00000> PMU: version 4 [07624.615] 00000.00000> UART: started IRQ driven RX [07624.615] 00000.00000> UART: started IRQ driven TX [07624.615] 00000.00000> cpu topology: [07624.615] 00000.00000> 0: apic id 0x0 BSP [07624.615] 00000.00000> 1: apic id 0x1 [07624.615] 00000.00000> 2: apic id 0x2 [07624.615] 00000.00000> 3: apic id 0x3 [07624.615] 00000.00000> Found 4 cpus [07624.615] 00000.00000> booting apic ids: 0x1 0x2 0x3 [07624.629] 00000.00000> entering scheduler on cpu 1 [07624.631] 00000.00000> entering scheduler on cpu 2 [07624.631] 00000.00000> entering scheduler on cpu 3 [07624.633] 00000.00000> smbios: manufacturer="Intel Corporation" product="NUC7i5DNKE" [07624.633] 00000.00000> initializing target [07624.633] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001850b8 (x86_pcie_init) at level 0xa0000, flags 0x1 [07624.633] 00000.00000> moving to last init level [07624.633] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001214cc (debuglog) at level 0xb0000, flags 0x1 [07624.633] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00174d40 (kcounters) at level 0xb0000, flags 0x1 [07624.633] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00102aec (kernel_shell) at level 0xc0000, flags 0x1 [07624.633] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00202ad4 (ktrace) at level 0xc0000, flags 0x1 [07624.637] 00000.00000> ktrace: buffer at 0xffffff904c0da000 (33554432 bytes) [07624.637] 00000.00000> INIT: cpu 0, calling hook 0xffffffff002184f8 (userboot) at level 0xc0000, flags 0x1 [07624.637] 00000.00000> userboot: ramdisk 0xa02000 @ 0xffffff80066d9000 [07624.637] 00000.00000> userboot: userboot rodata 0 @ [0x4685d9be1000,0x4685d9be4000) [07624.637] 00000.00000> userboot: userboot code 0x3000 @ [0x4685d9be4000,0x4685d9bef000) [07624.637] 00000.00000> userboot: vdso/full rodata 0 @ [0x4685d9bef000,0x4685d9bf6000) [07624.637] 00000.00000> userboot: vdso/full code 0x7000 @ [0x4685d9bf6000,0x4685d9bf7000) [07624.637] 00000.00000> userboot: entry point @ 0x4685d9be4c90 [07624.661] 01036.01043> userboot: searching bootfs for 'bin/bootsvc' [07624.661] 01036.01043> userboot: 'bin/bootsvc' has PT_INTERP "lib/ld.so.1" [07624.661] 01036.01043> userboot: searching bootfs for 'lib/ld.so.1' [07624.661] 01036.01043> userboot: userboot: loaded lib/ld.so.1 at 0x635104a6f000, entry point 0x635104a8d3d0 [07624.661] 01036.01043> userboot: userboot: loaded vDSO at 0x5fe7588fb000, entry point 0x5fe7589028fa [07624.661] 01036.01043> userboot: process bin/bootsvc started. [07624.661] 01036.01043> userboot: waiting for loader-service requests... [07624.662] 01036.01043> userboot: searching bootfs for 'lib/libasync-default.so' [07624.662] 01036.01043> userboot: searching bootfs for 'lib/libfdio.so' [07624.662] 01036.01043> userboot: searching bootfs for 'lib/libtrace-engine.so' [07624.662] 01036.01043> userboot: searching bootfs for 'lib/liblaunchpad.so' [07624.662] 01050.01053> {{{reset}}} [07624.662] 01050.01053> {{{module:0::elf:75b7f737f54581e4427ceff9748da4a4ef1bcd24}}} [07624.662] 01050.01053> {{{mmap:0x6d53557ff000:0x3a000:load:0:rx:0}}} [07624.662] 01050.01053> {{{mmap:0x6d5355839000:0x4000:load:0:rw:0x3a000}}} [07624.662] 01050.01053> dso: id=75b7f737f54581e4427ceff9748da4a4ef1bcd24 base=0x00006d53557ff000 name= [07624.662] 01050.01053> {{{module:0x2::elf:68c31726d3cd86378d628df5150993bf8eb2e46a}}} [07624.662] 01050.01053> {{{mmap:0x5fe7588fb000:0x7000:load:0x2:r:0}}} [07624.662] 01050.01053> {{{mmap:0x5fe758902000:0x1000:load:0x2:rx:0x7000}}} [07624.662] 01050.01053> dso: id=68c31726d3cd86378d628df5150993bf8eb2e46a base=0x00005fe7588fb000 name= [07624.662] 01050.01053> {{{module:0x3:libasync-default.so:elf:8dee7308d47746cef72d381b15fd39c6e6cb6930}}} [07624.662] 01050.01053> {{{mmap:0x1c7a100b1000:0x1000:load:0x3:rx:0}}} [07624.662] 01050.01053> {{{mmap:0x1c7a100b2000:0x1000:load:0x3:rw:0x1000}}} [07624.662] 01050.01053> dso: id=8dee7308d47746cef72d381b15fd39c6e6cb6930 base=0x00001c7a100b1000 name=libasync-default.so [07624.662] 01050.01053> {{{module:0x4:libfdio.so:elf:8c02956f2960026f9844da8c007b78a1dafe960d}}} [07624.662] 01050.01053> {{{mmap:0x4ba1788f2000:0x32000:load:0x4:rx:0}}} [07624.662] 01050.01053> {{{mmap:0x4ba178925000:0x4000:load:0x4:rw:0x33000}}} [07624.662] 01050.01053> dso: id=8c02956f2960026f9844da8c007b78a1dafe960d base=0x00004ba1788f2000 name=libfdio.so [07624.662] 01050.01053> {{{module:0x5:libtrace-engine.so:elf:0d18f1d55fa2a8c0ab778661679dcede1a6ae949}}} [07624.662] 01050.01053> {{{mmap:0x7ed69d9e1000:0x9000:load:0x5:rx:0}}} [07624.662] 01050.01053> {{{mmap:0x7ed69d9ea000:0x2000:load:0x5:rw:0x9000}}} [07624.662] 01050.01053> dso: id=0d18f1d55fa2a8c0ab778661679dcede1a6ae949 base=0x00007ed69d9e1000 name=libtrace-engine.so [07624.662] 01050.01053> {{{module:0x6:liblaunchpad.so:elf:4220af5ebe1b1fe8ef154e543bd66a43fbe8dcfc}}} [07624.662] 01050.01053> {{{mmap:0x1e1c585c000:0x7000:load:0x6:rx:0}}} [07624.662] 01050.01053> {{{mmap:0x1e1c5863000:0x2000:load:0x6:rw:0x7000}}} [07624.662] 01050.01053> dso: id=4220af5ebe1b1fe8ef154e543bd66a43fbe8dcfc base=0x000001e1c585c000 name=liblaunchpad.so [07624.662] 01050.01053> {{{module:0x1:libc.so:elf:a5efb1cb302707c1c33c5061c15df54ab3838c0f}}} [07624.662] 01050.01053> {{{mmap:0x635104a6f000:0xa6000:load:0x1:rx:0}}} [07624.662] 01050.01053> {{{mmap:0x635104b15000:0x5000:load:0x1:rw:0xa6000}}} [07624.662] 01050.01053> dso: id=a5efb1cb302707c1c33c5061c15df54ab3838c0f base=0x0000635104a6f000 name=libc.so [07624.662] 01050.01053> bootsvc: Starting... [07624.662] 01036.01043> userboot: loader-service channel peer closed [07624.662] 01036.01043> userboot: finished! [07624.662] 01050.01053> bootsvc: Creating bootfs service... [07624.663] 01050.01053> bootsvc: Retrieving boot image... [07624.663] 01050.01053> bootsvc: Decommitted BOOTDATA VMO from 0 to 0xa01000 [07624.663] 01050.01053> bootsvc: Loading boot arguments... [07624.663] 01050.01053> bootsvc: Creating svcfs service... [07624.663] 01050.01053> bootsvc: Loading kernel VMOs... [07624.663] 01050.01053> bootsvc: Creating loader service... [07624.663] 01050.01053> bootsvc: Launching next process... [07624.663] 01050.01107> bootsvc: Launched bin/devcoordinator [07624.664] 01114.01129> devcoordinator: launch /boot/bin/svchost (svchost) OK [07624.665] 01114.01129> devcoordinator: launch /boot/bin/fshost (fshost) OK [07624.667] 01114.01320> devcoordinator: launch /boot/bin/pwrbtn-monitor (pwrbtn-monitor) OK [07624.667] 01114.01348> devcoordinator: launch /boot/bin/netsvc (netsvc) OK [07624.668] 01114.01348> devcoordinator: launch /boot/bin/virtual-console (virtual-console) OK [07624.671] 01114.01129> devcoordinator: full system required, ignoring fallback drivers until /system is loaded [07624.671] 01114.01129> devcoordinator: launch devhost 'devhost:sys': pid=2186 [07624.672] 01114.01129> devcoordinator: launch devhost 'devhost:test': pid=2218 [07624.672] 01114.01129> devcoordinator: launch devhost 'devhost:root': pid=2271 [07624.673] 01114.01129> devcoordinator: launch devhost 'devhost:misc': pid=2336 [07624.673] 02186.02200> devhost: trace provider registry begun [07624.673] 02218.02240> devhost: trace provider registry begun [07624.674] 02271.02302> devhost: trace provider registry begun [07624.675] 02336.02367> devhost: trace provider registry begun [07624.675] 01114.01332> devcoordinator: launch /boot/bin/sh (sh:console) OK [07624.760] 02186.02200> acpi-bus: not using IOMMU [07624.768] 02186.02200> PMU: 7 arch events [07624.768] 02186.02200> PMU: arch event id range: 1-7 [07624.768] 02186.02200> PMU: 102 arch events [07624.768] 02186.02200> PMU: arch event id range: 1-241 [07624.768] 02186.02200> Intel Processor Trace configuration for this chipset: [07624.768] 02186.02200> mtc_freq_mask: 0x249 [07624.768] 02186.02200> cyc_thresh_mask: 0x3fff [07624.768] 02186.02200> psb_freq_mask: 0x3f [07624.768] 02186.02200> num addr ranges: 2 [07624.768] 02186.02200> [sysmem_init 28] async_get_default_dispatcher(): 0x4aa6988c68d0 [07624.768] 02186.02200> [sysmem_bind 40] sysmem_bind() [07624.768] 02186.02878> acpi-pwrbtn: initialized [07624.771] 01706.01738> vc: new input device /dev/class/input/000 [07624.778] 02186.02878> WARNING: ACPI found bad _CRS address entry [07624.787] 02186.02878> WARNING: ACPI found bad _CRS address entry [07624.799] 02186.02878> acpi: published device pci(0x4aa5d88c9f70), parent=sys(0x4aa7188cf110), handle=0x4aa5988da250 [07624.800] 01114.01129> devcoordinator: launch devhost 'devhost:pci#1:8086:5916': pid=2974 [07624.800] 01114.01129> devcoordinator: launch devhost 'devhost:pci#3:8086:9d2f': pid=3023 [07624.801] 03023.03044> devhost: trace provider registry begun [07624.801] 02974.02988> devhost: trace provider registry begun [07624.802] 01114.01129> devcoordinator: launch devhost 'devhost:pci#5:8086:9d60': pid=3182 [07624.803] 01114.01129> devcoordinator: launch devhost 'devhost:pci#6:8086:9d61': pid=3227 [07624.803] 02186.02878> acpi: published device rtc(0x4aa5d88cd4b0), parent=acpi(0x4aa7188cf610), handle=0x4aa598900450 [07624.803] 03182.03196> devhost: trace provider registry begun [07624.804] 02186.02878> acpi-ec: initialized [07624.805] 01114.01129> devcoordinator: launch devhost 'devhost:pci#9:8086:9d03': pid=3381 [07624.805] 03227.03253> devhost: trace provider registry begun [07624.805] 01114.01129> devcoordinator: launch devhost 'devhost:pci#14:8086:9d71': pid=3515 [07624.806] 01114.01129> devcoordinator: launch devhost 'devhost:pci#16:8086:156f': pid=3574 [07624.806] 03515.03529> devhost: trace provider registry begun [07624.807] 03227.03253> initialized intel serialio i2c driver, reg=0x4dbfe6664000 regsize=4096 [07624.807] 03182.03196> initialized intel serialio i2c driver, reg=0x1bcf8005b000 regsize=4096 [07624.807] 02186.02878> acpi: failed to create NHLT VMO (res -10) [07624.807] 02186.02878> acpi: failed to publish NHLT metadata [07624.808] 03574.03597> devhost: trace provider registry begun [07624.809] 03381.03395> devhost: trace provider registry begun [07624.814] 03381.03395> ahci: using MSI interrupt [07624.815] 03515.03529> [IHDA DSP 00:1f.3] Failed to fetch NHLT (res -25) [07624.815] 03515.03529> [IHDA Controller 00:1f.3] Failed to initialize DSP device (res = -25) [07624.817] 03023.04018> * found USB device (0x18d1:0xa002, USB 2.0) config 1 [07624.817] 03023.04018> * found USB device (0x18d1:0xa003, USB 3.0) config 1 [07624.888] 01618.01641> netifc: ? /dev/class/ethernet/000 [07624.888] 01618.01641> netifc: create 512 eth buffers [07624.888] 01618.01641> macaddr: d4:5d:df:1a:34:01 [07624.888] 01618.01641> ip6addr: fe80::d65d:df4d:fe1a:3401 [07624.888] 01618.01641> snmaddr: ff02::1:ff1a:3401 [07624.888] 01618.01641> netsvc: using /dev/class/ethernet/000 [07624.888] 01618.01641> netsvc: nodename='wake-dug-sky-amend' [07624.888] 01618.01641> netsvc: start [07624.915] 01706.01738> vc: new display device /dev/class/display-controller/000 [07624.956] 02974.04242> i915: MST not supported [07625.456] 02974.04242> i915: Found DP monitor [07625.456] 02974.04242> i915: Display 1 connected [07626.014] 01706.01738> vc: Successfully attached to display 1 [07626.279] 03023.04018> * found USB device (0x0781:0x5571, USB 2.0) config 1 [07626.530] 03023.04018> * found USB device (0x8087:0x0a2b, USB 2.0) config 1 [07626.815] 03227.03253> intel-i2c-controller: intel_serialio_i2c_slave_transfer: -21 [07626.815] 03227.03253> i2c-hid: could not read HID descriptor: 0 [07626.815] 03227.03253> devhost[00:15.1/i2c-bus-9d61/004c] bind driver '/boot/driver/i2c-hid.so' failed: -2 [07626.815] 01114.01129> devcoordinator: rpc: bind-driver '004c' status -2 [07626.815] 03182.03196> intel-i2c-controller: intel_serialio_i2c_slave_transfer: -21 [07626.815] 03182.03196> i2c-hid: could not read HID descriptor: 0 [07626.815] 03182.03196> devhost[00:15.0/i2c-bus-9d60/0020] bind driver '/boot/driver/i2c-hid.so' failed: -2 [07626.815] 01114.01129> devcoordinator: rpc: bind-driver '0020' status -2 [07626.829] 03381.03939> sata2: dev info [07626.829] 03381.03939> serial=711430951080 3 [07626.829] 03381.03939> firmware rev=1Q01A7 0 [07626.829] 03381.03939> model id=IBIW NSS D [07626.829] 03381.03939> major=0x3f0 ACS2 DMA 32 commands [07626.829] 03381.03939> LBA48 234441648 sectors, sector size=512 [07626.830] 01298.01312> fshost: /dev/class/block/000: GPT? [07626.830] 03381.03395> gpt: device_get_metadata failed (-25) [07626.831] 01298.01312> fshost: /dev/class/block/001: FVM? [07626.834] 01298.01312> devcoordinator: launch /boot/bin/blobfs (blobfs:/blob) OK [07626.984] 01298.01312> fshost: starting 'bin/pkgsvr' '6c8300983b3fb6562dff65ced50e15b3990a2c96d130e8ec964ddc711ec4f0c9'... [07626.992] 01298.01312> devcoordinator: launch bin/pkgsvr (pkgfs) OK [07627.004] 04653.04867> pkgsvr: system: will be served from 6c8300983b3fb6562dff65ced50e15b3990a2c96d130e8ec964ddc711ec4f0c9 [07627.004] 04653.04867> pkgsvr: pkgfs serving index /data/pkgfs_index from blobfs /blob [07627.007] 01298.01312> fshost: /dev/class/block/005: zxcrypt? [07627.007] 03381.03395> devhost_get_handles(0x5855a4036c10:block) open path='zxcrypt', r=-2 [07627.010] 01114.01751> devcoordinator: launch /system/bin/appmgr (appmgr) OK DEBUG: stopping or rebooting the node "wake-dug-sky-amend" ERROR: cannot connect to address "[fe80::d65d:dfff:fe1a:3401%eno2]:22": dial tcp6 [fe80::d65d:dfff:fe1a:3401%eno2]:22: i/o timeout @@@