From: Tripp Scott <tripps81@...>
Date: 2005-01-22T18:12:29+09:00
Subject: Profiling question

Given this script:

 $ cat ./profile1.rb
 #!/usr/bin/ruby

 def f1; i = 0; 10_000.times do i += 1 end end
 def f2; i = 0; 10_000.times do i -= 1 end end
 def f3; i = 0; (1..100).each do |x| i += Math.log(x) end end
 def f4; 10.times do f3 end end

 f1
 f2
 10.times do f3 end
 f4

Profiling this gives:

$ ruby -rprofile ./profile1.rb
  %   cumulative   self              self     total
 time   seconds   seconds    calls  ms/call  ms/call  name
 60.26     2.29      2.29        4   572.50   950.00  Integer#times
 12.89     2.78      0.49    10000     0.05     0.05  Fixnum#-
 12.89     3.27      0.49       20    24.50    33.50  Range#each
  8.95     3.61      0.34    10020     0.03     0.03  Fixnum#+
  2.89     3.72      0.11     2000     0.06     0.06  Math.log
  1.84     3.79      0.07     1980     0.04     0.04  Float#+
  0.53     3.81      0.02        1    20.00    20.00  Profiler__.start_profile
  0.26     3.82      0.01       20     0.50    34.00  Object#f3
  0.00     3.82      0.00        1     0.00  3800.00  #toplevel
  0.00     3.82      0.00        1     0.00  1640.00  Object#f2
  0.00     3.82      0.00        1     0.00   350.00  Object#f4
  0.00     3.82      0.00        4     0.00     0.00  Module#method_added
  0.00     3.82      0.00        1     0.00  1480.00  Object#f1

This is good and all, but how to profile in a higher granularity? That
is, I want to know how many times each of my methods is called (e.g.
f1 once and f3 20 times) and how much total time do they take?

Tripp