Include the role of Active Record queries in logs

Viewed 355

Rails now includes support for multiple database roles (by default, writing for the primary and reading for the replica):

ActiveRecord::Base.connected_to(role: :reading) do
  # all code in this block will be connected to the reading role
end

In development, Active Record queries are logged by default, for example:

> User.last
  User Load (0.1ms)  SELECT "users".* FROM "users" ORDER BY "users"."id" DESC LIMIT ?  [["LIMIT", 1]]

How can I include the role used for a query in the logging? For example:

> ActiveRecord::Base.connnected_to(role: :reading) { User.last }
  [role: reading] User Load (0.1ms)  SELECT "users".* FROM "users" ORDER BY "users"."id" DESC LIMIT ?  [["LIMIT", 1]]
2 Answers

since all query will be logged by the method log of class AbstractAdapter at the finally step, regardless which database adapter you're using: postgresql, mysql,.. So you could override that method and prepend the role

# lib/extent_dblog.rb
ActiveRecord::ConnectionAdapters::AbstractAdapter.class_eval do
  alias_method(:origin_log, :log)
  def log(sql, name = 'SQL', binds = [], 
          type_casted_binds = [], statement_name = nil, &block)
    # prepend the current role before the log
    name = "[role: #{ActiveRecord::Base.current_role}] #{name}"
    origin_log(sql, name, binds, type_casted_binds, statement_name, &block)
  end
end

# config/initializers/ext_log.rb
require File.join(Rails.root, "lib", "extent_dblog.rb")

demo

# config/application.rb
  ...
  config.active_record.reading_role = :dev
  config.active_record.reading_role = :test

# app/models/application_record.rb
 class ApplicationRecord < ActiveRecord::Base
   self.abstract_class = true
   connects_to database: { dev: :development, test: :test }
 end

ActiveRecord::Base.connected_to(role: :dev) do
  Target.all
end
# [role: dev]  (0.6ms)  SELECT "targets".* FROM "targets" 

Create a new file config/initializers/multidb_logger.rb with this code:

ActiveRecord::ConnectionAdapters::AbstractAdapter.class_eval do
  alias_method(:origin_log, :log)
  def log(sql, name = 'SQL', binds = [], type_casted_binds = [], statement_name = nil, &block)
    sql = "#{sql} /* #{@config[:replica] ? 'REPLICA' : 'MASTER'} DB */"
    origin_log(sql, name, binds, type_casted_binds, statement_name, &block)
  end
end

ActiveRecord::LogSubscriber.class_eval do
  alias_method(:origin_extract_query_source_location, :extract_query_source_location)
  def extract_query_source_location(locations)
    new_locations = locations.reject { |loc| loc.include? File.basename(__FILE__) }
    origin_extract_query_source_location(new_locations)
  end
end

Now in the SQL queries logged by ActiveRecord you are going to see "REPLICA DB" or "MASTER DB" at the end of each query.

This solution use a similar approach to @Lam Phan solution but it preserves all the standard logging behaviour:

  • It doesn't log SCHEMA queries
  • It correctly display the source file and line from which the query was triggered

Also note that I didn't use ActiveRecord::Base.current_role to get the role because it is not showing reliable information (i.e. it prints role writing but the query goes to replica DB).

The log can be further customized using the information available in the @config hash, such as host, port, database, etc.

Related