Erlang で gen_server を利用してサーバーを書く場合のパフォーマンス懸念事項とその解決法

erlang

Erlang で分散 Key-Value Storage を書いているのだがデータの insert で思うように速度が出ていない。get の 10 倍ほど遅い。
ログを見た印象と直感的には insert の際の lock が競合しているのではないかと思われたがプロファイルをとってみたらボトルネックは lock ではなかった。


まず始めに Erlang 付属の fprof でプロファイルをとったがゴミデータばかりで肝心の事は何も分からなかった。 gen_server は末尾再帰ループなので余計に出力が見にくい。さらに数千プロセス分のログが出るので分からない。ML でも gen_server と fprof の相性は良くないという投稿が見受けられた。


色々ググっていたところ、Erlang 製のAmazon Dynamoクローン「Dynomite」の開発者がブログで dynomite_prof というモジュールを紹介していた。これを利用してみた。仕組みは単純で、あるキーに対して start_profile(key), stop_profile(key) とすると裏で ETS に経過時間を記録していってくれる。 PID 毎に start/stop の対応を見てくれるので楽。


結果がこちら。{キー、経過時間(秒)、call 回数}のリストになっている。なお今回は分散させずにローカルだけで計測した。

stats [{link_on_level_ge1_mino,151.48183798789978,9946},
       {do_link_level_ge1_check,24.871869802474976,111530},
       {do_link_level_ge1_retry,0.1215519905090332,66},
       {do_link_level_ge1_link,27.336875200271606,111464},
       {do_link_on_level_0_invari,1.4485905170440674,9965},
       {do_link_on_level_0_hoge,1.0463826656341553,9965},
       {do_link_on_level_0_hoge2,1.095094919204712,9965},
       {do_link_on_level_0_hoge1,3.3636646270751953,9965},
       {do_link_level_ge1,113.57014083862305,111530},
       {do_link_level_ge1_inserted2,7.656825065612793,111464},
       {lock_sleep,2.5396618843078613,1566},
       {set_inserted_op,0.7937221527099609,121410},
       {insert_op_call,178.38436031341553,10000},
       {link_on_level_0,26.792501211166382,10000},
       {do_link_on_level_0,12.066293954849243,9965},
       {global_lock,26.7523992061615,347898},
       {do_link_level_ge1_lock,27.986917734146118,111530}]

結果を見ると do_link_level_ge1_inserted2 で 7.6 秒消費している事が分かる。これは相手ノードに「Level n での insert は完了しました」とフラグを立てる処理。実際には gen_server:call(Node, {get_inserted_op, Level}) という gen_server:call として呼び出される。gen_server:call なので相手がローカルであろうとリモートであろうと区別する必要がないのがうれしいのだ。set_inserted_op は最終的に handle_call される。その中で時間を計測したのが set_inserted_op の 790 msec の部分。


あれ、7.6秒と 0.79秒では消費時間にずいぶん開きがある。これが今回のボトルネックの gen_server:call のコストだと思われる。具体的には message が enqueue、dequeue されて実際に処理するまでにかかる時間。ざっくり計算すると 10万回で 7 秒だから一回あたり 70 usec くらい。十分速いような気もするが積み重なるとかなり大きい。


この処理は gen_server プロセス(Pid)にひもづくステータスを更新しているので、gen_server の作り的には loop 引数で Status を持ち回る、現在の実装が正しい気がするのだが遅い。


結局高速にデータを read/write したいのでステータスを ets に保存する実験をしてみたところ 10 倍以上速くなった。ふーむ。これはありだな。
ただし ets には2つ問題がある。

  • ets は分散していないのでノードの物理位置と違う場所に SPOF が出来てしまう
  • ets は分散 replication に対応していない


というわけで更にググってみたところ mnesia を使えば良さそうという事が分かってきた。
mnesia には replication 機能がデフォルトで搭載されていて、バックエンドに ets を使えるのだ。(更に将来的にデータをディスクに書いても良いかもしれない)あとから Node を追加した場合に、テーブルを簡単にコピーできる。


というわけで実験。ets:lookup を mnesia:read に置き換えてみた。gen_server より速いがいまいち。速度優先の dirty_read で十分なので変えてみたところ ets の 2倍。これなら許容範囲内。

結論

gen_server プロセスのステータス管理には gen_server の State を使うのが定石だが、速度が要求される場合は ets を使うと速くなる。分散の場合は mnesia (on memory) + memory copy で運用すると良さそう。