apache / apache/mina-sshd

InterruptedByTimeoutException from UnixAsynchronousSocketChannelImpl on big files after around 10 minutes

Open
#764 3 comments 0 reactions 0 assignees View on GitHub
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

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.