diff --git a/activesupport/lib/active_support/logger.rb b/activesupport/lib/active_support/logger.rb index 33fccdcf9516..b82a6217df80 100644 --- a/activesupport/lib/active_support/logger.rb +++ b/activesupport/lib/active_support/logger.rb @@ -44,6 +44,20 @@ def self.broadcast(logger) # :nodoc: def initialize(*args) super @formatter = SimpleFormatter.new + 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 a8efdef944fa..d5dc81b1047d 100644 --- a/activesupport/lib/active_support/logger_silence.rb +++ b/activesupport/lib/active_support/logger_silence.rb @@ -1,21 +1,42 @@ require 'active_support/concern' +require 'thread_safe' module LoggerSilence extend ActiveSupport::Concern included do cattr_accessor :silencer + attr_reader :local_levels self.silencer = true end + + def after_initialize + @local_levels = ThreadSafe::Cache.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 d2801849ca43..5ec89c7389a7 100644 --- a/activesupport/test/logger_test.rb +++ b/activesupport/test/logger_test.rb @@ -3,6 +3,7 @@ require 'stringio' require 'fileutils' require 'tempfile' +require 'active_support/concurrency/latch' class LoggerTest < ActiveSupport::TestCase include MultibyteTestHelpers @@ -113,6 +114,7 @@ def test_should_know_if_its_loglevel_is_below_a_given_level end def test_buffer_multibyte + @logger.level = Logger::INFO @logger.info(UNICODE_STRING) @logger.info(BYTE_STRING) assert @output.string.include?(UNICODE_STRING) @@ -130,4 +132,83 @@ def test_silencing_everything_but_errors 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 = ActiveSupport::Concurrency::Latch.new + latch2 = ActiveSupport::Concurrency::Latch.new + + t = Thread.new do + latch.await + assert_level(Logger::INFO) + latch2.release + end + + @logger.silence(Logger::ERROR) do + assert_level(Logger::ERROR) + latch.release + latch2.await + end + + t.join + end + + def test_logger_level_local_thread_safety + @logger.level = Logger::INFO + assert_level(Logger::INFO) + + thread_1_latch = ActiveSupport::Concurrency::Latch.new + thread_2_latch = ActiveSupport::Concurrency::Latch.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.await 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.release + thread_1_latch.await + end + assert_level(Logger::DEBUG) + end + end + + # allow thread 1 to finish + assert_level(Logger::INFO) + thread_1_latch.release 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