A good while back I spoke about using ruby_prof and kcachegrind at LRUG.
I was asked back then if I could stick up my ruby=prof filter-code... and I've been just a *little* bit slack about getting around to that... but recently I've been profiling again, so I thought I'd bring it out again for general use.
Here's a way to quickly add ruby-prof profiling to any given *action*. Use the following around_filter on your action. Note: this will *only* profile what happens in the controller-action. I use this on our uber-heavy summary-page views to make sure that the mammoth Active Record fetches aren't themselves the problem... before getting onto a full-stack profiling-run.
around_filter :profile_it, :only => :my_slow_action
# profiling around-filter - just does the controller-action only
def profile_it
require 'ruby-prof'
logger.info "Starting profiling"
# profile the first set
RubyProf.start
# actually do the action
yield
result = RubyProf.stop
logger.info "Profiling finished, printing files"
# Print the callgraph profile
filename = Time.now.strftime("RubyProf_#{params[:controller].gsub('/','-')}_#{params[:action].gsub('/','-')}_%Y-%m-%d_%H:%M:%S.grind")
File.open(filename,'w') do |the_file|
printer = RubyProf::CallTreePrinter.new(result)
printer.print(the_file, 0)
end
true
end
or to profile the full stack through to the template render, you'll want to split the start/stop. I tend to call start_profiling at the top of the controller action (to get rid of most of the rails loading time), and then call stop_profiling at the bottom of the relevant layout.
Put this into application_controller.rb
# Will only start the profiling... to stop, you'll need to use the helper
# at the bottom of your template.
# Use this pair to catch template-rendering in your profiling data
# Pass ":wall" as a variable to use wall-time instead of process-time
def start_profiling(time_type = nil)
require 'ruby-prof'
logger.info "Starting profiling"
RubyProf.measure_mode = RubyProf::WALL_TIME if time_type == :wall
# profile the first set
RubyProf.start
end
Put this into application_helper.rb
# Use this helper in your template to stop profiling. Asumes you have
# called "start_profiling" in your action somewhere
# Will asplode if you haven't actually *started* a profiler
# (eg if the previous action threw an exception before completing the profiling run)
def stop_profiling
if RubyProf.running?
result = RubyProf.stop
logger.info "Profiling finished, printing files"
# Print the callgraph profile
filename = Time.now.strftime("RubyProf_#{params[:controller].gsub('/','-')}_#{params[:action].gsub('/','-')}_%Y-%m-%d_%H:%M:%S.grind")
File.open(filename,'w') do |the_file|
printer = RubyProf::CallTreePrinter.new(result)
printer.print(the_file, 0)
end
else
raise "Stop profiling called when no profiling started!!!"
end
true
end