add request id to operational logs; use json format

Gemfile

@@ -22,6 +22,9 @@ gem "tzinfo-data", platforms: %i[ mswin jruby ]
 # Reduces boot times through caching; required in config/boot.rb
 gem "bootsnap", require: false
 
+# json logging
+gem "json_tagged_logger"
+
 # Use Active Storage variants [https://guides.rubyonrails.org/active_storage_overview.html#transforming-images]
 # gem "image_processing", "~> 1.2"
 

Gemfile.lock

@@ -112,6 +112,9 @@ GEM
       actionview (>= 5.0.0)
       activesupport (>= 5.0.0)
     json (2.7.2)
+    json_tagged_logger (0.8.0)
+      actionpack (>= 5.2)
+      activesupport (>= 5.2)
     jwt (2.9.3)
       base64
     language_server-protocol (3.17.0.3)
@@ -290,6 +293,7 @@ DEPENDENCIES
   faraday-retry
   interactor (~> 3.0)
   jbuilder
+  json_tagged_logger
   jwt
   ostruct
   puma (>= 5.0)

app/lib/audit_logger.rb

@@ -1,6 +1,6 @@
 class AuditLogger < ActiveSupport::Logger
   def initialize
     super(Config[:audit_log_file])
-    self.formatter = AuditLogFormatter.new
+    self.formatter = JsonLogFormatter.new
   end
 end

app/lib/audit_log_formatter.rb → app/lib/json_log_formatter.rb

@@ -1,4 +1,4 @@
-class AuditLogFormatter < ActiveSupport::Logger::SimpleFormatter
+class JsonLogFormatter < ActiveSupport::Logger::SimpleFormatter
   def call(severity, timestamp, _progname, message)
     # request_id is unique to the life of the api request
     request_id = Thread.current[:request_id]

config/environments/production.rb

@@ -47,14 +47,6 @@
   # Skip http-to-https redirect for the default health check endpoint.
   # config.ssl_options = { redirect: { exclude: ->(request) { request.path == "/up" } } }
 
-  # Log to STDOUT by default
-  config.logger = ActiveSupport::Logger.new(STDOUT)
-    .tap  { |logger| logger.formatter = ::Logger::Formatter.new }
-    .then { |logger| ActiveSupport::TaggedLogging.new(logger) }
-
-  # Prepend all log lines with the following tags.
-  config.log_tags = [ :request_id ]
-
   # "info" includes generic and useful information about system operation, but avoids logging too much
   # information to avoid inadvertent exposure of personally identifiable information (PII). If you
   # want to log everything, set the level to "debug".

config/initializers/logging.rb

@@ -0,0 +1,4 @@
+Rails.logger = JsonTaggedLogger::Logger.new(Rails.logger)
+Rails.configuration.log_tags = JsonTaggedLogger::LogTagsConfig.generate(
+  :request_id
+)

test/lib/audit_log_formatter_test.rb → test/lib/json_log_formatter_test.rb

@@ -1,27 +1,27 @@
 require "test_helper"
 
-class AuditLogFormatterTest < ActiveSupport::TestCase
+class JsonLogFormatterTest < ActiveSupport::TestCase
   setup do
     Thread.current[:request_id] = nil
   end
 
   test "#call formats logformatter inputs as json" do
     t = Time.now
-    result = AuditLogFormatter.new.call("info", t, nil, "some message")
+    result = JsonLogFormatter.new.call("info", t, nil, "some message")
     assert_equal %Q({"type":"info","time":"#{t}","request_id":null,"message":"some message"}\n), result
   end
 
   test "#call accepts and merges a Hash type for the message" do
     t = Time.now
-    result = AuditLogFormatter.new.call("info", t, nil, { key: "some message", key2: "another" })
+    result = JsonLogFormatter.new.call("info", t, nil, { key: "some message", key2: "another" })
     assert_equal %Q({"type":"info","time":"#{t}","request_id":null,"key":"some message","key2":"another"}\n), result
   end
 
   test "#call can render a thread local request_id" do
     t = Time.now
     req_id = SecureRandom.hex
     Thread.stub :current, { request_id: req_id } do
-      result = AuditLogFormatter.new.call("info", t, nil, { key: "some message" })
+      result = JsonLogFormatter.new.call("info", t, nil, { key: "some message" })
       assert_equal %Q({"type":"info","time":"#{t}","request_id":"#{req_id}","key":"some message"}\n), result
     end
   end