2019-10-12 21:52:04 +05:30
|
|
|
# frozen_string_literal: true
|
|
|
|
|
2018-10-15 14:42:47 +05:30
|
|
|
module ActiveRecord
|
|
|
|
class QueryRecorder
|
2021-09-04 01:27:46 +05:30
|
|
|
attr_reader :log, :skip_cached, :skip_schema_queries, :cached, :data
|
2018-10-15 14:42:47 +05:30
|
|
|
|
2021-04-29 21:17:54 +05:30
|
|
|
UNKNOWN = %w[unknown unknown].freeze
|
|
|
|
|
2021-09-04 01:27:46 +05:30
|
|
|
def initialize(skip_cached: true, skip_schema_queries: true, log_file: nil, query_recorder_debug: false, &block)
|
2021-04-29 21:17:54 +05:30
|
|
|
@data = Hash.new { |h, k| h[k] = { count: 0, occurrences: [], backtrace: [], durations: [] } }
|
2018-10-15 14:42:47 +05:30
|
|
|
@log = []
|
|
|
|
@cached = []
|
2018-11-08 19:23:39 +05:30
|
|
|
@skip_cached = skip_cached
|
2021-09-04 01:27:46 +05:30
|
|
|
@skip_schema_queries = skip_schema_queries
|
2021-04-29 21:17:54 +05:30
|
|
|
@query_recorder_debug = ENV['QUERY_RECORDER_DEBUG'] || query_recorder_debug
|
|
|
|
@log_file = log_file
|
2021-06-08 01:23:25 +05:30
|
|
|
record(&block) if block_given?
|
|
|
|
end
|
|
|
|
|
|
|
|
def record(&block)
|
2019-12-04 20:38:33 +05:30
|
|
|
# force replacement of bind parameters to give tests the ability to check for ids
|
|
|
|
ActiveRecord::Base.connection.unprepared_statement do
|
|
|
|
ActiveSupport::Notifications.subscribed(method(:callback), 'sql.active_record', &block)
|
|
|
|
end
|
2018-10-15 14:42:47 +05:30
|
|
|
end
|
|
|
|
|
2021-04-29 21:17:54 +05:30
|
|
|
def show_backtrace(values, duration)
|
|
|
|
values[:sql].lines.each do |line|
|
|
|
|
print_to_log(:SQL, line)
|
|
|
|
end
|
|
|
|
print_to_log(:DURATION, duration)
|
2020-05-24 23:13:21 +05:30
|
|
|
Gitlab::BacktraceCleaner.clean_backtrace(caller).each do |line|
|
2021-04-29 21:17:54 +05:30
|
|
|
print_to_log(:backtrace, line)
|
|
|
|
end
|
|
|
|
end
|
|
|
|
|
|
|
|
def print_to_log(label, line)
|
|
|
|
msg = "QueryRecorder #{label}: --> #{line}"
|
|
|
|
|
|
|
|
if @log_file
|
|
|
|
@log_file.puts(msg)
|
|
|
|
else
|
|
|
|
Rails.logger.debug(msg)
|
2020-05-24 23:13:21 +05:30
|
|
|
end
|
2020-03-13 15:44:24 +05:30
|
|
|
end
|
|
|
|
|
|
|
|
def get_sql_source(sql)
|
2021-04-29 21:17:54 +05:30
|
|
|
matches = sql.match(%r{,line:(?<line>.*):in\s+`(?<method>.*)'\*/})
|
2020-03-13 15:44:24 +05:30
|
|
|
matches ? [matches[:line], matches[:method]] : UNKNOWN
|
|
|
|
end
|
|
|
|
|
2021-04-29 21:17:54 +05:30
|
|
|
def store_sql_by_source(values: {}, duration: nil, backtrace: nil)
|
2020-03-13 15:44:24 +05:30
|
|
|
full_name = get_sql_source(values[:sql]).join(':')
|
|
|
|
@data[full_name][:count] += 1
|
|
|
|
@data[full_name][:occurrences] << values[:sql]
|
|
|
|
@data[full_name][:backtrace] << backtrace
|
2021-04-29 21:17:54 +05:30
|
|
|
@data[full_name][:durations] << duration
|
2020-03-13 15:44:24 +05:30
|
|
|
end
|
|
|
|
|
|
|
|
def find_query(query_regexp, limit, first_only: false)
|
|
|
|
out = []
|
|
|
|
|
|
|
|
@data.each_pair do |k, v|
|
|
|
|
if v[:count] > limit && k.match(query_regexp)
|
|
|
|
out << [k, v[:count]]
|
|
|
|
break if first_only
|
|
|
|
end
|
|
|
|
end
|
|
|
|
|
|
|
|
out.flatten! if first_only
|
|
|
|
out
|
|
|
|
end
|
|
|
|
|
|
|
|
def occurrences_by_line_method
|
|
|
|
@occurrences_by_line_method ||= @data.sort_by { |_, v| v[:count] }
|
2018-10-15 14:42:47 +05:30
|
|
|
end
|
|
|
|
|
|
|
|
def callback(name, start, finish, message_id, values)
|
2021-04-29 21:17:54 +05:30
|
|
|
duration = finish - start
|
2018-10-15 14:42:47 +05:30
|
|
|
|
2019-07-31 22:56:46 +05:30
|
|
|
if values[:cached] && skip_cached
|
2018-10-15 14:42:47 +05:30
|
|
|
@cached << values[:sql]
|
2021-09-04 01:27:46 +05:30
|
|
|
elsif !skip_schema_queries || !values[:name]&.include?("SCHEMA")
|
2021-04-29 21:17:54 +05:30
|
|
|
backtrace = @query_recorder_debug ? show_backtrace(values, duration) : nil
|
2018-10-15 14:42:47 +05:30
|
|
|
@log << values[:sql]
|
2021-04-29 21:17:54 +05:30
|
|
|
store_sql_by_source(values: values, duration: duration, backtrace: backtrace)
|
2018-10-15 14:42:47 +05:30
|
|
|
end
|
|
|
|
end
|
|
|
|
|
|
|
|
def count
|
2020-03-13 15:44:24 +05:30
|
|
|
@count ||= @log.count
|
2018-10-15 14:42:47 +05:30
|
|
|
end
|
|
|
|
|
|
|
|
def cached_count
|
2020-03-13 15:44:24 +05:30
|
|
|
@cached_count ||= @cached.count
|
2018-10-15 14:42:47 +05:30
|
|
|
end
|
|
|
|
|
|
|
|
def log_message
|
2020-03-13 15:44:24 +05:30
|
|
|
@log_message ||= @log.join("\n\n")
|
2018-10-15 14:42:47 +05:30
|
|
|
end
|
2019-09-30 21:07:59 +05:30
|
|
|
|
|
|
|
def occurrences
|
2020-03-13 15:44:24 +05:30
|
|
|
@occurrences ||= @log.group_by(&:to_s).transform_values(&:count)
|
2019-09-30 21:07:59 +05:30
|
|
|
end
|
2018-10-15 14:42:47 +05:30
|
|
|
end
|
|
|
|
end
|