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

totalSizeCap susceptible to race condition

    XMLWordPrintable

Details

    • Icon: Bug Bug
    • Resolution: Unresolved
    • Icon: Major Major
    • None
    • 1.1.7
    • logback-core
    • None

    Description

      When the totalSizeCap code is executed, it is done asynchronously and may sometimes delete the current log file. This is what seems to be happening on the regular test failures seen in Travis CI for TimeBasedRollingWithArchiveRemoval_Test#checkThatSmallTotalSizeCapLeavesAtLeastOneArhcive:

      • successful log to clean-2016-03-25.txt
      • another log happens
        • rollover event happens
        • TimeBasedArchiveRemover#cleanAsynchronously is invoked
          • ArhiveRemoverRunnable is queued up asynchronously
        • log is written to clean-2016-03-26.txt (the newly created file from rollover event)
      • async cleanup thread runs
        • clean-2016-03-26.txt (current log file) is deleted because the single log event contained in the current file (75 bytes) is enough to exceed the cap (1 byte)
      • logs continue to be written to the open file descriptor, which is a deleted log file (i.e., lost)

      This is happening regularly on Travis. Locally, I could reproduce it ~10% of the time. I tried adding a Thread.sleep() to the beginning of the async code to help simulate the slower conditions, and it caused the test to fail consistently.

      One of the main problems here is that the deletion code doesn't limit itself to archived files, as the docs suggest, but all files including the current one.

      Attachments

        Activity

          People

            logback-dev Logback dev list
            ericdahl Eric Dahl
            Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

            Dates

              Created:
              Updated: