Instrumenting Ruby on Rails with Prometheus

If you’re running a production application, you need metrics. There are great products out there that allow you to gain visibility into how your application is performing, give some nice graphs, and charge you for it. In the Rails community, this is commonly achieved by using NewRelic and Skylight. But for some of us, we achieve visibility by using Prometheus and Grafana that we build and host ourselves.

Rails provides an easy to use telemetry framework in the form of ActiveSupport Notifications. Out of the box, you can subscribe to metrics from controllers, models, views, and several other pieces in the core Ruby on Rails framework. We can leverage this functionality to easily export metrics from our queries, requests, or even custom events as Prometheus metrics.

In this guide we’re going to learn:

• How to subscribe to notifications for controller actions and model queries

• Setting up and sending metrics to the Prometheus Exporter server

• Labeling SQL query metrics with the controller actions for granularity

Demo Application

This tutorial builds a miniature rails application to teach how to hook up Prometheus. You don't need to do this step if you're just here for the gist of things.

In a folder of your choice, let's create a new rails application (5.2.2 in this case):

$ rails new instrumenting-with-prometheus
$ cd instrumenting-with-prometheus
$ rails g scaffold Post title:string body:text
$ rails db:migrate

With that, let's get this show on the road.

Active Support Notifications

First, let’s do a quick rundown of Active Support Notifications. At a high level, it’s a simple in-process queue that you can publish events to and create subscriptions for those events. A good example of an event that is published is anytime a query is executed. Rails will publish an event with the name of “sql.active\_record” and include information such as how long it took and the model name.

Above you can see that whenever we do a query (in this case, retrieving all users), ActiveRecord notifies ActiveSupport Notifications with a new event. Then, all of our subscriptions receive that event and process accordingly.

Subscribing to Notifications

To subscribe to a notification, we need to setup active support notifications so that we receive all events for a specific key. Rails has structured their keys in the format of {event}.{namespace} (which is backward in my opinion, but 🤷‍♂️). So in the case of ActiveRecord, we’re going to subscribe to the “sql.active\_record” key. This key represents an event that is published for every query ActiveRecord performs.

There's another lesser-known class in the Ruby on Rails framework called ActiveSupport::Subscriber that makes creating subscriptions a breeze. We're going to create a file in app/subscribers/active_record_prometheus_subscriber.rb. In this file, we're going to utilize a subscriber to start sending metrics to Prometheus.

# app/subscribers/active_record_prometheus_subscriber.rb
class ActiveRecordPrometheusSubscriber < ActiveSupport::Subscriber
  attach_to :active_record
  def sql(event)
  end
end

This class inherits from the ActiveSupport::Subscriber class and immediately calls attach_to :active_record. Keep in mind that events are formatted as {event}.{namespace}. The reason this is important is that any public methods defined in the class will be sent events that match the method name and namespace. So attach_to :active_record and def sql(event) will subscribe to sql.active_record.

Let's just do something easy and log some info to see if this works:

class ActiveRecordPrometheusSubscriber < ActiveSupport::Subscriber
  attach_to :active_record
  def sql(event)
    Rails.logger.info(event: 'query performed')
  end
end

The event parameter is assigned to an instance of ActiveSupport::Notifications::Event.

In the example application built to write this tutorial, my logs weren't displaying as I expected when I loaded the /posts route. I realized it's because, in development mode, classes are only loaded when they are called into action. So to do this, I just slapped the constant at the bottom of ApplicationController:

class ApplicationController < ActionController::Base
end
ActiveRecordPrometheusSubscriber

Let's start our rails server:

$ rails server

This forces Rails to load the constant, which will then attach to our notifications. Then, when I performed simple page loads, I saw what we wanted!

Started GET "/posts/1" for ::1 at 2019-05-04 19:45:43 -0400
{:event=>"query performed"}
Processing by PostsController#show as HTML
  Parameters: {"id"=>"1"}
{:event=>"query performed"}
{:event=>"query performed"}
{:event=>"query performed"}
{:event=>"query performed"}
{:event=>"query performed"}

This isn't ideal though, so instead, I decided the entire directory for app/subscribers should automatically load no matter what. I created an initializer called config/initializers/load_notification_subscribers.rb and load all of the classes in the folder:

Dir[Rails.root.join('app', 'subscribers', '**', '*_subscriber.rb')].each do |subscriber_file|
  require subscriber_file
end

You'll need to restart your server for this to take effect. Now, anytime our application boots, our subscribers will automatically attach to the relevant notifications.

Setting Up Prometheus

In this project, we're going to set up prometheus\_exporter so we have a place to easily send our metrics to. This project is really great and allows you to get going with Prometheus in Ruby super fast. It also includes a bunch of other metrics that you can include like Sidekiq (their documentation for this is great). Let's add it to our gem file:

$ bundle add prometheus_exporter

I find the interface to interact with the client is a little awkward. The interface I wanted was:

Prometheus.counters['sql_queries'].observe(1)

But the gem doesn't expose this in a global fashion that I could find, so I ended up creating a singleton class that allows us to observe metrics easily. Using the Ruby Singleton Module, we can make the desired interface I described above. Create a file at app/lib/prometheus.rb.

require 'prometheus_exporter/client'
class Prometheus
  include Singleton
  def client
    @client ||= PrometheusExporter::Client.default
  end
  def self.counters(*args)
    instance.counters(*args)
  end
  def counters
    @counters ||= Hash.new do |hash, key|
      hash[key] = client.register(:counter, key, "count of #{key}")
    end
  end
end

Now we have an easy way to get to our Prometheus counter to send it over to our exporter! Let's head back to our subscriber class and hook this new class up.

class ActiveRecordPrometheusSubscriber < ActiveSupport::Subscriber
  attach_to :active_record
  def sql(event)
      # Observe one counter for each event
    Prometheus.counters['sql_queries'].observe(1)
  end
end

Our subscriber class now utilizes our Prometheus singleton to increment our sql query counter. Let's start all of this up:

In one terminal, run:

$ rails server

In another terminal, run:

$ prometheus_exporter

Prometheus exporter listens on port `:9394` by default. We should be able to see metrics on localhost:9394/metrics now.

Next, let's visit our Rails application to kick off a simple query. Open another browser tab/window to localhost:5000/posts (created from our scaffold). Loading this page will execute a query because of the generated controller index:

# GET /posts
# GET /posts.json
def index
  @posts = Post.all
end

Now let's go back to our Prometheus exporter tab and refresh. We _should_ see our query metric appear:

Woot! Our implementation is sending any ActiveRecord queries to our metrics endpoint now!

Labeling Query Metrics

This metric is a good start, but let's add some more granularity. Next, we're going to add histograms and labels to easily identify which controllers and actions are tied to our queries. To do this, it's a little gross, I'm not going to lie.

In our ApplicationController, we can set a Thread value with our current controller and action with relative ease. The important part is making sure we erase it after the controller action is done. The best way to do this is by using an around_action controller callback.

class ApplicationController < ActionController::Base
  around_action :label_metrics
  private
  def label_metrics
    Thread.current['metrics_labels'] = { controller: params[:controller], action: params[:action] }
    yield # call the action
  ensure
    # reset to nil so nothing else can access it
    Thread.current['metrics_labels'] = nil
  end
end

With this, let's modify our Prometheus singleton to allow us to send histograms:

require 'prometheus_exporter/client'
class Prometheus
  include Singleton
  def client
    @client ||= PrometheusExporter::Client.default
  end
  def self.counters(*args)
    instance.counters(*args)
  end
  def self.histograms(*args)
    instance.histograms(*args)
  end
  def counters
    @counters ||= Hash.new do |hash, key|
      hash[key] = client.register(:counter, key, "count of #{key}")
    end
  end
  def histograms
    @histograms ||= Hash.new do |hash, key|
      hash[key] = client.register(:histogram, key, "histogram of #{key}")
    end
  end
end

The logic here is basically the same. The nice thing about histograms is that they include counts in the metrics endpoint as well. This means our subscription class can just call histograms and we can remove the counter call.

Lastly, let's modify our Subscriber class:

class ActiveRecordPrometheusSubscriber < ActiveSupport::Subscriber
  attach_to :active_record
  def sql(event)
    Prometheus.histograms['sql_queries_duration'].observe(event.duration, (Thread.current['metrics_labels'] || {}))
  end
end

In here, we've changed from counters to histograms. The method observe stays the same. Also, we're using the event.duration which is automatically calculated by Rails and assigned to the event. Last, we're passing in a hash that is coming from our controller that is set on the global Thread.current. Using Thread.current is important if you use threaded servers such as Puma (which is the rails default now). If we restart both of our servers, let's see what changes.

Huzzah! Now we're seeing our metrics tagged with our controller action and the times for it.

Conclusion

The Prometheus toolchain is an awesome way for applications to export telemetry information. If you are using Rails and have started using Prometheus in other applications, this is a super simple way to start exporting metrics from our application to Prometheus.

We have the final version of this simple Rails app here if you'd like to see the final result: https://github.com/firehydrant/blog-instrumenting-with-prometheus

You just got paged. Now what?

FireHydrant helps every team master incident response with straightforward processes that build trust and make communication easy.

Learn How