diff options
| -rw-r--r-- | activesupport/lib/active_support/log_subscriber.rb | 33 | ||||
| -rw-r--r-- | activesupport/lib/active_support/notifications/instrumenter.rb | 16 | ||||
| -rw-r--r-- | activesupport/test/notifications_test.rb | 4 |
3 files changed, 42 insertions, 11 deletions
diff --git a/activesupport/lib/active_support/log_subscriber.rb b/activesupport/lib/active_support/log_subscriber.rb index d5f0e3fa6c..2e423b0364 100644 --- a/activesupport/lib/active_support/log_subscriber.rb +++ b/activesupport/lib/active_support/log_subscriber.rb @@ -61,7 +61,7 @@ module ActiveSupport @@flushable_loggers = nil log_subscriber.public_methods(false).each do |event| - next if :call == event + next if %w{ start finish }.include?(event.to_s) notifier.subscribe("#{event}.#{namespace}", log_subscriber) end @@ -86,14 +86,35 @@ module ActiveSupport end end - def call(message, *args) + def initialize + @event_stack = Hash.new { |h,id| + h[id] = Hash.new { |ids,name| ids[name] = [] } + } + super + end + + def start(name, id, payload) + return unless logger + + e = ActiveSupport::Notifications::Event.new(name, Time.now, nil, id, payload) + parent = @event_stack[id][name].last + parent << e if parent + + @event_stack[id][name].push e + end + + def finish(name, id, payload) return unless logger - method = message.split('.').first + finished = Time.now + event = @event_stack[id][name].pop + event.end = finished + + method = name.split('.').first begin - send(method, ActiveSupport::Notifications::Event.new(message, *args)) - rescue => e - logger.error "Could not log #{message.inspect} event. #{e.class}: #{e.message} #{e.backtrace}" + send(method, event) + rescue Exception => e + logger.error "Could not log #{name.inspect} event. #{e.class}: #{e.message} #{e.backtrace}" end end diff --git a/activesupport/lib/active_support/notifications/instrumenter.rb b/activesupport/lib/active_support/notifications/instrumenter.rb index 58e292c658..7dfea4bb4b 100644 --- a/activesupport/lib/active_support/notifications/instrumenter.rb +++ b/activesupport/lib/active_support/notifications/instrumenter.rb @@ -31,7 +31,8 @@ module ActiveSupport end class Event - attr_reader :name, :time, :end, :transaction_id, :payload, :duration + attr_reader :name, :time, :transaction_id, :payload, :children + attr_accessor :end def initialize(name, start, ending, transaction_id, payload) @name = name @@ -39,12 +40,19 @@ module ActiveSupport @time = start @transaction_id = transaction_id @end = ending - @duration = 1000.0 * (@end - @time) + @children = [] + end + + def duration + 1000.0 * (self.end - time) + end + + def <<(event) + @children << event end def parent_of?(event) - start = (time - event.time) * 1000 - start <= 0 && (start + duration >= event.duration) + @children.include? event end end end diff --git a/activesupport/test/notifications_test.rb b/activesupport/test/notifications_test.rb index fc9fa90d07..bcb393c7bc 100644 --- a/activesupport/test/notifications_test.rb +++ b/activesupport/test/notifications_test.rb @@ -221,13 +221,15 @@ module Notifications assert_equal Hash[:payload => :bar], event.payload end - def test_event_is_parent_based_on_time_frame + def test_event_is_parent_based_on_children time = Time.utc(2009, 01, 01, 0, 0, 1) parent = event(:foo, Time.utc(2009), Time.utc(2009) + 100, random_id, {}) child = event(:foo, time, time + 10, random_id, {}) not_child = event(:foo, time, time + 100, random_id, {}) + parent.children << child + assert parent.parent_of?(child) assert !child.parent_of?(parent) assert !parent.parent_of?(not_child) |