You are viewing a plain text version of this content. The canonical link for it is here.
Posted to log4j-user@logging.apache.org by Stig Døssing <st...@crowdstrike.com.INVALID> on 2022/11/18 10:03:09 UTC
PatternLayout caching system property lookup values
Hi,
I’m seeing some unfortunate caching or substitution behavior when using system property lookups in a PatternLayout. I’m using a system property lookup to inject some application-specific context into all my log lines. The context is not available when the logging system is initialized, but is set later.
The layout I’m using is similar to this: <PatternLayout pattern="${sys:testProperty} %m%n"/>.
What I’m seeing is that if I initialize the logging system before “testProperty” has a value, then the placeholder is put into the Layout in the appender. This causes Log4j to look up the system property every time an event is logged. Logging a few lines, I get something like this:
${sys:testProperty} System property not yet set
firstValue System property set to first value
secondValue System property set to second value
As you can see, the placeholder is left in the line logged before the property is set, but Log4j looks up the value for each event, so changes to the system property are reflected.
What I’d like to be able to do is set a default value to use for lines up until the property is set. This does not appear to be workable though. If I either set the system property to some value before initializing the logging system, or I set a default in the pattern like ${sys:testProperty:-default}, log4j reacts by replacing the placeholder in the Layout by the default value. The effect is that the default value becomes permanent, and logs stop changing based on the system property value.
default System property not yet set
default System property set to first value
default System property set to second value
Is there a way to disable this “permanent substitution” and get log4j to do the system property lookup for every log event, even if there is a default value? If not, should there be? System properties can be changed from inside the application, so it seems strange to assume that if a system property has a value during logging init, it will keep that same value permanently.
I’ve uploaded a reproducer here https://github.com/srdo-humio/log4j-sys-lookup-cache-repro.
Re: PatternLayout caching system property lookup values
Posted by Stig Døssing <st...@crowdstrike.com.INVALID>.
Thanks for your responses. They both resolve the issue I had.
On 18/11/2022, 16.48, "Piotr P. Karwasz" <pi...@gmail.com> wrote:
Hi Stig,
On Fri, 18 Nov 2022 at 11:03, Stig Døssing
<st...@crowdstrike.com.invalid> wrote:
> Is there a way to disable this “permanent substitution” and get log4j to do the system property lookup for every log event, even if there is a default value? If not, should there be? System properties can be changed from inside the application, so it seems strange to assume that if a system property has a value during logging init, it will keep that same value permanently.
The `${...}` placeholders are replaced at configure time. If no value
is available, they are left as is (this is IMHO a bug).
If you want to evaluate the lookup at each logging event, just escape
the dollar sign: `$${sys:testProperty}`. At configuration time one
dollar sign will be stripped, so that the lookup will be performed at
every logging event.
Piotr
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-user-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-user-help@logging.apache.org
Re: PatternLayout caching system property lookup values
Posted by "Piotr P. Karwasz" <pi...@gmail.com>.
Hi Stig,
On Fri, 18 Nov 2022 at 11:03, Stig Døssing
<st...@crowdstrike.com.invalid> wrote:
> Is there a way to disable this “permanent substitution” and get log4j to do the system property lookup for every log event, even if there is a default value? If not, should there be? System properties can be changed from inside the application, so it seems strange to assume that if a system property has a value during logging init, it will keep that same value permanently.
The `${...}` placeholders are replaced at configure time. If no value
is available, they are left as is (this is IMHO a bug).
If you want to evaluate the lookup at each logging event, just escape
the dollar sign: `$${sys:testProperty}`. At configuration time one
dollar sign will be stripped, so that the lookup will be performed at
every logging event.
Piotr
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-user-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-user-help@logging.apache.org
Re: PatternLayout caching system property lookup values
Posted by Volkan Yazıcı <vo...@yazi.ci>.
Hey Stig,
I see the problem and I don't know of a way to disable the substitution
performed at "pattern compile-time", which is possibly there due to
efficiency reasons. Others might have a better idea, though, given you try
to glue a business logic via lookups, what you can also do is to implement
your own either `StrLookup` or (preferably) `LogEventPatternConverter`. The
latter is pretty easy and efficient, check ThreadNamePatternConverter
<https://github.com/apache/logging-log4j2/blob/470ac2cf2472580fe20e7cf4c2e6b5f0618e4da6/log4j-core/src/main/java/org/apache/logging/log4j/core/pattern/ThreadNamePatternConverter.java>
for some inspiration. Having such a `LogEventPatternConverter` class in
your class path and using it via one of its `@ConverterKeys` in your
pattern would suffice.
Kind regards.
On Fri, Nov 18, 2022 at 11:03 AM Stig Døssing
<st...@crowdstrike.com.invalid> wrote:
> Hi,
>
> I’m seeing some unfortunate caching or substitution behavior when using
> system property lookups in a PatternLayout. I’m using a system property
> lookup to inject some application-specific context into all my log lines.
> The context is not available when the logging system is initialized, but is
> set later.
>
> The layout I’m using is similar to this: <PatternLayout
> pattern="${sys:testProperty} %m%n"/>.
>
> What I’m seeing is that if I initialize the logging system before
> “testProperty” has a value, then the placeholder is put into the Layout in
> the appender. This causes Log4j to look up the system property every time
> an event is logged. Logging a few lines, I get something like this:
>
> ${sys:testProperty} System property not yet set
> firstValue System property set to first value
> secondValue System property set to second value
>
> As you can see, the placeholder is left in the line logged before the
> property is set, but Log4j looks up the value for each event, so changes to
> the system property are reflected.
>
> What I’d like to be able to do is set a default value to use for lines up
> until the property is set. This does not appear to be workable though. If I
> either set the system property to some value before initializing the
> logging system, or I set a default in the pattern like
> ${sys:testProperty:-default}, log4j reacts by replacing the placeholder in
> the Layout by the default value. The effect is that the default value
> becomes permanent, and logs stop changing based on the system property
> value.
>
> default System property not yet set
> default System property set to first value
> default System property set to second value
>
> Is there a way to disable this “permanent substitution” and get log4j to
> do the system property lookup for every log event, even if there is a
> default value? If not, should there be? System properties can be changed
> from inside the application, so it seems strange to assume that if a system
> property has a value during logging init, it will keep that same value
> permanently.
>
> I’ve uploaded a reproducer here
> https://github.com/srdo-humio/log4j-sys-lookup-cache-repro.
>