log4j2 is only keeping 1 backup log and deleting the rest

48 views Asked by At

I'm building a stand-alone Java application that is going to be scheduled to run at least once everyday. I'm configuring log4j2 2.23.1 via XML file to specify a DefaultRolloverStrategy along with a Delete action so that it should retain a maximum of 100 log files, delete backed up log files older than 3 months or when the backup folder exceeds 100MB.

What happens instead is that it deletes everything from the backup folder and then backs up the log from the day before so that only 1 log file is retained.

What I want to achieve is the following:

  1. A fresh log file should be created every day in log/mystandaloneapp.log
  2. If running the app from a second time on the same day, it should append the logs to the same log file
  3. The log file from the previous day should be backed up into log/bak/%d{yyyy-MM}/mystandaloneapp-%d{yyyy-MM-dd}.log.gz
  4. It should retain a maximum of 100 log files
  5. It should delete log files older than 3 months
  6. It should delete log files if the size of the backup folder exceeds 100MB

This is the configuration in question:

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="WARN">
    <Appenders>
        <RollingFile name="RollingFile" fileName="log/mystandaloneapp.log"
                     filePattern="log/bak/%d{yyyy-MM}/mystandaloneapp-%d{yyyy-MM-dd}.log.gz">
            <PatternLayout pattern="%d{HH:mm:ss.SSS} %-5level - %msg%n"/>
            <Policies>
                <TimeBasedTriggeringPolicy/>
            </Policies>
            <DefaultRolloverStrategy max="100">
                <Delete basePath="log/bak" maxDepth="2">
                    <IfAny>
                        <IfLastModified age="P3M"/>
                        <IfAccumulatedFileSize exceeds="100MB"/>
                    </IfAny>
                </Delete>
            </DefaultRolloverStrategy>
        </RollingFile>

    </Appenders>
    <Loggers>
        <Root level="info">
            <AppenderRef ref="RollingFile"/>
        </Root>
    </Loggers>
</Configuration>

So I'm expecting to find a backed up log per day into the log/bak/%d{yyyy-MM} but what happens instead is that on a new day, when the application runs for the first time, it deletes every log file into the log/bak folder, it backs up the *.log from the day before and puts it into log/bak/%d{yyyy-MM}.

The day after it will delete this and every other file in log/bak subdirectories so that only 1 single backup file remains, and it is always the one from the day before.

I can't figure out where is the mistake in my configuration.

The last change I did yesterday was adding a max=100 attribute, but that didn't change anything. Only 1 log file is retained at a time.

Here is a debug log:

2024-03-23T12:02:31.209413100Z main DEBUG Now writing to log/mystandaloneapp.log at 2024-03-23T13:02:31.209+0100
2024-03-23T12:02:31.215413Z main DEBUG AsyncLogger.ThreadNameStrategy=UNCACHED (user specified null, default is UNCACHED)
2024-03-23T12:02:31.215413Z main TRACE Using default SystemClock for timestamps.
2024-03-23T12:02:31.215413Z main DEBUG org.apache.logging.log4j.core.util.SystemClock supports precise timestamps.
2024-03-23T12:02:31.218935900Z Log4j2-TF-1-RollingFileManager-1 DEBUG Starting DeleteAction[basePath=log\bak, options=[], maxDepth=2, conditions=[IfAny[IfLastModified(age=PT3M), IfAccumulatedFileSize(exceeds=104857600)]]]
2024-03-23T12:02:31.221933800Z Log4j2-TF-1-RollingFileManager-1 DEBUG DeleteAction complete in 0.0031349 seconds
2024-03-23T12:02:31.222935200Z Log4j2-TF-1-RollingFileManager-1 TRACE Sorted paths:
2024-03-23T12:02:31.222935200Z Log4j2-TF-1-RollingFileManager-1 TRACE log\bak\2024-03\mystandaloneapp-2024-03-18.log.gz (modified: 2024-03-23T12:02:31.2164187Z)
2024-03-23T12:02:31.222935200Z Log4j2-TF-1-RollingFileManager-1 TRACE log\bak\2024-03\mystandaloneapp-2024-03-17.log.gz (modified: 2024-03-17T23:10:23.1878364Z)
2024-03-23T12:02:31.222935200Z Log4j2-TF-1-RollingFileManager-1 TRACE IfLastModified REJECTED: 2024-03\mystandaloneapp-2024-03-18.log.gz ageMillis '6' < 'PT3M'
2024-03-23T12:02:31.223934500Z Log4j2-TF-1-RollingFileManager-1 TRACE IfAccumulatedFileSize REJECTED: 2024-03\mystandaloneapp-2024-03-18.log.gz accumulated size '13760' <= thresholdBytes '104857600'
2024-03-23T12:02:31.223934500Z Log4j2-TF-1-RollingFileManager-1 TRACE Not deleting base=log\bak, relative=2024-03\mystandaloneapp-2024-03-18.log.gz
2024-03-23T12:02:31.223934500Z Log4j2-TF-1-RollingFileManager-1 TRACE IfLastModified ACCEPTED: 2024-03\mystandaloneapp-2024-03-17.log.gz ageMillis '478328036' >= 'PT3M'
2024-03-23T12:02:31.223934500Z Log4j2-TF-1-RollingFileManager-1 TRACE Deleting log\bak\2024-03\mystandaloneapp-2024-03-17.log.gz

What is bugging me a lot is this: IfLastModified ACCEPTED: 2024-03\mystandaloneapp-2024-03-17.log.gz ageMillis '478328036' >= 'PT3M' . It is not possible that this file is older than 3 months when it was created some days ago.

2

There are 2 answers

0
supaplexer On

I have found a solution here. It seems you cannot specify a Duration in months as it will be interpreted in minutes. Despite setting P3M, log4j2 was interpreting it as PT3M, hence deleting all log files older than 3 minutes.

Solution was to specify Duration in Days, so the correct setting for 3 months is this:

<IfLastModified age="90D"/>
1
Piotr P. Karwasz On

PT3M means "3 minutes".

Check the Javadoc of Duration#parse for the allowed format. The general form is:

PnDTmHpMqS

where n, m, p and q are integers. What you probably want is P90D.