この記事について
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ということだと思います。