Stackprof - sampling call-stack profiler for ruby

Posted . Visible to the public.

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
Tobias Kraze
Last edit
Tobias Kraze
License
Source code in this card is licensed under the MIT License.
Posted by Tobias Kraze to makandra dev (2016-03-11 16:03)