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

ActiveSupport::BroadcastLogger does not respect config.log_level in Rails 7.1 #50324

Closed
ghiculescu opened this issue Dec 11, 2023 · 4 comments · Fixed by #50337
Closed

ActiveSupport::BroadcastLogger does not respect config.log_level in Rails 7.1 #50324

ghiculescu opened this issue Dec 11, 2023 · 4 comments · Fixed by #50337

Comments

@ghiculescu
Copy link
Member

ghiculescu commented Dec 11, 2023

I am working on upgrading an app from Rails 7 to 7.1 and onto edge. I've come across an issue that I think is a bug, but could also be configuration not being used as intended.

Rails 7 config:

# config/application.rb
config.logger = Logist::Logger.new($stdout)
other_logger = AnotherLogger.new

config.logger.extend(ActiveSupport::Logger.broadcast(other_logger))

config.log_level = :info if Rails.env.production?

With this config, Rails.logger.debug does nothing in production. 🟢

The Rails 7 config relied on the private API described in #48615, so we have to refactor it for 7.1. 7.1/Edge Rails config:

# config/application.rb
config.logger = Logist::Logger.new($stdout)
other_logger = AnotherLogger.new

config.logger = ActiveSupport::BroadcastLogger.new(config.logger, other_logger)

config.log_level = :info if Rails.env.production?

With this config, Rails.logger.debug logs in production. 🔴

I think the issue comes from #49721, since the log_level is no longer being assigned to the broadcast loggers. I would expect config.log_level to work for whatever you assign config.logger too, and if that's changing it seems like a breaking change to me.

Is the expectation that if you use BroadcastLogger, you set the level manually on loggers?

cc @Edouard-chin @andrewn617 @rafaelfranca

System configuration

Rails version: main

Ruby version: 3.2

@Edouard-chin
Copy link
Member

Edouard-chin commented Dec 11, 2023

👋

I think the real issue is the log_level config being set to :debug by default which shouldn't apply when a broadcast is configured:

In Rails 7, if you had configured a broadcast with different logger levels, this would have had to be done inside an initializer after Rails' initialize_logger one, otherwise the level on your broadcast would be changed to the default DEBUG value.

Rails.logger.level = ActiveSupport::Logger.const_get(config.log_level.to_s.upcase)

I agree with you that config.log_level being ignored seems off, so I think the behaviour that would make the most sense is:

  • Ignore the default DEBUG log_level when using a Broadcast Logger
  • Set the whole broadcast level when log_level= is explicitly called

@ghiculescu
Copy link
Member Author

ghiculescu commented Dec 11, 2023

Thanks for thinking it through with me @Edouard-chin

I'm not sure about this:

Ignore the default DEBUG log_level when using a Broadcast Logger

If you don't set a log_level, then your broadcast loggers need a level, right? So either you've set one manually on them (which overrides the DEBUG default), or you haven't (so you should get the DEBUG default).

My opinion is we just need this:

Set the whole broadcast level when log_level= is explicitly called

Although as I write that, I realise that is at odds with the issue described by #49721 🤔 (And I think even if we ignored the DEBUG default it still would be.)


Proposing we take #49721 off 7-1-stable while this gets sorted out: #50329

@Edouard-chin
Copy link
Member

Edouard-chin commented Dec 12, 2023

So either you've set one manually on them (which overrides the DEBUG default)

The default log_level had precedence and was overriding the whole broadcasts, e.g.

# config/application.rb

stdout = Logger.new(STDOUT, level: Logger::INFO)
stderr = Logger.new(STDERR, level: Logger::ERROR)
config.logger = ActiveSupport::BroadcastLogger.new(stdout, stderr)

# After the app boots
puts Rails.logger.broadcasts.map(&:level) # => [Logger::DEBUG, Logger::DEBUG]

Although as I write that, I realise that is at odds with the issue described by #49721

That's true, but if an application sets a broadcast logger with various levels and then explicitly calls config.log_level=, then it's a configuration error at the application level, not a bug in Rails.

I believe #49721 was originally opened to fix the issue in my first snippet, with the side effect that it's now completely ignoring Rails' log_level.


I don't think it's worth reverting #49721. I can open a fix today (hopefully my rationale makes sense 😅).

Edouard-chin added a commit to Edouard-chin/rails that referenced this issue Dec 12, 2023
Fix `config.log_level` being ignored when using a Broadcast Logger:

- ### Problem

  If an application has configured a Broadcast Logger, setting the
  `config.log_level` to any value has no effect:

  ```ruby
  # config/application.rb

  config.logger = ActiveSupport::BroadcastLogger.new(Logger.new(STDOUT))
  config.log_level = :warn

  puts Rails.logger.broadcasts.map(&:level) # => [Logger::DEBUG]
  ```

  This is a side effect of rails#49621 which tried to fix the `log_level`
  default value overriding the whole broadcasts.

  ### Context

  The `log_level` default's value shouldn't apply to a Broadcast
  Logger, as otherwise it overrides whatever the application
  previously configured. While this behaviour is the same with
  a vanilla logger, at least we can workaround it:

  ```ruby
  # When using a vanilla logger

  config.logger = Logger.new(STDOUT, level: LOGGER::WARN)
  # Once the app boots, the level is overriden to DEBUG. We need to add the following line.
  config.log_level = :warn

  # When using a broadcast logger

  stdout = Logger.new(STDOUT, level: Logger::INFO)
  stderr = Logger.new(STDERR, level: Logger::ERROR)
  config.logger = ActiveSupport::BroadcastLogger(stdout, stderr)

  # Once the app boots the whole broadcast level is overriden to DEBUG.
  # There is no way to workaround this as you can't fine grain the level of each
  # loggers with `config.log_level=`.
  ```

  ### Solution

  This PR ignores the default `log_level` value when using a Broadcast Logger,
  but ensure it gets used if an application manually sets it.

  Fix rails#50324
Edouard-chin added a commit to Edouard-chin/rails that referenced this issue Dec 12, 2023
- ### Problem

  If an application has configured a Broadcast Logger, setting the
  `config.log_level` to any value has no effect:

  ```ruby
  # config/application.rb

  config.logger = ActiveSupport::BroadcastLogger.new(Logger.new(STDOUT))
  config.log_level = :warn

  puts Rails.logger.broadcasts.map(&:level) # => [Logger::DEBUG]
  ```

  This is a side effect of rails#49621 which tried to fix the `log_level`
  default value overriding the whole broadcasts.

  ### Context

  The `log_level` default's value shouldn't apply to a Broadcast
  Logger, as otherwise it overrides whatever the application
  previously configured. While this behaviour is the same with
  a vanilla logger, at least we can workaround it:

  ```ruby
  # When using a vanilla logger

  config.logger = Logger.new(STDOUT, level: LOGGER::WARN)
  # Once the app boots, the level is overriden to DEBUG. We need to add the following line.
  config.log_level = :warn

  # When using a broadcast logger

  stdout = Logger.new(STDOUT, level: Logger::INFO)
  stderr = Logger.new(STDERR, level: Logger::ERROR)
  config.logger = ActiveSupport::BroadcastLogger(stdout, stderr)

  # Once the app boots the whole broadcast level is overriden to DEBUG.
  # There is no way to workaround this as you can't fine grain the level of each
  # loggers with `config.log_level=`.
  ```

  ### Solution

  This PR ignores the default `log_level` value when using a Broadcast Logger,
  but ensure it gets used if an application manually sets it.

  Fix rails#50324
@ghiculescu
Copy link
Member Author

Thanks for your help, makes total sense to me.

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.

2 participants