"BOKU"のITな日常

興味のむくまま気の向くままに調べたり・まとめたりしてます。

学習時のレイヤー毎の処理時間計測機能(Profile)を試す/Neural Network Consoleの使い方

今回は Neural Network Console(ニューラルネットワークコンソール:以後 NNC)の実行速度を計測するってのをやってみます。

f:id:arakan_no_boku:20190326212937j:plain

 

Profileという機能

 

NNCのドキュメントを見ていると、こういうページがあります。

support.dl.sony.com

 

このページの下段の方にこんな記述があります。

2 設計中のニューラルネットワークの実行速度を詳細に測定するには、学習実行ボタンを右クリックして表示されるポップアップメニューから、Profileを選択します。

なるほど。

実行速度を計測する機能が一応ついているみたいです。 

でも、こんなあっさりした書き方だと、よくわかりません。 

とりあえず、試してみます。

 

サンプルのLeNetで試す

 

NNCをたちあげて、適当なプロジェクト(今回は LeNetにします)を開きます。

f:id:arakan_no_boku:20180327221823j:plain

 

ここで学習を実行する時に、右クリックでメニューを表示して「profile」を選びます。

f:id:arakan_no_boku:20180327222009j:plain

 

実行はすぐに終わります。

f:id:arakan_no_boku:20180327222114j:plain

 

通常の学習グラフとかは描かれず、実行時間が表示され、最後は「Profile Completed」で終わります。 

結果はプロジェクトの結果フォルダに「profile.csv」というファイルに出力されます。 

結果フォルダは、例えばLeNet.sdcprojなら、LeNet.filesフォルダの下に20180327_214703のように日付・時刻の名前でできているフォルダです。 

 

Profileの出力結果

 

今回の結果出力はこんな感じです。

time in ms,optimizer 'Optimizer' with network 'Main'
load_dataset,8.795510
let_data (x to Input),1.474923
let_data (y to CategoricalCrossEntropy_T),1.215375
setup_function (Convolution : Convolution),0.018949
setup_function (ReLU : ReLU),0.015936
setup_function (MaxPooling : MaxPooling),0.016661
setup_function (Convolution_2 : Convolution),0.019913
setup_function (MaxPooling_2 : MaxPooling),0.016837
setup_function (Tanh_2 : Tanh),0.015366
setup_function (Affine : Affine),0.019549
setup_function (ReLU_2 : ReLU),0.016816
setup_function (Affine_2 : Affine),0.018646
setup_function (Softmax : Softmax),0.015892
setup_function (CategoricalCrossEntropy : CategoricalCrossEntropy),0.017392
forward_function (Convolution : Convolution),27.410212
forward_function (ReLU : ReLU : in_place),3.465282
forward_function (MaxPooling : MaxPooling),5.355465
forward_function (Convolution_2 : Convolution),18.437052
forward_function (MaxPooling_2 : MaxPooling),1.697405
forward_function (Tanh_2 : Tanh),0.337538
forward_function (Affine : Affine),2.177109
forward_function (ReLU_2 : ReLU : in_place),0.105423
forward_function (Affine_2 : Affine),0.097511
forward_function (Softmax : Softmax),0.047945
forward_function (CategoricalCrossEntropy : CategoricalCrossEntropy),0.022275
prepare_backward,0.047319
backward_function (CategoricalCrossEntropy : CategoricalCrossEntropy),0.026390
backward_function (Softmax : Softmax),0.028893
backward_function (Affine_2 : Affine),0.215850
backward_function (ReLU_2 : ReLU : in_place),0.073585
backward_function (Affine : Affine),4.904253
backward_function (Tanh_2 : Tanh),0.096198
backward_function (MaxPooling_2 : MaxPooling),0.376493
backward_function (Convolution_2 : Convolution),39.057310
backward_function (MaxPooling : MaxPooling),1.724951
backward_function (ReLU : ReLU : in_place),2.270902
backward_function (Convolution : Convolution),22.783430
forward_all,59.236925
backward_all,71.124361
backward_all(wo param zero_grad),71.054265
update (Adam),1.309114
monitor_loss,0.795285

 

data_load、ネットワーク構築(Setup)、順伝播(forward)、逆伝播(backward)で各レイヤー毎の実行時間がミリ秒(ms)単位で記録されています。 

batch1回分の時間みたいです。 

 

結果をEXCELでちょっとだけ分析

 

このまま眺めてても、「ふーん」で終わります。 

EXCELに読み込んで、トータル時間を合計して、各ステップ毎の時間の割合(%)を計算してみました。

f:id:arakan_no_boku:20180327235452j:plain

 

Convolutionの合計(Setup+forward+backward)が、全体の約75%以上です。 

次がデータロードとMaxPoolingの各約6%なので、この3つで約87%以上ですね。 

CNNでConvoluton+Poolingのレイヤーが深くなると、学習にかかる時間が爆発的に増加する理由がよくわかります。 

今回、合計してみると約142ミリ秒でした。 

これがバッチサイズ1回分ということみたいです。

だったら、1epocheにかかる見込み時間は「データ60000件÷バッチサイズ(64)回数(切り上げ)分✕142ミリ秒」で計算できることになります。

これにEpoche数をかけると、だいたいの学習にかかる時間も予想できるのですかね。

試しに、計算してみました。 

約22分位です。 

実際にやってみた学習の所要時間が約31分ほど。 

ちょっと誤差があります。 

けど。

Profile時にはやってない1Epoche毎のバリデーションのステップがあったり、グラフの描画していたりとか、正味の学習以外のオーバーヘッドがありますからね。

計算の約1.4倍ってのは、だいたいそんなもん・・なんでしょうかね。 

まあ・・。

実行速度にシビアなプログラム開発をしている時みたいに、この結果を見てどうこうということが必要なケースは、そうないんじゃないかと思います。 

でも、複雑なネットワークを組んだりした時に、だいたいの学習時間を予測したりとか、そういう用途には使えそうではありますね。

今回はこんな感じで。