From 5836a2edc58dd6ffaeeb0a9d92b7afffce2f873e Mon Sep 17 00:00:00 2001
From: Neamah Al-Selwi <neamah.alselwi@digital.cabinet-office.gov.uk>
Date: Fri, 16 Jun 2023 14:33:51 +0100
Subject: [PATCH] Change the default logger to include govuk_request_id.

We have added govuk_request_id to the logs. This is to increase traceability. Also, we changed the logs to log into json format and send them to stdout and show them in kibabna logs and doesn't send the logs into stderr.

Co-authored-by: Iris Lau <iris.lau@digital.cabinet-office.gov.uk>
Co-authored-by: Tuomas Nylund <tuomas.nylund@digital.cabinet-office.gov.uk>
---
 lib/govuk_app_config/govuk_json_logging.rb | 23 +++++++++-
 spec/lib/govuk_json_logging_spec.rb        | 53 ++++++++++++++++++++--
 2 files changed, 70 insertions(+), 6 deletions(-)

diff --git a/lib/govuk_app_config/govuk_json_logging.rb b/lib/govuk_app_config/govuk_json_logging.rb
index eeaf830..8693126 100644
--- a/lib/govuk_app_config/govuk_json_logging.rb
+++ b/lib/govuk_app_config/govuk_json_logging.rb
@@ -1,3 +1,4 @@
+require "json"
 require "logstasher"
 require "action_controller"
 require_relative "rails_ext/action_dispatch/debug_exceptions"
@@ -28,8 +29,26 @@ def self.configure
     Rails.logger = Logger.new(
       $real_stdout, # rubocop:disable Style/GlobalVars
       level: Rails.logger.level,
-      formatter: proc { |_severity, datetime, _progname, msg|
-        "#{msg.is_a?(JSON) ? { **msg, govuk_request_id: 'blah' }.to_json : JSON.dump(timestamp: datetime.to_s, message: msg)}\n"
+      formatter: proc { |severity, datetime, _progname, msg|
+
+        begin
+          message = JSON.parse(msg)
+        rescue JSON::ParserError, TypeError => _e
+          message = msg
+        end
+
+        hash = {
+          "@timestamp": datetime.utc.iso8601(3),
+          message: message,
+          level: severity,
+          tags: %w[rails],
+        }
+
+        if defined?(GdsApi::GovukHeaders) && !GdsApi::GovukHeaders.headers[:govuk_request_id].nil?
+          hash[:govuk_request_id] = GdsApi::GovukHeaders.headers[:govuk_request_id]
+        end
+
+        "#{hash.to_json}\n"
       },
     )
 
diff --git a/spec/lib/govuk_json_logging_spec.rb b/spec/lib/govuk_json_logging_spec.rb
index 6fde492..519c173 100644
--- a/spec/lib/govuk_json_logging_spec.rb
+++ b/spec/lib/govuk_json_logging_spec.rb
@@ -4,6 +4,13 @@
 require "rack/test"
 
 RSpec.describe GovukJsonLogging do
+  let(:govuk_headers_class) do
+    Class.new do
+      def self.headers
+        { govuk_request_id: "some-value" }
+      end
+    end
+  end
   before do
     stub_const("DummyLoggingRailsApp", Class.new(Rails::Application) do
       config.hosts.clear
@@ -74,6 +81,7 @@ def app
       end
 
       it "logs errors thrown by the application" do
+        stub_const("GdsApi::GovukHeaders", govuk_headers_class)
         GovukJsonLogging.configure
         get "/error"
         fake_stdout.rewind
@@ -81,15 +89,52 @@ def app
         expect(lines).to include(/default exception/)
         error_log_line = lines.find { |log| log.match?(/default exception/) }
         expect(error_log_line).not_to be_empty
+
         error_log_json = JSON.parse(error_log_line)
-        error_log_json_msg = JSON.parse(error_log_json["message"])
-        expect(error_log_json_msg).to match(hash_including(
-                                          "exception_class" => "StandardError",
-                                          "exception_message" => "default exception",
+        expect(error_log_json).to match(hash_including(
+                                          "govuk_request_id" => "some-value",
                                         ))
+
+        error_log_json_msg = error_log_json["message"]
+        expect(error_log_json_msg).to match(hash_including(
+                                              "exception_class" => "StandardError",
+                                              "exception_message" => "default exception",
+                                            ))
+        expect(error_log_json_msg).to have_key("stacktrace")
+        expect(error_log_json_msg["stacktrace"]).to be_a(Array)
+      end
+
+      it "logs errors thrown by the application with no govuk_request_id" do
+        GovukJsonLogging.configure
+        get "/error"
+        fake_stdout.rewind
+        lines = fake_stdout.read.split("\n")
+        expect(lines).to include(/default exception/)
+        error_log_line = lines.find { |log| log.match?(/default exception/) }
+        expect(error_log_line).not_to be_empty
+        error_log_json = JSON.parse(error_log_line)
+        error_log_json_msg = error_log_json["message"]
+        expect(error_log_json_msg).to match(hash_including(
+                                              "exception_class" => "StandardError",
+                                              "exception_message" => "default exception",
+                                            ))
         expect(error_log_json_msg).to have_key("stacktrace")
         expect(error_log_json_msg["stacktrace"]).to be_a(Array)
       end
+
+      it "logs to stdout in JSON format with govuk_request_id" do
+        stub_const("GdsApi::GovukHeaders", govuk_headers_class)
+        GovukJsonLogging.configure
+        logger = Rails.logger
+        logger.info("test default log entry")
+        fake_stdout.rewind
+        log_line = fake_stdout.read
+        log_json = JSON.parse(log_line)
+
+        expect(log_json).to include("message" => "test default log entry")
+        expect(log_json).to include("govuk_request_id" => "some-value")
+
+      end
     end
   end
 end