CODEWITHSUNDEEP
ruby-on-railsloggingactiverecordmulti-database
Patrick Brinich-Langlois
Patrick Brinich-Langlois

Reputation: 1429

Include the role of Active Record queries in logs

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

Upvotes: 3

Views: 1322

Answers (3)

Linh Dam
Linh Dam

Reputation: 2219

One way to do this (copying from Octopus::LogSubscriber from Octopus gem):

# In `config/initializers/active_record_multidb_logger.rb`

if (ENV['RAILS_ENV'] != 'production')
  module CustomMultiDbLogger
    def self.included(base)
      base.send(:attr_accessor, :is_replica) # Add custom attribute to track if the connection is a replica

      base.send :alias_method, :origin_sql, :sql
      base.send :alias_method, :sql, :custom_sql

      base.send :alias_method, :origin_debug, :debug
      base.send :alias_method, :debug, :debug_with_is_replica
    end

    def custom_sql(event)
      self.is_replica = event.payload[:connection].replica?
      origin_sql(event)
    end

    def debug_with_is_replica(msg)
      conn = is_replica ? color("[Replica]", ActiveSupport::LogSubscriber::GREEN, true) : 'Primary'
      origin_debug(conn + msg)
    end
  end

  ActiveRecord::LogSubscriber.send(:include, CustomMultiDbLogger)
end

This doesn't really log the role, but I guess you could find something else relevant in event.payload[:connection]

--

You might still want to add the code from @Martín to show the correct file location log:

# Still in `config/initializers/active_record_multidb_logger.rb`

if (ENV['RAILS_ENV'] != 'production')
  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
end

Upvotes: 0

Martín De la Fuente
Martín De la Fuente

Reputation: 6756

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.

Upvotes: 8

Lam Phan
Lam Phan

Reputation: 3811

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"

Upvotes: 7

Related Questions