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

2019/04/20 03:19:26 Setting up secrets server at localhost:8081 2019/04/20 03:19:39 QEMU invocation: [/b/s/w/ir/qemu/bin/qemu-system-x86_64 -machine q35 -device isa-debug-exit,iobase=0xf4,iosize=0x04 -cpu host -enable-kvm -m 4096 -smp 4 -nographic -serial stdio -monitor none -kernel /b/s/w/ir/multiboot-created_by_recipe.bin -initrd /b/s/w/ir/test-infra.zbi -drive id=maindisk,file=/b/s/w/ir/obj/build/images/fvm.blk,format=raw,if=none -device virtio-blk-pci,drive=maindisk -drive id=testdisk,file=/b/s/w/ir/output.fs,format=raw,if=none -device virtio-blk-pci,drive=testdisk,addr=06.0 -netdev user,id=net0 -device virtio-net-pci,netdev=net0 -append zircon.autorun.system=/boot/bin/sh+/boot/infra/runcmds kernel.halt-on-panic=true devmgr.suspend-timeout-debug=true TERM=dumb kernel.serial=legacy] [00000.000] 00000:00000> zbi: @ 0xffffff8000e97000 (14234760 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 [0xe97000, 0x1c2afff] [00000.000] 00000:00000> PMM: boot reserve marking WIRED [0x100000, 0x2fffff] [00000.000] 00000:00000> PMM: boot reserve marking WIRED [0xe97000, 0x1c2afff] [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 [0x1c2b000, 0x1c2b080) [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-77bb9431c1bc18aaa78895879af3afea1700c9f8-dirty [00000.000] 00000:00000> ELF build ID: e79b6138c7f60ab9cbd644819af856d216e3d01e [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: unable to find any cache levels. [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> pvclock: Clocksource is stable [00000.000] 00000:00000> HPET frequency: 100000 ticks/ms [00000.000] 00000:00000> pvclock: Fetching TSC frequency [00000.000] 00000:00000> TSC frequency: 2300000 ticks/ms [00000.654] 00000:00000> timer features: constant_tsc 1 invariant_tsc 1 tsc_deadline 1 [00000.654] 00000:00000> Using TSC as wallclock [00000.654] 00000:00000> INIT: cpu 0, calling hook 0xffffffff00208930 (percpu_heap_init) at level 0x60003, flags 0x1 [00000.654] 00000:00000> initializing kernel [00000.654] 00000:00000> initializing mp [00000.654] 00000:00000> INIT: cpu 0, calling hook 0xffffffff00115118 (global_prng_thread_safe) at level 0x7ffff, flags 0x1 [00000.654] 00000:00000> creating bootstrap completion thread [00000.654] 00000:00000> top of bootstrap2() [00000.654] 00000:00000> INIT: cpu 0, calling hook 0xffffffff00131734 (libobject) at level 0x80000, flags 0x1 [00000.654] 00000:00000> OOM: started thread [00000.654] 00000:00000> INIT: cpu 0, calling hook 0xffffffff0020589c (dpc) at level 0x80000, flags 0x1 [00000.654] 00000:00000> Processor Model Info: type 0 family 0x6 model 0xf stepping 0 [00000.654] 00000:00000> display_family 0x6 display_model 0x3f [00000.654] 00000:00000> Vendor: Intel [00000.654] 00000:00000> Microarch: Haswell [00000.654] 00000:00000> F/M/S: 6/3f/0 [00000.654] 00000:00000> patch_level: 0 [00000.654] 00000:00000> Brand: Intel(R) Xeon(R) CPU @ 2.30GHz [00000.654] 00000:00000> Features: fpu sse sse2 sse3 ssse3 sse4.1 sse4.2 mmx avx avx2 fxsr pcid xsave aesni clflush [00000.654] 00000:00000> fsgsbase tsc_adj smep erms rdrand syscall nx rdtscp tsc_deadline x2apic hypervisor [00000.654] 00000:00000> Properties: meltdown l1tf pcid_good [00000.654] 00000:00000> initializing platform [00000.654] 00000:00000> INIT: cpu 0, calling hook 0xffffffff001a157c (x86_perfmon) at level 0x90000, flags 0x1 [00000.654] 00000:00000> x86_perfmon_init_once:454: perfmon: unexpected programmable counter width 0 in cpuid.0AH [00000.655] 00000:00000> UART: started IRQ driven RX [00000.655] 00000:00000> UART: started IRQ driven TX [00000.655] 00000:00000> cpu topology: [00000.655] 00000:00000> 0: apic id 0x0 BSP [00000.655] 00000:00000> 1: apic id 0x1 [00000.655] 00000:00000> 2: apic id 0x2 [00000.655] 00000:00000> 3: apic id 0x3 [00000.655] 00000:00000> Found 4 cpus [00000.656] 00000:00000> booting apic ids: 0x1 0x2 0x3 [00000.668] 00000:00000> entering scheduler on cpu 2 [00000.668] 00000:00000> entering scheduler on cpu 3 [00000.668] 00000:00000> entering scheduler on cpu 1 [00000.669] 00000:00000> smbios: manufacturer="QEMU" product="Standard PC (Q35 + ICH9, 2009)" [00000.669] 00000:00000> initializing target [00000.669] 00000:00000> INIT: cpu 0, calling hook 0xffffffff001850b8 (x86_pcie_init) at level 0xa0000, flags 0x1 [00000.669] 00000:00000> moving to last init level [00000.669] 00000:00000> INIT: cpu 0, calling hook 0xffffffff001214cc (debuglog) at level 0xb0000, flags 0x1 [00000.669] 00000:00000> INIT: cpu 0, calling hook 0xffffffff00174d40 (kcounters) at level 0xb0000, flags 0x1 [00000.669] 00000:00000> INIT: cpu 0, calling hook 0xffffffff00102aec (kernel_shell) at level 0xc0000, flags 0x1 [00000.670] 00000:00000> INIT: cpu 0, calling hook 0xffffffff00202ad4 (ktrace) at level 0xc0000, flags 0x1 [00001.049] 00000:00000> ktrace: buffer at 0xffffff92ec988000 (33554432 bytes) [00001.049] 00000:00000> INIT: cpu 0, calling hook 0xffffffff002184f8 (userboot) at level 0xc0000, flags 0x1 [00001.049] 00000:00000> userboot: ramdisk 0xd94000 @ 0xffffff8000e97000 [00001.064] 00000:00000> userboot: userboot rodata 0 @ [0x7b3123840000,0x7b3123843000) [00001.064] 00000:00000> userboot: userboot code 0x3000 @ [0x7b3123843000,0x7b312384e000) [00001.064] 00000:00000> userboot: vdso/full rodata 0 @ [0x7b312384e000,0x7b3123855000) [00001.064] 00000:00000> userboot: vdso/full code 0x7000 @ [0x7b3123855000,0x7b3123856000) [00001.064] 00000:00000> userboot: entry point @ 0x7b3123843c90 [00001.088] 01034:01041> userboot: option "/b/s/w/ir/multiboot-created_by_recipe.bin=" [00001.088] 01034:01041> userboot: option "zircon.autorun.system=/boot/bin/sh+/boot/infra/runcmds" [00001.088] 01034:01041> userboot: option "kernel.halt-on-panic=true" [00001.088] 01034:01041> userboot: option "devmgr.suspend-timeout-debug=true" [00001.088] 01034:01041> userboot: option "TERM=dumb" [00001.088] 01034:01041> userboot: option "kernel.serial=legacy" [00001.088] 01034:01041> userboot: option "multiboot.boot_loader_name=qemu" [00001.172] 01034:01041> userboot: searching bootfs for 'bin/bootsvc' [00001.172] 01034:01041> userboot: 'bin/bootsvc' has PT_INTERP "lib/ld.so.1" [00001.172] 01034:01041> userboot: searching bootfs for 'lib/ld.so.1' [00001.172] 01034:01041> userboot: userboot: loaded lib/ld.so.1 at 0x54c633916000, entry point 0x54c6339343d0 [00001.172] 01034:01041> userboot: userboot: loaded vDSO at 0x74bd99eb1000, entry point 0x74bd99eb88fa [00001.172] 01034:01041> userboot: process bin/bootsvc started. [00001.172] 01034:01041> userboot: waiting for loader-service requests... [00001.173] 01034:01041> userboot: searching bootfs for 'lib/libasync-default.so' [00001.173] 01034:01041> userboot: searching bootfs for 'lib/libfdio.so' [00001.173] 01034:01041> userboot: searching bootfs for 'lib/libtrace-engine.so' [00001.174] 01034:01041> userboot: searching bootfs for 'lib/liblaunchpad.so' [00001.174] 01048:01051> {{{reset}}} [00001.174] 01048:01051> {{{module:0:<application>:elf:04b4a34a2691363e32b2d7bb7f817640b16ec624}}} [00001.174] 01048:01051> {{{mmap:0x5af98f404000:0x3a000:load:0:rx:0}}} [00001.174] 01048:01051> {{{mmap:0x5af98f43e000:0x4000:load:0:rw:0x3a000}}} [00001.174] 01048:01051> dso: id=04b4a34a2691363e32b2d7bb7f817640b16ec624 base=0x00005af98f404000 name=<application> [00001.174] 01048:01051> {{{module:0x2:<vDSO>:elf:ea0dfec464c2dc7856e31bb691e2ffe7bae2bda5}}} [00001.174] 01048:01051> {{{mmap:0x74bd99eb1000:0x7000:load:0x2:r:0}}} [00001.174] 01048:01051> {{{mmap:0x74bd99eb8000:0x1000:load:0x2:rx:0x7000}}} [00001.174] 01048:01051> dso: id=ea0dfec464c2dc7856e31bb691e2ffe7bae2bda5 base=0x000074bd99eb1000 name=<vDSO> [00001.174] 01048:01051> {{{module:0x3:libasync-default.so:elf:8c511b4202cf569c8fdde14ca97222102ba3a9e0}}} [00001.174] 01048:01051> {{{mmap:0xb4c9250a000:0x1000:load:0x3:rx:0}}} [00001.174] 01048:01051> {{{mmap:0xb4c9250b000:0x1000:load:0x3:rw:0x1000}}} [00001.174] 01048:01051> dso: id=8c511b4202cf569c8fdde14ca97222102ba3a9e0 base=0x00000b4c9250a000 name=libasync-default.so [00001.174] 01048:01051> {{{module:0x4:libfdio.so:elf:57a73a8b04ea66e0b20945ca56238e6bc8a0b0bc}}} [00001.174] 01048:01051> {{{mmap:0x312bec229000:0x32000:load:0x4:rx:0}}} [00001.174] 01048:01051> {{{mmap:0x312bec25c000:0x4000:load:0x4:rw:0x33000}}} [00001.174] 01048:01051> dso: id=57a73a8b04ea66e0b20945ca56238e6bc8a0b0bc base=0x0000312bec229000 name=libfdio.so [00001.174] 01048:01051> {{{module:0x5:libtrace-engine.so:elf:95bc229c3cf2ab8a51f12c33a311105ff8976120}}} [00001.174] 01048:01051> {{{mmap:0x6c0b3f66f000:0x9000:load:0x5:rx:0}}} [00001.174] 01048:01051> {{{mmap:0x6c0b3f678000:0x2000:load:0x5:rw:0x9000}}} [00001.174] 01048:01051> dso: id=95bc229c3cf2ab8a51f12c33a311105ff8976120 base=0x00006c0b3f66f000 name=libtrace-engine.so [00001.174] 01048:01051> {{{module:0x6:liblaunchpad.so:elf:5b0854856213eae6bab93c982f39551f8f9591c5}}} [00001.174] 01048:01051> {{{mmap:0x7038fe993000:0x7000:load:0x6:rx:0}}} [00001.174] 01048:01051> {{{mmap:0x7038fe99a000:0x2000:load:0x6:rw:0x7000}}} [00001.174] 01048:01051> dso: id=5b0854856213eae6bab93c982f39551f8f9591c5 base=0x00007038fe993000 name=liblaunchpad.so [00001.174] 01048:01051> {{{module:0x1:libc.so:elf:5d417db61b3a48a58a8fa1ffbfc2e71b830e0857}}} [00001.174] 01048:01051> {{{mmap:0x54c633916000:0xa6000:load:0x1:rx:0}}} [00001.174] 01048:01051> {{{mmap:0x54c6339bc000:0x5000:load:0x1:rw:0xa6000}}} [00001.174] 01048:01051> dso: id=5d417db61b3a48a58a8fa1ffbfc2e71b830e0857 base=0x000054c633916000 name=libc.so [00001.175] 01048:01051> bootsvc: Starting... [00001.175] 01048:01051> bootsvc: Creating bootfs service... [00001.175] 01034:01041> userboot: loader-service channel peer closed [00001.175] 01034:01041> userboot: finished! [00001.176] 01048:01051> bootsvc: Retrieving boot image... [00001.176] 01048:01051> bootsvc: Decommitted BOOTDATA VMO from 0 to 0xd93000 [00001.176] 01048:01051> bootsvc: Loading boot arguments... [00001.176] 01048:01051> bootsvc: Creating svcfs service... [00001.176] 01048:01051> bootsvc: Loading kernel VMOs... [00001.176] 01048:01051> bootsvc: Creating loader service... [00001.176] 01048:01051> bootsvc: Launching next process... [00001.178] 01048:01106> bootsvc: Launched bin/devcoordinator [00001.181] 01113:01128> devcoordinator: launch /boot/bin/svchost (svchost) OK [00001.185] 01113:01128> devcoordinator: launch /boot/bin/fshost (fshost) OK [00001.226] 01113:01128> devcoordinator: full system required, ignoring fallback drivers until /system is loaded [00001.404] 01113:01324> devcoordinator: launch /boot/bin/pwrbtn-monitor (pwrbtn-monitor) OK [00001.409] 01113:01338> devcoordinator: launch /boot/bin/netsvc (netsvc) OK [00001.418] 01113:01128> devcoordinator: launch devhost 'devhost:sys': pid=2063 [00001.424] 01113:01128> devcoordinator: launch devhost 'devhost:test': pid=2173 [00001.425] 01113:01338> devcoordinator: launch /boot/bin/virtual-console (virtual-console) OK [00001.439] 01113:01128> devcoordinator: launch devhost 'devhost:root': pid=2242 [00001.450] 01113:01128> devcoordinator: launch devhost 'devhost:misc': pid=2302 [00001.460] 02063:02115> devhost: trace provider registry begun [00001.483] 02173:02192> devhost: trace provider registry begun [00001.492] 02242:02274> devhost: trace provider registry begun [00001.496] 02302:02333> devhost: trace provider registry begun [00001.504] 02063:02115> acpi-bus: not using IOMMU [00001.505] 01113:01330> devcoordinator: launch /boot/bin/sh (sh:console) OK [00001.512] 02063:02115> GetHwProperties: No PM support $ [00001.512] 02063:02115> IntelPT: No PT support [00001.512] 02063:02115> devhost[sys/cpu-trace] bind driver '/boot/driver/cpu-trace.so' failed: -2 [00001.513] 01113:01128> devcoordinator: rpc: bind-driver 'cpu-trace' status -2 [00001.514] 02063:02115> [sysmem_init 28] async_get_default_dispatcher(): 0x21e0039b0990 [00001.514] 02063:02115> [sysmem_bind 40] sysmem_bind() [00001.515] 02063:02779> acpi-pwrbtn: initialized [00001.516] 02196:02232> vc: new input device /dev/class/input/000 [00001.628] 02063:02779> acpi: published device pci(0x21df439b71f0), parent=sys(0x21e0839ada10), handle=0x21df039b20d0 [00001.628] 02063:02779> acpi: failed to get PCI base bus number for device 'PCI0' (status 4294967295) [00001.642] 02063:02779> acpi: published device rtc(0x21df439a6090), parent=acpi(0x21e0839ad210), handle=0x21df039b2450 [00001.649] 02063:02779> acpi: published device i8042(0x21df439ad290), parent=acpi(0x21e0839ad210), handle=0x21df039b26d0 [00001.660] 01113:01128> devcoordinator: launch devhost 'devhost:pci#1:1234:1111': pid=2902 [00001.667] 02902:02916> devhost: trace provider registry begun [00001.668] 01113:01128> devcoordinator: launch devhost 'devhost:pci#2:1af4:1001': pid=2969 [00001.681] 01113:01128> devcoordinator: launch devhost 'devhost:pci#3:1af4:1000': pid=3063 [00001.683] 02969:03013> devhost: trace provider registry begun [00001.687] 01113:01128> devcoordinator: launch devhost 'devhost:pci#4:1af4:1001': pid=3148 [00001.695] 03063:03092> devhost: trace provider registry begun [00001.695] 01113:01128> devcoordinator: launch devhost 'devhost:pci#6:8086:2922': pid=3234 [00001.707] 03148:03171> devhost: trace provider registry begun [00001.708] 02063:02115> devhost: WARNING: driver '/boot/driver/pc-ps2.so' did not add device in bind() [00001.719] 02063:03366> i8042 device 0xab 0x41 [00001.725] 02196:02232> vc: new input device /dev/class/input/001 [00001.738] 03234:03280> devhost: trace provider registry begun [00001.748] 02902:02916> bochs_vbe: initialized display, 1024 x 768 (stride=1024 format=00020001) [00001.760] 02196:02232> vc: new display device /dev/class/display-controller/000 [00001.761] 02902:02916> GetSysmemConnection failed (continuing) - status: -2 [00001.762] 03234:03280> ahci: using MSI interrupt [00001.774] 02196:02232> vc: Successfully attached to display 1 [00001.811] 02022:02042> netifc: ? /dev/class/ethernet/000 [00001.818] 02022:02042> netifc: create 512 eth buffers [00001.823] 02022:02042> macaddr: 52:54:00:12:34:56 [00001.824] 02022:02042> ip6addr: fe80::5054:4d:fe12:3456 [00001.824] 02022:02042> snmaddr: ff02::1:ff12:3456 [00001.824] 02022:02042> netsvc: using /dev/class/ethernet/000 [00001.824] 02022:02042> netsvc: nodename='swarm-donut-petri-acre' [00001.824] 02022:02042> netsvc: start [00001.842] 01297:01311> fshost: /dev/class/block/001: FVM? [00001.855] 02063:03366> i8042 device 0x00 [00001.859] 02063:02115> hid: boot mouse hack for "hid-device-002": report count (0->1), inp sz (24->24), out sz (0->0), feat sz (0->0) [00001.871] 02196:02232> vc: new input device /dev/class/input/002 [00001.878] 01297:01311> devcoordinator: launch /boot/bin/blobfs (blobfs:/blob) OK [00002.108] 01297:01311> fshost: starting 'bin/pkgsvr' '4759b99eccedd59d01b9b43d45f30de924b02bab89d4a14153d0ae3f45fdeac9'... [00002.122] 01297:01311> devcoordinator: launch bin/pkgsvr (pkgfs) OK [00002.155] 04048:04262> pkgsvr: system: will be served from 4759b99eccedd59d01b9b43d45f30de924b02bab89d4a14153d0ae3f45fdeac9 [00002.156] 04048:04262> pkgsvr: pkgfs serving index /data/pkgfs_index from blobfs /blob [00002.172] 01297:01311> fshost: mounting minfs [00002.196] 01297:01311> devcoordinator: launch /boot/bin/minfs (minfs:/data) OK [00002.221] 01113:04314> devcoordinator: adding system driver 'wlan' '/system/driver/wlanphy.so' [00002.529] 01113:02238> devcoordinator: launch /system/bin/appmgr (appmgr) OK [00002.529] 01113:02238> autorun: starting '/boot/bin/sh' '/boot/infra/runcmds'... [00002.560] 01113:04314> devcoordinator: adding system driver 'mt8167s_gpu' '/system/driver/libmsd_img_rgx_mtk.so' [00002.581] 01113:04314> devcoordinator: adding system driver 'gpu' '/system/driver/libmsd_intel.so' [00002.588] 01113:02238> devcoordinator: launch /boot/bin/sh (autorun:system) OK [00002.612] 01113:04314> devcoordinator: adding system driver 'qmi_usb' '/system/driver/qmi-transport.so' [00002.657] 01113:04314> devcoordinator: adding system driver 'usb_video' '/system/driver/usb_video.so' [00002.671] 01113:04314> devcoordinator: adding system driver 'bt_hog' '/system/driver/bt-hog.so' [00002.761] 01113:04314> devcoordinator: adding system driver 'wlan' '/system/driver/wlan.so' [00002.807] 01113:04314> devcoordinator: adding system driver 'bt_hci_atheros' '/system/driver/bt-hci-atheros.so' [00002.829] 01113:04314> devcoordinator: adding system driver 'magma_pdev_gpu' '/system/driver/libmsd_arm.so' [00002.861] 01113:04314> devcoordinator: adding system driver 'wlan' '/system/driver/wlanif.so' [00002.977] 01113:04314> devcoordinator: adding system driver 'virtual_camera' '/system/driver/virtual_camera_driver.so' [00002.992] 01113:04314> devcoordinator: adding system driver 'qmi_fake' '/system/driver/qmi-fake.so' [00003.012] 01113:04314> devcoordinator: adding system driver 'rtl88xx' '/system/driver/rtl88xx.so' [00003.071] 01113:04314> devcoordinator: adding system driver 'brcmfmac' '/system/driver/brcmfmac.so' [00003.169] 04508:04525> [INFO:namespace_builder.cc(93)] config-data for sysmgr [00003.389] 01113:04314> devcoordinator: adding system driver 'bt_hci_intel' '/system/driver/bt-hci-intel.so' [00003.811] 01113:04314> devcoordinator: adding system driver 'bt_host' '/system/driver/bt-host.so' [00004.445] 01113:04314> devcoordinator: adding system driver 'ralink' '/system/driver/ralink.so' [00004.508] 01113:04314> devcoordinator: adding system driver 'bt_hci_fake' '/system/driver/bt-hci-fake.so' [00004.541] 01113:04314> devcoordinator: adding system driver 'bt_hci_passthrough' '/system/driver/bt-hci-passthrough.so' [00004.578] 01113:04314> devcoordinator: adding system driver 'ath10k_pci' '/system/driver/ath10k.so' [00004.652] 01113:04314> devcoordinator: adding system driver 'virtual_audio' '/system/driver/virtual_audio_driver.so' [00004.690] 01113:04314> devcoordinator: adding system driver 'iwlwifi_pci' '/system/driver/iwlwifi.so' [00004.713] 01113:01128> devcoordinator: driver 'iwlwifi_pci' added [00004.714] 01113:01128> devcoordinator: driver 'ath10k_pci' added [00004.714] 01113:01128> devcoordinator: driver 'bt_hci_fake' added [00004.714] 01113:01128> devcoordinator: driver 'ralink' added [00004.714] 01113:01128> devcoordinator: driver 'bt_host' added [00004.714] 01113:01128> devcoordinator: driver 'bt_hci_intel' added [00004.714] 01113:01128> devcoordinator: driver 'brcmfmac' added [00004.714] 01113:01128> devcoordinator: driver 'rtl88xx' added [00004.714] 01113:01128> devcoordinator: driver 'qmi_fake' added [00004.714] 01113:01128> devcoordinator: driver 'wlan' added [00004.714] 01113:01128> devcoordinator: driver 'magma_pdev_gpu' added [00004.714] 01113:01128> devcoordinator: driver 'bt_hci_atheros' added [00004.714] 01113:01128> devcoordinator: driver 'wlan' added [00004.714] 01113:01128> devcoordinator: driver 'bt_hog' added [00004.715] 01113:01128> devcoordinator: driver 'usb_video' added [00004.715] 01113:01128> devcoordinator: driver 'qmi_usb' added [00004.715] 01113:01128> devcoordinator: driver 'gpu' added [00004.715] 01113:01128> devcoordinator: driver 'mt8167s_gpu' added [00004.715] 01113:01128> devcoordinator: driver 'wlan' added [00004.715] 01113:01128> devcoordinator: driver 'bt_hci_passthrough' added [00004.715] 01113:01128> devcoordinator: fallback driver 'usb_composite' is available [00004.715] 01113:01128> devcoordinator: driver 'usb_composite' added [00004.715] 01113:01128> devcoordinator: fallback driver 'intel_disp' is available [00004.715] 01113:01128> devcoordinator: driver 'intel_disp' added [00005.371] 04508:04525> [INFO:namespace_builder.cc(93)] config-data for amber [00005.821] 04508:04525> [INFO:namespace_builder.cc(93)] config-data for pkg_resolver [00006.518] 07343:07355> [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 [00006.518] 07343:07355> kfill_days=2, start_event_aggregator_worker=1. [00006.876] 04508:04525> [INFO:namespace_builder.cc(93)] config-data for wlancfg [00007.054] 04508:04525> [INFO:namespace_builder.cc(93)] config-data for mdns [00008.332] 04508:04525> [INFO:namespace_builder.cc(93)] config-data for crashpad_agent [00008.531] 10696:10719> [INFO:main.cc(35)] Trace Manager starting with config: /pkg/data/tracing.config [00008.577] 09154:09169> [INFO:system_metrics_main.cc(23)] Cobalt SystemMetricsDaemon: System metrics daemon created. [00008.814] 10367:10381> [00008.814] 10367:10381> ------------------------------------------------ [00008.814] 10367:10381> RUNNING TEST: /pkgfs/packages/ledger_tests/0/test/disabled/ledger_e2e_sync [00008.814] 10367:10381> [00008.996] 11405:11417> wlanstack2 [I]: Starting 2019/04/20 03:20:03 Serving secret for "ledger_e2e_sync_credentials" 2019/04/20 03:20:03 SHA256 of secret: 33d155e63aaf5302e51675d96d087b8f0d8994b7c2fedd443dabd77e043e9bad [00009.543] 10367:10381> [INFO:sync_params.cc(189)] Sync credentials sha256: 33D155E63AAF5302E51675D96D087B8F0D8994B7C2FEDD443DABD77E043E9BAD [00009.548] 10367:10381> [==========] Running 6 tests from 3 test suites. [00009.548] 10367:10381> [----------] Global test environment set-up. [00009.548] 10367:10381> [----------] 2 tests from ManyLedgersConvergenceTest/ConvergenceTest [00009.548] 10367:10381> [ RUN ] ManyLedgersConvergenceTest/ConvergenceTest.NLedgersConverge/0 [00009.819] 08179:08192> Starting mDNS on interface ethp0003 10.0.2.15 [00009.826] 13018:13030> TraceProvider: registry failed: status=-24(ZX_ERR_PEER_CLOSED) [00009.832] 13018:13030> [ERROR:src/lib/cobalt/cpp/cobalt_logger.cc(22)] Could not find config file at /pkg/data/firebase_auth_cobalt_config.pb [00009.844] 08179:08192> [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 [00009.846] 08179:08192> Starting mDNS on interface ethp0003 [80fe::5450:ff00:12fe:5634] [00009.865] 08179:08192> [WARNING:garnet/bin/mdns/service/mdns_interface_transceiver_v6.cc(29)] NET-291 IPV6_MULTICAST_LOOP not supported (ENOPROTOOPT), continuing anyway [00009.866] 08179:08192> [WARNING:garnet/bin/mdns/service/mdns_interface_transceiver_v6.cc(50)] NET-2180 IPV6_JOIN_GROUP returned ENODEV, mDNS will not communicate via IPV6 [00009.875] 08179:08192> mDNS: Verifying uniqueness of host name swarm-donut-petri-acre.local. [00009.899] 13161:13183> fidl channel writing error at ../../sdk/lib/fidl/cpp/internal/proxy_controller.cc:59: zx_status_t -24, type fuchsia.netconnector/NetConnectorRegisterServiceProviderRequest, 88 bytes, 0 handles [00009.899] 13161:13183> fidl channel writing error at ../../sdk/lib/fidl/cpp/internal/proxy_controller.cc:59: zx_status_t -24, type fuchsia.netconnector/NetConnectorGetKnownDeviceNamesRequest, 24 bytes, 0 handles [00010.047] 13790:13806> [ERROR:src/lib/cobalt/cpp/cobalt_logger.cc(22)] Could not find config file at /pkg/data/firebase_auth_cobalt_config.pb [00010.096] 13953:13983> fidl channel writing error at ../../sdk/lib/fidl/cpp/internal/proxy_controller.cc:59: zx_status_t -24, type fuchsia.netconnector/NetConnectorRegisterServiceProviderRequest, 88 bytes, 0 handles [00010.096] 13953:13983> fidl channel writing error at ../../sdk/lib/fidl/cpp/internal/proxy_controller.cc:59: zx_status_t -24, type fuchsia.netconnector/NetConnectorGetKnownDeviceNamesRequest, 24 bytes, 0 handles [00010.643] 13161:13183> [INFO:page_manager.cc(151)] Initial sync in background finished. Clients will receive a change notification. [00010.733] 08179:08192> mDNS: Using unique host name swarm-donut-petri-acre.local. [00011.357] 13018:13030> [ERROR:src/ledger/cloud_provider_firestore/bin/app/cloud_provider_impl.cc(79)] Lost connection to the token provider, shutting down the cloud provider. [00011.396] 10367:10381> [ OK ] ManyLedgersConvergenceTest/ConvergenceTest.NLedgersConverge/0 (1848 ms) [00011.396] 10367:10381> [ RUN ] ManyLedgersConvergenceTest/ConvergenceTest.NLedgersConverge/1 [00011.411] 10367:10381> TraceProvider: registry failed: status=-24(ZX_ERR_PEER_CLOSED) [00011.689] 15356:15368> [ERROR:src/lib/cobalt/cpp/cobalt_logger.cc(22)] Could not find config file at /pkg/data/firebase_auth_cobalt_config.pb [00011.906] 16106:16118> [ERROR:src/lib/cobalt/cpp/cobalt_logger.cc(22)] Could not find config file at /pkg/data/firebase_auth_cobalt_config.pb [00011.969] 15356:15368> [ERROR:src/lib/cobalt/cpp/cobalt_logger.cc(22)] Could not find config file at /pkg/data/firebase_auth_cobalt_config.pb [00011.973] 16106:16118> [ERROR:src/lib/cobalt/cpp/cobalt_logger.cc(22)] Could not find config file at /pkg/data/firebase_auth_cobalt_config.pb [00012.525] 15521:15533> [INFO:page_manager.cc(151)] Initial sync in background finished. Clients will receive a change notification. [00042.924] 15356:15368> [ERROR:src/ledger/cloud_provider_firestore/bin/app/cloud_provider_impl.cc(79)] Lost connection to the token provider, shutting down the cloud provider. [00042.968] 10367:10381> [ OK ] ManyLedgersConvergenceTest/ConvergenceTest.NLedgersConverge/1 (31571 ms) [00042.968] 10367:10381> [----------] 2 tests from ManyLedgersConvergenceTest/ConvergenceTest (33420 ms total) [00042.968] 10367:10381> [00042.968] 10367:10381> [----------] 1 test from LongHistorySyncTest/LongHistorySyncTest [00042.968] 10367:10381> [ RUN ] LongHistorySyncTest/LongHistorySyncTest.SyncLongHistory/0 [00042.997] 10367:10381> TraceProvider: registry failed: status=-24(ZX_ERR_PEER_CLOSED) [00043.300] 20440:20453> [ERROR:src/lib/cobalt/cpp/cobalt_logger.cc(22)] Could not find config file at /pkg/data/firebase_auth_cobalt_config.pb [00043.392] 20644:20658> fidl channel writing error at ../../sdk/lib/fidl/cpp/internal/proxy_controller.cc:59: zx_status_t -24, type fuchsia.netconnector/NetConnectorRegisterServiceProviderRequest, 88 bytes, 0 handles [00043.392] 20644:20658> fidl channel writing error at ../../sdk/lib/fidl/cpp/internal/proxy_controller.cc:59: zx_status_t -24, type fuchsia.netconnector/NetConnectorGetKnownDeviceNamesRequest, 24 bytes, 0 handles [00044.259] 20644:20658> [INFO:page_manager.cc(151)] Initial sync in background finished. Clients will receive a change notification. [00047.394] 03063:11061> dropping packet; out of descriptors [00047.394] 03063:11061> dropping packet; out of descriptors [00047.394] 03063:11061> dropping packet; out of descriptors [00047.399] 03063:11061> dropping packet; out of descriptors [00048.074] 38438:38450> [ERROR:src/lib/cobalt/cpp/cobalt_logger.cc(22)] Could not find config file at /pkg/data/firebase_auth_cobalt_config.pb [00048.118] 38566:38578> fidl channel writing error at ../../sdk/lib/fidl/cpp/internal/proxy_controller.cc:59: zx_status_t -24, type fuchsia.netconnector/NetConnectorRegisterServiceProviderRequest, 88 bytes, 0 handles [00048.118] 38566:38578> fidl channel writing error at ../../sdk/lib/fidl/cpp/internal/proxy_controller.cc:59: zx_status_t -24, type fuchsia.netconnector/NetConnectorGetKnownDeviceNamesRequest, 24 bytes, 0 handles [00048.702] 38438:38450> [ERROR:src/ledger/cloud_provider_firestore/bin/app/cloud_provider_impl.cc(79)] Lost connection to the token provider, shutting down the cloud provider. [00048.748] 20440:20453> [ERROR:src/ledger/cloud_provider_firestore/bin/app/cloud_provider_impl.cc(79)] Lost connection to the token provider, shutting down the cloud provider. [00048.808] 10367:10381> [ OK ] LongHistorySyncTest/LongHistorySyncTest.SyncLongHistory/0 (5825 ms) [00048.808] 10367:10381> [----------] 1 test from LongHistorySyncTest/LongHistorySyncTest (5825 ms total) [00048.808] 10367:10381> [00048.808] 10367:10381> [----------] 3 tests from SyncIntegrationTest/SyncIntegrationTest [00048.808] 10367:10381> [ RUN ] SyncIntegrationTest/SyncIntegrationTest.SerialConnection/0 [00048.808] 10367:10381> TraceProvider: registry failed: status=-24(ZX_ERR_PEER_CLOSED) [00049.188] 39737:39749> [ERROR:src/lib/cobalt/cpp/cobalt_logger.cc(22)] Could not find config file at /pkg/data/firebase_auth_cobalt_config.pb [00049.257] 39914:39926> fidl channel writing error at ../../sdk/lib/fidl/cpp/internal/proxy_controller.cc:59: zx_status_t -24, type fuchsia.netconnector/NetConnectorRegisterServiceProviderRequest, 88 bytes, 0 handles [00049.257] 39914:39926> fidl channel writing error at ../../sdk/lib/fidl/cpp/internal/proxy_controller.cc:59: zx_status_t -24, type fuchsia.netconnector/NetConnectorGetKnownDeviceNamesRequest, 24 bytes, 0 handles [00049.995] 39914:39926> [INFO:page_manager.cc(151)] Initial sync in background finished. Clients will receive a change notification. [00050.193] 40880:40892> [ERROR:src/lib/cobalt/cpp/cobalt_logger.cc(22)] Could not find config file at /pkg/data/firebase_auth_cobalt_config.pb [00050.791] 39737:39749> [ERROR:src/ledger/cloud_provider_firestore/bin/app/cloud_provider_impl.cc(79)] Lost connection to the token provider, shutting down the cloud provider. [00050.832] 10367:10381> [ OK ] SyncIntegrationTest/SyncIntegrationTest.SerialConnection/0 (2039 ms) [00050.832] 10367:10381> [ RUN ] SyncIntegrationTest/SyncIntegrationTest.ConcurrentConnection/0 [00050.845] 10367:10381> TraceProvider: registry failed: status=-24(ZX_ERR_PEER_CLOSED) [00051.207] 42155:42174> [ERROR:src/lib/cobalt/cpp/cobalt_logger.cc(22)] Could not find config file at /pkg/data/firebase_auth_cobalt_config.pb [00051.289] 42339:42355> fidl channel writing error at ../../sdk/lib/fidl/cpp/internal/proxy_controller.cc:59: zx_status_t -24, type fuchsia.netconnector/NetConnectorRegisterServiceProviderRequest, 88 bytes, 0 handles [00051.289] 42339:42355> fidl channel writing error at ../../sdk/lib/fidl/cpp/internal/proxy_controller.cc:59: zx_status_t -24, type fuchsia.netconnector/NetConnectorGetKnownDeviceNamesRequest, 24 bytes, 0 handles [00051.329] 42570:42592> [ERROR:src/lib/cobalt/cpp/cobalt_logger.cc(22)] Could not find config file at /pkg/data/firebase_auth_cobalt_config.pb [00051.364] 42774:42795> fidl channel writing error at ../../sdk/lib/fidl/cpp/internal/proxy_controller.cc:59: zx_status_t -24, type fuchsia.netconnector/NetConnectorRegisterServiceProviderRequest, 88 bytes, 0 handles [00051.364] 42774:42795> fidl channel writing error at ../../sdk/lib/fidl/cpp/internal/proxy_controller.cc:59: zx_status_t -24, type fuchsia.netconnector/NetConnectorGetKnownDeviceNamesRequest, 24 bytes, 0 handles [00051.979] 42339:42355> [INFO:page_manager.cc(151)] Initial sync in background finished. Clients will receive a change notification. [00052.370] 42570:42592> [ERROR:src/ledger/cloud_provider_firestore/bin/app/cloud_provider_impl.cc(79)] Lost connection to the token provider, shutting down the cloud provider. [00052.412] 42155:42174> [ERROR:src/ledger/cloud_provider_firestore/bin/app/cloud_provider_impl.cc(79)] Lost connection to the token provider, shutting down the cloud provider. [00052.474] 10367:10381> [ OK ] SyncIntegrationTest/SyncIntegrationTest.ConcurrentConnection/0 (1640 ms) [00052.474] 10367:10381> [ RUN ] SyncIntegrationTest/SyncIntegrationTest.LazyToEagerTransition/0 [00052.659] 44466:44482> [ERROR:src/lib/cobalt/cpp/cobalt_logger.cc(22)] Could not find config file at /pkg/data/firebase_auth_cobalt_config.pb [00052.864] 44686:44699> fidl channel writing error at ../../sdk/lib/fidl/cpp/internal/proxy_controller.cc:59: zx_status_t -24, type fuchsia.netconnector/NetConnectorRegisterServiceProviderRequest, 88 bytes, 0 handles [00052.864] 44686:44699> fidl channel writing error at ../../sdk/lib/fidl/cpp/internal/proxy_controller.cc:59: zx_status_t -24, type fuchsia.netconnector/NetConnectorGetKnownDeviceNamesRequest, 24 bytes, 0 handles [00052.903] 44867:44884> [ERROR:src/lib/cobalt/cpp/cobalt_logger.cc(22)] Could not find config file at /pkg/data/firebase_auth_cobalt_config.pb [00053.574] 44686:44699> [INFO:page_manager.cc(151)] Initial sync in background finished. Clients will receive a change notification. [00054.122] 44867:44884> [ERROR:src/ledger/cloud_provider_firestore/bin/app/cloud_provider_impl.cc(79)] Lost connection to the token provider, shutting down the cloud provider. [00054.173] 44466:44482> [ERROR:src/ledger/cloud_provider_firestore/bin/app/cloud_provider_impl.cc(79)] Lost connection to the token provider, shutting down the cloud provider. [00054.216] 10367:10381> [ OK ] SyncIntegrationTest/SyncIntegrationTest.LazyToEagerTransition/0 (1743 ms) [00054.216] 10367:10381> [----------] 3 tests from SyncIntegrationTest/SyncIntegrationTest (5423 ms total) [00054.216] 10367:10381> [00054.216] 10367:10381> [----------] Global test environment tear-down [00054.216] 10367:10381> [==========] 6 tests from 3 test suites ran. (44668 ms total) [00054.216] 10367:10381> [ PASSED ] 6 tests. [00054.468] 10367:10381> PASSED: /pkgfs/packages/ledger_tests/0/test/disabled/ledger_e2e_sync passed [00054.488] 10367:10381> [00054.488] 10367:10381> SUMMARY: Ran 1 tests: 0 failed (45.812 sec) [00054.520] 10166:10180> minfs: Unmounted