AnandhiSa opened a new issue, #922:
URL: https://github.com/apache/mina-sshd/issues/922
### Version
2.12.0
### Bug description
+ Huge File transfer (>5GB) to AIX host through SSH key credentials is always getting hung and SocketTimeoutException is reported
+ File transfer is successful with the following combination
Linux as Destination host + Host credentials
Linux as Destination host + SSH Key credentials
AIX as Destination host + Host Credentials
+ Hang with AIX + SSH Key credentials is unpredictable. At times, File transfer hangs after transferring 300MB and at times at 2GB, 4.9GB too.
+ Application uses Apache Mina SSHD client (2.12.0).
+ Transferred File is being streamed from Application UI to destination host. When the application uses SSH key credentials, SSH channel is created and used for further streaming it to launched application specific nmocat process (which performs the writing to the disk)
Application -> sshd client -> streams the packet to -> nmocat process-> writes the packet to file.
+ Packet size configured for file transfer - 2400 bytes
2026-03-19 10:16:35,082 [1086:35C07CE4] DEBUG - java.net.SocketTimeoutException: waitForCondition(RemoteWindow[client](ChannelExec[id=89, recipient=0]-ClientSessionImpl[p1qxmq1@localhost/127.0.0.1:22])) timeout exceeded: PT30S
java.net.SocketTimeoutException: waitForCondition(RemoteWindow[client](ChannelExec[id=89, recipient=0]-ClientSessionImpl[p1qxmq1@localhost/127.0.0.1:22])) timeout exceeded: PT30S
at org.apache.sshd.common.channel.RemoteWindow.waitForCondition(RemoteWindow.java:233)
at org.apache.sshd.common.channel.RemoteWindow.waitForSpace(RemoteWindow.java:187)
at org.apache.sshd.common.channel.ChannelOutputStream.flush(ChannelOutputStream.java:278)
at org.apache.sshd.common.channel.ChannelOutputStream.write(ChannelOutputStream.java:201)
at oracle.sysman.gcagent.util.streams.BytePacketOutputStream.setNext(BytePacketOutputStream.java:55)
at oracle.sysman.gcagent.util.streams.StreamManager$PipeStreamer.startPipe(StreamManager.java:193)
at oracle.sysman.gcagent.jobs.JobRequestDriver$JobReader.doWork(JobRequestDriver.java:448)
at oracle.sysman.gcagent.jobs.JobRequestDriverThread.run(JobRequestDriverThread.java:86)
at oracle.sysman.gcagent.util.system.GCAThread$RunnableWrapper.run(GCAThread.java:198)
at java.lang.Thread.run(Thread.java:820)
+ Increasing the timeout did not help resolving the issue
+ Findings from the debug logs:
- The file transfer started normally, with repeated SSH channel-window adjustments from receiver
- 70003 adjustments captured in the logs and subsequent expand was also processed by RemoteWindow
- Mina processed each adjustment and expanded its available sending window (evident from debug logs).
- Later, Mina consumed the available remote-window credit until it reached zero.
- After that point, no further SSH_MSG_CHANNEL_WINDOW_ADJUST or RemoteWindow.expand() messages were logged.
- Mina waited for additional window credit for 30 seconds and then failed with a SocketTimeoutException.
Request to review and share more insights on possible issue? Is there any way to workaround this issue?
Please comment.
Thanks
### Actual behavior
File transfer fails with a SocketTimeoutException
### Expected behavior
File transfer must succeed with out any errors
### Relevant log output
```Shell
[sshd-SshClient[51d53cea]-nio2-thread-2] DEBUG org.apache.sshd.client.session.ClientSessionImpl - doHandleMessage(ClientSessionImpl[test@localhost/127.0.0.1:22]) process #379815 SSH_MSG_CHANNEL_WINDOW_ADJUST
[sshd-SshClient[51d53cea]-nio2-thread-2] DEBUG org.apache.sshd.client.channel.ChannelExec - handleWindowAdjust(ChannelExec[id=0, recipient=0]-ClientSessionImpl[test@localhost/127.0.0.1:22]) SSH_MSG_CHANNEL_WINDOW_ADJUST window=131072
[sshd-SshClient[51d53cea]-nio2-thread-2] DEBUG org.apache.sshd.common.channel.RemoteWindow - expand(RemoteWindow[client](ChannelExec[id=0, recipient=0]-ClientSessionImpl[test@localhost/127.0.0.1:22])) increase window from 98304 by 131072 up to 229376
[sshd-SshClient[51d53cea]-nio2-thread-2] DEBUG org.apache.sshd.client.session.ClientSessionImpl - doHandleMessage(ClientSessionImpl[test@localhost/127.0.0.1:22]) process #379816 SSH_MSG_CHANNEL_DATA
[sshd-SshClient[51d53cea]-nio2-thread-2] DEBUG org.apache.sshd.common.channel.LocalWindow - Consume LocalWindow[client](ChannelExec[id=0, recipient=0]-ClientSessionImpl[test@localhost/127.0.0.1:22]) by 32 down to 2014624
[sshd-SshClient[51d53cea]-nio2-thread-2] DEBUG org.apache.sshd.client.channel.ChannelExec - handleData(ChannelExec[id=0, recipient=0]-ClientSessionImpl[test@localhost/127.0.0.1:22]) SSH_MSG_CHANNEL_DATA len=32
[sshd-SshClient[51d53cea]-nio2-thread-2] DEBUG org.apache.sshd.client.session.ClientSessionImpl - doHandleMessage(ClientSessionImpl[test@localhost/127.0.0.1:22]) process #379817 SSH_MSG_CHANNEL_DATA
[sshd-SshClient[51d53cea]-nio2-thread-2] DEBUG org.apache.sshd.common.channel.LocalWindow - Consume LocalWindow[client](ChannelExec[id=0, recipient=0]-ClientSessionImpl[test@localhost/127.0.0.1:22]) by 32 down to 2014592
[sshd-SshClient[51d53cea]-nio2-thread-2] DEBUG org.apache.sshd.client.channel.ChannelExec - handleData(ChannelExec[id=0, recipient=0]-ClientSessionImpl[test@localhost/127.0.0.1:22]) SSH_MSG_CHANNEL_DATA len=32
[sshd-SshClient[51d53cea]-nio2-thread-2] DEBUG org.apache.sshd.client.session.ClientSessionImpl - doHandleMessage(ClientSessionImpl[test@localhost/127.0.0.1:22]) process #379818 SSH_MSG_CHANNEL_DATA
[sshd-SshClient[51d53cea]-nio2-thread-2] DEBUG org.apache.sshd.common.channel.LocalWindow - Consume LocalWindow[client](ChannelExec[id=0, recipient=0]-ClientSessionImpl[test@localhost/127.0.0.1:22]) by 32 down to 2014560
[sshd-SshClient[51d53cea]-nio2-thread-2] DEBUG org.apache.sshd.client.channel.ChannelExec - handleData(ChannelExec[id=0, recipient=0]-ClientSessionImpl[test@localhost/127.0.0.1:22]) SSH_MSG_CHANNEL_DATA len=32
[JobReader-reproducer] DEBUG org.apache.sshd.common.io.nio2.Nio2Session - writeBuffer(Nio2Session[local=/127.0.0.1:41022, remote=localhost/127.0.0.1:22]) writing 32832 bytes
[JobReader-reproducer] DEBUG org.apache.sshd.common.channel.RemoteWindow - waitForSpace(RemoteWindow[client](ChannelExec[id=0, recipient=0]-ClientSessionImpl[test@localhost/127.0.0.1:22])) available: 229376
[JobReader-reproducer] DEBUG org.apache.sshd.common.channel.RemoteWindow - waitAndConsume(RemoteWindow[client](ChannelExec[id=0, recipient=0]-ClientSessionImpl[test@localhost/127.0.0.1:22])) - requested=32768, available=229376
[JobReader-reproducer] DEBUG org.apache.sshd.common.channel.RemoteWindow - Consume RemoteWindow[client](ChannelExec[id=0, recipient=0]-ClientSessionImpl[test@localhost/127.0.0.1:22]) by 32768 down to 196608
[JobReader-reproducer] DEBUG org.apache.sshd.client.session.ClientSessionImpl - encode(ClientSessionImpl[test@localhost/127.0.0.1:22]) packet #185367 sending command=94[SSH_MSG_CHANNEL_DATA] len=32777
[JobReader-reproducer] DEBUG org.apache.sshd.common.io.nio2.Nio2Session - writeBuffer(Nio2Session[local=/127.0.0.1:41022, remote=localhost/127.0.0.1:22]) writing 32832 bytes
[JobReader-reproducer] DEBUG org.apache.sshd.common.channel.RemoteWindow - waitForSpace(RemoteWindow[client](ChannelExec[id=0, recipient=0]-ClientSessionImpl[test@localhost/127.0.0.1:22])) available: 196608
[JobReader-reproducer] DEBUG org.apache.sshd.common.channel.RemoteWindow - waitAndConsume(RemoteWindow[client](ChannelExec[id=0, recipient=0]-ClientSessionImpl[test@localhost/127.0.0.1:22])) - requested=32768, available=196608
[JobReader-reproducer] DEBUG org.apache.sshd.common.channel.RemoteWindow - Consume RemoteWindow[client](ChannelExec[id=0, recipient=0]-ClientSessionImpl[test@localhost/127.0.0.1:22]) by 32768 down to 163840
[JobReader-reproducer] DEBUG org.apache.sshd.client.session.ClientSessionImpl - encode(ClientSessionImpl[test@localhost/127.0.0.1:22]) packet #185368 sending command=94[SSH_MSG_CHANNEL_DATA] len=32777
[JobReader-reproducer] DEBUG org.apache.sshd.common.io.nio2.Nio2Session - writeBuffer(Nio2Session[local=/127.0.0.1:41022, remote=localhost/127.0.0.1:22]) writing 32832 bytes
[JobReader-reproducer] DEBUG org.apache.sshd.common.channel.RemoteWindow - waitForSpace(RemoteWindow[client](ChannelExec[id=0, recipient=0]-ClientSessionImpl[test@localhost/127.0.0.1:22])) available: 163840
[JobReader-reproducer] DEBUG org.apache.sshd.common.channel.RemoteWindow - waitAndConsume(RemoteWindow[client](ChannelExec[id=0, recipient=0]-ClientSessionImpl[test@localhost/127.0.0.1:22])) - requested=32768, available=163840
[JobReader-reproducer] DEBUG org.apache.sshd.common.channel.RemoteWindow - Consume RemoteWindow[client](ChannelExec[id=0, recipient=0]-ClientSessionImpl[test@localhost/127.0.0.1:22]) by 32768 down to 131072
[JobReader-reproducer] DEBUG org.apache.sshd.client.session.ClientSessionImpl - encode(ClientSessionImpl[test@localhost/127.0.0.1:22]) packet #185369 sending command=94[SSH_MSG_CHANNEL_DATA] len=32777
[JobReader-reproducer] DEBUG org.apache.sshd.common.io.nio2.Nio2Session - writeBuffer(Nio2Session[local=/127.0.0.1:41022, remote=localhost/127.0.0.1:22]) writing 32832 bytes
[JobReader-reproducer] DEBUG org.apache.sshd.common.channel.RemoteWindow - waitForSpace(RemoteWindow[client](ChannelExec[id=0, recipient=0]-ClientSessionImpl[test@localhost/127.0.0.1:22])) available: 131072
[JobReader-reproducer] DEBUG org.apache.sshd.common.channel.RemoteWindow - waitAndConsume(RemoteWindow[client](ChannelExec[id=0, recipient=0]-ClientSessionImpl[test@localhost/127.0.0.1:22])) - requested=32768, available=131072
[JobReader-reproducer] DEBUG org.apache.sshd.common.channel.RemoteWindow - Consume RemoteWindow[client](ChannelExec[id=0, recipient=0]-ClientSessionImpl[test@localhost/127.0.0.1:22]) by 32768 down to 98304
[JobReader-reproducer] DEBUG org.apache.sshd.client.session.ClientSessionImpl - encode(ClientSessionImpl[test@localhost/127.0.0.1:22]) packet #185370 sending command=94[SSH_MSG_CHANNEL_DATA] len=32777
[JobReader-reproducer] DEBUG org.apache.sshd.common.io.nio2.Nio2Session - writeBuffer(Nio2Session[local=/127.0.0.1:41022, remote=localhost/127.0.0.1:22]) writing 32832 bytes
[JobReader-reproducer] DEBUG org.apache.sshd.common.channel.RemoteWindow - waitForSpace(RemoteWindow[client](ChannelExec[id=0, recipient=0]-ClientSessionImpl[test@localhost/127.0.0.1:22])) available: 98304
[JobReader-reproducer] DEBUG org.apache.sshd.common.channel.RemoteWindow - waitAndConsume(RemoteWindow[client](ChannelExec[id=0, recipient=0]-ClientSessionImpl[test@localhost/127.0.0.1:22])) - requested=32768, available=98304
[JobReader-reproducer] DEBUG org.apache.sshd.common.channel.RemoteWindow - Consume RemoteWindow[client](ChannelExec[id=0, recipient=0]-ClientSessionImpl[test@localhost/127.0.0.1:22]) by 32768 down to 65536
[JobReader-reproducer] DEBUG org.apache.sshd.client.session.ClientSessionImpl - encode(ClientSessionImpl[test@localhost/127.0.0.1:22]) packet #185371 sending command=94[SSH_MSG_CHANNEL_DATA] len=32777
[JobReader-reproducer] DEBUG org.apache.sshd.common.io.nio2.Nio2Session - writeBuffer(Nio2Session[local=/127.0.0.1:41022, remote=localhost/127.0.0.1:22]) writing 32832 bytes
[JobReader-reproducer] DEBUG org.apache.sshd.common.channel.RemoteWindow - waitForSpace(RemoteWindow[client](ChannelExec[id=0, recipient=0]-ClientSessionImpl[test@localhost/127.0.0.1:22])) available: 65536
[JobReader-reproducer] DEBUG org.apache.sshd.common.channel.RemoteWindow - waitAndConsume(RemoteWindow[client](ChannelExec[id=0, recipient=0]-ClientSessionImpl[test@localhost/127.0.0.1:22])) - requested=32768, available=65536
[JobReader-reproducer] DEBUG org.apache.sshd.common.channel.RemoteWindow - Consume RemoteWindow[client](ChannelExec[id=0, recipient=0]-ClientSessionImpl[test@localhost/127.0.0.1:22]) by 32768 down to 32768
[JobReader-reproducer] DEBUG org.apache.sshd.client.session.ClientSessionImpl - encode(ClientSessionImpl[test@localhost/127.0.0.1:22]) packet #185372 sending command=94[SSH_MSG_CHANNEL_DATA] len=32777
[JobReader-reproducer] DEBUG org.apache.sshd.common.io.nio2.Nio2Session - writeBuffer(Nio2Session[local=/127.0.0.1:41022, remote=localhost/127.0.0.1:22]) writing 32832 bytes
[JobReader-reproducer] DEBUG org.apache.sshd.common.channel.RemoteWindow - waitForSpace(RemoteWindow[client](ChannelExec[id=0, recipient=0]-ClientSessionImpl[test@localhost/127.0.0.1:22])) available: 32768
[JobReader-reproducer] DEBUG org.apache.sshd.common.channel.RemoteWindow - waitAndConsume(RemoteWindow[client](ChannelExec[id=0, recipient=0]-ClientSessionImpl[test@localhost/127.0.0.1:22])) - requested=32768, available=32768
[JobReader-reproducer] DEBUG org.apache.sshd.common.channel.RemoteWindow - Consume RemoteWindow[client](ChannelExec[id=0, recipient=0]-ClientSessionImpl[test@localhost/127.0.0.1:22]) by 32768 down to 0
[JobReader-reproducer] DEBUG org.apache.sshd.client.session.ClientSessionImpl - encode(ClientSessionImpl[test@localhost/127.0.0.1:22]) packet #185373 sending command=94[SSH_MSG_CHANNEL_DATA] len=32777
[JobReader-reproducer] DEBUG org.apache.sshd.common.io.nio2.Nio2Session - writeBuffer(Nio2Session[local=/127.0.0.1:41022, remote=localhost/127.0.0.1:22]) writing 32832 bytes
[JobReader-reproducer] DEBUG org.apache.sshd.client.channel.ChannelExec - flush(ChannelOutputStream[ChannelExec[id=0, recipient=0]-ClientSessionImpl[test@localhost/127.0.0.1:22]] SSH_MSG_CHANNEL_DATA) failed (SocketTimeoutException) to wait for space of len=32768: waitForCondition(RemoteWindow[client](ChannelExec[id=0, recipient=0]-ClientSessionImpl[test@localhost/127.0.0.1:22])) timeout exceeded: PT30S
[JobReader-reproducer] DEBUG org.apache.sshd.client.channel.ChannelExec - flush(ChannelOutputStream[ChannelExec[id=0, recipient=0]-ClientSessionImpl[test@localhost/127.0.0.1:22]] SSH_MSG_CHANNEL_DATA) failed (SocketTimeoutException) to wait for space of len=32768: waitForCondition(RemoteWindow[client](ChannelExec[id=0, recipient=0]-ClientSessionImpl[test@localhost/127.0.0.1:22])) timeout exceeded: PT30S
[qtp-1674194548-52] DEBUG org.apache.sshd.client.channel.ChannelExec - close(ChannelExec[id=0, recipient=0]-ClientSessionImpl[test@localhost/127.0.0.1:22]) Closing immediately
[qtp-1674194548-52] DEBUG org.apache.sshd.client.channel.ChannelExec - close(ChannelExec[id=0, recipient=0]-ClientSessionImpl[test@localhost/127.0.0.1:22]) no EOF sent
[qtp-1674194548-52] DEBUG org.apache.sshd.common.channel.LocalWindow - Closing LocalWindow[client](ChannelExec[id=0, recipient=0]-ClientSessionImpl[test@localhost/127.0.0.1:22])
[qtp-1674194548-52] DEBUG org.apache.sshd.common.channel.RemoteWindow - Closing RemoteWindow[client](ChannelExec[id=0, recipient=0]-ClientSessionImpl[test@localhost/127.0.0.1:22])
[qtp-1674194548-52] DEBUG org.apache.sshd.common.channel.AbstractChannel$GracefulChannelCloseable - close(ChannelExec[id=0, recipient=0]-ClientSessionImpl[test@localhost/127.0.0.1:22])[immediately=true] processing
[qtp-1674194548-52] DEBUG org.apache.sshd.client.session.ClientConnectionService - unregisterChannel(ChannelExec[id=0, recipient=0]-ClientSessionImpl[test@localhost/127.0.0.1:22]) result=ChannelExec[id=0, recipient=0]-ClientSessionImpl[test@localhost/127.0.0.1:22]
[qtp-1674194548-52] DEBUG org.apache.sshd.common.util.closeable.SequentialCloseable - doClose(org.apache.sshd.common.util.closeable.SequentialCloseable$1@fb794a46) signal close complete immediately=true
[qtp-1674194548-52] DEBUG org.apache.sshd.common.util.closeable.SequentialCloseable - doClose(org.apache.sshd.common.util.closeable.SequentialCloseable$1@a90e2547) signal close complete immediately=true
[qtp-1674194548-52] DEBUG org.apache.sshd.common.util.closeable.SequentialCloseable - doClose(org.apache.sshd.common.util.closeable.SequentialCloseable$1@901bc95) signal close complete immediately=true
[qtp-1674194548-52] DEBUG org.apache.sshd.client.channel.ChannelExec - close(ChannelExec[id=0, recipient=0]-ClientSessionImpl[test@localhost/127.0.0.1:22])[Immediately] closed
[qtp-1674194548-52] DEBUG org.apache.sshd.client.session.ClientSessionImpl - close(ClientSessionImpl[test@localhost/127.0.0.1:22]) Closing immediately
[qtp-1674194548-52] DEBUG org.apache.sshd.client.session.ClientSessionImpl - signalAuthFailure(ClientSessionImpl[test@localhost/127.0.0.1:22]) type=SshException, signalled=false, first=false: Session is being closed
[qtp-1674194548-52] DEBUG org.apache.sshd.common.session.helpers.SessionTimeoutListener - sessionClosed(ClientSessionImpl[test@localhost/127.0.0.1:22]) un-tracked
[qtp-1674194548-52] DEBUG org.apache.sshd.client.session.ClientConnectionService - close(ClientConnectionService[ClientSessionImpl[test@localhost/127.0.0.1:22]]) Closing immediately
[qtp-1674194548-52] DEBUG org.apache.sshd.client.session.ClientConnectionService - stopHeartBeat(ClientSessionImpl[test@localhost/127.0.0.1:22]) no heartbeat to stop
[qtp-1674194548-52] DEBUG org.apache.sshd.client.session.ClientConnectionService - close(ClientConnectionService[ClientSessionImpl[test@localhost/127.0.0.1:22]])[Immediately] closed
[qtp-1674194548-52] DEBUG org.apache.sshd.common.io.nio2.Nio2Session - close(Nio2Session[local=/127.0.0.1:41022, remote=localhost/127.0.0.1:22]) Closing immediately
[qtp-1674194548-52] DEBUG org.apache.sshd.common.io.nio2.Nio2Session - doCloseImmediately(Nio2Session[local=/127.0.0.1:41022, remote=localhost/127.0.0.1:22]) closing socket=sun.nio.ch.UnixAsynchronousSocketChannelImpl[connected local=/127.0.0.1:41022 remote=localhost/127.0.0.1:22]
[qtp-1674194548-52] DEBUG org.apache.sshd.common.io.nio2.Nio2Session - doCloseImmediately(Nio2Session[local=/127.0.0.1:41022, remote=localhost/127.0.0.1:22]) socket=sun.nio.ch.UnixAsynchronousSocketChannelImpl[closed] closed
[qtp-1674194548-52] DEBUG org.apache.sshd.common.io.nio2.Nio2Connector - unmapSession(id=101): Nio2Session[local=/127.0.0.1:41022, remote=localhost/127.0.0.1:22]
[qtp-1674194548-52] DEBUG org.apache.sshd.client.session.ClientSessionImpl - close(ClientSessionImpl[test@localhost/127.0.0.1:22])[Immediately] state already Immediate
[qtp-1674194548-52] DEBUG org.apache.sshd.common.io.nio2.Nio2Session - close(Nio2Session[local=/127.0.0.1:41022, remote=localhost/127.0.0.1:22])[Immediately] closed
[qtp-1674194548-52] DEBUG org.apache.sshd.common.util.closeable.SequentialCloseable - doClose(org.apache.sshd.common.util.closeable.SequentialCloseable$1@9601ecbb) signal close complete immediately=true
[qtp-1674194548-52] DEBUG org.apache.sshd.client.session.ClientSessionImpl - close(ClientSessionImpl[test@localhost/127.0.0.1:22])[Immediately] closed
[qtp-1674194548-52] WARN org.eclipse.jetty.server.handler.ContextHandler.ROOT - EM-style threaded HTTP transfer failed: destfile.dat
java.io.IOException: JobReader failed
at EmagentSshNmocatThreadedReproducer.throwIfFailed(EmagentSshNmocatThreadedReproducer.java:296)
at EmagentSshNmocatThreadedReproducer.transfer(EmagentSshNmocatThreadedReproducer.java:218)
at EmagentSshNmocatThreadedReproducer.access$400(EmagentSshNmocatThreadedReproducer.java:48)
at EmagentSshNmocatThreadedReproducer$TransferServlet.doPost(EmagentSshNmocatThreadedReproducer.java:412)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:707)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)
at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:799)
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:554)
at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1440)
at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188)
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:505)
at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186)
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1355)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
at org.eclipse.jetty.server.Server.handle(Server.java:516)
at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:487)
at org.eclipse.jetty.server.HttpChannel$$Lambda$97/0000000023664870.dispatch(Unknown Source)
at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:732)
at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:479)
at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:277)
at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311)
at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105)
at org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104)
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:883)
at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1034)
at java.lang.Thread.run(Thread.java:820)
Caused by: java.net.SocketTimeoutException: waitForCondition(RemoteWindow[client](ChannelExec[id=0, recipient=0]-ClientSessionImpl[test@localhost/127.0.0.1:22])) timeout exceeded: PT30S
at org.apache.sshd.common.channel.RemoteWindow.waitForCondition(RemoteWindow.java:233)
at org.apache.sshd.common.channel.RemoteWindow.waitForSpace(RemoteWindow.java:187)
at org.apache.sshd.common.channel.ChannelOutputStream.flush(ChannelOutputStream.java:278)
at org.apache.sshd.common.channel.ChannelOutputStream.write(ChannelOutputStream.java:201)
at EmagentSshNmocatThreadedReproducer.copyAsEmJobReader(EmagentSshNmocatThreadedReproducer.java:263)
at EmagentSshNmocatThreadedReproducer.access$100(EmagentSshNmocatThreadedReproducer.java:48)
at EmagentSshNmocatThreadedReproducer$2.run(EmagentSshNmocatThreadedReproducer.java:182)
... 1 more
Suppressed: java.net.SocketTimeoutException: waitForCondition(RemoteWindow[client](ChannelExec[id=0, recipient=0]-ClientSessionImpl[test@localhost/127.0.0.1:22])) timeout exceeded: PT30S
at org.apache.sshd.common.channel.RemoteWindow.waitForCondition(RemoteWindow.java:233)
at org.apache.sshd.common.channel.RemoteWindow.waitForSpace(RemoteWindow.java:187)
at org.apache.sshd.common.channel.ChannelOutputStream.flush(ChannelOutputStream.java:278)
at org.apache.sshd.common.channel.ChannelOutputStream.close(ChannelOutputStream.java:357)
at EmagentSshNmocatThreadedReproducer.copyAsEmJobReader(EmagentSshNmocatThreadedReproducer.java:272)
... 3 more
[sshd-SshClient[51d53cea]-nio2-thread-17] DEBUG org.apache.sshd.common.io.nio2.Nio2Session - handleReadCycleFailure(Nio2Session[local=/127.0.0.1:41022, remote=localhost/127.0.0.1:22]) AsynchronousCloseException after 60026087105 nanos at read cycle=25128: null
```
### Other information
_No response_
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: dev-unsubscribe@mina.apache.org.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@mina.apache.org
For additional commands, e-mail: dev-help@mina.apache.org
tomaswolf commented on issue #922: URL: https://github.com/apache/mina-sshd/issues/922#issuecomment-5939312875 I don't know why this happens, and I have no way to analyze this since I don't know your application code. There are two things that you could maybe try: * Use the latest Apache MINA SSHD 2.20.0. * Increase CoreModuleProperties.WAIT_FOR_SPACE_TIMEOUT (set a higher value for it on the session). Otherwise: run the client in debug mode with a breakpoint in RemoteWindow.waitForCondition() where that exception is raised. Set the breakpoint to suspend the whole VM. Then debug. If you can, also examine server side logs. Perhaps the server is not sending window adjustments anymore for some reason? If it does send them, why are they not read in the client? Is there some deadlock? Or is writing the data somehow starving reading and handling the server's messages? There was a similar report before: #764, but the symptoms were a bit different. -- This is an automated message from the Apache Git Service. To respond to the message, please log on to GitHub and use the URL above to go to the specific comment. To unsubscribe, e-mail: dev-unsubscribe@mina.apache.org For queries about this service, please contact Infrastructure at: users@infra.apache.org --------------------------------------------------------------------- To unsubscribe, e-mail: dev-unsubscribe@mina.apache.org For additional commands, e-mail: dev-help@mina.apache.org
tomaswolf commented on issue #922: URL: https://github.com/apache/mina-sshd/issues/922#issuecomment-5939512538 Another thing: a channel window of a mere 224kB strikes me as small. How big was the channel window right after the channel was opened, on the first writes? If it started out much larger, then maybe you have to examine more closely how the window size evolved. Were there previous periods during which the channel window only decreased and never fully recovered? If so, then this event where it finally drops to zero may be just another such period--what caused these periods and why did the window not get opened fully again? -- This is an automated message from the Apache Git Service. To respond to the message, please log on to GitHub and use the URL above to go to the specific comment. To unsubscribe, e-mail: dev-unsubscribe@mina.apache.org For queries about this service, please contact Infrastructure at: users@infra.apache.org --------------------------------------------------------------------- To unsubscribe, e-mail: dev-unsubscribe@mina.apache.org For additional commands, e-mail: dev-help@mina.apache.org