Log caller application stack trace together with each sql query

I have run into problem with hunting the roots of some sql queries in my project.

To troubleshoot it i wanted to log application caller stack together with each query fired.

I had googled no out of the box solution, so i decided to make reliable & reusable solution by myself.

By tracing the stack i found place where all queries passed Mysql2Adapter.execute method ( i mean case of mysql of course )

I have overridden this method in rails initializers dir, monkey patch with caller stack logging is listed below:

module ActiveRecord
  module ConnectionAdapters
    class Mysql2Adapter < AbstractAdapter
      def execute(sql, name = nil)
        @connection.query_options[:database_timezone] = ActiveRecord::Base.default_timezone
        if name == :skip_logging
          @connection.query(sql)
        else
          # caller logging 
          log_stack
          # EO
          log(sql, name) { @connection.query(sql) }
        end
      rescue ActiveRecord::StatementInvalid => exception
        if exception.message.split(":").first =~ /Packets out of order/
          raise ActiveRecord::StatementInvalid, "'Packets out of order'... bindings."
        else
          raise
        end
      end

      private

        def log_stack
          #If marazmuz will take over i would not like to spam logs in production
          return unless Rails.env == 'development'
          #Regex with rails directory path would be helpful in taking app stack trace only
          regexp = Regexp.new( Rails.root.to_s )
          res = ''
          caller.each_with_index{|x,i| 
          #We'll took only items containing Rails.root and we are not interested in current stack position, so skip i == 0
            res << "#{ '#'+i.to_s}:\t#{ x.sub(regexp,'') }\n" if x =~ regexp && i != 0 
          }
          Rails.logger.info( res ) unless res.blank?

        end

    end
  end
end

finally the following output is written to log

\#4:    /app/models/contact.rb:57:in `get_raw_cols'
\#5:    /app/models/contact.rb:65:in `stat_cols'
\#6:    /app/components/contacts_tab.rb:85:in `configuration'
\#19:   /app/views/welcome/index.html.erb:1:in    `_app_views_welcome_index_html_erb___736761216545810182_25680180__443487684开发者_如何学Go9107960087'
  SQL (0.1ms)  SELECT `contacts`.`activity` FROM `contacts`

Does anybody:

• know out of the box profiling solution with the same functionality?

• have ran ever into similar problem & how you solved it?

Any comments / improvements to the code above are also much appreciated. Thanks in advance.

---

For future Googlers: The active_record_query_trace gem can also do that.

---

I think I have found a perfect solution

https://github.com/lightyear/sql-logging

until now it works perfectly for me.

Enjoy