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__4434876849107960087'
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.
