MSDN Magazine Jan.2011 「データ処理: 並列処理とパフォーマンス」に思うこと (1)
表題の記事 (https://msdn.microsoft.com/ja-jp/magazine/gg535673.aspx) ですが少し不思議に思うところがあるので掘り下げて考えてみたいと思います。
この記事においては UTF-8 でエンコードされた非常に巨大なタブ区切りファイル (906,055,326 Bytes, 7,582,271行) に記された、山の名前と標高、国名から特定の条件で抽出を行う処理を C#, Native において比較しています。しかし、結論やベンチマークの結果にはいささか疑問が残ります。今回はこの例を用いて、並列化における問題点について考えてみたいと思います。
並列化を行う際に最も重要なことは、何がボトルネックになっているか、並列化可能な個所の調査です。表題の記事では最終節「確認していない問題」において
・プロファイリング ツールや Visual Studio 2010 ツールを使用して、パフォーマンスのボトルネックを特定および削除できるかどうか。
と記載されているので、まずは記事の図3, 4 のコードをプロファイリングしてどのような問題があるのか調査してみたいと思います。
なお、環境は Phenom II X4 940 (3.0GHz), RAM 12GB, Windows Server 2008 R2, .NET Framework 4.0 (特に指定のない場合、既定のの Workstation, Concurrent GC) Any CPU (x64) です。実行時間の計測には Stopwatch とProcess.GetCurrentProcess().TotalProcessorTime を用いています。Workstation GC では既定のスレッドプールのサイズが十分な量ではない (初期値 4) のでスレッドプールの最小値を 16 に指定してあります。
図1 記事のコードの実行時間
まずは実行時間を見てみましょう。左軸が、WithDegreeOfParallelism() に指定している最大並列度、左縦軸がプログラムの実行時間 (ms)、右縦軸がプロセッサ実行時間 (ms) です。AsParallel() を指定せずに通常の LINQ として実行したものを便宜的に DOP = 0 としてプロットしています。計測は各最大並列度毎に 5回行い、最も実行時間の短かったものをプロットしています。5度の計測における差は実行時間の 1% 程度でした。また、対象となるファイルは約 900MBもの容量がありますが、全てキャッシュに載った状態での実行結果となります。
さて、図1から読み取れるように、期待に反して並列度を上げても実行時間は変わらないどころか、純粋に直列のクエリとして実行した結果が最も速いという結果が得られました。一方で並列度を上げると総CPU使用時間はマシンに搭載されている 4コア分、およそ 3.7倍にまで膨れ上がっています。これは何故でしょうか？
プログラムを単純な部分に分解して問題を調べてみましょう。まずは入力部分に着目してみたいと思います。
Parallel.ForEach(
File.ReadLines(inFile),
new ParallelOptions() { MaxDegreeOfParallelism = dop },
_ => { });
図2 単純な行の読み出し (並列)
foreach (var line in File.ReadLines(inFile))
;
図3 単純な行の読み出し (直列)
図2、3 のプログラムを実行した結果を図1と同様にプロットしてみます。
図4 単純な行の読み出しの結果
図1 と同様の傾向が図4 から読み取れることがわかります。元のプログラムの実行時間の 7割以上が図2に示すコードで占められていることから、今回の並列化における最大の問題点は読み出しにあると推定することが可能でしょう。
ここで、Visual Studio 2010 の強力なプロファイラーの出番です。全体像を把握するために、まずは同時実行プロファイリングにより動作の様子を調べ、サンプリングでどの箇所にボトルネックが生じているのか調べてみます。
オリジナルのコードを最大並列度 16 で実行した様子を図5 に示します。
図5 同時実行プロファイリングの結果
これではわけがわからないので拡大表示してみます。
図5プロファイリングの結果 (拡大図) |
図6 実行全体に占める状態の割合 |
図6 の表示されているタイムライン プロファイルの結果から、実行が占める割合から 16並列の 24% である 4コア分は消費されていることがわかります。実際、図5 の様子からも並列にプログラムは実行されているようです。しかし、プログラムの実行時間は冒頭で述べたとおり、全く高速化されていません。
これは、改行位置が前回の取得結果に依存するため、ReadLines() を並列に実行することができないためです。したがって実行状態は 1/16 になってもおかしくないはずですが、どうやら行いたい処理の他に重たい何かが走っているようです。そこで、サンプリング プロファイリングによって問題を特定してみたいと思います。
図7 サンプリング プロファイルの結果
この結果より、最も CPU 時間を消費している関数は DynamicPartitionerForIEnumerable.InternalPartitionEnumerator.GrabNextChunk(int) が呼び出している JITutil_MonContention, File.<InternalReadLines>.MoveNext() であることがわかります。
GrabNextChunk(int) をクリックして関数の詳細を表示してみましょう。
図8 関数の詳細
File.ReadLines() が返す IEnumerable<string> に対して、動的な負荷分散のため複数の結果を格納した新しい IEnumerable<string> を生成しようと試みていることがわかります。しかし、関数の中身をよく見ると、GrabNextChunk() の占める割合 98.4% の内訳として File.<InternalReadLines>.MoveNext() が占める割合は22.6%、つまりプログラム全体のたった 22.2% であり、競合の調停のための関数である JITutil_MonContention, JIT_MonenterWorker_InlineGetThread_PatchLevel の2つの関数によってプログラム全体の 73.7% の時間が費やされていることがわかります。これが、並列度を上げることによって CPU 消費時間が増加する一方で実行時間はほとんど変わらない原因です。
このようにプロファイラーを用いることで非常に簡単に問題を特定することが可能になります。
次回は並列にファイルを読み込む方法について検討し、元記事の結論について検討したいと思います。10倍速くらいにはできるでしょう。
※ 追記) 踏み込んだ内容になるため、全5部程度の構成でお送りしたいと思います。
もしよろしければ RSS での購読をお勧めいたします。