作ったプログラムを実際に動かすときには、さまざまな条件が課せられます。例えば物体検知や姿勢推定を実装したシステムでは、「精度」が典型的な条件でしょう。精度が低くて使い物にならなければ意味ないですからね。
この他にも使用メモリ量に制限があったり、プログラムのサイズに制限があったりすることがあります。でも、精度の次に挙げられることの多い条件は「速度」ではないかと思います。あらかじめ撮りためた画像をバッチ的に処理するのならそれほど問題になりませんが、撮影したそばからいわゆるリアルタイム的に処理が必要な場合には、処理速度が特に重要な要素になります。
さて、速度を向上するためにもっとも有効な手段は、高速なハードウェアを使うことです。当たり前といえば当たり前ですが、これで問題が解決できるならそれにこしたことはありません。が、時にそうは行かないケースもあります。(高速なハードウェアを購入する予算がありませんと言う話ではありません笑)
一般に、高速なハードウェアは消費電力も多く、車載に代表される組込み機器で利用できないというのが典型的なケース。消費電力などの要件を満たすために、例えば「このターゲットハードウェアで30fps出して下さい」と条件設定される場合です。そんな時にやれることは大きく二つあって、ひとつはそのハードウェアの特性に応じてプログラムを最適化すること、もうひとつは正攻法でプログラムを高速化することです。今回は後者について考えてみることにします。
あるお仕事で、姿勢推定のプログラムをターゲットボード上で動作させる作業を行っていた時のこと。リアルタイム処理を求められているのですが、速度が足りず高速化を試みることになりました。プログラムを高速化すると言っても闇雲に手を付けるのは効率が悪い。動作が遅く全体の足かせになっているところから高速化できれば、効率よく作業を進めることができます。プログラムの動作状態を解析し、部分ごとの消費時間を測定する作業をプロファイリングと呼び、プロファイリングを行うことが高速化の方策立案の第一歩になります。
プロファイリングのためにはさまざまなツール(プロファイラ)が用意されていますが、PythonにはcProfileというプロファイラがありますので、これを使ってみることにします。cProfileは、プロファリリングを行う対象をmyscript.pyとすれば
$ python -m cProfile [-o output_file] [-s sort_order] myscript.py
のように使います。output_fileに保存された内容を各部分の消費時間でソートして表示するには
$ echo -e 'sort tottime\nstats' | python3 -m pstats profile.txt | less
のようにします。以下、実際にプロファイルしてみた結果です。注意：今回は都合上プロファイリングを高速なサーバー上で行ないましたが、本来はパフォーマンスが出ていないターゲット環境で行うのが筋です。
$ CUDA_VISIBLE_DEVICES=0 python -m cProfile -s time -o profile.txt tools/demo_mp.py --cfg experiments/coco/efficientnet/efficient_b1_256x192_40_32_32_32_adam_lr1e-3.yaml
$ echo -e 'sort tottime\nstats' | python3 -m pstats profile.txt | less
Welcome to the profile statistics browser.
profile.txt% profile.txt% Sun Jul 26 01:44:58 2020 profile.txt
1231520 function calls (1208713 primitive calls) in 19.429 seconds
Ordered by: internal time
ncalls tottime percall cumtime percall filename:lineno(function)
3666 4.361 0.001 4.361 0.001 {method 'acquire' of '_thread.lock' objects}
3540 2.223 0.001 2.223 0.001 {built-in method __new__ of type object at 0x5604bb2d0d40}
1 2.195 2.195 2.195 2.195 {method 'read' of 'cv2.VideoCapture' objects}
1 2.140 2.140 4.334 4.334 /home/eigo/src/temp/posenet-demo-trt_1Q-fast-nms/venv/lib/python3.7/site-packages/imutils/video/webcamvideostream.py:6(__init__)
252 1.445 0.006 2.485 0.010 /home/eigo/src/temp/posenet-demo-trt_1Q-fast-nms/posenet/object_detector_efnetssd/utils/box_utils.py:179(nms)
1 1.001 1.001 1.001 1.001 {built-in method time.sleep}
252 0.865 0.003 10.120 0.040 tools/pose_util_mp.py:204(predict)
252 0.822 0.003 0.822 0.003 {method 'cuda' of 'torch._C._TensorBase' objects}
253 0.758 0.003 0.758 0.003 {waitKey}
47652 0.629 0.000 0.629 0.000 {built-in method clamp}
522 0.595 0.001 0.595 0.001 {method 'cpu' of 'torch._C._TensorBase' objects}
312 0.312 0.001 0.312 0.001 {method 'copy' of 'numpy.ndarray' objects}
39710 0.278 0.000 0.278 0.000 {built-in method index_select}
534 0.168 0.000 0.168 0.000 {method 'astype' of 'numpy.ndarray' objects}
...
ncallsの列はその機能が呼ばれた回数を示します。tottimeは消費時間。percallは呼ばれるたびに使われた時間なので、tottime/percallです。ncallsが1、すなわち一度しか呼ばれていない機能は初期化部分などなので、ひとまずは無視します。システムの内部メソッド的な名前がついてるやつもひとまず無視。
そうすると下線太字の行が目に止まります。「nms」という関数が時間をとっているようです。今回は高速なサーバー上でプロファイルしたために消費時間が大きくありませんが、低速なターゲット環境上でプロファイルをとるともっと顕著にあらわれます。ひとまず各部分ごとの消費時間の傾向を見たと捉えてください。
NMS (Non Maximum Suppression) は、簡単に言えば複数ある候補から一番いいものを選択するためのアルゴリズムです。NMS自体はディープラーニングとも機械学習とも直接は関係ないのですが、推論結果の処理をする際に用いられることがあり、例えば物体検知では、ひとつのオブジェクトに対し候補となるバウンディングボックスが複数作られます。この中からNMSを用いてもっとも有力なアンカーボックスをひとつだけ採用するのです。
どうやらこのNMS が大きく計算時間を消費して足を引っ張っているようです。次回はNMSを高速化してみます。