Refactored to set request data in global state via middleware (#33)

* Refactored to set request data in global state via middleware

* Fix sanitization in event logger

app/controllers/concerns/event_logger_rails/loggable_controller.rb

@@ -10,12 +10,7 @@ module LoggableController
     def optional_data
       {
         action: action_name,
-        controller: controller_name.camelcase,
-        format: request.headers['Content-Type'],
-        method: request.method,
-        parameters: request.parameters.except(:controller, :action, :format),
-        path: request.path,
-        remote_ip: request.remote_ip
+        controller: controller_name.camelcase
       }
     end
 

lib/event_logger_rails.rb

@@ -2,13 +2,15 @@
 
 require 'rails'
 require 'active_support/dependencies'
-require 'event_logger_rails/version'
 require 'event_logger_rails/engine'
-require 'event_logger_rails/event_logger'
+require 'event_logger_rails/current_request'
 require 'event_logger_rails/event'
+require 'event_logger_rails/event_logger'
 require 'event_logger_rails/exceptions/invalid_logger_level'
 require 'event_logger_rails/exceptions/unregistered_event'
 require 'event_logger_rails/extensions/loggable'
+require 'event_logger_rails/middleware/capture_request_details'
+require 'event_logger_rails/version'
 
 ##
 # Namespace for EventLoggerRails gem
@@ -17,6 +19,8 @@ module EventLoggerRails
   autoload :Event, 'event_logger_rails/event'
   autoload :InvalidLoggerLevel, 'event_logger_rails/exceptions/invalid_logger_level'
   autoload :UnregisteredEvent, 'event_logger_rails/exceptions/unregistered_event'
+  autoload :CurrentRequest, 'event_logger_rails/current_request'
+  autoload :CaptureRequestDetails, 'event_logger_rails/middleware/capture_request_details'
 
   mattr_accessor :logdev
   mattr_accessor :logger_class

lib/event_logger_rails/current_request.rb

@@ -0,0 +1,9 @@
+# frozen_string_literal: true
+
+module EventLoggerRails
+  ##
+  # Provides global state with request details
+  class CurrentRequest < ActiveSupport::CurrentAttributes
+    attribute :id, :format, :method, :parameters, :path, :remote_ip
+  end
+end

lib/event_logger_rails/engine.rb

@@ -14,6 +14,10 @@ class Engine < ::Rails::Engine
     config.event_logger_rails.logdev = "log/event_logger_rails.#{Rails.env}.log"
     config.event_logger_rails.logger_class = Logger
 
+    initializer 'event_logger_rails.add_middleware' do |app|
+      app.middleware.use EventLoggerRails::Middleware::CaptureRequestDetails
+    end
+
     config.after_initialize do |app|
       EventLoggerRails.setup do |engine|
         engine.registered_events = Rails.application.config_for(:event_logger_rails)

lib/event_logger_rails/event.rb

@@ -28,6 +28,13 @@ def valid?
       identifier.present?
     end
 
+    def to_h
+      {
+        event_identifier: identifier,
+        event_description: description
+      }
+    end
+
     def to_s
       identifier&.to_s || provided_identifier.to_s
     end

lib/event_logger_rails/event_logger.rb

@@ -1,5 +1,6 @@
 # frozen_string_literal: true
 
+require_relative 'current_request'
 require_relative 'event'
 require_relative 'exceptions/invalid_logger_level'
 require_relative 'exceptions/unregistered_event'
@@ -29,24 +30,42 @@ def log(event, level, data = {})
 
     attr_reader :logger
 
+    def sanitizer
+      @sanitizer ||= ActiveSupport::ParameterFilter.new(EventLoggerRails.sensitive_fields)
+    end
+
     def log_message(event, level, data)
       logger.send(level) do
-        filtered_data = ActiveSupport::ParameterFilter.new(EventLoggerRails.sensitive_fields).filter(data)
-        { event_identifier: event.identifier, event_description: event.description }.merge(filtered_data)
+        event.to_h.merge(sanitizer.filter(data))
       end
     rescue NoMethodError
       raise EventLoggerRails::Exceptions::InvalidLoggerLevel.new(logger_level: level)
     end
 
+    # rubocop:disable Metrics/MethodLength
     def structured_output(level:, timestamp:, message:)
       {
-        host: Socket.gethostname,
         environment: Rails.env,
+        format: EventLoggerRails::CurrentRequest.format,
+        host: Socket.gethostname,
+        id: EventLoggerRails::CurrentRequest.id,
         service_name: Rails.application.class.module_parent_name,
         level:,
+        method: EventLoggerRails::CurrentRequest.method,
+        parameters: sanitizer.filter(EventLoggerRails::CurrentRequest.parameters),
+        path: EventLoggerRails::CurrentRequest.path,
+        remote_ip: EventLoggerRails::CurrentRequest.remote_ip,
         timestamp: timestamp.iso8601(3),
         **message
       }
     end
+    # rubocop:enable Metrics/MethodLength
+
+    def event_data(event)
+      {
+        event_identifier: event.identifier,
+        event_description: event.description
+      }
+    end
   end
 end

lib/event_logger_rails/middleware/capture_request_details.rb

@@ -0,0 +1,36 @@
+# frozen_string_literal: true
+
+require_relative '../current_request'
+
+module EventLoggerRails
+  module Middleware
+    ##
+    # Middleware to capture request details and store in global state
+    class CaptureRequestDetails
+      def initialize(app)
+        @app = app
+      end
+
+      # rubocop:disable Metrics/AbcSize, Metrics/MethodLength
+      def call(env)
+        begin
+          request = ActionDispatch::Request.new(env)
+
+          EventLoggerRails::CurrentRequest.id = env['action_dispatch.request_id']
+          EventLoggerRails::CurrentRequest.format = request.headers['Content-Type']
+          EventLoggerRails::CurrentRequest.method = request.method
+          EventLoggerRails::CurrentRequest.parameters = request.parameters.except(:controller, :action, :format)
+          EventLoggerRails::CurrentRequest.path = request.path
+          EventLoggerRails::CurrentRequest.remote_ip = request.remote_ip
+
+          status, headers, body = @app.call(env)
+        ensure
+          EventLoggerRails::CurrentRequest.reset
+        end
+
+        [status, headers, body]
+      end
+      # rubocop:enable Metrics/AbcSize, Metrics/MethodLength
+    end
+  end
+end

spec/app/controllers/concerns/event_logger_rails/loggable_controller_spec.rb

@@ -25,16 +25,10 @@ def test_three
 
 RSpec.describe EventLoggerRails::LoggableController, type: :request do
   let(:params) { { 'foo' => 'bar' } }
-  let(:headers) { { 'Content-Type' => 'text/html' } }
   let(:data_from_request) do
     {
       action: controller.action_name,
-      controller: controller.controller_name.camelcase,
-      format: 'text/html',
-      method: request.method,
-      parameters: request.params.except(:controller, :action, :format),
-      path: request.path,
-      remote_ip: request.remote_ip
+      controller: controller.controller_name.camelcase
     }
   end
 
@@ -55,7 +49,7 @@ def test_three
   end
 
   it 'calls the event logger with data from the request' do
-    get(test_one_path, params:, headers:)
+    get(test_one_path, params:)
     expect(logger_spy)
       .to have_received(:log)
       .with(

spec/lib/event_logger_rails/event_logger_spec.rb

@@ -18,6 +18,12 @@
 
     before do
       allow(IO).to receive(:open).and_return(buffer)
+      EventLoggerRails::CurrentRequest.id = '1234'
+      EventLoggerRails::CurrentRequest.format = 'text/html'
+      EventLoggerRails::CurrentRequest.method = 'GET'
+      EventLoggerRails::CurrentRequest.parameters = { foo: 'bar' }
+      EventLoggerRails::CurrentRequest.path = '/'
+      EventLoggerRails::CurrentRequest.remote_ip = '10.1.1.1'
     end
 
     # rubocop:disable RSpec/ExampleLength
@@ -28,8 +34,14 @@
         environment: 'test',
         event_description: event.description,
         event_identifier: event.identifier,
+        format: 'text/html',
         host: anything,
+        id: '1234',
         level: 'WARN',
+        method: 'GET',
+        parameters: { foo: 'bar' },
+        path: '/',
+        remote_ip: '10.1.1.1',
         service_name: 'Dummy',
         timestamp: match(/\A\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}(\.\d{3})?([+-]\d{2}:\d{2}|Z)?\z/),
         **data
@@ -49,8 +61,14 @@
           environment: 'test',
           event_description: event.description,
           event_identifier: event.identifier,
+          format: 'text/html',
           host: anything,
+          id: '1234',
           level: 'WARN',
+          method: 'GET',
+          parameters: { foo: 'bar' },
+          path: '/',
+          remote_ip: '10.1.1.1',
           service_name: 'Dummy',
           timestamp: match(/\A\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}(\.\d{3})?([+-]\d{2}:\d{2}|Z)?\z/),
           **filtered_data
@@ -70,8 +88,14 @@
           environment: 'test',
           event_description: 'Event reserved for testing.',
           event_identifier: 'event_logger_rails.event.testing',
+          format: 'text/html',
           host: anything,
+          id: '1234',
           level: 'WARN',
+          method: 'GET',
+          parameters: { foo: 'bar' },
+          path: '/',
+          remote_ip: '10.1.1.1',
           service_name: 'Dummy',
           timestamp: match(/\A\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}(\.\d{3})?([+-]\d{2}:\d{2}|Z)?\z/),
           **data
@@ -91,9 +115,14 @@
           environment: 'test',
           event_description: 'Indicates provided event was unregistered.',
           event_identifier: 'event_logger_rails.event.unregistered',
+          format: 'text/html',
           host: anything,
+          id: '1234',
           level: 'ERROR',
-          message: 'Event provided not registered: foo.bar',
+          method: 'GET',
+          parameters: { foo: 'bar' },
+          path: '/',
+          remote_ip: '10.1.1.1',
           service_name: 'Dummy',
           timestamp: match(/\A\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}(\.\d{3})?([+-]\d{2}:\d{2}|Z)?\z/)
         )
@@ -112,8 +141,14 @@
           environment: 'test',
           event_description: event.description,
           event_identifier: event.identifier,
+          format: 'text/html',
           host: anything,
+          id: '1234',
           level: 'INFO',
+          method: 'GET',
+          parameters: { foo: 'bar' },
+          path: '/',
+          remote_ip: '10.1.1.1',
           service_name: 'Dummy',
           timestamp: match(/\A\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}(\.\d{3})?([+-]\d{2}:\d{2}|Z)?\z/)
         )
@@ -132,9 +167,15 @@
           environment: 'test',
           event_description: 'Indicates provided level was invalid.',
           event_identifier: 'event_logger_rails.logger_level.invalid',
+          format: 'text/html',
           host: anything,
+          id: '1234',
           level: 'ERROR',
           message: "Invalid logger level provided: 'foo'. Valid levels: :debug, :info, :warn, :error, :unknown.",
+          method: 'GET',
+          parameters: { foo: 'bar' },
+          path: '/',
+          remote_ip: '10.1.1.1',
           service_name: 'Dummy',
           timestamp: match(/\A\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}(\.\d{3})?([+-]\d{2}:\d{2}|Z)?\z/)
         )
@@ -153,8 +194,14 @@
           environment: 'test',
           event_description: event.description,
           event_identifier: event.identifier,
+          format: 'text/html',
           host: anything,
+          id: '1234',
           level: 'WARN',
+          method: 'GET',
+          parameters: { foo: 'bar' },
+          path: '/',
+          remote_ip: '10.1.1.1',
           service_name: 'Dummy',
           timestamp: match(/\A\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}(\.\d{3})?([+-]\d{2}:\d{2}|Z)?\z/)
         )

spec/lib/event_logger_rails/event_spec.rb

@@ -75,6 +75,14 @@
     end
   end
 
+  describe '#to_h' do
+    subject(:method_call) { event.to_h }
+
+    let(:identifier) { 'foo.bar' }
+
+    it { is_expected.to eq({ event_identifier: event.identifier, event_description: event.description }) }
+  end
+
   describe '#to_s' do
     subject(:method_call) { event.to_s }