session.close() times out

[tomaskir]

trafficstars

Greetings,

I am getting exceptions trying to close a session:

DEBUG net.schmizz.sshj.connection.channel.direct.SessionChannel - Initialized - < session channel: id=0, recipient=0, localWin=[winSize=2097152], remoteWin=[winSize=0] >
DEBUG net.schmizz.concurrent.Promise - Setting <<chan#0 / open>> to `SOME`
DEBUG net.schmizz.sshj.connection.channel.direct.SessionChannel - Sending channel request for `pty-req`
DEBUG net.schmizz.concurrent.Promise - Awaiting <<chan#0 / chanreq for pty-req>>
TRACE net.schmizz.sshj.transport.TransportImpl - Received packet CHANNEL_SUCCESS
DEBUG net.schmizz.concurrent.Promise - Setting <<chan#0 / chanreq for pty-req>> to `SOME`
DEBUG net.schmizz.sshj.connection.channel.direct.SessionChannel - Sending channel request for `shell`
DEBUG net.schmizz.concurrent.Promise - Awaiting <<chan#0 / chanreq for shell>>
TRACE net.schmizz.sshj.transport.TransportImpl - Received packet CHANNEL_WINDOW_ADJUST
DEBUG net.schmizz.sshj.connection.channel.direct.SessionChannel - Received window adjustment for 131072 bytes
DEBUG net.schmizz.sshj.connection.channel.Window$Remote - Increasing by 131072 up to 131072
TRACE net.schmizz.sshj.transport.TransportImpl - Received packet CHANNEL_SUCCESS
DEBUG net.schmizz.concurrent.Promise - Setting <<chan#0 / chanreq for shell>> to `SOME`
TRACE net.schmizz.sshj.transport.TransportImpl - Received packet CHANNEL_DATA
DEBUG net.schmizz.sshj.connection.channel.Window$Local - Consuming by 64 down to 2097088
DEBUG net.schmizz.sshj.connection.channel.direct.SessionChannel - Sending close
DEBUG net.schmizz.concurrent.Promise - Awaiting <<chan#0 / close>>
Exception in thread "main" net.schmizz.sshj.connection.ConnectionException: Timeout expired
	at net.schmizz.sshj.connection.ConnectionException$1.chain(ConnectionException.java:32)
	at net.schmizz.sshj.connection.ConnectionException$1.chain(ConnectionException.java:26)
	at net.schmizz.concurrent.Promise.retrieve(Promise.java:139)
	at net.schmizz.concurrent.Event.await(Event.java:105)
	at net.schmizz.sshj.connection.channel.AbstractChannel.close(AbstractChannel.java:265)
	at local.test.sshj.Main.main(Main.java:66)
Caused by: java.util.concurrent.TimeoutException: Timeout expired
	... 4 more

The code is simple:

final SSHClient sshC = new SSHClient(new DefaultConfig());
sshC.addHostKeyVerifier(new PromiscuousVerifier());

sshC.connect(address, port);
sshC.authPassword(username, password);

Session session = sshC.startSession();
session.allocateDefaultPTY();
Session.Shell shell = session.startShell();

session.close();
sshC.disconnect();

System.out.println("done");

Any idea what could be wrong or how to further debug this?

Thanks!

[hierynomus]

Can you take a look at the DisconnectionTest class? I've tried to reproduce your code, but I'm not getting the timeout in there.

[x12a1f]

I have the same issue but it depends on the ssh server. My code:

        SSHClient client = new SSHClient();
        client.addHostKeyVerifier((hostname, port, key) -> true);
        client.connect("xxxx");
        client.authPassword("xxx", "xxx");

        Session session = client.startSession();
        Session.Shell shell = session.startShell();

        session.close();
        client.disconnect();

If I use it to connect to my switch, it just waits for a couple of seconds after calling session.close() and then gives a ConnectionException: Timeout expired. If I connect to another ssh server, it works fine.

Logs when connecting to my switch:

    15:17:57 D Received window adjustment for 131072 bytes   
    15:17:57 D Increasing by 131072 up to 131072   
    15:17:57 D Setting <<chan#0 / chanreq for shell>> to `SOME`   
    15:17:57 D Sending close   
    15:17:57 D Consuming by 66 down to 2097086   
    15:17:57 D Awaiting <<chan#0 / close>>   
    15:18:27 E Exception 
    net.schmizz.sshj.connection.ConnectionException: Timeout expired
        at net.schmizz.sshj.connection.ConnectionException$1.chain(ConnectionException.java:32)
        at net.schmizz.sshj.connection.ConnectionException$1.chain(ConnectionException.java:26)
        at net.schmizz.concurrent.Promise.retrieve(Promise.java:139)
        at net.schmizz.concurrent.Event.await(Event.java:105)
        at net.schmizz.sshj.connection.channel.AbstractChannel.close(AbstractChannel.java:266)
        at org.et10.datathing.processor.monitor.zyxel1920.Zyxel1920Test.disconnect(Zyxel1920Test.java:38)
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    Caused by: java.util.concurrent.TimeoutException: Timeout expired
        at net.schmizz.concurrent.Promise.retrieve(Promise.java:139)
        at net.schmizz.concurrent.Event.await(Event.java:105)
        at net.schmizz.sshj.connection.channel.AbstractChannel.close(AbstractChannel.java:266)
        at org.et10.datathing.processor.monitor.zyxel1920.Zyxel1920Test.disconnect(Zyxel1920Test.java:38)
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)

I've worked around it by ignoring the exception when it is caused by a TimeoutException but it would be nice if there is a cleaner way to do this.

I'm using version 0.31.0

Thanks.