2018/12/16 13:06:42 properties flag: /etc/botanist/config.json 2018/12/16 13:06:42 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.382] 00000.00000> timer features: constant_tsc 1 invariant_tsc 1 tsc_deadline 1 [00020.382] 00000.00000> Using TSC as wallclock [00020.382] 00000.00000> initializing kernel [00020.382] 00000.00000> initializing mp [00020.382] 00000.00000> initializing timers [00020.382] 00000.00000> INIT: cpu 0, calling hook 0xffffffff0013b230 (debuglog) at level 0x7ffff, flags 0x1 [00020.382] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00197624 (thread_set_priority_experiment) at level 0x7ffff, flags 0x1 [00020.382] 00000.00000> thread set priority experiment is : ENABLED [00020.382] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001ac5f8 (global_prng_thread_safe) at level 0x7ffff, flags 0x1 [00020.382] 00000.00000> creating bootstrap completion thread [00020.382] 00000.00000> top of bootstrap2() [00020.382] 00000.00000> INIT: cpu 0, calling hook 0xffffffff0012fe24 (dpc) at level 0x80000, flags 0x1 [00020.382] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001552b4 (libobject) at level 0x80000, flags 0x1 [00020.382] 00000.00000> OOM: started thread [00020.382] 00000.00000> Processor Model Info: type 0 family 0x6 model 0xe stepping 0x9 [00020.382] 00000.00000> display_family 0x6 display_model 0x8e [00020.382] 00000.00000> Vendor: Intel [00020.382] 00000.00000> Microarch: Kaby Lake [00020.382] 00000.00000> F/M/S: 6/8e/9 [00020.382] 00000.00000> Brand: Intel(R) Core(TM) i5-7300U CPU @ 2.60GHz [00020.382] 00000.00000> Features: fpu sse sse2 sse3 ssse3 sse4.1 sse4.2 mmx avx avx2 fxsr pcid xsave mon aesni clflush [00020.382] 00000.00000> clflushopt fsgsbase tsc_adj smep smap erms rdrand rdseed syscall nx huge rdtscp [00020.382] 00000.00000> invar_tsc tsc_deadline x2apic vmx pt hwp [00020.382] 00000.00000> initializing platform [00020.382] 00000.00000> cpu topology: [00020.382] 00000.00000> 0: apic id 0x0 package 0 node 0 core 0 smt 0 BSP [00020.382] 00000.00000> 1: apic id 0x2 package 0 node 0 core 1 smt 0 [00020.382] 00000.00000> 2: apic id 0x1 package 0 node 0 core 0 smt 1 [00020.382] 00000.00000> 3: apic id 0x3 package 0 node 0 core 1 smt 1 [00020.382] 00000.00000> Found 4 cpus [00020.382] 00000.00000> booting apic ids: 0x2 0x1 0x3 [00020.397] 00000.00000> entering scheduler on cpu 2 [00020.398] 00000.00000> entering scheduler on cpu 1 [00020.398] 00000.00000> entering scheduler on cpu 3 [00020.401] 00000.00000> smbios: manufacturer="Intel Corporation" product="NUC7i5DNKE" [00020.401] 00000.00000> initializing target [00020.401] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00105dfc (x86_pcie_init) at level 0xa0000, flags 0x1 [00020.401] 00000.00000> moving to last init level [00020.401] 00000.00000> INIT: cpu 0, calling hook 0xffffffff0014323c (ktrace) at level 0xc0000, flags 0x1 [00020.404] 00000.00000> ktrace: buffer at 0xffffff9842bbb000 (33554432 bytes) [00020.404] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00147b88 (userboot) at level 0xc0000, flags 0x1 [00020.404] 00000.00000> userboot: ramdisk 0xb55000 @ 0xffffff8000d92000 [00020.404] 00000.00000> userboot: userboot rodata 0 @ [0x5030402cd000,0x5030402d0000) [00020.404] 00000.00000> userboot: userboot code 0x3000 @ [0x5030402d0000,0x5030402db000) [00020.404] 00000.00000> userboot: vdso/full rodata 0 @ [0x5030402db000,0x5030402e1000) [00020.404] 00000.00000> userboot: vdso/full code 0x6000 @ [0x5030402e1000,0x5030402e2000) [00020.404] 00000.00000> userboot: entry point @ 0x5030402d0be0 [00020.404] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001abab0 (kernel_shell) at level 0xc0000, flags 0x1 [00020.404] 01034.01041> userboot: option "netsvc.disable=true" [00020.404] 01034.01041> userboot: option "zircon.system.disable-automount=true" [00020.404] 01034.01041> userboot: option "zircon.autorun.boot=/boot/infra/setup" [00020.404] 01034.01041> userboot: option "http://192.168.42.1/multiboot/d4%3A5d%3Adf%3A00%3Ad7%3A72=" [00020.404] 01034.01041> userboot: option "multiboot.boot_loader_name=iPXE+1.0.0++(d2063)" [00020.431] 01034.01041> userboot: searching bootfs for 'bin/devmgr' [00020.431] 01034.01041> userboot: 'bin/devmgr' has PT_INTERP "lib/ld.so.1" [00020.431] 01034.01041> userboot: searching bootfs for 'lib/ld.so.1' [00020.431] 01034.01041> userboot: userboot: loaded lib/ld.so.1 at 0x64a8c8e01000, entry point 0x64a8c8e875e3 [00020.431] 01034.01041> userboot: userboot: loaded vDSO at 0x6976f0ef4000, entry point 0x0 [00020.431] 01034.01041> userboot: process bin/devmgr started. [00020.431] 01034.01041> userboot: waiting for loader-service requests... [00020.431] 01034.01041> userboot: searching bootfs for 'lib/libasync-default.so' [00020.431] 01034.01041> userboot: searching bootfs for 'lib/liblaunchpad.so' [00020.431] 01034.01041> userboot: searching bootfs for 'lib/libfdio.so' [00020.432] 01048.01051> {{{reset}}} [00020.432] 01048.01051> {{{module:0:<application>:elf:adb289d09c14e41d57cc06e64c3fbad20af116de}}} [00020.432] 01048.01051> {{{mmap:0x70a5981dc000:0x16000:load:0:rx:0}}} [00020.432] 01048.01051> {{{mmap:0x70a5981f3000:0x2000:load:0:rw:0x17000}}} [00020.432] 01048.01051> dso: id=adb289d09c14e41d57cc06e64c3fbad20af116de base=0x000070a5981dc000 name=<application> [00020.432] 01048.01051> {{{module:0x3:libasync-default.so:elf:e185a560eff06a87149e82ac163f0cab85d35cd2}}} [00020.432] 01048.01051> {{{mmap:0xf8a680ae000:0x1000:load:0x3:rx:0}}} [00020.432] 01048.01051> {{{mmap:0xf8a680af000:0x1000:load:0x3:rw:0x1000}}} [00020.432] 01048.01051> dso: id=e185a560eff06a87149e82ac163f0cab85d35cd2 base=0x00000f8a680ae000 name=libasync-default.so [00020.432] 01048.01051> {{{module:0x4:liblaunchpad.so:elf:8b03b75574d08d314aa5efad9a560559dba03719}}} [00020.432] 01048.01051> {{{mmap:0x5e2d2f5c7000:0x7000:load:0x4:rx:0}}} [00020.432] 01048.01051> {{{mmap:0x5e2d2f5ce000:0x2000:load:0x4:rw:0x7000}}} [00020.432] 01048.01051> dso: id=8b03b75574d08d314aa5efad9a560559dba03719 base=0x00005e2d2f5c7000 name=liblaunchpad.so [00020.432] 01048.01051> {{{module:0x5:libfdio.so:elf:67093cd5a6d51815a7899f50f338c85506c5afeb}}} [00020.432] 01048.01051> {{{mmap:0x5d6911821000:0x1f000:load:0x5:rx:0}}} [00020.432] 01048.01051> {{{mmap:0x5d6911841000:0x4000:load:0x5:rw:0x20000}}} [00020.432] 01048.01051> dso: id=67093cd5a6d51815a7899f50f338c85506c5afeb base=0x00005d6911821000 name=libfdio.so [00020.432] 01048.01051> {{{module:0x2:<vDSO>:elf:669f338dda92c28c851da7148fb092cfbae24e8b}}} [00020.432] 01048.01051> {{{mmap:0x6976f0ef4000:0x6000:load:0x2:r:0}}} [00020.432] 01048.01051> {{{mmap:0x6976f0efa000:0x1000:load:0x2:rx:0x6000}}} [00020.432] 01048.01051> dso: id=669f338dda92c28c851da7148fb092cfbae24e8b base=0x00006976f0ef4000 name=<vDSO> [00020.432] 01048.01051> {{{module:0x1:libc.so:elf:f994d740a587fd43637c52aa7659f5ec4e448248}}} [00020.432] 01048.01051> {{{mmap:0x64a8c8e01000:0xcb000:load:0x1:rx:0}}} [00020.432] 01048.01051> {{{mmap:0x64a8c8ecd000:0x6000:load:0x1:rw:0xcc000}}} [00020.432] 01048.01051> dso: id=f994d740a587fd43637c52aa7659f5ec4e448248 base=0x000064a8c8e01000 name=libc.so [00020.432] 01034.01041> userboot: loader-service channel peer closed [00020.432] 01034.01041> userboot: finished! [00020.432] 01048.01051> devmgr: main() [00020.432] 01048.01051> devmgr: init [00020.432] 01048.01051> coordinator_init() [00020.432] 01048.01051> bootfs_open: 'config/devmgr' not found [00020.432] 01048.01051> cmdline: netsvc.disable=true [00020.432] 01048.01051> cmdline: zircon.system.disable-automount=true [00020.432] 01048.01051> cmdline: zircon.autorun.boot=/boot/infra/setup [00020.432] 01048.01051> cmdline: http://192.168.42.1/multiboot/d4%3A5d%3Adf%3A00%3Ad7%3A72= [00020.432] 01048.01051> cmdline: multiboot.boot_loader_name=iPXE+1.0.0++(d2063) [00020.432] 01048.01051> devmgr: svc init [00020.432] 01048.01051> devmgr: launch /boot/bin/svchost (svchost) OK [00020.432] 01048.01051> devmgr: vfs init [00020.432] 01048.01051> devmgr: launch /boot/bin/fshost (fshost) OK [00020.433] 01048.01168> devmgr: shell startup [00020.433] 01048.01051> devmgr: coordinator() [00020.433] 01130.01144> fshost: started. [00020.435] 01048.01159> devmgr: launch /boot/bin/pwrbtn-monitor (pwrbtn-monitor) OK [00020.435] 01048.01180> devmgr: launch /boot/bin/crashsvc (crashsvc) OK [00020.435] 01048.01180> devmgr: launch /boot/bin/virtual-console (virtual-console) OK [00020.435] 01048.01180> zircon.autorun.boot: starting '/boot/infra/setup'... [00020.436] 01048.01180> devmgr: launch /boot/infra/setup (autorun:boot) OK [00020.439] 01048.01051> devcoord: launch devhost 'devhost:sys': pid=1951 [00020.439] 01048.01051> devcoord: launch devhost 'devhost:test': pid=1984 [00020.439] 01048.01051> devcoord: launch devhost 'devhost:root': pid=2017 [00020.439] 01048.01051> devcoord: launch devhost 'devhost:misc': pid=2067 [00020.506] 01951.01975> acpi-bus: not using IOMMU [00020.533] 01951.01975> acpi-pwrbtn: initialized [00020.533] 01951.01975> acpi: published device pci(0x3d27d4962000), parent=proxy(0x3d27d4a05480), handle=0x3d27d4983780 [00020.535] 01951.01975> acpi: published device rtc(0x3d27d494f000), parent=acpi(0x3d27d4a05600), handle=0x3d27d499c1c0 [00020.536] 01951.01975> acpi-ec: initialized [00020.537] 01951.01975> acpi: failed to create NHLT VMO (res -10) [00020.537] 01951.01975> acpi: failed to publish NHLT metadata [00020.539] 01951.01975> Intel Processor Trace configuration for this chipset: [00020.539] 01951.01975> mtc_freq_mask: 0x249 [00020.539] 01951.01975> cyc_thresh_mask: 0x3fff [00020.539] 01951.01975> psb_freq_mask: 0x3f [00020.539] 01951.01975> num addr ranges: 2 [00020.539] 01951.01975> mtrace_ipm_control:34: action 0, options 0x0, arg 0x28fbbc2feac0, size 0x20 [00020.540] 01048.01051> devcoord: launch devhost 'devhost:pci#1:8086:5916': pid=2533 [00020.540] 01048.01051> devcoord: launch devhost 'devhost:pci#3:8086:9d2f': pid=2577 [00020.540] 01048.01051> devcoord: launch devhost 'devhost:pci#5:8086:9d60': pid=2642 [00020.541] 01048.01051> devcoord: launch devhost 'devhost:pci#6:8086:9d61': pid=2710 [00020.541] 01048.01168> devmgr: launch /boot/bin/sh (sh:console) OK [00020.542] 01048.01051> devcoord: launch devhost 'devhost:pci#9:8086:9d03': pid=2786 [00020.542] 01048.01051> devcoord: launch devhost 'devhost:pci#14:8086:9d71': pid=2923 [00020.543] 01048.01051> devcoord: launch devhost 'devhost:pci#16:8086:156f': pid=2994 [00020.544] 02642.02679> initialized intel serialio i2c driver, reg=0x4b2a81191000 regsize=4096 [00020.546] 02710.02744> initialized intel serialio i2c driver, reg=0x4b0ec0b77000 regsize=4096 [00020.548] 02786.02872> ahci: using MSI interrupt [00020.549] 02994.03038> eth: using MSI mode [00020.549] 02577.03204> * found USB device (0x18d1:0xa002, USB 2.0) config 1 [00020.550] 02577.03204> * found USB device (0x18d1:0xa003, USB 3.0) config 1 [00020.553] 02923.02962> [IHDA DSP 00:1f.3] Failed to fetch NHLT (res -25) [00020.553] 02923.02962> devhost[00:1f.3/intel-hda-000/intel-sst-dsp-000] bind driver '/boot/driver/dsp.so' failed: -25 [00020.553] 01048.01051> devcoord: rpc: bind-driver 'intel-sst-dsp-000' status -25 [00020.557] 02994.03038> eth: mac: d4:5d:df:00:d7:72 [00020.557] 02994.03038> eth: iomem @0x7626281a4000 (phys e93000) [00020.557] 02994.03038> eth: intel-ethernet online [00020.771] 02533.03567> i915: MST not supported [00021.182] 02533.03567> i915: Found DP monitor [00021.182] 02533.03567> i915: Display 1 connected [00021.262] 02577.03204> * found USB device (0x0781:0x5583, USB 3.0) config 1 [00021.263] 02577.02613> UMS:Max lun is: 0 [00021.755] 01360.01418> vc: Successfully attached to display 1 [00021.755] 01360.01418> vc: new input device /dev/class/input/000 [00022.013] 02577.03204> * found USB device (0x8087:0x0a2b, USB 2.0) config 1 [00022.014] 02577.02613> devhost[00:14.0/xhci/usb/002/ifc-001] bind driver '/boot/driver/bt-transport-usb.so' failed: -2 [00022.014] 01048.01051> devcoord: rpc: bind-driver 'ifc-001' status -2 [00022.265] 02577.03645> UMS: block size is: 0x00000200 [00022.265] 02577.03645> UMS: total blocks is: 30031872 [00022.265] 02577.03645> UMS: total size is: 15376318464 [00022.265] 02577.03645> UMS: read-only: 0 removable: 1 [00022.265] 01130.01144> devmgr: /dev/class/block/000: MBR? [00022.265] 01048.01051> devcoord: dc_bind_device() '/boot/driver/mbr.so' [00022.268] 01130.01144> devmgr: /dev/class/block/002: MBR? [00022.268] 01048.01051> devcoord: dc_bind_device() '/boot/driver/mbr.so' [00022.546] 02642.02679> i2c-hid: could not read HID descriptor: -21 [00022.546] 02642.02679> devhost[00:15.0/i2c-bus-9d60/0020] bind driver '/boot/driver/i2c-hid.so' failed: -2 [00022.546] 01048.01051> devcoord: rpc: bind-driver '0020' status -2 [00022.547] 02710.02744> i2c-hid: could not read HID descriptor: -21 [00022.547] 02710.02744> devhost[00:15.1/i2c-bus-9d61/004c] bind driver '/boot/driver/i2c-hid.so' failed: -2 [00022.547] 01048.01051> devcoord: rpc: bind-driver '004c' status -2 [00022.562] 02786.03292> sata2: dev info [00022.562] 02786.03292> serial=715400411000 1 [00022.562] 02786.03292> firmware rev=1P11A1E_ [00022.562] 02786.03292> model id=IBIW NSS D [00022.562] 02786.03292> major=0x3f0 ACS2 DMA 32 commands [00022.562] 02786.03292> LBA48 250069680 sectors, sector size=512 [00022.563] 01130.01144> devmgr: /dev/class/block/003: GPT? [00022.563] 01048.01051> devcoord: dc_bind_device() '/boot/driver/gpt.so' [00022.563] 01130.01144> devmgr: /dev/class/block/004: FVM? [00022.563] 01048.01051> devcoord: dc_bind_device() '/boot/driver/fvm.so' [00022.566] 01130.01144> devmgr: /dev/class/block/007: zxcrypt? [00022.566] 01048.01051> devcoord: dc_bind_device() '/boot/driver/zxcrypt.so' [00022.628] 04118.04144> 1024+0 records in [00022.628] 04118.04144> 1024+0 records out [00022.628] 04118.04144> 4194304 bytes copied [00022.629] 05377.05391> netifc: ? /dev/class/ethernet/000 [00022.629] 05377.05391> netifc: create 512 eth buffers [00022.629] 05377.05391> macaddr: d4:5d:df:00:d7:72 [00022.629] 05377.05391> ip6addr: fe80::d65d:df4d:fe00:d772 [00022.629] 05377.05391> snmaddr: ff02::1:ff00:d772 [00022.629] 05377.05391> netsvc: using /dev/class/ethernet/000 [00022.629] 05377.05391> _ _ _ [00022.629] 05377.05391> | | | | | [00022.629] 05377.05391> _______ __| | |__ ___ ___ | |_ [00022.629] 05377.05391> |_ / _ \/ _` | '_ \ / _ \ / _ \| __| [00022.629] 05377.05391> / / __/ (_| | |_) | (_) | (_) | |_ [00022.629] 05377.05391> /___\___|\__,_|_.__/ \___/ \___/ \__| [00022.629] 05377.05391> [00022.629] 05377.05391> [00022.629] 05377.05391> zedboot: version: 0.7.10 [00022.629] 05377.05391> [00022.629] 05377.05391> netsvc: nodename='nanny-kick-shiny-gooey' [00022.629] 05377.05391> netsvc: will not advertise [00022.629] 05377.05391> netsvc: start [02058.549] 05377.05391> netsvc: Running FVM Paver [02058.552] 05377.05483> install-disk-image:[InitializeGpt] Located GPT is invalid; Attempting to initialize [02058.552] 01048.01051> devcoord: dc_bind_device() '' [02058.552] 01048.01051> devcoord: dc_bind_device() '/boot/driver/gpt.so' [02058.553] 01130.01144> devmgr: /dev/class/block/003: GPT? [02058.553] 01048.01051> devcoord: dc_bind_device() '/boot/driver/gpt.so' [02058.553] 05377.05483> install-disk-image:[Initialize] Successfully intitialized EFI Device Partitioner [02058.554] 05377.05483> install-disk-image:[FvmPave] Paving FVM [02058.554] 05377.05483> install-disk-image:[FvmPave] Could not find FVM; attempting to add it: ZX_ERR_NOT_FOUND [02058.554] 05377.05483> install-disk-image:[FindFirstFit] Looking for space [02058.554] 05377.05483> install-disk-image:[FindFirstFit] Sorting [02058.554] 05377.05483> install-disk-image:[FindFirstFit] Partition[0] From Block [0, 34) ... (next partition starts at block 250069646) [02058.554] 05377.05483> install-disk-image:[FindFirstFit] There are 250069612 free blocks (16777216 requested) [02058.554] 05377.05483> install-disk-image:[AddPartition] Found space in GPT - OK 250069612 @ 34 [02058.554] 05377.05483> install-disk-image:[AddPartition] Final space in GPT - OK 16777216 @ 34 [02058.554] 01048.01051> devcoord: dc_bind_device() '' [02058.554] 05377.05483> install-disk-image:[AddPartition] Added partition, waiting for bind [02058.554] 01130.01144> devmgr: /dev/class/block/003: GPT? [02058.554] 01048.01051> devcoord: dc_bind_device() '/boot/driver/gpt.so' [02058.555] 05377.05483> install-disk-image:[AddPartition] Added partition, waiting for bind - OK [02058.555] 05377.05483> install-disk-image:[FvmPave] Streaming partitions... [02058.555] 05463.05477> Found compressed file [02058.555] 05377.05483> install-disk-image:[FvmStreamPartitions] Header Validated - OK [02058.555] 05377.05483> install-disk-image:[FvmPartitionFormat] Initializing partition as FVM [02058.557] 01048.01051> devcoord: dc_bind_device() '/boot/driver/fvm.so' [02060.559] 05377.05483> install-disk-image:[FvmStreamPartitions] Allocating partition blobfs consisting of 1 slices [02060.561] 05377.05483> install-disk-image:[FvmStreamPartitions] Extending partition[0] at offset 64 by length 1 [02060.561] 05377.05483> install-disk-image:[FvmStreamPartitions] Extending partition[0] at offset 128 by length 1 [02060.562] 05377.05483> install-disk-image:[FvmStreamPartitions] Extending partition[0] at offset 192 by length 1 [02060.563] 05377.05483> 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 [02062.159] 05377.05391> netsvc: tftp write of file <<image>>sparse.fvm completed [02062.563] 05377.05483> install-disk-image:[FvmStreamPartitions] Allocating partition minfs consisting of 1 slices [02062.565] 01130.01144> devmgr: /dev/class/block/011: zxcrypt? [02062.565] 01048.01051> devcoord: dc_bind_device() '/boot/driver/zxcrypt.so' [02062.565] 05377.05483> install-disk-image:[FvmStreamPartitions] Creating zxcrypt volume [02062.566] 02786.02872> devhost_get_handles(0x6d8b1e8ce9c0:block) open path='zxcrypt/block', r=-2 [02062.566] 01048.01051> devcoord: dc_bind_device() '/boot/driver/zxcrypt.so' [02062.566] 02786.02872> devhost_get_handles(0x6d8b1e8ce9c0:block) open path='zxcrypt', r=-2 [02062.566] 05377.05483> install-disk-image:[FvmStreamPartitions] Extending partition[1] at offset 64 by length 1 [02062.567] 05377.05483> install-disk-image:[FvmStreamPartitions] Extending partition[1] at offset 128 by length 1 [02062.568] 05377.05483> install-disk-image:[FvmStreamPartitions] Extending partition[1] at offset 192 by length 1 [02062.568] 05377.05483> install-disk-image:[FvmStreamPartitions] Extending partition[1] at offset 256 by length 2 [02062.569] 05377.05483> install-disk-image:[FvmStreamPartitions] Extending partition[1] at offset 320 by length 1 [02062.569] 05377.05483> install-disk-image:[FvmStreamPartitions] Partition space pre-allocated [02062.569] 05377.05483> install-disk-image:[FvmStreamPartitions] Streaming partition 0 [02062.569] 05377.05483> install-disk-image:[StreamFvmPartition] Writing extent 0... [02062.570] 05377.05489> netsvc: paver write progress 0.1% [02062.570] 05377.05483> install-disk-image:[StreamFvmPartition] 8192 bytes written, 8380416 zeroes left [02062.622] 05377.05483> install-disk-image:[StreamFvmPartition] Writing extent 1... [02062.623] 05377.05483> install-disk-image:[StreamFvmPartition] 8192 bytes written, 8380416 zeroes left [02062.677] 05377.05483> install-disk-image:[StreamFvmPartition] Writing extent 2... [02062.691] 05377.05483> install-disk-image:[StreamFvmPartition] 2097152 bytes written, 6291456 zeroes left [02062.731] 05377.05483> install-disk-image:[StreamFvmPartition] Writing extent 3... [02062.745] 05377.05483> install-disk-image:[StreamFvmPartition] 2097152 bytes written, 6291456 zeroes left [02062.786] 05377.05483> install-disk-image:[StreamFvmPartition] Writing extent 4... attempting to send <<image>>efi.img=fuchsia.esp.blk...target is busy, retrying in one second [02063.575] 05377.05489> netsvc: paver write progress 30.2% attempting to send <<image>>efi.img=fuchsia.esp.blk...target is busy, retrying in one second [02064.581] 05377.05489> netsvc: paver write progress 69.8% attempting to send <<image>>efi.img=fuchsia.esp.blk...target is busy, retrying in one second [02065.338] 05377.05483> install-disk-image:[StreamFvmPartition] 393256960 bytes written, 1007616 zeroes left [02065.343] 05377.05483> install-disk-image:[FvmStreamPartitions] Done streaming partition 0 [02065.343] 05377.05483> install-disk-image:[FvmStreamPartitions] Done flushing partition 0 [02065.343] 05377.05483> install-disk-image:[FvmStreamPartitions] Streaming partition 1 [02065.343] 05377.05483> install-disk-image:[StreamFvmPartition] Writing extent 0... [02065.345] 05377.05483> install-disk-image:[StreamFvmPartition] 8192 bytes written, 8380416 zeroes left [02065.399] 05377.05483> install-disk-image:[StreamFvmPartition] Writing extent 1... [02065.399] 05377.05483> install-disk-image:[StreamFvmPartition] 65536 bytes written, 8323072 zeroes left [02065.453] 05377.05483> install-disk-image:[StreamFvmPartition] Writing extent 2... [02065.454] 05377.05483> install-disk-image:[StreamFvmPartition] 65536 bytes written, 8323072 zeroes left [02065.507] 05377.05483> install-disk-image:[StreamFvmPartition] Writing extent 3... [02065.560] 05377.05483> install-disk-image:[StreamFvmPartition] Writing extent 4... [02065.574] 05377.05483> install-disk-image:[StreamFvmPartition] 2097152 bytes written, 14680064 zeroes left [02065.667] 05377.05483> install-disk-image:[StreamFvmPartition] Writing extent 5... [02065.668] 05377.05483> install-disk-image:[StreamFvmPartition] 57344 bytes written, 8331264 zeroes left [02065.719] 05377.05483> install-disk-image:[FvmStreamPartitions] Done streaming partition 1 [02065.720] 05377.05483> install-disk-image:[FvmStreamPartitions] Done flushing partition 1 [02065.721] 05463.05477> Reading FVM from compressed file: true [02065.721] 05463.05477> Remaining bytes read into compression buffer: 0 [02065.721] 05463.05477> Remaining bytes written to decompression buffer: 0 [02065.721] 05463.05477> Time reading bytes from sparse FVM file: 150720795 (0 s) [02065.721] 05463.05477> Time reading bytes AND decompressing them: 445447772 (0 s) [02065.721] 05377.05483> install-disk-image:[FvmPave] Completed successfully attempting to send <<image>>efi.img=fuchsia.esp.blk...[02066.161] 05377.05391> netsvc: Running EFI Paver [02066.165] 05377.06401> install-disk-image:[Initialize] Successfully intitialized EFI Device Partitioner [02066.165] 05377.06401> install-disk-image:[PartitionPave] Paving partition. [02066.165] 05377.06401> install-disk-image:[FindFirstFit] Looking for space [02066.165] 05377.06401> install-disk-image:[FindFirstFit] Partition seen with start 34, end 16777249 (length 16777216) [02066.165] 05377.06401> install-disk-image:[FindFirstFit] Sorting [02066.165] 05377.06401> install-disk-image:[FindFirstFit] Partition[0] From Block [0, 34) ... (next partition starts at block 34) [02066.165] 05377.06401> install-disk-image:[FindFirstFit] There are 0 free blocks (2097152 requested) [02066.165] 05377.06401> install-disk-image:[FindFirstFit] Partition[1] From Block [34, 16777250) ... (next partition starts at block 250069646) [02066.165] 05377.06401> install-disk-image:[FindFirstFit] There are 233292396 free blocks (2097152 requested) [02066.165] 05377.06401> install-disk-image:[AddPartition] Found space in GPT - OK 233292396 @ 16777250 [02066.165] 05377.06401> install-disk-image:[AddPartition] Final space in GPT - OK 2097152 @ 16777250 [02066.166] 01048.01051> devcoord: dc_bind_device() '' [02066.166] 05377.06401> install-disk-image:[AddPartition] Added partition, waiting for bind [02066.166] 01130.01144> devmgr: /dev/class/block/003: GPT? [02066.166] 01048.01051> devcoord: dc_bind_device() '/boot/driver/gpt.so' [02066.167] 01130.01144> devmgr: /dev/class/block/013: FVM? [02066.167] 01048.01051> devcoord: dc_bind_device() '/boot/driver/fvm.so' [02066.167] 05377.06401> install-disk-image:[AddPartition] Added partition, waiting for bind - OK done attempting to send <<netboot>>kernel.bin=test-infra.zbi...target is busy, retrying in one second [02066.170] 01130.01144> devmgr: /dev/class/block/016: zxcrypt? [02066.170] 01048.01051> devcoord: dc_bind_device() '/boot/driver/zxcrypt.so' [02066.182] 05377.05391> netsvc: tftp write of file <<image>>efi.img completed [02066.185] 05377.06401> install-disk-image:[PartitionPave] Completed successfully attempting to send <<netboot>>kernel.bin=test-infra.zbi...done 2018/12/16 13:06:51 sending cmdline "zircon.autorun.system=/boot/bin/sh+/boot/infra/runcmds " 2018/12/16 13:06:51 sending boot command 2018/12/16 13:06:51 waiting for "summary.json" [02067.268] 05377.05391> netsvc: tftp write of file <<netboot>>kernel.bin completed [00000.000] 00000.00000> zbi: @ 0xffffff8005c8d000 (5584776 bytes) [00000.000] 00000.00000> PMM: boot reserve add [0x100000, 0x2b5fff] [00000.000] 00000.00000> PMM: boot reserve add [0x5c8d000, 0x61e0fff] [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 [0x5c8d000, 0x61e0fff] [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 [0x61e1000, 0x61e1100) [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-117307db2685528b5ec5e5a6cf7f0b99899f7427 [00000.000] 00000.00000> ELF build ID: 5c33b84c49cf28199af9bbc862aac391c1ea4ca7 [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 [02067.536] 00000.00000> timer features: constant_tsc 1 invariant_tsc 1 tsc_deadline 1 [02067.536] 00000.00000> Using TSC as wallclock [02067.536] 00000.00000> initializing kernel [02067.536] 00000.00000> initializing mp [02067.536] 00000.00000> initializing timers [02067.536] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00137774 (debuglog) at level 0x7ffff, flags 0x1 [02067.536] 00000.00000> INIT: cpu 0, calling hook 0xffffffff0018d284 (thread_set_priority_experiment) at level 0x7ffff, flags 0x1 [02067.536] 00000.00000> thread set priority experiment is : ENABLED [02067.536] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001a1090 (global_prng_thread_safe) at level 0x7ffff, flags 0x1 [02067.536] 00000.00000> creating bootstrap completion thread [02067.536] 00000.00000> top of bootstrap2() [02067.536] 00000.00000> INIT: cpu 0, calling hook 0xffffffff0012dc54 (dpc) at level 0x80000, flags 0x1 [02067.536] 00000.00000> INIT: cpu 0, calling hook 0xffffffff0014d980 (libobject) at level 0x80000, flags 0x1 [02067.536] 00000.00000> OOM: started thread [02067.536] 00000.00000> Processor Model Info: type 0 family 0x6 model 0xe stepping 0x9 [02067.536] 00000.00000> display_family 0x6 display_model 0x8e [02067.536] 00000.00000> Vendor: Intel [02067.536] 00000.00000> Microarch: Kaby Lake [02067.536] 00000.00000> F/M/S: 6/8e/9 [02067.536] 00000.00000> Brand: Intel(R) Core(TM) i5-7300U CPU @ 2.60GHz [02067.536] 00000.00000> Features: fpu sse sse2 sse3 ssse3 sse4.1 sse4.2 mmx avx avx2 fxsr pcid xsave mon aesni clflush [02067.536] 00000.00000> clflushopt fsgsbase tsc_adj smep smap erms rdrand rdseed syscall nx huge rdtscp [02067.536] 00000.00000> invar_tsc tsc_deadline x2apic vmx pt hwp [02067.536] 00000.00000> initializing platform [02067.536] 00000.00000> INIT: cpu 0, calling hook 0xffffffff0011084c (x86_perfmon) at level 0x90000, flags 0x1 [02067.536] 00000.00000> PMU: version 4 [02067.536] 00000.00000> cpu topology: [02067.536] 00000.00000> 0: apic id 0x0 package 0 node 0 core 0 smt 0 BSP [02067.536] 00000.00000> 1: apic id 0x2 package 0 node 0 core 1 smt 0 [02067.536] 00000.00000> 2: apic id 0x1 package 0 node 0 core 0 smt 1 [02067.536] 00000.00000> 3: apic id 0x3 package 0 node 0 core 1 smt 1 [02067.536] 00000.00000> Found 4 cpus [02067.537] 00000.00000> booting apic ids: 0x2 0x1 0x3 [02067.551] 00000.00000> entering scheduler on cpu 2 [02067.553] 00000.00000> entering scheduler on cpu 1 [02067.553] 00000.00000> entering scheduler on cpu 3 [02067.555] 00000.00000> smbios: manufacturer="Intel Corporation" product="NUC7i5DNKE" [02067.555] 00000.00000> initializing target [02067.555] 00000.00000> INIT: cpu 0, calling hook 0xffffffff001059b8 (x86_pcie_init) at level 0xa0000, flags 0x1 [02067.555] 00000.00000> moving to last init level [02067.555] 00000.00000> INIT: cpu 0, calling hook 0xffffffff0013f338 (ktrace) at level 0xc0000, flags 0x1 [02067.558] 00000.00000> ktrace: buffer at 0xffffff93da489000 (33554432 bytes) [02067.558] 00000.00000> INIT: cpu 0, calling hook 0xffffffff00142af8 (userboot) at level 0xc0000, flags 0x1 [02067.558] 00000.00000> userboot: ramdisk 0x554000 @ 0xffffff8005c8d000 [02067.558] 00000.00000> userboot: userboot rodata 0 @ [0x3be828ebb000,0x3be828ebe000) [02067.558] 00000.00000> userboot: userboot code 0x3000 @ [0x3be828ebe000,0x3be828ec9000) [02067.558] 00000.00000> userboot: vdso/full rodata 0 @ [0x3be828ec9000,0x3be828ed0000) [02067.559] 00000.00000> userboot: vdso/full code 0x7000 @ [0x3be828ed0000,0x3be828ed1000) [02067.559] 00000.00000> userboot: entry point @ 0x3be828ebec10 [02067.559] 00000.00000> INIT: cpu 0, calling hook 0xffffffff0019fcbc (kernel_shell) at level 0xc0000, flags 0x1 [02067.559] 01034.01041> userboot: option "zircon.autorun.system=/boot/bin/sh+/boot/infra/runcmds" [02067.571] 01034.01041> userboot: searching bootfs for 'bin/bootsvc' [02067.571] 01034.01041> userboot: 'bin/bootsvc' has PT_INTERP "lib/ld.so.1" [02067.571] 01034.01041> userboot: searching bootfs for 'lib/ld.so.1' [02067.571] 01034.01041> userboot: userboot: loaded lib/ld.so.1 at 0x56c196e81000, entry point 0x56c196f06f63 [02067.571] 01034.01041> userboot: userboot: loaded vDSO at 0x6b1f7cdb6000, entry point 0x0 [02067.571] 01034.01041> userboot: process bin/bootsvc started. [02067.571] 01034.01041> userboot: waiting for loader-service requests... [02067.571] 01034.01041> userboot: searching bootfs for 'lib/libasync-default.so' [02067.571] 01034.01041> userboot: searching bootfs for 'lib/libfdio.so' [02067.571] 01034.01041> userboot: searching bootfs for 'lib/liblaunchpad.so' [02067.571] 01034.01041> userboot: searching bootfs for 'lib/libtrace-engine.so' [02067.572] 01048.01051> {{{reset}}} [02067.572] 01048.01051> {{{module:0:<application>:elf:dc50eddeff59d57bc869c83cbdc79b4529103a19}}} [02067.572] 01048.01051> {{{mmap:0xac1cdd44000:0x2d000:load:0:rx:0}}} [02067.572] 01048.01051> {{{mmap:0xac1cdd71000:0x4000:load:0:rw:0x2d000}}} [02067.572] 01048.01051> dso: id=dc50eddeff59d57bc869c83cbdc79b4529103a19 base=0x00000ac1cdd44000 name=<application> [02067.572] 01048.01051> {{{module:0x3:libasync-default.so:elf:5e3c55aea09e8943ae76d3603cc8c0b1ba27bfb7}}} [02067.572] 01048.01051> {{{mmap:0x4de1a699000:0x1000:load:0x3:rx:0}}} [02067.572] 01048.01051> {{{mmap:0x4de1a69a000:0x1000:load:0x3:rw:0x1000}}} [02067.572] 01048.01051> dso: id=5e3c55aea09e8943ae76d3603cc8c0b1ba27bfb7 base=0x000004de1a699000 name=libasync-default.so [02067.572] 01048.01051> {{{module:0x2:<vDSO>:elf:15398eb3d5622ee39ebf0738728ef1da4cdb710c}}} [02067.572] 01048.01051> {{{mmap:0x6b1f7cdb6000:0x7000:load:0x2:r:0}}} [02067.572] 01048.01051> {{{mmap:0x6b1f7cdbd000:0x1000:load:0x2:rx:0x7000}}} [02067.572] 01048.01051> dso: id=15398eb3d5622ee39ebf0738728ef1da4cdb710c base=0x00006b1f7cdb6000 name=<vDSO> [02067.572] 01048.01051> {{{module:0x1:libc.so:elf:9de96c717b326091f3478b4c96c1a1d8ab3c1fbb}}} [02067.572] 01048.01051> {{{mmap:0x56c196e81000:0xcb000:load:0x1:rx:0}}} [02067.572] 01048.01051> {{{mmap:0x56c196f4d000:0x6000:load:0x1:rw:0xcc000}}} [02067.572] 01048.01051> dso: id=9de96c717b326091f3478b4c96c1a1d8ab3c1fbb base=0x000056c196e81000 name=libc.so [02067.572] 01048.01051> {{{module:0x4:libfdio.so:elf:f654d3de6e389c2e34f38ebcf1d0d1501bad929f}}} [02067.572] 01048.01051> {{{mmap:0x5e2bc797d000:0x22000:load:0x4:rx:0}}} [02067.572] 01048.01051> {{{mmap:0x5e2bc799f000:0x5000:load:0x4:rw:0x22000}}} [02067.572] 01048.01051> dso: id=f654d3de6e389c2e34f38ebcf1d0d1501bad929f base=0x00005e2bc797d000 name=libfdio.so [02067.572] 01048.01051> {{{module:0x5:liblaunchpad.so:elf:3275d148fdc55d5dfbd06f5a7edb9dc4c294763f}}} [02067.572] 01048.01051> {{{mmap:0x658fe4f64000:0x7000:load:0x5:rx:0}}} [02067.572] 01048.01051> {{{mmap:0x658fe4f6b000:0x2000:load:0x5:rw:0x7000}}} [02067.572] 01048.01051> dso: id=3275d148fdc55d5dfbd06f5a7edb9dc4c294763f base=0x0000658fe4f64000 name=liblaunchpad.so [02067.572] 01048.01051> {{{module:0x6:libtrace-engine.so:elf:b522ed24160d7c2992490d76fde35676452b2308}}} [02067.572] 01048.01051> {{{mmap:0x3935a868a000:0x9000:load:0x6:rx:0}}} [02067.572] 01048.01051> {{{mmap:0x3935a8693000:0x2000:load:0x6:rw:0x9000}}} [02067.572] 01048.01051> dso: id=b522ed24160d7c2992490d76fde35676452b2308 base=0x00003935a868a000 name=libtrace-engine.so [02067.572] 01048.01051> bootsvc: Starting... [02067.572] 01034.01041> userboot: loader-service channel peer closed [02067.572] 01034.01041> userboot: finished! [02067.572] 01048.01051> bootsvc: Creating bootfs service... [02067.572] 01048.01051> bootsvc: Processing bootdata... [02067.572] 01048.01051> bootsvc: Loading boot cmdline overrides... [02067.572] 01048.01051> bootsvc: Loading kernel VMOs... [02067.572] 01048.01051> bootsvc: Creating loader service... [02067.572] 01048.01051> bootsvc: Launching next process... [02067.572] 01048.01095> bootsvc: launched bin/devmgr [02067.573] 01103.01116> devmgr: main() [02067.573] 01103.01116> devmgr: init [02067.573] 01103.01116> coordinator_init() [02067.573] 01103.01116> cmdline: zircon.autorun.system=/boot/bin/sh+/boot/infra/runcmds [02067.573] 01103.01116> cmdline: devhost.asan.strict=false [02067.573] 01103.01116> cmdline: devmgr.require-system=true [02067.573] 01103.01116> cmdline: zircon.system.pkgfs.cmd=bin/pkgsvr+46d0a17c3c8bf0ecb6c146ef2eac9b6738af741aaccbbdc85bf131bcbe52d4ed [02067.573] 01103.01116> cmdline: zircon.system.pkgfs.file.bin/pkgsvr=306a47a4d4b8692dcbb57c041325abd33656147b462f7bcab7409fd765e0d36f [02067.573] 01103.01116> cmdline: zircon.system.pkgfs.file.lib/ld.so.1=d78c3b4afb565122e9ac50b0e37a7eb730e539af7416057f5fd7a1fd45b8257b [02067.573] 01103.01116> cmdline: zircon.system.pkgfs.file.lib/libfdio.so=8b0288f6e5573403d8d11c0f9f84f8562f1060960dc0095f99212973ae628b54 [02067.573] 01103.01116> devmgr: svc init [02067.573] 01103.01116> devmgr: launch /boot/bin/svchost (svchost) OK [02067.573] 01103.01116> devmgr: vfs init [02067.573] 01103.01116> devmgr: launch /boot/bin/fshost (fshost) OK [02067.574] 01103.01222> devmgr: shell startup [02067.574] 01103.01116> devmgr: coordinator() [02067.575] 01179.01199> fshost: started. [02067.576] 01103.01210> devmgr: launch /boot/bin/pwrbtn-monitor (pwrbtn-monitor) OK [02067.576] 01103.01232> devmgr: launch /boot/bin/crashsvc (crashsvc) OK [02067.577] 01103.01232> devmgr: launch /boot/bin/netsvc (netsvc) OK [02067.577] 01257.01521> crashsvc: starting [02067.577] 01103.01232> devmgr: launch /boot/bin/virtual-console (virtual-console) OK [02067.580] 01103.01116> devcoord: launch devhost 'devhost:sys': pid=2017 [02067.580] 01103.01116> devcoord: launch devhost 'devhost:test': pid=2050 [02067.580] 01103.01116> devcoord: full system required, ignoring fallback drivers until /system is loaded [02067.580] 01103.01116> devcoord: launch devhost 'devhost:root': pid=2085 [02067.581] 01103.01116> devcoord: launch devhost 'devhost:misc': pid=2133 [02067.612] 01103.01222> devmgr: launch /boot/bin/sh (sh:console) OK [02067.638] 02017.02041> acpi-bus: not using IOMMU [02067.642] 02017.02041> acpi-pwrbtn: initialized [02067.664] 02017.02041> acpi: published device pci(0x7d6a503ae0c0), parent=proxy(0x7d6a503b9540), handle=0x7d6a503f7750 [02067.666] 02017.02041> acpi: published device rtc(0x7d6a503ae100), parent=acpi(0x7d6a503b96c0), handle=0x7d6a50410190 [02067.666] 02017.02041> acpi-ec: initialized [02067.668] 02017.02041> acpi: failed to create NHLT VMO (res -10) [02067.668] 02017.02041> acpi: failed to publish NHLT metadata [02067.670] 02017.02041> Intel Processor Trace configuration for this chipset: [02067.670] 02017.02041> mtc_freq_mask: 0x249 [02067.670] 02017.02041> cyc_thresh_mask: 0x3fff [02067.670] 02017.02041> psb_freq_mask: 0x3f [02067.670] 02017.02041> num addr ranges: 2 [02067.670] 01636.01713> vc: new input device /dev/class/input/000 [02067.671] 01103.01116> devcoord: launch devhost 'devhost:pci#1:8086:5916': pid=2684 [02067.671] 01103.01116> devcoord: launch devhost 'devhost:pci#3:8086:9d2f': pid=2731 [02067.671] 01103.01116> devcoord: launch devhost 'devhost:pci#5:8086:9d60': pid=2794 [02067.672] 01103.01116> devcoord: launch devhost 'devhost:pci#6:8086:9d61': pid=2860 [02067.672] 01103.01116> devcoord: launch devhost 'devhost:pci#9:8086:9d03': pid=2948 [02067.673] 01103.01116> devcoord: launch devhost 'devhost:pci#14:8086:9d71': pid=3045 [02067.674] 01103.01116> devcoord: launch devhost 'devhost:pci#16:8086:156f': pid=3120 [02067.675] 02948.02983> ahci: using MSI interrupt [02067.675] 02794.02843> initialized intel serialio i2c driver, reg=0x7806d926c000 regsize=4096 [02067.675] 02860.02903> initialized intel serialio i2c driver, reg=0x25dd9049f000 regsize=4096 [02067.680] 02731.03396> * found USB device (0x18d1:0xa002, USB 2.0) config 1 [02067.680] 02731.03396> * found USB device (0x18d1:0xa003, USB 3.0) config 1 [02067.681] 03045.03093> [IHDA DSP 00:1f.3] Failed to fetch NHLT (res -25) [02067.681] 03045.03093> devhost[00:1f.3/intel-hda-000/intel-sst-dsp-000] bind driver '/boot/driver/dsp.so' failed: -25 [02067.681] 01103.01116> devcoord: rpc: bind-driver 'intel-sst-dsp-000' status -25 [02067.688] 02731.02762> bus_set_hub_interface: no device for usb_device_id 65 [02067.688] 02731.02762> bus_set_hub_interface: no device for usb_device_id 66 [02067.752] 01532.01617> netifc: ? /dev/class/ethernet/000 [02067.752] 01532.01617> netifc: create 512 eth buffers [02067.752] 01532.01617> macaddr: d4:5d:df:00:d7:72 [02067.752] 01532.01617> ip6addr: fe80::d65d:df4d:fe00:d772 [02067.752] 01532.01617> snmaddr: ff02::1:ff00:d772 [02067.753] 01532.01617> netsvc: using /dev/class/ethernet/000 [02067.753] 01532.01617> netsvc: nodename='nanny-kick-shiny-gooey' [02067.753] 01532.01617> netsvc: start [02067.780] 01636.01713> vc: new display device /dev/class/display-controller/000/virtcon [02067.820] 02684.03704> i915: MST not supported [02068.312] 02684.03704> i915: Found DP monitor [02068.312] 02684.03704> i915: Display 1 connected [02068.400] 02731.03396> * found USB device (0x0781:0x5583, USB 3.0) config 1 [02068.874] 01636.01713> vc: Successfully attached to display 1 [02069.150] 02731.03396> * found USB device (0x8087:0x0a2b, USB 2.0) config 1 [02069.678] 02860.02903> intel-i2c-controller: intel_serialio_i2c_slave_transfer: -21 [02069.678] 02860.02903> i2c-hid: could not read HID descriptor: 0 [02069.678] 02860.02903> devhost[00:15.1/i2c-bus-9d61/004c] bind driver '/boot/driver/i2c-hid.so' failed: -2 [02069.678] 01103.01116> devcoord: rpc: bind-driver '004c' status -2 [02069.679] 02794.02843> intel-i2c-controller: intel_serialio_i2c_slave_transfer: -21 [02069.679] 02794.02843> i2c-hid: could not read HID descriptor: 0 [02069.679] 02794.02843> devhost[00:15.0/i2c-bus-9d60/0020] bind driver '/boot/driver/i2c-hid.so' failed: -2 [02069.679] 01103.01116> devcoord: rpc: bind-driver '0020' status -2 [02069.691] 02948.03319> sata2: dev info [02069.691] 02948.03319> serial=715400411000 1 [02069.691] 02948.03319> firmware rev=1P11A1E_ [02069.691] 02948.03319> model id=IBIW NSS D [02069.691] 02948.03319> major=0x3f0 ACS2 DMA 32 commands [02069.691] 02948.03319> LBA48 250069680 sectors, sector size=512 [02069.692] 01179.01199> devmgr: /dev/class/block/000: GPT? [02069.692] 01103.01116> devcoord: dc_bind_device() '/boot/driver/gpt.so' [02069.692] 02948.02983> gpt: device_get_metadata failed (-25) [02069.693] 01179.01199> devmgr: /dev/class/block/001: FVM? [02069.693] 01103.01116> devcoord: dc_bind_device() '/boot/driver/fvm.so' [02069.693] 01179.01199> devmgr: not automounting efi [02069.695] 01179.01199> devmgr: launch /boot/bin/blobfs (blobfs:/blob) OK [02069.749] 01179.01199> fshost: starting 'bin/pkgsvr' '46d0a17c3c8bf0ecb6c146ef2eac9b6738af741aaccbbdc85bf131bcbe52d4ed'... [02069.790] 01179.01199> devmgr: launch bin/pkgsvr (pkgfs) OK [02069.798] 04017.04233> pkgsvr: system: will be served from 46d0a17c3c8bf0ecb6c146ef2eac9b6738af741aaccbbdc85bf131bcbe52d4ed [02069.798] 04017.04233> pkgsvr: pkgfs serving index /data/pkgfs_index from blobfs /blob [02069.799] 01179.01199> devmgr: /dev/class/block/004: zxcrypt? [02069.799] 01103.01116> devcoord: dc_bind_device() '/boot/driver/zxcrypt.so' [02069.803] 01179.01199> devmgr: mounting minfs [02069.803] 01179.01199> devmgr: launch /boot/bin/minfs (minfs:/data) OK [02069.807] 01103.04292> devmgr: adding system driver 'qmi_usb' '/system/driver/qmi-transport.so' [02069.826] 01103.01728> devmgr: launch /system/bin/appmgr (appmgr) OK [02069.826] 01103.01728> zircon.autorun.system: starting '/boot/bin/sh' '/boot/infra/runcmds'... [02069.826] 01103.01728> devmgr: launch /boot/bin/sh (autorun:system) OK [02069.830] 01103.04292> devmgr: adding system driver 'brcmfmac' '/system/driver/brcmfmac.so' [02069.833] 01103.04292> devmgr: adding system driver 'bt_passthrough_hci' '/system/driver/bthci-passthrough.so' [02069.849] 01103.04292> devmgr: adding system driver 'bthci_fake' '/system/driver/bthci-fake.so' [02069.868] 01103.04292> devmgr: adding system driver 'bthost' '/system/driver/bthost.so' [02069.879] 01103.04292> devmgr: adding system driver 'wlan' '/system/driver/wlan.so' [02069.884] 01103.04292> devmgr: adding system driver 'gpu' '/system/driver/libmsd_intel.so' [02069.888] 01103.04292> devmgr: adding system driver 'rtl88xx' '/system/driver/rtl88xx.so' [02069.892] 01103.04292> devmgr: adding system driver 'ath10k_pci' '/system/driver/ath10k.so' [02069.901] 01103.04292> devmgr: adding system driver 'btintel' '/system/driver/btintel.so' [02069.904] 01103.04292> devmgr: adding system driver 'wlan' '/system/driver/wlanif.so' [02069.911] 01103.04292> devmgr: adding system driver 'wlan' '/system/driver/wlanphy.so' [02069.918] 01103.04292> devmgr: adding system driver 'usb_video' '/system/driver/usb_video.so' [02069.925] 01103.04292> devmgr: adding system driver 'ralink' '/system/driver/ralink.so' [02069.926] 01103.04292> devmgr: adding system driver 'bthog' '/system/driver/bthog.so' [02069.933] 01103.04292> devmgr: adding system driver 'wlantapctl' '/system/driver/wlantap.so' [02069.934] 01103.01116> devcoord: fallback driver 'usb_composite' is available [02069.934] 01103.01116> devcoord: fallback driver 'intel_disp' is available [02069.934] 01103.01116> devcoord: driver 'wlantapctl' added [02069.934] 01103.01116> devcoord: driver 'bthog' added [02069.934] 01103.01116> devcoord: driver 'ralink' added [02069.934] 01103.01116> devcoord: driver 'usb_video' added [02069.934] 01103.01116> devcoord: driver 'wlan' added [02069.934] 01103.01116> devcoord: driver 'wlan' added [02069.934] 01103.01116> devcoord: driver 'btintel' added [02069.934] 01103.01116> devcoord: driver 'ath10k_pci' added [02069.934] 01103.01116> devcoord: driver 'rtl88xx' added [02069.934] 01103.01116> devcoord: driver 'gpu' added [02069.934] 01103.01116> devcoord: drv='gpu' bindable to dev='intel-gpu-core' [02069.934] 01103.01116> devcoord: driver 'wlan' added [02069.934] 01103.01116> devcoord: driver 'bthost' added [02069.934] 01103.01116> devcoord: driver 'bthci_fake' added [02069.934] 01103.01116> devcoord: driver 'brcmfmac' added [02069.934] 01103.01116> devcoord: driver 'qmi_usb' added [02069.934] 01103.01116> devcoord: driver 'bt_passthrough_hci' added [02069.934] 01103.01116> devcoord: driver 'usb_composite' added [02069.934] 01103.01116> devcoord: drv='usb_composite' bindable to dev='001' [02069.934] 01103.01116> devcoord: drv='usb_composite' bindable to dev='002' [02069.934] 01103.01116> devcoord: driver 'intel_disp' added [02069.937] 02731.02762> UMS:Max lun is: 0 [02069.938] 02731.02762> devhost[00:14.0/xhci/usb/002/002/ifc-001] bind driver '/boot/driver/bt-transport-usb.so' failed: -2 [02069.938] 01103.01116> devcoord: rpc: bind-driver 'ifc-001' status -2 [02069.974] 02731.05715> btintel: already loaded [02069.974] 02731.05724> hci_read_thread: failed to read from command channel ZX_ERR_PEER_CLOSED [02069.974] 02731.05724> hci_read_thread: failed to read from ACL channel ZX_ERR_PEER_CLOSED [02069.974] 02731.05724> bt-transport-usb: all channels closed - exiting [02069.975] 02731.06084> [INFO:command_channel.cc(150)] hci: initialized [02069.995] 02731.06084> [INFO:acl_data_channel.cc(91)] hci: initialized [02070.120] 06939.06951> netstack: main.go:40: started [02070.121] 06939.06951> netstack: main.go:61: socket server started [02070.121] 06939.06951> netstack: main.go:117: OnInterfacesChanged failed: ErrPeerClosed: zx.Channel.Write [02070.177] 07679.07691> [INFO:cobalt_main.cc(102)] Cobalt client schedule params: schedule_interval=3600 seconds, min_interval=10 seconds, initial_interval=60 seconds. [02070.252] 08766.08778> netcfg: started [02070.252] 05551.05602> [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 [02070.252] 05551.05602> https://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02070.277] 06939.07178> netstack: netstack.go:553: NIC ethp001f6 added [02070.277] 06939.07178> netstack: netstack.go:568: NIC ethp001f6: link-local IPv6: fe80::d65d:dfff:fe00:d772 [02070.293] 06939.09397> netstack: netstack.go:255: NIC ethp001f6: stopped [02070.323] 09838.09852> [INFO:main.cc(35)] Trace Manager starting with config: /pkg/data/tracing.config [02070.331] 02731.06084> [WARN:bredr_discovery_manager.cc(470)] gap-bredr: write inquiry scan activity failed: [status: invalid HCI command parameters (HCI 0x12)] [02070.345] 10229.10241> wlanstack2 [I]: Starting [02070.407] 04975.04993> 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 [02070.407] 04975.04993> el fuchsia.scenic.image_grid_flutter_noclipping_noshadows --cmd set_root_view image_grid_flutter --unshadowed --clipping_disabled [02070.428] 11339.11356> == fuchsia.scenic.image_grid_flutter_noclipping_noshadows: Killing processes... [02070.429] 11582.11596> no tasks found [02070.430] 11651.11665> no tasks found [02070.431] 11720.11734> no tasks found [02070.433] 11789.11803> no tasks found [02070.434] 11858.11872> no tasks found [02070.435] 11927.11941> no tasks found [02070.435] 11339.11356> == fuchsia.scenic.image_grid_flutter_noclipping_noshadows: Configuring scenic renderer params... [02070.439] 05551.05602> [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 [02070.439] 05551.05602> https://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02070.447] 12173.12185> [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. [02070.448] 11339.11356> == fuchsia.scenic.image_grid_flutter_noclipping_noshadows: Tracing... [02070.448] 11339.11356> /tmp/infra-test-output/trace.2018-12-16T20:46:47.json [02070.463] 09838.09852> [INFO:trace_manager.cc(69)] Starting trace with 12 MB buffers, buffering mode=oneshot [02070.464] 12430.12444> Starting trace; will stop in 10 seconds... [02070.465] 05551.05602> [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 [02070.465] 05551.05602> oglesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02070.470] 12737.12752> [INFO:fdio_hid_decoder.cc(280)] hid-parser succesful for 000 with usage page 1 and usage 128 [02070.470] 12737.12752> [INFO:app.cc(151)] Presenter::HACK_SetRendererParams: Setting clipping enabled to false [02070.470] 12737.12752> [INFO:app.cc(164)] Presenter::HACK_SetRendererParams: Setting render frequency to 1 [02070.470] 12737.12752> [INFO:app.cc(158)] Presenter::HACK_SetRendererParams: Setting shadow technique to 0 [02070.474] 13017.13029> [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. [02070.474] 13017.13029> [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. [02070.474] 13017.13029> [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). [02070.474] 13017.13029> [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. [02070.474] 13017.13029> [WARNING:garnet/bin/ui/set_root_view/main.cc(36)] Use the newer present_view tool for launching apps with Views V2. [02070.474] 13017.13029> [INFO:main.cc(52)] set_root_view requesting input delivery by: ViewManager [02070.474] 05551.05602> [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 [02070.474] 05551.05602> ps://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02070.475] 12737.12752> [INFO:presentation1.cc(184)] Disconnected from a11y toggle broadcaster. [02070.557] 13405.13417> [INFO:display_watcher.cc(46)] Scenic: Acquired display controller /dev/class/display-controller/000.(000) [02070.789] 04473.04528> [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 [02070.801] 13560.14289> [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. [02070.802] 13560.14289> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Clipboard [02070.802] 13560.14289> [INFO:platform_view.cc(126)] Flutter, input comes from: ViewManager [02070.839] 13405.13417> [INFO:input_system.cc(236)] Scenic input system initialized. [02070.839] 12737.12752> [WARNING:garnet/bin/ui/root_presenter/displays/display_configuration.cc(76)] SceneManager: unrecognized display. [02070.839] 13405.13417> [INFO:input_system.cc(576)] Scenic: Parallel dispatch is turned OFF [02070.939] 02731.05399> UMS: block size is: 0x00000200 [02070.939] 02731.05399> UMS: total blocks is: 30031872 [02070.939] 02731.05399> UMS: total size is: 15376318464 [02070.939] 02731.05399> UMS: read-only: 0 removable: 1 [02070.940] 01179.01199> devmgr: /dev/class/block/006: MBR? [02070.940] 01103.01116> devcoord: dc_bind_device() '/boot/driver/mbr.so' [02070.943] 01179.01199> devmgr: /dev/class/block/008: MBR? [02070.943] 01103.01116> devcoord: dc_bind_device() '/boot/driver/mbr.so' [02071.148] 13560.14323> [INFO:paragraph.cc(291)] Could not find font collection for family "". [02071.148] 13560.14323> [INFO:paragraph.cc(291)] Could not find font collection for family "". [02071.497] 06939.09413> netstack: netstack.go:280: NIC ethp001f6: restarting [02073.270] 01532.01617> netsvc: handling tftp request failed (file might not exist) [02073.270] 01532.01617> netsvc: close, but no open file [02075.553] 06939.07183> netstack: netstack.go:209: NIC ethp001f6: DHCP acquired IP 192.168.42.112 for 240h0m0s [02075.553] 06939.07183> netstack: netstack.go:210: NIC ethp001f6: Adding DNS servers: [8.8.8.8] [02080.464] 12430.12444> Stopping trace... [02080.464] 09838.09852> [INFO:trace_manager.cc(92)] Stopping trace [02080.492] 09838.09852> [WARNING:garnet/bin/trace_manager/tracee.cc(411)] #8 {13405:scenic.cmx}: 158458 records were dropped [02080.492] 12430.12444> [WARNING:garnet/lib/trace_converters/chromium_exporter.cc(434)] #8 buffer overflowed, records were likely dropped [02082.436] 09838.09852> [INFO:tracee.cc(477)] #8 {13405:scenic.cmx} trace stats [02082.436] 09838.09852> [INFO:tracee.cc(478)] Wrapped count: 0 [02082.436] 09838.09852> [INFO:tracee.cc(479)] # records dropped: 158458 [02082.436] 09838.09852> [INFO:tracee.cc(480)] Durable buffer: 0x0, size 0x0 [02082.436] 09838.09852> [INFO:tracee.cc(483)] Non-durable buffer: 0xbfff80,0x0, size 0xbfff80 [02082.474] 09838.09852> [INFO:trace_manager.cc(95)] Stopped trace [02082.483] 12430.12444> Trace file written to /tmp/infra-test-output/trace.2018-12-16T20:46:47.json [02082.484] 11339.11356> == fuchsia.scenic.image_grid_flutter_noclipping_noshadows: Processing trace... [02085.222] 08102.08121> Starting mDNS on interface ethp001f6 192.168.42.112 [02085.222] 06939.07173> netstack: socket_conv.go:50: convSockOpt: TODO SOL_SOCKET optname=15 [02085.222] 06939.09413> netstack: socket_conv.go:86: convSockOpt: TODO IPPROTO_IP optname=32 [02085.222] 06939.09413> netstack: socket_conv.go:86: convSockOpt: TODO IPPROTO_IP optname=2 [02085.222] 08102.08121> Starting mDNS on interface ethp001f6 [80fe::5dd6:ffdf:fe:72d7] [02085.222] 06939.09413> netstack: socket_conv.go:50: convSockOpt: TODO SOL_SOCKET optname=15 [02085.222] 08102.08121> [ERROR:garnet/bin/mdns/service/mdns_interface_transceiver_v6.cc(102)] Failed to bind socket to V6 address, errno 98 [02085.222] 08102.08121> [ERROR:garnet/bin/mdns/service/mdns_interface_transceiver_v6.cc(105)] (EADDRINUSE) This is probably due to NET-1809. [02085.222] 08102.08121> mDNS: Verifying uniqueness of host name nanny-kick-shiny-gooey.local. [02086.178] 08102.08121> mDNS: Using unique host name nanny-kick-shiny-gooey.local. [02086.659] 92852.93059> === Scenic FPS === [02086.667] 92852.93059> 59.12fps [02086.667] 92852.93059> fps per one-second window: [60 59 59 59 59 59 59] [02086.674] 92852.93059> RenderFrame 1.333ms [02086.682] 92852.93059> ApplyScheduledSessionUpdates 1.048ms [02086.690] 92852.93059> CommandBuffer::Submit 0.03991ms [02086.698] 92852.93059> UpdateAndDeliverMetrics 0.006598ms [02086.705] 92852.93059> EngineRenderer::RenderLayers 0ms [02086.705] 92852.93059> Warning: no values found for EngineRenderer::RenderLayers. Falling back to a zero value. [02086.713] 92852.93059> Escher GPU time 1.465ms [02086.729] 92852.93059> unaccounted (mostly gfx driver) 0.459ms [02086.729] 92852.93059> Did not find any processes that matched [02086.734] 11339.11356> == fuchsia.scenic.image_grid_flutter_noclipping_noshadows: Finished processing trace. [02086.754] 04975.04993> 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. [02086.754] 04975.04993> scenic.image_grid_flutter_noshadows --cmd set_root_view image_grid_flutter --unshadowed --clipping_enabled [02086.760] 122446.122463> == fuchsia.scenic.image_grid_flutter_noshadows: Killing processes... [02086.763] 122781.122795> Killed 12737 root_presenter.cmx [02086.763] 13560.14289> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Presenter [02086.763] 13560.14289> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: View [02086.763] 13560.14289> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Service Provider [02086.764] 05551.05602> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/root_presenter#meta/root_presenter.cmx died [02086.765] 122852.122866> Killed 13405 scenic.cmx [02086.765] 13560.14289> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(37)] Interface error on: SessionListener [02086.765] 13800.13826> [ERROR:garnet/bin/ui/view_manager/view_registry.cc(144)] Exiting due to session connection error. [02086.766] 13560.14323> fdio_ns_destroy: ZX_ERR_BAD_STATE [02086.769] 05551.05602> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/view_manager#meta/view_manager.cmx died [02086.772] 05551.05602> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/scenic#meta/scenic.cmx died [02086.773] 02684.03722> Failed to send vsync event -24 [02086.777] 122921.122935> no tasks found [02086.778] 13560.14318> [INFO:vulkan_application.cc(105)] Destroying Vulkan instance [02086.779] 13017.13029> [INFO:main.cc(70)] Launched component terminated. [02086.781] 123014.123028> no tasks found [02086.782] 123087.123101> no tasks found [02086.783] 123156.123170> no tasks found [02086.783] 122446.122463> == fuchsia.scenic.image_grid_flutter_noshadows: Configuring scenic renderer params... [02086.787] 05551.05602> [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 [02086.787] 05551.05602> https://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02086.795] 123400.123412> [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. [02086.796] 122446.122463> == fuchsia.scenic.image_grid_flutter_noshadows: Tracing... [02086.796] 122446.122463> /tmp/infra-test-output/trace.2018-12-16T20:47:04.json [02086.810] 09838.09852> [INFO:trace_manager.cc(69)] Starting trace with 12 MB buffers, buffering mode=oneshot [02086.811] 05551.05602> [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 [02086.811] 05551.05602> oglesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02086.811] 123646.123661> Starting trace; will stop in 10 seconds... [02086.817] 124003.124015> [INFO:fdio_hid_decoder.cc(280)] hid-parser succesful for 000 with usage page 1 and usage 128 [02086.817] 124003.124015> [INFO:app.cc(151)] Presenter::HACK_SetRendererParams: Setting clipping enabled to true [02086.817] 124003.124015> [INFO:app.cc(164)] Presenter::HACK_SetRendererParams: Setting render frequency to 1 [02086.817] 124003.124015> [INFO:app.cc(158)] Presenter::HACK_SetRendererParams: Setting shadow technique to 0 [02086.819] 124228.124240> [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. [02086.819] 124228.124240> [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. [02086.819] 124228.124240> [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). [02086.819] 124228.124240> [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. [02086.819] 124228.124240> [WARNING:garnet/bin/ui/set_root_view/main.cc(36)] Use the newer present_view tool for launching apps with Views V2. [02086.819] 124228.124240> [INFO:main.cc(52)] set_root_view requesting input delivery by: ViewManager [02086.820] 05551.05602> [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 [02086.820] 05551.05602> ps://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02086.820] 124003.124015> [INFO:presentation1.cc(184)] Disconnected from a11y toggle broadcaster. [02086.893] 04473.04528> [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 [02086.895] 13560.124505> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Clipboard [02086.895] 13560.124505> [INFO:platform_view.cc(126)] Flutter, input comes from: ViewManager [02086.895] 124856.124875> [INFO:display_watcher.cc(46)] Scenic: Acquired display controller /dev/class/display-controller/000.(000) [02087.097] 124856.124875> [INFO:input_system.cc(236)] Scenic input system initialized. [02087.097] 124856.124875> [INFO:input_system.cc(576)] Scenic: Parallel dispatch is turned OFF [02087.097] 124003.124015> [WARNING:garnet/bin/ui/root_presenter/displays/display_configuration.cc(76)] SceneManager: unrecognized display. [02087.189] 13560.124541> [INFO:paragraph.cc(291)] Could not find font collection for family "". [02087.189] 13560.124541> [INFO:paragraph.cc(291)] Could not find font collection for family "". [02096.811] 123646.123661> Stopping trace... [02096.813] 09838.09852> [INFO:trace_manager.cc(92)] Stopping trace [02096.851] 09838.09852> [WARNING:garnet/bin/trace_manager/tracee.cc(411)] #12 {124856:scenic.cmx}: 189102 records were dropped [02096.851] 123646.123661> [WARNING:garnet/lib/trace_converters/chromium_exporter.cc(434)] #12 buffer overflowed, records were likely dropped [02099.006] 09838.09852> [INFO:tracee.cc(477)] #12 {124856:scenic.cmx} trace stats [02099.006] 09838.09852> [INFO:tracee.cc(478)] Wrapped count: 0 [02099.006] 09838.09852> [INFO:tracee.cc(479)] # records dropped: 189102 [02099.006] 09838.09852> [INFO:tracee.cc(480)] Durable buffer: 0x0, size 0x0 [02099.006] 09838.09852> [INFO:tracee.cc(483)] Non-durable buffer: 0xbfff80,0x0, size 0xbfff80 [02099.038] 09838.09852> [INFO:trace_manager.cc(95)] Stopped trace [02099.064] 123646.123661> Trace file written to /tmp/infra-test-output/trace.2018-12-16T20:47:04.json [02099.064] 122446.122463> == fuchsia.scenic.image_grid_flutter_noshadows: Processing trace... [02103.517] 206057.206265> === Scenic FPS === [02103.524] 206057.206265> 58.97fps [02103.524] 206057.206265> fps per one-second window: [59 59 59 59 59 59 59] [02103.534] 206057.206265> RenderFrame 1.203ms [02103.541] 206057.206265> ApplyScheduledSessionUpdates 0.8602ms [02103.551] 206057.206265> CommandBuffer::Submit 0.04097ms [02103.558] 206057.206265> UpdateAndDeliverMetrics 0.00669ms [02103.567] 206057.206265> EngineRenderer::RenderLayers 0ms [02103.567] 206057.206265> Warning: no values found for EngineRenderer::RenderLayers. Falling back to a zero value. [02103.574] 206057.206265> Escher GPU time 2.573ms [02103.591] 206057.206265> unaccounted (mostly gfx driver) 0.4752ms [02103.591] 206057.206265> Did not find any processes that matched [02103.602] 122446.122463> == fuchsia.scenic.image_grid_flutter_noshadows: Finished processing trace. [02103.630] 04975.04993> 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 [02103.630] 04975.04993> c.image_grid_flutter_ssdo --cmd set_root_view image_grid_flutter --screen_space_shadows --clipping_enabled [02103.638] 237557.237574> == fuchsia.scenic.image_grid_flutter_ssdo: Killing processes... [02103.639] 237818.237832> Killed 124003 root_presenter.cmx [02103.639] 13560.124505> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Presenter [02103.639] 13560.124505> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: View [02103.639] 13560.124505> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Service Provider [02103.641] 05551.05602> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/root_presenter#meta/root_presenter.cmx died [02103.641] 237891.237905> Killed 124856 scenic.cmx [02103.642] 125061.125081> [ERROR:garnet/bin/ui/view_manager/view_registry.cc(144)] Exiting due to session connection error. [02103.642] 13560.124505> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Input Connection [02103.642] 13560.124505> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: View Manager [02103.644] 02684.03722> Failed to send vsync event -24 [02103.649] 13560.124505> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(37)] Interface error on: SessionListener [02103.649] 05551.05602> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/scenic#meta/scenic.cmx died [02103.650] 13560.124541> fdio_ns_destroy: ZX_ERR_BAD_STATE [02103.650] 05551.05602> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/view_manager#meta/view_manager.cmx died [02103.652] 237960.237974> no tasks found [02103.655] 13560.124534> [INFO:vulkan_application.cc(105)] Destroying Vulkan instance [02103.656] 124228.124240> [INFO:main.cc(70)] Launched component terminated. [02103.656] 238051.238065> no tasks found [02103.658] 238126.238140> no tasks found [02103.659] 238195.238209> no tasks found [02103.659] 237557.237574> == fuchsia.scenic.image_grid_flutter_ssdo: Configuring scenic renderer params... [02103.663] 05551.05602> [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 [02103.663] 05551.05602> https://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02103.681] 238439.238451> [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. [02103.682] 237557.237574> == fuchsia.scenic.image_grid_flutter_ssdo: Tracing... [02103.682] 237557.237574> /tmp/infra-test-output/trace.2018-12-16T20:47:20.json [02103.697] 09838.09852> [INFO:trace_manager.cc(69)] Starting trace with 12 MB buffers, buffering mode=oneshot [02103.698] 05551.05602> [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 [02103.698] 05551.05602> oglesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02103.698] 238692.238706> Starting trace; will stop in 10 seconds... [02103.702] 239042.239054> [INFO:fdio_hid_decoder.cc(280)] hid-parser succesful for 000 with usage page 1 and usage 128 [02103.702] 239042.239054> [INFO:app.cc(151)] Presenter::HACK_SetRendererParams: Setting clipping enabled to true [02103.702] 239042.239054> [INFO:app.cc(164)] Presenter::HACK_SetRendererParams: Setting render frequency to 1 [02103.702] 239042.239054> [INFO:app.cc(158)] Presenter::HACK_SetRendererParams: Setting shadow technique to 1 [02103.712] 239267.239279> [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. [02103.712] 239267.239279> [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. [02103.712] 239267.239279> [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). [02103.712] 239267.239279> [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. [02103.712] 239267.239279> [WARNING:garnet/bin/ui/set_root_view/main.cc(36)] Use the newer present_view tool for launching apps with Views V2. [02103.712] 239267.239279> [INFO:main.cc(52)] set_root_view requesting input delivery by: ViewManager [02103.713] 05551.05602> [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 [02103.713] 05551.05602> ps://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02103.713] 239042.239054> [INFO:presentation1.cc(184)] Disconnected from a11y toggle broadcaster. [02103.786] 04473.04528> [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 [02103.786] 13560.239542> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Clipboard [02103.786] 13560.239542> [INFO:platform_view.cc(126)] Flutter, input comes from: ViewManager [02103.790] 239883.239904> [INFO:display_watcher.cc(46)] Scenic: Acquired display controller /dev/class/display-controller/000.(000) [02103.980] 239883.239904> [INFO:input_system.cc(236)] Scenic input system initialized. [02103.980] 239883.239904> [INFO:input_system.cc(576)] Scenic: Parallel dispatch is turned OFF [02103.980] 239042.239054> [WARNING:garnet/bin/ui/root_presenter/displays/display_configuration.cc(76)] SceneManager: unrecognized display. [02104.074] 13560.239579> [INFO:paragraph.cc(291)] Could not find font collection for family "". [02104.074] 13560.239579> [INFO:paragraph.cc(291)] Could not find font collection for family "". [02113.698] 238692.238706> Stopping trace... [02113.698] 09838.09852> [INFO:trace_manager.cc(92)] Stopping trace [02113.742] 09838.09852> [WARNING:garnet/bin/trace_manager/tracee.cc(411)] #15 {239883:scenic.cmx}: 222818 records were dropped [02113.742] 238692.238706> [WARNING:garnet/lib/trace_converters/chromium_exporter.cc(434)] #15 buffer overflowed, records were likely dropped [02116.024] 09838.09852> [INFO:tracee.cc(477)] #15 {239883:scenic.cmx} trace stats [02116.025] 09838.09852> [INFO:tracee.cc(478)] Wrapped count: 0 [02116.025] 09838.09852> [INFO:tracee.cc(479)] # records dropped: 222818 [02116.025] 09838.09852> [INFO:tracee.cc(480)] Durable buffer: 0x0, size 0x0 [02116.025] 09838.09852> [INFO:tracee.cc(483)] Non-durable buffer: 0xbfff78,0x0, size 0xbfff80 [02116.064] 09838.09852> [INFO:trace_manager.cc(95)] Stopped trace [02116.079] 238692.238706> Trace file written to /tmp/infra-test-output/trace.2018-12-16T20:47:20.json [02116.080] 237557.237574> == fuchsia.scenic.image_grid_flutter_ssdo: Processing trace... [02120.926] 341724.341932> === Scenic FPS === [02120.935] 341724.341932> 58.61fps [02120.935] 341724.341932> fps per one-second window: [57 58 60 59 58 59 60] [02120.943] 341724.341932> RenderFrame 2.298ms [02120.953] 341724.341932> ApplyScheduledSessionUpdates 0.8762ms [02120.963] 341724.341932> CommandBuffer::Submit 0.03501ms [02120.972] 341724.341932> UpdateAndDeliverMetrics 0.007352ms [02120.981] 341724.341932> EngineRenderer::RenderLayers 0ms [02120.981] 341724.341932> Warning: no values found for EngineRenderer::RenderLayers. Falling back to a zero value. [02120.990] 341724.341932> Escher GPU time 8.762ms [02121.008] 341724.341932> unaccounted (mostly gfx driver) 0.5313ms [02121.008] 341724.341932> Did not find any processes that matched [02121.021] 237557.237574> == fuchsia.scenic.image_grid_flutter_ssdo: Finished processing trace. [02121.045] 04975.04993> 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 [02121.045] 04975.04993> .scenic.image_grid_flutter_shadow_map --cmd set_root_view image_grid_flutter --shadow_map --clipping_enabled [02121.055] 384431.384448> == fuchsia.scenic.image_grid_flutter_shadow_map: Killing processes... [02121.056] 384672.384686> Killed 239042 root_presenter.cmx [02121.056] 13560.239542> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Presenter [02121.057] 13560.239542> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: View [02121.057] 13560.239542> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Service Provider [02121.058] 05551.05602> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/root_presenter#meta/root_presenter.cmx died [02121.059] 384745.384759> Killed 239883 scenic.cmx [02121.061] 13560.239572> fidl channel writing error at ../../garnet/public/lib/fidl/cpp/internal/proxy_controller.cc:59: zx_status_t -24, type fuchsia.ui.scenic/SessionEnqueueRequest, 65152 bytes, 0 handles [02121.061] 13560.239572> fidl channel writing error at ../../garnet/public/lib/fidl/cpp/internal/proxy_controller.cc:59: zx_status_t -24, type fuchsia.ui.scenic/SessionEnqueueRequest, 38752 bytes, 0 handles [02121.061] 13560.239572> fidl channel writing error at ../../garnet/public/lib/fidl/cpp/internal/proxy_controller.cc:59: zx_status_t -24, type fuchsia.ui.scenic/SessionPresentRequest, 72 bytes, 0 handles [02121.061] 13560.239542> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(37)] Interface error on: SessionListener [02121.061] 240079.240099> [ERROR:garnet/bin/ui/view_manager/view_registry.cc(144)] Exiting due to session connection error. [02121.061] 13560.239579> fdio_ns_destroy: ZX_ERR_BAD_STATE [02121.065] 05551.05602> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/view_manager#meta/view_manager.cmx died [02121.068] 02684.03722> Failed to send vsync event -24 [02121.071] 13560.239572> [INFO:vulkan_application.cc(105)] Destroying Vulkan instance [02121.075] 05551.05602> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/scenic#meta/scenic.cmx died [02121.075] 239267.239279> [INFO:main.cc(70)] Launched component terminated. [02121.076] 384908.384922> no tasks found [02121.078] 385006.385020> no tasks found [02121.079] 385075.385089> no tasks found [02121.080] 385144.385158> no tasks found [02121.080] 384431.384448> == fuchsia.scenic.image_grid_flutter_shadow_map: Configuring scenic renderer params... [02121.085] 05551.05602> [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 [02121.085] 05551.05602> https://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02121.093] 385388.385400> [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. [02121.093] 384431.384448> == fuchsia.scenic.image_grid_flutter_shadow_map: Tracing... [02121.093] 384431.384448> /tmp/infra-test-output/trace.2018-12-16T20:47:38.json [02121.109] 09838.09852> [INFO:trace_manager.cc(69)] Starting trace with 12 MB buffers, buffering mode=oneshot [02121.110] 385646.385661> Starting trace; will stop in 10 seconds... [02121.111] 05551.05602> [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 [02121.111] 05551.05602> oglesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02121.115] 385952.385964> [INFO:fdio_hid_decoder.cc(280)] hid-parser succesful for 000 with usage page 1 and usage 128 [02121.115] 385952.385964> [INFO:app.cc(151)] Presenter::HACK_SetRendererParams: Setting clipping enabled to true [02121.115] 385952.385964> [INFO:app.cc(164)] Presenter::HACK_SetRendererParams: Setting render frequency to 1 [02121.115] 385952.385964> [INFO:app.cc(158)] Presenter::HACK_SetRendererParams: Setting shadow technique to 2 [02121.119] 386216.386228> [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. [02121.119] 386216.386228> [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. [02121.119] 386216.386228> [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). [02121.119] 386216.386228> [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. [02121.119] 386216.386228> [WARNING:garnet/bin/ui/set_root_view/main.cc(36)] Use the newer present_view tool for launching apps with Views V2. [02121.119] 386216.386228> [INFO:main.cc(52)] set_root_view requesting input delivery by: ViewManager [02121.119] 05551.05602> [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 [02121.119] 05551.05602> ps://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02121.120] 385952.385964> [INFO:presentation1.cc(184)] Disconnected from a11y toggle broadcaster. [02121.160] 386676.386692> [INFO:display_watcher.cc(46)] Scenic: Acquired display controller /dev/class/display-controller/000.(000) [02121.164] 04473.04528> [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 [02121.172] 13560.386495> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Clipboard [02121.172] 13560.386495> [INFO:platform_view.cc(126)] Flutter, input comes from: ViewManager [02121.351] 386676.386692> [INFO:input_system.cc(236)] Scenic input system initialized. [02121.351] 385952.385964> [WARNING:garnet/bin/ui/root_presenter/displays/display_configuration.cc(76)] SceneManager: unrecognized display. [02121.351] 386676.386692> [INFO:input_system.cc(576)] Scenic: Parallel dispatch is turned OFF [02121.484] 13560.386528> [INFO:paragraph.cc(291)] Could not find font collection for family "". [02121.485] 13560.386528> [INFO:paragraph.cc(291)] Could not find font collection for family "". [02131.110] 385646.385661> Stopping trace... [02131.110] 09838.09852> [INFO:trace_manager.cc(92)] Stopping trace [02131.188] 09838.09852> [WARNING:garnet/bin/trace_manager/tracee.cc(411)] #18 {386676:scenic.cmx}: 204852 records were dropped [02131.188] 385646.385661> [WARNING:garnet/lib/trace_converters/chromium_exporter.cc(434)] #18 buffer overflowed, records were likely dropped [02133.272] 01532.01617> netsvc: handling tftp request failed (file might not exist) [02133.272] 01532.01617> netsvc: close, but no open file [02133.437] 09838.09852> [INFO:tracee.cc(477)] #18 {386676:scenic.cmx} trace stats [02133.437] 09838.09852> [INFO:tracee.cc(478)] Wrapped count: 0 [02133.437] 09838.09852> [INFO:tracee.cc(479)] # records dropped: 204852 [02133.437] 09838.09852> [INFO:tracee.cc(480)] Durable buffer: 0x0, size 0x0 [02133.437] 09838.09852> [INFO:tracee.cc(483)] Non-durable buffer: 0xbfff78,0x0, size 0xbfff80 [02133.437] 09838.09852> [INFO:trace_manager.cc(95)] Stopped trace [02133.485] 385646.385661> Trace file written to /tmp/infra-test-output/trace.2018-12-16T20:47:38.json [02133.486] 384431.384448> == fuchsia.scenic.image_grid_flutter_shadow_map: Processing trace... [02137.944] 474790.475103> === Scenic FPS === [02137.953] 474790.475103> 58.57fps [02137.953] 474790.475103> fps per one-second window: [55 59 59 59 59 59 59] [02137.960] 474790.475103> RenderFrame 1.415ms [02137.969] 474790.475103> ApplyScheduledSessionUpdates 0.8484ms [02137.977] 474790.475103> CommandBuffer::Submit 0.04016ms [02137.986] 474790.475103> UpdateAndDeliverMetrics 0.007039ms [02137.994] 474790.475103> EngineRenderer::RenderLayers 0ms [02137.994] 474790.475103> Warning: no values found for EngineRenderer::RenderLayers. Falling back to a zero value. [02138.003] 474790.475103> Escher GPU time 8.564ms [02138.019] 474790.475103> unaccounted (mostly gfx driver) 0.48ms [02138.019] 474790.475103> Did not find any processes that matched [02138.028] 384431.384448> == fuchsia.scenic.image_grid_flutter_shadow_map: Finished processing trace. [02138.052] 04975.04993> 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 [02138.052] 04975.04993> fuchsia.scenic.image_grid_flutter_moment_shadow_map --cmd set_root_view image_grid_flutter --moment_shadow_map --clipping_enabled [02138.058] 508711.508728> == fuchsia.scenic.image_grid_flutter_moment_shadow_map: Killing processes... [02138.062] 508952.508966> Killed 385952 root_presenter.cmx [02138.062] 13560.386495> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Presenter [02138.062] 13560.386495> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: View [02138.062] 13560.386495> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Service Provider [02138.065] 05551.05602> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/root_presenter#meta/root_presenter.cmx died [02138.065] 509147.509161> Killed 386676 scenic.cmx [02138.066] 13560.386495> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(37)] Interface error on: SessionListener [02138.066] 387028.387045> [ERROR:garnet/bin/ui/view_manager/view_registry.cc(144)] Exiting due to session connection error. [02138.068] 13560.386528> fdio_ns_destroy: ZX_ERR_BAD_STATE [02138.068] 05551.05602> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/scenic#meta/scenic.cmx died [02138.069] 02684.03722> Failed to send vsync event -24 [02138.077] 05551.05602> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/view_manager#meta/view_manager.cmx died [02138.079] 509216.509230> no tasks found [02138.081] 13560.386521> [INFO:vulkan_application.cc(105)] Destroying Vulkan instance [02138.082] 509292.509307> no tasks found [02138.082] 386216.386228> [INFO:main.cc(70)] Launched component terminated. [02138.084] 509382.509396> no tasks found [02138.085] 509451.509465> no tasks found [02138.085] 508711.508728> == fuchsia.scenic.image_grid_flutter_moment_shadow_map: Configuring scenic renderer params... [02138.090] 05551.05602> [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 [02138.090] 05551.05602> https://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02138.097] 509695.509707> [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. [02138.098] 508711.508728> == fuchsia.scenic.image_grid_flutter_moment_shadow_map: Tracing... [02138.098] 508711.508728> /tmp/infra-test-output/trace.2018-12-16T20:47:55.json [02138.113] 09838.09852> [INFO:trace_manager.cc(69)] Starting trace with 12 MB buffers, buffering mode=oneshot [02138.113] 509950.509964> Starting trace; will stop in 10 seconds... [02138.114] 05551.05602> [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 [02138.114] 05551.05602> oglesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02138.118] 510259.510271> [INFO:fdio_hid_decoder.cc(280)] hid-parser succesful for 000 with usage page 1 and usage 128 [02138.118] 510259.510271> [INFO:app.cc(151)] Presenter::HACK_SetRendererParams: Setting clipping enabled to true [02138.118] 510259.510271> [INFO:app.cc(164)] Presenter::HACK_SetRendererParams: Setting render frequency to 1 [02138.118] 510259.510271> [INFO:app.cc(158)] Presenter::HACK_SetRendererParams: Setting shadow technique to 3 [02138.122] 510523.510535> [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. [02138.122] 510523.510535> [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. [02138.122] 510523.510535> [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). [02138.122] 510523.510535> [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. [02138.122] 510523.510535> [WARNING:garnet/bin/ui/set_root_view/main.cc(36)] Use the newer present_view tool for launching apps with Views V2. [02138.122] 510523.510535> [INFO:main.cc(52)] set_root_view requesting input delivery by: ViewManager [02138.123] 510259.510271> [INFO:presentation1.cc(184)] Disconnected from a11y toggle broadcaster. [02138.123] 05551.05602> [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 [02138.123] 05551.05602> ps://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02138.165] 04473.04528> [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 [02138.172] 510989.511003> [INFO:display_watcher.cc(46)] Scenic: Acquired display controller /dev/class/display-controller/000.(000) [02138.172] 13560.510799> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Clipboard [02138.172] 13560.510799> [INFO:platform_view.cc(126)] Flutter, input comes from: ViewManager [02138.396] 510989.511003> [INFO:input_system.cc(236)] Scenic input system initialized. [02138.396] 510989.511003> [INFO:input_system.cc(576)] Scenic: Parallel dispatch is turned OFF [02138.396] 510259.510271> [WARNING:garnet/bin/ui/root_presenter/displays/display_configuration.cc(76)] SceneManager: unrecognized display. [02138.485] 13560.510835> [INFO:paragraph.cc(291)] Could not find font collection for family "". [02138.486] 13560.510835> [INFO:paragraph.cc(291)] Could not find font collection for family "". [02148.113] 509950.509964> Stopping trace... [02148.113] 09838.09852> [INFO:trace_manager.cc(92)] Stopping trace [02148.144] 09838.09852> [WARNING:garnet/bin/trace_manager/tracee.cc(411)] #22 {510989:scenic.cmx}: 204373 records were dropped [02148.145] 509950.509964> [WARNING:garnet/lib/trace_converters/chromium_exporter.cc(434)] #22 buffer overflowed, records were likely dropped [02150.252] 09838.09852> [INFO:tracee.cc(477)] #22 {510989:scenic.cmx} trace stats [02150.253] 09838.09852> [INFO:tracee.cc(478)] Wrapped count: 0 [02150.253] 09838.09852> [INFO:tracee.cc(479)] # records dropped: 204373 [02150.253] 09838.09852> [INFO:tracee.cc(480)] Durable buffer: 0x0, size 0x0 [02150.253] 09838.09852> [INFO:tracee.cc(483)] Non-durable buffer: 0xbfff80,0x0, size 0xbfff80 [02150.298] 09838.09852> [INFO:trace_manager.cc(95)] Stopped trace [02150.310] 509950.509964> Trace file written to /tmp/infra-test-output/trace.2018-12-16T20:47:55.json [02150.310] 508711.508728> == fuchsia.scenic.image_grid_flutter_moment_shadow_map: Processing trace... [02154.782] 597825.598027> === Scenic FPS === [02154.790] 597825.598027> 58.57fps [02154.790] 597825.598027> fps per one-second window: [56 59 59 59 59 59 59] [02154.799] 597825.598027> RenderFrame 1.438ms [02154.806] 597825.598027> ApplyScheduledSessionUpdates 0.8552ms [02154.816] 597825.598027> CommandBuffer::Submit 0.04156ms [02154.823] 597825.598027> UpdateAndDeliverMetrics 0.006949ms [02154.832] 597825.598027> EngineRenderer::RenderLayers 0ms [02154.832] 597825.598027> Warning: no values found for EngineRenderer::RenderLayers. Falling back to a zero value. [02154.839] 597825.598027> Escher GPU time 8.563ms [02154.856] 597825.598027> unaccounted (mostly gfx driver) 0.5144ms [02154.856] 597825.598027> Did not find any processes that matched [02154.867] 508711.508728> == fuchsia.scenic.image_grid_flutter_moment_shadow_map: Finished processing trace. [02154.888] 04975.04993> 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_ [02154.888] 04975.04993> 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 [02154.888] 04975.04993> bled [02154.897] 631671.631688> == fuchsia.scenic.image_grid_flutter_x3_noclipping_noshadows: Killing processes... [02154.899] 632035.632049> Killed 510259 root_presenter.cmx [02154.899] 13560.510799> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Presenter [02154.899] 13560.510799> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: View [02154.899] 13560.510799> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Service Provider [02154.900] 05551.05602> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/root_presenter#meta/root_presenter.cmx died [02154.902] 632108.632122> Killed 510989 scenic.cmx [02154.902] 13560.510799> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(37)] Interface error on: SessionListener [02154.902] 511214.511234> [ERROR:garnet/bin/ui/view_manager/view_registry.cc(144)] Exiting due to session connection error. [02154.903] 13560.510799> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Input Connection [02154.903] 13560.510799> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: View Manager [02154.903] 13560.510835> fdio_ns_destroy: ZX_ERR_BAD_STATE [02154.906] 05551.05602> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/view_manager#meta/view_manager.cmx died [02154.907] 02684.03722> Failed to send vsync event -24 [02154.908] 05551.05602> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/scenic#meta/scenic.cmx died [02154.911] 13560.510828> [INFO:vulkan_application.cc(105)] Destroying Vulkan instance [02154.912] 510523.510535> [INFO:main.cc(70)] Launched component terminated. [02154.917] 632177.632219> no tasks found [02154.918] 632274.632288> no tasks found [02154.920] 632343.632357> no tasks found [02154.921] 632412.632426> no tasks found [02154.921] 631671.631688> == fuchsia.scenic.image_grid_flutter_x3_noclipping_noshadows: Configuring scenic renderer params... [02154.925] 05551.05602> [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 [02154.925] 05551.05602> https://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02154.933] 632656.632668> [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. [02154.933] 631671.631688> == fuchsia.scenic.image_grid_flutter_x3_noclipping_noshadows: Tracing... [02154.933] 631671.631688> /tmp/infra-test-output/trace.2018-12-16T20:48:12.json [02154.950] 09838.09852> [INFO:trace_manager.cc(69)] Starting trace with 12 MB buffers, buffering mode=oneshot [02154.950] 05551.05602> [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 [02154.950] 05551.05602> oglesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02154.951] 632908.632923> Starting trace; will stop in 10 seconds... [02154.957] 633263.633275> [INFO:fdio_hid_decoder.cc(280)] hid-parser succesful for 000 with usage page 1 and usage 128 [02154.957] 633263.633275> [INFO:app.cc(151)] Presenter::HACK_SetRendererParams: Setting clipping enabled to false [02154.957] 633263.633275> [INFO:app.cc(164)] Presenter::HACK_SetRendererParams: Setting render frequency to 1 [02154.957] 633263.633275> [INFO:app.cc(158)] Presenter::HACK_SetRendererParams: Setting shadow technique to 0 [02154.959] 633488.633500> [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. [02154.959] 633488.633500> [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. [02154.959] 633488.633500> [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). [02154.959] 633488.633500> [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. [02154.959] 633488.633500> [WARNING:garnet/bin/ui/set_root_view/main.cc(36)] Use the newer present_view tool for launching apps with Views V2. [02154.959] 633488.633500> [INFO:main.cc(52)] set_root_view requesting input delivery by: ViewManager [02154.960] 633263.633275> [INFO:presentation1.cc(184)] Disconnected from a11y toggle broadcaster. [02155.006] 05551.05602> [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 [02155.006] 05551.05602> ps://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02155.007] 05551.05602> [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 [02155.007] 05551.05602> ps://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02155.007] 634070.634082> [INFO:display_watcher.cc(46)] Scenic: Acquired display controller /dev/class/display-controller/000.(000) [02155.008] 05551.05602> [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 [02155.008] 05551.05602> ps://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02155.081] 04473.04528> [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 [02155.085] 04473.04528> [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 [02155.093] 635072.635475> [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. [02155.094] 635072.635475> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Clipboard [02155.097] 635072.635400> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Clipboard [02155.106] 04473.04528> [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 [02155.117] 635072.635419> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Clipboard [02155.142] 634070.634082> [INFO:input_system.cc(236)] Scenic input system initialized. [02155.142] 633263.633275> [WARNING:garnet/bin/ui/root_presenter/displays/display_configuration.cc(76)] SceneManager: unrecognized display. [02155.142] 634070.634082> [INFO:input_system.cc(576)] Scenic: Parallel dispatch is turned OFF [02155.546] 635072.635440> [INFO:paragraph.cc(291)] Could not find font collection for family "". [02155.547] 635072.635440> [INFO:paragraph.cc(291)] Could not find font collection for family "". [02155.574] 635072.635566> [INFO:paragraph.cc(291)] Could not find font collection for family "". [02155.574] 635072.635566> [INFO:paragraph.cc(291)] Could not find font collection for family "". [02155.579] 635072.635500> [INFO:paragraph.cc(291)] Could not find font collection for family "". [02155.579] 635072.635500> [INFO:paragraph.cc(291)] Could not find font collection for family "". [02164.950] 632908.632923> Stopping trace... [02164.951] 09838.09852> [INFO:trace_manager.cc(92)] Stopping trace [02165.015] 09838.09852> [WARNING:garnet/bin/trace_manager/tracee.cc(411)] #25 {634070:scenic.cmx}: 615920 records were dropped [02165.015] 632908.632923> [WARNING:garnet/lib/trace_converters/chromium_exporter.cc(434)] #25 buffer overflowed, records were likely dropped [02167.229] 09838.09852> [INFO:tracee.cc(477)] #25 {634070:scenic.cmx} trace stats [02167.229] 09838.09852> [INFO:tracee.cc(478)] Wrapped count: 0 [02167.229] 09838.09852> [INFO:tracee.cc(479)] # records dropped: 615920 [02167.229] 09838.09852> [INFO:tracee.cc(480)] Durable buffer: 0x0, size 0x0 [02167.229] 09838.09852> [INFO:tracee.cc(483)] Non-durable buffer: 0xbfff78,0x0, size 0xbfff80 [02167.253] 09838.09852> [INFO:trace_manager.cc(95)] Stopped trace [02167.284] 632908.632923> Trace file written to /tmp/infra-test-output/trace.2018-12-16T20:48:12.json [02167.285] 631671.631688> == fuchsia.scenic.image_grid_flutter_x3_noclipping_noshadows: Processing trace... [02171.906] 762063.762431> === Scenic FPS === [02171.915] 762063.762431> 57.83fps [02171.915] 762063.762431> fps per one-second window: [58 58 59 57 58] [02171.923] 762063.762431> RenderFrame 2.108ms [02171.933] 762063.762431> ApplyScheduledSessionUpdates 1.617ms [02171.940] 762063.762431> CommandBuffer::Submit 0.07864ms [02171.950] 762063.762431> UpdateAndDeliverMetrics 0.01624ms [02171.957] 762063.762431> EngineRenderer::RenderLayers 0ms [02171.957] 762063.762431> Warning: no values found for EngineRenderer::RenderLayers. Falling back to a zero value. [02171.968] 762063.762431> Escher GPU time 1.455ms [02171.987] 762063.762431> unaccounted (mostly gfx driver) 1.789ms [02171.987] 762063.762431> Did not find any processes that matched [02171.996] 631671.631688> == fuchsia.scenic.image_grid_flutter_x3_noclipping_noshadows: Finished processing trace. [02172.021] 04975.04993> 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 [02172.021] 04975.04993> 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 [02172.031] 813430.813447> == fuchsia.scenic.image_grid_flutter_x3_noshadows: Killing processes... [02172.032] 813832.813846> Killed 633263 root_presenter.cmx [02172.033] 635072.635475> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: View [02172.033] 635072.635475> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Service Provider [02172.033] 635072.635419> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: View [02172.033] 635072.635419> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Service Provider [02172.033] 635072.635400> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: View [02172.033] 635072.635400> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Service Provider [02172.034] 635072.635419> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Presenter [02172.035] 635072.635400> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Presenter [02172.035] 635072.635475> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Presenter [02172.035] 635072.635440> fdio_ns_destroy: ZX_ERR_BAD_STATE [02172.038] 05551.05602> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/root_presenter#meta/root_presenter.cmx died [02172.042] 813923.813937> Killed 634070 scenic.cmx [02172.043] 634202.634215> [ERROR:garnet/bin/ui/view_manager/view_registry.cc(144)] Exiting due to session connection error. [02172.043] 633784.633796> [INFO:view_provider_component.cc(51)] Lost connection to Scenic. [02172.048] 05551.05602> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/view_manager#meta/view_manager.cmx died [02172.049] 633488.633500> [INFO:main.cc(70)] Launched component terminated. [02172.051] 05551.05602> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/scenic#meta/scenic.cmx died [02172.052] 02684.03722> Failed to send vsync event -24 [02172.056] 813992.814006> no tasks found [02172.057] 814061.814075> no tasks found [02172.058] 814130.814144> no tasks found [02172.060] 814199.814213> no tasks found [02172.060] 813430.813447> == fuchsia.scenic.image_grid_flutter_x3_noshadows: Configuring scenic renderer params... [02172.065] 05551.05602> [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 [02172.065] 05551.05602> https://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02172.072] 814443.814455> [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. [02172.073] 813430.813447> == fuchsia.scenic.image_grid_flutter_x3_noshadows: Tracing... [02172.073] 813430.813447> /tmp/infra-test-output/trace.2018-12-16T20:48:29.json [02172.088] 09838.09852> [INFO:trace_manager.cc(69)] Starting trace with 12 MB buffers, buffering mode=oneshot [02172.089] 05551.05602> [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 [02172.089] 05551.05602> oglesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02172.089] 814696.814710> Starting trace; will stop in 10 seconds... [02172.095] 815050.815062> [INFO:fdio_hid_decoder.cc(280)] hid-parser succesful for 000 with usage page 1 and usage 128 [02172.095] 815050.815062> [INFO:app.cc(151)] Presenter::HACK_SetRendererParams: Setting clipping enabled to true [02172.095] 815050.815062> [INFO:app.cc(164)] Presenter::HACK_SetRendererParams: Setting render frequency to 1 [02172.095] 815050.815062> [INFO:app.cc(158)] Presenter::HACK_SetRendererParams: Setting shadow technique to 0 [02172.097] 815275.815287> [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. [02172.097] 815275.815287> [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. [02172.097] 815275.815287> [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). [02172.097] 815275.815287> [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. [02172.097] 815275.815287> [WARNING:garnet/bin/ui/set_root_view/main.cc(36)] Use the newer present_view tool for launching apps with Views V2. [02172.097] 815275.815287> [INFO:main.cc(52)] set_root_view requesting input delivery by: ViewManager [02172.098] 815050.815062> [INFO:presentation1.cc(184)] Disconnected from a11y toggle broadcaster. [02172.144] 05551.05602> [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 [02172.144] 05551.05602> ps://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02172.146] 815726.815738> [INFO:display_watcher.cc(46)] Scenic: Acquired display controller /dev/class/display-controller/000.(000) [02172.147] 05551.05602> [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 [02172.147] 05551.05602> ps://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02172.148] 05551.05602> [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 [02172.148] 05551.05602> ps://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02172.227] 04473.04528> [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 [02172.227] 04473.04528> [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 [02172.230] 04473.04528> [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 [02172.243] 816729.817107> [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. [02172.244] 816729.817285> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Clipboard [02172.244] 816729.817087> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Clipboard [02172.245] 816729.817107> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Clipboard [02172.286] 815726.815738> [INFO:input_system.cc(236)] Scenic input system initialized. [02172.286] 815050.815062> [WARNING:garnet/bin/ui/root_presenter/displays/display_configuration.cc(76)] SceneManager: unrecognized display. [02172.286] 815726.815738> [INFO:input_system.cc(576)] Scenic: Parallel dispatch is turned OFF [02172.683] 816729.817352> [INFO:paragraph.cc(291)] Could not find font collection for family "". [02172.683] 816729.817352> [INFO:paragraph.cc(291)] Could not find font collection for family "". [02172.686] 816729.817121> [INFO:paragraph.cc(291)] Could not find font collection for family "". [02172.686] 816729.817121> [INFO:paragraph.cc(291)] Could not find font collection for family "". [02172.712] 816729.817307> [INFO:paragraph.cc(291)] Could not find font collection for family "". [02172.712] 816729.817307> [INFO:paragraph.cc(291)] Could not find font collection for family "". [02182.089] 814696.814710> Stopping trace... [02182.089] 09838.09852> [INFO:trace_manager.cc(92)] Stopping trace [02182.145] 09838.09852> [WARNING:garnet/bin/trace_manager/tracee.cc(411)] #30 {815726:scenic.cmx}: 612663 records were dropped [02182.145] 814696.814710> [WARNING:garnet/lib/trace_converters/chromium_exporter.cc(434)] #30 buffer overflowed, records were likely dropped [02184.234] 09838.09852> [INFO:tracee.cc(477)] #30 {815726:scenic.cmx} trace stats [02184.234] 09838.09852> [INFO:tracee.cc(478)] Wrapped count: 0 [02184.234] 09838.09852> [INFO:tracee.cc(479)] # records dropped: 612663 [02184.234] 09838.09852> [INFO:tracee.cc(480)] Durable buffer: 0x0, size 0x0 [02184.234] 09838.09852> [INFO:tracee.cc(483)] Non-durable buffer: 0xbfff78,0x0, size 0xbfff80 [02184.269] 09838.09852> [INFO:trace_manager.cc(95)] Stopped trace [02184.287] 814696.814710> Trace file written to /tmp/infra-test-output/trace.2018-12-16T20:48:29.json [02184.287] 813430.813447> == fuchsia.scenic.image_grid_flutter_x3_noshadows: Processing trace... [02188.859] 942156.942365> === Scenic FPS === [02188.870] 942156.942365> 58.74fps [02188.870] 942156.942365> fps per one-second window: [59 58 59 59 59] [02188.878] 942156.942365> RenderFrame 2.119ms [02188.887] 942156.942365> ApplyScheduledSessionUpdates 1.585ms [02188.896] 942156.942365> CommandBuffer::Submit 0.06131ms [02188.905] 942156.942365> UpdateAndDeliverMetrics 0.01634ms [02188.915] 942156.942365> EngineRenderer::RenderLayers 0ms [02188.915] 942156.942365> Warning: no values found for EngineRenderer::RenderLayers. Falling back to a zero value. [02188.923] 942156.942365> Escher GPU time 2.096ms [02188.940] 942156.942365> unaccounted (mostly gfx driver) 1.096ms [02188.940] 942156.942365> Did not find any processes that matched [02188.950] 813430.813447> == fuchsia.scenic.image_grid_flutter_x3_noshadows: Finished processing trace. [02188.975] 04975.04993> 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 [02188.975] 04975.04993> 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 [02188.986] 992895.992919> == fuchsia.scenic.image_grid_flutter_x3_ssdo: Killing processes... [02188.987] 993165.993179> Killed 815050 root_presenter.cmx [02188.987] 816729.817285> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: View [02188.987] 816729.817285> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Service Provider [02188.988] 816729.817107> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: View [02188.988] 816729.817107> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Service Provider [02188.988] 816729.817087> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: View [02188.988] 05551.05602> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/root_presenter#meta/root_presenter.cmx died [02188.989] 816729.817087> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Service Provider [02188.989] 816729.817087> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Presenter [02188.989] 816729.817285> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Presenter [02188.989] 816729.817107> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Presenter [02188.990] 816729.817121> fdio_ns_destroy: ZX_ERR_BAD_STATE [02189.000] 993238.993252> Killed 815726 scenic.cmx [02189.000] 815978.815990> [ERROR:garnet/bin/ui/view_manager/view_registry.cc(144)] Exiting due to session connection error. [02189.000] 815569.815581> [INFO:view_provider_component.cc(51)] Lost connection to Scenic. [02189.004] 05551.05602> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/view_manager#meta/view_manager.cmx died [02189.004] 815275.815287> [INFO:main.cc(70)] Launched component terminated. [02189.007] 05551.05602> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/scenic#meta/scenic.cmx died [02189.008] 02684.03722> Failed to send vsync event -24 [02189.013] 993377.993391> no tasks found [02189.016] 993446.993460> no tasks found [02189.017] 993515.993529> no tasks found [02189.018] 993584.993598> no tasks found [02189.018] 992895.992919> == fuchsia.scenic.image_grid_flutter_x3_ssdo: Configuring scenic renderer params... [02189.022] 05551.05602> [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 [02189.022] 05551.05602> https://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02189.030] 993828.993840> [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. [02189.031] 992895.992919> == fuchsia.scenic.image_grid_flutter_x3_ssdo: Tracing... [02189.031] 992895.992919> /tmp/infra-test-output/trace.2018-12-16T20:48:46.json [02189.047] 09838.09852> [INFO:trace_manager.cc(69)] Starting trace with 12 MB buffers, buffering mode=oneshot [02189.048] 05551.05602> [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 [02189.048] 05551.05602> oglesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02189.061] 994083.994097> Starting trace; will stop in 10 seconds... [02189.062] 994474.994486> [INFO:fdio_hid_decoder.cc(280)] hid-parser succesful for 000 with usage page 1 and usage 128 [02189.062] 994474.994486> [INFO:app.cc(151)] Presenter::HACK_SetRendererParams: Setting clipping enabled to true [02189.062] 994474.994486> [INFO:app.cc(164)] Presenter::HACK_SetRendererParams: Setting render frequency to 1 [02189.062] 994474.994486> [INFO:app.cc(158)] Presenter::HACK_SetRendererParams: Setting shadow technique to 1 [02189.063] 994593.994607> [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. [02189.063] 994593.994607> [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. [02189.063] 994593.994607> [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). [02189.063] 994593.994607> [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. [02189.063] 994593.994607> [WARNING:garnet/bin/ui/set_root_view/main.cc(36)] Use the newer present_view tool for launching apps with Views V2. [02189.063] 994593.994607> [INFO:main.cc(52)] set_root_view requesting input delivery by: ViewManager [02189.063] 994474.994486> [INFO:presentation1.cc(184)] Disconnected from a11y toggle broadcaster. [02189.120] 05551.05602> [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 [02189.120] 05551.05602> ps://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02189.121] 05551.05602> [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 [02189.121] 05551.05602> ps://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02189.121] 995111.995123> [INFO:display_watcher.cc(46)] Scenic: Acquired display controller /dev/class/display-controller/000.(000) [02189.122] 05551.05602> [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 [02189.122] 05551.05602> ps://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02189.192] 04473.04528> [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 [02189.192] 04473.04528> [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 [02189.194] 04473.04528> [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 [02189.204] 995917.996397> [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. [02189.205] 995917.996321> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Clipboard [02189.205] 995917.996397> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Clipboard [02189.221] 995917.996301> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Clipboard [02189.267] 995111.995123> [INFO:input_system.cc(236)] Scenic input system initialized. [02189.267] 994474.994486> [WARNING:garnet/bin/ui/root_presenter/displays/display_configuration.cc(76)] SceneManager: unrecognized display. [02189.267] 995111.995123> [INFO:input_system.cc(576)] Scenic: Parallel dispatch is turned OFF [02189.704] 995917.996529> [INFO:paragraph.cc(291)] Could not find font collection for family "". [02189.704] 995917.996529> [INFO:paragraph.cc(291)] Could not find font collection for family "". [02189.729] 995917.996424> [INFO:paragraph.cc(291)] Could not find font collection for family "". [02189.729] 995917.996424> [INFO:paragraph.cc(291)] Could not find font collection for family "". [02189.735] 995917.996342> [INFO:paragraph.cc(291)] Could not find font collection for family "". [02189.735] 995917.996342> [INFO:paragraph.cc(291)] Could not find font collection for family "". [02193.274] 01532.01617> netsvc: handling tftp request failed (file might not exist) [02193.274] 01532.01617> netsvc: close, but no open file [02199.061] 994083.994097> Stopping trace... [02199.061] 09838.09852> [INFO:trace_manager.cc(92)] Stopping trace [02199.142] 09838.09852> [WARNING:garnet/bin/trace_manager/tracee.cc(411)] #36 {995111:scenic.cmx}: 645905 records were dropped [02199.142] 994083.994097> [WARNING:garnet/lib/trace_converters/chromium_exporter.cc(434)] #36 buffer overflowed, records were likely dropped [02201.563] 09838.09852> [INFO:tracee.cc(477)] #36 {995111:scenic.cmx} trace stats [02201.563] 09838.09852> [INFO:tracee.cc(478)] Wrapped count: 0 [02201.563] 09838.09852> [INFO:tracee.cc(479)] # records dropped: 645905 [02201.563] 09838.09852> [INFO:tracee.cc(480)] Durable buffer: 0x0, size 0x0 [02201.563] 09838.09852> [INFO:tracee.cc(483)] Non-durable buffer: 0xbfff80,0x0, size 0xbfff80 [02201.564] 09838.09852> [INFO:trace_manager.cc(95)] Stopped trace [02201.616] 994083.994097> Trace file written to /tmp/infra-test-output/trace.2018-12-16T20:48:46.json [02201.617] 992895.992919> == fuchsia.scenic.image_grid_flutter_x3_ssdo: Processing trace... [02206.724] 1144460.1144823> === Scenic FPS === [02206.733] 1144460.1144823> 58.43fps [02206.733] 1144460.1144823> fps per one-second window: [57 59 59 59 59] [02206.742] 1144460.1144823> RenderFrame 4.068ms [02206.752] 1144460.1144823> ApplyScheduledSessionUpdates 1.495ms [02206.762] 1144460.1144823> CommandBuffer::Submit 0.05374ms [02206.773] 1144460.1144823> UpdateAndDeliverMetrics 0.01612ms [02206.782] 1144460.1144823> EngineRenderer::RenderLayers 0ms [02206.782] 1144460.1144823> Warning: no values found for EngineRenderer::RenderLayers. Falling back to a zero value. [02206.791] 1144460.1144823> Escher GPU time 9.405ms [02206.809] 1144460.1144823> unaccounted (mostly gfx driver) 1.177ms [02206.809] 1144460.1144823> Did not find any processes that matched [02206.819] 992895.992919> == fuchsia.scenic.image_grid_flutter_x3_ssdo: Finished processing trace. [02206.850] 04975.04993> 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 [02206.850] 04975.04993> 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 [02206.859] 1209997.1210014> == fuchsia.scenic.image_grid_flutter_x3_shadow_map: Killing processes... [02206.862] 1210247.1210274> Killed 994474 root_presenter.cmx [02206.863] 995917.996397> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: View [02206.863] 995917.996397> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Service Provider [02206.863] 995917.996321> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: View [02206.863] 995917.996321> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Service Provider [02206.863] 995917.996301> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: View [02206.863] 995917.996301> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Service Provider [02206.864] 995917.996301> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Presenter [02206.864] 995917.996321> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Presenter [02206.864] 995917.996397> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Presenter [02206.865] 995917.996342> fdio_ns_destroy: ZX_ERR_BAD_STATE [02206.867] 995917.996529> image_grid_flutter(flutter): Error in proxy with interface name [Launcher] and service name [fuchsia.sys.Launcher]: Peer unexpectedly closed [02206.869] 05551.05602> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/root_presenter#meta/root_presenter.cmx died [02206.878] 1210449.1210466> Killed 995111 scenic.cmx [02206.878] 995352.995367> [ERROR:garnet/bin/ui/view_manager/view_registry.cc(144)] Exiting due to session connection error. [02206.879] 994954.994966> [INFO:view_provider_component.cc(51)] Lost connection to Scenic. [02206.879] 02684.03722> Failed to send vsync event -24 [02206.888] 994593.994607> [INFO:main.cc(70)] Launched component terminated. [02206.890] 05551.05602> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/view_manager#meta/view_manager.cmx died [02206.890] 05551.05602> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/scenic#meta/scenic.cmx died [02206.892] 1210583.1210598> no tasks found [02206.894] 1210654.1210668> no tasks found [02206.895] 1210723.1210737> no tasks found [02206.897] 1210792.1210806> no tasks found [02206.897] 1209997.1210014> == fuchsia.scenic.image_grid_flutter_x3_shadow_map: Configuring scenic renderer params... [02206.906] 05551.05602> [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 [02206.906] 05551.05602> https://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02206.914] 1211036.1211048> [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. [02206.915] 1209997.1210014> == fuchsia.scenic.image_grid_flutter_x3_shadow_map: Tracing... [02206.915] 1209997.1210014> /tmp/infra-test-output/trace.2018-12-16T20:49:04.json [02206.949] 09838.09852> [INFO:trace_manager.cc(69)] Starting trace with 12 MB buffers, buffering mode=oneshot [02206.950] 05551.05602> [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 [02206.950] 05551.05602> oglesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02206.950] 1211293.1211307> Starting trace; will stop in 10 seconds... [02206.956] 1211643.1211655> [INFO:fdio_hid_decoder.cc(280)] hid-parser succesful for 000 with usage page 1 and usage 128 [02206.956] 1211643.1211655> [INFO:app.cc(151)] Presenter::HACK_SetRendererParams: Setting clipping enabled to true [02206.956] 1211643.1211655> [INFO:app.cc(164)] Presenter::HACK_SetRendererParams: Setting render frequency to 1 [02206.956] 1211643.1211655> [INFO:app.cc(158)] Presenter::HACK_SetRendererParams: Setting shadow technique to 2 [02206.959] 1211868.1211880> [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. [02206.959] 1211868.1211880> [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. [02206.959] 1211868.1211880> [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). [02206.959] 1211868.1211880> [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. [02206.959] 1211868.1211880> [WARNING:garnet/bin/ui/set_root_view/main.cc(36)] Use the newer present_view tool for launching apps with Views V2. [02206.959] 1211868.1211880> [INFO:main.cc(52)] set_root_view requesting input delivery by: ViewManager [02206.959] 1211643.1211655> [INFO:presentation1.cc(184)] Disconnected from a11y toggle broadcaster. [02207.029] 05551.05602> [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 [02207.029] 05551.05602> ps://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02207.030] 1212448.1212460> [INFO:display_watcher.cc(46)] Scenic: Acquired display controller /dev/class/display-controller/000.(000) [02207.031] 05551.05602> [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 [02207.031] 05551.05602> ps://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02207.034] 05551.05602> [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 [02207.034] 05551.05602> ps://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02207.095] 04473.04528> [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 [02207.099] 04473.04528> [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 [02207.102] 04473.04528> [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 [02207.112] 1213166.1213521> [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. [02207.114] 1213166.1213521> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Clipboard [02207.119] 1213166.1213632> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Clipboard [02207.120] 1213166.1213541> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Clipboard [02207.163] 1212448.1212460> [INFO:input_system.cc(236)] Scenic input system initialized. [02207.163] 1211643.1211655> [WARNING:garnet/bin/ui/root_presenter/displays/display_configuration.cc(76)] SceneManager: unrecognized display. [02207.163] 1212448.1212460> [INFO:input_system.cc(576)] Scenic: Parallel dispatch is turned OFF [02207.561] 1213166.1213694> [INFO:paragraph.cc(291)] Could not find font collection for family "". [02207.561] 1213166.1213694> [INFO:paragraph.cc(291)] Could not find font collection for family "". [02207.563] 1213166.1213761> [INFO:paragraph.cc(291)] Could not find font collection for family "". [02207.564] 1213166.1213761> [INFO:paragraph.cc(291)] Could not find font collection for family "". [02207.574] 1213166.1213560> [INFO:paragraph.cc(291)] Could not find font collection for family "". [02207.574] 1213166.1213560> [INFO:paragraph.cc(291)] Could not find font collection for family "". [02216.950] 1211293.1211307> Stopping trace... [02216.950] 09838.09852> [INFO:trace_manager.cc(92)] Stopping trace [02217.002] 09838.09852> [WARNING:garnet/bin/trace_manager/tracee.cc(411)] #40 {1212448:scenic.cmx}: 618828 records were dropped [02217.002] 1211293.1211307> [WARNING:garnet/lib/trace_converters/chromium_exporter.cc(434)] #40 buffer overflowed, records were likely dropped [02219.270] 09838.09852> [INFO:tracee.cc(477)] #40 {1212448:scenic.cmx} trace stats [02219.270] 09838.09852> [INFO:tracee.cc(478)] Wrapped count: 0 [02219.270] 09838.09852> [INFO:tracee.cc(479)] # records dropped: 618828 [02219.270] 09838.09852> [INFO:tracee.cc(480)] Durable buffer: 0x0, size 0x0 [02219.270] 09838.09852> [INFO:tracee.cc(483)] Non-durable buffer: 0xbfff78,0x0, size 0xbfff80 [02219.302] 09838.09852> [INFO:trace_manager.cc(95)] Stopped trace [02219.330] 1211293.1211307> Trace file written to /tmp/infra-test-output/trace.2018-12-16T20:49:04.json [02219.331] 1209997.1210014> == fuchsia.scenic.image_grid_flutter_x3_shadow_map: Processing trace... [02224.038] 1345904.1346255> === Scenic FPS === [02224.050] 1345904.1346255> 57.88fps [02224.050] 1345904.1346255> fps per one-second window: [53 59 59 59 59] [02224.059] 1345904.1346255> RenderFrame 2.527ms [02224.071] 1345904.1346255> ApplyScheduledSessionUpdates 1.526ms [02224.081] 1345904.1346255> CommandBuffer::Submit 0.08382ms [02224.090] 1345904.1346255> UpdateAndDeliverMetrics 0.01871ms [02224.101] 1345904.1346255> EngineRenderer::RenderLayers 0ms [02224.101] 1345904.1346255> Warning: no values found for EngineRenderer::RenderLayers. Falling back to a zero value. [02224.113] 1345904.1346255> Escher GPU time 8.447ms [02224.133] 1345904.1346255> unaccounted (mostly gfx driver) 1.879ms [02224.133] 1345904.1346255> Did not find any processes that matched [02224.142] 1209997.1210014> == fuchsia.scenic.image_grid_flutter_x3_shadow_map: Finished processing trace. [02224.169] 04975.04993> 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 [02224.169] 04975.04993> 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 [02224.169] 04975.04993> bled [02224.185] 1400634.1400651> == fuchsia.scenic.image_grid_flutter_x3_moment_shadow_map: Killing processes... [02224.191] 1400955.1400988> Killed 1211643 root_presenter.cmx [02224.191] 1213166.1213632> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: View [02224.191] 1213166.1213632> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Service Provider [02224.192] 1213166.1213541> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: View [02224.192] 1213166.1213541> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Service Provider [02224.192] 1213166.1213521> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: View [02224.192] 1213166.1213521> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Service Provider [02224.192] 1213166.1213541> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Presenter [02224.192] 1213166.1213521> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Presenter [02224.192] 1213166.1213632> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Presenter [02224.193] 1213166.1213560> fdio_ns_destroy: ZX_ERR_BAD_STATE [02224.196] 05551.05602> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/root_presenter#meta/root_presenter.cmx died [02224.199] 1401143.1401179> Killed 1212448 scenic.cmx [02224.200] 1212581.1212593> [ERROR:garnet/bin/ui/view_manager/view_registry.cc(144)] Exiting due to session connection error. [02224.201] 1212162.1212174> [INFO:view_provider_component.cc(51)] Lost connection to Scenic. [02224.201] 02684.03722> Failed to send vsync event -24 [02224.206] 05551.05602> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/view_manager#meta/view_manager.cmx died [02224.206] 1211868.1211880> [INFO:main.cc(70)] Launched component terminated. [02224.213] 05551.05602> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/scenic#meta/scenic.cmx died [02224.215] 1401278.1401292> no tasks found [02224.216] 1401347.1401361> no tasks found [02224.218] 1401428.1401442> no tasks found [02224.219] 1401587.1401601> no tasks found [02224.219] 1400634.1400651> == fuchsia.scenic.image_grid_flutter_x3_moment_shadow_map: Configuring scenic renderer params... [02224.224] 05551.05602> [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 [02224.224] 05551.05602> https://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02224.232] 1401831.1401843> [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. [02224.233] 1400634.1400651> == fuchsia.scenic.image_grid_flutter_x3_moment_shadow_map: Tracing... [02224.233] 1400634.1400651> /tmp/infra-test-output/trace.2018-12-16T20:49:21.json [02224.248] 09838.09852> [INFO:trace_manager.cc(69)] Starting trace with 12 MB buffers, buffering mode=oneshot [02224.248] 05551.05602> [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 [02224.248] 05551.05602> oglesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02224.249] 1402084.1402098> Starting trace; will stop in 10 seconds... [02224.255] 1402438.1402450> [INFO:fdio_hid_decoder.cc(280)] hid-parser succesful for 000 with usage page 1 and usage 128 [02224.255] 1402438.1402450> [INFO:app.cc(151)] Presenter::HACK_SetRendererParams: Setting clipping enabled to true [02224.255] 1402438.1402450> [INFO:app.cc(164)] Presenter::HACK_SetRendererParams: Setting render frequency to 1 [02224.255] 1402438.1402450> [INFO:app.cc(158)] Presenter::HACK_SetRendererParams: Setting shadow technique to 3 [02224.257] 1402663.1402675> [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. [02224.257] 1402663.1402675> [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. [02224.257] 1402663.1402675> [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). [02224.257] 1402663.1402675> [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. [02224.257] 1402663.1402675> [WARNING:garnet/bin/ui/set_root_view/main.cc(36)] Use the newer present_view tool for launching apps with Views V2. [02224.257] 1402663.1402675> [INFO:main.cc(52)] set_root_view requesting input delivery by: ViewManager [02224.258] 1402438.1402450> [INFO:presentation1.cc(184)] Disconnected from a11y toggle broadcaster. [02224.305] 05551.05602> [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 [02224.305] 05551.05602> ps://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02224.306] 1403243.1403255> [INFO:display_watcher.cc(46)] Scenic: Acquired display controller /dev/class/display-controller/000.(000) [02224.306] 05551.05602> [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 [02224.306] 05551.05602> ps://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02224.308] 05551.05602> [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 [02224.308] 05551.05602> ps://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02224.385] 04473.04528> [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 [02224.397] 1404215.1404656> [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. [02224.398] 04473.04528> [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 [02224.398] 1404215.1404656> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Clipboard [02224.400] 04473.04528> [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 [02224.416] 1404215.1404575> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Clipboard [02224.418] 1404215.1404593> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Clipboard [02224.451] 1403243.1403255> [INFO:input_system.cc(236)] Scenic input system initialized. [02224.451] 1402438.1402450> [WARNING:garnet/bin/ui/root_presenter/displays/display_configuration.cc(76)] SceneManager: unrecognized display. [02224.451] 1403243.1403255> [INFO:input_system.cc(576)] Scenic: Parallel dispatch is turned OFF [02224.859] 1404215.1404675> [INFO:paragraph.cc(291)] Could not find font collection for family "". [02224.859] 1404215.1404675> [INFO:paragraph.cc(291)] Could not find font collection for family "". [02224.860] 1404215.1404610> [INFO:paragraph.cc(291)] Could not find font collection for family "". [02224.860] 1404215.1404610> [INFO:paragraph.cc(291)] Could not find font collection for family "". [02224.898] 1404215.1404750> [INFO:paragraph.cc(291)] Could not find font collection for family "". [02224.898] 1404215.1404750> [INFO:paragraph.cc(291)] Could not find font collection for family "". [02234.249] 1402084.1402098> Stopping trace... [02234.249] 09838.09852> [INFO:trace_manager.cc(92)] Stopping trace [02234.299] 09838.09852> [WARNING:garnet/bin/trace_manager/tracee.cc(411)] #45 {1403243:scenic.cmx}: 622385 records were dropped [02234.299] 1402084.1402098> [WARNING:garnet/lib/trace_converters/chromium_exporter.cc(434)] #45 buffer overflowed, records were likely dropped [02236.568] 09838.09852> [INFO:tracee.cc(477)] #45 {1403243:scenic.cmx} trace stats [02236.568] 09838.09852> [INFO:tracee.cc(478)] Wrapped count: 0 [02236.568] 09838.09852> [INFO:tracee.cc(479)] # records dropped: 622385 [02236.568] 09838.09852> [INFO:tracee.cc(480)] Durable buffer: 0x0, size 0x0 [02236.568] 09838.09852> [INFO:tracee.cc(483)] Non-durable buffer: 0xbfff78,0x0, size 0xbfff80 [02236.612] 09838.09852> [INFO:trace_manager.cc(95)] Stopped trace [02236.621] 1402084.1402098> Trace file written to /tmp/infra-test-output/trace.2018-12-16T20:49:21.json [02236.622] 1400634.1400651> == fuchsia.scenic.image_grid_flutter_x3_moment_shadow_map: Processing trace... [02241.464] 1536844.1537056> === Scenic FPS === [02241.473] 1536844.1537056> 58.24fps [02241.473] 1536844.1537056> fps per one-second window: [55 59 59 59 59] [02241.484] 1536844.1537056> RenderFrame 2.343ms [02241.493] 1536844.1537056> ApplyScheduledSessionUpdates 1.47ms [02241.505] 1536844.1537056> CommandBuffer::Submit 0.06435ms [02241.517] 1536844.1537056> UpdateAndDeliverMetrics 0.01715ms [02241.525] 1536844.1537056> EngineRenderer::RenderLayers 0ms [02241.526] 1536844.1537056> Warning: no values found for EngineRenderer::RenderLayers. Falling back to a zero value. [02241.537] 1536844.1537056> Escher GPU time 8.382ms [02241.557] 1536844.1537056> unaccounted (mostly gfx driver) 1.302ms [02241.557] 1536844.1537056> Did not find any processes that matched [02241.569] 1400634.1400651> == fuchsia.scenic.image_grid_flutter_x3_moment_shadow_map: Finished processing trace. [02241.593] 04975.04993> 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 [02241.593] 04975.04993> 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 [02241.593] 04975.04993> ll --session_shell_args=--root_module=choreography --story_shell=mondrian --unshadowed --clipping_disabled [02241.604] 1593093.1593115> == fuchsia.scenic.choreography_noclipping_noshadows: Killing processes... [02241.605] 1593409.1593423> Killed 1402438 root_presenter.cmx [02241.605] 1404215.1404656> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: View [02241.606] 1404215.1404656> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Service Provider [02241.606] 1404215.1404593> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: View [02241.607] 1404215.1404593> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Service Provider [02241.607] 1404215.1404575> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: View [02241.607] 05551.05602> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/root_presenter#meta/root_presenter.cmx died [02241.607] 1404215.1404575> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Service Provider [02241.607] 1404215.1404593> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Presenter [02241.607] 1404215.1404575> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Presenter [02241.608] 1404215.1404656> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Presenter [02241.609] 1404215.1404610> image_grid_flutter(flutter): Error in proxy with interface name [Launcher] and service name [fuchsia.sys.Launcher]: Peer unexpectedly closed [02241.609] 1404215.1404610> fdio_ns_destroy: ZX_ERR_BAD_STATE [02241.611] 1404215.1404750> image_grid_flutter(flutter): Error in proxy with interface name [Launcher] and service name [fuchsia.sys.Launcher]: Peer unexpectedly closed [02241.620] 1593487.1593514> Killed 1403243 scenic.cmx [02241.621] 1403376.1403388> [ERROR:garnet/bin/ui/view_manager/view_registry.cc(144)] Exiting due to session connection error. [02241.621] 1402974.1402987> [INFO:view_provider_component.cc(51)] Lost connection to Scenic. [02241.625] 1402663.1402675> [INFO:main.cc(70)] Launched component terminated. [02241.627] 02684.03722> Failed to send vsync event -24 [02241.628] 05551.05602> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/view_manager#meta/view_manager.cmx died [02241.628] 05551.05602> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/scenic#meta/scenic.cmx died [02241.630] 1593621.1593635> WARNING: zx_object_get_child(4824, (job)1400596, ...) failed: ZX_ERR_NOT_FOUND (-25) [02241.630] 1593621.1593635> no tasks found [02241.633] 1593690.1593704> no tasks found [02241.634] 1593759.1593773> no tasks found [02241.635] 1593828.1593842> no tasks found [02241.636] 1593093.1593115> == fuchsia.scenic.choreography_noclipping_noshadows: Configuring scenic renderer params... [02241.640] 05551.05602> [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 [02241.640] 05551.05602> https://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02241.647] 1594072.1594084> [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. [02241.648] 1593093.1593115> == fuchsia.scenic.choreography_noclipping_noshadows: Tracing... [02241.648] 1593093.1593115> /tmp/infra-test-output/trace.2018-12-16T20:49:38.json [02241.663] 09838.09852> [INFO:trace_manager.cc(69)] Starting trace with 12 MB buffers, buffering mode=oneshot [02241.664] 05551.05602> [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 [02241.664] 05551.05602> s/+/master/glossary.md#fuchsia_pkg-url for more information. [02241.664] 1594329.1594343> Starting trace; will stop in 10 seconds... [02241.670] 1594681.1594693> [INFO:fdio_hid_decoder.cc(280)] hid-parser succesful for 000 with usage page 1 and usage 128 [02241.670] 1594681.1594693> [INFO:app.cc(151)] Presenter::HACK_SetRendererParams: Setting clipping enabled to false [02241.670] 1594681.1594693> [INFO:app.cc(164)] Presenter::HACK_SetRendererParams: Setting render frequency to 1 [02241.670] 1594681.1594693> [INFO:app.cc(158)] Presenter::HACK_SetRendererParams: Setting shadow technique to 0 [02241.675] 1594916.1594928> [ERROR:peridot/lib/session_shell_settings/session_shell_settings.cc(163)] /system/data/sysui/base_shell_config.json: read failed [02241.675] 1594916.1594928> [INFO:basemgr_impl.cc(209)] [02241.675] 1594916.1594928> [02241.675] 1594916.1594928> ======================== Starting Test [=choreography] [02241.675] 1594916.1594928> ============================================================ [02241.675] 1594916.1594928> [02241.675] 05551.05602> [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 [02241.675] 05551.05602> . See https://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02241.676] 1594916.1594928> [INFO:basemgr_impl.cc(465)] Setting shadow technique to 0 [02241.676] 1594916.1594928> [ERROR:peridot/bin/basemgr/basemgr_impl.cc(87)] Active session shell index is 0, but only 0 session shell settings exist. [02241.676] 1594681.1594693> [INFO:presentation1.cc(184)] Disconnected from a11y toggle broadcaster. [02241.677] 05551.05602> [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 [02241.677] 05551.05602> . See https://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02241.677] 05551.05602> [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 [02241.677] 05551.05602> .googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02241.690] 1595285.1595297> No service found for path fuchsia.modular.Lifecycle [02241.694] 1595398.1595410> No service found for path fuchsia.modular.auth.AccountProvider [02241.704] 1594916.1594928> [INFO:user_provider_impl.cc(191)] fuchsia::modular::UserProvider::Login() Incognito mode [02241.704] 1594916.1594928> [INFO:user_controller_impl.cc(54)] SESSIONMGR DATA ORIGIN IS /data/modular/USER_GUEST_1575989715 [02241.705] 1594916.1594928> [INFO:basemgr_impl.cc(465)] Setting shadow technique to 0 [02241.705] 1594916.1594928> [ERROR:peridot/bin/basemgr/basemgr_impl.cc(87)] Active session shell index is 0, but only 0 session shell settings exist. [02241.705] 1594916.1594928> [WARNING:peridot/bin/basemgr/user_provider_impl.cc(137)] AuthenticationContextProvider disconnected. [02241.751] 1595497.1595509> [ERROR:peridot/public/lib/integration_testing/cpp/testing.cc(39)] This application must be run under test_runner. [02241.751] 1594681.1594693> [INFO:presentation1.cc(184)] Disconnected from a11y toggle broadcaster. [02241.753] 1595813.1595825> [INFO:display_watcher.cc(46)] Scenic: Acquired display controller /dev/class/display-controller/000.(000) [02241.769] 1594681.1594693> [ERROR:garnet/bin/ui/root_presenter/presentation1.cc(822)] Root presenter: Content view terminated unexpectedly. [02241.775] 1596162.1596183> [INFO:device_info.cc(61)] device_info: syncing device id for user: GUEST set to: 0bb7cdc3-fb42-4a50-b708-8f809f557f5d [02241.782] 1596162.1596183> [INFO:user_intelligence_provider_impl.cc(113)] Starting session_agents: [02241.782] 1596162.1596183> [INFO:user_intelligence_provider_impl.cc(119)] Starting startup_agents: [02241.838] 1597412.1597427> [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?) [02241.847] 05551.05602> [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: [02241.847] 05551.05602> //fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02241.877] 1596162.1596183> [INFO:device_map_impl.cc(155)] Updated Device: Device/0bb7cdc3-fb42-4a50-b708-8f809f557f5d value={"@version":3,"name":"nanny-kick-shiny-gooey","device_id":"0bb7cdc3-fb42-4a50-b708-8f809f557f5d","profile":"{}","hostname":"nan [02241.877] 1596162.1596183> ny-kick-shiny-gooey","last_change_timestamp":1544993379} [02241.891] 1595813.1595825> [INFO:input_system.cc(236)] Scenic input system initialized. [02241.891] 1594681.1594693> [WARNING:garnet/bin/ui/root_presenter/displays/display_configuration.cc(76)] SceneManager: unrecognized display. [02241.891] 1595813.1595825> [INFO:input_system.cc(576)] Scenic: Parallel dispatch is turned OFF [02241.891] 1594681.1594693> [WARNING:garnet/bin/ui/root_presenter/presentation1.cc(930)] Presentation1::SetRendererParams: Cannot change shadow technique, default was overriden in root_presenter [02241.919] 1599139.1599229> [INFO:dev_session_shell.cc(103)] DevSessionShell START choreography [02241.988] 1598889.1598905> [INFO:local_module_resolver.cc(109)] No manifest found for handler=choreography [02241.988] 1596162.1596183> [INFO:add_mod_call.cc(92)] Module Resolver does not know about module 'choreography' with action = 'action'. Going to try using it anyway.. [02241.989] 05551.05602> [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 [02241.989] 05551.05602> esource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02241.992] 05551.05602> [ERROR:garnet/lib/loader/package_loader.cc(65)] Could not open directory /pkgfs/packages/choreography/0 No such file or directory [02241.992] 1596162.1596183> [ERROR:peridot/lib/module_manifest/module_facet_reader_impl.cc(34)] Could not resolve URL: file://choreography [02242.037] 1599139.1599229> [INFO:dev_session_shell.cc(184)] DevSessionShell Starting story with id: story [02242.037] 1599139.1599229> [INFO:dev_session_shell.cc(210)] DevSessionShell State 3 [02242.037] 05551.05602> [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/ [02242.037] 05551.05602> docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02242.037] 1599139.1599229> [INFO:dev_session_shell.cc(210)] DevSessionShell State 1 [02242.037] 1596162.1596183> [INFO:story_controller_impl.cc(183)] StoryControllerImpl::LaunchModule() choreography root [02242.044] 05551.05602> [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 [02242.044] 05551.05602> esource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02242.049] 05551.05602> [ERROR:garnet/lib/loader/package_loader.cc(65)] Could not open directory /pkgfs/packages/choreography/0 No such file or directory [02242.095] 1601911.1602096> [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. [02242.096] 1601911.1602096> [INFO:platform_view.cc(126)] Flutter, input comes from: Scenic [02251.664] 1594329.1594343> Stopping trace... [02251.664] 09838.09852> [INFO:trace_manager.cc(92)] Stopping trace [02251.846] 09838.09852> [INFO:tracee.cc(477)] #50 {1595813:scenic.cmx} trace stats [02251.846] 09838.09852> [INFO:tracee.cc(478)] Wrapped count: 0 [02251.846] 09838.09852> [INFO:tracee.cc(479)] # records dropped: 0 [02251.846] 09838.09852> [INFO:tracee.cc(480)] Durable buffer: 0x0, size 0x0 [02251.846] 09838.09852> [INFO:tracee.cc(483)] Non-durable buffer: 0x111a68,0x0, size 0xbfff80 [02251.854] 09838.09852> [INFO:trace_manager.cc(95)] Stopped trace [02251.884] 1594329.1594343> Trace file written to /tmp/infra-test-output/trace.2018-12-16T20:49:38.json [02251.884] 1593093.1593115> == fuchsia.scenic.choreography_noclipping_noshadows: Processing trace... [02252.173] 1619348.1619603> === Scenic FPS === [02252.174] 1619348.1619603> 59.07fps [02252.174] 1619348.1619603> fps per one-second window: [60 59 59 59 59 59 59 59 59] [02252.174] 1619348.1619603> RenderFrame 0.2535ms [02252.175] 1619348.1619603> ApplyScheduledSessionUpdates 0.08381ms [02252.176] 1619348.1619603> CommandBuffer::Submit 0.02836ms [02252.177] 1619348.1619603> UpdateAndDeliverMetrics 0.006554ms [02252.177] 1619348.1619603> EngineRenderer::RenderLayers 0ms [02252.177] 1619348.1619603> Warning: no values found for EngineRenderer::RenderLayers. Falling back to a zero value. [02252.179] 1619348.1619603> Escher GPU time 0.5568ms [02252.184] 1619348.1619550> unaccounted (mostly gfx driver) 0.2241ms [02252.184] 1619348.1619550> Did not find any processes that matched [02252.186] 1593093.1593115> == fuchsia.scenic.choreography_noclipping_noshadows: Finished processing trace. [02252.208] 04975.04993> 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 [02252.208] 04975.04993> .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 [02252.208] 04975.04993> s=--root_module=choreography --story_shell=mondrian --unshadowed --clipping_enabled [02252.215] 1620517.1620534> == fuchsia.scenic.choreography_noshadows: Killing processes... [02252.216] 1620758.1620772> Killed 1594681 root_presenter.cmx [02252.216] 1601911.1602096> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Presenter [02252.216] 1601911.1602096> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: View [02252.216] 1601911.1602096> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Service Provider [02252.217] 1601911.1602122> mondrian(flutter): Error in proxy with interface name [ViewContainer] and service name [null]: Peer unexpectedly closed [02252.217] 05551.05602> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/root_presenter#meta/root_presenter.cmx died [02252.219] 1620831.1620845> Killed 1595813 scenic.cmx [02252.219] 1601911.1602096> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(37)] Interface error on: SessionListener [02252.219] 1595955.1595969> [ERROR:garnet/bin/ui/view_manager/view_registry.cc(144)] Exiting due to session connection error. [02252.221] 1601911.1602122> fdio_ns_destroy: ZX_ERR_BAD_STATE [02252.221] 05551.05602> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/scenic#meta/scenic.cmx died [02252.222] 02684.03722> Failed to send vsync event -24 [02252.225] 05551.05602> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/view_manager#meta/view_manager.cmx died [02252.228] 1601911.1602117> [INFO:vulkan_application.cc(105)] Destroying Vulkan instance [02252.231] 1620900.1620914> Killed 1594916 basemgr [02252.232] 1599139.1599229> [ERROR:peridot/bin/sessionmgr/dev_session_shell.cc(178)] Story controller for story story died. Does this story exist? [02252.233] 1620900.1620914> WARNING: zx_object_get_child(1596484, (job)1601523, ...) failed: ZX_ERR_NOT_FOUND (-25) [02252.234] 1597412.1597427> 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 [02252.243] 1620995.1621009> WARNING: zx_object_get_child(5939, (job)1596484, ...) failed: ZX_ERR_NOT_FOUND (-25) [02252.243] 1620995.1621009> no tasks found [02252.244] 1621064.1621078> no tasks found [02252.246] 1621133.1621147> no tasks found [02252.246] 1620517.1620534> == fuchsia.scenic.choreography_noshadows: Configuring scenic renderer params... [02252.250] 05551.05602> [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 [02252.250] 05551.05602> https://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02252.258] 1621377.1621389> [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. [02252.259] 1620517.1620534> == fuchsia.scenic.choreography_noshadows: Tracing... [02252.259] 1620517.1620534> /tmp/infra-test-output/trace.2018-12-16T20:49:49.json [02252.275] 09838.09852> [INFO:trace_manager.cc(69)] Starting trace with 12 MB buffers, buffering mode=oneshot [02252.275] 05551.05602> [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 [02252.275] 05551.05602> s/+/master/glossary.md#fuchsia_pkg-url for more information. [02252.276] 1621631.1621646> Starting trace; will stop in 10 seconds... [02252.281] 1621986.1621998> [INFO:fdio_hid_decoder.cc(280)] hid-parser succesful for 000 with usage page 1 and usage 128 [02252.281] 1621986.1621998> [INFO:app.cc(151)] Presenter::HACK_SetRendererParams: Setting clipping enabled to true [02252.281] 1621986.1621998> [INFO:app.cc(164)] Presenter::HACK_SetRendererParams: Setting render frequency to 1 [02252.281] 1621986.1621998> [INFO:app.cc(158)] Presenter::HACK_SetRendererParams: Setting shadow technique to 0 [02252.286] 1622219.1622231> [ERROR:peridot/lib/session_shell_settings/session_shell_settings.cc(163)] /system/data/sysui/base_shell_config.json: read failed [02252.286] 1622219.1622231> [INFO:basemgr_impl.cc(209)] [02252.286] 1622219.1622231> [02252.286] 1622219.1622231> ======================== Starting Test [=choreography] [02252.286] 1622219.1622231> ============================================================ [02252.286] 1622219.1622231> [02252.286] 05551.05602> [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 [02252.286] 05551.05602> . See https://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02252.287] 05551.05602> [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 [02252.287] 05551.05602> . See https://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02252.288] 1622219.1622231> [INFO:basemgr_impl.cc(465)] Setting shadow technique to 0 [02252.288] 1622219.1622231> [ERROR:peridot/bin/basemgr/basemgr_impl.cc(87)] Active session shell index is 0, but only 0 session shell settings exist. [02252.296] 05551.05602> [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 [02252.296] 05551.05602> .googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02252.298] 1622553.1622565> No service found for path fuchsia.modular.Lifecycle [02252.302] 1622659.1622671> No service found for path fuchsia.modular.auth.AccountProvider [02252.307] 1621986.1621998> [INFO:presentation1.cc(184)] Disconnected from a11y toggle broadcaster. [02252.312] 1622219.1622231> [INFO:user_provider_impl.cc(191)] fuchsia::modular::UserProvider::Login() Incognito mode [02252.313] 1622219.1622231> [INFO:user_controller_impl.cc(54)] SESSIONMGR DATA ORIGIN IS /data/modular/USER_GUEST_1970440602 [02252.314] 1622219.1622231> [INFO:basemgr_impl.cc(465)] Setting shadow technique to 0 [02252.314] 1622219.1622231> [ERROR:peridot/bin/basemgr/basemgr_impl.cc(87)] Active session shell index is 0, but only 0 session shell settings exist. [02252.314] 1622219.1622231> [WARNING:peridot/bin/basemgr/user_provider_impl.cc(137)] AuthenticationContextProvider disconnected. [02252.355] 1621986.1621998> [INFO:presentation1.cc(184)] Disconnected from a11y toggle broadcaster. [02252.355] 1622784.1622796> [ERROR:peridot/public/lib/integration_testing/cpp/testing.cc(39)] This application must be run under test_runner. [02252.357] 1623094.1623106> [INFO:display_watcher.cc(46)] Scenic: Acquired display controller /dev/class/display-controller/000.(000) [02252.375] 1621986.1621998> [ERROR:garnet/bin/ui/root_presenter/presentation1.cc(822)] Root presenter: Content view terminated unexpectedly. [02252.380] 1623455.1623474> [INFO:device_info.cc(61)] device_info: syncing device id for user: GUEST set to: 9d24ccbd-2ca2-4413-9cbc-aa95bbf53afe [02252.388] 1623455.1623474> [INFO:user_intelligence_provider_impl.cc(113)] Starting session_agents: [02252.388] 1623455.1623474> [INFO:user_intelligence_provider_impl.cc(119)] Starting startup_agents: [02252.444] 1624719.1624737> [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?) [02252.444] 05551.05602> [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: [02252.444] 05551.05602> //fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02252.484] 1623455.1623474> [INFO:device_map_impl.cc(155)] Updated Device: Device/9d24ccbd-2ca2-4413-9cbc-aa95bbf53afe value={"@version":3,"name":"nanny-kick-shiny-gooey","device_id":"9d24ccbd-2ca2-4413-9cbc-aa95bbf53afe","profile":"{}","hostname":"nan [02252.484] 1623455.1623474> ny-kick-shiny-gooey","last_change_timestamp":1544993389} [02252.495] 1623094.1623106> [INFO:input_system.cc(236)] Scenic input system initialized. [02252.495] 1621986.1621998> [WARNING:garnet/bin/ui/root_presenter/displays/display_configuration.cc(76)] SceneManager: unrecognized display. [02252.495] 1621986.1621998> [WARNING:garnet/bin/ui/root_presenter/presentation1.cc(930)] Presentation1::SetRendererParams: Cannot change shadow technique, default was overriden in root_presenter [02252.495] 1623094.1623106> [INFO:input_system.cc(576)] Scenic: Parallel dispatch is turned OFF [02252.523] 1626178.1626262> [INFO:dev_session_shell.cc(103)] DevSessionShell START choreography [02252.603] 1625973.1625985> [INFO:local_module_resolver.cc(109)] No manifest found for handler=choreography [02252.603] 1623455.1623474> [INFO:add_mod_call.cc(92)] Module Resolver does not know about module 'choreography' with action = 'action'. Going to try using it anyway.. [02252.604] 05551.05602> [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 [02252.604] 05551.05602> esource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02252.609] 05551.05602> [ERROR:garnet/lib/loader/package_loader.cc(65)] Could not open directory /pkgfs/packages/choreography/0 No such file or directory [02252.609] 1623455.1623474> [ERROR:peridot/lib/module_manifest/module_facet_reader_impl.cc(34)] Could not resolve URL: file://choreography [02252.677] 1626178.1626262> [INFO:dev_session_shell.cc(184)] DevSessionShell Starting story with id: story [02252.677] 1626178.1626262> [INFO:dev_session_shell.cc(210)] DevSessionShell State 3 [02252.678] 05551.05602> [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/ [02252.678] 05551.05602> docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02252.678] 1623455.1623474> [INFO:story_controller_impl.cc(183)] StoryControllerImpl::LaunchModule() choreography root [02252.678] 1626178.1626262> [INFO:dev_session_shell.cc(210)] DevSessionShell State 1 [02252.680] 05551.05602> [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 [02252.680] 05551.05602> esource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02252.689] 05551.05602> [ERROR:garnet/lib/loader/package_loader.cc(65)] Could not open directory /pkgfs/packages/choreography/0 No such file or directory [02252.729] 1629178.1629375> [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. [02252.730] 1629178.1629375> [INFO:platform_view.cc(126)] Flutter, input comes from: Scenic [02253.276] 01532.01617> netsvc: handling tftp request failed (file might not exist) [02253.276] 01532.01617> netsvc: close, but no open file [02262.276] 1621631.1621646> Stopping trace... [02262.276] 09838.09852> [INFO:trace_manager.cc(92)] Stopping trace [02262.411] 09838.09852> [INFO:tracee.cc(477)] #57 {1623094:scenic.cmx} trace stats [02262.411] 09838.09852> [INFO:tracee.cc(478)] Wrapped count: 0 [02262.411] 09838.09852> [INFO:tracee.cc(479)] # records dropped: 0 [02262.411] 09838.09852> [INFO:tracee.cc(480)] Durable buffer: 0x0, size 0x0 [02262.411] 09838.09852> [INFO:tracee.cc(483)] Non-durable buffer: 0x112d58,0x0, size 0xbfff80 [02262.466] 09838.09852> [INFO:trace_manager.cc(95)] Stopped trace [02262.466] 1621631.1621646> Trace file written to /tmp/infra-test-output/trace.2018-12-16T20:49:49.json [02262.466] 1620517.1620534> == fuchsia.scenic.choreography_noshadows: Processing trace... [02262.764] 1646599.1646801> === Scenic FPS === [02262.765] 1646599.1646801> 58.87fps [02262.765] 1646599.1646801> fps per one-second window: [59 57 60 59 59 59 59 59 59] [02262.765] 1646599.1646801> RenderFrame 0.3051ms [02262.766] 1646599.1646801> ApplyScheduledSessionUpdates 0.08491ms [02262.766] 1646599.1646801> CommandBuffer::Submit 0.03037ms [02262.767] 1646599.1646801> UpdateAndDeliverMetrics 0.006779ms [02262.768] 1646599.1646801> EngineRenderer::RenderLayers 0ms [02262.768] 1646599.1646801> Warning: no values found for EngineRenderer::RenderLayers. Falling back to a zero value. [02262.768] 1646599.1646801> Escher GPU time 0.9626ms [02262.769] 1646599.1646801> unaccounted (mostly gfx driver) 0.2452ms [02262.769] 1646599.1646801> Did not find any processes that matched [02262.772] 1620517.1620534> == fuchsia.scenic.choreography_noshadows: Finished processing trace. [02262.789] 04975.04993> 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 [02262.789] 04975.04993> 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 [02262.789] 04975.04993> odule=choreography --story_shell=mondrian --screen_space_shadows --clipping_enabled [02262.796] 1647749.1647766> == fuchsia.scenic.choreography_ssdo: Killing processes... [02262.797] 1648003.1648017> Killed 1621986 root_presenter.cmx [02262.797] 1629178.1629375> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Presenter [02262.797] 1629178.1629375> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: View [02262.797] 1629178.1629375> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Service Provider [02262.798] 1629178.1629401> mondrian(flutter): Error in proxy with interface name [ViewContainer] and service name [null]: Peer unexpectedly closed [02262.800] 05551.05602> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/root_presenter#meta/root_presenter.cmx died [02262.801] 1648076.1648090> Killed 1623094 scenic.cmx [02262.801] 1629178.1629375> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(37)] Interface error on: SessionListener [02262.801] 1623240.1623252> [ERROR:garnet/bin/ui/view_manager/view_registry.cc(144)] Exiting due to session connection error. [02262.801] 1629178.1629401> fdio_ns_destroy: ZX_ERR_BAD_STATE [02262.802] 02684.03722> Failed to send vsync event -24 [02262.804] 05551.05602> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/view_manager#meta/view_manager.cmx died [02262.804] 05551.05602> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/scenic#meta/scenic.cmx died [02262.807] 1648147.1648166> Killed 1622219 basemgr [02262.807] 1626178.1626262> [ERROR:peridot/bin/sessionmgr/dev_session_shell.cc(178)] Story controller for story story died. Does this story exist? [02262.822] 1648223.1648237> no tasks found [02262.824] 1648292.1648307> no tasks found [02262.825] 1648362.1648376> no tasks found [02262.825] 1647749.1647766> == fuchsia.scenic.choreography_ssdo: Configuring scenic renderer params... [02262.830] 05551.05602> [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 [02262.830] 05551.05602> https://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02262.842] 1648606.1648618> [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. [02262.842] 1647749.1647766> == fuchsia.scenic.choreography_ssdo: Tracing... [02262.842] 1647749.1647766> /tmp/infra-test-output/trace.2018-12-16T20:50:00.json [02262.857] 09838.09852> [INFO:trace_manager.cc(69)] Starting trace with 12 MB buffers, buffering mode=oneshot [02262.858] 05551.05602> [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 [02262.858] 05551.05602> s/+/master/glossary.md#fuchsia_pkg-url for more information. [02262.858] 1648860.1648875> Starting trace; will stop in 10 seconds... [02262.863] 1649215.1649227> [INFO:fdio_hid_decoder.cc(280)] hid-parser succesful for 000 with usage page 1 and usage 128 [02262.864] 1649215.1649227> [INFO:app.cc(151)] Presenter::HACK_SetRendererParams: Setting clipping enabled to true [02262.864] 1649215.1649227> [INFO:app.cc(164)] Presenter::HACK_SetRendererParams: Setting render frequency to 1 [02262.864] 1649215.1649227> [INFO:app.cc(158)] Presenter::HACK_SetRendererParams: Setting shadow technique to 1 [02262.868] 1649448.1649460> [ERROR:peridot/lib/session_shell_settings/session_shell_settings.cc(163)] /system/data/sysui/base_shell_config.json: read failed [02262.868] 1649448.1649460> [INFO:basemgr_impl.cc(209)] [02262.868] 1649448.1649460> [02262.868] 1649448.1649460> ======================== Starting Test [=choreography] [02262.868] 1649448.1649460> ============================================================ [02262.868] 1649448.1649460> [02262.869] 05551.05602> [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 [02262.869] 05551.05602> . See https://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02262.870] 05551.05602> [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 [02262.870] 05551.05602> . See https://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02262.870] 1649448.1649460> [INFO:basemgr_impl.cc(465)] Setting shadow technique to 0 [02262.870] 1649448.1649460> [ERROR:peridot/bin/basemgr/basemgr_impl.cc(87)] Active session shell index is 0, but only 0 session shell settings exist. [02262.878] 05551.05602> [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 [02262.878] 05551.05602> .googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02262.880] 1649782.1649794> No service found for path fuchsia.modular.Lifecycle [02262.884] 1649888.1649900> No service found for path fuchsia.modular.auth.AccountProvider [02262.889] 1649215.1649227> [INFO:presentation1.cc(184)] Disconnected from a11y toggle broadcaster. [02262.896] 1649448.1649460> [INFO:user_provider_impl.cc(191)] fuchsia::modular::UserProvider::Login() Incognito mode [02262.896] 1649448.1649460> [INFO:user_controller_impl.cc(54)] SESSIONMGR DATA ORIGIN IS /data/modular/USER_GUEST_1086229237 [02262.900] 1649448.1649460> [INFO:basemgr_impl.cc(465)] Setting shadow technique to 0 [02262.900] 1649448.1649460> [ERROR:peridot/bin/basemgr/basemgr_impl.cc(87)] Active session shell index is 0, but only 0 session shell settings exist. [02262.900] 1649448.1649460> [WARNING:peridot/bin/basemgr/user_provider_impl.cc(137)] AuthenticationContextProvider disconnected. [02262.927] 1649215.1649227> [INFO:presentation1.cc(184)] Disconnected from a11y toggle broadcaster. [02262.927] 1650013.1650025> [ERROR:peridot/public/lib/integration_testing/cpp/testing.cc(39)] This application must be run under test_runner. [02262.929] 1650323.1650335> [INFO:display_watcher.cc(46)] Scenic: Acquired display controller /dev/class/display-controller/000.(000) [02262.933] 1649215.1649227> [ERROR:garnet/bin/ui/root_presenter/presentation1.cc(822)] Root presenter: Content view terminated unexpectedly. [02262.970] 1650808.1650820> [INFO:device_info.cc(61)] device_info: syncing device id for user: GUEST set to: ee66e93f-cddb-4bd3-8daf-51947faaa94c [02262.974] 1650808.1650820> [INFO:user_intelligence_provider_impl.cc(113)] Starting session_agents: [02262.974] 1650808.1650820> [INFO:user_intelligence_provider_impl.cc(119)] Starting startup_agents: [02263.034] 1652008.1652020> [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?) [02263.039] 05551.05602> [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: [02263.039] 05551.05602> //fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02263.074] 1650323.1650335> [INFO:input_system.cc(236)] Scenic input system initialized. [02263.074] 1649215.1649227> [WARNING:garnet/bin/ui/root_presenter/displays/display_configuration.cc(76)] SceneManager: unrecognized display. [02263.074] 1650323.1650335> [INFO:input_system.cc(576)] Scenic: Parallel dispatch is turned OFF [02263.074] 1649215.1649227> [WARNING:garnet/bin/ui/root_presenter/presentation1.cc(930)] Presentation1::SetRendererParams: Cannot change shadow technique, default was overriden in root_presenter [02263.075] 1650808.1650820> [INFO:device_map_impl.cc(155)] Updated Device: Device/ee66e93f-cddb-4bd3-8daf-51947faaa94c value={"@version":3,"name":"nanny-kick-shiny-gooey","device_id":"ee66e93f-cddb-4bd3-8daf-51947faaa94c","profile":"{}","hostname":"nan [02263.075] 1650808.1650820> ny-kick-shiny-gooey","last_change_timestamp":1544993400} [02263.104] 1653534.1653552> [INFO:dev_session_shell.cc(103)] DevSessionShell START choreography [02263.191] 1652982.1652994> [INFO:local_module_resolver.cc(109)] No manifest found for handler=choreography [02263.191] 1650808.1650820> [INFO:add_mod_call.cc(92)] Module Resolver does not know about module 'choreography' with action = 'action'. Going to try using it anyway.. [02263.191] 05551.05602> [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 [02263.191] 05551.05602> esource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02263.194] 05551.05602> [ERROR:garnet/lib/loader/package_loader.cc(65)] Could not open directory /pkgfs/packages/choreography/0 No such file or directory [02263.194] 1650808.1650820> [ERROR:peridot/lib/module_manifest/module_facet_reader_impl.cc(34)] Could not resolve URL: file://choreography [02263.244] 1653534.1653552> [INFO:dev_session_shell.cc(184)] DevSessionShell Starting story with id: story [02263.244] 1653534.1653552> [INFO:dev_session_shell.cc(210)] DevSessionShell State 3 [02263.244] 1653534.1653552> [INFO:dev_session_shell.cc(210)] DevSessionShell State 1 [02263.244] 1650808.1650820> [INFO:story_controller_impl.cc(183)] StoryControllerImpl::LaunchModule() choreography root [02263.244] 05551.05602> [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/ [02263.244] 05551.05602> docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02263.247] 05551.05602> [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 [02263.247] 05551.05602> esource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02263.251] 05551.05602> [ERROR:garnet/lib/loader/package_loader.cc(65)] Could not open directory /pkgfs/packages/choreography/0 No such file or directory [02263.299] 1656329.1656541> [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. [02263.300] 1656329.1656541> [INFO:platform_view.cc(126)] Flutter, input comes from: Scenic [02272.858] 1648860.1648875> Stopping trace... [02272.858] 09838.09852> [INFO:trace_manager.cc(92)] Stopping trace [02273.119] 09838.09852> [INFO:tracee.cc(477)] #65 {1650323:scenic.cmx} trace stats [02273.119] 09838.09852> [INFO:tracee.cc(478)] Wrapped count: 0 [02273.119] 09838.09852> [INFO:tracee.cc(479)] # records dropped: 0 [02273.119] 09838.09852> [INFO:tracee.cc(480)] Durable buffer: 0x0, size 0x0 [02273.119] 09838.09852> [INFO:tracee.cc(483)] Non-durable buffer: 0x1fca28,0x0, size 0xbfff80 [02273.144] 09838.09852> [INFO:trace_manager.cc(95)] Stopped trace [02273.162] 1648860.1648875> Trace file written to /tmp/infra-test-output/trace.2018-12-16T20:50:00.json [02273.163] 1647749.1647766> == fuchsia.scenic.choreography_ssdo: Processing trace... [02273.652] 1692037.1692271> === Scenic FPS === [02273.653] 1692037.1692271> 58.29fps [02273.653] 1692037.1692271> fps per one-second window: [52 60 59 59 59 59 59 59 59] [02273.654] 1692037.1692271> RenderFrame 1.179ms [02273.655] 1692037.1692271> ApplyScheduledSessionUpdates 0.08299ms [02273.656] 1692037.1692271> CommandBuffer::Submit 0.02715ms [02273.657] 1692037.1692271> UpdateAndDeliverMetrics 0.007142ms [02273.658] 1692037.1692271> EngineRenderer::RenderLayers 0ms [02273.658] 1692037.1692271> Warning: no values found for EngineRenderer::RenderLayers. Falling back to a zero value. [02273.658] 1692037.1692271> Escher GPU time 4.598ms [02273.661] 1692037.1692271> unaccounted (mostly gfx driver) 0.2334ms [02273.661] 1692037.1692271> Did not find any processes that matched [02273.666] 1647749.1647766> == fuchsia.scenic.choreography_ssdo: Finished processing trace. [02273.685] 04975.04993> 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 [02273.685] 04975.04993> 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 [02273.685] 04975.04993> rgs=--root_module=choreography --story_shell=mondrian --shadow_map --clipping_enabled [02273.691] 1694264.1694281> == fuchsia.scenic.choreography_shadow_map: Killing processes... [02273.692] 1694505.1694519> Killed 1649215 root_presenter.cmx [02273.692] 1656329.1656541> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Presenter [02273.693] 1656329.1656541> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: View [02273.694] 1656329.1656567> mondrian(flutter): Error in proxy with interface name [ViewContainer] and service name [null]: Peer unexpectedly closed [02273.694] 1656329.1656541> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Service Provider [02273.694] 05551.05602> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/root_presenter#meta/root_presenter.cmx died [02273.697] 1694614.1694636> Killed 1650323 scenic.cmx [02273.698] 1650459.1650473> [ERROR:garnet/bin/ui/view_manager/view_registry.cc(144)] Exiting due to session connection error. [02273.698] 1656329.1656541> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(37)] Interface error on: SessionListener [02273.698] 1656329.1656541> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Input Connection [02273.699] 1656329.1656541> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: View Manager [02273.699] 1656329.1656567> fdio_ns_destroy: ZX_ERR_BAD_STATE [02273.702] 05551.05602> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/view_manager#meta/view_manager.cmx died [02273.702] 02684.03722> Failed to send vsync event -24 [02273.704] 05551.05602> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/scenic#meta/scenic.cmx died [02273.708] 1656329.1656562> [INFO:vulkan_application.cc(105)] Destroying Vulkan instance [02273.709] 1694699.1694714> Killed 1649448 basemgr [02273.709] 1653534.1653552> [ERROR:peridot/bin/sessionmgr/dev_session_shell.cc(178)] Story controller for story story died. Does this story exist? [02273.711] 1694699.1694714> WARNING: zx_object_get_child(1651019, (job)1655931, ...) failed: ZX_ERR_NOT_FOUND (-25) [02273.712] 1656329.1656341> [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 [02273.722] 1694787.1694801> no tasks found [02273.724] 1694856.1694870> no tasks found [02273.725] 1694925.1694939> no tasks found [02273.725] 1694264.1694281> == fuchsia.scenic.choreography_shadow_map: Configuring scenic renderer params... [02273.729] 05551.05602> [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 [02273.729] 05551.05602> https://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02273.737] 1695169.1695181> [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. [02273.738] 1694264.1694281> == fuchsia.scenic.choreography_shadow_map: Tracing... [02273.738] 1694264.1694281> /tmp/infra-test-output/trace.2018-12-16T20:50:11.json [02273.752] 09838.09852> [INFO:trace_manager.cc(69)] Starting trace with 12 MB buffers, buffering mode=oneshot [02273.753] 1695421.1695436> Starting trace; will stop in 10 seconds... [02273.754] 05551.05602> [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 [02273.754] 05551.05602> s/+/master/glossary.md#fuchsia_pkg-url for more information. [02273.757] 1695733.1695745> [INFO:fdio_hid_decoder.cc(280)] hid-parser succesful for 000 with usage page 1 and usage 128 [02273.758] 1695733.1695745> [INFO:app.cc(151)] Presenter::HACK_SetRendererParams: Setting clipping enabled to true [02273.758] 1695733.1695745> [INFO:app.cc(164)] Presenter::HACK_SetRendererParams: Setting render frequency to 1 [02273.758] 1695733.1695745> [INFO:app.cc(158)] Presenter::HACK_SetRendererParams: Setting shadow technique to 2 [02273.764] 1696011.1696023> [ERROR:peridot/lib/session_shell_settings/session_shell_settings.cc(163)] /system/data/sysui/base_shell_config.json: read failed [02273.764] 1696011.1696023> [INFO:basemgr_impl.cc(209)] [02273.764] 1696011.1696023> [02273.764] 1696011.1696023> ======================== Starting Test [=choreography] [02273.764] 1696011.1696023> ============================================================ [02273.764] 1696011.1696023> [02273.764] 05551.05602> [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 [02273.764] 05551.05602> . See https://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02273.765] 05551.05602> [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 [02273.765] 05551.05602> . See https://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02273.766] 1696011.1696023> [INFO:basemgr_impl.cc(465)] Setting shadow technique to 0 [02273.766] 1696011.1696023> [ERROR:peridot/bin/basemgr/basemgr_impl.cc(87)] Active session shell index is 0, but only 0 session shell settings exist. [02273.774] 05551.05602> [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 [02273.774] 05551.05602> .googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02273.776] 1696345.1696357> No service found for path fuchsia.modular.Lifecycle [02273.792] 1696451.1696463> No service found for path fuchsia.modular.auth.AccountProvider [02273.797] 1695733.1695745> [INFO:presentation1.cc(184)] Disconnected from a11y toggle broadcaster. [02273.827] 1696011.1696023> [INFO:user_provider_impl.cc(191)] fuchsia::modular::UserProvider::Login() Incognito mode [02273.828] 1696011.1696023> [INFO:user_controller_impl.cc(54)] SESSIONMGR DATA ORIGIN IS /data/modular/USER_GUEST_289830496 [02273.829] 1696011.1696023> [INFO:basemgr_impl.cc(465)] Setting shadow technique to 0 [02273.829] 1696011.1696023> [ERROR:peridot/bin/basemgr/basemgr_impl.cc(87)] Active session shell index is 0, but only 0 session shell settings exist. [02273.829] 1696011.1696023> [WARNING:peridot/bin/basemgr/user_provider_impl.cc(137)] AuthenticationContextProvider disconnected. [02273.834] 1696576.1696588> [ERROR:peridot/public/lib/integration_testing/cpp/testing.cc(39)] This application must be run under test_runner. [02273.835] 1695733.1695745> [INFO:presentation1.cc(184)] Disconnected from a11y toggle broadcaster. [02273.836] 1696733.1696745> [INFO:display_watcher.cc(46)] Scenic: Acquired display controller /dev/class/display-controller/000.(000) [02273.842] 1695733.1695745> [ERROR:garnet/bin/ui/root_presenter/presentation1.cc(822)] Root presenter: Content view terminated unexpectedly. [02273.862] 1697356.1697370> [INFO:device_info.cc(61)] device_info: syncing device id for user: GUEST set to: 3a5902d1-d491-447d-b8ef-d3b4e3fe9deb [02273.866] 1697356.1697370> [INFO:user_intelligence_provider_impl.cc(113)] Starting session_agents: [02273.866] 1697356.1697370> [INFO:user_intelligence_provider_impl.cc(119)] Starting startup_agents: [02273.906] 1698299.1698313> [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?) [02273.906] 05551.05602> [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: [02273.906] 05551.05602> //fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02273.961] 1697356.1697370> [INFO:device_map_impl.cc(155)] Updated Device: Device/3a5902d1-d491-447d-b8ef-d3b4e3fe9deb value={"@version":3,"name":"nanny-kick-shiny-gooey","device_id":"3a5902d1-d491-447d-b8ef-d3b4e3fe9deb","profile":"{}","hostname":"nan [02273.961] 1697356.1697370> ny-kick-shiny-gooey","last_change_timestamp":1544993411} [02273.977] 1699979.1700000> [INFO:dev_session_shell.cc(103)] DevSessionShell START choreography [02273.988] 1696733.1696745> [INFO:input_system.cc(236)] Scenic input system initialized. [02273.988] 1695733.1695745> [WARNING:garnet/bin/ui/root_presenter/displays/display_configuration.cc(76)] SceneManager: unrecognized display. [02273.988] 1696733.1696745> [INFO:input_system.cc(576)] Scenic: Parallel dispatch is turned OFF [02273.989] 1695733.1695745> [WARNING:garnet/bin/ui/root_presenter/presentation1.cc(930)] Presentation1::SetRendererParams: Cannot change shadow technique, default was overriden in root_presenter [02274.054] 1699479.1699494> [INFO:local_module_resolver.cc(109)] No manifest found for handler=choreography [02274.054] 1697356.1697370> [INFO:add_mod_call.cc(92)] Module Resolver does not know about module 'choreography' with action = 'action'. Going to try using it anyway.. [02274.054] 05551.05602> [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 [02274.054] 05551.05602> esource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02274.058] 05551.05602> [ERROR:garnet/lib/loader/package_loader.cc(65)] Could not open directory /pkgfs/packages/choreography/0 No such file or directory [02274.058] 1697356.1697370> [ERROR:peridot/lib/module_manifest/module_facet_reader_impl.cc(34)] Could not resolve URL: file://choreography [02274.120] 1699979.1700000> [INFO:dev_session_shell.cc(184)] DevSessionShell Starting story with id: story [02274.120] 1699979.1700000> [INFO:dev_session_shell.cc(210)] DevSessionShell State 3 [02274.120] 05551.05602> [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/ [02274.120] 05551.05602> docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02274.120] 1697356.1697370> [INFO:story_controller_impl.cc(183)] StoryControllerImpl::LaunchModule() choreography root [02274.121] 1699979.1700000> [INFO:dev_session_shell.cc(210)] DevSessionShell State 1 [02274.125] 05551.05602> [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 [02274.125] 05551.05602> esource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02274.131] 05551.05602> [ERROR:garnet/lib/loader/package_loader.cc(65)] Could not open directory /pkgfs/packages/choreography/0 No such file or directory [02274.173] 1703076.1703310> [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. [02274.173] 1703076.1703310> [INFO:platform_view.cc(126)] Flutter, input comes from: Scenic [02283.753] 1695421.1695436> Stopping trace... [02283.753] 09838.09852> [INFO:trace_manager.cc(92)] Stopping trace [02283.908] 09838.09852> [INFO:tracee.cc(477)] #71 {1696733:scenic.cmx} trace stats [02283.908] 09838.09852> [INFO:tracee.cc(478)] Wrapped count: 0 [02283.908] 09838.09852> [INFO:tracee.cc(479)] # records dropped: 0 [02283.908] 09838.09852> [INFO:tracee.cc(480)] Durable buffer: 0x0, size 0x0 [02283.908] 09838.09852> [INFO:tracee.cc(483)] Non-durable buffer: 0x148910,0x0, size 0xbfff80 [02283.973] 09838.09852> [INFO:trace_manager.cc(95)] Stopped trace [02283.973] 1695421.1695436> Trace file written to /tmp/infra-test-output/trace.2018-12-16T20:50:11.json [02283.973] 1694264.1694281> == fuchsia.scenic.choreography_shadow_map: Processing trace... [02284.318] 1725607.1725815> === Scenic FPS === [02284.319] 1725607.1725815> 58.56fps [02284.319] 1725607.1725815> fps per one-second window: [55 59 59 59 59 58 59 59 59] [02284.320] 1725607.1725815> RenderFrame 0.4201ms [02284.320] 1725607.1725815> ApplyScheduledSessionUpdates 0.05227ms [02284.321] 1725607.1725815> CommandBuffer::Submit 0.02785ms [02284.322] 1725607.1725815> UpdateAndDeliverMetrics 0.006661ms [02284.322] 1725607.1725815> EngineRenderer::RenderLayers 0ms [02284.322] 1725607.1725815> Warning: no values found for EngineRenderer::RenderLayers. Falling back to a zero value. [02284.323] 1725607.1725815> Escher GPU time 2.348ms [02284.326] 1725607.1725809> unaccounted (mostly gfx driver) 0.2226ms [02284.326] 1725607.1725809> Did not find any processes that matched [02284.330] 1694264.1694281> == fuchsia.scenic.choreography_shadow_map: Finished processing trace. [02284.348] 04975.04993> 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_moment_shadow_map.json --benchmark_label fuchsi [02284.348] 04975.04993> a.scenic.choreography_moment_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 --s [02284.348] 04975.04993> ession_shell_args=--root_module=choreography --story_shell=mondrian --moment_shadow_map --clipping_enabled [02284.353] 1726991.1727008> == fuchsia.scenic.choreography_moment_shadow_map: Killing processes... [02284.355] 1727232.1727246> Killed 1695733 root_presenter.cmx [02284.355] 1703076.1703310> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Presenter [02284.355] 1703076.1703310> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: View [02284.355] 1703076.1703310> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(31)] Interface error on: Service Provider [02284.355] 1703076.1703336> mondrian(flutter): Error in proxy with interface name [ViewContainer] and service name [null]: Peer unexpectedly closed [02284.358] 05551.05602> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/root_presenter#meta/root_presenter.cmx died [02284.358] 1727303.1727317> Killed 1696733 scenic.cmx [02284.358] 1703076.1703310> [ERROR:topaz/runtime/flutter_runner/platform_view.cc(37)] Interface error on: SessionListener [02284.359] 1697009.1697021> [ERROR:garnet/bin/ui/view_manager/view_registry.cc(144)] Exiting due to session connection error. [02284.359] 1703076.1703336> fdio_ns_destroy: ZX_ERR_BAD_STATE [02284.361] 02684.03722> Failed to send vsync event -24 [02284.361] 05551.05602> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/scenic#meta/scenic.cmx died [02284.367] 05551.05602> [ERROR:garnet/bin/sysmgr/app.cc(153)] Singleton fuchsia-pkg://fuchsia.com/view_manager#meta/view_manager.cmx died [02284.371] 1727372.1727386> Killed 1696011 basemgr [02284.371] 1699979.1700000> [ERROR:peridot/bin/sessionmgr/dev_session_shell.cc(178)] Story controller for story story died. Does this story exist? [02284.372] 1727372.1727386> WARNING: zx_object_get_child(1697573, (job)1702699, ...) failed: ZX_ERR_NOT_FOUND (-25) [02284.387] 1727469.1727483> no tasks found [02284.388] 1727538.1727552> no tasks found [02284.389] 1727607.1727621> no tasks found [02284.389] 1726991.1727008> == fuchsia.scenic.choreography_moment_shadow_map: Configuring scenic renderer params... [02284.394] 05551.05602> [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 [02284.394] 05551.05602> https://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02284.401] 1727851.1727863> [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. [02284.402] 1726991.1727008> == fuchsia.scenic.choreography_moment_shadow_map: Tracing... [02284.402] 1726991.1727008> /tmp/infra-test-output/trace.2018-12-16T20:50:21.json [02284.417] 09838.09852> [INFO:trace_manager.cc(69)] Starting trace with 12 MB buffers, buffering mode=oneshot [02284.418] 1728106.1728120> Starting trace; will stop in 10 seconds... [02284.419] 05551.05602> [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 [02284.419] 05551.05602> s/+/master/glossary.md#fuchsia_pkg-url for more information. [02284.422] 1728414.1728427> [INFO:fdio_hid_decoder.cc(280)] hid-parser succesful for 000 with usage page 1 and usage 128 [02284.422] 1728414.1728427> [INFO:app.cc(151)] Presenter::HACK_SetRendererParams: Setting clipping enabled to true [02284.422] 1728414.1728427> [INFO:app.cc(164)] Presenter::HACK_SetRendererParams: Setting render frequency to 1 [02284.422] 1728414.1728427> [INFO:app.cc(158)] Presenter::HACK_SetRendererParams: Setting shadow technique to 3 [02284.429] 1728693.1728705> [ERROR:peridot/lib/session_shell_settings/session_shell_settings.cc(163)] /system/data/sysui/base_shell_config.json: read failed [02284.429] 1728693.1728705> [INFO:basemgr_impl.cc(209)] [02284.429] 1728693.1728705> [02284.429] 1728693.1728705> ======================== Starting Test [=choreography] [02284.429] 1728693.1728705> ============================================================ [02284.429] 1728693.1728705> [02284.429] 05551.05602> [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 [02284.429] 05551.05602> . See https://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02284.430] 05551.05602> [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 [02284.430] 05551.05602> . See https://fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02284.431] 1728693.1728705> [INFO:basemgr_impl.cc(465)] Setting shadow technique to 0 [02284.431] 1728693.1728705> [ERROR:peridot/bin/basemgr/basemgr_impl.cc(87)] Active session shell index is 0, but only 0 session shell settings exist. [02284.439] 05551.05602> [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 [02284.439] 05551.05602> .googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02284.441] 1729027.1729039> No service found for path fuchsia.modular.Lifecycle [02284.445] 1729133.1729145> No service found for path fuchsia.modular.auth.AccountProvider [02284.449] 1728414.1728427> [INFO:presentation1.cc(184)] Disconnected from a11y toggle broadcaster. [02284.456] 1728693.1728705> [INFO:user_provider_impl.cc(191)] fuchsia::modular::UserProvider::Login() Incognito mode [02284.456] 1728693.1728705> [INFO:user_controller_impl.cc(54)] SESSIONMGR DATA ORIGIN IS /data/modular/USER_GUEST_2950653525 [02284.460] 1728693.1728705> [INFO:basemgr_impl.cc(465)] Setting shadow technique to 0 [02284.460] 1728693.1728705> [ERROR:peridot/bin/basemgr/basemgr_impl.cc(87)] Active session shell index is 0, but only 0 session shell settings exist. [02284.460] 1728693.1728705> [WARNING:peridot/bin/basemgr/user_provider_impl.cc(137)] AuthenticationContextProvider disconnected. [02284.485] 1729568.1729580> [INFO:display_watcher.cc(46)] Scenic: Acquired display controller /dev/class/display-controller/000.(000) [02284.500] 1728414.1728427> [INFO:presentation1.cc(184)] Disconnected from a11y toggle broadcaster. [02284.500] 1729258.1729270> [ERROR:peridot/public/lib/integration_testing/cpp/testing.cc(39)] This application must be run under test_runner. [02284.520] 1728414.1728427> [ERROR:garnet/bin/ui/root_presenter/presentation1.cc(822)] Root presenter: Content view terminated unexpectedly. [02284.522] 1729980.1729992> [INFO:device_info.cc(61)] device_info: syncing device id for user: GUEST set to: ac7dba5e-8baf-4b81-aa9b-2c44a9b19991 [02284.528] 1729980.1729992> [INFO:user_intelligence_provider_impl.cc(113)] Starting session_agents: [02284.528] 1729980.1729992> [INFO:user_intelligence_provider_impl.cc(119)] Starting startup_agents: [02284.573] 1730963.1730977> [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?) [02284.577] 05551.05602> [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: [02284.577] 05551.05602> //fuchsia.googlesource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02284.610] 1729980.1729992> [INFO:device_map_impl.cc(155)] Updated Device: Device/ac7dba5e-8baf-4b81-aa9b-2c44a9b19991 value={"@version":3,"name":"nanny-kick-shiny-gooey","device_id":"ac7dba5e-8baf-4b81-aa9b-2c44a9b19991","profile":"{}","hostname":"nan [02284.610] 1729980.1729992> ny-kick-shiny-gooey","last_change_timestamp":1544993421} [02284.636] 1732774.1732786> [INFO:dev_session_shell.cc(103)] DevSessionShell START choreography [02284.648] 1729568.1729580> [INFO:input_system.cc(236)] Scenic input system initialized. [02284.648] 1728414.1728427> [WARNING:garnet/bin/ui/root_presenter/displays/display_configuration.cc(76)] SceneManager: unrecognized display. [02284.648] 1729568.1729580> [INFO:input_system.cc(576)] Scenic: Parallel dispatch is turned OFF [02284.648] 1728414.1728427> [WARNING:garnet/bin/ui/root_presenter/presentation1.cc(930)] Presentation1::SetRendererParams: Cannot change shadow technique, default was overriden in root_presenter [02284.716] 1732276.1732288> [INFO:local_module_resolver.cc(109)] No manifest found for handler=choreography [02284.716] 1729980.1729992> [INFO:add_mod_call.cc(92)] Module Resolver does not know about module 'choreography' with action = 'action'. Going to try using it anyway.. [02284.716] 05551.05602> [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 [02284.716] 05551.05602> esource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02284.718] 05551.05602> [ERROR:garnet/lib/loader/package_loader.cc(65)] Could not open directory /pkgfs/packages/choreography/0 No such file or directory [02284.718] 1729980.1729992> [ERROR:peridot/lib/module_manifest/module_facet_reader_impl.cc(34)] Could not resolve URL: file://choreography [02284.787] 1732774.1732786> [INFO:dev_session_shell.cc(184)] DevSessionShell Starting story with id: story [02284.787] 1732774.1732786> [INFO:dev_session_shell.cc(210)] DevSessionShell State 3 [02284.788] 05551.05602> [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/ [02284.788] 05551.05602> docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02284.788] 1729980.1729992> [INFO:story_controller_impl.cc(183)] StoryControllerImpl::LaunchModule() choreography root [02284.788] 1732774.1732786> [INFO:dev_session_shell.cc(210)] DevSessionShell State 1 [02284.794] 05551.05602> [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 [02284.794] 05551.05602> esource.com/docs/+/master/glossary.md#fuchsia_pkg-url for more information. [02284.797] 05551.05602> [ERROR:garnet/lib/loader/package_loader.cc(65)] Could not open directory /pkgfs/packages/choreography/0 No such file or directory [02284.846] 1735836.1736040> [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. [02284.846] 1735836.1736040> [INFO:platform_view.cc(126)] Flutter, input comes from: Scenic [02294.418] 1728106.1728120> Stopping trace... [02294.418] 09838.09852> [INFO:trace_manager.cc(92)] Stopping trace [02294.614] 09838.09852> [INFO:tracee.cc(477)] #78 {1729568:scenic.cmx} trace stats [02294.614] 09838.09852> [INFO:tracee.cc(478)] Wrapped count: 0 [02294.614] 09838.09852> [INFO:tracee.cc(479)] # records dropped: 0 [02294.614] 09838.09852> [INFO:tracee.cc(480)] Durable buffer: 0x0, size 0x0 [02294.614] 09838.09852> [INFO:tracee.cc(483)] Non-durable buffer: 0x148698,0x0, size 0xbfff80 [02294.636] 09838.09852> [INFO:trace_manager.cc(95)] Stopped trace [02294.647] 1728106.1728120> Trace file written to /tmp/infra-test-output/trace.2018-12-16T20:50:21.json [02294.647] 1726991.1727008> == fuchsia.scenic.choreography_moment_shadow_map: Processing trace... [02295.005] 1758378.1758609> === Scenic FPS === [02295.006] 1758378.1758609> 58.46fps [02295.006] 1758378.1758609> fps per one-second window: [57 56 59 59 59 59 59 59 59] [02295.007] 1758378.1758609> RenderFrame 0.4393ms [02295.008] 1758378.1758609> ApplyScheduledSessionUpdates 0.05216ms [02295.011] 1758378.1758609> CommandBuffer::Submit 0.02781ms [02295.013] 1758378.1758609> UpdateAndDeliverMetrics 0.006691ms [02295.013] 1758378.1758609> EngineRenderer::RenderLayers 0ms [02295.013] 1758378.1758609> Warning: no values found for EngineRenderer::RenderLayers. Falling back to a zero value. [02295.014] 1758378.1758609> Escher GPU time 2.385ms [02295.017] 1758378.1758609> unaccounted (mostly gfx driver) 0.2261ms [02295.017] 1758378.1758609> Did not find any processes that matched [02295.020] 1726991.1727008> == fuchsia.scenic.choreography_moment_shadow_map: Finished processing trace. [02295.035] 04975.04993> runbench: writing summary.json to /tmp/infra-test-output/summary.json 2018/12/16 13:10:57 reading "summary.json" 2018/12/16 13:10:57 copying test output 2018/12/16 13:10:57 tarring test output... [02313.279] 01532.01617> netsvc: tftp read of file /tmp/infra-test-output/summary.json completed [02313.283] 01532.01617> netsvc: tftp read of file /tmp/infra-test-output/fuchsia.scenic.image_grid_flutter_noclipping_noshadows.json completed [02313.284] 01532.01617> netsvc: tftp read of file /tmp/infra-test-output/fuchsia.scenic.image_grid_flutter_noclipping_noshadows.catapult_json completed [02313.287] 01532.01617> netsvc: tftp read of file /tmp/infra-test-output/fuchsia.scenic.image_grid_flutter_noshadows.json completed [02313.288] 01532.01617> netsvc: tftp read of file /tmp/infra-test-output/fuchsia.scenic.image_grid_flutter_noshadows.catapult_json completed [02313.292] 01532.01617> netsvc: tftp read of file /tmp/infra-test-output/fuchsia.scenic.image_grid_flutter_ssdo.json completed [02313.293] 01532.01617> netsvc: tftp read of file /tmp/infra-test-output/fuchsia.scenic.image_grid_flutter_ssdo.catapult_json completed [02313.297] 01532.01617> netsvc: tftp read of file /tmp/infra-test-output/fuchsia.scenic.image_grid_flutter_shadow_map.json completed [02313.298] 01532.01617> netsvc: tftp read of file /tmp/infra-test-output/fuchsia.scenic.image_grid_flutter_shadow_map.catapult_json completed [02313.301] 01532.01617> netsvc: tftp read of file /tmp/infra-test-output/fuchsia.scenic.image_grid_flutter_moment_shadow_map.json completed [02313.302] 01532.01617> netsvc: tftp read of file /tmp/infra-test-output/fuchsia.scenic.image_grid_flutter_moment_shadow_map.catapult_json completed [02313.304] 01532.01617> netsvc: tftp read of file /tmp/infra-test-output/fuchsia.scenic.image_grid_flutter_x3_noclipping_noshadows.json completed [02313.305] 01532.01617> netsvc: tftp read of file /tmp/infra-test-output/fuchsia.scenic.image_grid_flutter_x3_noclipping_noshadows.catapult_json completed [02313.307] 01532.01617> netsvc: tftp read of file /tmp/infra-test-output/fuchsia.scenic.image_grid_flutter_x3_noshadows.json completed [02313.307] 01532.01617> netsvc: tftp read of file /tmp/infra-test-output/fuchsia.scenic.image_grid_flutter_x3_noshadows.catapult_json completed [02313.310] 01532.01617> netsvc: tftp read of file /tmp/infra-test-output/fuchsia.scenic.image_grid_flutter_x3_ssdo.json completed [02313.311] 01532.01617> netsvc: tftp read of file /tmp/infra-test-output/fuchsia.scenic.image_grid_flutter_x3_ssdo.catapult_json completed [02313.314] 01532.01617> netsvc: tftp read of file /tmp/infra-test-output/fuchsia.scenic.image_grid_flutter_x3_shadow_map.json completed [02313.314] 01532.01617> netsvc: tftp read of file /tmp/infra-test-output/fuchsia.scenic.image_grid_flutter_x3_shadow_map.catapult_json completed [02313.317] 01532.01617> netsvc: tftp read of file /tmp/infra-test-output/fuchsia.scenic.image_grid_flutter_x3_moment_shadow_map.json completed [02313.318] 01532.01617> netsvc: tftp read of file /tmp/infra-test-output/fuchsia.scenic.image_grid_flutter_x3_moment_shadow_map.catapult_json completed [02313.320] 01532.01617> netsvc: tftp read of file /tmp/infra-test-output/fuchsia.scenic.choreography_noclipping_noshadows.json completed [02313.321] 01532.01617> netsvc: tftp read of file /tmp/infra-test-output/fuchsia.scenic.choreography_noclipping_noshadows.catapult_json completed [02313.324] 01532.01617> netsvc: tftp read of file /tmp/infra-test-output/fuchsia.scenic.choreography_noshadows.json completed [02313.325] 01532.01617> netsvc: tftp read of file /tmp/infra-test-output/fuchsia.scenic.choreography_noshadows.catapult_json completed [02313.330] 01532.01617> netsvc: tftp read of file /tmp/infra-test-output/fuchsia.scenic.choreography_ssdo.json completed [02313.331] 01532.01617> netsvc: tftp read of file /tmp/infra-test-output/fuchsia.scenic.choreography_ssdo.catapult_json completed [02313.334] 01532.01617> netsvc: tftp read of file /tmp/infra-test-output/fuchsia.scenic.choreography_shadow_map.json completed [02313.336] 01532.01617> netsvc: tftp read of file /tmp/infra-test-output/fuchsia.scenic.choreography_shadow_map.catapult_json completed [02313.339] 01532.01617> netsvc: tftp read of file /tmp/infra-test-output/fuchsia.scenic.choreography_moment_shadow_map.json completed 2018/12/16 13:10:57 rebooting the node "nanny-kick-shiny-gooey" [02313.340] 01532.01617> netsvc: tftp read of file /tmp/infra-test-output/fuchsia.scenic.choreography_moment_shadow_map.catapult_json completed