Tools or patch for Ruby Sequel or ORM instrumenting SQL queries for slow query log analysis

Question

We have MySQL slow query logs from a suite of applications, mostly in Ruby, some using Rails ActiveRecord, others using Sequel.

We'd love to be able to easily track a particular (MySQL) slow query back to the code which generated it. Is there a feature that can be enabled in these tools, or a patch that can be applied to them, which adds instrumentation embedded into SQL comments, something like a __FILE__ and __FUNCTION__ identifier?

Answer 1

Interesting question, here is how I would handle it...

I would use config.active_record.auto_explain_threshold_in_seconds to automatically explain slow queries, as it sounds like you are doing.

Then, I would override the logging_query_plan method in ActiveRecord::Explain to add any relevant data to your log. Here is an example that adds the current stacktrace:

# /config/initializers/add_additional_instumentation_to_explain.rb
module ActiveRecord
  module Explain


    def logging_query_plan # :nodoc:
      return yield unless logger

      threshold = auto_explain_threshold_in_seconds
      current   = Thread.current
      if threshold && current[:available_queries_for_explain].nil?
        begin
          queries = current[:available_queries_for_explain] = []
          start = Time.now
          result = yield
          if Time.now - start > threshold
            # START ADDING ADDITIONAL INFORMATION
            begin
              puts 'ADDING ADDITIONAL INFORMATION...'
              raise 'foo'
            rescue
              puts 'DISPLAYING THE CURRENT STACKTRACE FOR THE FOLLOWING EXPLAIN'
              puts $@
            end

            logger.warn(exec_explain(queries))

          end
          result
        ensure
          current[:available_queries_for_explain] = nil
        end
      else
        yield
      end
    end


  end
end

I would prefer a method that doesn't rely on an entire modified method from rails, but this is the only way that I could get it to work reliably.

For what it's worth, this would be pretty easy to spin off into a gem, with a new one for each rails version, and just include the relevant gem for your version, per app, as it sounds like you may possibly support multiple versions of rails. This would serve to minimize some of the brittleness of said approach. Anyway, hope this helps - good luck!

Answer 2

I highly recommend rack-mini-profiler for helping to quickly understand how your Rails (or other rack based) app is spending it's time. It's especially good at showing which Ruby code generated which SQL statements. Visit all three links below to learn to use it well. Good luck.

http://miniprofiler.com/

http://railscasts.com/episodes/368-miniprofiler

http://samsaffron.com/archive/2012/07/12/miniprofiler-ruby-edition