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