Module: Profiler__

Defined in:
lib/profiler.rb

Overview

Profile provides a way to Profile your Ruby application.

Profiling your program is a way of determining which methods are called and how long each method takes to complete. This way you can detect which methods are possible bottlenecks.

Profiling your program will slow down your execution time considerably, so activate it only when you need it. Don’t confuse benchmarking with profiling.

There are two ways to activate Profiling:

Command line

Run your Ruby script with -rprofile:

ruby -rprofile example.rb

If you’re profiling an executable in your $PATH you can use ruby -S:

ruby -rprofile -S some_executable

From code

Just require ‘profile’:

require 'profile'

def slow_method
  5000.times do
    9999999999999999*999999999
  end
end

def fast_method
  5000.times do
    9999999999999999+999999999
  end
end

slow_method
fast_method

The output in both cases is a report when the execution is over:

ruby -rprofile example.rb

  %   cumulative   self              self     total
 time   seconds   seconds    calls  ms/call  ms/call  name
 68.42     0.13      0.13        2    65.00    95.00  Integer#times
 15.79     0.16      0.03     5000     0.01     0.01  Fixnum#*
 15.79     0.19      0.03     5000     0.01     0.01  Fixnum#+
  0.00     0.19      0.00        2     0.00     0.00  IO#set_encoding
  0.00     0.19      0.00        1     0.00   100.00  Object#slow_method
  0.00     0.19      0.00        2     0.00     0.00  Module#method_added
  0.00     0.19      0.00        1     0.00    90.00  Object#fast_method
  0.00     0.19      0.00        1     0.00   190.00  #toplevel

Defined Under Namespace

Classes: Wrapper

Constant Summary collapse

PROFILE_CALL_PROC =

the map of call data keyed by thread, class and id. Call data contains the call count, total time,

TracePoint.new(*%i[call c_call b_call]) {|tp| # :nodoc:
  now = Process.times[0]
  stack = (@@stacks[Thread.current] ||= [])
  stack.push [now, 0.0]
}
PROFILE_RETURN_PROC =

:nodoc:

TracePoint.new(*%i[return c_return b_return]) {|tp| # :nodoc:
  now = Process.times[0]
  key = Wrapper.new(tp.defined_class, tp.method_id)
  stack = (@@stacks[Thread.current] ||= [])
  if tick = stack.pop
    threadmap = (@@maps[Thread.current] ||= {})
    data = (threadmap[key] ||= [0, 0.0, 0.0, key])
    data[0] += 1
    cost = now - tick[0]
    data[1] += cost
    data[2] += cost - tick[1]
    stack[-1][1] += cost if stack[-1]
  end
}
@@start =

internal values

nil
@@stacks =

the start time that profiling began

nil
@@maps =

the map of stacks keyed by thread

nil

Class Method Summary collapse

Class Method Details

Outputs the results from the profiler.

See Profiler__ for more information.



119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
 
# File 'lib/profiler.rb', line 119

def print_profile(f)
  stop_profile
  total = Process.times[0] - @@start
  if total == 0 then total = 0.01 end
  totals = {}
  @@maps.values.each do |threadmap|
    threadmap.each do |key, data|
      total_data = (totals[key] ||= [0, 0.0, 0.0, key])
      total_data[0] += data[0]
      total_data[1] += data[1]
      total_data[2] += data[2]
    end
  end

  # Maybe we should show a per thread output and a totals view?

  data = totals.values
  data = data.sort_by{|x| -x[2]}
  sum = 0
  f.printf "  %%   cumulative   self              self     total\n"
  f.printf " time   seconds   seconds    calls  ms/call  ms/call  name\n"
  for d in data
    sum += d[2]
    f.printf "%6.2f %8.2f  %8.2f %8d ", d[2]/total*100, sum, d[2], d[0]
    f.printf "%8.2f %8.2f  %s\n", d[2]*1000/d[0], d[1]*1000/d[0], d[3]
  end
  f.printf "%6.2f %8.2f  %8.2f %8d ", 0.0, total, 0.0, 1     # ???
  f.printf "%8.2f %8.2f  %s\n", 0.0, total*1000, "#toplevel" # ???
end

.start_profile ⇒ Object

Starts the profiler.

See Profiler__ for more information.



102
103
104
105
106
107
108
 
# File 'lib/profiler.rb', line 102

def start_profile
  @@start = Process.times[0]
  @@stacks = {}
  @@maps = {}
  PROFILE_CALL_PROC.enable
  PROFILE_RETURN_PROC.enable
end

.stop_profile ⇒ Object

Stops the profiler.

See Profiler__ for more information.



112
113
114
115
 
# File 'lib/profiler.rb', line 112

def stop_profile
  PROFILE_CALL_PROC.disable
  PROFILE_RETURN_PROC.disable
end