[SSHD-1281] ClientSession.auth().verify() is terminated with timeout

• Type: Bug
• Status: Resolved
• Priority: Major
• Resolution: Fixed
• Affects Version/s: 2.9.0
• Fix Version/s: 2.9.1
• Environment: Java SE 8, Apache NetBeans IDE 12.5, Bitvise SSH Server 9.23
• Assignee: Thomas Wolf
• Reporter: dgü
• Created: 27/Jul/22 21:31
• Updated: 02/Aug/22 21:40
• Resolved: 02/Aug/22 21:40

Description

Hello!

The following code works successfully in SSHD 2.8.0; but it fails in SSHD 2.9.0:

        final ClientSession clientSession = SSH_CLIENT.connect(pURI.toString()).verify().getSession();
        System.out.println("clientSession.getSessionState(): " + clientSession.getSessionState());
        System.out.println("clientSession.isClosed()       : " + clientSession.isClosed());
        System.out.println("clientSession.isClosing()      : " + clientSession.isClosing());
        System.out.println("clientSession.isOpen()         : " + clientSession.isOpen());
        System.out.println("before addPasswordIdentity: " + new Date(System.currentTimeMillis()));
        clientSession.addPasswordIdentity("deneme123");

        try {
            Thread.sleep(3000);
        } catch (InterruptedException ex) {
            Logger.getLogger(UBSSHDProcessProvider.class.getName()).log(Level.SEVERE, null, ex);
        }

        System.out.println("clientSession.getSessionState(): " + clientSession.getSessionState());
        System.out.println("clientSession.isClosed()       : " + clientSession.isClosed());
        System.out.println("clientSession.isClosing()      : " + clientSession.isClosing());
        System.out.println("clientSession.isOpen()         : " + clientSession.isOpen());

        System.out.println("before auth().verify(): " + new Date(System.currentTimeMillis()));
        clientSession.auth().verify();

The output and exception:

Tem 27, 2022 11:50:19 PM org.apache.sshd.common.io.DefaultIoServiceFactoryFactory getIoServiceProvider
INFO: No detected/configured IoServiceFactoryFactory using Nio2ServiceFactoryFactory
clientSession.getSessionState(): []
clientSession.isClosed() : false
clientSession.isClosing() : false
clientSession.isOpen() : true
before addPasswordIdentity: Wed Jul 27 23:50:19 EET 2022
clientSession.getSessionState(): []
clientSession.isClosed() : false
clientSession.isClosing() : false
clientSession.isOpen() : true
before auth().verify(): Wed Jul 27 23:50:22 EET 2022
Tem 27, 2022 11:52:20 PM org.apache.sshd.common.session.helpers.SessionHelper disconnect
INFO: Disconnecting(ClientSessionImpl[deneme@/127.0.0.1:22]): SSH2_DISCONNECT_PROTOCOL_ERROR - Detected AuthTimeout after 120687/120000 ms.
Exception in thread "main" org.apache.sshd.common.SshException: Session is being closed
at org.apache.sshd.common.future.AbstractSshFuture.verifyResult(AbstractSshFuture.java:127)
at org.apache.sshd.client.future.DefaultAuthFuture.verify(DefaultAuthFuture.java:39)
at org.apache.sshd.client.future.DefaultAuthFuture.verify(DefaultAuthFuture.java:32)
at org.apache.sshd.common.future.VerifiableFuture.verify(VerifiableFuture.java:43)
at com.ubtools.ubutils.system.impl.UBSSHDProcessProvider.getServiceConnection(UBSSHDProcessProvider.java:85)
at com.ubtools.ubutils.system.impl.UBSSHDProcessProvider.getServiceConnection(UBSSHDProcessProvider.java:19)
at com.ubtools.ubutils.service.UBServiceManager.getServiceConnection(UBServiceManager.java:135)
at com.ubtools.ubutils.UBExec.main(UBExec.java:33)
Caused by: org.apache.sshd.common.SshException: Session is being closed
at org.apache.sshd.client.session.ClientSessionImpl.preClose(ClientSessionImpl.java:169)
at org.apache.sshd.common.util.closeable.AbstractCloseable.close(AbstractCloseable.java:94)
at org.apache.sshd.common.session.helpers.AbstractSessionIoHandler.sessionClosed(AbstractSessionIoHandler.java:46)
at org.apache.sshd.common.io.nio2.Nio2Session.doCloseImmediately(Nio2Session.java:283)
at org.apache.sshd.common.util.closeable.AbstractCloseable.close(AbstractCloseable.java:95)
at org.apache.sshd.common.io.nio2.Nio2Session.exceptionCaught(Nio2Session.java:215)
at org.apache.sshd.common.io.nio2.Nio2Session.handleWriteCycleFailure(Nio2Session.java:548)
at org.apache.sshd.common.io.nio2.Nio2Session$2.onFailed(Nio2Session.java:506)
at org.apache.sshd.common.io.nio2.Nio2CompletionHandler.lambda$failed$1(Nio2CompletionHandler.java:46)
at java.security.AccessController.doPrivileged(Native Method)
at org.apache.sshd.common.io.nio2.Nio2CompletionHandler.failed(Nio2CompletionHandler.java:45)
at sun.nio.ch.Invoker.invokeUnchecked(Invoker.java:128)
at sun.nio.ch.Invoker$2.run(Invoker.java:218)
at sun.nio.ch.AsynchronousChannelGroupImpl$1.run(AsynchronousChannelGroupImpl.java:112)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
C:\Users\dunal\AppData\Local\NetBeans\Cache\12.5\executor-snippets\run.xml:111: The following error occurred while executing this line:
C:\Users\dunal\AppData\Local\NetBeans\Cache\12.5\executor-snippets\run.xml:94: Java returned: 1
BUILD FAILED (total time: 2 minutes 2 seconds)

The attached Bitvise SSH Server shows that the connection has ended at 23:50.19, which is immediately after SSH_CLIENT.connect(pURI.toString()).verify().getSession().

I added Thread.sleep(3000) to see if ClientSession state changes. After 3 seconds sleep, client session is still open. But, clientSession.auth().verify() is terminated with timeout after 2 minutes.

 

Issue Links

• is caused by: SSHD-1285 2.9.0 release broken on Java 8