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

Incorrect rolling files by TimeBasedArchiveRemover if totalSizeCap limit is exceeded

    Details

    • Type: Bug
    • Status: Open
    • Priority: Critical
    • Resolution: Unresolved
    • Affects Version/s: 1.1.8, 1.3.0-alpha4
    • Fix Version/s: None
    • Component/s: logback-core
    • Labels:
    • Environment:

      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

          Issue Links

            Activity

              People

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

                Dates

                • Created:
                  Updated: