[
https://issues.apache.org/jira/browse/LOG4J2-3195?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Jean-Luc VANNIERE updated LOG4J2-3195:
--------------------------------------
Description:
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}2021-11-22 19:32:09.535+0100{color} INFO
com.calypso.log.timezone.TestTZ (thread1) After TimeZone Switch
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 either not recording the timezone when no timezone is given
to the logging, either providing an adapter which extends TimeZone and
delegates systematically to the current default timezone (as bellow in
DatePatternConverter). That way the date formatter would always use the current
default time zone.
{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}
was:
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}2021-11-22 19:32:09.535{color:#de350b}+0100{color}{color} INFO
com.calypso.log.timezone.TestTZ (thread1) After TimeZone Switch
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}
> 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
> Priority: Major
>
> 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}2021-11-22 19:32:09.535+0100{color} INFO
> com.calypso.log.timezone.TestTZ (thread1) After TimeZone Switch
> 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 either not recording the timezone when no timezone is
> given to the logging, either providing an adapter which extends TimeZone and
> delegates systematically to the current default timezone (as bellow in
> DatePatternConverter). That way the date formatter would always use the
> current default time zone.
> {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)
