QOS.ch JIRA

  • Log In Access more options
    • Online Help
    • Keyboard Shortcuts
    • About JIRA
    • JIRA Credits
    • What’s New
  • Dashboards Access more options (Alt+d)
  • Projects Access more options (Alt+p)
  • Issues Access more options (Alt+i)
  • logback-core
  • LBCORE-164

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

  • Log In
  • Views
    • XML
    • Word
    • Printable

Details

  • Type: Bug Bug
  • Status: Resolved Resolved
  • Priority: Major Major
  • Resolution: Fixed
  • Affects Version/s: 0.9.24
  • Fix Version/s: None
  • Component/s: Rolling
  • Labels:
    None
  • Environment:
    Windows XP, java jdk1.6.0_18

Description

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++;
    }
  }

Activity

  • All
  • Comments
  • History
  • Activity
Hide
Permalink
Ceki Gulcu added a comment - 13/Oct/10 11:25 PM
This is one of the best bug reports I have ever seen. Fixed in http://github.com/ceki/logback/commit/b5c7149857fa174



Show
Ceki Gulcu added a comment - 13/Oct/10 11:25 PM This is one of the best bug reports I have ever seen. Fixed in http://github.com/ceki/logback/commit/b5c7149857fa174

People

  • Assignee:
    Ceki Gulcu
    Reporter:
    Dieter Mueller
Vote (0)
Watch (0)

Dates

  • Created:
    10/Aug/10 2:41 PM
    Updated:
    13/Oct/10 11:25 PM
    Resolved:
    13/Oct/10 11:25 PM
  • Atlassian JIRA (v5.0.4#731-sha1:3aa7374)
  • Report a problem
  • Powered by a free Atlassian JIRA open source license for logback. Try JIRA - bug tracking software for your team.