From 714f361b170013a64052cb22884d0b2f5e00e77b Mon Sep 17 00:00:00 2001
From: jules <jules.ivanic@gmail.com>
Date: Mon, 29 Feb 2016 15:32:29 +0100
Subject: [PATCH] Use the https://github.com/aserafin/grape_logging/pull/18
 code to add thread safety for the use of ActiveSupport::Notifications

---
 README.md                                     |  2 --
 lib/grape_logging.rb                          |  2 +-
 lib/grape_logging/loggers/database_time.rb    | 26 -------------------
 .../middleware/request_logger.rb              | 23 +++++++++++++++-
 lib/grape_logging/timings.rb                  | 21 +++++++++++++++
 5 files changed, 44 insertions(+), 30 deletions(-)
 delete mode 100644 lib/grape_logging/loggers/database_time.rb
 create mode 100644 lib/grape_logging/timings.rb

diff --git a/README.md b/README.md
index 0e75ff6..9f6e600 100644
--- a/README.md
+++ b/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
     
diff --git a/lib/grape_logging.rb b/lib/grape_logging.rb
index 6789ec0..d23956a 100644
--- a/lib/grape_logging.rb
+++ b/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'
diff --git a/lib/grape_logging/loggers/database_time.rb b/lib/grape_logging/loggers/database_time.rb
deleted file mode 100644
index 0738422..0000000
--- a/lib/grape_logging/loggers/database_time.rb
+++ /dev/null
@@ -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
diff --git a/lib/grape_logging/middleware/request_logger.rb b/lib/grape_logging/middleware/request_logger.rb
index 0272124..f46fcf6 100644
--- a/lib/grape_logging/middleware/request_logger.rb
+++ b/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
diff --git a/lib/grape_logging/timings.rb b/lib/grape_logging/timings.rb
new file mode 100644
index 0000000..145d99f
--- /dev/null
+++ b/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
\ No newline at end of file