アラカン"BOKU"のITな日常

文系システムエンジニアの”BOKU”が勉強したこと、経験したこと、日々思うことを書いてます。

学習の実行速度を計測する機能(Profile)を試してみる/使い方31/Neural Network Console

 Neural Network Console(ニューラルネットワークコンソール:以後 NNC)のドキュメントを見ていると、こういうページがあります。

support.dl.sony.com

 

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

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

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

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

 

サンプルのLeNetで試してみよう

 

プロファイラ機能は通常、関数の呼び出しの頻度やそれにかかる時間を計測して、無駄なループや性能のボトルネックになっている部分を調査するために使います。 

NNCの場合は各レイヤーが関数にあたるのですかね。 

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のように日付・時刻の名前でできているフォルダです。 

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

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に読み込んで、トータル時間を合計して、各ステップ毎の時間の割合(%)を計算してみました。

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倍ってのは、だいたいそんなもん・・なんでしょうかね。 

正直。 

今は、シビアにチューニングが必要なことはやってません。 

だから、実行速度にシビアなプログラム開発をしている時みたいに、この結果を見てどうこうというのはしないと思います。 

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

もちろん。 

超ざっくり・・ですが(笑) 

ま、こういう機能も使えるんだというが確認できたところで、今回はこんな感じで。

 

f:id:arakan_no_boku:20171115215731j:plain