sftp: Performance regression from v1.12.0 to v1.13.0 (and master)

While investigating https://github.com/rclone/rclone/issues/5197 I discovered that doing transfers to rsync.net had gone from 300 KB/s in v1.12.0 to 100KB/s in v1.13.0

The rsync.net servers run FreeBSD which is one unusual thing about them and the other is that they are a long way away from me (150ms) so have the usual problems with long fat TCP pipes. Rclone uses the ReadFrom interface in the sftp client so that the sftp library can increase the number of outstanding packets to help with this.

Here are some tests (my upload is capable of 2MB/s).

make && rclone version && rclone copy -vv --stats 10s /tmp/499.91M rsyncnet: 2>&1 | grep 499.91M:

v1.12.0

 *                                       499.91M:  0% /499.910M, 312.432k/s, 27m8s
 *                                       499.91M:  1% /499.910M, 309.264k/s, 27m15s
 *                                       499.91M:  1% /499.910M, 281.361k/s, 29m49s
 *                                       499.91M:  2% /499.910M, 312.820k/s, 26m37s
 *                                       499.91M:  3% /499.910M, 347.230k/s, 23m48s

v1.13.0

 *                                       499.91M:  0% /499.910M, 81.331k/s, 1h44m44s
 *                                       499.91M:  0% /499.910M, 97.554k/s, 1h27m8s
 *                                       499.91M:  0% /499.910M, 98.655k/s, 1h25m59s
 *                                       499.91M:  0% /499.910M, 122.371k/s, 1h9m7s
 *                                       499.91M:  1% /499.910M, 122.173k/s, 1h9m4s

master

 *                                       499.91M:  0% /499.910M, 109.761k/s, 1h17m33s
 *                                       499.91M:  0% /499.910M, 102.153k/s, 1h23m11s
 *                                       499.91M:  0% /499.910M, 91.254k/s, 1h32m58s
 *                                       499.91M:  0% /499.910M, 85.305k/s, 1h39m18s
 *                                       499.91M:  0% /499.910M, 76.641k/s, 1h50m23s

I bisected this change and discovered this commit is probably the problem. I’m reasonably sure that is the problem commit, and it is certainly touching the code in question. Before this commit at 0be6950c0e91d5cb73a4d690270d3a5010ac9808 the performance is definitely OK and after it is is bad. However there is some variation after the commit so there may be more commits involved.

commit fc156996912168806d33b55794e2f5436fae2c3d Author: Cassondra Foesch Date: Sun Feb 21 20:32:09 2021 +0000

fixed concurrent writes, mid-polish

client.go | 614 +++++++++++++++++++++++++++++++++++++±----------------------- 1 file changed, 373 insertions(+), 241 deletions(-)

Cc: @puellanivis