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

logs appenders with prudent mode do not recover after "no space left on device" error

    XMLWordPrintable

Details

    • Icon: Bug Bug
    • Resolution: Fixed
    • Icon: Major Major
    • 1.1.3
    • None
    • logback-core
    • None

    Description

      Hey,
      I've seen that this error has been around for some time and I hope that this description is complete and will be helpful in reproducing and fixing.

      System:
      a logback.xml with a file appender with prudent=true.
      the log path should be to a volume with little available space.

      Scenario:
      start writing to the log file. as soon as the space is depleted, errors start happening:
      15:44:40,595 |-ERROR in c.q.l.c.recovery.ResilientFileOutputStream@1944673755 - IO failure while writing to file [/Volumes/TESTVOL/logs/my-log.2015-02-01.log] java.io.IOException: No space left on device
      at java.io.IOException: No space left on device
      at at java.io.FileOutputStream.writeBytes(Native Method)
      at at java.io.FileOutputStream.write(FileOutputStream.java:345)
      at at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:82)
      at at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:140)
      at at ch.qos.logback.core.recovery.ResilientOutputStreamBase.flush(ResilientOutputStreamBase.java:79)
      [...]
      15:44:51,064 |-INFO in c.q.l.c.recovery.ResilientFileOutputStream@1944673755 - Attempting to recover from IO failure on file [/Volumes/TESTVOL/logs/my-log.2015-02-01.log]
      15:44:51,064 |-INFO in c.q.l.c.recovery.ResilientFileOutputStream@1944673755 - Recovered from IO failure on file [/Volumes/TESTVOL/logs/my-log.2015-02-01.log]
      15:44:51,064 |-ERROR in ch.qos.logback.core.rolling.RollingFileAppender[MY_LOG] - IO failure in appender java.nio.channels.ClosedChannelException
      at java.nio.channels.ClosedChannelException
      at at sun.nio.ch.FileLockImpl.release(FileLockImpl.java:58)

      and then:
      15:44:51,069 |-WARN in ch.qos.logback.core.rolling.RollingFileAppender[MY_LOG] - Attempted to append to non started appender [MY_LOG].

      Debugging:
      i have investigated this issue and found the culprit to be line 204 in FileAppender:
      finally {
      if (fileLock != null)

      { ---> fileLock.release(); }

      [...]

      the problem is that when the original IOException was thrown, the channel was closed as part of the attemptRecovery method in ResilientOutputStreamBase.
      the release will throw a ClosedChannelException if the file channel is closed.
      the appender is then set to started=false in OutputStreamAppender subAppend Method and stays this way until restarted.

      Fix suggestion:
      the easy fix here is changing the guard of the release:
      finally {
      if (fileLock != null && fileChannel.isOpen())

      { fileLock.release(); }

      [...]

      this prevents the release from throwing the exception.

      for now, an easy mitigation (if possible) is to set prudent=false.

      hope this helps and the bug will be fixed.

      Attachments

        Activity

          People

            tony19 Tony Trinh
            nadavwe Nadav Wexler
            Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved: