[SSHD-901] InterruptedByTimeoutException occurring in client despite keepalive global request being sent

• Type: Bug
• Status: Resolved
• Priority: Major
• Resolution: Fixed
• Affects Version/s: 2.2.0
• Fix Version/s: 2.3.0
• Environment: Windows 10
• Assignee: Lyor Goldstein
• Reporter: Jared Wiltshire
• Created: 26/Feb/19 00:30
• Updated: 21/Jul/20 20:10
• Resolved: 28/Feb/19 07:02

Description

This may be related to SSHD-891 but I couldn't follow that issue exactly.

I was noticed that after exactly 10 minutes and 15 minutes a java.nio.channels.InterruptedByTimeoutException exception was being thrown by the client. After a little digging I discovered that this is the default value for NIO2_READ_TIMEOUT. This is the stack trace -

ERROR 2019-02-25T17:25:16,879 (com.infiniteautomation.mango.cloudConnect.client.CloudConnectClient$ClientSessionListener.sessionException:83) - Session exception, session ClientSessionImpl[mango@localhost/127.0.0.1:9005] 
java.nio.channels.InterruptedByTimeoutException: null
	at sun.nio.ch.WindowsAsynchronousSocketChannelImpl$ReadTask.timeout(WindowsAsynchronousSocketChannelImpl.java:614) ~[?:1.8.0_144]
	at sun.nio.ch.WindowsAsynchronousSocketChannelImpl$2.run(WindowsAsynchronousSocketChannelImpl.java:649) ~[?:1.8.0_144]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ~[?:1.8.0_144]
	at java.util.concurrent.FutureTask.run(FutureTask.java:266) ~[?:1.8.0_144]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) ~[?:1.8.0_144]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) ~[?:1.8.0_144]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) ~[?:1.8.0_144]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) ~[?:1.8.0_144]
	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_144]

Now I have the heat beat interval (ClientFactoryManager.HEARTBEAT_INTERVAL) property set to less than 10 minutes and I verified that the global request is indeed being sent and received by the server.

However I think that the issue is that the global request is sent with wantReply set to false. So the server does not reply with anything and the client does not read any data from the socket and hence times out.

Does it not make sense for the server to reply? I believe this is a self defined global request (not in the SSH RFC) so we should be able change its behavior.

Issue Links

• relates to: SSHD-782 Consider implementing a "reverse" keep-alive mechanism in the server
• supercedes: SSHD-1020 SSH connections getting closed abruptly with timeout exceptions. java.nio.channels.InterruptedByTimeoutException
• links to: GitHub Pull Request #95
• links to: How to Keep Alive SSH Sessions