LoginSignup
13
13

Delete article

Deleted articles cannot be recovered.

Draft of this article would be also deleted.

Are you sure you want to delete this article?

More than 5 years have passed since last update.

@shu65(Shuji Suzuki)

Chainer/ChainerMNのCPUリソース不足による速度低下と解決法

Posted at

高速化をしようと思ったら、まず、プロファイルを取って遅い原因を探るということをするかと思います。
このため、前回、Chainer/ChainerMNのプロファイルの取り方等を紹介する記事を書きました。
https://qiita.com/shu65/items/42914bd2ad01d1e323da

しかし、学習速度がでない原因の中にはプロファイルでは見つけにくいものがあります。
この記事では、このプロファイルでは判断しにくい上に、私が頻繁に遭遇する速度低下原因のChainer/ChainerMNのCPUリソース不足による速度低下についての紹介と、その解決方法、この原因が起きているかどうかの見極め方について紹介します。

CPUリソース不足による速度低下が起きる理由とプロファイラで見つけにくい理由

そもそもなぜCPUリソースの不足が起きるか？

CPUリソースが不足する原因はいくつかあるかと思いますが、私が遭遇したことのある原因のほとんどは、
「各ライブラリのデフォルトスレッド数、プロセス数がマシンのCPUのコア数になっている」
ことが原因でした。

Chainerを使った場合、IOやdata augmentationの高速化のために、MultiProcessIteratorを使って並列化をすると思いますが、MultiProcessIteratorのデフォルトプロセス数はマシンのCPUコア数になっています。
これ自体、Chainerだけを使っているならほとんど問題はありません。
しかし、ChainerMNを使って1ノードで複数GPUを使って学習する場合、MPIの1つのプロセスで別々のMultiProcessIteratorが動きます。そして、MultiProcessIteratorのデフォルトのままだと、MPIの1つのプロセスでそれそれマシンのCPUのコア数分のプロセスが立ち上がります。
この結果、立ち上がっているプロセス数が簡単にマシンのコア数を超えます。

これがChainer/ChainerMNだけが関係していれば、「MultiProcessIteratorのプロセス数には気を付けましょう」で話が終わるのですが、そう簡単な話ではありません。
デフォルトスレッド数がマシンのCPUのコア数になっているライブラリは他にもあります。

私が知っているだけでも以下のものは状況によってデフォルトスレッド数がCPUのコア数になっています。

  1. NumPy (正確にはNumPy内部で使われているOpenMPなどのライブラリ)
  2. OpenCV

他にも別のライブラリを使っている場合は注意が必要かと思います。

CPUリソース不足が起きるとどうして学習速度が低下するか？

CPUリソースが足りなくなるとどのようにどうして学習速度が低下するのでしょうか？

Chainer/ChainerMNの場合、理想的な状態はGPUがフルに動き続けている状態です。
しかし、CPUリソースが不足し、各プロセスに待ちが発生すると、当然、学習のメインのChainerのプロセスにも待ちが発生します。
この結果、学習のメインのChainerのプロセスが行っているCUDAカーネルのlaunchの間隔も空いて、結果としてGPUの待ちが発生するようになります。
このため、学習速度が低下します。

ちなみに、私が経験した中で最も速度が低下したものは、CPUリソース不足が発生している状態だと1/6まで学習速度が低下していたというのがあります。

なぜ、プロファイラで見つけにくいか？

プロファイラで、速度低下原因を探る場合の手順としては、プロファイルを取得し、遅い部分に注目して改良を加えるということをすると思います。
しかし、今回のCPUリソース不足の場合、プロファイルで時間のかかっている部分を改良しても根本解決にはなりません。
これが、CPUリソース不足による学習速度低下が起きていた場合の厄介な問題です。

解決法

ここまでCPUリソース不足が起きる原因を紹介しました。では、解決方法は？というと
「ライブラリ毎にちゃんとスレッド数とプロセス数を指定してあげる」ということです。

とはいえ、じゃあどれくらいのスレッド数やプロセス数にすればいいのか？という疑問が湧くかと思います。
以前までなら地道にスレッド数やプロセス数を変えて頑張って最適化してくださいという話になっていたのですが、今回はもう少し賢い方法である、Optunaを使った最適化を紹介します。

Optunaを使ったパラメータ最適化

OptunaはPFNがOSSとして公開したハイパーパラメータサーチのライブラリです。
https://optuna.org/

ハイパーパラメータサーチは機械学習の精度面の最適化で良くやられるので、Optunaの使用例も機械学習の精度面の最適化が多い印象です。
しかし、ハイパーパラメータサーチは最適化する目的関数さえ定義できれば、どのような問題でも使えるものです。
また、Optunaは覚えることも少ないのですごく簡単に利用できます。
今回はこのOptunaを使ったスレッド数とプロセス数の最適化の紹介をしようと思ます。

コードはこちらに上げてあります。
https://github.com/shu65/opt_chainermn_cpu

今回は簡単な例としてChainerMNを使ったMNISTのexampleをベースにしたコードで、ChainerのMultiProcessIteratorのプロセス数とNumPyが使っているOpenMPのスレッド数の最適化をします。
最適化するパラメータは使うライブラリが変われば変更する必要があるので、このコードを参考にするときは注意してください。

また、今回はわかりやすいMNISTをベースにしていますが、本来であれば、augmentationとデータ読み込みもないMNISTで MultiProcessIterator を使う意味はないので注意してください。

まずはコードのポイントを簡単に紹介します。
Optunaでは目的関数を定義する必要がありますが、目的関数の結果としてどのような値を返すか？が重要な問題になります。
今回はChaienrの LogReport の出力に含まれる計算時間（elapsed_time）を返すようにします。

また、以下のようにOptunaのコードでChainerの学習コードを実行する部分はPythonの subprocess.Popen を使うようにします。

run_optuna.py
    proc = subprocess.Popen(shell_command.split(), stdout=subprocess.PIPE,
                            stderr=subprocess.STDOUT, cwd=working_dir, env=env)

そしてChainerの学習が終わり次第、LogReport の出力結果をパースして、計算時間を取り出し、返すようにします。

run_optuna.py
    chainer_log_file = os.path.join(out, 'log')
    with open(chainer_log_file) as f:
        chainer_log = json.load(f)
    return chainer_log[-1]['elapsed_time']

また、ChainerのMultiProcessIteratorのプロセス数とNumPyが使っているOpenMPのスレッド数の指定方法はそれぞれ以下のようにして指定します。

  • ChainerのMultiProcessIteratorのプロセス数: Chainerの学習コード本体の train_mnist_with_benchmark.py の引数で指定
  • OpenMPのスレッド数: 今回のコードでmpirunが叩くtask_wrapper.sh 内部で指定

また、今回は余計なオーバーヘッドが入らないように学習コードのbenchmarkモードでは EvaluatorとLogReport 以外のextensionはすべて切って、LogReport も最後に一度だけ動くように変更します。

train_mnist_with_benchmark.py
        if args.benchmark:
            trainer.extend(extensions.LogReport(), trigger=stop_trigger)
        else:
            trainer.extend(extensions.dump_graph('main/loss'))
            trainer.extend(extensions.LogReport())
            trainer.extend(extensions.PrintReport(
                ['epoch', 'main/loss', 'validation/main/loss',
                 'main/accuracy', 'validation/main/accuracy', 'elapsed_time']))
            trainer.extend(extensions.ProgressBar())

            if args.resume:
                chainer.serializers.load_npz(args.resume, trainer)

次に、実際に以下の環境で実行した結果を紹介します。

ソフトウェア環境

  • Optuna: v0.7.0
  • Chainer: v5.2
  • CuPy: v5.2
  • CUDA: 9.0
  • MPI:　OpenMPI 1.10.7

サーバー環境

  • CPU
    • 物理コア数：16
    • 論理コア数：32

Optunaの内部の設定

  • MPIのプロセス数：8
  • MultiProcessIteratorのプロセス数：1-16
  • NumPyのスレッド数:1-16
  • Optunaのtrial数：50

実行した結果は以下の通り。

$ python run_optuna.py
[I 2019-02-11 22:23:30,711] A new study created with name: chainermn_cpu
shell_command: mpirun -n 8 -bind-to none -- ./task_wrapper.sh optuna_results/1-1 14 1
...
[I 2019-02-11 23:48:32,853] Finished a trial resulted in value: 73.03446615114808. Current best value is 17.88512086868286 with parameters: {'NUMPY_NUM_THREADS': 1, 'NUM_ITERATOR_WORKERS': 1}.
{'NUMPY_NUM_THREADS': 1, 'NUM_ITERATOR_WORKERS': 1}
17.88512086868286

結果としては以下のパラメータが最適でした。

  • MultiProcessIteratorのプロセス数：1
  • NumPyのスレッド数:1

MNISTなのでaugmentationもデータ読み込みもないので、順当な結果かなと思います。

CPUリソース不足が起きているかどうかの見極め方

コードによって使用するライブラリも違うので、上記の問題が起きているのかどうか判定する方法も紹介したほうが有用かと思います。

ただ、残念ながら私も今まで高速化していて、この問題が起きているかどうか判定できる完璧な方法をまだ見つけられていません。
なので完璧な方法ではありませんが、参考になればと思い、私が今までこの問題に気が付いたとき、「もしかしてCPUリソースが不足しているのでは？」と思った状況を紹介しようと思います。

1. cProfileの結果がマシン毎に予想以上に異なる

1つ目はcProfileでたまたま気が付いたという話です。
高速化をする上でたまたま複数のマシンで別バージョンのライブラリを使っていてどちらでもcProfileを取るということをしていました。
この際、時間のかかっている関数のランキングを見ていると片方のマシンでは時間のかからない関数が別のマシンではかなり上位に来ているということがありました。
プロファイル結果も実行するたびに多少は変化するため、順位もある程度は変化します。ただ、あるマシンでは下位にあった関数が上位にまでくることはそうはありません。
また、ライブラリのバージョンが違うので当然パフォーマンスが変わることが考えられますが、ライブラリのコードを読んだ限り性能に関係しそうな変更がほとんどありませんでした。
このため、「何かおかしい」と重い、CPUリソース不足に気が付くことができました。

2. topコマンドの各プロセスのCPU使用率が予想以上に高い

2つ目はtopコマンドで各プロセスのCPU使用率が私の想定よりも明らかに高いという状況があり、CPUリソース不足に気が付くことができましたという話です。
並列化したコードを書く際、自分の書いたコードがどの関数でどれくらいのCPU使用率になるかをわりといつも意識していました。
そんな中、当時はまだOpenCVのスレッド数のデフォルトがどうなっているか気にしていなかったころ、MultiProcessIteratorのプロセス数とNumPyのスレッド数の調節をしていた時にtopコマンドを見てびっくり。
予測としては最大でも200％くらいのCPU使用率になるはずなところ、300％を超えていました。
この結果、「これはおかしい」と思い、使っているライブラリを片っ端から調べてOpenCVのスレッド数が原因だということに気が付きました。

終わりに

今回は頻繁に起きるCPUリソース不足について言及しましたが、他のリソースに関係して学習速度が低下することもあります。
そして、それらは軒並みプロファイル結果を見ても良く原因がわからない厄介な速度低下である場合が多い印象です。
これらの問題は知らないと疑いもしないと思われるので、頭の片隅にでも覚えておくと良いかと思います。

13
13
0

Register as a new user and use Qiita more conveniently

  1. You get articles that match your needs
  2. You can efficiently read back useful information
  3. You can use dark theme
What you can do with signing up
Sign upLogin
13
13

Delete article

Deleted articles cannot be recovered.

Draft of this article would be also deleted.

Are you sure you want to delete this article?