How to get the line of code that triggers a query?

Question

is there a way (a gem, a plugin or something else) in rails 3.2 to know which line of code triggers a database query? For example in my log I have:

User Load (0.4ms)  SELECT `users`.* FROM `users` WHERE `users`.`id` = 5 LIMIT 1

How can I know the line of code that triggers the query? Thx...

score 34 · Accepted Answer · answered Jun 06 '12 at 13:22

34

I've found this solution:

module QueryTrace
  def self.enable!
    ::ActiveRecord::LogSubscriber.send(:include, self)
  end

  def self.append_features(klass)
    super
    klass.class_eval do
      unless method_defined?(:log_info_without_trace)
        alias_method :log_info_without_trace, :sql
        alias_method :sql, :log_info_with_trace
      end
    end
  end

  def log_info_with_trace(event)
    log_info_without_trace(event)
    trace_log = Rails.backtrace_cleaner.clean(caller).first
    if trace_log && event.payload[:name] != 'SCHEMA'
      logger.debug("   \\_ \e[33mCalled from:\e[0m " + trace_log)
    end
  end
end

In some initializer add QueryTrace.enable!

answered Jun 06 '12 at 13:22

Pioz

6,051
4
48
67

is this rails version specific? cant find it working with ruby 1.9.3, rails3.2.4, using console. I could see query being fired but not code line number. – Amol Pujari Jun 06 '12 at 15:29
With rails 3.2.4 and ruby 1.9.3 work for me... You need to add QueryTrace.enable! in some initializer... – Pioz Jun 06 '12 at 18:19
1

Thank you, kind sir. This has been a tremendous help to me in tracking down some n+1 problems. – antinome Aug 07 '12 at 16:01
It appears that this is now broken. All I get is ```activesupport (3.2.9) lib/active_support/log_subscriber.rb:93:in `call'``` – Preston Marshall Nov 27 '12 at 13:46
Works for me on Rails 4.2.6 – Nathan Long Aug 02 '16 at 19:26

score 19 · Answer 2 · edited Sep 02 '20 at 14:49

19

Rails 5.2+

Add this to your config/environments/test.rb or whatever environment you want to have the lines in. I am testing on rails 5.

  ActiveRecord::Base.verbose_query_logs = true

You'll get the file and the line.

edited Sep 02 '20 at 14:49

Joshua Pinter

45,245
23
243
245

answered Oct 22 '19 at 16:01

shampoo

1,173
12
22

1

**NOTE: This was only added in Rails 5.2: https://github.com/rails/rails/commit/3876defd7c951335129fa92c573c7b8fce085aac** – Joshua Pinter Sep 02 '20 at 14:51
The `ActiveRecord::Base` method call has been deprecated. You should use `ActiveRecord.verbose_query_logs = true` instead, or set `config.active_record.verbose_query_logs` inside your `test.rb` config block. – Dave Powers Mar 09 '22 at 17:22

score 16 · Answer 3 · answered Dec 30 '17 at 17:19

16

Using the active-record-query-trace gem:

In Gemfile:

gem 'active_record_query_trace'

Then bundle, then in config/environments/development.rb:

ActiveRecordQueryTrace.enabled = true

answered Dec 30 '17 at 17:19

Dorian

22,759
8
120
116

Update from the future: this gem doesn't work very well anymore, but Rails has a build in way to do something similar: https://guides.rubyonrails.org/debugging_rails_applications.html#verbose-query-logs – Mike Szyndel Oct 24 '22 at 13:31

score 0 · Answer 4 · answered Jun 06 '12 at 11:32

You can monkey patch the BufferedLogger to do what you want. Put this file in your config/initializers path:

require 'active_support/buffered_logger'

class ActiveSupport::BufferedLogger

  def add(severity, message = nil, progname = nil, &block)
    add_debugging_details(severity)
    @log.add(severity, message, progname, &block)
  end

  private

  EXCLUDE_CALLERS = Gem.paths.path.clone << 'script/rails' << RbConfig::CONFIG['rubylibdir'] << __FILE__

  def add_debugging_details(severity)
    caller_in_app = caller.select do |line|
      EXCLUDE_CALLERS.detect { |gem_path| line.starts_with?(gem_path) }.nil?
    end

    return if caller_in_app.empty?

    @log.add(severity, "Your code in \e[1;33m#{caller_in_app.first}\e[0;0m triggered:")
  end

end if Rails.env.development?

Not work form me... it add always same line: `Your code in xxx/lib/query_trace.rb:20:in `log_info_with_trace' triggered:`. Check out my solution. — Pioz, Jun 06 '12 at 13:23
You combined it with the other `QueryTrace` answer. You can either add `xxx/lib/query_trace.rb` to the `EXCLUDE_CALLERS` constant or disable it. — Christoph Petschnig, Jun 06 '12 at 13:29

How to get the line of code that triggers a query?

4 Answers4

Rails 5.2+

Linked