QueryTrace plugin for Rails

It’s nice that ActiveRecord logs the queries that are performed when your actions are executed, since it makes it easy to see when you have serious inefficiencies in your application. The next question, though, is always, “OK, so where are those being run from?” Before QueryTrace, that question could be a real pain to answer, since you’d have to go trawling through your code looking for the culprit. Once you have QueryTrace installed, though, your logs won’t just tell you that you have a problem, they will pinpoint the location of that problem for you.

Usage

Either install the QueryTrace as a plugin or as a gem. You can enable QueryTrace by setting the QUERY_TRACE environment variable like so:

QUERY_TRACE=true script/server

If you want QueryTrace to always be enabled, create a file in config/initializers, and add the following line:

QueryTrace.enable!

QueryTrace only outputs traces at the at the DEBUG log level, and honors your log colorization settings.

Example

Before:

Schedule Load (0.023687)   SELECT * FROM schedules WHERE (schedules.id = 3) LIMIT 1
Resource Load (0.001076)   SELECT * FROM resources WHERE (resources.id = 328) LIMIT 1
Schedule Load (0.011488)   SELECT * FROM schedules WHERE (schedules.id = 3) LIMIT 1
Resource Load (0.022471)   SELECT * FROM resources WHERE (resources.id = 328) LIMIT 1

After:

Schedule Load (0.023687)   SELECT * FROM schedules WHERE (schedules.id = 3) LIMIT 1
  app/models/available_work.rb:50:in `study_method'
  app/helpers/plan_helper.rb:4:in `work_description'
  app/views/plan/_resource_schedule.rhtml:27:in `_run_rhtml_plan__resource_schedule'
  app/views/plan/_resource_schedule.rhtml:24:in `_run_rhtml_plan__resource_schedule'
  app/views/plan/_schedule_listing.rhtml:5:in `_run_rhtml_plan__schedule_listing'
  app/views/plan/_schedule_listing.rhtml:3:in `_run_rhtml_plan__schedule_listing'
  app/views/plan/_schedule_listing.rhtml:1:in `_run_rhtml_plan__schedule_listing'
  app/views/plan/index.rhtml:6:in `_run_rhtml_plan_index'
  vendor/plugins/textmate_footnotes/lib/textmate_footnotes.rb:60:in `render'
Resource Load (0.001076)   SELECT * FROM resources WHERE (resources.id = 328) LIMIT 1
  app/models/available_work.rb:54:in `div_type'
  app/helpers/plan_helper.rb:6:in `work_description'
  app/views/plan/_resource_schedule.rhtml:27:in `_run_rhtml_plan__resource_schedule'
  app/views/plan/_resource_schedule.rhtml:24:in `_run_rhtml_plan__resource_schedule'
  app/views/plan/_schedule_listing.rhtml:5:in `_run_rhtml_plan__schedule_listing'
  app/views/plan/_schedule_listing.rhtml:3:in `_run_rhtml_plan__schedule_listing'
  app/views/plan/_schedule_listing.rhtml:1:in `_run_rhtml_plan__schedule_listing'
  app/views/plan/index.rhtml:6:in `_run_rhtml_plan_index'
  vendor/plugins/textmate_footnotes/lib/textmate_footnotes.rb:60:in `render'
Schedule Load (0.011488)   SELECT * FROM schedules WHERE (schedules.id = 3) LIMIT 1
  app/models/available_work.rb:50:in `study_method'
  app/helpers/plan_helper.rb:4:in `work_description'
  app/views/plan/_resource_schedule.rhtml:27:in `_run_rhtml_plan__resource_schedule'
  app/views/plan/_resource_schedule.rhtml:24:in `_run_rhtml_plan__resource_schedule'
  app/views/plan/_schedule_listing.rhtml:5:in `_run_rhtml_plan__schedule_listing'
  app/views/plan/_schedule_listing.rhtml:3:in `_run_rhtml_plan__schedule_listing'
  app/views/plan/_schedule_listing.rhtml:1:in `_run_rhtml_plan__schedule_listing'
  app/views/plan/index.rhtml:6:in `_run_rhtml_plan_index'
  vendor/plugins/textmate_footnotes/lib/textmate_footnotes.rb:60:in `render'
Resource Load (0.022471)   SELECT * FROM resources WHERE (resources.id = 328) LIMIT 1
  app/models/available_work.rb:54:in `div_type'
  app/helpers/plan_helper.rb:6:in `work_description'
  app/views/plan/_resource_schedule.rhtml:27:in `_run_rhtml_plan__resource_schedule'
  app/views/plan/_resource_schedule.rhtml:24:in `_run_rhtml_plan__resource_schedule'
  app/views/plan/_schedule_listing.rhtml:5:in `_run_rhtml_plan__schedule_listing'
  app/views/plan/_schedule_listing.rhtml:3:in `_run_rhtml_plan__schedule_listing'
  app/views/plan/_schedule_listing.rhtml:1:in `_run_rhtml_plan__schedule_listing'
  app/views/plan/index.rhtml:6:in `_run_rhtml_plan_index'
  vendor/plugins/textmate_footnotes/lib/textmate_footnotes.rb:60:in `render'

Additional Info

Author: Nathaniel Talbott (for Terralien) Contact: [email protected] License: MIT Home: github.com/ntalbott/query_trace/ Subversion mirror: terralien.devguard.com/svn/projects/plugins/query_trace