Reimplement TaggedLogging:

- ### Context

  The Tagged Logging functionality has been a source of a few
  issues over the years, especially when combined with the
  broadcasting feature.
  Initializating a Tagged Logger wasn't very intuitive:

  ```ruby
    logger = Logger.new(STDOUT)
    tagged_logger = ActiveSupport::TaggedLogging.new(logger)
    # Would expect the `tagged_logger` to be an instance of `AS::TaggedLogging`
    # but it's a clone of the `logger`.

    tagged_logger.formatter = ->(_, _, _, message) do
      { message: message }
    end
    # Modifies the formatter to output JSON formatted logs.
    # This breaks tagged logging.
  ```

  I believe the main reason of those issues is because tagged logging
  is implemented at the wrong level.

  ### Solution

  I made a proposal on the Ruby logger upstream in ruby/logger#90 to help
  solve this but it hasn't been reviewed yet. So I thought about adding
  it here for now.
  The TL;DR is to decouple formatting and adding extra information to
  logs (which is what tagged logging does).

  ### Deprecation

  Since TaggedLogging will no longer access the formatter, there is a
  few things I'd like to deprecate (such as setting a default
  formatter https://github.com/rails/rails/blob/d68e43922bc11829c52ad9f736ad5549fc97631b/activesupport/lib/active_support/tagged_logging.rb#L124)
  but doing so in this PR would increase the size of the diff
  significantly and would maybe distract for PR reviews.

  Another thing that I believe should be deprecated is
  `ActiveSupport::TaggedLogging.new`. Adding tagging
  functionality to a logger should be done using
  a more ruby approach such as `logger.extend(AS::TaggedLogging)`.

  Fix rails#49757
  Fix rails#49745
  Fix rails#46084
  Fix rails#44668

I made a propose on the Ruby logger upstream in ruby/logger#90,
  but it hasn't been reviewed it.

actioncable/lib/action_cable/connection/tagged_logger_proxy.rb

@@ -25,7 +25,7 @@ def add_tags(*tags)
 
       def tag(logger, &block)
         if logger.respond_to?(:tagged)
-          current_tags = tags - logger.formatter.current_tags
+          current_tags = tags - logger.tag_processor.current_tags
           logger.tagged(*current_tags, &block)
         else
           yield

activejob/lib/active_job/logging.rb

@@ -43,7 +43,7 @@ def tag_logger(*tags, &block)
       end
 
       def logger_tagged_by_active_job?
-        logger.formatter.current_tags.include?("ActiveJob")
+        logger.tag_processor.current_tags.include?("ActiveJob")
       end
   end
 end

activesupport/lib/active_support/broadcast_logger.rb

@@ -1,5 +1,7 @@
 # frozen_string_literal: true
 
+require "active_support/tagged_logging"
+
 module ActiveSupport
   # = Active Support Broadcast Logger
   #
@@ -71,6 +73,40 @@ module ActiveSupport
   #   logger.broadcast_to(MyLogger.new(STDOUT))
   #   puts logger.broadcasts # => [MyLogger, MyLogger]
   #   logger.loggable? # [true, true]
+  #
+  # ====== A note on tagging logs while using the Broadcast logger
+  #
+  # It is quite frequent to tag logs using the `ActiveSupport::TaggedLogging` module
+  # while also broadcasting them (the default Rails.logger in development is
+  # configured in such a way).
+  # Tagging your logs can be done for the whole broadcast or for each sink independently.
+  #
+  # Tagging logs for the whole broadcast:
+  #
+  #   broadcast = BroadcastLogger.new(stdout_logger, file_logger)
+  #   broadcast.tagged("BMX") { broadcast.info("Hello world!") }
+  #
+  #   Outputs: "[BMX] Hello world!" is written on both STDOUT and in the file.
+  #
+  # Tagging logs for a single logger:
+  #
+  #   stdout_logger.extend(ActiveSupport::TaggedLogging)
+  #   stdout_logger.push_tags("BMX")
+  #   broadcast = BroadcastLogger.new(stdout_logger, file_logger)
+  #   broadcast.info("Hello world!")
+  #
+  #   Outputs: "[BMX] Hello world!" is written on STDOUT
+  #   Outputs: "Hello world!"       is written in the file
+  #
+  # Adding tags for the whole broadcast and adding extra tags on a specific logger:
+  #
+  #   stdout_logger.extend(ActiveSupport::TaggedLogging)
+  #   stdout_logger.push_tags("BMX")
+  #   broadcast = BroadcastLogger.new(stdout_logger, file_logger)
+  #   broadcast.tagged("APP") { broadcast.info("Hello world!") }
+  #
+  #   Outputs: "[APP][BMX] Hello world!" is written on STDOUT
+  #   Outputs: "[APP] Hello world!"      is written in the file
   class BroadcastLogger
     include ActiveSupport::LoggerSilence
 
@@ -80,6 +116,8 @@ class BroadcastLogger
     attr_accessor :progname
 
     def initialize(*loggers)
+      extend ActiveSupport::TaggedLogging
+
       @broadcasts = []
       @progname = "Broadcast"
 
@@ -91,6 +129,10 @@ def initialize(*loggers)
     #   broadcast_logger = ActiveSupport::BroadcastLogger.new
     #   broadcast_logger.broadcast_to(Logger.new(STDOUT), Logger.new(STDERR))
     def broadcast_to(*loggers)
+      loggers.each do |logger|
+        logger.extend(LogProcessor) unless logger.is_a?(LogProcessor)
+      end
+
       @broadcasts.concat(loggers)
     end
 
@@ -114,32 +156,32 @@ def <<(message)
     end
 
     def add(...)
-      dispatch { |logger| logger.add(...) }
+      dispatch_with_processors { |logger| logger.add(...) }
     end
     alias_method :log, :add
 
     def debug(...)
-      dispatch { |logger| logger.debug(...) }
+      dispatch_with_processors { |logger| logger.debug(...) }
     end
 
     def info(...)
-      dispatch { |logger| logger.info(...) }
+      dispatch_with_processors { |logger| logger.info(...) }
     end
 
     def warn(...)
-      dispatch { |logger| logger.warn(...) }
+      dispatch_with_processors { |logger| logger.warn(...) }
     end
 
     def error(...)
-      dispatch { |logger| logger.error(...) }
+      dispatch_with_processors { |logger| logger.error(...) }
     end
 
     def fatal(...)
-      dispatch { |logger| logger.fatal(...) }
+      dispatch_with_processors { |logger| logger.fatal(...) }
     end
 
     def unknown(...)
-      dispatch { |logger| logger.unknown(...) }
+      dispatch_with_processors { |logger| logger.unknown(...) }
     end
 
     def formatter=(formatter)
@@ -218,7 +260,7 @@ def fatal!
       dispatch { |logger| logger.fatal! }
     end
 
-    def initialize_copy(other)
+    def initialize_dup(other)
       @broadcasts = []
       @progname = other.progname.dup
       @formatter = other.formatter.dup
@@ -232,6 +274,18 @@ def dispatch(&block)
         true
       end
 
+      def dispatch_with_processors(&block)
+        @broadcasts.each do |logger|
+          logger.processors.unshift(processors)
+
+          block.call(logger)
+        ensure
+          logger.processors.shift(processors.count)
+        end
+
+        true
+      end
+
       def method_missing(name, ...)
         loggers = @broadcasts.select { |logger| logger.respond_to?(name) }
 

activesupport/lib/active_support/log_processor.rb

@@ -0,0 +1,26 @@
+# frozen_string_literal: true
+
+module ActiveSupport
+  module LogProcessor # :nodoc:
+    attr_accessor :processors
+
+    def self.extended(base)
+      base.processors = []
+    end
+
+    def initialize(*args, **kwargs)
+      super
+
+      self.processors = []
+    end
+
+    private
+      def format_message(severity, datetime, progname, msg)
+        processors.flatten.reverse_each do |processor|
+          msg = processor.call(msg, self)
+        end
+
+        super(severity, datetime, progname, msg)
+      end
+  end
+end

activesupport/lib/active_support/logger.rb

@@ -2,11 +2,13 @@
 
 require "active_support/logger_silence"
 require "active_support/logger_thread_safe_level"
+require "active_support/log_processor"
 require "logger"
 
 module ActiveSupport
   class Logger < ::Logger
     include LoggerSilence
+    include LogProcessor
 
     # Returns true if the logger destination matches one of the sources
     #

activesupport/lib/active_support/tagged_logging.rb

@@ -27,10 +27,13 @@ module ActiveSupport
   # it easy to stamp log lines with subdomains, request ids, and anything else
   # to aid debugging of multi-user production applications.
   module TaggedLogging
-    module Formatter # :nodoc:
-      # This method is invoked when a log event occurs.
-      def call(severity, timestamp, progname, msg)
-        super(severity, timestamp, progname, tag_stack.format_message(msg))
+    class TagProcessor # :nodoc:
+      def call(msg, logger)
+        if logger.formatter.nil?
+          logger.formatter ||= Logger::SimpleFormatter.new
+        end
+
+        tag_stack.format_message(msg)
       end
 
       def tagged(*tags)
@@ -118,33 +121,43 @@ def self.logger(*args, **kwargs)
       new ActiveSupport::Logger.new(*args, **kwargs)
     end
 
-    def self.new(logger)
-      logger = logger.clone
-
-      if logger.formatter
-        logger.formatter = logger.formatter.clone
+    def self.new(logger) # :nodoc:
+      # Workaround for https://bugs.ruby-lang.org/issues/20250
+      # Can be removed when Ruby 3.4 is the least supported version.
+      logger.formatter.object_id if logger.formatter.is_a?(Proc)
 
-        # Workaround for https://bugs.ruby-lang.org/issues/20250
-        # Can be removed when Ruby 3.4 is the least supported version.
-        logger.formatter.object_id if logger.formatter.is_a?(Proc)
+      if logger.is_a?(TaggedLogging)
+        logger.clone
       else
-        # Ensure we set a default formatter so we aren't extending nil!
-        logger.formatter = ActiveSupport::Logger::SimpleFormatter.new
+        logger.extend(TaggedLogging)
       end
+    end
+
+    def self.extended(base)
+      base.tag_processor = TagProcessor.new
+      base.extend(ActiveSupport::LogProcessor)
 
-      logger.formatter.extend Formatter
-      logger.extend(self)
+      base.processors << base.tag_processor
     end
 
-    delegate :push_tags, :pop_tags, :clear_tags!, to: :formatter
+    def initialize_clone(_)
+      self.tag_processor = TagProcessor.new
+      self.processors = [tag_processor]
+
+      super
+    end
+
+    delegate :push_tags, :pop_tags, :clear_tags!, to: :tag_processor
+    attr_accessor :tag_processor
 
     def tagged(*tags)
       if block_given?
-        formatter.tagged(*tags) { yield self }
+        tag_processor.tagged(*tags) { yield(self) }
       else
-        logger = ActiveSupport::TaggedLogging.new(self)
-        logger.formatter.extend LocalTagStorage
-        logger.push_tags(*formatter.current_tags, *tags)
+        logger = clone
+        logger.tag_processor.extend(LocalTagStorage)
+        logger.tag_processor.push_tags(*tag_processor.current_tags, *tags)
+
         logger
       end
     end