Rails Notifications: Subscribe to internal events
We’re all agree that it is very useful (and necessary) to know how our application is performing in production (detect bottlenecks, generate statistics, measure metrics, etc).
Rails 3 introduced a very easy-to-use mechanism to allow access for all internal notifications: ActiveSupport::Notifications
. In fact, it’s the system that Rails itself uses internally to log ActiveRecord
and ActionView
events.
In action
To take a first look, we’re going to print all notifications into the log file. We just need to subscribe to all notifications. For do this, add this piece of code to an initializer (/config/initializers/notifications.rb):
ActiveSupport::Notifications.subscribe do |name, start, finish, id, payload|
Rails.logger.debug("[NOTIFICATION] #{name} #{start} #{finish} #{payload}")
end
Restart the server and make a request. We’ll see those lines in the application log:
[NOTIFICATION] start_processing.action_controller
2013-08-01 20:10:45 +0200 2013-08-01 20:10:45 +0200
{
:controller=>"TopicsController", :action=>"index",
:params=>{"action"=>"index", "controller"=>"topics"},
:format=>:html, :method=>"GET", :path=>"/topics"
}
[NOTIFICATION] sql.active_record
2013-08-01 20:10:45 +0200 2013-08-01 20:10:45 +0200
{
:sql=>"SELECT `topics`.* FROM `topics` LIMIT 10 OFFSET 0",
:name=>"Topic Load", :connection_id=>92001860, :binds=>[]
}
[NOTIFICATION] render_template.action_view
2013-08-01 20:10:45 +0200 2013-08-01 20:10:45 +0200
{
:virtual_path=>"topics/index"
}
...
[NOTIFICATION] process_action.action_controller
2013-08-01 20:10:45 +0200 2013-08-01 20:10:45 +0200
{
:controller=>"TopicsController", :action=>"index",
:params=>{"action"=>"index", "controller"=>"topics"},
:format=>:html, :method=>"GET", :path=>"/topics", :status=>200,
:view_runtime=>121.30655800000001, :db_runtime=>1.2731360000000003
}
We can observe different kinds of notifications:
start_processing.action_controller
sql.active_record
render_template.action_view
process_action.action_controller
Very useful the last one. That notification includes information such as: the params, the path, the view_runtime, the db_runtime …
We can subscribe to only one specific type of notifications by filtering them. To accomplish this, we’ll pass a parameter to subscribe
method:
ActiveSupport::Notifications.subscribe(/action_controller/) do |*args|
...
end
Another interesting idea would be to store notifications into your database in order to manage information easily.
# assuming Notification is an existing ActiveRecord class
ActiveSupport::Notifications.subscribe do |name, start, finish, id, payload|
notification_params = {
name: name,
start: start,
finish: finish,
payload: payload
}
Notification.create(notification_params)
end
We can even implement more complex solutions. For example: store data to Memcached or Redis, and bulk it into a persisted storage periodically. Any good idea across your mind!
Create custom notifications
We can create our own notifications and subscribe to them as well. For example:
# create custom notification
ActiveSupport::Notifications.instrument('render') do
...
end
# subscribe to it
ActiveSupport::Notifications.subscribe('render') do |*args|
...
end
Final words
There are some professional and well known tools to monitor our applications in production environments, like RPM New Relic, Librato Metrics, Riemann. Totally right, full solutions with lots of options, but this API helps us to build for example: a custom case study, a custom logging, a self-made usage statistics, alerting, etc. Cool!
Be sure to check out the official documentation for further information.