2016-12-20 09:48:04 -05:00
|
|
|
module ActiveRecord
|
|
|
|
class QueryRecorder
|
2017-04-04 17:52:59 -04:00
|
|
|
attr_reader :log, :cached
|
2016-12-20 09:48:04 -05:00
|
|
|
|
|
|
|
def initialize(&block)
|
|
|
|
@log = []
|
2017-04-04 17:52:59 -04:00
|
|
|
@cached = []
|
2016-12-20 09:48:04 -05:00
|
|
|
ActiveSupport::Notifications.subscribed(method(:callback), 'sql.active_record', &block)
|
|
|
|
end
|
|
|
|
|
2017-11-20 12:18:15 -05:00
|
|
|
def show_backtrace(values)
|
|
|
|
Rails.logger.debug("QueryRecorder SQL: #{values[:sql]}")
|
|
|
|
caller.each { |line| Rails.logger.debug(" --> #{line}") }
|
|
|
|
end
|
|
|
|
|
2016-12-20 09:48:04 -05:00
|
|
|
def callback(name, start, finish, message_id, values)
|
2017-11-20 12:18:15 -05:00
|
|
|
show_backtrace(values) if ENV['QUERY_RECORDER_DEBUG']
|
|
|
|
|
2017-04-04 17:52:59 -04:00
|
|
|
if values[:name]&.include?("CACHE")
|
|
|
|
@cached << values[:sql]
|
|
|
|
elsif !values[:name]&.include?("SCHEMA")
|
|
|
|
@log << values[:sql]
|
|
|
|
end
|
2016-12-20 09:48:04 -05:00
|
|
|
end
|
|
|
|
|
|
|
|
def count
|
|
|
|
@log.count
|
|
|
|
end
|
|
|
|
|
2017-04-04 17:52:59 -04:00
|
|
|
def cached_count
|
|
|
|
@cached.count
|
|
|
|
end
|
|
|
|
|
2016-12-20 09:48:04 -05:00
|
|
|
def log_message
|
|
|
|
@log.join("\n\n")
|
|
|
|
end
|
|
|
|
end
|
|
|
|
end
|
|
|
|
|
|
|
|
RSpec::Matchers.define :exceed_query_limit do |expected|
|
|
|
|
supports_block_expectations
|
|
|
|
|
|
|
|
match do |block|
|
2017-12-04 10:58:44 -05:00
|
|
|
@subject_block = block
|
|
|
|
actual_count > expected_count + threshold
|
2016-12-20 09:48:04 -05:00
|
|
|
end
|
|
|
|
|
|
|
|
failure_message_when_negated do |actual|
|
2017-09-14 05:40:19 -04:00
|
|
|
threshold_message = threshold > 0 ? " (+#{@threshold})" : ''
|
|
|
|
counts = "#{expected_count}#{threshold_message}"
|
|
|
|
"Expected a maximum of #{counts} queries, got #{actual_count}:\n\n#{log_message}"
|
|
|
|
end
|
|
|
|
|
|
|
|
def with_threshold(threshold)
|
|
|
|
@threshold = threshold
|
|
|
|
self
|
|
|
|
end
|
|
|
|
|
2017-12-04 10:58:44 -05:00
|
|
|
def for_query(query)
|
|
|
|
@query = query
|
|
|
|
self
|
|
|
|
end
|
|
|
|
|
2017-09-14 05:40:19 -04:00
|
|
|
def threshold
|
|
|
|
@threshold.to_i
|
|
|
|
end
|
|
|
|
|
|
|
|
def expected_count
|
|
|
|
if expected.is_a?(ActiveRecord::QueryRecorder)
|
|
|
|
expected.count
|
|
|
|
else
|
|
|
|
expected
|
|
|
|
end
|
|
|
|
end
|
|
|
|
|
|
|
|
def actual_count
|
2017-12-04 10:58:44 -05:00
|
|
|
@actual_count ||= if @query
|
|
|
|
recorder.log.select { |recorded| recorded =~ @query }.size
|
|
|
|
else
|
|
|
|
recorder.count
|
|
|
|
end
|
2016-12-20 09:48:04 -05:00
|
|
|
end
|
|
|
|
|
2017-12-04 10:58:44 -05:00
|
|
|
def recorder
|
|
|
|
@recorder ||= ActiveRecord::QueryRecorder.new(&@subject_block)
|
2016-12-20 09:48:04 -05:00
|
|
|
end
|
2017-09-14 05:40:19 -04:00
|
|
|
|
2017-11-22 06:12:47 -05:00
|
|
|
def count_queries(queries)
|
|
|
|
queries.each_with_object(Hash.new(0)) { |query, counts| counts[query] += 1 }
|
|
|
|
end
|
|
|
|
|
2017-09-14 05:40:19 -04:00
|
|
|
def log_message
|
|
|
|
if expected.is_a?(ActiveRecord::QueryRecorder)
|
2017-11-22 06:12:47 -05:00
|
|
|
counts = count_queries(expected.log)
|
|
|
|
extra_queries = @recorder.log.reject { |query| counts[query] -= 1 unless counts[query].zero? }
|
|
|
|
extra_queries_display = count_queries(extra_queries).map { |query, count| "[#{count}] #{query}" }
|
|
|
|
|
|
|
|
(['Extra queries:'] + extra_queries_display).join("\n\n")
|
2017-09-14 05:40:19 -04:00
|
|
|
else
|
|
|
|
@recorder.log_message
|
|
|
|
end
|
|
|
|
end
|
2016-12-20 09:48:04 -05:00
|
|
|
end
|