SshServer shutdown on Windows may report exceptions about already shut down ExecutorService

[tomaswolf]

Version

2.10.0

Bug description

From the mailing list:

Attached code causes circa 50 exceptions:

public static void main(String[] args) throws Exception {

    for (int i = 0; i < 100; i++) {
        SshServer sshd = SshServer.setUpDefaultServer();
        SimpleGeneratorHostKeyProvider hostKeyProvider = new SimpleGeneratorHostKeyProvider(
            Paths.get(".", "cert"));
        hostKeyProvider.setAlgorithm(KeyUtils.RSA_ALGORITHM);

        sshd.setKeyPairProvider(hostKeyProvider);
        sshd.start();
        sshd.stop(false);
    }
}

Actual behavior

Lots of exceptions about an already shut down ExecutorService are logged.

This occurs on Windows only; it's not reproducible on Linux.

Expected behavior

No exceptions are logged; the server shuts down cleanly.

Relevant log output

Exception in thread "Thread-3" Exception in thread "Thread-2"
java.lang.IllegalStateException: Executor has been shut down
        at
org.apache.sshd.common.util.ValidateUtils.createFormattedException(ValidateUtils.java:213)
        at
org.apache.sshd.common.util.ValidateUtils.throwIllegalStateException(ValidateUtils.java:207)
        at
org.apache.sshd.common.util.ValidateUtils.checkState(ValidateUtils.java:184)
        at
org.apache.sshd.common.util.threads.NoCloseExecutor.execute(NoCloseExecutor.java:100)
        at
java.base/sun.nio.ch.AsynchronousChannelGroupImpl.executeOnPooledThread(AsynchronousChannelGroupImpl.java:190)
        at java.base/sun.nio.ch.Invoker.invokeIndirectly(Invoker.java:215)
        at java.base/sun.nio.ch.Invoker.invokeIndirectly(Invoker.java:316)
        at
java.base/sun.nio.ch.WindowsAsynchronousServerSocketChannelImpl$AcceptTask.failed(WindowsAsynchronousServerSocketChannelImpl.java:288)
        at java.base/sun.nio.ch.Iocp$EventHandlerTask.run(Iocp.java:389)
        at java.base/java.lang.Thread.run(Thread.java:1589)

Other information

OS: Windows

Originally reported using temurin 19.0.2.7 and Apache MINA sshd 2.10.0, but it also occurs with other JVMs/JDKs.

[tomaswolf]

Compare also https://stackoverflow.com/questions/14073554 : that is exactly the same problem, but without Apache MINA sshd in the loop.

That example just uses group.shutdownNow() to close the acceptor and the group. Apache MINA sshd in its Nio2Acceptor and Nio2ServiceFactory first explicitly closes the acceptor, and then the group, so that would correspond to

acceptor.close();
group.shutdown();

in that example.

What happens is that closing the acceptor causes an AsynchronousCloseException that should be reported via the CompletionHandler passed to acceptor.accept().

This appears to work fine on Unix, but on Windows, the task calling CompletionHandler.failed() ends up being executed via the thread pool of the AsynchronousChannelGroup after that thread pool has already been shut down.

It's unclear to me whether this a JDK bug. If closing the AsynchronousServerSocketChannel has such asynchronous effects, then either the AsynchronousChannelGroup should wait with shutting down its thread pool until all such asynchronous effects are done with, or AsynchronousServerSocketChannel.close() should return a Future that could be used to wait until the channel is really closed (and a possible AsynchronousCloseException has been dealt with). Then client code could wait on that Future, and only then shut down the group.

One way to avoid these exceptions is to give the group a ThreadPoolExecutor with a rejection policy that simply discards executions on an already shut down executor, such as a CallerRunsPolicy. But that is more like a work-around.

[tomaswolf]

Interesting: https://bugs.openjdk.org/browse/JDK-7056546 (from 2011, reported against Java 1.7):

This bug is a bit of a corner case that is specific to Windows and specific to cases where a channel group is constructed with a custom thread pool. [...] in this test case the last remaining channel is closed just prior to doing the shutdown. This creates a race where the task to invoke the completion handler isn't submitted before the thread pool is shutdown. The bug is not critical to 7 and we will examine solutions for a future release.

Well, that bug is still in state "open". Sounds very much what we are seeing here: we have a single channel (the acceptor) and close it before the group shutdown, and the problem exists only on Windows.