以前の記事で tf.nn.conv2d を複数GPUでやったら遅かったという記事を書いたのですが、「オーバーヘッドも含めて計測しているため遅いだろう」というご指摘があったため、もう一度検証してみました。最近参加している勉強会の主催者の方から、NVIDIA Visual Profiler という GPU のプロファイラについてのアドバイスをいただいたため、それを使い、処理時間の計測を行いました。
以前の記事:
keimina.hatenablog.jp
プロファイリングのために使用するのはnvprof コマンドと NVIDIA Visual Profiler (GUIアプリ) の二つです。nvprof コマンドは NVIDIA の GPU のプロファイルをおこなうためのコマンドで、プロファイリングの結果をファイルとして保存してくれます。NVIDIA Visual Profiler はその名前の通り、ビジュアルなプロファイリングを行うGUIアプリです。
目次
2. nvprof コマンドについて
nvprof コマンドは NVIDIA の GPU のプロファイルをおこなうためのコマンドで、プロファイリングの結果をファイルとして保存してくれます。コマンドのインストール方法は割愛します。私の場合、GCE(Google Compute Engine)に標準でインストールされていました。参考として使用したGCEのイメージを以下に記載します。
使用したGCEのイメージ:
Intel® optimized Deep Learning Image: TensorFlow 1.12.0 m15 (with Intel® MKL-DNN/MKL and CUDA 10.0) A Debian based image with TensorFlow (With CUDA 10.0 and Intel® MKL-DNN, Intel® MKL) plus Intel® optimized NumPy, SciPy, and scikit-learn.
3. NVIDIA Visual Profiler について
nvprof が出力するプロファインリング結果(ファイル)を読み取って可視化してくれるアプリです。こちらもインストール方法は割愛しますが、私はインストール時に設定するチェックボックスやらなんやらは全てデフォルトでひたすら「Next」を押してインストールしました。Macbook pro にインストールしたのですが、以下の場所にプロファイラがインストールされてました。
プロファイラがインストールされた場所:
/Developer/NVIDIA/CUDA-10.0/libnvvp/nvvp.app
4. 手順概要
nvprof コマンドを用いてプロファイリングした結果をファイルとして取得、次に、あとで説明する NVIDIA Visual Profiler(GUIアプリ) でそのファイルを食わせて可視化します。
5. 手順詳細 (1/2) - nvprof コマンドの実行
以下にプロファイリングの手順を書きます。
※以下の説明では GPUを実行する環境(私の場合 GCEのインスタンス上)で nvprof はすでにインストールされているものとします。また、NVIDIA Visual Profiler も nvprof のファイルを読み込むための PC(私の場合 Macbook pro) にインストールされているものとします。
以下のようにGPU環境(私の場合GCEのインスタンス上)で 計測したいスクリプトを nvprof コマンドを経由して実行させます。
nvprof -o out-file.nvp python3 sample-script.py
“-o” で出力ファイル名を指定しています。これにより sample-script.py が実行され、同時に out-file.nvp が作成されます。この out-file.nvp にプロファイリングの情報が入っています。
6. 手順詳細 (2/2) - NVIDIA Visual Profiler による可視化
nvprof コマンドで作成した *.nvp ファイルを NVIDIA Visual Profiler という GUI アプリにインポートし読み込み結果を可視化します。GPU の情報をタイムラインで表示してくれるので、時間のかかっている場所がどこなのかなどを見ることができます。まず、out-file.nvp ファイルがサーバーにある人(私)は ローカル(私の場合 Macbook pro)に移しておきます。次に以下を実施します。
(1) NVIDIA Visual Profiler を開く
(2) File > Import をクリック
(3) “Select an import source:” で Nvprof を選択して Next をクリック
(4) “Multiple processes” を選択して Next をクリック
(5) “The nvprof pfofile files:” で Browse をクリックして読み込みたい *.nvp ファイルを選択
(6) Finish をクリック
実行すると、読み込まれた*.nvpファイルに保存されているプロライリングの結果がGUIで表示されます。
GPUの状況などがタイムラインで表示されているのですが、縮小されていてみづらいため、虫眼鏡を押して拡大します。
凸凹してるところをさらに拡大してみます。
このように拡大して詳細にみていくことができます。縮小すれば全体を俯瞰して見ることができます。左側のパネルから GPU をクリックし Context > Compute とクリックすると Compute の内訳が見れます(上記 図3. の真ん中の左側付近)。内訳の上から見ていくと、volta_gcgemm_64_32_nt と volta_gemm_64_32_tn というものが実行されているようです。それぞれ Compute の 19%、18%を占めていることがわかります。gemmはググるとどうやら行列の積和演算の処理らしいです。この二つで Compute の約40%を占めていることがわかります。その他、割愛しますが処理時間の平均(Avg. Duration)や、呼び出し回数(Invocations)など様々な情報が記載されていることがわかります。
7. プロファイリング結果の考察
tf.nn.conv2dのスクリプトが遅い件を調べるために、実際に使用したプロファイルのコマンドは以下になります。スクリプトでGPU2個を動かすために引数に2を指定しています。遅い件やスクリプトの詳細はTensorFlowで複数GPUで２次元畳み込みやってみる(tf.nn.conv2d with multiple GPUs) - keiminaの日記を参照してください。
nvprof -o profile_2gpu.nvp python3 multi_gpu.py 2 840 100 100
これで出力された *.nvp ファイルを NVIDIA Visual Profiler で開いて 左のパネルにある一つの GPUを選択して“Compute” をクリックして 右下にある Properties をみて見ると Kernels: 21.8ms となっていました。GPUでの計算時間は実質 21.8ms ということがわかります。左のパネルにあるもう一つの GPUを選択してみてもやはり 21msくらいでした。このことから、GPUで行われた計算の時間は最大でも 2 * 22ms = 44ms だと推測できます。Scipyを使用したCPUでの計算時間は約220msでしたので、少なくともCPUよりGPUのほうが約5倍は速いことになります。
余談:
私の環境では GPU 3 個までは表示できましたが、残念ながらGPU4個以上のものは アプリの制約なのか表示できませんでした。
8. まとめ・感想
前回記事でGPUに対する信頼度が低くなっていたのですが、今回の検証でGPUは速いと思えるようになったことが一番の収穫だと思います。GPUで何が行われているのか完全にブラックボックスだったのですが、このプロファイラによって完全なブラックボックスから少しは脱却できたのかなと思います。ただし当方、素人なため可視化しても理解できないところが多々ありますので、プロフェッショナル方からこのアプリの見方を教えていただきたいところです。なんだか、趣味の範囲を超えてきている感がありますので、ひとまずできることはやった、GPUは速かったということで、これからはあまり疑問をもたずGPUを使っていこうと思います。
以上です。おやすみなさい。
