A custom Rails logger for only reporting completed requests with their timing

performance_logging.rb

# frozen_string_literal: true

module Performance
  LOGGER = ActiveSupport::TaggedLogging.new(Logger.new(Rails.root.join("log", "performance.log")))

  class LogSubscriber < ActiveSupport::LogSubscriber
    def logger
      LOGGER
    end
  end

  class ControllerLogSubscriber < LogSubscriber
    INTERNAL_PARAMS = %w(controller action format _method only_path)

    def process_action(event)
      info do
        payload = event.payload
        format = payload[:format]
        format  = format.to_s.upcase if format.is_a?(Symbol)
        request_name = payload[:name].presence ? payload[:name] : "#{payload[:controller]}##{payload[:action]} as #{format}"
        additions = ActionController::Base.log_process_action(payload)
        status = payload[:status]

        if status.nil? && payload[:exception].present?
          exception_class_name = payload[:exception].first
          status = ActionDispatch::ExceptionWrapper.status_code_for_exception(exception_class_name)
        end

        additions << "[#{payload[:headers]['action_dispatch.request_id'].inspect}] Allocations: #{event.allocations}" if event.respond_to?(:allocations)

        message = +"[#{payload[:headers]['action_dispatch.request_id'].inspect}] Completed #{request_name} #{status} #{Rack::Utils::HTTP_STATUS_CODES[status]} in #{event.duration.round}ms"
        message << "[#{payload[:headers]['action_dispatch.request_id'].inspect}]  (#{additions.join(" | ")})" unless additions.empty?

        message
      end
    end
  end
end

Performance::ControllerLogSubscriber.attach_to :action_controller