Windows unclosed file handle bug introduced between 1.3.15 and 1.5.19 for FileAppender

[theangrydev]

Description

When using a FileAppender (or RollingFileAppender) and calling LoggerContext.stop(), the log file handle is not immediately released on Windows. Using Sysinternals handle.exe shows that java.exe still holds an open file handle to the log file after stop() returns.

This behavior changed between version 1.3.15 (which properly released handles) and 1.5.19 (which does not).

Impact

• Applications that need to delete or move log files after stopping logging cannot do so reliably
• May cause file locking issues in applications that restart logging or manage log file rotation externally

Steps to Reproduce

1. Configure logback with a FileAppender:

   <configuration>
       <appender name="FILE" class="ch.qos.logback.core.FileAppender">
           <file>logs/test.log</file>
           <encoder>
               <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern>
           </encoder>
       </appender>
       <root level="info">
           <appender-ref ref="FILE"/>
       </root>
   </configuration>

2. Initialize and use the logger:

   LoggerContext loggerContext = (LoggerContext) LoggerFactory.getILoggerFactory();
   Logger logger = loggerContext.getLogger("test");
   logger.info("Test message");

3. Stop the logging context:

   loggerContext.stop();

4. Check open file handles on Windows:

   handle.exe logs\test.log

Expected Result: No processes should have the file open

Actual Result: java.exe still has an open file handle to logs\test.log

Workaround

When you let LoggerContext.stop() handle it (1.5.19):

public void stop() {
    try {
        configurationLock.lock();  // <-- Lock acquired
        reset();                    // Eventually calls FileAppender.stop()
          └─> root.recursiveReset()
              └─> FileAppender.stop()
                  └─> OutputStreamAppender.stop()
                      └─> closeOutputStream()  // File close happens HERE
        fireOnStop();
        resetAllListeners();
        super.stop();
    } finally {
        configurationLock.unlock(); // <-- Lock released
    }
}

The file close happens inside the configurationLock critical section. On Windows, the file handle may not be released until the lock is fully released and the method returns.

When you stop the FileAppender directly first:

Workaround:

findAppender(FileAppender.class).ifPresent(Appender::stop);  // <-- Happens OUTSIDE configurationLock
getLoggerContext().stop();

This calls:

FileAppender.stop()
  └─> OutputStreamAppender.stop()
      └─> streamWriteLock.lock()    // <-- Different lock, not configurationLock
      └─> closeOutputStream()        // File closes immediately
      └─> streamWriteLock.unlock()

The file close happens outside the configurationLock context, so Windows releases the handle immediately.

In 1.3.15 it worked because:
There was no configurationLock wrapping the entire stop sequence, so the file handle was released immediately after closeOutputStream() completed.

[ceki]

@theangrydev Thank you for this detailed report.

The file is supposed remain open after calling loggerContext.stop() which is not what I observe. The file is not open. Thus, on Windows 11 Home and JDK 22, I am unable to reproduce the problem. The Java file I am using is available as a gist file.

Which version of Windows and Java are you using?

[theangrydev]

I see the issue on a Windows Server 2019 build agent with Eclipse Adoptium jdk-17.0.14.7-hotspot via a JUnit test, which began to fail after the logback update due to the file handle issue.

The workaround was to close the FileAppender directly as well as the LoggerContext, that one line change fixed the issue for my use case.

It might be there are other conditions needed to reproduce that I'm not aware of.

This isn't a priority personally at the moment since the workaround is good enough and I don't have the spare time to debug it further.