Simple Benchmarking in Ruby

While working on a new feature, I ran into a problem where the response time for a single page was approaching 30 seconds. Each request made an API call, so I first ruled that out as the culprit by logging the response time for every external request. I then turned my attention to the Rails log.

Rails gives a decent breakdown of where it's spending time before delivering a response to the browser — you can see how much time is spent rendering views, individual partials, and interacting with the database:

Completed 200 OK in 32625.1ms (Views: 31013.9ms | ActiveRecord: 16.8ms)

In my case, this didn't give enough detail to know exactly what the problem was, but it gave me a good place to start. In order to see what needed optimization, I turned to Ruby's Benchmark class to log the processing time for blocks of code. I briefly looked at Rails' instrumentation facilities, but it wasn't clear how to use it to get the result I wanted.

Instead, I whipped up a quick class with a corresponding helper to log processing times for a given block of code that I've since turned into a gem. While I used this in a Rails application, it will work in any Ruby program as well. To use, include the helper in your class and wrap any code you want to benchmark in a log_execution_for block:

class Foo
 include SimpleBenchmark::Helper

 def do_a_thing
 log_execution_for('wait') { sleep(1); 'done' }
 end
end

Calling Foo#do_a_thing will create a line in your logfile with the label "wait" and the time the block of code took to execute. By default, it will use Rails.logger if available or will write to the file benchmark.log in the current directory. You can always override this by setting the value of SimpleBenchmark.logger. When moving to production, you can either delete the benchmarking code or leave it in and disable it with SimpleBenchmark.enabled = false.

If you're using it inside of Rails like I was, create an initializer and optionally add SimpleBenchmark::Helper to the top of your ApplicationController:

# config/initializers/benchmarking.rb
require 'simple_benchmark'
SimpleBenchmark.enabled = Rails.env.development?

# app/controllers/application_controller.rb
class ApplicationController < ActionController::Base
 include SimpleBenchmark::Helper
 helper_method :log_execution_for
end

Happy benchmarking!