Skip to content

Commit

Permalink
use new ActiveRecord::RuntimeRegistry for rails 7.1
Browse files Browse the repository at this point in the history
This eliminates the need for monkey patching ActiveRecord::LogSubscriber.
  • Loading branch information
skaes committed Oct 11, 2023
1 parent 961319c commit b6b7ec5
Show file tree
Hide file tree
Showing 6 changed files with 216 additions and 165 deletions.
162 changes: 5 additions & 157 deletions lib/time_bandits/monkey_patches/active_record.rb
Original file line number Diff line number Diff line change
@@ -1,158 +1,6 @@
# this file monkey patches class ActiveRecord::LogSubscriber
# to count the number of sql statements being executed
# and the number of query cache hits
# it needs to be adapted to each new rails version

require "active_record/log_subscriber"

module ActiveRecord
class LogSubscriber
IGNORE_PAYLOAD_NAMES = ["SCHEMA", "EXPLAIN"] unless defined?(IGNORE_PAYLOAD_NAMES)

if Gem::Version.new(ActiveRecord::VERSION::STRING) >= Gem::Version.new("7.1.0")
def self.reset_runtime
ActiveRecord::RuntimeRegistry.reset
end
def self.runtime
ActiveRecord::RuntimeRegistry.sql_runtime
end
def self.runtime=(value)
ActiveRecord::RuntimeRegistry.sql_runtime = value
end
end

def self.call_count=(value)
Thread.current.thread_variable_set(:active_record_sql_call_count, value)
end

def self.call_count
Thread.current.thread_variable_get(:active_record_sql_call_count) ||
Thread.current.thread_variable_set(:active_record_sql_call_count, 0)
end

def self.query_cache_hits=(value)
Thread.current.thread_variable_set(:active_record_sql_query_cache_hits, value)
end

def self.query_cache_hits
Thread.current.thread_variable_get(:active_record_sql_query_cache_hits) ||
Thread.current.thread_variable_set(:active_record_sql_query_cache_hits, 0)
end

def self.reset_call_count
calls = call_count
self.call_count = 0
calls
end

def self.reset_query_cache_hits
hits = query_cache_hits
self.query_cache_hits = 0
hits
end

remove_method :sql
def sql(event)
payload = event.payload

self.class.runtime += event.duration
self.class.call_count += 1
self.class.query_cache_hits += 1 if payload[:cached] || payload[:name] == "CACHE"

return unless logger.debug?

return if IGNORE_PAYLOAD_NAMES.include?(payload[:name])

log_sql_statement(payload, event)
end

private
def log_sql_statement(payload, event)
name = if payload[:async]
"ASYNC #{payload[:name]} (#{payload[:lock_wait].round(1)}ms) (db time #{event.duration.round(1)}ms)"
else
"#{payload[:name]} (#{event.duration.round(1)}ms)"
end
name = "CACHE #{name}" if payload[:cached]
sql = payload[:sql]
binds = render_binds(payload)

name = colorize_payload_name(name, payload[:name])
sql = colorize_sql(sql) if colorize_logging

debug " #{name} #{sql}#{binds}"
end

if Gem::Version.new(ActiveRecord::VERSION::STRING) >= Gem::Version.new("7.1.0")
def render_binds(payload)
binds = nil
if payload[:binds]&.any?
casted_params = type_casted_binds(payload[:type_casted_binds])

binds = []
payload[:binds].each_with_index do |attr, i|
attribute_name = if attr.respond_to?(:name)
attr.name
elsif attr.respond_to?(:[]) && attr[i].respond_to?(:name)
attr[i].name
else
nil
end

filtered_params = filter(attribute_name, casted_params[i])

binds << render_bind(attr, filtered_params)
end
binds = binds.inspect
binds.prepend(" ")
end
return binds
end
def colorize_sql(sql)
color(sql, sql_color(sql), bold: true)
end
else
def render_binds(payload)
binds = nil
unless (payload[:binds] || []).empty?
casted_params = type_casted_binds(payload[:type_casted_binds])
binds = " " + payload[:binds].zip(casted_params).map { |attr, value|
render_bind(attr, value)
}.inspect
end
return binds
end
def colorize_sql(sql)
color(sql, sql_color(sql), true)
end
end
end

require "active_record/railties/controller_runtime"

module Railties
module ControllerRuntime
remove_method :cleanup_view_runtime
def cleanup_view_runtime
# this method has been redefined to do nothing for activerecord on purpose
super
end

remove_method :append_info_to_payload
def append_info_to_payload(payload)
super
if ActiveRecord::Base.connected?
payload[:db_runtime] = TimeBandits::TimeConsumers::Database.instance.consumed
end
end

module ClassMethods
# this method has been redefined to do nothing for activerecord on purpose
remove_method :log_process_action
def log_process_action(payload)
super
end
end
end
end
if Gem::Version.new(ActiveRecord::VERSION::STRING) < Gem::Version.new("7.1.0")
require_relative "active_record/log_subscriber"
else
require_relative "active_record/runtime_registry"
end
require_relative "active_record/railties/controller_runtime"
77 changes: 77 additions & 0 deletions lib/time_bandits/monkey_patches/active_record/log_subscriber.rb
Original file line number Diff line number Diff line change
@@ -0,0 +1,77 @@
# This file monkey patches class ActiveRecord::LogSubscriber to count
# the number of sql statements being executed and the number of query
# cache hits, but is only used for Rails versions before 7.1.0.

require "active_record/log_subscriber"

module ActiveRecord
class LogSubscriber
IGNORE_PAYLOAD_NAMES = ["SCHEMA", "EXPLAIN"] unless defined?(IGNORE_PAYLOAD_NAMES)

def self.call_count=(value)
Thread.current.thread_variable_set(:active_record_sql_call_count, value)
end

def self.call_count
Thread.current.thread_variable_get(:active_record_sql_call_count) ||
Thread.current.thread_variable_set(:active_record_sql_call_count, 0)
end

def self.query_cache_hits=(value)
Thread.current.thread_variable_set(:active_record_sql_query_cache_hits, value)
end

def self.query_cache_hits
Thread.current.thread_variable_get(:active_record_sql_query_cache_hits) ||
Thread.current.thread_variable_set(:active_record_sql_query_cache_hits, 0)
end

def self.reset_call_count
calls = call_count
self.call_count = 0
calls
end

def self.reset_query_cache_hits
hits = query_cache_hits
self.query_cache_hits = 0
hits
end

remove_method :sql
def sql(event)
payload = event.payload

self.class.runtime += event.duration
self.class.call_count += 1
self.class.query_cache_hits += 1 if payload[:cached] || payload[:name] == "CACHE"

return unless logger.debug?

return if IGNORE_PAYLOAD_NAMES.include?(payload[:name])

log_sql_statement(payload, event)
end

private
def log_sql_statement(payload, event)
name = "#{payload[:name]} (#{event.duration.round(1)}ms)"
name = "CACHE #{name}" if payload[:cached]
sql = payload[:sql]
binds = nil

unless (payload[:binds] || []).empty?
casted_params = type_casted_binds(payload[:type_casted_binds])
binds = " " + payload[:binds].zip(casted_params).map { |attr, value|
render_bind(attr, value)
}.inspect
end

name = colorize_payload_name(name, payload[:name])
sql = color(sql, sql_color(sql), true)

debug " #{name} #{sql}#{binds}"
end
end

end
Original file line number Diff line number Diff line change
@@ -0,0 +1,29 @@
require "active_record/railties/controller_runtime"

module ActiveRecord
module Railties
module ControllerRuntime
remove_method :cleanup_view_runtime
def cleanup_view_runtime
# this method has been redefined to do nothing for activerecord on purpose
super
end

remove_method :append_info_to_payload
def append_info_to_payload(payload)
super
if ActiveRecord::Base.connected?
payload[:db_runtime] = TimeBandits::TimeConsumers::Database.instance.consumed
end
end

module ClassMethods
# this method has been redefined to do nothing for activerecord on purpose
remove_method :log_process_action
def log_process_action(payload)
super
end
end
end
end
end
50 changes: 50 additions & 0 deletions lib/time_bandits/monkey_patches/active_record/runtime_registry.rb
Original file line number Diff line number Diff line change
@@ -0,0 +1,50 @@
# This file monkey patches class ActiveRecord::RuntimeRegistry to
# additionally store call counts and cache hits and subscribes an
# event listener to manage those counters.

require "active_record/runtime_registry"

module ActiveRecord
module RuntimeRegistry

def self.call_count
ActiveSupport::IsolatedExecutionState[:active_record_sql_call_count] ||= 0
end

def self.call_count=(value)
ActiveSupport::IsolatedExecutionState[:active_record_sql_call_count] = value
end

def self.query_cache_hits
ActiveSupport::IsolatedExecutionState[:active_record_sql_query_cache_hits] ||= 0
end

def self.query_cache_hits=(value)
ActiveSupport::IsolatedExecutionState[:active_record_sql_query_cache_hits] = value
end

alias_method :reset_runtime, :reset
alias_method :runtime, :sql_runtime
alias_method :runtime=, :sql_runtime=

def self.reset_call_count
calls = call_count
self.call_count = 0
calls
end

def self.reset_query_cache_hits
hits = query_cache_hits
self.query_cache_hits = 0
hits
end

end
end

require "active_support/notifications"

ActiveSupport::Notifications.subscribe("sql.active_record") do |event|
ActiveRecord::RuntimeRegistry.call_count += 1
ActiveRecord::RuntimeRegistry.query_cache_hits += 1 if event.payload[:cached]
end
16 changes: 14 additions & 2 deletions lib/time_bandits/time_consumers/database.rb
Original file line number Diff line number Diff line change
Expand Up @@ -13,6 +13,18 @@ class Database < TimeBandits::TimeConsumers::BaseConsumer
fields :time, :calls, :sql_query_cache_hits
format "ActiveRecord: %.3fms(%dq,%dh)", :time, :calls, :sql_query_cache_hits

class << self
if Gem::Version.new(ActiveRecord::VERSION::STRING) >= Gem::Version.new("7.1.0")
def metrics_store
ActiveRecord::RuntimeRegistry
end
else
def metrics_store
ActiveRecord::LogSubscriber
end
end
end

def reset
reset_stats
super
Expand All @@ -27,13 +39,13 @@ def consumed
end

def current_runtime
Database.instance.time + ActiveRecord::LogSubscriber.runtime
Database.instance.time + self.class.metrics_store.runtime
end

private

def reset_stats
s = ActiveRecord::LogSubscriber
s = self.class.metrics_store
hits = s.reset_query_cache_hits
calls = s.reset_call_count
time = s.reset_runtime
Expand Down
Loading

0 comments on commit b6b7ec5

Please sign in to comment.