読者です 読者をやめる 読者になる 読者になる

mixi engineer blog

ミクシィ・グループで、実際に開発に携わっているエンジニア達が執筆している公式ブログです。様々なサービスの開発や運用を行っていく際に得た技術情報から採用情報まで、有益な情報を幅広く取り扱っています。

最適化しよう?

mixi

当エンジニアブログを私物化していると専らの評判のmikioです。ブログを書かないと死んでしまう病に冒されているのでしかたないですね。個人ブログ時代よりもわかりやすくする努力はしているんですけどね。さて、今回はソースコードの最適化による高速化について述べます。

ベンチマークテスト

TCはQDBMや他のDBMより高速であるという主張をしたいのですが、その根拠としてベンチマークテストの結果が必要となります。そこで、データベースに100万レコードを格納する処理と、そうして作ったデータベースから全てのレコードを探索する処理の時間を、各DBMで計測してみました(TCのパッケージのbrosというディレクトリにテストコードが入っています)。実行環境は、Thinkpad T60(Intel(R) Core2 CPU T7200 @ 2.00GHz)上のLinux version 2.6.16です。

ハッシュwrite ハッシュread B+木write B+木read
Tokyo Cabinet 1.259秒 2.526秒 1.865秒 1.538秒
QDBM 2.835秒 2.408秒 1.909秒 1.434秒
Berkeley DB 6.280秒 3.577秒 2.630秒 2.248秒

このテストではたった100万件の読み書きしかしていないので、ほぼ全てののI/O要求がファイルシステムのキャッシュ上で完結しています。したがって、実運用環境において実メモリの容量を越えるような規模のデータベースを扱った場合の性能特性とはかなりずれたものになる可能性があることには注意してください。今回のテストではコード自体のミクロ視点の効率性を測るために100万件の読み書きという単純なテスト内容にしています。ちなみに実時間の測定は誤差(というか試行毎の偏差)が大きいので、20回測定して順位が真ん中の10個の平均を代表値にしました。

で、結果を見てみると、TCの性能はBerkeley DBには概ね勝っていますが、QDBMとはほぼ同じ性能だということがわかります。ハッシュwriteに関しては非同期モードのおかげで爆発的な性能が出ていますが、その他はQDBMの時代からあんまり進化していないように見えます。データフォーマットとAPIは変わりましたが基本的なアルゴリズムは全く同じなので、性能がだいたい同じになるのは予想通りです。

最適化の余地

しかし、個人的には納得いきません。TCのコーディングはQDBMの時以上に実行時のオーバーヘッドを気にしてやってきたからです。どこかで無駄なことをやっていて、その無駄を削ればもっと早くなるような気がするのです。実はその答えはわかっていて、QDBMで手動でやっていた各種のコード最適化をTCではまだやっていないのです。

これ以上早くすることに実用的な意味はほとんどないのですが、ベンチマークテストの見映えをよくするというのは市場競争の観点から言えばそれなりに重要なことです。コンパイラによる最適化以上の最適化をしようとすると手でソースコードを書き換えることになり、それは可読性と保守性を損なうリスキーな行為なのですが、それでも敢えてやるべきこともあるのです。

さて、闇雲に最適化をして回るとコードがめちゃくちゃになってしまうので、まずはどこに時間がかかっているかをプロファイルで見なければなりません。すなわち関数単位でのホットスポットの発見です。その上で、その関数自身とその関数を呼び出している周辺のみに絞って最適化を検討します。gccの-pgオプションを用いてライブラリとテストコマンド群(こんなこともあろうかテストツールを揃えておいてよかった)をビルドし、それらが出力したプロファイル情報をgprofコマンドで閲覧します。ちなみに、gprofによるプロファイルは実行時間やその割合などを結構細かい値で出力してくれるのですが、誤差もそれなりに大きいことには注意してください(傾向を見るのには十分ですが)。

ハッシュデータベースに500万レコードを格納した際(tchtest write casket 5000000 5000000)のプロファイルは以下です。tchdbwriterecはレコードを直列化してから書き込む関数で、tchdbbidxはハッシュ関数です。これら2つで約37%の時間を使っていることがわかります。

  %   cumulative   self              self     total
 time   seconds   seconds    calls   s/call   s/call  name
 24.69      1.18     1.18  5000000     0.00     0.00  tchdbwriterec
 12.34      1.77     0.59  5000000     0.00     0.00  tchdbbidx
 11.72      2.33     0.56  5000000     0.00     0.00  tchdbputimpl
  6.69      2.65     0.32  6620023     0.00     0.00  tcseekwrite
  6.07      2.94     0.29  5000000     0.00     0.00  tchdbput
  5.23      3.19     0.25  6622585     0.00     0.00  tcwrite
  4.18      3.39     0.20  3379978     0.00     0.00  tchdbsetbucket
  4.18      3.59     0.20        1     0.20     4.78  procwrite
  3.35      3.75     0.16  5000000     0.00     0.00  tchdbgetbucket
  3.14      3.90     0.15  5000000     0.00     0.00  tchdbfbpsearch

ハッシュデータベースから500万レコードを取得した際(tchtest read casket)のプロファイルは以下です。tchdbwriterecはレコードを読み込んでから非直列化する関数で、tchdbbidxはハッシュ関数です。これら2つで約36%の時間を使っていることがわかります。

  %   cumulative   self              self     total
 time   seconds   seconds    calls   s/call   s/call  name
 19.44      0.84     0.84  6864280     0.00     0.00  tchdbreadrec
 17.13      1.58     0.74  5000000     0.00     0.00  tchdbbidx
  9.03      1.97     0.39  5000000     0.00     0.00  tchdbgetimpl
  8.80      2.35     0.38        1     0.38     4.32  procread
  8.56      2.72     0.37  6864281     0.00     0.00  tcseekread
  6.94      3.02     0.30  5002510     0.00     0.00  tcreckeycmp
  5.79      3.27     0.25  5000000     0.00     0.00  tchdbget
  4.40      3.46     0.19  5000000     0.00     0.00  tcmemdup
  4.17      3.64     0.18  6864281     0.00     0.00  tcread

ハッシュデータベースに500万レコードを格納した際(tcbtest write casket 5000000)のプロファイルは以下です。tcbdbcmplexicalはB+木の比較関数で、tclistvalは配列リストの要素を参照する関数です。これら2つで約27%の時間を使っていることがわかります。

  %   cumulative   self              self     total
 time   seconds   seconds    calls   s/call   s/call  name
 17.44      2.66     2.66 43035340     0.00     0.00  tcbdbcmplexical
 10.03      4.19     1.53 76005216     0.00     0.00  tclistval
  9.64      5.66     1.47  5000000     0.00     0.00  tcbdbleafaddrec
  9.57      7.12     1.46  5480393     0.00     0.00  tcmapmove
  8.52      8.42     1.30  5637861     0.00     0.00  tcmapget
  4.33      9.08     0.66 10234421     0.00     0.00  tclistpush
  3.41      9.60     0.52  5000000     0.00     0.00  tcbdbputimpl
  3.28     10.10     0.50  4843752     0.00     0.00  tcbdbgethistleaf
  3.08     10.57     0.47 15951567     0.00     0.00  tclistnum

B+木データベースから500万レコードを取得した際(tcbtest read casket)のプロファイルは以下です。tcbdbcmplexicalはB+木の比較関数で、tclistvalは配列リストの要素を参照する関数です。これら2つで約28%の時間を使っていることがわかります。

  %   cumulative   self              self     total
 time   seconds   seconds    calls   s/call   s/call  name
 18.01      2.55     2.55 39135085     0.00     0.00  tcbdbcmplexical
 11.02      4.11     1.56  5468133     0.00     0.00  tcmapmove
 10.17      5.55     1.44  5000000     0.00     0.00  tcbdbsearchrec
  9.82      6.94     1.39  5704335     0.00     0.00  tcmapget
  9.32      8.26     1.32 44590215     0.00     0.00  tclistval
  4.87      8.95     0.69  5000000     0.00     0.00  tcbdbgetimpl
  4.45      9.58     0.63 15078730     0.00     0.00  tcmemdup
  4.45     10.21     0.63  5078123     0.00     0.00  tcbdbleafload
  3.46     10.70     0.49  5000000     0.00     0.00  tcbdbget
  3.32     11.17     0.47  4921875     0.00     0.00  tcbdbgethistleaf

QDBMとの対抗上では、ハッシュデータベースの格納をより高速化する必要があります。しかし、tcbdbwriterec関数は空間効率を向上させるためにQDBMよりも複雑な計算をせざるを得ず、かつ既に限界まで最適化しているので、今回は特にいじらないことにしました。tchdbbidx関数も同様です(以前話題にした37の掛算は (h<<5)+(h<<2)+h に展開されています)。

残るフロンティアはB+木データベースです。これはBerkeley DBと性能が拮抗している部分でもありますので、もうちょい頑張って突き放したいところです。しかも、よく見るとまだまだ最適化の余地がありそうです。特に、tcbdbcmplexicalやtclistvalの呼び出し回数が多いのがわかりやすいですね。tcbdbcmplexicalが4303万回、tclistvalが7600万回ですから、つまり1レコードあたり43回とか76回とか呼ばれているわけです。

インライン化しよう

システムコールの呼び出しが大きなオーバーヘッドになるというのはわかりやすいですが、通常の関数の呼び出しもなにげにオーバーヘッドが大きいのです。C99やC++ではそれを削減するために、関数のコードを呼び出し側に埋め込むインライン関数という機構があります。しかし、それには制限があって、同じコンパイル単位でないとインライン展開されなかったり、複雑過ぎるとインライン展開されなかったりします。そこで、インライン展開を確実にするために、古式ゆかしいマクロを使います。

tcbdbcmplexicalはデフォルトの比較関数なのですが、アプリケーション側から渡されるポインタを介して呼び出されるので、コンパイラの能力ではインライン化は絶対にできません。マクロ化にするにはまず、ポインタがtcbdbcmplexicalであることを調べてから、そうである場合にはtcbdbcmplexicalに相当するコードのマクロを実行するようにします。例は以下のような感じです。マクロをdo-whileで包んでいるのは、式ではなく文として使用することを強制するためです。

マクロ化以前:
int tcbdbcmplexical(const char *aptr, int asiz, const char *bptr, int bsiz, void *op){
  assert(aptr && asiz >= 0 && bptr && bsiz >= 0);
  int min = asiz < bsiz ? asiz : bsiz;
  for(int i = 0; i < min; i++){
    if(((unsigned char *)aptr)[i] != ((unsigned char *)bptr)[i])
      return ((unsigned char *)aptr)[i] - ((unsigned char *)bptr)[i];
  }
  if(asiz == bsiz) return 0;
  return asiz - bsiz;
}
...
  bdb->cmp = tcbdbcmplexical;
...
  int rv = bdb->cmp(kbuf, ksiz, recp->kbuf, recp->ksiz, bdb->cmpop);
マクロ化以後:
#define TCCMPLEXICAL(TC_rv, TC_aptr, TC_asiz, TC_bptr, TC_bsiz) \
  do { \
    (TC_rv) = 0; \
    int _TC_min = (TC_asiz) < (TC_bsiz) ? (TC_asiz) : (TC_bsiz); \
    for(int _TC_i = 0; _TC_i < _TC_min; _TC_i++){ \
      if(((unsigned char *)(TC_aptr))[_TC_i] != ((unsigned char *)(TC_bptr))[_TC_i]){ \
        (TC_rv) = ((unsigned char *)(TC_aptr))[_TC_i] - ((unsigned char *)(TC_bptr))[_TC_i]; \
        break; \
      } \
    } \
    if((TC_rv) == 0) (TC_rv) = (TC_asiz) - (TC_bsiz); \
  } while(false)

int tcbdbcmplexical(const char *aptr, int asiz, const char *bptr, int bsiz, void *op){
  assert(aptr && asiz >= 0 && bptr && bsiz >= 0);
  int rv;
  TCCMPLEXICAL(rv, aptr, asiz, bptr, bsiz);
  return rv;
}
...
  bdb->cmp = tcbdbcmplexical;
...
  if(bdb->cmp == tcbdbcmplexical){
    TCCMPLEXICAL(rv, kbuf, ksiz, recp->kbuf, recp->ksiz);
  } else {
    rv = bdb->cmp(kbuf, ksiz, recp->kbuf, recp->ksiz, bdb->cmpop);
  }

実行時にif文が余計に入るのですが、それでも関数呼び出しのオーバーヘッドに比べればマシなようです。この改善(というか改悪というか)を行ってからまた性能測定をしてみたのですが、良好な結果が出ました。これだけでスループットが4%も向上したことになります。消費税が免除されたくらい家計に嬉しいですよね。

B+木write B+木read
Tokyo Cabinet(改善前) 1.865秒 1.538秒
Tokyo Cabinet(改善後) 1.780秒 1.458秒

ひとまずの結果

tclistvalやその他のユーティリティAPI関数のインライン化も進めた結果、かなりの改善を見ることができました。改善後のプロファイルを見ると、当然ですが、インライン化された関数の呼び出しは消滅しています。余談ですが、writeの上位9位までの関数で実行時間の約80%を使っているのですが、その行数の合計はたった376行です。今回のテストに関連するコード(tctest.c, tcutil.c, tchdb.c, tcbdb,c)の合計は約11000行ですから、コードの3.5%で実行時間の8割が使われるというネタが得られました。

write:
  %   cumulative   self              self     total
 time   seconds   seconds    calls   s/call   s/call  name
 26.89      2.92     2.92  5000000     0.00     0.00  tcbdbleafaddrec
 14.46      4.49     1.57  5637861     0.00     0.00  tcmapget
 13.44      5.95     1.46  5480393     0.00     0.00  tcmapmove
  6.91      6.70     0.75  4843752     0.00     0.00  tcbdbgethistleaf
  5.89      7.34     0.64    78125     0.00     0.00  tcbdbleafsave
  3.59      7.73     0.39  5000000     0.00     0.00  tcbdbputimpl
  3.59      8.12     0.39    78123     0.00     0.00  tcbdbleafdivide
  3.22      8.47     0.35   156250     0.00     0.00  tcbdbleafdatasize
  2.95      8.79     0.32    78124     0.00     0.00  tcbdbleafcacheout
  2.76      9.09     0.30        1     0.30    10.86  procwrite

read:
  %   cumulative   self              self     total
 time   seconds   seconds    calls   s/call   s/call  name
 29.20      2.78     2.78  5000000     0.00     0.00  tcbdbsearchrec
 16.39      4.34     1.56  5704335     0.00     0.00  tcmapget
 14.08      5.68     1.34  5468133     0.00     0.00  tcmapmove
  8.51      6.49     0.81  5078123     0.00     0.00  tcbdbleafload
  5.46      7.01     0.52  4921875     0.00     0.00  tcbdbgethistleaf
  3.68      7.36     0.35   156248     0.00     0.00  tcbdbsearchleaf
  3.47      7.69     0.33  5000000     0.00     0.00  tcbdbget
  3.47      8.02     0.33        1     0.33     9.52  procread
  3.26      8.33     0.31    78124     0.00     0.00  tcbdbleafcacheout
  2.42      8.56     0.23  5000000     0.00     0.00  tcbdbgetimpl

そしていよいよ性能測定の結果発表です。結果は以下のようになりました。writeで18%、readで14%ほどスループットが向上したことになります。

B+木write B+木read
Tokyo Cabinet(改善前) 1.865秒 1.538秒
Tokyo Cabinet(改善後) 1.575秒 1.349秒

現状のベンチマークテストの結果を、他のDBMの結果とも合わせて掲示します。

ハッシュwrite ハッシュread B+木write
(昇順)
B+木read
(昇順)
B+木write
(ランダム)
B+木read
(ランダム)
TC 1.258秒 2.568秒 1.575秒 1.349秒 5.081秒 3.352秒
QDBM 2.842秒 2.433秒 1.902秒 1.442秒 7.667秒 3.641秒
BDB 6.234秒 3.530秒 2.614秒 2.251秒 8.483秒 3.031秒
NDBM 8.345秒 7.590秒 - - - -
TDB 10.517秒 1.708秒 - - - -
CDB 0.682秒 0.627秒 - - - -
tcgraph.png

関数のインライン化やループのアンロールはやれば簡単にできるし際限なくやってしまいがちなのですが、もうこのくらいにしておかないと保守できなくなりそうです。インラインアセンブラとかいう声も聞こえてきそうですが、今は聞こえないことにします。

まとめ

手工芸的なコード最適化は、プロファイルをとった上で、有効な部分だけに絞って実施しましょう。関数の実行時間が大きいものから無駄がないか検討するのです。また、関数の呼び出し回数が多いものは、マクロなどを駆使してインライン化をすると有効です。TCでやってみたところ、最大約18%のスループット向上を達成することができました。

繰り返しになりますが、ベンチマークテストの結果に一喜一憂するのは愚かしいことです。アルゴリズムやデータ構造を見直すならまだしも、コード最適化による性能改善なんてのはたかが知れています(別の環境ではむしろ遅くなっているかもしれません)。ぶっちゃけて言えば、半分は見栄で、残り半分は自己満足にすぎないのです。むしゃくしゃしてやってしまいましたが、今は反省しています。

余談ですが、rskyさんによるTCのPHPのバインディングが出ました(パチパチパチパチ)。ミクシィ社内でTCを使う機会って実はそんなにないので、各種バインディングの登場で世の中でのユースケースが出やすくなるのは作者冥利につきますね。