diff --git a/.env.example b/.env.example index 8eb12c5b4..6509a090b 100644 --- a/.env.example +++ b/.env.example @@ -24,3 +24,4 @@ GOV_UK_NOTIFY_API_KEY=key GOV_UK_NOTIFY_API_TEMPLATE_ID=id SESSION_TIMEOUT=1 HOST=http://localhost:3000 +ENABLE_ASIM_LOGGER=false diff --git a/Gemfile b/Gemfile index 07bf7d7af..51e138957 100644 --- a/Gemfile +++ b/Gemfile @@ -129,6 +129,7 @@ gem "puma", "~> 6.4.2" gem "appsignal" # Log formatting +gem "json_tagged_logger" gem "lograge" # speedup server boot time diff --git a/Gemfile.lock b/Gemfile.lock index 1251427d0..b46cf6158 100644 --- a/Gemfile.lock +++ b/Gemfile.lock @@ -291,6 +291,9 @@ GEM js_cookie_rails (2.1.4) railties (>= 3.1) json (2.6.3) + json_tagged_logger (0.7.0) + actionpack (>= 6.1) + activesupport (>= 6.1) jwt (2.8.1) base64 kaminari (1.2.2) @@ -751,6 +754,7 @@ DEPENDENCIES jquery-ui-rails (>= 7.0.0) js_cookie_rails (= 2.1.4) json + json_tagged_logger kaminari launchy letter_opener diff --git a/app/controllers/application_controller.rb b/app/controllers/application_controller.rb index 23d6199f5..f96d990cc 100644 --- a/app/controllers/application_controller.rb +++ b/app/controllers/application_controller.rb @@ -9,6 +9,7 @@ class ApplicationController < ActionController::Base before_action :configure_permitted_parameters, if: :devise_controller? before_action :set_context_tags + before_action :set_current_attributes before_action :set_paper_trail_whodunnit before_action :disable_browser_caching! @@ -165,6 +166,17 @@ def set_context_tags private + def set_current_attributes + Current.user_id = current_user&.id || current_admin&.id + Current.user_type = if current_user.present? + "User" + elsif current_admin.present? + "Admin" + else + "Other" + end + end + def configure_permitted_parameters devise_parameter_sanitizer.permit( :sign_up, diff --git a/app/models/current.rb b/app/models/current.rb new file mode 100644 index 000000000..03cba1834 --- /dev/null +++ b/app/models/current.rb @@ -0,0 +1,4 @@ +class Current < ActiveSupport::CurrentAttributes + attribute :user_id + attribute :user_type +end diff --git a/config/environments/development.rb b/config/environments/development.rb index 39341b495..b5ea3d819 100644 --- a/config/environments/development.rb +++ b/config/environments/development.rb @@ -1,4 +1,5 @@ require "active_support/core_ext/integer/time" +require Rails.root.join("lib/formatters/asim_formatter") Rails.application.configure do # Settings specified here will take precedence over those in config/application.rb. @@ -70,4 +71,21 @@ # Uncomment if you wish to allow Action Cable access from any origin. # config.action_cable.disable_request_forgery_protection = true + + # Enable ASIM logging if ENABLE_ASIM_LOGGER is set to 'true' + if ENV["ENABLE_ASIM_LOGGER"] == "true" + config.lograge.enabled = true + config.lograge.formatter = AsimFormatter.new + config.logger = ActiveSupport::TaggedLogging.new(Logger.new($stdout)) + else + # normal development logging configuration + config.logger = ActiveSupport::TaggedLogging.new(ActiveSupport::Logger.new($stdout)) + end + + config.log_tags = JsonTaggedLogger::LogTagsConfig.generate( + :request_id, + :remote_ip, + JsonTaggedLogger::TagFromSession.get(:user_id), + :user_agent, + ) end diff --git a/config/environments/production.rb b/config/environments/production.rb index bbe9edb99..72eb267ad 100644 --- a/config/environments/production.rb +++ b/config/environments/production.rb @@ -86,14 +86,18 @@ # Send deprecation notices to registered listeners. config.active_support.deprecation = :notify + config.log_tags = JsonTaggedLogger::LogTagsConfig.generate( + :request_id, + :remote_ip, + JsonTaggedLogger::TagFromSession.get(:user_id), + :user_agent, + ) + logger = ActiveSupport::Logger.new($stdout) + config.logger = JsonTaggedLogger::Logger.new(logger) + config.lograge.enabled = true config.lograge.ignore_actions = ["HealthcheckController#index"] - config.lograge.keep_original_rails_log = true - config.lograge.logger = Appsignal::Logger.new( - "rails", - format: Appsignal::Logger::LOGFMT, - ) - config.logger = ActiveSupport::Logger.new($stdout) # Lograge-formatted logs to STDOUT + config.lograge.formatter = AsimFormatter.new # Do not dump schema after migrations. config.active_record.dump_schema_after_migration = false diff --git a/lib/formatters/asim_formatter.rb b/lib/formatters/asim_formatter.rb new file mode 100644 index 000000000..44f9babbc --- /dev/null +++ b/lib/formatters/asim_formatter.rb @@ -0,0 +1,87 @@ +require "time" +require "date" + +class AsimFormatter + def call(data) + end_time = Time.now.utc + start_time = end_time - (data[:duration] || 0) + + { + "EventCount" => 1, + "EventStartTime" => format_time(start_time), + "EventEndTime" => format_time(end_time), + "EventType" => event_type(data), + "EventResult" => event_result(data), + "EventSeverity" => map_severity(data[:level]), + "EventOriginalSeverity" => data[:level], + "EventSchema" => "ProcessEvent", + "EventSchemaVersion" => "0.1.4", + "EventProduct" => "KAE", + "EventProductVersion" => Rails.version, + "EventVendor" => "Ruby on Rails", + "EventOwner" => data[:owner], + "ActingAppType" => "Ruby on Rails", + "SrcIpAddr" => data[:remote_ip], + "SrcPortNumber" => ENV["PORT"] || 3000, + "IpAddr" => data[:remote_ip], + "SrcUserId" => Current.user_id, + "SrcUserType" => Current.user_type, + "HttpUserAgent" => data[:user_agent], + "Dvc" => ENV["DOMAIN"] || "unknown", + "DvcDomain" => ENV["DOMAIN"] || "unknown", + "AdditionalFields" => { + "RailsLogFormatterAsimVersion" => "1.0.0", + "TraceHeaders" => trace_headers(data), + "RawLog" => data.to_json, + }, + }.to_json + end + + private + + def format_time(time) + time.iso8601 if time + end + + def event_type(data) + controller = data[:controller] + action = data[:action] + if controller && action + "#{controller}##{action}" + else + "UnknownEvent" + end + end + + def event_result(data) + status = data[:status] + if status + (status >= 400) ? "Failure" : "Success" + else + "NA" + end + end + + def map_severity(level) + case level.to_s.upcase + when "DEBUG" + "Informational" + when "INFO" + "Informational" + when "WARN" + "Medium" + when "ERROR" + "High" + when "FATAL" + "High" + else + "Informational" + end + end + + def trace_headers(data) + { + "X-Request-Id" => data[:request_id], + } + end +end