RollingRandomAccessFile uses wrong file name inside .zip

[JohnLussmyer]

Description

When using a RollingRandomAccessFile appender that zips the logs, and there are multiple threads really spewing logging, when log4j zip's the previous log file - it often uses the name of the current log file.

So, the base log file name is "stuff.log". Rolling every 100MB into stuff.%i.log.zip. What I'm getting is stuff.1.log.zip contains stuff.7.log. All zips up to 7 contain stuff.7.log - though the actual log content is what is expected for stuff.1, or stuff.2, etc.. So the correct file is getting zipped - but given the wrong file name.

Configuration

Version: Log4j 2.21.0

Operating system: [OS and version] Win 11

JDK: [JDK distribution and version] Adoptium JDK-17.0.5+8

Logs

Reproduction

    <RollingRandomAccessFile
        name="Log"
        fileName="${sys:metrixLogFolder}/${sys:metrixLogName}.log"
        filePattern="${sys:metrixLogFolder}/${sys:metrixLogName}.%i.log.zip">
        <PatternLayout
            pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} [%20.20t] %-5level %30.30logger - %msg%n"
            header="Application: ${sys:metrixBuild}%n" />
        <Policies>
            <OnStartupTriggeringPolicy />
            <SizeBasedTriggeringPolicy
                size="100 MB" />
        </Policies>
    </RollingRandomAccessFile>

[JohnLussmyer]

One thing I just figured out is that when rolling the logs, it only counts up to 7. After that, it starts deleting the oldest log, and renumbering the others.

[ppkarwasz]

@JohnLussmyer,

The default configuration of DefaultRolloverStrategy keeps only 7 values of the %i index: the archived files will range from stuff.1.log.zip (the oldest) to stuff.7.log.zip (the most recent).

When you already have 7 files, each rollover will:

• remove stuff.1.log.zip,
• move stuff.2.log.zip to stuff.1.log.zip,
• ...
• move stuff.7.log.zip to stuff.6.log.zip,
• move the current stuff.log to stuff.7.log,
• compress stuff.7.log to obtain stuff.7.log.zip.

This explains why you only have 7 files and each archive contains a file named stuff.7.log: after 6 rotations stuff.7.log.zip becomes stuff.1.log.zip.

If you want to change the default configuration use the fileIndex, min and max parameters of DefaultRolloverStrategy, e.g.:

<RollingRandomAccessfile>
    ...
    <DefaultRolloverStrategy fileIndex="nomax"/>
</RollingRandomAccessfile>

will remove the limit on the number of archived files and both your problems. Check the documentation for other options.

[JohnLussmyer]

Ahh, thanks. Yet Another option I missed. Though, the file naming in the .zip files just screws everything up. If you want to unzip all the logs - you have to rename most of them. Royal PITA.

[ppkarwasz]

@JohnLussmyer,

If you change the fileIndex option the problem should solve itself: as explained above all the stuff.<n>.log.zip files were originally stuff.7.log.zip, but they were renamed multiple times. If you change fileIndex to "nomax", stuff.<n>.log.zip will never be renamed and will contain stuff.<n>.log.

If file renaming is enabled, we would need to rename the archive entry each time we rename a *.zip file. I doubt this can be done efficiently.

[JohnLussmyer]

Don't rename the files already in the .zip. Just rename the log file BEFORE adding to a zip - using the number that it would be if you weren't limiting it to 7. So the .zip files might contain xx.23.log, xx.24.log, etc... Heck, you could even name the .zip files that way, just limit the number of them by deleting the old ones.