2019/05/22 10:38:00 attempting to send <<image>>sparse.fvm...
[00000.000] 00000.00000> zbi: @ 0xffffff80012f2000 (17482848 bytes)
[00000.000] 00000.00000> UART: FIFO depth 16
[00000.000] 00000.00000> PMM: boot reserve add [0x100000, 0x2c5fff]
[00000.000] 00000.00000> PMM: boot reserve add [0x12f2000, 0x239efff]
[00000.000] 00000.00000> PMM: arena too small to be useful (size 4096)
[00000.000] 00000.00000> PMM: pmm_add_arena failed to initialize arena
[00000.000] 00000.00000> MEM: Failed to add pmm range at 0x7ffff000 size 0x1000
[00000.000] 00000.00000> PMM: boot reserve marking WIRED [0x100000, 0x2c5fff]
[00000.000] 00000.00000> PMM: boot reserve marking WIRED [0x12f2000, 0x239efff]
[00000.000] 00000.00000>
[00000.000] 00000.00000> welcome to Zircon
[00000.000] 00000.00000>
[00000.000] 00000.00000> KASLR: .text section at 0xffffffff00100000
[00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001aa428 (global_prng_seed) at level 0x30000, flags 0x1
[00000.000] 00000.00000> initializing vm pre-heap
[00000.000] 00000.00000> VM: marking boot alloc used range [0x239f000, 0x239f100)
[00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00147abc (elf_build_id) at level 0x4fffe, flags 0x1
[00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00147c48 (version) at level 0x4ffff, flags 0x1
[00000.000] 00000.00000> version:
[00000.000] 00000.00000> arch: x86
[00000.000] 00000.00000> platform: pc
[00000.000] 00000.00000> target: pc
[00000.000] 00000.00000> project: x64
[00000.000] 00000.00000> buildid: git-13ee3dc5e4c46bf127977ad28645c47442ec517d
[00000.000] 00000.00000> ELF build ID: 5f3e39bd4ed89d3b8122947842f1eac846a04683
[00000.000] 00000.00000> initializing heap
[00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00102e1c (x86_resource_init) at level 0x50000, flags 0x1
[00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001a9630 (console) at level 0x50000, flags 0x1
[00000.000] 00000.00000> initializing vm
[00000.000] 00000.00000> VM: reserving kernel region [0xffffffff00100000, 0xffffffff001ee000) flags 0x28 name 'kernel_code'
[00000.000] 00000.00000> VM: reserving kernel region [0xffffffff001ee000, 0xffffffff00232000) flags 0x8 name 'kernel_rodata'
[00000.000] 00000.00000> VM: reserving kernel region [0xffffffff00232000, 0xffffffff00242000) flags 0x18 name 'kernel_data'
[00000.000] 00000.00000> VM: reserving kernel region [0xffffffff00242000, 0xffffffff002c6000) flags 0x18 name 'kernel_bss'
[00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00103ae0 (display_memtype) at level 0x60001, flags 0x1
[00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00138fa0 (acpi_tables) at level 0x60001, flags 0x1
[00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00101c40 (hpet) at level 0x60002, flags 0x1
[00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00102000 (apic) at level 0x60002, flags 0x1
[00000.000] 00000.00000> x2APIC enabled
[00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001061b4 (timer) at level 0x60003, flags 0x1
[00000.000] 00000.00000> HPET frequency: 23999 ticks/ms
[00000.000] 00000.00000> TSC frequency: 2712000 ticks/ms
[00021.363] 00000.00000> timer features: constant_tsc 1 invariant_tsc 1 tsc_deadline 1
[00021.363] 00000.00000> Using TSC as wallclock
[00021.363] 00000.00000> initializing kernel
[00021.363] 00000.00000> initializing mp
[00021.363] 00000.00000> initializing timers
[00021.363] 00000.00000> INIT: cpu 0, calling hook 0xffffffff0013c578 (debuglog) at level 0x7ffff, flags 0x1
[00021.363] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00195518 (thread_set_priority_experiment) at level 0x7ffff, flags 0x1
[00021.363] 00000.00000> thread set priority experiment is : ENABLED
[00021.363] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001aa67c (global_prng_thread_safe) at level 0x7ffff, flags 0x1
[00021.363] 00000.00000> creating bootstrap completion thread
[00021.705] 00000.00000> top of bootstrap2()
[00021.705] 00000.00000> INIT: cpu 0, calling hook 0xffffffff0013151c (dpc) at level 0x80000, flags 0x1
[00021.719] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00152978 (libobject) at level 0x80000, flags 0x1
[00021.719] 00000.00000> OOM: started thread
[00021.732] 00000.00000> Processor Model Info: type 0 family 0x6 model 0xe stepping 0x9
[00021.732] 00000.00000> display_family 0x6 display_model 0x8e
[00021.732] 00000.00000> Vendor: Intel
[00021.732] 00000.00000> Microarch: Kaby Lake
[00021.732] 00000.00000> F/M/S: 6/8e/9
[00021.732] 00000.00000> Brand: Intel(R) Core(TM) i5-7300U CPU @ 2.60GHz
[00021.732] 00000.00000> Features: fpu sse sse2 sse3 ssse3 sse4.1 sse4.2 mmx avx avx2 fxsr pcid xsave mon aesni clflush
[00021.732] 00000.00000> clflushopt fsgsbase tsc_adj smep smap erms rdrand rdseed syscall nx huge rdtscp
[00021.732] 00000.00000> invar_tsc tsc_deadline x2apic vmx pt hwp
[00021.732] 00000.00000> initializing platform
[00021.732] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001101f4 (x86_perfmon) at level 0x90000, flags 0x1
[00021.732] 00000.00000> PMU: version 4
[00021.732] 00000.00000> UART: started IRQ driven RX
[00021.732] 00000.00000> UART: started IRQ driven TX
[00021.732] 00000.00000> cpu topology:
[00021.732] 00000.00000> 0: apic id 0x0 package 0 node 0 core 0 smt 0 BSP
[00021.732] 00000.00000> 1: apic id 0x2 package 0 node 0 core 1 smt 0
[00021.732] 00000.00000> 2: apic id 0x1 package 0 node 0 core 0 smt 1
[00021.732] 00000.00000> 3: apic id 0x3 package 0 node 0 core 1 smt 1
[00021.732] 00000.00000> Found 4 cpus
[00021.732] 00000.00000> booting apic ids: 0x2 0x1 0x3
[00021.748] 00000.00000> entering scheduler on cpu 2
[00021.749] 00000.00000> entering scheduler on cpu 1
[00021.749] 00000.00000> entering scheduler on cpu 3
[00021.752] 00000.00000> smbios: manufacturer="Intel Corporation" product="NUC7i5DNKE"
[00021.752] 00000.00000> initializing target
[00021.752] 00000.00000> INIT: cpu 1, calling hook 0xffffffff001053a0 (x86_pcie_init) at level 0xa0000, flags 0x1
[00021.752] 00000.00000> moving to last init level
[00021.752] 00000.00000> INIT: cpu 1, calling hook 0xffffffff00144140 (ktrace) at level 0xc0000, flags 0x1
[00021.755] 00000.00000> ktrace: buffer at 0xffffff920c929000 (33554432 bytes)
[00021.755] 00000.00000> INIT: cpu 1, calling hook 0xffffffff00147ab4 (userboot) at level 0xc0000, flags 0x1
[00021.755] 00000.00000> userboot: ramdisk 0x10ad000 @ 0xffffff80012f2000
[00021.756] 00000.00000> userboot: userboot rodata 0 @ [0x19b69fd9e000,0x19b69fda1000)
[00021.756] 00000.00000> userboot: userboot code 0x3000 @ [0x19b69fda1000,0x19b69fdac000)
[00021.756] 00000.00000> userboot: vdso/full rodata 0 @ [0x19b69fdac000,0x19b69fdb3000)
[00021.756] 00000.00000> userboot: vdso/full code 0x7000 @ [0x19b69fdb3000,0x19b69fdb4000)
[00021.756] 00000.00000> userboot: entry point @ 0x19b69fda1c10
[00021.756] 00000.00000> INIT: cpu 1, calling hook 0xffffffff001aa030 (kernel_shell) at level 0xc0000, flags 0x1
[00021.756] 01036.01043> userboot: option "netsvc.disable=true"
[00021.756] 01036.01043> userboot: option "zircon.system.disable-automount=true"
[00021.756] 01036.01043> userboot: option "zircon.autorun.boot=/boot/infra/setup"
[00021.756] 01036.01043> userboot: option "kernel.serial=legacy"
[00021.756] 01036.01043> userboot: option "
http://192.168.42.1/multiboot/d4%3A5d%3Adf%3A07%3Abe%3A7e="
[00021.756] 01036.01043> userboot: option "multiboot.boot_loader_name=iPXE+1.0.0++(d2063)"
[00021.795] 01036.01043> userboot: searching bootfs for 'bin/bootsvc'
[00021.795] 01036.01043> userboot: 'bin/bootsvc' has PT_INTERP "lib/ld.so.1"
[00021.795] 01036.01043> userboot: searching bootfs for 'lib/ld.so.1'
[00021.795] 01036.01043> userboot: userboot: loaded lib/ld.so.1 at 0x52caf5366000, entry point 0x52caf53ec0d3
[00021.795] 01036.01043> userboot: userboot: loaded vDSO at 0x5f96ea925000, entry point 0x0
[00021.795] 01036.01043> userboot: process bin/bootsvc started.
[00021.795] 01036.01043> userboot: waiting for loader-service requests...
[00021.795] 01036.01043> userboot: searching bootfs for 'lib/libasync-default.so'
[00021.795] 01036.01043> userboot: searching bootfs for 'lib/libfdio.so'
[00021.795] 01036.01043> userboot: searching bootfs for 'lib/liblaunchpad.so'
[00021.795] 01036.01043> userboot: searching bootfs for 'lib/libtrace-engine.so'
[00021.796] 01050.01053> {{{reset}}}
[00021.796] 01050.01053> {{{module:0:<application>:elf:18de7d58f51e8ba5c4f6afdd0cc8440f482c2b45}}}
[00021.796] 01050.01053> {{{mmap:0x3dab052cb000:0x2e000:load:0:rx:0}}}
[00021.796] 01050.01053> {{{mmap:0x3dab052f9000:0x4000:load:0:rw:0x2e000}}}
[00021.796] 01050.01053> dso: id=18de7d58f51e8ba5c4f6afdd0cc8440f482c2b45 base=0x00003dab052cb000 name=<application>
[00021.796] 01050.01053> {{{module:0x3:libasync-default.so:elf:c189f51f19d10785d93b5235ad1b46dca4451b00}}}
[00021.796] 01050.01053> {{{mmap:0x448073db9000:0x1000:load:0x3:rx:0}}}
[00021.796] 01050.01053> {{{mmap:0x448073dba000:0x1000:load:0x3:rw:0x1000}}}
[00021.796] 01050.01053> dso: id=c189f51f19d10785d93b5235ad1b46dca4451b00 base=0x0000448073db9000 name=libasync-default.so
[00021.796] 01050.01053> {{{module:0x2:<vDSO>:elf:40ab5fa3b61f12fef4a44477a687f608661cd450}}}
[00021.796] 01050.01053> {{{mmap:0x5f96ea925000:0x7000:load:0x2:r:0}}}
[00021.796] 01050.01053> {{{mmap:0x5f96ea92c000:0x1000:load:0x2:rx:0x7000}}}
[00021.796] 01050.01053> dso: id=40ab5fa3b61f12fef4a44477a687f608661cd450 base=0x00005f96ea925000 name=<vDSO>
[00021.796] 01050.01053> {{{module:0x1:libc.so:elf:67a12284bce140fc32aaaeac223e0e8f85cb5085}}}
[00021.796] 01050.01053> {{{mmap:0x52caf5366000:0xcb000:load:0x1:rx:0}}}
[00021.796] 01050.01053> {{{mmap:0x52caf5432000:0x6000:load:0x1:rw:0xcc000}}}
[00021.796] 01050.01053> dso: id=67a12284bce140fc32aaaeac223e0e8f85cb5085 base=0x000052caf5366000 name=libc.so
[00021.796] 01050.01053> {{{module:0x4:libfdio.so:elf:27787977e95f3b9563c9e0bd4d34ec92b7e9ad88}}}
[00021.796] 01050.01053> {{{mmap:0x55d12da8c000:0x24000:load:0x4:rx:0}}}
[00021.796] 01050.01053> {{{mmap:0x55d12dab1000:0x4000:load:0x4:rw:0x25000}}}
[00021.796] 01050.01053> dso: id=27787977e95f3b9563c9e0bd4d34ec92b7e9ad88 base=0x000055d12da8c000 name=libfdio.so
[00021.796] 01050.01053> {{{module:0x5:liblaunchpad.so:elf:6fc2232dc8c1bc5c6adb8ad50ca794b5a260ee4f}}}
[00021.796] 01050.01053> {{{mmap:0x8c910abd000:0x7000:load:0x5:rx:0}}}
[00021.796] 01050.01053> {{{mmap:0x8c910ac4000:0x2000:load:0x5:rw:0x7000}}}
[00021.796] 01050.01053> dso: id=6fc2232dc8c1bc5c6adb8ad50ca794b5a260ee4f base=0x000008c910abd000 name=liblaunchpad.so
[00021.796] 01050.01053> {{{module:0x6:libtrace-engine.so:elf:c9042b83fe01206008fcefb16395238417248169}}}
[00021.796] 01050.01053> {{{mmap:0x518f24ce9000:0x9000:load:0x6:rx:0}}}
[00021.796] 01050.01053> {{{mmap:0x518f24cf2000:0x2000:load:0x6:rw:0x9000}}}
[00021.796] 01050.01053> dso: id=c9042b83fe01206008fcefb16395238417248169 base=0x0000518f24ce9000 name=libtrace-engine.so
[00021.796] 01050.01053> bootsvc: Starting...
[00021.796] 01036.01043> userboot: loader-service channel peer closed
[00021.796] 01036.01043> userboot: finished!
[00021.796] 01050.01053> bootsvc: Creating bootfs service...
[00021.796] 01050.01053> bootsvc: Processing bootdata...
[00021.796] 01050.01053> bootsvc: Loading boot cmdline overrides...
[00021.796] 01050.01053> bootsvc: Loading kernel VMOs...
[00021.796] 01050.01053> bootsvc: Creating loader service...
[00021.796] 01050.01053> bootsvc: Launching next process...
[00021.797] 01050.01096> bootsvc: launched bin/devmgr
[00021.797] 01104.01117> devmgr: main()
[00021.797] 01104.01117> cmdline: netsvc.disable=true
[00021.797] 01104.01117> cmdline: zircon.system.disable-automount=true
[00021.797] 01104.01117> cmdline: zircon.autorun.boot=/boot/infra/setup
[00021.797] 01104.01117> cmdline: kernel.serial=legacy
[00021.797] 01104.01117> cmdline:
http://192.168.42.1/multiboot/d4%3A5d%3Adf%3A07%3Abe%3A7e=
[00021.797] 01104.01117> cmdline: multiboot.boot_loader_name=iPXE+1.0.0++(d2063)
[00021.797] 01104.01117> devmgr: coordinator_init()
[00021.797] 01104.01117> devmgr: init
[00021.797] 01104.01117> devmgr: svc init
[00021.797] 01104.01117> devmgr: launch /boot/bin/svchost (svchost) OK
[00021.797] 01104.01117> devmgr: vfs init
[00021.798] 01104.01117> devmgr: launch /boot/bin/fshost (fshost) OK
[00021.798] 01104.01222> devmgr: shell startup
[00021.799] 01182.01202> fshost: started.
[00021.800] 01104.01213> devmgr: launch /boot/bin/pwrbtn-monitor (pwrbtn-monitor) OK
[00021.800] 01104.01233> devmgr: launch /boot/bin/virtual-console (virtual-console) OK
[00021.800] 01104.01233> zircon.autorun.boot: starting '/boot/infra/setup'...
[00021.801] 01104.01233> devmgr: launch /boot/infra/setup (autorun:boot) OK
[00021.803] 01104.01117> devcoord: launch devhost 'devhost:sys': pid=2049
[00021.803] 01104.01117> devcoord: launch devhost 'devhost:test': pid=2082
[00021.803] 01104.01117> devcoord: launch devhost 'devhost:root': pid=2115
[00021.804] 01104.01117> devcoord: launch devhost 'devhost:misc': pid=2165
[00021.805] 02049.02073> devhost: trace provider registry begun
[00021.806] 02082.02106> devhost: trace provider registry begun
[00021.807] 02165.02200> devhost: trace provider registry begun
[00021.807] 02115.02151> devhost: trace provider registry begun
[00021.815] 01104.01222> devmgr: launch /boot/bin/sh (sh:console) OK
[00021.864] 02049.02073> acpi-bus: not using IOMMU
[00021.868] 02049.02073> acpi-pwrbtn: initialized
[00021.874] 02049.02073> WARNING: ACPI found bad _CRS address entry
[00021.880] 02049.02073> WARNING: ACPI found bad _CRS address entry
[00021.891] 02049.02073> acpi: published device pci(0x326e11c0e200), parent=proxy(0x326e11c0a540), handle=0x326e11c46c30
[00021.892] 02049.02073> acpi: published device rtc(0x326e11c09080), parent=acpi(0x326e11c0a780), handle=0x326e11c5f5b0
[00021.893] 02049.02073> acpi-ec: initialized
[00021.895] 02049.02073> acpi: failed to create NHLT VMO (res -10)
[00021.895] 02049.02073> acpi: failed to publish NHLT metadata
[00021.897] 02049.02073> [sysmem_init 28] async_get_default_dispatcher(): 0x326e11bfd0a0
[00021.897] 02049.02073> [sysmem_bind 40] sysmem_bind()
[00021.897] 02049.02073> acpi-bus: sysmem_register_protocol() intentionally ignored for now.
[00021.897] 02049.02073> PMU: 7 arch events
[00021.897] 02049.02073> PMU: arch event id range: 1-7
[00021.897] 02049.02073> PMU: 102 model events
[00021.897] 02049.02073> PMU: model event id range: 1-241
[00021.897] 02049.02073> Intel Processor Trace configuration for this chipset:
[00021.897] 02049.02073> mtc_freq_mask: 0x249
[00021.897] 02049.02073> cyc_thresh_mask: 0x3fff
[00021.897] 02049.02073> psb_freq_mask: 0x3f
[00021.897] 02049.02073> num addr ranges: 2
[00021.898] 01104.01117> devcoord: launch devhost 'devhost:pci#1:8086:5916': pid=2837
[00021.898] 01104.01117> devcoord: launch devhost 'devhost:pci#3:8086:9d2f': pid=2880
[00021.898] 01104.01117> devcoord: launch devhost 'devhost:pci#5:8086:9d60': pid=2944
[00021.899] 02837.02860> devhost: trace provider registry begun
[00021.899] 01104.01117> devcoord: launch devhost 'devhost:pci#6:8086:9d61': pid=3008
[00021.900] 02880.02917> devhost: trace provider registry begun
[00021.900] 02944.02978> devhost: trace provider registry begun
[00021.900] 01104.01117> devcoord: launch devhost 'devhost:pci#9:8086:9d03': pid=3110
[00021.900] 03008.03076> devhost: trace provider registry begun
[00021.901] 01104.01117> devcoord: launch devhost 'devhost:pci#14:8086:9d71': pid=3230
[00021.901] 01104.01117> devcoord: launch devhost 'devhost:pci#16:8086:156f': pid=3315
[00021.901] 03110.03182> devhost: trace provider registry begun
[00021.903] 03008.03076> initialized intel serialio i2c driver, reg=0x4064dd81f000 regsize=4096
[00021.903] 02944.02978> initialized intel serialio i2c driver, reg=0x72789c274000 regsize=4096
[00021.903] 03230.03294> devhost: trace provider registry begun
[00021.903] 03315.03358> devhost: trace provider registry begun
[00021.905] 03110.03182> ahci: using MSI interrupt
[00021.919] 02880.03730> * found USB device (0x18d1:0xa002, USB 2.0) config 1
[00021.919] 02880.03730> * found USB device (0x18d1:0xa003, USB 3.0) config 1
[00021.920] 03230.03294> [IHDA DSP 00:1f.3] Failed to fetch NHLT (res -25)
[00021.920] 03230.03294> devhost[00:1f.3/intel-hda-000/intel-sst-dsp-000] bind driver '/boot/driver/dsp.so' failed: -25
[00021.920] 01104.01117> devcoord: rpc: bind-driver 'intel-sst-dsp-000' status -25
[00021.920] 01241.01587> vc: new input device /dev/class/input/000
[00022.010] 01241.01587> vc: new display device /dev/class/display-controller/000/virtcon
[00022.150] 02837.04142> i915: Found DP monitor
[00022.150] 02837.04142> i915: Display 1 connected
[00022.151] 02837.04142> i915: MST not supported
[00023.209] 01241.01587> vc: Successfully attached to display 1
[00023.382] 02880.03730> * found USB device (0x0781:0x5571, USB 2.0) config 1
[00023.383] 02880.02917> UMS: parent: 'ifc-000'
[00023.383] 02880.02917> UMS:Max lun is: 0
[00023.633] 02880.03730> * found USB device (0x8087:0x0a2b, USB 2.0) config 1
[00023.635] 02880.02917> devhost[00:14.0/xhci/usb-bus/002/002/ifc-001] bind driver '/boot/driver/bt-transport-usb.so' failed: -2
[00023.635] 01104.01117> devcoord: rpc: bind-driver 'ifc-001' status -2
[00023.906] 03008.03076> intel-i2c-controller: intel_serialio_i2c_slave_transfer: -21
[00023.906] 03008.03076> i2c-hid: could not read HID descriptor: 0
[00023.906] 03008.03076> devhost[00:15.1/i2c-bus-9d61/004c] bind driver '/boot/driver/i2c-hid.so' failed: -2
[00023.906] 01104.01117> devcoord: rpc: bind-driver '004c' status -2
[00023.907] 02944.02978> intel-i2c-controller: intel_serialio_i2c_slave_transfer: -21
[00023.907] 02944.02978> i2c-hid: could not read HID descriptor: 0
[00023.907] 02944.02978> devhost[00:15.0/i2c-bus-9d60/0020] bind driver '/boot/driver/i2c-hid.so' failed: -2
[00023.907] 01104.01117> devcoord: rpc: bind-driver '0020' status -2
[00023.920] 03110.03662> sata2: dev info
[00023.920] 03110.03662> serial=715400411052 5
[00023.920] 03110.03662> firmware rev=1P11A1E_
[00023.920] 03110.03662> model id=IBIW NSS D
[00023.920] 03110.03662> major=0x3f0 ACS2 DMA 32 commands
[00023.920] 03110.03662> LBA48 250069680 sectors, sector size=512
[00023.921] 01182.01202> devmgr: /dev/class/block/000: GPT?
[00023.921] 01104.01117> devcoord: dc_bind_device() '/boot/driver/gpt.so'
[00023.921] 03110.03182> gpt: device_get_metadata failed (-25)
[00023.922] 01182.01202> devmgr: /dev/class/block/001: FVM?
[00023.922] 01104.01117> devcoord: dc_bind_device() '/boot/driver/fvm.so'
[00023.926] 04418.04441> paver:[Initialize] Successfully initialized EFI Device Partitioner
[00023.927] 04418.04441> paver:[WipePartitions] Immediate reboot strongly recommended
[00023.927] 03110.03182> block: Joining un-closed FIFO server
[00023.927] 03110.03182> block: Joining un-closed FIFO server
[00023.927] 03110.03182> block: Joining un-closed FIFO server
[00023.927] 01104.01117> devcoord: dc_bind_device() ''
[00023.927] 01182.01202> devmgr: /dev/class/block/000: GPT?
[00023.927] 01104.01117> devcoord: dc_bind_device() '/boot/driver/gpt.so'
[00023.928] 03110.03182> gpt: device_get_metadata failed (-25)
[00023.930] 04715.04731> 34+0 records in
[00023.930] 04715.04731> 34+0 records out
[00023.930] 04715.04731> 17408 bytes copied
[00023.933] 04820.04834> 34+0 records in
[00023.933] 04820.04834> 34+0 records out
[00023.933] 04820.04834> 17408 bytes copied
[00023.934] 04924.04938> netifc: ? /dev/class/ethernet/000
[00023.934] 04924.04938> netifc: create 512 eth buffers
[00023.934] 04924.04938> macaddr: d4:5d:df:07:be:7e
[00023.934] 04924.04938> ip6addr: fe80::d65d:df4d:fe07:be7e
[00023.934] 04924.04938> snmaddr: ff02::1:ff07:be7e
[00023.934] 04924.04938> netsvc: using /dev/class/ethernet/000
[00023.934] 04924.04938> _ _ _
[00023.934] 04924.04938> | | | | |
[00023.934] 04924.04938> _______ __| | |__ ___ ___ | |_
[00023.934] 04924.04938> |_ / _ \/ _` | '_ \ / _ \ / _ \| __|
[00023.934] 04924.04938> / / __/ (_| | |_) | (_) | (_) | |_
[00023.934] 04924.04938> /___\___|\__,_|_.__/ \___/ \___/ \__|
[00023.934] 04924.04938>
[00023.934] 04924.04938>
[00023.934] 04924.04938> zedboot: version: 0.7.13
[00023.934] 04924.04938>
[00023.934] 04924.04938> netsvc: nodename='upper-stoop-folk-grape'
[00023.934] 04924.04938> netsvc: will not advertise
[00023.934] 04924.04938> netsvc: start
[00024.385] 02880.04246> UMS: block size is: 0x00000200
[00024.385] 02880.04246> UMS: total blocks is: 15630336
[00024.385] 02880.04246> UMS: total size is: 8002732032
[00024.385] 02880.04246> UMS: read-only: 0 removable: 1
[00024.387] 01182.01202> devmgr: /dev/class/block/006: MBR?
[00024.387] 01104.01117> devcoord: dc_bind_device() '/boot/driver/mbr.so'
[00024.389] 01182.01202> devmgr: /dev/class/block/008: MBR?
[00024.389] 01104.01117> devcoord: dc_bind_device() '/boot/driver/mbr.so'
[03509.887] 04924.04938> netsvc: Running FVM Paver
[03509.889] 04924.05107> paver:[InitializeGpt] Located GPT is invalid; Attempting to initialize
[03509.890] 01104.01117> devcoord: dc_bind_device() ''
[03509.890] 01104.01117> devcoord: dc_bind_device() '/boot/driver/gpt.so'
[03509.890] 03110.03182> gpt: device_get_metadata failed (-25)
[03509.890] 01182.01202> devmgr: /dev/class/block/000: GPT?
[03509.890] 01104.01117> devcoord: dc_bind_device() '/boot/driver/gpt.so'
[03509.890] 03110.03182> devhost: rpc:bind-device failed: -20
[03509.891] 04924.05107> paver:[Initialize] Successfully initialized EFI Device Partitioner
[03509.891] 04924.05107> paver:[PartitionPave] Paving partition.
[03509.891] 04924.05107> paver:[FindFirstFit] Looking for space
[03509.891] 04924.05107> paver:[FindFirstFit] Sorting
[03509.891] 04924.05107> paver:[FindFirstFit] Partition[0] From Block [0, 34) ... (next partition starts at block 250069646)
[03509.891] 04924.05107> paver:[FindFirstFit] There are 250069612 free blocks (16777216 requested)
[03509.891] 04924.05107> paver:[AddPartition] Found space in GPT - OK 250069612 @ 34
[03509.891] 04924.05107> paver:[AddPartition] Final space in GPT - OK 16777216 @ 34
[03509.891] 04924.05107> paver:[AddPartition] Added partition, waiting for bind
[03509.891] 01104.01117> devcoord: dc_bind_device() ''
[03509.891] 01182.01202> devmgr: /dev/class/block/000: GPT?
[03509.892] 01104.01117> devcoord: dc_bind_device() '/boot/driver/gpt.so'
[03509.892] 03110.03182> gpt: device_get_metadata failed (-25)
[03509.892] 04924.05107> paver:[AddPartition] Added partition, waiting for bind - OK
[03509.892] 04924.05107> paver:[PartitionPave] Streaming partitions...
[03509.892] 05087.05101> Found compressed file
[03509.892] 04924.05107> paver:[FvmStreamPartitions] Header Validated - OK
[03509.892] 04924.05107> paver:[FvmPartitionFormat] Initializing partition as FVM
[03509.895] 01104.01117> devcoord: dc_bind_device() '/boot/driver/fvm.so'
[03510.896] 04924.05107> paver:[FvmStreamPartitions] Partitions pre-validated successfully: Enough space exists to pave.
[03510.896] 04924.05107> paver:[AllocatePartitions] Allocating partition blobfs consisting of 1 slices
[03510.900] 04924.05107> paver:[AllocatePartitions] Allocating partition minfs consisting of 1 slices
[03510.901] 04924.05107> paver:[AllocatePartitions] Creating zxcrypt volume
[03510.902] 03110.03182> devhost_get_handles(0x7b72adf8f900:block) open path='zxcrypt/block', r=-2
[03510.902] 01104.01117> devcoord: dc_bind_device() '/boot/driver/zxcrypt.so'
[03510.903] 03110.03182> devhost_get_handles(0x7b72adf8f900:block) open path='zxcrypt', r=-2
[03510.906] 04924.05107> paver:[FvmStreamPartitions] Partition space pre-allocated successfully.
[03510.906] 04924.05107> paver:[FvmStreamPartitions] Streaming partition 0
[03510.906] 04924.05107> paver:[StreamFvmPartition] Writing extent 0...
[03510.906] 04924.05113> netsvc: paver write progress 0.0%
[03510.906] 04924.05107> paver:[StreamFvmPartition] 8192 bytes written, 8380416 zeroes left
[03510.958] 04924.05107> paver:[StreamFvmPartition] Writing extent 1...
[03510.959] 04924.05107> paver:[StreamFvmPartition] 16384 bytes written, 8372224 zeroes left
[03511.012] 04924.05107> paver:[StreamFvmPartition] Writing extent 2...
[03511.025] 04924.05107> paver:[StreamFvmPartition] 2097152 bytes written, 6291456 zeroes left
[03511.066] 04924.05107> paver:[StreamFvmPartition] Writing extent 3...
[03511.079] 04924.05107> paver:[StreamFvmPartition] 2097152 bytes written, 6291456 zeroes left
[03511.119] 04924.05107> paver:[StreamFvmPartition] Writing extent 4...
[03511.907] 04924.05113> netsvc: paver write progress 17.1%
[03512.913] 04924.05113> netsvc: paver write progress 38.6%
[03513.941] 04924.05113> netsvc: paver write progress 51.9%
[03514.965] 04924.05113> netsvc: paver write progress 56.9%
[03515.968] 04924.05113> netsvc: paver write progress 72.8%
2019/05/22 10:38:06 done
2019/05/22 10:38:06 attempting to send <<image>>bootloader.img...
2019/05/22 10:38:06 target is busy, retrying in one second
[03516.624] 04924.04938> netsvc: tftp write of file <<image>>sparse.fvm completed
[03516.624] 04924.04938> netsvc: metrics: {"inorderblks": 659113,"oooblks": 0,"ack": 2575,"nack": 0,"timeouts": 0,"sas": 0,"inorderbytes": 674931252}
[03516.970] 04924.05113> netsvc: paver write progress 96.1%
[03517.139] 04924.05107> paver:[StreamFvmPartition] 722788352 bytes written, 7020544 zeroes left
[03517.184] 04924.05107> paver:[FvmStreamPartitions] Done streaming partition 0
[03517.184] 04924.05107> paver:[FvmStreamPartitions] Done flushing partition 0
[03517.184] 04924.05107> paver:[FvmStreamPartitions] Streaming partition 1
[03517.184] 04924.05107> paver:[StreamFvmPartition] Writing extent 0...
[03517.185] 04924.05107> paver:[StreamFvmPartition] 8192 bytes written, 8380416 zeroes left
[03517.237] 04924.05107> paver:[StreamFvmPartition] Writing extent 1...
[03517.238] 04924.05107> paver:[StreamFvmPartition] 65536 bytes written, 8323072 zeroes left
[03517.290] 04924.05107> paver:[StreamFvmPartition] Writing extent 2...
[03517.291] 04924.05107> paver:[StreamFvmPartition] 65536 bytes written, 8323072 zeroes left
[03517.342] 04924.05107> paver:[StreamFvmPartition] Writing extent 3...
[03517.394] 04924.05107> paver:[StreamFvmPartition] Writing extent 4...
[03517.406] 04924.05107> paver:[StreamFvmPartition] 2097152 bytes written, 14680064 zeroes left
[03517.503] 04924.05107> paver:[StreamFvmPartition] Writing extent 5...
[03517.504] 04924.05107> paver:[StreamFvmPartition] 57344 bytes written, 8331264 zeroes left
[03517.557] 04924.05107> paver:[FvmStreamPartitions] Done streaming partition 1
[03517.557] 04924.05107> paver:[FvmStreamPartitions] Done flushing partition 1
[03517.558] 05087.05101> Reading FVM from compressed file: true
[03517.558] 05087.05101> Remaining bytes read into compression buffer: 0
[03517.558] 05087.05101> Remaining bytes written to decompression buffer: 0
[03517.558] 05087.05101> Time reading bytes from sparse FVM file: 352405838 (0 s)
[03517.558] 05087.05101> Time reading bytes AND decompressing them: 709111487 (0 s)
[03517.558] 04924.05107> paver:[PartitionPave] Completed successfully
2019/05/22 10:38:07 attempting to send <<image>>bootloader.img...
2019/05/22 10:38:07 done
2019/05/22 10:38:07 attempting to send <<image>>zircona.img...
[03517.625] 04924.04938> netsvc: Running BOOTLOADER Paver
[03517.627] 04924.06349> paver:[Initialize] Successfully initialized EFI Device Partitioner
[03517.627] 04924.06349> paver:[RealMain] SKIPPING BOOTLOADER install on x64 device, pass --force if desired.
[03517.641] 04924.04938> netsvc: tftp write of file <<image>>bootloader.img completed
[03517.641] 04924.04938> netsvc: metrics: {"inorderblks": 1093,"oooblks": 0,"ack": 5,"nack": 0,"timeouts": 0,"sas": 0,"inorderbytes": 1118208}
[03517.642] 04924.04938> netsvc: Running ZIRCON-A Paver
[03517.644] 04924.06478> paver:[Initialize] Successfully initialized EFI Device Partitioner
[03517.644] 04924.06478> paver:[PartitionPave] Paving partition.
[03517.644] 04924.06478> paver:[FindFirstFit] Looking for space
[03517.644] 04924.06478> paver:[FindFirstFit] Partition seen with start 34, end 16777249 (length 16777216)
[03517.644] 04924.06478> paver:[FindFirstFit] Sorting
[03517.644] 04924.06478> paver:[FindFirstFit] Partition[0] From Block [0, 34) ... (next partition starts at block 34)
[03517.644] 04924.06478> paver:[FindFirstFit] There are 0 free blocks (32768 requested)
[03517.644] 04924.06478> paver:[FindFirstFit] Partition[1] From Block [34, 16777250) ... (next partition starts at block 250069646)
[03517.644] 04924.06478> paver:[FindFirstFit] There are 233292396 free blocks (32768 requested)
[03517.644] 04924.06478> paver:[AddPartition] Found space in GPT - OK 233292396 @ 16777250
[03517.644] 04924.06478> paver:[AddPartition] Final space in GPT - OK 32768 @ 16777250
[03517.645] 03110.03182> block: Joining un-closed FIFO server
[03517.645] 04924.06478> paver:[AddPartition] Added partition, waiting for bind
[03517.645] 03110.03182> block: Joining un-closed FIFO server
[03517.645] 01104.01117> devcoord: dc_bind_device() ''
[03517.646] 01182.01202> devmgr: /dev/class/block/000: GPT?
[03517.646] 01104.01117> devcoord: dc_bind_device() '/boot/driver/gpt.so'
[03517.646] 03110.03182> gpt: device_get_metadata failed (-25)
[03517.646] 01182.01202> devmgr: /dev/class/block/013: FVM?
[03517.646] 01104.01117> devcoord: dc_bind_device() '/boot/driver/fvm.so'
[03517.646] 04924.06478> paver:[AddPartition] Added partition, waiting for bind - OK
2019/05/22 10:38:08 done
2019/05/22 10:38:08 attempting to send <<image>>zirconr.img...
2019/05/22 10:38:08 target is busy, retrying in one second
[03517.774] 04924.04938> netsvc: tftp write of file <<image>>zircona.img completed
[03517.774] 04924.04938> netsvc: metrics: {"inorderblks": 12203,"oooblks": 0,"ack": 48,"nack": 0,"timeouts": 0,"sas": 0,"inorderbytes": 12495176}
[03517.849] 04924.06478> paver:[PartitionPave] Completed successfully
2019/05/22 10:38:09 attempting to send <<image>>zirconr.img...
[03518.775] 04924.04938> netsvc: Running ZIRCON-R Paver
[03518.778] 04924.06738> paver:[Initialize] Successfully initialized EFI Device Partitioner
[03518.778] 04924.06738> paver:[PartitionPave] Paving partition.
[03518.778] 04924.06738> paver:[FindFirstFit] Looking for space
[03518.778] 04924.06738> paver:[FindFirstFit] Partition seen with start 34, end 16777249 (length 16777216)
[03518.778] 04924.06738> paver:[FindFirstFit] Partition seen with start 16777250, end 16810017 (length 32768)
[03518.778] 04924.06738> paver:[FindFirstFit] Sorting
[03518.778] 04924.06738> paver:[FindFirstFit] Partition[0] From Block [0, 34) ... (next partition starts at block 34)
[03518.778] 04924.06738> paver:[FindFirstFit] There are 0 free blocks (49152 requested)
[03518.778] 04924.06738> paver:[FindFirstFit] Partition[1] From Block [34, 16777250) ... (next partition starts at block 16777250)
[03518.778] 04924.06738> paver:[FindFirstFit] There are 0 free blocks (49152 requested)
[03518.778] 04924.06738> paver:[FindFirstFit] Partition[2] From Block [16777250, 16810018) ... (next partition starts at block 250069646)
[03518.778] 04924.06738> paver:[FindFirstFit] There are 233259628 free blocks (49152 requested)
[03518.778] 04924.06738> paver:[AddPartition] Found space in GPT - OK 233259628 @ 16810018
[03518.778] 04924.06738> paver:[AddPartition] Final space in GPT - OK 49152 @ 16810018
[03518.779] 04924.06738> paver:[AddPartition] Added partition, waiting for bind
[03518.779] 03110.03182> block: Joining un-closed FIFO server
[03518.779] 01104.01117> devcoord: dc_bind_device() ''
[03518.779] 01182.01202> devmgr: /dev/class/block/000: GPT?
[03518.779] 01104.01117> devcoord: dc_bind_device() '/boot/driver/gpt.so'
[03518.779] 03110.03182> gpt: device_get_metadata failed (-25)
[03518.780] 01182.01202> devmgr: /dev/class/block/017: FVM?
[03518.780] 01104.01117> devcoord: dc_bind_device() '/boot/driver/fvm.so'
[03518.780] 04924.06738> paver:[AddPartition] Added partition, waiting for bind - OK
2019/05/22 10:38:09 done
2019/05/22 10:38:09 attempting to send <<image>>authorized_keys...
2019/05/22 10:38:09 target is busy, retrying in one second
[03518.909] 04924.04938> netsvc: tftp write of file <<image>>zirconr.img completed
[03518.909] 04924.04938> netsvc: metrics: {"inorderblks": 11146,"oooblks": 0,"ack": 44,"nack": 0,"timeouts": 0,"sas": 0,"inorderbytes": 11413104}
[03518.976] 04924.06738> paver:[PartitionPave] Completed successfully
2019/05/22 10:38:10 attempting to send <<image>>authorized_keys...
2019/05/22 10:38:10 done
2019/05/22 10:38:10 attempting to send <<netboot>>kernel.bin...
2019/05/22 10:38:10 target is busy, retrying in one second
[03519.910] 04924.04938> netsvc: Installing SSH authorized_keys
[03519.911] 04924.04938> netsvc: tftp write of file <<image>>authorized_keys completed
[03519.911] 04924.04938> netsvc: metrics: {"inorderblks": 1,"oooblks": 0,"ack": 1,"nack": 0,"timeouts": 0,"sas": 0,"inorderbytes": 806}
[03519.913] 04924.07015> paver:[Initialize] Successfully initialized EFI Device Partitioner
[03519.914] 01104.01117> devcoord: dc_bind_device() '/boot/driver/zxcrypt.so'
[03519.914] 03110.03182> devhost_get_handles(0x7b72adf8f900:block) open path='zxcrypt', r=-2
[03519.939] 04924.07015> paver:[DataFilePave] Wrote ssh/authorized_keys
2019/05/22 10:38:11 attempting to send <<netboot>>kernel.bin...
2019/05/22 10:38:11 done
[00000.000] 00000.00000> zbi: @ 0xffffff80066f4000 (10903144 bytes)
[00000.000] 00000.00000> UART: FIFO depth 16
[00000.000] 00000.00000> PMM: boot reserve add [0x100000, 0x311fff]
[00000.000] 00000.00000> PMM: boot reserve add [0x66f4000, 0x7159fff]
[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, 0x311fff]
[00000.000] 00000.00000> PMM: boot reserve marking WIRED [0x66f4000, 0x7159fff]
[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 0xffffffff00118014 (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 [0x715a000, 0x715a100)
[00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00125270 (elf_build_id) at level 0x4fffe, flags 0x1
[00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001253fc (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-c6f89f99e4712632917300ff480339ef2c3a704a-dirty
[00000.000] 00000.00000> ELF build ID: 4b31e2e01b268026705ee30438d03e36a282c644
[00000.000] 00000.00000> initializing heap
[00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00101f78 (console) at level 0x50000, flags 0x1
[00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00186c70 (x86_resource_init) at level 0x50000, flags 0x1
[00000.000] 00000.00000> initializing vm
[00000.000] 00000.00000> VM: reserving kernel region [0xffffffff00100000, 0xffffffff00229000) flags 0x28 name 'kernel_code'
[00000.000] 00000.00000> VM: reserving kernel region [0xffffffff00229000, 0xffffffff0027c000) flags 0x8 name 'kernel_rodata'
[00000.000] 00000.00000> VM: reserving kernel region [0xffffffff0027c000, 0xffffffff00284000) flags 0x18 name 'kernel_data'
[00000.000] 00000.00000> VM: reserving kernel region [0xffffffff00284000, 0xffffffff00312000) flags 0x18 name 'kernel_bss'
[00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00187994 (display_memtype) at level 0x60001, flags 0x1
[00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff0018aeb8 (acpi_tables) at level 0x60001, flags 0x1
[00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00185998 (hpet) at level 0x60002, flags 0x1
[00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00185db4 (apic) at level 0x60002, flags 0x1
[00000.000] 00000.00000> x2APIC enabled
[00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001acbd4 (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 0xffffffff0018a4a8 (timer) at level 0x60003, flags 0x1
[00000.000] 00000.00000> HPET frequency: 23999 ticks/ms
[00000.000] 00000.00000> TSC frequency: 2712000 ticks/ms
[03521.327] 00000.00000> timer features: constant_tsc 1 invariant_tsc 1 tsc_deadline 1
[03521.327] 00000.00000> Using TSC as wallclock
[03521.327] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00218bf4 (percpu_heap_init) at level 0x60003, flags 0x1
[03521.327] 00000.00000> initializing kernel
[03521.327] 00000.00000> initializing mp
[03521.327] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00118268 (global_prng_thread_safe) at level 0x7ffff, flags 0x1
[03521.327] 00000.00000> creating bootstrap completion thread
[03521.327] 00000.00000> top of bootstrap2()
[03521.327] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001348cc (libobject) at level 0x80000, flags 0x1
[03521.327] 00000.00000> OOM: started thread
[03521.327] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00215a04 (dpc) at level 0x80000, flags 0x1
[03521.327] 00000.00000> Processor Model Info: type 0 family 0x6 model 0xe stepping 0x9
[03521.327] 00000.00000> display_family 0x6 display_model 0x8e
[03521.327] 00000.00000> Vendor: Intel
[03521.327] 00000.00000> Microarch: Kaby Lake
[03521.327] 00000.00000> F/M/S: 6/8e/9
[03521.327] 00000.00000> patch_level: 8e
[03521.327] 00000.00000> Brand: Intel(R) Core(TM) i5-7300U CPU @ 2.60GHz
[03521.327] 00000.00000> Features: fpu sse sse2 sse3 ssse3 sse4.1 sse4.2 mmx avx avx2 fxsr pcid xsave mon aesni clflush
[03521.327] 00000.00000> clflushopt fsgsbase tsc_adj smep smap erms rdrand rdseed syscall nx huge rdtscp
[03521.327] 00000.00000> invar_tsc tsc_deadline x2apic vmx pt hwp
[03521.327] 00000.00000> Properties: meltdown l1tf pcid_good
[03521.327] 00000.00000> initializing platform
[03521.327] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001a6298 (x86_perfmon) at level 0x90000, flags 0x1
[03521.327] 00000.00000> PMU: version 4
[03521.327] 00000.00000> UART: started IRQ driven RX
[03521.327] 00000.00000> UART: started IRQ driven TX
[03521.327] 00000.00000> cpu topology:
[03521.327] 00000.00000> 0: apic id 0x0 BSP
[03521.327] 00000.00000> 1: apic id 0x1
[03521.327] 00000.00000> 2: apic id 0x2
[03521.327] 00000.00000> 3: apic id 0x3
[03521.327] 00000.00000> Found 4 cpus
[03521.327] 00000.00000> booting apic ids: 0x1 0x2 0x3
[03521.342] 00000.00000> entering scheduler on cpu 1
[03521.343] 00000.00000> entering scheduler on cpu 2
[03521.343] 00000.00000> entering scheduler on cpu 3
[03521.346] 00000.00000> smbios: manufacturer="Intel Corporation" product="NUC7i5DNKE"
[03521.346] 00000.00000> initializing target
[03521.346] 00000.00000> INIT: cpu 0, calling hook 0xffffffff0018964c (x86_pcie_init) at level 0xa0000, flags 0x1
[03521.346] 00000.00000> moving to last init level
[03521.346] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001244c8 (debuglog) at level 0xb0000, flags 0x1
[03521.346] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00179278 (kcounters) at level 0xb0000, flags 0x1
[03521.346] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00102aa0 (kernel_shell) at level 0xc0000, flags 0x1
[03521.346] 00000.00000> INIT: cpu 0, calling hook 0xffffffff0021242c (ktrace) at level 0xc0000, flags 0x1
[03521.349] 00000.00000> ktrace: buffer at 0xffffff91dc2d2000 (33554432 bytes)
[03521.349] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00225a38 (userboot) at level 0xc0000, flags 0x1
[03521.349] 00000.00000> userboot: ramdisk 0xa66000 @ 0xffffff80066f4000
[03521.350] 00000.00000> userboot: userboot rodata 0 @ [0x2209a9eb6000,0x2209a9eb9000)
[03521.350] 00000.00000> userboot: userboot code 0x3000 @ [0x2209a9eb9000,0x2209a9ec4000)
[03521.350] 00000.00000> userboot: vdso/full rodata 0 @ [0x2209a9ec4000,0x2209a9ecb000)
[03521.350] 00000.00000> userboot: vdso/full code 0x7000 @ [0x2209a9ecb000,0x2209a9ecc000)
[03521.350] 00000.00000> userboot: entry point @ 0x2209a9eb9c90
[03521.374] 01036.01043> userboot: searching bootfs for 'bin/bootsvc'
[03521.374] 01036.01043> userboot: 'bin/bootsvc' has PT_INTERP "lib/ld.so.1"
[03521.374] 01036.01043> userboot: searching bootfs for 'lib/ld.so.1'
[03521.374] 01036.01043> userboot: userboot: loaded lib/ld.so.1 at 0x513b9c245000, entry point 0x513b9c263880
[03521.374] 01036.01043> userboot: userboot: loaded vDSO at 0x7ea5b431a000, entry point 0x7ea5b4321947
[03521.374] 01036.01043> userboot: process bin/bootsvc started.
[03521.374] 01036.01043> userboot: waiting for loader-service requests...
[03521.374] 01036.01043> userboot: searching bootfs for 'lib/libfdio.so'
[03521.374] 01036.01043> userboot: searching bootfs for 'lib/libtrace-engine.so'
[03521.374] 01036.01043> userboot: searching bootfs for 'lib/libasync-default.so'
[03521.374] 01036.01043> userboot: searching bootfs for 'lib/liblaunchpad.so'
[03521.374] 01036.01043> userboot: searching bootfs for 'lib/libc++.so.2'
[03521.375] 01036.01043> userboot: searching bootfs for 'lib/libc++abi.so.1'
[03521.375] 01036.01043> userboot: searching bootfs for 'lib/libunwind.so.1'
[03521.375] 01050.01053> {{{reset}}}
[03521.375] 01050.01053> {{{module:0:<application>:elf:378da0248fca2fb8c10e339ae03cb289aff5c110}}}
[03521.375] 01050.01053> {{{mmap:0x150375271000:0x3b000:load:0:rx:0}}}
[03521.375] 01050.01053> {{{mmap:0x1503752ac000:0x4000:load:0:rw:0x3b000}}}
[03521.375] 01050.01053> dso: id=378da0248fca2fb8c10e339ae03cb289aff5c110 base=0x0000150375271000 name=<application>
[03521.375] 01050.01053> {{{module:0x2:<vDSO>:elf:f82422446b9a9c521dcb0b0be40cb053fb8e7ef2}}}
[03521.375] 01050.01053> {{{mmap:0x7ea5b431a000:0x7000:load:0x2:r:0}}}
[03521.375] 01050.01053> {{{mmap:0x7ea5b4321000:0x1000:load:0x2:rx:0x7000}}}
[03521.375] 01050.01053> dso: id=f82422446b9a9c521dcb0b0be40cb053fb8e7ef2 base=0x00007ea5b431a000 name=<vDSO>
[03521.375] 01050.01053> {{{module:0x3:libfdio.so:elf:040528230cb93f3e80655a281da76235ec3b9308}}}
[03521.375] 01050.01053> {{{mmap:0x3914e6e84000:0x38000:load:0x3:rx:0}}}
[03521.375] 01050.01053> {{{mmap:0x3914e6ebd000:0x6000:load:0x3:rw:0x39000}}}
[03521.375] 01050.01053> dso: id=040528230cb93f3e80655a281da76235ec3b9308 base=0x00003914e6e84000 name=libfdio.so
[03521.375] 01050.01053> {{{module:0x4:libtrace-engine.so:elf:386dbd94d10ac2f61293861e8e1ac22585e420b8}}}
[03521.375] 01050.01053> {{{mmap:0x228cf5161000:0x9000:load:0x4:rx:0}}}
[03521.375] 01050.01053> {{{mmap:0x228cf516a000:0x2000:load:0x4:rw:0x9000}}}
[03521.375] 01050.01053> dso: id=386dbd94d10ac2f61293861e8e1ac22585e420b8 base=0x0000228cf5161000 name=libtrace-engine.so
[03521.375] 01050.01053> {{{module:0x5:libasync-default.so:elf:744cfae1697ffe6c2ab3401ff64a56d828f4e099}}}
[03521.375] 01050.01053> {{{mmap:0x215be928c000:0x1000:load:0x5:rx:0}}}
[03521.375] 01050.01053> {{{mmap:0x215be928d000:0x1000:load:0x5:rw:0x1000}}}
[03521.375] 01050.01053> dso: id=744cfae1697ffe6c2ab3401ff64a56d828f4e099 base=0x0000215be928c000 name=libasync-default.so
[03521.375] 01050.01053> {{{module:0x6:liblaunchpad.so:elf:2f80313e6faa90c888a0f1df712c7e806cc50153}}}
[03521.375] 01050.01053> {{{mmap:0x19381b44d000:0x7000:load:0x6:rx:0}}}
[03521.375] 01050.01053> {{{mmap:0x19381b454000:0x2000:load:0x6:rw:0x7000}}}
[03521.375] 01050.01053> dso: id=2f80313e6faa90c888a0f1df712c7e806cc50153 base=0x000019381b44d000 name=liblaunchpad.so
[03521.375] 01050.01053> {{{module:0x1:libc.so:elf:b183f02896022681571a29ba78b01e870de381bb}}}
[03521.375] 01050.01053> {{{mmap:0x513b9c245000:0xa6000:load:0x1:rx:0}}}
[03521.375] 01050.01053> {{{mmap:0x513b9c2eb000:0x5000:load:0x1:rw:0xa6000}}}
[03521.375] 01050.01053> dso: id=b183f02896022681571a29ba78b01e870de381bb base=0x0000513b9c245000 name=libc.so
[03521.375] 01050.01053> {{{module:0x7:libc++.so.2:elf:c40e3db9703e022b}}}
[03521.375] 01050.01053> {{{mmap:0x64287c59e000:0x53000:load:0x7:r:0}}}
[03521.375] 01050.01053> {{{mmap:0x64287c5f1000:0x7e000:load:0x7:rx:0x53000}}}
[03521.375] 01050.01053> {{{mmap:0x64287c66f000:0x5000:load:0x7:rw:0xd1000}}}
[03521.375] 01050.01053> {{{mmap:0x64287c674000:0x3000:load:0x7:rw:0xd6000}}}
[03521.375] 01050.01053> dso: id=c40e3db9703e022b base=0x000064287c59e000 name=libc++.so.2
[03521.375] 01050.01053> {{{module:0x8:libc++abi.so.1:elf:7dd43029d9b84d36}}}
[03521.375] 01050.01053> {{{mmap:0x4341b945a000:0x16000:load:0x8:r:0}}}
[03521.375] 01050.01053> {{{mmap:0x4341b9470000:0x23000:load:0x8:rx:0x16000}}}
[03521.375] 01050.01053> {{{mmap:0x4341b9493000:0x3000:load:0x8:rw:0x39000}}}
[03521.375] 01050.01053> {{{mmap:0x4341b9496000:0x1000:load:0x8:rw:0x3c000}}}
[03521.375] 01050.01053> dso: id=7dd43029d9b84d36 base=0x00004341b945a000 name=libc++abi.so.1
[03521.375] 01050.01053> {{{module:0x9:libunwind.so.1:elf:53013261665bb49a}}}
[03521.375] 01050.01053> {{{mmap:0x2bf9648b000:0x6000:load:0x9:r:0}}}
[03521.375] 01050.01053> {{{mmap:0x2bf96491000:0x8000:load:0x9:rx:0x6000}}}
[03521.375] 01050.01053> {{{mmap:0x2bf96499000:0x1000:load:0x9:rw:0xe000}}}
[03521.375] 01050.01053> {{{mmap:0x2bf9649a000:0x1000:load:0x9:rw:0xf000}}}
[03521.375] 01050.01053> dso: id=53013261665bb49a base=0x000002bf9648b000 name=libunwind.so.1
[03521.376] 01050.01053> bootsvc: Starting...
[03521.376] 01036.01043> userboot: loader-service channel peer closed
[03521.376] 01036.01043> userboot: finished!
[03521.376] 01050.01053> bootsvc: Creating bootfs service...
[03521.376] 01050.01053> bootsvc: Retrieving boot image...
[03521.376] 01050.01053> bootsvc: Decommitted BOOTDATA VMO from 0 to 0xa65000
[03521.376] 01050.01053> bootsvc: Loading boot arguments...
[03521.376] 01050.01053> bootsvc: Creating svcfs service...
[03521.376] 01050.01053> bootsvc: Loading kernel VMOs...
[03521.376] 01050.01053> bootsvc: Creating loader service...
[03521.376] 01050.01053> bootsvc: Launching next process...
[03521.376] 01050.01117> bootsvc: bootsvc.next = bin/devcoordinator
[03521.376] 01050.01117> bootsvc: Launched bin/devcoordinator
[03521.378] 01124.01139> devcoordinator: launch /boot/bin/svchost (svchost) OK
[03521.380] 01124.01139> devcoordinator: launch /boot/bin/fshost (fshost) OK
[03521.383] 01124.01361> devcoordinator: launch /boot/bin/pwrbtn-monitor (pwrbtn-monitor) OK
[03521.384] 01124.01385> devcoordinator: launch /boot/bin/miscsvc (miscsvc) OK
[03521.384] 01124.01385> devcoordinator: launch /boot/bin/netsvc (netsvc) OK
[03521.386] 01124.01385> devcoordinator: launch /boot/bin/virtual-console (virtual-console) OK
[03521.390] 01124.01139> devcoordinator: full system required, ignoring fallback drivers until /system is loaded
[03521.390] 01124.01139> devcoordinator: launch devhost 'devhost:sys': pid=2462
[03521.390] 01124.01139> devcoordinator: launch devhost 'devhost:test': pid=2494
[03521.391] 01124.01139> devcoordinator: launch devhost 'devhost:root': pid=2542
[03521.391] 01124.01139> devcoordinator: launch devhost 'devhost:misc': pid=2628
[03521.402] 01124.01371> devcoordinator: launch /boot/bin/sh (sh:console) OK
[03521.479] 02462.02476> acpi-bus: not using IOMMU
[03521.487] 02462.02476> PMU: 7 arch events
[03521.487] 02462.02476> PMU: arch event id range: 1-7
[03521.487] 02462.02476> PMU: 102 arch events
[03521.487] 02462.02476> PMU: arch event id range: 1-241
[03521.487] 02462.02476> Intel Processor Trace configuration for this chipset:
[03521.487] 02462.02476> mtc_freq_mask: 0x249
[03521.487] 02462.02476> cyc_thresh_mask: 0x3fff
[03521.487] 02462.02476> psb_freq_mask: 0x3f
[03521.487] 02462.02476> num addr ranges: 2
[03521.487] 02462.02476> [sysmem_init 28] async_get_default_dispatcher(): 0xc972e4010d0
[03521.487] 02462.02476> [sysmem_bind 40] sysmem_bind()
[03521.487] 02462.03270> acpi-pwrbtn: initialized
[03521.487] 01957.02009> vc: new input device /dev/class/input/000
[03521.497] 02462.03270> WARNING: ACPI found bad _CRS address entry
[03521.506] 02462.03270> WARNING: ACPI found bad _CRS address entry
[03521.518] 02462.03270> acpi: published device pci(0xc966e3fd310), parent=sys(0xc97ae402310), handle=0xc962e40ee10
[03521.519] 01124.01139> devcoordinator: launch devhost 'devhost:pci#1:8086:5916': pid=3364
[03521.519] 01124.01139> devcoordinator: launch devhost 'devhost:pci#3:8086:9d2f': pid=3422
[03521.520] 01124.01139> devcoordinator: launch devhost 'devhost:pci#5:8086:9d60': pid=3497
[03521.520] 01124.01139> devcoordinator: launch devhost 'devhost:pci#6:8086:9d61': pid=3555
[03521.522] 01124.01139> devcoordinator: launch devhost 'devhost:pci#9:8086:9d03': pid=3682
[03521.522] 02462.03270> acpi: published device rtc(0xc966e401390), parent=acpi(0xc97ae401210), handle=0xc962e434050
[03521.524] 01124.01139> devcoordinator: launch devhost 'devhost:pci#14:8086:9d71': pid=3795
[03521.525] 02462.03270> acpi-ec: initialized
[03521.526] 01124.01139> devcoordinator: launch devhost 'devhost:pci#16:8086:156f': pid=3968
[03521.529] 02462.03270> acpi: failed to create NHLT VMO (res -10)
[03521.529] 02462.03270> acpi: failed to publish NHLT metadata
[03521.533] 03497.03520> initialized intel serialio i2c driver, reg=0x47111c695000 regsize=4096
[03521.535] 03555.03580> initialized intel serialio i2c driver, reg=0x7fece6578000 regsize=4096
[03521.546] 03682.03713> ahci: using MSI interrupt
[03521.556] 03422.04531> * found USB device (0x18d1:0xa002, USB 2.0) config 1
[03521.556] 03422.04531> * found USB device (0x18d1:0xa003, USB 3.0) config 1
[03521.556] 03795.03865> [IHDA DSP 00:1f.3] Failed to fetch NHLT (res -25)
[03521.556] 03795.03865> [IHDA Controller 00:1f.3] Failed to initialize DSP device (res = -25)
[03521.627] 01830.01872> netifc: ? /dev/class/ethernet/000
[03521.627] 01830.01872> netifc: create 512 eth buffers
[03521.627] 01830.01872> macaddr: d4:5d:df:07:be:7e
[03521.627] 01830.01872> ip6addr: fe80::d65d:df4d:fe07:be7e
[03521.627] 01830.01872> snmaddr: ff02::1:ff07:be7e
[03521.627] 01830.01872> netsvc: using /dev/class/ethernet/000
[03521.627] 01830.01872> netsvc: nodename='upper-stoop-folk-grape'
[03521.627] 01830.01872> netsvc: start
[03521.646] 01957.02009> vc: new display device /dev/class/display-controller/000
[03521.686] 03364.04821> i915: Found DP monitor
[03521.686] 03364.04821> i915: Display 1 connected
[03521.686] 03364.04821> i915: MST not supported
[03522.744] 01957.02009> vc: Successfully attached to display 1
[03523.018] 03422.04531> * found USB device (0x0781:0x5571, USB 2.0) config 1
[03523.269] 03422.04531> * found USB device (0x8087:0x0a2b, USB 2.0) config 1
[03523.538] 03497.03520> intel-i2c-controller: intel_serialio_i2c_slave_transfer: -21
[03523.538] 03497.03520> i2c-hid: could not read HID descriptor: 0
[03523.538] 03497.03520> devhost[00:15.0/i2c-bus-9d60/0020] bind driver '/boot/driver/i2c-hid.so' failed: -2
[03523.538] 01124.01139> devcoordinator: rpc: bind-driver '0020' status -2
[03523.546] 03555.03580> intel-i2c-controller: intel_serialio_i2c_slave_transfer: -21
[03523.546] 03555.03580> i2c-hid: could not read HID descriptor: 0
[03523.546] 03555.03580> devhost[00:15.1/i2c-bus-9d61/004c] bind driver '/boot/driver/i2c-hid.so' failed: -2
[03523.546] 01124.01139> devcoordinator: rpc: bind-driver '004c' status -2
[03523.567] 03682.04520> sata2: dev info
[03523.567] 03682.04520> serial=1745001401255
[03523.567] 03682.04520> firmware rev=P1111A_E
[03523.567] 03682.04520> model id=BIWIN SSD
[03523.567] 03682.04520> major=0x3f0 ACS2 DMA 32 commands
[03523.567] 03682.04520> LBA48 250069680 sectors, sector size=512
[03523.568] 01339.01353> fshost: Binding: /boot/driver/gpt.so
[03523.568] 03682.03713> DeviceControllerBind running: /boot/driver/gpt.so
[03523.568] 01124.01139> devcoordinator: rpc: bind-device 'block'
[03523.568] 03682.03713> DeviceControllerBind finished: /boot/driver/gpt.so ZX_OK
[03523.568] 03682.03713> gpt: device_get_metadata failed (-25)
[03523.569] 01339.01353> fshost: Binding: /boot/driver/fvm.so
[03523.569] 03682.03713> DeviceControllerBind running: /boot/driver/fvm.so
[03523.569] 01124.01139> devcoordinator: rpc: bind-device 'block'
[03523.569] 03682.03713> DeviceControllerBind finished: /boot/driver/fvm.so ZX_OK
[03523.570] 01339.01353> fshost: (/dev/class/block/002) failed: ZX_ERR_NOT_SUPPORTED
[03523.570] 01339.01353> fshost: (/dev/class/block/003) failed: ZX_ERR_NOT_SUPPORTED
[03523.572] 01339.01353> fshost: BlockDevice::MountFilesystem(blobfs)
[03523.572] 01339.01353> devcoordinator: launch /boot/bin/blobfs (blobfs:/blob) OK
[03523.714] 01339.01353> fshost: starting 'bin/pkgsvr' '630b89bcd1dae792b7d403d5f381f00b301011a3d8de84e5cce710cc1d0a9daf'...
[03523.721] 01339.01353> devcoordinator: launch bin/pkgsvr (pkgfs) OK
[03523.735] 05266.05470> pkgsvr: system: will be served from 630b89bcd1dae792b7d403d5f381f00b301011a3d8de84e5cce710cc1d0a9daf
[03523.735] 05266.05470> pkgsvr: pkgfs serving index /data/pkgfs_index from blobfs /blob
[03523.735] 01339.01353> fshost: unsealing zxcrypt
[03523.735] 03682.03713> DeviceControllerBind running: /boot/driver/zxcrypt.so
[03523.735] 01124.01139> devcoordinator: rpc: bind-device 'block'
[03523.736] 03682.03713> DeviceControllerBind finished: /boot/driver/zxcrypt.so ZX_OK
[03523.737] 01339.01353> fshost: mounting minfs
[03523.737] 01339.01353> fshost: BlockDevice::MountFilesystem(minfs)
[03523.739] 01339.01353> devcoordinator: launch /boot/bin/minfs (minfs:/data) OK
[03523.743] 05659.05673> minfs: filesystem in clean state.
[03523.749] 01124.05519> devcoordinator: adding system driver 'qmi_usb' '/system/driver/qmi-transport.so'
[03523.755] 01124.02019> devcoordinator: launch /system/bin/appmgr (appmgr) OK
[03523.779] 01124.05519> devcoordinator: adding system driver 'ralink' '/system/driver/ralink.so'
[03523.780] 01124.05519> devcoordinator: adding system driver 'bt_hog' '/system/driver/bt-hog.so'
[03523.785] 01124.05519> devcoordinator: adding system driver 'virtual_camera' '/system/driver/virtual_camera_driver.so'
[03523.789] 01124.05519> devcoordinator: adding system driver 'gpu' '/system/driver/libmsd_intel.so'
[03523.799] 01124.05519> devcoordinator: adding system driver 'mt8167s_gpu' '/system/driver/libmsd_img_rgx_mt8167.so'
[03523.830] 01124.05519> devcoordinator: adding system driver 'wlan' '/system/driver/wlan.so'
[03523.833] 01124.05519> devcoordinator: adding system driver 'rtl88xx' '/system/driver/rtl88xx.so'
[03523.835] 01124.05519> devcoordinator: adding system driver 'qmi_fake' '/system/driver/qmi-fake.so'
[03523.842] 01124.05519> devcoordinator: adding system driver 'bt_hci_fake' '/system/driver/bt-hci-fake.so'
[03523.848] 01124.05519> devcoordinator: adding system driver 'bt_hci_atheros' '/system/driver/bt-hci-atheros.so'
[03523.852] 01124.05519> devcoordinator: adding system driver 'virtual_audio' '/system/driver/virtual_audio_driver.so'
[03523.855] 01124.05519> devcoordinator: adding system driver 'ath10k_pci' '/system/driver/ath10k.so'
[03523.859] 01124.05519> devcoordinator: adding system driver 'bt_hci_intel' '/system/driver/bt-hci-intel.so'
[03523.862] 01124.05519> devcoordinator: adding system driver 'wlan' '/system/driver/wlanif.so'
[03523.866] 01124.05519> devcoordinator: adding system driver 'wlantapctl' '/system/driver/wlantap.so'
[03523.871] 01124.05519> devcoordinator: adding system driver 'brcmfmac' '/system/driver/brcmfmac.so'
[03523.880] 01124.05519> devcoordinator: adding system driver 'no_hardware_gpu' '/system/driver/libmsd_img_rgx_no_hardware.so'
[03523.898] 01124.05519> devcoordinator: adding system driver 'bt_host' '/system/driver/bt-host.so'
[03523.901] 05791.05805> [INFO:namespace_builder.cc(44)] config-data for sysmgr
[03523.902] 01124.05519> devcoordinator: adding system driver 'bt_hci_passthrough' '/system/driver/bt-hci-passthrough.so'
[03523.907] 01124.05519> devcoordinator: adding system driver 'magma_pdev_gpu' '/system/driver/libmsd_arm.so'
[03523.911] 01124.05519> devcoordinator: adding system driver 'wlan' '/system/driver/wlanphy.so'
[03523.912] 01124.05519> devcoordinator: adding system driver 'iwlwifi_pci' '/system/driver/iwlwifi.so'
[03523.917] 01124.05519> devcoordinator: adding system driver 'usb_video' '/system/driver/usb_video.so'
[03523.917] 01124.01139> devcoordinator: driver 'usb_video' added
[03523.917] 01124.01139> devcoordinator: driver 'iwlwifi_pci' added
[03523.917] 01124.01139> devcoordinator: driver 'wlan' added
[03523.917] 01124.01139> devcoordinator: driver 'magma_pdev_gpu' added
[03523.917] 01124.01139> devcoordinator: driver 'bt_host' added
[03523.917] 01124.01139> devcoordinator: driver 'brcmfmac' added
[03523.917] 01124.01139> devcoordinator: driver 'wlan' added
[03523.917] 01124.01139> devcoordinator: driver 'bt_hci_intel' added
[03523.917] 01124.01139> devcoordinator: driver 'ath10k_pci' added
[03523.917] 01124.01139> devcoordinator: driver 'bt_hci_atheros' added
[03523.917] 01124.01139> devcoordinator: driver 'bt_hci_fake' added
[03523.917] 01124.01139> devcoordinator: driver 'qmi_fake' added
[03523.917] 01124.01139> devcoordinator: driver 'rtl88xx' added
[03523.917] 01124.01139> devcoordinator: driver 'wlan' added
[03523.917] 01124.01139> devcoordinator: driver 'mt8167s_gpu' added
[03523.917] 01124.01139> devcoordinator: driver 'gpu' added
[03523.917] 01124.01139> devcoordinator: driver 'bt_hog' added
[03523.917] 01124.01139> devcoordinator: driver 'ralink' added
[03523.917] 01124.01139> devcoordinator: driver 'qmi_usb' added
[03523.917] 01124.01139> devcoordinator: driver 'bt_hci_passthrough' added
[03523.917] 01124.01139> devcoordinator: fallback driver 'usb_composite' is available
[03523.917] 01124.01139> devcoordinator: driver 'usb_composite' added
[03523.918] 02494.02517> img_rgx_no_hardware: Not implemented in OSCreateStatisticEntry:../../third_party/imgtec-pvr-rgx-km/services/server/env/fuchsia/osfunc.cc:846
[03523.918] 02494.02517> img_rgx_no_hardware: Not implemented in OSCreateStatisticEntry:../../third_party/imgtec-pvr-rgx-km/services/server/env/fuchsia/osfunc.cc:846
[03523.918] 02494.02517> img_rgx_no_hardware: Not implemented in OSPlatformBridgeInit:../../third_party/imgtec-pvr-rgx-km/services/server/env/fuchsia/pvr_bridge_k.cc:48
[03523.919] 02494.02517> img_rgx_no_hardware: Not implemented in OSCreateStatisticEntry:../../third_party/imgtec-pvr-rgx-km/services/server/env/fuchsia/osfunc.cc:846
[03523.919] 02494.02517> img_rgx_no_hardware: Not implemented in OSSetThreadPriority:../../third_party/imgtec-pvr-rgx-km/services/server/env/fuchsia/osfunc.cc:609
[03523.919] 01124.01139> devcoordinator: fallback driver 'intel_disp' is available
[03523.919] 01124.01139> devcoordinator: driver 'intel_disp' added
[03523.919] 02494.02517> img_rgx_no_hardware: Not implemented in OSSetThreadPriority:../../third_party/imgtec-pvr-rgx-km/services/server/env/fuchsia/osfunc.cc:609
[03523.919] 02494.02517> img_rgx_no_hardware: Not implemented in OSCreateStatisticEntry:../../third_party/imgtec-pvr-rgx-km/services/server/env/fuchsia/osfunc.cc:846
[03523.941] 03422.03448> UMS: parent: 'ifc-000'
[03523.941] 03422.03448> UMS:Max lun is: 0
[03523.942] 03422.03448> devhost[00:14.0/xhci/usb-bus/002/002/ifc-001] bind driver '/boot/driver/bt-transport-usb.so' failed: -2
[03523.942] 01124.01139> devcoordinator: rpc: bind-driver 'ifc-001' status -2
[03523.945] 03422.06710> UMS: block size is: 0x00000200
[03523.945] 03422.06710> UMS: total blocks is: 15630336
[03523.945] 03422.06710> UMS: total size is: 8002732032
[03523.945] 03422.06710> UMS: read-only: 0 removable: 1
[03523.978] 03422.06865> btintel: firmware already loaded
[03523.978] 03422.06875> hci_read_thread: failed to read from command channel ZX_ERR_PEER_CLOSED
[03523.978] 03422.06875> hci_read_thread: failed to read from ACL channel ZX_ERR_PEER_CLOSED
[03523.978] 03422.06875> bt-transport-usb: all channels closed - exiting
[03523.979] 03422.07179> [INFO:command_channel.cc(148)] hci: initialized
[03523.980] 01339.01353> fshost: Binding: /boot/driver/mbr.so
[03523.980] 03422.03448> DeviceControllerBind running: /boot/driver/mbr.so
[03523.980] 01124.01139> devcoordinator: rpc: bind-device 'block'
[03523.980] 03422.03448> DeviceControllerBind finished: /boot/driver/mbr.so ZX_OK
[03523.982] 01339.01353> fshost: (/dev/class/block/008) failed: ZX_ERR_NOT_FOUND
[03523.983] 01339.01353> fshost: Binding: /boot/driver/mbr.so
[03523.983] 03422.03448> DeviceControllerBind running: /boot/driver/mbr.so
[03523.983] 01124.01139> devcoordinator: rpc: bind-device 'block'
[03523.983] 03422.03448> DeviceControllerBind finished: /boot/driver/mbr.so ZX_OK
[03523.991] 05791.05805> [INFO:namespace_builder.cc(44)] config-data for amber
[03523.999] 03422.07179> [INFO:acl_data_channel.cc(91)] hci: initialized
[03524.022] 07997.08009> [03524.022874][1230184835][0][netstack] INFO: netstack.go(668): NIC lo added [sniff = false]
[03524.023] 07997.08225> [03524.023260][1230184835][0][netstack] WARNING: main.go(148): OnInterfacesChanged failed: ErrBadHandle: zx.Channel.Write
[03524.040] 05791.05805> [INFO:namespace_builder.cc(44)] config-data for pkg_resolver
[03524.115] 08745.08757> [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
[03524.115] 08745.08757> kfill_days=2, start_event_aggregator_worker=1.
[03524.137] 05791.05805> [INFO:namespace_builder.cc(44)] config-data for mdns
[03524.172] 05791.05805> [INFO:namespace_builder.cc(44)] config-data for wlancfg
[03524.273] 05791.05805> [INFO:namespace_builder.cc(44)] config-data for crashpad_agent
[03524.290] 11315.11330> [INFO:main.cc(35)] Trace Manager starting with config: /pkg/data/tracing.config
[03524.309] 10140.10153> [INFO:system_metrics_main.cc(23)] Cobalt SystemMetricsDaemon: System metrics daemon created.
[03524.309] 07997.08009> [03524.309870][1230184835][0][netstack] INFO: netstack.go(668): NIC ethp001f6 added [sniff = false]
[03524.309] 07997.08009> [03524.309927][1230184835][0][netstack] INFO: netstack.go(694): NIC ethp001f6: link-local IPv6: fe80::d65d:dfff:fe07:be7e
[03524.310] 07997.08009> [03524.310195][1230184835][0][netstack] INFO: netstack.go(434): NIC ethp001f6: stopped
[03524.334] 07997.08260> [03524.334858][1230184835][0][netstack] WARNING: netstack.go(540): getNodeName: device settings error: key not set
[03524.336] 03422.07179> [WARN:bredr_discovery_manager.cc(480)] gap-bredr: write inquiry scan activity failed: [status: invalid HCI command parameters (HCI 0x12)]
[03524.336] 11881.11900> wlanstack [I]: Starting
[03524.337] 07997.08229> [03524.337364][1230184835][0][netstack] WARNING: netstack.go(540): getNodeName: device settings error: key not set
[03524.343] 07997.08219> [03524.343545][1230184835][0][netstack] WARNING: netstack.go(540): getNodeName: device settings error: key not set
[03524.367] 07997.08265> [03524.367378][1230184835][0][netstack] INFO: netstack.go(455): NIC ethp001f6: starting
IPv4 address of upper-stoop-folk-grape found: 192.168.42.113
environment of subprocess:
[FUCHSIA_TEST_OUTDIR=/b/s/w/iouMKQUf BUILDBUCKET_ID=8912768060757274752 SWARMING_SERVER=
https://chromium-swarm.appspot.com CIPD_PROTOCOL=v2 SWARMING_EXTERNAL_BOT_SETUP=1 HOSTNAME=fuchsia-tests-x64-lab01-0003--upper-stoop-folk-grape SWARMING_HEADLESS=1 SWARMING_TASK_ID=44f7ef9c40a9a011 NO_GCE_CHECK=False DEBIAN_FRONTEND=noninteractive BOTO_CONFIG=/home/swarming/.boto SWARMING_BOT_ID=fuchsia-tests-x64-lab01-0003--upper-stoop-folk-grape LUCI_CONTEXT=/b/s/w/itWCWMBU/luci_ctx.1TlczH.json HOME=/home/swarming CIPD_CACHE_DIR=/b/s/cipd_cache/cache TMPDIR=/b/s/w/itWCWMBU PATH=/b/s/cipd_cache/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin FUCHSIA_NODENAME=upper-stoop-folk-grape FUCHSIA_IPV4_ADDR=192.168.42.113 FUCHSIA_SSH_KEY=/etc/botanist/keys/pkey_infra]
TAP version 13
1..326
[03524.428] 07997.08260> [03524.428870][1230184835][0][netstack] INFO: netstack.go(373): NIC ethp001f6: DHCP acquired IP 192.168.42.113 for 240h0m0s
[03524.428] 07997.08260> [03524.428901][1230184835][0][netstack] INFO: netstack.go(374): NIC ethp001f6: Adding DNS servers: [8.8.8.8]
[03524.429] 07997.08260> [03524.428925][1230184835][0][netstack] INFO: netstack.go(384): adding routes [{Destination:0.0.0.0 Mask:0.0.0.0 Gateway:192.168.42.1 NIC:2} {Destination::: Mask::: Gateway: NIC:2} {Destination:192.168.42.0 Mask:255.255.255.
[03524.429] 07997.08260> 0 Gateway: NIC:2}] with metric=<not-set> dynamic=true
[03525.110] 07997.08229> [03525.110035][1230184835][0][netstack] INFO: socket_conv.go(523): unimplemented setsockopt: SOL_IPV6 name=67 optVal=20000000
[03525.110] 12666.12678> setsockopt IPV6_TCLASS 32: Protocol not available:
[03525.170] 07997.12773> [03525.170741][1230184835][0][netstack] INFO: socket_conv.go(523): unimplemented setsockopt: SOL_IPV6 name=67 optVal=20000000
[03525.170] 13026.13045> setsockopt IPV6_TCLASS 32: Protocol not available:
[03525.339] 09271.09284> Starting mDNS on interface ethp001f6 192.168.42.113 using port 5356
[03525.340] 09271.09284> [WARNING:src/connectivity/network/mdns/service/mdns_interface_transceiver_v4.cc(68)] NET-2177 IP_TTL not supported (ENOPROTOOPT), continuing anyway. May cause spurious IP traffic
[03525.340] 09271.09284> Starting mDNS on interface ethp001f6 fe80::d65d:dfff:fe07:be7e using port 5356
[03525.340] 07997.08219> [03525.340523][1230184835][0][netstack] INFO: socket_conv.go(523): unimplemented setsockopt: SOL_IPV6 name=19 optVal=00
[03525.340] 09271.09284> [WARNING:src/connectivity/network/mdns/service/mdns_interface_transceiver_v6.cc(29)] NET-291 IPV6_MULTICAST_LOOP not supported (ENOPROTOOPT), continuing anyway
[03525.340] 09271.09284> [WARNING:src/connectivity/network/mdns/service/mdns_interface_transceiver_v6.cc(50)] NET-2180 IPV6_JOIN_GROUP returned ENODEV, mDNS will not communicate via IPV6
[03525.340] 09271.09284> Starting mDNS on interface ethp001f6 ff02::1:ff07:be7e using port 5356
[03525.341] 07997.08219> [03525.341037][1230184835][0][netstack] INFO: socket_conv.go(523): unimplemented setsockopt: SOL_IPV6 name=19 optVal=00
[03525.341] 09271.09284> [WARNING:src/connectivity/network/mdns/service/mdns_interface_transceiver_v6.cc(29)] NET-291 IPV6_MULTICAST_LOOP not supported (ENOPROTOOPT), continuing anyway
[03525.341] 09271.09284> [WARNING:src/connectivity/network/mdns/service/mdns_interface_transceiver_v6.cc(50)] NET-2180 IPV6_JOIN_GROUP returned ENODEV, mDNS will not communicate via IPV6
[03525.341] 09271.09284> mDNS: Verifying uniqueness of host name upper-stoop-folk-grape.local.
[03526.210] 09271.09284> mDNS: Using unique host name upper-stoop-folk-grape.local.
------------------------------------------------
RUNNING TEST: /pkgfs/packages/ime_service_tests/0/test/ime_service_unittests
running 49 tests
test index_convert::test::test_byte_to_char ... ok
test index_convert::test::test_byte_to_codeunit ... ok
test ime_service::test::test_inject_input_sends_action ... ok
test ime_service::test::test_visibility_service_sends_updates ... ok
test index_convert::test::test_char_to_byte ... ok
test ime_service::test::test_inject_input_updates_ime ... ok
test index_convert::test::test_codeunit_to_byte ... ok
test legacy_ime::tests::test_action ... ok
test legacy_ime::tests::test_cursor_left_on_inverted_selection ... ok
test legacy_ime::tests::test_cursor_left_on_selection ... ok
test legacy_ime::tests::test_cursor_right_on_selection ... ok
test legacy_ime::tests::test_cursor_word ... ok
test legacy_ime::tests::test_cursor_word_left ... ok
test legacy_ime::tests::test_cursor_word_left_no_words ... ok
test legacy_ime::tests::test_cursor_word_off_limits ... ok
test legacy_ime::tests::test_cursor_word_right ... ok
test legacy_ime::tests::test_cursor_word_right_no_words ... ok
test legacy_ime::tests::test_delete_backward_beginning_string ... ok
test legacy_ime::tests::test_delete_backward_empty_string ... ok
test legacy_ime::tests::test_delete_backward_first_char_selected ... ok
test legacy_ime::tests::test_delete_backward_emoji ... ok
test legacy_ime::tests::test_delete_backward_combining_diacritic ... ok
test legacy_ime::tests::test_delete_backward_flag ... ok
test legacy_ime::tests::test_delete_backward_end_string ... ok
test legacy_ime::tests::test_delete_forward_beginning_string ... ok
test legacy_ime::tests::test_delete_forward_combining_diacritic ... ok
test legacy_ime::tests::test_delete_forward_emoji ... ok
test legacy_ime::tests::test_delete_forward_empty_string ... ok
test legacy_ime::tests::test_delete_forward_end_string ... ok
test legacy_ime::tests::test_delete_forward_flag ... ok
test legacy_ime::tests::test_delete_forward_last_char_selected ... ok
test legacy_ime::tests::test_delete_no_selection ... ok
test legacy_ime::tests::test_delete_selection ... ok
test legacy_ime::tests::test_delete_selection_inverted ... ok
test legacy_ime::tests::test_delete_selection_out_of_bounds ... ok
test legacy_ime::tests::test_delete_with_zero_width_selection ... ok
test legacy_ime::tests::test_delete_with_zero_width_selection_at_end ... ok
test legacy_ime::tests::test_mock_ime_channels ... ok
test legacy_ime::tests::test_type_at_beginning ... ok
test legacy_ime::tests::test_set_state ... ok
test legacy_ime::tests::test_type_empty_string ... ok
test legacy_ime::tests::test_type_invalid_selection ... ok
test legacy_ime::tests::test_type_inverted_selection ... ok
test legacy_ime::tests::test_type_selection ... ok
test legacy_ime::tests::test_unicode_selection ... ok
test legacy_ime::tests::test_unicode_backspace ... ok
test multiplex::tests::forwards_content_requests_correctly ... ok
test multiplex::tests::queues_interleaving_edits_correctly ... ok
test test::test_external_text_field_implementation ... ok
test result: ok. 49 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
PASSED: /pkgfs/packages/ime_service_tests/0/test/ime_service_unittests passed
SUMMARY: Ran 1 tests: 0 failed (0.081 sec)
ok 1 //garnet/bin/ui:ime_service_bin_test (1.274206993s)
------------------------------------------------
RUNNING TEST: /pkgfs/packages/scenic_tests/0/test/gfx_apptests
Running main() from ../../third_party/googletest/googletest/src/gtest_main.cc
[==========] Running 4 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 4 tests from GfxSystemTest
[ RUN ] GfxSystemTest.CreateAndDestroySession
TEST_LOOP_RANDOM_SEED="423511205"
[INFO:gfx_system.cc(196)] No Vulkan found, but using a test-only "display".
[ OK ] GfxSystemTest.CreateAndDestroySession (0 ms)
[ RUN ] GfxSystemTest.ScheduleUpdateInOrder
TEST_LOOP_RANDOM_SEED="392885383"
[INFO:gfx_system.cc(196)] No Vulkan found, but using a test-only "display".
[ OK ] GfxSystemTest.ScheduleUpdateInOrder (1 ms)
[ RUN ] GfxSystemTest.ReleaseFences
TEST_LOOP_RANDOM_SEED="2080432344"
[INFO:gfx_system.cc(196)] No Vulkan found, but using a test-only "display".
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 1 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=16666667 wakeup_time=8666667 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=16666667 frame_number=0
[INFO:default_frame_scheduler.cc(189)] Calling RenderFrame presentation_time=16666667 frame_number=0
[WARNING:garnet/lib/ui/gfx/engine/default_frame_scheduler.cc(216)] RenderFrame failed. There may not be any calls to OnFrameRendered or OnFramePresented, and no callbacks may be invoked.
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 1 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1016666687 wakeup_time=1008666687 frame_number=1
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1016666687 frame_number=1
[INFO:default_frame_scheduler.cc(189)] Calling RenderFrame presentation_time=1016666687 frame_number=1
[WARNING:garnet/lib/ui/gfx/engine/default_frame_scheduler.cc(216)] RenderFrame failed. There may not be any calls to OnFrameRendered or OnFramePresented, and no callbacks may be invoked.
[ OK ] GfxSystemTest.ReleaseFences (0 ms)
[ RUN ] GfxSystemTest.AcquireAndReleaseFences
TEST_LOOP_RANDOM_SEED="4171837963"
[INFO:gfx_system.cc(196)] No Vulkan found, but using a test-only "display".
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 1 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1016666687 wakeup_time=1008666687 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1016666687 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1033333354 wakeup_time=1025333354 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1033333354 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1050000021 wakeup_time=1042000021 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1050000021 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1066666688 wakeup_time=1058666688 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1066666688 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1083333355 wakeup_time=1075333355 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1083333355 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1100000022 wakeup_time=1092000022 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1100000022 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1116666689 wakeup_time=1108666689 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1116666689 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1133333356 wakeup_time=1125333356 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1133333356 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1150000023 wakeup_time=1142000023 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1150000023 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1166666690 wakeup_time=1158666690 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1166666690 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1183333357 wakeup_time=1175333357 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1183333357 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1200000024 wakeup_time=1192000024 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1200000024 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1216666691 wakeup_time=1208666691 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1216666691 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1233333358 wakeup_time=1225333358 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1233333358 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1250000025 wakeup_time=1242000025 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1250000025 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1266666692 wakeup_time=1258666692 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1266666692 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1283333359 wakeup_time=1275333359 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1283333359 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1300000026 wakeup_time=1292000026 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1300000026 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1316666693 wakeup_time=1308666693 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1316666693 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1333333360 wakeup_time=1325333360 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1333333360 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1350000027 wakeup_time=1342000027 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1350000027 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1366666694 wakeup_time=1358666694 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1366666694 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1383333361 wakeup_time=1375333361 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1383333361 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1400000028 wakeup_time=1392000028 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1400000028 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1416666695 wakeup_time=1408666695 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1416666695 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1433333362 wakeup_time=1425333362 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1433333362 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1450000029 wakeup_time=1442000029 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1450000029 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1466666696 wakeup_time=1458666696 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1466666696 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1483333363 wakeup_time=1475333363 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1483333363 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1500000030 wakeup_time=1492000030 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1500000030 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1516666697 wakeup_time=1508666697 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1516666697 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1533333364 wakeup_time=1525333364 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1533333364 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1550000031 wakeup_time=1542000031 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1550000031 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1566666698 wakeup_time=1558666698 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1566666698 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1583333365 wakeup_time=1575333365 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1583333365 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1600000032 wakeup_time=1592000032 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1600000032 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1616666699 wakeup_time=1608666699 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1616666699 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1633333366 wakeup_time=1625333366 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1633333366 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1650000033 wakeup_time=1642000033 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1650000033 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1666666700 wakeup_time=1658666700 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1666666700 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1683333367 wakeup_time=1675333367 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1683333367 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1700000034 wakeup_time=1692000034 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1700000034 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1716666701 wakeup_time=1708666701 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1716666701 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1733333368 wakeup_time=1725333368 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1733333368 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1750000035 wakeup_time=1742000035 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1750000035 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1766666702 wakeup_time=1758666702 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1766666702 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1783333369 wakeup_time=1775333369 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1783333369 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1800000036 wakeup_time=1792000036 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1800000036 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1816666703 wakeup_time=1808666703 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1816666703 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1833333370 wakeup_time=1825333370 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1833333370 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1850000037 wakeup_time=1842000037 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1850000037 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1866666704 wakeup_time=1858666704 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1866666704 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1883333371 wakeup_time=1875333371 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1883333371 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1900000038 wakeup_time=1892000038 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1900000038 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1916666705 wakeup_time=1908666705 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1916666705 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1933333372 wakeup_time=1925333372 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1933333372 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1950000039 wakeup_time=1942000039 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1950000039 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1966666706 wakeup_time=1958666706 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1966666706 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1983333373 wakeup_time=1975333373 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1983333373 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=2000000040 wakeup_time=1992000040 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=2000000040 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
PASSED: /pkgfs/packages/scenic_tests/0/test/gfx_apptests passed
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 1 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=2016666707 wakeup_time=2008666707 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=2016666707 frame_number=0
[INFO:default_frame_scheduler.cc(189)] Calling RenderFrame presentation_time=2016666707 frame_number=0
[WARNING:garnet/lib/ui/gfx/engine/default_frame_scheduler.cc(216)] RenderFrame failed. There may not be any calls to OnFrameRendered or OnFramePresented, and no callbacks may be invoked.
[ OK ] GfxSystemTest.AcquireAndReleaseFences (3 ms)
[----------] 4 tests from GfxSystemTest (4 ms total)
[----------] Global test environment tear-down
[==========] 4 tests from 1 test suite ran. (4 ms total)
[ PASSED ] 4 tests.
[03527.723] 05791.05805> [WARNING:garnet/bin/appmgr/service_provider_dir_impl.cc(127)] Component fuchsia-pkg://fuchsia.com/scenic_tests#meta/gfx_apptests.cmx is not allowed to connect to fuchsia.sysmem.Allocator because this service is not present i
[03527.723] 05791.05805> n the component's sandbox.
[03527.723] 05791.05805> Refer to
https://fuchsia.googlesource.com/fuchsia/+/master/docs/the-book/sandboxing.md#services for more information.
[03527.723] 05791.05805> [WARNING:garnet/bin/appmgr/service_provider_dir_impl.cc(127)] Component fuchsia-pkg://fuchsia.com/scenic_tests#meta/gfx_apptests.cmx is not allowed to connect to fuchsia.sysmem.Allocator because this service is not present i
[03527.723] 05791.05805> n the component's sandbox.
[03527.723] 05791.05805> Refer to
https://fuchsia.googlesource.com/fuchsia/+/master/docs/the-book/sandboxing.md#services for more information.
[03527.724] 05791.05805> [WARNING:garnet/bin/appmgr/service_provider_dir_impl.cc(127)] Component fuchsia-pkg://fuchsia.com/scenic_tests#meta/gfx_apptests.cmx is not allowed to connect to fuchsia.sysmem.Allocator because this service is not present i
[03527.724] 05791.05805> n the component's sandbox.
[03527.724] 05791.05805> Refer to
https://fuchsia.googlesource.com/fuchsia/+/master/docs/the-book/sandboxing.md#services for more information.
[03527.724] 05791.05805> [WARNING:garnet/bin/appmgr/service_provider_dir_impl.cc(127)] Component fuchsia-pkg://fuchsia.com/scenic_tests#meta/gfx_apptests.cmx is not allowed to connect to fuchsia.sysmem.Allocator because this service is not present i
[03527.724] 05791.05805> n the component's sandbox.
[03527.724] 05791.05805> Refer to
https://fuchsia.googlesource.com/fuchsia/+/master/docs/the-book/sandboxing.md#services for more information.
SUMMARY: Ran 1 tests: 0 failed (0.101 sec)
ok 2 //garnet/bin/ui:gfx_apptests (1.29301333s)
------------------------------------------------
RUNNING TEST: /pkgfs/packages/scenic_tests/0/test/gfx_pixeltests
[03529.031] 05791.05805> [WARNING:garnet/bin/appmgr/service_provider_dir_impl.cc(127)] Component fuchsia-pkg://fuchsia.com/scenic_tests#meta/gfx_pixeltests.cmx is not allowed to connect to fuchsia.tracelink.Registry because this service is not prese
[03529.031] 05791.05805> nt in the component's sandbox.
[03529.031] 05791.05805> Refer to
https://fuchsia.googlesource.com/fuchsia/+/master/docs/the-book/sandboxing.md#services for more information.
[03529.085] 05791.05805> [INFO:namespace_builder.cc(44)] config-data for root_presenter
Running main() from ../../third_party/googletest/googletest/src/gtest_main.cc
[==========] Running 8 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 8 tests from ScenicPixelTest
[ RUN ] ScenicPixelTest.SolidColor
[INFO:display_watcher.cc(40)] Scenic: Acquired display controller /dev/class/display-controller/000.(000)
[INFO:input_interpreter.cc(398)] Can't process HID report descriptor for 000; All parsing attempts failed.
[INFO:main.cc(35)] Trace Manager starting with config: /pkg/data/tracing.config
[INFO:input_system.cc(203)] Scenic input system initialized.
[ERROR:garnet/lib/ui/input/input_system.cc(200)] Scenic lost connection to TextSync
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 1 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:input_system.cc(556)] Scenic: Parallel dispatch is turned OFF
[WARNING:garnet/bin/ui/root_presenter/displays/display_configuration.cc(79)] RootPresenter: unrecognized display.
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 2 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 2 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 2 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=3529204359355 wakeup_time=3529196359355 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=3529204359355 frame_number=0
[INFO:default_frame_scheduler.cc(189)] Calling RenderFrame presentation_time=3529204359355 frame_number=0
[INFO:background_view.cc(61)] OnScenicEvent
[INFO:background_view.cc(81)] Metrics: 1117.09x628.364x1000
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 1 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(281)] DefaultFrameScheduler::OnFramePresented frame_number=0
[03529.265] 03364.03378> DdkClose
[03529.267] 03364.04831> Failed to send vsync event -24
[03529.321] 05791.05805> [INFO:namespace_builder.cc(44)] config-data for root_presenter
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=3529221026022 wakeup_time=3529213026022 frame_number=1
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=3529221026022 frame_number=1
[INFO:default_frame_scheduler.cc(189)] Calling RenderFrame presentation_time=3529221026022 frame_number=1
[INFO:default_frame_scheduler.cc(281)] DefaultFrameScheduler::OnFramePresented frame_number=1
[ OK ] ScenicPixelTest.SolidColor (228 ms)
[ RUN ] ScenicPixelTest.NV12Texture
[INFO:display_watcher.cc(40)] Scenic: Acquired display controller /dev/class/display-controller/000.(000)
[INFO:input_interpreter.cc(398)] Can't process HID report descriptor for 000; All parsing attempts failed.
[INFO:main.cc(35)] Trace Manager starting with config: /pkg/data/tracing.config
[INFO:input_system.cc(203)] Scenic input system initialized.
[ERROR:garnet/lib/ui/input/input_system.cc(200)] Scenic lost connection to TextSync
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 1 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:input_system.cc(556)] Scenic: Parallel dispatch is turned OFF
[WARNING:garnet/bin/ui/root_presenter/displays/display_configuration.cc(79)] RootPresenter: unrecognized display.
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 2 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 2 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 2 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=3529458667002 wakeup_time=3529450667002 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=3529458667002 frame_number=0
[INFO:default_frame_scheduler.cc(189)] Calling RenderFrame presentation_time=3529458667002 frame_number=0
[03529.520] 03364.03378> DdkClose
[03529.521] 03364.04831> Failed to send vsync event -24
[INFO:background_view.cc(61)] OnScenicEvent
[INFO:background_view.cc(81)] Metrics: 1117.09x628.364x1000
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 1 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(281)] DefaultFrameScheduler::OnFramePresented frame_number=0
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=3529475333669 wakeup_time=3529467333669 frame_number=1
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=3529475333669 frame_number=1
[INFO:default_frame_scheduler.cc(189)] Calling RenderFrame presentation_time=3529475333669 frame_number=1
[INFO:descriptor_set_allocator.cc(86)] Allocating immutable descriptor set layout, sampler = 0x95ee3a84ff0
[INFO:default_frame_scheduler.cc(281)] DefaultFrameScheduler::OnFramePresented frame_number=1
[ OK ] ScenicPixelTest.NV12Texture (254 ms)
[ RUN ] ScenicPixelTest.ViewCoordinates
[INFO:display_watcher.cc(40)] Scenic: Acquired display controller /dev/class/display-controller/000.(000)
[INFO:main.cc(35)] Trace Manager starting with config: /pkg/data/tracing.config
[INFO:input_system.cc(203)] Scenic input system initialized.
[ERROR:garnet/lib/ui/input/input_system.cc(200)] Scenic lost connection to TextSync
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 1 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=3529684592924 wakeup_time=3529676592924 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=3529684592924 frame_number=0
[INFO:default_frame_scheduler.cc(189)] Calling RenderFrame presentation_time=3529684592924 frame_number=0
[WARNING:garnet/lib/ui/gfx/engine/default_frame_scheduler.cc(216)] RenderFrame failed. There may not be any calls to OnFrameRendered or OnFramePresented, and no callbacks may be invoked.
[INFO:input_interpreter.cc(398)] Can't process HID report descriptor for 000; All parsing attempts failed.
[INFO:input_system.cc(556)] Scenic: Parallel dispatch is turned OFF
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 2 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[WARNING:garnet/bin/ui/root_presenter/displays/display_configuration.cc(79)] RootPresenter: unrecognized display.
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 2 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 2 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=3529701259591 wakeup_time=3529693259591 frame_number=1
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=3529701259591 frame_number=1
[INFO:default_frame_scheduler.cc(189)] Calling RenderFrame presentation_time=3529701259591 frame_number=1
[INFO:background_view.cc(61)] OnScenicEvent
[INFO:background_view.cc(81)] Metrics: 0x0x0
[INFO:background_view.cc(81)] Metrics: 1117.09x628.364x1000
[03529.679] 05791.05805> [INFO:namespace_builder.cc(44)] config-data for root_presenter
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 1 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=3529717926258 wakeup_time=3529709926258 frame_number=2
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=3529717926258 frame_number=2
[INFO:default_frame_scheduler.cc(281)] DefaultFrameScheduler::OnFramePresented frame_number=1
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=3529727444726 wakeup_time=3529719444726 frame_number=2
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=3529727444726 frame_number=2
[INFO:default_frame_scheduler.cc(189)] Calling RenderFrame presentation_time=3529727444726 frame_number=2
[INFO:default_frame_scheduler.cc(281)] DefaultFrameScheduler::OnFramePresented frame_number=2
[ OK ] ScenicPixelTest.ViewCoordinates (235 ms)
[ RUN ] ScenicPixelTest.GlobalCoordinates
[03529.754] 03364.03378> DdkClose
[03529.755] 03364.04831> Failed to send vsync event -24
[INFO:display_watcher.cc(40)] Scenic: Acquired display controller /dev/class/display-controller/000.(000)
[INFO:main.cc(35)] Trace Manager starting with config: /pkg/data/tracing.config
[INFO:input_system.cc(203)] Scenic input system initialized.
[ERROR:garnet/lib/ui/input/input_system.cc(200)] Scenic lost connection to TextSync
[INFO:scenic_pixel_test.cc(386)] Testing orthographic camera
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 1 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=3529921043243 wakeup_time=3529913043243 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=3529921043243 frame_number=0
[INFO:default_frame_scheduler.cc(189)] Calling RenderFrame presentation_time=3529921043243 frame_number=0
[INFO:default_frame_scheduler.cc(281)] DefaultFrameScheduler::OnFramePresented frame_number=0
[INFO:scenic_pixel_test.cc(386)] Testing perspective camera
[03529.984] 03364.03378> DdkClose
[03529.984] 03364.04831> Failed to send vsync event -24
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 1 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=3529960785794 wakeup_time=3529952785794 frame_number=1
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=3529960785794 frame_number=1
[INFO:default_frame_scheduler.cc(189)] Calling RenderFrame presentation_time=3529960785794 frame_number=1
[INFO:default_frame_scheduler.cc(281)] DefaultFrameScheduler::OnFramePresented frame_number=1
[ OK ] ScenicPixelTest.GlobalCoordinates (227 ms)
[ RUN ] ScenicPixelTest.StereoCamera
[INFO:display_watcher.cc(40)] Scenic: Acquired display controller /dev/class/display-controller/000.(000)
[INFO:main.cc(35)] Trace Manager starting with config: /pkg/data/tracing.config
[INFO:input_system.cc(203)] Scenic input system initialized.
[ERROR:garnet/lib/ui/input/input_system.cc(200)] Scenic lost connection to TextSync
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 1 presentation_time: 0
[03530.182] 03364.03378> DdkClose
[03530.183] 03364.04831> Failed to send vsync event -24
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=3530150079251 wakeup_time=3530142079251 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=3530150079251 frame_number=0
[INFO:default_frame_scheduler.cc(189)] Calling RenderFrame presentation_time=3530150079251 frame_number=0
[INFO:default_frame_scheduler.cc(281)] DefaultFrameScheduler::OnFramePresented frame_number=0
[ OK ] ScenicPixelTest.StereoCamera (200 ms)
[ RUN ] ScenicPixelTest.PoseBuffer
[INFO:display_watcher.cc(40)] Scenic: Acquired display controller /dev/class/display-controller/000.(000)
[INFO:main.cc(35)] Trace Manager starting with config: /pkg/data/tracing.config
[INFO:input_system.cc(203)] Scenic input system initialized.
[ERROR:garnet/lib/ui/input/input_system.cc(200)] Scenic lost connection to TextSync
[ERROR:garnet/lib/ui/gfx/tests/scenic_pixel_test.cc(733)] translation: vec3(960.000000, 540.000000, -375.000000)
[ERROR:garnet/lib/ui/gfx/tests/scenic_pixel_test.cc(734)] orientation: quat(0.000000, 0.000000, 0.000000, 1.000000)
[ERROR:garnet/lib/ui/gfx/tests/scenic_pixel_test.cc(733)] translation: vec3(960.000000, 540.000000, -625.000000)
[ERROR:garnet/lib/ui/gfx/tests/scenic_pixel_test.cc(734)] orientation: quat(1.000000, 0.000000, 0.000000, -0.000000)
[ERROR:garnet/lib/ui/gfx/tests/scenic_pixel_test.cc(733)] translation: vec3(835.000000, 540.000000, -500.000000)
[ERROR:garnet/lib/ui/gfx/tests/scenic_pixel_test.cc(734)] orientation: quat(-0.000000, -0.707107, -0.000000, 0.707107)
[ERROR:garnet/lib/ui/gfx/tests/scenic_pixel_test.cc(733)] translation: vec3(1085.000000, 540.000000, -500.000000)
[ERROR:garnet/lib/ui/gfx/tests/scenic_pixel_test.cc(734)] orientation: quat(0.000000, 0.707107, 0.000000, 0.707107)
[ERROR:garnet/lib/ui/gfx/tests/scenic_pixel_test.cc(733)] translation: vec3(960.000000, 415.000000, -500.000000)
[ERROR:garnet/lib/ui/gfx/tests/scenic_pixel_test.cc(734)] orientation: quat(0.707107, 0.000000, 0.000000, 0.707107)
[ERROR:garnet/lib/ui/gfx/tests/scenic_pixel_test.cc(733)] translation: vec3(960.000000, 665.000000, -500.000000)
[ERROR:garnet/lib/ui/gfx/tests/scenic_pixel_test.cc(734)] orientation: quat(-0.707107, -0.000000, -0.000000, 0.707107)
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 1 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=3530529407766 wakeup_time=3530521407766 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=3530529407766 frame_number=0
[INFO:default_frame_scheduler.cc(189)] Calling RenderFrame presentation_time=3530529407766 frame_number=0
[INFO:default_frame_scheduler.cc(281)] DefaultFrameScheduler::OnFramePresented frame_number=0
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 1 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=3530610786701 wakeup_time=3530602786701 frame_number=1
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=3530610786701 frame_number=1
[INFO:default_frame_scheduler.cc(189)] Calling RenderFrame presentation_time=3530610786701 frame_number=1
[INFO:default_frame_scheduler.cc(281)] DefaultFrameScheduler::OnFramePresented frame_number=1
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 1 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=3530644119212 wakeup_time=3530636119212 frame_number=2
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=3530644119212 frame_number=2
[INFO:default_frame_scheduler.cc(189)] Calling RenderFrame presentation_time=3530644119212 frame_number=2
[INFO:default_frame_scheduler.cc(281)] DefaultFrameScheduler::OnFramePresented frame_number=2
[INFO:default_frame_scheduler.cc(281)] DefaultFrameScheduler::OnFramePresented frame_number=3
[ OK ] ScenicPixelTest.PoseBuffer (665 ms)
[ RUN ] ScenicPixelTest.Opacity
[INFO:display_watcher.cc(40)] Scenic: Acquired display controller /dev/class/display-controller/000.(000)
[INFO:input_interpreter.cc(398)] Can't process HID report descriptor for 000; All parsing attempts failed.
[03530.850] 03364.03378> DdkClose
[03530.850] 03364.04831> Failed to send vsync event -24
[03530.904] 05791.05805> [INFO:namespace_builder.cc(44)] config-data for root_presenter
[INFO:main.cc(35)] Trace Manager starting with config: /pkg/data/tracing.config
[INFO:input_system.cc(203)] Scenic input system initialized.
[ERROR:garnet/lib/ui/input/input_system.cc(200)] Scenic lost connection to TextSync
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 1 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:input_system.cc(556)] Scenic: Parallel dispatch is turned OFF
[WARNING:garnet/bin/ui/root_presenter/displays/display_configuration.cc(79)] RootPresenter: unrecognized display.
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 2 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 2 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 2 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=3531041149233 wakeup_time=3531033149233 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=3531041149233 frame_number=0
[WARNING:garnet/lib/ui/gfx/resources/nodes/opacity_node.cc(17)] Opacity support is limited. Z sorting and shadows may not behave correctly.
[INFO:default_frame_scheduler.cc(189)] Calling RenderFrame presentation_time=3531041149233 frame_number=0
[INFO:opacity_view.cc(70)] OnScenicEvent
[INFO:opacity_view.cc(90)] Metrics: 1117.09x628.364x1000
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 1 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(281)] DefaultFrameScheduler::OnFramePresented frame_number=0
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=3531057815900 wakeup_time=3531049815900 frame_number=1
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=3531057815900 frame_number=1
[INFO:default_frame_scheduler.cc(189)] Calling RenderFrame presentation_time=3531057815900 frame_number=1
[INFO:default_frame_scheduler.cc(281)] DefaultFrameScheduler::OnFramePresented frame_number=1
[ERROR:garnet/bin/ui/root_presenter/app.cc(268)] Root presenter: Content view terminated unexpectedly.
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 3 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[WARNING:garnet/bin/ui/root_presenter/displays/display_configuration.cc(79)] RootPresenter: unrecognized display.
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 2 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 2 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=3531110782768 wakeup_time=3531102782768 frame_number=2
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=3531110782768 frame_number=2
[WARNING:garnet/lib/ui/gfx/resources/nodes/opacity_node.cc(17)] Opacity support is limited. Z sorting and shadows may not behave correctly.
[03531.228] 03364.03378> DdkClose
[03531.229] 03364.04831> Failed to send vsync event -24
[INFO:default_frame_scheduler.cc(189)] Calling RenderFrame presentation_time=3531110782768 frame_number=2
[INFO:opacity_view.cc(70)] OnScenicEvent
[INFO:opacity_view.cc(90)] Metrics: 1117.09x628.364x1000
[INFO:default_frame_scheduler.cc(281)] DefaultFrameScheduler::OnFramePresented frame_number=2
[INFO:default_frame_scheduler.cc(281)] DefaultFrameScheduler::OnFramePresented frame_number=3
[ERROR:garnet/bin/ui/root_presenter/app.cc(268)] Root presenter: Content view terminated unexpectedly.
[WARNING:garnet/bin/ui/root_presenter/displays/display_configuration.cc(79)] RootPresenter: unrecognized display.
[WARNING:garnet/lib/ui/gfx/resources/nodes/opacity_node.cc(17)] Opacity support is limited. Z sorting and shadows may not behave correctly.
[INFO:opacity_view.cc(70)] OnScenicEvent
[INFO:opacity_view.cc(90)] Metrics: 1117.09x628.364x1000
[ OK ] ScenicPixelTest.Opacity (381 ms)
[ RUN ] ScenicPixelTest.RotationTest
[INFO:display_watcher.cc(40)] Scenic: Acquired display controller /dev/class/display-controller/000.(000)
[INFO:main.cc(35)] Trace Manager starting with config: /pkg/data/tracing.config
[INFO:input_system.cc(203)] Scenic input system initialized.
[ERROR:garnet/lib/ui/input/input_system.cc(200)] Scenic lost connection to TextSync
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 1 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=3531408205322 wakeup_time=3531400205322 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=3531408205322 frame_number=0
[INFO:default_frame_scheduler.cc(189)] Calling RenderFrame presentation_time=3531408205322 frame_number=0
[INFO:default_frame_scheduler.cc(281)] DefaultFrameScheduler::OnFramePresented frame_number=0
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 1 presentation_time: 1000000
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=3531460787559 wakeup_time=3531452787559 frame_number=1
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=3531460787559 frame_number=1
[INFO:default_frame_scheduler.cc(189)] Calling RenderFrame presentation_time=3531460787559 frame_number=1
[INFO:default_frame_scheduler.cc(281)] DefaultFrameScheduler::OnFramePresented frame_number=1
[ OK ] ScenicPixelTest.RotationTest (324 ms)
[----------] 8 tests from ScenicPixelTest (2514 ms total)
[----------] Global test environment tear-down
[==========] 8 tests from 1 test suite ran. (2514 ms total)
[ PASSED ] 8 tests.
YOU HAVE 1 DISABLED TEST
PASSED: /pkgfs/packages/scenic_tests/0/test/gfx_pixeltests passed
SUMMARY: Ran 1 tests: 0 failed (2.629 sec)
ok 3 //garnet/bin/ui:gfx_pixeltests (3.83834848s)
[03531.544] 03364.03378> DdkClose
[03531.545] 03364.04831> Failed to send vsync event -24
------------------------------------------------
RUNNING TEST: /pkgfs/packages/scenic_tests/0/test/gfx_viewstate_apptests
[03532.910] 05791.05805> [INFO:namespace_builder.cc(44)] config-data for root_presenter
Running main() from ../../third_party/googletest/googletest/src/gtest_main.cc
[==========] Running 1 test from 1 test suite.
[----------] Global test environment set-up.
[----------] 1 test from ViewEmbedderTest
[ RUN ] ViewEmbedderTest.BouncingBall
[INFO:display_watcher.cc(40)] Scenic: Acquired display controller /dev/class/display-controller/000.(000)
[INFO:input_interpreter.cc(398)] Can't process HID report descriptor for 000; All parsing attempts failed.
[INFO:main.cc(35)] Trace Manager starting with config: /pkg/data/tracing.config
[INFO:input_system.cc(203)] Scenic input system initialized.
[ERROR:garnet/lib/ui/input/input_system.cc(200)] Scenic lost connection to TextSync
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 1 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 1 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 2 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:input_system.cc(556)] Scenic: Parallel dispatch is turned OFF
[WARNING:garnet/bin/ui/root_presenter/displays/display_configuration.cc(79)] RootPresenter: unrecognized display.
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 3 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 3 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 3 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=3533096163966 wakeup_time=3533088163966 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=3533096163966 frame_number=0
[INFO:default_frame_scheduler.cc(189)] Calling RenderFrame presentation_time=3533096163966 frame_number=0
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 1 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=3533112830633 wakeup_time=3533104830633 frame_number=1
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=3533112830633 frame_number=1
[INFO:default_frame_scheduler.cc(281)] DefaultFrameScheduler::OnFramePresented frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 2 presentation_time: 3533127451005
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=3533127451005 wakeup_time=3533119451005 frame_number=1
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=3533127451005 frame_number=1
[INFO:default_frame_scheduler.cc(189)] Calling RenderFrame presentation_time=3533127451005 frame_number=1
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(281)] DefaultFrameScheduler::OnFramePresented frame_number=1
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=3533144117672 wakeup_time=3533136117672 frame_number=2
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=3533144117672 frame_number=2
[INFO:default_frame_scheduler.cc(189)] Calling RenderFrame presentation_time=3533144117672 frame_number=2
[ERROR:garnet/bin/ui/root_presenter/app.cc(268)] Root presenter: Content view terminated unexpectedly.
[ OK ] ViewEmbedderTest.BouncingBall (314 ms)
[----------] 1 test from ViewEmbedderTest (314 ms total)
[----------] Global test environment tear-down
[==========] 1 test from 1 test suite ran. (314 ms total)
[ PASSED ] 1 test.
PASSED: /pkgfs/packages/scenic_tests/0/test/gfx_viewstate_apptests passed
SUMMARY: Ran 1 tests: 0 failed (0.378 sec)
ok 4 //garnet/bin/ui:gfx_viewstate_apptests (1.585506547s)
[03533.147] 03364.03378> DdkClose
[03533.148] 03364.04831> Failed to send vsync event -24
------------------------------------------------
RUNNING TEST: /pkgfs/packages/scenic_tests/0/test/gfx_unittests
[==========] Running 156 tests from 29 test suites.
[----------] Global test environment set-up.
[----------] 1 test from CompositorTest
[ RUN ] CompositorTest.Validation
fidl channel writing error at ../../sdk/lib/fidl/cpp/internal/proxy_controller.cc:59: zx_status_t -24, type fuchsia.scheduler/ProfileProviderGetProfileRequest, 80 bytes, 0 handles
TEST_LOOP_RANDOM_SEED="271189938"
[ OK ] CompositorTest.Validation (0 ms)
[----------] 1 test from CompositorTest (0 ms total)
[----------] 10 tests from FrameSchedulerTest
[ RUN ] FrameSchedulerTest.PresentTimeZero_ShouldBeScheduledBeforeNextVsync
TEST_LOOP_RANDOM_SEED="4045442459"
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 1 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=100000000 wakeup_time=92000000 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=100000000 frame_number=0
[INFO:default_frame_scheduler.cc(189)] Calling RenderFrame presentation_time=100000000 frame_number=0
[INFO:default_frame_scheduler.cc(281)] DefaultFrameScheduler::OnFramePresented frame_number=0
[ OK ] FrameSchedulerTest.PresentTimeZero_ShouldBeScheduledBeforeNextVsync (0 ms)
[ RUN ] FrameSchedulerTest.PresentBiggerThanNextVsync_ShouldBeScheduledAfterNextVsync
TEST_LOOP_RANDOM_SEED="22720695"
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 1 presentation_time: 150000000
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=200000000 wakeup_time=192000000 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=200000000 frame_number=0
[INFO:default_frame_scheduler.cc(189)] Calling RenderFrame presentation_time=200000000 frame_number=0
[INFO:default_frame_scheduler.cc(281)] DefaultFrameScheduler::OnFramePresented frame_number=0
[ OK ] FrameSchedulerTest.PresentBiggerThanNextVsync_ShouldBeScheduledAfterNextVsync (0 ms)
[ RUN ] FrameSchedulerTest.SinglePresent_ShouldGetSingleRenderCall
TEST_LOOP_RANDOM_SEED="451108447"
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 1 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=100000000 wakeup_time=92000000 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=100000000 frame_number=0
[INFO:default_frame_scheduler.cc(189)] Calling RenderFrame presentation_time=100000000 frame_number=0
[INFO:default_frame_scheduler.cc(281)] DefaultFrameScheduler::OnFramePresented frame_number=0
[ OK ] FrameSchedulerTest.SinglePresent_ShouldGetSingleRenderCall (0 ms)
[ RUN ] FrameSchedulerTest.PresentsForTheSameFrame_ShouldGetSingleRenderCall
TEST_LOOP_RANDOM_SEED="429241557"
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 1 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 2 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=100000000 wakeup_time=92000000 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=100000000 frame_number=0
[INFO:default_frame_scheduler.cc(189)] Calling RenderFrame presentation_time=100000000 frame_number=0
[INFO:default_frame_scheduler.cc(281)] DefaultFrameScheduler::OnFramePresented frame_number=0
[ OK ] FrameSchedulerTest.PresentsForTheSameFrame_ShouldGetSingleRenderCall (1 ms)
[ RUN ] FrameSchedulerTest.PresentsForDifferentFrames_ShouldGetSeparateRenderCalls
TEST_LOOP_RANDOM_SEED="4240552465"
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 1 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 1 presentation_time: 150000000
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=100000000 wakeup_time=92000000 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=100000000 frame_number=0
[INFO:default_frame_scheduler.cc(189)] Calling RenderFrame presentation_time=100000000 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(281)] DefaultFrameScheduler::OnFramePresented frame_number=0
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=200000000 wakeup_time=192000000 frame_number=1
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=200000000 frame_number=1
[INFO:default_frame_scheduler.cc(189)] Calling RenderFrame presentation_time=200000000 frame_number=1
[ OK ] FrameSchedulerTest.PresentsForDifferentFrames_ShouldGetSeparateRenderCalls (0 ms)
[ RUN ] FrameSchedulerTest.SecondPresentDuringRender_ShouldApplyUpdatesAndReschedule
TEST_LOOP_RANDOM_SEED="1615869159"
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 1 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=100000000 wakeup_time=92000000 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=100000000 frame_number=0
[INFO:default_frame_scheduler.cc(189)] Calling RenderFrame presentation_time=100000000 frame_number=0
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 1 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=200000000 wakeup_time=192000000 frame_number=1
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=200000000 frame_number=1
[INFO:default_frame_scheduler.cc(281)] DefaultFrameScheduler::OnFramePresented frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=300000000 wakeup_time=292000000 frame_number=1
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=300000000 frame_number=1
[INFO:default_frame_scheduler.cc(189)] Calling RenderFrame presentation_time=300000000 frame_number=1
[INFO:default_frame_scheduler.cc(281)] DefaultFrameScheduler::OnFramePresented frame_number=1
[ OK ] FrameSchedulerTest.SecondPresentDuringRender_ShouldApplyUpdatesAndReschedule (0 ms)
[ RUN ] FrameSchedulerTest.RenderCalls_ShouldNotExceed_MaxOutstandingFrames
TEST_LOOP_RANDOM_SEED="3984162580"
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 1 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=100000000 wakeup_time=92000000 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=100000000 frame_number=0
[INFO:default_frame_scheduler.cc(189)] Calling RenderFrame presentation_time=100000000 frame_number=0
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 1 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=600000000 wakeup_time=592000000 frame_number=1
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=600000000 frame_number=1
[ OK ] FrameSchedulerTest.RenderCalls_ShouldNotExceed_MaxOutstandingFrames (0 ms)
[ RUN ] FrameSchedulerTest.SignalSuccessfulPresentCallbackOnlyWhenFramePresented
TEST_LOOP_RANDOM_SEED="2159408319"
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 1 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=100000000 wakeup_time=92000000 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=100000000 frame_number=0
[INFO:default_frame_scheduler.cc(189)] Calling RenderFrame presentation_time=100000000 frame_number=0
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 1 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=200000000 wakeup_time=192000000 frame_number=1
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=200000000 frame_number=1
[INFO:default_frame_scheduler.cc(281)] DefaultFrameScheduler::OnFramePresented frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=400000000 wakeup_time=392000000 frame_number=1
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=400000000 frame_number=1
[INFO:default_frame_scheduler.cc(189)] Calling RenderFrame presentation_time=400000000 frame_number=1
[INFO:default_frame_scheduler.cc(281)] DefaultFrameScheduler::OnFramePresented frame_number=1
[ OK ] FrameSchedulerTest.SignalSuccessfulPresentCallbackOnlyWhenFramePresented (0 ms)
[ RUN ] FrameSchedulerTest.FailedUpdate_ShouldNotTriggerRenderCall
TEST_LOOP_RANDOM_SEED="1097324100"
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 1 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=100000000 wakeup_time=92000000 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=100000000 frame_number=0
[ OK ] FrameSchedulerTest.FailedUpdate_ShouldNotTriggerRenderCall (0 ms)
[ RUN ] FrameSchedulerTest.NoOpUpdateWithSecondPendingUpdate_ShouldBeRescheduled
TEST_LOOP_RANDOM_SEED="3293226574"
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 1 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 1 presentation_time: 100000000
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=100000000 wakeup_time=92000000 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=100000000 frame_number=0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=200000000 wakeup_time=192000000 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=200000000 frame_number=0
[INFO:default_frame_scheduler.cc(189)] Calling RenderFrame presentation_time=200000000 frame_number=0
[ OK ] FrameSchedulerTest.NoOpUpdateWithSecondPendingUpdate_ShouldBeRescheduled (0 ms)
[----------] 10 tests from FrameSchedulerTest (1 ms total)
[----------] 7 tests from DurationPredictor
[ RUN ] DurationPredictor.FirstPredictionIsInitialPrediction
[ OK ] DurationPredictor.FirstPredictionIsInitialPrediction (0 ms)
[ RUN ] DurationPredictor.PredictionAfterWindowFlushIsMeasurement
[ OK ] DurationPredictor.PredictionAfterWindowFlushIsMeasurement (0 ms)
[ RUN ] DurationPredictor.PredictionIsSmallestInWindowAsMeasurementsIncrease
[ OK ] DurationPredictor.PredictionIsSmallestInWindowAsMeasurementsIncrease (0 ms)
[ RUN ] DurationPredictor.PredictionIsSmallestInWindowAsMeasurementsDecrease
[ OK ] DurationPredictor.PredictionIsSmallestInWindowAsMeasurementsDecrease (0 ms)
[ RUN ] DurationPredictor.PredictionIsSmallestInWindow
[ OK ] DurationPredictor.PredictionIsSmallestInWindow (0 ms)
[ RUN ] DurationPredictor.MinIsResetWhenSmallestIsOutOfWindow
[ OK ] DurationPredictor.MinIsResetWhenSmallestIsOutOfWindow (0 ms)
[ RUN ] DurationPredictor.WindowSizeOfOneWorks
[ OK ] DurationPredictor.WindowSizeOfOneWorks (0 ms)
[----------] 7 tests from DurationPredictor (0 ms total)
[----------] 1 test from EscherVulkanSmokeTest
[ RUN ] EscherVulkanSmokeTest.OnlyIfSupported
[ OK ] EscherVulkanSmokeTest.OnlyIfSupported (0 ms)
[----------] 1 test from EscherVulkanSmokeTest (0 ms total)
[----------] 1 test from EventTimestamperTest
[ RUN ] EventTimestamperTest.WatchingState
[ OK ] EventTimestamperTest.WatchingState (10 ms)
[----------] 1 test from EventTimestamperTest (10 ms total)
[----------] 8 tests from FramePredictorTest
[ RUN ] FramePredictorTest.BasicPredictions_ShouldBeReasonable
TEST_LOOP_RANDOM_SEED="1419331920"
[ OK ] FramePredictorTest.BasicPredictions_ShouldBeReasonable (0 ms)
[ RUN ] FramePredictorTest.PredictionsAfterUpdating_ShouldBeMoreReasonable
TEST_LOOP_RANDOM_SEED="3297499401"
[ OK ] FramePredictorTest.PredictionsAfterUpdating_ShouldBeMoreReasonable (1 ms)
[ RUN ] FramePredictorTest.OneExpensiveTime_ShouldNotPredictForFutureVsyncIntervals
TEST_LOOP_RANDOM_SEED="891147338"
[ OK ] FramePredictorTest.OneExpensiveTime_ShouldNotPredictForFutureVsyncIntervals (0 ms)
[ RUN ] FramePredictorTest.ManyExpensiveTimes_ShouldPredictForFutureVsyncIntervals
TEST_LOOP_RANDOM_SEED="3569475808"
[ OK ] FramePredictorTest.ManyExpensiveTimes_ShouldPredictForFutureVsyncIntervals (0 ms)
[ RUN ] FramePredictorTest.ManyFramesOfPredictions_ShouldBeReasonable
TEST_LOOP_RANDOM_SEED="2726806362"
[ OK ] FramePredictorTest.ManyFramesOfPredictions_ShouldBeReasonable (0 ms)
[ RUN ] FramePredictorTest.MissedLastVsync_ShouldPredictWithInterval
TEST_LOOP_RANDOM_SEED="4008837215"
[ OK ] FramePredictorTest.MissedLastVsync_ShouldPredictWithInterval (0 ms)
[ RUN ] FramePredictorTest.MissedPresentRequest_ShouldTargetNextVsync
TEST_LOOP_RANDOM_SEED="127176618"
[ OK ] FramePredictorTest.MissedPresentRequest_ShouldTargetNextVsync (0 ms)
[ RUN ] FramePredictorTest.AttemptsToBeLowLatent_ShouldBePossible
TEST_LOOP_RANDOM_SEED="478557495"
[ OK ] FramePredictorTest.AttemptsToBeLowLatent_ShouldBePossible (0 ms)
[----------] 8 tests from FramePredictorTest (1 ms total)
[----------] 6 tests from FrameTimingsTest
[ RUN ] FrameTimingsTest.ReceivingCallsInOrder_ShouldTriggerFrameSchedulerCallsInOrder
TEST_LOOP_RANDOM_SEED="3040697443"
[ OK ] FrameTimingsTest.ReceivingCallsInOrder_ShouldTriggerFrameSchedulerCallsInOrder (0 ms)
[ RUN ] FrameTimingsTest.ReceivingCallsOutOfOrder_ShouldTriggerFrameSchedulerCallsInOrder
TEST_LOOP_RANDOM_SEED="2457464494"
[ OK ] FrameTimingsTest.ReceivingCallsOutOfOrder_ShouldTriggerFrameSchedulerCallsInOrder (0 ms)
[ RUN ] FrameTimingsTest.ReceivingCallsAndTimesOutOfOrder_ShouldTriggerFrameSchedulerCallsInOrder
TEST_LOOP_RANDOM_SEED="1843619895"
[ OK ] FrameTimingsTest.ReceivingCallsAndTimesOutOfOrder_ShouldTriggerFrameSchedulerCallsInOrder (0 ms)
[ RUN ] FrameTimingsTest.ReceivingTimesOutOfOrder_ShouldRecordTimesInOrder
TEST_LOOP_RANDOM_SEED="2572447646"
[ OK ] FrameTimingsTest.ReceivingTimesOutOfOrder_ShouldRecordTimesInOrder (0 ms)
[ RUN ] FrameTimingsTest.FrameDroppedAfterRender_ShouldNotTriggerSecondFrameRenderedCall
TEST_LOOP_RANDOM_SEED="349099332"
[ OK ] FrameTimingsTest.FrameDroppedAfterRender_ShouldNotTriggerSecondFrameRenderedCall (0 ms)
[ RUN ] FrameTimingsTest.FrameDroppedBeforeRender_ShouldStillTriggerFrameRenderedCall
TEST_LOOP_RANDOM_SEED="3565595279"
[ OK ] FrameTimingsTest.FrameDroppedBeforeRender_ShouldStillTriggerFrameRenderedCall (0 ms)
[----------] 6 tests from FrameTimingsTest (0 ms total)
[----------] 2 tests from FrameTimings
[ RUN ] FrameTimings.DroppedAndUnitializedTimesAreUnique
[ OK ] FrameTimings.DroppedAndUnitializedTimesAreUnique (0 ms)
[ RUN ] FrameTimings.InitTimestamps
[ OK ] FrameTimings.InitTimestamps (0 ms)
[----------] 2 tests from FrameTimings (0 ms total)
[----------] 3 tests from GfxCommandApplierTest
[ RUN ] GfxCommandApplierTest.NewCreateEntityNodeCmd
TEST_LOOP_RANDOM_SEED="1801559128"
[ OK ] GfxCommandApplierTest.NewCreateEntityNodeCmd (0 ms)
[ RUN ] GfxCommandApplierTest.EraseResource
TEST_LOOP_RANDOM_SEED="4223073677"
[ OK ] GfxCommandApplierTest.EraseResource (0 ms)
[ RUN ] GfxCommandApplierTest.SeparateSessionsAreIndependent
TEST_LOOP_RANDOM_SEED="3190806561"
[ OK ] GfxCommandApplierTest.SeparateSessionsAreIndependent (0 ms)
[----------] 3 tests from GfxCommandApplierTest (0 ms total)
[----------] 5 tests from HLATest
[ RUN ] HLATest.HasHardwareLayerAssignment
TEST_LOOP_RANDOM_SEED="4030657513"
[ OK ] HLATest.HasHardwareLayerAssignment (0 ms)
[ RUN ] HLATest.HardwareLayerAssignmentMissingSwapchain
TEST_LOOP_RANDOM_SEED="3490047330"
[WARNING:garnet/lib/ui/gfx/engine/hardware_layer_assignment.cc(16)] Invalid HardwareLayerAssignment: no swapchain.
[ OK ] HLATest.HardwareLayerAssignmentMissingSwapchain (0 ms)
[ RUN ] HLATest.HardwareLayerAssignmentMissingLayers
TEST_LOOP_RANDOM_SEED="1137180507"
[WARNING:garnet/lib/ui/gfx/engine/hardware_layer_assignment.cc(26)] Invalid HardwareLayerAssignment: item with no layers.
[ OK ] HLATest.HardwareLayerAssignmentMissingLayers (0 ms)
[ RUN ] HLATest.HardwareLayerAssignmentMissingItems
TEST_LOOP_RANDOM_SEED="2858093763"
[WARNING:garnet/lib/ui/gfx/engine/hardware_layer_assignment.cc(19)] Invalid HardwareLayerAssignment: no items.
[ OK ] HLATest.HardwareLayerAssignmentMissingItems (0 ms)
[ RUN ] HLATest.HardwareLayerAssignmentDuplicateLayerIDs
TEST_LOOP_RANDOM_SEED="4212499765"
[WARNING:garnet/lib/ui/gfx/engine/hardware_layer_assignment.cc(32)] Invalid HardwareLayerAssignment: duplicate layer ID �
[ OK ] HLATest.HardwareLayerAssignmentDuplicateLayerIDs (0 ms)
[----------] 5 tests from HLATest (0 ms total)
[----------] 1 test from MultiSessionHitTestTest
[ RUN ] MultiSessionHitTestTest.GlobalHits
TEST_LOOP_RANDOM_SEED="1401218214"
[WARNING:garnet/lib/ui/scenic/event_reporter.cc(23)] EventReporter not set up, dropped event: ViewConnectedEvent(view_holder_id=1008)
[WARNING:garnet/lib/ui/scenic/event_reporter.cc(23)] EventReporter not set up, dropped event: ViewAttachedToSceneEvent(view_id=2001, properties=<TBD>
[WARNING:garnet/lib/ui/scenic/event_reporter.cc(23)] EventReporter not set up, dropped event: ViewPropertiesChangedEvent(view_id=2001, properties=<TBD>)
[WARNING:garnet/lib/ui/scenic/event_reporter.cc(23)] EventReporter not set up, dropped event: ViewHolderConnectedEvent(view_id=2001)
[WARNING:garnet/lib/ui/scenic/event_reporter.cc(23)] EventReporter not set up, dropped event: ViewConnectedEvent(view_holder_id=1009)
[WARNING:garnet/lib/ui/scenic/event_reporter.cc(23)] EventReporter not set up, dropped event: ViewAttachedToSceneEvent(view_id=3001, properties=<TBD>
[WARNING:garnet/lib/ui/scenic/event_reporter.cc(23)] EventReporter not set up, dropped event: ViewPropertiesChangedEvent(view_id=3001, properties=<TBD>)
[WARNING:garnet/lib/ui/scenic/event_reporter.cc(23)] EventReporter not set up, dropped event: ViewHolderConnectedEvent(view_id=3001)
[WARNING:garnet/lib/ui/scenic/event_reporter.cc(23)] EventReporter not set up, dropped event: ViewDisconnectedEvent(view_holder_id=1009)
[WARNING:garnet/lib/ui/scenic/event_reporter.cc(23)] EventReporter not set up, dropped event: ViewDisconnectedEvent(view_holder_id=1008)
[ OK ] MultiSessionHitTestTest.GlobalHits (0 ms)
[----------] 1 test from MultiSessionHitTestTest (0 ms total)
[----------] 3 tests from HostImageTest
[ RUN ] HostImageTest.FindResource
TEST_LOOP_RANDOM_SEED="2851287762"
[ OK ] HostImageTest.FindResource (20 ms)
[ RUN ] HostImageTest.RgbaImport
TEST_LOOP_RANDOM_SEED="1693558366"
[WARNING:garnet/lib/ui/gfx/resources/host_image.cc(162)] No BatchGpuUploader, cannot UpdatePixels.
[ OK ] HostImageTest.RgbaImport (13 ms)
[ RUN ] HostImageTest.YuvImportOnUmaPlatform
TEST_LOOP_RANDOM_SEED="2960008585"
[ OK ] HostImageTest.YuvImportOnUmaPlatform (25 ms)
[----------] 3 tests from HostImageTest (58 ms total)
[----------] 7 tests from ImagePipeTest
[ RUN ] ImagePipeTest.ImagePipeImageIdMustNotBeZero
TEST_LOOP_RANDOM_SEED="1273780228"
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 1 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[ OK ] ImagePipeTest.ImagePipeImageIdMustNotBeZero (0 ms)
[ RUN ] ImagePipeTest.PresentImagesOutOfOrder
TEST_LOOP_RANDOM_SEED="2099078813"
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 1 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[ OK ] ImagePipeTest.PresentImagesOutOfOrder (1 ms)
[ RUN ] ImagePipeTest.PresentImagesInOrder
TEST_LOOP_RANDOM_SEED="2789942959"
[ OK ] ImagePipeTest.PresentImagesInOrder (0 ms)
[ RUN ] ImagePipeTest.PresentImagesWithOffset
TEST_LOOP_RANDOM_SEED="2108178685"
[ OK ] ImagePipeTest.PresentImagesWithOffset (0 ms)
[ RUN ] ImagePipeTest.ImagePipePresentTwoFrames
TEST_LOOP_RANDOM_SEED="2710112792"
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 1 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1016666687 wakeup_time=1008666687 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1016666687 frame_number=0
[INFO:default_frame_scheduler.cc(189)] Calling RenderFrame presentation_time=1016666687 frame_number=0
[WARNING:garnet/lib/ui/gfx/engine/default_frame_scheduler.cc(216)] RenderFrame failed. There may not be any calls to OnFrameRendered or OnFramePresented, and no callbacks may be invoked.
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 1 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=3016666727 wakeup_time=3008666727 frame_number=1
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=3016666727 frame_number=1
[INFO:default_frame_scheduler.cc(189)] Calling RenderFrame presentation_time=3016666727 frame_number=1
[WARNING:garnet/lib/ui/gfx/engine/default_frame_scheduler.cc(216)] RenderFrame failed. There may not be any calls to OnFrameRendered or OnFramePresented, and no callbacks may be invoked.
[ OK ] ImagePipeTest.ImagePipePresentTwoFrames (1 ms)
[ RUN ] ImagePipeTest.ImagePipeUpdateTwoFrames
TEST_LOOP_RANDOM_SEED="1158171321"
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 1 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 1 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=16666667 wakeup_time=8666667 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=16666667 frame_number=0
[INFO:default_frame_scheduler.cc(189)] Calling RenderFrame presentation_time=16666667 frame_number=0
[WARNING:garnet/lib/ui/gfx/engine/default_frame_scheduler.cc(216)] RenderFrame failed. There may not be any calls to OnFrameRendered or OnFramePresented, and no callbacks may be invoked.
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 1 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1016666687 wakeup_time=1008666687 frame_number=1
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1016666687 frame_number=1
[INFO:default_frame_scheduler.cc(189)] Calling RenderFrame presentation_time=1016666687 frame_number=1
[WARNING:garnet/lib/ui/gfx/engine/default_frame_scheduler.cc(216)] RenderFrame failed. There may not be any calls to OnFrameRendered or OnFramePresented, and no callbacks may be invoked.
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 1 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=2016666707 wakeup_time=2008666707 frame_number=2
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=2016666707 frame_number=2
[INFO:default_frame_scheduler.cc(189)] Calling RenderFrame presentation_time=2016666707 frame_number=2
[WARNING:garnet/lib/ui/gfx/engine/default_frame_scheduler.cc(216)] RenderFrame failed. There may not be any calls to OnFrameRendered or OnFramePresented, and no callbacks may be invoked.
[ OK ] ImagePipeTest.ImagePipeUpdateTwoFrames (0 ms)
[ RUN ] ImagePipeTest.ImagePipeRemoveImageThatIsPendingPresent
TEST_LOOP_RANDOM_SEED="2660306664"
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 1 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=1016666687 wakeup_time=1008666687 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=1016666687 frame_number=0
[INFO:default_frame_scheduler.cc(189)] Calling RenderFrame presentation_time=1016666687 frame_number=0
[WARNING:garnet/lib/ui/gfx/engine/default_frame_scheduler.cc(216)] RenderFrame failed. There may not be any calls to OnFrameRendered or OnFramePresented, and no callbacks may be invoked.
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 1 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=4016666747 wakeup_time=4008666747 frame_number=1
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=4016666747 frame_number=1
[INFO:default_frame_scheduler.cc(189)] Calling RenderFrame presentation_time=4016666747 frame_number=1
[WARNING:garnet/lib/ui/gfx/engine/default_frame_scheduler.cc(216)] RenderFrame failed. There may not be any calls to OnFrameRendered or OnFramePresented, and no callbacks may be invoked.
[ OK ] ImagePipeTest.ImagePipeRemoveImageThatIsPendingPresent (1 ms)
[----------] 7 tests from ImagePipeTest (3 ms total)
[----------] 16 tests from ImportTest
[ RUN ] ImportTest.ExportsResourceViaCmd
TEST_LOOP_RANDOM_SEED="203891441"
[ OK ] ImportTest.ExportsResourceViaCmd (0 ms)
[ RUN ] ImportTest.ImportsUnlinkedImportViaCmd
TEST_LOOP_RANDOM_SEED="80836984"
[ OK ] ImportTest.ImportsUnlinkedImportViaCmd (0 ms)
[ RUN ] ImportTest.PerformsFullLinking
TEST_LOOP_RANDOM_SEED="2596185937"
[ OK ] ImportTest.PerformsFullLinking (0 ms)
[ RUN ] ImportTest.HandlesDeadSourceHandle
TEST_LOOP_RANDOM_SEED="3047075410"
[ OK ] ImportTest.HandlesDeadSourceHandle (0 ms)
[ RUN ] ImportTest.HandlesDeadDestinationHandle
TEST_LOOP_RANDOM_SEED="279439522"
[ OK ] ImportTest.HandlesDeadDestinationHandle (0 ms)
[ RUN ] ImportTest.DestroyingExportedResourceSendsEvent
TEST_LOOP_RANDOM_SEED="4273346368"
[ OK ] ImportTest.DestroyingExportedResourceSendsEvent (0 ms)
[ RUN ] ImportTest.ImportingNodeAfterDestroyingExportedResourceSendsEvent
TEST_LOOP_RANDOM_SEED="1585582776"
[ OK ] ImportTest.ImportingNodeAfterDestroyingExportedResourceSendsEvent (0 ms)
[ RUN ] ImportTest.KillingImportedResourceEvictsFromResourceLinker
TEST_LOOP_RANDOM_SEED="1398532898"
[ OK ] ImportTest.KillingImportedResourceEvictsFromResourceLinker (0 ms)
[ RUN ] ImportTest.ResourceUnexportedAfterImportsAndImportHandlesDie1
TEST_LOOP_RANDOM_SEED="32581129"
[ OK ] ImportTest.ResourceUnexportedAfterImportsAndImportHandlesDie1 (0 ms)
[ RUN ] ImportTest.ResourceUnexportedAfterImportsAndImportHandlesDie2
TEST_LOOP_RANDOM_SEED="3851682390"
[ OK ] ImportTest.ResourceUnexportedAfterImportsAndImportHandlesDie2 (0 ms)
[ RUN ] ImportTest.ResourceUnexportedAfterImportsAndImportHandlesDie3
TEST_LOOP_RANDOM_SEED="401645257"
[ OK ] ImportTest.ResourceUnexportedAfterImportsAndImportHandlesDie3 (0 ms)
[ RUN ] ImportTest.ResourceUnexportedAfterImportsAndImportHandlesDie4
TEST_LOOP_RANDOM_SEED="923211096"
[ OK ] ImportTest.ResourceUnexportedAfterImportsAndImportHandlesDie4 (0 ms)
[ RUN ] ImportTest.ProxiesCanBeFoundByTheirContainerOrTheirUnderlyingEntityType
TEST_LOOP_RANDOM_SEED="2279417774"
[ OK ] ImportTest.ProxiesCanBeFoundByTheirContainerOrTheirUnderlyingEntityType (1 ms)
[ RUN ] ImportTest.UnlinkedImportedResourceCanAcceptCommands
TEST_LOOP_RANDOM_SEED="726459714"
[ OK ] ImportTest.UnlinkedImportedResourceCanAcceptCommands (0 ms)
[ RUN ] ImportTest.LinkedResourceShouldBeAbleToAcceptCommands
TEST_LOOP_RANDOM_SEED="1391308856"
[ OK ] ImportTest.LinkedResourceShouldBeAbleToAcceptCommands (0 ms)
[ RUN ] ImportTest.EmbedderCanEmbedNodesFromElsewhere
TEST_LOOP_RANDOM_SEED="3864982534"
[ OK ] ImportTest.EmbedderCanEmbedNodesFromElsewhere (0 ms)
[----------] 16 tests from ImportTest (1 ms total)
[----------] 1 test from MemoryTest
[ RUN ] MemoryTest.MemoryAllocationSizeValidation
TEST_LOOP_RANDOM_SEED="487574276"
[ OK ] MemoryTest.MemoryAllocationSizeValidation (0 ms)
[----------] 1 test from MemoryTest (0 ms total)
[----------] 5 tests from VkMemoryTest
[ RUN ] VkMemoryTest.ImportDeviceMemory
TEST_LOOP_RANDOM_SEED="748649038"
[ OK ] VkMemoryTest.ImportDeviceMemory (29 ms)
[ RUN ] VkMemoryTest.ImportReadOnlyHostMemory
TEST_LOOP_RANDOM_SEED="2958819209"
[INFO:memory.cc(167)] Host memory VMO could not be imported to any valid Vulkan memory types.
[ OK ] VkMemoryTest.ImportReadOnlyHostMemory (13 ms)
[ RUN ] VkMemoryTest.ImportReadOnlyHostMemoryAsDeviceMemory
TEST_LOOP_RANDOM_SEED="1470987506"
[ OK ] VkMemoryTest.ImportReadOnlyHostMemoryAsDeviceMemory (13 ms)
[ RUN ] VkMemoryTest.ImportReadOnlyDeviceMemory
TEST_LOOP_RANDOM_SEED="2620443273"
[ OK ] VkMemoryTest.ImportReadOnlyDeviceMemory (24 ms)
[ RUN ] VkMemoryTest.ImportMaliciousClient
TEST_LOOP_RANDOM_SEED="2971734558"
[ OK ] VkMemoryTest.ImportMaliciousClient (13 ms)
[----------] 5 tests from VkMemoryTest (93 ms total)
[----------] 5 tests from NodeTest
[ RUN ] NodeTest.Tagging
TEST_LOOP_RANDOM_SEED="1398499529"
[ OK ] NodeTest.Tagging (0 ms)
[ RUN ] NodeTest.ShapeNodeMaterialAndShape
TEST_LOOP_RANDOM_SEED="918693335"
[ OK ] NodeTest.ShapeNodeMaterialAndShape (0 ms)
[ RUN ] NodeTest.NodesWithChildren
TEST_LOOP_RANDOM_SEED="1239722104"
[ OK ] NodeTest.NodesWithChildren (0 ms)
[ RUN ] NodeTest.SettingHitTestBehavior
TEST_LOOP_RANDOM_SEED="886321855"
[ OK ] NodeTest.SettingHitTestBehavior (0 ms)
[ RUN ] NodeTest.SettingClipPlanes
TEST_LOOP_RANDOM_SEED="3561031484"
[ OK ] NodeTest.SettingClipPlanes (0 ms)
[----------] 5 tests from NodeTest (0 ms total)
[----------] 20 tests from ObjectLinkerTest
[ RUN ] ObjectLinkerTest.InitialState
TEST_LOOP_RANDOM_SEED="3455872590"
[ OK ] ObjectLinkerTest.InitialState (0 ms)
[ RUN ] ObjectLinkerTest.AllowsExport
TEST_LOOP_RANDOM_SEED="3752123202"
[ OK ] ObjectLinkerTest.AllowsExport (0 ms)
[ RUN ] ObjectLinkerTest.CannotExportInvalidToken
TEST_LOOP_RANDOM_SEED="2204703475"
[ OK ] ObjectLinkerTest.CannotExportInvalidToken (0 ms)
[ RUN ] ObjectLinkerTest.CannotExportWithDeadExportToken
TEST_LOOP_RANDOM_SEED="2203175669"
[ OK ] ObjectLinkerTest.CannotExportWithDeadExportToken (0 ms)
[ RUN ] ObjectLinkerTest.CanExportWithDeadImportToken
TEST_LOOP_RANDOM_SEED="1659831416"
[ OK ] ObjectLinkerTest.CanExportWithDeadImportToken (0 ms)
[ RUN ] ObjectLinkerTest.CannotExportSameTokenTwice
TEST_LOOP_RANDOM_SEED="2858135530"
[ OK ] ObjectLinkerTest.CannotExportSameTokenTwice (0 ms)
[ RUN ] ObjectLinkerTest.LinkDeathRemovesExport
TEST_LOOP_RANDOM_SEED="860530931"
[ OK ] ObjectLinkerTest.LinkDeathRemovesExport (0 ms)
[ RUN ] ObjectLinkerTest.AllowsImport
TEST_LOOP_RANDOM_SEED="2533572527"
[ OK ] ObjectLinkerTest.AllowsImport (0 ms)
[ RUN ] ObjectLinkerTest.CannotImportInvalidToken
TEST_LOOP_RANDOM_SEED="2777916999"
[ OK ] ObjectLinkerTest.CannotImportInvalidToken (0 ms)
[ RUN ] ObjectLinkerTest.CannotImportWithDeadImportToken
TEST_LOOP_RANDOM_SEED="1617206431"
[ OK ] ObjectLinkerTest.CannotImportWithDeadImportToken (0 ms)
[ RUN ] ObjectLinkerTest.CanImportWithDeadExportToken
TEST_LOOP_RANDOM_SEED="676252592"
[ OK ] ObjectLinkerTest.CanImportWithDeadExportToken (0 ms)
[ RUN ] ObjectLinkerTest.CannotImportSameTokenTwice
TEST_LOOP_RANDOM_SEED="3602121069"
[ OK ] ObjectLinkerTest.CannotImportSameTokenTwice (0 ms)
[ RUN ] ObjectLinkerTest.LinkDeathRemovesImport
TEST_LOOP_RANDOM_SEED="3660488924"
[ OK ] ObjectLinkerTest.LinkDeathRemovesImport (0 ms)
[ RUN ] ObjectLinkerTest.InitializeLinksMatchingPeers
TEST_LOOP_RANDOM_SEED="1053878029"
[ OK ] ObjectLinkerTest.InitializeLinksMatchingPeers (0 ms)
[ RUN ] ObjectLinkerTest.InitializeLinksMatchingPeersWithImportBeforeExport
TEST_LOOP_RANDOM_SEED="874906063"
[ OK ] ObjectLinkerTest.InitializeLinksMatchingPeersWithImportBeforeExport (0 ms)
[ RUN ] ObjectLinkerTest.InitializeDoesNotLinkNonMatchingPeers
TEST_LOOP_RANDOM_SEED="791507625"
[ OK ] ObjectLinkerTest.InitializeDoesNotLinkNonMatchingPeers (0 ms)
[ RUN ] ObjectLinkerTest.EarlyImportTokenDeathCausesExportDisconnection
TEST_LOOP_RANDOM_SEED="3006186047"
[ OK ] ObjectLinkerTest.EarlyImportTokenDeathCausesExportDisconnection (0 ms)
[ RUN ] ObjectLinkerTest.ImportTokenDeathCausesExportDisconnection
TEST_LOOP_RANDOM_SEED="1598723187"
[ OK ] ObjectLinkerTest.ImportTokenDeathCausesExportDisconnection (0 ms)
[ RUN ] ObjectLinkerTest.EarlyExportTokenDeathCausesImportDisconnection
TEST_LOOP_RANDOM_SEED="2797730040"
[ OK ] ObjectLinkerTest.EarlyExportTokenDeathCausesImportDisconnection (0 ms)
[ RUN ] ObjectLinkerTest.ExportTokenDeathCausesImportDisconnection
TEST_LOOP_RANDOM_SEED="1248471634"
[ OK ] ObjectLinkerTest.ExportTokenDeathCausesImportDisconnection (0 ms)
[----------] 20 tests from ObjectLinkerTest (0 ms total)
[----------] 1 test from PoseBufferTest
[ RUN ] PoseBufferTest.Validation
TEST_LOOP_RANDOM_SEED="4059733016"
[ OK ] PoseBufferTest.Validation (25 ms)
[----------] 1 test from PoseBufferTest (25 ms total)
[----------] 15 tests from ResourceLinkerTest
[ RUN ] ResourceLinkerTest.AllowsExport
TEST_LOOP_RANDOM_SEED="2563820740"
[ OK ] ResourceLinkerTest.AllowsExport (0 ms)
[ RUN ] ResourceLinkerTest.AllowsImport
TEST_LOOP_RANDOM_SEED="248410692"
[ OK ] ResourceLinkerTest.AllowsImport (0 ms)
[ RUN ] ResourceLinkerTest.CannotImportWithDeadSourceAndDestinationHandles
TEST_LOOP_RANDOM_SEED="3675433201"
[ OK ] ResourceLinkerTest.CannotImportWithDeadSourceAndDestinationHandles (0 ms)
[ RUN ] ResourceLinkerTest.CannotImportWithDeadDestinationHandles
TEST_LOOP_RANDOM_SEED="2121581868"
[ OK ] ResourceLinkerTest.CannotImportWithDeadDestinationHandles (0 ms)
[ RUN ] ResourceLinkerTest.CanImportWithDeadSourceHandle
TEST_LOOP_RANDOM_SEED="1993831616"
[ OK ] ResourceLinkerTest.CanImportWithDeadSourceHandle (0 ms)
[ RUN ] ResourceLinkerTest.CannotExportWithDeadSourceAndDestinationHandles
TEST_LOOP_RANDOM_SEED="965789841"
[ OK ] ResourceLinkerTest.CannotExportWithDeadSourceAndDestinationHandles (0 ms)
[ RUN ] ResourceLinkerTest.CannotExportWithDeadSourceHandle
TEST_LOOP_RANDOM_SEED="2136478340"
[ OK ] ResourceLinkerTest.CannotExportWithDeadSourceHandle (0 ms)
[ RUN ] ResourceLinkerTest.CanExportWithDeadDestinationHandle
TEST_LOOP_RANDOM_SEED="1905274804"
[ OK ] ResourceLinkerTest.CanExportWithDeadDestinationHandle (0 ms)
[ RUN ] ResourceLinkerTest.DestinationHandleDeathAutomaticallyCleansUpResourceExport
TEST_LOOP_RANDOM_SEED="1990494259"
[ OK ] ResourceLinkerTest.DestinationHandleDeathAutomaticallyCleansUpResourceExport (0 ms)
[ RUN ] ResourceLinkerTest.SourceHandleDeathAutomaticallyCleansUpUnresolvedImports
TEST_LOOP_RANDOM_SEED="2131998802"
[ OK ] ResourceLinkerTest.SourceHandleDeathAutomaticallyCleansUpUnresolvedImports (0 ms)
[ RUN ] ResourceLinkerTest.ResourceDeathAutomaticallyCleansUpResourceExport
TEST_LOOP_RANDOM_SEED="2139003772"
[ OK ] ResourceLinkerTest.ResourceDeathAutomaticallyCleansUpResourceExport (0 ms)
[ RUN ] ResourceLinkerTest.ImportsBeforeExportsAreServiced
TEST_LOOP_RANDOM_SEED="2082460606"
[ OK ] ResourceLinkerTest.ImportsBeforeExportsAreServiced (0 ms)
[ RUN ] ResourceLinkerTest.ImportAfterReleasedExportedResourceFails
TEST_LOOP_RANDOM_SEED="1610183973"
[ OK ] ResourceLinkerTest.ImportAfterReleasedExportedResourceFails (0 ms)
[ RUN ] ResourceLinkerTest.DuplicatedDestinationHandlesAllowMultipleImports
TEST_LOOP_RANDOM_SEED="3862667081"
[ OK ] ResourceLinkerTest.DuplicatedDestinationHandlesAllowMultipleImports (0 ms)
[ RUN ] ResourceLinkerTest.UnresolvedImportIsRemovedIfDestroyed
TEST_LOOP_RANDOM_SEED="1390567713"
[ OK ] ResourceLinkerTest.UnresolvedImportIsRemovedIfDestroyed (1 ms)
[----------] 15 tests from ResourceLinkerTest (2 ms total)
[----------] 3 tests from SceneGraphTest
[ RUN ] SceneGraphTest.CompositorsGetAddedAndRemoved
TEST_LOOP_RANDOM_SEED="3279357852"
[ OK ] SceneGraphTest.CompositorsGetAddedAndRemoved (0 ms)
[ RUN ] SceneGraphTest.LookupCompositor
TEST_LOOP_RANDOM_SEED="3031574042"
[ OK ] SceneGraphTest.LookupCompositor (0 ms)
[ RUN ] SceneGraphTest.FirstCompositorIsStable
TEST_LOOP_RANDOM_SEED="3217752268"
[ OK ] SceneGraphTest.FirstCompositorIsStable (0 ms)
[----------] 3 tests from SceneGraphTest (0 ms total)
[----------] 1 test from SceneTest
[ RUN ] SceneTest.Lighting
TEST_LOOP_RANDOM_SEED="4103664589"
[ OK ] SceneTest.Lighting (0 ms)
[----------] 1 test from SceneTest (0 ms total)
[----------] 1 test from SessionHandlerTest
[ RUN ] SessionHandlerTest.WhenSessionHandlerDestroyed_ShouldRemoveSessionHandlerPtrFromSessionManager
TEST_LOOP_RANDOM_SEED="1954875583"
[ OK ] SessionHandlerTest.WhenSessionHandlerDestroyed_ShouldRemoveSessionHandlerPtrFromSessionManager (0 ms)
[----------] 1 test from SessionHandlerTest (0 ms total)
[----------] 5 tests from SessionTest
[ RUN ] SessionTest.ScheduleUpdateOutOfOrder
TEST_LOOP_RANDOM_SEED="2793458636"
[ OK ] SessionTest.ScheduleUpdateOutOfOrder (0 ms)
[ RUN ] SessionTest.ScheduleUpdateInOrder
TEST_LOOP_RANDOM_SEED="3258581563"
[ OK ] SessionTest.ScheduleUpdateInOrder (0 ms)
[ RUN ] SessionTest.ResourceIdAlreadyUsed
TEST_LOOP_RANDOM_SEED="1328572869"
[ OK ] SessionTest.ResourceIdAlreadyUsed (0 ms)
[ RUN ] SessionTest.AddAndRemoveResource
TEST_LOOP_RANDOM_SEED="154933147"
[ OK ] SessionTest.AddAndRemoveResource (0 ms)
[ RUN ] SessionTest.Labeling
TEST_LOOP_RANDOM_SEED="104906841"
[ OK ] SessionTest.Labeling (0 ms)
[----------] 5 tests from SessionTest (0 ms total)
[----------] 1 test from BufferSessionTest
[ RUN ] BufferSessionTest.BufferAliasing
TEST_LOOP_RANDOM_SEED="2602013035"
[ OK ] BufferSessionTest.BufferAliasing (25 ms)
[----------] 1 test from BufferSessionTest (25 ms total)
[----------] 2 tests from ShapeTest
[ RUN ] ShapeTest.Circle
TEST_LOOP_RANDOM_SEED="2736769776"
[ OK ] ShapeTest.Circle (0 ms)
[ RUN ] ShapeTest.Rectangle
TEST_LOOP_RANDOM_SEED="2034213498"
[ OK ] ShapeTest.Rectangle (0 ms)
[----------] 2 tests from ShapeTest (0 ms total)
[----------] 1 test from SizeChangeHintTest
[ RUN ] SizeChangeHintTest.SendingSizeChangeEventWorks
TEST_LOOP_RANDOM_SEED="203824018"
[ OK ] SizeChangeHintTest.SendingSizeChangeEventWorks (0 ms)
[----------] 1 test from SizeChangeHintTest (0 ms total)
[----------] 1 test from StereoCameraTest
[ RUN ] StereoCameraTest.Basic
TEST_LOOP_RANDOM_SEED="29142418"
[ OK ] StereoCameraTest.Basic (0 ms)
[----------] 1 test from StereoCameraTest (0 ms total)
[----------] 23 tests from ViewTest
[ RUN ] ViewTest.ChildrenCanBeAddedToViewWithoutViewHolder
TEST_LOOP_RANDOM_SEED="2839309512"
[ OK ] ViewTest.ChildrenCanBeAddedToViewWithoutViewHolder (0 ms)
[ RUN ] ViewTest.ExportsViewHolderViaCmd
TEST_LOOP_RANDOM_SEED="1016788927"
[ OK ] ViewTest.ExportsViewHolderViaCmd (0 ms)
[ RUN ] ViewTest.ImportsViewViaCmd
TEST_LOOP_RANDOM_SEED="3362520215"
[ OK ] ViewTest.ImportsViewViaCmd (0 ms)
[ RUN ] ViewTest.PairedViewAndHolderAreLinked
TEST_LOOP_RANDOM_SEED="1082996855"
[ OK ] ViewTest.PairedViewAndHolderAreLinked (0 ms)
[ RUN ] ViewTest.ExportViewHolderWithDeadHandleFails
TEST_LOOP_RANDOM_SEED="1955323425"
[ OK ] ViewTest.ExportViewHolderWithDeadHandleFails (0 ms)
[ RUN ] ViewTest.ViewHolderDestroyedBeforeView
TEST_LOOP_RANDOM_SEED="605424232"
[ OK ] ViewTest.ViewHolderDestroyedBeforeView (0 ms)
[ RUN ] ViewTest.ViewDestroyedBeforeViewHolder
TEST_LOOP_RANDOM_SEED="3827465412"
[ OK ] ViewTest.ViewDestroyedBeforeViewHolder (0 ms)
[ RUN ] ViewTest.ViewAndViewHolderConnectedEvents
TEST_LOOP_RANDOM_SEED="956193982"
[ OK ] ViewTest.ViewAndViewHolderConnectedEvents (0 ms)
[ RUN ] ViewTest.ViewHolderConnectsToScene
TEST_LOOP_RANDOM_SEED="4127042443"
[ OK ] ViewTest.ViewHolderConnectsToScene (0 ms)
[ RUN ] ViewTest.ViewHolderDetachedAndReleased
TEST_LOOP_RANDOM_SEED="413546693"
[ OK ] ViewTest.ViewHolderDetachedAndReleased (1 ms)
[ RUN ] ViewTest.ViewHolderChildrenReleasedFromSceneGraphWhenViewDestroyed
TEST_LOOP_RANDOM_SEED="1540878978"
[ OK ] ViewTest.ViewHolderChildrenReleasedFromSceneGraphWhenViewDestroyed (0 ms)
[ RUN ] ViewTest.ViewNodeChildAddedToViewHolder
TEST_LOOP_RANDOM_SEED="991212581"
[ OK ] ViewTest.ViewNodeChildAddedToViewHolder (0 ms)
[ RUN ] ViewTest.ViewHolderCannotAddArbitraryChildNodes
TEST_LOOP_RANDOM_SEED="1058683904"
[ OK ] ViewTest.ViewHolderCannotAddArbitraryChildNodes (0 ms)
[ RUN ] ViewTest.ViewNodePairedToView
TEST_LOOP_RANDOM_SEED="2263671418"
[ OK ] ViewTest.ViewNodePairedToView (0 ms)
[ RUN ] ViewTest.ViewNodeNotInResourceMap
TEST_LOOP_RANDOM_SEED="3916034721"
[ OK ] ViewTest.ViewNodeNotInResourceMap (0 ms)
[ RUN ] ViewTest.ViewHolderGrandchildGetsSceneRefreshed
TEST_LOOP_RANDOM_SEED="68693303"
[ OK ] ViewTest.ViewHolderGrandchildGetsSceneRefreshed (0 ms)
[ RUN ] ViewTest.ViewLinksAfterViewHolderConnectsToScene
TEST_LOOP_RANDOM_SEED="2371630374"
[ OK ] ViewTest.ViewLinksAfterViewHolderConnectsToScene (0 ms)
[ RUN ] ViewTest.ViewStateChangeNotifiesViewHolder
TEST_LOOP_RANDOM_SEED="2074465593"
[ OK ] ViewTest.ViewStateChangeNotifiesViewHolder (0 ms)
[ RUN ] ViewTest.RenderStateAcrossManyFrames
TEST_LOOP_RANDOM_SEED="4071575318"
[ OK ] ViewTest.RenderStateAcrossManyFrames (0 ms)
[ RUN ] ViewTest.RenderStateFalseWhenViewDisconnects
TEST_LOOP_RANDOM_SEED="198231423"
[ OK ] ViewTest.RenderStateFalseWhenViewDisconnects (1 ms)
[ RUN ] ViewTest.ViewHolderRenderWaitClearedWhenViewDestroyed
TEST_LOOP_RANDOM_SEED="4016709738"
[ OK ] ViewTest.ViewHolderRenderWaitClearedWhenViewDestroyed (0 ms)
[ RUN ] ViewTest.RenderSignalDoesntCrashWhenViewHolderDestroyed
TEST_LOOP_RANDOM_SEED="2978872687"
[ OK ] ViewTest.RenderSignalDoesntCrashWhenViewHolderDestroyed (0 ms)
[ RUN ] ViewTest.RenderStateFalseWhenViewHolderDisconnectsFromScene
TEST_LOOP_RANDOM_SEED="2101207277"
[ OK ] ViewTest.RenderStateFalseWhenViewHolderDisconnectsFromScene (0 ms)
[----------] 23 tests from ViewTest (2 ms total)
[----------] Global test environment tear-down
[==========] 156 tests from 29 test suites ran. (222 ms total)
[ PASSED ] 156 tests.
YOU HAVE 5 DISABLED TESTS
PASSED: /pkgfs/packages/scenic_tests/0/test/gfx_unittests passed
SUMMARY: Ran 1 tests: 0 failed (0.548 sec)
ok 5 //garnet/bin/ui:gfx_unittests (1.760590839s)
------------------------------------------------
RUNNING TEST: /pkgfs/packages/scenic_tests/0/test/geometry_util_unittests
Running main() from ../../third_party/googletest/googletest/src/gtest_main.cc
[==========] Running 10 tests from 4 test suites.
[----------] Global test environment set-up.
[----------] 1 test from RectTest
[ RUN ] RectTest.Comparisons
[ OK ] RectTest.Comparisons (0 ms)
[----------] 1 test from RectTest (0 ms total)
[----------] 1 test from SizeTest
[ RUN ] SizeTest.Comparisons
[ OK ] SizeTest.Comparisons (0 ms)
[----------] 1 test from SizeTest (0 ms total)
[----------] 1 test from PointTest
[ RUN ] PointTest.Comparisons
[ OK ] PointTest.Comparisons (0 ms)
[----------] 1 test from PointTest (0 ms total)
[----------] 7 tests from TransformFunctionsTest
[ RUN ] TransformFunctionsTest.SetIdentityTransform
[ OK ] TransformFunctionsTest.SetIdentityTransform (0 ms)
[ RUN ] TransformFunctionsTest.SetTranslationTransform
[ OK ] TransformFunctionsTest.SetTranslationTransform (0 ms)
[ RUN ] TransformFunctionsTest.Translate
[ OK ] TransformFunctionsTest.Translate (0 ms)
[ RUN ] TransformFunctionsTest.Scale
[ OK ] TransformFunctionsTest.Scale (0 ms)
[ RUN ] TransformFunctionsTest.CreateIdentityTransform
[ OK ] TransformFunctionsTest.CreateIdentityTransform (0 ms)
[ RUN ] TransformFunctionsTest.CreateTranslationTransform
[ OK ] TransformFunctionsTest.CreateTranslationTransform (0 ms)
[ RUN ] TransformFunctionsTest.CreateScaleTransform
[ OK ] TransformFunctionsTest.CreateScaleTransform (0 ms)
[----------] 7 tests from TransformFunctionsTest (0 ms total)
[----------] Global test environment tear-down
[==========] 10 tests from 4 test suites ran. (0 ms total)
[ PASSED ] 10 tests.
PASSED: /pkgfs/packages/scenic_tests/0/test/geometry_util_unittests passed
SUMMARY: Ran 1 tests: 0 failed (0.052 sec)
ok 6 //garnet/bin/ui:geometry_util_unittests (1.266529128s)
------------------------------------------------
RUNNING TEST: /pkgfs/packages/scenic_tests/0/test/input_apptests
Running main() from ../../third_party/googletest/googletest/src/gtest_main.cc
[==========] Running 9 tests from 2 test suites.
[----------] Global test environment set-up.
[----------] 7 tests from ReaderInterpreterInputTest
[ RUN ] ReaderInterpreterInputTest.BootMouse
TEST_LOOP_RANDOM_SEED="3151872797"
[ OK ] ReaderInterpreterInputTest.BootMouse (0 ms)
[ RUN ] ReaderInterpreterInputTest.BootKeyboard
TEST_LOOP_RANDOM_SEED="2383736743"
[ OK ] ReaderInterpreterInputTest.BootKeyboard (0 ms)
[ RUN ] ReaderInterpreterInputTest.EgalaxTouchScreen
TEST_LOOP_RANDOM_SEED="322318680"
[INFO:touch.cc(106)] Touch descriptor: Failed to find any touch points
[INFO:input_interpreter.cc(323)] Can't process HID report descriptor for MockHidDecoder; Failed to do generic device parsing
[INFO:input_interpreter.cc(329)] hid-parser successful for MockHidDecoder with usage page 1 and usage 1
[INFO:input_interpreter.cc(329)] hid-parser successful for MockHidDecoder with usage page 13 and usage 4
[ OK ] ReaderInterpreterInputTest.EgalaxTouchScreen (1 ms)
[ RUN ] ReaderInterpreterInputTest.ParadiseTouchscreen
TEST_LOOP_RANDOM_SEED="788652448"
[INFO:input_interpreter.cc(329)] hid-parser successful for MockHidDecoder with usage page 13 and usage 4
[INFO:input_interpreter.cc(329)] hid-parser successful for MockHidDecoder with usage page 13 and usage 2
[INFO:input_interpreter.cc(329)] hid-parser successful for MockHidDecoder with usage page 1 and usage 2
[ OK ] ReaderInterpreterInputTest.ParadiseTouchscreen (0 ms)
[ RUN ] ReaderInterpreterInputTest.ParadiseTouchpad
TEST_LOOP_RANDOM_SEED="1053700629"
[INFO:input_interpreter.cc(329)] hid-parser successful for MockHidDecoder with usage page 13 and usage 5
[ OK ] ReaderInterpreterInputTest.ParadiseTouchpad (0 ms)
[ RUN ] ReaderInterpreterInputTest.SensorTest
TEST_LOOP_RANDOM_SEED="750758758"
[INFO:input_interpreter.cc(329)] hid-parser successful for MockHidDecoder with usage page 32 and usage 1
[ OK ] ReaderInterpreterInputTest.SensorTest (0 ms)
[ RUN ] ReaderInterpreterInputTest.MediaButtonsTest
TEST_LOOP_RANDOM_SEED="2792306696"
[INFO:input_interpreter.cc(329)] hid-parser successful for MockHidDecoder with usage page 12 and usage 1
[ OK ] ReaderInterpreterInputTest.MediaButtonsTest (0 ms)
[----------] 7 tests from ReaderInterpreterInputTest (1 ms total)
[----------] 2 tests from InputInterfaceTest
[ RUN ] InputInterfaceTest.RegisterKeyboardTest
TEST_LOOP_RANDOM_SEED="1445913315"
[ OK ] InputInterfaceTest.RegisterKeyboardTest (0 ms)
[ RUN ] InputInterfaceTest.InputKeyboardTest
TEST_LOOP_RANDOM_SEED="3584317205"
[ OK ] InputInterfaceTest.InputKeyboardTest (0 ms)
[----------] 2 tests from InputInterfaceTest (0 ms total)
[----------] Global test environment tear-down
[==========] 9 tests from 2 test suites ran. (1 ms total)
[ PASSED ] 9 tests.
PASSED: /pkgfs/packages/scenic_tests/0/test/input_apptests passed
SUMMARY: Ran 1 tests: 0 failed (0.070 sec)
ok 7 //garnet/bin/ui:input_apptests (1.285103086s)
------------------------------------------------
RUNNING TEST: /pkgfs/packages/scenic_tests/0/test/input_reader_unittests
Running main() from ../../third_party/googletest/googletest/src/gtest_main.cc
[==========] Running 15 tests from 5 test suites.
[----------] Global test environment set-up.
[----------] 1 test from MouseTest
[ RUN ] MouseTest.BootMouse
[INFO:mouse.cc(108)] Mouse report 255 does not match report id 0
[ OK ] MouseTest.BootMouse (0 ms)
[----------] 1 test from MouseTest (0 ms total)
[----------] 2 tests from SensorTest
[ RUN ] SensorTest.LightMeter
[ OK ] SensorTest.LightMeter (0 ms)
[ RUN ] SensorTest.Accelerometer
[ OK ] SensorTest.Accelerometer (0 ms)
[----------] 2 tests from SensorTest (0 ms total)
[----------] 2 tests from StylusTest
[ RUN ] StylusTest.Paradise
[ OK ] StylusTest.Paradise (0 ms)
[ RUN ] StylusTest.Acer12
[ OK ] StylusTest.Acer12 (0 ms)
[----------] 2 tests from StylusTest (0 ms total)
[----------] 2 tests from TouchpadTest
[ RUN ] TouchpadTest.ParadiseV1
[ OK ] TouchpadTest.ParadiseV1 (0 ms)
[ RUN ] TouchpadTest.ParadiseV2
PASSED: /pkgfs/packages/scenic_tests/0/test/input_reader_unittests passed
[ OK ] TouchpadTest.ParadiseV2 (0 ms)
[----------] 2 tests from TouchpadTest (0 ms total)
[----------] 8 tests from TouchscreenTest
[ RUN ] TouchscreenTest.Gechic1101
[ OK ] TouchscreenTest.Gechic1101 (0 ms)
[ RUN ] TouchscreenTest.CoolTouch
[ OK ] TouchscreenTest.CoolTouch (0 ms)
[ RUN ] TouchscreenTest.WaveShare
[ OK ] TouchscreenTest.WaveShare (0 ms)
[ RUN ] TouchscreenTest.Gechic1303
[ OK ] TouchscreenTest.Gechic1303 (0 ms)
[ RUN ] TouchscreenTest.ParadiseV1
[ OK ] TouchscreenTest.ParadiseV1 (1 ms)
[ RUN ] TouchscreenTest.ParadiseV2
[ OK ] TouchscreenTest.ParadiseV2 (0 ms)
[ RUN ] TouchscreenTest.ParadiseV3
[ OK ] TouchscreenTest.ParadiseV3 (0 ms)
[ RUN ] TouchscreenTest.Ft3x27
[ OK ] TouchscreenTest.Ft3x27 (0 ms)
[----------] 8 tests from TouchscreenTest (1 ms total)
[----------] Global test environment tear-down
[==========] 15 tests from 5 test suites ran. (1 ms total)
[ PASSED ] 15 tests.
SUMMARY: Ran 1 tests: 0 failed (0.061 sec)
ok 8 //garnet/bin/ui:input_reader_unittests (1.277580058s)
------------------------------------------------
RUNNING TEST: /pkgfs/packages/scenic_tests/0/test/input_unittests
[==========] Running 5 tests from 4 test suites.
[----------] Global test environment set-up.
[----------] 1 test from CoordinateTransformTest
[ RUN ] CoordinateTransformTest.CoordinateTransform
TEST_LOOP_RANDOM_SEED="2871444145"
[INFO:gfx_system.cc(196)] No Vulkan found, but using a test-only "display".
[INFO:input_system.cc(203)] Scenic input system initialized.
[ERROR:garnet/lib/ui/input/input_system.cc(200)] Scenic lost connection to TextSync
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 1 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=3540083404135 wakeup_time=3540075404135 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=3540083404135 frame_number=0
[INFO:default_frame_scheduler.cc(189)] Calling RenderFrame presentation_time=3540083404135 frame_number=0
[WARNING:garnet/lib/ui/gfx/engine/default_frame_scheduler.cc(216)] RenderFrame failed. There may not be any calls to OnFrameRendered or OnFramePresented, and no callbacks may be invoked.
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 2 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=3540100070802 wakeup_time=3540092070802 frame_number=1
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=3540100070802 frame_number=1
[INFO:default_frame_scheduler.cc(189)] Calling RenderFrame presentation_time=3540100070802 frame_number=1
[WARNING:garnet/lib/ui/gfx/engine/default_frame_scheduler.cc(216)] RenderFrame failed. There may not be any calls to OnFrameRendered or OnFramePresented, and no callbacks may be invoked.
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 3 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=3540116737469 wakeup_time=3540108737469 frame_number=2
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=3540116737469 frame_number=2
[INFO:default_frame_scheduler.cc(189)] Calling RenderFrame presentation_time=3540116737469 frame_number=2
[WARNING:garnet/lib/ui/gfx/engine/default_frame_scheduler.cc(216)] RenderFrame failed. There may not be any calls to OnFrameRendered or OnFramePresented, and no callbacks may be invoked.
[ OK ] CoordinateTransformTest.CoordinateTransform (1 ms)
[----------] 1 test from CoordinateTransformTest (1 ms total)
[----------] 1 test from FocusAvoidanceTest
[ RUN ] FocusAvoidanceTest.ViewHierarchyByScenic
TEST_LOOP_RANDOM_SEED="1092838580"
[INFO:gfx_system.cc(196)] No Vulkan found, but using a test-only "display".
[INFO:input_system.cc(203)] Scenic input system initialized.
[ERROR:garnet/lib/ui/input/input_system.cc(200)] Scenic lost connection to TextSync
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 1 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=16666667 wakeup_time=8666667 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=16666667 frame_number=0
[INFO:default_frame_scheduler.cc(189)] Calling RenderFrame presentation_time=16666667 frame_number=0
[WARNING:garnet/lib/ui/gfx/engine/default_frame_scheduler.cc(216)] RenderFrame failed. There may not be any calls to OnFrameRendered or OnFramePresented, and no callbacks may be invoked.
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 2 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=33333334 wakeup_time=25333334 frame_number=1
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=33333334 frame_number=1
[INFO:default_frame_scheduler.cc(189)] Calling RenderFrame presentation_time=33333334 frame_number=1
[WARNING:garnet/lib/ui/gfx/engine/default_frame_scheduler.cc(216)] RenderFrame failed. There may not be any calls to OnFrameRendered or OnFramePresented, and no callbacks may be invoked.
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 3 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=50000001 wakeup_time=42000001 frame_number=2
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=50000001 frame_number=2
[INFO:default_frame_scheduler.cc(189)] Calling RenderFrame presentation_time=50000001 frame_number=2
[WARNING:garnet/lib/ui/gfx/engine/default_frame_scheduler.cc(216)] RenderFrame failed. There may not be any calls to OnFrameRendered or OnFramePresented, and no callbacks may be invoked.
[ OK ] FocusAvoidanceTest.ViewHierarchyByScenic (1 ms)
[----------] 1 test from FocusAvoidanceTest (1 ms total)
[----------] 1 test from HardKeyboardDeliveryTest
[ RUN ] HardKeyboardDeliveryTest.Test
TEST_LOOP_RANDOM_SEED="1519764342"
[INFO:gfx_system.cc(196)] No Vulkan found, but using a test-only "display".
[INFO:input_system.cc(203)] Scenic input system initialized.
[ERROR:garnet/lib/ui/input/input_system.cc(200)] Scenic lost connection to TextSync
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 1 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=3540083404135 wakeup_time=3540075404135 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=3540083404135 frame_number=0
[INFO:default_frame_scheduler.cc(189)] Calling RenderFrame presentation_time=3540083404135 frame_number=0
[WARNING:garnet/lib/ui/gfx/engine/default_frame_scheduler.cc(216)] RenderFrame failed. There may not be any calls to OnFrameRendered or OnFramePresented, and no callbacks may be invoked.
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 2 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=3540100070802 wakeup_time=3540092070802 frame_number=1
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=3540100070802 frame_number=1
[INFO:default_frame_scheduler.cc(189)] Calling RenderFrame presentation_time=3540100070802 frame_number=1
[WARNING:garnet/lib/ui/gfx/engine/default_frame_scheduler.cc(216)] RenderFrame failed. There may not be any calls to OnFrameRendered or OnFramePresented, and no callbacks may be invoked.
[ OK ] HardKeyboardDeliveryTest.Test (2 ms)
[----------] 1 test from HardKeyboardDeliveryTest (2 ms total)
[----------] 2 tests from MouseDeliveryTest
[ RUN ] MouseDeliveryTest.StandardTest
TEST_LOOP_RANDOM_SEED="1532077877"
[INFO:gfx_system.cc(196)] No Vulkan found, but using a test-only "display".
[INFO:input_system.cc(203)] Scenic input system initialized.
[ERROR:garnet/lib/ui/input/input_system.cc(200)] Scenic lost connection to TextSync
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 1 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=3540083404135 wakeup_time=3540075404135 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=3540083404135 frame_number=0
[INFO:default_frame_scheduler.cc(189)] Calling RenderFrame presentation_time=3540083404135 frame_number=0
[WARNING:garnet/lib/ui/gfx/engine/default_frame_scheduler.cc(216)] RenderFrame failed. There may not be any calls to OnFrameRendered or OnFramePresented, and no callbacks may be invoked.
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 2 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=3540100070802 wakeup_time=3540092070802 frame_number=1
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=3540100070802 frame_number=1
[INFO:default_frame_scheduler.cc(189)] Calling RenderFrame presentation_time=3540100070802 frame_number=1
[WARNING:garnet/lib/ui/gfx/engine/default_frame_scheduler.cc(216)] RenderFrame failed. There may not be any calls to OnFrameRendered or OnFramePresented, and no callbacks may be invoked.
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 3 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=3540116737469 wakeup_time=3540108737469 frame_number=2
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=3540116737469 frame_number=2
[INFO:default_frame_scheduler.cc(189)] Calling RenderFrame presentation_time=3540116737469 frame_number=2
[WARNING:garnet/lib/ui/gfx/engine/default_frame_scheduler.cc(216)] RenderFrame failed. There may not be any calls to OnFrameRendered or OnFramePresented, and no callbacks may be invoked.
[ OK ] MouseDeliveryTest.StandardTest (1 ms)
[ RUN ] MouseDeliveryTest.NoFocusTest
TEST_LOOP_RANDOM_SEED="2734249841"
[INFO:gfx_system.cc(196)] No Vulkan found, but using a test-only "display".
[INFO:input_system.cc(203)] Scenic input system initialized.
[ERROR:garnet/lib/ui/input/input_system.cc(200)] Scenic lost connection to TextSync
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 1 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=3540083404135 wakeup_time=3540075404135 frame_number=0
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=3540083404135 frame_number=0
[INFO:default_frame_scheduler.cc(189)] Calling RenderFrame presentation_time=3540083404135 frame_number=0
[WARNING:garnet/lib/ui/gfx/engine/default_frame_scheduler.cc(216)] RenderFrame failed. There may not be any calls to OnFrameRendered or OnFramePresented, and no callbacks may be invoked.
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 2 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=3540100070802 wakeup_time=3540092070802 frame_number=1
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=3540100070802 frame_number=1
[INFO:default_frame_scheduler.cc(189)] Calling RenderFrame presentation_time=3540100070802 frame_number=1
[WARNING:garnet/lib/ui/gfx/engine/default_frame_scheduler.cc(216)] RenderFrame failed. There may not be any calls to OnFrameRendered or OnFramePresented, and no callbacks may be invoked.
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 3 presentation_time: 0
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[INFO:default_frame_scheduler.cc(148)] MaybeRenderFrame presentation_time=3540116737469 wakeup_time=3540108737469 frame_number=2
[INFO:default_frame_scheduler.cc(250)] ApplyScheduledSessionUpdates presentation_time=3540116737469 frame_number=2
[INFO:default_frame_scheduler.cc(189)] Calling RenderFrame presentation_time=3540116737469 frame_number=2
[WARNING:garnet/lib/ui/gfx/engine/default_frame_scheduler.cc(216)] RenderFrame failed. There may not be any calls to OnFrameRendered or OnFramePresented, and no callbacks may be invoked.
[ OK ] MouseDeliveryTest.NoFocusTest (2 ms)
[----------] 2 tests from MouseDeliveryTest (3 ms total)
[----------] Global test environment tear-down
[==========] 5 tests from 4 test suites ran. (7 ms total)
[ PASSED ] 5 tests.
PASSED: /pkgfs/packages/scenic_tests/0/test/input_unittests passed
SUMMARY: Ran 1 tests: 0 failed (0.105 sec)
ok 9 //garnet/bin/ui:input_unittests (1.325446955s)
[03540.060] 05791.05805> [WARNING:garnet/bin/appmgr/service_provider_dir_impl.cc(127)] Component fuchsia-pkg://fuchsia.com/scenic_tests#meta/input_unittests.cmx is not allowed to connect to fuchsia.sysmem.Allocator because this service is not presen
[03540.060] 05791.05805> t in the component's sandbox.
[03540.060] 05791.05805> Refer to
https://fuchsia.googlesource.com/fuchsia/+/master/docs/the-book/sandboxing.md#services for more information.
[03540.062] 05791.05805> [WARNING:garnet/bin/appmgr/service_provider_dir_impl.cc(127)] Component fuchsia-pkg://fuchsia.com/scenic_tests#meta/input_unittests.cmx is not allowed to connect to fuchsia.sysmem.Allocator because this service is not presen
[03540.062] 05791.05805> t in the component's sandbox.
[03540.062] 05791.05805> Refer to
https://fuchsia.googlesource.com/fuchsia/+/master/docs/the-book/sandboxing.md#services for more information.
[03540.063] 05791.05805> [WARNING:garnet/bin/appmgr/service_provider_dir_impl.cc(127)] Component fuchsia-pkg://fuchsia.com/scenic_tests#meta/input_unittests.cmx is not allowed to connect to fuchsia.sysmem.Allocator because this service is not presen
[03540.063] 05791.05805> t in the component's sandbox.
[03540.063] 05791.05805> Refer to
https://fuchsia.googlesource.com/fuchsia/+/master/docs/the-book/sandboxing.md#services for more information.
[03540.064] 05791.05805> [WARNING:garnet/bin/appmgr/service_provider_dir_impl.cc(127)] Component fuchsia-pkg://fuchsia.com/scenic_tests#meta/input_unittests.cmx is not allowed to connect to fuchsia.sysmem.Allocator because this service is not presen
[03540.064] 05791.05805> t in the component's sandbox.
[03540.064] 05791.05805> Refer to
https://fuchsia.googlesource.com/fuchsia/+/master/docs/the-book/sandboxing.md#services for more information.
[03540.065] 05791.05805> [WARNING:garnet/bin/appmgr/service_provider_dir_impl.cc(127)] Component fuchsia-pkg://fuchsia.com/scenic_tests#meta/input_unittests.cmx is not allowed to connect to fuchsia.sysmem.Allocator because this service is not presen
[03540.065] 05791.05805> t in the component's sandbox.
[03540.065] 05791.05805> Refer to
https://fuchsia.googlesource.com/fuchsia/+/master/docs/the-book/sandboxing.md#services for more information.
------------------------------------------------
RUNNING TEST: /pkgfs/packages/scenic_tests/0/test/input_tool_unittests
Running main() from ../../third_party/googletest/googletest/src/gtest_main.cc
[==========] Running 5 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 5 tests from InverseKeymapTest
[ RUN ] InverseKeymapTest.PlainKey
[ OK ] InverseKeymapTest.PlainKey (0 ms)
[ RUN ] InverseKeymapTest.ShiftKey
[ OK ] InverseKeymapTest.ShiftKey (0 ms)
[ RUN ] InverseKeymapTest.Lowercase
[ OK ] InverseKeymapTest.Lowercase (0 ms)
[ RUN ] InverseKeymapTest.Sentence
[ OK ] InverseKeymapTest.Sentence (0 ms)
[ RUN ] InverseKeymapTest.HoldShift
[ OK ] InverseKeymapTest.HoldShift (0 ms)
[----------] 5 tests from InverseKeymapTest (0 ms total)
[----------] Global test environment tear-down
[==========] 5 tests from 1 test suite ran. (0 ms total)
[ PASSED ] 5 tests.
PASSED: /pkgfs/packages/scenic_tests/0/test/input_tool_unittests passed
SUMMARY: Ran 1 tests: 0 failed (0.059 sec)
ok 10 //garnet/bin/ui:input_tool_unittests (1.290471865s)
------------------------------------------------
RUNNING TEST: /pkgfs/packages/scenic_tests/0/test/presentation_mode_unittests
Running main() from ../../third_party/googletest/googletest/src/gtest_main.cc
[==========] Running 7 tests from 3 test suites.
[----------] Global test environment set-up.
[----------] 1 test from PositiveData
[ RUN ] PositiveData.MovingAverage
[ OK ] PositiveData.MovingAverage (0 ms)
[----------] 1 test from PositiveData (0 ms total)
[----------] 1 test from NegativeData
[ RUN ] NegativeData.MovingAverage
[ OK ] NegativeData.MovingAverage (0 ms)
[----------] 1 test from NegativeData (0 ms total)
[----------] 5 tests from Detector
[ RUN ] Detector.Closed
[ OK ] Detector.Closed (0 ms)
[ RUN ] Detector.Laptop
[ OK ] Detector.Laptop (0 ms)
[ RUN ] Detector.Tablet
[ OK ] Detector.Tablet (0 ms)
[ RUN ] Detector.Tent
[ OK ] Detector.Tent (0 ms)
[ RUN ] Detector.NonAccelerometer
[ OK ] Detector.NonAccelerometer (0 ms)
[----------] 5 tests from Detector (0 ms total)
[----------] Global test environment tear-down
[==========] 7 tests from 3 test suites ran. (0 ms total)
[ PASSED ] 7 tests.
PASSED: /pkgfs/packages/scenic_tests/0/test/presentation_mode_unittests passed
SUMMARY: Ran 1 tests: 0 failed (0.058 sec)
ok 11 //garnet/bin/ui:presentation_mode_unittests (1.282343297s)
------------------------------------------------
RUNNING TEST: /pkgfs/packages/scenic_tests/0/test/root_presenter_unittests
Running main() from ../../third_party/googletest/googletest/src/gtest_main.cc
[==========] Running 4 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 4 tests from DisplayConfiguration
[ RUN ] DisplayConfiguration.Basic_2160x1440
[INFO:display_configuration.cc(62)] RootPresenter: treating device as an Acer Switch 12 Alpha.
[ OK ] DisplayConfiguration.Basic_2160x1440 (0 ms)
[ RUN ] DisplayConfiguration.Basic_2400x1600
[INFO:display_configuration.cc(67)] RootPresenter: treating device as a Google Pixelbook.
[ OK ] DisplayConfiguration.Basic_2400x1600 (0 ms)
[ RUN ] DisplayConfiguration.Basic_3840x2160
[INFO:display_configuration.cc(71)] RootPresenter: treating display as a 24in 4K monitor.
[ OK ] DisplayConfiguration.Basic_3840x2160 (0 ms)
[ RUN ] DisplayConfiguration.Basic_1920x1200
[INFO:display_configuration.cc(75)] RootPresenter: treating display as a 24in monitor.
[ OK ] DisplayConfiguration.Basic_1920x1200 (0 ms)
[----------] 4 tests from DisplayConfiguration (0 ms total)
[----------] Global test environment tear-down
[==========] 4 tests from 1 test suite ran. (0 ms total)
[ PASSED ] 4 tests.
PASSED: /pkgfs/packages/scenic_tests/0/test/root_presenter_unittests passed
SUMMARY: Ran 1 tests: 0 failed (0.049 sec)
ok 12 //garnet/bin/ui:root_presenter_unittests (1.279468711s)
------------------------------------------------
RUNNING TEST: /pkgfs/packages/scenic_tests/0/test/scenic_unittests
Running main() from ../../third_party/googletest/googletest/src/gtest_main.cc
[==========] Running 2 tests from 2 test suites.
[----------] Global test environment set-up.
[----------] 1 test from ScenicTest
[ RUN ] ScenicTest.SessionCreatedAfterAllSystemsInitialized
TEST_LOOP_RANDOM_SEED="2133011931"
[ OK ] ScenicTest.SessionCreatedAfterAllSystemsInitialized (0 ms)
[----------] 1 test from ScenicTest (0 ms total)
[----------] 1 test from ScenicGfxTest
[ RUN ] ScenicGfxTest.InvalidPresentCall_ShouldDestroySession
TEST_LOOP_RANDOM_SEED="2177237865"
[INFO:gfx_system.cc(196)] No Vulkan found, but using a test-only "display".
[INFO:default_frame_scheduler.cc(237)] ScheduleUpdateForSession session_id: 1 presentation_time: 10
[INFO:default_frame_scheduler.cc(115)] RequestFrame
[ERROR:garnet/lib/ui/scenic/session.cc(159)] scenic_impl::gfx::Session: Present called with out-of-order presentation time. requested presentation time=0, last scheduled presentation time=10.
Session error: scenic_impl::gfx::Session: Present called with out-of-order presentation time. requested presentation time=0, last scheduled presentation time=10.[ OK ] ScenicGfxTest.InvalidPresentCall_ShouldDestroySession (1 ms)
[----------] 1 test from ScenicGfxTest (1 ms total)
[----------] Global test environment tear-down
[==========] 2 tests from 2 test suites ran. (1 ms total)
[ PASSED ] 2 tests.
PASSED: /pkgfs/packages/scenic_tests/0/test/scenic_unittests passed
SUMMARY: Ran 1 tests: 0 failed (0.077 sec)
ok 13 //garnet/bin/ui:scenic_unittests (1.294236311s)
[03545.218] 05791.05805> [WARNING:garnet/bin/appmgr/service_provider_dir_impl.cc(127)] Component fuchsia-pkg://fuchsia.com/scenic_tests#meta/scenic_unittests.cmx is not allowed to connect to fuchsia.sysmem.Allocator because this service is not prese
[03545.218] 05791.05805> nt in the component's sandbox.
[03545.218] 05791.05805> Refer to
https://fuchsia.googlesource.com/fuchsia/+/master/docs/the-book/sandboxing.md#services for more information.
------------------------------------------------
RUNNING TEST: /pkgfs/packages/default_hardware_ime_tests/0/test/default_hardware_ime_unittests
running 1 test
test tests::state_sends_edits_on_input_and_retries ... ok
test result: ok. 1 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out
PASSED: /pkgfs/packages/default_hardware_ime_tests/0/test/default_hardware_ime_unittests passed
SUMMARY: Ran 1 tests: 0 failed (0.048 sec)
ok 14 //garnet/bin/ui/text/default_hardware_ime:default_hardware_ime_bin_test (1.276358066s)
------------------------------------------------
RUNNING TEST: /pkgfs/packages/shortcut_test/0/test/shortcut_bin_test
DEBUG: stopping or rebooting the node "upper-stoop-folk-grape"
[03740.567] 07997.08260> [03740.567866][1230184835][0][netstack] INFO: socket_conv.go(523): unimplemented setsockopt: SOL_IPV6 name=67 optVal=20000000
[03740.567] 233782.233794> setsockopt IPV6_TCLASS 32: Protocol not available: