Rails 2.x: Log all SQL queries excluding SELECT

Posted by ZedTuX 0n R00t on January 12, 2014

Initial state

It could really help when you can see which SQL queries was executed during a session in order to analyze and understand what was happened.

You can do this easily by changing the log level of the production environment of Rails framework, but as you can imagine, this will have a side effect: A lot of disk access. This will reduce the performance of your application.

So let’s say we want to still log SQL queries like UPDATE, DELETE, SET,… but no more SELECT. How to do that?

ActiveRecord statement execution logger

That’s the key for sure! Each statements are executed as block of code to a log method in the AbstractAdapter class.

Here is the log_info method description that contains the logger:

1
2
3
4
5
6
def log_info(sql, name, seconds)
  if @logger && @logger.debug?
    name = "#{name.nil? ? "SQL" : name} (#{sprintf("%.1f", seconds * 1000)}ms)"
    @logger.debug(format_log_entry(name, sql.squeeze(' ')))
  end
end

Implementing the exclusion of SQL SELECT command

First thing is that we want to still log everything using the logger level Logger::DEBUG, and exclude SELECT when using Logger::INFO.

To implement this solution, for your application, you can use Monkey patching and Rails Initializers!

Here is how I have implemented it:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
# The purpose of this Rails initializer is to override the logging method from active record.
#
# We want in our log files to have all the SQL statements excluding SELECTs.
# With DEBUG log level, everything is logged in
# With INFO log level, all SQL queries are logged in, excluding SELECT statments.
 
module ActiveRecord
  module ConnectionAdapters
    class AbstractAdapter
      def log_info(sql, name, seconds)
        if @logger
          name = "#{name.nil? ? "SQL" : name} (#{sprintf("%.1f", seconds * 1000)}ms)"
          if @logger.debug?
            @logger.debug(format_log_entry(name, sql.squeeze(' ')))
          elsif @logger.info? && !sql.starts_with?("SELECT")
            @logger.info(format_log_entry(name, sql.squeeze(' ')))
          end
        end
      end
    end
  end
end

Last but not least, we now to set the log level to Logger::INFO in production environment.

To do that, open the config/environments/production.rb file and add the following line:

1
config.logger.level = Logger::INFO