Skip to content

Commit

Permalink
Ensure ActiveSupport::BroadcastLogger only executes blocks once.
Browse files Browse the repository at this point in the history
Prior to this change, BroadcastLoggers would iterate each broadcast and
execute the user provided block for each. This resulted in unintended
behaviour since a user-provided block could execute multiple times.

The consumer of any Logger would reasonably expect than when calling a
method with a block, that block would only execute a single time. That is,
the fact that a Logger is a BroadcastLogger should be irrelevant to user.

The most significant example of this is with
ActiveSupport::TaggedLogging. If a BroadcastLogger is used, and there
are multiple loggers being broadcast to that respond to the `tagged`
method, then calling `tagged` with a block would result in the block
being called multiple times. For example:

```ruby
broadcasts = ActiveSupport::BroadcastLogger.new(
  *Array.new(2) { ActiveSupport::TaggedLogging.logger }
)
number = 0
broadcasts.tagged("FOO") { broadcasts.log(++number.to_s) }
```

This commit modifies the implementation used for dispatching to instead
'nest' methods called with a block such that the user-provided block is
only executed in the innermost call. For example, the above example
would effectively be performed as so:
```ruby
broadcasts[0].tagged("FOO") {
  broadcasts[1].tagged("FOO") {
    yield
  }
}
```
  • Loading branch information
armstrjare committed Sep 28, 2024
1 parent 13d5f87 commit 6b14642
Show file tree
Hide file tree
Showing 2 changed files with 60 additions and 24 deletions.
57 changes: 35 additions & 22 deletions activesupport/lib/active_support/broadcast_logger.rb
Original file line number Diff line number Diff line change
Expand Up @@ -114,32 +114,32 @@ def <<(message)
end

def add(...)
dispatch { |logger| logger.add(...) }
dispatch_method(:add, ...).first
end
alias_method :log, :add

def debug(...)
dispatch { |logger| logger.debug(...) }
dispatch_method(:debug, ...).first
end

def info(...)
dispatch { |logger| logger.info(...) }
dispatch_method(:info, ...).first
end

def warn(...)
dispatch { |logger| logger.warn(...) }
dispatch_method(:warn, ...).first
end

def error(...)
dispatch { |logger| logger.error(...) }
dispatch_method(:error, ...).first
end

def fatal(...)
dispatch { |logger| logger.fatal(...) }
dispatch_method(:fatal, ...).first
end

def unknown(...)
dispatch { |logger| logger.unknown(...) }
dispatch_method(:unknown, ...).first
end

def formatter=(formatter)
Expand All @@ -160,7 +160,7 @@ def local_level=(level)
end

def close
dispatch { |logger| logger.close }
dispatch { |logger| logger.close }.first
end

# +True+ if the log level allows entries with severity Logger::DEBUG to be written
Expand All @@ -171,7 +171,7 @@ def debug?

# Sets the log level to Logger::DEBUG for the whole broadcast.
def debug!
dispatch { |logger| logger.debug! }
dispatch { |logger| logger.debug! }.first
end

# +True+ if the log level allows entries with severity Logger::INFO to be written
Expand All @@ -182,7 +182,7 @@ def info?

# Sets the log level to Logger::INFO for the whole broadcast.
def info!
dispatch { |logger| logger.info! }
dispatch { |logger| logger.info! }.first
end

# +True+ if the log level allows entries with severity Logger::WARN to be written
Expand All @@ -193,7 +193,7 @@ def warn?

# Sets the log level to Logger::WARN for the whole broadcast.
def warn!
dispatch { |logger| logger.warn! }
dispatch { |logger| logger.warn! }.first
end

# +True+ if the log level allows entries with severity Logger::ERROR to be written
Expand All @@ -204,7 +204,7 @@ def error?

# Sets the log level to Logger::ERROR for the whole broadcast.
def error!
dispatch { |logger| logger.error! }
dispatch { |logger| logger.error! }.first
end

# +True+ if the log level allows entries with severity Logger::FATAL to be written
Expand All @@ -215,7 +215,7 @@ def fatal?

# Sets the log level to Logger::FATAL for the whole broadcast.
def fatal!
dispatch { |logger| logger.fatal! }
dispatch { |logger| logger.fatal! }.first
end

def initialize_copy(other)
Expand All @@ -228,19 +228,32 @@ def initialize_copy(other)

private
def dispatch(&block)
@broadcasts.each { |logger| block.call(logger) }
true
@broadcasts.map { |logger| block.call(logger) }
end

def method_missing(name, ...)
loggers = @broadcasts.select { |logger| logger.respond_to?(name) }
def dispatch_method(name, *args, **kwargs, &block)
if block_given?
@broadcasts.inject(block) { |block, logger|
if logger.respond_to?(name)
proc { logger.send(name, *args, **kwargs, &block) }
else
block
end
}.call
else
@broadcasts.map { |logger|
if logger.respond_to?(name)
logger.send(name, *args, **kwargs)
end
}
end
end

if loggers.none?
super
elsif loggers.one?
loggers.first.send(name, ...)
def method_missing(name, ...)
if @broadcasts.any? { |logger| logger.respond_to?(name) }
dispatch_method(name, ...)
else
loggers.map { |logger| logger.send(name, ...) }
super
end
end

Expand Down
27 changes: 25 additions & 2 deletions activesupport/test/broadcast_logger_test.rb
Original file line number Diff line number Diff line change
Expand Up @@ -263,9 +263,21 @@ def info(msg, &block)
end

test "calling a method when a subset of loggers in the broadcast have implemented" do
logger = BroadcastLogger.new(CustomLogger.new, FakeLogger.new)
special_logger = Class.new(CustomLogger) do
def special_method = true
end.new
logger = BroadcastLogger.new(CustomLogger.new, FakeLogger.new, special_logger)

assert(logger.foo)
assert_equal [nil, nil, true], logger.special_method
end

test "calling a method returns the return values" do
special_logger = Class.new(CustomLogger) do
def foo = "bar"
end.new
logger = BroadcastLogger.new(CustomLogger.new, FakeLogger.new, special_logger)

assert_equal [true, true, "bar"], logger.foo
end

test "calling a method that accepts a block" do
Expand All @@ -278,6 +290,16 @@ def info(msg, &block)
assert(called)
end

test "calling a method that accepts a block with multiple loggers" do
logger = BroadcastLogger.new(CustomLogger.new, CustomLogger.new)

called = 0
logger.bar do
called += 1
end
assert_equal 1, called, "block should be called just once"
end

test "calling a method that accepts args" do
logger = BroadcastLogger.new(CustomLogger.new)

Expand Down Expand Up @@ -386,6 +408,7 @@ def <<(x)

def add(message_level, message = nil, progname = nil, &block)
@adds << [message_level, message, progname] if message_level >= local_level
true
end

def debug?
Expand Down

0 comments on commit 6b14642

Please sign in to comment.