Profiling Ruby Code
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.
This is my own question, but I found a tool that's so amazing for profiling that I have to add it here:
http://samsaffron.com/archive/2013/03/19/flame-graphs-in-ruby-miniprofiler
Flamegraphs make the source of performance problems amazingly obvious, relative to looking at backtraces.
There is also ruby -rprofile
or equivalently from within Ruby source, require 'profile'
Documentation:
https://ruby-doc.org/stdlib-2.1.0/libdoc/profiler/rdoc/Profiler__.html
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.