1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
|
# frozen_string_literal: true
require "securerandom"
module ActiveSupport
module Notifications
# Instrumenters are stored in a thread local.
class Instrumenter
attr_reader :id
def initialize(notifier)
@id = unique_id
@notifier = notifier
end
# 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 = {})
# some of the listeners might have state
listeners_state = start name, payload
begin
yield payload
rescue Exception => e
payload[:exception] = [e.class.name, e.message]
payload[:exception_object] = e
raise e
ensure
finish_with_state listeners_state, name, payload
end
end
# Send a start notification with +name+ and +payload+.
def start(name, payload)
@notifier.start name, @id, payload
end
# Send a finish notification with +name+ and +payload+.
def finish(name, payload)
@notifier.finish name, @id, payload
end
def finish_with_state(listeners_state, name, payload)
@notifier.finish name, @id, payload, listeners_state
end
private
def unique_id
SecureRandom.hex(10)
end
end
class Event
attr_reader :name, :time, :transaction_id, :payload, :children
attr_accessor :end
def self.clock_gettime_supported? # :nodoc:
defined?(Process::CLOCK_PROCESS_CPUTIME_ID) &&
!Gem.win_platform?
end
def initialize(name, start, ending, transaction_id, payload)
@name = name
@payload = payload.dup
@time = start
@transaction_id = transaction_id
@end = ending
@children = []
@duration = nil
@cpu_time_start = nil
@cpu_time_finish = nil
@allocation_count_start = 0
@allocation_count_finish = 0
end
# Record information at the time this event starts
def start!
@time = now
@cpu_time_start = now_cpu
@allocation_count_start = now_allocations
end
# Record information at the time this event finishes
def finish!
@cpu_time_finish = now_cpu
@end = now
@allocation_count_finish = now_allocations
end
# Returns the CPU time (in milliseconds) passed since the call to
# +start!+ and the call to +finish!+
def cpu_time
(@cpu_time_finish - @cpu_time_start) * 1000
end
# Returns the idle time time (in milliseconds) passed since the call to
# +start!+ and the call to +finish!+
def idle_time
duration - cpu_time
end
# Returns the number of allocations made since the call to +start!+ and
# the call to +finish!+
def allocations
@allocation_count_finish - @allocation_count_start
end
# Returns the difference in milliseconds between when the execution of the
# event started and when it ended.
#
# ActiveSupport::Notifications.subscribe('wait') do |*args|
# @event = ActiveSupport::Notifications::Event.new(*args)
# end
#
# ActiveSupport::Notifications.instrument('wait') do
# sleep 1
# end
#
# @event.duration # => 1000.138
def duration
@duration ||= 1000.0 * (self.end - time)
end
def <<(event)
@children << event
end
def parent_of?(event)
@children.include? event
end
private
def now
Process.clock_gettime(Process::CLOCK_MONOTONIC)
end
if clock_gettime_supported?
def now_cpu
Process.clock_gettime(Process::CLOCK_PROCESS_CPUTIME_ID)
end
else
def now_cpu
0
end
end
if defined?(JRUBY_VERSION)
def now_allocations
0
end
else
def now_allocations
GC.stat :total_allocated_objects
end
end
end
end
end
|
