Use the https://github.com/aserafin/grape_logging/pull/18 code to add thread safety for the use of ActiveSupport::Notifications

README.md

@@ -48,7 +48,6 @@ You can include logging of other parts of the request / response cycle by includ
       use GrapeLogging::Middleware::RequestLogger,
         logger: logger,
         include: [ GrapeLogging::Loggers::Response.new,
-                   GrapeLogging::Loggers::DatabaseTime.new,
                    GrapeLogging::Loggers::FilterParameters.new ]
     end
 
@@ -71,7 +70,6 @@ First, config ```grape_logging```, like that:
       use GrapeLogging::Middleware::RequestLogger,
         instrumentation_key: 'grape_key',
         include: [ GrapeLogging::Loggers::Response.new,
-                   GrapeLogging::Loggers::DatabaseTime.new,
                    GrapeLogging::Loggers::FilterParameters.new ]
     end
     

lib/grape_logging.rb

@@ -3,7 +3,7 @@ require 'grape_logging/version'
 require 'grape_logging/formatters/default'
 require 'grape_logging/formatters/json'
 require 'grape_logging/loggers/base'
-require 'grape_logging/loggers/database_time'
 require 'grape_logging/loggers/response'
 require 'grape_logging/loggers/filter_parameters'
+require 'grape_logging/timings'
 require 'grape_logging/middleware/request_logger'

lib/grape_logging/loggers/database_time.rb

@@ -1,26 +0,0 @@
-module GrapeLogging
-  module Loggers
-    class DatabaseTime < GrapeLogging::Loggers::Base
-      def before
-        @duration = 0
-        @subscription = ActiveSupport::Notifications.subscribe('sql.active_record') do |*args|
-          event = ActiveSupport::Notifications::Event.new(*args)
-          @duration += event.duration
-        end if defined?(ActiveRecord)
-      end
-
-      def after
-      ensure
-        ActiveSupport::Notifications.unsubscribe(@subscription) if @subscription
-      end
-
-      def parameters(request, response)
-        {
-          time: {
-            db: @duration.round(2)
-          }
-        }
-      end
-    end
-  end
-end

lib/grape_logging/middleware/request_logger.rb

@@ -3,6 +3,12 @@ require 'grape/middleware/base'
 module GrapeLogging
   module Middleware
     class RequestLogger < Grape::Middleware::Base
+
+      ActiveSupport::Notifications.subscribe('sql.active_record') do |*args|
+        event = ActiveSupport::Notifications::Event.new(*args)
+        GrapeLogging::Timings.append_db_runtime(event)
+      end if defined?(ActiveRecord)
+
       def initialize(app, options = {})
         super
         if options[:instrumentation_key]
@@ -15,6 +21,7 @@ module GrapeLogging
       end
 
       def before
+        reset_db_runtime
         start_time
         @included_loggers.each { |included_logger| included_logger.before }
       end
@@ -46,7 +53,9 @@ module GrapeLogging
         {
           status: response.status,
           time: {
-            total: total_runtime
+            total: total_runtime,
+            db: db_runtime,
+            view: view_runtime
           },
           method: request.request_method,
           path: request.path,
@@ -63,6 +72,18 @@ module GrapeLogging
         ((stop_time - start_time) * 1000).round(2)
       end
 
+      def view_runtime
+        total_runtime - db_runtime
+      end
+
+      def db_runtime
+        GrapeLogging::Timings.db_runtime.round(2)
+      end
+
+      def reset_db_runtime
+        GrapeLogging::Timings.reset_db_runtime
+      end
+
       def start_time
         @start_time ||= Time.now
       end

lib/grape_logging/timings.rb

@@ -0,0 +1,21 @@
+module GrapeLogging
+  module Timings
+    extend self
+
+    def db_runtime=(value)
+      Thread.current[:grape_db_runtime] = value
+    end
+
+    def db_runtime
+      Thread.current[:grape_db_runtime] ||= 0
+    end
+
+    def reset_db_runtime
+      self.db_runtime = 0
+    end
+
+    def append_db_runtime(event)
+      self.db_runtime = event.duration
+    end
+  end
+end