備忘録、はじめました。

作業したこと忘れないようにメモっておきます。

Erlangプロセスのmessage_queue_dataの影響について見てみた

前回の「Erlangのメッセージングでバッファを使う - 備忘録、はじめました。」でバッファがないときに大量のメッセージを送受信すると非常に遅くなることが分かりました。 この劣化の要因は大量のメッセージを一斉に送信していることです。

なので、プロセスのメッセージパッシングの流れについて調べてみました。

  1. 送信されたメッセージの大きさの計算
  2. メッセージに対して十分の領域をアロケーション
  3. メッセージのペイロードをコピー
  4. メタデータを含めたメッセージの箱(message container)をアロケーション
  5. “受信プロセスのメッセージキュー”にそのメッセージの箱を挿入

プロセスがメッセージを送受信するときのパフォーマンスは、上記のステップ2が大きく影響を受けます。

ステップ2は、デフォルトではプロセスのロックを取得し、ヒープの空き領域の計算、割当をします。 この処理の間、受信プロセスはメッセージを待ち続けることになります。

erlang 19.0から、ステップ2のアロケーション戦略をプロセス単位で変更できるようになりました。 アロケーション戦略を変更することで、メインへのロックなしにメッセージを送信できるようになるようです。 変更方法は以下の感じです。

process_flag(message_queue_data, on_heap|off_heap)

今回は、この「message_queue_data」について少し調べてみた話です。

message_queue_dataについて

デフォルトはon_heapで、送信プロセスはプロセスのロックを取りに行って、送信するメッセージをコピーするための十分なヒープ領域を確保します。 もしロックが取れなければヒープフラグメントという領域を作成してそこへコピーします。 off_heapの場合は、ヒープフラグメントという領域へコピーするだけでプロセスのロックを取りません。 ただし、必ずヒープフラグメント領域を作成するため、そのコストは必然と高くなります。 (詳細は Erlang 19.0 Garbage Collector | Erlang Solution blog

ということなので、実際に計測をしてみました。

計測

PCの環境:

OS: Linux 4.10.13-1-ARCH x86_64 GNU/Linux CPU: Intel® Core™ i3-4160 CPU @ 3.60GHz MEM: 16G

プログラムは前回のものを少しリファクタリングしたもので実施しました。

erlang-bench/gcbench at master · tkyshm/erlang-bench · GitHub

  • on_heapのとき
timeout sent    time(msec)      rate(req/sec)
0       50000   219     228310.502283
0       100000  531     188323.917137
0       200000  848     235849.056604
0       300000  1250    240000.000000
0       500000  218067  2292.873291
  • off_heapのとき
timeout sent    time(msec)      rate(req/sec)
0       50000   233     214592.274678
0       100000  492     203252.032520
0       200000  1020    196078.431373
0       300000  1716    174825.174825
0       500000  2882    173490.631506

結果、50万でも詰まるようなことはなくなりました。ただし、20万と30万とを比較すると実行時間やスループットは落ちているように見えます。

基本的にはon_heapにしたほうがパフォーマンスは良いとされているため、 競合する頻度が高いようなプロセスはoff_heapにすると良い、というのがポイントになりそうです。

fprofの結果

送信側、benchサーバーのプロファイリングをし、送信プロセスのGC時間を観測します。

%                                               CNT       ACC       OWN        
[{ totals,                                     5924282,336771.282,341835.044}].  %%%

...

{[{{gen_server,try_dispatch,4},                361000,325031.836,159262.044}],     
 { {benchman_server,handle_info,2},            361000,325031.836,159262.044},     %
 [{garbage_collect,                            59932,162105.521,162105.521},      
  {suspend,                                    58867, 3194.156,    0.000},      
  {{erlang,setelement,3},                      360995,  468.915,  468.915},      
  {{benchman_server,print_result,4},              5,    1.192,    0.014},      
  {{erlang,system_time,1},                        5,    0.008,    0.008}]}.   
  • off_heap
%                                               CNT       ACC       OWN        
[{ totals,                                     5833813,11566.663,19300.610}].  %%%

...

{[{{gen_server,try_dispatch,4},                361000, 1431.519,  913.937}],     
 { {benchman_server,handle_info,2},            361000, 1431.519,  913.937},     %
 [{{erlang,setelement,3},                      360995,  389.500,  389.500},      
  {garbage_collect,                            18051,   86.159,   86.159},      
  {suspend,                                    3611,   40.982,    0.000},      
  {{benchman_server,print_result,4},              5,    0.935,    0.013},      
  {{erlang,system_time,1},                        5,    0.006,    0.006}]}.  

CNTは関数が呼ばれた回数、ACCは関数の合計時間(msec)、OWNは関数内部の他の関数を含まない時間(msec)です。 % がついている箇所が対象の関数です。2つめのリストは、%内で呼び出されたOWN以外の実行時間です。

on_heap時の結果を見ると、半分以上がGCによるものだとわかります。 一方、off_heap時は殆どGCに時間を費やしていないことがわかります。

ただ、%のhandle_info/2のOWN時間に差が出ている点はよく分かってません。

おまけ:バッファありケース

timeout sent    time(msec)      rate(req/sec)
0       1000    205     4878.048780
0       10000   230     43478.260870
0       50000   336     148809.523810
0       100000  471     212314.225053
0       200000  728     274725.274725
0       300000  995     301507.537688
0       500000  1544    323834.196891
  • off_heap
timeout sent    time(msec)      rate(req/sec)
0       1000    206     4854.368932
0       10000   246     40650.406504
0       50000   317     157728.706625
0       100000  443     225733.634312
0       200000  671     298062.593145
0       300000  896     334821.428571
0       500000  1345    371747.211896

バッファありのケースでも、off_heapの方がメッセージング数が多くなるにつれてパフォーマンスの差が大きくなる傾向がありそうです。 50万のときは200 msec程短くて、スループットも向上している感じにはなりました。

感想

Erlangプロセス内のGCやらヒープの使われ方などを知っておくと実装したり動作を確認するときに見るべきポイントが明確になりそうかと思い、今回のテーマに手を付けてみました。 やってみたものの、参考にした記事を元にざっくりこんな感じになるのかなぁと当たりを付けて調べていった感じになっちゃいました。 (なので、なんでhandle_info/2の部分の結果が出たのか分かってないなどあります。あと、実装したプログラムの問題もありそうな予感もしてます。)

バッファがなくてもそれなりにパフォーマンスが出せる結果は出ましたが、やっぱりバッファをおいて実装するほうが速そう、ということが分かったのは良かったかなと思いました。 なので、バッファなどを導入するかoff_heapで対応するかは要件次第になってきそうです。どちらにせよ、off_heapに変更する場合は先にちゃんとprofileを取ってからになりそう。

あと、fprofの見方間違ってないかどうか若干不安。

参考記事についてはあんまり触れられていなかったので、どこかの機会でまとめられたらいいなと思います。

参考