[LOG4J2-1487] Log4j RollingFileAppender every minute

• Type: Bug
• Status: Resolved
• Priority: Minor
• Resolution: Fixed
• Affects Version/s: 2.6.2
• Fix Version/s: 2.8
• Component/s: Appenders

Environment

Windows 7

• Assignee: Ralph Goers
• Reporter: Enrique Lamas
• Created: 29/Jul/16 10:06
• Updated: 02/Jan/17 01:00
• Resolved: 02/Jan/17 01:00

Description

http://stackoverflow.com/questions/38638105/log4j-rollingfileappender-every-minute

I'm testing Log4j RollingFileAppender with log4j 2.6.2.

I want to rotate the logs every minute and so I have a log4j2.xml very similar to one example of here https://logging.apache.org/log4j/2.x/manual/appenders.html#RollingFileAppender. This is my log4j2.xml

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="warn" name="testlog4j2" packages="">
  <Properties>
    <Property name="baseDir">C:/tmp/testlog4</Property>
  </Properties>
  <Appenders>
    <RollingFile name="RollingFile" fileName="${baseDir}/app.log"
          filePattern="${baseDir}/$${date:yyyy-MM}/app-%d{yyyy-MM-dd-HH-mm}.log.gz">
      <PatternLayout pattern="%d %p %c{1.} [%t] %m%n" />
      <CronTriggeringPolicy schedule="0 0/1 * * * ?"/>
      <DefaultRolloverStrategy>
        <Delete basePath="${baseDir}" maxDepth="2">
          <IfFileName glob="*/app-*.log.gz" />
          <IfLastModified age="60d" />
        </Delete>
      </DefaultRolloverStrategy>
    </RollingFile>
  </Appenders>
  <Loggers>
    <Root level="ALL">
      <AppenderRef ref="RollingFile"/>
    </Root>
  </Loggers>
</Configuration>

And this is an app where I write a log every second.

package testlog4j2;

import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;

public class TestLog4j {

    private final static Logger logger = LogManager.getLogger(TestLog4j.class);

    public static void main(String[] args) {
        try {
            for (int i=1; i<=240; i++) {
                logger.info("Hello");
                Thread.sleep(1*1000);
            }
        } catch (Exception e) {
            //e.printStackTrace();
            logger.error("Excepcion general", e);
        }
    }
}

What happens is:

once the system rotates the log at the first minute appears continuously errors like this

2016-07-28 15:10:02,015 Log4j2-Log4j2Scheduled-1 ERROR Unable to move file C:\tmp\testlog4\2016-07\app-2016-07-28-15-10.log.gz to C:\tmp\testlog4\2016-07\app-2016-07-28-15-10.log.gz: java.nio.file.NoSuchFileException C:\tmp\testlog4\2016-07\app-2016-07-28-15-10.log.gz -> C:\tmp\testlog4\2016-07\app-2016-07-28-15-10.log.gz

There isn't a gz for every minute
The result gz don't have a log with 60 lines. Instead they have 1, 2 or three lines of log.
The main log C:\tmp\testlog4\app.log has no content

Thanks

Issue Links

• Is contained by: LOG4J2-1653 CronTriggeringPolicy uses wrong naming and produces NPE
• is related to: LOG4J2-1653 CronTriggeringPolicy uses wrong naming and produces NPE