1
0
Fork 0
mirror of https://github.com/rails/rails.git synced 2022-11-09 12:12:34 -05:00

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

This commit is contained in:
Frederick Cheung 2011-05-22 19:49:31 +01:00
parent 4ee7d923e1
commit 60b55baca9
2 changed files with 31 additions and 3 deletions

View file

@ -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

View file

@ -23,8 +23,8 @@ module ActiveRecord
db_rt_before_render = ActiveRecord::LogSubscriber.reset_runtime
runtime = super
db_rt_after_render = ActiveRecord::LogSubscriber.reset_runtime
self.db_runtime = db_rt_before_render + db_rt_after_render
runtime - db_rt_after_render
self.db_runtime = db_rt_before_render + db_during_render
runtime - db_during_render
else
super
end
@ -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