Low-overhead Ruby profiling?

Question

I have a Ruby program that takes about 4 minutes to complete task and I'd like to get it down to under 1 minute.

I tried ruby-prof from gem but enabling it increases running times to ~30 minutes, and doesn't even seem to preserve monotonicity particularly well (some changes reliably improve performance-with-profiler and as reliably deteriorate performance-without-profiler). This task also cannot really be broken down into parts that can be meaningfully profiled independently.

What's the current best way to profile Ruby code with lowest overhead?

I use OSX, but if for any reason profiler requires another OS, I might reboot.

EDIT: perftools.rb has much lower overhead, but results look rather dubious to be honest, way outside any reasonable sampling error - at the very least it must be messing with GC or i/o buffering or something like that, causing a lot of silly misattributions. It still beats ruby-prof.

I'll keep the question open in case someone knows anything better than that.

Answer 1

I don't think you can do any better with either MRI or YARV.

Rubinius, however, has a built-in profiler (just call with -Xprofile) with much less overhead.

And with JRuby, you get the whole array of Java tooling, which includes some of the best profilers ever created. Even without specific support for JRuby, those tools can be quite helpful. Oracle JDK has this extremely cool VisualVM tool, which lets you visualize all sorts of stuff about your program (and AFAIK there's even a JRuby plugin for it). Oracle JRockit also has a great profiler. The Azul JVM is rumored to have an absolutely mindblowingly awesome profiler. I think J9 has a great one, too. And of course, there's YourKit.

Charles Oliver Nutter and other members of the JRuby community have recently written a series of articles on comprehending runtime behavior of Ruby code using JRuby. Mostly, those articles were written as a reaction to the memprof library for MRI and thus they tend to focus on memory profiling, but there is also some stuff about call profiling in there.

AFAIK, one of the goals for MacRuby was to be able to use XCode's runtime comprehension stuff (Instruments and Co.) for Ruby, but that's more of a long-term goal, I don't know if this is currently implemented.

Here's a little example from Rubinius:

rbx -Xprofile -e'
  Hash.new {|fibs, n|
    fibs[n] = if n < 2 then n else fibs[n-1] + fibs[n-2] end
  }[100]
'

Which prints:

Total running time: 0.009895000000000001s

  %   cumulative   self                self     total
 time   seconds   seconds      calls  ms/call  ms/call  name
------------------------------------------------------------
   7.59    0.00      0.00        234     0.00     0.01  Hash#find_entry
   5.86    0.00      0.00        419     0.00     0.00  Hash#key_index
   5.49    0.00      0.00        275     0.00     0.00  Hash::Entry#match?
   4.97    0.01      0.00        234     0.00     0.02  Hash#[]

As you can see, one interesting property of the Rubinius profiler is that, since it can profile arbitrary Ruby code, and Rubinius itself is mostly Ruby code, it can profile deeply into the system itself.

Answer 2

Any profiler that gives you self-time, reports at the function level, thinks accuracy and efficiency are important, and gives you a call graph, is based on the same set of concepts as in the original gprof, with minor variations. ruby_prof is just one of numerous examples.

Here's why that is not good.

Here's a method that actually finds problems, so you can make your code run faster, and you don't have to buy or install anything.

Here's an example of using it to get a big speedup.