Issue Type: Bug Bug
Assignee: Logback dev list
Components: logback-core
Created: 01/Feb/15 3:37 PM
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.

Project: logback
Priority: Major Major
Reporter: Nadav Wexler
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira