[
https://issues.apache.org/jira/browse/SSHD-1020?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17162829#comment-17162829
]
Guillaume Nodet commented on SSHD-1020:
---------------------------------------
Yeah, we could implement the counter thing too. In theory this would help
making a difference between a really busy ssh server and an unresponsive one,
though i'm not convinced that a busy server can simply drop a request and
respond to the next one, that could really be problematic if the requests are
anything else than keepalive requests. So I'm not completely convinced about
that feature yet. We can always raise a JIRA later.
I'll commit the PR with the 2 changes in default values:
* HEARTBEAT_REPLY_WAIT to 5 minutes
* NIO2_READ_TIMEOUT to zero (infinite timeout)
I think this will help a lot users so that setting {{heartbeat-interval}}
should be enough to have proper support for keeping sessions alive.
> SSH connections getting closed abruptly with timeout exceptions.
> java.nio.channels.InterruptedByTimeoutException
> ----------------------------------------------------------------------------------------------------------------
>
> Key: SSHD-1020
> URL: https://issues.apache.org/jira/browse/SSHD-1020
> Project: MINA SSHD
> Issue Type: Bug
> Affects Versions: 2.2.0
> Reporter: Sivanagarajup
> Assignee: Guillaume Nodet
> Priority: Blocker
> Fix For: 2.6.0
>
> Attachments: image-2020-06-26-15-18-58-509.png,
> image-2020-06-26-15-22-17-259.png, server.log
>
> Time Spent: 10m
> Remaining Estimate: 0h
>
> Hi Team
> SSH sessions are closing with timeout exceptions as mentioned below
> {code:java}
> 2020-06-18 03:07:11,942 DEBUG [org.apache.sshd.common.io.nio2.Nio2Session]
> (sshd-SshServer[6c96892e](port=8345)-nio2-thread-1)
> exceptionCaught(Nio2Session[local=/10.1.2.3:8345,
> remote=/20.24.16.108:41480]) caught InterruptedByTimeoutException[null] -
> calling handler2020-06-18 03:07:11,942 DEBUG
> [org.apache.sshd.common.io.nio2.Nio2Session]
> (sshd-SshServer[6c96892e](port=8345)-nio2-thread-1)
> exceptionCaught(Nio2Session[local=/10.1.2.3:8345,
> remote=/20.24.16.108:41480]) caught InterruptedByTimeoutException[null] -
> calling handler2020-06-18 03:07:11,943 WARN
> [org.apache.sshd.server.session.ServerSessionImpl]
> (sshd-SshServer[6c96892e](port=8345)-nio2-thread-1)
> exceptionCaught(ServerSessionImpl[clientNBI@/20.24.16.108:41480])[state=Opened]
> InterruptedByTimeoutException: null2020-06-18 03:07:11,943 DEBUG
> [org.apache.sshd.server.session.ServerSessionImpl]
> (sshd-SshServer[6c96892e](port=8345)-nio2-thread-1)
> exceptionCaught(ServerSessionImpl[clientNBI@/20.24.16.108:41480])[state=Opened]
> details: java.nio.channels.InterruptedByTimeoutException at
> sun.nio.ch.UnixAsynchronousSocketChannelImpl$1.run(UnixAsynchronousSocketChannelImpl.java:456)
> [rt.jar:1.8.0_231] at
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
> [rt.jar:1.8.0_231] at
> java.util.concurrent.FutureTask.run(FutureTask.java:266) [rt.jar:1.8.0_231]
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
> [rt.jar:1.8.0_231] at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
> [rt.jar:1.8.0_231] at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
> [rt.jar:1.8.0_231] at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
> [rt.jar:1.8.0_231] at java.lang.Thread.run(Thread.java:748)
> [rt.jar:1.8.0_231]
> 2020-06-18 03:07:11,945 DEBUG
> [org.apache.sshd.common.session.helpers.SessionTimeoutListener]
> (sshd-SshServer[6c96892e](port=8345)-nio2-thread-1)
> sessionException(ServerSessionImpl[clientNBI@/20.24.16.108:41480])
> InterruptedByTimeoutException: null2020-06-18 03:07:11,945 TRACE
> [org.apache.sshd.common.session.helpers.SessionTimeoutListener]
> (sshd-SshServer[6c96892e](port=8345)-nio2-thread-1)
> sessionException(ServerSessionImpl[clientNBI@/20.24.16.108:41480]) details:
> java.nio.channels.InterruptedByTimeoutException at
> sun.nio.ch.UnixAsynchronousSocketChannelImpl$1.run(UnixAsynchronousSocketChannelImpl.java:456)
> [rt.jar:1.8.0_231] at
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
> [rt.jar:1.8.0_231] at
> java.util.concurrent.FutureTask.run(FutureTask.java:266) [rt.jar:1.8.0_231]
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
> [rt.jar:1.8.0_231] at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
> [rt.jar:1.8.0_231] at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
> [rt.jar:1.8.0_231] at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
> [rt.jar:1.8.0_231] at java.lang.Thread.run(Thread.java:748)
> [rt.jar:1.8.0_231]
> 2020-06-18 03:07:11,946 DEBUG
> [org.apache.sshd.common.session.helpers.SessionTimeoutListener]
> (sshd-SshServer[6c96892e](port=8345)-nio2-thread-1)
> sessionClosed(ServerSessionImpl[clientNBI@/20.24.16.108:41480])
> un-tracked2020-06-18 03:07:11,946 DEBUG
> [org.apache.sshd.server.session.ServerSessionImpl]
> (sshd-SshServer[6c96892e](port=8345)-nio2-thread-1)
> close(ServerSessionImpl[clientNBI@/20.24.16.108:41480]) Closing
> immediately2020-06-18 03:07:11,946 TRACE
> [org.apache.sshd.common.session.helpers.SessionTimeoutListener]
> (sshd-SshServer[6c96892e](port=8345)-nio2-thread-1)
> sessionClosed(ServerSessionImpl[clientNBI@/20.24.16.108:41480]) not
> tracked2020-06-18 03:07:11,946 TRACE
> [org.apache.sshd.common.util.closeable.SequentialCloseable]
> (sshd-SshServer[6c96892e](port=8345)-nio2-thread-1) doClose(true) closing
> org.apache.sshd.common.util.closeable.ParallelCloseable@a0279422020-06-18
> 03:07:11,946 TRACE [org.apache.sshd.common.util.closeable.ParallelCloseable]
> (sshd-SshServer[6c96892e](port=8345)-nio2-thread-1) doClose(true) pending
> closeables: 22020-06-18 03:07:11,946 DEBUG
> [org.apache.sshd.server.session.ServerConnectionService]
> (sshd-SshServer[6c96892e](port=8345)-nio2-thread-1)
> close(ServerConnectionService[ServerSessionImpl[clientNBI@/20.24.16.108:41480]])
> Closing immediately2020-06-18 03:07:11,947 TRACE
> [org.apache.sshd.common.util.closeable.ParallelCloseable]
> (sshd-SshServer[6c96892e](port=8345)-nio2-thread-1) doClose(true) pending
> closeables: 22020-06-18 03:07:11,947 DEBUG
> [org.apache.sshd.server.channel.ChannelSession]
> (sshd-SshServer[6c96892e](port=8345)-nio2-thread-1)
> close(ChannelSession[id=0,
> recipient=0]-ServerSessionImpl[clientNBI@/20.24.16.108:41480]) Closing
> immediately2020-06-18 03:07:11,947 DEBUG
> [org.apache.sshd.server.channel.ChannelSession]
> (sshd-SshServer[6c96892e](port=8345)-nio2-thread-1)
> close(ChannelSession[id=0,
> recipient=0]-ServerSessionImpl[clientNBI@/20.24.16.108:41480]) prevent
> sending EOF2020-06-18 03:07:11,947 DEBUG
> [org.apache.sshd.common.channel.Window]
> (sshd-SshServer[6c96892e](port=8345)-nio2-thread-1) Closing
> Window[server/local](ChannelSession[id=0,
> recipient=0]-ServerSessionImpl[clientNBI@/20.24.16.108:41480])2020-06-18
> 03:07:11,947 DEBUG [org.apache.sshd.common.channel.Window]
> (sshd-SshServer[6c96892e](port=8345)-nio2-thread-1) Closing
> Window[server/remote](ChannelSession[id=0,
> recipient=0]-ServerSessionImpl[clientNBI@/20.24.16.108:41480])2020-06-18
> 03:07:11,948 TRACE
> [org.apache.sshd.common.util.closeable.SequentialCloseable]
> (sshd-SshServer[6c96892e](port=8345)-nio2-thread-1) doClose(true) closing
> org.apache.sshd.server.channel.ChannelSession$CommandCloseable@662e3d1e2020-06-18
> 03:07:11,948 TRACE
> [org.apache.sshd.common.util.closeable.SequentialCloseable]
> (sshd-SshServer[6c96892e](port=8345)-nio2-thread-1) doClose(true) closing
> org.apache.sshd.common.util.closeable.SequentialCloseable@da00d8f2020-06-18
> 03:07:11,948 TRACE
> [org.apache.sshd.common.util.closeable.SequentialCloseable]
> (sshd-SshServer[6c96892e](port=8345)-nio2-thread-1) doClose(true) closing
> GracefulChannelCloseable[ChannelSession[id=0,
> recipient=0]-ServerSessionImpl[clientNBI@/20.24.16.108:41480]]2020-06-18
> 03:07:11,948 DEBUG
> [org.apache.sshd.common.channel.AbstractChannel$GracefulChannelCloseable]
> (sshd-SshServer[6c96892e](port=8345)-nio2-thread-1)
> close(ChannelSession[id=0,
> recipient=0]-ServerSessionImpl[clientNBI@/20.24.16.108:41480])[immediately=true]
> processing2020-06-18 03:07:11,948 TRACE
> [org.apache.sshd.common.util.closeable.SequentialCloseable]
> (sshd-SshServer[6c96892e](port=8345)-nio2-thread-1) doClose(true) closing
> org.apache.sshd.common.util.closeable.Builder$1@73992fa72020-06-18
> 03:07:11,948 DEBUG [org.apache.sshd.server.session.ServerConnectionService]
> (sshd-SshServer[6c96892e](port=8345)-nio2-thread-1)
> unregisterChannel(ChannelSession[id=0,
> recipient=0]-ServerSessionImpl[clientNBI@/20.24.16.108:41480])
> result=ChannelSession[id=0,
> recipient=0]-ServerSessionImpl[clientNBI@/20.24.16.108:41480]2020-06-18
> 03:07:11,948 DEBUG
> [org.apache.sshd.common.util.closeable.SequentialCloseable]
> (sshd-SshServer[6c96892e](port=8345)-nio2-thread-1) doClose(true) signal
> close complete2020-06-18 03:07:11,948 TRACE
> [org.apache.sshd.common.util.closeable.SequentialCloseable]
> (sshd-SshServer[6c96892e](port=8345)-nio2-thread-1) doClose(true) closing
> org.apache.sshd.common.util.closeable.ParallelCloseable@6a4880ff2020-06-18
> 03:07:11,948 TRACE [org.apache.sshd.common.util.closeable.ParallelCloseable]
> (sshd-SshServer[6c96892e](port=8345)-nio2-thread-1) doClose(true) completed
> pending: 02020-06-18 03:07:11,948 TRACE
> [org.apache.sshd.common.util.closeable.SequentialCloseable]
> (sshd-SshServer[6c96892e](port=8345)-nio2-thread-1) doClose(true) closing
> org.apache.sshd.common.util.closeable.Builder$1@7d1986652020-06-18
> 03:07:11,949 DEBUG [org.apache.sshd.server.channel.ChannelSession]
> (sshd-SshServer[6c96892e](port=8345)-nio2-thread-1)
> closeShell(ChannelSession[id=0,
> recipient=0]-ServerSessionImpl[clientNBI@/20.24.16.108:41480]) exit
> code=-12020-06-18 03:07:11,949 DEBUG
> [org.apache.sshd.server.channel.ChannelSession]
> (sshd-SshServer[6c96892e](port=8345)-nio2-thread-1)
> onExit(ChannelSession[id=0,
> recipient=0]-ServerSessionImpl[clientNBI@/20.24.16.108:41480]) code=-1
> message='' shell closed2020-06-18 03:07:11,949 TRACE
> [org.apache.sshd.server.channel.ChannelSession]
> (sshd-SshServer[6c96892e](port=8345)-nio2-thread-1)
> close(ChannelOutputStream[ChannelSession[id=0,
> recipient=0]-ServerSessionImpl[clientNBI@/20.24.16.108:41480]]
> SSH_MSG_CHANNEL_DATA) closing2020-06-18 03:07:11,949 TRACE
> [org.apache.sshd.server.channel.ChannelSession]
> (sshd-SshServer[6c96892e](port=8345)-nio2-thread-1)
> close(ChannelOutputStream[ChannelSession[id=0,
> recipient=0]-ServerSessionImpl[clientNBI@/20.24.16.108:41480]]
> SSH_MSG_CHANNEL_EXTENDED_DATA) closing2020-06-18 03:07:11,950 DEBUG
> [org.apache.sshd.server.channel.ChannelSession]
> (sshd-SshServer[6c96892e](port=8345)-nio2-thread-1)
> doCloseImmediately(ChannelSession[id=0,
> recipient=0]-ServerSessionImpl[clientNBI@/20.24.16.108:41480]) failed
> (SshChannelClosedException) to close resources:
> flush(ChannelOutputStream[ChannelSession[id=0,
> recipient=0]-ServerSessionImpl[clientNBI@/20.24.16.108:41480]]
> SSH_MSG_CHANNEL_DATA) length=0 - stream is already closed2020-06-18
> 03:07:11,950 DEBUG [org.apache.sshd.server.channel.ChannelSession]
> (pool-7-thread-757) closeShell(ChannelSession[id=0,
> recipient=0]-ServerSessionImpl[clientNBI@/20.24.16.108:41480]) exit
> code=02020-06-18 03:07:11,950 TRACE
> [org.apache.sshd.server.channel.ChannelSession]
> (sshd-SshServer[6c96892e](port=8345)-nio2-thread-1) Suppressed
> SshChannelClosedException) while close immediately resource(s) of
> ChannelSession[id=0,
> recipient=0]-ServerSessionImpl[clientNBI@/20.24.16.108:41480]:
> flush(ChannelOutputStream[ChannelSession[id=0,
> recipient=0]-ServerSessionImpl[clientNBI@/20.24.16.108:41480]]
> SSH_MSG_CHANNEL_EXTENDED_DATA) length=0 - stream is already closed2020-06-18
> 03:07:11,951 DEBUG
> [org.apache.sshd.common.util.closeable.SequentialCloseable]
> (sshd-SshServer[6c96892e](port=8345)-nio2-thread-1) doClose(true) signal
> close complete
> {code}
> Could you please help us what cause the issue and how to evaluate this?
>
> Thanks
> Siva
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
