Re: Context data propagation and logger-bound context data
Hi Ralph,
On Tue, 19 Mar 2024 at 07:45, Ralph Goers wrote:
> 2. The links you provide describe the problem of passing contexts to threads
> magnificently. Unfortunately, they solve it by requiring you NOT to use
> standard JDK tooling for managing threads. I am not prepared to be dependent
> on any specific framework other than the JDK.
> ...
> 3. As I stated, I am not prepared to provide a solution that is dependent on
> another framework. However that framework is welcome to integrate with us.
I would propose to meet those libraries half-way:
* we extend our SPI to provide a fast method to copy the contents of
the ThreadLocal used by ThreadContextMap, restore it on another thread
or clear it,
* the `context-propagation` library integrates our newly added SPI.
> 2. As I noted, adding a wrapper around a Logger doesn’t accomplish anything,
> at least in terms of getting data into LogEvents.
The wrapper could do something like:
public void info(String message) {
if (logger.isEnabled(null, Level.INFO, message)) {
try (CloseableThreadContext.Instance ignored =
CloseableThreadContext.putAll(context)) {
logger.info(message);
}
}
}
using only Log4j API. Log4j Core could do better of course.
> SLF4J has recently introduced
> https://www.slf4j.org/apidocs-2.1.0-alpha0/org.slf4j/org/slf4j/MDCAmbit.html
> which to me looks like a horrible way to add a “scope-based” context as it
> relies on the user to perform cleanup.
This is a horrible workaround of the way "try-with-resources" work,
when "catch" clauses are also present. Since the resource is closed
**before** the "catch" code is executed, the new context keys are no
longer available in the "catch" clauses.
> Java 21 introduces ScopedValues -
> https://docs.oracle.com/en/java/javase/21/docs/api/java.base/java/lang/ScopedValue.html.
> It does allow ScopedValues to be passed to child threads but I haven’t
> experimented with it enough yet to know how it really works.
In the future we will certainly switch to this, but for now I would
keep all usages of `ScopedValue` in an `o.a.l.l.experimental` package,
so that users know that we can remove it any time we want.
Piotr
Re: Context data propagation and logger-bound context data
I agree with the way Piotr dissects the problem. I think `ScopedContext`,
even though it has its own merits, doesn't address the problem reported by
users. They simply want a new logger associated with some additional
context data.
*[See my comments below.]*
On Mon, Mar 18, 2024 at 10:40 AM Piotr P. Karwasz
wrote:
> == Possible solutions
>
> As far as I know there are currently the following approaches we can
> take for problem 1:
>
> * we can add a list of `` elements in the configuration of a
> ``, which will add the given keys to all loggers using that
> configuration. This is something we can do for very static data, e.g.
> we can add to each log statement the name of the library that issued
> it.
I don't like this approach. This is simply a hack, an abuse of a component
designed for totally something else.
> * we can create a `Logger` wrapper "bound" to context data as Mikko
> does. This wrapper will take care of setting the `ThreadContext`
> before the logger call and restore it after it.
Creating a wrapper `Logger` can work without needing to deal with
`ThreadContext`. I can think of two different ways to carry this out:
1. Currently, `AbstractLogger` only creates `Message`s. We can rework it
to create `LogEvent`s too. Once `AbstractLogger` gets its hand on a
`LogEvent`, it can enrich its context data as it wishes.
2. We can extend `ContextDataInjector` with a new `void
injectContextData(Logger logger, StringMap target)` method, provide a
`ContextDataInjector` implementation that branches on `logger instanceof
ContextDataProvider`, and call `ContextDataInjector` with the associated
`Logger` in `LogEventFactory`.
On Tue, Mar 19, 2024 at 7:45 AM Ralph Goers
wrote:
> In the meantime, I provided
https://github.com/apache/logging-log4j2/pull/2385 which I very loosely
modeled after ScopedValues.
The fact that `ScopedContext` tries to imitate `ScopedValue` using
`ThreadLocal`s is extremely confusing (from a user's pov) and risky
liability (from a maintainer's pov). I guess you wanted to implement *a*
`ScopedValue` without using *the* `ScopedValue` to be compatible with Java
8. If so, that really sounds like the `o.a.l.log4j.util.Supplier` downward
spiral. We can rather have an *internal* `Log4jScopedValue` interface and
provide Java 8 (using `InheritableThreadLocal`) and Java 21+ (using
`ScopedValue`) compatible solutions in an MRJ (Multi-Release JAR).
We can integrate `ScopedContext` to the `LogEventFactory` by providing a
specialized `ContextDataInjector` plugin – assuming `LogEventFactory`
employs all available `ContextDataInjector` plugins.
I find the current ceremony also too long:
`ScopedContext.getCurrent().where("key1", "value1").run(...)`. I would
rather aim for `ScopedContext.run(key, value, runnable)` and similar
`ScopedContext.op(..., runnable)` interaction.
I will also drop some other remarks to the PR.
Re: Context data propagation and logger-bound context data
1. I am experimenting with adding Thread support to ScopedContext as we speak.
It should be straightforward.
I am not sure we ever want to deal with ScopedValue. ScopedContext provides the
same functionality plus integration with logging.
Ralph
> On Mar 20, 2024, at 4:22 AM, Piotr P. Karwasz wrote:
>
> Hi Ralph,
>
> On Tue, 19 Mar 2024 at 07:45, Ralph Goers wrote:
>> 2. The links you provide describe the problem of passing contexts to threads
>> magnificently. Unfortunately, they solve it by requiring you NOT to use
>> standard JDK tooling for managing threads. I am not prepared to be dependent
>> on any specific framework other than the JDK.
>> ...
>> 3. As I stated, I am not prepared to provide a solution that is dependent on
>> another framework. However that framework is welcome to integrate with us.
>
> I would propose to meet those libraries half-way:
>
> * we extend our SPI to provide a fast method to copy the contents of
> the ThreadLocal used by ThreadContextMap, restore it on another thread
> or clear it,
> * the `context-propagation` library integrates our newly added SPI.
>
>> 2. As I noted, adding a wrapper around a Logger doesn’t accomplish anything,
>> at least in terms of getting data into LogEvents.
>
> The wrapper could do something like:
>
> public void info(String message) {
>if (logger.isEnabled(null, Level.INFO, message)) {
>try (CloseableThreadContext.Instance ignored =
> CloseableThreadContext.putAll(context)) {
>logger.info(message);
>}
>}
> }
>
> using only Log4j API. Log4j Core could do better of course.
>
>> SLF4J has recently introduced
>> https://www.slf4j.org/apidocs-2.1.0-alpha0/org.slf4j/org/slf4j/MDCAmbit.html
>> which to me looks like a horrible way to add a “scope-based” context as it
>> relies on the user to perform cleanup.
>
> This is a horrible workaround of the way "try-with-resources" work,
> when "catch" clauses are also present. Since the resource is closed
> **before** the "catch" code is executed, the new context keys are no
> longer available in the "catch" clauses.
>
>> Java 21 introduces ScopedValues -
>> https://docs.oracle.com/en/java/javase/21/docs/api/java.base/java/lang/ScopedValue.html.
>> It does allow ScopedValues to be passed to child threads but I haven’t
>> experimented with it enough yet to know how it really works.
>
> In the future we will certainly switch to this, but for now I would
> keep all usages of `ScopedValue` in an `o.a.l.l.experimental` package,
> so that users know that we can remove it any time we want.
>
> Piotr
Re: Context data propagation and logger-bound context data
> On Mar 18, 2024, at 2:39 AM, Piotr P. Karwasz wrote: > > Hi, > > Given the ongoing context data propagation in three Github > issues/PRs/discussions (cf. [1], [2] and [3]). I think we should move > the debate to the mailing list, which guarantees the maximal reachout. > > == Problem summary > > We have two different problems regarding context data in log files: > > 1. Raman and Mikko would like to bind context data to an object > implementing the `Logger` interface or more generally to a service > object (e.g. resource manager, DAO and variants), Yes, I’ve seen that. Personally, I am not much of a fan of this use case as it is pretty easy to add the data you want to a single class. That said, we already offer a solution. Allowing a MessageFactory to be provided on a Logger was done for exactly this reason. For example, a User could configure a custom MessageFactory that provides an extension of MapMessage that causes the message to include data from the class or resource. Going to the extreme of trying to shoehorn in Context data as well simply isn’t necessary. > 2. Other users would like to bind context data to a processing > pipeline, regardless of which threads it uses. > ScopedContext covers this use case and is the one I find far more compelling. That is why I am adding support for passing data to Threads to my PR. I will let you know when it is there. Ralph
Re: Context data propagation and logger-bound context data
Unfortunately this is another message I somehow didn't get in my inbox.
Replying to it via lists.a.o is not a great experience but is the best I can do.
On 2024/03/20 13:51:56 Volkan Yazıcı wrote:
> I agree with the way Piotr dissects the problem. I think `ScopedContext`,
> even though it has its own merits, doesn't address the problem reported by
> users. They simply want a new logger associated with some additional
> context data.
Two users do. I have personally been asked for something like ScopedContext
several times.
As I replied to Piotr, we already solved the problem of adding data to Loggers.
That is what MessageFactories are intended for.
>
> *[See my comments below.]*
>
> On Mon, Mar 18, 2024 at 10:40 AM Piotr P. Karwasz
> wrote:
>
> > * we can create a `Logger` wrapper "bound" to context data as Mikko
> > does. This wrapper will take care of setting the `ThreadContext`
> > before the logger call and restore it after it.
>
> Creating a wrapper `Logger` can work without needing to deal with
> `ThreadContext`. I can think of two different ways to carry this out:
>
>1. Currently, `AbstractLogger` only creates `Message`s. We can rework it
>to create `LogEvent`s too. Once `AbstractLogger` gets its hand on a
>`LogEvent`, it can enrich its context data as it wishes.
>2. We can extend `ContextDataInjector` with a new `void
>injectContextData(Logger logger, StringMap target)` method, provide a
>`ContextDataInjector` implementation that branches on `logger instanceof
>ContextDataProvider`, and call `ContextDataInjector` with the associated
>`Logger` in `LogEventFactory`.
We can do lots of things, most of which I wouldn't recommend. As to yours:
1. Logger/AbstractLogger got very complex with Async, Garbage Free, Reliablity
Strategies, etc. Trying to move creating the LogEvent sooner is likely to be a
major PITA and could seriously impact performance. While we could add a context
map to AbstractLogger we would have to pass that on the logging calls to
LoggerConfig and deal with all that that means - remember, a LoggerConfig can
be handling multiple Loggers.
2. I don't recommend extending ContextDataInjector. That proved difficult to
work with which is why we now recommend using ContextDataProviders. You really
can only have one ContextDataInjector. Also, please note that
ContextDataInjector is called while constructing the LogEvent. The LogEvent
isn't passed the Logger, only the LoggerName. Looking up the Logger to do this
is yet another way to slow down logging.
>
> On Tue, Mar 19, 2024 at 7:45 AM Ralph Goers
> wrote:
> > In the meantime, I provided
> https://github.com/apache/logging-log4j2/pull/2385 which I very loosely
> modeled after ScopedValues.
>
> The fact that `ScopedContext` tries to imitate `ScopedValue` using
> `ThreadLocal`s is extremely confusing (from a user's pov) and risky
> liability (from a maintainer's pov). I guess you wanted to implement *a*
> `ScopedValue` without using *the* `ScopedValue` to be compatible with Java
> 8. If so, that really sounds like the `o.a.l.log4j.util.Supplier` downward
> spiral. We can rather have an *internal* `Log4jScopedValue` interface and
> provide Java 8 (using `InheritableThreadLocal`) and Java 21+ (using
> `ScopedValue`) compatible solutions in an MRJ (Multi-Release JAR).
I am NOT trying to make ScopedContext compatible with ScopedValue. I am trying
to make it conceptually close enough to ScopedValue that users will understand
what it is doing.
We can argue about naming if you want. Gary has already expressed his opinion.
>
> We can integrate `ScopedContext` to the `LogEventFactory` by providing a
> specialized `ContextDataInjector` plugin – assuming `LogEventFactory`
> employs all available `ContextDataInjector` plugins.
ScopedContext is integrated with a ContextDataProvider, which is the supported
way to do this. Again, you cannot have more than one ContextDataInjector so
providing "specialized versions" is a pipe dream. You will simply have to
enhance the one we already have. ContextDataInjector is NOT a plugin.
>
> I find the current ceremony also too long:
> `ScopedContext.getCurrent().where("key1", "value1").run(...)`. I would
> rather aim for `ScopedContext.run(key, value, runnable)` and similar
> `ScopedContext.op(..., runnable)` interaction.
Those are going to be provided as well.
Ralph
