From 8a722e09122a2beeb122a8931a08b72c46d6bc50 Mon Sep 17 00:00:00 2001 From: Frederick Cheung Date: Sun, 22 May 2011 19:49:31 +0100 Subject: Take into account time spent in AR even if a redirect occurs or if it is after the render --- .../test/activerecord/controller_runtime_test.rb | 26 ++++++++++++++++++++++ .../active_record/railties/controller_runtime.rb | 4 +++- 2 files changed, 29 insertions(+), 1 deletion(-) diff --git a/actionpack/test/activerecord/controller_runtime_test.rb b/actionpack/test/activerecord/controller_runtime_test.rb index b87b9f9c47..2d789395ce 100644 --- a/actionpack/test/activerecord/controller_runtime_test.rb +++ b/actionpack/test/activerecord/controller_runtime_test.rb @@ -15,6 +15,17 @@ class ControllerRuntimeLogSubscriberTest < ActionController::TestCase def zero render :inline => "Zero DB runtime" end + + def redirect + Project.all + redirect_to :action => 'show' + end + + def db_after_render + render :inline => "Hello world" + Project.all + ActiveRecord::LogSubscriber.runtime += 100 + end end include ActiveSupport::LogSubscriber::TestHelper @@ -52,4 +63,19 @@ class ControllerRuntimeLogSubscriberTest < ActionController::TestCase assert_equal 2, @logger.logged(:info).size assert_match(/\(Views: [\d.]+ms \| ActiveRecord: 0.0ms\)/, @logger.logged(:info)[1]) end + + def test_log_with_active_record_when_redirecting + get :redirect + wait + assert_equal 3, @logger.logged(:info).size + assert_match(/\(ActiveRecord: [\d.]+ms\)/, @logger.logged(:info)[2]) + end + + def test_include_time_query_time_after_rendering + get :db_after_render + wait + + assert_equal 2, @logger.logged(:info).size + assert_match(/\(Views: [\d.]+ms \| ActiveRecord: ([1-9][\d.]+)ms\)/, @logger.logged(:info)[1]) + end end diff --git a/activerecord/lib/active_record/railties/controller_runtime.rb b/activerecord/lib/active_record/railties/controller_runtime.rb index fb3fd34665..c5db9b4625 100644 --- a/activerecord/lib/active_record/railties/controller_runtime.rb +++ b/activerecord/lib/active_record/railties/controller_runtime.rb @@ -32,7 +32,9 @@ module ActiveRecord def append_info_to_payload(payload) super - payload[:db_runtime] = db_runtime + if ActiveRecord::Base.connected? + payload[:db_runtime] = (db_runtime || 0) + ActiveRecord::LogSubscriber.reset_runtime + end end module ClassMethods -- cgit v1.2.3