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

2018/12/15 23:25:39 properties flag: /etc/botanist/config.json 2018/12/15 23:25:39 starting log listener attempting to send <<image>>sparse.fvm=fvm.sparse.blk...[00000.000] 00000.00000> zbi: @ 0xffffff8000d92000 (11879096 bytes) [00000.000] 00000.00000> PMM: boot reserve add [0x100000, 0x2bcfff] [00000.000] 00000.00000> PMM: boot reserve add [0xd92000, 0x18e6fff] [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 0x8afff000 size 0x1000 [00000.000] 00000.00000> PMM: boot reserve marking WIRED [0x100000, 0x2bcfff] [00000.000] 00000.00000> PMM: boot reserve marking WIRED [0xd92000, 0x18e6fff] [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 0xffffffff001ac398 (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 [0x18e7000, 0x18e7100) [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00147b90 (elf_build_id) at level 0x4fffe, flags 0x1 [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00147d1c (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-71785cd38a478fd12119897e6c8514fd7fdb1bf3-dirty [00000.000] 00000.00000> ELF build ID: 1f5e3e417ba1f67767aa444fd66f7c0ae3e572fc [00000.000] 00000.00000> initializing heap [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00103420 (x86_resource_init) at level 0x50000, flags 0x1 [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001ab000 (console) at level 0x50000, flags 0x1 [00000.000] 00000.00000> initializing vm [00000.000] 00000.00000> VM: reserving kernel region [0xffffffff00100000, 0xffffffff001eb000) flags 0x28 name 'kernel_code' [00000.000] 00000.00000> VM: reserving kernel region [0xffffffff001eb000, 0xffffffff0022a000) flags 0x8 name 'kernel_rodata' [00000.000] 00000.00000> VM: reserving kernel region [0xffffffff0022a000, 0xffffffff0023a000) flags 0x18 name 'kernel_data' [00000.000] 00000.00000> VM: reserving kernel region [0xffffffff0023a000, 0xffffffff002bd000) flags 0x18 name 'kernel_bss' [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00101168 (acpi_tables) at level 0x60001, flags 0x1 [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001041c0 (display_memtype) at level 0x60001, flags 0x1 [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff0010212c (hpet) at level 0x60002, flags 0x1 [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001024b4 (apic) at level 0x60002, flags 0x1 [00000.000] 00000.00000> x2APIC enabled [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00106ec8 (timer) at level 0x60003, flags 0x1 [00000.000] 00000.00000> HPET frequency: 23999 ticks/ms [00000.000] 00000.00000> TSC frequency: 2712000 ticks/ms [00020.383] 00000.00000> timer features: constant_tsc 1 invariant_tsc 1 tsc_deadline 1 [00020.383] 00000.00000> Using TSC as wallclock [00020.383] 00000.00000> initializing kernel [00020.383] 00000.00000> initializing mp [00020.383] 00000.00000> initializing timers [00020.383] 00000.00000> INIT: cpu 0, calling hook 0xffffffff0013b230 (debuglog) at level 0x7ffff, flags 0x1 [00020.383] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00197624 (thread_set_priority_experiment) at level 0x7ffff, flags 0x1 [00020.383] 00000.00000> thread set priority experiment is : ENABLED [00020.383] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001ac5f8 (global_prng_thread_safe) at level 0x7ffff, flags 0x1 [00020.383] 00000.00000> creating bootstrap completion thread [00020.383] 00000.00000> top of bootstrap2() [00020.383] 00000.00000> INIT: cpu 0, calling hook 0xffffffff0012fe24 (dpc) at level 0x80000, flags 0x1 [00020.383] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001552b4 (libobject) at level 0x80000, flags 0x1 [00020.383] 00000.00000> OOM: started thread [00020.383] 00000.00000> Processor Model Info: type 0 family 0x6 model 0xe stepping 0x9 [00020.383] 00000.00000> display_family 0x6 display_model 0x8e [00020.383] 00000.00000> Vendor: Intel [00020.383] 00000.00000> Microarch: Kaby Lake [00020.383] 00000.00000> F/M/S: 6/8e/9 [00020.383] 00000.00000> Brand: Intel(R) Core(TM) i5-7300U CPU @ 2.60GHz [00020.383] 00000.00000> Features: fpu sse sse2 sse3 ssse3 sse4.1 sse4.2 mmx avx avx2 fxsr pcid xsave mon aesni clflush [00020.383] 00000.00000> clflushopt fsgsbase tsc_adj smep smap erms rdrand rdseed syscall nx huge rdtscp [00020.383] 00000.00000> invar_tsc tsc_deadline x2apic vmx pt hwp [00020.383] 00000.00000> initializing platform [00020.383] 00000.00000> cpu topology: [00020.383] 00000.00000> 0: apic id 0x0 package 0 node 0 core 0 smt 0 BSP [00020.383] 00000.00000> 1: apic id 0x2 package 0 node 0 core 1 smt 0 [00020.383] 00000.00000> 2: apic id 0x1 package 0 node 0 core 0 smt 1 [00020.383] 00000.00000> 3: apic id 0x3 package 0 node 0 core 1 smt 1 [00020.383] 00000.00000> Found 4 cpus [00020.383] 00000.00000> booting apic ids: 0x2 0x1 0x3 [00020.398] 00000.00000> entering scheduler on cpu 2 [00020.400] 00000.00000> entering scheduler on cpu 3 [00020.400] 00000.00000> entering scheduler on cpu 1 [00020.402] 00000.00000> smbios: manufacturer="Intel Corporation" product="NUC7i5DNKE" [00020.402] 00000.00000> initializing target [00020.402] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00105dfc (x86_pcie_init) at level 0xa0000, flags 0x1 [00020.402] 00000.00000> moving to last init level [00020.402] 00000.00000> INIT: cpu 0, calling hook 0xffffffff0014323c (ktrace) at level 0xc0000, flags 0x1 [00020.405] 00000.00000> ktrace: buffer at 0xffffff9d42982000 (33554432 bytes) [00020.405] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00147b88 (userboot) at level 0xc0000, flags 0x1 [00020.405] 00000.00000> userboot: ramdisk 0xb55000 @ 0xffffff8000d92000 [00020.406] 00000.00000> userboot: userboot rodata 0 @ [0x4aee5fccb000,0x4aee5fcce000) [00020.406] 00000.00000> userboot: userboot code 0x3000 @ [0x4aee5fcce000,0x4aee5fcd9000) [00020.406] 00000.00000> userboot: vdso/full rodata 0 @ [0x4aee5fcd9000,0x4aee5fcdf000) [00020.406] 00000.00000> userboot: vdso/full code 0x6000 @ [0x4aee5fcdf000,0x4aee5fce0000) [00020.406] 00000.00000> userboot: entry point @ 0x4aee5fccebe0 [00020.406] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001abab0 (kernel_shell) at level 0xc0000, flags 0x1 [00020.406] 01034.01041> userboot: option "netsvc.disable=true" [00020.406] 01034.01041> userboot: option "zircon.system.disable-automount=true" [00020.406] 01034.01041> userboot: option "zircon.autorun.boot=/boot/infra/setup" [00020.406] 01034.01041> userboot: option "http://192.168.42.1/multiboot/d4%3A5d%3Adf%3A00%3Ad9%3A20=" [00020.406] 01034.01041> userboot: option "multiboot.boot_loader_name=iPXE+1.0.0++(d2063)" [00020.432] 01034.01041> userboot: searching bootfs for 'bin/devmgr' [00020.432] 01034.01041> userboot: 'bin/devmgr' has PT_INTERP "lib/ld.so.1" [00020.432] 01034.01041> userboot: searching bootfs for 'lib/ld.so.1' [00020.432] 01034.01041> userboot: userboot: loaded lib/ld.so.1 at 0x52daddde4000, entry point 0x52dadde6a5e3 [00020.432] 01034.01041> userboot: userboot: loaded vDSO at 0x5c6693d94000, entry point 0x0 [00020.432] 01034.01041> userboot: process bin/devmgr started. [00020.432] 01034.01041> userboot: waiting for loader-service requests... [00020.433] 01034.01041> userboot: searching bootfs for 'lib/libasync-default.so' [00020.433] 01034.01041> userboot: searching bootfs for 'lib/liblaunchpad.so' [00020.433] 01034.01041> userboot: searching bootfs for 'lib/libfdio.so' [00020.433] 01048.01051> {{{reset}}} [00020.433] 01048.01051> {{{module:0:<application>:elf:adb289d09c14e41d57cc06e64c3fbad20af116de}}} [00020.433] 01048.01051> {{{mmap:0x7259c4677000:0x16000:load:0:rx:0}}} [00020.433] 01048.01051> {{{mmap:0x7259c468e000:0x2000:load:0:rw:0x17000}}} [00020.433] 01048.01051> dso: id=adb289d09c14e41d57cc06e64c3fbad20af116de base=0x00007259c4677000 name=<application> [00020.433] 01048.01051> {{{module:0x3:libasync-default.so:elf:e185a560eff06a87149e82ac163f0cab85d35cd2}}} [00020.433] 01048.01051> {{{mmap:0x60047e766000:0x1000:load:0x3:rx:0}}} [00020.433] 01048.01051> {{{mmap:0x60047e767000:0x1000:load:0x3:rw:0x1000}}} [00020.433] 01048.01051> dso: id=e185a560eff06a87149e82ac163f0cab85d35cd2 base=0x000060047e766000 name=libasync-default.so [00020.433] 01048.01051> {{{module:0x4:liblaunchpad.so:elf:8b03b75574d08d314aa5efad9a560559dba03719}}} [00020.433] 01048.01051> {{{mmap:0x683729295000:0x7000:load:0x4:rx:0}}} [00020.433] 01048.01051> {{{mmap:0x68372929c000:0x2000:load:0x4:rw:0x7000}}} [00020.433] 01048.01051> dso: id=8b03b75574d08d314aa5efad9a560559dba03719 base=0x0000683729295000 name=liblaunchpad.so [00020.433] 01048.01051> {{{module:0x5:libfdio.so:elf:67093cd5a6d51815a7899f50f338c85506c5afeb}}} [00020.433] 01048.01051> {{{mmap:0x5eb0f0b7c000:0x1f000:load:0x5:rx:0}}} [00020.433] 01048.01051> {{{mmap:0x5eb0f0b9c000:0x4000:load:0x5:rw:0x20000}}} [00020.433] 01048.01051> dso: id=67093cd5a6d51815a7899f50f338c85506c5afeb base=0x00005eb0f0b7c000 name=libfdio.so [00020.433] 01048.01051> {{{module:0x2:<vDSO>:elf:669f338dda92c28c851da7148fb092cfbae24e8b}}} [00020.433] 01048.01051> {{{mmap:0x5c6693d94000:0x6000:load:0x2:r:0}}} [00020.433] 01048.01051> {{{mmap:0x5c6693d9a000:0x1000:load:0x2:rx:0x6000}}} [00020.433] 01048.01051> dso: id=669f338dda92c28c851da7148fb092cfbae24e8b base=0x00005c6693d94000 name=<vDSO> [00020.433] 01048.01051> {{{module:0x1:libc.so:elf:f994d740a587fd43637c52aa7659f5ec4e448248}}} [00020.433] 01048.01051> {{{mmap:0x52daddde4000:0xcb000:load:0x1:rx:0}}} [00020.433] 01048.01051> {{{mmap:0x52daddeb0000:0x6000:load:0x1:rw:0xcc000}}} [00020.433] 01048.01051> dso: id=f994d740a587fd43637c52aa7659f5ec4e448248 base=0x000052daddde4000 name=libc.so [00020.433] 01034.01041> userboot: loader-service channel peer closed [00020.433] 01034.01041> userboot: finished! [00020.433] 01048.01051> devmgr: main() [00020.433] 01048.01051> devmgr: init [00020.433] 01048.01051> coordinator_init() [00020.433] 01048.01051> bootfs_open: 'config/devmgr' not found [00020.433] 01048.01051> cmdline: netsvc.disable=true [00020.433] 01048.01051> cmdline: zircon.system.disable-automount=true [00020.433] 01048.01051> cmdline: zircon.autorun.boot=/boot/infra/setup [00020.433] 01048.01051> cmdline: http://192.168.42.1/multiboot/d4%3A5d%3Adf%3A00%3Ad9%3A20= [00020.433] 01048.01051> cmdline: multiboot.boot_loader_name=iPXE+1.0.0++(d2063) [00020.433] 01048.01051> devmgr: svc init [00020.433] 01048.01051> devmgr: launch /boot/bin/svchost (svchost) OK [00020.433] 01048.01051> devmgr: vfs init [00020.434] 01048.01051> devmgr: launch /boot/bin/fshost (fshost) OK [00020.434] 01048.01167> devmgr: shell startup [00020.434] 01048.01051> devmgr: coordinator() [00020.435] 01130.01144> fshost: started. [00020.436] 01048.01159> devmgr: launch /boot/bin/pwrbtn-monitor (pwrbtn-monitor) OK [00020.436] 01048.01181> devmgr: launch /boot/bin/crashsvc (crashsvc) OK [00020.436] 01048.01181> devmgr: launch /boot/bin/virtual-console (virtual-console) OK [00020.437] 01048.01181> zircon.autorun.boot: starting '/boot/infra/setup'... [00020.437] 01048.01181> devmgr: launch /boot/infra/setup (autorun:boot) OK [00020.440] 01048.01051> devcoord: launch devhost 'devhost:sys': pid=1951 [00020.440] 01048.01051> devcoord: launch devhost 'devhost:test': pid=1984 [00020.440] 01048.01051> devcoord: launch devhost 'devhost:root': pid=2017 [00020.441] 01048.01051> devcoord: launch devhost 'devhost:misc': pid=2073 [00020.508] 01951.01975> acpi-bus: not using IOMMU [00020.539] 01951.01975> acpi-pwrbtn: initialized [00020.540] 01951.01975> acpi: published device pci(0x738895661000), parent=proxy(0x738895704480), handle=0x738895682780 [00020.541] 01951.01975> acpi: published device rtc(0x73889564e000), parent=acpi(0x738895704600), handle=0x73889569b1c0 [00020.542] 01048.01167> devmgr: launch /boot/bin/sh (sh:console) OK [00020.542] 01951.01975> acpi-ec: initialized [00020.543] 01951.01975> acpi: failed to create NHLT VMO (res -10) [00020.543] 01951.01975> acpi: failed to publish NHLT metadata [00020.545] 01951.01975> Intel Processor Trace configuration for this chipset: [00020.545] 01951.01975> mtc_freq_mask: 0x249 [00020.545] 01951.01975> cyc_thresh_mask: 0x3fff [00020.545] 01951.01975> psb_freq_mask: 0x3f [00020.545] 01951.01975> num addr ranges: 2 [00020.545] 01951.01975> mtrace_ipm_control:34: action 0, options 0x0, arg 0x3271fe233ac0, size 0x20 [00020.546] 01048.01051> devcoord: launch devhost 'devhost:pci#1:8086:5916': pid=2597 [00020.546] 01048.01051> devcoord: launch devhost 'devhost:pci#3:8086:9d2f': pid=2644 [00020.546] 01048.01051> devcoord: launch devhost 'devhost:pci#5:8086:9d60': pid=2706 [00020.547] 01048.01051> devcoord: launch devhost 'devhost:pci#6:8086:9d61': pid=2765 [00020.548] 01048.01051> devcoord: launch devhost 'devhost:pci#9:8086:9d03': pid=2840 [00020.548] 01048.01051> devcoord: launch devhost 'devhost:pci#14:8086:9d71': pid=2968 [00020.549] 01048.01051> devcoord: launch devhost 'devhost:pci#16:8086:156f': pid=3029 [00020.550] 02765.02807> initialized intel serialio i2c driver, reg=0x232074d2c000 regsize=4096 [00020.550] 02706.02738> initialized intel serialio i2c driver, reg=0x1b9095b70000 regsize=4096 [00020.552] 02840.02898> ahci: using MSI interrupt [00020.554] 03029.03071> eth: using MSI mode [00020.554] 03029.03071> eth: mac: d4:5d:df:00:d9:20 [00020.554] 03029.03071> eth: iomem @0xb0606599000 (phys e93000) [00020.554] 03029.03071> eth: intel-ethernet online [00020.555] 02644.03323> * found USB device (0x18d1:0xa002, USB 2.0) config 1 [00020.555] 02644.03323> * found USB device (0x18d1:0xa003, USB 3.0) config 1 [00020.564] 02968.03010> [IHDA DSP 00:1f.3] Failed to fetch NHLT (res -25) [00020.564] 02968.03010> devhost[00:1f.3/intel-hda-000/intel-sst-dsp-000] bind driver '/boot/driver/dsp.so' failed: -25 [00020.564] 01048.01051> devcoord: rpc: bind-driver 'intel-sst-dsp-000' status -25 [00020.777] 02597.03567> i915: MST not supported [00020.792] 02765.03154> i2c: tx abort detected: 0x05000001 [00020.792] 02765.02807> i2c-hid: could not read HID descriptor: -40 [00020.792] 02765.02807> devhost[00:15.1/i2c-bus-9d61/004c] bind driver '/boot/driver/i2c-hid.so' failed: -2 [00020.792] 01048.01051> devcoord: rpc: bind-driver '004c' status -2 [00021.110] 02597.03567> i915: Found DP monitor [00021.110] 02597.03567> i915: Display 1 connected [00021.268] 02644.03323> * found USB device (0x0781:0x5583, USB 3.0) config 1 [00021.269] 02644.02678> UMS:Max lun is: 0 [00021.684] 01354.01413> vc: Successfully attached to display 1 [00021.684] 01354.01413> vc: new input device /dev/class/input/000 [00022.018] 02644.03323> * found USB device (0x8087:0x0a2b, USB 2.0) config 1 [00022.020] 02644.02678> devhost[00:14.0/xhci/usb/002/ifc-001] bind driver '/boot/driver/bt-transport-usb.so' failed: -2 [00022.020] 01048.01051> devcoord: rpc: bind-driver 'ifc-001' status -2 [00022.271] 02644.03647> UMS: block size is: 0x00000200 [00022.271] 02644.03647> UMS: total blocks is: 30031872 [00022.271] 02644.03647> UMS: total size is: 15376318464 [00022.271] 02644.03647> UMS: read-only: 0 removable: 1 [00022.271] 01130.01144> devmgr: /dev/class/block/000: MBR? [00022.272] 01048.01051> devcoord: dc_bind_device() '/boot/driver/mbr.so' [00022.274] 01130.01144> devmgr: /dev/class/block/002: MBR? [00022.274] 01048.01051> devcoord: dc_bind_device() '/boot/driver/mbr.so' [00022.554] 02706.02738> i2c-hid: could not read HID descriptor: -21 [00022.554] 02706.02738> devhost[00:15.0/i2c-bus-9d60/0020] bind driver '/boot/driver/i2c-hid.so' failed: -2 [00022.554] 01048.01051> devcoord: rpc: bind-driver '0020' status -2 [00022.567] 02840.03260> sata2: dev info [00022.567] 02840.03260> serial=715400411010 3 [00022.567] 02840.03260> firmware rev=1P11A1E_ [00022.567] 02840.03260> model id=IBIW NSS D [00022.567] 02840.03260> major=0x3f0 ACS2 DMA 32 commands [00022.567] 02840.03260> LBA48 250069680 sectors, sector size=512 [00022.568] 01130.01144> devmgr: /dev/class/block/003: GPT? [00022.568] 01048.01051> devcoord: dc_bind_device() '/boot/driver/gpt.so' [00022.569] 01130.01144> devmgr: /dev/class/block/004: FVM? [00022.569] 01048.01051> devcoord: dc_bind_device() '/boot/driver/fvm.so' [00022.572] 01130.01144> devmgr: /dev/class/block/007: zxcrypt? [00022.572] 01048.01051> devcoord: dc_bind_device() '/boot/driver/zxcrypt.so' [00022.633] 04121.04146> 1024+0 records in [00022.633] 04121.04146> 1024+0 records out [00022.633] 04121.04146> 4194304 bytes copied [00022.634] 05379.05393> netifc: ? /dev/class/ethernet/000 [00022.634] 05379.05393> netifc: create 512 eth buffers [00022.634] 05379.05393> macaddr: d4:5d:df:00:d9:20 [00022.634] 05379.05393> ip6addr: fe80::d65d:df4d:fe00:d920 [00022.634] 05379.05393> snmaddr: ff02::1:ff00:d920 [00022.634] 05379.05393> netsvc: using /dev/class/ethernet/000 [00022.634] 05379.05393> _ _ _ [00022.634] 05379.05393> | | | | | [00022.634] 05379.05393> _______ __| | |__ ___ ___ | |_ [00022.634] 05379.05393> |_ / _ \/ _` | '_ \ / _ \ / _ \| __| [00022.634] 05379.05393> / / __/ (_| | |_) | (_) | (_) | |_ [00022.634] 05379.05393> /___\___|\__,_|_.__/ \___/ \___/ \__| [00022.634] 05379.05393> [00022.634] 05379.05393> [00022.634] 05379.05393> zedboot: version: 0.7.10 [00022.634] 05379.05393> [00022.634] 05379.05393> netsvc: nodename='viral-blush-shiny-grew' [00022.634] 05379.05393> netsvc: will not advertise [00022.634] 05379.05393> netsvc: start [01032.460] 05379.05393> netsvc: Running FVM Paver [01032.462] 05379.05485> install-disk-image:[InitializeGpt] Located GPT is invalid; Attempting to initialize [01032.463] 01048.01051> devcoord: dc_bind_device() '' [01032.464] 01048.01051> devcoord: dc_bind_device() '/boot/driver/gpt.so' [01032.464] 01130.01144> devmgr: /dev/class/block/003: GPT? [01032.464] 01048.01051> devcoord: dc_bind_device() '/boot/driver/gpt.so' [01032.465] 05379.05485> install-disk-image:[Initialize] Successfully intitialized EFI Device Partitioner [01032.465] 05379.05485> install-disk-image:[FvmPave] Paving FVM [01032.465] 05379.05485> install-disk-image:[FvmPave] Could not find FVM; attempting to add it: ZX_ERR_NOT_FOUND [01032.465] 05379.05485> install-disk-image:[FindFirstFit] Looking for space [01032.465] 05379.05485> install-disk-image:[FindFirstFit] Sorting [01032.465] 05379.05485> install-disk-image:[FindFirstFit] Partition[0] From Block [0, 34) ... (next partition starts at block 250069646) [01032.465] 05379.05485> install-disk-image:[FindFirstFit] There are 250069612 free blocks (16777216 requested) [01032.465] 05379.05485> install-disk-image:[AddPartition] Found space in GPT - OK 250069612 @ 34 [01032.465] 05379.05485> install-disk-image:[AddPartition] Final space in GPT - OK 16777216 @ 34 [01032.465] 01048.01051> devcoord: dc_bind_device() '' [01032.465] 05379.05485> install-disk-image:[AddPartition] Added partition, waiting for bind [01032.465] 01130.01144> devmgr: /dev/class/block/003: GPT? [01032.465] 01048.01051> devcoord: dc_bind_device() '/boot/driver/gpt.so' [01032.466] 05379.05485> install-disk-image:[AddPartition] Added partition, waiting for bind - OK [01032.466] 05379.05485> install-disk-image:[FvmPave] Streaming partitions... [01032.466] 05465.05479> Found compressed file [01032.466] 05379.05485> install-disk-image:[FvmStreamPartitions] Header Validated - OK [01032.467] 05379.05485> install-disk-image:[FvmPartitionFormat] Initializing partition as FVM [01032.469] 01048.01051> devcoord: dc_bind_device() '/boot/driver/fvm.so' [01034.471] 05379.05485> install-disk-image:[FvmStreamPartitions] Allocating partition blobfs consisting of 1 slices [01034.472] 05379.05485> install-disk-image:[FvmStreamPartitions] Extending partition[0] at offset 64 by length 1 [01034.473] 05379.05485> install-disk-image:[FvmStreamPartitions] Extending partition[0] at offset 128 by length 1 [01034.474] 05379.05485> install-disk-image:[FvmStreamPartitions] Extending partition[0] at offset 192 by length 1 [01034.474] 05379.05485> install-disk-image:[FvmStreamPartitions] Extending partition[0] at offset 256 by length 47 done attempting to send <<image>>efi.img=fuchsia.esp.blk...target is busy, retrying in one second [01035.960] 05379.05393> netsvc: tftp write of file <<image>>sparse.fvm completed [01036.475] 05379.05485> install-disk-image:[FvmStreamPartitions] Allocating partition minfs consisting of 1 slices [01036.476] 01130.01144> devmgr: /dev/class/block/011: zxcrypt? [01036.476] 01048.01051> devcoord: dc_bind_device() '/boot/driver/zxcrypt.so' [01036.477] 05379.05485> install-disk-image:[FvmStreamPartitions] Creating zxcrypt volume [01036.477] 02840.02898> devhost_get_handles(0x37664a8289c0:block) open path='zxcrypt/block', r=-2 [01036.477] 01048.01051> devcoord: dc_bind_device() '/boot/driver/zxcrypt.so' [01036.477] 02840.02898> devhost_get_handles(0x37664a8289c0:block) open path='zxcrypt', r=-2 [01036.478] 05379.05485> install-disk-image:[FvmStreamPartitions] Extending partition[1] at offset 64 by length 1 [01036.479] 05379.05485> install-disk-image:[FvmStreamPartitions] Extending partition[1] at offset 128 by length 1 [01036.479] 05379.05485> install-disk-image:[FvmStreamPartitions] Extending partition[1] at offset 192 by length 1 [01036.480] 05379.05485> install-disk-image:[FvmStreamPartitions] Extending partition[1] at offset 256 by length 2 [01036.480] 05379.05485> install-disk-image:[FvmStreamPartitions] Extending partition[1] at offset 320 by length 1 [01036.481] 05379.05485> install-disk-image:[FvmStreamPartitions] Partition space pre-allocated [01036.481] 05379.05485> install-disk-image:[FvmStreamPartitions] Streaming partition 0 [01036.481] 05379.05485> install-disk-image:[StreamFvmPartition] Writing extent 0... [01036.481] 05379.05491> netsvc: paver write progress 0.1% [01036.481] 05379.05485> install-disk-image:[StreamFvmPartition] 8192 bytes written, 8380416 zeroes left [01036.531] 05379.05485> install-disk-image:[StreamFvmPartition] Writing extent 1... [01036.533] 05379.05485> install-disk-image:[StreamFvmPartition] 8192 bytes written, 8380416 zeroes left [01036.583] 05379.05485> install-disk-image:[StreamFvmPartition] Writing extent 2... [01036.597] 05379.05485> install-disk-image:[StreamFvmPartition] 2097152 bytes written, 6291456 zeroes left [01036.638] 05379.05485> install-disk-image:[StreamFvmPartition] Writing extent 3... [01036.652] 05379.05485> install-disk-image:[StreamFvmPartition] 2097152 bytes written, 6291456 zeroes left [01036.694] 05379.05485> install-disk-image:[StreamFvmPartition] Writing extent 4... attempting to send <<image>>efi.img=fuchsia.esp.blk...target is busy, retrying in one second [01037.485] 05379.05491> netsvc: paver write progress 30.2% attempting to send <<image>>efi.img=fuchsia.esp.blk...target is busy, retrying in one second [01038.491] 05379.05491> netsvc: paver write progress 69.8% attempting to send <<image>>efi.img=fuchsia.esp.blk...target is busy, retrying in one second [01039.248] 05379.05485> install-disk-image:[StreamFvmPartition] 393248768 bytes written, 1015808 zeroes left [01039.252] 05379.05485> install-disk-image:[FvmStreamPartitions] Done streaming partition 0 [01039.252] 05379.05485> install-disk-image:[FvmStreamPartitions] Done flushing partition 0 [01039.252] 05379.05485> install-disk-image:[FvmStreamPartitions] Streaming partition 1 [01039.252] 05379.05485> install-disk-image:[StreamFvmPartition] Writing extent 0... [01039.254] 05379.05485> install-disk-image:[StreamFvmPartition] 8192 bytes written, 8380416 zeroes left [01039.308] 05379.05485> install-disk-image:[StreamFvmPartition] Writing extent 1... [01039.309] 05379.05485> install-disk-image:[StreamFvmPartition] 65536 bytes written, 8323072 zeroes left [01039.363] 05379.05485> install-disk-image:[StreamFvmPartition] Writing extent 2... [01039.364] 05379.05485> install-disk-image:[StreamFvmPartition] 65536 bytes written, 8323072 zeroes left [01039.418] 05379.05485> install-disk-image:[StreamFvmPartition] Writing extent 3... [01039.472] 05379.05485> install-disk-image:[StreamFvmPartition] Writing extent 4... [01039.486] 05379.05485> install-disk-image:[StreamFvmPartition] 2097152 bytes written, 14680064 zeroes left [01039.582] 05379.05485> install-disk-image:[StreamFvmPartition] Writing extent 5... [01039.583] 05379.05485> install-disk-image:[StreamFvmPartition] 57344 bytes written, 8331264 zeroes left [01039.637] 05379.05485> install-disk-image:[FvmStreamPartitions] Done streaming partition 1 [01039.637] 05379.05485> install-disk-image:[FvmStreamPartitions] Done flushing partition 1 [01039.638] 05465.05479> Reading FVM from compressed file: true [01039.638] 05465.05479> Remaining bytes read into compression buffer: 0 [01039.638] 05465.05479> Remaining bytes written to decompression buffer: 0 [01039.638] 05465.05479> Time reading bytes from sparse FVM file: 128649928 (0 s) [01039.638] 05465.05479> Time reading bytes AND decompressing them: 452022099 (0 s) [01039.638] 05379.05485> install-disk-image:[FvmPave] Completed successfully attempting to send <<image>>efi.img=fuchsia.esp.blk...done attempting to send <<netboot>>kernel.bin=test-infra.zbi...target is busy, retrying in one second [01039.963] 05379.05393> netsvc: Running EFI Paver [01039.966] 05379.06403> install-disk-image:[Initialize] Successfully intitialized EFI Device Partitioner [01039.966] 05379.06403> install-disk-image:[PartitionPave] Paving partition. [01039.966] 05379.06403> install-disk-image:[FindFirstFit] Looking for space [01039.966] 05379.06403> install-disk-image:[FindFirstFit] Partition seen with start 34, end 16777249 (length 16777216) [01039.966] 05379.06403> install-disk-image:[FindFirstFit] Sorting [01039.966] 05379.06403> install-disk-image:[FindFirstFit] Partition[0] From Block [0, 34) ... (next partition starts at block 34) [01039.966] 05379.06403> install-disk-image:[FindFirstFit] There are 0 free blocks (2097152 requested) [01039.966] 05379.06403> install-disk-image:[FindFirstFit] Partition[1] From Block [34, 16777250) ... (next partition starts at block 250069646) [01039.966] 05379.06403> install-disk-image:[FindFirstFit] There are 233292396 free blocks (2097152 requested) [01039.966] 05379.06403> install-disk-image:[AddPartition] Found space in GPT - OK 233292396 @ 16777250 [01039.966] 05379.06403> install-disk-image:[AddPartition] Final space in GPT - OK 2097152 @ 16777250 [01039.968] 01048.01051> devcoord: dc_bind_device() '' [01039.968] 05379.06403> install-disk-image:[AddPartition] Added partition, waiting for bind [01039.968] 01130.01144> devmgr: /dev/class/block/003: GPT? [01039.968] 01048.01051> devcoord: dc_bind_device() '/boot/driver/gpt.so' [01039.969] 01130.01144> devmgr: /dev/class/block/013: FVM? [01039.969] 01048.01051> devcoord: dc_bind_device() '/boot/driver/fvm.so' [01039.969] 05379.06403> install-disk-image:[AddPartition] Added partition, waiting for bind - OK [01039.971] 01130.01144> devmgr: /dev/class/block/016: zxcrypt? [01039.971] 01048.01051> devcoord: dc_bind_device() '/boot/driver/zxcrypt.so' [01039.979] 05379.05393> netsvc: tftp write of file <<image>>efi.img completed [01039.982] 05379.06403> install-disk-image:[PartitionPave] Completed successfully attempting to send <<netboot>>kernel.bin=test-infra.zbi...done 2018/12/15 23:25:48 sending cmdline "zircon.autorun.system=/boot/bin/sh+/boot/infra/runcmds " 2018/12/15 23:25:48 sending boot command 2018/12/15 23:25:48 waiting for "summary.json" [00000.000] 00000.00000> zbi: @ 0xffffff8005cb0000 (5584776 bytes) [00000.000] 00000.00000> PMM: boot reserve add [0x100000, 0x2b5fff] [00000.000] 00000.00000> PMM: boot reserve add [0x5cb0000, 0x6203fff] [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 0x8afff000 size 0x1000 [00000.000] 00000.00000> PMM: boot reserve marking WIRED [0x100000, 0x2b5fff] [00000.000] 00000.00000> PMM: boot reserve marking WIRED [0x5cb0000, 0x6203fff] [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 0xffffffff001a0e3c (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 [0x6204000, 0x6204100) [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00142b00 (elf_build_id) at level 0x4fffe, flags 0x1 [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00142c8c (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-6a20498ad5747c7a813109cf832b6757f5a9f325 [00000.000] 00000.00000> ELF build ID: c6376d362aad4a9129fefd85c55f33eb3b484126 [00000.000] 00000.00000> initializing heap [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001033d8 (x86_resource_init) at level 0x50000, flags 0x1 [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff0019f2bc (console) at level 0x50000, flags 0x1 [00000.000] 00000.00000> initializing vm [00000.000] 00000.00000> VM: reserving kernel region [0xffffffff00100000, 0xffffffff001e0000) flags 0x28 name 'kernel_code' [00000.000] 00000.00000> VM: reserving kernel region [0xffffffff001e0000, 0xffffffff00222000) flags 0x8 name 'kernel_rodata' [00000.000] 00000.00000> VM: reserving kernel region [0xffffffff00222000, 0xffffffff00232000) flags 0x18 name 'kernel_data' [00000.000] 00000.00000> VM: reserving kernel region [0xffffffff00232000, 0xffffffff002b6000) flags 0x18 name 'kernel_bss' [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00101168 (acpi_tables) at level 0x60001, flags 0x1 [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001040a8 (display_memtype) at level 0x60001, flags 0x1 [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00102130 (hpet) at level 0x60002, flags 0x1 [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001024b8 (apic) at level 0x60002, flags 0x1 [00000.000] 00000.00000> x2APIC enabled [00000.000] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001067d4 (timer) at level 0x60003, flags 0x1 [00000.000] 00000.00000> HPET frequency: 23999 ticks/ms [00000.000] 00000.00000> TSC frequency: 2712000 ticks/ms [01041.331] 00000.00000> timer features: constant_tsc 1 invariant_tsc 1 tsc_deadline 1 [01041.331] 00000.00000> Using TSC as wallclock [01041.331] 00000.00000> initializing kernel [01041.331] 00000.00000> initializing mp [01041.331] 00000.00000> initializing timers [01041.331] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00137774 (debuglog) at level 0x7ffff, flags 0x1 [01041.331] 00000.00000> INIT: cpu 0, calling hook 0xffffffff0018d284 (thread_set_priority_experiment) at level 0x7ffff, flags 0x1 [01041.331] 00000.00000> thread set priority experiment is : ENABLED [01041.331] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001a1090 (global_prng_thread_safe) at level 0x7ffff, flags 0x1 [01041.331] 00000.00000> creating bootstrap completion thread [01041.331] 00000.00000> top of bootstrap2() [01041.331] 00000.00000> INIT: cpu 0, calling hook 0xffffffff0012dc54 (dpc) at level 0x80000, flags 0x1 [01041.331] 00000.00000> INIT: cpu 0, calling hook 0xffffffff0014d980 (libobject) at level 0x80000, flags 0x1 [01041.331] 00000.00000> OOM: started thread [01041.331] 00000.00000> Processor Model Info: type 0 family 0x6 model 0xe stepping 0x9 [01041.331] 00000.00000> display_family 0x6 display_model 0x8e [01041.331] 00000.00000> Vendor: Intel [01041.331] 00000.00000> Microarch: Kaby Lake [01041.331] 00000.00000> F/M/S: 6/8e/9 [01041.331] 00000.00000> Brand: Intel(R) Core(TM) i5-7300U CPU @ 2.60GHz [01041.331] 00000.00000> Features: fpu sse sse2 sse3 ssse3 sse4.1 sse4.2 mmx avx avx2 fxsr pcid xsave mon aesni clflush [01041.331] 00000.00000> clflushopt fsgsbase tsc_adj smep smap erms rdrand rdseed syscall nx huge rdtscp [01041.331] 00000.00000> invar_tsc tsc_deadline x2apic vmx pt hwp [01041.331] 00000.00000> initializing platform [01041.331] 00000.00000> INIT: cpu 0, calling hook 0xffffffff0011084c (x86_perfmon) at level 0x90000, flags 0x1 [01041.331] 00000.00000> PMU: version 4 [01041.331] 00000.00000> cpu topology: [01041.331] 00000.00000> 0: apic id 0x0 package 0 node 0 core 0 smt 0 BSP [01041.331] 00000.00000> 1: apic id 0x2 package 0 node 0 core 1 smt 0 [01041.331] 00000.00000> 2: apic id 0x1 package 0 node 0 core 0 smt 1 [01041.331] 00000.00000> 3: apic id 0x3 package 0 node 0 core 1 smt 1 [01041.331] 00000.00000> Found 4 cpus [01041.331] 00000.00000> booting apic ids: 0x2 0x1 0x3 [01041.346] 00000.00000> entering scheduler on cpu 2 [01041.347] 00000.00000> entering scheduler on cpu 1 [01041.347] 00000.00000> entering scheduler on cpu 3 [01041.350] 00000.00000> smbios: manufacturer="Intel Corporation" product="NUC7i5DNKE" [01041.350] 00000.00000> initializing target [01041.350] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001059b8 (x86_pcie_init) at level 0xa0000, flags 0x1 [01041.350] 00000.00000> moving to last init level [01041.350] 00000.00000> INIT: cpu 0, calling hook 0xffffffff0013f338 (ktrace) at level 0xc0000, flags 0x1 [01041.353] 00000.00000> ktrace: buffer at 0xffffff989c8d9000 (33554432 bytes) [01041.353] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00142af8 (userboot) at level 0xc0000, flags 0x1 [01041.353] 00000.00000> userboot: ramdisk 0x554000 @ 0xffffff8005cb0000 [01041.353] 00000.00000> userboot: userboot rodata 0 @ [0x6c57b82bf000,0x6c57b82c2000) [01041.353] 00000.00000> userboot: userboot code 0x3000 @ [0x6c57b82c2000,0x6c57b82cd000) [01041.353] 00000.00000> userboot: vdso/full rodata 0 @ [0x6c57b82cd000,0x6c57b82d4000) [01041.353] 00000.00000> userboot: vdso/full code 0x7000 @ [0x6c57b82d4000,0x6c57b82d5000) [01041.353] 00000.00000> userboot: entry point @ 0x6c57b82c2c10 [01041.353] 00000.00000> INIT: cpu 0, calling hook 0xffffffff0019fcbc (kernel_shell) at level 0xc0000, flags 0x1 [01041.353] 01034.01041> userboot: option "zircon.autorun.system=/boot/bin/sh+/boot/infra/runcmds" [01041.366] 01034.01041> userboot: searching bootfs for 'bin/bootsvc' [01041.366] 01034.01041> userboot: 'bin/bootsvc' has PT_INTERP "lib/ld.so.1" [01041.366] 01034.01041> userboot: searching bootfs for 'lib/ld.so.1' [01041.366] 01034.01041> userboot: userboot: loaded lib/ld.so.1 at 0x7a60a216c000, entry point 0x7a60a21f1f63 [01041.366] 01034.01041> userboot: userboot: loaded vDSO at 0x5f6568a26000, entry point 0x0 [01041.366] 01034.01041> userboot: process bin/bootsvc started. [01041.366] 01034.01041> userboot: waiting for loader-service requests... [01041.366] 01034.01041> userboot: searching bootfs for 'lib/libasync-default.so' [01041.366] 01034.01041> userboot: searching bootfs for 'lib/libfdio.so' [01041.366] 01034.01041> userboot: searching bootfs for 'lib/liblaunchpad.so' [01041.366] 01034.01041> userboot: searching bootfs for 'lib/libtrace-engine.so' [01041.366] 01048.01051> {{{reset}}} [01041.366] 01048.01051> {{{module:0:<application>:elf:dc50eddeff59d57bc869c83cbdc79b4529103a19}}} [01041.366] 01048.01051> {{{mmap:0x7bb099d1b000:0x2d000:load:0:rx:0}}} [01041.366] 01048.01051> {{{mmap:0x7bb099d48000:0x4000:load:0:rw:0x2d000}}} [01041.366] 01048.01051> dso: id=dc50eddeff59d57bc869c83cbdc79b4529103a19 base=0x00007bb099d1b000 name=<application> [01041.366] 01048.01051> {{{module:0x3:libasync-default.so:elf:5e3c55aea09e8943ae76d3603cc8c0b1ba27bfb7}}} [01041.366] 01048.01051> {{{mmap:0x23f5bc651000:0x1000:load:0x3:rx:0}}} [01041.366] 01048.01051> {{{mmap:0x23f5bc652000:0x1000:load:0x3:rw:0x1000}}} [01041.366] 01048.01051> dso: id=5e3c55aea09e8943ae76d3603cc8c0b1ba27bfb7 base=0x000023f5bc651000 name=libasync-default.so [01041.366] 01048.01051> {{{module:0x2:<vDSO>:elf:15398eb3d5622ee39ebf0738728ef1da4cdb710c}}} [01041.366] 01048.01051> {{{mmap:0x5f6568a26000:0x7000:load:0x2:r:0}}} [01041.366] 01048.01051> {{{mmap:0x5f6568a2d000:0x1000:load:0x2:rx:0x7000}}} [01041.366] 01048.01051> dso: id=15398eb3d5622ee39ebf0738728ef1da4cdb710c base=0x00005f6568a26000 name=<vDSO> [01041.366] 01048.01051> {{{module:0x1:libc.so:elf:9de96c717b326091f3478b4c96c1a1d8ab3c1fbb}}} [01041.366] 01048.01051> {{{mmap:0x7a60a216c000:0xcb000:load:0x1:rx:0}}} [01041.366] 01048.01051> {{{mmap:0x7a60a2238000:0x6000:load:0x1:rw:0xcc000}}} [01041.366] 01048.01051> dso: id=9de96c717b326091f3478b4c96c1a1d8ab3c1fbb base=0x00007a60a216c000 name=libc.so [01041.366] 01048.01051> {{{module:0x4:libfdio.so:elf:f654d3de6e389c2e34f38ebcf1d0d1501bad929f}}} [01041.366] 01048.01051> {{{mmap:0x52341078e000:0x22000:load:0x4:rx:0}}} [01041.366] 01048.01051> {{{mmap:0x5234107b0000:0x5000:load:0x4:rw:0x22000}}} [01041.366] 01048.01051> dso: id=f654d3de6e389c2e34f38ebcf1d0d1501bad929f base=0x000052341078e000 name=libfdio.so [01041.366] 01048.01051> {{{module:0x5:liblaunchpad.so:elf:3275d148fdc55d5dfbd06f5a7edb9dc4c294763f}}} [01041.366] 01048.01051> {{{mmap:0x31b4caf0c000:0x7000:load:0x5:rx:0}}} [01041.366] 01048.01051> {{{mmap:0x31b4caf13000:0x2000:load:0x5:rw:0x7000}}} [01041.366] 01048.01051> dso: id=3275d148fdc55d5dfbd06f5a7edb9dc4c294763f base=0x000031b4caf0c000 name=liblaunchpad.so [01041.366] 01048.01051> {{{module:0x6:libtrace-engine.so:elf:b522ed24160d7c2992490d76fde35676452b2308}}} [01041.366] 01048.01051> {{{mmap:0x4dbca453b000:0x9000:load:0x6:rx:0}}} [01041.366] 01048.01051> {{{mmap:0x4dbca4544000:0x2000:load:0x6:rw:0x9000}}} [01041.366] 01048.01051> dso: id=b522ed24160d7c2992490d76fde35676452b2308 base=0x00004dbca453b000 name=libtrace-engine.so [01041.367] 01048.01051> bootsvc: Starting... [01041.367] 01034.01041> userboot: loader-service channel peer closed [01041.367] 01034.01041> userboot: finished! [01041.367] 01048.01051> bootsvc: Creating bootfs service... [01041.367] 01048.01051> bootsvc: Processing bootdata... [01041.367] 01048.01051> bootsvc: Loading boot cmdline overrides... [01041.367] 01048.01051> bootsvc: Loading kernel VMOs... [01041.367] 01048.01051> bootsvc: Creating loader service... [01041.367] 01048.01051> bootsvc: Launching next process... [01041.367] 01048.01095> bootsvc: launched bin/devmgr [01041.368] 01103.01116> devmgr: main() [01041.368] 01103.01116> devmgr: init [01041.368] 01103.01116> coordinator_init() [01041.368] 01103.01116> cmdline: zircon.autorun.system=/boot/bin/sh+/boot/infra/runcmds [01041.368] 01103.01116> cmdline: devhost.asan.strict=false [01041.368] 01103.01116> cmdline: devmgr.require-system=true [01041.368] 01103.01116> cmdline: zircon.system.pkgfs.cmd=bin/pkgsvr+61075d4112e018b0ff59bb4b8704a2fab2af30e8b3aea4caa15b05f955b8b875 [01041.368] 01103.01116> cmdline: zircon.system.pkgfs.file.bin/pkgsvr=306a47a4d4b8692dcbb57c041325abd33656147b462f7bcab7409fd765e0d36f [01041.368] 01103.01116> cmdline: zircon.system.pkgfs.file.lib/ld.so.1=d78c3b4afb565122e9ac50b0e37a7eb730e539af7416057f5fd7a1fd45b8257b [01041.368] 01103.01116> cmdline: zircon.system.pkgfs.file.lib/libfdio.so=8b0288f6e5573403d8d11c0f9f84f8562f1060960dc0095f99212973ae628b54 [01041.368] 01103.01116> devmgr: svc init [01041.368] 01103.01116> devmgr: launch /boot/bin/svchost (svchost) OK [01041.368] 01103.01116> devmgr: vfs init [01041.368] 01103.01116> devmgr: launch /boot/bin/fshost (fshost) OK [01041.368] 01103.01220> devmgr: shell startup [01041.368] 01103.01116> devmgr: coordinator() [01041.369] 01179.01199> fshost: started. [01041.370] 01103.01210> devmgr: launch /boot/bin/pwrbtn-monitor (pwrbtn-monitor) OK [01041.370] 01103.01232> devmgr: launch /boot/bin/crashsvc (crashsvc) OK [01041.371] 01103.01232> devmgr: launch /boot/bin/netsvc (netsvc) OK [01041.372] 01103.01232> devmgr: launch /boot/bin/virtual-console (virtual-console) OK [01041.372] 01248.01511> crashsvc: starting [01041.374] 01103.01116> devcoord: launch devhost 'devhost:sys': pid=2017 [01041.374] 01103.01116> devcoord: launch devhost 'devhost:test': pid=2050 [01041.374] 01103.01116> devcoord: full system required, ignoring fallback drivers until /system is loaded [01041.375] 01103.01116> devcoord: launch devhost 'devhost:root': pid=2083 [01041.375] 01103.01116> devcoord: launch devhost 'devhost:misc': pid=2134 [01041.385] 01103.01220> devmgr: launch /boot/bin/sh (sh:console) OK [01041.432] 02017.02041> acpi-bus: not using IOMMU [01041.437] 02017.02041> acpi-pwrbtn: initialized [01041.459] 02017.02041> acpi: published device pci(0x1c2d6ab050c0), parent=proxy(0x1c2d6ab10540), handle=0x1c2d6ab4e750 [01041.460] 02017.02041> acpi: published device rtc(0x1c2d6ab05100), parent=acpi(0x1c2d6ab106c0), handle=0x1c2d6ab67190 [01041.461] 02017.02041> acpi-ec: initialized [01041.463] 02017.02041> acpi: failed to create NHLT VMO (res -10) [01041.463] 02017.02041> acpi: failed to publish NHLT metadata [01041.465] 02017.02041> Intel Processor Trace configuration for this chipset: [01041.465] 02017.02041> mtc_freq_mask: 0x249 [01041.465] 02017.02041> cyc_thresh_mask: 0x3fff [01041.465] 02017.02041> psb_freq_mask: 0x3f [01041.465] 02017.02041> num addr ranges: 2 [01041.465] 01586.01698> vc: new input device /dev/class/input/000 [01041.465] 01103.01116> devcoord: launch devhost 'devhost:pci#1:8086:5916': pid=2684 [01041.466] 01103.01116> devcoord: launch devhost 'devhost:pci#3:8086:9d2f': pid=2731 [01041.466] 01103.01116> devcoord: launch devhost 'devhost:pci#5:8086:9d60': pid=2792 [01041.467] 01103.01116> devcoord: launch devhost 'devhost:pci#6:8086:9d61': pid=2858 [01041.467] 01103.01116> devcoord: launch devhost 'devhost:pci#9:8086:9d03': pid=2934 [01041.468] 01103.01116> devcoord: launch devhost 'devhost:pci#14:8086:9d71': pid=3046 [01041.469] 01103.01116> devcoord: launch devhost 'devhost:pci#16:8086:156f': pid=3113 [01041.470] 02934.02978> ahci: using MSI interrupt [01041.470] 02858.02902> initialized intel serialio i2c driver, reg=0x53a991ee7000 regsize=4096 [01041.470] 02792.02828> initialized intel serialio i2c driver, reg=0x6181ef1c5000 regsize=4096 [01041.475] 02731.03351> * found USB device (0x18d1:0xa002, USB 2.0) config 1 [01041.475] 02731.03351> * found USB device (0x18d1:0xa003, USB 3.0) config 1 [01041.475] 02731.02763> bus_set_hub_interface: no device for usb_device_id 65 [01041.476] 02731.02763> bus_set_hub_interface: no device for usb_device_id 66 [01041.476] 03046.03088> [IHDA DSP 00:1f.3] Failed to fetch NHLT (res -25) [01041.476] 03046.03088> devhost[00:1f.3/intel-hda-000/intel-sst-dsp-000] bind driver '/boot/driver/dsp.so' failed: -25 [01041.476] 01103.01116> devcoord: rpc: bind-driver 'intel-sst-dsp-000' status -25 [01041.548] 01513.01581> netifc: ? /dev/class/ethernet/000 [01041.548] 01513.01581> netifc: create 512 eth buffers [01041.548] 01513.01581> macaddr: d4:5d:df:00:d9:20 [01041.548] 01513.01581> ip6addr: fe80::d65d:df4d:fe00:d920 [01041.548] 01513.01581> snmaddr: ff02::1:ff00:d920 [01041.548] 01513.01581> netsvc: using /dev/class/ethernet/000 [01041.548] 01513.01581> netsvc: nodename='viral-blush-shiny-grew' [01041.548] 01513.01581> netsvc: start [01041.575] 01586.01698> vc: new display device /dev/class/display-controller/000/virtcon [01041.615] 02684.03704> i915: MST not supported [01041.756] 02858.03257> i2c: tx abort detected: 0x05000001 [01041.756] 02858.02902> intel-i2c-controller: intel_serialio_i2c_slave_transfer: -40 [01041.756] 02858.02902> i2c-hid: could not read HID descriptor: 0 [01041.756] 02858.02902> devhost[00:15.1/i2c-bus-9d61/004c] bind driver '/boot/driver/i2c-hid.so' failed: -2 [01041.756] 01103.01116> devcoord: rpc: bind-driver '004c' status -2 [01041.957] 02684.03704> i915: Found DP monitor [01041.957] 02684.03704> i915: Display 1 connected [01042.216] 02731.03351> * found USB device (0x0781:0x5583, USB 3.0) config 1 [01042.519] 01586.01698> vc: Successfully attached to display 1 [01042.946] 02731.03351> * found USB device (0x8087:0x0a2b, USB 2.0) config 1 [01043.474] 02792.02828> intel-i2c-controller: intel_serialio_i2c_slave_transfer: -21 [01043.474] 02792.02828> i2c-hid: could not read HID descriptor: 0 [01043.474] 02792.02828> devhost[00:15.0/i2c-bus-9d60/0020] bind driver '/boot/driver/i2c-hid.so' failed: -2 [01043.474] 01103.01116> devcoord: rpc: bind-driver '0020' status -2 [01043.488] 02934.03474> sata2: dev info [01043.488] 02934.03474> serial=715400411010 3 [01043.488] 02934.03474> firmware rev=1P11A1E_ [01043.488] 02934.03474> model id=IBIW NSS D [01043.488] 02934.03474> major=0x3f0 ACS2 DMA 32 commands [01043.488] 02934.03474> LBA48 250069680 sectors, sector size=512 [01043.489] 01179.01199> devmgr: /dev/class/block/000: GPT? [01043.489] 01103.01116> devcoord: dc_bind_device() '/boot/driver/gpt.so' [01043.489] 02934.02978> gpt: device_get_metadata failed (-25) [01043.490] 01179.01199> devmgr: /dev/class/block/001: FVM? [01043.490] 01103.01116> devcoord: dc_bind_device() '/boot/driver/fvm.so' [01043.490] 01179.01199> devmgr: not automounting efi [01043.492] 01179.01199> devmgr: launch /boot/bin/blobfs (blobfs:/blob) OK [01043.546] 01179.01199> fshost: starting 'bin/pkgsvr' '61075d4112e018b0ff59bb4b8704a2fab2af30e8b3aea4caa15b05f955b8b875'... [01043.581] 01179.01199> devmgr: launch bin/pkgsvr (pkgfs) OK [01043.589] 04019.04235> pkgsvr: system: will be served from 61075d4112e018b0ff59bb4b8704a2fab2af30e8b3aea4caa15b05f955b8b875 [01043.589] 04019.04235> pkgsvr: pkgfs serving index /data/pkgfs_index from blobfs /blob [01043.589] 01179.01199> devmgr: /dev/class/block/004: zxcrypt? [01043.589] 01103.01116> devcoord: dc_bind_device() '/boot/driver/zxcrypt.so' [01043.594] 01103.01708> devmgr: launch /system/bin/appmgr (appmgr) OK [01043.594] 01103.01708> zircon.autorun.system: starting '/boot/bin/sh' '/boot/infra/runcmds'... [01043.595] 01179.01199> devmgr: mounting minfs [01043.595] 01103.04293> devmgr: adding system driver 'bt_passthrough_hci' '/system/driver/bthci-passthrough.so' [01043.596] 01103.01708> devmgr: launch /boot/bin/sh (autorun:system) OK [01043.596] 01179.01199> devmgr: launch /boot/bin/minfs (minfs:/data) OK [01043.603] 01103.04293> devmgr: adding system driver 'qmi_usb' '/system/driver/qmi-transport.so' [01043.610] 01103.04293> devmgr: adding system driver 'usb_video' '/system/driver/usb_video.so' [01043.636] 01103.04293> devmgr: adding system driver 'bthci_fake' '/system/driver/bthci-fake.so' [01043.643] 01103.04293> devmgr: adding system driver 'wlan' '/system/driver/wlanif.so' [01043.648] 01103.04293> devmgr: adding system driver 'ath10k_pci' '/system/driver/ath10k.so' [01043.655] 01103.04293> devmgr: adding system driver 'ralink' '/system/driver/ralink.so' [01043.660] 01103.04293> devmgr: adding system driver 'gpu' '/system/driver/libmsd_intel.so' [01043.667] 01103.04293> devmgr: adding system driver 'btintel' '/system/driver/btintel.so' [01043.671] 01103.04293> devmgr: adding system driver 'rtl88xx' '/system/driver/rtl88xx.so' [01043.680] 01103.04293> devmgr: adding system driver 'wlan' '/system/driver/wlan.so' [01043.684] 01103.04293> devmgr: adding system driver 'brcmfmac' '/system/driver/brcmfmac.so' [01043.691] 01103.04293> devmgr: adding system driver 'wlan' '/system/driver/wlanphy.so' [01043.693] 01103.04293> devmgr: adding system driver 'bthog' '/system/driver/bthog.so' [01043.706] 01103.04293> devmgr: adding system driver 'bthost' '/system/driver/bthost.so' [01043.716] 01103.04293> devmgr: adding system driver 'wlantapctl' '/system/driver/wlantap.so' [01043.717] 01103.01116> devcoord: fallback driver 'usb_composite' is available [01043.717] 01103.01116> devcoord: fallback driver 'intel_disp' is available [01043.717] 01103.01116> devcoord: driver 'wlantapctl' added [01043.717] 01103.01116> devcoord: driver 'bthost' added [01043.717] 01103.01116> devcoord: driver 'bthog' added [01043.717] 01103.01116> devcoord: driver 'wlan' added [01043.717] 01103.01116> devcoord: driver 'brcmfmac' added [01043.717] 01103.01116> devcoord: driver 'wlan' added [01043.717] 01103.01116> devcoord: driver 'rtl88xx' added [01043.717] 01103.01116> devcoord: driver 'btintel' added [01043.717] 01103.01116> devcoord: driver 'gpu' added [01043.717] 01103.01116> devcoord: drv='gpu' bindable to dev='intel-gpu-core' [01043.717] 01103.01116> devcoord: driver 'ralink' added [01043.717] 01103.01116> devcoord: driver 'ath10k_pci' added [01043.717] 01103.01116> devcoord: driver 'wlan' added [01043.717] 01103.01116> devcoord: driver 'bthci_fake' added [01043.717] 01103.01116> devcoord: driver 'usb_video' added [01043.717] 01103.01116> devcoord: driver 'qmi_usb' added [01043.717] 01103.01116> devcoord: driver 'bt_passthrough_hci' added [01043.717] 01103.01116> devcoord: driver 'usb_composite' added [01043.717] 01103.01116> devcoord: drv='usb_composite' bindable to dev='001' [01043.717] 01103.01116> devcoord: drv='usb_composite' bindable to dev='002' [01043.717] 01103.01116> devcoord: driver 'intel_disp' added [01043.719] 02731.02763> UMS:Max lun is: 0 [01043.720] 02731.02763> devhost[00:14.0/xhci/usb/002/002/ifc-001] bind driver '/boot/driver/bt-transport-usb.so' failed: -2 [01043.720] 01103.01116> devcoord: rpc: bind-driver 'ifc-001' status -2 [01043.752] 02731.05832> btintel: already loaded [01043.752] 02731.05840> hci_read_thread: failed to read from command channel ZX_ERR_PEER_CLOSED [01043.752] 02731.05840> hci_read_thread: failed to read from ACL channel ZX_ERR_PEER_CLOSED [01043.752] 02731.05840> bt-transport-usb: all channels closed - exiting [01043.754] 02731.06301> [INFO:command_channel.cc(150)] hci: initialized [01043.774] 02731.06301> [INFO:acl_data_channel.cc(91)] hci: initialized [01043.893] 06889.06901> netstack: main.go:40: started [01043.894] 06889.06901> netstack: main.go:61: socket server started [01043.894] 06889.07085> netstack: main.go:117: OnInterfacesChanged failed: ErrBadHandle: zx.Channel.Write [01043.944] 07598.07610> [INFO:cobalt_main.cc(102)] Cobalt client schedule params: schedule_interval=3600 seconds, min_interval=10 seconds, initial_interval=60 seconds. [01044.000] 08433.08445> netcfg: started [01044.030] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://vulkan_is_supported was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/vulkan_is_supported#meta/vulkan_is_supported.cmx instead. See [01044.030] 05277.05323> https://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01044.042] 06889.07085> netstack: netstack.go:553: NIC ethp001f6 added [01044.042] 06889.07085> netstack: netstack.go:568: NIC ethp001f6: link-local IPv6: fe80::d65d:dfff:fe00:d920 [01044.043] 06889.09299> netstack: netstack.go:255: NIC ethp001f6: stopped [01044.108] 09799.09811> [INFO:main.cc(35)] Trace Manager starting with config: /pkg/data/tracing.config [01044.126] 02731.06301> [WARN:bredr_discovery_manager.cc(470)] gap-bredr: write inquiry scan activity failed: [status: invalid HCI command parameters (HCI 0x12)] [01044.140] 10320.10332> wlanstack2 [I]: Starting [01044.187] 04945.04962> runbench: running /pkgfs/packages/scenic_benchmarks/0/bin/run_scenic_benchmark.sh --out_dir /tmp/infra-test-output --out_file /tmp/infra-test-output/fuchsia.scenic.image_grid_flutter_noclipping_noshadows.json --benchmark_lab [01044.187] 04945.04962> el fuchsia.scenic.image_grid_flutter_noclipping_noshadows --cmd set_root_view image_grid_flutter --unshadowed --clipping_disabled [01044.193] 11322.11339> == fuchsia.scenic.image_grid_flutter_noclipping_noshadows: Killing processes... [01044.194] 11565.11579> no tasks found [01044.195] 11634.11648> no tasks found [01044.197] 11703.11717> no tasks found [01044.198] 11772.11786> no tasks found [01044.199] 11841.11855> no tasks found [01044.200] 11910.11924> no tasks found [01044.200] 11322.11339> == fuchsia.scenic.image_grid_flutter_noclipping_noshadows: Configuring scenic renderer params... [01044.205] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://set_renderer_params was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/set_renderer_params#meta/set_renderer_params.cmx instead. See [01044.205] 05277.05323> https://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01044.213] 12156.12168> [WARNING:garnet/bin/ui/set_renderer_params_HACK/main.cc(22)] This tool is intended for testing and debugging purposes only and may cause problems if invoked incorrectly. [01044.213] 11322.11339> == fuchsia.scenic.image_grid_flutter_noclipping_noshadows: Tracing... [01044.213] 11322.11339> /tmp/infra-test-output/trace.2018-12-16T07:21:11.json [01044.229] 09799.09811> [INFO:trace_manager.cc(69)] Starting trace with 12 MB buffers, buffering mode=oneshot [01044.230] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://set_root_view was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/set_root_view#meta/set_root_view.cmx instead. See https://fuchsia.go [01044.230] 05277.05323> oglesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01044.230] 12411.12425> Starting trace; will stop in 10 seconds... [01044.233] 12762.12774> [INFO:fdio_hid_decoder.cc(280)] hid-parser succesful for 000 with usage page 1 and usage 128 [01044.233] 12762.12774> [INFO:app.cc(151)] Presenter::HACK_SetRendererParams: Setting clipping enabled to false [01044.233] 12762.12774> [INFO:app.cc(164)] Presenter::HACK_SetRendererParams: Setting render frequency to 1 [01044.233] 12762.12774> [INFO:app.cc(158)] Presenter::HACK_SetRendererParams: Setting shadow technique to 0 [01044.250] 13008.13020> [WARNING:garnet/bin/ui/set_root_view/main.cc(23)] BE ADVISED: The set_root_view tool takes the URL to an app that provided the ViewProvider interface and makes it's view the root view. [01044.250] 13008.13020> [WARNING:garnet/bin/ui/set_root_view/main.cc(26)] This tool is intended for testing and debugging purposes only and may cause problems if invoked incorrectly. [01044.250] 13008.13020> [WARNING:garnet/bin/ui/set_root_view/main.cc(29)] Do not invoke set_root_view if a view tree already exists (i.e. if any process that creates a view is already running). [01044.250] 13008.13020> [WARNING:garnet/bin/ui/set_root_view/main.cc(33)] If scenic is already running on your system you will probably want to kill it before invoking this tool. [01044.250] 13008.13020> [WARNING:garnet/bin/ui/set_root_view/main.cc(36)] Use the newer present_view tool for launching apps with Views V2. [01044.250] 13008.13020> [INFO:main.cc(52)] set_root_view requesting input delivery by: ViewManager [01044.250] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://image_grid_flutter was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/image_grid_flutter#meta/image_grid_flutter.cmx instead. See htt [01044.250] 05277.05323> ps://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01044.251] 12762.12774> [INFO:presentation1.cc(184)] Disconnected from a11y toggle broadcaster. [01044.292] 13388.13400> [INFO:display_watcher.cc(46)] Scenic: Acquired display controller /dev/class/display-controller/000.(000) [01044.576] 04297.04432> [ERROR:garnet/bin/appmgr/service_provider_dir_impl.cc(99)] Cannot serve service fuchsia.modular.Clipboard for component file://image_grid_flutter: ZX_ERR_NOT_FOUND [01044.584] 13692.14290> [WARNING:third_party/flutter/shell/common/persistent_cache.cc(46)] Could not acquire the persistent cache directory. Caching of GPU resources on disk is disabled. [01044.585] 13692.14290> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Clipboard [01044.585] 13692.14290> [INFO:platform_view.cc(126)] Flutter, input comes from: ViewManager [01044.616] 13388.13400> [INFO:input_system.cc(236)] Scenic input system initialized. [01044.616] 12762.12774> [WARNING:garnet/bin/ui/root_presenter/displays/display_configuration.cc(76)] SceneManager: unrecognized display. [01044.616] 13388.13400> [INFO:input_system.cc(576)] Scenic: Parallel dispatch is turned OFF [01044.725] 02731.05531> UMS: block size is: 0x00000200 [01044.725] 02731.05531> UMS: total blocks is: 30031872 [01044.725] 02731.05531> UMS: total size is: 15376318464 [01044.725] 02731.05531> UMS: read-only: 0 removable: 1 [01044.726] 01179.01199> devmgr: /dev/class/block/006: MBR? [01044.726] 01103.01116> devcoord: dc_bind_device() '/boot/driver/mbr.so' [01044.729] 01179.01199> devmgr: /dev/class/block/008: MBR? [01044.729] 01103.01116> devcoord: dc_bind_device() '/boot/driver/mbr.so' [01044.911] 13692.14322> [INFO:paragraph.cc(291)] Could not find font collection for family "". [01044.912] 13692.14322> [INFO:paragraph.cc(291)] Could not find font collection for family "". [01045.089] 06889.09299> netstack: netstack.go:280: NIC ethp001f6: restarting [01047.064] 01513.01581> netsvc: handling tftp request failed (file might not exist) [01047.064] 01513.01581> netsvc: close, but no open file [01049.168] 06889.17576> netstack: netstack.go:209: NIC ethp001f6: DHCP acquired IP 192.168.42.105 for 240h0m0s [01049.168] 06889.17576> netstack: netstack.go:210: NIC ethp001f6: Adding DNS servers: [8.8.8.8] [01054.230] 12411.12425> Stopping trace... [01054.230] 09799.09811> [INFO:trace_manager.cc(92)] Stopping trace [01054.266] 09799.09811> [WARNING:garnet/bin/trace_manager/tracee.cc(411)] #8 {13388:scenic.cmx}: 159847 records were dropped [01054.266] 12411.12425> [WARNING:garnet/lib/trace_converters/chromium_exporter.cc(434)] #8 buffer overflowed, records were likely dropped [01056.200] 09799.09811> [INFO:tracee.cc(477)] #8 {13388:scenic.cmx} trace stats [01056.200] 09799.09811> [INFO:tracee.cc(478)] Wrapped count: 0 [01056.200] 09799.09811> [INFO:tracee.cc(479)] # records dropped: 159847 [01056.200] 09799.09811> [INFO:tracee.cc(480)] Durable buffer: 0x0, size 0x0 [01056.200] 09799.09811> [INFO:tracee.cc(483)] Non-durable buffer: 0xbfff80,0x0, size 0xbfff80 [01056.231] 09799.09811> [INFO:trace_manager.cc(95)] Stopped trace [01056.246] 12411.12425> Trace file written to /tmp/infra-test-output/trace.2018-12-16T07:21:11.json [01056.247] 11322.11339> == fuchsia.scenic.image_grid_flutter_noclipping_noshadows: Processing trace... [01058.984] 08086.08098> Starting mDNS on interface ethp001f6 192.168.42.105 [01058.985] 06889.07100> netstack: socket_conv.go:50: convSockOpt: TODO SOL_SOCKET optname=15 [01058.985] 06889.07139> netstack: socket_conv.go:86: convSockOpt: TODO IPPROTO_IP optname=32 [01058.985] 06889.07139> netstack: socket_conv.go:86: convSockOpt: TODO IPPROTO_IP optname=2 [01058.985] 08086.08098> Starting mDNS on interface ethp001f6 [80fe::5dd6:ffdf:fe:20d9] [01058.985] 06889.07100> netstack: socket_conv.go:50: convSockOpt: TODO SOL_SOCKET optname=15 [01058.985] 08086.08098> [ERROR:garnet/bin/mdns/service/mdns_interface_transceiver_v6.cc(102)] Failed to bind socket to V6 address, errno 98 [01058.985] 08086.08098> [ERROR:garnet/bin/mdns/service/mdns_interface_transceiver_v6.cc(105)] (EADDRINUSE) This is probably due to NET-1809. [01058.985] 08086.08098> mDNS: Verifying uniqueness of host name viral-blush-shiny-grew.local. [01059.762] 08086.08098> mDNS: Using unique host name viral-blush-shiny-grew.local. [01060.361] 92956.93158> === Scenic FPS === [01060.369] 92956.93158> 59.11fps [01060.369] 92956.93158> fps per one-second window: [60 59 59 59 59 59 59] [01060.376] 92956.93158> RenderFrame 1.329ms [01060.384] 92956.93158> ApplyScheduledSessionUpdates 1.048ms [01060.391] 92956.93158> CommandBuffer::Submit 0.04046ms [01060.399] 92956.93158> UpdateAndDeliverMetrics 0.007338ms [01060.406] 92956.93158> EngineRenderer::RenderLayers 0ms [01060.406] 92956.93158> Warning: no values found for EngineRenderer::RenderLayers. Falling back to a zero value. [01060.414] 92956.93158> Escher GPU time 1.47ms [01060.428] 92956.93158> unaccounted (mostly gfx driver) 0.3838ms [01060.428] 92956.93158> Did not find any processes that matched [01060.435] 11322.11339> == fuchsia.scenic.image_grid_flutter_noclipping_noshadows: Finished processing trace. [01060.455] 04945.04962> runbench: running /pkgfs/packages/scenic_benchmarks/0/bin/run_scenic_benchmark.sh --out_dir /tmp/infra-test-output --out_file /tmp/infra-test-output/fuchsia.scenic.image_grid_flutter_noshadows.json --benchmark_label fuchsia. [01060.455] 04945.04962> scenic.image_grid_flutter_noshadows --cmd set_root_view image_grid_flutter --unshadowed --clipping_enabled [01060.463] 122035.122052> == fuchsia.scenic.image_grid_flutter_noshadows: Killing processes... [01060.465] 122388.122403> Killed 12762 root_presenter.cmx [01060.465] 13692.14290> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Presenter [01060.466] 13692.14290> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: View [01060.466] 13692.14290> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Service Provider [01060.466] 05277.05323> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/root_presenter#meta/root_presenter.cmx died [01060.468] 122461.122475> Killed 13388 scenic.cmx [01060.468] 13692.14290> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(37)] Interface error on: SessionListener [01060.468] 13835.13854> [ERROR:garnet/bin/ui/view_manager/view_registry.cc(144)] Exiting due to session connection error. [01060.469] 13692.14322> fdio_ns_destroy: ZX_ERR_BAD_STATE [01060.470] 05277.05323> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/view_manager#meta/view_manager.cmx died [01060.471] 02684.03722> Failed to send vsync event -24 [01060.473] 05277.05323> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/scenic#meta/scenic.cmx died [01060.481] 122537.122551> no tasks found [01060.481] 13692.14317> [INFO:vulkan_application.cc(105)] Destroying Vulkan instance [01060.482] 13008.13020> [INFO:main.cc(70)] Launched component terminated. [01060.483] 122623.122637> no tasks found [01060.484] 122696.122710> no tasks found [01060.485] 122765.122779> no tasks found [01060.486] 122035.122052> == fuchsia.scenic.image_grid_flutter_noshadows: Configuring scenic renderer params... [01060.490] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://set_renderer_params was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/set_renderer_params#meta/set_renderer_params.cmx instead. See [01060.490] 05277.05323> https://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01060.497] 123009.123021> [WARNING:garnet/bin/ui/set_renderer_params_HACK/main.cc(22)] This tool is intended for testing and debugging purposes only and may cause problems if invoked incorrectly. [01060.498] 122035.122052> == fuchsia.scenic.image_grid_flutter_noshadows: Tracing... [01060.498] 122035.122052> /tmp/infra-test-output/trace.2018-12-16T07:21:27.json [01060.513] 09799.09811> [INFO:trace_manager.cc(69)] Starting trace with 12 MB buffers, buffering mode=oneshot [01060.514] 123264.123278> Starting trace; will stop in 10 seconds... [01060.515] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://set_root_view was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/set_root_view#meta/set_root_view.cmx instead. See https://fuchsia.go [01060.515] 05277.05323> oglesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01060.519] 123570.123585> [INFO:fdio_hid_decoder.cc(280)] hid-parser succesful for 000 with usage page 1 and usage 128 [01060.519] 123570.123585> [INFO:app.cc(151)] Presenter::HACK_SetRendererParams: Setting clipping enabled to true [01060.519] 123570.123585> [INFO:app.cc(164)] Presenter::HACK_SetRendererParams: Setting render frequency to 1 [01060.519] 123570.123585> [INFO:app.cc(158)] Presenter::HACK_SetRendererParams: Setting shadow technique to 0 [01060.523] 123837.123849> [WARNING:garnet/bin/ui/set_root_view/main.cc(23)] BE ADVISED: The set_root_view tool takes the URL to an app that provided the ViewProvider interface and makes it's view the root view. [01060.523] 123837.123849> [WARNING:garnet/bin/ui/set_root_view/main.cc(26)] This tool is intended for testing and debugging purposes only and may cause problems if invoked incorrectly. [01060.523] 123837.123849> [WARNING:garnet/bin/ui/set_root_view/main.cc(29)] Do not invoke set_root_view if a view tree already exists (i.e. if any process that creates a view is already running). [01060.523] 123837.123849> [WARNING:garnet/bin/ui/set_root_view/main.cc(33)] If scenic is already running on your system you will probably want to kill it before invoking this tool. [01060.523] 123837.123849> [WARNING:garnet/bin/ui/set_root_view/main.cc(36)] Use the newer present_view tool for launching apps with Views V2. [01060.523] 123837.123849> [INFO:main.cc(52)] set_root_view requesting input delivery by: ViewManager [01060.524] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://image_grid_flutter was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/image_grid_flutter#meta/image_grid_flutter.cmx instead. See htt [01060.524] 05277.05323> ps://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01060.524] 123570.123585> [INFO:presentation1.cc(184)] Disconnected from a11y toggle broadcaster. [01060.565] 04297.04432> [ERROR:garnet/bin/appmgr/service_provider_dir_impl.cc(99)] Cannot serve service fuchsia.modular.Clipboard for component file://image_grid_flutter: ZX_ERR_NOT_FOUND [01060.568] 124304.124318> [INFO:display_watcher.cc(46)] Scenic: Acquired display controller /dev/class/display-controller/000.(000) [01060.574] 13692.124114> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Clipboard [01060.574] 13692.124114> [INFO:platform_view.cc(126)] Flutter, input comes from: ViewManager [01060.803] 124304.124318> [INFO:input_system.cc(236)] Scenic input system initialized. [01060.803] 124304.124318> [INFO:input_system.cc(576)] Scenic: Parallel dispatch is turned OFF [01060.803] 123570.123585> [WARNING:garnet/bin/ui/root_presenter/displays/display_configuration.cc(76)] SceneManager: unrecognized display. [01060.921] 13692.124149> [INFO:paragraph.cc(291)] Could not find font collection for family "". [01060.921] 13692.124149> [INFO:paragraph.cc(291)] Could not find font collection for family "". [01070.514] 123264.123278> Stopping trace... [01070.514] 09799.09811> [INFO:trace_manager.cc(92)] Stopping trace [01070.542] 09799.09811> [WARNING:garnet/bin/trace_manager/tracee.cc(411)] #12 {124304:scenic.cmx}: 187290 records were dropped [01070.542] 123264.123278> [WARNING:garnet/lib/trace_converters/chromium_exporter.cc(434)] #12 buffer overflowed, records were likely dropped [01072.621] 09799.09811> [INFO:tracee.cc(477)] #12 {124304:scenic.cmx} trace stats [01072.621] 09799.09811> [INFO:tracee.cc(478)] Wrapped count: 0 [01072.621] 09799.09811> [INFO:tracee.cc(479)] # records dropped: 187290 [01072.621] 09799.09811> [INFO:tracee.cc(480)] Durable buffer: 0x0, size 0x0 [01072.621] 09799.09811> [INFO:tracee.cc(483)] Non-durable buffer: 0xbfff80,0x0, size 0xbfff80 [01072.666] 09799.09811> [INFO:trace_manager.cc(95)] Stopped trace [01072.681] 123264.123278> Trace file written to /tmp/infra-test-output/trace.2018-12-16T07:21:27.json [01072.682] 122035.122052> == fuchsia.scenic.image_grid_flutter_noshadows: Processing trace... [01077.104] 205058.205272> === Scenic FPS === [01077.111] 205058.205272> 58.98fps [01077.111] 205058.205272> fps per one-second window: [59 59 59 59 59 59 59] [01077.120] 205058.205272> RenderFrame 1.221ms [01077.127] 205058.205272> ApplyScheduledSessionUpdates 0.8678ms [01077.136] 205058.205272> CommandBuffer::Submit 0.04193ms [01077.143] 205058.205272> UpdateAndDeliverMetrics 0.006903ms [01077.153] 205058.205272> EngineRenderer::RenderLayers 0ms [01077.153] 205058.205272> Warning: no values found for EngineRenderer::RenderLayers. Falling back to a zero value. [01077.159] 205058.205272> Escher GPU time 2.518ms [01077.176] 205058.205272> unaccounted (mostly gfx driver) 0.4134ms [01077.176] 205058.205272> Did not find any processes that matched [01077.185] 122035.122052> == fuchsia.scenic.image_grid_flutter_noshadows: Finished processing trace. [01077.205] 04945.04962> runbench: running /pkgfs/packages/scenic_benchmarks/0/bin/run_scenic_benchmark.sh --out_dir /tmp/infra-test-output --out_file /tmp/infra-test-output/fuchsia.scenic.image_grid_flutter_ssdo.json --benchmark_label fuchsia.sceni [01077.205] 04945.04962> c.image_grid_flutter_ssdo --cmd set_root_view image_grid_flutter --screen_space_shadows --clipping_enabled [01077.221] 236217.236234> == fuchsia.scenic.image_grid_flutter_ssdo: Killing processes... [01077.224] 236569.236584> Killed 123570 root_presenter.cmx [01077.224] 13692.124114> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Presenter [01077.224] 13692.124114> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: View [01077.225] 13692.124114> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Service Provider [01077.226] 05277.05323> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/root_presenter#meta/root_presenter.cmx died [01077.227] 13692.124114> [WARNING:topaz/runtime/flutter_runner/platform_view.cc(382)] Flutter PlatformView::OnScenicEvent: Unhandled GFX event (fuchsia.ui.gfx.ImportUnboundEvent). [01077.227] 236644.236658> Killed 124304 scenic.cmx [01077.228] 13692.124114> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(37)] Interface error on: SessionListener [01077.228] 13692.124142> fidl channel writing error at ../../garnet/public/lib/fidl/cpp/internal/proxy_controller.cc:59: zx_status_t -11, type fuchsia.ui.scenic/SessionEnqueueRequest, 65152 bytes, 0 handles [01077.229] 13692.124142> fidl channel writing error at ../../garnet/public/lib/fidl/cpp/internal/proxy_controller.cc:59: zx_status_t -11, type fuchsia.ui.scenic/SessionEnqueueRequest, 65152 bytes, 0 handles [01077.229] 13692.124142> fidl channel writing error at ../../garnet/public/lib/fidl/cpp/internal/proxy_controller.cc:59: zx_status_t -11, type fuchsia.ui.scenic/SessionEnqueueRequest, 65152 bytes, 0 handles [01077.229] 124540.124557> [ERROR:garnet/bin/ui/view_manager/view_registry.cc(144)] Exiting due to session connection error. [01077.229] 13692.124142> fidl channel writing error at ../../garnet/public/lib/fidl/cpp/internal/proxy_controller.cc:59: zx_status_t -11, type fuchsia.ui.scenic/SessionEnqueueRequest, 38752 bytes, 0 handles [01077.229] 13692.124142> fidl channel writing error at ../../garnet/public/lib/fidl/cpp/internal/proxy_controller.cc:59: zx_status_t -11, type fuchsia.ui.scenic/SessionPresentRequest, 72 bytes, 0 handles [01077.230] 13692.124149> fdio_ns_destroy: ZX_ERR_BAD_STATE [01077.230] 05277.05323> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/scenic#meta/scenic.cmx died [01077.230] 02684.03722> Failed to send vsync event -24 [01077.238] 05277.05323> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/view_manager#meta/view_manager.cmx died [01077.241] 236807.236821> no tasks found [01077.243] 13692.124142> [INFO:vulkan_application.cc(105)] Destroying Vulkan instance [01077.244] 236895.236916> no tasks found [01077.244] 123837.123849> [INFO:main.cc(70)] Launched component terminated. [01077.246] 236975.236989> no tasks found [01077.247] 237044.237058> no tasks found [01077.247] 236217.236234> == fuchsia.scenic.image_grid_flutter_ssdo: Configuring scenic renderer params... [01077.251] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://set_renderer_params was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/set_renderer_params#meta/set_renderer_params.cmx instead. See [01077.251] 05277.05323> https://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01077.258] 237288.237300> [WARNING:garnet/bin/ui/set_renderer_params_HACK/main.cc(22)] This tool is intended for testing and debugging purposes only and may cause problems if invoked incorrectly. [01077.259] 236217.236234> == fuchsia.scenic.image_grid_flutter_ssdo: Tracing... [01077.259] 236217.236234> /tmp/infra-test-output/trace.2018-12-16T07:21:44.json [01077.274] 09799.09811> [INFO:trace_manager.cc(69)] Starting trace with 12 MB buffers, buffering mode=oneshot [01077.275] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://set_root_view was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/set_root_view#meta/set_root_view.cmx instead. See https://fuchsia.go [01077.275] 05277.05323> oglesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01077.275] 237534.237549> Starting trace; will stop in 10 seconds... [01077.280] 237891.237903> [INFO:fdio_hid_decoder.cc(280)] hid-parser succesful for 000 with usage page 1 and usage 128 [01077.280] 237891.237903> [INFO:app.cc(151)] Presenter::HACK_SetRendererParams: Setting clipping enabled to true [01077.280] 237891.237903> [INFO:app.cc(164)] Presenter::HACK_SetRendererParams: Setting render frequency to 1 [01077.280] 237891.237903> [INFO:app.cc(158)] Presenter::HACK_SetRendererParams: Setting shadow technique to 1 [01077.283] 238116.238128> [WARNING:garnet/bin/ui/set_root_view/main.cc(23)] BE ADVISED: The set_root_view tool takes the URL to an app that provided the ViewProvider interface and makes it's view the root view. [01077.283] 238116.238128> [WARNING:garnet/bin/ui/set_root_view/main.cc(26)] This tool is intended for testing and debugging purposes only and may cause problems if invoked incorrectly. [01077.284] 238116.238128> [WARNING:garnet/bin/ui/set_root_view/main.cc(29)] Do not invoke set_root_view if a view tree already exists (i.e. if any process that creates a view is already running). [01077.284] 238116.238128> [WARNING:garnet/bin/ui/set_root_view/main.cc(33)] If scenic is already running on your system you will probably want to kill it before invoking this tool. [01077.284] 238116.238128> [WARNING:garnet/bin/ui/set_root_view/main.cc(36)] Use the newer present_view tool for launching apps with Views V2. [01077.284] 238116.238128> [INFO:main.cc(52)] set_root_view requesting input delivery by: ViewManager [01077.284] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://image_grid_flutter was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/image_grid_flutter#meta/image_grid_flutter.cmx instead. See htt [01077.284] 05277.05323> ps://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01077.284] 237891.237903> [INFO:presentation1.cc(184)] Disconnected from a11y toggle broadcaster. [01077.360] 04297.04432> [ERROR:garnet/bin/appmgr/service_provider_dir_impl.cc(99)] Cannot serve service fuchsia.modular.Clipboard for component file://image_grid_flutter: ZX_ERR_NOT_FOUND [01077.362] 238735.238760> [INFO:display_watcher.cc(46)] Scenic: Acquired display controller /dev/class/display-controller/000.(000) [01077.362] 13692.238391> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Clipboard [01077.362] 13692.238391> [INFO:platform_view.cc(126)] Flutter, input comes from: ViewManager [01077.590] 238735.238760> [INFO:input_system.cc(236)] Scenic input system initialized. [01077.591] 237891.237903> [WARNING:garnet/bin/ui/root_presenter/displays/display_configuration.cc(76)] SceneManager: unrecognized display. [01077.591] 238735.238760> [INFO:input_system.cc(576)] Scenic: Parallel dispatch is turned OFF [01077.689] 13692.238428> [INFO:paragraph.cc(291)] Could not find font collection for family "". [01077.689] 13692.238428> [INFO:paragraph.cc(291)] Could not find font collection for family "". [01087.275] 237534.237549> Stopping trace... [01087.275] 09799.09811> [INFO:trace_manager.cc(92)] Stopping trace [01087.330] 09799.09811> [WARNING:garnet/bin/trace_manager/tracee.cc(411)] #15 {238735:scenic.cmx}: 218902 records were dropped [01087.330] 237534.237549> [WARNING:garnet/lib/trace_converters/chromium_exporter.cc(434)] #15 buffer overflowed, records were likely dropped [01089.620] 09799.09811> [INFO:tracee.cc(477)] #15 {238735:scenic.cmx} trace stats [01089.620] 09799.09811> [INFO:tracee.cc(478)] Wrapped count: 0 [01089.620] 09799.09811> [INFO:tracee.cc(479)] # records dropped: 218902 [01089.620] 09799.09811> [INFO:tracee.cc(480)] Durable buffer: 0x0, size 0x0 [01089.620] 09799.09811> [INFO:tracee.cc(483)] Non-durable buffer: 0xbfff18,0x0, size 0xbfff80 [01089.645] 09799.09811> [INFO:trace_manager.cc(95)] Stopped trace [01089.673] 237534.237549> Trace file written to /tmp/infra-test-output/trace.2018-12-16T07:21:44.json [01089.673] 236217.236234> == fuchsia.scenic.image_grid_flutter_ssdo: Processing trace... [01094.539] 340684.340898> === Scenic FPS === [01094.547] 340684.340898> 58.75fps [01094.547] 340684.340898> fps per one-second window: [57 59 59 59 59 59 59] [01094.556] 340684.340898> RenderFrame 2.282ms [01094.564] 340684.340898> ApplyScheduledSessionUpdates 0.8851ms [01094.574] 340684.340898> CommandBuffer::Submit 0.0353ms [01094.583] 340684.340898> UpdateAndDeliverMetrics 0.007378ms [01094.591] 340684.340898> EngineRenderer::RenderLayers 0ms [01094.591] 340684.340898> Warning: no values found for EngineRenderer::RenderLayers. Falling back to a zero value. [01094.600] 340684.340898> Escher GPU time 8.813ms [01094.618] 340684.340898> unaccounted (mostly gfx driver) 0.5653ms [01094.618] 340684.340898> Did not find any processes that matched [01094.626] 236217.236234> == fuchsia.scenic.image_grid_flutter_ssdo: Finished processing trace. [01094.655] 04945.04962> runbench: running /pkgfs/packages/scenic_benchmarks/0/bin/run_scenic_benchmark.sh --out_dir /tmp/infra-test-output --out_file /tmp/infra-test-output/fuchsia.scenic.image_grid_flutter_shadow_map.json --benchmark_label fuchsia [01094.655] 04945.04962> .scenic.image_grid_flutter_shadow_map --cmd set_root_view image_grid_flutter --shadow_map --clipping_enabled [01094.663] 383492.383509> == fuchsia.scenic.image_grid_flutter_shadow_map: Killing processes... [01094.666] 383870.383888> Killed 237891 root_presenter.cmx [01094.666] 13692.238391> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Presenter [01094.666] 13692.238391> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: View [01094.667] 13692.238391> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Service Provider [01094.668] 05277.05323> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/root_presenter#meta/root_presenter.cmx died [01094.670] 383949.383963> Killed 238735 scenic.cmx [01094.670] 238936.238958> [ERROR:garnet/bin/ui/view_manager/view_registry.cc(144)] Exiting due to session connection error. [01094.670] 13692.238391> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(37)] Interface error on: SessionListener [01094.672] 13692.238428> fdio_ns_destroy: ZX_ERR_BAD_STATE [01094.675] 05277.05323> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/view_manager#meta/view_manager.cmx died [01094.676] 02684.03722> Failed to send vsync event -24 [01094.678] 05277.05323> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/scenic#meta/scenic.cmx died [01094.680] 13692.238421> [INFO:vulkan_application.cc(105)] Destroying Vulkan instance [01094.681] 238116.238128> [INFO:main.cc(70)] Launched component terminated. [01094.684] 384046.384060> no tasks found [01094.685] 384115.384129> no tasks found [01094.686] 384184.384198> no tasks found [01094.687] 384253.384267> no tasks found [01094.687] 383492.383509> == fuchsia.scenic.image_grid_flutter_shadow_map: Configuring scenic renderer params... [01094.692] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://set_renderer_params was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/set_renderer_params#meta/set_renderer_params.cmx instead. See [01094.692] 05277.05323> https://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01094.699] 384497.384509> [WARNING:garnet/bin/ui/set_renderer_params_HACK/main.cc(22)] This tool is intended for testing and debugging purposes only and may cause problems if invoked incorrectly. [01094.700] 383492.383509> == fuchsia.scenic.image_grid_flutter_shadow_map: Tracing... [01094.700] 383492.383509> /tmp/infra-test-output/trace.2018-12-16T07:22:02.json [01094.717] 09799.09811> [INFO:trace_manager.cc(69)] Starting trace with 12 MB buffers, buffering mode=oneshot [01094.717] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://set_root_view was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/set_root_view#meta/set_root_view.cmx instead. See https://fuchsia.go [01094.717] 05277.05323> oglesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01094.717] 384750.384764> Starting trace; will stop in 10 seconds... [01094.723] 385100.385112> [INFO:fdio_hid_decoder.cc(280)] hid-parser succesful for 000 with usage page 1 and usage 128 [01094.723] 385100.385112> [INFO:app.cc(151)] Presenter::HACK_SetRendererParams: Setting clipping enabled to true [01094.723] 385100.385112> [INFO:app.cc(164)] Presenter::HACK_SetRendererParams: Setting render frequency to 1 [01094.723] 385100.385112> [INFO:app.cc(158)] Presenter::HACK_SetRendererParams: Setting shadow technique to 2 [01094.726] 385325.385337> [WARNING:garnet/bin/ui/set_root_view/main.cc(23)] BE ADVISED: The set_root_view tool takes the URL to an app that provided the ViewProvider interface and makes it's view the root view. [01094.726] 385325.385337> [WARNING:garnet/bin/ui/set_root_view/main.cc(26)] This tool is intended for testing and debugging purposes only and may cause problems if invoked incorrectly. [01094.726] 385325.385337> [WARNING:garnet/bin/ui/set_root_view/main.cc(29)] Do not invoke set_root_view if a view tree already exists (i.e. if any process that creates a view is already running). [01094.726] 385325.385337> [WARNING:garnet/bin/ui/set_root_view/main.cc(33)] If scenic is already running on your system you will probably want to kill it before invoking this tool. [01094.726] 385325.385337> [WARNING:garnet/bin/ui/set_root_view/main.cc(36)] Use the newer present_view tool for launching apps with Views V2. [01094.726] 385325.385337> [INFO:main.cc(52)] set_root_view requesting input delivery by: ViewManager [01094.726] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://image_grid_flutter was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/image_grid_flutter#meta/image_grid_flutter.cmx instead. See htt [01094.726] 05277.05323> ps://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01094.727] 385100.385112> [INFO:presentation1.cc(184)] Disconnected from a11y toggle broadcaster. [01094.768] 04297.04432> [ERROR:garnet/bin/appmgr/service_provider_dir_impl.cc(99)] Cannot serve service fuchsia.modular.Clipboard for component file://image_grid_flutter: ZX_ERR_NOT_FOUND [01094.775] 13692.385604> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Clipboard [01094.775] 13692.385604> [INFO:platform_view.cc(126)] Flutter, input comes from: ViewManager [01094.779] 385791.385805> [INFO:display_watcher.cc(46)] Scenic: Acquired display controller /dev/class/display-controller/000.(000) [01095.018] 385791.385805> [INFO:input_system.cc(236)] Scenic input system initialized. [01095.018] 385791.385805> [INFO:input_system.cc(576)] Scenic: Parallel dispatch is turned OFF [01095.018] 385100.385112> [WARNING:garnet/bin/ui/root_presenter/displays/display_configuration.cc(76)] SceneManager: unrecognized display. [01095.119] 13692.385637> [INFO:paragraph.cc(291)] Could not find font collection for family "". [01095.119] 13692.385637> [INFO:paragraph.cc(291)] Could not find font collection for family "". [01104.717] 384750.384764> Stopping trace... [01104.717] 09799.09811> [INFO:trace_manager.cc(92)] Stopping trace [01104.786] 09799.09811> [WARNING:garnet/bin/trace_manager/tracee.cc(411)] #18 {385791:scenic.cmx}: 200518 records were dropped [01104.786] 384750.384764> [WARNING:garnet/lib/trace_converters/chromium_exporter.cc(434)] #18 buffer overflowed, records were likely dropped [01106.930] 09799.09811> [INFO:tracee.cc(477)] #18 {385791:scenic.cmx} trace stats [01106.930] 09799.09811> [INFO:tracee.cc(478)] Wrapped count: 0 [01106.930] 09799.09811> [INFO:tracee.cc(479)] # records dropped: 200518 [01106.930] 09799.09811> [INFO:tracee.cc(480)] Durable buffer: 0x0, size 0x0 [01106.930] 09799.09811> [INFO:tracee.cc(483)] Non-durable buffer: 0xbfff80,0x0, size 0xbfff80 [01106.931] 09799.09811> [INFO:trace_manager.cc(95)] Stopped trace [01106.975] 384750.384764> Trace file written to /tmp/infra-test-output/trace.2018-12-16T07:22:02.json [01106.975] 383492.383509> == fuchsia.scenic.image_grid_flutter_shadow_map: Processing trace... [01107.065] 01513.01581> netsvc: handling tftp request failed (file might not exist) [01107.065] 01513.01581> netsvc: close, but no open file [01111.473] 472688.472896> === Scenic FPS === [01111.482] 472688.472896> 58.57fps [01111.482] 472688.472896> fps per one-second window: [56 59 59 59 59 59 59] [01111.489] 472688.472896> RenderFrame 1.426ms [01111.498] 472688.472896> ApplyScheduledSessionUpdates 0.8589ms [01111.506] 472688.472896> CommandBuffer::Submit 0.04037ms [01111.515] 472688.472896> UpdateAndDeliverMetrics 0.006824ms [01111.523] 472688.472896> EngineRenderer::RenderLayers 0ms [01111.523] 472688.472896> Warning: no values found for EngineRenderer::RenderLayers. Falling back to a zero value. [01111.532] 472688.472896> Escher GPU time 8.63ms [01111.549] 472688.472896> unaccounted (mostly gfx driver) 0.4822ms [01111.549] 472688.472896> Did not find any processes that matched [01111.557] 383492.383509> == fuchsia.scenic.image_grid_flutter_shadow_map: Finished processing trace. [01111.581] 04945.04962> runbench: running /pkgfs/packages/scenic_benchmarks/0/bin/run_scenic_benchmark.sh --out_dir /tmp/infra-test-output --out_file /tmp/infra-test-output/fuchsia.scenic.image_grid_flutter_moment_shadow_map.json --benchmark_label [01111.581] 04945.04962> fuchsia.scenic.image_grid_flutter_moment_shadow_map --cmd set_root_view image_grid_flutter --moment_shadow_map --clipping_enabled [01111.597] 506504.506521> == fuchsia.scenic.image_grid_flutter_moment_shadow_map: Killing processes... [01111.599] 506773.506807> Killed 385100 root_presenter.cmx [01111.599] 13692.385604> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Presenter [01111.601] 13692.385604> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: View [01111.601] 13692.385604> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Service Provider [01111.603] 05277.05323> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/root_presenter#meta/root_presenter.cmx died [01111.606] 506938.506953> Killed 385791 scenic.cmx [01111.606] 386007.386028> [ERROR:garnet/bin/ui/view_manager/view_registry.cc(144)] Exiting due to session connection error. [01111.606] 13692.385604> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(37)] Interface error on: SessionListener [01111.606] 13692.385604> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Input Connection [01111.607] 13692.385604> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: View Manager [01111.607] 13692.385637> fdio_ns_destroy: ZX_ERR_BAD_STATE [01111.608] 05277.05323> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/view_manager#meta/view_manager.cmx died [01111.610] 02684.03722> Failed to send vsync event -24 [01111.611] 05277.05323> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/scenic#meta/scenic.cmx died [01111.619] 507010.507024> no tasks found [01111.619] 13692.385630> [INFO:vulkan_application.cc(105)] Destroying Vulkan instance [01111.620] 385325.385337> [INFO:main.cc(70)] Launched component terminated. [01111.621] 507103.507117> no tasks found [01111.623] 507176.507190> no tasks found [01111.624] 507245.507259> no tasks found [01111.624] 506504.506521> == fuchsia.scenic.image_grid_flutter_moment_shadow_map: Configuring scenic renderer params... [01111.628] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://set_renderer_params was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/set_renderer_params#meta/set_renderer_params.cmx instead. See [01111.628] 05277.05323> https://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01111.635] 507489.507501> [WARNING:garnet/bin/ui/set_renderer_params_HACK/main.cc(22)] This tool is intended for testing and debugging purposes only and may cause problems if invoked incorrectly. [01111.636] 506504.506521> == fuchsia.scenic.image_grid_flutter_moment_shadow_map: Tracing... [01111.636] 506504.506521> /tmp/infra-test-output/trace.2018-12-16T07:22:19.json [01111.651] 09799.09811> [INFO:trace_manager.cc(69)] Starting trace with 12 MB buffers, buffering mode=oneshot [01111.653] 507742.507756> Starting trace; will stop in 10 seconds... [01111.653] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://set_root_view was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/set_root_view#meta/set_root_view.cmx instead. See https://fuchsia.go [01111.653] 05277.05323> oglesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01111.657] 508050.508065> [INFO:fdio_hid_decoder.cc(280)] hid-parser succesful for 000 with usage page 1 and usage 128 [01111.657] 508050.508065> [INFO:app.cc(151)] Presenter::HACK_SetRendererParams: Setting clipping enabled to true [01111.657] 508050.508065> [INFO:app.cc(164)] Presenter::HACK_SetRendererParams: Setting render frequency to 1 [01111.657] 508050.508065> [INFO:app.cc(158)] Presenter::HACK_SetRendererParams: Setting shadow technique to 3 [01111.662] 508317.508329> [WARNING:garnet/bin/ui/set_root_view/main.cc(23)] BE ADVISED: The set_root_view tool takes the URL to an app that provided the ViewProvider interface and makes it's view the root view. [01111.662] 508317.508329> [WARNING:garnet/bin/ui/set_root_view/main.cc(26)] This tool is intended for testing and debugging purposes only and may cause problems if invoked incorrectly. [01111.662] 508317.508329> [WARNING:garnet/bin/ui/set_root_view/main.cc(29)] Do not invoke set_root_view if a view tree already exists (i.e. if any process that creates a view is already running). [01111.662] 508317.508329> [WARNING:garnet/bin/ui/set_root_view/main.cc(33)] If scenic is already running on your system you will probably want to kill it before invoking this tool. [01111.662] 508317.508329> [WARNING:garnet/bin/ui/set_root_view/main.cc(36)] Use the newer present_view tool for launching apps with Views V2. [01111.662] 508317.508329> [INFO:main.cc(52)] set_root_view requesting input delivery by: ViewManager [01111.662] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://image_grid_flutter was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/image_grid_flutter#meta/image_grid_flutter.cmx instead. See htt [01111.662] 05277.05323> ps://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01111.662] 508050.508065> [INFO:presentation1.cc(184)] Disconnected from a11y toggle broadcaster. [01111.703] 04297.04432> [ERROR:garnet/bin/appmgr/service_provider_dir_impl.cc(99)] Cannot serve service fuchsia.modular.Clipboard for component file://image_grid_flutter: ZX_ERR_NOT_FOUND [01111.710] 13692.508596> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Clipboard [01111.710] 13692.508596> [INFO:platform_view.cc(126)] Flutter, input comes from: ViewManager [01111.724] 508784.508798> [INFO:display_watcher.cc(46)] Scenic: Acquired display controller /dev/class/display-controller/000.(000) [01111.956] 508784.508798> [INFO:input_system.cc(236)] Scenic input system initialized. [01111.956] 508784.508798> [INFO:input_system.cc(576)] Scenic: Parallel dispatch is turned OFF [01111.956] 508050.508065> [WARNING:garnet/bin/ui/root_presenter/displays/display_configuration.cc(76)] SceneManager: unrecognized display. [01112.059] 13692.508632> [INFO:paragraph.cc(291)] Could not find font collection for family "". [01112.059] 13692.508632> [INFO:paragraph.cc(291)] Could not find font collection for family "". [01121.653] 507742.507756> Stopping trace... [01121.653] 09799.09811> [INFO:trace_manager.cc(92)] Stopping trace [01121.724] 09799.09811> [WARNING:garnet/bin/trace_manager/tracee.cc(411)] #21 {508784:scenic.cmx}: 200857 records were dropped [01121.724] 507742.507756> [WARNING:garnet/lib/trace_converters/chromium_exporter.cc(434)] #21 buffer overflowed, records were likely dropped [01123.811] 09799.09811> [INFO:tracee.cc(477)] #21 {508784:scenic.cmx} trace stats [01123.811] 09799.09811> [INFO:tracee.cc(478)] Wrapped count: 0 [01123.811] 09799.09811> [INFO:tracee.cc(479)] # records dropped: 200857 [01123.811] 09799.09811> [INFO:tracee.cc(480)] Durable buffer: 0x0, size 0x0 [01123.811] 09799.09811> [INFO:tracee.cc(483)] Non-durable buffer: 0xbfff80,0x0, size 0xbfff80 [01123.811] 09799.09811> [INFO:trace_manager.cc(95)] Stopped trace [01123.858] 507742.507756> Trace file written to /tmp/infra-test-output/trace.2018-12-16T07:22:19.json [01123.858] 506504.506521> == fuchsia.scenic.image_grid_flutter_moment_shadow_map: Processing trace... [01128.329] 595401.595615> === Scenic FPS === [01128.338] 595401.595615> 58.57fps [01128.338] 595401.595615> fps per one-second window: [56 59 59 59 59 59 59] [01128.345] 595401.595615> RenderFrame 1.433ms [01128.354] 595401.595615> ApplyScheduledSessionUpdates 0.8616ms [01128.362] 595401.595615> CommandBuffer::Submit 0.04039ms [01128.371] 595401.595615> UpdateAndDeliverMetrics 0.007062ms [01128.378] 595401.595615> EngineRenderer::RenderLayers 0ms [01128.378] 595401.595615> Warning: no values found for EngineRenderer::RenderLayers. Falling back to a zero value. [01128.387] 595401.595615> Escher GPU time 8.574ms [01128.405] 595401.595615> unaccounted (mostly gfx driver) 0.4024ms [01128.405] 595401.595615> Did not find any processes that matched [01128.414] 506504.506521> == fuchsia.scenic.image_grid_flutter_moment_shadow_map: Finished processing trace. [01128.436] 04945.04962> runbench: running /pkgfs/packages/scenic_benchmarks/0/bin/run_scenic_benchmark.sh --out_dir /tmp/infra-test-output --out_file /tmp/infra-test-output/fuchsia.scenic.image_grid_flutter_x3_noclipping_noshadows.json --benchmark_ [01128.436] 04945.04962> label fuchsia.scenic.image_grid_flutter_x3_noclipping_noshadows --cmd set_root_view fuchsia-pkg://fuchsia.com/tile_view#meta/tile_view.cmx image_grid_flutter image_grid_flutter image_grid_flutter --unshadowed --clipping_disa [01128.436] 04945.04962> bled [01128.442] 629332.629349> == fuchsia.scenic.image_grid_flutter_x3_noclipping_noshadows: Killing processes... [01128.444] 629573.629587> Killed 508050 root_presenter.cmx [01128.444] 13692.508596> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Presenter [01128.444] 13692.508596> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: View [01128.444] 13692.508596> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Service Provider [01128.448] 05277.05323> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/root_presenter#meta/root_presenter.cmx died [01128.449] 629730.629772> Killed 508784 scenic.cmx [01128.449] 508997.509015> [ERROR:garnet/bin/ui/view_manager/view_registry.cc(144)] Exiting due to session connection error. [01128.449] 13692.508596> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(37)] Interface error on: SessionListener [01128.450] 13692.508632> fdio_ns_destroy: ZX_ERR_BAD_STATE [01128.454] 02684.03722> Failed to send vsync event -24 [01128.455] 05277.05323> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/view_manager#meta/view_manager.cmx died [01128.455] 05277.05323> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/scenic#meta/scenic.cmx died [01128.457] 629838.629852> no tasks found [01128.459] 629914.629928> no tasks found [01128.460] 629983.629997> no tasks found [01128.461] 630052.630066> Killed 508317 set_root_view [01128.462] 629332.629349> == fuchsia.scenic.image_grid_flutter_x3_noclipping_noshadows: Configuring scenic renderer params... [01128.465] 13692.508624> [INFO:vulkan_application.cc(105)] Destroying Vulkan instance [01128.466] 13692.13704> [INFO:runner.cc(96)] The remote end of the application runner tried to terminate an application that has already been terminated, possibly because we initiated the termination [01128.468] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://set_renderer_params was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/set_renderer_params#meta/set_renderer_params.cmx instead. See [01128.468] 05277.05323> https://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01128.475] 630313.630325> [WARNING:garnet/bin/ui/set_renderer_params_HACK/main.cc(22)] This tool is intended for testing and debugging purposes only and may cause problems if invoked incorrectly. [01128.476] 629332.629349> == fuchsia.scenic.image_grid_flutter_x3_noclipping_noshadows: Tracing... [01128.476] 629332.629349> /tmp/infra-test-output/trace.2018-12-16T07:22:35.json [01128.492] 09799.09811> [INFO:trace_manager.cc(69)] Starting trace with 12 MB buffers, buffering mode=oneshot [01128.493] 630566.630580> Starting trace; will stop in 10 seconds... [01128.493] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://set_root_view was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/set_root_view#meta/set_root_view.cmx instead. See https://fuchsia.go [01128.493] 05277.05323> oglesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01128.498] 630920.630932> [INFO:fdio_hid_decoder.cc(280)] hid-parser succesful for 000 with usage page 1 and usage 128 [01128.498] 630920.630932> [INFO:app.cc(151)] Presenter::HACK_SetRendererParams: Setting clipping enabled to false [01128.498] 630920.630932> [INFO:app.cc(164)] Presenter::HACK_SetRendererParams: Setting render frequency to 1 [01128.498] 630920.630932> [INFO:app.cc(158)] Presenter::HACK_SetRendererParams: Setting shadow technique to 0 [01128.501] 631145.631157> [WARNING:garnet/bin/ui/set_root_view/main.cc(23)] BE ADVISED: The set_root_view tool takes the URL to an app that provided the ViewProvider interface and makes it's view the root view. [01128.501] 631145.631157> [WARNING:garnet/bin/ui/set_root_view/main.cc(26)] This tool is intended for testing and debugging purposes only and may cause problems if invoked incorrectly. [01128.501] 631145.631157> [WARNING:garnet/bin/ui/set_root_view/main.cc(29)] Do not invoke set_root_view if a view tree already exists (i.e. if any process that creates a view is already running). [01128.501] 631145.631157> [WARNING:garnet/bin/ui/set_root_view/main.cc(33)] If scenic is already running on your system you will probably want to kill it before invoking this tool. [01128.501] 631145.631157> [WARNING:garnet/bin/ui/set_root_view/main.cc(36)] Use the newer present_view tool for launching apps with Views V2. [01128.502] 631145.631157> [INFO:main.cc(52)] set_root_view requesting input delivery by: ViewManager [01128.502] 630920.630932> [INFO:presentation1.cc(184)] Disconnected from a11y toggle broadcaster. [01128.548] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://image_grid_flutter was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/image_grid_flutter#meta/image_grid_flutter.cmx instead. See htt [01128.548] 05277.05323> ps://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01128.549] 631727.631739> [INFO:display_watcher.cc(46)] Scenic: Acquired display controller /dev/class/display-controller/000.(000) [01128.549] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://image_grid_flutter was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/image_grid_flutter#meta/image_grid_flutter.cmx instead. See htt [01128.549] 05277.05323> ps://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01128.550] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://image_grid_flutter was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/image_grid_flutter#meta/image_grid_flutter.cmx instead. See htt [01128.550] 05277.05323> ps://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01128.615] 04297.04432> [ERROR:garnet/bin/appmgr/service_provider_dir_impl.cc(99)] Cannot serve service fuchsia.modular.Clipboard for component file://image_grid_flutter: ZX_ERR_NOT_FOUND [01128.615] 04297.04432> [ERROR:garnet/bin/appmgr/service_provider_dir_impl.cc(99)] Cannot serve service fuchsia.modular.Clipboard for component file://image_grid_flutter: ZX_ERR_NOT_FOUND [01128.618] 04297.04432> [ERROR:garnet/bin/appmgr/service_provider_dir_impl.cc(99)] Cannot serve service fuchsia.modular.Clipboard for component file://image_grid_flutter: ZX_ERR_NOT_FOUND [01128.633] 632613.633130> [WARNING:third_party/flutter/shell/common/persistent_cache.cc(46)] Could not acquire the persistent cache directory. Caching of GPU resources on disk is disabled. [01128.635] 632613.633040> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Clipboard [01128.635] 632613.633130> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Clipboard [01128.635] 632613.633061> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Clipboard [01128.686] 631727.631739> [INFO:input_system.cc(236)] Scenic input system initialized. [01128.686] 630920.630932> [WARNING:garnet/bin/ui/root_presenter/displays/display_configuration.cc(76)] SceneManager: unrecognized display. [01128.686] 631727.631739> [INFO:input_system.cc(576)] Scenic: Parallel dispatch is turned OFF [01129.071] 632613.633077> [INFO:paragraph.cc(291)] Could not find font collection for family "". [01129.071] 632613.633077> [INFO:paragraph.cc(291)] Could not find font collection for family "". [01129.075] 632613.633213> [INFO:paragraph.cc(291)] Could not find font collection for family "". [01129.075] 632613.633213> [INFO:paragraph.cc(291)] Could not find font collection for family "". [01129.083] 632613.633154> [INFO:paragraph.cc(291)] Could not find font collection for family "". [01129.083] 632613.633154> [INFO:paragraph.cc(291)] Could not find font collection for family "". [01138.493] 630566.630580> Stopping trace... [01138.493] 09799.09811> [INFO:trace_manager.cc(92)] Stopping trace [01138.531] 09799.09811> [WARNING:garnet/bin/trace_manager/tracee.cc(411)] #25 {631727:scenic.cmx}: 620760 records were dropped [01138.531] 630566.630580> [WARNING:garnet/lib/trace_converters/chromium_exporter.cc(434)] #25 buffer overflowed, records were likely dropped [01140.806] 09799.09811> [INFO:tracee.cc(477)] #25 {631727:scenic.cmx} trace stats [01140.806] 09799.09811> [INFO:tracee.cc(478)] Wrapped count: 0 [01140.806] 09799.09811> [INFO:tracee.cc(479)] # records dropped: 620760 [01140.806] 09799.09811> [INFO:tracee.cc(480)] Durable buffer: 0x0, size 0x0 [01140.806] 09799.09811> [INFO:tracee.cc(483)] Non-durable buffer: 0xbfff80,0x0, size 0xbfff80 [01140.860] 09799.09811> [INFO:trace_manager.cc(95)] Stopped trace [01140.866] 630566.630580> Trace file written to /tmp/infra-test-output/trace.2018-12-16T07:22:35.json [01140.866] 629332.629349> == fuchsia.scenic.image_grid_flutter_x3_noclipping_noshadows: Processing trace... [01145.489] 760140.760538> === Scenic FPS === [01145.500] 760140.760538> 58.73fps [01145.500] 760140.760538> fps per one-second window: [58 59 59 59 58] [01145.507] 760140.760538> RenderFrame 2.022ms [01145.516] 760140.760538> ApplyScheduledSessionUpdates 1.551ms [01145.523] 760140.760538> CommandBuffer::Submit 0.06867ms [01145.534] 760140.760538> UpdateAndDeliverMetrics 0.02135ms [01145.541] 760140.760538> EngineRenderer::RenderLayers 0ms [01145.541] 760140.760538> Warning: no values found for EngineRenderer::RenderLayers. Falling back to a zero value. [01145.550] 760140.760538> Escher GPU time 1.425ms [01145.568] 760140.760538> unaccounted (mostly gfx driver) 1.439ms [01145.568] 760140.760538> Did not find any processes that matched [01145.574] 629332.629349> == fuchsia.scenic.image_grid_flutter_x3_noclipping_noshadows: Finished processing trace. [01145.600] 04945.04962> runbench: running /pkgfs/packages/scenic_benchmarks/0/bin/run_scenic_benchmark.sh --out_dir /tmp/infra-test-output --out_file /tmp/infra-test-output/fuchsia.scenic.image_grid_flutter_x3_noshadows.json --benchmark_label fuchs [01145.600] 04945.04962> ia.scenic.image_grid_flutter_x3_noshadows --cmd set_root_view fuchsia-pkg://fuchsia.com/tile_view#meta/tile_view.cmx image_grid_flutter image_grid_flutter image_grid_flutter --unshadowed --clipping_enabled [01145.607] 811295.811329> == fuchsia.scenic.image_grid_flutter_x3_noshadows: Killing processes... [01145.608] 811554.811568> Killed 630920 root_presenter.cmx [01145.608] 632613.633130> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: View [01145.608] 632613.633130> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Service Provider [01145.609] 632613.633061> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: View [01145.609] 632613.633061> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Service Provider [01145.609] 632613.633040> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: View [01145.609] 632613.633040> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Service Provider [01145.609] 632613.633040> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Presenter [01145.609] 632613.633130> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Presenter [01145.609] 632613.633061> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Presenter [01145.610] 632613.633077> fdio_ns_destroy: ZX_ERR_BAD_STATE [01145.612] 632613.633154> image_grid_flutter(flutter): Error in proxy with interface name [Launcher] and service name [fuchsia.sys.Launcher]: Peer unexpectedly closed [01145.612] 632613.633154> image_grid_flutter(flutter): Error in proxy with interface name [Environment] and service name [fuchsia.sys.Environment]: Peer unexpectedly closed [01145.614] 05277.05323> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/root_presenter#meta/root_presenter.cmx died [01145.623] 811691.811710> Killed 631727 scenic.cmx [01145.623] 631858.631872> [ERROR:garnet/bin/ui/view_manager/view_registry.cc(144)] Exiting due to session connection error. [01145.624] 631441.631453> [INFO:view_provider_component.cc(51)] Lost connection to Scenic. [01145.626] 05277.05323> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/view_manager#meta/view_manager.cmx died [01145.627] 631145.631157> [INFO:main.cc(70)] Launched component terminated. [01145.628] 02684.03722> Failed to send vsync event -24 [01145.636] 05277.05323> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/scenic#meta/scenic.cmx died [01145.637] 811805.811819> no tasks found [01145.638] 811874.811888> no tasks found [01145.639] 811943.811957> no tasks found [01145.640] 812012.812026> no tasks found [01145.640] 811295.811329> == fuchsia.scenic.image_grid_flutter_x3_noshadows: Configuring scenic renderer params... [01145.645] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://set_renderer_params was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/set_renderer_params#meta/set_renderer_params.cmx instead. See [01145.645] 05277.05323> https://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01145.652] 812256.812268> [WARNING:garnet/bin/ui/set_renderer_params_HACK/main.cc(22)] This tool is intended for testing and debugging purposes only and may cause problems if invoked incorrectly. [01145.653] 811295.811329> == fuchsia.scenic.image_grid_flutter_x3_noshadows: Tracing... [01145.653] 811295.811329> /tmp/infra-test-output/trace.2018-12-16T07:22:53.json [01145.668] 09799.09811> [INFO:trace_manager.cc(69)] Starting trace with 12 MB buffers, buffering mode=oneshot [01145.669] 812508.812523> Starting trace; will stop in 10 seconds... [01145.669] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://set_root_view was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/set_root_view#meta/set_root_view.cmx instead. See https://fuchsia.go [01145.669] 05277.05323> oglesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01145.674] 812817.812832> [INFO:fdio_hid_decoder.cc(280)] hid-parser succesful for 000 with usage page 1 and usage 128 [01145.674] 812817.812832> [INFO:app.cc(151)] Presenter::HACK_SetRendererParams: Setting clipping enabled to true [01145.674] 812817.812832> [INFO:app.cc(164)] Presenter::HACK_SetRendererParams: Setting render frequency to 1 [01145.674] 812817.812832> [INFO:app.cc(158)] Presenter::HACK_SetRendererParams: Setting shadow technique to 0 [01145.677] 813088.813100> [WARNING:garnet/bin/ui/set_root_view/main.cc(23)] BE ADVISED: The set_root_view tool takes the URL to an app that provided the ViewProvider interface and makes it's view the root view. [01145.678] 813088.813100> [WARNING:garnet/bin/ui/set_root_view/main.cc(26)] This tool is intended for testing and debugging purposes only and may cause problems if invoked incorrectly. [01145.678] 813088.813100> [WARNING:garnet/bin/ui/set_root_view/main.cc(29)] Do not invoke set_root_view if a view tree already exists (i.e. if any process that creates a view is already running). [01145.678] 813088.813100> [WARNING:garnet/bin/ui/set_root_view/main.cc(33)] If scenic is already running on your system you will probably want to kill it before invoking this tool. [01145.678] 813088.813100> [WARNING:garnet/bin/ui/set_root_view/main.cc(36)] Use the newer present_view tool for launching apps with Views V2. [01145.678] 813088.813100> [INFO:main.cc(52)] set_root_view requesting input delivery by: ViewManager [01145.678] 812817.812832> [INFO:presentation1.cc(184)] Disconnected from a11y toggle broadcaster. [01145.725] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://image_grid_flutter was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/image_grid_flutter#meta/image_grid_flutter.cmx instead. See htt [01145.725] 05277.05323> ps://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01145.726] 813539.813551> [INFO:display_watcher.cc(46)] Scenic: Acquired display controller /dev/class/display-controller/000.(000) [01145.726] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://image_grid_flutter was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/image_grid_flutter#meta/image_grid_flutter.cmx instead. See htt [01145.726] 05277.05323> ps://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01145.727] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://image_grid_flutter was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/image_grid_flutter#meta/image_grid_flutter.cmx instead. See htt [01145.727] 05277.05323> ps://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01145.803] 04297.04432> [ERROR:garnet/bin/appmgr/service_provider_dir_impl.cc(99)] Cannot serve service fuchsia.modular.Clipboard for component file://image_grid_flutter: ZX_ERR_NOT_FOUND [01145.803] 04297.04432> [ERROR:garnet/bin/appmgr/service_provider_dir_impl.cc(99)] Cannot serve service fuchsia.modular.Clipboard for component file://image_grid_flutter: ZX_ERR_NOT_FOUND [01145.815] 04297.04432> [ERROR:garnet/bin/appmgr/service_provider_dir_impl.cc(99)] Cannot serve service fuchsia.modular.Clipboard for component file://image_grid_flutter: ZX_ERR_NOT_FOUND [01145.819] 814800.815025> [WARNING:third_party/flutter/shell/common/persistent_cache.cc(46)] Could not acquire the persistent cache directory. Caching of GPU resources on disk is disabled. [01145.824] 814800.815025> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Clipboard [01145.824] 814800.815007> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Clipboard [01145.831] 814800.815088> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Clipboard [01145.866] 813539.813551> [INFO:input_system.cc(236)] Scenic input system initialized. [01145.866] 812817.812832> [WARNING:garnet/bin/ui/root_presenter/displays/display_configuration.cc(76)] SceneManager: unrecognized display. [01145.866] 813539.813551> [INFO:input_system.cc(576)] Scenic: Parallel dispatch is turned OFF [01146.272] 814800.815473> [INFO:paragraph.cc(291)] Could not find font collection for family "". [01146.272] 814800.815473> [INFO:paragraph.cc(291)] Could not find font collection for family "". [01146.274] 814800.815047> [INFO:paragraph.cc(291)] Could not find font collection for family "". [01146.274] 814800.815047> [INFO:paragraph.cc(291)] Could not find font collection for family "". [01146.283] 814800.815101> [INFO:paragraph.cc(291)] Could not find font collection for family "". [01146.283] 814800.815101> [INFO:paragraph.cc(291)] Could not find font collection for family "". [01155.669] 812508.812523> Stopping trace... [01155.669] 09799.09811> [INFO:trace_manager.cc(92)] Stopping trace [01155.739] 09799.09811> [WARNING:garnet/bin/trace_manager/tracee.cc(411)] #30 {813539:scenic.cmx}: 618636 records were dropped [01155.739] 812508.812523> [WARNING:garnet/lib/trace_converters/chromium_exporter.cc(434)] #30 buffer overflowed, records were likely dropped [01157.910] 09799.09811> [INFO:tracee.cc(477)] #30 {813539:scenic.cmx} trace stats [01157.910] 09799.09811> [INFO:tracee.cc(478)] Wrapped count: 0 [01157.910] 09799.09811> [INFO:tracee.cc(479)] # records dropped: 618636 [01157.910] 09799.09811> [INFO:tracee.cc(480)] Durable buffer: 0x0, size 0x0 [01157.910] 09799.09811> [INFO:tracee.cc(483)] Non-durable buffer: 0xbfff80,0x0, size 0xbfff80 [01157.925] 09799.09811> [INFO:trace_manager.cc(95)] Stopped trace [01157.959] 812508.812523> Trace file written to /tmp/infra-test-output/trace.2018-12-16T07:22:53.json [01157.959] 811295.811329> == fuchsia.scenic.image_grid_flutter_x3_noshadows: Processing trace... [01162.567] 941170.941387> === Scenic FPS === [01162.575] 941170.941387> 58.38fps [01162.575] 941170.941387> fps per one-second window: [56 59 59 58 60] [01162.584] 941170.941387> RenderFrame 1.91ms [01162.592] 941170.941387> ApplyScheduledSessionUpdates 1.423ms [01162.601] 941170.941387> CommandBuffer::Submit 0.05159ms [01162.608] 941170.941387> UpdateAndDeliverMetrics 0.01317ms [01162.617] 941170.941387> EngineRenderer::RenderLayers 0ms [01162.617] 941170.941387> Warning: no values found for EngineRenderer::RenderLayers. Falling back to a zero value. [01162.626] 941170.941387> Escher GPU time 2.163ms [01162.642] 941170.941387> unaccounted (mostly gfx driver) 0.5208ms [01162.642] 941170.941387> Did not find any processes that matched [01162.652] 811295.811329> == fuchsia.scenic.image_grid_flutter_x3_noshadows: Finished processing trace. [01162.674] 04945.04962> runbench: running /pkgfs/packages/scenic_benchmarks/0/bin/run_scenic_benchmark.sh --out_dir /tmp/infra-test-output --out_file /tmp/infra-test-output/fuchsia.scenic.image_grid_flutter_x3_ssdo.json --benchmark_label fuchsia.sc [01162.674] 04945.04962> enic.image_grid_flutter_x3_ssdo --cmd set_root_view fuchsia-pkg://fuchsia.com/tile_view#meta/tile_view.cmx image_grid_flutter image_grid_flutter image_grid_flutter --screen_space_shadows --clipping_enabled [01162.681] 991954.991971> == fuchsia.scenic.image_grid_flutter_x3_ssdo: Killing processes... [01162.683] 992339.992353> Killed 812817 root_presenter.cmx [01162.683] 814800.815088> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: View [01162.684] 814800.815088> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Service Provider [01162.684] 814800.815025> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: View [01162.684] 814800.815025> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Service Provider [01162.684] 814800.815007> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: View [01162.684] 814800.815007> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Service Provider [01162.686] 814800.815088> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Presenter [01162.686] 814800.815007> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Presenter [01162.686] 814800.815025> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Presenter [01162.686] 814800.815047> fdio_ns_destroy: ZX_ERR_BAD_STATE [01162.688] 814800.815101> image_grid_flutter(flutter): Error in proxy with interface name [Launcher] and service name [fuchsia.sys.Launcher]: Peer unexpectedly closed [01162.690] 05277.05323> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/root_presenter#meta/root_presenter.cmx died [01162.693] 992434.992448> Killed 813539 scenic.cmx [01162.694] 813788.813803> [ERROR:garnet/bin/ui/view_manager/view_registry.cc(144)] Exiting due to session connection error. [01162.694] 813382.813394> [INFO:view_provider_component.cc(51)] Lost connection to Scenic. [01162.699] 05277.05323> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/view_manager#meta/view_manager.cmx died [01162.699] 813088.813100> [INFO:main.cc(70)] Launched component terminated. [01162.702] 05277.05323> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/scenic#meta/scenic.cmx died [01162.703] 02684.03722> Failed to send vsync event -24 [01162.706] 992503.992517> no tasks found [01162.708] 992572.992586> no tasks found [01162.709] 992641.992655> no tasks found [01162.710] 992710.992724> no tasks found [01162.710] 991954.991971> == fuchsia.scenic.image_grid_flutter_x3_ssdo: Configuring scenic renderer params... [01162.715] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://set_renderer_params was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/set_renderer_params#meta/set_renderer_params.cmx instead. See [01162.715] 05277.05323> https://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01162.722] 992954.992966> [WARNING:garnet/bin/ui/set_renderer_params_HACK/main.cc(22)] This tool is intended for testing and debugging purposes only and may cause problems if invoked incorrectly. [01162.723] 991954.991971> == fuchsia.scenic.image_grid_flutter_x3_ssdo: Tracing... [01162.723] 991954.991971> /tmp/infra-test-output/trace.2018-12-16T07:23:10.json [01162.753] 09799.09811> [INFO:trace_manager.cc(69)] Starting trace with 12 MB buffers, buffering mode=oneshot [01162.754] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://set_root_view was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/set_root_view#meta/set_root_view.cmx instead. See https://fuchsia.go [01162.754] 05277.05323> oglesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01162.754] 993201.993215> Starting trace; will stop in 10 seconds... [01162.760] 993561.993573> [INFO:fdio_hid_decoder.cc(280)] hid-parser succesful for 000 with usage page 1 and usage 128 [01162.760] 993561.993573> [INFO:app.cc(151)] Presenter::HACK_SetRendererParams: Setting clipping enabled to true [01162.760] 993561.993573> [INFO:app.cc(164)] Presenter::HACK_SetRendererParams: Setting render frequency to 1 [01162.760] 993561.993573> [INFO:app.cc(158)] Presenter::HACK_SetRendererParams: Setting shadow technique to 1 [01162.762] 993786.993798> [WARNING:garnet/bin/ui/set_root_view/main.cc(23)] BE ADVISED: The set_root_view tool takes the URL to an app that provided the ViewProvider interface and makes it's view the root view. [01162.762] 993786.993798> [WARNING:garnet/bin/ui/set_root_view/main.cc(26)] This tool is intended for testing and debugging purposes only and may cause problems if invoked incorrectly. [01162.762] 993786.993798> [WARNING:garnet/bin/ui/set_root_view/main.cc(29)] Do not invoke set_root_view if a view tree already exists (i.e. if any process that creates a view is already running). [01162.762] 993786.993798> [WARNING:garnet/bin/ui/set_root_view/main.cc(33)] If scenic is already running on your system you will probably want to kill it before invoking this tool. [01162.762] 993786.993798> [WARNING:garnet/bin/ui/set_root_view/main.cc(36)] Use the newer present_view tool for launching apps with Views V2. [01162.762] 993786.993798> [INFO:main.cc(52)] set_root_view requesting input delivery by: ViewManager [01162.763] 993561.993573> [INFO:presentation1.cc(184)] Disconnected from a11y toggle broadcaster. [01162.821] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://image_grid_flutter was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/image_grid_flutter#meta/image_grid_flutter.cmx instead. See htt [01162.821] 05277.05323> ps://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01162.822] 994366.994378> [INFO:display_watcher.cc(46)] Scenic: Acquired display controller /dev/class/display-controller/000.(000) [01162.823] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://image_grid_flutter was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/image_grid_flutter#meta/image_grid_flutter.cmx instead. See htt [01162.823] 05277.05323> ps://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01162.824] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://image_grid_flutter was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/image_grid_flutter#meta/image_grid_flutter.cmx instead. See htt [01162.824] 05277.05323> ps://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01162.885] 04297.04432> [ERROR:garnet/bin/appmgr/service_provider_dir_impl.cc(99)] Cannot serve service fuchsia.modular.Clipboard for component file://image_grid_flutter: ZX_ERR_NOT_FOUND [01162.891] 04297.04432> [ERROR:garnet/bin/appmgr/service_provider_dir_impl.cc(99)] Cannot serve service fuchsia.modular.Clipboard for component file://image_grid_flutter: ZX_ERR_NOT_FOUND [01162.896] 995086.995575> [WARNING:third_party/flutter/shell/common/persistent_cache.cc(46)] Could not acquire the persistent cache directory. Caching of GPU resources on disk is disabled. [01162.903] 04297.04432> [ERROR:garnet/bin/appmgr/service_provider_dir_impl.cc(99)] Cannot serve service fuchsia.modular.Clipboard for component file://image_grid_flutter: ZX_ERR_NOT_FOUND [01162.903] 995086.995575> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Clipboard [01162.911] 995086.995462> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Clipboard [01162.929] 995086.995441> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Clipboard [01162.951] 994366.994378> [INFO:input_system.cc(236)] Scenic input system initialized. [01162.951] 993561.993573> [WARNING:garnet/bin/ui/root_presenter/displays/display_configuration.cc(76)] SceneManager: unrecognized display. [01162.952] 994366.994378> [INFO:input_system.cc(576)] Scenic: Parallel dispatch is turned OFF [01163.381] 995086.995486> [INFO:paragraph.cc(291)] Could not find font collection for family "". [01163.381] 995086.995486> [INFO:paragraph.cc(291)] Could not find font collection for family "". [01163.417] 995086.995693> [INFO:paragraph.cc(291)] Could not find font collection for family "". [01163.418] 995086.995693> [INFO:paragraph.cc(291)] Could not find font collection for family "". [01163.440] 995086.995625> [INFO:paragraph.cc(291)] Could not find font collection for family "". [01163.440] 995086.995625> [INFO:paragraph.cc(291)] Could not find font collection for family "". [01167.066] 01513.01581> netsvc: handling tftp request failed (file might not exist) [01167.066] 01513.01581> netsvc: close, but no open file [01172.754] 993201.993215> Stopping trace... [01172.754] 09799.09811> [INFO:trace_manager.cc(92)] Stopping trace [01172.771] 09799.09811> [WARNING:garnet/bin/trace_manager/tracee.cc(411)] #35 {994366:scenic.cmx}: 633192 records were dropped [01172.771] 993201.993215> [WARNING:garnet/lib/trace_converters/chromium_exporter.cc(434)] #35 buffer overflowed, records were likely dropped [01175.263] 09799.09811> [INFO:tracee.cc(477)] #35 {994366:scenic.cmx} trace stats [01175.263] 09799.09811> [INFO:tracee.cc(478)] Wrapped count: 0 [01175.263] 09799.09811> [INFO:tracee.cc(479)] # records dropped: 633192 [01175.263] 09799.09811> [INFO:tracee.cc(480)] Durable buffer: 0x0, size 0x0 [01175.263] 09799.09811> [INFO:tracee.cc(483)] Non-durable buffer: 0xbfff78,0x0, size 0xbfff80 [01175.333] 09799.09811> [INFO:trace_manager.cc(95)] Stopped trace [01175.334] 993201.993215> Trace file written to /tmp/infra-test-output/trace.2018-12-16T07:23:10.json [01175.334] 991954.991971> == fuchsia.scenic.image_grid_flutter_x3_ssdo: Processing trace... [01180.484] 1143735.1144065> === Scenic FPS === [01180.492] 1143735.1144065> 58.01fps [01180.492] 1143735.1144065> fps per one-second window: [54 59 59 59 59] [01180.502] 1143735.1144065> RenderFrame 4.354ms [01180.510] 1143735.1144065> ApplyScheduledSessionUpdates 1.684ms [01180.521] 1143735.1144065> CommandBuffer::Submit 0.05371ms [01180.530] 1143735.1144065> UpdateAndDeliverMetrics 0.01914ms [01180.539] 1143735.1144065> EngineRenderer::RenderLayers 0ms [01180.539] 1143735.1144065> Warning: no values found for EngineRenderer::RenderLayers. Falling back to a zero value. [01180.548] 1143735.1144065> Escher GPU time 9.522ms [01180.565] 1143735.1144065> unaccounted (mostly gfx driver) 1.283ms [01180.565] 1143735.1144065> Did not find any processes that matched [01180.576] 991954.991971> == fuchsia.scenic.image_grid_flutter_x3_ssdo: Finished processing trace. [01180.615] 04945.04962> runbench: running /pkgfs/packages/scenic_benchmarks/0/bin/run_scenic_benchmark.sh --out_dir /tmp/infra-test-output --out_file /tmp/infra-test-output/fuchsia.scenic.image_grid_flutter_x3_shadow_map.json --benchmark_label fuch [01180.615] 04945.04962> sia.scenic.image_grid_flutter_x3_shadow_map --cmd set_root_view fuchsia-pkg://fuchsia.com/tile_view#meta/tile_view.cmx image_grid_flutter image_grid_flutter image_grid_flutter --shadow_map --clipping_enabled [01180.625] 1210471.1210492> == fuchsia.scenic.image_grid_flutter_x3_shadow_map: Killing processes... [01180.626] 1210727.1210741> Killed 993561 root_presenter.cmx [01180.626] 995086.995575> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: View [01180.626] 995086.995575> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Service Provider [01180.627] 995086.995462> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: View [01180.627] 995086.995462> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Service Provider [01180.627] 995086.995441> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: View [01180.627] 995086.995441> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Service Provider [01180.627] 05277.05323> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/root_presenter#meta/root_presenter.cmx died [01180.628] 995086.995441> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Presenter [01180.628] 995086.995462> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Presenter [01180.628] 995086.995575> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Presenter [01180.628] 995086.995486> fdio_ns_destroy: ZX_ERR_BAD_STATE [01180.631] 995086.995693> image_grid_flutter(flutter): Error in proxy with interface name [Launcher] and service name [fuchsia.sys.Launcher]: Peer unexpectedly closed [01180.639] 1210823.1210842> Killed 994366 scenic.cmx [01180.642] 1210823.1210842> WARNING: zx_object_get_child(5937, (job)994515, ...) failed: ZX_ERR_NOT_FOUND (-25) [01180.645] 994499.994511> [ERROR:garnet/bin/ui/view_manager/view_registry.cc(144)] Exiting due to session connection error. [01180.646] 994080.994092> [INFO:view_provider_component.cc(51)] Lost connection to Scenic. [01180.646] 05277.05323> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/view_manager#meta/view_manager.cmx died [01180.646] 02684.03722> Failed to send vsync event -24 [01180.652] 993786.993798> [INFO:main.cc(70)] Launched component terminated. [01180.652] 05277.05323> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/scenic#meta/scenic.cmx died [01180.653] 1210945.1210959> no tasks found [01180.655] 1211014.1211030> no tasks found [01180.657] 1211118.1211132> no tasks found [01180.658] 1211187.1211201> no tasks found [01180.658] 1210471.1210492> == fuchsia.scenic.image_grid_flutter_x3_shadow_map: Configuring scenic renderer params... [01180.663] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://set_renderer_params was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/set_renderer_params#meta/set_renderer_params.cmx instead. See [01180.663] 05277.05323> https://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01180.670] 1211431.1211443> [WARNING:garnet/bin/ui/set_renderer_params_HACK/main.cc(22)] This tool is intended for testing and debugging purposes only and may cause problems if invoked incorrectly. [01180.671] 1210471.1210492> == fuchsia.scenic.image_grid_flutter_x3_shadow_map: Tracing... [01180.671] 1210471.1210492> /tmp/infra-test-output/trace.2018-12-16T07:23:28.json [01180.687] 09799.09811> [INFO:trace_manager.cc(69)] Starting trace with 12 MB buffers, buffering mode=oneshot [01180.687] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://set_root_view was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/set_root_view#meta/set_root_view.cmx instead. See https://fuchsia.go [01180.687] 05277.05323> oglesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01180.688] 1211686.1211700> Starting trace; will stop in 10 seconds... [01180.693] 1212038.1212050> [INFO:fdio_hid_decoder.cc(280)] hid-parser succesful for 000 with usage page 1 and usage 128 [01180.694] 1212038.1212050> [INFO:app.cc(151)] Presenter::HACK_SetRendererParams: Setting clipping enabled to true [01180.694] 1212038.1212050> [INFO:app.cc(164)] Presenter::HACK_SetRendererParams: Setting render frequency to 1 [01180.694] 1212038.1212050> [INFO:app.cc(158)] Presenter::HACK_SetRendererParams: Setting shadow technique to 2 [01180.696] 1212263.1212275> [WARNING:garnet/bin/ui/set_root_view/main.cc(23)] BE ADVISED: The set_root_view tool takes the URL to an app that provided the ViewProvider interface and makes it's view the root view. [01180.696] 1212263.1212275> [WARNING:garnet/bin/ui/set_root_view/main.cc(26)] This tool is intended for testing and debugging purposes only and may cause problems if invoked incorrectly. [01180.696] 1212263.1212275> [WARNING:garnet/bin/ui/set_root_view/main.cc(29)] Do not invoke set_root_view if a view tree already exists (i.e. if any process that creates a view is already running). [01180.696] 1212263.1212275> [WARNING:garnet/bin/ui/set_root_view/main.cc(33)] If scenic is already running on your system you will probably want to kill it before invoking this tool. [01180.696] 1212263.1212275> [WARNING:garnet/bin/ui/set_root_view/main.cc(36)] Use the newer present_view tool for launching apps with Views V2. [01180.696] 1212263.1212275> [INFO:main.cc(52)] set_root_view requesting input delivery by: ViewManager [01180.697] 1212038.1212050> [INFO:presentation1.cc(184)] Disconnected from a11y toggle broadcaster. [01180.743] 1212714.1212726> [INFO:display_watcher.cc(46)] Scenic: Acquired display controller /dev/class/display-controller/000.(000) [01180.743] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://image_grid_flutter was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/image_grid_flutter#meta/image_grid_flutter.cmx instead. See htt [01180.743] 05277.05323> ps://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01180.745] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://image_grid_flutter was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/image_grid_flutter#meta/image_grid_flutter.cmx instead. See htt [01180.745] 05277.05323> ps://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01180.745] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://image_grid_flutter was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/image_grid_flutter#meta/image_grid_flutter.cmx instead. See htt [01180.745] 05277.05323> ps://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01180.811] 04297.04432> [ERROR:garnet/bin/appmgr/service_provider_dir_impl.cc(99)] Cannot serve service fuchsia.modular.Clipboard for component file://image_grid_flutter: ZX_ERR_NOT_FOUND [01180.811] 04297.04432> [ERROR:garnet/bin/appmgr/service_provider_dir_impl.cc(99)] Cannot serve service fuchsia.modular.Clipboard for component file://image_grid_flutter: ZX_ERR_NOT_FOUND [01180.811] 04297.04432> [ERROR:garnet/bin/appmgr/service_provider_dir_impl.cc(99)] Cannot serve service fuchsia.modular.Clipboard for component file://image_grid_flutter: ZX_ERR_NOT_FOUND [01180.828] 1213569.1213919> [WARNING:third_party/flutter/shell/common/persistent_cache.cc(46)] Could not acquire the persistent cache directory. Caching of GPU resources on disk is disabled. [01180.829] 1213569.1213919> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Clipboard [01180.829] 1213569.1213937> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Clipboard [01180.829] 1213569.1214013> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Clipboard [01180.881] 1212714.1212726> [INFO:input_system.cc(236)] Scenic input system initialized. [01180.881] 1212714.1212726> [INFO:input_system.cc(576)] Scenic: Parallel dispatch is turned OFF [01180.881] 1212038.1212050> [WARNING:garnet/bin/ui/root_presenter/displays/display_configuration.cc(76)] SceneManager: unrecognized display. [01181.265] 1213569.1213955> [INFO:paragraph.cc(291)] Could not find font collection for family "". [01181.265] 1213569.1213955> [INFO:paragraph.cc(291)] Could not find font collection for family "". [01181.300] 1213569.1214034> [INFO:paragraph.cc(291)] Could not find font collection for family "". [01181.300] 1213569.1214034> [INFO:paragraph.cc(291)] Could not find font collection for family "". [01181.325] 1213569.1214149> [INFO:paragraph.cc(291)] Could not find font collection for family "". [01181.325] 1213569.1214149> [INFO:paragraph.cc(291)] Could not find font collection for family "". [01190.688] 1211686.1211700> Stopping trace... [01190.688] 09799.09811> [INFO:trace_manager.cc(92)] Stopping trace [01190.754] 09799.09811> [WARNING:garnet/bin/trace_manager/tracee.cc(411)] #40 {1212714:scenic.cmx}: 620902 records were dropped [01190.755] 1211686.1211700> [WARNING:garnet/lib/trace_converters/chromium_exporter.cc(434)] #40 buffer overflowed, records were likely dropped [01193.016] 09799.09811> [INFO:tracee.cc(477)] #40 {1212714:scenic.cmx} trace stats [01193.016] 09799.09811> [INFO:tracee.cc(478)] Wrapped count: 0 [01193.016] 09799.09811> [INFO:tracee.cc(479)] # records dropped: 620902 [01193.016] 09799.09811> [INFO:tracee.cc(480)] Durable buffer: 0x0, size 0x0 [01193.016] 09799.09811> [INFO:tracee.cc(483)] Non-durable buffer: 0xbfff78,0x0, size 0xbfff80 [01193.033] 09799.09811> [INFO:trace_manager.cc(95)] Stopped trace [01193.067] 1211686.1211700> Trace file written to /tmp/infra-test-output/trace.2018-12-16T07:23:28.json [01193.068] 1210471.1210492> == fuchsia.scenic.image_grid_flutter_x3_shadow_map: Processing trace... [01197.919] 1346032.1346319> === Scenic FPS === [01197.927] 1346032.1346319> 57.47fps [01197.927] 1346032.1346319> fps per one-second window: [51 59 59 59 59] [01197.938] 1346032.1346319> RenderFrame 2.365ms [01197.947] 1346032.1346319> ApplyScheduledSessionUpdates 1.468ms [01197.957] 1346032.1346319> CommandBuffer::Submit 0.06048ms [01197.969] 1346032.1346319> UpdateAndDeliverMetrics 0.01633ms [01197.978] 1346032.1346319> EngineRenderer::RenderLayers 0ms [01197.978] 1346032.1346319> Warning: no values found for EngineRenderer::RenderLayers. Falling back to a zero value. [01197.989] 1346032.1346319> Escher GPU time 8.394ms [01198.009] 1346032.1346319> unaccounted (mostly gfx driver) 1.324ms [01198.009] 1346032.1346319> Did not find any processes that matched [01198.018] 1210471.1210492> == fuchsia.scenic.image_grid_flutter_x3_shadow_map: Finished processing trace. [01198.041] 04945.04962> runbench: running /pkgfs/packages/scenic_benchmarks/0/bin/run_scenic_benchmark.sh --out_dir /tmp/infra-test-output --out_file /tmp/infra-test-output/fuchsia.scenic.image_grid_flutter_x3_moment_shadow_map.json --benchmark_lab [01198.041] 04945.04962> el fuchsia.scenic.image_grid_flutter_x3_moment_shadow_map --cmd set_root_view fuchsia-pkg://fuchsia.com/tile_view#meta/tile_view.cmx image_grid_flutter image_grid_flutter image_grid_flutter --moment_shadow_map --clipping_ena [01198.041] 04945.04962> bled [01198.051] 1401497.1401514> == fuchsia.scenic.image_grid_flutter_x3_moment_shadow_map: Killing processes... [01198.053] 1401926.1401940> Killed 1212038 root_presenter.cmx [01198.053] 1213569.1214013> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: View [01198.053] 1213569.1214013> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Service Provider [01198.053] 1213569.1213937> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: View [01198.053] 1213569.1213937> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Service Provider [01198.054] 1213569.1213919> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: View [01198.054] 1213569.1213919> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Service Provider [01198.054] 1213569.1213919> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Presenter [01198.054] 1213569.1213937> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Presenter [01198.054] 1213569.1214013> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Presenter [01198.055] 1213569.1213955> fdio_ns_destroy: ZX_ERR_BAD_STATE [01198.058] 05277.05323> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/root_presenter#meta/root_presenter.cmx died [01198.062] 1402000.1402014> Killed 1212714 scenic.cmx [01198.063] 1212571.1212587> [INFO:view_provider_component.cc(51)] Lost connection to Scenic. [01198.063] 1212966.1212978> [ERROR:garnet/bin/ui/view_manager/view_registry.cc(144)] Exiting due to session connection error. [01198.068] 1212263.1212275> [INFO:main.cc(70)] Launched component terminated. [01198.068] 05277.05323> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/view_manager#meta/view_manager.cmx died [01198.071] 05277.05323> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/scenic#meta/scenic.cmx died [01198.073] 02684.03722> Failed to send vsync event -24 [01198.075] 1402069.1402083> no tasks found [01198.078] 1402138.1402152> no tasks found [01198.080] 1402207.1402221> no tasks found [01198.081] 1402276.1402290> no tasks found [01198.082] 1401497.1401514> == fuchsia.scenic.image_grid_flutter_x3_moment_shadow_map: Configuring scenic renderer params... [01198.086] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://set_renderer_params was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/set_renderer_params#meta/set_renderer_params.cmx instead. See [01198.086] 05277.05323> https://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01198.094] 1402520.1402532> [WARNING:garnet/bin/ui/set_renderer_params_HACK/main.cc(22)] This tool is intended for testing and debugging purposes only and may cause problems if invoked incorrectly. [01198.095] 1401497.1401514> == fuchsia.scenic.image_grid_flutter_x3_moment_shadow_map: Tracing... [01198.095] 1401497.1401514> /tmp/infra-test-output/trace.2018-12-16T07:23:45.json [01198.111] 09799.09811> [INFO:trace_manager.cc(69)] Starting trace with 12 MB buffers, buffering mode=oneshot [01198.111] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://set_root_view was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/set_root_view#meta/set_root_view.cmx instead. See https://fuchsia.go [01198.111] 05277.05323> oglesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01198.112] 1402773.1402787> Starting trace; will stop in 10 seconds... [01198.117] 1403127.1403139> [INFO:fdio_hid_decoder.cc(280)] hid-parser succesful for 000 with usage page 1 and usage 128 [01198.117] 1403127.1403139> [INFO:app.cc(151)] Presenter::HACK_SetRendererParams: Setting clipping enabled to true [01198.117] 1403127.1403139> [INFO:app.cc(164)] Presenter::HACK_SetRendererParams: Setting render frequency to 1 [01198.117] 1403127.1403139> [INFO:app.cc(158)] Presenter::HACK_SetRendererParams: Setting shadow technique to 3 [01198.120] 1403352.1403364> [WARNING:garnet/bin/ui/set_root_view/main.cc(23)] BE ADVISED: The set_root_view tool takes the URL to an app that provided the ViewProvider interface and makes it's view the root view. [01198.120] 1403352.1403364> [WARNING:garnet/bin/ui/set_root_view/main.cc(26)] This tool is intended for testing and debugging purposes only and may cause problems if invoked incorrectly. [01198.120] 1403352.1403364> [WARNING:garnet/bin/ui/set_root_view/main.cc(29)] Do not invoke set_root_view if a view tree already exists (i.e. if any process that creates a view is already running). [01198.120] 1403352.1403364> [WARNING:garnet/bin/ui/set_root_view/main.cc(33)] If scenic is already running on your system you will probably want to kill it before invoking this tool. [01198.120] 1403352.1403364> [WARNING:garnet/bin/ui/set_root_view/main.cc(36)] Use the newer present_view tool for launching apps with Views V2. [01198.120] 1403352.1403364> [INFO:main.cc(52)] set_root_view requesting input delivery by: ViewManager [01198.121] 1403127.1403139> [INFO:presentation1.cc(184)] Disconnected from a11y toggle broadcaster. [01198.166] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://image_grid_flutter was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/image_grid_flutter#meta/image_grid_flutter.cmx instead. See htt [01198.166] 05277.05323> ps://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01198.167] 1403932.1403944> [INFO:display_watcher.cc(46)] Scenic: Acquired display controller /dev/class/display-controller/000.(000) [01198.168] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://image_grid_flutter was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/image_grid_flutter#meta/image_grid_flutter.cmx instead. See htt [01198.168] 05277.05323> ps://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01198.169] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://image_grid_flutter was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/image_grid_flutter#meta/image_grid_flutter.cmx instead. See htt [01198.169] 05277.05323> ps://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01198.228] 04297.04432> [ERROR:garnet/bin/appmgr/service_provider_dir_impl.cc(99)] Cannot serve service fuchsia.modular.Clipboard for component file://image_grid_flutter: ZX_ERR_NOT_FOUND [01198.235] 1404658.1405031> [WARNING:third_party/flutter/shell/common/persistent_cache.cc(46)] Could not acquire the persistent cache directory. Caching of GPU resources on disk is disabled. [01198.236] 1404658.1405031> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Clipboard [01198.245] 04297.04432> [ERROR:garnet/bin/appmgr/service_provider_dir_impl.cc(99)] Cannot serve service fuchsia.modular.Clipboard for component file://image_grid_flutter: ZX_ERR_NOT_FOUND [01198.252] 04297.04432> [ERROR:garnet/bin/appmgr/service_provider_dir_impl.cc(99)] Cannot serve service fuchsia.modular.Clipboard for component file://image_grid_flutter: ZX_ERR_NOT_FOUND [01198.258] 1404658.1405145> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Clipboard [01198.266] 1404658.1405007> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Clipboard [01198.305] 1403932.1403944> [INFO:input_system.cc(236)] Scenic input system initialized. [01198.306] 1403127.1403139> [WARNING:garnet/bin/ui/root_presenter/displays/display_configuration.cc(76)] SceneManager: unrecognized display. [01198.306] 1403932.1403944> [INFO:input_system.cc(576)] Scenic: Parallel dispatch is turned OFF [01198.707] 1404658.1405253> [INFO:paragraph.cc(291)] Could not find font collection for family "". [01198.707] 1404658.1405186> [INFO:paragraph.cc(291)] Could not find font collection for family "". [01198.707] 1404658.1405253> [INFO:paragraph.cc(291)] Could not find font collection for family "". [01198.707] 1404658.1405186> [INFO:paragraph.cc(291)] Could not find font collection for family "". [01198.728] 1404658.1405046> [INFO:paragraph.cc(291)] Could not find font collection for family "". [01198.729] 1404658.1405046> [INFO:paragraph.cc(291)] Could not find font collection for family "". [01208.112] 1402773.1402787> Stopping trace... [01208.112] 09799.09811> [INFO:trace_manager.cc(92)] Stopping trace [01208.194] 09799.09811> [WARNING:garnet/bin/trace_manager/tracee.cc(411)] #45 {1403932:scenic.cmx}: 625231 records were dropped [01208.194] 1402773.1402787> [WARNING:garnet/lib/trace_converters/chromium_exporter.cc(434)] #45 buffer overflowed, records were likely dropped [01210.453] 09799.09811> [INFO:tracee.cc(477)] #45 {1403932:scenic.cmx} trace stats [01210.453] 09799.09811> [INFO:tracee.cc(478)] Wrapped count: 0 [01210.453] 09799.09811> [INFO:tracee.cc(479)] # records dropped: 625231 [01210.453] 09799.09811> [INFO:tracee.cc(480)] Durable buffer: 0x0, size 0x0 [01210.453] 09799.09811> [INFO:tracee.cc(483)] Non-durable buffer: 0xbfff78,0x0, size 0xbfff80 [01210.453] 09799.09811> [INFO:trace_manager.cc(95)] Stopped trace [01210.502] 1402773.1402787> Trace file written to /tmp/infra-test-output/trace.2018-12-16T07:23:45.json [01210.503] 1401497.1401514> == fuchsia.scenic.image_grid_flutter_x3_moment_shadow_map: Processing trace... [01215.272] 1538052.1538260> === Scenic FPS === [01215.284] 1538052.1538260> 57.49fps [01215.284] 1538052.1538260> fps per one-second window: [51 59 59 59 59] [01215.292] 1538052.1538260> RenderFrame 2.528ms [01215.304] 1538052.1538260> ApplyScheduledSessionUpdates 1.489ms [01215.313] 1538052.1538260> CommandBuffer::Submit 0.09859ms [01215.323] 1538052.1538260> UpdateAndDeliverMetrics 0.01917ms [01215.336] 1538052.1538260> EngineRenderer::RenderLayers 0ms [01215.336] 1538052.1538260> Warning: no values found for EngineRenderer::RenderLayers. Falling back to a zero value. [01215.344] 1538052.1538260> Escher GPU time 8.505ms [01215.367] 1538052.1538260> unaccounted (mostly gfx driver) 2.092ms [01215.367] 1538052.1538260> Did not find any processes that matched [01215.376] 1401497.1401514> == fuchsia.scenic.image_grid_flutter_x3_moment_shadow_map: Finished processing trace. [01215.401] 04945.04962> runbench: running /pkgfs/packages/scenic_benchmarks/0/bin/run_scenic_benchmark.sh --out_dir /tmp/infra-test-output --out_file /tmp/infra-test-output/fuchsia.scenic.choreography_noclipping_noshadows.json --benchmark_label fuc [01215.401] 04945.04962> hsia.scenic.choreography_noclipping_noshadows --cmd basemgr --test --enable_presenter --account_provider=dev_token_manager --base_shell=dev_base_shell --base_shell_args=--test_timeout_ms=60000 --session_shell=dev_session_she [01215.401] 04945.04962> ll --session_shell_args=--root_module=choreography --story_shell=mondrian --unshadowed --clipping_disabled [01215.408] 1592940.1592957> == fuchsia.scenic.choreography_noclipping_noshadows: Killing processes... [01215.409] 1593183.1593197> Killed 1403127 root_presenter.cmx [01215.409] 1404658.1405145> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: View [01215.409] 1404658.1405031> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: View [01215.409] 1404658.1405145> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Service Provider [01215.409] 1404658.1405031> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Service Provider [01215.409] 1404658.1405007> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: View [01215.410] 1404658.1405007> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Service Provider [01215.410] 1404658.1405145> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Presenter [01215.410] 1404658.1405007> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Presenter [01215.410] 1404658.1405031> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Presenter [01215.410] 1404658.1405046> fdio_ns_destroy: ZX_ERR_BAD_STATE [01215.412] 1404658.1405253> image_grid_flutter(flutter): Error in proxy with interface name [Launcher] and service name [fuchsia.sys.Launcher]: Peer unexpectedly closed [01215.412] 1404658.1405253> image_grid_flutter(flutter): Error in proxy with interface name [Environment] and service name [fuchsia.sys.Environment]: Peer unexpectedly closed [01215.413] 1404658.1405253> image_grid_flutter(flutter): Error in proxy with interface name [ServiceProvider] and service name [null]: Peer unexpectedly closed [01215.416] 05277.05323> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/root_presenter#meta/root_presenter.cmx died [01215.424] 1593291.1593311> Killed 1403932 scenic.cmx [01215.425] 1404064.1404077> [ERROR:garnet/bin/ui/view_manager/view_registry.cc(144)] Exiting due to session connection error. [01215.425] 1403646.1403658> [INFO:view_provider_component.cc(51)] Lost connection to Scenic. [01215.427] 02684.03722> Failed to send vsync event -24 [01215.435] 05277.05323> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/view_manager#meta/view_manager.cmx died [01215.435] 1403352.1403364> [INFO:main.cc(70)] Launched component terminated. [01215.439] 1593403.1593417> WARNING: zx_object_get_child(4811, (job)1401459, ...) failed: ZX_ERR_NOT_FOUND (-25) [01215.440] 05277.05323> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/scenic#meta/scenic.cmx died [01215.440] 1593403.1593417> WARNING: zx_object_get_child(5937, (job)1403927, ...) failed: ZX_ERR_NOT_FOUND (-25) [01215.440] 1593403.1593417> no tasks found [01215.442] 1593507.1593521> no tasks found [01215.443] 1593576.1593590> no tasks found [01215.444] 1593645.1593659> no tasks found [01215.444] 1592940.1592957> == fuchsia.scenic.choreography_noclipping_noshadows: Configuring scenic renderer params... [01215.449] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://set_renderer_params was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/set_renderer_params#meta/set_renderer_params.cmx instead. See [01215.449] 05277.05323> https://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01215.456] 1593889.1593901> [WARNING:garnet/bin/ui/set_renderer_params_HACK/main.cc(22)] This tool is intended for testing and debugging purposes only and may cause problems if invoked incorrectly. [01215.457] 1592940.1592957> == fuchsia.scenic.choreography_noclipping_noshadows: Tracing... [01215.457] 1592940.1592957> /tmp/infra-test-output/trace.2018-12-16T07:24:02.json [01215.473] 09799.09811> [INFO:trace_manager.cc(69)] Starting trace with 12 MB buffers, buffering mode=oneshot [01215.474] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://basemgr was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/basemgr#meta/basemgr.cmx instead. See https://fuchsia.googlesource.com/doc [01215.474] 05277.05323> s/+/master/glossary.md#fuchsia_pkg-url for more information. [01215.474] 1594144.1594158> Starting trace; will stop in 10 seconds... [01215.479] 1594498.1594510> [INFO:fdio_hid_decoder.cc(280)] hid-parser succesful for 000 with usage page 1 and usage 128 [01215.479] 1594498.1594510> [INFO:app.cc(151)] Presenter::HACK_SetRendererParams: Setting clipping enabled to false [01215.479] 1594498.1594510> [INFO:app.cc(164)] Presenter::HACK_SetRendererParams: Setting render frequency to 1 [01215.479] 1594498.1594510> [INFO:app.cc(158)] Presenter::HACK_SetRendererParams: Setting shadow technique to 0 [01215.484] 1594733.1594745> [ERROR:peridot/lib/session_shell_settings/session_shell_settings.cc(163)] /system/data/sysui/base_shell_config.json: read failed [01215.484] 1594733.1594745> [INFO:basemgr_impl.cc(209)] [01215.484] 1594733.1594745> [01215.484] 1594733.1594745> ======================== Starting Test [=choreography] [01215.484] 1594733.1594745> ============================================================ [01215.484] 1594733.1594745> [01215.485] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://token_manager_factory was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/token_manager_factory#meta/token_manager_factory.cmx instead [01215.485] 05277.05323> . See https://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01215.486] 1594733.1594745> [INFO:basemgr_impl.cc(465)] Setting shadow technique to 0 [01215.486] 1594733.1594745> [ERROR:peridot/bin/basemgr/basemgr_impl.cc(87)] Active session shell index is 0, but only 0 session shell settings exist. [01215.486] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://token_manager_factory was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/token_manager_factory#meta/token_manager_factory.cmx instead [01215.486] 05277.05323> . See https://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01215.487] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://dev_base_shell was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/dev_base_shell#meta/dev_base_shell.cmx instead. See https://fuchsia [01215.487] 05277.05323> .googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01215.495] 1594498.1594510> [INFO:presentation1.cc(184)] Disconnected from a11y toggle broadcaster. [01215.498] 1595102.1595114> No service found for path fuchsia.modular.Lifecycle [01215.502] 1595215.1595227> No service found for path fuchsia.modular.auth.AccountProvider [01215.512] 1594733.1594745> [INFO:user_provider_impl.cc(191)] fuchsia::modular::UserProvider::Login() Incognito mode [01215.512] 1594733.1594745> [INFO:user_controller_impl.cc(54)] SESSIONMGR DATA ORIGIN IS /data/modular/USER_GUEST_2150845075 [01215.524] 1594733.1594745> [INFO:basemgr_impl.cc(465)] Setting shadow technique to 0 [01215.524] 1594733.1594745> [ERROR:peridot/bin/basemgr/basemgr_impl.cc(87)] Active session shell index is 0, but only 0 session shell settings exist. [01215.524] 1594733.1594745> [WARNING:peridot/bin/basemgr/user_provider_impl.cc(137)] AuthenticationContextProvider disconnected. [01215.541] 1595630.1595642> [INFO:display_watcher.cc(46)] Scenic: Acquired display controller /dev/class/display-controller/000.(000) [01215.551] 1594498.1594510> [INFO:presentation1.cc(184)] Disconnected from a11y toggle broadcaster. [01215.551] 1595314.1595326> [ERROR:peridot/public/lib/integration_testing/cpp/testing.cc(39)] This application must be run under test_runner. [01215.569] 1594498.1594510> [ERROR:garnet/bin/ui/root_presenter/presentation1.cc(822)] Root presenter: Content view terminated unexpectedly. [01215.573] 1596044.1596056> [INFO:device_info.cc(61)] device_info: syncing device id for user: GUEST set to: d5a7fa5e-7adb-44d5-b948-53c3084f93c8 [01215.580] 1596044.1596056> [INFO:user_intelligence_provider_impl.cc(113)] Starting session_agents: [01215.580] 1596044.1596056> [INFO:user_intelligence_provider_impl.cc(119)] Starting startup_agents: [01215.630] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://dev_session_shell was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/dev_session_shell#meta/dev_session_shell.cmx instead. See https: [01215.630] 05277.05323> //fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01215.635] 1597267.1597283> [WARNING:peridot/bin/ledger/app/ledger_repository_factory_impl.cc(305)] No cloud provider - Ledger will work locally but not sync. (running in Guest mode?) [01215.666] 1596044.1596056> [INFO:device_map_impl.cc(155)] Updated Device: Device/d5a7fa5e-7adb-44d5-b948-53c3084f93c8 value={"@version":3,"name":"viral-blush-shiny-grew","device_id":"d5a7fa5e-7adb-44d5-b948-53c3084f93c8","profile":"{}","hostname":"vir [01215.666] 1596044.1596056> al-blush-shiny-grew","last_change_timestamp":1544945043} [01215.688] 1595630.1595642> [INFO:input_system.cc(236)] Scenic input system initialized. [01215.688] 1594498.1594510> [WARNING:garnet/bin/ui/root_presenter/displays/display_configuration.cc(76)] SceneManager: unrecognized display. [01215.688] 1595630.1595642> [INFO:input_system.cc(576)] Scenic: Parallel dispatch is turned OFF [01215.688] 1594498.1594510> [WARNING:garnet/bin/ui/root_presenter/presentation1.cc(930)] Presentation1::SetRendererParams: Cannot change shadow technique, default was overriden in root_presenter [01215.693] 1598712.1598724> [INFO:dev_session_shell.cc(103)] DevSessionShell START choreography [01215.787] 1598534.1598549> [INFO:local_module_resolver.cc(109)] No manifest found for handler=choreography [01215.787] 1596044.1596056> [INFO:add_mod_call.cc(92)] Module Resolver does not know about module 'choreography' with action = 'action'. Going to try using it anyway.. [01215.787] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://choreography was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/choreography#meta/choreography.cmx instead. See https://fuchsia.googl [01215.787] 05277.05323> esource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01215.790] 05277.05323> [ERROR:garnet/lib/loader/package_loader.cc(65)] Could not open directory /pkgfs/packages/choreography/0 No such file or directory [01215.790] 1596044.1596056> [ERROR:peridot/lib/module_manifest/module_facet_reader_impl.cc(34)] Could not resolve URL: file://choreography [01215.868] 1598712.1598724> [INFO:dev_session_shell.cc(184)] DevSessionShell Starting story with id: story [01215.869] 1598712.1598724> [INFO:dev_session_shell.cc(210)] DevSessionShell State 3 [01215.869] 1598712.1598724> [INFO:dev_session_shell.cc(210)] DevSessionShell State 1 [01215.869] 1596044.1596056> [INFO:story_controller_impl.cc(183)] StoryControllerImpl::LaunchModule() choreography root [01215.869] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://mondrian was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/mondrian#meta/mondrian.cmx instead. See https://fuchsia.googlesource.com/ [01215.869] 05277.05323> docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01215.874] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://choreography was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/choreography#meta/choreography.cmx instead. See https://fuchsia.googl [01215.874] 05277.05323> esource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01215.879] 05277.05323> [ERROR:garnet/lib/loader/package_loader.cc(65)] Could not open directory /pkgfs/packages/choreography/0 No such file or directory [01215.936] 1601739.1601937> [WARNING:third_party/flutter/shell/common/persistent_cache.cc(46)] Could not acquire the persistent cache directory. Caching of GPU resources on disk is disabled. [01215.936] 1601739.1601937> [INFO:platform_view.cc(126)] Flutter, input comes from: Scenic [01216.162] 1598109.1598121> fidl channel writing error at ../../garnet/public/lib/fidl/cpp/internal/proxy_controller.cc:59: zx_status_t -24, type fuchsia.modular/EntityGetTypesRequest, 16 bytes, 0 handles [01225.474] 1594144.1594158> Stopping trace... [01225.474] 09799.09811> [INFO:trace_manager.cc(92)] Stopping trace [01225.620] 09799.09811> [INFO:tracee.cc(477)] #50 {1595630:scenic.cmx} trace stats [01225.620] 09799.09811> [INFO:tracee.cc(478)] Wrapped count: 0 [01225.620] 09799.09811> [INFO:tracee.cc(479)] # records dropped: 0 [01225.620] 09799.09811> [INFO:tracee.cc(480)] Durable buffer: 0x0, size 0x0 [01225.620] 09799.09811> [INFO:tracee.cc(483)] Non-durable buffer: 0x111ba0,0x0, size 0xbfff80 [01225.666] 09799.09811> [INFO:trace_manager.cc(95)] Stopped trace [01225.666] 1594144.1594158> Trace file written to /tmp/infra-test-output/trace.2018-12-16T07:24:02.json [01225.666] 1592940.1592957> == fuchsia.scenic.choreography_noclipping_noshadows: Processing trace... [01225.957] 1619138.1619372> === Scenic FPS === [01225.957] 1619138.1619372> 59.08fps [01225.957] 1619138.1619372> fps per one-second window: [60 59 59 59 59 59 59 59 59] [01225.958] 1619138.1619372> RenderFrame 0.2337ms [01225.958] 1619138.1619372> ApplyScheduledSessionUpdates 0.0668ms [01225.959] 1619138.1619372> CommandBuffer::Submit 0.02853ms [01225.959] 1619138.1619372> UpdateAndDeliverMetrics 0.006472ms [01225.960] 1619138.1619372> EngineRenderer::RenderLayers 0ms [01225.960] 1619138.1619372> Warning: no values found for EngineRenderer::RenderLayers. Falling back to a zero value. [01225.962] 1619138.1619372> Escher GPU time 0.553ms [01225.966] 1619138.1619340> unaccounted (mostly gfx driver) 0.196ms [01225.966] 1619138.1619340> Did not find any processes that matched [01225.969] 1592940.1592957> == fuchsia.scenic.choreography_noclipping_noshadows: Finished processing trace. [01225.986] 04945.04962> runbench: running /pkgfs/packages/scenic_benchmarks/0/bin/run_scenic_benchmark.sh --out_dir /tmp/infra-test-output --out_file /tmp/infra-test-output/fuchsia.scenic.choreography_noshadows.json --benchmark_label fuchsia.scenic [01225.986] 04945.04962> .choreography_noshadows --cmd basemgr --test --enable_presenter --account_provider=dev_token_manager --base_shell=dev_base_shell --base_shell_args=--test_timeout_ms=60000 --session_shell=dev_session_shell --session_shell_arg [01225.986] 04945.04962> s=--root_module=choreography --story_shell=mondrian --unshadowed --clipping_enabled [01225.992] 1620289.1620306> == fuchsia.scenic.choreography_noshadows: Killing processes... [01225.993] 1620530.1620544> Killed 1594498 root_presenter.cmx [01225.993] 1601739.1601937> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Presenter [01225.993] 1601739.1601937> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: View [01225.993] 1601739.1601937> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Service Provider [01225.994] 1601739.1601963> mondrian(flutter): Error in proxy with interface name [ViewContainer] and service name [null]: Peer unexpectedly closed [01225.995] 05277.05323> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/root_presenter#meta/root_presenter.cmx died [01225.997] 1620601.1620615> Killed 1595630 scenic.cmx [01225.997] 1601739.1601937> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(37)] Interface error on: SessionListener [01225.997] 1595920.1595932> [ERROR:garnet/bin/ui/view_manager/view_registry.cc(144)] Exiting due to session connection error. [01225.999] 1601739.1601963> fdio_ns_destroy: ZX_ERR_BAD_STATE [01225.999] 02684.03722> Failed to send vsync event -24 [01226.006] 05277.05323> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/scenic#meta/scenic.cmx died [01226.009] 05277.05323> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/view_manager#meta/view_manager.cmx died [01226.012] 1620670.1620684> Killed 1594733 basemgr [01226.012] 1598712.1598724> [ERROR:peridot/bin/sessionmgr/dev_session_shell.cc(178)] Story controller for story story died. Does this story exist? [01226.027] 1620765.1620779> no tasks found [01226.028] 1620836.1620850> no tasks found [01226.029] 1620905.1620919> no tasks found [01226.030] 1620289.1620306> == fuchsia.scenic.choreography_noshadows: Configuring scenic renderer params... [01226.034] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://set_renderer_params was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/set_renderer_params#meta/set_renderer_params.cmx instead. See [01226.034] 05277.05323> https://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01226.041] 1621149.1621161> [WARNING:garnet/bin/ui/set_renderer_params_HACK/main.cc(22)] This tool is intended for testing and debugging purposes only and may cause problems if invoked incorrectly. [01226.042] 1620289.1620306> == fuchsia.scenic.choreography_noshadows: Tracing... [01226.042] 1620289.1620306> /tmp/infra-test-output/trace.2018-12-16T07:24:13.json [01226.057] 09799.09811> [INFO:trace_manager.cc(69)] Starting trace with 12 MB buffers, buffering mode=oneshot [01226.058] 1621406.1621420> Starting trace; will stop in 10 seconds... [01226.059] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://basemgr was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/basemgr#meta/basemgr.cmx instead. See https://fuchsia.googlesource.com/doc [01226.059] 05277.05323> s/+/master/glossary.md#fuchsia_pkg-url for more information. [01226.062] 1621712.1621725> [INFO:fdio_hid_decoder.cc(280)] hid-parser succesful for 000 with usage page 1 and usage 128 [01226.062] 1621712.1621725> [INFO:app.cc(151)] Presenter::HACK_SetRendererParams: Setting clipping enabled to true [01226.063] 1621712.1621725> [INFO:app.cc(164)] Presenter::HACK_SetRendererParams: Setting render frequency to 1 [01226.063] 1621712.1621725> [INFO:app.cc(158)] Presenter::HACK_SetRendererParams: Setting shadow technique to 0 [01226.069] 1621991.1622003> [ERROR:peridot/lib/session_shell_settings/session_shell_settings.cc(163)] /system/data/sysui/base_shell_config.json: read failed [01226.069] 1621991.1622003> [INFO:basemgr_impl.cc(209)] [01226.069] 1621991.1622003> [01226.069] 1621991.1622003> ======================== Starting Test [=choreography] [01226.069] 1621991.1622003> ============================================================ [01226.069] 1621991.1622003> [01226.069] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://token_manager_factory was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/token_manager_factory#meta/token_manager_factory.cmx instead [01226.069] 05277.05323> . See https://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01226.070] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://token_manager_factory was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/token_manager_factory#meta/token_manager_factory.cmx instead [01226.070] 05277.05323> . See https://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01226.070] 1621991.1622003> [INFO:basemgr_impl.cc(465)] Setting shadow technique to 0 [01226.070] 1621991.1622003> [ERROR:peridot/bin/basemgr/basemgr_impl.cc(87)] Active session shell index is 0, but only 0 session shell settings exist. [01226.079] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://dev_base_shell was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/dev_base_shell#meta/dev_base_shell.cmx instead. See https://fuchsia [01226.079] 05277.05323> .googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01226.081] 1622325.1622337> No service found for path fuchsia.modular.Lifecycle [01226.085] 1622431.1622443> No service found for path fuchsia.modular.auth.AccountProvider [01226.090] 1621712.1621725> [INFO:presentation1.cc(184)] Disconnected from a11y toggle broadcaster. [01226.121] 1621991.1622003> [INFO:user_provider_impl.cc(191)] fuchsia::modular::UserProvider::Login() Incognito mode [01226.121] 1621991.1622003> [INFO:user_controller_impl.cc(54)] SESSIONMGR DATA ORIGIN IS /data/modular/USER_GUEST_336645398 [01226.122] 1621991.1622003> [INFO:basemgr_impl.cc(465)] Setting shadow technique to 0 [01226.123] 1621991.1622003> [ERROR:peridot/bin/basemgr/basemgr_impl.cc(87)] Active session shell index is 0, but only 0 session shell settings exist. [01226.123] 1621991.1622003> [WARNING:peridot/bin/basemgr/user_provider_impl.cc(137)] AuthenticationContextProvider disconnected. [01226.127] 1621712.1621725> [INFO:presentation1.cc(184)] Disconnected from a11y toggle broadcaster. [01226.129] 1622556.1622568> [ERROR:peridot/public/lib/integration_testing/cpp/testing.cc(39)] This application must be run under test_runner. [01226.129] 1622713.1622725> [INFO:display_watcher.cc(46)] Scenic: Acquired display controller /dev/class/display-controller/000.(000) [01226.134] 1621712.1621725> [ERROR:garnet/bin/ui/root_presenter/presentation1.cc(822)] Root presenter: Content view terminated unexpectedly. [01226.154] 1623338.1623351> [INFO:device_info.cc(61)] device_info: syncing device id for user: GUEST set to: cb9d1c3f-248d-4d22-998d-748c6f06a022 [01226.159] 1623338.1623351> [INFO:user_intelligence_provider_impl.cc(113)] Starting session_agents: [01226.159] 1623338.1623351> [INFO:user_intelligence_provider_impl.cc(119)] Starting startup_agents: [01226.192] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://dev_session_shell was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/dev_session_shell#meta/dev_session_shell.cmx instead. See https: [01226.192] 05277.05323> //fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01226.199] 1624173.1624194> [WARNING:peridot/bin/ledger/app/ledger_repository_factory_impl.cc(305)] No cloud provider - Ledger will work locally but not sync. (running in Guest mode?) [01226.234] 1623338.1623351> [INFO:device_map_impl.cc(155)] Updated Device: Device/cb9d1c3f-248d-4d22-998d-748c6f06a022 value={"@version":3,"name":"viral-blush-shiny-grew","device_id":"cb9d1c3f-248d-4d22-998d-748c6f06a022","profile":"{}","hostname":"vir [01226.234] 1623338.1623351> al-blush-shiny-grew","last_change_timestamp":1544945053} [01226.264] 1625902.1625917> [INFO:dev_session_shell.cc(103)] DevSessionShell START choreography [01226.285] 1622713.1622725> [INFO:input_system.cc(236)] Scenic input system initialized. [01226.285] 1621712.1621725> [WARNING:garnet/bin/ui/root_presenter/displays/display_configuration.cc(76)] SceneManager: unrecognized display. [01226.285] 1622713.1622725> [INFO:input_system.cc(576)] Scenic: Parallel dispatch is turned OFF [01226.285] 1621712.1621725> [WARNING:garnet/bin/ui/root_presenter/presentation1.cc(930)] Presentation1::SetRendererParams: Cannot change shadow technique, default was overriden in root_presenter [01226.352] 1625359.1625371> [INFO:local_module_resolver.cc(109)] No manifest found for handler=choreography [01226.352] 1623338.1623351> [INFO:add_mod_call.cc(92)] Module Resolver does not know about module 'choreography' with action = 'action'. Going to try using it anyway.. [01226.352] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://choreography was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/choreography#meta/choreography.cmx instead. See https://fuchsia.googl [01226.352] 05277.05323> esource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01226.357] 05277.05323> [ERROR:garnet/lib/loader/package_loader.cc(65)] Could not open directory /pkgfs/packages/choreography/0 No such file or directory [01226.357] 1623338.1623351> [ERROR:peridot/lib/module_manifest/module_facet_reader_impl.cc(34)] Could not resolve URL: file://choreography [01226.424] 1625902.1625917> [INFO:dev_session_shell.cc(184)] DevSessionShell Starting story with id: story [01226.424] 1625902.1625917> [INFO:dev_session_shell.cc(210)] DevSessionShell State 3 [01226.425] 1625902.1625917> [INFO:dev_session_shell.cc(210)] DevSessionShell State 1 [01226.425] 1623338.1623351> [INFO:story_controller_impl.cc(183)] StoryControllerImpl::LaunchModule() choreography root [01226.425] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://mondrian was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/mondrian#meta/mondrian.cmx instead. See https://fuchsia.googlesource.com/ [01226.425] 05277.05323> docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01226.428] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://choreography was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/choreography#meta/choreography.cmx instead. See https://fuchsia.googl [01226.428] 05277.05323> esource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01226.437] 05277.05323> [ERROR:garnet/lib/loader/package_loader.cc(65)] Could not open directory /pkgfs/packages/choreography/0 No such file or directory [01226.476] 1628957.1629142> [WARNING:third_party/flutter/shell/common/persistent_cache.cc(46)] Could not acquire the persistent cache directory. Caching of GPU resources on disk is disabled. [01226.477] 1628957.1629142> [INFO:platform_view.cc(126)] Flutter, input comes from: Scenic [01227.067] 01513.01581> netsvc: handling tftp request failed (file might not exist) [01227.067] 01513.01581> netsvc: close, but no open file [01236.058] 1621406.1621420> Stopping trace... [01236.058] 09799.09811> [INFO:trace_manager.cc(92)] Stopping trace [01236.220] 09799.09811> [INFO:tracee.cc(477)] #57 {1622713:scenic.cmx} trace stats [01236.220] 09799.09811> [INFO:tracee.cc(478)] Wrapped count: 0 [01236.220] 09799.09811> [INFO:tracee.cc(479)] # records dropped: 0 [01236.220] 09799.09811> [INFO:tracee.cc(480)] Durable buffer: 0x0, size 0x0 [01236.220] 09799.09811> [INFO:tracee.cc(483)] Non-durable buffer: 0x111a90,0x0, size 0xbfff80 [01236.250] 09799.09811> [INFO:trace_manager.cc(95)] Stopped trace [01236.259] 1621406.1621420> Trace file written to /tmp/infra-test-output/trace.2018-12-16T07:24:13.json [01236.260] 1620289.1620306> == fuchsia.scenic.choreography_noshadows: Processing trace... [01236.559] 1646328.1646562> === Scenic FPS === [01236.561] 1646328.1646562> 58.66fps [01236.561] 1646328.1646562> fps per one-second window: [57 58 59 59 59 59 59 59 59] [01236.562] 1646328.1646562> RenderFrame 0.2843ms [01236.562] 1646328.1646562> ApplyScheduledSessionUpdates 0.06056ms [01236.563] 1646328.1646562> CommandBuffer::Submit 0.03059ms [01236.563] 1646328.1646562> UpdateAndDeliverMetrics 0.006648ms [01236.564] 1646328.1646562> EngineRenderer::RenderLayers 0ms [01236.564] 1646328.1646562> Warning: no values found for EngineRenderer::RenderLayers. Falling back to a zero value. [01236.564] 1646328.1646562> Escher GPU time 0.9477ms [01236.566] 1646328.1646562> unaccounted (mostly gfx driver) 0.2316ms [01236.566] 1646328.1646562> Did not find any processes that matched [01236.569] 1620289.1620306> == fuchsia.scenic.choreography_noshadows: Finished processing trace. [01236.586] 04945.04962> runbench: running /pkgfs/packages/scenic_benchmarks/0/bin/run_scenic_benchmark.sh --out_dir /tmp/infra-test-output --out_file /tmp/infra-test-output/fuchsia.scenic.choreography_ssdo.json --benchmark_label fuchsia.scenic.chor [01236.586] 04945.04962> eography_ssdo --cmd basemgr --test --enable_presenter --account_provider=dev_token_manager --base_shell=dev_base_shell --base_shell_args=--test_timeout_ms=60000 --session_shell=dev_session_shell --session_shell_args=--root_m [01236.586] 04945.04962> odule=choreography --story_shell=mondrian --screen_space_shadows --clipping_enabled [01236.592] 1647478.1647495> == fuchsia.scenic.choreography_ssdo: Killing processes... [01236.593] 1647719.1647733> Killed 1621712 root_presenter.cmx [01236.593] 1628957.1629142> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Presenter [01236.593] 1628957.1629142> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: View [01236.593] 1628957.1629142> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Service Provider [01236.594] 1628957.1629168> mondrian(flutter): Error in proxy with interface name [ViewContainer] and service name [null]: Peer unexpectedly closed [01236.596] 05277.05323> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/root_presenter#meta/root_presenter.cmx died [01236.597] 1647790.1647804> Killed 1622713 scenic.cmx [01236.597] 1628957.1629142> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(37)] Interface error on: SessionListener [01236.597] 1622984.1622998> [ERROR:garnet/bin/ui/view_manager/view_registry.cc(144)] Exiting due to session connection error. [01236.598] 1628957.1629168> fdio_ns_destroy: ZX_ERR_BAD_STATE [01236.601] 05277.05323> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/view_manager#meta/view_manager.cmx died [01236.603] 05277.05323> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/scenic#meta/scenic.cmx died [01236.606] 02684.03722> Failed to send vsync event -24 [01236.606] 1647859.1647873> Killed 1621991 basemgr [01236.606] 1625902.1625917> [ERROR:peridot/bin/sessionmgr/dev_session_shell.cc(178)] Story controller for story story died. Does this story exist? [01236.622] 1647941.1647962> no tasks found [01236.623] 1648017.1648031> no tasks found [01236.624] 1648086.1648100> no tasks found [01236.625] 1647478.1647495> == fuchsia.scenic.choreography_ssdo: Configuring scenic renderer params... [01236.629] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://set_renderer_params was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/set_renderer_params#meta/set_renderer_params.cmx instead. See [01236.629] 05277.05323> https://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01236.638] 1648330.1648342> [WARNING:garnet/bin/ui/set_renderer_params_HACK/main.cc(22)] This tool is intended for testing and debugging purposes only and may cause problems if invoked incorrectly. [01236.639] 1647478.1647495> == fuchsia.scenic.choreography_ssdo: Tracing... [01236.639] 1647478.1647495> /tmp/infra-test-output/trace.2018-12-16T07:24:24.json [01236.654] 09799.09811> [INFO:trace_manager.cc(69)] Starting trace with 12 MB buffers, buffering mode=oneshot [01236.655] 1648583.1648597> Starting trace; will stop in 10 seconds... [01236.656] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://basemgr was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/basemgr#meta/basemgr.cmx instead. See https://fuchsia.googlesource.com/doc [01236.656] 05277.05323> s/+/master/glossary.md#fuchsia_pkg-url for more information. [01236.659] 1648891.1648906> [INFO:fdio_hid_decoder.cc(280)] hid-parser succesful for 000 with usage page 1 and usage 128 [01236.660] 1648891.1648906> [INFO:app.cc(151)] Presenter::HACK_SetRendererParams: Setting clipping enabled to true [01236.660] 1648891.1648906> [INFO:app.cc(164)] Presenter::HACK_SetRendererParams: Setting render frequency to 1 [01236.660] 1648891.1648906> [INFO:app.cc(158)] Presenter::HACK_SetRendererParams: Setting shadow technique to 1 [01236.666] 1649172.1649184> [ERROR:peridot/lib/session_shell_settings/session_shell_settings.cc(163)] /system/data/sysui/base_shell_config.json: read failed [01236.666] 1649172.1649184> [INFO:basemgr_impl.cc(209)] [01236.666] 1649172.1649184> [01236.666] 1649172.1649184> ======================== Starting Test [=choreography] [01236.666] 1649172.1649184> ============================================================ [01236.666] 1649172.1649184> [01236.666] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://token_manager_factory was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/token_manager_factory#meta/token_manager_factory.cmx instead [01236.666] 05277.05323> . See https://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01236.667] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://token_manager_factory was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/token_manager_factory#meta/token_manager_factory.cmx instead [01236.667] 05277.05323> . See https://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01236.667] 1649172.1649184> [INFO:basemgr_impl.cc(465)] Setting shadow technique to 0 [01236.667] 1649172.1649184> [ERROR:peridot/bin/basemgr/basemgr_impl.cc(87)] Active session shell index is 0, but only 0 session shell settings exist. [01236.676] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://dev_base_shell was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/dev_base_shell#meta/dev_base_shell.cmx instead. See https://fuchsia [01236.676] 05277.05323> .googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01236.678] 1649506.1649518> No service found for path fuchsia.modular.Lifecycle [01236.682] 1649612.1649624> No service found for path fuchsia.modular.auth.AccountProvider [01236.687] 1648891.1648906> [INFO:presentation1.cc(184)] Disconnected from a11y toggle broadcaster. [01236.694] 1649172.1649184> [INFO:user_provider_impl.cc(191)] fuchsia::modular::UserProvider::Login() Incognito mode [01236.694] 1649172.1649184> [INFO:user_controller_impl.cc(54)] SESSIONMGR DATA ORIGIN IS /data/modular/USER_GUEST_2720535951 [01236.698] 1649172.1649184> [INFO:basemgr_impl.cc(465)] Setting shadow technique to 0 [01236.698] 1649172.1649184> [ERROR:peridot/bin/basemgr/basemgr_impl.cc(87)] Active session shell index is 0, but only 0 session shell settings exist. [01236.698] 1649172.1649184> [WARNING:peridot/bin/basemgr/user_provider_impl.cc(137)] AuthenticationContextProvider disconnected. [01236.725] 1648891.1648906> [INFO:presentation1.cc(184)] Disconnected from a11y toggle broadcaster. [01236.725] 1649737.1649749> [ERROR:peridot/public/lib/integration_testing/cpp/testing.cc(39)] This application must be run under test_runner. [01236.727] 1650047.1650059> [INFO:display_watcher.cc(46)] Scenic: Acquired display controller /dev/class/display-controller/000.(000) [01236.745] 1648891.1648906> [ERROR:garnet/bin/ui/root_presenter/presentation1.cc(822)] Root presenter: Content view terminated unexpectedly. [01236.750] 1650421.1650439> [INFO:device_info.cc(61)] device_info: syncing device id for user: GUEST set to: 0448e196-dc04-41ff-8021-bd684b432828 [01236.756] 1650421.1650439> [INFO:user_intelligence_provider_impl.cc(113)] Starting session_agents: [01236.756] 1650421.1650439> [INFO:user_intelligence_provider_impl.cc(119)] Starting startup_agents: [01236.796] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://dev_session_shell was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/dev_session_shell#meta/dev_session_shell.cmx instead. See https: [01236.796] 05277.05323> //fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01236.796] 1651302.1651318> [WARNING:peridot/bin/ledger/app/ledger_repository_factory_impl.cc(305)] No cloud provider - Ledger will work locally but not sync. (running in Guest mode?) [01236.830] 1650421.1650439> [INFO:device_map_impl.cc(155)] Updated Device: Device/0448e196-dc04-41ff-8021-bd684b432828 value={"@version":3,"name":"viral-blush-shiny-grew","device_id":"0448e196-dc04-41ff-8021-bd684b432828","profile":"{}","hostname":"vir [01236.830] 1650421.1650439> al-blush-shiny-grew","last_change_timestamp":1544945064} [01236.857] 1653157.1653169> [INFO:dev_session_shell.cc(103)] DevSessionShell START choreography [01236.879] 1650047.1650059> [INFO:input_system.cc(236)] Scenic input system initialized. [01236.879] 1648891.1648906> [WARNING:garnet/bin/ui/root_presenter/displays/display_configuration.cc(76)] SceneManager: unrecognized display. [01236.879] 1650047.1650059> [INFO:input_system.cc(576)] Scenic: Parallel dispatch is turned OFF [01236.879] 1648891.1648906> [WARNING:garnet/bin/ui/root_presenter/presentation1.cc(930)] Presentation1::SetRendererParams: Cannot change shadow technique, default was overriden in root_presenter [01236.951] 1652638.1652653> [INFO:local_module_resolver.cc(109)] No manifest found for handler=choreography [01236.951] 1650421.1650439> [INFO:add_mod_call.cc(92)] Module Resolver does not know about module 'choreography' with action = 'action'. Going to try using it anyway.. [01236.952] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://choreography was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/choreography#meta/choreography.cmx instead. See https://fuchsia.googl [01236.952] 05277.05323> esource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01236.955] 05277.05323> [ERROR:garnet/lib/loader/package_loader.cc(65)] Could not open directory /pkgfs/packages/choreography/0 No such file or directory [01236.955] 1650421.1650439> [ERROR:peridot/lib/module_manifest/module_facet_reader_impl.cc(34)] Could not resolve URL: file://choreography [01237.027] 1653157.1653169> [INFO:dev_session_shell.cc(184)] DevSessionShell Starting story with id: story [01237.027] 1653157.1653169> [INFO:dev_session_shell.cc(210)] DevSessionShell State 3 [01237.027] 1653157.1653169> [INFO:dev_session_shell.cc(210)] DevSessionShell State 1 [01237.028] 1650421.1650439> [INFO:story_controller_impl.cc(183)] StoryControllerImpl::LaunchModule() choreography root [01237.028] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://mondrian was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/mondrian#meta/mondrian.cmx instead. See https://fuchsia.googlesource.com/ [01237.028] 05277.05323> docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01237.031] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://choreography was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/choreography#meta/choreography.cmx instead. See https://fuchsia.googl [01237.031] 05277.05323> esource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01237.037] 05277.05323> [ERROR:garnet/lib/loader/package_loader.cc(65)] Could not open directory /pkgfs/packages/choreography/0 No such file or directory [01237.080] 1656066.1656275> [WARNING:third_party/flutter/shell/common/persistent_cache.cc(46)] Could not acquire the persistent cache directory. Caching of GPU resources on disk is disabled. [01237.081] 1656066.1656275> [INFO:platform_view.cc(126)] Flutter, input comes from: Scenic [01237.330] 1651756.1651779> fidl channel writing error at ../../garnet/public/lib/fidl/cpp/internal/proxy_controller.cc:59: zx_status_t -24, type fuchsia.modular/EntityGetTypesRequest, 16 bytes, 0 handles [01246.655] 1648583.1648597> Stopping trace... [01246.655] 09799.09811> [INFO:trace_manager.cc(92)] Stopping trace [01246.876] 09799.09811> [INFO:tracee.cc(477)] #64 {1650047:scenic.cmx} trace stats [01246.876] 09799.09811> [INFO:tracee.cc(478)] Wrapped count: 0 [01246.876] 09799.09811> [INFO:tracee.cc(479)] # records dropped: 0 [01246.876] 09799.09811> [INFO:tracee.cc(480)] Durable buffer: 0x0, size 0x0 [01246.876] 09799.09811> [INFO:tracee.cc(483)] Non-durable buffer: 0x1fe970,0x0, size 0xbfff80 [01246.950] 09799.09811> [INFO:trace_manager.cc(95)] Stopped trace [01246.950] 1648583.1648597> Trace file written to /tmp/infra-test-output/trace.2018-12-16T07:24:24.json [01246.951] 1647478.1647495> == fuchsia.scenic.choreography_ssdo: Processing trace... [01247.450] 1691894.1692096> === Scenic FPS === [01247.451] 1691894.1692096> 58.62fps [01247.451] 1691894.1692096> fps per one-second window: [56 59 59 59 59 59 59 59 59] [01247.451] 1691894.1692096> RenderFrame 1.077ms [01247.452] 1691894.1692096> ApplyScheduledSessionUpdates 0.05757ms [01247.454] 1691894.1692096> CommandBuffer::Submit 0.02676ms [01247.454] 1691894.1692096> UpdateAndDeliverMetrics 0.006942ms [01247.455] 1691894.1692096> EngineRenderer::RenderLayers 0ms [01247.455] 1691894.1692096> Warning: no values found for EngineRenderer::RenderLayers. Falling back to a zero value. [01247.456] 1691894.1692096> Escher GPU time 4.505ms [01247.458] 1691894.1692096> unaccounted (mostly gfx driver) 0.5303ms [01247.458] 1691894.1692096> Did not find any processes that matched [01247.464] 1647478.1647495> == fuchsia.scenic.choreography_ssdo: Finished processing trace. [01247.484] 04945.04962> runbench: running /pkgfs/packages/scenic_benchmarks/0/bin/run_scenic_benchmark.sh --out_dir /tmp/infra-test-output --out_file /tmp/infra-test-output/fuchsia.scenic.choreography_shadow_map.json --benchmark_label fuchsia.sceni [01247.484] 04945.04962> c.choreography_shadow_map --cmd basemgr --test --enable_presenter --account_provider=dev_token_manager --base_shell=dev_base_shell --base_shell_args=--test_timeout_ms=60000 --session_shell=dev_session_shell --session_shell_a [01247.484] 04945.04962> rgs=--root_module=choreography --story_shell=mondrian --shadow_map --clipping_enabled [01247.489] 1694208.1694225> == fuchsia.scenic.choreography_shadow_map: Killing processes... [01247.490] 1694449.1694463> Killed 1648891 root_presenter.cmx [01247.490] 1656066.1656275> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Presenter [01247.491] 1656066.1656275> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: View [01247.491] 1656066.1656301> mondrian(flutter): Error in proxy with interface name [ViewContainer] and service name [null]: Peer unexpectedly closed [01247.492] 1656066.1656275> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Service Provider [01247.493] 1656066.1656275> [WARNING:topaz/runtime/flutter_runner/platform_view.cc(382)] Flutter PlatformView::OnScenicEvent: Unhandled GFX event (fuchsia.ui.gfx.ImportUnboundEvent). [01247.494] 05277.05323> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/root_presenter#meta/root_presenter.cmx died [01247.495] 1694522.1694536> Killed 1650047 scenic.cmx [01247.495] 1656066.1656275> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(37)] Interface error on: SessionListener [01247.495] 1650193.1650205> [ERROR:garnet/bin/ui/view_manager/view_registry.cc(144)] Exiting due to session connection error. [01247.497] 1656066.1656301> fdio_ns_destroy: ZX_ERR_BAD_STATE [01247.498] 02684.03722> Failed to send vsync event -24 [01247.498] 05277.05323> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/scenic#meta/scenic.cmx died [01247.499] 05277.05323> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/view_manager#meta/view_manager.cmx died [01247.504] 1656066.1656296> [INFO:vulkan_application.cc(105)] Destroying Vulkan instance [01247.506] 1694591.1694605> Killed 1649172 basemgr [01247.507] 1653157.1653169> [ERROR:peridot/bin/sessionmgr/dev_session_shell.cc(178)] Story controller for story story died. Does this story exist? [01247.510] 1651302.1651318> fidl channel writing error at ../../garnet/public/lib/fidl/cpp/internal/proxy_controller.cc:59: zx_status_t -24, type fuchsia.ledger/ConflictResolverFactoryGetPolicyRequest, 32 bytes, 0 handles [01247.511] 1694591.1694605> WARNING: zx_object_get_child(1650731, (job)1653859, ...) failed: ZX_ERR_NOT_FOUND (-25) [01247.519] 1694686.1694700> no tasks found [01247.521] 1694755.1694769> no tasks found [01247.522] 1694824.1694838> no tasks found [01247.522] 1694208.1694225> == fuchsia.scenic.choreography_shadow_map: Configuring scenic renderer params... [01247.526] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://set_renderer_params was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/set_renderer_params#meta/set_renderer_params.cmx instead. See [01247.526] 05277.05323> https://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01247.542] 1695068.1695080> [WARNING:garnet/bin/ui/set_renderer_params_HACK/main.cc(22)] This tool is intended for testing and debugging purposes only and may cause problems if invoked incorrectly. [01247.543] 1694208.1694225> == fuchsia.scenic.choreography_shadow_map: Tracing... [01247.543] 1694208.1694225> /tmp/infra-test-output/trace.2018-12-16T07:24:35.json [01247.559] 09799.09811> [INFO:trace_manager.cc(69)] Starting trace with 12 MB buffers, buffering mode=oneshot [01247.559] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://basemgr was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/basemgr#meta/basemgr.cmx instead. See https://fuchsia.googlesource.com/doc [01247.559] 05277.05323> s/+/master/glossary.md#fuchsia_pkg-url for more information. [01247.559] 1695320.1695335> Starting trace; will stop in 10 seconds... [01247.565] 1695677.1695689> [INFO:fdio_hid_decoder.cc(280)] hid-parser succesful for 000 with usage page 1 and usage 128 [01247.565] 1695677.1695689> [INFO:app.cc(151)] Presenter::HACK_SetRendererParams: Setting clipping enabled to true [01247.565] 1695677.1695689> [INFO:app.cc(164)] Presenter::HACK_SetRendererParams: Setting render frequency to 1 [01247.565] 1695677.1695689> [INFO:app.cc(158)] Presenter::HACK_SetRendererParams: Setting shadow technique to 2 [01247.570] 1695910.1695922> [ERROR:peridot/lib/session_shell_settings/session_shell_settings.cc(163)] /system/data/sysui/base_shell_config.json: read failed [01247.570] 1695910.1695922> [INFO:basemgr_impl.cc(209)] [01247.570] 1695910.1695922> [01247.570] 1695910.1695922> ======================== Starting Test [=choreography] [01247.570] 1695910.1695922> ============================================================ [01247.570] 1695910.1695922> [01247.570] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://token_manager_factory was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/token_manager_factory#meta/token_manager_factory.cmx instead [01247.570] 05277.05323> . See https://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01247.571] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://token_manager_factory was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/token_manager_factory#meta/token_manager_factory.cmx instead [01247.571] 05277.05323> . See https://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01247.572] 1695910.1695922> [INFO:basemgr_impl.cc(465)] Setting shadow technique to 0 [01247.572] 1695910.1695922> [ERROR:peridot/bin/basemgr/basemgr_impl.cc(87)] Active session shell index is 0, but only 0 session shell settings exist. [01247.580] 05277.05323> [WARNING:garnet/lib/loader/package_loader.cc(53)] Component file://dev_base_shell was launched without using fuchsia-pkg URLs! Use fuchsia-pkg://fuchsia.com/dev_base_shell#meta/dev_base_shell.cmx instead. See https://fuchsia [01247.580] 05277.05323> .googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [01247.583] 1696244.1696256> No service found for path fuchsia.modular.Lifecycle [01247.586] 1696350.1696362> No service found for path fuchsia.modular.auth.AccountProvider [01247.591] 1695677.1695689> [INFO:presentation1.cc(184)] Disconnected from a11y toggle broadcaster. [01247.593] 1696474.1696486> fidl channel writing error at ../../garnet/public/lib/fidl/cpp/internal/proxy_controller.cc:59: zx_status_t -24, type fuchsia.testing.runner/TestRunnerIdentifyRequest, 80 bytes, 0 handles [01247.593] 1696474.1696486> fidl channel writing error at ../../garnet/public/lib/fidl/cpp/internal/proxy_controller.cc:59: zx_status_t -24, type fuchsia.testing.runner/TestRunnerSetTestPointCountRequest, 24 bytes, 0 handles [01247.593] 1696474.1696486> fidl channel writing error at ../../garnet/public/lib/fidl/cpp/internal/proxy_controller.cc:59: zx_status_t -24, type fuchsia.testing.runner/TestRunnerStoreGetRequest, 48 bytes, 0 handles [01247.593] 1696474.1696486> [ERROR:peridot/public/lib/integration_testing/cpp/testing.cc(39)] This application must be run under test_runner. [01247.635] 1696679.1696691> [INFO:display_watcher.cc(46)] Scenic: Acquired display controller /dev/class/display-controller/000.(000) [01247.636] 1695677.1695689> [ERROR:garnet/bin/ui/root_presenter/presentation1.cc(822)] Root presenter: Content view terminated unexpectedly. [01247.732] 1696679.1696691> [INFO:input_system.cc(236)] Scenic input system initialized. [01247.732] 1696679.1696691> [INFO:input_system.cc(576)] Scenic: Parallel dispatch is turned OFF [01257.559] 1695320.1695335> Stopping trace... [01257.559] 09799.09811> [INFO:trace_manager.cc(92)] Stopping trace [01257.611] 09799.09811> [INFO:tracee.cc(477)] #71 {1696679:scenic.cmx} trace stats [01257.612] 09799.09811> [INFO:tracee.cc(478)] Wrapped count: 0 [01257.612] 09799.09811> [INFO:tracee.cc(479)] # records dropped: 0 [01257.612] 09799.09811> [INFO:tracee.cc(480)] Durable buffer: 0x0, size 0x0 [01257.612] 09799.09811> [INFO:tracee.cc(483)] Non-durable buffer: 0x1678,0x0, size 0xbfff80 [01257.631] 09799.09811> [INFO:trace_manager.cc(95)] Stopped trace [01257.631] 1695320.1695335> Trace file written to /tmp/infra-test-output/trace.2018-12-16T07:24:35.json [01257.632] 1694208.1694225> == fuchsia.scenic.choreography_shadow_map: Processing trace... [01257.657] 1697899.1698101> === Scenic FPS === [01257.659] 1697899.1698101> panic: runtime error: index out of range [01257.659] 1697899.1698101> [01257.659] 1697899.1698101> goroutine 1 [running]: [01257.659] 1697899.1698101> main.calculateFpsForEvents(0x0, 0x0, 0x0, 0x4202d8073ad8, 0x4202d8073ae8, 0x0, 0x0) [01257.659] 1697899.1698101> /b/s/w/ir/kitchen-workdir/out/release-x64/gen/gopaths/process_scenic_trace/src/process_scenic_trace/process_scenic_trace.go:57 +0x429 [01257.659] 1697899.1698101> main.calculateFps(0x4202d807e420, 0x1, 0x1, 0x451590f20c73, 0x3, 0x451590f21fe2, 0xe, 0x0, 0x0, 0x0, ...) [01257.659] 1697899.1698101> /b/s/w/ir/kitchen-workdir/out/release-x64/gen/gopaths/process_scenic_trace/src/process_scenic_trace/process_scenic_trace.go:94 +0x86 [01257.659] 1697899.1698101> main.reportScenicFps(0x4202d807e420, 0x1, 0x1, 0x4d1a46593df9, 0x26, 0x4202d807c940) [01257.659] 1697899.1698101> /b/s/w/ir/kitchen-workdir/out/release-x64/gen/gopaths/process_scenic_trace/src/process_scenic_trace/process_scenic_trace.go:219 +0xce [01257.659] 1697899.1698101> main.main() [01257.659] 1697899.1698101> /b/s/w/ir/kitchen-workdir/out/release-x64/gen/gopaths/process_scenic_trace/src/process_scenic_trace/process_scenic_trace.go:405 +0x2b0 [01257.660] 1694208.1694225> == fuchsia.scenic.choreography_shadow_map: Finished processing trace. [01257.669] 1698480.1698494> Failed to parse input file, "/tmp/infra-test-output/fuchsia.scenic.choreography_shadow_map.json": The document is empty. (offset 0) [01287.068] 01513.01581> netsvc: handling tftp request failed (file might not exist) [01287.068] 01513.01581> netsvc: close, but no open file [01347.069] 01513.01581> netsvc: handling tftp request failed (file might not exist) [01347.069] 01513.01581> netsvc: close, but no open file [01407.070] 01513.01581> netsvc: handling tftp request failed (file might not exist) [01407.070] 01513.01581> netsvc: close, but no open file [01467.071] 01513.01581> netsvc: handling tftp request failed (file might not exist) [01467.071] 01513.01581> netsvc: close, but no open file [01527.072] 01513.01581> netsvc: handling tftp request failed (file might not exist) [01527.072] 01513.01581> netsvc: close, but no open file [01587.073] 01513.01581> netsvc: handling tftp request failed (file might not exist) [01587.073] 01513.01581> netsvc: close, but no open file [01647.074] 01513.01581> netsvc: handling tftp request failed (file might not exist) [01647.074] 01513.01581> netsvc: close, but no open file [01707.076] 01513.01581> netsvc: handling tftp request failed (file might not exist) [01707.076] 01513.01581> netsvc: close, but no open file [01767.077] 01513.01581> netsvc: handling tftp request failed (file might not exist) [01767.077] 01513.01581> netsvc: close, but no open file [01827.078] 01513.01581> netsvc: handling tftp request failed (file might not exist) [01827.078] 01513.01581> netsvc: close, but no open file [01887.079] 01513.01581> netsvc: handling tftp request failed (file might not exist) [01887.079] 01513.01581> netsvc: close, but no open file [01947.080] 01513.01581> netsvc: handling tftp request failed (file might not exist) [01947.080] 01513.01581> netsvc: close, but no open file [02007.081] 01513.01581> netsvc: handling tftp request failed (file might not exist) [02007.081] 01513.01581> netsvc: close, but no open file [02067.082] 01513.01581> netsvc: handling tftp request failed (file might not exist) [02067.082] 01513.01581> netsvc: close, but no open file [02127.083] 01513.01581> netsvc: handling tftp request failed (file might not exist) [02127.083] 01513.01581> netsvc: close, but no open file [02187.084] 01513.01581> netsvc: handling tftp request failed (file might not exist) [02187.084] 01513.01581> netsvc: close, but no open file 2018/12/15 23:45:39 rebooting the node "viral-blush-shiny-grew"