今回は Neural Network Console（ニューラルネットワークコンソール：以後 NNC）の実行速度を計測するってのをやってみます。
学習時のレイヤー毎の処理時間計測機能（Profile）を試す
NNCのドキュメントを見ていると、こういうページがあります。
このページの下段の方にこんな記述があります。
2 設計中のニューラルネットワークの実行速度を詳細に測定するには、学習実行ボタンを右クリックして表示されるポップアップメニューから、Profileを選択します。
なるほど。
実行速度を計測する機能が一応ついているみたいです。
でも、こんなあっさりした書き方だと、よくわかりません。
とりあえず、試してみます。
サンプルのLeNetで試す
NNCをたちあげて、適当なプロジェクト（今回は LeNetにします）を開きます。
ここで学習を実行する時に、右クリックでメニューを表示して「profile」を選びます。
実行はすぐに終わります。
通常の学習グラフとかは描かれず、実行時間が表示され、最後は「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)単位で記録されています。
結果をEXCELでちょっとだけ分析
このまま眺めてても、「ふーん」で終わります。
EXCELに読み込んで、トータル時間を合計して、各ステップ毎の時間の割合（％）を計算してみました。
Convolutionの合計（Setup＋forward＋backward）が、全体の約75%以上です。
次がデータロードとMaxPoolingの各約6%なので、この３つで約87%以上です。
CNNでConvoluton＋Poolingのレイヤーが深くなると、学習にかかる時間が爆発的に増加する理由がよくわかるなとは思いました。
今回はこんな感じで。
ではでは。
