Merge pull request #1228 from fcheung/db_time_fix2

Take into account time spent in AR even if a redirect occurs or if it is after the render

1 files changed, 26 insertions, 0 deletions

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