aboutsummaryrefslogtreecommitdiffstats
diff options
context:
space:
mode:
-rw-r--r--activerecord/test/cases/base_test.rb1
-rw-r--r--activesupport/lib/active_support/logger.rb14
-rw-r--r--activesupport/lib/active_support/logger_silence.rb24
-rw-r--r--activesupport/test/logger_test.rb85
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