Flat Profiles¶ ↑

Flat profiles show the total amount of time spent in each method. As an example, here is the output from running printers_test.rb.

Thread ID: 21277412

%self  cumulative  total     self   children  calls self/call total/call  name
46.34     4.06      8.72     4.06     4.66      501     0.01     0.02     Integer#upto
23.89     6.16      2.09     2.09     0.00       61     0.03     0.03     Kernel.sleep
15.12     7.48      1.33     1.33     0.00   250862     0.00     0.00     Fixnum#%
14.13     8.72      1.24     1.24     0.00   250862     0.00     0.00     Fixnum#==
 0.18     8.74      0.02     0.02     0.00        1     0.02     0.02     Array#each_index
 0.17     8.75      6.64     0.01     6.63      500     0.00     0.01     Object#is_prime
 0.17     8.77      6.66     0.01     6.64        1     0.01     6.66     Array#select
 0.00     8.77      0.00     0.00     0.00      501     0.00     0.00     Fixnum#-
 0.00     8.77      0.00     0.00     0.00        1     0.00     0.00     Array#first
 0.00     8.77      0.00     0.00     0.00        1     0.00     0.00     Array#length
 0.00     8.77      0.00     0.00     0.00        1     0.00     0.00     Array#initialize
 0.00     8.77      8.77     0.00     8.77        1     0.00     8.77     Object#run_primes
 0.00     8.77      0.00     0.00     0.00        1     0.00     0.00     Integer#to_int
 0.00     8.77      6.66     0.00     6.66        1     0.00     6.66     Object#find_primes
 0.00     8.77      2.09     0.00     2.09        1     0.00     2.09     Object#find_largest
 0.00     8.77      0.02     0.00     0.02        1     0.00     0.02     Object#make_random_array
 0.00     8.77      0.00     0.00     0.00        1     0.00     0.00     Class#new
 0.00     8.77      0.00     0.00     0.00      500     0.00     0.00     Array#[]=
 0.00     8.77      0.00     0.00     0.00       61     0.00     0.00     Fixnum#>
 0.00     8.77      0.00     0.00     0.00       61     0.00     0.00     Array#[]
 0.00     8.77      8.77     0.00     8.77        1     0.00     8.77     #toplevel
 0.00     8.77      0.00     0.00     0.00      500     0.00     0.00     Kernel.rand

All values are in seconds.

The columns are:

      %self        - The percentage of time spent in this method, derived from self_time/total_time
      cumulative   - The sum of the time spent in this method and all the methods listed above it.
      total        - The time spent in this method and its children.
      self         - The time spent in this method.
      children     - The time spent in this method's children.
      calls        - The number of times this method was called.
      self/call    - The average time spent per call in this method.
total/call   - The average time spent per call in this method and its children.
name         - The name of the method.

Methods are sorted based on %self, therefore the methods that execute the longest are listed first.

The interpretation of method names is:

• toplevel - The root method that calls all other methods

• MyObject#test - An instance method “test” of the class “MyObject”

• <Object:MyObject>#test - The <> characters indicate a singleton method on a singleton class.

For example, wee can see that Integer#upto took the most time, 4.06 seconds. An additional 4.66 seconds were spent in its children, for a total time of 8.72 seconds.