Correctly disconnecting when using local and remote port forwarding

[Velstadt]

I am currently writing an application that involves connecting to an Amazon EC2 instance and then using SSHJ to tunnel RMI over SSH. I managed to get the port forwarding set up and working from looking at the provided tutorials but I get errors when disconnecting from the SSHClient. I am starting the local port forwarder in a separate thread like so:

executor.submit(() -> {
                Parameters params = new Parameters("127.0.0.1", port, "127.0.0.1", port);
                try(ServerSocket ss = new ServerSocket()){
                    ss.bind(new InetSocketAddress(params.getLocalHost(), params.getLocalPort()));
                    client.newLocalPortForwarder(params, ss).listen();
                }
                catch(IOException ex){
                    ex.printStackTrace(System.out);
                    System.out.println("problem (probably serversocket)");
                }
            });

I have also tried just using new Thread(...).start(); instead of ExecutorService with the same results.

And the remote port forwarder (I was originally running this in it's own thread as well and calling client.getTransport().join() but it seemed to work fine without it):

client.getRemotePortForwarder().bind(new Forward("127.0.0.1", 8080), new SocketForwardingConnectListener(new InetSocketAddress("127.0.0.1", 8080)));
client.getConnection().getKeepAlive().setKeepAliveInterval(30);

I am getting the following error when client.disconnect(); is called:

[main] INFO net.schmizz.sshj.connection.channel.direct.LocalPortForwarder - Closing listener on /127.0.0.1:5000
[main] INFO net.schmizz.sshj.transport.TransportImpl - Disconnected - BY_APPLICATION
[chan2soc] ERROR net.schmizz.sshj.common.StreamCopier - In pipe from < ChannelInputStream for Channel #8 > to java.net.SocketOutputStream@74480065
net.schmizz.sshj.transport.TransportException: [BY_APPLICATION] Disconnected
	at net.schmizz.sshj.transport.TransportImpl.disconnect(TransportImpl.java:410)
	at net.schmizz.sshj.transport.TransportImpl.disconnect(TransportImpl.java:401)
	at net.schmizz.sshj.transport.TransportImpl.disconnect(TransportImpl.java:396)
	at net.schmizz.sshj.SSHClient.disconnect(SSHClient.java:434)
	at masterapplication.CloudConnection.closeConnection(CloudConnection.java:128)
	at masterapplication.CommunicationController.cleanup(CommunicationController.java:401)
	at view.ViewController.waitForGUI(ViewController.java:64)
	at masterapplication.CommunicationController.main(CommunicationController.java:449)

Sometimes it will also give this error immediately after the one above (seems to only happen if I start the remote port forwarder):

[sockmon] ERROR net.schmizz.concurrent.Promise - <<copyDone>> woke to: net.schmizz.sshj.transport.TransportException: [BY_APPLICATION] Disconnected
[soc2chan] ERROR net.schmizz.sshj.common.StreamCopier - In pipe from java.net.SocketInputStream@70ff915 to < ChannelOutputStream for Channel #8 >
java.net.SocketException: Socket closed
	at java.net.SocketInputStream.socketRead0(Native Method)
	at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
	at java.net.SocketInputStream.read(SocketInputStream.java:170)
	at java.net.SocketInputStream.read(SocketInputStream.java:141)
	at java.net.SocketInputStream.read(SocketInputStream.java:127)
	at net.schmizz.sshj.common.StreamCopier.copy(StreamCopier.java:131)
	at net.schmizz.sshj.common.StreamCopier$3.run(StreamCopier.java:110)

I assume that I'm just not closing something properly but I have tried things like keeping a reference to the returned LocalPortForwarder from client.newLocalPortForwarder(params, ss); and then closing it before calling client.disconnect();

Any help with working out why this is happening would be greatly appreciated. It seems to be more of an annoyance than anything else because the tunnelling itself does work. If you need any more information please let me know.

[DarrMirr]

Hi!

I have same issue with local port forward. I suppose that issue appears due to SocketStreamCopyMonitor class. When you invoke listen() method then instance of LocalPortForwarder.DirectTCPIPChannel class is created and invoked start() method. After that anonymous daemon threads are created by SocketStreamCopyMonitor. I suppose this threads have incorrect condition of termination. Unfortunatly, I can't find how change this condition and check my suggestion.

Also I notice that issue appears when you send data over ssh tunnel. If you create local port forward and close it without sending data, error doesn't appear.

In conslusion when disconnect() method is invoked on ssh client then socket is closed. But daemon threads are still alive because exactly they aren't closed. And it seem there is issue with condition of termination these daemon threads.

[kyle-cackett]

Hey, I am hitting this issue in my application as well. I am considering putting together a pull-request for SSHJ which would close the threads gracefully when the client is disconnected. Could you provide any suggestions as to what a fix for this might look like or where in the code I might start investigating?

Thanks!

[DarrMirr]

Hello!

Class SocketStreamCopyMonitor is created as anonymous one. Personally I believe the easiest way is Shutdown Hooks API. Also you can change condition of infinite loop. I think daemon threads are closed if that condition evaluate false after program is closed. But I have no idea how to fix this condition.

[saimsiddiqui]

I am running into the same issue while trying to disconnect the SSHClient. Has there been an update on this? Is there any workaround?

Trace of the issue:

[ERROR] 2018-07-23 17:06:35.389 [soc2chan] StreamCopier - In pipe from java.net.SocketInputStream@53b38d2c to < ChannelOutputStream for Channel #0 > net.schmizz.sshj.transport.TransportException: Socket closed at net.schmizz.sshj.transport.TransportImpl.write(TransportImpl.java:454) ~[sshj-0.23.1-SNAPSHOT.jar:0.23.1-SNAPSHOT] at net.schmizz.sshj.connection.channel.ChannelOutputStream$DataBuffer.flush(ChannelOutputStream.java:102) ~[sshj-0.23.1-SNAPSHOT.jar:0.23.1-SNAPSHOT] at net.schmizz.sshj.connection.channel.ChannelOutputStream$DataBuffer.flush(ChannelOutputStream.java:70) ~[sshj-0.23.1-SNAPSHOT.jar:0.23.1-SNAPSHOT] at net.schmizz.sshj.connection.channel.ChannelOutputStream.flush(ChannelOutputStream.java:182) ~[sshj-0.23.1-SNAPSHOT.jar:0.23.1-SNAPSHOT] at net.schmizz.sshj.common.StreamCopier.write(StreamCopier.java:157) ~[sshj-0.23.1-SNAPSHOT.jar:0.23.1-SNAPSHOT] at net.schmizz.sshj.common.StreamCopier.copy(StreamCopier.java:132) ~[sshj-0.23.1-SNAPSHOT.jar:0.23.1-SNAPSHOT] at net.schmizz.sshj.common.StreamCopier$3.run(StreamCopier.java:110) [sshj-0.23.1-SNAPSHOT.jar:0.23.1-SNAPSHOT] Caused by: java.net.SocketException: Socket closed at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:118) ~[?:1.8.0_131] at java.net.SocketOutputStream.write(SocketOutputStream.java:155) ~[?:1.8.0_131] at net.schmizz.sshj.transport.TransportImpl.write(TransportImpl.java:451) ~[sshj-0.23.1-SNAPSHOT.jar:0.23.1-SNAPSHOT] ... 6 more

Right after

[ERROR] 2018-07-23 17:06:35.386 [chan2soc] StreamCopier - In pipe from < ChannelInputStream for Channel #0 > to java.net.SocketOutputStream@55846825 net.schmizz.sshj.transport.TransportException: Disconnected at net.schmizz.sshj.transport.TransportImpl.disconnect(TransportImpl.java:413) ~[sshj-0.23.1-SNAPSHOT.jar:0.23.1-SNAPSHOT] at net.schmizz.sshj.transport.TransportImpl.disconnect(TransportImpl.java:404) ~[sshj-0.23.1-SNAPSHOT.jar:0.23.1-SNAPSHOT] at net.schmizz.sshj.transport.TransportImpl.disconnect(TransportImpl.java:399) ~[sshj-0.23.1-SNAPSHOT.jar:0.23.1-SNAPSHOT] at net.schmizz.sshj.SSHClient.disconnect(SSHClient.java:440) ~[sshj-0.23.1-SNAPSHOT.jar:0.23.1-SNAPSHOT]

Then

[ERROR] 2018-07-23 17:06:35.422 [sockmon] Promise - <<copyDone>> woke to: net.schmizz.sshj.transport.TransportException: Socket closed

[oakkitten]

i'm still getting this error in 0.30

also, if i don't close the forwarding socket (the one that connects to the ServerSocket), i don't get these log lines:

soc2 : net.schmizz.sshj.common.StreamCopier 0.3 KiB transferred in 2.1 seconds (0.16 KiB/s)
soc2 : net.schmizz.sshj.common.StreamCopier Done copying from java.net.SocketInputStream@3453224

but instead i do get a lot of these

sock : net.schmizz.concurrent.Promise Awaiting <<copyDone>>
sock : net.schmizz.concurrent.Promise Awaiting <<copyDone>>

i'm really not sure what to make of this

[hsoehalim]

any update on this issue?

[farion]

I have the same issue.

Our implementation is here: https://github.com/EXXETA/correomqtt/blob/0425407d213a92cde4f4a722abe5fcee780be3a3/src/main/java/org/correomqtt/business/mqtt/BaseCorreoMqttClient.java#L258