use a hash to collect optional statistics about the instrumentation

3 files changed, 29 insertions, 7 deletions

diff --git a/activesupport/lib/active_support/notifications.rb b/activesupport/lib/active_support/notifications.rb
index 886d7183eb..d65431a943 100644
--- a/activesupport/lib/active_support/notifications.rb
+++ b/activesupport/lib/active_support/notifications.rb
@@ -47,11 +47,21 @@ module ActiveSupport
       attr_writer :notifier
       delegate :publish, :unsubscribe, :to => :notifier
 
-      def instrument(name, payload = {})
+      def instrument(name, payload = {}, info = nil)
         if @instrumenters[name]
-          instrumenter.instrument(name, payload) { yield payload if block_given? }
+          instrumenter.instrument(name, payload, info) {
+            yield payload if block_given?
+          }
         else
-          yield payload if block_given?
+          value = nil
+          if block_given?
+            if info
+              info[:elapsed] = Benchmark.ms { value = yield payload }
+            else
+              value = yield payload
+            end
+          end
+          value
         end
       end
 
diff --git a/activesupport/lib/active_support/notifications/instrumenter.rb b/activesupport/lib/active_support/notifications/instrumenter.rb
index 441fefb491..4fc446fb2b 100644
--- a/activesupport/lib/active_support/notifications/instrumenter.rb
+++ b/activesupport/lib/active_support/notifications/instrumenter.rb
@@ -14,16 +14,19 @@ module ActiveSupport
       # Instrument the given block by measuring the time taken to execute it
       # and publish it. Notice that events get sent even if an error occurs
       # in the passed-in block
-      def instrument(name, payload={})
-        started = Time.now
-
+      def instrument(name, payload={}, info = nil)
         begin
+          started = Time.now
           yield
         rescue Exception => e
           payload[:exception] = [e.class.name, e.message]
           raise e
         ensure
-          @notifier.publish(name, started, Time.now, @id, payload)
+          finished = Time.now
+          if info
+            info[:elapsed] = 1000.0 * (finished.to_f - started.to_f)
+          end
+          @notifier.publish(name, started, finished, @id, payload)
         end
       end
 
diff --git a/activesupport/test/notifications_test.rb b/activesupport/test/notifications_test.rb
index 9faa11efbc..41e8ca4ae7 100644
--- a/activesupport/test/notifications_test.rb
+++ b/activesupport/test/notifications_test.rb
@@ -172,6 +172,15 @@ module Notifications
         :exception => ["RuntimeError", "FAIL"]], @events.last.payload
     end
 
+    def test_elapsed
+      instrument(:something) do
+        sleep(0.001)
+      end
+
+      # Elapsed returns duration in ms
+      assert_in_delta 1, ActiveSupport::Notifications.instrumenter.elapsed, 100
+    end
+
     def test_event_is_pushed_even_without_block
       instrument(:awesome, :payload => "notifications")
       assert_equal 1, @events.size