edgetpu Inference times an order of magnitude higher using examples on M.2/pcie connected edgetpu

Description

It would appear that I'm seeing inference times that are an order of magnitude higher than they should be. Thus far I've been unable to track down the source of the issue nor find references to similar behaviour in the issues here or more broadly through search.

Using latest install/clone/dkms build as of 2021-10-17
Temperature seem good (see temperature readouts)
Link speed seem to be fine (see lspci output).
There does seem to be a kernel message whenever the TPU starts to be used, it's included but I'm unsure if it's related.

Click to expand!

Issue Type

Performance

Operating System

Linux

Coral Device

M.2 Accelerator with dual Edge TPU

Other Devices

No response

Programming Language

Python 3.9

Relevant Log Output

dmesg:
# dmesg | grep gask
[    0.000000] Command line: BOOT_IMAGE=/vmlinuz-5.4.0-88-generic root=[redacted] ro intel_iommu=on hugepagesz=2M hugepages=16384 pcie_aspm=off gasket.dma_bit_mask=32
[    1.344764] Kernel command line: BOOT_IMAGE=/vmlinuz-5.4.0-88-generic root=[redacted] ro intel_iommu=on hugepagesz=2M hugepages=16384 pcie_aspm=off gasket.dma_bit_mask=32
[   45.346545] gasket: loading out-of-tree module taints kernel.
[   45.346642] gasket: module verification failed: signature and/or required key missing - tainting kernel
# dmesg | grep apex
[   45.381632] apex 0000:05:00.0: enabling device (0140 -> 0142)
[   50.532007] apex 0000:05:00.0: Apex performance not throttled due to temperature
[18870.374955] apex 0000:05:00.0: Process 679185 is opening a node held by 619462.
[19010.227275] apex 0000:05:00.0: entry 6144 is not free

This appears whenever running the example inferences:
[20659.536795] x86/PAT: python3:739924 map pfn RAM range req uncached-minus for [mem 0x2462444000-0x2462447fff], got write-back

Temperature is solid, varying by 1-2 degrees:
#cat /sys/class/apex/apex_0/temp
40550

# cat /sys/class/apex/apex_0/trip_point*
84800
89800
94800


PCI info, appears to show full link speed:
05:00.0 0880: 1ac1:089a (prog-if ff)
        Subsystem: 1ac1:089a
        Physical Slot: 2
        Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr+ Stepping- SERR+ FastB2B- DisINTx+
        Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
        Latency: 0, Cache Line Size: 64 bytes
        Interrupt: pin A routed to IRQ 16
        NUMA node: 0
        Region 0: Memory at 39fffc00000 (64-bit, prefetchable) [size=16K]
        Region 2: Memory at 39fffb00000 (64-bit, prefetchable) [size=1M]
        Capabilities: [80] Express (v2) Endpoint, MSI 00
                DevCap: MaxPayload 256 bytes, PhantFunc 0, Latency L0s <64ns, L1 <1us
                        ExtTag+ AttnBtn- AttnInd- PwrInd- RBE+ FLReset- SlotPowerLimit 0.000W
                DevCtl: CorrErr- NonFatalErr+ FatalErr+ UnsupReq-
                        RlxdOrd+ ExtTag+ PhantFunc- AuxPwr- NoSnoop+
                        MaxPayload 256 bytes, MaxReadReq 4096 bytes
                DevSta: CorrErr+ NonFatalErr- FatalErr- UnsupReq+ AuxPwr- TransPend-
                LnkCap: Port #1, Speed 5GT/s, Width x1, ASPM L0s L1, Exit Latency L0s <64ns, L1 <1us
                        ClockPM+ Surprise- LLActRep- BwNot- ASPMOptComp+
                LnkCtl: ASPM Disabled; RCB 64 bytes Disabled- CommClk-
                        ExtSynch- ClockPM- AutWidDis- BWInt- AutBWInt-
                LnkSta: Speed 5GT/s (ok), Width x1 (ok)
                        TrErr- Train- SlotClk- DLActive- BWMgmt- ABWMgmt-
                DevCap2: Completion Timeout: Range ABCD, TimeoutDis+, NROPrPrP-, LTR+
                         10BitTagComp-, 10BitTagReq-, OBFF Not Supported, ExtFmt+, EETLPPrefix-
                         EmergencyPowerReduction Not Supported, EmergencyPowerReductionInit-
                         FRS-, TPHComp-, ExtTPHComp-
                         AtomicOpsCap: 32bit- 64bit- 128bitCAS-
                DevCtl2: Completion Timeout: 50us to 50ms, TimeoutDis-, LTR-, OBFF Disabled
                         AtomicOpsCtl: ReqEn-
                LnkCtl2: Target Link Speed: 5GT/s, EnterCompliance- SpeedDis-
                         Transmit Margin: Normal Operating Range, EnterModifiedCompliance- ComplianceSOS-
                         Compliance De-emphasis: -6dB
                LnkSta2: Current De-emphasis Level: -6dB, EqualizationComplete-, EqualizationPhase1-
                         EqualizationPhase2-, EqualizationPhase3-, LinkEqualizationRequest-
        Capabilities: [d0] MSI-X: Enable+ Count=128 Masked-
                Vector table: BAR=2 offset=00046800
                PBA: BAR=2 offset=00046068
        Capabilities: [e0] MSI: Enable- Count=1/32 Maskable- 64bit+
                Address: 0000000000000000  Data: 0000
        Capabilities: [f8] Power Management version 3
                Flags: PMEClk- DSI- D1- D2- AuxCurrent=0mA PME(D0-,D1-,D2-,D3hot-,D3cold-)
                Status: D0 NoSoftRst+ PME-Enable- DSel=0 DScale=0 PME-
        Capabilities: [100 v1] Vendor Specific Information: ID=1556 Rev=1 Len=008 <?>
        Capabilities: [108 v1] Latency Tolerance Reporting
                Max snoop latency: 0ns
                Max no snoop latency: 0ns
        Capabilities: [110 v1] L1 PM Substates
                L1SubCap: PCI-PM_L1.2+ PCI-PM_L1.1+ ASPM_L1.2+ ASPM_L1.1+ L1_PM_Substates+
                          PortCommonModeRestoreTime=10us PortTPowerOnTime=10us
                L1SubCtl1: PCI-PM_L1.2- PCI-PM_L1.1- ASPM_L1.2- ASPM_L1.1-
                           T_CommonMode=0us LTR1.2_Threshold=0ns
                L1SubCtl2: T_PwrOn=10us
        Capabilities: [200 v2] Advanced Error Reporting
                UESta:  DLP- SDES- TLP- FCP- CmpltTO- CmpltAbrt- UnxCmplt- RxOF- MalfTLP- ECRC- UnsupReq- ACSViol-
                UEMsk:  DLP- SDES- TLP- FCP- CmpltTO- CmpltAbrt- UnxCmplt- RxOF- MalfTLP- ECRC- UnsupReq- ACSViol-
                UESvrt: DLP+ SDES- TLP- FCP+ CmpltTO- CmpltAbrt- UnxCmplt- RxOF- MalfTLP+ ECRC- UnsupReq- ACSViol-
                CESta:  RxErr- BadTLP- BadDLLP- Rollover- Timeout- AdvNonFatalErr-
                CEMsk:  RxErr- BadTLP- BadDLLP- Rollover- Timeout- AdvNonFatalErr+
                AERCap: First Error Pointer: 00, ECRCGenCap+ ECRCGenEn- ECRCChkCap+ ECRCChkEn-
                        MultHdrRecCap- MultHdrRecEn- TLPPfxPres- HdrLogCap-
                HeaderLog: 04000001 0010000f 05070000 be098272
        Kernel driver in use: apex
        Kernel modules: apex

Inference time appearing to be an order of magnitude higher than it should be:
# python3 examples/classify_image.py --model test_data/mobilenet_v2_1.0_224_inat_bird_quant_edgetpu.tflite --labels test_data/inat_bird_labels.txt --input test_data/parrot.jpg
----INFERENCE TIME----
Note: The first inference on Edge TPU is slow because it includes loading the model into Edge TPU memory.
151.1ms
70.8ms
71.2ms
71.4ms
71.4ms
-------RESULTS--------
Ara macao (Scarlet Macaw): 0.75781

Oct 17 '21 05:10 brilthor

@brilthor On which hardware/machine have you connected the M.2 device ? Please share the output of following commands:

lscpu
uname -a

Oct 18 '21 06:10 manoj7410

@manoj7410

HP DL360 Gen9

CPU op-mode(s):                  32-bit, 64-bit
Byte Order:                      Little Endian
Address sizes:                   46 bits physical, 48 bits virtual
CPU(s):                          48
On-line CPU(s) list:             0-47
Thread(s) per core:              2
Core(s) per socket:              12
Socket(s):                       2
NUMA node(s):                    2
Vendor ID:                       GenuineIntel
CPU family:                      6
Model:                           79
Model name:                      Intel(R) Xeon(R) CPU E5-2650 v4 @ 2.20GHz
Stepping:                        1
CPU MHz:                         1950.328
CPU max MHz:                     2900.0000
CPU min MHz:                     1200.0000
BogoMIPS:                        4394.89
Virtualization:                  VT-x
L1d cache:                       768 KiB
L1i cache:                       768 KiB
L2 cache:                        6 MiB
L3 cache:                        60 MiB
NUMA node0 CPU(s):               0-11,24-35
NUMA node1 CPU(s):               12-23,36-47
Vulnerability Itlb multihit:     KVM: Mitigation: Split huge pages
Vulnerability L1tf:              Mitigation; PTE Inversion; VMX conditional cache flushes, SMT vulnerable
Vulnerability Mds:               Mitigation; Clear CPU buffers; SMT vulnerable
Vulnerability Meltdown:          Mitigation; PTI
Vulnerability Spec store bypass: Mitigation; Speculative Store Bypass disabled via prctl and seccomp
Vulnerability Spectre v1:        Mitigation; usercopy/swapgs barriers and __user pointer sanitization
Vulnerability Spectre v2:        Mitigation; Full generic retpoline, IBPB conditional, IBRS_FW, STIBP conditional, RSB filling
Vulnerability Srbds:             Not affected
Vulnerability Tsx async abort:   Mitigation; Clear CPU buffers; SMT vulnerable
Flags:                           fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm p
                                 be syscall nx pdpe1gb rdtscp lm constant_tsc arch_perfmon pebs bts rep_good nopl xtopology nonstop_tsc cpuid aperfmpe
                                 rf pni pclmulqdq dtes64 monitor ds_cpl vmx smx est tm2 ssse3 sdbg fma cx16 xtpr pdcm pcid dca sse4_1 sse4_2 x2apic mo
                                 vbe popcnt tsc_deadline_timer aes xsave avx f16c rdrand lahf_lm abm 3dnowprefetch cpuid_fault epb cat_l3 cdp_l3 invpc
                                 id_single pti intel_ppin ssbd ibrs ibpb stibp tpr_shadow vnmi flexpriority ept vpid ept_ad fsgsbase tsc_adjust bmi1 h
                                 le avx2 smep bmi2 erms invpcid rtm cqm rdt_a rdseed adx smap intel_pt xsaveopt cqm_llc cqm_occup_llc cqm_mbm_total cq
                                 m_mbm_local dtherm ida arat pln pts md_clear flush_l1d

Linux host 5.4.0-88-generic #99-Ubuntu SMP Thu Sep 23 17:29:00 UTC 2021 x86_64 x86_64 x86_64 GNU/Linux

Oct 18 '21 12:10 brilthor

@brilthor I am trying to reproduce this on my machine but unable to.

Can you share the output of:

modinfo apex
modinfo gasket

Oct 19 '21 06:10 manoj7410

@manoj7410

# modinfo apex
filename:       /lib/modules/5.4.0-88-generic/updates/dkms/apex.ko
author:         John Joseph <[email protected]>
license:        GPL v2
version:        1.2
description:    Google Apex driver
srcversion:     37A768932BDAF006DA92150
alias:          pci:v00001AC1d0000089Asv*sd*bc*sc*i*
depends:        gasket
retpoline:      Y
name:           apex
vermagic:       5.4.0-88-generic SMP mod_unload modversions 
sig_id:         PKCS#7
signer:         host Secure Boot Module Signature key
sig_key:        ....
sig_hashalgo:   sha512
signature:      ....
parm:           allow_power_save:int
parm:           allow_sw_clock_gating:int
parm:           allow_hw_clock_gating:int
parm:           bypass_top_level:int
parm:           trip_point0_temp:int
parm:           trip_point1_temp:int
parm:           trip_point2_temp:int
parm:           hw_temp_warn1:int
parm:           hw_temp_warn2:int
parm:           hw_temp_warn1_en:bool
parm:           hw_temp_warn2_en:bool
parm:           temp_poll_interval:int

# modinfo gasket
filename:       /lib/modules/5.4.0-88-generic/updates/dkms/gasket.ko
author:         Rob Springer <[email protected]>
license:        GPL v2
version:        1.1.4
description:    Google Gasket driver framework
srcversion:     A7A1F644810CD4FF575450E
depends:        
retpoline:      Y
name:           gasket
vermagic:       5.4.0-88-generic SMP mod_unload modversions 
sig_id:         PKCS#7
signer:         host Secure Boot Module Signature key
sig_key:        ....
sig_hashalgo:   sha512
signature:      .....

Oct 19 '21 14:10 brilthor

Any other information / debug steps that would be helpful? @manoj7410 @hjonnala

Oct 25 '21 14:10 brilthor

@brilthor modinfo information seems correct. Please share the output of:

lsmod | grep apex

Additionally, run below commands:

sudo sh -c "echo 'SUBSYSTEM==\"apex\", MODE=\"0660\", GROUP=\"apex\"' >> /etc/udev/rules.d/65-apex.rules"

sudo groupadd apex

sudo adduser $USER apex

Then reboot the system and run the demo again. Let us know if this improves the inference speed.

Oct 26 '21 09:10 manoj7410

@manoj7410 inference times did not improve:

$ lsmod | grep apex
apex                   28672  0
gasket                110592  1 apex

$ cat /etc/udev/rules.d/65-apex.rules 
SUBSYSTEM=="apex", MODE="0660", GROUP="apex"

$ ls -al /dev/apex_0 
crw-rw---- 1 root apex 120, 0 Oct 16 18:58 /dev/apex_0

$ python3 examples/classify_image.py --model test_data/mobilenet_v2_1.0_224_inat_bird_quant_edgetpu.tflite --labels test_data/inat_bird_labels.txt --input test_data/parrot.jpg
----INFERENCE TIME----
Note: The first inference on Edge TPU is slow because it includes loading the model into Edge TPU memory.
150.5ms
70.8ms
70.8ms
71.0ms
71.3ms
-------RESULTS--------
Ara macao (Scarlet Macaw): 0.75781
$ id
....,5003(apex)

Oct 26 '21 18:10 brilthor

Is there a debug build for the kenel modules or similar that could help debug this? Is the coral hardware faulty and needs to be returned? @manoj7410 @hjonnala

Nov 10 '21 15:11 brilthor

@brilthor can you please try this and share the logs: https://github.com/google-coral/edgetpu/issues/491#issuecomment-948069240

Nov 10 '21 17:11 hjonnala

Added and run, output is below:

Expand for the run output

~/tmp/pycoral$ python3 examples/classify_image.py --model test_data/mobilenet_v2_1.0_224_inat_bird_quant_edgetpu.tflite --labels test_data/inat_bird_labels.txt --input test_data/inat_bird_labels.txt --input test_data/parrot.jpg
I tflite/edgetpu_manager_direct.cc:453] No matching device is already opened for shared ownership.
I driver/usb/local_usb_device.cc:944] EnumerateDevices: vendor:0x1a6e, product:0x89a
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[1] port[0]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[3] port[0]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[3]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[12]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[3]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[2]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[1]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[11]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[0]
I driver/usb/local_usb_device.cc:944] EnumerateDevices: vendor:0x18d1, product:0x9302
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[1] port[0]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[3] port[0]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[3]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[12]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[3]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[2]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[1]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[11]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[0]
I tflite/edgetpu_context_direct.cc:106] USB always DFU: False (default)
I tflite/edgetpu_context_direct.cc:128] USB bulk-in queue capacity: default
I tflite/edgetpu_context_direct.cc:67] Performance expectation: Max (default)
I ./driver/mmio/host_queue.h:266] Starting in normal mode
I driver/kernel/kernel_registers.cc:83] Opening /dev/apex_0. read_only=0
I driver/kernel/kernel_registers.cc:97] mmap_offset=0x0000000000040000, mmap_size=4096
I driver/kernel/kernel_registers.cc:108] Got map addr at 0x0x7f27a5835000
I driver/kernel/kernel_registers.cc:97] mmap_offset=0x0000000000044000, mmap_size=4096
I driver/kernel/kernel_registers.cc:108] Got map addr at 0x0x7f27a5834000
I driver/kernel/kernel_registers.cc:97] mmap_offset=0x0000000000048000, mmap_size=4096
I driver/kernel/kernel_registers.cc:108] Got map addr at 0x0x7f27a4d6e000
I driver/kernel/kernel_registers.cc:211] Read: offset = 0x00000000000486f0, value: = 0x0000000000000000
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000487a8, value = 0x0000000000000000
I driver/kernel/kernel_registers.cc:211] Read: offset = 0x0000000000048578, value: = 0x0000000000000010
I driver/kernel/kernel_mmu_mapper.cc:135] MmuMapper#Map() : 00007f27a1c1d000 -> 0000000001000000 (1 pages) flags=00000000.
I driver/memory/mmio_address_space.cc:55] MapMemory() page-aligned : device_address = 0x0000000001000000
I ./driver/mmio/host_queue.h:162] Queue base : 0x7f27a1c1d000 -> 0x0000000001000000 [4096 bytes]
I driver/kernel/kernel_mmu_mapper.cc:135] MmuMapper#Map() : 00007f27a1c1e000 -> 0000000001001000 (1 pages) flags=00000000.
I driver/memory/mmio_address_space.cc:55] MapMemory() page-aligned : device_address = 0x0000000001001000
I ./driver/mmio/host_queue.h:172] Queue status block : 0x7f27a1c1e000 -> 0x0000000001001000 [16 bytes]
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x0000000000048590, value = 0x0000000001000000
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x0000000000048598, value = 0x0000000001001000
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000485a0, value = 0x0000000000000100
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x0000000000048568, value = 0x0000000000000005
I driver/kernel/kernel_registers.cc:211] Read: offset = 0x0000000000048570, value: = 0x0000000000000001
I driver/kernel/kernel_registers.cc:211] Read: offset = 0x00000000000486d0, value: = 0x0000000000000000
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x0000000000044018, value = 0x0000000000000001
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x0000000000044158, value = 0x0000000000000001
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x0000000000044198, value = 0x0000000000000001
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000441d8, value = 0x0000000000000001
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x0000000000044218, value = 0x0000000000000001
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x0000000000048788, value = 0x000000000000007f
I driver/kernel/kernel_registers.cc:211] Read: offset = 0x0000000000048788, value: = 0x000000000000007f
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000400c0, value = 0x0000000000000001
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x0000000000040150, value = 0x0000000000000001
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x0000000000040110, value = 0x0000000000000001
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x0000000000040250, value = 0x0000000000000001
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x0000000000040298, value = 0x0000000000000001
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000402e0, value = 0x0000000000000001
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x0000000000040328, value = 0x0000000000000001
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x0000000000040190, value = 0x0000000000000001
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000401d0, value = 0x0000000000000001
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x0000000000040210, value = 0x0000000000000001
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000486e8, value = 0x0000000000000000
I driver/kernel/linux/kernel_event_handler_linux.cc:45] Set event fd : event_id:0 -> event_fd:7, 
I driver/kernel/linux/kernel_event_handler_linux.cc:45] Set event fd : event_id:4 -> event_fd:11, 
I driver/kernel/linux/kernel_event_handler_linux.cc:45] Set event fd : event_id:5 -> event_fd:12, 
I driver/kernel/linux/kernel_event_handler_linux.cc:45] Set event fd : event_id:6 -> event_fd:13, 
I driver/kernel/linux/kernel_event_linux.cc:62] event_fd=11. Monitor thread begin.
I driver/kernel/linux/kernel_event_linux.cc:62] event_fd=7. Monitor thread begin.
I driver/kernel/linux/kernel_event_handler_linux.cc:45] Set event fd : event_id:7 -> event_fd:14, 
I driver/kernel/linux/kernel_event_linux.cc:62] event_fd=13. Monitor thread begin.
I driver/kernel/linux/kernel_event_handler_linux.cc:45] Set event fd : event_id:8 -> event_fd:15, 
I driver/kernel/linux/kernel_event_linux.cc:62] event_fd=12. Monitor thread begin.
I driver/kernel/linux/kernel_event_handler_linux.cc:45] Set event fd : event_id:9 -> event_fd:16, 
I driver/kernel/linux/kernel_event_handler_linux.cc:45] Set event fd : event_id:10 -> event_fd:17, 
I driver/kernel/linux/kernel_event_linux.cc:62] event_fd=14. Monitor thread begin.
I driver/kernel/linux/kernel_event_handler_linux.cc:45] Set event fd : event_id:11 -> event_fd:18, 
I driver/kernel/linux/kernel_event_linux.cc:62] event_fd=17. Monitor thread begin.
I driver/kernel/linux/kernel_event_handler_linux.cc:45] Set event fd : event_id:12 -> event_fd:19, 
I driver/kernel/linux/kernel_event_linux.cc:62] event_fd=15. Monitor thread begin.
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000486a0, value = 0x000000000000000f
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000485c0, value = 0x0000000000000001
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000486c0, value = 0x0000000000000001
I driver/kernel/linux/kernel_event_linux.cc:62] event_fd=16. Monitor thread begin.
I tflite/edgetpu_context_direct.cc:174] Opening device at /dev/apex_0
I driver/kernel/linux/kernel_event_linux.cc:62] event_fd=18. Monitor thread begin.
I driver/kernel/linux/kernel_event_linux.cc:62] event_fd=19. Monitor thread begin.
----INFERENCE TIME----
Note: The first inference on Edge TPU is slow because it includes loading the model into Edge TPU memory.
I driver/request.cc:47] Adding input "map/TensorArrayStack/TensorArrayGatherV3" with 150528 bytes.
I driver/request.cc:58] Adding output "prediction" with 965 bytes.
I driver/request.cc:167] Request prepared, total batch size: 1, total TPU requests required: 1.
I driver/driver.cc:307] Request [0]: Submitting P0 request immediately.
I driver/driver.cc:369] Request [0]: Need to map parameters.
I driver/kernel/kernel_mmu_mapper.cc:135] MmuMapper#Map() : 00007f27983eb000 -> 8000000000000000 (964 pages) flags=00000002.
I driver/memory/mmio_address_space.cc:55] MapMemory() page-aligned : device_address = 0x8000000000000000
I driver/driver.cc:249] Mapped params : Buffer(ptr=0x7f27983eb000) -> 0x8000000000000000, 3947392 bytes.
I driver/driver.cc:249] Mapped params : Buffer(ptr=(nil)) -> 0x0000000000000000, 0 bytes.
I driver/driver.cc:383] Request [0]: Need to do parameter-caching.
I driver/single_tpu_request.cc:80] [0] Request constructed.
I driver/instruction_buffers.cc:46] InstructionBuffers created.
I driver/package_registry.cc:647] Created new instruction buffers.
I driver/device_buffer_mapper.cc:75] Mapped scratch : Buffer(ptr=(nil)) -> 0x0000000000000000, 0 bytes.
I driver/single_tpu_request.cc:365] MapDataBuffers() done.
I driver/executable_util.cc:187] Linking Parameter: 0x8000000000000000
I driver/kernel/kernel_mmu_mapper.cc:135] MmuMapper#Map() : 0000000002d10000 -> 8000000000400000 (3 pages) flags=00000002.
I driver/memory/mmio_address_space.cc:55] MapMemory() page-aligned : device_address = 0x8000000000400000
I driver/device_buffer_mapper.cc:222] Mapped "instructions" : Buffer(ptr=0x2d10000) -> 0x8000000000400000, 10064 bytes. Direction=1
I driver/single_tpu_request.cc:381] MapInstructionBuffers() done.
I driver/single_tpu_request.cc:478] [0] SetState old=0, new=1.
I driver/single_tpu_request.cc:390] [0] NotifyRequestSubmitted()
I driver/single_tpu_request.cc:478] [0] SetState old=1, new=2.
I driver/single_queue_dma_scheduler.cc:82] Request[0]: Submitted
I driver/single_tpu_request.cc:398] [0] NotifyRequestActive()
I driver/single_tpu_request.cc:478] [0] SetState old=2, new=3.
I driver/single_queue_dma_scheduler.cc:132] Request[0]: Scheduling DMA[0]
I ./driver/mmio/host_queue.h:383] Adding an element to the host queue.
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000485a8, value = 0x0000000000000001
I driver/single_tpu_request.cc:80] [1] Request constructed.
I driver/single_tpu_request.cc:113] Adding input "map/TensorArrayStack/TensorArrayGatherV3" with 150528 bytes.
I driver/single_tpu_request.cc:187] Adding output "prediction" with 965 bytes.
I driver/instruction_buffers.cc:46] InstructionBuffers created.
I driver/package_registry.cc:647] Created new instruction buffers.
I driver/device_buffer_mapper.cc:75] Mapped scratch : Buffer(ptr=(nil)) -> 0x0000000000000000, 0 bytes.
I driver/kernel/kernel_mmu_mapper.cc:135] MmuMapper#Map() : 0000000002cc5000 -> 8000000000440000 (38 pages) flags=00000002.
I driver/memory/mmio_address_space.cc:55] MapMemory() page-aligned : device_address = 0x8000000000440000
I driver/device_buffer_mapper.cc:222] Mapped "map/TensorArrayStack/TensorArrayGatherV3" : Buffer(ptr=0x2cc5a00) -> 0x8000000000440a00, 150528 bytes. Direction=1
I driver/kernel/kernel_mmu_mapper.cc:135] MmuMapper#Map() : 0000000002d16000 -> 8000000000404000 (1 pages) flags=00000004.
I driver/memory/mmio_address_space.cc:55] MapMemory() page-aligned : device_address = 0x8000000000404000
I driver/device_buffer_mapper.cc:222] Mapped "prediction" : Buffer(ptr=0x2d16000) -> 0x8000000000404000, 968 bytes. Direction=2
I driver/single_tpu_request.cc:365] MapDataBuffers() done.
I driver/executable_util.cc:93] Linking map/TensorArrayStack/TensorArrayGatherV3[0]: 0x8000000000440a00
I driver/executable_util.cc:93] Linking prediction[0]: 0x8000000000404000
I driver/kernel/kernel_mmu_mapper.cc:135] MmuMapper#Map() : 0000000002d18000 -> 8000000000480000 (64 pages) flags=00000002.
I driver/memory/mmio_address_space.cc:55] MapMemory() page-aligned : device_address = 0x8000000000480000
I driver/kernel/kernel_mmu_mapper.cc:135] MmuMapper#Map() : 0000000002d59000 -> 8000000000408000 (3 pages) flags=00000002.
I driver/memory/mmio_address_space.cc:55] MapMemory() page-aligned : device_address = 0x8000000000408000
I driver/device_buffer_mapper.cc:222] Mapped "instructions" : Buffer(ptr=0x2d18000) -> 0x8000000000480000, 261920 bytes. Direction=1
I driver/device_buffer_mapper.cc:222] Mapped "instructions" : Buffer(ptr=0x2d59000) -> 0x8000000000408000, 10224 bytes. Direction=1
I driver/single_tpu_request.cc:381] MapInstructionBuffers() done.
I driver/single_tpu_request.cc:478] [1] SetState old=0, new=1.
I driver/kernel/linux/kernel_event_linux.cc:75] event_fd=7. Monitor thread got num_events=1.
I driver/single_tpu_request.cc:390] [1] NotifyRequestSubmitted()
I ./driver/mmio/host_queue.h:416] Completed 1 elements.
I driver/single_tpu_request.cc:478] [1] SetState old=1, new=2.
I driver/single_queue_dma_scheduler.cc:82] Request[1]: Submitted
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000485c8, value = 0x0000000000000000
I driver/single_tpu_request.cc:398] [1] NotifyRequestActive()
I driver/single_tpu_request.cc:478] [1] SetState old=2, new=3.
I driver/single_queue_dma_scheduler.cc:132] Request[1]: Scheduling DMA[0]
I ./driver/mmio/host_queue.h:383] Adding an element to the host queue.
I driver/single_queue_dma_scheduler.cc:154] Completing DMA[0]
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000485a8, value = 0x0000000000000002
I driver/single_queue_dma_scheduler.cc:132] Request[1]: Scheduling DMA[1]
I ./driver/mmio/host_queue.h:383] Adding an element to the host queue.
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000485a8, value = 0x0000000000000003
I driver/kernel/linux/kernel_event_linux.cc:75] event_fd=11. Monitor thread got num_events=1.
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000486a8, value = 0x000000000000000e
I driver/kernel/kernel_registers.cc:211] Read: offset = 0x00000000000486d0, value: = 0x0000000000000001
I driver/single_tpu_request.cc:410] [0] NotifyCompletion()
I driver/kernel/kernel_mmu_mapper.cc:171] MmuMaper#Unmap() : 0000000002d10000 -> 8000000000400000 (3 pages).
I driver/memory/mmio_address_space.cc:82] UnmapMemory() page-aligned : device_address = 0x8000000000400000, num_pages = 3
I driver/package_registry.cc:658] Returned instruction buffers back to executable reference
I driver/single_tpu_request.cc:478] [0] SetState old=3, new=4.
I driver/single_queue_dma_scheduler.cc:234] Request[0]: Completed
I driver/single_tpu_request.cc:96] [0] Request destroyed.
I driver/kernel/linux/kernel_event_linux.cc:75] event_fd=7. Monitor thread got num_events=1.
I ./driver/mmio/host_queue.h:416] Completed 1 elements.
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000485c8, value = 0x0000000000000000
I driver/single_queue_dma_scheduler.cc:154] Completing DMA[0]
I driver/kernel/linux/kernel_event_linux.cc:75] event_fd=7. Monitor thread got num_events=1.
I ./driver/mmio/host_queue.h:416] Completed 1 elements.
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000485c8, value = 0x0000000000000000
I driver/single_queue_dma_scheduler.cc:154] Completing DMA[1]
I driver/kernel/linux/kernel_event_linux.cc:75] event_fd=11. Monitor thread got num_events=1.
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000486a8, value = 0x000000000000000e
I driver/kernel/kernel_registers.cc:211] Read: offset = 0x00000000000486d0, value: = 0x0000000000000002
I driver/single_tpu_request.cc:410] [1] NotifyCompletion()
I driver/kernel/kernel_mmu_mapper.cc:171] MmuMaper#Unmap() : 0000000002d18000 -> 8000000000480000 (64 pages).
I driver/memory/mmio_address_space.cc:82] UnmapMemory() page-aligned : device_address = 0x8000000000480000, num_pages = 64
I driver/kernel/kernel_mmu_mapper.cc:171] MmuMaper#Unmap() : 0000000002d59000 -> 8000000000408000 (3 pages).
I driver/memory/mmio_address_space.cc:82] UnmapMemory() page-aligned : device_address = 0x8000000000408000, num_pages = 3
I driver/kernel/kernel_mmu_mapper.cc:171] MmuMaper#Unmap() : 0000000002cc5000 -> 8000000000440000 (38 pages).
I driver/memory/mmio_address_space.cc:82] UnmapMemory() page-aligned : device_address = 0x8000000000440000, num_pages = 38
I driver/kernel/kernel_mmu_mapper.cc:171] MmuMaper#Unmap() : 0000000002d16000 -> 8000000000404000 (1 pages).
I driver/memory/mmio_address_space.cc:82] UnmapMemory() page-aligned : device_address = 0x8000000000404000, num_pages = 1
I driver/package_registry.cc:658] Returned instruction buffers back to executable reference
I driver/single_tpu_request.cc:478] [1] SetState old=3, new=4.
I driver/single_queue_dma_scheduler.cc:234] Request[1]: Completed
I driver/single_tpu_request.cc:96] [1] Request destroyed.
151.0ms
I driver/request.cc:47] Adding input "map/TensorArrayStack/TensorArrayGatherV3" with 150528 bytes.
I driver/request.cc:58] Adding output "prediction" with 965 bytes.
I driver/request.cc:167] Request prepared, total batch size: 1, total TPU requests required: 1.
I driver/driver.cc:307] Request [1]: Submitting P0 request immediately.
I driver/single_tpu_request.cc:80] [2] Request constructed.
I driver/single_tpu_request.cc:113] Adding input "map/TensorArrayStack/TensorArrayGatherV3" with 150528 bytes.
I driver/single_tpu_request.cc:187] Adding output "prediction" with 965 bytes.
I driver/package_registry.cc:639] Reusing old instruction buffers.
I driver/device_buffer_mapper.cc:75] Mapped scratch : Buffer(ptr=(nil)) -> 0x0000000000000000, 0 bytes.
I driver/kernel/kernel_mmu_mapper.cc:135] MmuMapper#Map() : 0000000002cc5000 -> 8000000000400000 (38 pages) flags=00000002.
I driver/memory/mmio_address_space.cc:55] MapMemory() page-aligned : device_address = 0x8000000000400000
I driver/device_buffer_mapper.cc:222] Mapped "map/TensorArrayStack/TensorArrayGatherV3" : Buffer(ptr=0x2cc5a00) -> 0x8000000000400a00, 150528 bytes. Direction=1
I driver/kernel/kernel_mmu_mapper.cc:135] MmuMapper#Map() : 0000000002d5d000 -> 8000000000440000 (1 pages) flags=00000004.
I driver/memory/mmio_address_space.cc:55] MapMemory() page-aligned : device_address = 0x8000000000440000
I driver/device_buffer_mapper.cc:222] Mapped "prediction" : Buffer(ptr=0x2d5d000) -> 0x8000000000440000, 968 bytes. Direction=2
I driver/single_tpu_request.cc:365] MapDataBuffers() done.
I driver/executable_util.cc:93] Linking map/TensorArrayStack/TensorArrayGatherV3[0]: 0x8000000000400a00
I driver/executable_util.cc:93] Linking prediction[0]: 0x8000000000440000
I driver/kernel/kernel_mmu_mapper.cc:135] MmuMapper#Map() : 0000000002d18000 -> 8000000000480000 (64 pages) flags=00000002.
I driver/memory/mmio_address_space.cc:55] MapMemory() page-aligned : device_address = 0x8000000000480000
I driver/kernel/kernel_mmu_mapper.cc:135] MmuMapper#Map() : 0000000002d59000 -> 8000000000444000 (3 pages) flags=00000002.
I driver/memory/mmio_address_space.cc:55] MapMemory() page-aligned : device_address = 0x8000000000444000
I driver/device_buffer_mapper.cc:222] Mapped "instructions" : Buffer(ptr=0x2d18000) -> 0x8000000000480000, 261920 bytes. Direction=1
I driver/device_buffer_mapper.cc:222] Mapped "instructions" : Buffer(ptr=0x2d59000) -> 0x8000000000444000, 10224 bytes. Direction=1
I driver/single_tpu_request.cc:381] MapInstructionBuffers() done.
I driver/single_tpu_request.cc:478] [2] SetState old=0, new=1.
I driver/single_tpu_request.cc:390] [2] NotifyRequestSubmitted()
I driver/single_tpu_request.cc:478] [2] SetState old=1, new=2.
I driver/single_queue_dma_scheduler.cc:82] Request[2]: Submitted
I driver/single_tpu_request.cc:398] [2] NotifyRequestActive()
I driver/single_tpu_request.cc:478] [2] SetState old=2, new=3.
I driver/single_queue_dma_scheduler.cc:132] Request[2]: Scheduling DMA[0]
I ./driver/mmio/host_queue.h:383] Adding an element to the host queue.
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000485a8, value = 0x0000000000000004
I driver/single_queue_dma_scheduler.cc:132] Request[2]: Scheduling DMA[1]
I ./driver/mmio/host_queue.h:383] Adding an element to the host queue.
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000485a8, value = 0x0000000000000005
I driver/kernel/linux/kernel_event_linux.cc:75] event_fd=7. Monitor thread got num_events=1.
I ./driver/mmio/host_queue.h:416] Completed 1 elements.
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000485c8, value = 0x0000000000000000
I driver/single_queue_dma_scheduler.cc:154] Completing DMA[0]
I driver/kernel/linux/kernel_event_linux.cc:75] event_fd=7. Monitor thread got num_events=1.
I ./driver/mmio/host_queue.h:416] Completed 1 elements.
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000485c8, value = 0x0000000000000000
I driver/single_queue_dma_scheduler.cc:154] Completing DMA[1]
I driver/kernel/linux/kernel_event_linux.cc:75] event_fd=11. Monitor thread got num_events=1.
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000486a8, value = 0x000000000000000e
I driver/kernel/kernel_registers.cc:211] Read: offset = 0x00000000000486d0, value: = 0x0000000000000003
I driver/single_tpu_request.cc:410] [2] NotifyCompletion()
I driver/kernel/kernel_mmu_mapper.cc:171] MmuMaper#Unmap() : 0000000002d18000 -> 8000000000480000 (64 pages).
I driver/memory/mmio_address_space.cc:82] UnmapMemory() page-aligned : device_address = 0x8000000000480000, num_pages = 64
I driver/kernel/kernel_mmu_mapper.cc:171] MmuMaper#Unmap() : 0000000002d59000 -> 8000000000444000 (3 pages).
I driver/memory/mmio_address_space.cc:82] UnmapMemory() page-aligned : device_address = 0x8000000000444000, num_pages = 3
I driver/kernel/kernel_mmu_mapper.cc:171] MmuMaper#Unmap() : 0000000002cc5000 -> 8000000000400000 (38 pages).
I driver/memory/mmio_address_space.cc:82] UnmapMemory() page-aligned : device_address = 0x8000000000400000, num_pages = 38
I driver/kernel/kernel_mmu_mapper.cc:171] MmuMaper#Unmap() : 0000000002d5d000 -> 8000000000440000 (1 pages).
I driver/memory/mmio_address_space.cc:82] UnmapMemory() page-aligned : device_address = 0x8000000000440000, num_pages = 1
I driver/package_registry.cc:658] Returned instruction buffers back to executable reference
I driver/single_tpu_request.cc:478] [2] SetState old=3, new=4.
I driver/single_queue_dma_scheduler.cc:234] Request[2]: Completed
I driver/single_tpu_request.cc:96] [2] Request destroyed.
71.4ms
I driver/request.cc:47] Adding input "map/TensorArrayStack/TensorArrayGatherV3" with 150528 bytes.
I driver/request.cc:58] Adding output "prediction" with 965 bytes.
I driver/request.cc:167] Request prepared, total batch size: 1, total TPU requests required: 1.
I driver/driver.cc:307] Request [2]: Submitting P0 request immediately.
I driver/single_tpu_request.cc:80] [3] Request constructed.
I driver/single_tpu_request.cc:113] Adding input "map/TensorArrayStack/TensorArrayGatherV3" with 150528 bytes.
I driver/single_tpu_request.cc:187] Adding output "prediction" with 965 bytes.
I driver/package_registry.cc:639] Reusing old instruction buffers.
I driver/device_buffer_mapper.cc:75] Mapped scratch : Buffer(ptr=(nil)) -> 0x0000000000000000, 0 bytes.
I driver/kernel/kernel_mmu_mapper.cc:135] MmuMapper#Map() : 0000000002cc5000 -> 8000000000400000 (38 pages) flags=00000002.
I driver/memory/mmio_address_space.cc:55] MapMemory() page-aligned : device_address = 0x8000000000400000
I driver/device_buffer_mapper.cc:222] Mapped "map/TensorArrayStack/TensorArrayGatherV3" : Buffer(ptr=0x2cc5a00) -> 0x8000000000400a00, 150528 bytes. Direction=1
I driver/kernel/kernel_mmu_mapper.cc:135] MmuMapper#Map() : 0000000002d5d000 -> 8000000000440000 (1 pages) flags=00000004.
I driver/memory/mmio_address_space.cc:55] MapMemory() page-aligned : device_address = 0x8000000000440000
I driver/device_buffer_mapper.cc:222] Mapped "prediction" : Buffer(ptr=0x2d5d000) -> 0x8000000000440000, 968 bytes. Direction=2
I driver/single_tpu_request.cc:365] MapDataBuffers() done.
I driver/executable_util.cc:93] Linking map/TensorArrayStack/TensorArrayGatherV3[0]: 0x8000000000400a00
I driver/executable_util.cc:93] Linking prediction[0]: 0x8000000000440000
I driver/kernel/kernel_mmu_mapper.cc:135] MmuMapper#Map() : 0000000002d18000 -> 8000000000480000 (64 pages) flags=00000002.
I driver/memory/mmio_address_space.cc:55] MapMemory() page-aligned : device_address = 0x8000000000480000
I driver/kernel/kernel_mmu_mapper.cc:135] MmuMapper#Map() : 0000000002d59000 -> 8000000000444000 (3 pages) flags=00000002.
I driver/memory/mmio_address_space.cc:55] MapMemory() page-aligned : device_address = 0x8000000000444000
I driver/device_buffer_mapper.cc:222] Mapped "instructions" : Buffer(ptr=0x2d18000) -> 0x8000000000480000, 261920 bytes. Direction=1
I driver/device_buffer_mapper.cc:222] Mapped "instructions" : Buffer(ptr=0x2d59000) -> 0x8000000000444000, 10224 bytes. Direction=1
I driver/single_tpu_request.cc:381] MapInstructionBuffers() done.
I driver/single_tpu_request.cc:478] [3] SetState old=0, new=1.
I driver/single_tpu_request.cc:390] [3] NotifyRequestSubmitted()
I driver/single_tpu_request.cc:478] [3] SetState old=1, new=2.
I driver/single_queue_dma_scheduler.cc:82] Request[3]: Submitted
I driver/single_tpu_request.cc:398] [3] NotifyRequestActive()
I driver/single_tpu_request.cc:478] [3] SetState old=2, new=3.
I driver/single_queue_dma_scheduler.cc:132] Request[3]: Scheduling DMA[0]
I ./driver/mmio/host_queue.h:383] Adding an element to the host queue.
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000485a8, value = 0x0000000000000006
I driver/single_queue_dma_scheduler.cc:132] Request[3]: Scheduling DMA[1]
I ./driver/mmio/host_queue.h:383] Adding an element to the host queue.
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000485a8, value = 0x0000000000000007
I driver/kernel/linux/kernel_event_linux.cc:75] event_fd=7. Monitor thread got num_events=1.
I ./driver/mmio/host_queue.h:416] Completed 1 elements.
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000485c8, value = 0x0000000000000000
I driver/single_queue_dma_scheduler.cc:154] Completing DMA[0]
I driver/kernel/linux/kernel_event_linux.cc:75] event_fd=7. Monitor thread got num_events=1.
I ./driver/mmio/host_queue.h:416] Completed 1 elements.
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000485c8, value = 0x0000000000000000
I driver/single_queue_dma_scheduler.cc:154] Completing DMA[1]
I driver/kernel/linux/kernel_event_linux.cc:75] event_fd=11. Monitor thread got num_events=1.
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000486a8, value = 0x000000000000000e
I driver/kernel/kernel_registers.cc:211] Read: offset = 0x00000000000486d0, value: = 0x0000000000000004
I driver/single_tpu_request.cc:410] [3] NotifyCompletion()
I driver/kernel/kernel_mmu_mapper.cc:171] MmuMaper#Unmap() : 0000000002d18000 -> 8000000000480000 (64 pages).
I driver/memory/mmio_address_space.cc:82] UnmapMemory() page-aligned : device_address = 0x8000000000480000, num_pages = 64
I driver/kernel/kernel_mmu_mapper.cc:171] MmuMaper#Unmap() : 0000000002d59000 -> 8000000000444000 (3 pages).
I driver/memory/mmio_address_space.cc:82] UnmapMemory() page-aligned : device_address = 0x8000000000444000, num_pages = 3
I driver/kernel/kernel_mmu_mapper.cc:171] MmuMaper#Unmap() : 0000000002cc5000 -> 8000000000400000 (38 pages).
I driver/memory/mmio_address_space.cc:82] UnmapMemory() page-aligned : device_address = 0x8000000000400000, num_pages = 38
I driver/kernel/kernel_mmu_mapper.cc:171] MmuMaper#Unmap() : 0000000002d5d000 -> 8000000000440000 (1 pages).
I driver/memory/mmio_address_space.cc:82] UnmapMemory() page-aligned : device_address = 0x8000000000440000, num_pages = 1
I driver/package_registry.cc:658] Returned instruction buffers back to executable reference
I driver/single_tpu_request.cc:478] [3] SetState old=3, new=4.
I driver/single_queue_dma_scheduler.cc:234] Request[3]: Completed
I driver/single_tpu_request.cc:96] [3] Request destroyed.
71.3ms
I driver/request.cc:47] Adding input "map/TensorArrayStack/TensorArrayGatherV3" with 150528 bytes.
I driver/request.cc:58] Adding output "prediction" with 965 bytes.
I driver/request.cc:167] Request prepared, total batch size: 1, total TPU requests required: 1.
I driver/driver.cc:307] Request [3]: Submitting P0 request immediately.
I driver/single_tpu_request.cc:80] [4] Request constructed.
I driver/single_tpu_request.cc:113] Adding input "map/TensorArrayStack/TensorArrayGatherV3" with 150528 bytes.
I driver/single_tpu_request.cc:187] Adding output "prediction" with 965 bytes.
I driver/package_registry.cc:639] Reusing old instruction buffers.
I driver/device_buffer_mapper.cc:75] Mapped scratch : Buffer(ptr=(nil)) -> 0x0000000000000000, 0 bytes.
I driver/kernel/kernel_mmu_mapper.cc:135] MmuMapper#Map() : 0000000002cc5000 -> 8000000000400000 (38 pages) flags=00000002.
I driver/memory/mmio_address_space.cc:55] MapMemory() page-aligned : device_address = 0x8000000000400000
I driver/device_buffer_mapper.cc:222] Mapped "map/TensorArrayStack/TensorArrayGatherV3" : Buffer(ptr=0x2cc5a00) -> 0x8000000000400a00, 150528 bytes. Direction=1
I driver/kernel/kernel_mmu_mapper.cc:135] MmuMapper#Map() : 0000000002d5d000 -> 8000000000440000 (1 pages) flags=00000004.
I driver/memory/mmio_address_space.cc:55] MapMemory() page-aligned : device_address = 0x8000000000440000
I driver/device_buffer_mapper.cc:222] Mapped "prediction" : Buffer(ptr=0x2d5d000) -> 0x8000000000440000, 968 bytes. Direction=2
I driver/single_tpu_request.cc:365] MapDataBuffers() done.
I driver/executable_util.cc:93] Linking map/TensorArrayStack/TensorArrayGatherV3[0]: 0x8000000000400a00
I driver/executable_util.cc:93] Linking prediction[0]: 0x8000000000440000
I driver/kernel/kernel_mmu_mapper.cc:135] MmuMapper#Map() : 0000000002d18000 -> 8000000000480000 (64 pages) flags=00000002.
I driver/memory/mmio_address_space.cc:55] MapMemory() page-aligned : device_address = 0x8000000000480000
I driver/kernel/kernel_mmu_mapper.cc:135] MmuMapper#Map() : 0000000002d59000 -> 8000000000444000 (3 pages) flags=00000002.
I driver/memory/mmio_address_space.cc:55] MapMemory() page-aligned : device_address = 0x8000000000444000
I driver/device_buffer_mapper.cc:222] Mapped "instructions" : Buffer(ptr=0x2d18000) -> 0x8000000000480000, 261920 bytes. Direction=1
I driver/device_buffer_mapper.cc:222] Mapped "instructions" : Buffer(ptr=0x2d59000) -> 0x8000000000444000, 10224 bytes. Direction=1
I driver/single_tpu_request.cc:381] MapInstructionBuffers() done.
I driver/single_tpu_request.cc:478] [4] SetState old=0, new=1.
I driver/single_tpu_request.cc:390] [4] NotifyRequestSubmitted()
I driver/single_tpu_request.cc:478] [4] SetState old=1, new=2.
I driver/single_queue_dma_scheduler.cc:82] Request[4]: Submitted
I driver/single_tpu_request.cc:398] [4] NotifyRequestActive()
I driver/single_tpu_request.cc:478] [4] SetState old=2, new=3.
I driver/single_queue_dma_scheduler.cc:132] Request[4]: Scheduling DMA[0]
I ./driver/mmio/host_queue.h:383] Adding an element to the host queue.
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000485a8, value = 0x0000000000000008
I driver/single_queue_dma_scheduler.cc:132] Request[4]: Scheduling DMA[1]
I ./driver/mmio/host_queue.h:383] Adding an element to the host queue.
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000485a8, value = 0x0000000000000009
I driver/kernel/linux/kernel_event_linux.cc:75] event_fd=7. Monitor thread got num_events=1.
I ./driver/mmio/host_queue.h:416] Completed 1 elements.
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000485c8, value = 0x0000000000000000
I driver/single_queue_dma_scheduler.cc:154] Completing DMA[0]
I driver/kernel/linux/kernel_event_linux.cc:75] event_fd=7. Monitor thread got num_events=1.
I ./driver/mmio/host_queue.h:416] Completed 1 elements.
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000485c8, value = 0x0000000000000000
I driver/single_queue_dma_scheduler.cc:154] Completing DMA[1]
I driver/kernel/linux/kernel_event_linux.cc:75] event_fd=11. Monitor thread got num_events=1.
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000486a8, value = 0x000000000000000e
I driver/kernel/kernel_registers.cc:211] Read: offset = 0x00000000000486d0, value: = 0x0000000000000005
I driver/single_tpu_request.cc:410] [4] NotifyCompletion()
I driver/kernel/kernel_mmu_mapper.cc:171] MmuMaper#Unmap() : 0000000002d18000 -> 8000000000480000 (64 pages).
I driver/memory/mmio_address_space.cc:82] UnmapMemory() page-aligned : device_address = 0x8000000000480000, num_pages = 64
I driver/kernel/kernel_mmu_mapper.cc:171] MmuMaper#Unmap() : 0000000002d59000 -> 8000000000444000 (3 pages).
I driver/memory/mmio_address_space.cc:82] UnmapMemory() page-aligned : device_address = 0x8000000000444000, num_pages = 3
I driver/kernel/kernel_mmu_mapper.cc:171] MmuMaper#Unmap() : 0000000002cc5000 -> 8000000000400000 (38 pages).
I driver/memory/mmio_address_space.cc:82] UnmapMemory() page-aligned : device_address = 0x8000000000400000, num_pages = 38
I driver/kernel/kernel_mmu_mapper.cc:171] MmuMaper#Unmap() : 0000000002d5d000 -> 8000000000440000 (1 pages).
I driver/memory/mmio_address_space.cc:82] UnmapMemory() page-aligned : device_address = 0x8000000000440000, num_pages = 1
I driver/package_registry.cc:658] Returned instruction buffers back to executable reference
I driver/single_tpu_request.cc:478] [4] SetState old=3, new=4.
I driver/single_queue_dma_scheduler.cc:234] Request[4]: Completed
I driver/single_tpu_request.cc:96] [4] Request destroyed.
71.2ms
I driver/request.cc:47] Adding input "map/TensorArrayStack/TensorArrayGatherV3" with 150528 bytes.
I driver/request.cc:58] Adding output "prediction" with 965 bytes.
I driver/request.cc:167] Request prepared, total batch size: 1, total TPU requests required: 1.
I driver/driver.cc:307] Request [4]: Submitting P0 request immediately.
I driver/single_tpu_request.cc:80] [5] Request constructed.
I driver/single_tpu_request.cc:113] Adding input "map/TensorArrayStack/TensorArrayGatherV3" with 150528 bytes.
I driver/single_tpu_request.cc:187] Adding output "prediction" with 965 bytes.
I driver/package_registry.cc:639] Reusing old instruction buffers.
I driver/device_buffer_mapper.cc:75] Mapped scratch : Buffer(ptr=(nil)) -> 0x0000000000000000, 0 bytes.
I driver/kernel/kernel_mmu_mapper.cc:135] MmuMapper#Map() : 0000000002cc5000 -> 8000000000400000 (38 pages) flags=00000002.
I driver/memory/mmio_address_space.cc:55] MapMemory() page-aligned : device_address = 0x8000000000400000
I driver/device_buffer_mapper.cc:222] Mapped "map/TensorArrayStack/TensorArrayGatherV3" : Buffer(ptr=0x2cc5a00) -> 0x8000000000400a00, 150528 bytes. Direction=1
I driver/kernel/kernel_mmu_mapper.cc:135] MmuMapper#Map() : 0000000002d5d000 -> 8000000000440000 (1 pages) flags=00000004.
I driver/memory/mmio_address_space.cc:55] MapMemory() page-aligned : device_address = 0x8000000000440000
I driver/device_buffer_mapper.cc:222] Mapped "prediction" : Buffer(ptr=0x2d5d000) -> 0x8000000000440000, 968 bytes. Direction=2
I driver/single_tpu_request.cc:365] MapDataBuffers() done.
I driver/executable_util.cc:93] Linking map/TensorArrayStack/TensorArrayGatherV3[0]: 0x8000000000400a00
I driver/executable_util.cc:93] Linking prediction[0]: 0x8000000000440000
I driver/kernel/kernel_mmu_mapper.cc:135] MmuMapper#Map() : 0000000002d18000 -> 8000000000480000 (64 pages) flags=00000002.
I driver/memory/mmio_address_space.cc:55] MapMemory() page-aligned : device_address = 0x8000000000480000
I driver/kernel/kernel_mmu_mapper.cc:135] MmuMapper#Map() : 0000000002d59000 -> 8000000000444000 (3 pages) flags=00000002.
I driver/memory/mmio_address_space.cc:55] MapMemory() page-aligned : device_address = 0x8000000000444000
I driver/device_buffer_mapper.cc:222] Mapped "instructions" : Buffer(ptr=0x2d18000) -> 0x8000000000480000, 261920 bytes. Direction=1
I driver/device_buffer_mapper.cc:222] Mapped "instructions" : Buffer(ptr=0x2d59000) -> 0x8000000000444000, 10224 bytes. Direction=1
I driver/single_tpu_request.cc:381] MapInstructionBuffers() done.
I driver/single_tpu_request.cc:478] [5] SetState old=0, new=1.
I driver/single_tpu_request.cc:390] [5] NotifyRequestSubmitted()
I driver/single_tpu_request.cc:478] [5] SetState old=1, new=2.
I driver/single_queue_dma_scheduler.cc:82] Request[5]: Submitted
I driver/single_tpu_request.cc:398] [5] NotifyRequestActive()
I driver/single_tpu_request.cc:478] [5] SetState old=2, new=3.
I driver/single_queue_dma_scheduler.cc:132] Request[5]: Scheduling DMA[0]
I ./driver/mmio/host_queue.h:383] Adding an element to the host queue.
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000485a8, value = 0x000000000000000a
I driver/single_queue_dma_scheduler.cc:132] Request[5]: Scheduling DMA[1]
I ./driver/mmio/host_queue.h:383] Adding an element to the host queue.
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000485a8, value = 0x000000000000000b
I driver/kernel/linux/kernel_event_linux.cc:75] event_fd=7. Monitor thread got num_events=1.
I ./driver/mmio/host_queue.h:416] Completed 1 elements.
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000485c8, value = 0x0000000000000000
I driver/single_queue_dma_scheduler.cc:154] Completing DMA[0]
I driver/kernel/linux/kernel_event_linux.cc:75] event_fd=7. Monitor thread got num_events=1.
I ./driver/mmio/host_queue.h:416] Completed 1 elements.
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000485c8, value = 0x0000000000000000
I driver/single_queue_dma_scheduler.cc:154] Completing DMA[1]
I driver/kernel/linux/kernel_event_linux.cc:75] event_fd=11. Monitor thread got num_events=1.
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000486a8, value = 0x000000000000000e
I driver/kernel/kernel_registers.cc:211] Read: offset = 0x00000000000486d0, value: = 0x0000000000000006
I driver/single_tpu_request.cc:410] [5] NotifyCompletion()
I driver/kernel/kernel_mmu_mapper.cc:171] MmuMaper#Unmap() : 0000000002d18000 -> 8000000000480000 (64 pages).
I driver/memory/mmio_address_space.cc:82] UnmapMemory() page-aligned : device_address = 0x8000000000480000, num_pages = 64
I driver/kernel/kernel_mmu_mapper.cc:171] MmuMaper#Unmap() : 0000000002d59000 -> 8000000000444000 (3 pages).
I driver/memory/mmio_address_space.cc:82] UnmapMemory() page-aligned : device_address = 0x8000000000444000, num_pages = 3
I driver/kernel/kernel_mmu_mapper.cc:171] MmuMaper#Unmap() : 0000000002cc5000 -> 8000000000400000 (38 pages).
I driver/memory/mmio_address_space.cc:82] UnmapMemory() page-aligned : device_address = 0x8000000000400000, num_pages = 38
I driver/kernel/kernel_mmu_mapper.cc:171] MmuMaper#Unmap() : 0000000002d5d000 -> 8000000000440000 (1 pages).
I driver/memory/mmio_address_space.cc:82] UnmapMemory() page-aligned : device_address = 0x8000000000440000, num_pages = 1
I driver/package_registry.cc:658] Returned instruction buffers back to executable reference
I driver/single_tpu_request.cc:478] [5] SetState old=3, new=4.
I driver/single_queue_dma_scheduler.cc:234] Request[5]: Completed
I driver/single_tpu_request.cc:96] [5] Request destroyed.
71.1ms
-------RESULTS--------
Ara macao (Scarlet Macaw): 0.75781
I driver/kernel/kernel_mmu_mapper.cc:171] MmuMaper#Unmap() : 00007f27983eb000 -> 8000000000000000 (964 pages).
I driver/memory/mmio_address_space.cc:82] UnmapMemory() page-aligned : device_address = 0x8000000000000000, num_pages = 964
I driver/instruction_buffers.cc:51] InstructionBuffers destroyed.
I driver/instruction_buffers.cc:51] InstructionBuffers destroyed.
I tflite/edgetpu_manager_direct.cc:226] Releasing Edge TPU device at /dev/apex_0
I tflite/edgetpu_context_direct.cc:180] Closing Edge TPU device at /dev/apex_0
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000486d8, value = 0x0000000000000001
I driver/kernel/kernel_registers.cc:211] Read: offset = 0x00000000000486e0, value: = 0x0000000000000001
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x0000000000044018, value = 0x0000000000000002
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x0000000000044158, value = 0x0000000000000002
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x0000000000044198, value = 0x0000000000000002
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000441d8, value = 0x0000000000000002
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x0000000000044218, value = 0x0000000000000002
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x0000000000048788, value = 0x000000000000007f
I driver/kernel/kernel_registers.cc:211] Read: offset = 0x0000000000048788, value: = 0x000000000000007f
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000400c0, value = 0x0000000000000002
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x0000000000040150, value = 0x0000000000000002
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x0000000000040110, value = 0x0000000000000002
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x0000000000040250, value = 0x0000000000000002
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x0000000000040298, value = 0x0000000000000002
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000402e0, value = 0x0000000000000002
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x0000000000040328, value = 0x0000000000000002
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x0000000000040190, value = 0x0000000000000002
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000401d0, value = 0x0000000000000002
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x0000000000040210, value = 0x0000000000000002
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000486c0, value = 0x0000000000000000
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000485c0, value = 0x0000000000000000
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000486a0, value = 0x0000000000000000
I driver/kernel/linux/kernel_event_linux.cc:75] event_fd=7. Monitor thread got num_events=1.
I driver/kernel/linux/kernel_event_linux.cc:85] event_fd=7. Monitor thread exit.
I driver/kernel/linux/kernel_event_linux.cc:75] event_fd=11. Monitor thread got num_events=1.
I driver/kernel/linux/kernel_event_linux.cc:85] event_fd=11. Monitor thread exit.
I driver/kernel/linux/kernel_event_linux.cc:75] event_fd=12. Monitor thread got num_events=1.
I driver/kernel/linux/kernel_event_linux.cc:85] event_fd=12. Monitor thread exit.
I driver/kernel/linux/kernel_event_linux.cc:75] event_fd=13. Monitor thread got num_events=1.
I driver/kernel/linux/kernel_event_linux.cc:85] event_fd=13. Monitor thread exit.
I driver/kernel/linux/kernel_event_linux.cc:75] event_fd=14. Monitor thread got num_events=1.
I driver/kernel/linux/kernel_event_linux.cc:85] event_fd=14. Monitor thread exit.
I driver/kernel/linux/kernel_event_linux.cc:75] event_fd=15. Monitor thread got num_events=1.
I driver/kernel/linux/kernel_event_linux.cc:85] event_fd=15. Monitor thread exit.
I driver/kernel/linux/kernel_event_linux.cc:75] event_fd=16. Monitor thread got num_events=1.
I driver/kernel/linux/kernel_event_linux.cc:85] event_fd=16. Monitor thread exit.
I driver/kernel/linux/kernel_event_linux.cc:75] event_fd=17. Monitor thread got num_events=1.
I driver/kernel/linux/kernel_event_linux.cc:85] event_fd=17. Monitor thread exit.
I driver/kernel/linux/kernel_event_linux.cc:75] event_fd=18. Monitor thread got num_events=1.
I driver/kernel/linux/kernel_event_linux.cc:85] event_fd=18. Monitor thread exit.
I driver/kernel/linux/kernel_event_linux.cc:75] event_fd=19. Monitor thread got num_events=1.
I driver/kernel/linux/kernel_event_linux.cc:85] event_fd=19. Monitor thread exit.
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x0000000000048568, value = 0x0000000000000000
I driver/kernel/kernel_registers.cc:211] Read: offset = 0x0000000000048570, value: = 0x0000000000000000
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000485a8, value = 0x0000000000000000
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x0000000000048590, value = 0x0000000000000000
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x0000000000048598, value = 0x0000000000000000
I driver/kernel/kernel_mmu_mapper.cc:171] MmuMaper#Unmap() : 00007f27a1c1d000 -> 0000000001000000 (1 pages).
I driver/memory/mmio_address_space.cc:82] UnmapMemory() page-aligned : device_address = 0x0000000001000000, num_pages = 1
I driver/kernel/kernel_mmu_mapper.cc:171] MmuMaper#Unmap() : 00007f27a1c1e000 -> 0000000001001000 (1 pages).
I driver/memory/mmio_address_space.cc:82] UnmapMemory() page-aligned : device_address = 0x0000000001001000, num_pages = 1
I driver/kernel/kernel_registers.cc:122] Closing /dev/apex_0. mmap_offset=0x0000000000040000, mmap_size=4096, read_only=0
I driver/kernel/kernel_registers.cc:122] Closing /dev/apex_0. mmap_offset=0x0000000000044000, mmap_size=4096, read_only=0
I driver/kernel/kernel_registers.cc:122] Closing /dev/apex_0. mmap_offset=0x0000000000048000, mmap_size=4096, read_only=0

Nov 10 '21 18:11 brilthor

It seems coral hardware does not support your motherboard, you might face the same issue with replacement also.

Can you please try the demo by changing this line to

case 1: interpreter = make_interpreter(*args.model.split('@'), device='pci:0') case 2: interpreter = make_interpreter(*args.model.split('@'), device='pci:1')

Nov 10 '21 22:11 hjonnala

Added and run, output is below: (pci:0 had the same performance, pci:1 had a traceback)

Expand for the outputs

`pci:0`

~/tmp/pycoral$ python3 examples/classify_image.py --model test_data/mobilenet_v2_1.0_224_inat_bird_quant_edgetpu.tflite --labels test_data/inat_bird_labels.txt --input test_data/inat_bird_labels.txt --input test_data/parrot.jpg
I driver/usb/local_usb_device.cc:944] EnumerateDevices: vendor:0x1a6e, product:0x89a
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[1] port[0]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[3] port[0]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[3]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[12]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[3]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[2]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[1]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[11]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[0]
I driver/usb/local_usb_device.cc:944] EnumerateDevices: vendor:0x18d1, product:0x9302
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[1] port[0]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[3] port[0]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[3]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[12]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[3]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[2]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[1]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[11]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[0]
I tflite/edgetpu_manager_direct.cc:453] No matching device is already opened for shared ownership.
I driver/usb/local_usb_device.cc:944] EnumerateDevices: vendor:0x1a6e, product:0x89a
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[1] port[0]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[3] port[0]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[3]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[12]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[3]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[2]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[1]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[11]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[0]
I driver/usb/local_usb_device.cc:944] EnumerateDevices: vendor:0x18d1, product:0x9302
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[1] port[0]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[3] port[0]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[3]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[12]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[3]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[2]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[1]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[11]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[0]
I tflite/edgetpu_context_direct.cc:106] USB always DFU: False (default)
I tflite/edgetpu_context_direct.cc:128] USB bulk-in queue capacity: default
I tflite/edgetpu_context_direct.cc:67] Performance expectation: Max (default)
I ./driver/mmio/host_queue.h:266] Starting in normal mode
I driver/kernel/kernel_registers.cc:83] Opening /dev/apex_0. read_only=0
I driver/kernel/kernel_registers.cc:97] mmap_offset=0x0000000000040000, mmap_size=4096
I driver/kernel/kernel_registers.cc:108] Got map addr at 0x0x7f2577f07000
I driver/kernel/kernel_registers.cc:97] mmap_offset=0x0000000000044000, mmap_size=4096
I driver/kernel/kernel_registers.cc:108] Got map addr at 0x0x7f2577f06000
I driver/kernel/kernel_registers.cc:97] mmap_offset=0x0000000000048000, mmap_size=4096
I driver/kernel/kernel_registers.cc:108] Got map addr at 0x0x7f2577440000
I driver/kernel/kernel_registers.cc:211] Read: offset = 0x00000000000486f0, value: = 0x0000000000000000
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000487a8, value = 0x0000000000000000
I driver/kernel/kernel_registers.cc:211] Read: offset = 0x0000000000048578, value: = 0x0000000000000010
I driver/kernel/kernel_mmu_mapper.cc:135] MmuMapper#Map() : 00007f25742ef000 -> 0000000001000000 (1 pages) flags=00000000.
I driver/memory/mmio_address_space.cc:55] MapMemory() page-aligned : device_address = 0x0000000001000000
I ./driver/mmio/host_queue.h:162] Queue base : 0x7f25742ef000 -> 0x0000000001000000 [4096 bytes]
I driver/kernel/kernel_mmu_mapper.cc:135] MmuMapper#Map() : 00007f25742f0000 -> 0000000001001000 (1 pages) flags=00000000.
I driver/memory/mmio_address_space.cc:55] MapMemory() page-aligned : device_address = 0x0000000001001000
I ./driver/mmio/host_queue.h:172] Queue status block : 0x7f25742f0000 -> 0x0000000001001000 [16 bytes]
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x0000000000048590, value = 0x0000000001000000
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x0000000000048598, value = 0x0000000001001000
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000485a0, value = 0x0000000000000100
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x0000000000048568, value = 0x0000000000000005
I driver/kernel/kernel_registers.cc:211] Read: offset = 0x0000000000048570, value: = 0x0000000000000001
I driver/kernel/kernel_registers.cc:211] Read: offset = 0x00000000000486d0, value: = 0x0000000000000000
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x0000000000044018, value = 0x0000000000000001
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x0000000000044158, value = 0x0000000000000001
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x0000000000044198, value = 0x0000000000000001
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000441d8, value = 0x0000000000000001
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x0000000000044218, value = 0x0000000000000001
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x0000000000048788, value = 0x000000000000007f
I driver/kernel/kernel_registers.cc:211] Read: offset = 0x0000000000048788, value: = 0x000000000000007f
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000400c0, value = 0x0000000000000001
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x0000000000040150, value = 0x0000000000000001
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x0000000000040110, value = 0x0000000000000001
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x0000000000040250, value = 0x0000000000000001
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x0000000000040298, value = 0x0000000000000001
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000402e0, value = 0x0000000000000001
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x0000000000040328, value = 0x0000000000000001
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x0000000000040190, value = 0x0000000000000001
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000401d0, value = 0x0000000000000001
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x0000000000040210, value = 0x0000000000000001
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000486e8, value = 0x0000000000000000
I driver/kernel/linux/kernel_event_handler_linux.cc:45] Set event fd : event_id:0 -> event_fd:7, 
I driver/kernel/linux/kernel_event_handler_linux.cc:45] Set event fd : event_id:4 -> event_fd:11, 
I driver/kernel/linux/kernel_event_handler_linux.cc:45] Set event fd : event_id:5 -> event_fd:12, 
I driver/kernel/linux/kernel_event_linux.cc:62] event_fd=7. Monitor thread begin.
I driver/kernel/linux/kernel_event_handler_linux.cc:45] Set event fd : event_id:6 -> event_fd:13, 
I driver/kernel/linux/kernel_event_linux.cc:62] event_fd=11. Monitor thread begin.
I driver/kernel/linux/kernel_event_handler_linux.cc:45] Set event fd : event_id:7 -> event_fd:14, 
I driver/kernel/linux/kernel_event_linux.cc:62] event_fd=12. Monitor thread begin.
I driver/kernel/linux/kernel_event_handler_linux.cc:45] Set event fd : event_id:8 -> event_fd:15, 
I driver/kernel/linux/kernel_event_linux.cc:62] event_fd=13. Monitor thread begin.
I driver/kernel/linux/kernel_event_handler_linux.cc:45] Set event fd : event_id:9 -> event_fd:16, 
I driver/kernel/linux/kernel_event_linux.cc:62] event_fd=14. Monitor thread begin.
I driver/kernel/linux/kernel_event_handler_linux.cc:45] Set event fd : event_id:10 -> event_fd:17, 
I driver/kernel/linux/kernel_event_linux.cc:62] event_fd=15. Monitor thread begin.
I driver/kernel/linux/kernel_event_handler_linux.cc:45] Set event fd : event_id:11 -> event_fd:18, 
I driver/kernel/linux/kernel_event_linux.cc:62] event_fd=16. Monitor thread begin.
I driver/kernel/linux/kernel_event_linux.cc:62] event_fd=17. Monitor thread begin.
I driver/kernel/linux/kernel_event_handler_linux.cc:45] Set event fd : event_id:12 -> event_fd:19, 
I driver/kernel/linux/kernel_event_linux.cc:62] event_fd=18. Monitor thread begin.
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000486a0, value = 0x000000000000000f
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000485c0, value = 0x0000000000000001
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000486c0, value = 0x0000000000000001
I driver/kernel/linux/kernel_event_linux.cc:62] event_fd=19. Monitor thread begin.
I tflite/edgetpu_context_direct.cc:174] Opening device at /dev/apex_0
----INFERENCE TIME----
Note: The first inference on Edge TPU is slow because it includes loading the model into Edge TPU memory.
I driver/request.cc:47] Adding input "map/TensorArrayStack/TensorArrayGatherV3" with 150528 bytes.
I driver/request.cc:58] Adding output "prediction" with 965 bytes.
I driver/request.cc:167] Request prepared, total batch size: 1, total TPU requests required: 1.
I driver/driver.cc:307] Request [0]: Submitting P0 request immediately.
I driver/driver.cc:369] Request [0]: Need to map parameters.
I driver/kernel/kernel_mmu_mapper.cc:135] MmuMapper#Map() : 00007f25597d4000 -> 8000000000000000 (964 pages) flags=00000002.
I driver/memory/mmio_address_space.cc:55] MapMemory() page-aligned : device_address = 0x8000000000000000
I driver/driver.cc:249] Mapped params : Buffer(ptr=0x7f25597d4000) -> 0x8000000000000000, 3947392 bytes.
I driver/driver.cc:249] Mapped params : Buffer(ptr=(nil)) -> 0x0000000000000000, 0 bytes.
I driver/driver.cc:383] Request [0]: Need to do parameter-caching.
I driver/single_tpu_request.cc:80] [0] Request constructed.
I driver/instruction_buffers.cc:46] InstructionBuffers created.
I driver/package_registry.cc:647] Created new instruction buffers.
I driver/device_buffer_mapper.cc:75] Mapped scratch : Buffer(ptr=(nil)) -> 0x0000000000000000, 0 bytes.
I driver/single_tpu_request.cc:365] MapDataBuffers() done.
I driver/executable_util.cc:187] Linking Parameter: 0x8000000000000000
I driver/kernel/kernel_mmu_mapper.cc:135] MmuMapper#Map() : 0000000002e02000 -> 8000000000400000 (3 pages) flags=00000002.
I driver/memory/mmio_address_space.cc:55] MapMemory() page-aligned : device_address = 0x8000000000400000
I driver/device_buffer_mapper.cc:222] Mapped "instructions" : Buffer(ptr=0x2e02000) -> 0x8000000000400000, 10064 bytes. Direction=1
I driver/single_tpu_request.cc:381] MapInstructionBuffers() done.
I driver/single_tpu_request.cc:478] [0] SetState old=0, new=1.
I driver/single_tpu_request.cc:390] [0] NotifyRequestSubmitted()
I driver/single_tpu_request.cc:478] [0] SetState old=1, new=2.
I driver/single_queue_dma_scheduler.cc:82] Request[0]: Submitted
I driver/single_tpu_request.cc:398] [0] NotifyRequestActive()
I driver/single_tpu_request.cc:478] [0] SetState old=2, new=3.
I driver/single_queue_dma_scheduler.cc:132] Request[0]: Scheduling DMA[0]
I ./driver/mmio/host_queue.h:383] Adding an element to the host queue.
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000485a8, value = 0x0000000000000001
I driver/single_tpu_request.cc:80] [1] Request constructed.
I driver/single_tpu_request.cc:113] Adding input "map/TensorArrayStack/TensorArrayGatherV3" with 150528 bytes.
I driver/single_tpu_request.cc:187] Adding output "prediction" with 965 bytes.
I driver/instruction_buffers.cc:46] InstructionBuffers created.
I driver/package_registry.cc:647] Created new instruction buffers.
I driver/device_buffer_mapper.cc:75] Mapped scratch : Buffer(ptr=(nil)) -> 0x0000000000000000, 0 bytes.
I driver/kernel/kernel_mmu_mapper.cc:135] MmuMapper#Map() : 0000000002dba000 -> 8000000000440000 (38 pages) flags=00000002.
I driver/memory/mmio_address_space.cc:55] MapMemory() page-aligned : device_address = 0x8000000000440000
I driver/device_buffer_mapper.cc:222] Mapped "map/TensorArrayStack/TensorArrayGatherV3" : Buffer(ptr=0x2dbac80) -> 0x8000000000440c80, 150528 bytes. Direction=1
I driver/kernel/kernel_mmu_mapper.cc:135] MmuMapper#Map() : 0000000002e08000 -> 8000000000404000 (1 pages) flags=00000004.
I driver/memory/mmio_address_space.cc:55] MapMemory() page-aligned : device_address = 0x8000000000404000
I driver/device_buffer_mapper.cc:222] Mapped "prediction" : Buffer(ptr=0x2e08000) -> 0x8000000000404000, 968 bytes. Direction=2
I driver/single_tpu_request.cc:365] MapDataBuffers() done.
I driver/executable_util.cc:93] Linking map/TensorArrayStack/TensorArrayGatherV3[0]: 0x8000000000440c80
I driver/executable_util.cc:93] Linking prediction[0]: 0x8000000000404000
I driver/kernel/kernel_mmu_mapper.cc:135] MmuMapper#Map() : 0000000002e0a000 -> 8000000000480000 (64 pages) flags=00000002.
I driver/memory/mmio_address_space.cc:55] MapMemory() page-aligned : device_address = 0x8000000000480000
I driver/kernel/kernel_mmu_mapper.cc:135] MmuMapper#Map() : 0000000002e4b000 -> 8000000000408000 (3 pages) flags=00000002.
I driver/memory/mmio_address_space.cc:55] MapMemory() page-aligned : device_address = 0x8000000000408000
I driver/device_buffer_mapper.cc:222] Mapped "instructions" : Buffer(ptr=0x2e0a000) -> 0x8000000000480000, 261920 bytes. Direction=1
I driver/device_buffer_mapper.cc:222] Mapped "instructions" : Buffer(ptr=0x2e4b000) -> 0x8000000000408000, 10224 bytes. Direction=1
I driver/single_tpu_request.cc:381] MapInstructionBuffers() done.
I driver/single_tpu_request.cc:478] [1] SetState old=0, new=1.
I driver/single_tpu_request.cc:390] [1] NotifyRequestSubmitted()
I driver/single_tpu_request.cc:478] [1] SetState old=1, new=2.
I driver/single_queue_dma_scheduler.cc:82] Request[1]: Submitted
I driver/single_tpu_request.cc:398] [1] NotifyRequestActive()
I driver/single_tpu_request.cc:478] [1] SetState old=2, new=3.
I driver/single_queue_dma_scheduler.cc:132] Request[1]: Scheduling DMA[0]
I ./driver/mmio/host_queue.h:383] Adding an element to the host queue.
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000485a8, value = 0x0000000000000002
I driver/single_queue_dma_scheduler.cc:132] Request[1]: Scheduling DMA[1]
I ./driver/mmio/host_queue.h:383] Adding an element to the host queue.
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000485a8, value = 0x0000000000000003
I driver/kernel/linux/kernel_event_linux.cc:75] event_fd=7. Monitor thread got num_events=1.
I ./driver/mmio/host_queue.h:416] Completed 1 elements.
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000485c8, value = 0x0000000000000000
I driver/single_queue_dma_scheduler.cc:154] Completing DMA[0]
I driver/kernel/linux/kernel_event_linux.cc:75] event_fd=11. Monitor thread got num_events=1.
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000486a8, value = 0x000000000000000e
I driver/kernel/kernel_registers.cc:211] Read: offset = 0x00000000000486d0, value: = 0x0000000000000001
I driver/single_tpu_request.cc:410] [0] NotifyCompletion()
I driver/kernel/kernel_mmu_mapper.cc:171] MmuMaper#Unmap() : 0000000002e02000 -> 8000000000400000 (3 pages).
I driver/memory/mmio_address_space.cc:82] UnmapMemory() page-aligned : device_address = 0x8000000000400000, num_pages = 3
I driver/package_registry.cc:658] Returned instruction buffers back to executable reference
I driver/single_tpu_request.cc:478] [0] SetState old=3, new=4.
I driver/single_queue_dma_scheduler.cc:234] Request[0]: Completed
I driver/single_tpu_request.cc:96] [0] Request destroyed.
I driver/kernel/linux/kernel_event_linux.cc:75] event_fd=7. Monitor thread got num_events=1.
I ./driver/mmio/host_queue.h:416] Completed 1 elements.
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000485c8, value = 0x0000000000000000
I driver/single_queue_dma_scheduler.cc:154] Completing DMA[0]
I driver/kernel/linux/kernel_event_linux.cc:75] event_fd=7. Monitor thread got num_events=1.
I ./driver/mmio/host_queue.h:416] Completed 1 elements.
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000485c8, value = 0x0000000000000000
I driver/single_queue_dma_scheduler.cc:154] Completing DMA[1]
I driver/kernel/linux/kernel_event_linux.cc:75] event_fd=11. Monitor thread got num_events=1.
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000486a8, value = 0x000000000000000e
I driver/kernel/kernel_registers.cc:211] Read: offset = 0x00000000000486d0, value: = 0x0000000000000002
I driver/single_tpu_request.cc:410] [1] NotifyCompletion()
I driver/kernel/kernel_mmu_mapper.cc:171] MmuMaper#Unmap() : 0000000002e0a000 -> 8000000000480000 (64 pages).
I driver/memory/mmio_address_space.cc:82] UnmapMemory() page-aligned : device_address = 0x8000000000480000, num_pages = 64
I driver/kernel/kernel_mmu_mapper.cc:171] MmuMaper#Unmap() : 0000000002e4b000 -> 8000000000408000 (3 pages).
I driver/memory/mmio_address_space.cc:82] UnmapMemory() page-aligned : device_address = 0x8000000000408000, num_pages = 3
I driver/kernel/kernel_mmu_mapper.cc:171] MmuMaper#Unmap() : 0000000002dba000 -> 8000000000440000 (38 pages).
I driver/memory/mmio_address_space.cc:82] UnmapMemory() page-aligned : device_address = 0x8000000000440000, num_pages = 38
I driver/kernel/kernel_mmu_mapper.cc:171] MmuMaper#Unmap() : 0000000002e08000 -> 8000000000404000 (1 pages).
I driver/memory/mmio_address_space.cc:82] UnmapMemory() page-aligned : device_address = 0x8000000000404000, num_pages = 1
I driver/package_registry.cc:658] Returned instruction buffers back to executable reference
I driver/single_tpu_request.cc:478] [1] SetState old=3, new=4.
I driver/single_queue_dma_scheduler.cc:234] Request[1]: Completed
I driver/single_tpu_request.cc:96] [1] Request destroyed.
150.9ms
I driver/request.cc:47] Adding input "map/TensorArrayStack/TensorArrayGatherV3" with 150528 bytes.
I driver/request.cc:58] Adding output "prediction" with 965 bytes.
I driver/request.cc:167] Request prepared, total batch size: 1, total TPU requests required: 1.
I driver/driver.cc:307] Request [1]: Submitting P0 request immediately.
I driver/single_tpu_request.cc:80] [2] Request constructed.
I driver/single_tpu_request.cc:113] Adding input "map/TensorArrayStack/TensorArrayGatherV3" with 150528 bytes.
I driver/single_tpu_request.cc:187] Adding output "prediction" with 965 bytes.
I driver/package_registry.cc:639] Reusing old instruction buffers.
I driver/device_buffer_mapper.cc:75] Mapped scratch : Buffer(ptr=(nil)) -> 0x0000000000000000, 0 bytes.
I driver/kernel/kernel_mmu_mapper.cc:135] MmuMapper#Map() : 0000000002dba000 -> 8000000000400000 (38 pages) flags=00000002.
I driver/memory/mmio_address_space.cc:55] MapMemory() page-aligned : device_address = 0x8000000000400000
I driver/device_buffer_mapper.cc:222] Mapped "map/TensorArrayStack/TensorArrayGatherV3" : Buffer(ptr=0x2dbac80) -> 0x8000000000400c80, 150528 bytes. Direction=1
I driver/kernel/kernel_mmu_mapper.cc:135] MmuMapper#Map() : 0000000002e4f000 -> 8000000000440000 (1 pages) flags=00000004.
I driver/memory/mmio_address_space.cc:55] MapMemory() page-aligned : device_address = 0x8000000000440000
I driver/device_buffer_mapper.cc:222] Mapped "prediction" : Buffer(ptr=0x2e4f000) -> 0x8000000000440000, 968 bytes. Direction=2
I driver/single_tpu_request.cc:365] MapDataBuffers() done.
I driver/executable_util.cc:93] Linking map/TensorArrayStack/TensorArrayGatherV3[0]: 0x8000000000400c80
I driver/executable_util.cc:93] Linking prediction[0]: 0x8000000000440000
I driver/kernel/kernel_mmu_mapper.cc:135] MmuMapper#Map() : 0000000002e0a000 -> 8000000000480000 (64 pages) flags=00000002.
I driver/memory/mmio_address_space.cc:55] MapMemory() page-aligned : device_address = 0x8000000000480000
I driver/kernel/kernel_mmu_mapper.cc:135] MmuMapper#Map() : 0000000002e4b000 -> 8000000000444000 (3 pages) flags=00000002.
I driver/memory/mmio_address_space.cc:55] MapMemory() page-aligned : device_address = 0x8000000000444000
I driver/device_buffer_mapper.cc:222] Mapped "instructions" : Buffer(ptr=0x2e0a000) -> 0x8000000000480000, 261920 bytes. Direction=1
I driver/device_buffer_mapper.cc:222] Mapped "instructions" : Buffer(ptr=0x2e4b000) -> 0x8000000000444000, 10224 bytes. Direction=1
I driver/single_tpu_request.cc:381] MapInstructionBuffers() done.
I driver/single_tpu_request.cc:478] [2] SetState old=0, new=1.
I driver/single_tpu_request.cc:390] [2] NotifyRequestSubmitted()
I driver/single_tpu_request.cc:478] [2] SetState old=1, new=2.
I driver/single_queue_dma_scheduler.cc:82] Request[2]: Submitted
I driver/single_tpu_request.cc:398] [2] NotifyRequestActive()
I driver/single_tpu_request.cc:478] [2] SetState old=2, new=3.
I driver/single_queue_dma_scheduler.cc:132] Request[2]: Scheduling DMA[0]
I ./driver/mmio/host_queue.h:383] Adding an element to the host queue.
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000485a8, value = 0x0000000000000004
I driver/single_queue_dma_scheduler.cc:132] Request[2]: Scheduling DMA[1]
I ./driver/mmio/host_queue.h:383] Adding an element to the host queue.
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000485a8, value = 0x0000000000000005
I driver/kernel/linux/kernel_event_linux.cc:75] event_fd=7. Monitor thread got num_events=1.
I ./driver/mmio/host_queue.h:416] Completed 1 elements.
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000485c8, value = 0x0000000000000000
I driver/single_queue_dma_scheduler.cc:154] Completing DMA[0]
I driver/kernel/linux/kernel_event_linux.cc:75] event_fd=7. Monitor thread got num_events=1.
I ./driver/mmio/host_queue.h:416] Completed 1 elements.
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000485c8, value = 0x0000000000000000
I driver/single_queue_dma_scheduler.cc:154] Completing DMA[1]
I driver/kernel/linux/kernel_event_linux.cc:75] event_fd=11. Monitor thread got num_events=1.
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000486a8, value = 0x000000000000000e
I driver/kernel/kernel_registers.cc:211] Read: offset = 0x00000000000486d0, value: = 0x0000000000000003
I driver/single_tpu_request.cc:410] [2] NotifyCompletion()
I driver/kernel/kernel_mmu_mapper.cc:171] MmuMaper#Unmap() : 0000000002e0a000 -> 8000000000480000 (64 pages).
I driver/memory/mmio_address_space.cc:82] UnmapMemory() page-aligned : device_address = 0x8000000000480000, num_pages = 64
I driver/kernel/kernel_mmu_mapper.cc:171] MmuMaper#Unmap() : 0000000002e4b000 -> 8000000000444000 (3 pages).
I driver/memory/mmio_address_space.cc:82] UnmapMemory() page-aligned : device_address = 0x8000000000444000, num_pages = 3
I driver/kernel/kernel_mmu_mapper.cc:171] MmuMaper#Unmap() : 0000000002dba000 -> 8000000000400000 (38 pages).
I driver/memory/mmio_address_space.cc:82] UnmapMemory() page-aligned : device_address = 0x8000000000400000, num_pages = 38
I driver/kernel/kernel_mmu_mapper.cc:171] MmuMaper#Unmap() : 0000000002e4f000 -> 8000000000440000 (1 pages).
I driver/memory/mmio_address_space.cc:82] UnmapMemory() page-aligned : device_address = 0x8000000000440000, num_pages = 1
I driver/package_registry.cc:658] Returned instruction buffers back to executable reference
I driver/single_tpu_request.cc:478] [2] SetState old=3, new=4.
I driver/single_queue_dma_scheduler.cc:234] Request[2]: Completed
I driver/single_tpu_request.cc:96] [2] Request destroyed.
71.4ms
I driver/request.cc:47] Adding input "map/TensorArrayStack/TensorArrayGatherV3" with 150528 bytes.
I driver/request.cc:58] Adding output "prediction" with 965 bytes.
I driver/request.cc:167] Request prepared, total batch size: 1, total TPU requests required: 1.
I driver/driver.cc:307] Request [2]: Submitting P0 request immediately.
I driver/single_tpu_request.cc:80] [3] Request constructed.
I driver/single_tpu_request.cc:113] Adding input "map/TensorArrayStack/TensorArrayGatherV3" with 150528 bytes.
I driver/single_tpu_request.cc:187] Adding output "prediction" with 965 bytes.
I driver/package_registry.cc:639] Reusing old instruction buffers.
I driver/device_buffer_mapper.cc:75] Mapped scratch : Buffer(ptr=(nil)) -> 0x0000000000000000, 0 bytes.
I driver/kernel/kernel_mmu_mapper.cc:135] MmuMapper#Map() : 0000000002dba000 -> 8000000000400000 (38 pages) flags=00000002.
I driver/memory/mmio_address_space.cc:55] MapMemory() page-aligned : device_address = 0x8000000000400000
I driver/device_buffer_mapper.cc:222] Mapped "map/TensorArrayStack/TensorArrayGatherV3" : Buffer(ptr=0x2dbac80) -> 0x8000000000400c80, 150528 bytes. Direction=1
I driver/kernel/kernel_mmu_mapper.cc:135] MmuMapper#Map() : 0000000002e51000 -> 8000000000440000 (1 pages) flags=00000004.
I driver/memory/mmio_address_space.cc:55] MapMemory() page-aligned : device_address = 0x8000000000440000
I driver/device_buffer_mapper.cc:222] Mapped "prediction" : Buffer(ptr=0x2e51000) -> 0x8000000000440000, 968 bytes. Direction=2
I driver/single_tpu_request.cc:365] MapDataBuffers() done.
I driver/executable_util.cc:93] Linking map/TensorArrayStack/TensorArrayGatherV3[0]: 0x8000000000400c80
I driver/executable_util.cc:93] Linking prediction[0]: 0x8000000000440000
I driver/kernel/kernel_mmu_mapper.cc:135] MmuMapper#Map() : 0000000002e0a000 -> 8000000000480000 (64 pages) flags=00000002.
I driver/memory/mmio_address_space.cc:55] MapMemory() page-aligned : device_address = 0x8000000000480000
I driver/kernel/kernel_mmu_mapper.cc:135] MmuMapper#Map() : 0000000002e4b000 -> 8000000000444000 (3 pages) flags=00000002.
I driver/memory/mmio_address_space.cc:55] MapMemory() page-aligned : device_address = 0x8000000000444000
I driver/device_buffer_mapper.cc:222] Mapped "instructions" : Buffer(ptr=0x2e0a000) -> 0x8000000000480000, 261920 bytes. Direction=1
I driver/device_buffer_mapper.cc:222] Mapped "instructions" : Buffer(ptr=0x2e4b000) -> 0x8000000000444000, 10224 bytes. Direction=1
I driver/single_tpu_request.cc:381] MapInstructionBuffers() done.
I driver/single_tpu_request.cc:478] [3] SetState old=0, new=1.
I driver/single_tpu_request.cc:390] [3] NotifyRequestSubmitted()
I driver/single_tpu_request.cc:478] [3] SetState old=1, new=2.
I driver/single_queue_dma_scheduler.cc:82] Request[3]: Submitted
I driver/single_tpu_request.cc:398] [3] NotifyRequestActive()
I driver/single_tpu_request.cc:478] [3] SetState old=2, new=3.
I driver/single_queue_dma_scheduler.cc:132] Request[3]: Scheduling DMA[0]
I ./driver/mmio/host_queue.h:383] Adding an element to the host queue.
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000485a8, value = 0x0000000000000006
I driver/single_queue_dma_scheduler.cc:132] Request[3]: Scheduling DMA[1]
I ./driver/mmio/host_queue.h:383] Adding an element to the host queue.
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000485a8, value = 0x0000000000000007
I driver/kernel/linux/kernel_event_linux.cc:75] event_fd=7. Monitor thread got num_events=1.
I ./driver/mmio/host_queue.h:416] Completed 1 elements.
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000485c8, value = 0x0000000000000000
I driver/single_queue_dma_scheduler.cc:154] Completing DMA[0]
I driver/kernel/linux/kernel_event_linux.cc:75] event_fd=7. Monitor thread got num_events=1.
I ./driver/mmio/host_queue.h:416] Completed 1 elements.
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000485c8, value = 0x0000000000000000
I driver/single_queue_dma_scheduler.cc:154] Completing DMA[1]
I driver/kernel/linux/kernel_event_linux.cc:75] event_fd=11. Monitor thread got num_events=1.
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000486a8, value = 0x000000000000000e
I driver/kernel/kernel_registers.cc:211] Read: offset = 0x00000000000486d0, value: = 0x0000000000000004
I driver/single_tpu_request.cc:410] [3] NotifyCompletion()
I driver/kernel/kernel_mmu_mapper.cc:171] MmuMaper#Unmap() : 0000000002e0a000 -> 8000000000480000 (64 pages).
I driver/memory/mmio_address_space.cc:82] UnmapMemory() page-aligned : device_address = 0x8000000000480000, num_pages = 64
I driver/kernel/kernel_mmu_mapper.cc:171] MmuMaper#Unmap() : 0000000002e4b000 -> 8000000000444000 (3 pages).
I driver/memory/mmio_address_space.cc:82] UnmapMemory() page-aligned : device_address = 0x8000000000444000, num_pages = 3
I driver/kernel/kernel_mmu_mapper.cc:171] MmuMaper#Unmap() : 0000000002dba000 -> 8000000000400000 (38 pages).
I driver/memory/mmio_address_space.cc:82] UnmapMemory() page-aligned : device_address = 0x8000000000400000, num_pages = 38
I driver/kernel/kernel_mmu_mapper.cc:171] MmuMaper#Unmap() : 0000000002e51000 -> 8000000000440000 (1 pages).
I driver/memory/mmio_address_space.cc:82] UnmapMemory() page-aligned : device_address = 0x8000000000440000, num_pages = 1
I driver/package_registry.cc:658] Returned instruction buffers back to executable reference
I driver/single_tpu_request.cc:478] [3] SetState old=3, new=4.
I driver/single_queue_dma_scheduler.cc:234] Request[3]: Completed
I driver/single_tpu_request.cc:96] [3] Request destroyed.
71.7ms
I driver/request.cc:47] Adding input "map/TensorArrayStack/TensorArrayGatherV3" with 150528 bytes.
I driver/request.cc:58] Adding output "prediction" with 965 bytes.
I driver/request.cc:167] Request prepared, total batch size: 1, total TPU requests required: 1.
I driver/driver.cc:307] Request [3]: Submitting P0 request immediately.
I driver/single_tpu_request.cc:80] [4] Request constructed.
I driver/single_tpu_request.cc:113] Adding input "map/TensorArrayStack/TensorArrayGatherV3" with 150528 bytes.
I driver/single_tpu_request.cc:187] Adding output "prediction" with 965 bytes.
I driver/package_registry.cc:639] Reusing old instruction buffers.
I driver/device_buffer_mapper.cc:75] Mapped scratch : Buffer(ptr=(nil)) -> 0x0000000000000000, 0 bytes.
I driver/kernel/kernel_mmu_mapper.cc:135] MmuMapper#Map() : 0000000002dba000 -> 8000000000400000 (38 pages) flags=00000002.
I driver/memory/mmio_address_space.cc:55] MapMemory() page-aligned : device_address = 0x8000000000400000
I driver/device_buffer_mapper.cc:222] Mapped "map/TensorArrayStack/TensorArrayGatherV3" : Buffer(ptr=0x2dbac80) -> 0x8000000000400c80, 150528 bytes. Direction=1
I driver/kernel/kernel_mmu_mapper.cc:135] MmuMapper#Map() : 0000000002e53000 -> 8000000000440000 (1 pages) flags=00000004.
I driver/memory/mmio_address_space.cc:55] MapMemory() page-aligned : device_address = 0x8000000000440000
I driver/device_buffer_mapper.cc:222] Mapped "prediction" : Buffer(ptr=0x2e53000) -> 0x8000000000440000, 968 bytes. Direction=2
I driver/single_tpu_request.cc:365] MapDataBuffers() done.
I driver/executable_util.cc:93] Linking map/TensorArrayStack/TensorArrayGatherV3[0]: 0x8000000000400c80
I driver/executable_util.cc:93] Linking prediction[0]: 0x8000000000440000
I driver/kernel/kernel_mmu_mapper.cc:135] MmuMapper#Map() : 0000000002e0a000 -> 8000000000480000 (64 pages) flags=00000002.
I driver/memory/mmio_address_space.cc:55] MapMemory() page-aligned : device_address = 0x8000000000480000
I driver/kernel/kernel_mmu_mapper.cc:135] MmuMapper#Map() : 0000000002e4b000 -> 8000000000444000 (3 pages) flags=00000002.
I driver/memory/mmio_address_space.cc:55] MapMemory() page-aligned : device_address = 0x8000000000444000
I driver/device_buffer_mapper.cc:222] Mapped "instructions" : Buffer(ptr=0x2e0a000) -> 0x8000000000480000, 261920 bytes. Direction=1
I driver/device_buffer_mapper.cc:222] Mapped "instructions" : Buffer(ptr=0x2e4b000) -> 0x8000000000444000, 10224 bytes. Direction=1
I driver/single_tpu_request.cc:381] MapInstructionBuffers() done.
I driver/single_tpu_request.cc:478] [4] SetState old=0, new=1.
I driver/single_tpu_request.cc:390] [4] NotifyRequestSubmitted()
I driver/single_tpu_request.cc:478] [4] SetState old=1, new=2.
I driver/single_queue_dma_scheduler.cc:82] Request[4]: Submitted
I driver/single_tpu_request.cc:398] [4] NotifyRequestActive()
I driver/single_tpu_request.cc:478] [4] SetState old=2, new=3.
I driver/single_queue_dma_scheduler.cc:132] Request[4]: Scheduling DMA[0]
I ./driver/mmio/host_queue.h:383] Adding an element to the host queue.
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000485a8, value = 0x0000000000000008
I driver/single_queue_dma_scheduler.cc:132] Request[4]: Scheduling DMA[1]
I ./driver/mmio/host_queue.h:383] Adding an element to the host queue.
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000485a8, value = 0x0000000000000009
I driver/kernel/linux/kernel_event_linux.cc:75] event_fd=7. Monitor thread got num_events=1.
I ./driver/mmio/host_queue.h:416] Completed 1 elements.
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000485c8, value = 0x0000000000000000
I driver/single_queue_dma_scheduler.cc:154] Completing DMA[0]
I driver/kernel/linux/kernel_event_linux.cc:75] event_fd=7. Monitor thread got num_events=1.
I ./driver/mmio/host_queue.h:416] Completed 1 elements.
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000485c8, value = 0x0000000000000000
I driver/single_queue_dma_scheduler.cc:154] Completing DMA[1]
I driver/kernel/linux/kernel_event_linux.cc:75] event_fd=11. Monitor thread got num_events=1.
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000486a8, value = 0x000000000000000e
I driver/kernel/kernel_registers.cc:211] Read: offset = 0x00000000000486d0, value: = 0x0000000000000005
I driver/single_tpu_request.cc:410] [4] NotifyCompletion()
I driver/kernel/kernel_mmu_mapper.cc:171] MmuMaper#Unmap() : 0000000002e0a000 -> 8000000000480000 (64 pages).
I driver/memory/mmio_address_space.cc:82] UnmapMemory() page-aligned : device_address = 0x8000000000480000, num_pages = 64
I driver/kernel/kernel_mmu_mapper.cc:171] MmuMaper#Unmap() : 0000000002e4b000 -> 8000000000444000 (3 pages).
I driver/memory/mmio_address_space.cc:82] UnmapMemory() page-aligned : device_address = 0x8000000000444000, num_pages = 3
I driver/kernel/kernel_mmu_mapper.cc:171] MmuMaper#Unmap() : 0000000002dba000 -> 8000000000400000 (38 pages).
I driver/memory/mmio_address_space.cc:82] UnmapMemory() page-aligned : device_address = 0x8000000000400000, num_pages = 38
I driver/kernel/kernel_mmu_mapper.cc:171] MmuMaper#Unmap() : 0000000002e53000 -> 8000000000440000 (1 pages).
I driver/memory/mmio_address_space.cc:82] UnmapMemory() page-aligned : device_address = 0x8000000000440000, num_pages = 1
I driver/package_registry.cc:658] Returned instruction buffers back to executable reference
I driver/single_tpu_request.cc:478] [4] SetState old=3, new=4.
I driver/single_queue_dma_scheduler.cc:234] Request[4]: Completed
I driver/single_tpu_request.cc:96] [4] Request destroyed.
71.5ms
I driver/request.cc:47] Adding input "map/TensorArrayStack/TensorArrayGatherV3" with 150528 bytes.
I driver/request.cc:58] Adding output "prediction" with 965 bytes.
I driver/request.cc:167] Request prepared, total batch size: 1, total TPU requests required: 1.
I driver/driver.cc:307] Request [4]: Submitting P0 request immediately.
I driver/single_tpu_request.cc:80] [5] Request constructed.
I driver/single_tpu_request.cc:113] Adding input "map/TensorArrayStack/TensorArrayGatherV3" with 150528 bytes.
I driver/single_tpu_request.cc:187] Adding output "prediction" with 965 bytes.
I driver/package_registry.cc:639] Reusing old instruction buffers.
I driver/device_buffer_mapper.cc:75] Mapped scratch : Buffer(ptr=(nil)) -> 0x0000000000000000, 0 bytes.
I driver/kernel/kernel_mmu_mapper.cc:135] MmuMapper#Map() : 0000000002dba000 -> 8000000000400000 (38 pages) flags=00000002.
I driver/memory/mmio_address_space.cc:55] MapMemory() page-aligned : device_address = 0x8000000000400000
I driver/device_buffer_mapper.cc:222] Mapped "map/TensorArrayStack/TensorArrayGatherV3" : Buffer(ptr=0x2dbac80) -> 0x8000000000400c80, 150528 bytes. Direction=1
I driver/kernel/kernel_mmu_mapper.cc:135] MmuMapper#Map() : 0000000002e53000 -> 8000000000440000 (1 pages) flags=00000004.
I driver/memory/mmio_address_space.cc:55] MapMemory() page-aligned : device_address = 0x8000000000440000
I driver/device_buffer_mapper.cc:222] Mapped "prediction" : Buffer(ptr=0x2e53000) -> 0x8000000000440000, 968 bytes. Direction=2
I driver/single_tpu_request.cc:365] MapDataBuffers() done.
I driver/executable_util.cc:93] Linking map/TensorArrayStack/TensorArrayGatherV3[0]: 0x8000000000400c80
I driver/executable_util.cc:93] Linking prediction[0]: 0x8000000000440000
I driver/kernel/kernel_mmu_mapper.cc:135] MmuMapper#Map() : 0000000002e0a000 -> 8000000000480000 (64 pages) flags=00000002.
I driver/memory/mmio_address_space.cc:55] MapMemory() page-aligned : device_address = 0x8000000000480000
I driver/kernel/kernel_mmu_mapper.cc:135] MmuMapper#Map() : 0000000002e4b000 -> 8000000000444000 (3 pages) flags=00000002.
I driver/memory/mmio_address_space.cc:55] MapMemory() page-aligned : device_address = 0x8000000000444000
I driver/device_buffer_mapper.cc:222] Mapped "instructions" : Buffer(ptr=0x2e0a000) -> 0x8000000000480000, 261920 bytes. Direction=1
I driver/device_buffer_mapper.cc:222] Mapped "instructions" : Buffer(ptr=0x2e4b000) -> 0x8000000000444000, 10224 bytes. Direction=1
I driver/single_tpu_request.cc:381] MapInstructionBuffers() done.
I driver/single_tpu_request.cc:478] [5] SetState old=0, new=1.
I driver/single_tpu_request.cc:390] [5] NotifyRequestSubmitted()
I driver/single_tpu_request.cc:478] [5] SetState old=1, new=2.
I driver/single_queue_dma_scheduler.cc:82] Request[5]: Submitted
I driver/single_tpu_request.cc:398] [5] NotifyRequestActive()
I driver/single_tpu_request.cc:478] [5] SetState old=2, new=3.
I driver/single_queue_dma_scheduler.cc:132] Request[5]: Scheduling DMA[0]
I ./driver/mmio/host_queue.h:383] Adding an element to the host queue.
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000485a8, value = 0x000000000000000a
I driver/single_queue_dma_scheduler.cc:132] Request[5]: Scheduling DMA[1]
I ./driver/mmio/host_queue.h:383] Adding an element to the host queue.
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000485a8, value = 0x000000000000000b
I driver/kernel/linux/kernel_event_linux.cc:75] event_fd=7. Monitor thread got num_events=1.
I ./driver/mmio/host_queue.h:416] Completed 1 elements.
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000485c8, value = 0x0000000000000000
I driver/single_queue_dma_scheduler.cc:154] Completing DMA[0]
I driver/kernel/linux/kernel_event_linux.cc:75] event_fd=7. Monitor thread got num_events=1.
I ./driver/mmio/host_queue.h:416] Completed 1 elements.
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000485c8, value = 0x0000000000000000
I driver/single_queue_dma_scheduler.cc:154] Completing DMA[1]
I driver/kernel/linux/kernel_event_linux.cc:75] event_fd=11. Monitor thread got num_events=1.
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000486a8, value = 0x000000000000000e
I driver/kernel/kernel_registers.cc:211] Read: offset = 0x00000000000486d0, value: = 0x0000000000000006
I driver/single_tpu_request.cc:410] [5] NotifyCompletion()
I driver/kernel/kernel_mmu_mapper.cc:171] MmuMaper#Unmap() : 0000000002e0a000 -> 8000000000480000 (64 pages).
I driver/memory/mmio_address_space.cc:82] UnmapMemory() page-aligned : device_address = 0x8000000000480000, num_pages = 64
I driver/kernel/kernel_mmu_mapper.cc:171] MmuMaper#Unmap() : 0000000002e4b000 -> 8000000000444000 (3 pages).
I driver/memory/mmio_address_space.cc:82] UnmapMemory() page-aligned : device_address = 0x8000000000444000, num_pages = 3
I driver/kernel/kernel_mmu_mapper.cc:171] MmuMaper#Unmap() : 0000000002dba000 -> 8000000000400000 (38 pages).
I driver/memory/mmio_address_space.cc:82] UnmapMemory() page-aligned : device_address = 0x8000000000400000, num_pages = 38
I driver/kernel/kernel_mmu_mapper.cc:171] MmuMaper#Unmap() : 0000000002e53000 -> 8000000000440000 (1 pages).
I driver/memory/mmio_address_space.cc:82] UnmapMemory() page-aligned : device_address = 0x8000000000440000, num_pages = 1
I driver/package_registry.cc:658] Returned instruction buffers back to executable reference
I driver/single_tpu_request.cc:478] [5] SetState old=3, new=4.
I driver/single_queue_dma_scheduler.cc:234] Request[5]: Completed
I driver/single_tpu_request.cc:96] [5] Request destroyed.
71.3ms
-------RESULTS--------
Ara macao (Scarlet Macaw): 0.75781
I driver/kernel/kernel_mmu_mapper.cc:171] MmuMaper#Unmap() : 00007f25597d4000 -> 8000000000000000 (964 pages).
I driver/memory/mmio_address_space.cc:82] UnmapMemory() page-aligned : device_address = 0x8000000000000000, num_pages = 964
I driver/instruction_buffers.cc:51] InstructionBuffers destroyed.
I driver/instruction_buffers.cc:51] InstructionBuffers destroyed.
I tflite/edgetpu_manager_direct.cc:226] Releasing Edge TPU device at /dev/apex_0
I tflite/edgetpu_context_direct.cc:180] Closing Edge TPU device at /dev/apex_0
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000486d8, value = 0x0000000000000001
I driver/kernel/kernel_registers.cc:211] Read: offset = 0x00000000000486e0, value: = 0x0000000000000001
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x0000000000044018, value = 0x0000000000000002
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x0000000000044158, value = 0x0000000000000002
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x0000000000044198, value = 0x0000000000000002
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000441d8, value = 0x0000000000000002
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x0000000000044218, value = 0x0000000000000002
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x0000000000048788, value = 0x000000000000007f
I driver/kernel/kernel_registers.cc:211] Read: offset = 0x0000000000048788, value: = 0x000000000000007f
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000400c0, value = 0x0000000000000002
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x0000000000040150, value = 0x0000000000000002
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x0000000000040110, value = 0x0000000000000002
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x0000000000040250, value = 0x0000000000000002
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x0000000000040298, value = 0x0000000000000002
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000402e0, value = 0x0000000000000002
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x0000000000040328, value = 0x0000000000000002
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x0000000000040190, value = 0x0000000000000002
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000401d0, value = 0x0000000000000002
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x0000000000040210, value = 0x0000000000000002
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000486c0, value = 0x0000000000000000
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000485c0, value = 0x0000000000000000
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000486a0, value = 0x0000000000000000
I driver/kernel/linux/kernel_event_linux.cc:75] event_fd=7. Monitor thread got num_events=1.
I driver/kernel/linux/kernel_event_linux.cc:85] event_fd=7. Monitor thread exit.
I driver/kernel/linux/kernel_event_linux.cc:75] event_fd=11. Monitor thread got num_events=1.
I driver/kernel/linux/kernel_event_linux.cc:85] event_fd=11. Monitor thread exit.
I driver/kernel/linux/kernel_event_linux.cc:75] event_fd=12. Monitor thread got num_events=1.
I driver/kernel/linux/kernel_event_linux.cc:85] event_fd=12. Monitor thread exit.
I driver/kernel/linux/kernel_event_linux.cc:75] event_fd=13. Monitor thread got num_events=1.
I driver/kernel/linux/kernel_event_linux.cc:85] event_fd=13. Monitor thread exit.
I driver/kernel/linux/kernel_event_linux.cc:75] event_fd=14. Monitor thread got num_events=1.
I driver/kernel/linux/kernel_event_linux.cc:85] event_fd=14. Monitor thread exit.
I driver/kernel/linux/kernel_event_linux.cc:75] event_fd=15. Monitor thread got num_events=1.
I driver/kernel/linux/kernel_event_linux.cc:85] event_fd=15. Monitor thread exit.
I driver/kernel/linux/kernel_event_linux.cc:75] event_fd=16. Monitor thread got num_events=1.
I driver/kernel/linux/kernel_event_linux.cc:85] event_fd=16. Monitor thread exit.
I driver/kernel/linux/kernel_event_linux.cc:75] event_fd=17. Monitor thread got num_events=1.
I driver/kernel/linux/kernel_event_linux.cc:85] event_fd=17. Monitor thread exit.
I driver/kernel/linux/kernel_event_linux.cc:75] event_fd=18. Monitor thread got num_events=1.
I driver/kernel/linux/kernel_event_linux.cc:85] event_fd=18. Monitor thread exit.
I driver/kernel/linux/kernel_event_linux.cc:75] event_fd=19. Monitor thread got num_events=1.
I driver/kernel/linux/kernel_event_linux.cc:85] event_fd=19. Monitor thread exit.
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x0000000000048568, value = 0x0000000000000000
I driver/kernel/kernel_registers.cc:211] Read: offset = 0x0000000000048570, value: = 0x0000000000000000
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000485a8, value = 0x0000000000000000
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x0000000000048590, value = 0x0000000000000000
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x0000000000048598, value = 0x0000000000000000
I driver/kernel/kernel_mmu_mapper.cc:171] MmuMaper#Unmap() : 00007f25742ef000 -> 0000000001000000 (1 pages).
I driver/memory/mmio_address_space.cc:82] UnmapMemory() page-aligned : device_address = 0x0000000001000000, num_pages = 1
I driver/kernel/kernel_mmu_mapper.cc:171] MmuMaper#Unmap() : 00007f25742f0000 -> 0000000001001000 (1 pages).
I driver/memory/mmio_address_space.cc:82] UnmapMemory() page-aligned : device_address = 0x0000000001001000, num_pages = 1
I driver/kernel/kernel_registers.cc:122] Closing /dev/apex_0. mmap_offset=0x0000000000040000, mmap_size=4096, read_only=0
I driver/kernel/kernel_registers.cc:122] Closing /dev/apex_0. mmap_offset=0x0000000000044000, mmap_size=4096, read_only=0
I driver/kernel/kernel_registers.cc:122] Closing /dev/apex_0. mmap_offset=0x0000000000048000, mmap_size=4096, read_only=0

`pci:1`

~/tmp/pycoral$ python3 examples/classify_image.py --model test_data/mobilenet_v2_1.0_224_inat_bird_quant_edgetpu.tflite --labels test_data/inat_bird_labels.txt --input test_data/inat_bird_labels.txt --input test_data/parrot.jpg
I driver/usb/local_usb_device.cc:944] EnumerateDevices: vendor:0x1a6e, product:0x89a
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[1] port[0]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[3] port[0]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[3]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[12]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[3]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[2]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[1]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[11]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[0]
I driver/usb/local_usb_device.cc:944] EnumerateDevices: vendor:0x18d1, product:0x9302
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[1] port[0]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[3] port[0]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[3]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[12]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[3]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[2]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[1]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[11]
I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[0]
Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/tflite_runtime/interpreter.py", line 160, in load_delegate
    delegate = Delegate(library, options)
  File "/usr/lib/python3/dist-packages/tflite_runtime/interpreter.py", line 119, in __init__
    raise ValueError(capture.message)
ValueError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "examples/classify_image.py", line 125, in <module>
    main()
  File "examples/classify_image.py", line 75, in main
    interpreter = make_interpreter(*args.model.split('@'), device='pci:1')
  File "/usr/lib/python3/dist-packages/pycoral/utils/edgetpu.py", line 87, in make_interpreter
    delegates = [load_edgetpu_delegate({'device': device} if device else {})]
  File "/usr/lib/python3/dist-packages/pycoral/utils/edgetpu.py", line 52, in load_edgetpu_delegate
    return tflite.load_delegate(_EDGETPU_SHARED_LIB, options or {})
  File "/usr/lib/python3/dist-packages/tflite_runtime/interpreter.py", line 162, in load_delegate
    raise ValueError('Failed to load delegate from {}\n{}'.format(
ValueError: Failed to load delegate from libedgetpu.so.1

Nov 10 '21 23:11 brilthor

It looks only one tpu got detected. can you please share the output of below snippet.

root@root ~# python3
Python 3.7.3 (default, Jan 22 2021, 20:04:44) 
[GCC 8.3.0] on linux
Type "help", "copyright", "credits" or "license" for more information.
>>> from pycoral.pybind._pywrap_coral import ListEdgeTpus as list_edge_tpus
>>> list_edge_tpus()
[{'type': 'pci', 'path': '/dev/apex_0'}]

Nov 10 '21 23:11 hjonnala

python3 examples/scratch.py 
[{'path': '/dev/apex_0', 'type': 'pci'}]

~/tmp/pycoral$ cat examples/scratch.py 
import pprint
from pycoral.pybind._pywrap_coral import ListEdgeTpus as list_edge_tpus

pprint.pprint(list_edge_tpus())

Nov 10 '21 23:11 brilthor

yes, Only one tpu got detected with the motherboard and there is some data transfer issue with the mother board and coral hardware which is causing high latency.

Nov 10 '21 23:11 hjonnala

I could live with 1 tpu if the inference speed was as expected, any idea for where to start digging to root out the high latency?

Nov 10 '21 23:11 brilthor

can you try to run this c++ code

hemanth@glaptop:~/libcoral/out/k8/benchmarks/coral$ ./single_model_benchmark -model ../../../../test_data/mobilenet_v2_1.0_224_inat_bird_quant_edgetpu.tflite
2021-11-10 16:14:00
Running ./single_model_benchmark
Run on (4 X 3900 MHz CPU s)
CPU Caches:
  L1 Data 32K (x2)
  L1 Instruction 32K (x2)
  L2 Unified 256K (x2)
  L3 Unified 4096K (x1)
Load Average: 0.45, 0.61, 0.62
***WARNING*** CPU scaling is enabled, the benchmark real time measurements may be noisy and will incur extra overhead.
-----------------------------------------------------
Benchmark           Time             CPU   Iterations
-----------------------------------------------------
BM_Model         11.9 ms        0.241 ms         1000 mobilenet_v2_1.0_224_inat_bird_quant_edgetpu.tflite

Nov 11 '21 00:11 hjonnala

~/tmp/pycoral$ ./single_model_benchmark --model test_data/mobilenet_v2_1.0_224_inat_bird_quant_edgetpu.tflite 
2021-11-10 20:23:59
Running ./single_model_benchmark
Run on (48 X 2900 MHz CPU s)
CPU Caches:
  L1 Data 32K (x24)
  L1 Instruction 32K (x24)
  L2 Unified 256K (x24)
  L3 Unified 30720K (x2)
Load Average: 15.30, 18.19, 18.41
***WARNING*** CPU scaling is enabled, the benchmark real time measurements may be noisy and will incur extra overhead.
-----------------------------------------------------
Benchmark           Time             CPU   Iterations
-----------------------------------------------------
BM_Model         71.8 ms        0.281 ms          100 mobilenet_v2_1.0_224_inat_bird_quant_edgetpu.tflite

Nov 11 '21 01:11 brilthor

I am not sure of exact thing that causing high latency. I am working with USB accelerator. The difference I can see the number of DMAs scheduled. you can find the relevant code here: https://github.com/google-coral/libedgetpu/blob/master/driver/single_queue_dma_scheduler.cc#L132

M.2 Dual EDGE TPU

I driver/single_queue_dma_scheduler.cc:132] Request[1]: Scheduling DMA[0]
I ./driver/mmio/host_queue.h:383] Adding an element to the host queue.
I driver/kernel/kernel_registers.cc:190] Write: offset = 0x00000000000485a8, value = 0x0000000000000002
I driver/single_queue_dma_scheduler.cc:132] Request[1]: Scheduling DMA[1]

USB accelerator:

I driver/single_queue_dma_scheduler.cc:132] Request[1]: Scheduling DMA[0]
I driver/single_queue_dma_scheduler.cc:132] Request[1]: Scheduling DMA[1]
I driver/single_queue_dma_scheduler.cc:132] Request[1]: Scheduling DMA[2]
I driver/single_queue_dma_scheduler.cc:132] Request[1]: Scheduling DMA[3]
I driver/single_queue_dma_scheduler.cc:132] Request[1]: Scheduling DMA[4]

python3 examples/classify_image.py --model test_data/mobilenet_v2_1.0_224_inat_bird_quant_edgetpu.tflite --labels test_data/inat_bird_labels.txt --input test_data/parrot.jpg -c 1 I driver/driver_factory_default.cc:31] Failed to open /sys/class/apex: No such file or directory I driver/usb/local_usb_device.cc:944] EnumerateDevices: vendor:0x1a6e, product:0x89a I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[4] port[0] I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[3] port[1] I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[3] port[0] I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[1] I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[0] I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[1] port[9] I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[1] port[8] I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[1] port[7] I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[1] port[2] I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[1] port[0] I driver/usb/local_usb_device.cc:944] EnumerateDevices: vendor:0x18d1, product:0x9302 I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[4] port[0] I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[3] port[1] I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[3] port[0] I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[1] I driver/usb/local_usb_device.cc:998] EnumerateDevices: found [/sys/bus/usb/devices/2-1] I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[0] I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[1] port[9] I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[1] port[8] I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[1] port[7] I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[1] port[2] I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[1] port[0] I driver/beagle/beagle_usb_driver_provider.cc:225] Enumerate: adding path [/sys/bus/usb/devices/2-1] I tflite/edgetpu_manager_direct.cc:453] No matching device is already opened for shared ownership. I driver/driver_factory_default.cc:31] Failed to open /sys/class/apex: No such file or directory I driver/usb/local_usb_device.cc:944] EnumerateDevices: vendor:0x1a6e, product:0x89a I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[4] port[0] I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[3] port[1] I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[3] port[0] I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[1] I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[0] I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[1] port[9] I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[1] port[8] I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[1] port[7] I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[1] port[2] I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[1] port[0] I driver/usb/local_usb_device.cc:944] EnumerateDevices: vendor:0x18d1, product:0x9302 I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[4] port[0] I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[3] port[1] I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[3] port[0] I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[1] I driver/usb/local_usb_device.cc:998] EnumerateDevices: found [/sys/bus/usb/devices/2-1] I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[2] port[0] I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[1] port[9] I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[1] port[8] I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[1] port[7] I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[1] port[2] I driver/usb/local_usb_device.cc:979] EnumerateDevices: checking bus[1] port[0] I driver/beagle/beagle_usb_driver_provider.cc:225] Enumerate: adding path [/sys/bus/usb/devices/2-1] I tflite/edgetpu_context_direct.cc:106] USB always DFU: False (default) I tflite/edgetpu_context_direct.cc:147] USB bulk-in queue capacity: 8 I tflite/edgetpu_context_direct.cc:67] Performance expectation: Max (default) I driver/usb/usb_driver.cc:1383] Open device and check if DFU is needed I driver/usb/local_usb_device.cc:1013] OpenDevice: [/sys/bus/usb/devices/2-1] I driver/usb/local_usb_device.cc:1050] OpenDevice: checking bus[4] port[0] I driver/usb/local_usb_device.cc:1050] OpenDevice: checking bus[3] port[1] I driver/usb/local_usb_device.cc:1050] OpenDevice: checking bus[3] port[0] I driver/usb/local_usb_device.cc:1050] OpenDevice: checking bus[2] port[1] I driver/usb/local_usb_device.cc:1081] OpenDevice: device opened 0x1da6210 I driver/usb/local_usb_device.cc:184] LocalUsbDevice I driver/usb/usb_standard_commands.cc:36] UsbStandardCommands I driver/usb/usb_dfu_commands.cc:37] UsbDfuCommands I driver/usb/usb_standard_commands.cc:43] GetDeviceDescriptor I driver/usb/local_usb_device.cc:398] GetDescriptor I driver/usb/usb_standard_commands.cc:78] Vender ID: 0x18d1 I driver/usb/usb_standard_commands.cc:79] Product ID: 0x9302 I driver/usb/usb_driver.cc:1410] Device is already in application mode, skipping DFU I driver/usb/usb_driver.cc:1422] Resetting device I driver/usb/local_usb_device.cc:243] Close: closing device 0x1da6210 I driver/usb/local_usb_device.cc:216] DoCancelAllTransfers: cancelling 0 async transfers I driver/usb/local_usb_device.cc:224] DoCancelAllTransfers: waiting for all async transfers to complete I driver/usb/local_usb_device.cc:234] DoCancelAllTransfers: all async transfers have completed I driver/usb/local_usb_device.cc:276] Close: releasing 0 transfer buffers I driver/usb/local_usb_device.cc:289] Close: performing graceful reset I driver/usb/local_usb_device.cc:322] Close: final clean up completed I driver/usb/usb_driver.cc:1364] Opening device expecting application mode I driver/usb/local_usb_device.cc:1013] OpenDevice: [/sys/bus/usb/devices/2-1] I driver/usb/local_usb_device.cc:1050] OpenDevice: checking bus[4] port[0] I driver/usb/local_usb_device.cc:1050] OpenDevice: checking bus[3] port[1] I driver/usb/local_usb_device.cc:1050] OpenDevice: checking bus[3] port[0] I driver/usb/local_usb_device.cc:1050] OpenDevice: checking bus[2] port[1] I driver/usb/local_usb_device.cc:1081] OpenDevice: device opened 0x1d7ddc0 I driver/usb/local_usb_device.cc:184] LocalUsbDevice I driver/usb/usb_standard_commands.cc:36] UsbStandardCommands I driver/usb/usb_ml_commands.cc:47] UsbMlCommands I driver/usb/usb_dfu_commands.cc:40] ~UsbDfuCommands I driver/usb/usb_standard_commands.cc:39] ~UsbStandardCommands I driver/usb/local_usb_device.cc:196] ~LocalUsbDevice I driver/usb/local_usb_device.cc:243] Close: closing device (nil) I driver/usb/local_usb_device.cc:352] ClaimInterface I driver/usb/usb_ml_commands.cc:80] ReadRegister32 offset 0x1a30c I driver/usb/local_usb_device.cc:514] SendControlCommandWithDataIn I driver/usb/local_usb_device.cc:521] SYNC CTRL WITH DATA IN begin I driver/usb/local_usb_device.cc:538] SYNC CTRL WITH DATA IN end I driver/usb/usb_ml_commands.cc:110] ReadRegister32 [0x1A30C] == 0xF0059 I driver/usb/usb_ml_commands.cc:153] WriteRegister32 [0x1A30C] := 0xF0059 I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:80] ReadRegister32 offset 0x1a314 I driver/usb/local_usb_device.cc:514] SendControlCommandWithDataIn I driver/usb/local_usb_device.cc:521] SYNC CTRL WITH DATA IN begin I driver/usb/local_usb_device.cc:538] SYNC CTRL WITH DATA IN end I driver/usb/usb_ml_commands.cc:110] ReadRegister32 [0x1A314] == 0x110000 I driver/usb/usb_ml_commands.cc:80] ReadRegister32 offset 0x1a318 I driver/usb/local_usb_device.cc:514] SendControlCommandWithDataIn I driver/usb/local_usb_device.cc:521] SYNC CTRL WITH DATA IN begin I driver/usb/local_usb_device.cc:538] SYNC CTRL WITH DATA IN end I driver/usb/usb_ml_commands.cc:110] ReadRegister32 [0x1A318] == 0xC5025C I driver/usb/usb_ml_commands.cc:80] ReadRegister32 offset 0x1a318 I driver/usb/local_usb_device.cc:514] SendControlCommandWithDataIn I driver/usb/local_usb_device.cc:521] SYNC CTRL WITH DATA IN begin I driver/usb/local_usb_device.cc:538] SYNC CTRL WITH DATA IN end I driver/usb/usb_ml_commands.cc:110] ReadRegister32 [0x1A318] == 0xC5025C I driver/usb/usb_ml_commands.cc:153] WriteRegister32 [0x1A318] := 0x85025C I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:80] ReadRegister32 offset 0x1a318 I driver/usb/local_usb_device.cc:514] SendControlCommandWithDataIn I driver/usb/local_usb_device.cc:521] SYNC CTRL WITH DATA IN begin I driver/usb/local_usb_device.cc:538] SYNC CTRL WITH DATA IN end I driver/usb/usb_ml_commands.cc:110] ReadRegister32 [0x1A318] == 0x850004 I driver/usb/usb_ml_commands.cc:117] ReadRegister64 offset 0x44018 I driver/usb/local_usb_device.cc:514] SendControlCommandWithDataIn I driver/usb/local_usb_device.cc:521] SYNC CTRL WITH DATA IN begin I driver/usb/local_usb_device.cc:538] SYNC CTRL WITH DATA IN end I driver/usb/usb_ml_commands.cc:147] ReadRegister64 [0x44018] == 0x0 I driver/usb/usb_ml_commands.cc:178] WriteRegister64 [0x4A000] := 0x1 I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:178] WriteRegister64 [0x48788] := 0x7F I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:117] ReadRegister64 offset 0x48788 I driver/usb/local_usb_device.cc:514] SendControlCommandWithDataIn I driver/usb/local_usb_device.cc:521] SYNC CTRL WITH DATA IN begin I driver/usb/local_usb_device.cc:538] SYNC CTRL WITH DATA IN end I driver/usb/usb_ml_commands.cc:147] ReadRegister64 [0x48788] == 0x7F I driver/usb/usb_ml_commands.cc:178] WriteRegister64 [0x40020] := 0x1E02 I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:80] ReadRegister32 offset 0x1a314 I driver/usb/local_usb_device.cc:514] SendControlCommandWithDataIn I driver/usb/local_usb_device.cc:521] SYNC CTRL WITH DATA IN begin I driver/usb/local_usb_device.cc:538] SYNC CTRL WITH DATA IN end I driver/usb/usb_ml_commands.cc:110] ReadRegister32 [0x1A314] == 0x110000 I driver/usb/usb_ml_commands.cc:153] WriteRegister32 [0x1A314] := 0x150000 I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:80] ReadRegister32 offset 0x1a000 I driver/usb/local_usb_device.cc:514] SendControlCommandWithDataIn I driver/usb/local_usb_device.cc:521] SYNC CTRL WITH DATA IN begin I driver/usb/local_usb_device.cc:538] SYNC CTRL WITH DATA IN end I driver/usb/usb_ml_commands.cc:110] ReadRegister32 [0x1A000] == 0x119089A I driver/usb/usb_driver.cc:321] e-fuse programming revision: 1 I driver/usb/usb_driver.cc:328] InitializeChip Enabling only sc host interrupt descriptors I driver/usb/usb_ml_commands.cc:178] WriteRegister64 [0x4C148] := 0xF0 I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_driver.cc:341] InitializeChip Enabling single EP mode I driver/usb/usb_ml_commands.cc:178] WriteRegister64 [0x4C160] := 0x0 I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_driver.cc:369] InitializeChip Setting 1KB chunk for bulk-ins I driver/usb/usb_ml_commands.cc:178] WriteRegister64 [0x4C058] := 0x80 I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:178] WriteRegister64 [0x44018] := 0x1 I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:178] WriteRegister64 [0x44158] := 0x1 I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:178] WriteRegister64 [0x44198] := 0x1 I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:178] WriteRegister64 [0x441D8] := 0x1 I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:178] WriteRegister64 [0x44218] := 0x1 I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:178] WriteRegister64 [0x48788] := 0x7F I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:117] ReadRegister64 offset 0x48788 I driver/usb/local_usb_device.cc:514] SendControlCommandWithDataIn I driver/usb/local_usb_device.cc:521] SYNC CTRL WITH DATA IN begin I driver/usb/local_usb_device.cc:538] SYNC CTRL WITH DATA IN end I driver/usb/usb_ml_commands.cc:147] ReadRegister64 [0x48788] == 0x7F I driver/usb/usb_ml_commands.cc:178] WriteRegister64 [0x400C0] := 0x1 I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:178] WriteRegister64 [0x40150] := 0x1 I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:178] WriteRegister64 [0x40110] := 0x1 I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:178] WriteRegister64 [0x40250] := 0x1 I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:178] WriteRegister64 [0x40298] := 0x1 I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:178] WriteRegister64 [0x402E0] := 0x1 I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:178] WriteRegister64 [0x40328] := 0x1 I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:178] WriteRegister64 [0x40190] := 0x1 I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:178] WriteRegister64 [0x401D0] := 0x1 I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:178] WriteRegister64 [0x40210] := 0x1 I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:178] WriteRegister64 [0x4C060] := 0x1 I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:178] WriteRegister64 [0x4C070] := 0x1 I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:178] WriteRegister64 [0x4C080] := 0x1 I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:178] WriteRegister64 [0x4C090] := 0x1 I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:178] WriteRegister64 [0x4C0A0] := 0x1 I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:80] ReadRegister32 offset 0x1a0d4 I driver/usb/local_usb_device.cc:514] SendControlCommandWithDataIn I driver/usb/local_usb_device.cc:521] SYNC CTRL WITH DATA IN begin I driver/usb/local_usb_device.cc:538] SYNC CTRL WITH DATA IN end I driver/usb/usb_ml_commands.cc:110] ReadRegister32 [0x1A0D4] == 0x1 I driver/usb/usb_ml_commands.cc:153] WriteRegister32 [0x1A0D4] := 0x80000001 I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:80] ReadRegister32 offset 0x1a704 I driver/usb/local_usb_device.cc:514] SendControlCommandWithDataIn I driver/usb/local_usb_device.cc:521] SYNC CTRL WITH DATA IN begin I driver/usb/local_usb_device.cc:538] SYNC CTRL WITH DATA IN end I driver/usb/usb_ml_commands.cc:110] ReadRegister32 [0x1A704] == 0x70007F I driver/usb/usb_ml_commands.cc:153] WriteRegister32 [0x1A704] := 0x7F I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:80] ReadRegister32 offset 0x1a33c I driver/usb/local_usb_device.cc:514] SendControlCommandWithDataIn I driver/usb/local_usb_device.cc:521] SYNC CTRL WITH DATA IN begin I driver/usb/local_usb_device.cc:538] SYNC CTRL WITH DATA IN end I driver/usb/usb_ml_commands.cc:110] ReadRegister32 [0x1A33C] == 0xC003F I driver/usb/usb_ml_commands.cc:153] WriteRegister32 [0x1A33C] := 0x3F I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:153] WriteRegister32 [0x1A500] := 0x1 I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:153] WriteRegister32 [0x1A600] := 0x1 I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:153] WriteRegister32 [0x1A558] := 0x3 I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:153] WriteRegister32 [0x1A658] := 0x3 I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:80] ReadRegister32 offset 0x1a0d8 I driver/usb/local_usb_device.cc:514] SendControlCommandWithDataIn I driver/usb/local_usb_device.cc:521] SYNC CTRL WITH DATA IN begin I driver/usb/local_usb_device.cc:538] SYNC CTRL WITH DATA IN end I driver/usb/usb_ml_commands.cc:110] ReadRegister32 [0x1A0D8] == 0x0 I driver/usb/usb_ml_commands.cc:153] WriteRegister32 [0x1A0D8] := 0x80000000 I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I tflite/edgetpu_context_direct.cc:174] Opening device at /sys/bus/usb/devices/2-1 I driver/usb/usb_driver.cc:1155] WorkerThreadFunc starting worker thread I driver/usb/usb_driver.cc:1174] WorkerThreadFunc dispatching 0 callback events in worker thread I driver/usb/usb_driver.cc:1210] WorkerThreadFunc Re-installing event reader I driver/usb/local_usb_device.cc:748] AsyncBulkInTransfer I driver/usb/local_usb_device.cc:761] ASYNC IN 2 begin I driver/usb/usb_driver.cc:1232] WorkerThreadFunc Re-installing interrupt reader I driver/usb/local_usb_device.cc:785] AsyncInterruptInTransfer I driver/usb/local_usb_device.cc:798] ASYNC IN 3 begin I driver/usb/usb_driver.cc:1260] WorkerThreadFunc Installing bulk-in reader. buffer index [0] I driver/usb/local_usb_device.cc:748] AsyncBulkInTransfer I driver/usb/local_usb_device.cc:761] ASYNC IN 1 begin I driver/usb/usb_driver.cc:1260] WorkerThreadFunc Installing bulk-in reader. buffer index [1] I driver/usb/local_usb_device.cc:748] AsyncBulkInTransfer I driver/usb/local_usb_device.cc:761] ASYNC IN 1 begin I driver/usb/usb_driver.cc:1260] WorkerThreadFunc Installing bulk-in reader. buffer index [2] I driver/usb/local_usb_device.cc:748] AsyncBulkInTransfer I driver/usb/local_usb_device.cc:761] ASYNC IN 1 begin I driver/usb/usb_driver.cc:1260] WorkerThreadFunc Installing bulk-in reader. buffer index [3] I driver/usb/local_usb_device.cc:748] AsyncBulkInTransfer I driver/usb/local_usb_device.cc:761] ASYNC IN 1 begin I driver/usb/usb_driver.cc:1260] WorkerThreadFunc Installing bulk-in reader. buffer index [4] I driver/usb/local_usb_device.cc:748] AsyncBulkInTransfer I driver/usb/local_usb_device.cc:761] ASYNC IN 1 begin I driver/usb/usb_driver.cc:1260] WorkerThreadFunc Installing bulk-in reader. buffer index [5] I driver/usb/local_usb_device.cc:748] AsyncBulkInTransfer I driver/usb/local_usb_device.cc:761] ASYNC IN 1 begin I driver/usb/usb_driver.cc:1260] WorkerThreadFunc Installing bulk-in reader. buffer index [6] I driver/usb/local_usb_device.cc:748] AsyncBulkInTransfer I driver/usb/local_usb_device.cc:761] ASYNC IN 1 begin I driver/usb/usb_driver.cc:1260] WorkerThreadFunc Installing bulk-in reader. buffer index [7] I driver/usb/local_usb_device.cc:748] AsyncBulkInTransfer I driver/usb/local_usb_device.cc:761] ASYNC IN 1 begin I driver/usb/usb_driver.cc:1317] WorkerThreadFunc waiting on state change I driver/usb/usb_driver.cc:91] Unlocks both mutex ----INFERENCE TIME---- Note: The first inference on Edge TPU is slow because it includes loading the model into Edge TPU memory. I driver/request.cc:47] Adding input "map/TensorArrayStack/TensorArrayGatherV3" with 150528 bytes. I driver/request.cc:58] Adding output "prediction" with 965 bytes. I driver/request.cc:167] Request prepared, total batch size: 1, total TPU requests required: 1. I driver/driver.cc:307] Request [0]: Submitting P0 request immediately. I driver/driver.cc:369] Request [0]: Need to map parameters. I driver/driver.cc:249] Mapped params : Buffer(ptr=0x7f7ac5896000) -> 0x00007f7ac5896000, 3947392 bytes. I driver/driver.cc:249] Mapped params : Buffer(ptr=(nil)) -> 0x0000000000000000, 0 bytes. I driver/driver.cc:383] Request [0]: Need to do parameter-caching. I driver/single_tpu_request.cc:80] [0] Request constructed. I driver/instruction_buffers.cc:46] InstructionBuffers created. I driver/package_registry.cc:647] Created new instruction buffers. I driver/device_buffer_mapper.cc:75] Mapped scratch : Buffer(ptr=(nil)) -> 0x0000000000000000, 0 bytes. I driver/single_tpu_request.cc:365] MapDataBuffers() done. I driver/executable_util.cc:187] Linking Parameter: 0x00007f7ac5896000 I driver/device_buffer_mapper.cc:222] Mapped "instructions" : Buffer(ptr=0x1df4000) -> 0x0000000001df4000, 10064 bytes. Direction=1 I driver/single_tpu_request.cc:381] MapInstructionBuffers() done. I driver/single_tpu_request.cc:478] [0] SetState old=0, new=1. I driver/single_tpu_request.cc:390] [0] NotifyRequestSubmitted() I driver/single_tpu_request.cc:478] [0] SetState old=1, new=2. I driver/single_queue_dma_scheduler.cc:82] Request[0]: Submitted I driver/dma_info_extractor.cc:166] DMA[0]: Instruction: device_address = 0x1df4000, bytes = 10064, pending I driver/dma_info_extractor.cc:166] DMA[1]: Parameter: device_address = 0x7f7ac5896000, bytes = 3947392, pending I driver/dma_info_extractor.cc:166] DMA[2]: SC interrupt 0 I driver/single_tpu_request.cc:80] [1] Request constructed. I driver/usb/usb_driver.cc:86] lock (does nothing) I driver/usb/usb_driver.cc:1322] WorkerThreadFunc driver state change detected I driver/single_tpu_request.cc:113] Adding input "map/TensorArrayStack/TensorArrayGatherV3" with 150528 bytes. I driver/usb/usb_driver.cc:1174] WorkerThreadFunc dispatching 0 callback events in worker thread I driver/single_tpu_request.cc:187] Adding output "prediction" with 965 bytes. I driver/single_tpu_request.cc:398] [0] NotifyRequestActive() I driver/single_tpu_request.cc:478] [0] SetState old=2, new=3. I driver/single_queue_dma_scheduler.cc:132] Request[0]: Scheduling DMA[0] I driver/single_queue_dma_scheduler.cc:132] Request[0]: Scheduling DMA[1] I driver/single_queue_dma_scheduler.cc:132] Request[0]: Scheduling DMA[2] I driver/usb/usb_driver.cc:777] ProcessIo [0-0] bulk out header I driver/usb/usb_ml_commands.cc:215] PrepareHeader ep 1: header hex 50 27 0 0 - 0 0 0 0 I driver/usb/local_usb_device.cc:708] AsyncBulkOutTransfer I driver/usb/local_usb_device.cc:722] ASYNC OUT 1 begin I driver/dma_chunker.cc:42] Completed 0 bytes; Outstanding 0 bytes; Processing next 10064 bytes I driver/usb/local_usb_device.cc:708] AsyncBulkOutTransfer I driver/usb/local_usb_device.cc:722] ASYNC OUT 1 begin I driver/usb/usb_driver.cc:777] ProcessIo [1-2] bulk out header I driver/usb/usb_ml_commands.cc:215] PrepareHeader ep 1: header hex 80 3b 3c 0 - 2 0 0 0 I driver/usb/local_usb_device.cc:708] AsyncBulkOutTransfer I driver/usb/local_usb_device.cc:657] ASYNC OUT 1 end I driver/usb/local_usb_device.cc:722] ASYNC OUT 1 begin I driver/usb/local_usb_device.cc:642] UnregisterCompletedTransfer I driver/dma_chunker.cc:42] Completed 0 bytes; Outstanding 0 bytes; Processing next 1048576 bytes I driver/usb/local_usb_device.cc:657] ASYNC OUT 1 end I driver/usb/local_usb_device.cc:708] AsyncBulkOutTransfer I driver/usb/local_usb_device.cc:642] UnregisterCompletedTransfer I driver/usb/local_usb_device.cc:722] ASYNC OUT 1 begin I driver/usb/local_usb_device.cc:657] ASYNC OUT 1 end I driver/usb/local_usb_device.cc:642] UnregisterCompletedTransfer I driver/usb/usb_driver.cc:1310] WorkerThreadFunc re-evaluation is needed I driver/usb/usb_driver.cc:1174] WorkerThreadFunc dispatching 3 callback events in worker thread I driver/usb/usb_driver.cc:796] [0-0] bulk out for header done I driver/usb/usb_driver.cc:850] operator() [0-0] bulk out for 10064 bytes done I driver/usb/usb_driver.cc:796] [1-2] bulk out for header done I driver/single_queue_dma_scheduler.cc:154] Completing DMA[0] I driver/usb/usb_driver.cc:550] IO completed I driver/dma_chunker.cc:42] Completed 0 bytes; Outstanding 1048576 bytes; Processing next 1048576 bytes I driver/usb/local_usb_device.cc:708] AsyncBulkOutTransfer I driver/usb/local_usb_device.cc:722] ASYNC OUT 1 begin I driver/usb/usb_driver.cc:1310] WorkerThreadFunc re-evaluation is needed I driver/usb/usb_driver.cc:1174] WorkerThreadFunc dispatching 0 callback events in worker thread I driver/dma_chunker.cc:42] Completed 0 bytes; Outstanding 2097152 bytes; Processing next 1048576 bytes I driver/usb/local_usb_device.cc:708] AsyncBulkOutTransfer I driver/usb/local_usb_device.cc:722] ASYNC OUT 1 begin I driver/usb/usb_driver.cc:1310] WorkerThreadFunc re-evaluation is needed I driver/usb/usb_driver.cc:1174] WorkerThreadFunc dispatching 0 callback events in worker thread I driver/usb/usb_driver.cc:643] [1-2] number of concurrent transfers too high, wait (3 >= 3) I driver/usb/usb_driver.cc:1317] WorkerThreadFunc waiting on state change I driver/usb/usb_driver.cc:91] Unlocks both mutex I driver/instruction_buffers.cc:46] InstructionBuffers created. I driver/package_registry.cc:647] Created new instruction buffers. I driver/device_buffer_mapper.cc:75] Mapped scratch : Buffer(ptr=(nil)) -> 0x0000000000000000, 0 bytes. I driver/device_buffer_mapper.cc:222] Mapped "map/TensorArrayStack/TensorArrayGatherV3" : Buffer(ptr=0x1db8c40) -> 0x0000000001db8c40, 150528 bytes. Direction=1 I driver/device_buffer_mapper.cc:222] Mapped "prediction" : Buffer(ptr=0x1dfa000) -> 0x0000000001dfa000, 968 bytes. Direction=2 I driver/single_tpu_request.cc:365] MapDataBuffers() done. I driver/executable_util.cc:93] Linking map/TensorArrayStack/TensorArrayGatherV3[0]: 0x0000000001db8c40 I driver/executable_util.cc:93] Linking prediction[0]: 0x0000000001dfa000 I driver/device_buffer_mapper.cc:222] Mapped "instructions" : Buffer(ptr=0x1e0a000) -> 0x0000000001e0a000, 261920 bytes. Direction=1 I driver/device_buffer_mapper.cc:222] Mapped "instructions" : Buffer(ptr=0x1dfc000) -> 0x0000000001dfc000, 10224 bytes. Direction=1 I driver/single_tpu_request.cc:381] MapInstructionBuffers() done. I driver/single_tpu_request.cc:478] [1] SetState old=0, new=1. I driver/single_tpu_request.cc:390] [1] NotifyRequestSubmitted() I driver/single_tpu_request.cc:478] [1] SetState old=1, new=2. I driver/single_queue_dma_scheduler.cc:82] Request[1]: Submitted I driver/dma_info_extractor.cc:166] DMA[0]: Instruction: device_address = 0x1e0a000, bytes = 261920, pending I driver/dma_info_extractor.cc:166] DMA[1]: Input activation: device_address = 0x1db8c40, bytes = 150528, pending I driver/dma_info_extractor.cc:166] DMA[2]: Instruction: device_address = 0x1dfc000, bytes = 10224, pending I driver/dma_info_extractor.cc:166] DMA[3]: Output activation: device_address = 0x1dfa000, bytes = 968, pending I driver/dma_info_extractor.cc:166] DMA[4]: SC interrupt 0 I driver/usb/usb_driver.cc:86] lock (does nothing) I driver/usb/usb_driver.cc:1322] WorkerThreadFunc driver state change detected I driver/usb/usb_driver.cc:1174] WorkerThreadFunc dispatching 0 callback events in worker thread I driver/single_tpu_request.cc:398] [1] NotifyRequestActive() I driver/single_tpu_request.cc:478] [1] SetState old=2, new=3. I driver/single_queue_dma_scheduler.cc:132] Request[1]: Scheduling DMA[0] I driver/single_queue_dma_scheduler.cc:132] Request[1]: Scheduling DMA[1] I driver/single_queue_dma_scheduler.cc:132] Request[1]: Scheduling DMA[2] I driver/single_queue_dma_scheduler.cc:132] Request[1]: Scheduling DMA[3] I driver/single_queue_dma_scheduler.cc:132] Request[1]: Scheduling DMA[4] I driver/usb/usb_driver.cc:643] [1-2] number of concurrent transfers too high, wait (3 >= 3) I driver/usb/usb_driver.cc:1317] WorkerThreadFunc waiting on state change I driver/usb/usb_driver.cc:91] Unlocks both mutex I driver/usb/local_usb_device.cc:657] ASYNC OUT 1 end I driver/usb/local_usb_device.cc:642] UnregisterCompletedTransfer I driver/usb/usb_driver.cc:86] lock (does nothing) I driver/usb/usb_driver.cc:1322] WorkerThreadFunc driver state change detected I driver/usb/usb_driver.cc:1174] WorkerThreadFunc dispatching 1 callback events in worker thread I driver/usb/usb_driver.cc:850] operator() [1-2] bulk out for 1048576 bytes done I driver/dma_chunker.cc:42] Completed 1048576 bytes; Outstanding 2097152 bytes; Processing next 801664 bytes I driver/usb/local_usb_device.cc:708] AsyncBulkOutTransfer I driver/usb/local_usb_device.cc:722] ASYNC OUT 1 begin I driver/usb/usb_driver.cc:643] [0-0] number of concurrent transfers too high, wait (3 >= 3) I driver/usb/usb_driver.cc:1310] WorkerThreadFunc re-evaluation is needed I driver/usb/usb_driver.cc:1174] WorkerThreadFunc dispatching 0 callback events in worker thread I driver/usb/usb_driver.cc:643] [1-2] number of concurrent transfers too high, wait (3 >= 3) I driver/usb/usb_driver.cc:1317] WorkerThreadFunc waiting on state change I driver/usb/usb_driver.cc:91] Unlocks both mutex I driver/usb/local_usb_device.cc:657] ASYNC OUT 1 end I driver/usb/local_usb_device.cc:642] UnregisterCompletedTransfer I driver/usb/usb_driver.cc:86] lock (does nothing) I driver/usb/usb_driver.cc:1322] WorkerThreadFunc driver state change detected I driver/usb/usb_driver.cc:1174] WorkerThreadFunc dispatching 1 callback events in worker thread I driver/usb/usb_driver.cc:850] operator() [1-2] bulk out for 1048576 bytes done I driver/usb/usb_driver.cc:777] ProcessIo [0-0] bulk out header I driver/usb/usb_ml_commands.cc:215] PrepareHeader ep 1: header hex 20 ff 3 0 - 0 0 0 0 I driver/usb/local_usb_device.cc:708] AsyncBulkOutTransfer I driver/usb/local_usb_device.cc:722] ASYNC OUT 1 begin I driver/dma_chunker.cc:42] Completed 0 bytes; Outstanding 0 bytes; Processing next 261920 bytes I driver/usb/local_usb_device.cc:708] AsyncBulkOutTransfer I driver/usb/local_usb_device.cc:722] ASYNC OUT 1 begin I driver/usb/usb_driver.cc:643] [1-1] number of concurrent transfers too high, wait (4 >= 3) I driver/usb/usb_driver.cc:1310] WorkerThreadFunc re-evaluation is needed I driver/usb/usb_driver.cc:1174] WorkerThreadFunc dispatching 0 callback events in worker thread I driver/usb/usb_driver.cc:643] [0-0] number of concurrent transfers too high, wait (3 >= 3) I driver/usb/usb_driver.cc:1317] WorkerThreadFunc waiting on state change I driver/usb/usb_driver.cc:91] Unlocks both mutex I driver/usb/local_usb_device.cc:657] ASYNC OUT 1 end I driver/usb/local_usb_device.cc:642] UnregisterCompletedTransfer I driver/usb/usb_driver.cc:86] lock (does nothing) I driver/usb/usb_driver.cc:1322] WorkerThreadFunc driver state change detected I driver/usb/usb_driver.cc:1174] WorkerThreadFunc dispatching 1 callback events in worker thread I driver/usb/usb_driver.cc:850] operator() [1-2] bulk out for 1048576 bytes done I driver/usb/usb_driver.cc:777] ProcessIo [1-1] bulk out header I driver/usb/usb_ml_commands.cc:215] PrepareHeader ep 1: header hex 0 4c 2 0 - 1 0 0 0 I driver/usb/local_usb_device.cc:708] AsyncBulkOutTransfer I driver/usb/local_usb_device.cc:722] ASYNC OUT 1 begin I driver/dma_chunker.cc:42] Completed 0 bytes; Outstanding 0 bytes; Processing next 150528 bytes I driver/usb/local_usb_device.cc:708] AsyncBulkOutTransfer I driver/usb/local_usb_device.cc:722] ASYNC OUT 1 begin I driver/usb/usb_driver.cc:643] [2-0] number of concurrent transfers too high, wait (4 >= 3) I driver/usb/usb_driver.cc:1310] WorkerThreadFunc re-evaluation is needed I driver/usb/usb_driver.cc:1174] WorkerThreadFunc dispatching 0 callback events in worker thread I driver/usb/usb_driver.cc:643] [1-1] number of concurrent transfers too high, wait (3 >= 3) I driver/usb/usb_driver.cc:1317] WorkerThreadFunc waiting on state change I driver/usb/usb_driver.cc:91] Unlocks both mutex I driver/usb/local_usb_device.cc:657] ASYNC OUT 1 end I driver/usb/local_usb_device.cc:642] UnregisterCompletedTransfer I driver/usb/local_usb_device.cc:657] ASYNC OUT 1 end I driver/usb/local_usb_device.cc:642] UnregisterCompletedTransfer I driver/usb/local_usb_device.cc:672] ASYNC IN 2 end I driver/usb/usb_ml_commands.cc:258] operator() tag:4, offset:0x0, length 0 I driver/usb/usb_ml_commands.cc:266] operator() callback done I driver/usb/local_usb_device.cc:642] UnregisterCompletedTransfer I driver/usb/usb_driver.cc:86] lock (does nothing) I driver/usb/usb_driver.cc:1322] WorkerThreadFunc driver state change detected I driver/usb/usb_driver.cc:1174] WorkerThreadFunc dispatching 3 callback events in worker thread I driver/usb/usb_driver.cc:850] operator() [1-2] bulk out for 801664 bytes done I driver/usb/usb_driver.cc:796] [0-0] bulk out for header done I driver/usb/usb_driver.cc:1050] Digesting descriptor from device tag[4], data[0x0], size[0] I driver/usb/usb_io_request.cc:94] DMA[2] hint matched with descriptor I driver/usb/usb_driver.cc:1210] WorkerThreadFunc Re-installing event reader I driver/usb/local_usb_device.cc:748] AsyncBulkInTransfer I driver/usb/local_usb_device.cc:761] ASYNC IN 2 begin I driver/single_queue_dma_scheduler.cc:154] Completing DMA[1] I driver/usb/usb_driver.cc:550] IO completed I driver/single_queue_dma_scheduler.cc:154] Completing DMA[2] I driver/single_tpu_request.cc:410] [0] NotifyCompletion() I driver/package_registry.cc:658] Returned instruction buffers back to executable reference I driver/single_tpu_request.cc:478] [0] SetState old=3, new=4. I driver/single_queue_dma_scheduler.cc:234] Request[0]: Completed I driver/single_tpu_request.cc:96] [0] Request destroyed. I driver/usb/usb_driver.cc:550] IO completed I driver/usb/usb_driver.cc:777] ProcessIo [2-0] bulk out header I driver/usb/usb_ml_commands.cc:215] PrepareHeader ep 1: header hex f0 27 0 0 - 0 0 0 0 I driver/usb/local_usb_device.cc:708] AsyncBulkOutTransfer I driver/usb/local_usb_device.cc:722] ASYNC OUT 1 begin I driver/dma_chunker.cc:42] Completed 0 bytes; Outstanding 0 bytes; Processing next 10224 bytes I driver/usb/local_usb_device.cc:708] AsyncBulkOutTransfer I driver/usb/local_usb_device.cc:722] ASYNC OUT 1 begin I driver/usb/usb_driver.cc:1310] WorkerThreadFunc re-evaluation is needed I driver/usb/usb_driver.cc:1174] WorkerThreadFunc dispatching 0 callback events in worker thread I driver/usb/usb_driver.cc:643] [2-0] number of concurrent transfers too high, wait (3 >= 3) I driver/usb/usb_driver.cc:1317] WorkerThreadFunc waiting on state change I driver/usb/usb_driver.cc:91] Unlocks both mutex I driver/usb/local_usb_device.cc:657] ASYNC OUT 1 end I driver/usb/local_usb_device.cc:642] UnregisterCompletedTransfer I driver/usb/local_usb_device.cc:657] ASYNC OUT 1 end I driver/usb/usb_driver.cc:86] lock (does nothing) I driver/usb/usb_driver.cc:1322] WorkerThreadFunc driver state change detected I driver/usb/local_usb_device.cc:642] UnregisterCompletedTransfer I driver/usb/usb_driver.cc:1174] WorkerThreadFunc dispatching 2 callback events in worker thread I driver/usb/usb_driver.cc:850] operator() [0-0] bulk out for 261920 bytes done I driver/usb/usb_driver.cc:796] [1-1] bulk out for header done I driver/single_queue_dma_scheduler.cc:154] Completing DMA[0] I driver/usb/usb_driver.cc:550] IO completed I driver/usb/usb_driver.cc:1317] WorkerThreadFunc waiting on state change I driver/usb/usb_driver.cc:91] Unlocks both mutex I driver/usb/local_usb_device.cc:657] ASYNC OUT 1 end I driver/usb/local_usb_device.cc:642] UnregisterCompletedTransfer I driver/usb/local_usb_device.cc:657] ASYNC OUT 1 end I driver/usb/local_usb_device.cc:642] UnregisterCompletedTransfer I driver/usb/usb_driver.cc:86] lock (does nothing) I driver/usb/usb_driver.cc:1322] WorkerThreadFunc driver state change detected I driver/usb/local_usb_device.cc:657] ASYNC OUT 1 end I driver/usb/local_usb_device.cc:642] UnregisterCompletedTransfer I driver/usb/usb_driver.cc:1174] WorkerThreadFunc dispatching 2 callback events in worker thread I driver/usb/usb_driver.cc:850] operator() [1-1] bulk out for 150528 bytes done I driver/usb/usb_driver.cc:796] [2-0] bulk out for header done I driver/usb/usb_driver.cc:850] operator() [2-0] bulk out for 10224 bytes done I driver/single_queue_dma_scheduler.cc:154] Completing DMA[1] I driver/usb/usb_driver.cc:550] IO completed I driver/single_queue_dma_scheduler.cc:154] Completing DMA[2] I driver/usb/usb_driver.cc:550] IO completed I driver/usb/usb_driver.cc:1317] WorkerThreadFunc waiting on state change I driver/usb/usb_driver.cc:91] Unlocks both mutex I driver/usb/local_usb_device.cc:672] ASYNC IN 1 end I driver/usb/local_usb_device.cc:642] UnregisterCompletedTransfer I driver/usb/local_usb_device.cc:672] ASYNC IN 2 end I driver/usb/usb_ml_commands.cc:258] operator() tag:4, offset:0x0, length 0 I driver/usb/usb_ml_commands.cc:266] operator() callback done I driver/usb/local_usb_device.cc:642] UnregisterCompletedTransfer I driver/usb/usb_driver.cc:86] lock (does nothing) I driver/usb/usb_driver.cc:1322] WorkerThreadFunc driver state change detected I driver/usb/usb_driver.cc:1174] WorkerThreadFunc dispatching 2 callback events in worker thread I driver/usb/usb_driver.cc:1138] bulk in 968 bytes from buffer index [0] I driver/usb/usb_driver.cc:1050] Digesting descriptor from device tag[4], data[0x0], size[0] I driver/usb/usb_io_request.cc:94] DMA[4] hint matched with descriptor I driver/usb/usb_driver.cc:1210] WorkerThreadFunc Re-installing event reader I driver/usb/local_usb_device.cc:748] AsyncBulkInTransfer I driver/usb/local_usb_device.cc:761] ASYNC IN 2 begin I driver/dma_chunker.cc:30] Completed 0 bytes; Outstanding 0 bytes; Processing next 968 bytes I driver/usb/usb_driver.cc:916] [3-3] bulk in for 968 bytes has yielded 968 bytes from index [0] I driver/usb/usb_driver.cc:1310] WorkerThreadFunc re-evaluation is needed I driver/usb/usb_driver.cc:1174] WorkerThreadFunc dispatching 0 callback events in worker thread I driver/usb/usb_driver.cc:1260] WorkerThreadFunc Installing bulk-in reader. buffer index [0] I driver/usb/local_usb_device.cc:748] AsyncBulkInTransfer I driver/usb/local_usb_device.cc:761] ASYNC IN 1 begin I driver/single_queue_dma_scheduler.cc:154] Completing DMA[3] I driver/usb/usb_driver.cc:550] IO completed I driver/single_queue_dma_scheduler.cc:154] Completing DMA[4] I driver/single_tpu_request.cc:410] [1] NotifyCompletion() I driver/package_registry.cc:658] Returned instruction buffers back to executable reference I driver/single_tpu_request.cc:478] [1] SetState old=3, new=4. I driver/single_queue_dma_scheduler.cc:234] Request[1]: Completed I driver/single_tpu_request.cc:96] [1] Request destroyed. I driver/usb/usb_driver.cc:550] IO completed I driver/usb/usb_driver.cc:1317] WorkerThreadFunc waiting on state change I driver/usb/usb_driver.cc:91] Unlocks both mutex 11.8ms -------RESULTS-------- Ara macao (Scarlet Macaw): 0.75781

I driver/instruction_buffers.cc:51] InstructionBuffers destroyed. I driver/instruction_buffers.cc:51] InstructionBuffers destroyed. I tflite/edgetpu_manager_direct.cc:226] Releasing Edge TPU device at /sys/bus/usb/devices/2-1 I tflite/edgetpu_context_direct.cc:180] Closing Edge TPU device at /sys/bus/usb/devices/2-1 I driver/usb/local_usb_device.cc:216] DoCancelAllTransfers: cancelling 10 async transfers I driver/usb/usb_driver.cc:86] lock (does nothing) I driver/usb/usb_driver.cc:1322] WorkerThreadFunc driver state change detected I driver/usb/local_usb_device.cc:672] ASYNC IN 1 end I driver/usb/local_usb_device.cc:97] ConvertLibUsbTransferStatus: USB transfer error 3 [LibUsbDataInCallback] I driver/usb/local_usb_device.cc:642] UnregisterCompletedTransfer I driver/usb/local_usb_device.cc:224] DoCancelAllTransfers: waiting for all async transfers to complete I driver/usb/local_usb_device.cc:672] ASYNC IN 2 end I driver/usb/local_usb_device.cc:97] ConvertLibUsbTransferStatus: USB transfer error 3 [LibUsbDataInCallback] I driver/usb/local_usb_device.cc:642] UnregisterCompletedTransfer I driver/usb/local_usb_device.cc:672] ASYNC IN 3 end I driver/usb/local_usb_device.cc:97] ConvertLibUsbTransferStatus: USB transfer error 3 [LibUsbDataInCallback] I driver/usb/local_usb_device.cc:642] UnregisterCompletedTransfer I driver/usb/local_usb_device.cc:672] ASYNC IN 1 end I driver/usb/local_usb_device.cc:97] ConvertLibUsbTransferStatus: USB transfer error 3 [LibUsbDataInCallback] I driver/usb/local_usb_device.cc:642] UnregisterCompletedTransfer I driver/usb/local_usb_device.cc:672] ASYNC IN 1 end I driver/usb/local_usb_device.cc:97] ConvertLibUsbTransferStatus: USB transfer error 3 [LibUsbDataInCallback] I driver/usb/local_usb_device.cc:642] UnregisterCompletedTransfer I driver/usb/local_usb_device.cc:672] ASYNC IN 1 end I driver/usb/local_usb_device.cc:97] ConvertLibUsbTransferStatus: USB transfer error 3 [LibUsbDataInCallback] I driver/usb/local_usb_device.cc:642] UnregisterCompletedTransfer I driver/usb/local_usb_device.cc:672] ASYNC IN 1 end I driver/usb/local_usb_device.cc:97] ConvertLibUsbTransferStatus: USB transfer error 3 [LibUsbDataInCallback] I driver/usb/local_usb_device.cc:642] UnregisterCompletedTransfer I driver/usb/local_usb_device.cc:672] ASYNC IN 1 end I driver/usb/local_usb_device.cc:97] ConvertLibUsbTransferStatus: USB transfer error 3 [LibUsbDataInCallback] I driver/usb/local_usb_device.cc:642] UnregisterCompletedTransfer I driver/usb/local_usb_device.cc:672] ASYNC IN 1 end I driver/usb/local_usb_device.cc:97] ConvertLibUsbTransferStatus: USB transfer error 3 [LibUsbDataInCallback] I driver/usb/local_usb_device.cc:642] UnregisterCompletedTransfer I driver/usb/local_usb_device.cc:672] ASYNC IN 1 end I driver/usb/local_usb_device.cc:97] ConvertLibUsbTransferStatus: USB transfer error 3 [LibUsbDataInCallback] I driver/usb/local_usb_device.cc:642] UnregisterCompletedTransfer I driver/usb/local_usb_device.cc:234] DoCancelAllTransfers: all async transfers have completed I driver/usb/usb_driver.cc:1174] WorkerThreadFunc dispatching 10 callback events in worker thread I driver/usb/usb_driver.cc:404] HandleEvent cancelled, ignore. I driver/usb/usb_driver.cc:466] HandleInterrupt cancelled, ignore. I driver/usb/usb_driver.cc:1194] All bulk-in buffers are available I driver/usb/usb_driver.cc:1201] Driver is closing, and all async operations have completed. I driver/usb/usb_driver.cc:1330] WorkerThreadFunc leaving worker thread I driver/usb/usb_ml_commands.cc:178] WriteRegister64 [0x4C070] := 0x0 I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:178] WriteRegister64 [0x4C080] := 0x0 I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:178] WriteRegister64 [0x4C090] := 0x0 I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:178] WriteRegister64 [0x4C0A0] := 0x0 I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:80] ReadRegister32 offset 0x1a0d4 I driver/usb/local_usb_device.cc:514] SendControlCommandWithDataIn I driver/usb/local_usb_device.cc:521] SYNC CTRL WITH DATA IN begin I driver/usb/local_usb_device.cc:538] SYNC CTRL WITH DATA IN end I driver/usb/usb_ml_commands.cc:110] ReadRegister32 [0x1A0D4] == 0x80000001 I driver/usb/usb_ml_commands.cc:153] WriteRegister32 [0x1A0D4] := 0x1 I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:80] ReadRegister32 offset 0x1a704 I driver/usb/local_usb_device.cc:514] SendControlCommandWithDataIn I driver/usb/local_usb_device.cc:521] SYNC CTRL WITH DATA IN begin I driver/usb/local_usb_device.cc:538] SYNC CTRL WITH DATA IN end I driver/usb/usb_ml_commands.cc:110] ReadRegister32 [0x1A704] == 0x7F I driver/usb/usb_ml_commands.cc:153] WriteRegister32 [0x1A704] := 0x70007F I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:80] ReadRegister32 offset 0x1a33c I driver/usb/local_usb_device.cc:514] SendControlCommandWithDataIn I driver/usb/local_usb_device.cc:521] SYNC CTRL WITH DATA IN begin I driver/usb/local_usb_device.cc:538] SYNC CTRL WITH DATA IN end I driver/usb/usb_ml_commands.cc:110] ReadRegister32 [0x1A33C] == 0x3F I driver/usb/usb_ml_commands.cc:153] WriteRegister32 [0x1A33C] := 0xC003F I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:153] WriteRegister32 [0x1A500] := 0x0 I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:153] WriteRegister32 [0x1A600] := 0x0 I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:153] WriteRegister32 [0x1A558] := 0x0 I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:153] WriteRegister32 [0x1A658] := 0x0 I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:80] ReadRegister32 offset 0x1a0d8 I driver/usb/local_usb_device.cc:514] SendControlCommandWithDataIn I driver/usb/local_usb_device.cc:521] SYNC CTRL WITH DATA IN begin I driver/usb/local_usb_device.cc:538] SYNC CTRL WITH DATA IN end I driver/usb/usb_ml_commands.cc:110] ReadRegister32 [0x1A0D8] == 0x80000000 I driver/usb/usb_ml_commands.cc:153] WriteRegister32 [0x1A0D8] := 0x0 I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:178] WriteRegister64 [0x4C060] := 0x0 I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:178] WriteRegister64 [0x44018] := 0x2 I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:178] WriteRegister64 [0x44158] := 0x2 I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:178] WriteRegister64 [0x44198] := 0x2 I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:178] WriteRegister64 [0x441D8] := 0x2 I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:178] WriteRegister64 [0x44218] := 0x2 I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:178] WriteRegister64 [0x48788] := 0x7F I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:117] ReadRegister64 offset 0x48788 I driver/usb/local_usb_device.cc:514] SendControlCommandWithDataIn I driver/usb/local_usb_device.cc:521] SYNC CTRL WITH DATA IN begin I driver/usb/local_usb_device.cc:538] SYNC CTRL WITH DATA IN end I driver/usb/usb_ml_commands.cc:147] ReadRegister64 [0x48788] == 0x7F I driver/usb/usb_ml_commands.cc:178] WriteRegister64 [0x400C0] := 0x2 I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:178] WriteRegister64 [0x40150] := 0x2 I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:178] WriteRegister64 [0x40110] := 0x2 I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:178] WriteRegister64 [0x40250] := 0x2 I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:178] WriteRegister64 [0x40298] := 0x2 I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:178] WriteRegister64 [0x402E0] := 0x2 I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:178] WriteRegister64 [0x40328] := 0x2 I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:178] WriteRegister64 [0x40190] := 0x2 I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:178] WriteRegister64 [0x401D0] := 0x2 I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:178] WriteRegister64 [0x40210] := 0x2 I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:80] ReadRegister32 offset 0x1a318 I driver/usb/local_usb_device.cc:514] SendControlCommandWithDataIn I driver/usb/local_usb_device.cc:521] SYNC CTRL WITH DATA IN begin I driver/usb/local_usb_device.cc:538] SYNC CTRL WITH DATA IN end I driver/usb/usb_ml_commands.cc:110] ReadRegister32 [0x1A318] == 0x85000C I driver/usb/usb_ml_commands.cc:153] WriteRegister32 [0x1A318] := 0xC5000C I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:80] ReadRegister32 offset 0x1a318 I driver/usb/local_usb_device.cc:514] SendControlCommandWithDataIn I driver/usb/local_usb_device.cc:521] SYNC CTRL WITH DATA IN begin I driver/usb/local_usb_device.cc:538] SYNC CTRL WITH DATA IN end I driver/usb/usb_ml_commands.cc:110] ReadRegister32 [0x1A318] == 0xC5025C I driver/usb/usb_ml_commands.cc:153] WriteRegister32 [0x1907C] := 0xF I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:153] WriteRegister32 [0x1907C] := 0x0 I driver/usb/local_usb_device.cc:475] SendControlCommandWithDataOut I driver/usb/local_usb_device.cc:482] SYNC CTRL WITH DATA OUT begin I driver/usb/local_usb_device.cc:499] SYNC CTRL WITH DATA OUT end I driver/usb/usb_ml_commands.cc:50] ~UsbMlCommands I driver/usb/usb_standard_commands.cc:39] ~UsbStandardCommands I driver/usb/local_usb_device.cc:196] ~LocalUsbDevice I driver/usb/local_usb_device.cc:243] Close: closing device 0x1d7ddc0 I driver/usb/local_usb_device.cc:263] Close: releasing claimed interface 0 I driver/usb/local_usb_device.cc:216] DoCancelAllTransfers: cancelling 0 async transfers I driver/usb/local_usb_device.cc:224] DoCancelAllTransfers: waiting for all async transfers to complete I driver/usb/local_usb_device.cc:234] DoCancelAllTransfers: all async transfers have completed I driver/usb/local_usb_device.cc:276] Close: releasing 0 transfer buffers I driver/usb/local_usb_device.cc:322] Close: final clean up completed

Nov 11 '21 14:11 hjonnala

@brilthor perhaps you can try with the new dual edge tpu or with any other machines to figure out if the issue is with motherboard or with the coral device.

Nov 18 '21 15:11 hjonnala

will try swapping it into another host when I have a maintenance window and report back

Nov 18 '21 20:11 brilthor

I've done an entirely fresh install of ubuntu 20.04 on a separate system and am still getting the same results:

@testcoral:~/coral/pycoral$ python3 examples/classify_image.py \
> --model test_data/mobilenet_v2_1.0_224_inat_bird_quant_edgetpu.tflite \
> --labels test_data/inat_bird_labels.txt \
> --input test_data/parrot.jpg
----INFERENCE TIME----
Note: The first inference on Edge TPU is slow because it includes loading the model into Edge TPU memory.
149.8ms
70.7ms
70.8ms
70.8ms
70.7ms
-------RESULTS--------
Ara macao (Scarlet Macaw): 0.75781

Jan 16 '22 18:01 brilthor

I've now also tested this on the listed version of debian with identical results

Apr 15 '22 18:04 brilthor

Can you please try to build libcoral and try the single_model_benchmark.cc script and share the results. Thanks!

hemanth@hemanth:~/libcoral/out/k8/benchmarks/coral$ ./single_model_benchmark -model /home/hemanth/Downloads/ssd_mobilenet_ssd_v1_coco_quant_postprocess_edgetpu.tflite
2022-03-10 07:38:52
Running ./single_model_benchmark
Run on (4 X 3900 MHz CPU s)
CPU Caches:
  L1 Data 32K (x2)
  L1 Instruction 32K (x2)
  L2 Unified 256K (x2)
  L3 Unified 4096K (x1)
Load Average: 0.37, 0.65, 0.89
***WARNING*** CPU scaling is enabled, the benchmark real time measurements may be noisy and will incur extra overhead.
-----------------------------------------------------
Benchmark           Time             CPU   Iterations
-----------------------------------------------------
BM_Model         9.63 ms         1.53 ms          495 ssd_mobilenet_ssd_v1_coco_quant_postprocess_edgetpu.tflite

Apr 15 '22 18:04 hjonnala

@hjonnala

testbench:~/coral/libcoral/out/k8/benchmarks/coral$ ./single_model_benchmark -model ~/ssd_mobilenet_v1_coco_quant_postprocess_edgetpu.tflite 
2022-04-15 19:43:38
Running ./single_model_benchmark
Run on (8 X 2200 MHz CPU s)
CPU Caches:
  L1 Data 32K (x4)
  L1 Instruction 32K (x4)
  L2 Unified 256K (x4)
  L3 Unified 6144K (x1)
Load Average: 0.14, 2.17, 2.49
***WARNING*** CPU scaling is enabled, the benchmark real time measurements may be noisy and will incur extra overhead.
-----------------------------------------------------
Benchmark           Time             CPU   Iterations
-----------------------------------------------------
BM_Model          146 ms         2.17 ms          100 ssd_mobilenet_v1_coco_quant_postprocess_edgetpu.tflite

Apr 15 '22 19:04 brilthor

@brilthor can you please try with libedgetpu1-max frequency and new m.2 device if possible.

May 25 '22 22:05 hjonnala

This appears to be a hardware issue with the coral edgeTPU. If I use the second edgeTPU on the chip it performs as expected, so it appears to be half-dead, how are warranty issues handled?

Sep 21 '23 16:09 brilthor

edgetpu edgetpu copied to clipboard

Inference times an order of magnitude higher using examples on M.2/pcie connected edgetpu

Description

Issue Type

Operating System

Coral Device

Other Devices

Programming Language

Relevant Log Output

pci:0

pci:1

edgetpu
edgetpu copied to clipboard

`pci:0`

`pci:1`