2019-08-09 00:33:20 -04:00
|
|
|
# frozen_string_literal: true
|
|
|
|
|
|
|
|
module Gitlab
|
|
|
|
module InstrumentationHelper
|
|
|
|
extend self
|
|
|
|
|
2020-04-27 23:09:53 -04:00
|
|
|
DURATION_PRECISION = 6 # microseconds
|
2019-08-09 00:33:20 -04:00
|
|
|
|
2021-02-05 10:09:28 -05:00
|
|
|
def init_instrumentation_data(request_ip: nil)
|
|
|
|
# Set `request_start_time` only if this is request
|
|
|
|
# This is done, as `request_start_time` imply `request_deadline`
|
|
|
|
if request_ip
|
|
|
|
Gitlab::RequestContext.instance.client_ip = request_ip
|
|
|
|
Gitlab::RequestContext.instance.request_start_time = Gitlab::Metrics::System.real_time
|
|
|
|
end
|
|
|
|
|
|
|
|
Gitlab::RequestContext.instance.start_thread_cpu_time = Gitlab::Metrics::System.thread_cpu_time
|
|
|
|
Gitlab::RequestContext.instance.thread_memory_allocations = Gitlab::Memory::Instrumentation.start_thread_memory_allocations
|
2020-06-16 08:09:00 -04:00
|
|
|
end
|
|
|
|
|
2019-08-09 00:33:20 -04:00
|
|
|
def add_instrumentation_data(payload)
|
2020-05-27 05:08:30 -04:00
|
|
|
instrument_gitaly(payload)
|
|
|
|
instrument_rugged(payload)
|
|
|
|
instrument_redis(payload)
|
|
|
|
instrument_elasticsearch(payload)
|
2020-11-06 10:09:14 -05:00
|
|
|
instrument_throttle(payload)
|
2020-12-03 10:09:46 -05:00
|
|
|
instrument_active_record(payload)
|
2021-01-22 10:09:08 -05:00
|
|
|
instrument_external_http(payload)
|
2021-02-01 07:09:03 -05:00
|
|
|
instrument_rack_attack(payload)
|
2021-02-05 10:09:28 -05:00
|
|
|
instrument_cpu(payload)
|
|
|
|
instrument_thread_memory_allocations(payload)
|
2021-06-30 17:07:26 -04:00
|
|
|
instrument_load_balancing(payload)
|
2021-08-12 05:09:05 -04:00
|
|
|
instrument_pid(payload)
|
2020-05-27 05:08:30 -04:00
|
|
|
end
|
|
|
|
|
|
|
|
def instrument_gitaly(payload)
|
2019-08-09 00:33:20 -04:00
|
|
|
gitaly_calls = Gitlab::GitalyClient.get_request_count
|
|
|
|
|
2020-05-27 05:08:30 -04:00
|
|
|
return if gitaly_calls == 0
|
|
|
|
|
|
|
|
payload[:gitaly_calls] = gitaly_calls
|
|
|
|
payload[:gitaly_duration_s] = Gitlab::GitalyClient.query_time
|
|
|
|
end
|
2019-08-09 00:33:20 -04:00
|
|
|
|
2020-05-27 05:08:30 -04:00
|
|
|
def instrument_rugged(payload)
|
2019-08-09 00:33:20 -04:00
|
|
|
rugged_calls = Gitlab::RuggedInstrumentation.query_count
|
|
|
|
|
2020-05-27 05:08:30 -04:00
|
|
|
return if rugged_calls == 0
|
|
|
|
|
|
|
|
payload[:rugged_calls] = rugged_calls
|
|
|
|
payload[:rugged_duration_s] = Gitlab::RuggedInstrumentation.query_time
|
|
|
|
end
|
2020-03-24 14:07:55 -04:00
|
|
|
|
2020-05-27 05:08:30 -04:00
|
|
|
def instrument_redis(payload)
|
2020-06-16 08:09:00 -04:00
|
|
|
payload.merge! ::Gitlab::Instrumentation::Redis.payload
|
2020-05-27 05:08:30 -04:00
|
|
|
end
|
|
|
|
|
|
|
|
def instrument_elasticsearch(payload)
|
2020-05-27 02:08:13 -04:00
|
|
|
# Elasticsearch integration is only available in EE but instrumentation
|
|
|
|
# only depends on the Gem which is also available in FOSS.
|
|
|
|
elasticsearch_calls = Gitlab::Instrumentation::ElasticsearchTransport.get_request_count
|
|
|
|
|
2020-05-27 05:08:30 -04:00
|
|
|
return if elasticsearch_calls == 0
|
|
|
|
|
|
|
|
payload[:elasticsearch_calls] = elasticsearch_calls
|
|
|
|
payload[:elasticsearch_duration_s] = Gitlab::Instrumentation::ElasticsearchTransport.query_time
|
2021-02-16 16:09:23 -05:00
|
|
|
payload[:elasticsearch_timed_out_count] = Gitlab::Instrumentation::ElasticsearchTransport.get_timed_out_count
|
2019-08-09 00:33:20 -04:00
|
|
|
end
|
2019-10-28 11:05:58 -04:00
|
|
|
|
2021-01-22 10:09:08 -05:00
|
|
|
def instrument_external_http(payload)
|
|
|
|
external_http_count = Gitlab::Metrics::Subscribers::ExternalHttp.request_count
|
|
|
|
|
|
|
|
return if external_http_count == 0
|
|
|
|
|
|
|
|
payload.merge! Gitlab::Metrics::Subscribers::ExternalHttp.payload
|
|
|
|
end
|
|
|
|
|
2020-11-06 10:09:14 -05:00
|
|
|
def instrument_throttle(payload)
|
|
|
|
safelist = Gitlab::Instrumentation::Throttle.safelist
|
|
|
|
payload[:throttle_safelist] = safelist if safelist.present?
|
|
|
|
end
|
|
|
|
|
2020-12-03 10:09:46 -05:00
|
|
|
def instrument_active_record(payload)
|
|
|
|
db_counters = ::Gitlab::Metrics::Subscribers::ActiveRecord.db_counter_payload
|
|
|
|
|
|
|
|
payload.merge!(db_counters)
|
|
|
|
end
|
|
|
|
|
2021-02-01 07:09:03 -05:00
|
|
|
def instrument_rack_attack(payload)
|
|
|
|
rack_attack_redis_count = ::Gitlab::Metrics::Subscribers::RackAttack.payload[:rack_attack_redis_count]
|
|
|
|
return if rack_attack_redis_count == 0
|
|
|
|
|
|
|
|
payload.merge!(::Gitlab::Metrics::Subscribers::RackAttack.payload)
|
|
|
|
end
|
|
|
|
|
2021-02-05 10:09:28 -05:00
|
|
|
def instrument_cpu(payload)
|
|
|
|
cpu_s = ::Gitlab::Metrics::System.thread_cpu_duration(
|
|
|
|
::Gitlab::RequestContext.instance.start_thread_cpu_time)
|
|
|
|
|
|
|
|
payload[:cpu_s] = cpu_s.round(DURATION_PRECISION) if cpu_s
|
|
|
|
end
|
|
|
|
|
2021-08-12 05:09:05 -04:00
|
|
|
def instrument_pid(payload)
|
|
|
|
payload[:pid] = Process.pid
|
|
|
|
end
|
|
|
|
|
2021-02-05 10:09:28 -05:00
|
|
|
def instrument_thread_memory_allocations(payload)
|
|
|
|
counters = ::Gitlab::Memory::Instrumentation.measure_thread_memory_allocations(
|
|
|
|
::Gitlab::RequestContext.instance.thread_memory_allocations)
|
|
|
|
payload.merge!(counters) if counters
|
|
|
|
end
|
|
|
|
|
2021-06-30 17:07:26 -04:00
|
|
|
def instrument_load_balancing(payload)
|
|
|
|
load_balancing_payload = ::Gitlab::Metrics::Subscribers::LoadBalancing.load_balancing_payload
|
|
|
|
|
|
|
|
payload.merge!(load_balancing_payload)
|
|
|
|
end
|
|
|
|
|
2019-10-28 11:05:58 -04:00
|
|
|
# Returns the queuing duration for a Sidekiq job in seconds, as a float, if the
|
|
|
|
# `enqueued_at` field or `created_at` field is available.
|
|
|
|
#
|
|
|
|
# * If the job doesn't contain sufficient information, returns nil
|
|
|
|
# * If the job has a start time in the future, returns 0
|
|
|
|
# * If the job contains an invalid start time value, returns nil
|
|
|
|
# @param [Hash] job a Sidekiq job, represented as a hash
|
|
|
|
def self.queue_duration_for_job(job)
|
|
|
|
# Old gitlab-shell messages don't provide enqueued_at/created_at attributes
|
|
|
|
enqueued_at = job['enqueued_at'] || job['created_at']
|
|
|
|
return unless enqueued_at
|
|
|
|
|
|
|
|
enqueued_at_time = convert_to_time(enqueued_at)
|
|
|
|
return unless enqueued_at_time
|
|
|
|
|
2021-10-05 20:11:56 -04:00
|
|
|
round_elapsed_time(enqueued_at_time)
|
|
|
|
end
|
|
|
|
|
|
|
|
# Returns the time it took for a scheduled job to be enqueued in seconds, as a float,
|
|
|
|
# if the `scheduled_at` and `enqueued_at` fields are available.
|
|
|
|
#
|
|
|
|
# * If the job doesn't contain sufficient information, returns nil
|
|
|
|
# * If the job has a start time in the future, returns 0
|
|
|
|
# * If the job contains an invalid start time value, returns nil
|
|
|
|
# @param [Hash] job a Sidekiq job, represented as a hash
|
|
|
|
def self.enqueue_latency_for_scheduled_job(job)
|
|
|
|
scheduled_at = job['scheduled_at']
|
|
|
|
enqueued_at = job['enqueued_at']
|
|
|
|
|
|
|
|
return unless scheduled_at && enqueued_at
|
|
|
|
|
|
|
|
scheduled_at_time = convert_to_time(scheduled_at)
|
|
|
|
enqueued_at_time = convert_to_time(enqueued_at)
|
|
|
|
|
|
|
|
return unless scheduled_at_time && enqueued_at_time
|
|
|
|
|
|
|
|
round_elapsed_time(scheduled_at_time, enqueued_at_time)
|
|
|
|
end
|
|
|
|
|
|
|
|
def self.round_elapsed_time(start, end_time = Time.now)
|
|
|
|
# It's possible that if there is clock-skew between two nodes this
|
|
|
|
# value may be less than zero. In that event, we record the value
|
2019-10-28 11:05:58 -04:00
|
|
|
# as zero.
|
2021-10-05 20:11:56 -04:00
|
|
|
[elapsed_by_absolute_time(start, end_time), 0].max.round(DURATION_PRECISION)
|
2019-10-28 11:05:58 -04:00
|
|
|
end
|
|
|
|
|
|
|
|
# Calculates the time in seconds, as a float, from
|
|
|
|
# the provided start time until now
|
|
|
|
#
|
|
|
|
# @param [Time] start
|
2021-10-05 20:11:56 -04:00
|
|
|
def self.elapsed_by_absolute_time(start, end_time)
|
|
|
|
(end_time - start).to_f.round(DURATION_PRECISION)
|
2019-10-28 11:05:58 -04:00
|
|
|
end
|
|
|
|
private_class_method :elapsed_by_absolute_time
|
|
|
|
|
|
|
|
# Convert a representation of a time into a `Time` value
|
|
|
|
#
|
|
|
|
# @param time_value String, Float time representation, or nil
|
|
|
|
def self.convert_to_time(time_value)
|
|
|
|
return time_value if time_value.is_a?(Time)
|
|
|
|
return Time.iso8601(time_value) if time_value.is_a?(String)
|
|
|
|
return Time.at(time_value) if time_value.is_a?(Numeric) && time_value > 0
|
|
|
|
rescue ArgumentError
|
|
|
|
# Swallow invalid dates. Better to loose some observability
|
|
|
|
# than bring all background processing down because of a date
|
|
|
|
# formatting bug in a client
|
|
|
|
end
|
|
|
|
private_class_method :convert_to_time
|
2019-08-09 00:33:20 -04:00
|
|
|
end
|
|
|
|
end
|