Log Rails request response time

log_response_time.rb

# config/initializers/log_response_time.rb

event_logger = ::Logger.new("#{Rails.root}/log/response_times.log")
event_logger.formatter = proc { |_severity, _datetime, _progname, msg|
  "#{msg}\n"
}

ActiveSupport::Notifications.subscribe('process_action.action_controller') do |_, started, finished, _, stats|
  request_time = (finished - started) * 1000
  controller = stats[:controller][0..-11].underscore
  action = "#{stats[:method]} #{controller}##{stats[:action]}.#{stats[:format]}"

  event_logger.info "#{action} | Status: #{stats[:status]} | "\
                    "Total: #{request_time} | "\
                    "ActiveRecord: #{stats[:db_runtime]} | "\
                    "Views: #{stats[:view_runtime]}"
end

# This will produce a log file in log/response_times.log with the following format:
# GET organizations#index.html | Status: 200 | Total: 1945.0608069999998 | ActiveRecord: 369.2160559999999 | Views: 1568.163872000155
# GET organizations#index.json | Status: 200 | Total: 19969.031894 | ActiveRecord: 1948.9441309999995 | Views: 18013.89978099879
# GET organizations#index.html | Status: 200 | Total: 5174.803143 | ActiveRecord: 427.5121660000008 | Views: 4746.199888995121
# GET organizations#index.html | Status: 200 | Total: 4926.097762 | ActiveRecord: 434.552126999999 | Views: 4490.50438000332