Merge pull request #35984 from vishaltelangre/asn-misc-fixes

Various fixes in ActiveSupport::Notifications::Event

3 files changed, 18 insertions, 10 deletions

diff --git a/activesupport/lib/active_support/notifications/fanout.rb b/activesupport/lib/active_support/notifications/fanout.rb
index c506b35b1e..8812b67f63 100644
--- a/activesupport/lib/active_support/notifications/fanout.rb
+++ b/activesupport/lib/active_support/notifications/fanout.rb
@@ -180,13 +180,13 @@ module ActiveSupport
 
           def start(name, id, payload)
             timestack = Thread.current[:_timestack] ||= []
-            timestack.push Time.now
+            timestack.push Concurrent.monotonic_time
           end
 
           def finish(name, id, payload)
             timestack = Thread.current[:_timestack]
             started = timestack.pop
-            @delegate.call(name, started, Time.now, id, payload)
+            @delegate.call(name, started, Concurrent.monotonic_time, id, payload)
           end
         end
 
diff --git a/activesupport/lib/active_support/notifications/instrumenter.rb b/activesupport/lib/active_support/notifications/instrumenter.rb
index a03e7e483e..12546511a8 100644
--- a/activesupport/lib/active_support/notifications/instrumenter.rb
+++ b/activesupport/lib/active_support/notifications/instrumenter.rb
@@ -68,9 +68,8 @@ module ActiveSupport
         @transaction_id = transaction_id
         @end            = ending
         @children       = []
-        @duration       = nil
-        @cpu_time_start = nil
-        @cpu_time_finish = nil
+        @cpu_time_start = 0
+        @cpu_time_finish = 0
         @allocation_count_start = 0
         @allocation_count_finish = 0
       end
@@ -125,7 +124,7 @@ module ActiveSupport
       #
       #   @event.duration # => 1000.138
       def duration
-        @duration ||= 1000.0 * (self.end - time)
+        1000.0 * (self.end - time)
       end
 
       def <<(event)
diff --git a/activesupport/test/notifications_test.rb b/activesupport/test/notifications_test.rb
index bb20d26a25..0af59764b5 100644
--- a/activesupport/test/notifications_test.rb
+++ b/activesupport/test/notifications_test.rb
@@ -302,7 +302,7 @@ module Notifications
 
   class EventTest < TestCase
     def test_events_are_initialized_with_details
-      time = Time.now
+      time = Concurrent.monotonic_time
       event = event(:foo, time, time + 0.01, random_id, {})
 
       assert_equal :foo, event.name
@@ -310,15 +310,24 @@ module Notifications
       assert_in_delta 10.0, event.duration, 0.00001
     end
 
+    def test_event_cpu_time_and_idle_time_when_start_and_finish_is_not_called
+      time = Concurrent.monotonic_time
+      event = event(:foo, time, time + 0.01, random_id, {})
+
+      assert_equal 0, event.cpu_time
+      assert_in_delta 10.0, event.idle_time, 0.00001
+    end
+
+
     def test_events_consumes_information_given_as_payload
-      event = event(:foo, Time.now, Time.now + 1, random_id, payload: :bar)
+      event = event(:foo, Concurrent.monotonic_time, Concurrent.monotonic_time + 1, random_id, payload: :bar)
       assert_equal Hash[payload: :bar], event.payload
     end
 
     def test_event_is_parent_based_on_children
-      time = Time.utc(2009, 01, 01, 0, 0, 1)
+      time = Concurrent.monotonic_time
 
-      parent    = event(:foo, Time.utc(2009), Time.utc(2009) + 100, random_id, {})
+      parent    = event(:foo, Concurrent.monotonic_time, Concurrent.monotonic_time + 100, random_id, {})
       child     = event(:foo, time, time + 10, random_id, {})
       not_child = event(:foo, time, time + 100, random_id, {})