QueryTrace

QueryTrace is a Rails plugin for pinpointing where in your Rails application that slow query is running. While ActiveRecord takes you half-way there by logging all queries and how long they’re taking, it won’t answer the question of where they’re being executed. Enter QueryTrace – once you have it installed, your logs won’t just tell you that you have a problem, they will pinpoint the exact location of that problem for you.

Installation

script/plugin install git://github.com/ntalbott/query_trace.git

Usage

All you have to do is have the plugin installed – QueryTrace takes care of the rest, including:

• Only displaying when at the DEBUG log level
• Honoring 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'

http://terralien.com/projects/querytrace/