君たちの愛したmruby-profilerは復活した(その1)
お盆休みの一部を利用して、mruby-prpfiler(https://github.com/miura1729/mruby-profiler)を復活させました。
mruby-profilerって何?
mruby-profilerはVMの命令ごとに実行時間を数えていて、rubyのソースコードやVMの命令レベルで実行時間を表示してくれるというものです。フィボナッチを実行すると、こんな感じの出力が最後に出ます。
0000 0.00000 # Fib 39
0001 0.00000
0002 0.00000 def fib n
0003 4119.25760 return n if n < 2
204668309 586.53534 MOVE
204668309 666.29443 LOADI
204668309 927.08844 LT
204668309 1377.01244 JMPNOT
102334155 562.32694 RETURN
0004 5941.06001 fib(n-2) + fib(n-1)
102334154 301.43419 LOADSELF
102334154 375.47193 MOVE
102334154 472.92432 SUBI
102334154 1341.11332 SEND
102334154 318.84731 LOADSELF
102334154 347.61494 MOVE
102334154 446.54848 SUBI
102334154 1346.05755 SEND
102334154 364.15757 ADD
102334154 626.89040 RETURN
0005 1139.70203 end
204668310 1139.70185 ENTER
1 0.00008 LAMBDA
1 0.00010 METHOD
0006 0.00000
0007 0.00508 puts fib(39)
1 0.00003 LOADSELF
1 0.00000 LOADSELF
1 0.00002 LOADI
1 0.00015 SEND
1 0.00011 SEND
1 0.00477 STOP１カラム目から始まる行がRubyレベルで、行番号、実行時間、Rubyレベルのソース。インデントされているのがVMレベルで、実行回数、実行時間、命令(オペコードとかは表示されない今後改善予定) です。
実行時間の単位はrdtscの出力をそのまま使っているのでよくわかりません。大きい数字なら時間がかかっているということで。
これを見れば、どこを直せば速くなるか一目瞭然ですね。そんな、甘くはないのですけど。
復活って?動かなかったの?
mruby-profilerは去年の10月に出来ていたのですが、今年の3月ごろに使えなくなりました。その理由はmrubyが変わってしまったため。もっと具体的に言うと、mrb_state構造体にirepというメンバーが無くなったためです。
irepメンバーはすべてのIREP構造体が入っている配列です。しかも、IREP構造体にはirepのどこに入っているかのインデックスがありました。IREP構造体は、mrubyのソースコードをVM命令にコンパイルした結果が、リテラルテーブルとかシンボルテーブルなんかの実行に必要な情報とともにまとまっている構造体です。
なぜなくなったかと言うと、IREP構造体もGCの対象になるようにしたからです。irepメンバーにすべてのIREP構造体が入っていればどこにも指されないという条件は常に成り立たないわけです。irepメンバーが無ければ、必要のないIREPは死んでもらえるわけです(そう、花●とアンのように)。
ところが、mruby-profilerはirepメンバーとIREP構造体のirepメンバーのインデックスに大いに依存して作られていました(過去形)。
今日は炎天下の草取りで疲れたので、この辺で。ごきげんよう、またお会いしましょう。
