From 6d961242848ffe0eac69f190fd02f44aaeef3e0a Mon Sep 17 00:00:00 2001 From: Tom Ward Date: Sat, 14 May 2011 10:31:00 +0100 Subject: Reset ActiveRecord::LogSubscriber runtime at the start of each request Previously the runtime was reset implicitly when #cleanup_view_runtime was called at the end of most requests. However, this doesn't happen when the request redirects, or send_file is called. Consequently, the ActiveRecord runtime recorded in the logs included the time taken for both the current request and the previous redirect. Explicitly resetting at the start of each request ensures that this can't happen, no matter what occurs previously. --- actionpack/test/activerecord/controller_runtime_test.rb | 13 +++++++++++++ 1 file changed, 13 insertions(+) (limited to 'actionpack') diff --git a/actionpack/test/activerecord/controller_runtime_test.rb b/actionpack/test/activerecord/controller_runtime_test.rb index c030315d2b..b87b9f9c47 100644 --- a/actionpack/test/activerecord/controller_runtime_test.rb +++ b/actionpack/test/activerecord/controller_runtime_test.rb @@ -11,6 +11,10 @@ class ControllerRuntimeLogSubscriberTest < ActionController::TestCase def show render :inline => "<%= Project.all %>" end + + def zero + render :inline => "Zero DB runtime" + end end include ActiveSupport::LogSubscriber::TestHelper @@ -39,4 +43,13 @@ class ControllerRuntimeLogSubscriberTest < ActionController::TestCase assert_equal 2, @logger.logged(:info).size assert_match(/\(Views: [\d.]+ms \| ActiveRecord: [\d.]+ms\)/, @logger.logged(:info)[1]) end + + def test_runtime_reset_before_requests + ActiveRecord::LogSubscriber.runtime += 12345 + get :zero + wait + + assert_equal 2, @logger.logged(:info).size + assert_match(/\(Views: [\d.]+ms \| ActiveRecord: 0.0ms\)/, @logger.logged(:info)[1]) + end end -- cgit v1.2.3