Merge pull request rails#53093 from armstrjare/broadcast-logger-with-block

Fix ActiveSupport::BroadcastLogger from executing a block argument for each logger (tagged, info, etc.)

Author: rafaelfranca

activesupport/lib/active_support/broadcast_logger.rb

@@ -76,7 +76,6 @@ class BroadcastLogger
 
     # Returns all the logger that are part of this broadcast.
     attr_reader :broadcasts
-    attr_reader :formatter
     attr_accessor :progname
 
     def initialize(*loggers)
@@ -105,62 +104,36 @@ def stop_broadcasting_to(logger)
       @broadcasts.delete(logger)
     end
 
-    def level
-      @broadcasts.map(&:level).min
-    end
-
-    def <<(message)
-      dispatch { |logger| logger.<<(message) }
-    end
-
-    def add(...)
-      dispatch { |logger| logger.add(...) }
-    end
-    alias_method :log, :add
-
-    def debug(...)
-      dispatch { |logger| logger.debug(...) }
-    end
-
-    def info(...)
-      dispatch { |logger| logger.info(...) }
-    end
-
-    def warn(...)
-      dispatch { |logger| logger.warn(...) }
-    end
-
-    def error(...)
-      dispatch { |logger| logger.error(...) }
-    end
-
-    def fatal(...)
-      dispatch { |logger| logger.fatal(...) }
-    end
-
-    def unknown(...)
-      dispatch { |logger| logger.unknown(...) }
+    def local_level=(level)
+      @broadcasts.each do |logger|
+        logger.local_level = level if logger.respond_to?(:local_level=)
+      end
     end
 
-    def formatter=(formatter)
-      dispatch { |logger| logger.formatter = formatter }
-
-      @formatter = formatter
-    end
+    def local_level
+      loggers = @broadcasts.select { |logger| logger.respond_to?(:local_level) }
 
-    def level=(level)
-      dispatch { |logger| logger.level = level }
+      loggers.map do |logger|
+        logger.local_level
+      end.first
     end
-    alias_method :sev_threshold=, :level=
 
-    def local_level=(level)
-      dispatch do |logger|
-        logger.local_level = level if logger.respond_to?(:local_level=)
-      end
+    LOGGER_METHODS = %w[
+      << log add debug info warn error fatal unknown
+      level= sev_threshold= close
+      formatter formatter=
+    ] # :nodoc:
+    LOGGER_METHODS.each do |method|
+      class_eval <<-RUBY, __FILE__, __LINE__ + 1
+        def #{method}(...)
+          dispatch(:#{method}, ...)
+        end
+      RUBY
     end
 
-    def close
-      dispatch { |logger| logger.close }
+    # Returns the lowest level of all the loggers in the broadcast.
+    def level
+      @broadcasts.map(&:level).min
     end
 
     # True if the log level allows entries with severity +Logger::DEBUG+ to be written
@@ -171,7 +144,7 @@ def debug?
 
     # Sets the log level to +Logger::DEBUG+ for the whole broadcast.
     def debug!
-      dispatch { |logger| logger.debug! }
+      dispatch(:debug!)
     end
 
     # True if the log level allows entries with severity +Logger::INFO+ to be written
@@ -182,7 +155,7 @@ def info?
 
     # Sets the log level to +Logger::INFO+ for the whole broadcast.
     def info!
-      dispatch { |logger| logger.info! }
+      dispatch(:info!)
     end
 
     # True if the log level allows entries with severity +Logger::WARN+ to be written
@@ -193,7 +166,7 @@ def warn?
 
     # Sets the log level to +Logger::WARN+ for the whole broadcast.
     def warn!
-      dispatch { |logger| logger.warn! }
+      dispatch(:warn!)
     end
 
     # True if the log level allows entries with severity +Logger::ERROR+ to be written
@@ -204,7 +177,7 @@ def error?
 
     # Sets the log level to +Logger::ERROR+ for the whole broadcast.
     def error!
-      dispatch { |logger| logger.error! }
+      dispatch(:error!)
     end
 
     # True if the log level allows entries with severity +Logger::FATAL+ to be written
@@ -215,21 +188,35 @@ def fatal?
 
     # Sets the log level to +Logger::FATAL+ for the whole broadcast.
     def fatal!
-      dispatch { |logger| logger.fatal! }
+      dispatch(:fatal!)
     end
 
     def initialize_copy(other)
       @broadcasts = []
       @progname = other.progname.dup
-      @formatter = other.formatter.dup
 
       broadcast_to(*other.broadcasts.map(&:dup))
     end
 
     private
-      def dispatch(&block)
-        @broadcasts.each { |logger| block.call(logger) }
-        true
+      def dispatch(method, *args, **kwargs, &block)
+        if block_given?
+          # Maintain semantics that the first logger yields the block
+          # as normal, but subsequent loggers won't re-execute the block.
+          # Instead, the initial result is immediately returned.
+          called, result = false, nil
+          block = proc { |*args, **kwargs|
+            if called then result
+            else
+              called = true
+              result = yield(*args, **kwargs)
+            end
+          }
+        end
+
+        @broadcasts.map { |logger|
+          logger.send(method, *args, **kwargs, &block)
+        }.first
       end
 
       def method_missing(name, ...)

activesupport/test/broadcast_logger_test.rb

@@ -268,14 +268,28 @@ def info(msg, &block)
       assert(logger.foo)
     end
 
-    test "calling a method that accepts a block" do
-      logger = BroadcastLogger.new(CustomLogger.new)
+    test "methods are called on each logger" do
+      calls = 0
+      loggers = [CustomLogger.new, FakeLogger.new, CustomLogger.new].each do |logger|
+        logger.define_singleton_method(:special_method) do
+          calls += 1
+        end
+      end
+      logger = BroadcastLogger.new(*loggers)
+      logger.special_method
+      assert_equal(3, calls)
+    end
 
-      called = false
-      logger.bar do
-        called = true
+    test "calling a method that accepts a block is yielded only once" do
+      called = 0
+      logger.info do
+        called += 1
+        "Hello"
       end
-      assert(called)
+
+      assert_equal 1, called, "block should be called just once"
+      assert_equal [[::Logger::INFO, "Hello", nil]], log1.adds
+      assert_equal [[::Logger::INFO, "Hello", nil]], log2.adds
     end
 
     test "calling a method that accepts args" do
@@ -356,27 +370,27 @@ def qux(param:)
         true
       end
 
-      def debug(message, &block)
+      def debug(message = nil, &block)
         add(::Logger::DEBUG, message, &block)
       end
 
-      def info(message, &block)
+      def info(message = nil, &block)
         add(::Logger::INFO, message, &block)
       end
 
-      def warn(message, &block)
+      def warn(message = nil, &block)
         add(::Logger::WARN, message, &block)
       end
 
-      def error(message, &block)
+      def error(message = nil, &block)
         add(::Logger::ERROR, message, &block)
       end
 
-      def fatal(message, &block)
+      def fatal(message = nil, &block)
         add(::Logger::FATAL, message, &block)
       end
 
-      def unknown(message, &block)
+      def unknown(message = nil, &block)
         add(::Logger::UNKNOWN, message, &block)
       end
 
@@ -385,7 +399,8 @@ def <<(x)
       end
 
       def add(message_level, message = nil, progname = nil, &block)
-        @adds << [message_level, message, progname] if message_level >= local_level
+        @adds << [message_level, block_given? ? block.call : message, progname] if message_level >= local_level
+        true
       end
 
       def debug?

railties/lib/rails/application/bootstrap.rb

@@ -59,9 +59,7 @@ module Bootstrap
           end
         else
           Rails.logger.level = ActiveSupport::Logger.const_get(config.log_level.to_s.upcase)
-          broadcast_logger = ActiveSupport::BroadcastLogger.new(Rails.logger)
-          broadcast_logger.formatter = Rails.logger.formatter
-          Rails.logger = broadcast_logger
+          Rails.logger = ActiveSupport::BroadcastLogger.new(Rails.logger)
         end
       end