InterruptedByTimeoutException from UnixAsynchronousSocketChannelImpl on big files after around 10 minutes
- Dominant language
- Java
- Stars
- 1.1k
- Forks
- 400
- Avg merge
- 5d 1h
- Merged PRs (30d)
- 1
Description
### Version
2.14.0
### Bug description
Hi,
While sending files around 1.4 Gb to an sftp server:
Client string: 'SSH-2.0-APACHE-SSHD-2.14.0' vs. Server string: 'SSH-2.0-6.4.13.36 SSH Tectia Server'
We get all the time after around 10 minutes java.nio.channels.InterruptedByTimeoutException
````
Got a functional exception com.amadeus.dis.distribution.exception.DistributionFunctionalException: Problem in the SFTP upload of file '...' in directory '/xxxxxx': Unable to transmit file: xxxxxxx
at com.amadeus.dis.distribution.process.sftp.SftpProfileClient.sendSource(SftpProfileClient.java:200) ~[common-process-3.30.38.jar!/:?]
...
at java.base/java.lang.Thread.run(Thread.java:829) [?:?]
Caused by: com.amadeus.dis.distribution.transfer.exception.TransferException: Unable to transmit file: AvlReport.D250613.T043149.output.jsonl.gz
at com.amadeus.dis.distribution.transfer.sftp.sshd.SshdSftpClient.doWrite(SshdSftpClient.java:219) ~[common-transfer-3.30.38.jar!/:?]
at com.amadeus.dis.distribution.transfer.sftp.AbstractSftpClient.transferStream(AbstractSftpClient.java:80) ~[common-transfer-3.30.38.jar!/:?]
at com.amadeus.dis.distribution.transfer.sftp.SftpFallbackClient.transferStream(SftpFallbackClient.java:22) ~[common-transfer-3.30.38.jar!/:?]
at com.amadeus.dis.distribution.process.sftp.SftpProfileClient.sendSource(SftpProfileClient.java:194) ~[common-process-3.30.38.jar!/:?]
... 17 more
Caused by: org.apache.sshd.common.SshException: IoWriteFutureImpl[SftpChannelSubsystem[id=1, recipient=1]-ClientSessionImpl[usertoto@/xx.xxx.xx:22][sftp][SSH_MSG_CHANNEL_DATA]]: Failed (InterruptedByTimeoutException) to execute: null
at org.apache.sshd.common.future.AbstractSshFuture.lambda$verifyResult$2(AbstractSshFuture.java:146) ~[sshd-common-2.14.0.jar!/:2.14.0]
at org.apache.sshd.common.future.AbstractSshFuture.formatExceptionMessage(AbstractSshFuture.java:206) ~[sshd-common-2.14.0.jar!/:2.14.0]
at org.apache.sshd.common.future.AbstractSshFuture.verifyResult(AbstractSshFuture.java:145) ~[sshd-common-2.14.0.jar!/:2.14.0]
at org.apache.sshd.common.io.AbstractIoWriteFuture.verify(AbstractIoWriteFuture.java:41) ~[sshd-common-2.14.0.jar!/:2.14.0]
at org.apache.sshd.common.io.AbstractIoWriteFuture.verify(AbstractIoWriteFuture.java:32) ~[sshd-common-2.14.0.jar!/:2.14.0]
at org.apache.sshd.common.future.VerifiableFuture.verify(VerifiableFuture.java:110) ~[sshd-common-2.14.0.jar!/:2.14.0]
at org.apache.sshd.common.future.VerifiableFuture.verify(VerifiableFuture.java:96) ~[sshd-common-2.14.0.jar!/:2.14.0]
at org.apache.sshd.sftp.client.SftpMessage.waitUntilSent(SftpMessage.java:85) ~[sshd-sftp-2.14.0.jar!/:2.14.0]
at org.apache.sshd.sftp.client.impl.SftpOutputStreamAsync.internalFlush(SftpOutputStreamAsync.java:358) ~[sshd-sftp-2.14.0.jar!/:2.14.0]
at org.apache.sshd.sftp.client.impl.SftpOutputStreamAsync.internalTransfer(SftpOutputStreamAsync.java:285) ~[sshd-sftp-2.14.0.jar!/:2.14.0]
at org.apache.sshd.sftp.client.impl.SftpOutputStreamAsync.write(SftpOutputStreamAsync.java:180) ~[sshd-sftp-2.14.0.jar!/:2.14.0]
at java.base/java.io.InputStream.transferTo(InputStream.java:705) ~[?:?]
at com.amadeus.dis.distribution.transfer.sftp.sshd.SshdSftpClient.doWrite(SshdSftpClient.java:215) ~[common-transfer-3.30.38.jar!/:?]
at com.amadeus.dis.distribution.transfer.sftp.AbstractSftpClient.transferStream(AbstractSftpClient.java:80) ~[common-transfer-3.30.38.jar!/:?]
at com.amadeus.dis.distribution.transfer.sftp.SftpFallbackClient.transferStream(SftpFallbackClient.java:22) ~[common-transfer-3.30.38.jar!/:?]
at com.amadeus.dis.distribution.process.sftp.SftpProfileClient.sendSource(SftpProfileClient.java:194) ~[common-process-3.30.38.jar!/:?]
... 17 more
Suppressed: org.apache.sshd.common.SshException: Write attempt on closing session: SSH_MSG_CHANNEL_DATA
at org.apache.sshd.common.future.AbstractSshFuture.verifyResult(AbstractSshFuture.java:141) ~[sshd-common-2.14.0.jar!/:2.14.0]
at org.apache.sshd.common.io.AbstractIoWriteFuture.verify(AbstractIoWriteFuture.java:41) ~[sshd-common-2.14.0.jar!/:2.14.0]
at org.apache.sshd.common.io.AbstractIoWriteFuture.verify(AbstractIoWriteFuture.java:32) ~[sshd-common-2.14.0.jar!/:2.14.0]
at org.apache.sshd.common.future.VerifiableFuture.verify(VerifiableFuture.java:110) ~[sshd-common-2.14.0.jar!/:2.14.0]
at org.apache.sshd.common.future.VerifiableFuture.verify(VerifiableFuture.java:96) ~[sshd-common-2.14.0.jar!/:2.14.0]
at org.apache.sshd.sftp.client.SftpMessage.waitUntilSent(SftpMessage.java:85) ~[sshd-sftp-2.14.0.jar!/:2.14.0]
at org.apache.sshd.sftp.client.impl.DefaultSftpClient.send(DefaultSftpClient.java:273) ~[sshd-sftp-2.14.0.jar!/:2.14.0]
at org.apache.sshd.sftp.client.impl.AbstractSftpClient.rpc(AbstractSftpClient.java:167) ~[sshd-sftp-2.14.0.jar!/:2.14.0]
at org.apache.sshd.sftp.client.impl.AbstractSftpClient.checkCommandStatus(AbstractSftpClient.java:232) ~[sshd-sftp-2.14.0.jar!/:2.14.0]
at org.apache.sshd.sftp.client.impl.AbstractSftpClient.close(AbstractSftpClient.java:609) ~[sshd-sftp-2.14.0.jar!/:2.14.0]
at org.apache.sshd.sftp.client.impl.DefaultCloseableHandle.close(DefaultCloseableHandle.java:53) ~[sshd-sftp-2.14.0.jar!/:2.14.0]
at org.apache.sshd.sftp.client.impl.SftpOutputStreamAsync.close(SftpOutputStreamAsync.java:440) ~[sshd-sftp-2.14.0.jar!/:2.14.0]
at com.amadeus.dis.distribution.transfer.sftp.sshd.SshdSftpClient.doWrite(SshdSftpClient.java:213) ~[common-transfer-3.30.38.jar!/:?]
...
at java.base/java.lang.Thread.run(Thread.java:829) [?:?]
Caused by: org.apache.sshd.common.SshException: Write attempt on closing session: SSH_MSG_CHANNEL_DATA
at org.apache.sshd.common.session.helpers.KeyExchangeMessageHandler.writeOrEnqueue(KeyExchangeMessageHandler.java:300) ~[sshd-core-2.14.0.jar!/:2.14.0]
at org.apache.sshd.common.session.helpers.KeyExchangeMessageHandler.writePacket(KeyExchangeMessageHandler.java:246) ~[sshd-core-2.14.0.jar!/:2.14.0]
at org.apache.sshd.common.session.helpers.AbstractSession.writePacket(AbstractSession.java:1078) ~[sshd-core-2.14.0.jar!/:2.14.0]
at org.apache.sshd.common.channel.AbstractChannel.writePacket(AbstractChannel.java:818) ~[sshd-core-2.14.0.jar!/:2.14.0]
at org.apache.sshd.common.channel.throttle.DefaultChannelStreamWriter.writeData(DefaultChannelStreamWriter.java:46) ~[sshd-core-2.14.0.jar!/:2.14.0]
at org.apache.sshd.common.channel.ChannelAsyncOutputStream.writePacket(ChannelAsyncOutputStream.java:348) ~[sshd-core-2.14.0.jar!/:2.14.0]
at org.apache.sshd.common.channel.ChannelAsyncOutputStream.doWriteIfPossible(ChannelAsyncOutputStream.java:225) ~[sshd-core-2.14.0.jar!/:2.14.0]
at org.apache.sshd.common.channel.ChannelAsyncOutputStream.writeBuffer(ChannelAsyncOutputStream.java:119) ~[sshd-core-2.14.0.jar!/:2.14.0]
at org.apache.sshd.sftp.client.impl.DefaultSftpClient.write(DefaultSftpClient.java:308) ~[sshd-sftp-2.14.0.jar!/:2.14.0]
at org.apache.sshd.sftp.client.impl.DefaultSftpClient.send(DefaultSftpClient.java:272) ~[sshd-sftp-2.14.0.jar!/:2.14.0]
... 26 more
Caused by: java.nio.channels.InterruptedByTimeoutException
at java.base/sun.nio.ch.UnixAsynchronousSocketChannelImpl$2.run(UnixAsynchronousSocketChannelImpl.java:661) ~[?:?]
at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) ~[?:?]
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[?:?]
at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) ~[?:?]
... 3 more
````
I found from long ago https://issues.apache.org/jira/browse/SSHD-1020 that seems to be fixed for a long time now ...
And I am having hard time to undertand what is this timeout coming from and leading to the channel closing,
### Actual behavior
Timeout after 10 minutes
### Expected behavior
I do not see why any timeout should happen
### Relevant log output
```Shell
Areound the time of the issue I gathered the following logs from Mina
2025/06/13 08:51:03.236000 lgsap253-MUC disapp03 DDS_UDD#0-0 APP WARN Multi1 [sshd-SshClient[5134a7d6]-nio2-thread-15] {} exceptionCaught(ClientSessionImpl[toto@/xx.xx.xxx.xxx:22])[state=Opened] InterruptedByTimeoutException: null
2025/06/13 08:51:03.237000 lgsap234-MUC disapp03 DDS_UDD#0-0 APP WARN Multi1 [sshd-SshClient[5134a7d6]-nio2-thread-15] {} doCloseImmediately([SftpChannelSubsystem[id=1, recipient=1]-ClientSessionImpl[toto@/xxx.xxx.xxxx:22][sftp]] cmd=SSH_MSG_CHANNEL_DATA): still have 21 bytes of 21 on closing channel
```
### Other information
_No response_
Contributor guide
No contributing guide indexed for this repository
Research direction
Start with SftpOutputStreamAsync.internalTransfer and internalFlush, then follow SftpMessage.waitUntilSent through AbstractSshFuture.verifyResult and the UnixAsynchronousSocketChannelImpl timeout shown in the trace. Reproduce a large SFTP upload and inspect the Mina logs around exceptionCaught and doCloseImmediately. Done means the source of the ten-minute timeout is identified and the upload no longer closes unexpectedly, with regression coverage if the repository supports it.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- java
- Domain
- networking
- Issue type
- Bug
- Difficulty
- 4/5
- Estimated time
- 3-5 days
- Activity status
- Stale
- Clarity
- Mostly clear
- Newbie friendliness
- 35/100