From 8a722e09122a2beeb122a8931a08b72c46d6bc50 Mon Sep 17 00:00:00 2001
From: Frederick Cheung <frederick.cheung@gmail.com>
Date: Sun, 22 May 2011 19:49:31 +0100
Subject: [PATCH] Take into account time spent in AR even if a redirect occurs
 or if it is after the render

---
 .../activerecord/controller_runtime_test.rb   | 26 +++++++++++++++++++
 .../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 b87b9f9c47d75..2d789395ce146 100644
--- a/actionpack/test/activerecord/controller_runtime_test.rb
+++ b/actionpack/test/activerecord/controller_runtime_test.rb
@@ -15,6 +15,17 @@ def show
     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 @@ def test_runtime_reset_before_requests
     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 fb3fd34665fec..c5db9b4625eda 100644
--- a/activerecord/lib/active_record/railties/controller_runtime.rb
+++ b/activerecord/lib/active_record/railties/controller_runtime.rb
@@ -32,7 +32,9 @@ def cleanup_view_runtime
 
       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