How to fix: Rails query logs always show lib/active_record/log_subscriber.rb as source

Posted Over 3 years ago. Visible to the public.

Rails 5.2+ supports "verbose query logs" where it shows the source of a query in the application log.
Normally, it looks like this:

  User Load (0.5ms)  SELECT "users".* FROM "users" WHERE ...
  ↳ app/controllers/users_controller.rb:42:in `load_users'

However, you may encounter ActiveRecord's LogSubscriber as the source for all/most queries which is not helpful at all:

  User Load (0.5ms)  SELECT "users".* FROM "users" WHERE ...
  ↳ activerecord (6.0.3.3) lib/active_record/log_subscriber.rb:100:in `debug'

While there was an issue back in 2018 Show archive.org snapshot which can be resolved by upgrading Rails, this also happens when ActiveSupport's BacktraceCleaner is configured to not hide gems from the backtrace. In such cases, log_subscriber.rb is the inner-most (i.e. "best") source in the backtrace.

You probably have an initializer with this line:

Rails.backtrace_cleaner.remove_silencers!

Remove it, and your verbose query logs will be helpful.

If you're using verbose query logs only in development, you may also choose to enable silencers in development only:

unless Rails.configuration.active_record.verbose_query_logs
  Rails.backtrace_cleaner.remove_silencers!
end
Arne Hartherz
Last edit
Over 3 years ago
Henning Koch
License
Source code in this card is licensed under the MIT License.
Posted by Arne Hartherz to makandra dev (2020-09-10 08:13)