Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

4.1 Backport of LoggerSilence#silence Threadsafety patch (see: PR #20507) #22968

Merged
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Jump to
Jump to file
Failed to load files.
Diff view
Diff view
14 changes: 14 additions & 0 deletions activesupport/lib/active_support/logger.rb
Original file line number Diff line number Diff line change
Expand Up @@ -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.
Expand Down
27 changes: 24 additions & 3 deletions activesupport/lib/active_support/logger_silence.rb
Original file line number Diff line number Diff line change
@@ -1,24 +1,45 @@
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
end
end
end
end
85 changes: 83 additions & 2 deletions activesupport/test/logger_test.rb
Original file line number Diff line number Diff line change
Expand Up @@ -3,6 +3,7 @@
require 'stringio'
require 'fileutils'
require 'tempfile'
require 'active_support/concurrency/latch'

class LoggerTest < ActiveSupport::TestCase
include MultibyteTestHelpers
Expand Down Expand Up @@ -113,21 +114,101 @@ 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)
byte_string = @output.string.dup
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 = 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