AIの片隅で(14) Jetson Nano、nvprof

Jetson Nanoを使っていくために、大事な

/usr/local/cuda (私の環境では実体は /usr/local/cuda-10.0)

の中のコマンドなどについて順に実際に動かして確かめておこうと思い立ちました。一番といえばやはり nvcc でしょうが、サンプルプログラムをコンパイルするのに既に使っているし、かといってその機能を網羅しようとしたりすればどれだけかかるか分かりません。今回は、使う人は使うけれども、使わない人は使わないんじゃないかと想像する、

nvprof

から動かしてみることにいたしました。コマンドラインのcuda用プロファイラですね。

AIの片隅で 投稿順index

CUDAのプロファイリングをする場合、EclipseベースのIDEに統合されているNsightというツールからも出来ます。Eclipseなのでコードの開発、ビルドからプロファイルまでできる筈。昔Jetson Nanoとは違う環境でちょっと使ってみたけれどかっこいいGUIです。でも、淡々とプロファイリングデータを集めて考えたいときは、CUIツールのnvprofが役に立つ気がします。nvprofは奥深いツールでなかなか使いきれない機能があると思います。とくに、sshでJetson Nanoにリモートログインして使っているCUI環境メインでは、これこそ本命のプロファイリングツールじゃないでしょか。nvcc同様、/usr/local/cuda/bin 内に実行ファイルが存在するので、パスも切ってあるし、動く筈、と早速実行してみました。

例によってビーグル(モルモットというべきか?)は、Chainer版のMNISTのサンプルプログラム。上記のように、ちゃんとnvprofから立ち上がり、実行を開始したかに見えたのですが、

Warning: Insufficient privileges to start the profiling session. Use root privileges

などと言われ、結果が何も出てきません。x86のシステムでnvprofにお世話になっていたときにプリビレッジなんて要求されたっけ?たかだか数年前のことですが、これまた忘却の彼方。でも実際にWarning でているのだから仕方がない。

$ sudo nvprof python3 train_mnist.py -e 3 -g

などとしてみます。ちなみに -e 3 は Epsonは3世代でやめとけ、という指令。-gは当然 GPU使えの指令。ところが、

sudoはnvprofの在りかを知らない

ということに気付きました。要は、/usr/local/cuda/binは自分のPATHには入れてあるけれど、sudoから見えるPATHには入っていない。そこでまたちょっとハマりました。昔は、結構 su していた気がするのですが、ここ何年も sudo ばかりで、su なぞしたことありません。つい魔が差したのか、su でルートになって、そこでpathとかプロンプトとか環境変数をsourceしてやればお手軽じゃん、と。しかし、suするときに聞かれるパスワードにsudoのときのパスワード入れても駄目です。

    • sudo は、sudoerに入っているユーザなら、ユーザのパスワード
    • su は、rootのパスワード

あっ、そうか。しかし、Jetson Nanoのrootのパスワードなんて設定したっけ?調べたら、ちゃんとNVIDIAのQ&Aにお答えがありました。

Root password

ほえほえ~、そうか

$ sudo su

でできるのか。ROOTになりました。燦然とプロンプト

#

が返ってきました。しかし、#を見た瞬間、このプロンプトで動かすの抵抗大きいよね、と心にリミッターかかりました。とは言え、sudo から見えるPATH(確か、secure_path というやつ)を書き換えていくものあまり良い習慣にも思えません。sudoからnvprofが見えないだけで、立ち上がった後はpythonも、そしてchainerの存在するモジュールパスも見えるので、何も変更せず、以下のようにいたしました。

$ sudo /usr/local/cuda/bin/nvprof python3 train_mnist.py -e 3 -g

OKですね。ちょいと面倒ですが、特にセキュリティなど変更もせず。結果は、こんな感じ。

$ sudo /usr/local/cuda/bin/nvprof python3 train_mnist.py -e 3 -g
Device: @cupy:0
# unit: 1000
# Minibatch-size: 100
# epoch: 3

==7972== NVPROF is profiling process 7972, command: python3 train_mnist.py -e 3 -g
==7972== Warning: Unified Memory Profiling is not supported on the underlying platform. System requirements for unified memory can be found at: http://docs.nvidia.com/cuda/cuda-c-programming-guide/index.html#um-requirements
epoch main/loss validation/main/loss main/accuracy validation/main/accuracy elapsed_time
1 0.191864 0.093435 0.941667 0.971 30.5796
2 0.073031 0.078387 0.977016 0.976 47.5662
3 0.0481163 0.0775014 0.984415 0.9758 64.5136
==7972== Profiling application: python3 train_mnist.py -e 3 -g
==7972== Profiling result:
Type Time(%) Time Calls Avg Min Max Name
GPU activities: 31.17% 7.25732s 10800 671.97us 2.8130us 12.738ms adam
23.48% 5.46669s 4200 1.3016ms 971.26us 7.3256ms sgemm_128x128x8_NT_vec
19.68% 4.58170s 3600 1.2727ms 991.68us 6.8373ms sgemm_128x128x8_TN_vec
11.09% 2.58165s 1800 1.4343ms 1.2051ms 7.1955ms sgemm_128x128x8_NN_vec
3.92% 913.73ms 21927 41.671us 1.2500us 1.7760ms cupy_add
2.03% 472.35ms 1 472.35ms 472.35ms 472.35ms generate_seed_pseudo(__int64, __int64, __int64, curandOrdering, curandStateXORWOW*, unsigned int*)
1.74% 404.07ms 6300 64.137us 2.1870us 476.78us cupy_maximum
~途中略~
0.32% 74.249ms 4208 17.644us 208ns 305.05us [CUDA memcpy HtoD]
~途中略~
0.07% 16.033ms 42 381.73us 417ns 5.2291ms [CUDA memcpy DtoH]
~途中略~
0.00% 86.041us 16 5.3770us 990ns 21.614us [CUDA memset]
~以下略~

とりあえずデフォルト設定の「素の」プロファイリングですが、ちゃんと動作しておるようです。単精度の行列演算ルーチンと思われる sgemmや、pythonのcudaモジュールcupy配下などが列挙されているのは納得です。けれども一位の

adam

というやつは何? Chainerの中核部品なのかな。。。CPUとGPU間のメモリコピーなどは想像していたのより短い(別に何か根拠があってそう思ったわけでもないけれども)。しかし、全体で1分ちょっとの実行時間のうち、GPU動いている時間たかだか23秒くらいか。MNIST、計算的には軽めなので、前処理、後処理の時間の方が多く見えるのかね、などとブツブツ。

たしか朧げな記憶では、nvprofはGPUだけでなく、CPUのプロファイリングもできる筈(デフォルトはOFF)、ちょいとやってみるかい。下のようにcpu-profilingをONにして、train_mnist.pyへの-gオプションを外して、CPUオンリで走らせてみました。が、これは失敗でしたね。

2行目御覧ください。

Warning: CPU Profiling is not supported on the underlying platform.

です。実際、CPUで3世代までちゃんと計算しているけど、プロファイリングの方はまったく結果は出てこない。ただ、これみるとプロファイラから起動している多少不利な条件なのに

CPUのみ使用計算、1世代で約1200秒くらい

で処理できている(GPU使えば約17秒だが)。Raspberry Pi 3 model B+ 上では、1世代で約2500秒かかっていたので、Jetson NanoはCPUのみの速度でも Pi 3 model B+  の倍くらい速い。Pi 3 model B+とJetson NanoのCPUクロック周波数はどちらも1.4GHz前後の筈ですが、コアがCortex-A53とCortex-A57と差がある。こんなに違うのかね、とまたブツブツ。

まあ、Jetson nano上での nvprof の動かし方の感触はつかめたけれど、新な疑問もわいてきました。

    1. プロファイラの定番中の定番、gprof を nvccから使ったらどんな感じ?
    2. nvprof同様ハードウエアカウンタ使うタイプのプロファイラ oprofile は使えるの?

これら疑問はまた今度。

AIの片隅で(13) Jetson NanoでLチカ へ戻る

AIの片隅で(15) nvccとgprof, oprofile へ進む