Skip to content

New feature to allow adding extra information to log - #90

Open
Edouard-chin wants to merge 1 commit into
ruby:masterfrom
Edouard-chin:ec-logger-processor
Open

New feature to allow adding extra information to log#90
Edouard-chin wants to merge 1 commit into
ruby:masterfrom
Edouard-chin:ec-logger-processor

Conversation

@Edouard-chin

Copy link
Copy Markdown
Member

Hello, thank you for maintaining this library ❤️ ! I'm opening this PR to propose a new feature:

Context

It's quite common to add extra info to each log messages to make debugging easier. For instance, adding a request ID to trace the request more easily if an exception occurs. Or add user information for various needs.

Right now, the easiest way to implement this is to create a custom formatter.

Problem

I believe formatting the log and adding extra information are two distincts features that should be handled with different objects. Moreover, because libraries or frameworks usually provide this feature, it makes things hard for them to not conflict with each others. As well as conflicting with the potential formatter set by an application. It ends up in a cascade of monkeypatch and doesn't allow much flexibility for the end user.

Solution

I'd like to introduce the concept of a log processor who's interface is similar to the formatter but its responsibility is to only add extra info to the message. More importantly, a logger can have multiple processors, each defining the logic within their scope.

This should allow for a lot more flexibility (applications can now easily re-order processors, remove or add them on the fly, change their formatter afterward without breaking libraries functionalities).

It will also make things easier for libraries and provide a cleaner way to hook into the logger.

This change is fully backward compatible.

Edouard-chin added a commit to Edouard-chin/rails that referenced this pull request 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)`.
Fixrails#49757Fixrails#49745Fixrails#46084Fixrails#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 pull request 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)`.
Fixrails#49757Fixrails#49745Fixrails#46084Fixrails#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 pull request Oct 28, 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)`.
Fixrails#49757Fixrails#49745Fixrails#46084Fixrails#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 pull request Oct 28, 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)`.
Fixrails#49757Fixrails#49745Fixrails#46084Fixrails#44668
I made a propose on the Ruby logger upstream in ruby/logger#90,
but it hasn't been reviewed it.
Comment threadlib/logger.rb Outdated
Comment threadlib/logger.rb Outdated
- ### Context
It's quite common to add extra info to each log messages to make
debugging easier.
For instance, adding a request ID to trace the request more easily
if an exception occurs. Or add user information for various needs.
Right now, the easiest way to implement this is to create a custom
formatter.
### Problem
I believe formatting the log and adding extra information are two
distincts features that should be handled with different objects.
Moreover, because libraries or frameworks usually provide this
feature, it makes things hard for them to not conflict with
each others. As well as conflicting with the potential
formatter set by an application.
It ends up in a cascade of monkeypatch and doesn't allow
much flexibility for the end user.
### Solution
I'd like to introduce the concept of a log processor who's interface
is similar to the formatter but its responsibility is to only
add extra info to the message.
More importantly, a logger can have multiple processors, each
defining the logic within their scope.
This should allow for a lot more flexibility (applications can
now easily re-order processors, remove or add them on the fly,
change their formatter afterward without breaking libraries
functionalities).
It will also make things easier for libraries and provide a cleaner
way to hook into the logger.
This change is fully backward compatible.
@Edouard-chin

Copy link
Copy Markdown
MemberAuthor

Thanks for having a look!

Comment threadlib/logger.rb
Comment on lines +733 to 735
message = process_message(format_severity(severity), Time.now, progname, message)
@logdev.write(
format_message(format_severity(severity), Time.now, progname, message))

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Shouldn't we use the same time?

Suggested change
message=process_message(format_severity(severity),Time.now,progname,message)
@logdev.write(
format_message(format_severity(severity),Time.now,progname,message))
now=Time.now
message=process_message(format_severity(severity),now,progname,message)
@logdev.write(
format_message(format_severity(severity),now,progname,message))

@HoneyryderChuckHoneyryderChuck mentioned this pull request Aug 14, 2025
Sign up for freeto join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants

@Edouard-chin@nobu