first time to use ruby-prof

ruby

What's ruby-prof

profiler for ruby. would you see http://ruby-prof.rubyforge.org/

Install

would you see http://ruby-prof.rubyforge.org/. I installed version 0.10.7.

% sudo gem install ruby-prof

Usage

There are three ways of running ruby-prof.
http://ruby-prof.rubyforge.org/

The first : ruby-prof executable

for example.

% ruby-prof --printer=flat --file=result --mode=wall hoge.rb

hoge.rb

for i in 1..10000
  p i
end

result（cat result）

% cat result
Thread ID: -604468348
Total: 0.081816

 %self     total     self     wait    child    calls  name
 37.88      0.03     0.03     0.00     0.00    20000  IO#write
 27.31      0.07     0.02     0.00     0.05    10000  Kernel#p
 12.84      0.08     0.01     0.00     0.07        1  Range#each
 11.71      0.02     0.01     0.00     0.01    10000  Kernel#inspect
 10.14      0.01     0.01     0.00     0.00    10000  Fixnum#to_s
  0.08      0.08     0.00     0.00     0.08        1  Kernel#load
  0.03      0.08     0.00     0.00     0.08        1  Global#[No method]
  0.00      0.00     0.00     0.00     0.00        1  <Class::Object>#allocate
The second : ruby-prof API
% ruby hoge.rb

result(STDOUT)

Thread ID: -604386428
Total: 0.082106

 %self     total     self     wait    child    calls  name
 32.35      0.03     0.03     0.00     0.00    20000  IO#write
 28.93      0.07     0.02     0.00     0.05    10000  Kernel#p
 14.90      0.08     0.01     0.00     0.07        1  Range#each
 13.02      0.02     0.01     0.00     0.01    10000  Kernel#inspect
 10.79      0.01     0.01     0.00     0.00    10000  Fixnum#to_s
  0.01      0.08     0.00     0.00     0.08        1  Global#[No method]

hoge.rb

require 'rubygems'
require 'ruby-prof'

# Profile the code
result = RubyProf.profile do

  for i in 1..10000
    p i
  end

end

# print a flat profile to text
printer = RubyProf::FlatPrinter.new(result)

profile_options = {
  :measure_modes => [RubyProf::WALL_TIME],
  :min_percent => 0
}

printer.print(STDOUT, profile_options)
The third : require unprof
% ruby hoge.rb

result(STDOUT)

Thread ID: -604060798
Total: 0.084379

 %self     total     self     wait    child    calls  name
 33.02      0.03     0.03     0.00     0.00    20000  IO#write
 29.09      0.07     0.02     0.00     0.05    10000  Kernel#p
 14.07      0.08     0.01     0.00     0.07        1  Range#each
 13.25      0.02     0.01     0.00     0.01    10000  Kernel#inspect
 10.55      0.01     0.01     0.00     0.00    10000  Fixnum#to_s
  0.02      0.08     0.00     0.00     0.08        1  Global#[No method]

hoge.rb

require 'rubygems'
require 'unprof'

for i in 1..10000
  p i
end

Graph html

% ruby-prof --printer=graph_html --file=result.html --mode=wall hoge.rb

hoge.rb

for i in 1..10000
  p i
end

result

KCacheGrind

% ruby-prof --printer=call_tree --file=callgrind.out --mode=wall hoge.rb

hoge.rb

for i in 1..10000
  p i
end

result view on Windows.

I'm on

OS CentOS release 5.3 (Final)
ruby ruby 1.8.6 (2009-06-08 patchlevel 369) [i686-linux]
ruby-prof 0.10.7

Reference