mirror of
https://github.com/github/rails.git
synced 2026-01-13 16:47:56 -05:00
6d96124284
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.
56 lines
1.4 KiB
Ruby
56 lines
1.4 KiB
Ruby
require 'active_record_unit'
|
|
require 'active_record/railties/controller_runtime'
|
|
require 'fixtures/project'
|
|
require 'active_support/log_subscriber/test_helper'
|
|
require 'action_controller/log_subscriber'
|
|
|
|
ActionController::Base.send :include, ActiveRecord::Railties::ControllerRuntime
|
|
|
|
class ControllerRuntimeLogSubscriberTest < ActionController::TestCase
|
|
class LogSubscriberController < ActionController::Base
|
|
def show
|
|
render :inline => "<%= Project.all %>"
|
|
end
|
|
|
|
def zero
|
|
render :inline => "Zero DB runtime"
|
|
end
|
|
end
|
|
|
|
include ActiveSupport::LogSubscriber::TestHelper
|
|
tests LogSubscriberController
|
|
|
|
def setup
|
|
super
|
|
@old_logger = ActionController::Base.logger
|
|
ActionController::LogSubscriber.attach_to :action_controller
|
|
end
|
|
|
|
def teardown
|
|
super
|
|
ActiveSupport::LogSubscriber.log_subscribers.clear
|
|
ActionController::Base.logger = @old_logger
|
|
end
|
|
|
|
def set_logger(logger)
|
|
ActionController::Base.logger = logger
|
|
end
|
|
|
|
def test_log_with_active_record
|
|
get :show
|
|
wait
|
|
|
|
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
|