apache / apache/mina-sshd

A write operation is already pending

Open
#644 2 comments 0 reactions 0 assignees View on GitHub
bug
Dominant language
Java
Stars
1.1k
Forks
400
Avg merge
5d 1h
Merged PRs (30d)
1

Description

### Version

2.13.2

### Bug description

Hi @tomaswolf,

I have a strange situation where I get this exception:
org.apache.sshd.common.io.WritePendingException: A write operation is already pending; cannot write ... bytes.

To explain the context, I use a shared session:

```
ClientSession clientSession =
this.sshClient
.connect(sshdConfiguration.getUserName(), sshdConfiguration.getHost(),
sshdConfiguration.getPort())
.verify(verifyTimeout)
.getSession();
```

And then in order to not create too many sessions I create different channels on this same session:

```
SftpClient client = SftpClientFactory.instance().createSftpClient(clientSession);
```

The different clients are used in one thread only, there is no concurrency involved when using them… So for me I should not have parallels write operations on the same client so not on the same `ChannelAsyncOutputStream` …

Still I get this exception… However, I can see that I first get a:

```
Caused by: org.apache.sshd.common.SshException: IoWriteFutureImpl[SftpChannelSubsystem[id=8, recipient=8]-ClientSessionImpl[xxxxxxxxxxx@/xx.x.xxx.xx:22][sftp][SSH_MSG_CHANNEL_DATA]]: Failed to get operation result within specified timeout: 30000 msec
at org.apache.sshd.common.future.AbstractSshFuture.lambda$verifyResult$1(AbstractSshFuture.java:114) ~[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:114) ~[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]
```

Then I get when closing the channel or trying to send another message later:

```
org.apache.sshd.common.io.WritePendingException: A write operation is already pending; cannot write 31 bytes
at org.apache.sshd.common.channel.ChannelAsyncOutputStream.writeBuffer(ChannelAsyncOutputStream.java:110) ~[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]
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]
```

I wonder if the internal state `ChannelAsyncOutputStream#writeState.writeInProgress = true;` is not reset leading to that problem ?
I can add that I check before trying a new transfer if the channel is closed, so if my first guess is correct I guess we should have the channel closed in such case or the state reset ?

Also if you could confirm that the first timeout is caused by the fact that server is not replying at all or at least we did not receive a reply ?

### Actual behavior

We get a time out then exception on next write

### Expected behavior

I expected to be able to write again on the same channel or get the channel closed

### Relevant log output

_No response_

### Other information

_No response_

Contributor guide

No contributing guide indexed for this repository

Research direction

Start with ChannelAsyncOutputStream.java and trace the timeout path from SftpOutputStreamAsync.java through DefaultSftpClient.java, using the stack traces and writeState reference in the report. Reproduce the timeout followed by channel close or another write, then verify that the channel can either be closed cleanly or accept a subsequent write without the pending-write exception.

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.