diff --git a/README.md b/README.md index 267752b..53e62bd 100644 --- a/README.md +++ b/README.md @@ -183,9 +183,16 @@ class CommentController < ApplicationController end ``` -Once you instrument an action, `librato-rails` will start reporting a set of metrics specific to that action including # of requests, total time used per request, and db and view time used per request. +Once you instrument an action, `librato-rails` will start reporting a set of metrics specific to that action including: -Action instrumentation metrics are named following the format `rails.action....*`. +* rails.action.request.total (# of requests) +* rails.action.request.slow (requests >= 200ms to produce) +* rails.action.request.exceptions +* rails.action.request.time (total time spent in action) +* rails.action.request.time.db (db interaction time) +* rails.action.request.time.view (view rendering time) + +Each instrumented action will appear as a source for the `rails.action.*` metrics, for example `mycontroller.action.html`. IMPORTANT NOTE: Metrics from `instrument_action` take into account all time spent in the ActionController stack for that action, including before/after filters and any global processing. They are _not_ equivalent to using a `Librato.timing` block inside the method body. diff --git a/lib/librato/rails/subscribers/controller.rb b/lib/librato/rails/subscribers/controller.rb index b9284ca..cf8f708 100644 --- a/lib/librato/rails/subscribers/controller.rb +++ b/lib/librato/rails/subscribers/controller.rb @@ -56,17 +56,18 @@ def self.watch_controller_action(controller, action) end # end group if @watches && @watches.index("#{controller}##{action}") - page_key = "#{controller}.#{action}.#{format}" - collector.group "rails.action.#{page_key}" do |r| + source = "#{controller}.#{action}.#{format}" + collector.group 'rails.action.request' do |r| - r.increment 'total' - r.timing 'time', event.duration + r.increment 'total', source: source + r.increment 'slow', source: source if event.duration > 200.0 + r.timing 'time', event.duration, source: source if exception - r.increment 'exceptions' + r.increment 'exceptions', source: source else - r.timing 'time.db', event.payload[:db_runtime] || 0 - r.timing 'time.view', event.payload[:view_runtime] || 0 + r.timing 'time.db', event.payload[:db_runtime] || 0, source: source + r.timing 'time.view', event.payload[:view_runtime] || 0, source: source end end diff --git a/test/integration/instrument_action_test.rb b/test/integration/instrument_action_test.rb index 65a56c3..c3a80fa 100644 --- a/test/integration/instrument_action_test.rb +++ b/test/integration/instrument_action_test.rb @@ -8,14 +8,15 @@ class InstrumentActionTest < ActiveSupport::IntegrationCase # puts aggregate.instance_variable_get(:@cache).queued.inspect # puts counters.instance_variable_get(:@cache).inspect - base = 'rails.action.InstrumentActionController.inst.html' + source = 'InstrumentActionController.inst.html' + base = 'rails.action.request' timings = %w{time time.db time.view} timings.each do |t| - assert_equal 1, aggregate["#{base}.#{t}"][:count] + assert_equal 1, aggregate.fetch("#{base}.#{t}", source: source)[:count] end - assert_equal 1, counters["#{base}.total"] + assert_equal 1, counters.fetch("#{base}.total", source: source) end end