Rebex.Net.SshException: The operation was not completed within the specified time limit

Question

Hello

While doing sftp.GetFile with a 500Mb file, i get the exception:

2018-07-31 15:13:14.502 DEBUG Sftp(9)[1] Response: SSHFXPDATA (9045, 28672 bytes)
2018-07-31 15:13:14.502 DEBUG Sftp(9)[1] Command: SSHFXPREAD (9061, 0x0, 259682304, 28672)
2018-07-31 15:13:14.524 DEBUG Sftp(9)[1] Response: SSHFXPDATA (9046, 28672 bytes)
2018-07-31 15:13:14.524 DEBUG Sftp(9)[1] Command: SSHFXPREAD (9062, 0x0, 259710976, 28672)
2018-07-31 15:13:14.542 DEBUG Sftp(9)[1] Response: SSHFXPDATA (9047, 28672 bytes)
2018-07-31 15:13:14.542 DEBUG Sftp(9)[1] Command: SSHFXPREAD (9063, 0x0, 259739648, 28672)
2018-07-31 15:13:14.561 DEBUG Sftp(9)[1] Response: SSHFXPDATA (9048, 28672 bytes)
2018-07-31 15:13:14.561 DEBUG Sftp(9)[1] Command: SSHFXPREAD (9064, 0x0, 259768320, 28672)
2018-07-31 15:13:14.577 DEBUG Sftp(9)[1] Response: SSHFXPDATA (9049, 28672 bytes)
2018-07-31 15:13:14.577 DEBUG Sftp(9)[1] Command: SSHFXPREAD (9065, 0x0, 259796992, 28672)
2018-07-31 15:13:14.599 DEBUG Sftp(9)[1] Response: SSHFXPDATA (9050, 28672 bytes)
2018-07-31 15:13:14.603 DEBUG Sftp(9)[1] Command: SSHFXPREAD (9066, 0x0, 259825664, 28672)
2018-07-31 15:13:14.615 DEBUG Sftp(9)[1] Response: SSHFXPDATA (9051, 28672 bytes)
2018-07-31 15:13:14.615 DEBUG Sftp(9)[1] Command: SSHFXPREAD (9067, 0x0, 259854336, 28672)
2018-07-31 15:13:14.633 DEBUG Sftp(9)[1] Response: SSHFXPDATA (9052, 28672 bytes)
2018-07-31 15:13:14.633 DEBUG Sftp(9)[1] Command: SSHFXPREAD (9068, 0x0, 259883008, 28672)
2018-07-31 15:15:14.656 ERROR Sftp(9)[1] SSH: Rebex.Net.SshException: The operation was not completed within the specified time limit.
in Rebex.Net.SshSession.wwqq[a,b](vgmq2 adk, Int32 adl, vgmr adm, b adn, a ado, a adp) in Rebex.Net.SshSession.wwqp[a,b](vgmq2 adi, b adj)
in Rebex.Net.SshChannel.rphn[a,b](vgmq2 va, b vb) in Rebex.Net.SshChannel.Receive(Byte[] buffer, Int32 offset, Int32 count) 2018-07-31 15:15:14.657 DEBUG Sftp(9)[1] Info: Waiting for 15 outstanding read requests to arrive. 2018-07-31 15:17:14.672 ERROR Sftp(9)[1] SSH: Rebex.Net.SshException: The operation was not completed within the specified time limit. in Rebex.Net.SshSession.wwqq[a,b](vgmq2 adk, Int32 adl, vgmr adm, b adn, a ado, a adp)
in Rebex.Net.SshSession.wwqp[a,b](vgmq2 adi, b adj) in Rebex.Net.SshChannel.rphn[a,b](vgmq2 va, b vb)
in Rebex.Net.SshChannel.Receive(Byte[] buffer, Int32 offset, Int32 count)
2018-07-31 15:17:14.673 ERROR Sftp(9)[1] Info: Rebex.Net.SshException: The operation was not completed within the specified time limit.
in Rebex.Net.SshSession.wwqq[a,b](vgmq2 adk, Int32 adl, vgmr adm, b adn, a ado, a adp) in Rebex.Net.SshSession.wwqp[a,b](vgmq2 adi, b adj)
in Rebex.Net.SshChannel.rphn[a,b](vgmq`2 va, b vb)
in Rebex.Net.SshChannel.Receive(Byte[] buffer, Int32 offset, Int32 count)
in ctci.licr(Byte[] m, Int32 n, Int32 o)
in ctcy.mpez(Int32 arz)
in ctcy.mpfb(hffs& asc)
in ctcy.mpey(UInt32 arx, Boolean ary)
in ctcy.mpea(UInt32 apa, ctch apb)
in Rebex.Net.Sftp.ypkq(ctch sv, String sw, Stream sx, Int64 sy, Int64 sz, hetr ta)

Thanks, Marcelo.

Answer 1

UPDATE:

The issue was caused by a bug in the Rebex file server, which was fixed in version 2018 R2.1:

Fixed semi-random timeout exception in SFTP subsystem on extremely fast connections.

---

From the log, it seems that the server didn't send any data for 60 seconds so the client timed out. See highlighted part of the log:

2018-07-31 15:13:14.633 DEBUG Sftp(9)1 Command: SSHFXPREAD (9068, 0x0, 259883008, 28672)
2018-07-31 15:15:14.656 ERROR Sftp(9)1 SSH:
Rebex.Net.SshException: The operation was not completed within the
specified time limit.

It can be caused by two cases:

1. The client failed to receive the packet.
2. The server failed to send the packet.

To determine which case arose, you have to use a network analyzer (such as WireShark) and monitor the traffic.

---

However, I noticed following message in the log:

Info: Waiting for 15 outstanding read requests to arrive.

By default, transfer requests are queued to improve transfer speed. Please, try to disable this feature like this:

var client = new Sftp();
client.Settings.DisableTransferQueue = true;

Or decrease the queue length like this (default is 16):

client.Settings.DownloadQueueLength = 2;

Disabling transfer queue can solve the issue, but it can have negative effect to transfer speed. Unfortunately, some servers are not able to handle queued requests, so this is the only option in that case.

Comments

I forget to say that te server is Rebex. Maybe it could be a time out on server side.

---

Which versions of Rebex SFTP server and SFTP client you are using?

---

Rebex  (2018 R2) for .NET 4.0-4.7

Server Version: 3.0.6755.0
SFTP Version: 3.0.6755.0

I try with client.Settings.DisableTransferQueue = true;
and it works, but as you said, it's worsens downloading speed

---

Thank you for the info. For now, the workaround is to disable transfer queue.

We will try to reproduce the issue ourselves and analyze it. Can you please share more details about your environment?
If you don't want to shaere it here publicly, please send it to support@rebex.net.

We would like to know any useful information such as:
- what OS and .NET Framework you have on client and server (these information is at the beginning of Rebex log)
- do you use some special connection settings (such as proxy, bandwidth trotting etc.)
- do you use "direct" LAN connection or WiFi or VPN, etc.
- any other information which can help us to reproduce the issue

And also please share info about:
- does the timeout occur every time, for the 500MB file
- does it timeout at the same size

Thank you.

---

Hi,

I send to support all the information.

Marcelo.

---

Thank you very much for provided info.
We will diagnose the issue and keep you updated.

---

Thanks to information provided by @Marcelo, we were able to find the cause. It was server side issue, which will be fixed in next public release.