Stackprof is a sampling call-stack profile for Ruby 2.1+.
Instead of tracking all method calls, it will simply collect the current stack trace of a running program at fixed intervals. Methods that appear on top of the stack trace most often, are the methods your program spends most of its time in.
The big advantage of this is that it is very fast. You can even enable it in production and collect real performance data. See the README on how to add it as a middleware. It will dump its data to the tmp directory.
Sampling is by default based on CPU time, so it does not matter if an application is idle for a while.
The gem also includes a command line utility to extract useful information from the raw dumps. You can run
stackprof tmp/stackprof-cpu-* --limit 5
to see the 5 worst offenders. The output will look like this:
==================================
Mode: cpu(100)
Samples: 107530 (1.04% miss rate)
GC: 12232 (11.38%)
==================================
TOTAL (pct) SAMPLES (pct) FRAME
7472 (6.9%) 7472 (6.9%) ActiveRecord::Type::Integer#type_cast_from_database
3269 (3.0%) 3245 (3.0%) block in ActiveRecord::ConnectionAdapters::PostgreSQLAdapter#exec_cache
2484 (2.3%) 2297 (2.1%) block in Module#delegate
2437 (2.3%) 2290 (2.1%) block (2 levels) in V8::Function#methodcall
2037 (1.9%) 2032 (1.9%) ActiveRecord::Core#update_attributes_from_transaction_state
The TOTAL column counts the number of times a certain method appeared anywhere in the sampled stack traces, and the SAMPLES column how often it was on top of the stack trace. Both values correspond roughly to "time spent", either including or excluding children.
You can get more detailed information on a method by running
stackprof tmp/stackprof-cpu-* --method 'ActiveRecord::Type::Integer#type_cast_from_database'
The output will look like this:
ActiveRecord::Type::Integer#type_cast_from_database (activerecord-4.2.5.2/lib/active_record/type/integer.rb:15)
samples: 7472 self (6.9%) / 7472 total (6.9%)
callers:
7253 ( 97.1%) block (2 levels) in ActiveRecord::Result#cast_values
218 ( 2.9%) ActiveRecord::Attribute::FromDatabase#type_cast
code:
| 15 | def type_cast_from_database(value)
5811 (5.4%) / 5811 (5.4%) | 16 | return if value.nil?
1661 (1.5%) / 1661 (1.5%) | 17 | value.to_i
| 18 | end
