Rails 8 Instrumentation and Custom Metrics

Production Rails applications need visibility into what's happening under the hood. Rails provides a powerful instrumentation API through ActiveSupport::Notifications that allows developers to subscribe to built-in events and create custom metrics without external dependencies.

Understanding Rails Instrumentation

Rails instruments dozens of events out of the box: database queries, view rendering, cache operations, and HTTP requests. The instrumentation system follows a publish-subscribe pattern where code emits events and subscribers react to them.

Every instrumented event includes a name, timing information, and a payload hash with event-specific data. This foundation enables logging, metrics collection, and performance monitoring.

# config/initializers/instrumentation.rb

# Subscribe to all SQL queries
ActiveSupport::Notifications.subscribe('sql.active_record') do |name, start, finish, id, payload|
  duration = (finish - start) * 1000
  
  # Skip schema queries and EXPLAIN statements
  next if payload[:name] == 'SCHEMA' || payload[:sql].start_with?('EXPLAIN')
  
  if duration > 100
    Rails.logger.warn "[SLOW QUERY] #{duration.round(2)}ms: #{payload[:sql].truncate(200)}"
  end
end

# Subscribe to view rendering
ActiveSupport::Notifications.subscribe('render_template.action_view') do |name, start, finish, id, payload|
  duration = (finish - start) * 1000
  template = payload[:identifier].sub(Rails.root.to_s, '')
  
  if duration > 50
    Rails.logger.warn "[SLOW VIEW] #{duration.round(2)}ms: #{template}"
  end
end

The block receives five arguments: the event name, start time, finish time, a unique ID, and the payload. Using start and finish allows accurate duration calculation even when events are nested.

Creating Custom Instrumentation

Business-critical operations deserve the same observability as framework internals. Wrap important code paths with custom instrumentation to track performance and behavior.

# app/services/payment_processor.rb

class PaymentProcessor
  def charge(order)
    ActiveSupport::Notifications.instrument('charge.payment_processor', order_id: order.id, amount: order.total) do
      gateway_response = PaymentGateway.charge(
        amount: order.total_cents,
        currency: order.currency,
        source: order.payment_method_token
      )
      
      order.update!(
        payment_status: gateway_response.success? ? 'paid' : 'failed',
        payment_reference: gateway_response.transaction_id
      )
      
      gateway_response
    end
  end
end

# app/services/inventory_service.rb

class InventoryService
  def reserve(line_items)
    ActiveSupport::Notifications.instrument('reserve.inventory', item_count: line_items.size) do |payload|
      reserved = []
      
      line_items.each do |item|
        result = reserve_single(item)
        reserved << item if result.success?
      end
      
      # Add data to payload after execution
      payload[:reserved_count] = reserved.size
      payload[:failed_count] = line_items.size - reserved.size
      
      reserved
    end
  end
end

The instrument method accepts a block and automatically calculates timing. Passing the payload to the block allows adding data determined during execution, which subscribers can then access.

Building a Metrics Collector

Rather than scattering subscriber logic across initializers, centralize metrics collection in a dedicated class. This approach keeps instrumentation organized and testable.

# app/metrics/application_metrics.rb

class ApplicationMetrics
  SUBSCRIPTIONS = [
    'sql.active_record',
    'render_template.action_view',
    'process_action.action_controller',
    'charge.payment_processor',
    'reserve.inventory',
    'deliver.action_mailer'
  ].freeze
  
  class << self
    def subscribe_all
      SUBSCRIPTIONS.each { |event| subscribe(event) }
    end
    
    def subscribe(event)
      ActiveSupport::Notifications.subscribe(event) do |*args|
        event_data = ActiveSupport::Notifications::Event.new(*args)
        record(event_data)
      end
    end
    
    def record(event)
      metric = {
        name: event.name,
        duration_ms: event.duration.round(2),
        timestamp: event.time.iso8601,
        payload: sanitize_payload(event.payload)
      }
      
      # Store in thread-local array for request-scoped collection
      RequestMetrics.current << metric
      
      # Log slow operations
      log_slow_operation(event) if event.duration > threshold_for(event.name)
    end
    
    private
    
    def sanitize_payload(payload)
      payload.except(:binds, :connection).transform_values do |v|
        v.is_a?(String) ? v.truncate(500) : v
      end
    end
    
    def threshold_for(event_name)
      case event_name
      when 'sql.active_record' then 100
      when 'render_template.action_view' then 50
      when 'process_action.action_controller' then 500
      else 200
      end
    end
    
    def log_slow_operation(event)
      Rails.logger.warn "[SLOW #{event.name}] #{event.duration.round(2)}ms"
    end
  end
end

# app/metrics/request_metrics.rb

class RequestMetrics
  THREAD_KEY = :request_metrics
  
  def self.current
    Thread.current[THREAD_KEY] ||= []
  end
  
  def self.clear
    Thread.current[THREAD_KEY] = []
  end
  
  def self.summary
    metrics = current
    {
      total_events: metrics.size,
      total_duration_ms: metrics.sum { |m| m[:duration_ms] }.round(2),
      by_type: metrics.group_by { |m| m[:name] }.transform_values do |events|
        {
          count: events.size,
          total_ms: events.sum { |e| e[:duration_ms] }.round(2)
        }
      end
    }
  end
end

# config/initializers/instrumentation.rb

Rails.application.config.after_initialize do
  ApplicationMetrics.subscribe_all
end

The Event class wraps the raw notification arguments and provides convenient methods like duration and time. Thread-local storage keeps metrics isolated per request in multi-threaded servers.

Exposing Metrics via Controller

Development and staging environments benefit from accessible metrics endpoints. Add a controller to expose collected data for debugging and performance analysis.

# app/controllers/metrics_controller.rb

class MetricsController < ApplicationController
  before_action :authorize_metrics_access
  
  def show
    render json: {
      ruby_version: RUBY_VERSION,
      rails_version: Rails.version,
      request_metrics: RequestMetrics.summary,
      memory_mb: (GetProcessMem.new.mb rescue 'unavailable'),
      database_pool: database_pool_stats
    }
  end
  
  private
  
  def authorize_metrics_access
    return if Rails.env.development?
    
    authenticate_or_request_with_http_token do |token|
      ActiveSupport::SecurityUtils.secure_compare(
        token,
        Rails.application.credentials.metrics_token!
      )
    end
  end
  
  def database_pool_stats
    pool = ActiveRecord::Base.connection_pool
    {
      size: pool.size,
      connections: pool.connections.size,
      waiting: pool.num_waiting_in_queue
    }
  end
end

# config/routes.rb

Rails.application.routes.draw do
  get '/metrics', to: 'metrics#show'
end

Middleware for Request-Level Metrics

Reset metrics at the start of each request and optionally append timing data to response headers during development.

# app/middleware/metrics_middleware.rb

class MetricsMiddleware
  def initialize(app)
    @app = app
  end
  
  def call(env)
    RequestMetrics.clear
    
    start_time = Process.clock_gettime(Process::CLOCK_MONOTONIC)
    status, headers, response = @app.call(env)
    duration = Process.clock_gettime(Process::CLOCK_MONOTONIC) - start_time
    
    if Rails.env.development?
      summary = RequestMetrics.summary
      headers['X-Request-Duration-Ms'] = (duration * 1000).round(2).to_s
      headers['X-SQL-Queries'] = summary.dig(:by_type, 'sql.active_record', :count).to_s
      headers['X-SQL-Duration-Ms'] = summary.dig(:by_type, 'sql.active_record', :total_ms).to_s
    end
    
    [status, headers, response]
  ensure
    RequestMetrics.clear
  end
end

# config/application.rb

module MyApp
  class Application < Rails::Application
    config.middleware.insert_before Rails::Rack::Logger, MetricsMiddleware
  end
end

The middleware uses monotonic time for accurate duration measurement and ensures cleanup happens even when exceptions occur.

Common Mistakes to Avoid

Subscribers that perform heavy work block the instrumented code path. Keep subscriber logic fast—queue expensive operations for async processing. Avoid subscribing with regex patterns like /sql/ as this captures more events than intended and impacts performance.

Never log full SQL queries in production; they may contain sensitive data. The sanitize_payload method shown above removes bind parameters, but additional filtering may be necessary depending on the application.

Next Steps

Rails instrumentation provides the foundation for production observability. Consider forwarding metrics to external services like StatsD, Prometheus, or application performance monitoring tools. The patterns shown here integrate cleanly with any backend—subscribers simply need to push data to the appropriate client instead of logging.

10 claps
← Back to Blog