Find out which part of your code is triggering ActiveRecord or SQL queries.

Today, I got a new pet project to play with and my job was to identify the bottlenecks and performance improvements we can make in the application.

So I wanted to jump in and wanted to see what SQL queries were being triggered when someone requests data. Going through the entire code was not a feasible option for me.

So I was more like looking for a silver bullet, which would give me a list of queries that were triggered and the code snippets or areas which triggered them, so that I can see if it can be optimised any further.

What I had mind was to log all SQL queries and the caller or method which triggered them.

Looking a bit deep into the rails documentation, and some google and stack overflow links, I finally came with this helper script.

You can add this inside config/intializers directory and see the magic.

module LogQuerySource
  def debug(*args, &block)
    return unless super

    backtrace = Rails.backtrace_cleaner.clean caller

    relevant_caller_line = backtrace.detect do |caller_line|
      !caller_line.include?('/initializers/')
    end

    if relevant_caller_line
      logger.debug("  ↳ #{relevant_caller_line.sub("#{Rails.root}/", '')}")
    end
  end
end
ActiveRecord::LogSubscriber.send :prepend, LogQuerySource

So how does it shows its magic:

Here is an extract from my logs. As you can see the SQL query is bieng triggered by the block in processed_repayments_changes in app/services/lead_services/timeline.rb.

 CACHE (0.1ms)  SELECT  "admin_users".* FROM "admin_users" WHERE "admin_users"."id" = $1 LIMIT 1  [["id", "2"]]
  ↳ app/services/lead_services/timeline.rb:175:in `block in processed_repayments_changes'

Super useful yea ??

Spread the word and let it help someone else too :)