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 160 161 162 163 164 165 166 167 168 169 170 171 172 173 174 175 176 177 178 179 180 181 182 183 184 185 186 187 188 189 190 191 192 193 194 195 196 197 198 199 200 201 202 203 204 205 206 207 208 209 210 211 212 213 214 215 216 217 218 219 220 221 222 223 224 225 226 227 228 229 230 231 232 233 234 235 236 237 238 239 240
|
# frozen_string_literal: true
require "active_support/core_ext/module/delegation"
require "securerandom"
module ActiveSupport
module Notifications
# Instrumenters are stored in a thread local.
class Instrumenter
attr_reader :id
def initialize(notifier)
unless notifier.respond_to?(:build_handle)
notifier = LegacyHandle::Wrapper.new(notifier)
end
@id = unique_id
@notifier = notifier
end
class LegacyHandle # :nodoc:
class Wrapper # :nodoc:
def initialize(notifier)
@notifier = notifier
end
def build_handle(name, id, payload)
LegacyHandle.new(@notifier, name, id, payload)
end
delegate :start, :finish, to: :@notifier
end
def initialize(notifier, name, id, payload)
@notifier = notifier
@name = name
@id = id
@payload = payload
end
def start
@listener_state = @notifier.start @name, @id, @payload
end
def finish
@notifier.finish(@name, @id, @payload, @listener_state)
end
end
# Given a block, instrument it by measuring the time taken to execute
# and publish it. Without a block, simply send a message via the
# notifier. Notice that events get sent even if an error occurs in the
# passed-in block.
def instrument(name, payload = {})
handle = build_handle(name, payload)
handle.start
begin
yield payload if block_given?
rescue Exception => e
payload[:exception] = [e.class.name, e.message]
payload[:exception_object] = e
raise e
ensure
handle.finish
end
end
# Returns a "handle" for an event with the given +name+ and +payload+.
#
# #start and #finish must each be called exactly once on the returned object.
#
# Where possible, it's best to use #instrument, which will record the
# start and finish of the event and correctly handle any exceptions.
# +build_handle+ is a low-level API intended for cases where using
# +instrument+ isn't possible.
#
# See ActiveSupport::Notifications::Fanout::Handle.
def build_handle(name, payload)
@notifier.build_handle(name, @id, payload)
end
def new_event(name, payload = {}) # :nodoc:
Event.new(name, nil, nil, @id, payload)
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, :transaction_id
attr_accessor :payload
def initialize(name, start, ending, transaction_id, payload)
@name = name
@payload = payload.dup
@time = start ? start.to_f * 1_000.0 : start
@transaction_id = transaction_id
@end = ending ? ending.to_f * 1_000.0 : ending
@cpu_time_start = 0.0
@cpu_time_finish = 0.0
@allocation_count_start = 0
@allocation_count_finish = 0
@gc_time_start = 0
@gc_time_finish = 0
end
def time
@time / 1000.0 if @time
end
def end
@end / 1000.0 if @end
end
def record # :nodoc:
start!
begin
yield payload if block_given?
rescue Exception => e
payload[:exception] = [e.class.name, e.message]
payload[:exception_object] = e
raise e
ensure
finish!
end
end
# Record information at the time this event starts
def start!
@time = now
@cpu_time_start = now_cpu
@gc_time_start = now_gc
@allocation_count_start = now_allocations
end
# Record information at the time this event finishes
def finish!
@cpu_time_finish = now_cpu
@gc_time_finish = now_gc
@end = now
@allocation_count_finish = now_allocations
end
# Returns the CPU time (in milliseconds) passed between the call to
# #start! and the call to #finish!.
def cpu_time
@cpu_time_finish - @cpu_time_start
end
# Returns the idle time time (in milliseconds) passed between the call to
# #start! and the call to #finish!.
def idle_time
diff = duration - cpu_time
diff > 0.0 ? diff : 0.0
end
# Returns the number of allocations made between the call to #start! and
# the call to #finish!.
def allocations
@allocation_count_finish - @allocation_count_start
end
# Returns the time spent in GC (in milliseconds) between the call to #start!
# and the call to #finish!
def gc_time
(@gc_time_finish - @gc_time_start) / 1_000_000.0
end
# Returns the difference in milliseconds between when the execution of the
# event started and when it ended.
#
# ActiveSupport::Notifications.subscribe('wait') do |event|
# @event = event
# end
#
# ActiveSupport::Notifications.instrument('wait') do
# sleep 1
# end
#
# @event.duration # => 1000.138
def duration
@end - @time
end
private
def now
Process.clock_gettime(Process::CLOCK_MONOTONIC, :float_millisecond)
end
begin
Process.clock_gettime(Process::CLOCK_THREAD_CPUTIME_ID, :float_millisecond)
def now_cpu
Process.clock_gettime(Process::CLOCK_THREAD_CPUTIME_ID, :float_millisecond)
end
rescue
def now_cpu
0.0
end
end
if GC.respond_to?(:total_time)
def now_gc
GC.total_time
end
else
def now_gc
0
end
end
if GC.stat.key?(:total_allocated_objects)
def now_allocations
GC.stat(:total_allocated_objects)
end
else # Likely on JRuby, TruffleRuby
def now_allocations
0
end
end
end
end
end
|