Uploaded image for project: 'logback'
  1. logback
  2. LOGBACK-1386

Incorrect rolling files by TimeBasedArchiveRemover if totalSizeCap limit is exceeded

    XMLWordPrintable

Details

    • Icon: Bug Bug
    • Resolution: Unresolved
    • Icon: Critical Critical
    • None
    • 1.1.8, 1.3.0-alpha4
    • logback-core
    • Mac OS X, JDK8/9

    Description

      TimeBasedArchiveRemover doesn't get into account the oldest history files when rollover happens and totalSizeCap limit is exceeded.

      In the worst case this leads to an increase in the total log file size up to 2 times above totalSizeCap.

      It can be reproduced with following configuration:

      <configuration scan="true" scanPeriod="10 seconds" debug="true">
          <appender name="ROLLING" class="ch.qos.logback.core.rolling.RollingFileAppender">
              <file>mylog.log</file>
              <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
                  <fileNamePattern>mylog-%d{yyyyMMdd-HHmm}.%i.log</fileNamePattern>
                  <maxFileSize>2KB</maxFileSize>
                  <maxHistory>1</maxHistory>
                  <totalSizeCap>10KB</totalSizeCap>
                  <cleanHistoryOnStart>true</cleanHistoryOnStart>
              </rollingPolicy>
              <encoder>
                  <pattern>%msg%n</pattern>
              </encoder>
          </appender>
          <root level="DEBUG">
              <appender-ref ref="ROLLING"/>
          </root>
      </configuration>

      and simple application:

      public class Main {
          private static final Logger log = LoggerFactory.getLogger(Main.class);
          private static final long ONE_MILLION = 1_000_000L;
      
          public static void main(String[] args) throws InterruptedException {
              for (int i = 0; i < 10000; i++) {
                  log.info("I write in log {} times", ONE_MILLION + i);
                  Thread.sleep(100L);
              }
          }
      }
      

      Example of execution result of such configuration:

      2.0K Mar 21:44 mylog-20180304-2144.3.log <- this one should be removed
      2.0K Mar 21:44 mylog-20180304-2144.4.log
      2.0K Mar 21:44 mylog-20180304-2144.5.log
      2.0K Mar 21:44 mylog-20180304-2144.6.log
      2.0K Mar 21:44 mylog-20180304-2144.7.log
      2.1K Mar 21:45 mylog-20180304-2145.0.log <- but this will be removed instead
      2.0K Mar 21:45 mylog-20180304-2145.1.log
      2.0K Mar 21:45 mylog-20180304-2145.2.log
      2.0K Mar 21:45 mylog-20180304-2145.3.log
      2.0K Mar 21:45 mylog.log
      

      and in a moment:

      2.0K Mar 21:44 mylog-20180304-2144.3.log
      2.0K Mar 21:44 mylog-20180304-2144.4.log
      2.0K Mar 21:44 mylog-20180304-2144.5.log
      2.0K Mar 21:44 mylog-20180304-2144.6.log
      2.0K Mar 21:44 mylog-20180304-2144.7.log
      2.0K Mar 21:45 mylog-20180304-2145.1.log
      2.0K Mar 21:45 mylog-20180304-2145.2.log
      2.0K Mar 21:45 mylog-20180304-2145.3.log
      2.0K Mar 21:45 mylog-20180304-2145.4.log
      174B Mar 21:45 mylog.log
      

      Attachments

        Activity

          People

            logback-dev Logback dev list
            allebdev Aleksei Lebedev
            Votes:
            5 Vote for this issue
            Watchers:
            2 Start watching this issue

            Dates

              Created:
              Updated: