Sivanagarajup created SSHD-1020:
-----------------------------------
Summary: 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: Question
Affects Versions: 2.2.0
Reporter: Sivanagarajup
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.22.2:8345,
remote=/207.241.169.100: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.22.2:8345,
remote=/207.241.169.100: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[TelsasoftNBI@/207.241.169.100: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[TelsasoftNBI@/207.241.169.100: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[TelsasoftNBI@/207.241.169.100: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[TelsasoftNBI@/207.241.169.100: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[TelsasoftNBI@/207.241.169.100: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[TelsasoftNBI@/207.241.169.100: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[TelsasoftNBI@/207.241.169.100: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[TelsasoftNBI@/207.241.169.100: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[TelsasoftNBI@/207.241.169.100: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[TelsasoftNBI@/207.241.169.100: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[TelsasoftNBI@/207.241.169.100: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[TelsasoftNBI@/207.241.169.100: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[TelsasoftNBI@/207.241.169.100: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[TelsasoftNBI@/207.241.169.100: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[TelsasoftNBI@/207.241.169.100:41480])
result=ChannelSession[id=0,
recipient=0]-ServerSessionImpl[TelsasoftNBI@/207.241.169.100: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[TelsasoftNBI@/207.241.169.100: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[TelsasoftNBI@/207.241.169.100: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[TelsasoftNBI@/207.241.169.100: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[TelsasoftNBI@/207.241.169.100: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[TelsasoftNBI@/207.241.169.100:41480]) failed
(SshChannelClosedException) to close resources:
flush(ChannelOutputStream[ChannelSession[id=0,
recipient=0]-ServerSessionImpl[TelsasoftNBI@/207.241.169.100: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[TelsasoftNBI@/207.241.169.100: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[TelsasoftNBI@/207.241.169.100:41480]:
flush(ChannelOutputStream[ChannelSession[id=0,
recipient=0]-ServerSessionImpl[TelsasoftNBI@/207.241.169.100: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]
