From 75a53297c7b7adcffef3cab0183d72969564281f Mon Sep 17 00:00:00 2001 From: George Claghorn Date: Tue, 24 Sep 2019 13:47:34 -0400 Subject: [PATCH] Add ActionController::Base.log_at Allow setting a different log level per request. --- actionpack/CHANGELOG.md | 11 ++++++ actionpack/lib/action_controller.rb | 1 + actionpack/lib/action_controller/api.rb | 1 + actionpack/lib/action_controller/base.rb | 1 + .../lib/action_controller/metal/logging.rb | 20 ++++++++++ actionpack/test/controller/logging_test.rb | 39 +++++++++++++++++++ .../lib/active_support/logger_silence.rb | 15 +------ .../logger_thread_safe_level.rb | 19 +++++++-- activesupport/test/logger_test.rb | 35 +++++++++++++++++ 9 files changed, 126 insertions(+), 16 deletions(-) create mode 100644 actionpack/lib/action_controller/metal/logging.rb create mode 100644 actionpack/test/controller/logging_test.rb diff --git a/actionpack/CHANGELOG.md b/actionpack/CHANGELOG.md index 7ae63355d5..99d073433b 100644 --- a/actionpack/CHANGELOG.md +++ b/actionpack/CHANGELOG.md @@ -1,3 +1,14 @@ +* `ActionController::Base.log_at` allows setting a different log level per request. + + ```ruby + # Use the debug level if a particular cookie is set. + class ApplicationController < ActionController::Base + log_at :debug, if: -> { cookies[:debug] } + end + ``` + + *George Claghorn* + * Allow system test screen shots to be taken more than once in a test by prefixing the file name with an incrementing counter. diff --git a/actionpack/lib/action_controller.rb b/actionpack/lib/action_controller.rb index b46defcd7e..0187b133c4 100644 --- a/actionpack/lib/action_controller.rb +++ b/actionpack/lib/action_controller.rb @@ -39,6 +39,7 @@ module ActionController autoload :BasicImplicitRender autoload :ImplicitRender autoload :Instrumentation + autoload :Logging autoload :MimeResponds autoload :ParamsWrapper autoload :Redirecting diff --git a/actionpack/lib/action_controller/api.rb b/actionpack/lib/action_controller/api.rb index c276ee57c0..6ad89cf611 100644 --- a/actionpack/lib/action_controller/api.rb +++ b/actionpack/lib/action_controller/api.rb @@ -123,6 +123,7 @@ def self.without_modules(*modules) ForceSSL, DataStreaming, DefaultHeaders, + Logging, # Before callbacks should also be executed as early as possible, so # also include them at the bottom. diff --git a/actionpack/lib/action_controller/base.rb b/actionpack/lib/action_controller/base.rb index 63c138af55..058bd6b6d2 100644 --- a/actionpack/lib/action_controller/base.rb +++ b/actionpack/lib/action_controller/base.rb @@ -234,6 +234,7 @@ def self.without_modules(*modules) HttpAuthentication::Digest::ControllerMethods, HttpAuthentication::Token::ControllerMethods, DefaultHeaders, + Logging, # Before callbacks should also be executed as early as possible, so # also include them at the bottom. diff --git a/actionpack/lib/action_controller/metal/logging.rb b/actionpack/lib/action_controller/metal/logging.rb new file mode 100644 index 0000000000..589856e506 --- /dev/null +++ b/actionpack/lib/action_controller/metal/logging.rb @@ -0,0 +1,20 @@ +# frozen_string_literal: true + +module ActionController + module Logging + extend ActiveSupport::Concern + + module ClassMethods + # Set a different log level per request. + # + # # Use the debug log level if a particular cookie is set. + # class ApplicationController < ActionController::Base + # log_at :debug, if: -> { cookies[:debug] } + # end + # + def log_at(level, **options) + around_action ->(_, action) { logger.log_at(level, &action) }, **options + end + end + end +end diff --git a/actionpack/test/controller/logging_test.rb b/actionpack/test/controller/logging_test.rb new file mode 100644 index 0000000000..693f3db37d --- /dev/null +++ b/actionpack/test/controller/logging_test.rb @@ -0,0 +1,39 @@ +# frozen_string_literal: true + +require "abstract_unit" + +class LoggingTest < ActionController::TestCase + class TestController < ActionController::Base + log_at :debug, if: -> { params[:level] == "debug" } + log_at :warn, if: -> { params[:level] == "warn" } + + def show + render plain: logger.level + end + end + + tests TestController + + setup do + @logger = @controller.logger = ActiveSupport::Logger.new(nil, level: Logger::INFO) + end + + test "logging at the default level" do + get :show + assert_equal Logger::INFO.to_s, response.body + end + + test "logging at a noisier level per request" do + assert_no_changes -> { @logger.level } do + get :show, params: { level: "debug" } + assert_equal Logger::DEBUG.to_s, response.body + end + end + + test "logging at a quieter level per request" do + assert_no_changes -> { @logger.level } do + get :show, params: { level: "warn" } + assert_equal Logger::WARN.to_s, response.body + end + end +end diff --git a/activesupport/lib/active_support/logger_silence.rb b/activesupport/lib/active_support/logger_silence.rb index b2444c1e34..cd3f809df3 100644 --- a/activesupport/lib/active_support/logger_silence.rb +++ b/activesupport/lib/active_support/logger_silence.rb @@ -27,19 +27,8 @@ module LoggerSilence end # Silences the logger for the duration of the block. - def silence(temporary_level = Logger::ERROR) - if silencer - begin - old_local_level = local_level - self.local_level = temporary_level - - yield self - ensure - self.local_level = old_local_level - end - else - yield self - end + def silence(severity = Logger::ERROR) + silencer ? log_at(severity) { yield self } : yield(self) end end end diff --git a/activesupport/lib/active_support/logger_thread_safe_level.rb b/activesupport/lib/active_support/logger_thread_safe_level.rb index 3735f0395b..91004001fe 100644 --- a/activesupport/lib/active_support/logger_thread_safe_level.rb +++ b/activesupport/lib/active_support/logger_thread_safe_level.rb @@ -37,10 +37,15 @@ def local_level end def local_level=(level) - if level + case level + when Integer self.class.local_levels[local_log_id] = level - else + when Symbol + self.class.local_levels[local_log_id] = Logger::Severity.const_get(level.to_s.upcase) + when nil self.class.local_levels.delete(local_log_id) + else + raise ArgumentError, "Invalid log level: #{level.inspect}" end end @@ -48,9 +53,17 @@ def level local_level || super end + # Change the thread-local level for the duration of the given block. + def log_at(level) + old_local_level, self.local_level = local_level, level + yield + ensure + self.local_level = old_local_level + end + # Redefined to check severity against #level, and thus the thread-local level, rather than +@level+. # FIXME: Remove when the minimum Ruby version supports overriding Logger#level. - def add(severity, message = nil, progname = nil, &block) # :nodoc: + def add(severity, message = nil, progname = nil, &block) #:nodoc: severity ||= UNKNOWN progname ||= @progname diff --git a/activesupport/test/logger_test.rb b/activesupport/test/logger_test.rb index 73680f423e..2580434f91 100644 --- a/activesupport/test/logger_test.rb +++ b/activesupport/test/logger_test.rb @@ -315,6 +315,41 @@ def test_logger_level_local_fiber_safety assert_level(Logger::INFO) end + def test_temporarily_logging_at_a_noisier_level + @logger.level = Logger::INFO + + @logger.debug "NOT THERE" + + @logger.log_at Logger::DEBUG do + @logger.debug "THIS IS HERE" + end + + @logger.debug "NOT THERE" + + assert_not_includes @output.string, "NOT THERE" + assert_includes @output.string, "THIS IS HERE" + end + + def test_temporarily_logging_at_a_quieter_level + @logger.log_at Logger::ERROR do + @logger.debug "NOT THERE" + @logger.error "THIS IS HERE" + end + + assert_not_includes @output.string, "NOT THERE" + assert_includes @output.string, "THIS IS HERE" + end + + def test_temporarily_logging_at_a_symbolic_level + @logger.log_at :error do + @logger.debug "NOT THERE" + @logger.error "THIS IS HERE" + end + + assert_not_includes @output.string, "NOT THERE" + assert_includes @output.string, "THIS IS HERE" + end + private def level_name(level) ::Logger::Severity.constants.find do |severity| -- GitLab