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]
[0.000] 00000.00000> zbi: @ 0xffffff8000e97000 (14234760 bytes)
[0.000] 00000.00000> UART: FIFO depth 16
[0.000] 00000.00000> PMM: boot reserve add [0x100000, 0x2fffff]
[0.000] 00000.00000> PMM: boot reserve add [0xe97000, 0x1c2afff]
[0.000] 00000.00000> PMM: boot reserve marking WIRED [0x100000, 0x2fffff]
[0.000] 00000.00000> PMM: boot reserve marking WIRED [0xe97000, 0x1c2afff]
[0.000] 00000.00000> welcome to Zircon
[0.000] 00000.00000> KASLR: .text section at 0xffffffff00100000
[0.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00114ec4 (global_prng_seed) at level 0x30000, flags 0x1
[0.000] 00000.00000> initializing vm pre-heap
[0.000] 00000.00000> VM: marking boot alloc used range [0x1c2b000, 0x1c2b080)
[0.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00122274 (elf_build_id) at level 0x4fffe, flags 0x1
[0.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00122400 (version) at level 0x4ffff, flags 0x1
[0.000] 00000.00000> version:
[0.000] 00000.00000> arch: x86
[0.000] 00000.00000> platform: XXX
[0.000] 00000.00000> target: XXX
[0.000] 00000.00000> project: x64
[0.000] 00000.00000> buildid: git-77bb9431c1bc18aaa78895879af3afea1700c9f8-dirty
[0.000] 00000.00000> ELF build ID: e79b6138c7f60ab9cbd644819af856d216e3d01e
[0.000] 00000.00000> initializing heap
[0.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00101fc4 (console) at level 0x50000, flags 0x1
[0.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001826c4 (x86_resource_init) at level 0x50000, flags 0x1
[0.000] 00000.00000> initializing vm
[0.000] 00000.00000> VM: reserving kernel region [0xffffffff00100000, 0xffffffff0021b000) flags 0x28 name 'kernel_code'
[0.000] 00000.00000> VM: reserving kernel region [0xffffffff0021b000, 0xffffffff0026c000) flags 0x8 name 'kernel_rodata'
[0.000] 00000.00000> VM: reserving kernel region [0xffffffff0026c000, 0xffffffff00274000) flags 0x18 name 'kernel_data'
[0.000] 00000.00000> VM: reserving kernel region [0xffffffff00274000, 0xffffffff00300000) flags 0x18 name 'kernel_bss'
[0.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00183388 (display_memtype) at level 0x60001, flags 0x1
[0.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00186818 (acpi_tables) at level 0x60001, flags 0x1
[0.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001814c8 (hpet) at level 0x60002, flags 0x1
[0.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00181888 (apic) at level 0x60002, flags 0x1
[0.000] 00000.00000> x2APIC enabled
[0.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001a7e6c (system_topology_init) at level 0x60002, flags 0x1
[0.000] 00000.00000> WARNING: unable to find any cache levels.
[0.000] 00000.00000> WARNING: unable to find any cache levels.
[0.000] 00000.00000> Could not find SRAT table. ACPICA returned: 5
[0.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00185e08 (timer) at level 0x60003, flags 0x1
[0.000] 00000.00000> pvclock: Clocksource is stable
[0.000] 00000.00000> HPET frequency: 100000 ticks/ms
[0.000] 00000.00000> pvclock: Fetching TSC frequency
[0.000] 00000.00000> TSC frequency: 2300000 ticks/ms
[0.654] 00000.00000> timer features: constant_tsc 1 invariant_tsc 1 tsc_deadline 1
[0.654] 00000.00000> Using TSC as wallclock
[0.654] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00208930 (percpu_heap_init) at level 0x60003, flags 0x1
[0.654] 00000.00000> initializing kernel
[0.654] 00000.00000> initializing mp
[0.654] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00115118 (global_prng_thread_safe) at level 0x7ffff, flags 0x1
[0.654] 00000.00000> creating bootstrap completion thread
[0.654] 00000.00000> top of bootstrap2()
[0.654] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00131734 (libobject) at level 0x80000, flags 0x1
[0.654] 00000.00000> OOM: started thread
[0.654] 00000.00000> INIT: cpu 0, calling hook 0xffffffff0020589c (dpc) at level 0x80000, flags 0x1
[0.654] 00000.00000> Processor Model Info: type 0 family 0x6 model 0xf stepping 0
[0.654] 00000.00000> display_family 0x6 display_model 0x3f
[0.654] 00000.00000> Vendor: Intel
[0.654] 00000.00000> Microarch: Haswell
[0.654] 00000.00000> F/M/S: 6/3f/0
[0.654] 00000.00000> patch_level: 0
[0.654] 00000.00000> Brand: Intel(R) Xeon(R) CPU @ 2.30GHz
[0.654] 00000.00000> Features: fpu sse sse2 sse3 ssse3 sse4.1 sse4.2 mmx avx avx2 fxsr pcid xsave aesni clflush
[0.654] 00000.00000> fsgsbase tsc_adj smep erms rdrand syscall nx rdtscp tsc_deadline x2apic hypervisor
[0.654] 00000.00000> Properties: meltdown l1tf pcid_good
[0.654] 00000.00000> initializing platform
[0.654] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001a157c (x86_perfmon) at level 0x90000, flags 0x1
[0.654] 00000.00000> x86_perfmon_init_once:454: perfmon: unexpected programmable counter width 0 in cpuid.0AH
[0.655] 00000.00000> UART: started IRQ driven RX
[0.655] 00000.00000> UART: started IRQ driven TX
[0.655] 00000.00000> cpu topology:
[0.655] 00000.00000> 0: apic id 0x0 BSP
[0.655] 00000.00000> 1: apic id 0x1
[0.655] 00000.00000> 2: apic id 0x2
[0.655] 00000.00000> 3: apic id 0x3
[0.655] 00000.00000> Found 4 cpus
[0.656] 00000.00000> booting apic ids: 0x1 0x2 0x3
[0.668] 00000.00000> entering scheduler on cpu 2
[0.668] 00000.00000> entering scheduler on cpu 3
[0.668] 00000.00000> entering scheduler on cpu 1
[0.669] 00000.00000> smbios: manufacturer="QEMU" product="Standard PC (Q35 + ICH9, 2009)"
[0.669] 00000.00000> initializing target
[0.669] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001850b8 (x86_pcie_init) at level 0xa0000, flags 0x1
[0.669] 00000.00000> moving to last init level
[0.669] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001214cc (debuglog) at level 0xb0000, flags 0x1
[0.669] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00174d40 (kcounters) at level 0xb0000, flags 0x1
[0.669] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00102aec (kernel_shell) at level 0xc0000, flags 0x1
[0.670] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00202ad4 (ktrace) at level 0xc0000, flags 0x1
[1.049] 00000.00000> ktrace: buffer at 0xffffff92ec988000 (33554432 bytes)
[1.049] 00000.00000> INIT: cpu 0, calling hook 0xffffffff002184f8 (userboot) at level 0xc0000, flags 0x1
[1.049] 00000.00000> userboot: ramdisk 0xd94000 @ 0xffffff8000e97000
[1.064] 00000.00000> userboot: userboot rodata 0 @ [0x7b3123840000,0x7b3123843000)
[1.064] 00000.00000> userboot: userboot code 0x3000 @ [0x7b3123843000,0x7b312384e000)
[1.064] 00000.00000> userboot: vdso/full rodata 0 @ [0x7b312384e000,0x7b3123855000)
[1.064] 00000.00000> userboot: vdso/full code 0x7000 @ [0x7b3123855000,0x7b3123856000)
[1.064] 00000.00000> userboot: entry point @ 0x7b3123843c90
[1.088] 01034.01041> userboot: option "/b/s/w/ir/multiboot-created_by_recipe.bin="
[1.088] 01034.01041> userboot: option "zircon.autorun.system=/boot/bin/sh+/boot/infra/runcmds"
[1.088] 01034.01041> userboot: option "kernel.halt-on-panic=true"
[1.088] 01034.01041> userboot: option "devmgr.suspend-timeout-debug=true"
[1.088] 01034.01041> userboot: option "TERM=dumb"
[1.088] 01034.01041> userboot: option "kernel.serial=legacy"
[1.088] 01034.01041> userboot: option "multiboot.boot_loader_name=qemu"
[1.172] 01034.01041> userboot: searching bootfs for 'bin/bootsvc'
[1.172] 01034.01041> userboot: 'bin/bootsvc' has PT_INTERP "lib/ld.so.1"
[1.172] 01034.01041> userboot: searching bootfs for 'lib/ld.so.1'
[1.172] 01034.01041> userboot: userboot: loaded lib/ld.so.1 at 0x54c633916000, entry point 0x54c6339343d0
[1.172] 01034.01041> userboot: userboot: loaded vDSO at 0x74bd99eb1000, entry point 0x74bd99eb88fa
[1.172] 01034.01041> userboot: process bin/bootsvc started.
[1.172] 01034.01041> userboot: waiting for loader-service requests...
[1.173] 01034.01041> userboot: searching bootfs for 'lib/libasync-default.so'
[1.173] 01034.01041> userboot: searching bootfs for 'lib/libfdio.so'
[1.173] 01034.01041> userboot: searching bootfs for 'lib/libtrace-engine.so'
[1.174] 01034.01041> userboot: searching bootfs for 'lib/liblaunchpad.so'
[1.174] 01048.01051> dso: id=04b4a34a2691363e32b2d7bb7f817640b16ec624 base=0x00005af98f404000 name=<application>
[1.174] 01048.01051> dso: id=ea0dfec464c2dc7856e31bb691e2ffe7bae2bda5 base=0x000074bd99eb1000 name=<vDSO>
[1.174] 01048.01051> dso: id=8c511b4202cf569c8fdde14ca97222102ba3a9e0 base=0x00000b4c9250a000 name=libasync-default.so
[1.174] 01048.01051> dso: id=57a73a8b04ea66e0b20945ca56238e6bc8a0b0bc base=0x0000312bec229000 name=libfdio.so
[1.174] 01048.01051> dso: id=95bc229c3cf2ab8a51f12c33a311105ff8976120 base=0x00006c0b3f66f000 name=libtrace-engine.so
[1.174] 01048.01051> dso: id=5b0854856213eae6bab93c982f39551f8f9591c5 base=0x00007038fe993000 name=liblaunchpad.so
[1.174] 01048.01051> dso: id=5d417db61b3a48a58a8fa1ffbfc2e71b830e0857 base=0x000054c633916000 name=libc.so
[1.175] 01048.01051> bootsvc: Starting...
[1.175] 01048.01051> bootsvc: Creating bootfs service...
[1.175] 01034.01041> userboot: loader-service channel peer closed
[1.175] 01034.01041> userboot: finished!
[1.176] 01048.01051> bootsvc: Retrieving boot image...
[1.176] 01048.01051> bootsvc: Decommitted BOOTDATA VMO from 0 to 0xd93000
[1.176] 01048.01051> bootsvc: Loading boot arguments...
[1.176] 01048.01051> bootsvc: Creating svcfs service...
[1.176] 01048.01051> bootsvc: Loading kernel VMOs...
[1.176] 01048.01051> bootsvc: Creating loader service...
[1.176] 01048.01051> bootsvc: Launching next process...
[1.178] 01048.01106> bootsvc: Launched bin/devcoordinator
[1.181] 01113.01128> devcoordinator: launch /boot/bin/svchost (svchost) OK
[1.185] 01113.01128> devcoordinator: launch /boot/bin/fshost (fshost) OK
[1.226] 01113.01128> devcoordinator: full system required, ignoring fallback drivers until /system is loaded
[1.404] 01113.01324> devcoordinator: launch /boot/bin/pwrbtn-monitor (pwrbtn-monitor) OK
[1.409] 01113.01338> devcoordinator: launch /boot/bin/netsvc (netsvc) OK
[1.418] 01113.01128> devcoordinator: launch devhost 'devhost:sys': pid=2063
[1.424] 01113.01128> devcoordinator: launch devhost 'devhost:test': pid=2173
[1.425] 01113.01338> devcoordinator: launch /boot/bin/virtual-console (virtual-console) OK
[1.439] 01113.01128> devcoordinator: launch devhost 'devhost:root': pid=2242
[1.450] 01113.01128> devcoordinator: launch devhost 'devhost:misc': pid=2302
[1.460] 02063.02115> devhost: trace provider registry begun
[1.483] 02173.02192> devhost: trace provider registry begun
[1.492] 02242.02274> devhost: trace provider registry begun
[1.496] 02302.02333> devhost: trace provider registry begun
[1.504] 02063.02115> acpi-bus: not using IOMMU
[1.505] 01113.01330> devcoordinator: launch /boot/bin/sh (sh:console) OK
[1.512] 02063.02115> GetHwProperties: No PM support
$
[1.512] 02063.02115> IntelPT: No PT support
[1.512] 02063.02115> devhost[sys/cpu-trace] bind driver '/boot/driver/cpu-trace.so' failed: -2
[1.513] 01113.01128> devcoordinator: rpc: bind-driver 'cpu-trace' status -2
[1.514] 02063.02115> [sysmem_init 28] async_get_default_dispatcher(): 0x21e0039b0990
[1.514] 02063.02115> [sysmem_bind 40] sysmem_bind()
[1.515] 02063.02779> acpi-pwrbtn: initialized
[1.516] 02196.02232> vc: new input device /dev/class/input/000
[1.628] 02063.02779> acpi: published device pci(0x21df439b71f0), parent=sys(0x21e0839ada10), handle=0x21df039b20d0
[1.628] 02063.02779> acpi: failed to get PCI base bus number for device 'PCI0' (status 4294967295)
[1.642] 02063.02779> acpi: published device rtc(0x21df439a6090), parent=acpi(0x21e0839ad210), handle=0x21df039b2450
[1.649] 02063.02779> acpi: published device i8042(0x21df439ad290), parent=acpi(0x21e0839ad210), handle=0x21df039b26d0
[1.660] 01113.01128> devcoordinator: launch devhost 'devhost:pci#1:1234:1111': pid=2902
[1.667] 02902.02916> devhost: trace provider registry begun
[1.668] 01113.01128> devcoordinator: launch devhost 'devhost:pci#2:1af4:1001': pid=2969
[1.681] 01113.01128> devcoordinator: launch devhost 'devhost:pci#3:1af4:1000': pid=3063
[1.683] 02969.03013> devhost: trace provider registry begun
[1.687] 01113.01128> devcoordinator: launch devhost 'devhost:pci#4:1af4:1001': pid=3148
[1.695] 03063.03092> devhost: trace provider registry begun
[1.695] 01113.01128> devcoordinator: launch devhost 'devhost:pci#6:8086:2922': pid=3234
[1.707] 03148.03171> devhost: trace provider registry begun
[1.708] 02063.02115> devhost: WARNING: driver '/boot/driver/pc-ps2.so' did not add device in bind()
[1.719] 02063.03366> i8042 device 0xab 0x41
[1.725] 02196.02232> vc: new input device /dev/class/input/001
[1.738] 03234.03280> devhost: trace provider registry begun
[1.748] 02902.02916> bochs_vbe: initialized display, 1024 x 768 (stride=1024 format=00020001)
[1.760] 02196.02232> vc: new display device /dev/class/display-controller/000
[1.761] 02902.02916> GetSysmemConnection failed (continuing) - status: -2
[1.762] 03234.03280> ahci: using MSI interrupt
[1.774] 02196.02232> vc: Successfully attached to display 1
[1.811] 02022.02042> netifc: ? /dev/class/ethernet/000
[1.818] 02022.02042> netifc: create 512 eth buffers
[1.823] 02022.02042> macaddr: 52:54:00:12:34:56
[1.824] 02022.02042> ip6addr: fe80::5054:4d:fe12:3456
[1.824] 02022.02042> snmaddr: ff02::1:ff12:3456
[1.824] 02022.02042> netsvc: using /dev/class/ethernet/000
[1.824] 02022.02042> netsvc: nodename='swarm-donut-petri-acre'
[1.824] 02022.02042> netsvc: start
[1.842] 01297.01311> fshost: /dev/class/block/001: FVM?
[1.855] 02063.03366> i8042 device 0x00
[1.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)
[1.871] 02196.02232> vc: new input device /dev/class/input/002
[1.878] 01297.01311> devcoordinator: launch /boot/bin/blobfs (blobfs:/blob) OK
[2.108] 01297.01311> fshost: starting 'bin/pkgsvr' '4759b99eccedd59d01b9b43d45f30de924b02bab89d4a14153d0ae3f45fdeac9'...
[2.122] 01297.01311> devcoordinator: launch bin/pkgsvr (pkgfs) OK
[2.155] 04048.04262> pkgsvr: system: will be served from 4759b99eccedd59d01b9b43d45f30de924b02bab89d4a14153d0ae3f45fdeac9
[2.156] 04048.04262> pkgsvr: pkgfs serving index /data/pkgfs_index from blobfs /blob
[2.172] 01297.01311> fshost: mounting minfs
[2.196] 01297.01311> devcoordinator: launch /boot/bin/minfs (minfs:/data) OK
[2.221] 01113.04314> devcoordinator: adding system driver 'wlan' '/system/driver/wlanphy.so'
[2.529] 01113.02238> devcoordinator: launch /system/bin/appmgr (appmgr) OK
[2.529] 01113.02238> autorun: starting '/boot/bin/sh' '/boot/infra/runcmds'...
[2.560] 01113.04314> devcoordinator: adding system driver 'mt8167s_gpu' '/system/driver/libmsd_img_rgx_mtk.so'
[2.581] 01113.04314> devcoordinator: adding system driver 'gpu' '/system/driver/libmsd_intel.so'
[2.588] 01113.02238> devcoordinator: launch /boot/bin/sh (autorun:system) OK
[2.612] 01113.04314> devcoordinator: adding system driver 'qmi_usb' '/system/driver/qmi-transport.so'
[2.657] 01113.04314> devcoordinator: adding system driver 'usb_video' '/system/driver/usb_video.so'
[2.671] 01113.04314> devcoordinator: adding system driver 'bt_hog' '/system/driver/bt-hog.so'
[2.761] 01113.04314> devcoordinator: adding system driver 'wlan' '/system/driver/wlan.so'
[2.807] 01113.04314> devcoordinator: adding system driver 'bt_hci_atheros' '/system/driver/bt-hci-atheros.so'
[2.829] 01113.04314> devcoordinator: adding system driver 'magma_pdev_gpu' '/system/driver/libmsd_arm.so'
[2.861] 01113.04314> devcoordinator: adding system driver 'wlan' '/system/driver/wlanif.so'
[2.977] 01113.04314> devcoordinator: adding system driver 'virtual_camera' '/system/driver/virtual_camera_driver.so'
[2.992] 01113.04314> devcoordinator: adding system driver 'qmi_fake' '/system/driver/qmi-fake.so'
[3.012] 01113.04314> devcoordinator: adding system driver 'rtl88xx' '/system/driver/rtl88xx.so'
[3.071] 01113.04314> devcoordinator: adding system driver 'brcmfmac' '/system/driver/brcmfmac.so'
[3.169] 04508.04525> [INFO:namespace_builder.cc(93)] config-data for sysmgr
[3.389] 01113.04314> devcoordinator: adding system driver 'bt_hci_intel' '/system/driver/bt-hci-intel.so'
[3.811] 01113.04314> devcoordinator: adding system driver 'bt_host' '/system/driver/bt-host.so'
[4.445] 01113.04314> devcoordinator: adding system driver 'ralink' '/system/driver/ralink.so'
[4.508] 01113.04314> devcoordinator: adding system driver 'bt_hci_fake' '/system/driver/bt-hci-fake.so'
[4.541] 01113.04314> devcoordinator: adding system driver 'bt_hci_passthrough' '/system/driver/bt-hci-passthrough.so'
[4.578] 01113.04314> devcoordinator: adding system driver 'ath10k_pci' '/system/driver/ath10k.so'
[4.652] 01113.04314> devcoordinator: adding system driver 'virtual_audio' '/system/driver/virtual_audio_driver.so'
[4.690] 01113.04314> devcoordinator: adding system driver 'iwlwifi_pci' '/system/driver/iwlwifi.so'
[4.713] 01113.01128> devcoordinator: driver 'iwlwifi_pci' added
[4.714] 01113.01128> devcoordinator: driver 'ath10k_pci' added
[4.714] 01113.01128> devcoordinator: driver 'bt_hci_fake' added
[4.714] 01113.01128> devcoordinator: driver 'ralink' added
[4.714] 01113.01128> devcoordinator: driver 'bt_host' added
[4.714] 01113.01128> devcoordinator: driver 'bt_hci_intel' added
[4.714] 01113.01128> devcoordinator: driver 'brcmfmac' added
[4.714] 01113.01128> devcoordinator: driver 'rtl88xx' added
[4.714] 01113.01128> devcoordinator: driver 'qmi_fake' added
[4.714] 01113.01128> devcoordinator: driver 'wlan' added
[4.714] 01113.01128> devcoordinator: driver 'magma_pdev_gpu' added
[4.714] 01113.01128> devcoordinator: driver 'bt_hci_atheros' added
[4.714] 01113.01128> devcoordinator: driver 'wlan' added
[4.714] 01113.01128> devcoordinator: driver 'bt_hog' added
[4.715] 01113.01128> devcoordinator: driver 'usb_video' added
[4.715] 01113.01128> devcoordinator: driver 'qmi_usb' added
[4.715] 01113.01128> devcoordinator: driver 'gpu' added
[4.715] 01113.01128> devcoordinator: driver 'mt8167s_gpu' added
[4.715] 01113.01128> devcoordinator: driver 'wlan' added
[4.715] 01113.01128> devcoordinator: driver 'bt_hci_passthrough' added
[4.715] 01113.01128> devcoordinator: fallback driver 'usb_composite' is available
[4.715] 01113.01128> devcoordinator: driver 'usb_composite' added
[4.715] 01113.01128> devcoordinator: fallback driver 'intel_disp' is available
[4.715] 01113.01128> devcoordinator: driver 'intel_disp' added
[5.371] 04508.04525> [INFO:namespace_builder.cc(93)] config-data for amber
[5.821] 04508.04525> [INFO:namespace_builder.cc(93)] config-data for pkg_resolver
[6.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
[6.518] 07343.07355> kfill_days=2, start_event_aggregator_worker=1.
[6.876] 04508.04525> [INFO:namespace_builder.cc(93)] config-data for wlancfg
[7.054] 04508.04525> [INFO:namespace_builder.cc(93)] config-data for mdns
[8.332] 04508.04525> [INFO:namespace_builder.cc(93)] config-data for crashpad_agent
[8.531] 10696.10719> [INFO:main.cc(35)] Trace Manager starting with config: /pkg/data/tracing.config
[8.577] 09154.09169> [INFO:system_metrics_main.cc(23)] Cobalt SystemMetricsDaemon: System metrics daemon created.
[8.814] 10367.10381> ------------------------------------------------
[8.814] 10367.10381> RUNNING TEST: /pkgfs/packages/ledger_tests/0/test/disabled/ledger_e2e_sync
[8.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
[9.543] 10367.10381> [INFO:sync_params.cc(189)] Sync credentials sha256: 33D155E63AAF5302E51675D96D087B8F0D8994B7C2FEDD443DABD77E043E9BAD
[9.548] 10367.10381> [==========] Running 6 tests from 3 test suites.
[9.548] 10367.10381> [----------] Global test environment set-up.
[9.548] 10367.10381> [----------] 2 tests from ManyLedgersConvergenceTest/ConvergenceTest
[9.548] 10367.10381> [ RUN ] ManyLedgersConvergenceTest/ConvergenceTest.NLedgersConverge/0
[9.819] 08179.08192> Starting mDNS on interface ethp0003 10.0.2.15
[9.826] 13018.13030> TraceProvider: registry failed: status=-24(ZX_ERR_PEER_CLOSED)
[9.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
[9.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
[9.846] 08179.08192> Starting mDNS on interface ethp0003 [80fe::5450:ff00:12fe:5634]
[9.865] 08179.08192> [WARNING:garnet/bin/mdns/service/mdns_interface_transceiver_v6.cc(29)] NET-291 IPV6_MULTICAST_LOOP not supported (ENOPROTOOPT), continuing anyway
[9.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
[9.875] 08179.08192> mDNS: Verifying uniqueness of host name swarm-donut-petri-acre.local.
[9.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
[9.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
[10.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
[10.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
[10.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
[10.643] 13161.13183> [INFO:page_manager.cc(151)] Initial sync in background finished. Clients will receive a change notification.
[10.733] 08179.08192> mDNS: Using unique host name swarm-donut-petri-acre.local.
[11.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.
[11.396] 10367.10381> [ OK ] ManyLedgersConvergenceTest/ConvergenceTest.NLedgersConverge/0 (1848 ms)
[11.396] 10367.10381> [ RUN ] ManyLedgersConvergenceTest/ConvergenceTest.NLedgersConverge/1
[11.411] 10367.10381> TraceProvider: registry failed: status=-24(ZX_ERR_PEER_CLOSED)
[11.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
[11.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
[11.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
[11.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
[12.525] 15521.15533> [INFO:page_manager.cc(151)] Initial sync in background finished. Clients will receive a change notification.
[42.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.
[42.968] 10367.10381> [ OK ] ManyLedgersConvergenceTest/ConvergenceTest.NLedgersConverge/1 (31571 ms)
[42.968] 10367.10381> [----------] 2 tests from ManyLedgersConvergenceTest/ConvergenceTest (33420 ms total)
[42.968] 10367.10381> [----------] 1 test from LongHistorySyncTest/LongHistorySyncTest
[42.968] 10367.10381> [ RUN ] LongHistorySyncTest/LongHistorySyncTest.SyncLongHistory/0
[42.997] 10367.10381> TraceProvider: registry failed: status=-24(ZX_ERR_PEER_CLOSED)
[43.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
[43.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
[43.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
[44.259] 20644.20658> [INFO:page_manager.cc(151)] Initial sync in background finished. Clients will receive a change notification.
[47.394] 03063.11061> dropping packet; out of descriptors
[47.394] 03063.11061> dropping packet; out of descriptors
[47.394] 03063.11061> dropping packet; out of descriptors
[47.399] 03063.11061> dropping packet; out of descriptors
[48.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
[48.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
[48.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
[48.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.
[48.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.
[48.808] 10367.10381> [ OK ] LongHistorySyncTest/LongHistorySyncTest.SyncLongHistory/0 (5825 ms)
[48.808] 10367.10381> [----------] 1 test from LongHistorySyncTest/LongHistorySyncTest (5825 ms total)
[48.808] 10367.10381> [----------] 3 tests from SyncIntegrationTest/SyncIntegrationTest
[48.808] 10367.10381> [ RUN ] SyncIntegrationTest/SyncIntegrationTest.SerialConnection/0
[48.808] 10367.10381> TraceProvider: registry failed: status=-24(ZX_ERR_PEER_CLOSED)
[49.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
[49.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
[49.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
[49.995] 39914.39926> [INFO:page_manager.cc(151)] Initial sync in background finished. Clients will receive a change notification.
[50.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
[50.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.
[50.832] 10367.10381> [ OK ] SyncIntegrationTest/SyncIntegrationTest.SerialConnection/0 (2039 ms)
[50.832] 10367.10381> [ RUN ] SyncIntegrationTest/SyncIntegrationTest.ConcurrentConnection/0
[50.845] 10367.10381> TraceProvider: registry failed: status=-24(ZX_ERR_PEER_CLOSED)
[51.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
[51.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
[51.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
[51.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
[51.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
[51.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
[51.979] 42339.42355> [INFO:page_manager.cc(151)] Initial sync in background finished. Clients will receive a change notification.
[52.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.
[52.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.
[52.474] 10367.10381> [ OK ] SyncIntegrationTest/SyncIntegrationTest.ConcurrentConnection/0 (1640 ms)
[52.474] 10367.10381> [ RUN ] SyncIntegrationTest/SyncIntegrationTest.LazyToEagerTransition/0
[52.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
[52.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
[52.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
[52.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
[53.574] 44686.44699> [INFO:page_manager.cc(151)] Initial sync in background finished. Clients will receive a change notification.
[54.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.
[54.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.
[54.216] 10367.10381> [ OK ] SyncIntegrationTest/SyncIntegrationTest.LazyToEagerTransition/0 (1743 ms)
[54.216] 10367.10381> [----------] 3 tests from SyncIntegrationTest/SyncIntegrationTest (5423 ms total)
[54.216] 10367.10381> [----------] Global test environment tear-down
[54.216] 10367.10381> [==========] 6 tests from 3 test suites ran. (44668 ms total)
[54.216] 10367.10381> [ PASSED ] 6 tests.
[54.468] 10367.10381> PASSED: /pkgfs/packages/ledger_tests/0/test/disabled/ledger_e2e_sync passed
[54.488] 10367.10381> SUMMARY: Ran 1 tests: 0 failed (45.812 sec)
[54.520] 10166.10180> minfs: Unmounted