删除新日志文件的Log4j2默认翻转策略

Question

   LoggerContext ctx;
   public Logger logger;


    ConfigurationBuilder< BuiltConfiguration > builder =
    ConfigurationBuilderFactory.newConfigurationBuilder();

    builder.setStatusLevel(Level.ALL);
    builder.setConfigurationName("RollingBuilder");
// create the console appender
    AppenderComponentBuilder appenderBuilder = builder.newAppender("Stdout", "CONSOLE").addAttribute("target",
            ConsoleAppender.Target.SYSTEM_OUT);
    appenderBuilder.add(builder.newLayout("PatternLayout").
            addAttribute("pattern", "%d [%t] %-5level: %msg%n%throwable"));
    builder.add( appenderBuilder );

    LayoutComponentBuilder layoutBuilder = builder.newLayout("PatternLayout")
            .addAttribute("pattern", "%d [%t] %-5level: %msg%n");
    ComponentBuilder triggeringPolicy = builder.newComponent("Policies")
            .addComponent(builder.newComponent("CronTriggeringPolicy").addAttribute("schedule", "0 * * * * ?"))
            .addComponent(builder.newComponent("SizeBasedTriggeringPolicy").addAttribute("size", "100M"));
    ComponentBuilder defaultStrat = builder.newComponent("DefaultRolloverStrategy")
            .addAttribute("min", 10)
            .addAttribute("max", 20);
    appenderBuilder = builder.newAppender("rolling", "RollingFile")
            .addAttribute("fileName", "targetTest/rollingTEST.log")
            .addAttribute("filePattern", "targetTest/archive/rollingTEST-%d{yy-dd-MM-kk-mm}-test.log.gz") 
            .addAttribute("immediateFlush", false)
            .addComponent(defaultStrat)
            .add(layoutBuilder)
            .addComponent(triggeringPolicy);
    builder.add(appenderBuilder);


// create the new logger
    builder.add( builder.newLogger( "TestLogger", Level.ALL )
            .add( builder.newAppenderRef( "rolling" ) )   );
            //.addAttribute( "additivity", false ) );

    builder.add( builder.newRootLogger( Level.ALL )
            .add( builder.newAppenderRef( "rolling" ) ) );


    this.ctx = Configurator.initialize(builder.build());

    this.logger = ctx.getLogger("TestLogger");

以下是发生这种情况的日志：

2016-07-21 15:20:00,009 Log4j2-Log4j2Scheduled-1 TRACE DefaultRolloverStrategy.purge() took 6.0 milliseconds
2016-07-21 15:20:00,030 Log4j2-Log4j2Scheduled-1 DEBUG RollingFileManager executing synchronous FileRenameAction[targetTest/rollingTEST.log to targetTest/archive/rollingTEST-16-21-07-15-20-test.log, renameEmptyFiles=false]
2016-07-21 15:20:00,042 Log4j2-Log4j2Scheduled-1 TRACE Renamed file /Users/Source/targetTest/rollingTEST.log to /Users/Source/targetTest/archive/rollingTEST-16-21-07-15-20-test.log with Files.move
2016-07-21 15:20:00,042 Log4j2-Log4j2Scheduled-1 DEBUG RollingFileManager executing async GzCompressAction[targetTest/archive/rollingTEST-16-21-07-15-20-test.log to targetTest/archive/rollingTEST-16-21-07-15-20-test.log.gz, deleteSource=true]
2016-07-21 15:20:01,004 Log4j2-Log4j2Scheduled-1 TRACE DefaultRolloverStrategy.purge() took 0.0 milliseconds
2016-07-21 15:20:01,004 Log4j2-Log4j2Scheduled-1 DEBUG RollingFileManager executing synchronous FileRenameAction[targetTest/rollingTEST.log to targetTest/archive/rollingTEST-16-21-07-15-19-test.log, renameEmptyFiles=false]
2016-07-21 15:20:02,004 Log4j2-Log4j2Scheduled-1 DEBUG DefaultRolloverStrategy.purgeAscending deleting targetTest/archive/rollingTEST-16-21-07-15-20-test.log.gz at low index 10: all slots full.
2016-07-21 15:20:02,004 Log4j2-Log4j2Scheduled-1 DEBUG DefaultRolloverStrategy.purgeAscending executing 9 of 10: FileRenameAction[targetTest/archive/rollingTEST-16-21-07-15-20-test.log.gz to targetTest/archive/rollingTEST-16-21-07-15-20-test.log.gz, renameEmptyFiles=true]
2016-07-21 15:20:02,005 Log4j2-Log4j2Scheduled-1 ERROR Unable to move file /Users/Source/targetTest/archive/rollingTEST-16-21-07-15-20-test.log.gz to /Users/Source/targetTest/archive/rollingTEST-16-21-07-15-20-test.log.gz: java.nio.file.NoSuchFileException /Users/Source/targetTest/archive/rollingTEST-16-21-07-15-20-test.log.gz -> /Users/Source/targetTest/archive/rollingTEST-16-21-07-15-20-test.log.gz
2016-07-21 15:20:02,006 Log4j2-Log4j2Scheduled-1 ERROR Unable to copy file /Users/Source/targetTest/archive/rollingTEST-16-21-07-15-20-test.log.gz to /Users/Source/targetTest/archive/rollingTEST-16-21-07-15-20-test.log.gz: java.nio.file.NoSuchFileException /Users/Source/targetTest/archive/rollingTEST-16-21-07-15-20-test.log.gz
2016-07-21 15:20:03,004 Log4j2-Log4j2Scheduled-1 TRACE DefaultRolloverStrategy.purge() took 0.0 milliseconds
2016-07-21 15:20:03,004 Log4j2-Log4j2Scheduled-1 DEBUG RollingFileManager executing synchronous FileRenameAction[targetTest/rollingTEST.log to targetTest/archive/rollingTEST-16-21-07-15-20-test.log, renameEmptyFiles=false]
2016-07-21 15:20:04,004 Log4j2-Log4j2Scheduled-1 TRACE DefaultRolloverStrategy.purge() took 0.0 milliseconds
2016-07-21 15:20:04,005 Log4j2-Log4j2Scheduled-1 DEBUG RollingFileManager executing synchronous FileRenameAction[targetTest/rollingTEST.log to targetTest/archive/rollingTEST-16-21-07-15-20-test.log, renameEmptyFiles=false]
2016-07-21 15:20:05,006 Log4j2-Log4j2Scheduled-1 TRACE DefaultRolloverStrategy.purge() took 0.0 milliseconds
2016-07-21 15:20:05,006 Log4j2-Log4j2Scheduled-1 DEBUG RollingFileManager executing synchronous FileRenameAction[targetTest/rollingTEST.log to targetTest/archive/rollingTEST-16-21-07-15-20-test.log, renameEmptyFiles=false]
2016-07-21 15:20:06,005 Log4j2-Log4j2Scheduled-1 TRACE DefaultRolloverStrategy.purge() took 0.0 milliseconds
2016-07-21 15:20:06,006 Log4j2-Log4j2Scheduled-1 DEBUG RollingFileManager executing synchronous FileRenameAction[targetTest/rollingTEST.log to targetTest/archive/rollingTEST-16-21-07-15-20-test.log, renameEmptyFiles=false]
2016-07-21 15:20:06,007 Log4j2-Log4j2Scheduled-1 TRACE Renamed file /Users/Source/targetTest/rollingTEST.log to /Users/Source/targetTest/archive/rollingTEST-16-21-07-15-20-test.log with Files.move
2016-07-21 15:20:06,007 Log4j2-Log4j2Scheduled-1 DEBUG RollingFileManager executing async GzCompressAction[targetTest/archive/rollingTEST-16-21-07-15-20-test.log to targetTest/archive/rollingTEST-16-21-07-15-20-test.log.gz, deleteSource=true]
2016-07-21 15:20:07,001 Log4j2-Log4j2Scheduled-1 DEBUG DefaultRolloverStrategy.purgeAscending deleting targetTest/archive/rollingTEST-16-21-07-15-20-test.log.gz at low index 10: all slots full.
2016-07-21 15:20:07,002 Log4j2-Log4j2Scheduled-1 DEBUG DefaultRolloverStrategy.purgeAscending executing 9 of 10: FileRenameAction[targetTest/archive/rollingTEST-16-21-07-15-20-test.log.gz to targetTest/archive/rollingTEST-16-21-07-15-20-test.log.gz, renameEmptyFiles=true]
2016-07-21 15:20:07,002 Log4j2-Log4j2Scheduled-1 ERROR Unable to move file /Users/Source/targetTest/archive/rollingTEST-16-21-07-15-20-test.log.gz to /Users/Source/targetTest/archive/rollingTEST-16-21-07-15-20-test.log.gz: java.nio.file.NoSuchFileException /Users/Source/targetTest/archive/rollingTEST-16-21-07-15-20-test.log.gz -> /Users/Source/targetTest/archive/rollingTEST-16-21-07-15-20-test.log.gz
2016-07-21 15:20:07,002 Log4j2-Log4j2Scheduled-1 ERROR Unable to copy file /Users/Source/targetTest/archive/rollingTEST-16-21-07-15-20-test.log.gz to /Users/Source/targetTest/archive/rollingTEST-16-21-07-15-20-test.log.gz: java.nio.file.NoSuchFileException /Users/Source/targetTest/archive/rollingTEST-16-21-07-15-20-test.log.gz
2016-07-21 15:20:08,003 Log4j2-Log4j2Scheduled-1 TRACE DefaultRolloverStrategy.purge() took 0.0 milliseconds
2016-07-21 15:20:08,004 Log4j2-Log4j2Scheduled-1 DEBUG RollingFileManager executing synchronous FileRenameAction[targetTest/rollingTEST.log to targetTest/archive/rollingTEST-16-21-07-15-20-test.log, renameEmptyFiles=false]
2016-07-21 15:20:08,005 Log4j2-Log4j2Scheduled-1 TRACE Renamed file /Users/Source/targetTest/rollingTEST.log to /Users/Source/targetTest/archive/rollingTEST-16-21-07-15-20-test.log with Files.move
2016-07-21 15:20:08,005 Log4j2-Log4j2Scheduled-1 DEBUG RollingFileManager executing async GzCompressAction[targetTest/archive/rollingTEST-16-21-07-15-20-test.log to targetTest/archive/rollingTEST-16-21-07-15-20-test.log.gz, deleteSource=true]
2016-07-21 15:20:09,007 Log4j2-Log4j2Scheduled-1 DEBUG DefaultRolloverStrategy.purgeAscending deleting targetTest/archive/rollingTEST-16-21-07-15-20-test.log.gz at low index 10: all slots full.
2016-07-21 15:20:09,009 Log4j2-Log4j2Scheduled-1 DEBUG DefaultRolloverStrategy.purgeAscending executing 9 of 10: FileRenameAction[targetTest/archive/rollingTEST-16-21-07-15-20-test.log.gz to targetTest/archive/rollingTEST-16-21-07-15-20-test.log.gz, renameEmptyFiles=true]
2016-07-21 15:20:09,009 Log4j2-Log4j2Scheduled-1 ERROR Unable to move file /Users/Source/targetTest/archive/rollingTEST-16-21-07-15-20-test.log.gz to /Users/Source/targetTest/archive/rollingTEST-16-21-07-15-20-test.log.gz: java.nio.file.NoSuchFileException /Users/Source/targetTest/archive/rollingTEST-16-21-07-15-20-test.log.gz -> /Users/Source/targetTest/archive/rollingTEST-16-21-07-15-20-test.log.gz
2016-07-21 15:20:09,010 Log4j2-Log4j2Scheduled-1 ERROR Unable to copy file /Users/Source/targetTest/archive/rollingTEST-16-21-07-15-20-test.log.gz to /Users/Source/targetTest/archive/rollingTEST-16-21-07-15-20-test.log.gz: java.nio.file.NoSuchFileException /Users/Source/targetTest/archive/rollingTEST-16-21-07-15-20-test.log.gz
2016-07-21 15:20:10,004 Log4j2-Log4j2Scheduled-1 TRACE DefaultRolloverStrategy.purge() took 0.0 milliseconds
2016-07-21 15:20:10,004 Log4j2-Log4j2Scheduled-1 DEBUG RollingFileManager executing synchronous FileRenameAction[targetTest/rollingTEST.log to targetTest/archive/rollingTEST-16-21-07-15-20-test.log, renameEmptyFiles=false]
2016-07-21 15:20:11,004 Log4j2-Log4j2Scheduled-1 TRACE DefaultRolloverStrategy.purge() took 0.0 milliseconds
2016-07-21 15:20:11,005 Log4j2-Log4j2Scheduled-1 DEBUG RollingFileManager executing synchronous FileRenameAction[targetTest/rollingTEST.log to targetTest/archive/rollingTEST-16-21-07-15-20-test.log, renameEmptyFiles=false]
2016-07-21 15:20:11,006 Log4j2-Log4j2Scheduled-1 TRACE Renamed file /Users/Source/targetTest/rollingTEST.log to /Users/Source/targetTest/archive/rollingTEST-16-21-07-15-20-test.log with Files.move
2016-07-21 15:20:11,006 Log4j2-Log4j2Scheduled-1 DEBUG RollingFileManager executing async GzCompressAction[targetTest/archive/rollingTEST-16-21-07-15-20-test.log to targetTest/archive/rollingTEST-16-21-07-15-20-test.log.gz, deleteSource=true]
2016-07-21 15:20:12,006 Log4j2-Log4j2Scheduled-1 DEBUG DefaultRolloverStrategy.purgeAscending deleting targetTest/archive/rollingTEST-16-21-07-15-20-test.log.gz at low index 10: all slots full.
2016-07-21 15:20:12,006 Log4j2-Log4j2Scheduled-1 DEBUG DefaultRolloverStrategy.purgeAscending executing 9 of 10: FileRenameAction[targetTest/archive/rollingTEST-16-21-07-15-20-test.log.gz to targetTest/archive/rollingTEST-16-21-07-15-20-test.log.gz, renameEmptyFiles=true]
2016-07-21 15:20:12,007 Log4j2-Log4j2Scheduled-1 ERROR Unable to move file /Users/Source/targetTest/archive/rollingTEST-16-21-07-15-20-test.log.gz to /Users/Source/targetTest/archive/rollingTEST-16-21-07-15-20-test.log.gz: java.nio.file.NoSuchFileException /Users/Source/targetTest/archive/rollingTEST-16-21-07-15-20-test.log.gz -> /Users/Source/targetTest/archive/rollingTEST-16-21-07-15-20-test.log.gz
2016-07-21 15:20:12,007 Log4j2-Log4j2Scheduled-1 ERROR Unable to copy file /Users/Source/targetTest/archive/rollingTEST-16-21-07-15-20-test.log.gz to /Users/Source/targetTest/archive/rollingTEST-16-21-07-15-20-test.log.gz: java.nio.file.NoSuchFileException /Users/Source/targetTest/archive/rollingTEST-16-21-07-15-20-test.log.gz
2016-07-21 15:20:13,004 Log4j2-Log4j2Scheduled-1 TRACE DefaultRolloverStrategy.purge() took 0.0 milliseconds
2016-07-21 15:20:13,004 Log4j2-Log4j2Scheduled-1 DEBUG RollingFileManager executing synchronous FileRenameAction[targetTest/rollingTEST.log to targetTest/archive/rollingTEST-16-21-07-15-20-test.log, renameEmptyFiles=false]

如果我在文件名中添加%I参数，那么我的新文件将不会被删除，但是翻转过程仍然会在初始的翻转过程完成后每秒触发一次，并且我会为发送到记录器的每个日志事件生成一个新文件。

编辑：我只是使用XML配置文件而不是上面的编程方法进行了尝试，得到了类似的结果。下面是我使用的配置文件：

<Configuration status="DEBUG">
<Appenders>
    <RollingFile name="RollingFile" fileName="target/logfile.log"
                 filePattern="target/archive/logfile-%d{yyyy-MM-dd-hh-mm-ss}.log" >
        <PatternLayout>
            <pattern>%d{dd/MMM/yyyy HH:mm:ss,SSS}- %c{1}: %m%n</pattern>
        </PatternLayout>
        <Policies>
            <CronTriggeringPolicy schedule="0 * * * * ?"/>
        </Policies>
    </RollingFile>
</Appenders>
<Loggers>
    <Logger name="root" level="debug" additivity="false">
        <appender-ref ref="RollingFile" level="debug"/>
    </Logger>
    <Logger name="TestLogger" level="debug" additivity="false">
        <appender-ref ref="RollingFile" level="debug"/>
    </Logger>
    <Root level="debug" additivity="false">
        <AppenderRef ref="RollingFile"/>
    </Root>
</Loggers>

>

第一个是在初始事件之后每秒翻转一次，每个日志事件都有一个新文件

第二个是我上面描述的，在我的翻转文件创建后被删除。这也引发了最初事件后每秒钟的翻车。

Answer 1

这似乎在最后的版本中得到了解决。相关问题，https://issues.apache.org/jira/browse/log4j2-1480

https://issues.apache.org/jira/browse/log4j2-1548

我已经更新到2.8.2版，不再看到这个错误。