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

BroadcastLogger#tagged without a block returns an array instead of a logger #49757

Open
mroach opened this issue Oct 24, 2023 · 4 comments · May be fixed by #49771
Open

BroadcastLogger#tagged without a block returns an array instead of a logger #49757

mroach opened this issue Oct 24, 2023 · 4 comments · May be fixed by #49771

Comments

@mroach
Copy link

mroach commented Oct 24, 2023

Steps to reproduce

  1. Use BroadcastLogger#broadcast_to(logger) to add a new logger
  2. Use BroadcastLogger#tagged("MyTag") without a block to return a new tagged logger
  3. Try to use that new tagged logger
# frozen_string_literal: true

require "bundler/inline"

gemfile(true) do
  source "https://rubygems.org"

  git_source(:github) { |repo| "https://github.com/#{repo}.git" }

  gem "rails", github: "rails/rails", branch: "main"
  gem "pry"
end

require "active_support"
require "active_support/core_ext/object/blank"
require "minitest/autorun"

class BugTest < Minitest::Test
  def test_broadcast_to_multiple_tagged_loggers
    iologger1 = Logger.new($stdout)
    iologger1 = ActiveSupport::TaggedLogging.new(iologger1)

    logger = ActiveSupport::BroadcastLogger.new(iologger1)

    # This works fine
    logger.tagged("Test1").info("OK")

    iologger2 = Logger.new($stderr)
    iologger2 = ActiveSupport::TaggedLogging.new(iologger2)

    logger.broadcast_to(iologger2)

    # This works fine
    logger.tagged("Test1") { _1.info "OK" }

    # Now we have a problem. `logger.tagged` returns an Array
    # NoMethodError: undefined method `info' for [#<Logger
    #
    # https://github.com/rails/rails/blob/ca5132b78a44677f708045905dc1b092a02f6b30/activesupport/lib/active_support/broadcast_logger.rb#L242
    logger.tagged("Test2").info("OK")

    # We'll never get here, but this fails
    assert logger.is_a?(ActiveSupport::BroadcastLogger)
  end
end

Expected behavior

Using ActiveSupport::BroadcastLogger#tagged without a block returns a tagged logger that can be used for logging as normal.

Actual behavior

When broadcasting to more than one logger that supports tagging, an Array is returned rather than an object that you can log to directly.

The specific use case where this came up: in some tests, I want to capture logs so I can test them. Previously I was replacing Rails.logger entirely, but now I tried adding and removing a broadcast target and I noticed this didn't work.

This appears to be caused by the method_missing implementation:

loggers.map { |logger| logger.send(name, *args, **kwargs, &block) }

System configuration

Rails version: 7.1.1

Ruby version: 3.2.2

@akhilgkrishnan
Copy link
Member

looks like a similar issue of #49745. Need to investigate further more.

@davidstosik
Copy link
Contributor

davidstosik commented Oct 24, 2023

Similar yes. Basically #tagged is broken, with and without a block.
I suggested a work-around in my issue, but honestly, I am not confident with it yet as I haven't been able to run our application with more than one broadcasted logger...

@akhilgkrishnan
Copy link
Member

@Edouard-chin Do you have any thoughts on this issue?

@Edouard-chin
Copy link
Member

Thanks for the ping, I didn't see this issue and David's one. I have a few changes stashed that I originally wrote it to fix an unrelated issue with Broadcasting + Tagged logging, and this should also fix those two issues.

Will open a PR !

@Edouard-chin Edouard-chin self-assigned this Oct 24, 2023
@Edouard-chin Edouard-chin linked a pull request Oct 24, 2023 that will close this issue
Edouard-chin added a commit to Edouard-chin/rails that referenced this issue Oct 25, 2023
- ### 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.
Edouard-chin added a commit to Edouard-chin/rails that referenced this issue Jan 17, 2024
- ### 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.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging a pull request may close this issue.

4 participants