[LOG4J2-2485] SizeBasedTriggeringPolicy is not honored when using the DirectWriteRolloverStrategy if the machine restarts

• Type: Bug
• Status: Resolved
• Priority: Major
• Resolution: Fixed
• Fix Version/s: 2.11.2
• Assignee: Unassigned
• Reporter: Giovanni Matteo Fumarola
• Created: 22/Oct/18 20:19
• Updated: 23/Dec/18 07:00
• Resolved: 23/Dec/18 07:00

Description

We are working on migrate Log4J to Log4J2 in Hadoop codebase.

It seems like the SizeBasedTriggeringPolicy is not honored when using the DirectWriteRolloverStrategy if the machine restarts before it writes the size limit specified in the policy. We are coming across an issue where if a process using Log4j2 restarts continuously in a short time period, the size of the most recently created log will grow indefinitely.
The behavior we expect is for the log output to always be written to the most recently created file by the RollingFile appender, and for the log file size to never exceed what was specified in the SizeBasedTriggeringPolicy.
Our setup uses SLF4J and Log4j2 using the Log4j 1.2 API.
In reproducing the issue locally, I took an example of the usage of the DirectWriteRolloverStrategy from https://logging.apache.org/log4j/2.x/manual/appenders.html#TriggeringPolicies and modified it slightly to not compress the archived files. Here is the code used.

<?xml version="1.0" encoding="UTF-8"?>

<Configuration status="INFO">

  <Appenders>

    <RollingFile name="file" filePattern="logs/app-%d\{yyyy-MM-dd-HH}-%i.log">

      <PatternLayout>

        <Pattern>%d %p %c\{1.} [%t] %m%n</Pattern>

      </PatternLayout>

      <Policies>

        <SizeBasedTriggeringPolicy size="250 MB"/>

      </Policies>

      <DirectWriteRolloverStrategy maxFiles="10"/>

    </RollingFile>

  </Appenders>

  <Loggers>

    <Root level="debug">

      <AppenderRef ref="file"/>

    </Root>

  </Loggers>

</Configuration>

 

package com.test;

 

import org.slf4j.Logger;

import org.slf4j.LoggerFactory;

 

public class Test {

  private static Logger logger = LoggerFactory.getLogger(Test.class);

 

  public static void main(String[] args)

  {

    while (true)

    {

      logger.info("test");

    }

  }

}

 

First I ran this such that the log generated would be somewhere around half the size limit specified.

 

-rw-r--r-- 1 iapicker 1049089 251M Oct 22 12:53 app-2018-10-22-12-1.log

-rw-r--r-- 1 iapicker 1049089 121M Oct 22 12:53 app-2018-10-22-12-2.log

 

Then I ran it again, and noted the file sizes generated:

 

-rw-r--r-- 1 iapicker 1049089 251M Oct 22 12:53 app-2018-10-22-12-1.log

-rw-r--r-- 1 iapicker 1049089 371M Oct 22 12:55 app-2018-10-22-12-2.log

-rw-r--r-- 1 iapicker 1049089 251M Oct 22 12:56 app-2018-10-22-12-3.log

-rw-r--r-- 1 iapicker 1049089  48M Oct 22 12:56 app-2018-10-22-12-4.log

Here, the second log which was 121M at the time the first run finished now exceeds the 250M limit specified in the SizeBasedTriggeringPolicy. If another 250M is written to the same file without a restart happening, the behavior becomes what we expect.

Internally, this could be caused by the inability to specify a fileName parameter in DirectWriteRolloverStrategy, because the file specified with fileName is used for tracking the amount written to the log so far when Log4j first starts up. Otherwise, the size written so far would become zero.The Log4j version used is 2.11.0. Here is the full list of the Maven dependencies used.

<dependencies>

    <dependency>

      <groupId>org.apache.logging.log4j</groupId>

      <artifactId>log4j-api</artifactId>

      <version>2.11.0</version>

    </dependency>

    <dependency>

      <groupId>org.apache.logging.log4j</groupId>

      <artifactId>log4j-core</artifactId>

      <version>2.11.0</version>

    </dependency>

    <dependency>

      <groupId>org.apache.logging.log4j</groupId>

      <artifactId>log4j-slf4j-impl</artifactId>

      <version>2.11.0</version>

    </dependency>

    <dependency>

      <groupId>org.apache.logging.log4j</groupId>

      <artifactId>log4j-1.2-api</artifactId>

      <version>2.11.0</version>

    </dependency>

    <dependency>

      <groupId>org.apache.logging.log4j</groupId>

      <artifactId>log4j-iostreams</artifactId>

      <version>2.11.0</version>

    </dependency>

  </dependencies>