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
<stig.doess...@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.
>
