Include the role of Active Record queries in logs

Question

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]]

score 7 · Accepted Answer · answered Feb 04 '22 at 21:48

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.

score 6 · Answer 2 · answered Jul 28 '21 at 08:10

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"

Thanks for your solution. It already helped me observe a problem with my code and fix it. However, it sadly messes with the logging of the method that performed the query. It's systematically logging `↳ config/initializers/extend_dblog.rb:19:in log` (that's where I did put that code in my case). Great for debugging, but not to be used permanently in the code unless this can be helped. — Adeynack, Aug 10 '21 at 07:52

Include the role of Active Record queries in logs

2 Answers2

Linked