2020-02-25 13:09:02 -05:00
|
|
|
# frozen_string_literal: true
|
|
|
|
|
|
|
|
require 'prometheus/pid_provider'
|
|
|
|
|
|
|
|
module Gitlab
|
|
|
|
module Utils
|
|
|
|
class Measuring
|
2020-04-23 14:09:46 -04:00
|
|
|
class << self
|
2020-05-13 08:07:54 -04:00
|
|
|
attr_writer :logger
|
2020-04-23 14:09:46 -04:00
|
|
|
|
2020-05-13 08:07:54 -04:00
|
|
|
def logger
|
|
|
|
@logger ||= Logger.new(STDOUT)
|
2020-04-23 14:09:46 -04:00
|
|
|
end
|
|
|
|
end
|
|
|
|
|
2020-05-13 08:07:54 -04:00
|
|
|
def initialize(base_log_data = {})
|
2020-04-23 14:09:46 -04:00
|
|
|
@base_log_data = base_log_data
|
2020-02-25 13:09:02 -05:00
|
|
|
end
|
|
|
|
|
|
|
|
def with_measuring
|
2020-04-24 08:10:16 -04:00
|
|
|
result = nil
|
|
|
|
with_gc_stats do
|
2020-02-25 13:09:02 -05:00
|
|
|
with_count_queries do
|
|
|
|
with_measure_time do
|
2020-04-24 08:10:16 -04:00
|
|
|
result = yield
|
2020-02-25 13:09:02 -05:00
|
|
|
end
|
|
|
|
end
|
|
|
|
end
|
|
|
|
|
2020-04-23 14:09:46 -04:00
|
|
|
log_info(
|
|
|
|
gc_stats: gc_stats,
|
|
|
|
time_to_finish: time_to_finish,
|
|
|
|
number_of_sql_calls: sql_calls_count,
|
2020-05-13 05:08:37 -04:00
|
|
|
memory_usage: "#{Gitlab::Metrics::System.memory_usage_rss.to_f / 1024 / 1024} MiB",
|
2020-04-23 14:09:46 -04:00
|
|
|
label: ::Prometheus::PidProvider.worker_id
|
|
|
|
)
|
|
|
|
|
|
|
|
result
|
2020-02-25 13:09:02 -05:00
|
|
|
end
|
|
|
|
|
|
|
|
private
|
|
|
|
|
2020-05-13 08:07:54 -04:00
|
|
|
attr_reader :gc_stats, :time_to_finish, :sql_calls_count, :base_log_data
|
2020-02-25 13:09:02 -05:00
|
|
|
|
|
|
|
def with_count_queries(&block)
|
2020-04-23 14:09:46 -04:00
|
|
|
@sql_calls_count = 0
|
2020-02-25 13:09:02 -05:00
|
|
|
|
|
|
|
counter_f = ->(_name, _started, _finished, _unique_id, payload) {
|
2020-04-23 14:09:46 -04:00
|
|
|
@sql_calls_count += 1 unless payload[:name].in? %w[CACHE SCHEMA]
|
2020-02-25 13:09:02 -05:00
|
|
|
}
|
|
|
|
|
|
|
|
ActiveSupport::Notifications.subscribed(counter_f, "sql.active_record", &block)
|
2020-04-23 14:09:46 -04:00
|
|
|
end
|
2020-02-25 13:09:02 -05:00
|
|
|
|
2020-04-01 14:07:56 -04:00
|
|
|
def with_gc_stats
|
|
|
|
GC.start # perform a full mark-and-sweep
|
|
|
|
stats_before = GC.stat
|
2020-04-24 08:10:16 -04:00
|
|
|
yield
|
2020-04-01 14:07:56 -04:00
|
|
|
stats_after = GC.stat
|
2020-04-23 14:09:46 -04:00
|
|
|
@gc_stats = stats_after.map do |key, after_value|
|
2020-04-01 14:07:56 -04:00
|
|
|
before_value = stats_before[key]
|
|
|
|
[key, before: before_value, after: after_value, diff: after_value - before_value]
|
|
|
|
end.to_h
|
2020-02-25 13:09:02 -05:00
|
|
|
end
|
|
|
|
|
|
|
|
def with_measure_time
|
2020-04-23 14:09:46 -04:00
|
|
|
@time_to_finish = Benchmark.realtime do
|
2020-04-24 08:10:16 -04:00
|
|
|
yield
|
2020-02-25 13:09:02 -05:00
|
|
|
end
|
2020-04-24 08:10:16 -04:00
|
|
|
end
|
2020-02-25 13:09:02 -05:00
|
|
|
|
2020-04-24 08:10:16 -04:00
|
|
|
def log_info(details)
|
|
|
|
details = base_log_data.merge(details)
|
2020-05-13 08:07:54 -04:00
|
|
|
details = details.to_yaml if ActiveSupport::Logger.logger_outputs_to?(Measuring.logger, STDOUT)
|
|
|
|
Measuring.logger.info(details)
|
2020-02-25 13:09:02 -05:00
|
|
|
end
|
|
|
|
end
|
|
|
|
end
|
|
|
|
end
|