Active Support Instrumentation

Active Support is a part of core Rails that provides Ruby language extensions, utilities and other things. One of the things it includes is an instrumentation API that can be used inside an application to measure certain actions that occur within Ruby code, such as that inside a Rails application or the framework itself. It is not limited to Rails, however. It can be used independently in other Ruby scripts if it is so desired.

In this guide, you will learn how to use the instrumentation API inside of Active Support to measure events inside of Rails and other Ruby code.

After reading this guide, you will know:

  • What instrumentation can provide.
  • The hooks inside the Rails framework for instrumentation.
  • Adding a subscriber to a hook.
  • Building a custom instrumentation implementation.

Chapters

  1. Introduction to instrumentation
  2. Rails framework hooks
  3. Action Controller
  4. Action View
  5. Active Record
  6. Action Mailer
  7. Active Support
  8. Active Job
  9. Railties
  10. Rails
  11. Subscribing to an event
  12. Creating custom events

1 Introduction to instrumentation

The instrumentation API provided by Active Support allows developers to provide hooks which other developers may hook into. There are several of these within the Rails framework. With this API, developers can choose to be notified when certain events occur inside their application or another piece of Ruby code.

For example, there is a hook provided within Active Record that is called every time Active Record uses an SQL query on a database. This hook could be subscribed to, and used to track the number of queries during a certain action. There's another hook around the processing of an action of a controller. This could be used, for instance, to track how long a specific action has taken.

You are even able to create your own events inside your application which you can later subscribe to.

2 Rails framework hooks

Within the Ruby on Rails framework, there are a number of hooks provided for common events. These are detailed below.

3 Action Controller

3.1 write_fragment.action_controller

Key Value
:key The complete key 
{
  key: 'posts/1-dashboard-view'
}

3.2 read_fragment.action_controller

Key Value
:key The complete key 
{
  key: 'posts/1-dashboard-view'
}

3.3 expire_fragment.action_controller

Key Value
:key The complete key 
{
  key: 'posts/1-dashboard-view'
}

3.4 exist_fragment?.action_controller

Key Value
:key The complete key 
{
  key: 'posts/1-dashboard-view'
}

3.5 write_page.action_controller

Key Value
:path The complete path 
{
  path: '/users/1'
}

3.6 expire_page.action_controller

Key Value
:path The complete path 
{
  path: '/users/1'
}

3.7 start_processing.action_controller

Key Value
:controller The controller name
:action The action
:params Hash of request parameters without any filtered parameter
:headers Request headers
:format html/js/json/xml etc
:method HTTP request verb
:path Request path 
{
  controller: "PostsController",
  action: "new",
  params: { "action" => "new", "controller" => "posts" },
  headers: #<ActionDispatch::Http::Headers:0x0055a67a519b88>,
  format: :html,
  method: "GET",
  path: "/posts/new"
}

3.8 process_action.action_controller

Key Value
:controller The controller name
:action The action
:params Hash of request parameters without any filtered parameter
:headers Request headers
:format html/js/json/xml etc
:method HTTP request verb
:path Request path
:status HTTP status code
:view_runtime Amount spent in view in ms
:db_runtime Amount spent executing database queries in ms 
{
  controller: "PostsController",
  action: "index",
  params: {"action" => "index", "controller" => "posts"},
  headers: #<ActionDispatch::Http::Headers:0x0055a67a519b88>,
  format: :html,
  method: "GET",
  path: "/posts",
  status: 200,
  view_runtime: 46.848,
  db_runtime: 0.157
}

3.9 send_file.action_controller

Key Value
:path Complete path to the file

Additional keys may be added by the caller.

3.10 send_data.action_controller

ActionController does not had any specific information to the payload. All options are passed through to the payload.

3.11 redirect_to.action_controller

Key Value
:status HTTP response code
:location URL to redirect to 
{
  status: 302,
  location: "http://localhost:3000/posts/new"
}

3.12 halted_callback.action_controller

Key Value
:filter Filter that halted the action 
{
  filter: ":halting_filter"
}

4 Action View

4.1 render_template.action_view

Key Value
:identifier Full path to template
:layout Applicable layout 
{
  identifier: "/Users/adam/projects/notifications/app/views/posts/index.html.erb",
  layout: "layouts/application"
}

4.2 render_partial.action_view

Key Value
:identifier Full path to template 
{
  identifier: "/Users/adam/projects/notifications/app/views/posts/_form.html.erb"
}

4.3 render_collection.action_view

Key Value
:identifier Full path to template
:count Size of collection
:cache_hits Number of partials fetched from cache

:cache_hits is only included if the collection is rendered with cached: true.

{
  identifier: "/Users/adam/projects/notifications/app/views/posts/_post.html.erb",
  count: 3,
  cache_hits: 0
}

5 Active Record

5.1 sql.active_record

Key Value
:sql SQL statement
:name Name of the operation
:connection_id self.object_id
:binds Bind parameters

The adapters will add their own data as well.

{
  sql: "SELECT \"posts\".* FROM \"posts\" ",
  name: "Post Load",
  connection_id: 70307250813140,
  binds: []
}

5.2 instantiation.active_record

Key Value
:record_count Number of records that instantiated
:class_name Record's class 
{
  record_count: 1,
  class_name: "User"
}

6 Action Mailer

6.1 receive.action_mailer

Key Value
:mailer Name of the mailer class
:message_id ID of the message, generated by the Mail gem
:subject Subject of the mail
:to To address(es) of the mail
:from From address of the mail
:bcc BCC addresses of the mail
:cc CC addresses of the mail
:date Date of the mail
:mail The encoded form of the mail 
{
  mailer: "Notification",
  message_id: "[email protected]",
  subject: "Rails Guides",
  to: ["[email protected]", "[email protected]"],
  from: ["[email protected]"],
  date: Sat, 10 Mar 2012 14:18:09 +0100,
  mail: "..." # omitted for brevity
}

6.2 deliver.action_mailer

Key Value
:mailer Name of the mailer class
:message_id ID of the message, generated by the Mail gem
:subject Subject of the mail
:to To address(es) of the mail
:from From address of the mail
:bcc BCC addresses of the mail
:cc CC addresses of the mail
:date Date of the mail
:mail The encoded form of the mail 
{
  mailer: "Notification",
  message_id: "[email protected]",
  subject: "Rails Guides",
  to: ["[email protected]", "[email protected]"],
  from: ["[email protected]"],
  date: Sat, 10 Mar 2012 14:18:09 +0100,
  mail: "..." # omitted for brevity
}

7 Active Support

7.1 cache_read.active_support

Key Value
:key Key used in the store
:hit If this read is a hit
:super_operation :fetch is added when a read is used with #fetch

7.2 cache_generate.active_support

This event is only used when #fetch is called with a block.

Key Value
:key Key used in the store

Options passed to fetch will be merged with the payload when writing to the store

{
  key: 'name-of-complicated-computation'
}

7.3 cache_fetch_hit.active_support

This event is only used when #fetch is called with a block.

Key Value
:key Key used in the store

Options passed to fetch will be merged with the payload.

{
  key: 'name-of-complicated-computation'
}

7.4 cache_write.active_support

Key Value
:key Key used in the store

Cache stores may add their own keys

{
  key: 'name-of-complicated-computation'
}

7.5 cache_delete.active_support

Key Value
:key Key used in the store 
{
  key: 'name-of-complicated-computation'
}

7.6 cache_exist?.active_support

Key Value
:key Key used in the store 
{
  key: 'name-of-complicated-computation'
}

8 Active Job

8.1 enqueue_at.active_job

Key Value
:adapter QueueAdapter object processing the job
:job Job object

8.2 enqueue.active_job

Key Value
:adapter QueueAdapter object processing the job
:job Job object

8.3 perform_start.active_job

Key Value
:adapter QueueAdapter object processing the job
:job Job object

8.4 perform.active_job

Key Value
:adapter QueueAdapter object processing the job
:job Job object

9 Railties

9.1 load_config_initializer.railties

Key Value
:initializer Path to loaded initializer from config/initializers

10 Rails

10.1 deprecation.rails

Key Value
:message The deprecation warning
:callstack Where the deprecation came from

11 Subscribing to an event

Subscribing to an event is easy. Use ActiveSupport::Notifications.subscribe with a block to listen to any notification.

The block receives the following arguments:

  • The name of the event
  • Time when it started
  • Time when it finished
  • A unique ID for this event
  • The payload (described in previous sections)
ActiveSupport::Notifications.subscribe "process_action.action_controller" do |name, started, finished, unique_id, data|
  # your own custom stuff
  Rails.logger.info "#{name} Received!"
end

Defining all those block arguments each time can be tedious. You can easily create an ActiveSupport::Notifications::Event from block arguments like this:

ActiveSupport::Notifications.subscribe "process_action.action_controller" do |*args|
  event = ActiveSupport::Notifications::Event.new *args

  event.name      # => "process_action.action_controller"
  event.duration  # => 10 (in milliseconds)
  event.payload   # => {:extra=>information}

  Rails.logger.info "#{event} Received!"
end

Most times you only care about the data itself. Here is a shortcut to just get the data.

ActiveSupport::Notifications.subscribe "process_action.action_controller" do |*args|
  data = args.extract_options!
  data # { extra: :information }
end

You may also subscribe to events matching a regular expression. This enables you to subscribe to multiple events at once. Here's you could subscribe to everything from ActionController.

ActiveSupport::Notifications.subscribe /action_controller/ do |*args|
  # inspect all ActionController events
end

12 Creating custom events

Adding your own events is easy as well. ActiveSupport::Notifications will take care of all the heavy lifting for you. Simply call instrument with a name, payload and a block. The notification will be sent after the block returns. ActiveSupport will generate the start and end times as well as the unique ID. All data passed into the instrument call will make it into the payload.

Here's an example:

ActiveSupport::Notifications.instrument "my.custom.event", this: :data do
  # do your custom stuff here
end

Now you can listen to this event with:

ActiveSupport::Notifications.subscribe "my.custom.event" do |name, started, finished, unique_id, data|
  puts data.inspect # {:this=>:data}
end

You should follow Rails conventions when defining your own events. The format is: event.library. If you application is sending Tweets, you should create an event named tweet.twitter.

Feedback

You're encouraged to help improve the quality of this guide.

Please contribute if you see any typos or factual errors. To get started, you can read our documentation contributions section.

You may also find incomplete content, or stuff that is not up to date. Please do add any missing documentation for master. Make sure to check Edge Guides first to verify if the issues are already fixed or not on the master branch. Check the Ruby on Rails Guides Guidelines for style and conventions.

If for whatever reason you spot something to fix but cannot patch it yourself, please open an issue.

And last but not least, any kind of discussion regarding Ruby on Rails documentation is very welcome in the rubyonrails-docs mailing list.

© 2004–2018 David Heinemeier Hansson
Licensed under the Creative Commons Attribution-ShareAlike 4.0 International License.