From 0fe3fe4656eb5044283bce18f73cda473fe81988 Mon Sep 17 00:00:00 2001 From: Tomas D'Stefano Date: Mon, 18 Nov 2024 14:37:57 +0000 Subject: [PATCH 1/5] Make sure all logs in production has JSON format --- config/environments/production.rb | 6 ++++++ 1 file changed, 6 insertions(+) diff --git a/config/environments/production.rb b/config/environments/production.rb index 66bd4f0fec..4eab8eb488 100644 --- a/config/environments/production.rb +++ b/config/environments/production.rb @@ -48,6 +48,12 @@ # Logging config.rails_semantic_logger.add_file_appender = false + config.rails_semantic_logger.format = :json + config.semantic_logger.add_appender( + io: $stdout, + level: config.log_level, + formatter: config.rails_semantic_logger.format, + ) config.active_record.logger = nil # Don't log SQL in production From ae5315c97ac6f82b22fcca3010e7ece8ead7e48f Mon Sep 17 00:00:00 2001 From: Tomas D'Stefano Date: Mon, 18 Nov 2024 15:19:32 +0000 Subject: [PATCH 2/5] Remove application name config from logs and move log configuration Application name is blank so is an useless configuration --- config/application.rb | 3 +++ config/environments/production.rb | 2 +- config/initializers/semantic_logger.rb | 12 +++++------- 3 files changed, 9 insertions(+), 8 deletions(-) diff --git a/config/application.rb b/config/application.rb index c87a2026ae..3a0cca249a 100644 --- a/config/application.rb +++ b/config/application.rb @@ -68,5 +68,8 @@ class Application < Rails::Application config.exceptions_app = routes config.active_job.queue_adapter = :sidekiq + + config.log_tags = [:request_id] + config.log_level = Settings.log_level end end diff --git a/config/environments/production.rb b/config/environments/production.rb index 4eab8eb488..008b78b04c 100644 --- a/config/environments/production.rb +++ b/config/environments/production.rb @@ -52,7 +52,7 @@ config.semantic_logger.add_appender( io: $stdout, level: config.log_level, - formatter: config.rails_semantic_logger.format, + formatter: config.rails_semantic_logger.format ) config.active_record.logger = nil # Don't log SQL in production diff --git a/config/initializers/semantic_logger.rb b/config/initializers/semantic_logger.rb index d85d0aeed0..d12599ad1a 100644 --- a/config/initializers/semantic_logger.rb +++ b/config/initializers/semantic_logger.rb @@ -59,12 +59,10 @@ def method_is_post_or_put_or_patch? end unless Rails.env.local? - Rails.application.configure do - config.semantic_logger.application = Settings.application_name - config.log_tags = [:request_id] - config.log_level = Settings.log_level - end - - SemanticLogger.add_appender(io: $stdout, level: Settings.log_level, formatter: CustomLogFormatter.new) + SemanticLogger.add_appender( + io: $stdout, + level: Rails.application.config.log_level, + formatter: CustomLogFormatter.new + ) Rails.application.config.logger.info('Application logging to STDOUT') end From 3d95145d92a4aa258296af0585e11b3581f7ab0f Mon Sep 17 00:00:00 2001 From: Tomas D'Stefano Date: Mon, 18 Nov 2024 15:42:40 +0000 Subject: [PATCH 3/5] Debug semantic logger configuration --- config/initializers/semantic_logger.rb | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/config/initializers/semantic_logger.rb b/config/initializers/semantic_logger.rb index d12599ad1a..2203edf9a7 100644 --- a/config/initializers/semantic_logger.rb +++ b/config/initializers/semantic_logger.rb @@ -64,5 +64,7 @@ def method_is_post_or_put_or_patch? level: Rails.application.config.log_level, formatter: CustomLogFormatter.new ) - Rails.application.config.logger.info('Application logging to STDOUT') + Rails.application.config.logger.info( + "Application logging to STDOUT. Config: #{Rails.application.config.rails_semantic_logger}" + ) end From 6e048f3dfc4f0dd60318547c46deb477dc7829e4 Mon Sep 17 00:00:00 2001 From: Tomas D'Stefano Date: Mon, 18 Nov 2024 15:56:05 +0000 Subject: [PATCH 4/5] Remove custom log formatter In order to apply the JSON formatter this custom log needs to go. For the looks of it it is not doing anything that the normal log and filtering should do. --- config/initializers/semantic_logger.rb | 70 -------------------------- 1 file changed, 70 deletions(-) delete mode 100644 config/initializers/semantic_logger.rb diff --git a/config/initializers/semantic_logger.rb b/config/initializers/semantic_logger.rb deleted file mode 100644 index 2203edf9a7..0000000000 --- a/config/initializers/semantic_logger.rb +++ /dev/null @@ -1,70 +0,0 @@ -# frozen_string_literal: true - -return unless defined? SemanticLogger - -class CustomLogFormatter < SemanticLogger::Formatters::Raw - def call(log, logger) - super - format_job_data - format_exception - format_json_message_context - format_backtrace - remove_post_params - hash.to_json - end - - private - - def format_job_data - hash[:job_id] = RequestStore.store[:job_id] if RequestStore.store[:job_id].present? - hash[:job_queue] = RequestStore.store[:job_queue] if RequestStore.store[:job_queue].present? - end - - def format_exception - exception_message = hash.dig(:exception, :message) - return if exception_message.nil? - - hash[:message] = "Exception occured: #{exception_message}" - end - - def format_json_message_context - if hash[:message].present? - context = JSON.parse(hash[:message])['context'] - hash[:sidekiq_job_context] = hash[:message] - hash[:message] = context - end - rescue JSON::ParserError - nil - end - - def format_backtrace - return unless hash[:message]&.start_with?('/') - - message_lines = hash[:message].split("\n") - return unless message_lines.all? { |line| line.start_with?('/') } - - hash[:backtrace] = hash[:message] - hash[:message] = "Exception occured: #{message_lines.first}" - end - - def remove_post_params - return unless method_is_post_or_put_or_patch? && hash.dig(:payload, :params).present? - - hash[:payload][:params].clear - end - - def method_is_post_or_put_or_patch? - hash.dig(:payload, :method).in?(%w[PUT POST PATCH]) - end -end - -unless Rails.env.local? - SemanticLogger.add_appender( - io: $stdout, - level: Rails.application.config.log_level, - formatter: CustomLogFormatter.new - ) - Rails.application.config.logger.info( - "Application logging to STDOUT. Config: #{Rails.application.config.rails_semantic_logger}" - ) -end From 4f07749da40d595b308ef352bc1b2375b0dd3f8a Mon Sep 17 00:00:00 2001 From: Tomas D'Stefano Date: Tue, 19 Nov 2024 08:50:28 +0000 Subject: [PATCH 5/5] Make sure custom log formatter is used and it is JSON format --- app/lib/custom_log_formatter.rb | 59 +++++++++++++++++++++++++++++++ config/environments/production.rb | 5 +-- 2 files changed, 62 insertions(+), 2 deletions(-) create mode 100644 app/lib/custom_log_formatter.rb diff --git a/app/lib/custom_log_formatter.rb b/app/lib/custom_log_formatter.rb new file mode 100644 index 0000000000..b87c0d37c1 --- /dev/null +++ b/app/lib/custom_log_formatter.rb @@ -0,0 +1,59 @@ +# frozen_string_literal: true + +class CustomLogFormatter < SemanticLogger::Formatters::Json + def call(log, logger) + super + + format_job_data + format_exception + format_json_message_context + format_backtrace + remove_post_params + + hash.to_json + end + + private + + def format_job_data + hash[:job_id] = RequestStore.store[:job_id] if RequestStore.store[:job_id].present? + hash[:job_queue] = RequestStore.store[:job_queue] if RequestStore.store[:job_queue].present? + end + + def format_exception + exception_message = hash.dig(:exception, :message) + return if exception_message.nil? + + hash[:message] = "Exception occured: #{exception_message}" + end + + def format_json_message_context + if hash[:message].present? + context = JSON.parse(hash[:message])['context'] + hash[:sidekiq_job_context] = hash[:message] + hash[:message] = context + end + rescue JSON::ParserError + nil + end + + def format_backtrace + return unless hash[:message]&.start_with?('/') + + message_lines = hash[:message].split("\n") + return unless message_lines.all? { |line| line.start_with?('/') } + + hash[:backtrace] = hash[:message] + hash[:message] = "Exception occured: #{message_lines.first}" + end + + def remove_post_params + return unless method_is_post_or_put_or_patch? && hash.dig(:payload, :params).present? + + hash[:payload][:params].clear + end + + def method_is_post_or_put_or_patch? + hash.dig(:payload, :method).in?(%w[PUT POST PATCH]) + end +end diff --git a/config/environments/production.rb b/config/environments/production.rb index 008b78b04c..f63318eb33 100644 --- a/config/environments/production.rb +++ b/config/environments/production.rb @@ -1,6 +1,7 @@ # frozen_string_literal: true require "active_support/core_ext/integer/time" +require_dependency Rails.root.join('app/lib/custom_log_formatter') Rails.application.configure do config.x.read_only_database_url = ENV.fetch('DATABASE_URL', nil) @@ -48,11 +49,11 @@ # Logging config.rails_semantic_logger.add_file_appender = false - config.rails_semantic_logger.format = :json + config.rails_semantic_logger.format = CustomLogFormatter.new config.semantic_logger.add_appender( io: $stdout, level: config.log_level, - formatter: config.rails_semantic_logger.format + formatter: CustomLogFormatter.new ) config.active_record.logger = nil # Don't log SQL in production