You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@logging.apache.org by "Piotr P. Karwasz" <pi...@gmail.com> on 2022/06/06 06:36:36 UTC

LogManager.getContext(true)

Hi all,

While working on test parallelisation, I was looking for the existent
mechanisms to bind a logger context to a thread. That is easily
provided by `ContextAnchor.THREAD_CONTEXT` which can be accessed by
`LogManager.getContext()/LogManager.getContext(true)`.

However I am not sure what is the exact semantics of the
`LogManager.getContext(boolean)` call:

 * the BasicContextSelector always returns a thread-bound context,
even if the parameter is `false`,
 * the ClassLoaderContextSelector only does it if called with `true`
and if no thread bound context is found it returns a default context
(which is almost certainly not what the caller wants).

Would it be correct to modify the behavior of these selectors to:

 1. if called with `currentContext == false` apply the selector's
logic. I believe that the `BasicContextSelector` should always return
the same context in this case,
 2. if called with `currentContext == true` return a thread bound
context and fall back to `currentContext == false` if no context is
present. This would require a modification for the
`ClassLoaderContextSelector`.

Piotr

Re: LogManager.getContext(true)

Posted by "Piotr P. Karwasz" <pi...@gmail.com>.
Hi all,

On Tue, 7 Jun 2022 at 20:22, Matt Sicker <bo...@gmail.com> wrote:
> For the record, I like Piotr's idea on repurposing this parameter to
> allow for better caching of LoggerContext in the anchor spot. This
> should help with some test parallelization efforts we're working on.

I believe this can help in more than just test parallelisation. Most
frameworks I have worked with have some kind of thread bound context,
e.g. Spring's `RequestContextHolder` or Vaadin's `UI.getCurrent()` and
similar. These are usually propagated during async calls by the
framework or the developer that makes the call. If you can create a
custom context selector that uses the external thread bound context to
retrieve the appropriate `LoggerContext`, async calls will go
smoothly.

However that is only true for the async calls that the
framework/developer is aware of. Log4j2 should take care of
propagating the `LoggerContext` along its internal async calls. I
believe that enforcing a "get thread bound context or usual selector
logic" policy on context selectors could solve this problem.

As far as I can see the implications of this change would be:

1. `BasicContextSelector` called with `currentContext = false` will
always give a common logger context. This is in line with what we
describe in [1], while the threadlocal behavior is only documented in
[2]. I think this can be considered an internal change.
2. `log4j-web` + `BasicContextSelector` could break, since `log4j-web`
sets the current context and `LogManager.getContext(false)` retrieves
it anyway.

Piotr

[1] https://logging.apache.org/log4j/2.x/manual/logsep.html
[2] https://logging.apache.org/log4j/2.x/manual/extending.html

Re: LogManager.getContext(true)

Posted by Matt Sicker <bo...@gmail.com>.
For the record, I like Piotr's idea on repurposing this parameter to
allow for better caching of LoggerContext in the anchor spot. This
should help with some test parallelization efforts we're working on.

On Mon, Jun 6, 2022 at 1:36 AM Piotr P. Karwasz <pi...@gmail.com> wrote:
>
> Hi all,
>
> While working on test parallelisation, I was looking for the existent
> mechanisms to bind a logger context to a thread. That is easily
> provided by `ContextAnchor.THREAD_CONTEXT` which can be accessed by
> `LogManager.getContext()/LogManager.getContext(true)`.
>
> However I am not sure what is the exact semantics of the
> `LogManager.getContext(boolean)` call:
>
>  * the BasicContextSelector always returns a thread-bound context,
> even if the parameter is `false`,
>  * the ClassLoaderContextSelector only does it if called with `true`
> and if no thread bound context is found it returns a default context
> (which is almost certainly not what the caller wants).
>
> Would it be correct to modify the behavior of these selectors to:
>
>  1. if called with `currentContext == false` apply the selector's
> logic. I believe that the `BasicContextSelector` should always return
> the same context in this case,
>  2. if called with `currentContext == true` return a thread bound
> context and fall back to `currentContext == false` if no context is
> present. This would require a modification for the
> `ClassLoaderContextSelector`.
>
> Piotr

Re: LogManager.getContext(true)

Posted by "Piotr P. Karwasz" <pi...@gmail.com>.
Hi Ralph,

On Tue, 7 Jun 2022 at 22:31, Ralph Goers <ra...@dslextreme.com> wrote:
> You do not want to point the external context to JUnit’s ExtensionContext. Instead,
> you should add it as a key to the externalMap.

Why is that? Does `getExternalContext` have a special meaning or is it obsolete?

I don't fully understand which kinds of objects should end up in the
external map. For example each LoggerContext would benefit from its
own copy of PropertiesUtil, so that different logger contexts can have
different sets of properties. However I am not sure if I can add it to
the external map. This seems to me reserved to largely understood
contexts (servlet, JUnit, JSP, Spring) that use the logger context. Am
I wrong?

Piotr

Re: LogManager.getContext(true)

Posted by Ralph Goers <ra...@dslextreme.com>.
I would think we would want to use some sort of JunitContextSelector and modify 
PropertiesUtil so that JUnit can provide the SystemProperties.

You do not want to point the external context to JUnit’s ExtensionContext. Instead, 
you should add it as a key to the externalMap.

Ralph

> On Jun 7, 2022, at 12:27 PM, Piotr P. Karwasz <pi...@gmail.com> wrote:
> 
> Hi Volcan,
> 
> On Tue, 7 Jun 2022 at 21:04, Volkan Yazıcı <vo...@yazi.ci> wrote:
>> Piotr, thanks so much for sparing time for test parallelization. Is there
>> anything else we can do rather than thread-local `LoggerContext`s? Can't we
>> configure a `ContextSelector` for tests such that it will attach the
>> `LoggerContext`s to the lifetime of a test?
> 
> From my perspective the problem is not the `LoggerContext` itself that
> can be injected as a parameter in a JUnit5 test, but the
> `PropertiesUtil` calls used by many Log4j2 components.
> 
> The `PropertiesUtil` object in release 2.x is global, so I need to use
> `ThreadLocal`s to replace the system properties source that is usually
> used. The implementation of `TestPropertySource` I provided in [1]
> partially works, but it fails if the test creates new threads and
> calls `PropertiesUtil` from there. For example
> HttpThreadContextMapFilterTest[2] will check if JNDI is allowed in a
> new thread.
> 
> The most proper solution I could think of is to bind the
> `LoggerContext` to the thread and enhance all Log4j2 executors to
> propagate the current context. If I set the `LoggerContext`'s external
> context to JUnit5 `ExtensionContext`, I can easily implement a
> properties source that is restricted to the currently running test, no
> matter how many thread the test uses.
> 
> Piotr
> 
> [1] https://github.com/apache/logging-log4j2/pull/916
> [2] https://github.com/apache/logging-log4j2/blob/release-2.x/log4j-core/src/test/java/org/apache/logging/log4j/core/filter/HttpThreadContextMapFilterTest.java


Re: LogManager.getContext(true)

Posted by "Piotr P. Karwasz" <pi...@gmail.com>.
Hi Volcan,

On Tue, 7 Jun 2022 at 21:04, Volkan Yazıcı <vo...@yazi.ci> wrote:
> Piotr, thanks so much for sparing time for test parallelization. Is there
> anything else we can do rather than thread-local `LoggerContext`s? Can't we
> configure a `ContextSelector` for tests such that it will attach the
> `LoggerContext`s to the lifetime of a test?

From my perspective the problem is not the `LoggerContext` itself that
can be injected as a parameter in a JUnit5 test, but the
`PropertiesUtil` calls used by many Log4j2 components.

The `PropertiesUtil` object in release 2.x is global, so I need to use
`ThreadLocal`s to replace the system properties source that is usually
used. The implementation of `TestPropertySource` I provided in [1]
partially works, but it fails if the test creates new threads and
calls `PropertiesUtil` from there. For example
HttpThreadContextMapFilterTest[2] will check if JNDI is allowed in a
new thread.

The most proper solution I could think of is to bind the
`LoggerContext` to the thread and enhance all Log4j2 executors to
propagate the current context. If I set the `LoggerContext`'s external
context to JUnit5 `ExtensionContext`, I can easily implement a
properties source that is restricted to the currently running test, no
matter how many thread the test uses.

Piotr

[1] https://github.com/apache/logging-log4j2/pull/916
[2] https://github.com/apache/logging-log4j2/blob/release-2.x/log4j-core/src/test/java/org/apache/logging/log4j/core/filter/HttpThreadContextMapFilterTest.java

Re: LogManager.getContext(true)

Posted by Volkan Yazıcı <vo...@yazi.ci>.
I have the impression that the purpose of `currentContext` is already
ambiguous and it is not clearly implemented, if not already bloated. I am
not sure repurposing this would be a good idea. This said, I am far from
being an expert in that area.

Piotr, thanks so much for sparing time for test parallelization. Is there
anything else we can do rather than thread-local `LoggerContext`s? Can't we
configure a `ContextSelector` for tests such that it will attach the
`LoggerContext`s to the lifetime of a test?

On Mon, Jun 6, 2022 at 8:36 AM Piotr P. Karwasz <pi...@gmail.com>
wrote:

> Hi all,
>
> While working on test parallelisation, I was looking for the existent
> mechanisms to bind a logger context to a thread. That is easily
> provided by `ContextAnchor.THREAD_CONTEXT` which can be accessed by
> `LogManager.getContext()/LogManager.getContext(true)`.
>
> However I am not sure what is the exact semantics of the
> `LogManager.getContext(boolean)` call:
>
>  * the BasicContextSelector always returns a thread-bound context,
> even if the parameter is `false`,
>  * the ClassLoaderContextSelector only does it if called with `true`
> and if no thread bound context is found it returns a default context
> (which is almost certainly not what the caller wants).
>
> Would it be correct to modify the behavior of these selectors to:
>
>  1. if called with `currentContext == false` apply the selector's
> logic. I believe that the `BasicContextSelector` should always return
> the same context in this case,
>  2. if called with `currentContext == true` return a thread bound
> context and fall back to `currentContext == false` if no context is
> present. This would require a modification for the
> `ClassLoaderContextSelector`.
>
> Piotr
>