Profiling Ruby Code

T

4

35

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.

Textuary answered 3/11, 2010 at 23:37 Comment(1)

Are you having the same problems that I had in Is it possible to ignore irrelevant methods when profiling ruby applications?. I found out about ruby-prof's method elimination option. – Skysweeper 4/11, 2010 at 2:44

D

11

Lots of profilers are like that. What you need to know is not where the program spends its time, but why. Any references on Dynamic Code Analysis?

ADDED: Here's how I find "bottlenecks" in my code. (I hate that word.) Here's a list of reasons why.

It is perfectly natural to assume that to find "bottlenecks" you have to somehow do a lot of measuring. It is so natural that nearly all profilers are based on it.

Actually, finding and measuring are not the same problem. Measuring is needed to see if what you found (and fixed) made a difference. Finding what to fix, to me, is more like debugging than measuring.

The simplest way to explain it is to start from an infinite, or nearly infinite loop. How do you find it? You pause it and look at the stack, right? because you know the problem is somewhere on the stack. You only need to pause it once, and then you need to study the code on the stack. Pause it a few times if you want to be sure you've found it.

Suppose the code only takes twice as long as necessary. That means when you pause it, there is a 50% chance you will see it doing the unnecessary thing. If you pause it and look at it 10 times, you will catch it in the act roughly 5 times. In fact, as soon as you see it doing something you can optimize on as few as 2 samples, you've found a "bottleneck". Fix it, measure the speedup, show it off, and repeat.

Even if your biggest problem is not very big, this method will eventually find it. Also, there's a magnification phenomenon, where small problems become easier to find after you've removed larger ones. That allows you to keep going until the code is nearly optimal.

P.S. After you've done this, there may still be opportunities for speedup. For example, optimization algorithms can depend on numerical stability. Message-driven architectures can make it harder to trace why code is being executed. In real-time software, a performance problem may only happen occasionally, and be less easy to sample. This requires more cleverness. Falling back on just measuring doesn't do it.

Darwindarwinian answered 3/11, 2010 at 23:49 Comment(5)

Thanks for that, I'll try this method. I just found perftools too, which is a sampling profiler, and produces call graphs like the following: perftools-rb.rubyforge.org/examples/rubygems.gif - Do you think doing it manually for the bit of extra information provides much of an advantage really? – Textuary 4/11, 2010 at 18:19

@ehsanul: Absolutely, as explained in point 3 of the Alternatives To Gprof link. But don't just take my word for it: #2625167 #2474166 It's like comparing a flashy car to an ugly airplane. One looks nice, but the other gets you there. – Darwindarwinian 4/11, 2010 at 20:25

@MikeDunlavey: a tyro's question: how do you interrupt a ruby app and get a backtrace? Can you capture SIGINT to get into the ruby debugger? Or do you do everything under gdb? – Lanita 7/3, 2013 at 16:3

@fearless: This post says do "catch Interrupt". – Darwindarwinian 7/3, 2013 at 17:37

@MikeDunlavey: Didn't work for me -- see #15278634 – Lanita 7/3, 2013 at 19:44

D

15

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.

Discreet answered 29/6, 2015 at 16:35 Comment(0)