2016-06-17 15:45:37 +00:00
|
|
|
module Gitlab
|
|
|
|
module Metrics
|
|
|
|
# Class for tracking timing information about method calls
|
|
|
|
class MethodCall
|
2017-11-03 11:37:08 +00:00
|
|
|
MUTEX = Mutex.new
|
2017-09-06 13:40:41 +00:00
|
|
|
BASE_LABELS = { module: nil, method: nil }.freeze
|
2017-12-12 17:12:49 +00:00
|
|
|
attr_reader :real_time_seconds, :cpu_time, :call_count, :labels
|
2016-06-17 15:45:37 +00:00
|
|
|
|
2017-11-23 14:28:37 +00:00
|
|
|
def self.call_duration_histogram
|
|
|
|
return @call_duration_histogram if @call_duration_histogram
|
2017-11-03 11:37:08 +00:00
|
|
|
|
|
|
|
MUTEX.synchronize do
|
|
|
|
@call_duration_histogram ||= Gitlab::Metrics.histogram(
|
2017-11-23 14:28:37 +00:00
|
|
|
:gitlab_method_call_duration_seconds,
|
|
|
|
'Method calls real duration',
|
2017-11-03 11:37:08 +00:00
|
|
|
Transaction::BASE_LABELS.merge(BASE_LABELS),
|
2017-11-23 14:28:37 +00:00
|
|
|
[0.01, 0.05, 0.1, 0.5, 1])
|
2017-11-03 11:37:08 +00:00
|
|
|
end
|
2017-08-22 14:13:51 +00:00
|
|
|
end
|
|
|
|
|
2017-09-06 01:02:08 +00:00
|
|
|
# name - The full name of the method (including namespace) such as
|
|
|
|
# `User#sign_in`.
|
|
|
|
#
|
2017-09-06 11:59:21 +00:00
|
|
|
def initialize(name, module_name, method_name, transaction)
|
|
|
|
@module_name = module_name
|
|
|
|
@method_name = method_name
|
2017-09-06 11:35:47 +00:00
|
|
|
@transaction = transaction
|
2016-06-17 15:45:37 +00:00
|
|
|
@name = name
|
2017-10-16 13:18:59 +00:00
|
|
|
@labels = { module: @module_name, method: @method_name }
|
2017-12-19 18:40:43 +00:00
|
|
|
@real_time_seconds = 0.0
|
2016-07-28 13:08:57 +00:00
|
|
|
@cpu_time = 0
|
2016-06-17 15:45:37 +00:00
|
|
|
@call_count = 0
|
|
|
|
end
|
|
|
|
|
|
|
|
# Measures the real and CPU execution time of the supplied block.
|
|
|
|
def measure
|
2017-12-12 17:12:49 +00:00
|
|
|
start_real_seconds = System.monotonic_time
|
2016-06-17 15:45:37 +00:00
|
|
|
start_cpu = System.cpu_time
|
|
|
|
retval = yield
|
|
|
|
|
2017-12-12 17:12:49 +00:00
|
|
|
real_time_seconds = System.monotonic_time - start_real_seconds
|
2017-09-06 18:36:25 +00:00
|
|
|
cpu_time = System.cpu_time - start_cpu
|
|
|
|
|
2017-12-12 17:12:49 +00:00
|
|
|
@real_time_seconds += real_time_seconds
|
2017-09-07 18:24:31 +00:00
|
|
|
@cpu_time += cpu_time
|
2016-06-17 15:45:37 +00:00
|
|
|
@call_count += 1
|
|
|
|
|
2017-11-23 22:30:57 +00:00
|
|
|
if call_measurement_enabled? && above_threshold?
|
2017-12-12 17:12:49 +00:00
|
|
|
self.class.call_duration_histogram.observe(@transaction.labels.merge(labels), real_time_seconds)
|
2017-11-22 23:26:50 +00:00
|
|
|
end
|
2017-08-22 14:13:51 +00:00
|
|
|
|
2016-06-17 15:45:37 +00:00
|
|
|
retval
|
|
|
|
end
|
|
|
|
|
2017-12-12 17:12:49 +00:00
|
|
|
def real_time_milliseconds
|
2017-12-19 18:40:43 +00:00
|
|
|
real_time_seconds.in_milliseconds.to_i
|
2017-12-12 17:12:49 +00:00
|
|
|
end
|
|
|
|
|
2016-06-17 15:45:37 +00:00
|
|
|
# Returns a Metric instance of the current method call.
|
|
|
|
def to_metric
|
|
|
|
Metric.new(
|
2017-08-22 14:13:51 +00:00
|
|
|
Instrumentation.series,
|
2016-06-17 15:45:37 +00:00
|
|
|
{
|
2017-12-12 17:12:49 +00:00
|
|
|
duration: real_time_milliseconds,
|
2016-06-17 15:45:37 +00:00
|
|
|
cpu_duration: cpu_time,
|
2017-08-22 14:13:51 +00:00
|
|
|
call_count: call_count
|
2016-06-17 15:45:37 +00:00
|
|
|
},
|
|
|
|
method: @name
|
|
|
|
)
|
|
|
|
end
|
|
|
|
|
|
|
|
# Returns true if the total runtime of this method exceeds the method call
|
|
|
|
# threshold.
|
|
|
|
def above_threshold?
|
2017-12-19 16:45:25 +00:00
|
|
|
real_time_milliseconds >= Metrics.method_call_threshold
|
2016-06-17 15:45:37 +00:00
|
|
|
end
|
2017-11-22 23:26:50 +00:00
|
|
|
|
2017-11-23 22:30:57 +00:00
|
|
|
def call_measurement_enabled?
|
|
|
|
Feature.get(:prometheus_metrics_method_instrumentation).enabled?
|
2017-11-22 23:26:50 +00:00
|
|
|
end
|
2016-06-17 15:45:37 +00:00
|
|
|
end
|
|
|
|
end
|
|
|
|
end
|