Journal InTime

_ プロファイラ

profile.rbがあまりにも遅いのでCで書いてみた。

<URL:http://svn.shugo.net/src/ruby-prof/trunk/>

profile.rbの30倍くらいになったようだ(当社比)。

profile.rb:

$ time ruby -r profile fib.rb
  %   cumulative   self              self     total
 time   seconds   seconds    calls  ms/call  ms/call  name
 75.06     3.13      3.13    21891     0.14     2.58  Object#fib
 10.31     3.56      0.43    21891     0.02     0.02  Fixnum#<
  9.83     3.97      0.41    21890     0.02     0.02  Fixnum#-
  4.80     4.17      0.20    10945     0.02     0.02  Fixnum#+
  0.00     4.17      0.00        1     0.00     0.00  Fixnum#to_s
  0.00     4.17      0.00        2     0.00     0.00  IO#write
  0.00     4.17      0.00        1     0.00     0.00  Module#method_added
  0.00     4.17      0.00        1     0.00     0.00  Kernel.print
  0.00     4.17      0.00        1     0.00     0.00  Profiler__.start_profile
  0.00     4.17      0.00        1     0.00  4170.00  #toplevel
6765

real	0m4.307s
user	0m4.172s
sys	0m0.071s

prof.so:

$ time ruby -r doprof fib.rb
6765
  %%   cumulative   self              self     total
 time   seconds   seconds    calls  ms/call  ms/call  name
100.00    0.050     0.050    21891    0.002    0.032  Object#fib
  0.00    0.050     0.000        1    0.000   50.000  #toplevel
  0.00    0.050     0.000        1    0.000    0.000  Kernel.print
  0.00    0.050     0.000    21890    0.000    0.000  Fixnum#-
  0.00    0.050     0.000        2    0.000    0.000  IO#write
  0.00    0.050     0.000        1    0.000    0.000  Module#method_added
  0.00    0.050     0.000    10945    0.000    0.000  Fixnum#+
  0.00    0.050     0.000    21891    0.000    0.000  Fixnum#<
  0.00    0.050     0.000        1    0.000    0.000  Fixnum#to_s

real	0m0.128s
user	0m0.057s
sys	0m0.069s

難点はRubyにパッチをあてる必要があること。 call_trace_func自体が遅いので、こればっかりはどうしようもない。 staticじゃなかったらLD_PRELOADで何とかなるかもしれないけど。