Profiling Ruby Code

ehsanul picture ehsanul · Nov 4, 2010 · Viewed 17.6k times · Source

Besides ruby-prof and and the core Benchmark class, what do you use to profile your Ruby code? In particular, how do you find the bottlenecks in your code? It almost feels like I need to work on my own little tool just to figure out where all the time is being spent in my code.

I realize ruby-prof provides this, but the output is frankly very confusing and doesn't make it easy to find out which actual blocks of your own code are the source of the issue (it tells you about which method calls took the most time though). So I'm not really getting as much out of it as I'd like, and haven't really been able to make use of it.

Perhaps I'm doing it wrong? Are there alternatives? Google searches don't bring up anything for me.

Answer

conscho picture conscho · Jun 29, 2015

To really drill into your code try out stackprof.

Here's a quick solution on how to use it: Install the gem: gem install stackprof. In your code add: require 'stackprof' and surround the part that you want to check with this:

StackProf.run(mode: :cpu, out: 'stackprof-output.dump') do {YOUR_CODE} end

After running your ruby script go check the output in the terminal with stackprof stackprof.dump:

Mode: cpu(1000)
Samples: 9145 (1.25% miss rate)
GC: 448 (4.90%)

 TOTAL    (pct)     SAMPLES    (pct)     FRAME
   236   (2.6%)         231   (2.5%)     String#blank?
   546   (6.0%)         216   (2.4%)     ActiveRecord::ConnectionAdapters::Mysql2Adapter#select
   212   (2.3%)         199   (2.2%)     Mysql2::Client#query_with_timing
   190   (2.1%)         155   (1.7%)     ERB::Util#html_escape``

Here you can see all your methods that require a lot of time. Now the awesome part: To drill in just do stackprof stackprof.dump --method String#blank? and you get the output for the specific method:

String#blank? (lib/active_support/core_ext/object/blank.rb:80)
  samples:   231 self (2.5%)  /    236 total (2.6%)
  callers:
    112  (   47.5%)  Object#present?
  code:
                                  |    80  |   def blank?
  187    (2.0%) /   187   (2.0%)  |    81  |     self !~ /[^[:space:]]/
                                  |    82  |   end

And you can quite easily figure out which part of your code takes a lot of time to run.

If you want to get a visual output do stackprof stackprof.dump --graphviz >> stackprof.dot and using graphviz (brew install graphviz) dot -T pdf -o stackprof.pdf stackprof.dot get a beautiful PDF output, which highlights the methods that take a long time to run.