reidmorrison/rails_semantic_logger

log_tags configuration is not working for all logs

mikesnare opened this issue · 1 comments

Environment

  • Ruby Version. 2.6.3
  • Rails Version. 6.1.3
  • Semantic Logger Version. 4.10.0
  • Rails Semantic Logger Version. 4.9.0
  • Other Application/framework names and versions (e.g. Puma, etc.). Unicorn 5.8.0

Config:

config.log_tags = { request_id: :request_id }
config.semantic_logger.backtrace_level  = :info
config.rails_semantic_logger.ap_options = { multiline: false }
config.rails_semantic_logger.started    = false
config.rails_semantic_logger.processing = false
config.rails_semantic_logger.rendered   = false
config.rails_semantic_logger.semantic   = true
Rails.application
      .config
      .semantic_logger.add_appender({ io: $stdout, formatter: :json})

Expected Behavior

The log_tags config should result in the tags being output as a hash, containing the :request_id key and the value of the current request's ID. That is not happening

Actual Behavior

Instead, the tags entry in the log contains ["request_id", "request_id"]. This is the expected output for the default Rails::Rack::Logger

What appears to be happening is that the RailsSemanticLogger::Rack::Logger is not being used for all logging. I have added debug output in several places in both the default rails logger and the RSL logger, and I can see that the the RSL rack logger is being used in some cases -- but those cases do not have a request and so they don't output any thing for the tags -- but it is not used in others. In other places, the original Rails::Rack::Logger is being used. The result is the output you see above.

Please advise.

These are the log tags we are running with Rails 6.1 and the correct hash log tags appear everywhere we see them:

    config.log_tags = {
      request_id:    :request_id,
      ip:            :remote_ip,
      amzn_trace_id: ->(request) { request.headers["X-Amzn-Trace-ID"] },
      incap_req_id:  ->(request) { request.headers["INCAP-Req-ID"] }
    }

I will keep an eye out and see if I notice any invalid log entries. Our primary logging goes to Splunk in JSON format, so we seldom look at the text log outputs in Cloudwatch now.
If you can find a place in Rails that is not being monkey-patched, consider submitting a pull request so that it can be replaced with the correct logger.