2021-02-22 17:27:13 +05:30
|
|
|
# frozen_string_literal: true
|
|
|
|
|
|
|
|
module Gitlab
|
|
|
|
module PerformanceBar
|
|
|
|
# This class fetches Peek stats stored in redis and logs them in a
|
|
|
|
# structured log (so these can be then analyzed in Kibana)
|
|
|
|
class Stats
|
2021-04-29 21:17:54 +05:30
|
|
|
IGNORED_BACKTRACE_LOCATIONS = %w[
|
|
|
|
ee/lib/ee/peek
|
|
|
|
lib/peek
|
|
|
|
lib/gitlab/database
|
2021-11-18 22:05:49 +05:30
|
|
|
lib/gitlab/gitaly_client.rb
|
|
|
|
lib/gitlab/gitaly_client/call.rb
|
|
|
|
lib/gitlab/instrumentation/redis_interceptor.rb
|
2021-04-29 21:17:54 +05:30
|
|
|
].freeze
|
|
|
|
|
2021-02-22 17:27:13 +05:30
|
|
|
def initialize(redis)
|
|
|
|
@redis = redis
|
|
|
|
end
|
|
|
|
|
|
|
|
def process(id)
|
|
|
|
data = request(id)
|
|
|
|
return unless data
|
|
|
|
|
2021-11-18 22:05:49 +05:30
|
|
|
log_queries(id, data, 'active-record')
|
|
|
|
log_queries(id, data, 'gitaly')
|
|
|
|
log_queries(id, data, 'redis')
|
2022-05-07 20:08:51 +05:30
|
|
|
rescue StandardError => e
|
|
|
|
logger.error(message: "failed to process request id #{id}: #{e.message}")
|
2021-02-22 17:27:13 +05:30
|
|
|
end
|
|
|
|
|
|
|
|
private
|
|
|
|
|
|
|
|
def request(id)
|
|
|
|
# Peek gem stores request data under peek:requests:request_id key
|
|
|
|
json_data = @redis.get("peek:requests:#{id}")
|
2022-05-07 20:08:51 +05:30
|
|
|
raise "No data for #{id}" if json_data.nil?
|
|
|
|
|
2021-02-22 17:27:13 +05:30
|
|
|
Gitlab::Json.parse(json_data)
|
|
|
|
end
|
|
|
|
|
2021-11-18 22:05:49 +05:30
|
|
|
def log_queries(id, data, type)
|
|
|
|
queries_by_location(data, type).each do |location, queries|
|
2021-03-11 19:13:27 +05:30
|
|
|
next unless location
|
2021-02-22 17:27:13 +05:30
|
|
|
|
2021-03-11 19:13:27 +05:30
|
|
|
duration = queries.sum { |query| query['duration'].to_f }
|
|
|
|
log_info = {
|
|
|
|
method_path: "#{location[:filename]}:#{location[:method]}",
|
|
|
|
filename: location[:filename],
|
2021-11-18 22:05:49 +05:30
|
|
|
query_type: type,
|
2021-02-22 17:27:13 +05:30
|
|
|
request_id: id,
|
2021-03-11 19:13:27 +05:30
|
|
|
count: queries.count,
|
|
|
|
duration_ms: duration
|
|
|
|
}
|
2021-02-22 17:27:13 +05:30
|
|
|
|
|
|
|
logger.info(log_info)
|
|
|
|
end
|
|
|
|
end
|
|
|
|
|
2021-11-18 22:05:49 +05:30
|
|
|
def queries_by_location(data, type)
|
|
|
|
return [] unless queries = data.dig('data', type, 'details')
|
2021-03-11 19:13:27 +05:30
|
|
|
|
|
|
|
queries.group_by do |query|
|
|
|
|
parse_backtrace(query['backtrace'])
|
|
|
|
end
|
|
|
|
end
|
|
|
|
|
2021-02-22 17:27:13 +05:30
|
|
|
def parse_backtrace(backtrace)
|
2021-04-29 21:17:54 +05:30
|
|
|
return unless backtrace_row = find_caller(backtrace)
|
|
|
|
return unless match = /(?<filename>.*):(?<filenum>\d+):in `(?<method>.*)'/.match(backtrace_row)
|
2021-02-22 17:27:13 +05:30
|
|
|
|
|
|
|
{
|
|
|
|
filename: match[:filename],
|
2021-03-11 19:13:27 +05:30
|
|
|
# filenum may change quite frequently with every change in the file,
|
|
|
|
# because the intention is to aggregate these queries, we group
|
|
|
|
# them rather by method name which should not change so frequently
|
|
|
|
# filenum: match[:filenum].to_i,
|
2021-02-22 17:27:13 +05:30
|
|
|
method: match[:method]
|
|
|
|
}
|
|
|
|
end
|
|
|
|
|
2021-04-29 21:17:54 +05:30
|
|
|
def find_caller(backtrace)
|
|
|
|
backtrace.find do |line|
|
|
|
|
!line.start_with?(*IGNORED_BACKTRACE_LOCATIONS)
|
|
|
|
end
|
|
|
|
end
|
|
|
|
|
2021-02-22 17:27:13 +05:30
|
|
|
def logger
|
|
|
|
@logger ||= Gitlab::PerformanceBar::Logger.build
|
|
|
|
end
|
|
|
|
end
|
|
|
|
end
|
|
|
|
end
|