[
https://issues.apache.org/jira/browse/LOG4J2-3168?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Markus Ke updated LOG4J2-3168:
------------------------------
Description:
We use log4j2 for logging and have observed the phenomenon that when using
zipping, existing logs are overwritten when rotating logs.
The used LogConfig:
{code:xml}
<Configuration name="base">
<Appenders>
<Console name="console">
<JSONLayout compact="true" eventEol="true" locationInfo="true"/>
</Console>
<RollingFile name="file" append="true">
<fileName>./file.log</fileName>
<filePattern>./file.%d{yyyyMMdd'T'HHmmssZ}.%i.log.zip</filePattern>
<PatternLayout pattern="%d{HH:mm:ss,SSS} [%15.15t] %-5p
%30.30c@%-4L %x - %m%n" />
<Policies>
<OnStartupTriggeringPolicy/>
<SizeBasedTriggeringPolicy size="15 MB" />
</Policies>
<DefaultRolloverStrategy>
<Delete basePath="./">
<IfFileName glob="file.*.log.zip">
<IfLastModified age="7d"/>
</IfFileName>
</Delete>
</DefaultRolloverStrategy>
</RollingFile>
<!-- Just for testing to verify if the log files get lost by zipping
them-->
<RollingFile name="file-unzipped-bug-verification" append="true">
<fileName>./file-fallback.log</fileName>
<filePattern>./file-fallback.%d{yyyyMMdd'T'HHmmssZ}.%i.log</filePattern>
<PatternLayout pattern="%d{HH:mm:ss,SSS} [%15.15t] %-5p
%30.30c@%-4L %x - %m%n" />
<Policies>
<OnStartupTriggeringPolicy/>
<SizeBasedTriggeringPolicy size="15 MB" />
</Policies>
<DefaultRolloverStrategy>
<Delete basePath="./">
<IfFileName glob="./file-fallback.*.log">
<IfLastModified age="7d"/>
</IfFileName>
</Delete>
</DefaultRolloverStrategy>
</RollingFile>
</Appenders>
<Loggers>
<Logger name="org.example.project" level="debug"/>
<Root level="info">
<AppenderRef ref="console" />
<AppenderRef ref="file" />
<AppenderRef ref="file-unzipped-bug-verification" />
</Root>
</Loggers>
</Configuration>
{code}
It turns out that at any point in time, the rotation behavior changes and the
last time stamp of the log is no longer used as the file name, but the first.
This results in the following circumstance:
- file.20210914T144224+0200.1.log
** first line:
{code:java}
13:50:21,789 [lt-executor-194] DEBUG StreamHandler@68 [] - RPC stream
completed{code}
** last line:
{code:java}
14:42:24,974 [D_2400_supply-1] DEBUG ActionDispatcher@291 [] - Waiting at
action ...{code}
- file.20210914T155051+0200.1.log
** first line:
{code:java}
15:50:51,988 [ mc-exe-10] DEBUG ResourceSchedule@215 [] - discarding
MutexReservation{code}
** last line:
{code:java}
16:03:27,839 [ool-58-thread-1] DEBUG Repository@111 [] - Repository@1d41309
changed, publishing updates{code}
Another file between these times does not exist.
We verified this by adding a second appender without zipping, which contained
all logs. The files `./file-fallback.XXXXXXXXX.log` contain all logs
was:
We use log4j2 for logging and have observed the phenomenon that when using
zipping, existing logs are overwritten when rotating logs.
The used LogConfig:
{code:xml}
<Configuration name="base">
<Appenders>
<Console name="console">
<JSONLayout compact="true" eventEol="true" locationInfo="true"/>
</Console>
<RollingFile name="file" append="true">
<fileName>./file.log</fileName>
<filePattern>./file.%d{yyyyMMdd'T'HHmmssZ}.%i.log.zip</filePattern>
<PatternLayout pattern="%d{HH:mm:ss,SSS} [%15.15t] %-5p
%30.30c@%-4L %x - %m%n" />
<Policies>
<OnStartupTriggeringPolicy/>
<SizeBasedTriggeringPolicy size="15 MB" />
</Policies>
<DefaultRolloverStrategy>
<Delete basePath="./">
<IfFileName glob="file.*.log.zip">
<IfLastModified age="7d"/>
</IfFileName>
</Delete>
</DefaultRolloverStrategy>
</RollingFile>
<!-- Just for testing to verify if the log files get lost by zipping
them-->
<RollingFile name="file-unzipped-bug-verification" append="true">
<fileName>./file-fallback.log</fileName>
<filePattern>./file-fallback.%d{yyyyMMdd'T'HHmmssZ}.%i.log</filePattern>
<PatternLayout pattern="%d{HH:mm:ss,SSS} [%15.15t] %-5p
%30.30c@%-4L %x - %m%n" />
<Policies>
<OnStartupTriggeringPolicy/>
<SizeBasedTriggeringPolicy size="15 MB" />
</Policies>
<DefaultRolloverStrategy>
<Delete basePath="./">
<IfFileName glob="./file-fallback.*.log">
<IfLastModified age="7d"/>
</IfFileName>
</Delete>
</DefaultRolloverStrategy>
</RollingFile>
</Appenders>
<Loggers>
<Logger name="org.example.project" level="debug"/>
<Root level="info">
<AppenderRef ref="console" />
<AppenderRef ref="file" />
<AppenderRef ref="file-unzipped-bug-verification" />
</Root>
</Loggers>
</Configuration>
{code}
It turns out that at any point in time, the rotation behavior changes and the
last time stamp of the log is no longer used as the file name, but the first.
This results in the following circumstance:
- file.20210914T144224+0200.1.log
** first line: 13:50:21,789 [lt-executor-194] DEBUG StreamHandler@68 [] - RPC
stream completed
** last line: 14:42:24,974 [D_2400_supply-1] DEBUG ActionDispatcher@291 [] -
Waiting at action ...
- file.20210914T155051+0200.1.log
** first line: 15:50:51,988 [ mc-exe-10] DEBUG ResourceSchedule@215 [] -
discarding MutexReservation
** last line: 16:03:27,839 [ool-58-thread-1] DEBUG Repository@111 [] -
Repository@1d41309 changed, publishing updates
Another file between these times does not exist.
We verified this by adding a second appender without zipping, which contained
all logs. The files `./file-fallback.XXXXXXXXX.log` contain all logs
> RollingFileAppender: Overwritting rotated log file when using zip
> -----------------------------------------------------------------
>
> Key: LOG4J2-3168
> URL: https://issues.apache.org/jira/browse/LOG4J2-3168
> Project: Log4j 2
> Issue Type: Bug
> Components: Appenders
> Affects Versions: 2.13.3
> Environment: Windows 10 + java 1.8.0_201
> Reporter: Markus Ke
> Priority: Critical
>
> We use log4j2 for logging and have observed the phenomenon that when using
> zipping, existing logs are overwritten when rotating logs.
> The used LogConfig:
> {code:xml}
> <Configuration name="base">
> <Appenders>
> <Console name="console">
> <JSONLayout compact="true" eventEol="true" locationInfo="true"/>
> </Console>
> <RollingFile name="file" append="true">
> <fileName>./file.log</fileName>
>
> <filePattern>./file.%d{yyyyMMdd'T'HHmmssZ}.%i.log.zip</filePattern>
> <PatternLayout pattern="%d{HH:mm:ss,SSS} [%15.15t] %-5p
> %30.30c@%-4L %x - %m%n" />
> <Policies>
> <OnStartupTriggeringPolicy/>
> <SizeBasedTriggeringPolicy size="15 MB" />
> </Policies>
> <DefaultRolloverStrategy>
> <Delete basePath="./">
> <IfFileName glob="file.*.log.zip">
> <IfLastModified age="7d"/>
> </IfFileName>
> </Delete>
> </DefaultRolloverStrategy>
> </RollingFile>
> <!-- Just for testing to verify if the log files get lost by zipping
> them-->
> <RollingFile name="file-unzipped-bug-verification" append="true">
> <fileName>./file-fallback.log</fileName>
>
> <filePattern>./file-fallback.%d{yyyyMMdd'T'HHmmssZ}.%i.log</filePattern>
> <PatternLayout pattern="%d{HH:mm:ss,SSS} [%15.15t] %-5p
> %30.30c@%-4L %x - %m%n" />
> <Policies>
> <OnStartupTriggeringPolicy/>
> <SizeBasedTriggeringPolicy size="15 MB" />
> </Policies>
> <DefaultRolloverStrategy>
> <Delete basePath="./">
> <IfFileName glob="./file-fallback.*.log">
> <IfLastModified age="7d"/>
> </IfFileName>
> </Delete>
> </DefaultRolloverStrategy>
> </RollingFile>
> </Appenders>
> <Loggers>
> <Logger name="org.example.project" level="debug"/>
> <Root level="info">
> <AppenderRef ref="console" />
> <AppenderRef ref="file" />
> <AppenderRef ref="file-unzipped-bug-verification" />
>
> </Root>
> </Loggers>
> </Configuration>
> {code}
> It turns out that at any point in time, the rotation behavior changes and the
> last time stamp of the log is no longer used as the file name, but the first.
> This results in the following circumstance:
> - file.20210914T144224+0200.1.log
> ** first line:
> {code:java}
> 13:50:21,789 [lt-executor-194] DEBUG StreamHandler@68 [] - RPC stream
> completed{code}
> ** last line:
> {code:java}
> 14:42:24,974 [D_2400_supply-1] DEBUG ActionDispatcher@291 [] - Waiting at
> action ...{code}
> - file.20210914T155051+0200.1.log
> ** first line:
> {code:java}
> 15:50:51,988 [ mc-exe-10] DEBUG ResourceSchedule@215 [] - discarding
> MutexReservation{code}
> ** last line:
> {code:java}
> 16:03:27,839 [ool-58-thread-1] DEBUG Repository@111 [] - Repository@1d41309
> changed, publishing updates{code}
> Another file between these times does not exist.
> We verified this by adding a second appender without zipping, which contained
> all logs. The files `./file-fallback.XXXXXXXXX.log` contain all logs
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
