Permalink
Browse files

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.
  • Loading branch information...
tomafro committed May 14, 2011
1 parent 518ffcd commit 6d961242848ffe0eac69f190fd02f44aaeef3e0a
@@ -11,6 +11,10 @@ class LogSubscriberController < ActionController::Base
def show
render :inline => "<%= Project.all %>"
end
def zero
render :inline => "Zero DB runtime"
end
end
include ActiveSupport::LogSubscriber::TestHelper
@@ -39,4 +43,13 @@ def test_log_with_active_record
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
@@ -9,6 +9,11 @@ module ControllerRuntime
attr_internal :db_runtime
def process_action(action, *args)
ActiveRecord::LogSubscriber.reset_runtime
super
end
def cleanup_view_runtime
if ActiveRecord::Base.connected?
db_rt_before_render = ActiveRecord::LogSubscriber.reset_runtime

0 comments on commit 6d96124

Please sign in to comment.