この記事について

Google Coral Edge TPU USB Acceleratorの動作を解析します。
まずは、入出力サイズと速度の関係、データ転送時に何が起きているかを解析します。

元々は、Edge TPU内部の8MByte SRAMの使われ方を調べたり、どういうモデルを書けばEdge TPUの性能を引き出せるかを調べようと思っていました。
が、色々なOpのモデルを試したけど何か挙動が変だ -> 入出力のデータ転送周りか? -> Reshapeなど簡単なOpのモデルで試してみよう(Vengineerさんアドバイスm(_ _ )m) -> それでもなんか変だ -> 入出力に分けて解析する必要がありそう。
という流れで、まずは入出力Tensorのサイズがパフォーマンスに与える影響を調査することにしました。これをはっきりさせておけば、後々の解析で、余計な要因に悩まされないで済むはずです。

結論

とりあえず先に調査結果を記載してしまいます。

Jetson Nano 10W mode, USB3.0接続時の、Edge TPU操作のイニシャルコスト(データ転送ほぼ無し、呼び出しのみ)は、0.3msec程度
- この時間は、5W modeにしてCPUクロックを下げたり、USB2.0接続にするとより大きくなる
入出力どちらも、処理速度とサイズは線形比例 (256x256x3までの範囲で確認)
出力は入力の4～9倍時間がかる。これは、出力のデータ転送方法が原因

上2つは「そりゃそうだ」という結果ですが、最後の1つは大きな収穫でした。
* Edge TPUには超解像などの画像出力するモデルは向いていないということか? そういえば、ConvTransposeも未サポート。。。（個人の感想です）

注意

実験結果を基にした事実ベースで書いていきます。あまり自信がないので、個人の見解による考察は少なめです。何かミスがあったら教えてください
今回、タイトルにわざわざ「USB Accelerator」とつけています。同じEdge TPUでも、PCIe接続やDev Boardになると挙動は変わるかもしれません
今回の実験では、入出力だけに注目した不自然なモデル構造を作りました。そのため、実際に使用するモデルにおいては、本記事に挙げるような遅延時間は問題ないとなるケースがあるかもしれません

環境

Host PC
- モデル作成
  - Windows 10 64-bit
  - Anaconda, Python 3.6.8
  - tensorflow 1.13.1 (gpu_py36h9006a92_0)
- Edge TPU 用コンパイル
  - Ubuntu 18.04
  - Edge TPU Compiler version 1.0.249710469
  - Runtime version = 10
Target
- Jetson Nano: jetson-nano-sd-r32.1.1-2019-05-31.img
- Google Coral Edge TPU
- 適当なUSB2.0HUB

解析に使用したコマンド、操作

Jetson Nanoで動作モードを切り替える

CPU性能の影響を確認するため、Jetson Nanoの動作モードを10W(1.43 GHz x 4 core)と5W(0.92 GHz x 2 core)に切り替えて実験します。

動作モードを切り替えるコマンド

# 10W mode (1.43 GHz x 4 core)
sudo nvpmodel -m 0
sudo jetson_clocks
sudo jetson_clocks --show

# 5W mode (0.92 GHz x 2 core)
sudo nvpmodel -m 1
# sudo jetson_clocks
sudo jetson_clocks --show

USB3/USB2切り替え

Jetson NanoとEdge TPUを接続する際に、直接つなぐか、USB2.0ハブ経由にするかで切り替える

USBキャプチャリング解析

wiresharkインストールと実行

sudo apt install wireshark
sudo apt install tshark
sudo adduser jetson wireshark
sudo usermod -a -G wireshark jetson
# logoff

sudo modprobe usbmon
# sudo mount -t debugfs none /sys/kernel/debug
sudo wireshark &
sudo tshark -i usbmon2 > log.txt

一般ユーザに権限を与えたつもりだけど、上手くいかなかったので結局sudo実行した。
GUIにCPUパワー持っていかれるのが嫌だったので、wiresharkではなくtsharkでコンソールからログを取得した。

入力Tensorサイズと速度性能の関係

実験用モデルの作成

まずは、入力Tensorサイズと速度性能の関係を調べます。
出来るだけ余計な演算、出力による影響を排除することが必要です。
上記のような N x M x 3 入力、1 x 1 x 1 出力のモデルを作りました。
一つだけあるConv層で、stride幅を(N, M) とすることで、演算量を抑え、さらに出力サイズを小さくしています。

以下がソースコードです。今回注目しているのは速度だけなので、学習はしていません。モデル構造を作ってcompileしたらそのまま保存しています。
また、最後に量子化しています。

model_generator_stride.py

# -*- coding: utf-8 -*-
import tensorflow as tf
from tensorflow.python.keras.models import Model
from tensorflow.python.keras.layers import Input, Reshape, Dense, Add, Conv2D, ZeroPadding2D

# Model parameters
MODEL_WIDTH = 256
MODEL_HEIGHT = 256
MODEL_CHANNEL = 3

# Create model structure
input0 = Input(shape=(MODEL_WIDTH,MODEL_HEIGHT,MODEL_CHANNEL))
conv0 = Conv2D(
      filters=1,
      kernel_size=(1,1),
      strides=(MODEL_WIDTH,MODEL_HEIGHT),
      padding='valid',
      activation='relu'
)(input0)
model = Model(inputs=[input0], outputs=[conv0])

# Save model
model.summary()
model.compile(
    optimizer='adam',
    loss='categorical_crossentropy',
    metrics=['accuracy']
)
model_name = 'model_stride/model_stride_' + str(MODEL_WIDTH) +'x' + str(MODEL_HEIGHT) + 'x' + str(MODEL_CHANNEL)
model.save(model_name + '.h5')

# Convert to quantized tflite
converter = tf.lite.TFLiteConverter.from_keras_model_file(model_name + '.h5')
converter.inference_type = tf.lite.constants.QUANTIZED_UINT8
converter.default_ranges_stats = (0, 6)
input_arrays = converter.get_input_arrays()
converter.quantized_input_stats = {input_arrays[0] : (128., 127.)}  # mean, std_dev
tflite_model = converter.convert()
open(model_name + '.tflite', "wb").write(tflite_model)

Edge TPU用に変換

量子化済みのtfliteファイルを作ったら、Edge TPU Compilerで変換します。
変換自体はedgetpu_compiler model.tflite というコマンドでできるのですが、今回はモデル数が多いので、以下のようなワンライナーで一気に変換してしまいました。
find -name "*.tflite" -exec 'edgetpu_compiler' '{}' \;

変換に失敗した

入力サイズが、512x512 を超えると、compileがabortして失敗しました。PC上のoffline compilerだと256x256まではOK。Web上のonline compilerだと512x256まではOKでした。
昔は入力サイズが300x300程度までしか対応していないというコンパイラのベータ版制約があったのですが、今はなくなっているはずです。

https://coral.withgoogle.com/web-compiler/ に記載されているRequirementsを見ても、特に引っかかるようなことはしていないはずです。
気になるのは、You must use quantization-aware training (post-training quantization is not supported). ですが、そもそも今回学習はしていませんし、これで変換失敗になるとは思えません。他のサイズでは成功しているし。

何かポカミスしている感はありますが、今回は256x256x3までのサイズで実験します。
本当は入出力サイズが8MByte以上になるケースも検証したかったのですが。。。

実行

以下のようなコードで、Jetson Nano上で推論実行します。
ちなみに、処理時間の測定はengine.get_inference_time() を使ってもほぼ同じ結果が得られました。

text_speed.py

import time
from PIL import Image, ImageDraw, ImageFont
import numpy
from edgetpu.basic.basic_engine import BasicEngine

MODEL_NAME = "model_padding/model_padding_256x256x3_edgetpu.tflite"


### Load model and prepare TPU engine
engine = BasicEngine(MODEL_NAME)
width = engine.get_input_tensor_shape()[1]
height = engine.get_input_tensor_shape()[2]

### prepara input tensor
img = Image.new('RGB', (width, height), (128, 128, 128))
draw = ImageDraw.Draw(img)
input_tensor = numpy.asarray(img).flatten()

### Run inference
start = time.time()
num_measurement = 10000
for i in range(num_measurement):
    _, raw_result = engine.RunInference(input_tensor)
    # time.sleep(2)
elapsed_time = time.time() - start
print ("elapsed_time: {0} ".format(1000 * elapsed_time / num_measurement) + "[msec]")

結果

モデル構造		Size [Kbyte]	処理時間 [msec]
Output	Input	Input	10W			5W
			CPU	EdgeTPU	EdgeTPU (USB2.0)	CPU	EdgeTPU	EdgeTPU (USB2.0)
1x1x3	2x2x3	0.012	0.0077	0.2919	0.3715	0.0111	0.4577	0.5339
1x1x3	64x64x3	12.288	0.0093	0.3177	0.6805	0.0143	0.4682	0.9346
1x1x3	128x64x3	24.576	0.0114	0.3462	1.0275	0.0174	0.5070	1.4804
1x1x3	128x128x3	49.152	0.0153	0.4124	1.7095	0.0230	0.5989	2.5466
1x1x3	256x128x3	98.304	0.0218	0.6029	3.0534	0.0336	0.7837	4.7123
1x1x3	256x256x3	196.608	0.0363	0.9241	5.8114	0.0547	1.2264	8.4724

グラフは書きませんが、入力サイズと処理時間はほぼ線形比例です。
当然ですが、CPU実行の方が速いです、これはTPU側では何の処理も行っておらず、処理時間はほぼデータ転送とEdge TPUの制御というオーバーヘッドだけであるためです。
TPUの処理速度は、10W modeのUSB3.0接続、10W modeのUSB2.0接続、5W modeのUSB3.0接続、5W modeのUSB2.0接続、の順に速いです。
一番上段ではデータ転送量は数Byteだけであるため、このときの処理時間がEdge TPU呼び出しのオーバーヘッドと解釈して良いと思います。

この結果は何となく納得がいきます。Mobile Net等を動かしたときの結果と比べての妥当な速度性能だと思います。
とはいえ、MobileNet v2 224x224を動かしたときの処理時間が2.6msec程度であるため、入力データ転送だけで0.8msec(上の表より推測)程度かかっているというのは、やはりIO関係は結構な割合を占めているなという感想。

通信解析

wireshark結果

  857  18.311254         host → 2.38.1       USB 72 URB_BULK out
  858  18.311285         host → 2.38.1       USB 4896 URB_BULK out
  859  18.311326       2.38.1 → host         USB 64 URB_BULK out
  860  18.311350         host → 2.38.1       USB 72 URB_BULK out
  861  18.311378       2.38.1 → host         USB 64 URB_BULK out
  862  18.311417       2.38.1 → host         USB 64 URB_BULK out
  863  18.311507         host → 2.38.1       USB 61504 URB_BULK out
  864  18.312192       2.38.1 → host         USB 64 URB_BULK out
  865  18.312210       2.38.1 → host         USB 72 URB_BULK in
  866  18.312218       2.38.2 → host         USB 80 URB_BULK in
  867  18.312327         host → 2.38.2       USB 64 URB_BULK in
  868  18.312349         host → 2.38.1       USB 64 URB_BULK in

上記が、推論実行中のログです。初回はもう少し通信が発生しているのですが、作成済みengineを使って何回かRunInference を行った後のログです。
使用した入力サイズは256x256x3のモデルです。そのため、処理時間は0.924msec程度です。
入力データは~~256x256x3 = 196608 Byteなので、~~ 863の行で、~~圧縮して~~ 一回のバルク転送で送信しているのだと思います。
その後、864の行で、デバイス->hostに結果が返ってきています。大体0.6msec程度です。おそらく、これが本当にTPU側で処理が動いている時間だと思います。

858行目のhost->デバイスへの4896Byteの転送が何をやっているかは不明ですが、モデル構造やパラメータを送っているのかな?

出力Tensorサイズと速度性能の関係

実験用モデルの作成

入力Tensorサイズと速度性能の関係は、思っていた通りの結果となりました。
次に、出力Tensorサイズと速度性能の関係を調べます。
今回も、出来るだけ余計な演算、入力による影響を排除することが必要です。
そのため、上記のような 2 x 2 x 3 入力、N x M x 3 出力のモデルを作りました。
Padding層によって、上下左右のサイズを広げています。

以下がソースコードです。

model_generator_padding.py

# -*- coding: utf-8 -*-
import tensorflow as tf
from tensorflow.python.keras.models import Model
from tensorflow.python.keras.layers import Input, Reshape, Dense, Add, Conv2D, ZeroPadding2D

# Model parameters
MODEL_WIDTH = 256
MODEL_HEIGHT = 256
MODEL_CHANNEL = 3

# Create model structure
input0 = Input(shape=(2,2,MODEL_CHANNEL))
pad0 = ZeroPadding2D(padding=((int)(MODEL_WIDTH/2)-1, (int)(MODEL_HEIGHT/2)-1))(input0)
model = Model(inputs=[input0], outputs=[pad0])

# Save model
model.summary()
model.compile(
    optimizer='adam',
    loss='categorical_crossentropy',
    metrics=['accuracy']
)
model_name = 'model_padding/model_padding_' + str(MODEL_WIDTH) +'x' + str(MODEL_HEIGHT) + 'x' + str(MODEL_CHANNEL)
model.save(model_name + '.h5')

# Convert to quantized tflite
converter = tf.lite.TFLiteConverter.from_keras_model_file(model_name + '.h5')
converter.inference_type = tf.lite.constants.QUANTIZED_UINT8
converter.default_ranges_stats = (0, 6)
input_arrays = converter.get_input_arrays()
converter.quantized_input_stats = {input_arrays[0] : (128., 127.)}  # mean, std_dev
tflite_model = converter.convert()
open(model_name + '.tflite', "wb").write(tflite_model)

実行

推論実行コードは先ほどと同じです

結果

モデル構造		Size [Kbyte]	処理時間 [msec]
Input	Output	Output	10W			5W
			CPU	EdgeTPU	EdgeTPU (USB2.0)	CPU	EdgeTPU	EdgeTPU (USB2.0)
2x2x3	2x2x3	0.012	0.0072	0.2928	0.3565	0.0107	0.4244	0.5120
2x2x3	64x64x3	12.288	0.0418	0.7873	1.7768	0.0630	1.3242	3.1545
2x2x3	128x64x3	24.576	0.0758	1.3230	3.1939	0.1132	2.3057	5.9224
2x2x3	128x128x3	49.152	0.1424	2.3970	6.0146	0.2186	4.1833	11.4291
2x2x3	256x128x3	98.304	0.2954	4.5982	11.7406	0.4436	8.0880	22.9183
2x2x3	256x256x3	196.608	0.5844	8.7690	22.3967	0.8750	15.9580	45.3506

今回もグラフは書きませんが、出力サイズと処理時間はほぼ線形比例です。
が、処理時間がめちゃくちゃ長くなっています。
転送するデータ量としては、先ほどの入力サイズを変えた実験と同じですが、256x256x3の場合、9倍近く遅くなっています。

一番上段のデータ転送量が小さい場合は、先ほどの実験結果の処理時間とほぼ同じです。が、その後の増加量が大きいです。
ただ、それでも二次関数や指数関数的に増えているのではなく、あくまで線形増加で傾きが大きい、というイメージです。

ちなみに、

一番最初はReshape operationで実験していました。が、やはり処理時間の増加量が尋常じゃなくて??? となりました。
そのため、原因を解析するために、入出力を分けて調査しよう、というのが本記事のスタート地点です。
Reshape だと出力サイズ=入力サイズ(Byte) となるため、サイズ増加に応じて処理時間も爆増したのだと思います。

通信解析

wireshark結果(長いので折りたたみます)

wireshark結果

 2337  13.826804         host → 2.38.1       USB 72 URB_BULK out
 2338  13.826844         host → 2.38.1       USB 5088 URB_BULK out
 2339  13.826882       2.38.1 → host         USB 64 URB_BULK out
 2340  13.826933       2.38.1 → host         USB 64 URB_BULK out
 2341  13.826948         host → 2.38.1       USB 72 URB_BULK out
 2342  13.826972         host → 2.38.1       USB 80 URB_BULK out
 2343  13.827003       2.38.1 → host         USB 64 URB_BULK out
 2344  13.827061       2.38.1 → host         USB 64 URB_BULK out
 2345  13.827076       2.38.1 → host         USB 1088 URB_BULK in
 2346  13.827084       2.38.1 → host         USB 1088 URB_BULK in
 2347  13.827134       2.38.1 → host         USB 1088 URB_BULK in
 2348  13.827148       2.38.1 → host         USB 1088 URB_BULK in
 2349  13.827156       2.38.1 → host         USB 1088 URB_BULK in
 2350  13.827165       2.38.1 → host         USB 1088 URB_BULK in
 2351  13.827173       2.38.1 → host         USB 1088 URB_BULK in
 2352  13.827181       2.38.1 → host         USB 1088 URB_BULK in
 2353  13.827223         host → 2.38.1       USB 64 URB_BULK in
 2354  13.827237         host → 2.38.1       USB 64 URB_BULK in
 2355  13.827248         host → 2.38.1       USB 64 URB_BULK in
 2356  13.827261         host → 2.38.1       USB 64 URB_BULK in
 2357  13.827284       2.38.1 → host         USB 1088 URB_BULK in
 2358  13.827302       2.38.1 → host         USB 1088 URB_BULK in
 2359  13.827317         host → 2.38.1       USB 64 URB_BULK in
 2360  13.827346       2.38.1 → host         USB 1088 URB_BULK in
 2361  13.827358       2.38.1 → host         USB 1088 URB_BULK in
 2362  13.827387       2.38.1 → host         USB 1088 URB_BULK in
 2363  13.827399         host → 2.38.1       USB 64 URB_BULK in
 2364  13.827412         host → 2.38.1       USB 64 URB_BULK in
 2365  13.827423         host → 2.38.1       USB 64 URB_BULK in
 2366  13.827459       2.38.1 → host         USB 1088 URB_BULK in
 2367  13.827470       2.38.1 → host         USB 1088 URB_BULK in
 2368  13.827478       2.38.1 → host         USB 1088 URB_BULK in
 2369  13.827532         host → 2.38.1       USB 64 URB_BULK in
 2370  13.827556         host → 2.38.1       USB 64 URB_BULK in
 2371  13.827577         host → 2.38.1       USB 64 URB_BULK in
 2372  13.827591       2.38.1 → host         USB 1088 URB_BULK in
 2373  13.827616         host → 2.38.1       USB 64 URB_BULK in
 2374  13.827648       2.38.1 → host         USB 1088 URB_BULK in
 2375  13.827657       2.38.1 → host         USB 1088 URB_BULK in
 2376  13.827667         host → 2.38.1       USB 64 URB_BULK in
 2377  13.827680         host → 2.38.1       USB 64 URB_BULK in
 2378  13.827705       2.38.1 → host         USB 1088 URB_BULK in
 2379  13.827715         host → 2.38.1       USB 64 URB_BULK in
 2380  13.827755       2.38.1 → host         USB 1088 URB_BULK in
 2381  13.827763       2.38.1 → host         USB 1088 URB_BULK in
 2382  13.827771       2.38.1 → host         USB 1088 URB_BULK in
 2383  13.827783         host → 2.38.1       USB 64 URB_BULK in
 2384  13.827796         host → 2.38.1       USB 64 URB_BULK in
 2385  13.827811         host → 2.38.1       USB 64 URB_BULK in
 2386  13.827829         host → 2.38.1       USB 64 URB_BULK in
 2387  13.827847       2.38.1 → host         USB 1088 URB_BULK in
 2388  13.827852         host → 2.38.1       USB 64 URB_BULK in
 2389  13.827856       2.38.1 → host         USB 1088 URB_BULK in
 2390  13.827868       2.38.1 → host         USB 1088 URB_BULK in
 2391  13.827872         host → 2.38.1       USB 64 URB_BULK in
 2392  13.827875       2.38.1 → host         USB 1088 URB_BULK in
 2393  13.827887         host → 2.38.1       USB 64 URB_BULK in
 2394  13.827923         host → 2.38.1       USB 64 URB_BULK in
 2395  13.827954       2.38.1 → host         USB 1088 URB_BULK in
 2396  13.827958         host → 2.38.1       USB 64 URB_BULK in
 2397  13.827972       2.38.1 → host         USB 1088 URB_BULK in
 2398  13.827980       2.38.1 → host         USB 1088 URB_BULK in
 2399  13.827987       2.38.1 → host         USB 1088 URB_BULK in
 2400  13.827995       2.38.1 → host         USB 1088 URB_BULK in
 2401  13.828029         host → 2.38.1       USB 64 URB_BULK in
 2402  13.828049         host → 2.38.1       USB 64 URB_BULK in
 2403  13.828070         host → 2.38.1       USB 64 URB_BULK in
 2404  13.828089       2.38.1 → host         USB 1088 URB_BULK in
 2405  13.828093         host → 2.38.1       USB 64 URB_BULK in
 2406  13.828127       2.38.1 → host         USB 1088 URB_BULK in
 2407  13.828135       2.38.1 → host         USB 1088 URB_BULK in
 2408  13.828143       2.38.1 → host         USB 1088 URB_BULK in
 2409  13.828152         host → 2.38.1       USB 64 URB_BULK in
 2410  13.828165         host → 2.38.1       USB 64 URB_BULK in
 2411  13.828184         host → 2.38.1       USB 64 URB_BULK in
 2412  13.828217       2.38.1 → host         USB 1088 URB_BULK in
 2413  13.828229       2.38.1 → host         USB 1088 URB_BULK in
 2414  13.828264       2.38.1 → host         USB 1088 URB_BULK in
 2415  13.828275         host → 2.38.1       USB 64 URB_BULK in
 2416  13.828293         host → 2.38.1       USB 64 URB_BULK in
 2417  13.828324         host → 2.38.1       USB 64 URB_BULK in
 2418  13.828357       2.38.1 → host         USB 1088 URB_BULK in
 2419  13.828360         host → 2.38.1       USB 64 URB_BULK in
 2420  13.828368       2.38.1 → host         USB 1088 URB_BULK in
 2421  13.828386         host → 2.38.1       USB 64 URB_BULK in
 2422  13.828410       2.38.1 → host         USB 1088 URB_BULK in
 2423  13.828412         host → 2.38.1       USB 64 URB_BULK in
 2424  13.828423         host → 2.38.1       USB 64 URB_BULK in
 2425  13.828436         host → 2.38.1       USB 64 URB_BULK in
 2426  13.828462       2.38.1 → host         USB 1088 URB_BULK in
 2427  13.828470       2.38.1 → host         USB 1088 URB_BULK in
 2428  13.828478       2.38.1 → host         USB 1088 URB_BULK in
 2429  13.828486       2.38.1 → host         USB 1088 URB_BULK in
 2430  13.828510         host → 2.38.1       USB 64 URB_BULK in
 2431  13.828524       2.38.1 → host         USB 1088 URB_BULK in
 2432  13.828536         host → 2.38.1       USB 64 URB_BULK in
 2433  13.828550         host → 2.38.1       USB 64 URB_BULK in
 2434  13.828565         host → 2.38.1       USB 64 URB_BULK in
 2435  13.828579       2.38.1 → host         USB 1088 URB_BULK in
 2436  13.828588       2.38.1 → host         USB 1088 URB_BULK in
 2437  13.828634       2.38.1 → host         USB 1088 URB_BULK in
 2438  13.828645       2.38.1 → host         USB 1088 URB_BULK in
 2439  13.828657         host → 2.38.1       USB 64 URB_BULK in
 2440  13.828680         host → 2.38.1       USB 64 URB_BULK in
 2441  13.828696         host → 2.38.1       USB 64 URB_BULK in
 2442  13.828711         host → 2.38.1       USB 64 URB_BULK in
 2443  13.828728       2.38.1 → host         USB 1088 URB_BULK in
 2444  13.828734         host → 2.38.1       USB 64 URB_BULK in
 2445  13.828736       2.38.1 → host         USB 1088 URB_BULK in
 2446  13.828748       2.38.1 → host         USB 1088 URB_BULK in
 2447  13.828752         host → 2.38.1       USB 64 URB_BULK in
 2448  13.828826       2.38.1 → host         USB 1088 URB_BULK in
 2449  13.828836       2.38.1 → host         USB 1088 URB_BULK in
 2450  13.828844       2.38.1 → host         USB 1088 URB_BULK in
 2451  13.828872         host → 2.38.1       USB 64 URB_BULK in
 2452  13.828891         host → 2.38.1       USB 64 URB_BULK in
 2453  13.828908         host → 2.38.1       USB 64 URB_BULK in
 2454  13.828929         host → 2.38.1       USB 64 URB_BULK in
 2455  13.828936       2.38.1 → host         USB 1088 URB_BULK in
 2456  13.828947         host → 2.38.1       USB 64 URB_BULK in
 2457  13.828960         host → 2.38.1       USB 64 URB_BULK in
 2458  13.828987       2.38.1 → host         USB 1088 URB_BULK in
 2459  13.828999       2.38.1 → host         USB 1088 URB_BULK in
 2460  13.829006       2.38.1 → host         USB 1088 URB_BULK in
 2461  13.829015       2.38.1 → host         USB 1088 URB_BULK in
 2462  13.829022       2.38.1 → host         USB 1088 URB_BULK in
 2463  13.829062         host → 2.38.1       USB 64 URB_BULK in
 2464  13.829081         host → 2.38.1       USB 64 URB_BULK in
 2465  13.829104         host → 2.38.1       USB 64 URB_BULK in
 2466  13.829116       2.38.1 → host         USB 1088 URB_BULK in
 2467  13.829124         host → 2.38.1       USB 64 URB_BULK in
 2468  13.829137         host → 2.38.1       USB 64 URB_BULK in
 2469  13.829156         host → 2.38.1       USB 64 URB_BULK in
 2470  13.829191       2.38.1 → host         USB 1088 URB_BULK in
 2471  13.829195         host → 2.38.1       USB 64 URB_BULK in
 2472  13.829206         host → 2.38.1       USB 64 URB_BULK in
 2473  13.829208       2.38.1 → host         USB 1088 URB_BULK in
 2474  13.829219       2.38.1 → host         USB 1088 URB_BULK in
 2475  13.829227       2.38.1 → host         USB 1088 URB_BULK in
 2476  13.829234       2.38.1 → host         USB 1088 URB_BULK in
 2477  13.829242       2.38.1 → host         USB 1088 URB_BULK in
 2478  13.829250       2.38.1 → host         USB 1088 URB_BULK in
 2479  13.829291         host → 2.38.1       USB 64 URB_BULK in
 2480  13.829305         host → 2.38.1       USB 64 URB_BULK in
 2481  13.829320         host → 2.38.1       USB 64 URB_BULK in
 2482  13.829335         host → 2.38.1       USB 64 URB_BULK in
 2483  13.829350       2.38.1 → host         USB 1088 URB_BULK in
 2484  13.829355         host → 2.38.1       USB 64 URB_BULK in
 2485  13.829368       2.38.1 → host         USB 1088 URB_BULK in
 2486  13.829392         host → 2.38.1       USB 64 URB_BULK in
 2487  13.829411       2.38.1 → host         USB 1088 URB_BULK in
 2488  13.829416         host → 2.38.1       USB 64 URB_BULK in
 2489  13.829419       2.38.1 → host         USB 1088 URB_BULK in
 2490  13.829461       2.38.1 → host         USB 1088 URB_BULK in
 2491  13.829472       2.38.1 → host         USB 1088 URB_BULK in
 2492  13.829480       2.38.1 → host         USB 1088 URB_BULK in
 2493  13.829505         host → 2.38.1       USB 64 URB_BULK in
 2494  13.829524         host → 2.38.1       USB 64 URB_BULK in
 2495  13.829551         host → 2.38.1       USB 64 URB_BULK in
 2496  13.829566       2.38.1 → host         USB 1088 URB_BULK in
 2497  13.829575         host → 2.38.1       USB 64 URB_BULK in
 2498  13.829587         host → 2.38.1       USB 64 URB_BULK in
 2499  13.829628       2.38.1 → host         USB 1088 URB_BULK in
 2500  13.829637         host → 2.38.1       USB 64 URB_BULK in
 2501  13.829650       2.38.1 → host         USB 1088 URB_BULK in
 2502  13.829654         host → 2.38.1       USB 64 URB_BULK in
 2503  13.829658       2.38.1 → host         USB 1088 URB_BULK in
 2504  13.829669         host → 2.38.1       USB 64 URB_BULK in
 2505  13.829669       2.38.1 → host         USB 1088 URB_BULK in
 2506  13.829708         host → 2.38.1       USB 64 URB_BULK in
 2507  13.829730       2.38.1 → host         USB 1088 URB_BULK in
 2508  13.829739       2.38.1 → host         USB 1088 URB_BULK in
 2509  13.829746       2.38.1 → host         USB 1088 URB_BULK in
 2510  13.829783       2.38.1 → host         USB 1088 URB_BULK in
 2511  13.829810         host → 2.38.1       USB 64 URB_BULK in
 2512  13.829834         host → 2.38.1       USB 64 URB_BULK in
 2513  13.829847         host → 2.38.1       USB 64 URB_BULK in
 2514  13.829860       2.38.1 → host         USB 1088 URB_BULK in
 2515  13.829864         host → 2.38.1       USB 64 URB_BULK in
 2516  13.829878         host → 2.38.1       USB 64 URB_BULK in
 2517  13.829906         host → 2.38.1       USB 64 URB_BULK in
 2518  13.829934       2.38.1 → host         USB 1088 URB_BULK in
 2519  13.829938         host → 2.38.1       USB 64 URB_BULK in
 2520  13.829942       2.38.1 → host         USB 1088 URB_BULK in
 2521  13.829954       2.38.1 → host         USB 1088 URB_BULK in
 2522  13.829962       2.38.1 → host         USB 1088 URB_BULK in
 2523  13.829970       2.38.1 → host         USB 1088 URB_BULK in
 2524  13.830012       2.38.1 → host         USB 1088 URB_BULK in
 2525  13.830037         host → 2.38.1       USB 64 URB_BULK in
 2526  13.830054         host → 2.38.1       USB 64 URB_BULK in
 2527  13.830074         host → 2.38.1       USB 64 URB_BULK in
 2528  13.830086       2.38.1 → host         USB 1088 URB_BULK in
 2529  13.830090         host → 2.38.1       USB 64 URB_BULK in
 2530  13.830111         host → 2.38.1       USB 64 URB_BULK in
 2531  13.830147       2.38.1 → host         USB 1088 URB_BULK in
 2532  13.830156       2.38.1 → host         USB 1088 URB_BULK in
 2533  13.830157         host → 2.38.1       USB 64 URB_BULK in
 2534  13.830169         host → 2.38.1       USB 64 URB_BULK in
 2535  13.830171       2.38.1 → host         USB 1088 URB_BULK in
 2536  13.830228       2.38.1 → host         USB 1088 URB_BULK in
 2537  13.830236       2.38.1 → host         USB 1088 URB_BULK in
 2538  13.830246       2.38.1 → host         USB 1088 URB_BULK in
 2539  13.830257         host → 2.38.1       USB 64 URB_BULK in
 2540  13.830273         host → 2.38.1       USB 64 URB_BULK in
 2541  13.830289         host → 2.38.1       USB 64 URB_BULK in
 2542  13.830310         host → 2.38.1       USB 64 URB_BULK in
 2543  13.830326       2.38.1 → host         USB 1088 URB_BULK in
 2544  13.830330         host → 2.38.1       USB 64 URB_BULK in
 2545  13.830334       2.38.1 → host         USB 1088 URB_BULK in
 2546  13.830345         host → 2.38.1       USB 64 URB_BULK in
 2547  13.830346       2.38.1 → host         USB 1088 URB_BULK in
 2548  13.830409       2.38.1 → host         USB 1088 URB_BULK in
 2549  13.830418       2.38.1 → host         USB 1088 URB_BULK in
 2550  13.830426       2.38.1 → host         USB 1088 URB_BULK in
 2551  13.830438         host → 2.38.1       USB 64 URB_BULK in
 2552  13.830451         host → 2.38.1       USB 64 URB_BULK in
 2553  13.830467         host → 2.38.1       USB 64 URB_BULK in
 2554  13.830482         host → 2.38.1       USB 64 URB_BULK in
 2555  13.830498       2.38.1 → host         USB 1088 URB_BULK in
 2556  13.830502         host → 2.38.1       USB 64 URB_BULK in
 2557  13.830510       2.38.1 → host         USB 1088 URB_BULK in
 2558  13.830519       2.38.1 → host         USB 1088 URB_BULK in
 2559  13.830523         host → 2.38.1       USB 64 URB_BULK in
 2560  13.830536         host → 2.38.1       USB 64 URB_BULK in
 2561  13.830552         host → 2.38.1       USB 64 URB_BULK in
 2562  13.830586       2.38.1 → host         USB 1088 URB_BULK in
 2563  13.830594       2.38.1 → host         USB 1088 URB_BULK in
 2564  13.830602       2.38.1 → host         USB 1088 URB_BULK in
 2565  13.830610       2.38.1 → host         USB 1088 URB_BULK in
 2566  13.830618       2.38.1 → host         USB 1088 URB_BULK in
 2567  13.830678         host → 2.38.1       USB 64 URB_BULK in
 2568  13.830700         host → 2.38.1       USB 64 URB_BULK in
 2569  13.830715         host → 2.38.1       USB 64 URB_BULK in
 2570  13.830730       2.38.1 → host         USB 1088 URB_BULK in
 2571  13.830733         host → 2.38.1       USB 64 URB_BULK in
 2572  13.830747         host → 2.38.1       USB 64 URB_BULK in
 2573  13.830803       2.38.1 → host         USB 1088 URB_BULK in
 2574  13.830811       2.38.1 → host         USB 1088 URB_BULK in
 2575  13.830819       2.38.1 → host         USB 1088 URB_BULK in
 2576  13.830827       2.38.1 → host         USB 1088 URB_BULK in
 2577  13.830839         host → 2.38.1       USB 64 URB_BULK in
 2578  13.830854         host → 2.38.1       USB 64 URB_BULK in
 2579  13.830873         host → 2.38.1       USB 64 URB_BULK in
 2580  13.830899       2.38.1 → host         USB 1088 URB_BULK in
 2581  13.830907       2.38.1 → host         USB 1088 URB_BULK in
 2582  13.830916         host → 2.38.1       USB 64 URB_BULK in
 2583  13.830936         host → 2.38.1       USB 64 URB_BULK in
 2584  13.830956       2.38.1 → host         USB 1088 URB_BULK in
 2585  13.830959         host → 2.38.1       USB 64 URB_BULK in
 2586  13.830973         host → 2.38.1       USB 64 URB_BULK in
 2587  13.831006       2.38.1 → host         USB 1088 URB_BULK in
 2588  13.831008         host → 2.38.1       USB 64 URB_BULK in
 2589  13.831021       2.38.1 → host         USB 1088 URB_BULK in
 2590  13.831025         host → 2.38.1       USB 64 URB_BULK in
 2591  13.831029       2.38.1 → host         USB 1088 URB_BULK in
 2592  13.831040         host → 2.38.1       USB 64 URB_BULK in
 2593  13.831041       2.38.1 → host         USB 1088 URB_BULK in
 2594  13.831101       2.38.1 → host         USB 1088 URB_BULK in
 2595  13.831109       2.38.1 → host         USB 1088 URB_BULK in
 2596  13.831117       2.38.1 → host         USB 1088 URB_BULK in
 2597  13.831127         host → 2.38.1       USB 64 URB_BULK in
 2598  13.831144         host → 2.38.1       USB 64 URB_BULK in
 2599  13.831167         host → 2.38.1       USB 64 URB_BULK in
 2600  13.831182         host → 2.38.1       USB 64 URB_BULK in
 2601  13.831190       2.38.1 → host         USB 1088 URB_BULK in
 2602  13.831195         host → 2.38.1       USB 64 URB_BULK in
 2603  13.831241       2.38.1 → host         USB 1088 URB_BULK in
 2604  13.831248       2.38.1 → host         USB 1088 URB_BULK in
 2605  13.831256       2.38.1 → host         USB 1088 URB_BULK in
 2606  13.831264       2.38.1 → host         USB 1088 URB_BULK in
 2607  13.831299         host → 2.38.1       USB 64 URB_BULK in
 2608  13.831312         host → 2.38.1       USB 64 URB_BULK in
 2609  13.831327         host → 2.38.1       USB 64 URB_BULK in
 2610  13.831355       2.38.1 → host         USB 1088 URB_BULK in
 2611  13.831360         host → 2.38.1       USB 64 URB_BULK in
 2612  13.831393       2.38.1 → host         USB 1088 URB_BULK in
 2613  13.831401       2.38.1 → host         USB 1088 URB_BULK in
 2614  13.831410       2.38.1 → host         USB 1088 URB_BULK in
 2615  13.831420         host → 2.38.1       USB 64 URB_BULK in
 2616  13.831439         host → 2.38.1       USB 64 URB_BULK in
 2617  13.831457         host → 2.38.1       USB 64 URB_BULK in
 2618  13.831470         host → 2.38.1       USB 64 URB_BULK in
 2619  13.831480       2.38.1 → host         USB 1088 URB_BULK in
 2620  13.831485         host → 2.38.1       USB 64 URB_BULK in
 2621  13.831489       2.38.1 → host         USB 1088 URB_BULK in
 2622  13.831505         host → 2.38.1       USB 64 URB_BULK in
 2623  13.831516         host → 2.38.1       USB 64 URB_BULK in
 2624  13.831563       2.38.1 → host         USB 1088 URB_BULK in
 2625  13.831567         host → 2.38.1       USB 64 URB_BULK in
 2626  13.831571       2.38.1 → host         USB 1088 URB_BULK in
 2627  13.831583       2.38.1 → host         USB 1088 URB_BULK in
 2628  13.831591       2.38.1 → host         USB 1088 URB_BULK in
 2629  13.831643       2.38.1 → host         USB 1088 URB_BULK in
 2630  13.831651       2.38.1 → host         USB 1088 URB_BULK in
 2631  13.831677         host → 2.38.1       USB 64 URB_BULK in
 2632  13.831705         host → 2.38.1       USB 64 URB_BULK in
 2633  13.831728       2.38.1 → host         USB 1088 URB_BULK in
 2634  13.831739         host → 2.38.1       USB 64 URB_BULK in
 2635  13.831754         host → 2.38.1       USB 64 URB_BULK in
 2636  13.831772       2.38.1 → host         USB 1088 URB_BULK in
 2637  13.831774         host → 2.38.1       USB 64 URB_BULK in
 2638  13.831794         host → 2.38.1       USB 64 URB_BULK in
 2639  13.831807         host → 2.38.1       USB 64 URB_BULK in
 2640  13.831853       2.38.1 → host         USB 1088 URB_BULK in
 2641  13.831858         host → 2.38.1       USB 64 URB_BULK in
 2642  13.831862       2.38.1 → host         USB 1088 URB_BULK in
 2643  13.831874       2.38.1 → host         USB 1088 URB_BULK in
 2644  13.831877         host → 2.38.1       USB 64 URB_BULK in
 2645  13.831882       2.38.1 → host         USB 1088 URB_BULK in
 2646  13.831892         host → 2.38.1       USB 64 URB_BULK in
 2647  13.831894       2.38.1 → host         USB 1088 URB_BULK in
 2648  13.831929         host → 2.38.1       USB 64 URB_BULK in
 2649  13.831974       2.38.1 → host         USB 1088 URB_BULK in
 2650  13.831978         host → 2.38.1       USB 64 URB_BULK in
 2651  13.831982       2.38.1 → host         USB 1088 URB_BULK in
 2652  13.831993         host → 2.38.1       USB 64 URB_BULK in
 2653  13.831994       2.38.1 → host         USB 1088 URB_BULK in
 2654  13.832007       2.38.1 → host         USB 1088 URB_BULK in
 2655  13.832061       2.38.1 → host         USB 1088 URB_BULK in
 2656  13.832070       2.38.1 → host         USB 1088 URB_BULK in
 2657  13.832100         host → 2.38.1       USB 64 URB_BULK in
 2658  13.832120         host → 2.38.1       USB 64 URB_BULK in
 2659  13.832136         host → 2.38.1       USB 64 URB_BULK in
 2660  13.832150       2.38.1 → host         USB 1088 URB_BULK in
 2661  13.832152         host → 2.38.1       USB 64 URB_BULK in
 2662  13.832172         host → 2.38.1       USB 64 URB_BULK in
 2663  13.832185         host → 2.38.1       USB 64 URB_BULK in
 2664  13.832225       2.38.1 → host         USB 1088 URB_BULK in
 2665  13.832229         host → 2.38.1       USB 64 URB_BULK in
 2666  13.832233       2.38.1 → host         USB 1088 URB_BULK in
 2667  13.832243         host → 2.38.1       USB 64 URB_BULK in
 2668  13.832245       2.38.1 → host         USB 1088 URB_BULK in
 2669  13.832256       2.38.1 → host         USB 1088 URB_BULK in
 2670  13.832260         host → 2.38.1       USB 64 URB_BULK in
 2671  13.832264       2.38.1 → host         USB 1088 URB_BULK in
 2672  13.832275       2.38.1 → host         USB 1088 URB_BULK in
 2673  13.832339       2.38.1 → host         USB 1088 URB_BULK in
 2674  13.832348       2.38.1 → host         USB 1088 URB_BULK in
 2675  13.832359         host → 2.38.1       USB 64 URB_BULK in
 2676  13.832377         host → 2.38.1       USB 64 URB_BULK in
 2677  13.832391         host → 2.38.1       USB 64 URB_BULK in
 2678  13.832410         host → 2.38.1       USB 64 URB_BULK in
 2679  13.832411       2.38.1 → host         USB 1088 URB_BULK in
 2680  13.832423         host → 2.38.1       USB 64 URB_BULK in
 2681  13.832474       2.38.1 → host         USB 1088 URB_BULK in
 2682  13.832483       2.38.1 → host         USB 1088 URB_BULK in
 2683  13.832491       2.38.1 → host         USB 1088 URB_BULK in
 2684  13.832499       2.38.1 → host         USB 1088 URB_BULK in
 2685  13.832524         host → 2.38.1       USB 64 URB_BULK in
 2686  13.832542         host → 2.38.1       USB 64 URB_BULK in
 2687  13.832562         host → 2.38.1       USB 64 URB_BULK in
 2688  13.832586       2.38.1 → host         USB 1088 URB_BULK in
 2689  13.832595         host → 2.38.1       USB 64 URB_BULK in
 2690  13.832632       2.38.1 → host         USB 1088 URB_BULK in
 2691  13.832640       2.38.1 → host         USB 1088 URB_BULK in
 2692  13.832652         host → 2.38.1       USB 64 URB_BULK in
 2693  13.832667         host → 2.38.1       USB 64 URB_BULK in
 2694  13.832690       2.38.1 → host         USB 1088 URB_BULK in
 2695  13.832714         host → 2.38.1       USB 64 URB_BULK in
 2696  13.832747       2.38.1 → host         USB 1088 URB_BULK in
 2697  13.832749         host → 2.38.1       USB 64 URB_BULK in
 2698  13.832758       2.38.1 → host         USB 1088 URB_BULK in
 2699  13.832765         host → 2.38.1       USB 64 URB_BULK in
 2700  13.832785         host → 2.38.1       USB 64 URB_BULK in
 2701  13.832832       2.38.1 → host         USB 1088 URB_BULK in
 2702  13.832840       2.38.1 → host         USB 1088 URB_BULK in
 2703  13.832848       2.38.1 → host         USB 1088 URB_BULK in
 2704  13.832856       2.38.1 → host         USB 1088 URB_BULK in
 2705  13.832866         host → 2.38.1       USB 64 URB_BULK in
 2706  13.832882         host → 2.38.1       USB 64 URB_BULK in
 2707  13.832897         host → 2.38.1       USB 64 URB_BULK in
 2708  13.832927       2.38.1 → host         USB 1088 URB_BULK in
 2709  13.832930         host → 2.38.1       USB 64 URB_BULK in
 2710  13.832951         host → 2.38.1       USB 64 URB_BULK in
 2711  13.832987       2.38.1 → host         USB 1088 URB_BULK in
 2712  13.832991         host → 2.38.1       USB 64 URB_BULK in
 2713  13.832995       2.38.1 → host         USB 1088 URB_BULK in
 2714  13.833006         host → 2.38.1       USB 64 URB_BULK in
 2715  13.833007       2.38.1 → host         USB 1088 URB_BULK in
 2716  13.833018         host → 2.38.1       USB 64 URB_BULK in
 2717  13.833019       2.38.1 → host         USB 1088 URB_BULK in
 2718  13.833031       2.38.1 → host         USB 1088 URB_BULK in
 2719  13.833096       2.38.1 → host         USB 1088 URB_BULK in
 2720  13.833104       2.38.1 → host         USB 1088 URB_BULK in
 2721  13.833116         host → 2.38.1       USB 64 URB_BULK in
 2722  13.833135         host → 2.38.1       USB 64 URB_BULK in
 2723  13.833151         host → 2.38.1       USB 64 URB_BULK in
 2724  13.833178       2.38.1 → host         USB 1088 URB_BULK in
 2725  13.833180         host → 2.38.1       USB 64 URB_BULK in
 2726  13.833197         host → 2.38.1       USB 64 URB_BULK in
 2727  13.833213         host → 2.38.1       USB 64 URB_BULK in
 2728  13.833248       2.38.1 → host         USB 1088 URB_BULK in
 2729  13.833252         host → 2.38.1       USB 64 URB_BULK in
 2730  13.833256       2.38.1 → host         USB 1088 URB_BULK in
 2731  13.833268         host → 2.38.1       USB 64 URB_BULK in
 2732  13.833269       2.38.1 → host         USB 1088 URB_BULK in
 2733  13.833281       2.38.1 → host         USB 1088 URB_BULK in
 2734  13.833348       2.38.1 → host         USB 1088 URB_BULK in
 2735  13.833356       2.38.1 → host         USB 1088 URB_BULK in
 2736  13.833364       2.38.1 → host         USB 1088 URB_BULK in
 2737  13.833394         host → 2.38.1       USB 64 URB_BULK in
 2738  13.833407         host → 2.38.1       USB 64 URB_BULK in
 2739  13.833423         host → 2.38.1       USB 64 URB_BULK in
 2740  13.833459       2.38.1 → host         USB 1088 URB_BULK in
 2741  13.833467       2.38.1 → host         USB 1088 URB_BULK in
 2742  13.833475       2.38.1 → host         USB 1088 URB_BULK in
 2743  13.833495         host → 2.38.1       USB 64 URB_BULK in
 2744  13.833509         host → 2.38.1       USB 64 URB_BULK in
 2745  13.833527         host → 2.38.1       USB 64 URB_BULK in
 2746  13.833539         host → 2.38.1       USB 64 URB_BULK in
 2747  13.833559         host → 2.38.1       USB 64 URB_BULK in
 2748  13.833570       2.38.1 → host         USB 1088 URB_BULK in
 2749  13.833571         host → 2.38.1       USB 64 URB_BULK in
 2750  13.833585         host → 2.38.1       USB 64 URB_BULK in
 2751  13.833593       2.38.1 → host         USB 1088 URB_BULK in
 2752  13.833599         host → 2.38.1       USB 64 URB_BULK in
 2753  13.833602       2.38.1 → host         USB 1088 URB_BULK in
 2754  13.833613       2.38.1 → host         USB 1088 URB_BULK in
 2755  13.833621       2.38.1 → host         USB 1088 URB_BULK in
 2756  13.833629       2.38.1 → host         USB 1088 URB_BULK in
 2757  13.833638       2.38.1 → host         USB 1088 URB_BULK in
 2758  13.833681       2.38.1 → host         USB 1088 URB_BULK in
 2759  13.834741         host → 2.38.1       USB 64 URB_BULK in
 2760  13.834756         host → 2.38.1       USB 64 URB_BULK in
 2761  13.834770         host → 2.38.1       USB 64 URB_BULK in
 2762  13.834788         host → 2.38.1       USB 64 URB_BULK in
 2763  13.834800         host → 2.38.1       USB 64 URB_BULK in
 2764  13.834818       2.38.1 → host         USB 1088 URB_BULK in
 2765  13.834827       2.38.1 → host         USB 1088 URB_BULK in
 2766  13.834835       2.38.1 → host         USB 1088 URB_BULK in
 2767  13.834836         host → 2.38.1       USB 64 URB_BULK in
 2768  13.834850       2.38.1 → host         USB 1088 URB_BULK in
 2769  13.834851         host → 2.38.1       USB 64 URB_BULK in
 2770  13.834864         host → 2.38.1       USB 64 URB_BULK in
 2771  13.834865       2.38.1 → host         USB 1088 URB_BULK in
 2772  13.834878         host → 2.38.1       USB 64 URB_BULK in
 2773  13.834897         host → 2.38.1       USB 64 URB_BULK in
 2774  13.834951       2.38.1 → host         USB 1088 URB_BULK in
 2775  13.834953         host → 2.38.1       USB 64 URB_BULK in
 2776  13.834967         host → 2.38.1       USB 64 URB_BULK in
 2777  13.834976       2.38.1 → host         USB 1088 URB_BULK in
 2778  13.834979         host → 2.38.1       USB 64 URB_BULK in
 2779  13.834984       2.38.1 → host         USB 1088 URB_BULK in
 2780  13.834995       2.38.1 → host         USB 1088 URB_BULK in
 2781  13.835004       2.38.1 → host         USB 1088 URB_BULK in
 2782  13.835012       2.38.1 → host         USB 1088 URB_BULK in
 2783  13.835020       2.38.1 → host         USB 1088 URB_BULK in
 2784  13.835027         host → 2.38.1       USB 64 URB_BULK in
 2785  13.835028       2.38.1 → host         USB 1088 URB_BULK in
 2786  13.835047         host → 2.38.1       USB 64 URB_BULK in
 2787  13.835062         host → 2.38.1       USB 64 URB_BULK in
 2788  13.835076         host → 2.38.1       USB 64 URB_BULK in
 2789  13.835106       2.38.1 → host         USB 1088 URB_BULK in
 2790  13.835114       2.38.1 → host         USB 1088 URB_BULK in
 2791  13.835119         host → 2.38.1       USB 64 URB_BULK in
 2792  13.835123       2.38.1 → host         USB 1088 URB_BULK in
 2793  13.835134         host → 2.38.1       USB 64 URB_BULK in
 2794  13.835149         host → 2.38.1       USB 64 URB_BULK in
 2795  13.835200       2.38.1 → host         USB 1088 URB_BULK in
 2796  13.835203         host → 2.38.1       USB 64 URB_BULK in
 2797  13.835213       2.38.1 → host         USB 1088 URB_BULK in
 2798  13.835221       2.38.1 → host         USB 1088 URB_BULK in
 2799  13.835224         host → 2.38.1       USB 64 URB_BULK in
 2800  13.835232       2.38.1 → host         USB 1088 URB_BULK in
 2801  13.835241         host → 2.38.1       USB 64 URB_BULK in
 2802  13.835257         host → 2.38.1       USB 64 URB_BULK in
 2803  13.835285       2.38.1 → host         USB 1088 URB_BULK in
 2804  13.835288         host → 2.38.1       USB 64 URB_BULK in
 2805  13.835296       2.38.1 → host         USB 1088 URB_BULK in
 2806  13.835309         host → 2.38.1       USB 64 URB_BULK in
 2807  13.835321         host → 2.38.1       USB 64 URB_BULK in
 2808  13.835360       2.38.1 → host         USB 1088 URB_BULK in
 2809  13.835366         host → 2.38.1       USB 64 URB_BULK in
 2810  13.835374       2.38.1 → host         USB 1088 URB_BULK in
 2811  13.835380         host → 2.38.1       USB 64 URB_BULK in
 2812  13.835383       2.38.1 → host         USB 1088 URB_BULK in
 2813  13.835394       2.38.1 → host         USB 1088 URB_BULK in
 2814  13.835401         host → 2.38.1       USB 64 URB_BULK in
 2815  13.835402       2.38.1 → host         USB 1088 URB_BULK in
 2816  13.835414       2.38.1 → host         USB 1088 URB_BULK in
 2817  13.835417         host → 2.38.1       USB 64 URB_BULK in
 2818  13.835430         host → 2.38.1       USB 64 URB_BULK in
 2819  13.835447         host → 2.38.1       USB 64 URB_BULK in
 2820  13.835467       2.38.1 → host         USB 1088 URB_BULK in
 2821  13.835476       2.38.1 → host         USB 1088 URB_BULK in
 2822  13.835479         host → 2.38.1       USB 64 URB_BULK in
 2823  13.835484       2.38.1 → host         USB 1088 URB_BULK in
 2824  13.835495         host → 2.38.1       USB 64 URB_BULK in
 2825  13.835496       2.38.1 → host         USB 1088 URB_BULK in
 2826  13.835508       2.38.1 → host         USB 1088 URB_BULK in
 2827  13.835514         host → 2.38.1       USB 64 URB_BULK in
 2828  13.835534         host → 2.38.1       USB 64 URB_BULK in
 2829  13.835546         host → 2.38.1       USB 64 URB_BULK in
 2830  13.835582       2.38.1 → host         USB 1088 URB_BULK in
 2831  13.835588         host → 2.38.1       USB 64 URB_BULK in
 2832  13.835597       2.38.1 → host         USB 1088 URB_BULK in
 2833  13.835601         host → 2.38.1       USB 64 URB_BULK in
 2834  13.835605       2.38.1 → host         USB 1088 URB_BULK in
 2835  13.835615         host → 2.38.1       USB 64 URB_BULK in
 2836  13.835616       2.38.1 → host         USB 1088 URB_BULK in
 2837  13.835630       2.38.1 → host         USB 1088 URB_BULK in
 2838  13.835637         host → 2.38.1       USB 64 URB_BULK in
 2839  13.835638       2.38.1 → host         USB 1088 URB_BULK in
 2840  13.835650         host → 2.38.1       USB 64 URB_BULK in
 2841  13.835651       2.38.1 → host         USB 1088 URB_BULK in
 2842  13.835669         host → 2.38.1       USB 64 URB_BULK in
 2843  13.835689         host → 2.38.1       USB 64 URB_BULK in
 2844  13.835744       2.38.1 → host         USB 1088 URB_BULK in
 2845  13.835745         host → 2.38.1       USB 64 URB_BULK in
 2846  13.835759         host → 2.38.1       USB 64 URB_BULK in
 2847  13.835763       2.38.1 → host         USB 1088 URB_BULK in
 2848  13.835775         host → 2.38.1       USB 64 URB_BULK in
 2849  13.835775       2.38.2 → host         USB 80 URB_BULK in
 2850  13.835788       2.38.1 → host         USB 1088 URB_BULK in
 2851  13.835789         host → 2.38.1       USB 64 URB_BULK in
 2852  13.835803       2.38.1 → host         USB 1088 URB_BULK in
 2853  13.835811       2.38.1 → host         USB 1088 URB_BULK in
 2854  13.835819         host → 2.38.2       USB 64 URB_BULK in
 2855  13.835832         host → 2.38.1       USB 64 URB_BULK in
 2856  13.835850         host → 2.38.1       USB 64 URB_BULK in
 2857  13.835862         host → 2.38.1       USB 64 URB_BULK in
 2858  13.835873         host → 2.38.1       USB 64 URB_BULK in

なぜこんなに処理時間が長くなってしまったのか、推論実行中のUSBキャプチャログから解析します。
使用したのは、出力サイズが256x256x3のモデルです。

上記ログを見ると、デバイス->hostに対して定期的に1088 Byteの転送があります。これ以外に目立った通信は無いため、おそらくこれが出力データなのだと思います。
ちなみに、全部で256回の通信がありました。本当に必要なデータ数は256x256x3なので、256x1088は少し無駄があります。~~また、先ほどの入力データの場合は圧縮されているように見えるのに対して、こっちはおそらく非圧縮です(←想像ですが)。~~また、そもそも大容量を1回のバルク転送で送るのに比べて、コマ切れに送るのでは転送効率も悪いと思います。

恐らくこれが、データ出力の処理時間が遅い原因だと思います。

なんでこんなことになっているのか?

以下、想像です。

入力データに関しては、~~処理開始前にHOST側(今回はJetson Nano)で、高速に圧縮などが出来ます。また、~~ データを1回のバルク転送で一気にEdge TPUに送信しても、それはそのままネットワークに食わせることが出来ます。

一方、出力データは一度にまとめて出力されるのではなく、順次出力されると思われます。そのため、出てきた順にEdge TPU -> Hostに送るしかありません。大容量の出力バッファがあればいいのですが、おそらく用意されていないのだと思います。また、モデルによっては、転送の効率化よりも、出てきた順にデータ転送した方が良いのかもしれません。
とはいえ、それでも多少はまとめて送ろうとはしているのだと思います。そのためのバッファサイズが1088 Byteとか？単にUSB界隈でよく使われている数字なだけかもしれませんが、そこらへんは詳しくないです。。。

念のため別のモデルで検証

「入力データの転送に比べて、出力データの転送には時間がかかる。」という実験結果が得られました。
一つだけ気になるのが、「出力データの転送には時間がかかる」というのは、単にpadding処理で時間がかかっているだけでは? ということです。
この懸念を解消するために、以下のような、モデル内部でパディングして一度サイズを大きくして、その後Conv(stride大)で間引いて小さくするという、モデルで処理時間を測定しました。

model_generator_padding_stride.py

# -*- coding: utf-8 -*-
import tensorflow as tf
from tensorflow.python.keras.models import Model
from tensorflow.python.keras.layers import Input, Reshape, Dense, Add, Conv2D, ZeroPadding2D

# Model parameters
INTERNAL_MODEL_WIDTH = 256
INTERNAL_MODEL_HEIGHT = 256
MODEL_CHANNEL = 3

# Create model structure
input0 = Input(shape=(2,2,MODEL_CHANNEL))
pad0 = ZeroPadding2D(padding=((int)(INTERNAL_MODEL_WIDTH/2)-1, (int)(INTERNAL_MODEL_HEIGHT/2)-1))(input0)
conv0 = Conv2D(
      filters=1,
      kernel_size=(1,1),
      strides=(INTERNAL_MODEL_WIDTH,INTERNAL_MODEL_HEIGHT),
      padding='valid',
      activation='relu'
)(pad0)
model = Model(inputs=[input0], outputs=[conv0])

# Save model
model.summary()
model.compile(
    optimizer='adam',
    loss='categorical_crossentropy',
    metrics=['accuracy']
)
model_name = 'model_padding_stride/model_padding_stride_' + str(INTERNAL_MODEL_WIDTH) +'x' + str(INTERNAL_MODEL_HEIGHT) + 'x' + str(MODEL_CHANNEL)
model.save(model_name + '.h5')

# Convert to quantized tflite
converter = tf.lite.TFLiteConverter.from_keras_model_file(model_name + '.h5')
converter.inference_type = tf.lite.constants.QUANTIZED_UINT8
converter.default_ranges_stats = (0, 6)
input_arrays = converter.get_input_arrays()
converter.quantized_input_stats = {input_arrays[0] : (128., 127.)}  # mean, std_dev
tflite_model = converter.convert()
open(model_name + '.tflite', "wb").write(tflite_model)

結果

モデル構造			Size [Kbyte]	処理時間 [msec]
Input	Output	Internal	Internal	10W			5W
				CPU	EdgeTPU	EdgeTPU (USB2.0)	CPU	EdgeTPU	EdgeTPU (USB2.0)
2x2x3	1x1x3	2x2x3	0.012	0.0093	0.2926	0.3666	0.0150	0.4597	0.5308
2x2x3	1x1x3	64x64x3	12.288	0.0109	0.2959	0.3812	0.0168	0.4225	0.5455
2x2x3	1x1x3	128x64x3	24.576	0.0118	0.2952	0.3811	0.0181	0.4564	0.5522
2x2x3	1x1x3	128x128x3	49.152	0.0150	0.2969	0.3847	0.0223	0.4584	0.5144
2x2x3	1x1x3	256x128x3	98.304	0.0203	0.2991	0.3862	0.0303	0.4583	0.5349
2x2x3	1x1x3	256x256x3	196.608	0.0306	0.3066	0.4028	0.0461	0.4633	0.5321

結果、上記のように内部でいくらpadding処理でサイズを大きくしても処理時間はほとんど変わりませんでした。
つまり、先ほどの出力データ転送の処理時間測定に対して、padding処理の影響はほとんどない、ということが確認できました。

おわりに

ひとまず今回は、入出力だけに絞ってEdge TPUの動作を解析してみました。
IOが絡むせいか、結構大変でした。が、最初にこの影響を確認できたのは良かったです。
これから、モデル構造やオペレーションについても調べようと思っているのですが、データ入出力の影響を考慮しないと、分けわからないことになる所でした。

データ出力が遅いというのは、本当にいい結果が得られたと思います。
Edge TPUの用途的に超解像など、画像を出力する用途はあまりないかもしれないのですが、物体検知でもヒートマップなどを出力するケースでは注意が必要そうです。

ただ、冒頭にも書きましたが、実際のモデルではもしかしたら影響はないのかもしれません。
解析したように、データ出力は推論中に適宜行われます。そのため、モデル内での本当の処理時間がそこそこかかる通常のモデルでは、その時間にうまく隠れて影響が出ないかもしれません。今回は、データ入出力だけに絞ったので、目立ってしまっただけかもしれません。

また、今回はCPUクロックとUSB3/2の違いも比較しましたが、当然な結果しか得られませんでした。今後、モデル構造を変えていったときに、「TPU側での処理時間が支配的だから、CPUが遅くても影響が少ないね」とか、「このモデルは一部のopがCPUにオフロードされているから、CPUの性能をもろに受けるね」といったお話につなげていきたいと思います。

ソースコード・モデル・ログ
https://github.com/iwatake2222/EdgeTPU_Analysis/tree/master/InOut

(追記:2019/06/16) 実用的なモデルで検証

「データ出力が遅い」だけど、「モデル内での本当の処理時間がそこそこかかる通常のモデルでは、その時間にうまく隠れて影響が出ないかもしれません。今回は、データ入出力だけに絞ったので、目立ってしまっただけかもしれません。」と記載しました。

これを確認するために、MobileNet V2で追加検証してみました。

比較するのは、224x224x3サイズのMobileNetV2モデルです。片方は、通常通り出力層があり1000個の識別結果を出力します。もう片方は、出力層をなくして、途中のFeatureMap(7x7x1280)を出力します。
Kerasでモデルロード時に、MobileNetV2(include_top=True) , MobileNetV2(include_top=False) とすることで切り替えています。

下図の左側が出力層有り、右側が出力層無しのモデルの終段の構造です。出力層がある方が、演算量的には不利(演算量が多い)です。

モデル構造			Size [Kbyte]	処理時間 [msec]
	Input	Output	Output	10W
				CPU	EdgeTPU
出力層有	224x224x3	1000	1	91.8787	2.6457
出力層無	224x224x3	7x7x1280	62.72	87.9010	3.8143

結果、上記のようになりました。
測定条件は、Jetson Nano, 10W mode, USB3接続、です。

CPU使用時は、演算量的に不利な出力層有のモデルの方が、遅いです。この結果は自然です。
一方、TPU使用時は、演算量的には有利なはずの出力層無のモデルの方が、遅くなっています。

全結合での処理時間を考慮したら、大体1.5msec程度の差でしょうか。(1.2msec+α)
先ほどの実験結果から、出力サイズが62KByeの場合は、出力データ転送時間はざっくり3msec程度と見積もれます。
ですので、データ転送時間がそのまま加算されるわけではないようです。演算中にも転送処理が行われて、その分が隠れるのだと思います。
とはいえ、遅くはなっています。

Edge TPU (USB Accelerator) 使用時は、出来るだけモデル内(TPU内)で出力データ量を絞った方がよさそうです。

(追記:2019/06/16) データ出力の分割数に関して

出力Tensorサイズと速度性能の関係 -> 通信解析の所で、256x256x3の場合、1088 Byteの通信が256回発生していることが分かりました。
この、「256」がどこから来ているのかを検証しました。アスペクト比が縦長、横長選べる場合、効率的な転送方法があるのでは? という期待を込めて。

結果、
128 x 256と256 x 128では、処理時間はほぼ同じでした。。また、256 x 512と512 x 256でも、処理時間はほぼ同じでした。

以下が、通信解析結果です。

128 x 256 x 3: 1088 Byteの通信が、129 回発生
256 x 128 x 3: 1088 Byteの通信が、128 回発生
256 x 256 x 3: 1088 Byteの通信が、129 回発生
256 x 512 x 3: 1088 Byteの通信が、370 回発生
512 x 256 x 3: 1088 Byteの通信が、334 回発生

これを見ると、横幅や縦幅に依らず、転送サイズ数が1088 Byteになったらまとめて転送するような仕組みになっているようです。
通信効率だけで見ると、256x512よりも、512x256の方が少し効率的です。が、処理時間でみるとほぼ同じでした。

ログはこちら。
https://github.com/iwatake2222/EdgeTPU_Analysis/tree/master/InOut/log_wireshark/single_inference

(追記:2019/06/16) USB通信データ詳細

sudo tshark -V -i usbmon2 > log.txt コマンドで通信データの詳細ログが取れるようなので、取ってみました。

結果

入力データ、出力データ、どちらも非圧縮
- 記事の途中に入力データは圧縮されているかも、と書いたけど間違えでした。。。
出力データサイズは毎回 1088Byte。Frame長が1088Byte、内実データが1024Byte

ログ詳細: 入力データ転送

model_stride_256x256x3_edgetpu.tflite モデルを使って、入力サイズ = 256x256x3としたモデルのhost->device通信(入力データと思われる1frameのみ)のログを取得しました。

入力データとして、テストプログラムでimg = Image.new('RGB', (width, height), (127, 128, 129)) を設定。なので、7f8081 のデータ列があるはず。

host->device通信

Frame 251: 61504 bytes on wire (492032 bits), 61504 bytes captured (492032 bits) on interface 0
    Interface id: 0 (usbmon2)
        Interface name: usbmon2
    Encapsulation type: USB packets with Linux header and padding (115)
    Arrival Time: Jun 16, 2019 19:11:28.404189000 JST
    [Time shift for this packet: 0.000000000 seconds]
    Epoch Time: 1560679888.404189000 seconds
    [Time delta from previous captured frame: 0.000076000 seconds]
    [Time delta from previous displayed frame: 0.000076000 seconds]
    [Time since reference or first frame: 15.106933000 seconds]
    Frame Number: 251
    Frame Length: 61504 bytes (492032 bits)
    Capture Length: 61504 bytes (492032 bits)
    [Frame is marked: False]
    [Frame is ignored: False]
    [Protocols in frame: usb]
USB URB
    [Source: host]
    [Destination: 2.9.1]
    URB id: 0xffffffc0c11e29c0
    URB type: URB_SUBMIT ('S')
    URB transfer type: URB_BULK (0x03)
    Endpoint: 0x01, Direction: OUT
        0... .... = Direction: OUT (0)
        .... 0001 = Endpoint number: 1
    Device: 9
    URB bus id: 2
    Device setup request: not relevant ('-')
    Data: present (0)
    URB sec: 1560679888
    URB usec: 404189
    URB status: Operation now in progress (-EINPROGRESS) (-115)
    URB length [bytes]: 196608
    Data length [bytes]: 61440
    [bInterfaceClass: Vendor Specific (0xff)]
    Unused Setup Header
    Interval: 0
    Start frame: 0
    Copy of Transfer Flags: 0x00000000
    Number of ISO descriptors: 0
Leftover Capture Data: 7f80817f80817f80817f80817f80817f80817f80817f8081...

Leftover Capture Data の所に、7f8081... のデータが見つかりました。
Frame Length: 61504 bytesなのですが、実際に送ったデータは256x256x3=196608Byteです。
どうやら、URB lengthがそれに相当するらしい。USB通信のプロトコルはよくわからないので、詳細は不明です。

ログ詳細: 出力データ転送

model_padding_256x256x3_edgetpu.tflite モデルを使って、出力サイズ = 256x256x3としたモデルのdevice->host通信(出力データと思われる1frameのみ)のログを取得しました。

device->host通信

Frame 1358: 1088 bytes on wire (8704 bits), 1088 bytes captured (8704 bits) on interface 0
    Interface id: 0 (usbmon2)
        Interface name: usbmon2
    Encapsulation type: USB packets with Linux header and padding (115)
    Arrival Time: Jun 16, 2019 19:17:46.844009000 JST
    [Time shift for this packet: 0.000000000 seconds]
    Epoch Time: 1560680266.844009000 seconds
    [Time delta from previous captured frame: 0.000110000 seconds]
    [Time delta from previous displayed frame: 0.000110000 seconds]
    [Time since reference or first frame: 8.209078000 seconds]
    Frame Number: 1358
    Frame Length: 1088 bytes (8704 bits)
    Capture Length: 1088 bytes (8704 bits)
    [Frame is marked: False]
    [Frame is ignored: False]
    [Protocols in frame: usb]
USB URB
    [Source: 2.9.1]
    [Destination: host]
    URB id: 0xffffffc0c5481540
    URB type: URB_COMPLETE ('C')
    URB transfer type: URB_BULK (0x03)
    Endpoint: 0x81, Direction: IN
        1... .... = Direction: IN (1)
        .... 0001 = Endpoint number: 1
    Device: 9
    URB bus id: 2
    Device setup request: not relevant ('-')
    Data: present (0)
    URB sec: 1560680266
    URB usec: 844009
    URB status: Success (0)
    URB length [bytes]: 1024
    Data length [bytes]: 1024
    [Request in: 1357]
    [Time from request: 0.000110000 seconds]
    [bInterfaceClass: Vendor Specific (0xff)]
    Unused Setup Header
    Interval: 0
    Start frame: 0
    Copy of Transfer Flags: 0x00000200
    Number of ISO descriptors: 0
Leftover Capture Data: 808080808080808080808080808080808080808080808080...

0パディングしたので、0が量子化された128=0x80が延々と出力されています。
URB lengthは1024Byteです。
Frame Lengthが 1088 bytesなので、ヘッダ相当のものが64Byte、実データが1024Byteということだと思います。

Edge TPU USB Acceleratorの解析 - 入出力データの転送

この記事について

結論

注意

環境

解析に使用したコマンド、操作

Jetson Nanoで動作モードを切り替える

USB3/USB2切り替え

USBキャプチャリング解析

入力Tensorサイズと速度性能の関係

実験用モデルの作成

Edge TPU用に変換

変換に失敗した

実行

結果

通信解析

出力Tensorサイズと速度性能の関係

実験用モデルの作成

実行

結果

ちなみに、

通信解析

なんでこんなことになっているのか?

念のため別のモデルで検証

結果

おわりに

(追記:2019/06/16) 実用的なモデルで検証

(追記:2019/06/16) データ出力の分割数に関して

(追記:2019/06/16) USB通信データ詳細

結果

ログ詳細: 入力データ転送

ログ詳細: 出力データ転送