diff options
| -rw-r--r-- | activerecord/test/cases/base_test.rb | 1 | ||||
| -rw-r--r-- | activesupport/lib/active_support/logger.rb | 14 | ||||
| -rw-r--r-- | activesupport/lib/active_support/logger_silence.rb | 24 | ||||
| -rw-r--r-- | activesupport/test/logger_test.rb | 85 |
4 files changed, 120 insertions, 4 deletions
diff --git a/activerecord/test/cases/base_test.rb b/activerecord/test/cases/base_test.rb index f343a15317..ba3e16bdb2 100644 --- a/activerecord/test/cases/base_test.rb +++ b/activerecord/test/cases/base_test.rb @@ -1252,6 +1252,7 @@ class BasicsTest < ActiveRecord::TestCase original_logger = ActiveRecord::Base.logger log = StringIO.new ActiveRecord::Base.logger = ActiveSupport::Logger.new(log) + ActiveRecord::Base.logger.level = Logger::DEBUG ActiveRecord::Base.benchmark("Logging", :level => :debug, :silence => false) { ActiveRecord::Base.logger.debug "Quiet" } assert_match(/Quiet/, log.string) ensure diff --git a/activesupport/lib/active_support/logger.rb b/activesupport/lib/active_support/logger.rb index 82117a64d2..520268b244 100644 --- a/activesupport/lib/active_support/logger.rb +++ b/activesupport/lib/active_support/logger.rb @@ -46,6 +46,20 @@ module ActiveSupport super @formatter = SimpleFormatter.new @broadcast_messages = true + after_initialize if respond_to? :after_initialize + end + + def add(severity, message = nil, progname = nil, &block) + return true if @logdev.nil? || (severity || UNKNOWN) < level + super + end + + Logger::Severity.constants.each do |severity| + class_eval(<<-EOT, __FILE__, __LINE__ + 1) + def #{severity.downcase}? # def debug? + Logger::#{severity} >= level # DEBUG >= level + end # end + EOT end # Simple formatter which only displays the message. diff --git a/activesupport/lib/active_support/logger_silence.rb b/activesupport/lib/active_support/logger_silence.rb index 7d92256f24..690e5596f7 100644 --- a/activesupport/lib/active_support/logger_silence.rb +++ b/activesupport/lib/active_support/logger_silence.rb @@ -1,22 +1,42 @@ require 'active_support/concern' require 'active_support/core_ext/module/attribute_accessors' +require 'concurrent' module LoggerSilence extend ActiveSupport::Concern included do cattr_accessor :silencer + attr_reader :local_levels self.silencer = true end + def after_initialize + @local_levels = Concurrent::Map.new(:initial_capacity => 2) + end + + def local_log_id + Thread.current.__id__ + end + + def level + local_levels[local_log_id] || super + end + # Silences the logger for the duration of the block. def silence(temporary_level = Logger::ERROR) if silencer begin - old_logger_level, self.level = level, temporary_level + old_local_level = local_levels[local_log_id] + local_levels[local_log_id] = temporary_level + yield self ensure - self.level = old_logger_level + if old_local_level + local_levels[local_log_id] = old_local_level + else + local_levels.delete(local_log_id) + end end else yield self diff --git a/activesupport/test/logger_test.rb b/activesupport/test/logger_test.rb index d2801849ca..a57dc7a241 100644 --- a/activesupport/test/logger_test.rb +++ b/activesupport/test/logger_test.rb @@ -3,6 +3,7 @@ require 'multibyte_test_helpers' require 'stringio' require 'fileutils' require 'tempfile' +require 'concurrent/atomics' class LoggerTest < ActiveSupport::TestCase include MultibyteTestHelpers @@ -113,6 +114,7 @@ class LoggerTest < ActiveSupport::TestCase end def test_buffer_multibyte + @logger.level = Logger::INFO @logger.info(UNICODE_STRING) @logger.info(BYTE_STRING) assert @output.string.include?(UNICODE_STRING) @@ -120,14 +122,93 @@ class LoggerTest < ActiveSupport::TestCase byte_string.force_encoding("ASCII-8BIT") assert byte_string.include?(BYTE_STRING) end - + def test_silencing_everything_but_errors @logger.silence do @logger.debug "NOT THERE" @logger.error "THIS IS HERE" end - + assert !@output.string.include?("NOT THERE") assert @output.string.include?("THIS IS HERE") end + + def test_logger_level_per_object_thread_safety + logger1 = Logger.new(StringIO.new) + logger2 = Logger.new(StringIO.new) + + level = Logger::DEBUG + assert_equal level, logger1.level, "Expected level #{level_name(level)}, got #{level_name(logger1.level)}" + assert_equal level, logger2.level, "Expected level #{level_name(level)}, got #{level_name(logger2.level)}" + + logger1.level = Logger::ERROR + assert_equal level, logger2.level, "Expected level #{level_name(level)}, got #{level_name(logger2.level)}" + end + + def test_logger_level_main_thread_safety + @logger.level = Logger::INFO + assert_level(Logger::INFO) + + latch = Concurrent::CountDownLatch.new + latch2 = Concurrent::CountDownLatch.new + + t = Thread.new do + latch.wait + assert_level(Logger::INFO) + latch2.count_down + end + + @logger.silence(Logger::ERROR) do + assert_level(Logger::ERROR) + latch.count_down + latch2.wait + end + + t.join + end + + def test_logger_level_local_thread_safety + @logger.level = Logger::INFO + assert_level(Logger::INFO) + + thread_1_latch = Concurrent::CountDownLatch.new + thread_2_latch = Concurrent::CountDownLatch.new + + threads = (1..2).collect do |thread_number| + Thread.new do + # force thread 2 to wait until thread 1 is already in @logger.silence + thread_2_latch.wait if thread_number == 2 + + @logger.silence(Logger::ERROR) do + assert_level(Logger::ERROR) + @logger.silence(Logger::DEBUG) do + # allow thread 2 to finish but hold thread 1 + if thread_number == 1 + thread_2_latch.count_down + thread_1_latch.wait + end + assert_level(Logger::DEBUG) + end + end + + # allow thread 1 to finish + assert_level(Logger::INFO) + thread_1_latch.count_down if thread_number == 2 + end + end + + threads.each(&:join) + assert_level(Logger::INFO) + end + + private + def level_name(level) + ::Logger::Severity.constants.find do |severity| + Logger.const_get(severity) == level + end.to_s + end + + def assert_level(level) + assert_equal level, @logger.level, "Expected level #{level_name(level)}, got #{level_name(@logger.level)}" + end end |