Jean-Luc VANNIERE created LOG4J2-3195:
-----------------------------------------
Summary: Discrepancy between threads upon default timezone
changing.
Key: LOG4J2-3195
URL: https://issues.apache.org/jira/browse/LOG4J2-3195
Project: Log4j 2
Issue Type: Bug
Components: Appenders
Affects Versions: 2.13.3
Reporter: Jean-Luc VANNIERE
Let's consider the following use case:
* Start a process with the following layout in the console appender
(<PatternLayout pattern="{*}%d\{yyyy-MM-dd HH:mm:ss.SSSZ}{*} %-5p %c (%t)
%m%n"/>
* Initialize the logs in a given timezone (eg: Europe/Paris so GMT+0100)
* Log something in a thread #1,
{color:#0747a6}logger.info("Before TimeZone switch") --> {color}
{color:#0747a6}2021-11-22 19:32:09.533+0100 INFO
com.calypso.log.timezone.TestTZ (thread1) Before TimeZone Switch{color}
* Change the defaut timezone (eg to America/New_York so GMT-0500)
* Log something in another thread #2 which has never log so far
{color:#0747a6}logger.info("After TimeZone switch") --> {color}
{color:#0747a6}2021-11-22 13:32:09.534-0500 INFO
com.calypso.log.timezone.TestTZ (thread2) After TimeZone Switch{color}
* Log something in thread #1
{color:#0747a6}logger.info("After TimeZone switch") --> {color}
{color:#0747a6}{color:#de350b}2021-11-22 19:32:09.535+0100{color} INFO
com.calypso.log.timezone.TestTZ (thread1) After TimeZone Switch{color}
Thread #1, and any other thread that has logged before the default TimeZone
switch, will continue to log in the previous time zone.
Thread #2 (and any other thread that has not logged priror to the time zone
switch), will log in the new time zone.
And some of our customers are complaining about this discrepancy which cause
their logs to switch constantly between 2 time zones.
The root cause of this issue is due to the fact that (in
DatePatternConverter.formatWithoutAllocation()) the DatePatternConverter
records the formatter into a thread-local and this formatter contains the
timezone at the moment of its creation. In other words, the first time the
thread logs, it creates the formatter with the current timezone and records it
into a thread local storage for further reuse. The problem is that if the
default timezone change afterwards this latest is ignored by the thread.
A solution would be to avoid recording the timezone when no timezone is given
to the logging, to provide an adapter extending TimeZone and delegating
systematically to the current default timezone (as bellow in
DatePatternConverter)
{code:java}
private static Formatter createNonFixedFormatter(final String[] options) {
....
// if the option list contains a TZ option, then set it.
TimeZone tz = null;
if (options.length > 1 && options[1] != null) {
tz = TimeZone.getTimeZone(options[1]);
}
else {
tz = new TimeZoneAdapter(); // set tz to adapter
}
{code}
--
This message was sent by Atlassian Jira
(v8.20.1#820001)
