mirror of
https://github.com/rails/rails.git
synced 2022-11-09 12:12:34 -05:00
Fixes LoggerSilence#silence threadsafety
- uses instance defined level if no custom local log level defined - Keeps track of local log level per [ thread + object-instance ] - prevents memory leakage by removing local level hash key/value on #silence method exit - avoids the use of Thread local variables
This commit is contained in:
parent
2ad6deb534
commit
629efb6057
4 changed files with 120 additions and 4 deletions
|
@ -1252,6 +1252,7 @@ class BasicsTest < ActiveRecord::TestCase
|
||||||
original_logger = ActiveRecord::Base.logger
|
original_logger = ActiveRecord::Base.logger
|
||||||
log = StringIO.new
|
log = StringIO.new
|
||||||
ActiveRecord::Base.logger = ActiveSupport::Logger.new(log)
|
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" }
|
ActiveRecord::Base.benchmark("Logging", :level => :debug, :silence => false) { ActiveRecord::Base.logger.debug "Quiet" }
|
||||||
assert_match(/Quiet/, log.string)
|
assert_match(/Quiet/, log.string)
|
||||||
ensure
|
ensure
|
||||||
|
|
|
@ -46,6 +46,20 @@ module ActiveSupport
|
||||||
super
|
super
|
||||||
@formatter = SimpleFormatter.new
|
@formatter = SimpleFormatter.new
|
||||||
@broadcast_messages = true
|
@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
|
end
|
||||||
|
|
||||||
# Simple formatter which only displays the message.
|
# Simple formatter which only displays the message.
|
||||||
|
|
|
@ -1,22 +1,42 @@
|
||||||
require 'active_support/concern'
|
require 'active_support/concern'
|
||||||
require 'active_support/core_ext/module/attribute_accessors'
|
require 'active_support/core_ext/module/attribute_accessors'
|
||||||
|
require 'concurrent'
|
||||||
|
|
||||||
module LoggerSilence
|
module LoggerSilence
|
||||||
extend ActiveSupport::Concern
|
extend ActiveSupport::Concern
|
||||||
|
|
||||||
included do
|
included do
|
||||||
cattr_accessor :silencer
|
cattr_accessor :silencer
|
||||||
|
attr_reader :local_levels
|
||||||
self.silencer = true
|
self.silencer = true
|
||||||
end
|
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.
|
# Silences the logger for the duration of the block.
|
||||||
def silence(temporary_level = Logger::ERROR)
|
def silence(temporary_level = Logger::ERROR)
|
||||||
if silencer
|
if silencer
|
||||||
begin
|
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
|
yield self
|
||||||
ensure
|
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
|
end
|
||||||
else
|
else
|
||||||
yield self
|
yield self
|
||||||
|
|
|
@ -3,6 +3,7 @@ require 'multibyte_test_helpers'
|
||||||
require 'stringio'
|
require 'stringio'
|
||||||
require 'fileutils'
|
require 'fileutils'
|
||||||
require 'tempfile'
|
require 'tempfile'
|
||||||
|
require 'concurrent/atomics'
|
||||||
|
|
||||||
class LoggerTest < ActiveSupport::TestCase
|
class LoggerTest < ActiveSupport::TestCase
|
||||||
include MultibyteTestHelpers
|
include MultibyteTestHelpers
|
||||||
|
@ -113,6 +114,7 @@ class LoggerTest < ActiveSupport::TestCase
|
||||||
end
|
end
|
||||||
|
|
||||||
def test_buffer_multibyte
|
def test_buffer_multibyte
|
||||||
|
@logger.level = Logger::INFO
|
||||||
@logger.info(UNICODE_STRING)
|
@logger.info(UNICODE_STRING)
|
||||||
@logger.info(BYTE_STRING)
|
@logger.info(BYTE_STRING)
|
||||||
assert @output.string.include?(UNICODE_STRING)
|
assert @output.string.include?(UNICODE_STRING)
|
||||||
|
@ -130,4 +132,83 @@ class LoggerTest < ActiveSupport::TestCase
|
||||||
assert !@output.string.include?("NOT THERE")
|
assert !@output.string.include?("NOT THERE")
|
||||||
assert @output.string.include?("THIS IS HERE")
|
assert @output.string.include?("THIS IS HERE")
|
||||||
end
|
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
|
end
|
||||||
|
|
Loading…
Reference in a new issue