New subject: [JIRA] Assigned: (LBCORE-164) SizeAndTimeBasedFNATP will overwrite previous logging files with index > 9 on restart app.

10 Aug 2010

      SizeAndTimeBasedFNATP will overwrite previous logging files with index > 9 on restart app.
------------------------------------------------------------------------------------------

                 Key: LBCORE-164
                 URL: http://jira.qos.ch/browse/LBCORE-164
             Project: logback-core
          Issue Type: Bug
          Components: Rolling
    Affects Versions: 0.9.24
         Environment: Windows XP, java jdk1.6.0_18
            Reporter: Dieter Mueller
            Assignee: Logback dev list

Configuration:
  <appender name="DebugLog" class="ch.qos.logback.core.rolling.RollingFileAppender">
    <!--See also http://logback.qos.ch/manual/appenders.html#RollingFileAppender-->
    <file>c:/log/debug.log</file>
    <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
      <!-- rollover daily -->
      <fileNamePattern>c:/log/debug-old-%d{yyyy-MM-dd}.%i.log</fileNamePattern>
      <maxHistory>3</maxHistory>
      <timeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
        <maxFileSize>10KB</maxFileSize>
      </timeBasedFileNamingAndTriggeringPolicy>
    </rollingPolicy>
    <encoder>
      <pattern>%date{ISO8601} %-5level [%thread] %logger{30}:%line - %msg%n</pattern>
    </encoder>
  </appender>

Steps to reproduce:
1. Start the application
2. debug.log was created.
3. let run, until periodscounter reaches 10 or more (or prepare the files), e.g.

c:\log\debug-old-2010-08-10.0.log
c:\log\debug-old-2010-08-10.1.log
c:\log\debug-old-2010-08-10.10.log
c:\log\debug-old-2010-08-10.11.log
c:\log\debug-old-2010-08-10.12.log
c:\log\debug-old-2010-08-10.2.log
c:\log\debug-old-2010-08-10.3.log
c:\log\debug-old-2010-08-10.4.log
c:\log\debug-old-2010-08-10.5.log
c:\log\debug-old-2010-08-10.6.log
c:\log\debug-old-2010-08-10.7.log
c:\log\debug-old-2010-08-10.8.log
c:\log\debug-old-2010-08-10.9.log

4. restart the application
5. log to base.log
6. yyyy-MM-dd.10.log was (re-)created on rollover, overwrite the previous yyyy-MM-dd.10.log. Logging messages are lost.

It looks like the root cause is the (reversed) sorting via filenames in method

ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP.computeCurrentPeriodsHighestCounterValue(String)

    FileFilterUtil.reverseSortFileArrayByName(matchingFileArray);
    currentPeriodsCounter = FileFilterUtil.extractCounter(matchingFileArray[0], stemRegex);

because the input file array looks like:

c:\log\debug-old-2010-08-10.0.log
c:\log\debug-old-2010-08-10.1.log
c:\log\debug-old-2010-08-10.10.log
c:\log\debug-old-2010-08-10.11.log
c:\log\debug-old-2010-08-10.12.log
c:\log\debug-old-2010-08-10.2.log
c:\log\debug-old-2010-08-10.3.log
c:\log\debug-old-2010-08-10.4.log
c:\log\debug-old-2010-08-10.5.log
c:\log\debug-old-2010-08-10.6.log
c:\log\debug-old-2010-08-10.7.log
c:\log\debug-old-2010-08-10.8.log
c:\log\debug-old-2010-08-10.9.log

and in reversed order:

c:\log\debug-old-2010-08-10.9.log
c:\log\debug-old-2010-08-10.8.log
c:\log\debug-old-2010-08-10.7.log
c:\log\debug-old-2010-08-10.6.log
c:\log\debug-old-2010-08-10.5.log
c:\log\debug-old-2010-08-10.4.log
c:\log\debug-old-2010-08-10.3.log
c:\log\debug-old-2010-08-10.2.log
c:\log\debug-old-2010-08-10.12.log
c:\log\debug-old-2010-08-10.11.log
c:\log\debug-old-2010-08-10.10.log
c:\log\debug-old-2010-08-10.1.log
c:\log\debug-old-2010-08-10.0.log

then the wrong index 9 of the first file is used!

Suggestion for solution:

Get all indizes and use the highest.

for example:

  void computeCurrentPeriodsHighestCounterValue(final String stemRegex) {
    File file = new File(getCurrentPeriodsFileNameWithoutCompressionSuffix());

    File parentDir = file.getParentFile();
    File[] matchingFileArray = FileFilterUtil
            .filesInFolderMatchingStemRegex(parentDir, stemRegex);

    if (matchingFileArray == null || matchingFileArray.length == 0) {
      currentPeriodsCounter = 0;
      return;
    }

//    FileFilterUtil.reverseSortFileArrayByName(matchingFileArray);
//    currentPeriodsCounter = FileFilterUtil.extractCounter(matchingFileArray[0], stemRegex);

    for (File logFile : matchingFileArray) {
        int aPeriodCounter = FileFilterUtil.extractCounter(logFile, stemRegex);
        if (aPeriodCounter > currentPeriodsCounter) {
            currentPeriodsCounter = aPeriodCounter;
        }
    }

    if (tbrp.getParentsRawFileProperty() != null) {
      currentPeriodsCounter++;
    }
  }

-- 
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: http://jira.qos.ch/secure/Administrators.jspa
-
For more information on JIRA, see: http://www.atlassian.com/software/jira

[JIRA] Created: (LBCORE-164) SizeAndTimeBasedFNATP will overwrite previous logging files with index > 9 on restart app.

Dieter Mueller (JIRA)

Ceki Gulcu (JIRA)

Ceki Gulcu (JIRA)

tags

participants (2)