using pluggable loggers

separating out the base logger behaviour
and logging of specific parts of request / response
into pluggable components

also setting the defualt formatter for the logger

lib/grape_logging.rb

@@ -1,4 +1,8 @@
 require 'grape_logging/multi_io'
 require 'grape_logging/version'
 require 'grape_logging/formatters/default'
-require 'grape_logging/middleware/request_logger'
+require 'grape_logging/middleware/request_logger'
+require 'grape_logging/loggers/base'
+require 'grape_logging/loggers/database_time'
+require 'grape_logging/loggers/response'
+require 'grape_logging/loggers/filter_parameters'

lib/grape_logging/formatters/default.rb

@@ -11,7 +11,7 @@ module GrapeLogging
         elsif data.is_a?(Exception)
           format_exception(data)
         elsif data.is_a?(Hash)
-          "#{data.delete(:status)} -- total=#{data.delete(:total)} db=#{data.delete(:db)} -- #{data.delete(:method)} #{data.delete(:path)} #{format_hash(data)}"
+          "#{data.delete(:status)} -- #{format_hash(data.delete(:time))} -- #{data.delete(:method)} #{data.delete(:path)} #{format_hash(data)}"
         else
           data.inspect
         end
@@ -28,4 +28,4 @@ module GrapeLogging
       end
     end
   end
-end
+end

lib/grape_logging/loggers/base.rb

@@ -0,0 +1,12 @@
+module GrapeLogging
+  module Logger
+    class Base
+      def before
+      end
+
+      def parameters(request, response)
+        {}
+      end
+    end
+  end
+end

lib/grape_logging/loggers/database_time.rb

@@ -0,0 +1,21 @@
+module GrapeLogging
+  module Logger
+    class DatabaseTime < GrapeLogging::Logger::Base
+      def before
+        @duration = 0
+        ActiveSupport::Notifications.subscribe('sql.active_record') do |*args|
+          event = ActiveSupport::Notifications::Event.new(*args)
+          @duration += event.duration
+        end
+      end
+
+      def parameters(request, response)
+        {
+          time: {
+            db: @duration.round(2)
+          }
+        }
+      end
+    end
+  end
+end

lib/grape_logging/loggers/filter_parameters.rb

@@ -0,0 +1,23 @@
+module GrapeLogging
+  module Logger
+    class FilterParameters < GrapeLogging::Logger::Base
+      def initialize(filter_parameters = nil, replacement = '[FILTERED]')
+        @filter_parameters = filter_parameters || (defined?(Rails.application) ? Rails.application.config.filter_parameters : [])
+        @replacement = replacement
+      end
+
+      def parameters(request, response)
+        filtered_parameters = request.params.clone
+        @filter_parameters.each do |param|
+          if filtered_parameters[param.to_s]
+            filtered_parameters[param.to_s] = @replacement
+          end
+        end
+
+        {
+          params: filtered_parameters
+        }
+      end
+    end
+  end
+end

lib/grape_logging/loggers/response.rb

@@ -0,0 +1,11 @@
+module GrapeLogging
+  module Logger
+    class Response < GrapeLogging::Logger::Base
+      def parameters(request, response)
+        {
+          response: response.body
+        }
+      end
+    end
+  end
+end

lib/grape_logging/middleware/request_logger.rb

@@ -3,39 +3,47 @@ require 'grape/middleware/base'
 module GrapeLogging
   module Middleware
     class RequestLogger < Grape::Middleware::Base
+      def initialize(app, options = {})
+        super
+        @logger = @options[:logger] || Logger.new(STDOUT)
+        @logger.formatter = @options[:formatter] || GrapeLogging::Formatters::Default.new
+        @included_loggers = @options[:include] || []
+      end
+
       def before
         start_time
-
-        @db_duration = 0
-        ActiveSupport::Notifications.subscribe('sql.active_record') do |*args|
-          event = ActiveSupport::Notifications::Event.new(*args)
-          @db_duration += event.duration
-        end if defined?(ActiveRecord)
+        included_loggers.each do |included_logger|
+          included_logger.before
+        end
       end
 
       def after
         stop_time
-        logger.info parameters(request, response)
+
+        parameters = parameters(request, response)
+        included_loggers.each do |included_logger|
+          parameters.merge! included_logger.parameters(request, response) do |key, oldval, newval|
+            oldval.respond_to?(:merge) ? oldval.merge(newval) : newval
+          end
+        end
+        @logger.info parameters
         nil
       end
 
       protected
       def parameters(request, response)
         {
-            path: request.path,
-            params: obfuscate_parameters(request.params),
-            method: request.request_method,
-            total: total_runtime,
-            db: @db_duration.round(2),
-            status: response.status
+          status: response.status,
+          time: {
+            total: total_runtime
+          },
+          method: request.request_method,
+          path: request.path,
+          params: obfuscate_parameters(request.params)
         }
       end
 
       private
-      def logger
-        @logger ||= @options[:logger] || Logger.new(STDOUT)
-      end
-
       def request
         @request ||= ::Rack::Request.new(env)
       end
@@ -52,17 +60,6 @@ module GrapeLogging
         @stop_time ||= Time.now
       end
 
-      def obfuscate_parameters(request_parameters)
-        filtered_parameters = request_parameters.clone.to_hash
-        sensitive_parameters.each do |param|
-          filtered_parameters[param.to_s] = '***'
-        end
-        filtered_parameters
-      end
-
-      def sensitive_parameters
-        defined?(Rails.application) ? Rails.application.config.filter_parameters : []
-      end
     end
   end
-end
+end