ApacheモジュールはApache httpdに組み込んで使うために、いまいちモジュール単体のテストやプロファイルやデバッグがやりにくい印象があります。
デバッグに関しては以前gdbを使った方法を紹介しましたが、今回は色々あるプロファイラの中で比較的楽にプロファイルが得られるOProfileを使ったプロファイルの取り方を紹介したいと思います。非常に簡単です。
ちなみに、プロファイラをかます事で対象そのものに影響を大きく与えてはいけないという意味で、この話だけでも研究になりそうですが、あまり深入りし過ぎるとまた別の方向にいってしまいそうなので、今回はそういった精度よりもどれだけ簡単にできるかというところに重点を置いた方法を紹介したいと思います。
OProfileでApache httpdをプロファイル
まずは、OProfileがインストールされている状態で以下のコマンドによりプロファイルの準備をします。近頃のディストリビューションだとyumやapt-getですぐインストールできるでしょう。
また、プロファイルしたいバイナリは-gや-O0によりデバッグシンボルを残した状態でコンパイルしていることを忘れないで下さい。stripしたバイナリとかではほとんど情報は取れません。
[program lang=’bash’ escaped=’true’]
sudo opcontrol --no-vmlinux sudo opcontrol --start
[/program]
この状態で、プロファイルを取りたいモジュールが入ったApache httpdを起動させます。そして、Apacheなのでベンチマークツールなどにより負荷をかけます。
今回は「mod_mrubyとmod_rubyの比較のためにプロファイルしてみよう」という目的で、それぞれのモジュールを組み込んだ状態で、mod_mrubyで処理されるhelloworldスクリプトとmod_rubyで処理されるhelloworldスクリプトそれぞれに同じ数（10000回）だけリクエストを処理させました。そして、負荷をかけ終わった後は、以下のようにプロファイラを停止します。
[program lang=’bash’ escaped=’true’]
sudo opcontrol --stop
[/program]
そして、プロファイルしたいApacheモジュールの.soバイナリのパスを指定してプロファイルを見てみましょう。
今回の場合だと、mod_mrubyとmod_ruby、さらに、mod_rubyからダイナミックリンクされているlibruby.soの情報が欲しいはずです(mod_mrubyはスタティックにmrubyインタプリタをリンクしているため)。その場合は、以下のように該当するバイナリパスを複数指定することで、それぞれのバイナリの処理のおおよそのパフォーマンス比較が可能になります。
[program lang=’bash’ escaped=’true’]
sudo opreport /etc/httpd/modules/mod_ruby.so /etc/httpd/modules/mod_mruby.so /usr/lib/libruby.so
[/program]
すると以下のような結果が得られます。
[program lang=’text’ escaped=’true’]
samples¦ %¦
------------------
324659 53.7996 libruby.so.1.9.1
180762 29.9543 mod_mruby.so
98039 16.2461 mod_ruby.so
[/program]
libruby.so.1.9.1の処理を占める割合が多い事がわかります。さらにシンボル（関数名）単位で見て行きましょう。その場合は-lオプションを指定します。
[program lang=’bash’ escaped=’true’]
sudo opreport -l /etc/httpd/modules/mod_ruby.so /etc/httpd/modules/mod_mruby.so /usr/lib/libruby.so
[/program]
すると以下のような結果が得られるます。
[program lang=’text’ escaped=’true’]
samples % app name symbol name 53510 8.8672 libruby.so.1.9.1 st_lookup 50795 8.4173 mod_mruby.so mrb_sym2name_len 22249 3.6869 mod_mruby.so yyparse 21571 3.5746 libruby.so.1.9.1 vm_exec_core 20125 3.3349 libruby.so.1.9.1 ruby_yyparse 12161 2.0152 libruby.so.1.9.1 ruby_sip_hash24 11266 1.8669 libruby.so.1.9.1 st_foreach 8647 1.4329 libruby.so.1.9.1 __i686.get_pc_thunk.bx 6988 1.1580 libruby.so.1.9.1 rb_newobj 6537 1.0833 mod_ruby.so ruby_type_handler 6175 1.0233 mod_mruby.so __i686.get_pc_thunk.bx 6138 1.0171 libruby.so.1.9.1 slot_sweep 5788 0.9591 libruby.so.1.9.1 .plt 5093 0.8440 mod_mruby.so parser_yylex 4943 0.8191 mod_ruby.so rb_init_apache_request 4933 0.8175 libruby.so.1.9.1 rb_funcall 4559 0.7555 libruby.so.1.9.1 iseq_setup 4519 0.7488 libruby.so.1.9.1 gc_marks 4446 0.7368 libruby.so.1.9.1 rb_funcall2 4428 0.7338 mod_ruby.so ruby_handler_0 4403 0.7296 mod_ruby.so ruby_handler_internal 4357 0.7220 mod_mruby.so nextc 4058 0.6725 libruby.so.1.9.1 rb_check_funcall 3948 0.6542 mod_ruby.so .plt 3933 0.6517 mod_mruby.so mrb_run 3918 0.6493 mod_ruby.so ruby_child_cleanup 3852 0.6383 libruby.so.1.9.1 vm_call0 ・ ・ ・
[/program]
mod_mrubyの場合はmrb_sym2nam_len()の処理が占める割合が多いんだなぁと分かります。例えばこのように得られた関数に最適化の余地があれば、そこを改善することで大幅にパフォーマンス改善することも可能になるでしょう。CRubyのruby_yyparseとmrubyのyyparseはほとんど同じなんだなぁとか、mod_ruby+libruby.so側はmod_mrubyと比べて色々な関数が呼ばれている事も分かりますね。
また、opannotateコマンドを使う事で、ソースコードレベルやさらにはアセンブリレベルでプロファイラが可能ですので、上記のコマンドに加えてopannotateの-sや-aオプションで結果を眺めると面白いと思います。
まとめ
このように、非常に簡単にApacheモジュールのプロファイルを取る方法を紹介しました。これで、よりC言語によるOSやmiddlewareまわりの実装が捗りますね。