How to tag every log call in rails with request id (lograge)

Question

I'm using lograge with rails and I have configured my logs using JSON format. I would like every time I call logger.info,logger.warn, etc. to include the request uuid. The way rails handles this with tagged logging falls short of what I would like because it does not seem able to merge the request uuid with the remainder of the JSON payload, instead prepending it on the line in non-JSON format.

For instance, if I call logger.info(client: :ig) I would expect the following log output:

{"request_id": <request uuid>, "client": "ig"}

But instead rails will prepend the request uuid (when configured via config.log_tags = [:uuid]) like so:

[<request uuid>] {"client": "ig"}

Does anyone know if there is a way to get the tagging behavior to merge with the JSON payload instead of prepending it on the same line? I'd like to configure our logs to forward to Splunk using just a simple JSON formatter and not deal with this prepending format.

Also, I have configured lograge to include request_id set to the request uuid in a lambda passed to custom_options in config/application.rb. This works but only when rails logs the request. If I explicitly call one of the logging methods anywhere else, the request_id is not included.

# application.rb
config.lograge.enabled = true
config.lograge.formatter = Lograge::Formatters::Json.new
config.lograge.custom_options = lambda do |e|
  {
    params: e.payload[:params].except("controller", "action", "utf8"),
    request_id: e.payload[:request_id] # added this in `append_info_to_payload` in ApplicationController
  }
end

Then in config/environments/production.rb

config.log_tags = [ -> (req) { { request_id: req.env["action_dispatch.request_id"] } } ]

Any help is appreciated, thanks.

Answer 1

The problem is that the payload doesn't have the request_id. As you can see in:

./actionpack-3.2.11/lib/action_controller/metal/instrumentation.rb:18-25

raw_payload = {
    :controller => self.class.name,
    :action     => self.action_name,
    :params     => request.filtered_parameters,
    :format     => request.format.try(:ref),
    :method     => request.method,
    :path       => (request.fullpath rescue "unknown")
  }

I override this method (copy ./actionpack-3.2.11/lib/action_controller/metal/instrumentation.rb in config/initializer.rb) and add your param.

raw_payload = {
    :controller => self.class.name,
    :action     => self.action_name,
    :params     => request.filtered_parameters,
    :format     => request.format.try(:ref),
    :method     => request.method,
    :path       => (request.fullpath rescue "unknown"),
    :request_id => env["action_dispatch.request_id"]
  }

Maybe there are a better way for override instrumentation, but it is enough.