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
Bug when broadcasting TaggedLogging(without a block) loggers. #45854
Labels
Comments
Edouard-chin
added a commit
to Edouard-chin/rails
that referenced
this issue
Jun 29, 2023
Edouard-chin
added a commit
to Edouard-chin/rails
that referenced
this issue
Jul 3, 2023
- Opening this PR to get some first impression and feedback and see if that’s the path we want to take. ## Context While working on rails#44695, I realised that Broadcasting was still a private API, although it’s commonly used. Rafael mentioned that making it public would require some refactor because of the original implementation which was hard to understand and maintain. TaggedLogging is another piece of this PR, while it’s not related to broadcasting, both features combined were a source of issues and confusion (see rails#38850, rails#27792, rails#45854 and some more). Broadcasting and tagged logging were a bit entangled and I felt it would be easier to have the bigger picture in a single PR. TaggedLogging is public and the new implementation doesn’t introduce any breaking change. Broadcasting is in a grey zone, it’s not referenced in our docs but I saw it often in apps and libraries. This refactor would break them. Happy to revisit that and find a way to make it compatible. ## Implementation The changes would make a lot of diff chunks, so to make it easier to review I opted to not modify the original files and free the constant name (Logger, TaggedLogging) for the new implementation that are inside new files. All code in this PR is new and uses code from the previous implementation that don’t appear in the diff. The goal would be to copy/paste the required code at the end of the review process. --------------- ### Changing how broadcasting works: Broadcasting in a nutshell worked by “transforming” an existing logger into a broadcasted one. The logger would then be responsible to log and format its own messages as well as passing the message along to other logger it broadcasts to. The problem with this approach was the following: - Heavy use of metaprogramming. - Accessing the loggers in the broadcast wasn’t possible. Removing a logger from the broadcast either. - More importantly, modifying the main logger (the one that broadcasts logs to the others) wasn’t possible and the main source of misunderstanding. ```ruby logger = Logger.new(STDOUT) stderr_logger = Logger.new(STDER)) logger.extend(AS::Logger.broadcast(stderr_logger)) logger.level = DEBUG # This modifies the level on all other loggers logger.formatter = … # Modified the formatter on all other loggers ``` -> New approach To keep the contract unchanged on what Rails.logger returns, the new implementation is still a subclass of Logger. The difference is that now the broadcast logger just delegate al methods to all the other loggers it’s broadcasting to. It’s simple and boring and it’s now just an array that gets iterated over. Now, users can access all loggers inside the broadcast and modify them on the fly. They can also remove any logger from the broadcast at any time. ```ruby # Before stdout_logger = Logger.new(STDOUT) stderr_logger = Logger.new(STDER) file_logger = Logger.new(“development.log”) stdout_logger.extend(AS::Logger.broadcast(stderr_logger)) stdout_logger.extend(AS::Logger.broadcast(file_logger)) # After broadcast = BroadcastLogger.new broadcast.broadcast_to(stdout_logger, stderr_logger, file_logger) ``` I also think that now, it should be more clear for users that the broadcast sole job is to pass everything to the whole loggers in the broadcast. So there should be no surprise that all loggers in the broadcast get their level modified when they call `broadcast.level = DEBUG` . It’s also easier to wrap your head around more complex setup such as broadcasting logs to another broadcast: `broadcast.broadcast_to(stdout_logger, other_broadcast)` ### Changing TaggedLogging Tagged logging is painful to implement because there is basically no good way to hook into the vanilla logger code. The easiest is to hook on the formatter but IMHO this is implemented at the wrong level. Adding tags on the formatter means: - Monkeypatching the formatter on the logger. With the broadcasting feature, that meant modifying all formatters on all loggers. - From its name, I would assume that a formatter job is just to format. Not add modify the logs and add extra information. What I felt was missing was an object responsible to process the logs just before it gets formatted. So I implemented a “LogProcessor” which seats just after the user pass a log, but before it gets formatted. I thought it is a good addition that would allow to have multiple processors in the case users or libraries need to pass their logs into multiple processors.
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Steps to reproduce
Expected behavior
Actual behavior
If
#tagged
is used without blocking, the tag is incorrectly referenced in the broadcast destination logger.I think it is a bug related to #44695.
When the formatter of the logger that originated the broadcast is updated, the reference to the tag to which the broadcast is directed is switched.
rails/activesupport/lib/active_support/tagged_logging.rb
Lines 99 to 107 in 04972d9
without block
#tagged
creates a temporary logger, in which case the formatter is updated.rails/activesupport/lib/active_support/tagged_logging.rb
Line 116 in 04972d9
rails/activesupport/lib/active_support/tagged_logging.rb
Lines 85 to 90 in 04972d9
As a result, it appears that tags applied to temporary loggers are subsequently referenced in the broadcast destination loggers.
supplementary information
The standard output of logs at rails server startup in the development environment is implemented in broadcast.
Therefore, there may be differences in log output between standard output and
log/develooment.log
.rails/railties/lib/rails/commands/server/server_command.rb
Lines 75 to 85 in 3d84e12
System configuration
Rails version: 7.0.2.3
Ruby version: 3.1.1
The text was updated successfully, but these errors were encountered: