Slow speed after a while transferring files

CharonX · January 15, 2024, 8:24pm

What is the problem you are having with rclone?

Slow speed after a while transferring files.

I transfer a lot of big files from a couple of GB up to 50 GB. After a while for example a file is finished 70% at my max speed (I do have a 400Mbit download at home) the download speed is dropping to less than 1Mbit/s. Its not getting better over time. It keeps low. This is happening to all transfers.

I can stop rclone and restart again and I get full speed again. But why is this keep happening? Its not a problem son the source server since rsync is working fine. But rclone has some advantages.

Any ideas?

Run the command 'rclone version' and share the full output of the

command.rclone v1.65.1
- os/version: ubuntu 22.04 (64 bit)
- os/kernel: 4.4.302+ (x86_64)
- os/type: linux
- os/arch: amd64
- go/version: go1.21.5
- go/linking: static
- go/tags: none

Which cloud storage system are you using? (eg Google Drive)

sftp

The command you were trying to run (eg `rclone copy /tmp remote:tmp`)

rclone copy sftp-server:/path/  $DEST/ -P --transfers=8

Please run 'rclone config redacted' and share the full output. If you get command not found, please make sure to update rclone.

[sftp-server]
type = sftp
host = XXX
user = XXX
port = 22
pass = XXX
use_insecure_cipher = false
shell_type = unix
md5sum_command = md5sum
sha1sum_command = sha1sum
### Double check the config for sensitive info before posting publicly

Here is a screenshot. Less than 1Mbit/s total used.:

CharonX · January 15, 2024, 8:35pm

Needed 17min for 33GB. But for the last 2GB i need over 1h.

kapitainsky · January 15, 2024, 8:45pm

Can you try the same with --transfers=4?

If still a problem post full DEBUG output of:

rclone copy sftp-server:/path/  $DEST/ -vv

CharonX · January 16, 2024, 7:07pm

Thanks for your response.

I tried tu run a test:



2024/01/16 20:00:47 DEBUG : test.img: multi-thread copy: chunk 79/80 (5234491392-5301600256) size 64Mi finished
2024/01/16 20:00:47 DEBUG : test.img: multi-thread copy: chunk 80/80 (5301600256-5368709120) size 64Mi starting
2024/01/16 20:00:47 DEBUG : test.img.zosiloc0.partial: writing chunk 79
2024/01/16 20:00:48 DEBUG : test23img: multi-thread copy: chunk 75/80 (4966055936-5033164800) size 64Mi finished
2024/01/16 20:00:48 DEBUG : test23img: multi-thread copy: chunk 77/80 (5100273664-5167382528) size 64Mi starting
2024/01/16 20:00:48 DEBUG : test23img.talovod2.partial: writing chunk 76
2024/01/16 20:00:50 DEBUG : test.img: multi-thread copy: chunk 80/80 (5301600256-5368709120) size 64Mi finished
2024/01/16 20:00:50 DEBUG : test23img: multi-thread copy: chunk 76/80 (5033164800-5100273664) size 64Mi finished
2024/01/16 20:00:50 DEBUG : test23img: multi-thread copy: chunk 78/80 (5167382528-5234491392) size 64Mi starting
2024/01/16 20:00:50 DEBUG : test23img.talovod2.partial: writing chunk 77
2024/01/16 20:00:51 DEBUG : test23img: multi-thread copy: chunk 77/80 (5100273664-5167382528) size 64Mi finished
2024/01/16 20:00:51 DEBUG : test23img: multi-thread copy: chunk 79/80 (5234491392-5301600256) size 64Mi starting
2024/01/16 20:00:52 DEBUG : test23img.talovod2.partial: writing chunk 78
2024/01/16 20:00:53 DEBUG : test23img: multi-thread copy: chunk 78/80 (5167382528-5234491392) size 64Mi finished
2024/01/16 20:00:53 DEBUG : test23img: multi-thread copy: chunk 80/80 (5301600256-5368709120) size 64Mi starting
2024/01/16 20:00:53 DEBUG : test23img.talovod2.partial: writing chunk 79
2024/01/16 20:00:54 DEBUG : test23img: multi-thread copy: chunk 79/80 (5234491392-5301600256) size 64Mi finished
2024/01/16 20:00:56 DEBUG : test23img: multi-thread copy: chunk 80/80 (5301600256-5368709120) size 64Mi finished
2024/01/16 20:00:58 DEBUG : test.img.zosiloc0.partial: writing chunk 66
2024/01/16 20:01:58 DEBUG : sftp://user@server:22//test/: Not closing 12 unused connections as 6 sessions active
2024/01/16 20:02:58 DEBUG : sftp://user@server:22//test/: Not closing 12 unused connections as 6 sessions active
2024/01/16 20:03:58 DEBUG : sftp://user@server:22//test/: Not closing 12 unused connections as 6 sessions active
2024/01/16 20:04:58 DEBUG : sftp://user@server:22//test/: Not closing 12 unused connections as 6 sessions active
2024/01/16 20:05:58 DEBUG : sftp://user@server:22//test/: Not closing 12 unused connections as 6 sessions active
2024/01/16 20:06:58 DEBUG : sftp://user@server:22//test/: Not closing 12 unused connections as 6 sessions active
2024/01/16 20:07:58 DEBUG : sftp://user@server:22//test/: Not closing 12 unused connections as 6 sessions active
2024/01/16 20:08:58 DEBUG : sftp://user@server:22//test/: Not closing 12 unused connections as 6 sessions active
Transferred:       14.676 GiB / 35 GiB, 42%, 174.182 KiB/s, ETA 1d9h59m
Transferred:            0 / 5, 0%
Elapsed time:      7m32.9s
Transferring:
 *                                      test.img: 96% /5Gi, 86.563Ki/s, 35m47s
 *                                     test2.img: 99% /5Gi, 45.377Ki/s, 16m18s
 *                                     test23img: 97% /5Gi, 42.240Ki/s, 43m19s

As you can see. I transferred almost 15GB in 7min and now i need over one day for the rest?
I see there are some messages about sfp connection but I do not understand why are so many connections open? Any way to reduce the open connections?
I set transfers to 3 in this test case.

rcRsc · January 17, 2024, 7:20am

I see the same when syncing pCloud-to-Koofr or pCloud-to-OneDrive.
Didn't find a better solution that to restart sync.

asdffdsa · January 17, 2024, 1:56pm

that is most confusing, as every sync you do fails in the same manner.
sftp-to-local, and cloud-to-cloud.

not sure it will matter, but i might try
--multi-thread-streams=0 --inplace

kapitainsky · January 17, 2024, 2:02pm

I have to admit I do not understand what might cause it. I have never seen this behaviour myself.

I tend to think it is destination provider problem - throttling throughput after specific time or transferred data volume. But then it is strange that restarting sync restores speed to the original values....

Puzzled I am so far.

asdffdsa · January 17, 2024, 2:17pm

@CharonX, it would be most helpful, if you would post the top twenty lines from each debug log.
not 100% sure about $Dest, is that local?

in each case, the source and destination is different.
the OP has tested $Dest, which i assume is local.
and for the two cloud-to-cloud syncs that were mentioned, the dest are different cloud providers, koofr and onedrive.

CharonX · January 17, 2024, 2:32pm

$Dest ist local, right.

To avoid the speed issue I mount the folder using sshfs and use rclone just for ther transfer. It works like it should. I only have the issue using ssftp using rclone.

asdffdsa · January 17, 2024, 2:35pm

sorry, confused, if the issue is just sftp, then what does this have to do with it, as the soure is not sftp and the dest is not sftp?
"I see the same when syncing pCloud-to-Koofr or pCloud-to-OneDrive."

CharonX · January 17, 2024, 2:36pm

The source is remote (sftp).
sftp -> local

CharonX · January 17, 2024, 2:37pm

Thats not from me. Someone else wrote it

asdffdsa · January 17, 2024, 3:27pm

yeah, my bad, thanks for clarifying.

can post the top 20 lines of a debug log and tell us more about the sftp server?

i use sftp on a daily basis for backups, mostly hetzner storagebox and rsync.net.
in addition, i download torrents via sftp from a seedbox.
in all cases, never had issues.

so just now, i did a quick download on 853 small files, no multi-part.

DEBUG : rclone: Version "v1.65.1" starting with parameters ["c:\\data\\rclone\\rclone.exe" "copy" "rsync:rcloner/kdbx/zip/backup" "b:\\rsynctest" "--progress" "--log-level=DEBUG" "--log-file=.\\\\log.copy.txt"]
DEBUG : Creating backend with remote "rsync:rcloner/kdbx/zip/backup"
DEBUG : Using config file from "c:\\data\\rclone\\rclone.conf"
DEBUG : sftp://redacted@redacted.rsync.net:22/rcloner/kdbx/zip/backup: New connection 192.168.62.233:57580->216.66.77.203:22 to "SSH-2.0-OpenSSH_8.9-hpn14v15 FreeBSD-openssh-portable-8.9.p1_3,1"
DEBUG : sftp://redacted@redacted.rsync.net:22/rcloner/kdbx/zip/backup: Shell type "unix" from config
DEBUG : sftp://redacted@redacted.rsync.net:22/rcloner/kdbx/zip/backup: Relative path resolved to "/data2/home/redacted/rcloner/kdbx/zip/backup"
DEBUG : sftp://redacted@redacted.rsync.net:22/rcloner/kdbx/zip/backup: Using root directory "/data2/home/redacted/rcloner/kdbx/zip/backup"
DEBUG : Creating backend with remote "b:\\rsynctest"
DEBUG : fs cache: renaming cache item "b:\\rsynctest" to be canonical "//?/b:/rsynctest"
DEBUG : Local file system at //?/b:/rsynctest: Waiting for checks to finish
DEBUG : Local file system at //?/b:/rsynctest: Waiting for transfers to finish
<snip>
DEBUG : sftp://redacted@redacted.rsync.net:22/rcloner/kdbx/zip/backup: New connection 192.168.62.233:57584->216.66.77.203:22 to "SSH-2.0-OpenSSH_8.9-hpn14v15 FreeBSD-openssh-portable-8.9.p1_3,1"
DEBUG : sftp://redacted@redacted.rsync.net:22/rcloner/kdbx/zip/backup: New connection 192.168.62.233:57585->216.66.77.203:22 to "SSH-2.0-OpenSSH_8.9-hpn14v15 FreeBSD-openssh-portable-8.9.p1_3,1"
DEBUG : sftp://redacted@redacted.rsync.net:22/rcloner/kdbx/zip/backup: New connection 192.168.62.233:57586->216.66.77.203:22 to "SSH-2.0-OpenSSH_8.9-hpn14v15 FreeBSD-openssh-portable-8.9.p1_3,1"
DEBUG : sftp://redacted@redacted.rsync.net:22/rcloner/kdbx/zip/backup: Shell path "/data2/home/redacted/rcloner/kdbx/zip/backup/kdbx.20211111.165439.7z"
DEBUG : sftp://redacted@redacted.rsync.net:22/rcloner/kdbx/zip/backup: Running remote command: md5 -r /data2/home/redacted/rcloner/kdbx/zip/backup/kdbx.20211111.165439.7z
DEBUG : sftp://redacted@redacted.rsync.net:22/rcloner/kdbx/zip/backup: Remote command result: 887c892fe8375572b5c7078b1f20f7ac /data2/home/redacted/rcloner/kdbx/zip/backup/kdbx.20211111.165439.7z
DEBUG : kdbx.20211111.165439.7z: Parsed hash: 887c892fe8375572b5c7078b1f20f7ac
DEBUG : kdbx.20211111.165439.7z: md5 = 887c892fe8375572b5c7078b1f20f7ac OK
DEBUG : kdbx.20211111.165439.7z.xifasid4.partial: renamed to: kdbx.20211111.165439.7z
INFO  : kdbx.20211111.165439.7z: Copied (new)
DEBUG : sftp://redacted@redacted.rsync.net:22/rcloner/kdbx/zip/backup: Shell path "/data2/home/redacted/rcloner/kdbx/zip/backup/kdbx.20211111.160340.7z"
DEBUG : sftp://redacted@redacted.rsync.net:22/rcloner/kdbx/zip/backup: Shell path "/data2/home/redacted/rcloner/kdbx/zip/backup/kdbx.20211111.170046.7z"
DEBUG : sftp://redacted@redacted.rsync.net:22/rcloner/kdbx/zip/backup: Running remote command: md5 -r /data2/home/redacted/rcloner/kdbx/zip/backup/kdbx.20211111.160340.7z
DEBUG : sftp://redacted@redacted.rsync.net:22/rcloner/kdbx/zip/backup: Running remote command: md5 -r /data2/home/redacted/rcloner/kdbx/zip/backup/kdbx.20211111.170046.7z
DEBUG : sftp://redacted@redacted.rsync.net:22/rcloner/kdbx/zip/backup: Remote command result: 03cf50448a1226f9fba1d42c57a20871 /data2/home/redacted/rcloner/kdbx/zip/backup/kdbx.20211111.160340.7z
DEBUG : kdbx.20211111.160340.7z: Parsed hash: 03cf50448a1226f9fba1d42c57a20871
DEBUG : kdbx.20211111.160340.7z: md5 = 03cf50448a1226f9fba1d42c57a20871 OK
DEBUG : kdbx.20211111.160340.7z.nizoleh2.partial: renamed to: kdbx.20211111.160340.7z
INFO  : kdbx.20211111.160340.7z: Copied (new)
<snip>
INFO  : 
Transferred:   	    1.268 GiB / 1.268 GiB, 100%, 5.398 MiB/s, ETA 0s
Transferred:          853 / 853, 100%
Elapsed time:      5m36.2s

DEBUG : 41 go routines active
DEBUG : sftp://redacted@redacted.rsync.net:22/rcloner/kdbx/zip/backup: Closing 4 unused connections

larger download, uses multi-part

DEBUG : --max-age 1.7142857142857142w to 2024-01-05 10:47:13.2456416 -0500 EST m=-1036799.874078099
DEBUG : rclone: Version "v1.65.1" starting with parameters ["c:\\data\\rclone\\rclone.exe" "copy" "hetznersbox01_sftp_23:smbtest01/BCJ_ABP_EN10_CDRIVE_2_BR_SMBTEST01/ABP_EN10_CDRIVE - EN10" "b:\\hetznertest" "--transfers=8" "--checkers=8" "--max-age=12d" "--progress" "--log-level=DEBUG" "--log-file=.\\\\log.copy.txt"]
DEBUG : Creating backend with remote "hetznersbox01_sftp_23:smbtest01/BCJ_ABP_EN10_CDRIVE_2_BR_SMBTEST01/ABP_EN10_CDRIVE - EN10"
DEBUG : Using config file from "c:\\data\\rclone\\rclone.conf"
DEBUG : sftp://redacted@redacted.your-storagebox.de:23/smbtest01/BCJ_ABP_EN10_CDRIVE_2_BR_SMBTEST01/ABP_EN10_CDRIVE - EN10: New connection 192.168.62.233:58649->65.109.152.247:23 to "SSH-2.0-OpenSSH_9.3 FreeBSD-20230719"
DEBUG : sftp://redacted@redacted.your-storagebox.de:23/smbtest01/BCJ_ABP_EN10_CDRIVE_2_BR_SMBTEST01/ABP_EN10_CDRIVE - EN10: Shell type "unix" from config
DEBUG : sftp://redacted@redacted.your-storagebox.de:23/smbtest01/BCJ_ABP_EN10_CDRIVE_2_BR_SMBTEST01/ABP_EN10_CDRIVE - EN10: Relative path resolved to "/home/smbtest01/BCJ_ABP_EN10_CDRIVE_2_BR_SMBTEST01/ABP_EN10_CDRIVE - EN10"
DEBUG : sftp://redacted@redacted.your-storagebox.de:23/smbtest01/BCJ_ABP_EN10_CDRIVE_2_BR_SMBTEST01/ABP_EN10_CDRIVE - EN10: Using root directory "/home/smbtest01/BCJ_ABP_EN10_CDRIVE_2_BR_SMBTEST01/ABP_EN10_CDRIVE - EN10"
DEBUG : Creating backend with remote "b:\\hetznertest"
DEBUG : fs cache: renaming cache item "b:\\hetznertest" to be canonical "//?/b:/hetznertest"
<snip>
DEBUG : ABP_EN10_CDRIVE - EN10D2024-01-05T203022_D4E0.vib: multi-thread copy: disabling buffering because destination uses OpenWriterAt
DEBUG : Local file system at //?/b:/hetznertest: Waiting for transfers to finish
DEBUG : ABP_EN10_CDRIVE - EN10D2024-01-06T203028_81EF.vib: multi-thread copy: disabling buffering because destination uses OpenWriterAt
INFO  : Writing sparse files: use --local-no-sparse or --multi-thread-streams 0 to disable
DEBUG : ABP_EN10_CDRIVE - EN10D2024-01-06T203028_81EF.vib: multi-thread copy: write buffer set to 131072
DEBUG : ABP_EN10_CDRIVE - EN10D2024-01-05T203022_D4E0.vib: multi-thread copy: write buffer set to 131072
DEBUG : ABP_EN10_CDRIVE - EN10D2024-01-06T203028_81EF.vib: multi-thread copy: using backend concurrency of 4 instead of --multi-thread-streams 4
DEBUG : ABP_EN10_CDRIVE - EN10D2024-01-05T203022_D4E0.vib: multi-thread copy: using backend concurrency of 4 instead of --multi-thread-streams 4
DEBUG : ABP_EN10_CDRIVE - EN10D2024-01-05T203022_D4E0.vib: Starting multi-thread copy with 142 chunks of size 64Mi with 4 parallel streams
DEBUG : ABP_EN10_CDRIVE - EN10D2024-01-06T203028_81EF.vib: Starting multi-thread copy with 103 chunks of size 64Mi with 4 parallel streams
DEBUG : ABP_EN10_CDRIVE - EN10D2024-01-05T203022_D4E0.vib: multi-thread copy: chunk 4/142 (201326592-268435456) size 64Mi starting
DEBUG : ABP_EN10_CDRIVE - EN10D2024-01-05T203022_D4E0.vib: multi-thread copy: chunk 2/142 (67108864-134217728) size 64Mi starting
DEBUG : ABP_EN10_CDRIVE - EN10D2024-01-06T203028_81EF.vib: multi-thread copy: chunk 1/103 (0-67108864) size 64Mi starting
DEBUG : ABP_EN10_CDRIVE - EN10D2024-01-06T203028_81EF.vib: multi-thread copy: chunk 3/103 (134217728-201326592) size 64Mi starting
DEBUG : ABP_EN10_CDRIVE - EN10D2024-01-06T203028_81EF.vib: multi-thread copy: chunk 2/103 (67108864-134217728) size 64Mi starting
DEBUG : ABP_EN10_CDRIVE - EN10D2024-01-06T203028_81EF.vib: multi-thread copy: chunk 4/103 (201326592-268435456) size 64Mi starting
DEBUG : ABP_EN10_CDRIVE - EN10D2024-01-05T203022_D4E0.vib: multi-thread copy: chunk 1/142 (0-67108864) size 64Mi starting
DEBUG : ABP_EN10_CDRIVE - EN10D2024-01-05T203022_D4E0.vib: multi-thread copy: chunk 3/142 (134217728-201326592) size 64Mi starting
DEBUG : sftp://redacted@redacted.your-storagebox.de:23/smbtest01/BCJ_ABP_EN10_CDRIVE_2_BR_SMBTEST01/ABP_EN10_CDRIVE - EN10: New connection 192.168.62.233:58650->65.109.152.247:23 to "SSH-2.0-OpenSSH_9.3 FreeBSD-20230719"
DEBUG : sftp://redacted@redacted.your-storagebox.de:23/smbtest01/BCJ_ABP_EN10_CDRIVE_2_BR_SMBTEST01/ABP_EN10_CDRIVE - EN10: New connection 192.168.62.233:58651->65.109.152.247:23 to "SSH-2.0-OpenSSH_9.3 FreeBSD-20230719"
DEBUG : sftp://redacted@redacted.your-storagebox.de:23/smbtest01/BCJ_ABP_EN10_CDRIVE_2_BR_SMBTEST01/ABP_EN10_CDRIVE - EN10: New connection 192.168.62.233:58655->65.109.152.247:23 to "SSH-2.0-OpenSSH_9.3 FreeBSD-20230719"
DEBUG : sftp://redacted@redacted.your-storagebox.de:23/smbtest01/BCJ_ABP_EN10_CDRIVE_2_BR_SMBTEST01/ABP_EN10_CDRIVE - EN10: New connection 192.168.62.233:58653->65.109.152.247:23 to "SSH-2.0-OpenSSH_9.3 FreeBSD-20230719"
DEBUG : sftp://redacted@redacted.your-storagebox.de:23/smbtest01/BCJ_ABP_EN10_CDRIVE_2_BR_SMBTEST01/ABP_EN10_CDRIVE - EN10: New connection 192.168.62.233:58654->65.109.152.247:23 to "SSH-2.0-OpenSSH_9.3 FreeBSD-20230719"
DEBUG : sftp://redacted@redacted.your-storagebox.de:23/smbtest01/BCJ_ABP_EN10_CDRIVE_2_BR_SMBTEST01/ABP_EN10_CDRIVE - EN10: New connection 192.168.62.233:58652->65.109.152.247:23 to "SSH-2.0-OpenSSH_9.3 FreeBSD-20230719"
DEBUG : ABP_EN10_CDRIVE - EN10D2024-01-05T203022_D4E0.vib.deguwaz0.partial: writing chunk 3
DEBUG : ABP_EN10_CDRIVE - EN10D2024-01-05T203022_D4E0.vib.deguwaz0.partial: writing chunk 1
DEBUG : sftp://redacted@redacted.your-storagebox.de:23/smbtest01/BCJ_ABP_EN10_CDRIVE_2_BR_SMBTEST01/ABP_EN10_CDRIVE - EN10: New connection 192.168.62.233:58656->65.109.152.247:23 to "SSH-2.0-OpenSSH_9.3 FreeBSD-20230719"
DEBUG : ABP_EN10_CDRIVE - EN10D2024-01-06T203028_81EF.vib.giragug7.partial: writing chunk 3
DEBUG : ABP_EN10_CDRIVE - EN10D2024-01-06T203028_81EF.vib.giragug7.partial: writing chunk 2
DEBUG : ABP_EN10_CDRIVE - EN10D2024-01-06T203028_81EF.vib.giragug7.partial: writing chunk 1
DEBUG : sftp://redacted@redacted.your-storagebox.de:23/smbtest01/BCJ_ABP_EN10_CDRIVE_2_BR_SMBTEST01/ABP_EN10_CDRIVE - EN10: New connection 192.168.62.233:58657->65.109.152.247:23 to "SSH-2.0-OpenSSH_9.3 FreeBSD-20230719"
DEBUG : ABP_EN10_CDRIVE - EN10D2024-01-06T203028_81EF.vib.giragug7.partial: writing chunk 0
DEBUG : ABP_EN10_CDRIVE - EN10D2024-01-05T203022_D4E0.vib.deguwaz0.partial: writing chunk 0
DEBUG : ABP_EN10_CDRIVE - EN10D2024-01-05T203022_D4E0.vib.deguwaz0.partial: writing chunk 2
DEBUG : sftp://redacted@redacted.your-storagebox.de:23/smbtest01/BCJ_ABP_EN10_CDRIVE_2_BR_SMBTEST01/ABP_EN10_CDRIVE - EN10: Shell path "/home/smbtest01/BCJ_ABP_EN10_CDRIVE_2_BR_SMBTEST01/ABP_EN10_CDRIVE - EN10/ABP_EN10_CDRIVE - EN10.vbm"
DEBUG : sftp://redacted@redacted.your-storagebox.de:23/smbtest01/BCJ_ABP_EN10_CDRIVE_2_BR_SMBTEST01/ABP_EN10_CDRIVE - EN10: Running remote command: md5 -r /home/smbtest01/BCJ_ABP_EN10_CDRIVE_2_BR_SMBTEST01/ABP_EN10_CDRIVE\ -\ EN10/ABP_EN10_CDRIVE\ -\ EN10.vbm
DEBUG : sftp://redacted@redacted.your-storagebox.de:23/smbtest01/BCJ_ABP_EN10_CDRIVE_2_BR_SMBTEST01/ABP_EN10_CDRIVE - EN10: Remote command result: 9b6a0670f98fe523828713b87fc583f9 /home/smbtest01/BCJ_ABP_EN10_CDRIVE_2_BR_SMBTEST01/ABP_EN10_CDRIVE - EN10/ABP_EN10_CDRIVE - EN10.vbm
DEBUG : ABP_EN10_CDRIVE - EN10.vbm: Parsed hash: 9b6a0670f98fe523828713b87fc583f9
DEBUG : ABP_EN10_CDRIVE - EN10.vbm: md5 = 9b6a0670f98fe523828713b87fc583f9 OK
DEBUG : ABP_EN10_CDRIVE - EN10.vbm.lupiwoy4.partial: renamed to: ABP_EN10_CDRIVE - EN10.vbm
INFO  : ABP_EN10_CDRIVE - EN10.vbm: Copied (new)
DEBUG : sftp://redacted@redacted.your-storagebox.de:23/smbtest01/BCJ_ABP_EN10_CDRIVE_2_BR_SMBTEST01/ABP_EN10_CDRIVE - EN10: Not closing 9 unused connections as 8 sessions active
DEBUG : ABP_EN10_CDRIVE - EN10D2024-01-06T203028_81EF.vib: multi-thread copy: chunk 1/103 (0-67108864) size 64Mi finished
DEBUG : ABP_EN10_CDRIVE - EN10D2024-01-06T203028_81EF.vib: multi-thread copy: chunk 5/103 (268435456-335544320) size 64Mi starting
DEBUG : ABP_EN10_CDRIVE - EN10D2024-01-06T203028_81EF.vib.giragug7.partial: writing chunk 4
DEBUG : ABP_EN10_CDRIVE - EN10D2024-01-05T203022_D4E0.vib: multi-thread copy: chunk 1/142 (0-67108864) size 64Mi finished
DEBUG : ABP_EN10_CDRIVE - EN10D2024-01-05T203022_D4E0.vib: multi-thread copy: chunk 5/142 (268435456-335544320) size 64Mi starting
DEBUG : ABP_EN10_CDRIVE - EN10D2024-01-05T203022_D4E0.vib: multi-thread copy: chunk 3/142 (134217728-201326592) size 64Mi finished
DEBUG : ABP_EN10_CDRIVE - EN10D2024-01-06T203028_81EF.vib: multi-thread copy: chunk 4/103 (201326592-268435456) size 64Mi finished
DEBUG : ABP_EN10_CDRIVE - EN10D2024-01-05T203022_D4E0.vib: multi-thread copy: chunk 6/142 (335544320-402653184) size 64Mi starting
DEBUG : ABP_EN10_CDRIVE - EN10D2024-01-05T203022_D4E0.vib.deguwaz0.partial: writing chunk 4
DEBUG : ABP_EN10_CDRIVE - EN10D2024-01-05T203022_D4E0.vib.deguwaz0.partial: writing chunk 5
DEBUG : ABP_EN10_CDRIVE - EN10D2024-01-06T203028_81EF.vib: multi-thread copy: chunk 6/103 (335544320-402653184) size 64Mi starting
DEBUG : ABP_EN10_CDRIVE - EN10D2024-01-06T203028_81EF.vib.giragug7.partial: writing chunk 5
DEBUG : ABP_EN10_CDRIVE - EN10D2024-01-05T203022_D4E0.vib: multi-thread copy: chunk 4/142 (201326592-268435456) size 64Mi finished
DEBUG : ABP_EN10_CDRIVE - EN10D2024-01-06T203028_81EF.vib: multi-thread copy: chunk 2/103 (67108864-134217728) size 64Mi finished
DEBUG : ABP_EN10_CDRIVE - EN10D2024-01-05T203022_D4E0.vib: multi-thread copy: chunk 7/142 (402653184-469762048) size 64Mi starting
DEBUG : ABP_EN10_CDRIVE - EN10D2024-01-06T203028_81EF.vib: multi-thread copy: chunk 7/103 (402653184-469762048) size 64Mi starting
DEBUG : ABP_EN10_CDRIVE - EN10D2024-01-05T203022_D4E0.vib.deguwaz0.partial: writing chunk 6
DEBUG : ABP_EN10_CDRIVE - EN10D2024-01-06T203028_81EF.vib.giragug7.partial: writing chunk 6
<snip>
DEBUG : ABP_EN10_CDRIVE - EN10D2024-01-06T203028_81EF.vib: Finished multi-thread copy with 103 parts of size 64Mi
DEBUG : sftp://redacted@redacted.your-storagebox.de:23/smbtest01/BCJ_ABP_EN10_CDRIVE_2_BR_SMBTEST01/ABP_EN10_CDRIVE - EN10: Shell path "/home/smbtest01/BCJ_ABP_EN10_CDRIVE_2_BR_SMBTEST01/ABP_EN10_CDRIVE - EN10/ABP_EN10_CDRIVE - EN10D2024-01-06T203028_81EF.vib"
DEBUG : sftp://redacted@redacted.your-storagebox.de:23/smbtest01/BCJ_ABP_EN10_CDRIVE_2_BR_SMBTEST01/ABP_EN10_CDRIVE - EN10: Running remote command: md5 -r /home/smbtest01/BCJ_ABP_EN10_CDRIVE_2_BR_SMBTEST01/ABP_EN10_CDRIVE\ -\ EN10/ABP_EN10_CDRIVE\ -\ EN10D2024-01-06T203028_81EF.vib
DEBUG : ABP_EN10_CDRIVE - EN10D2024-01-05T203022_D4E0.vib: multi-thread copy: chunk 103/142 (6845104128-6912212992) size 64Mi finished
DEBUG : ABP_EN10_CDRIVE - EN10D2024-01-05T203022_D4E0.vib: multi-thread copy: chunk 106/142 (7046430720-7113539584) size 64Mi starting
DEBUG : ABP_EN10_CDRIVE - EN10D2024-01-05T203022_D4E0.vib.deguwaz0.partial: writing chunk 105
DEBUG : ABP_EN10_CDRIVE - EN10D2024-01-05T203022_D4E0.vib: multi-thread copy: chunk 102/142 (6777995264-6845104128) size 64Mi finished
DEBUG : ABP_EN10_CDRIVE - EN10D2024-01-05T203022_D4E0.vib: multi-thread copy: chunk 107/142 (7113539584-7180648448) size 64Mi starting
DEBUG : ABP_EN10_CDRIVE - EN10D2024-01-05T203022_D4E0.vib.deguwaz0.partial: writing chunk 106
DEBUG : sftp://redacted@redacted.your-storagebox.de:23/smbtest01/BCJ_ABP_EN10_CDRIVE_2_BR_SMBTEST01/ABP_EN10_CDRIVE - EN10: Remote command result: cfaa3c0a459238fe929100eac1397b88 /home/smbtest01/BCJ_ABP_EN10_CDRIVE_2_BR_SMBTEST01/ABP_EN10_CDRIVE - EN10/ABP_EN10_CDRIVE - EN10D2024-01-06T203028_81EF.vib
DEBUG : ABP_EN10_CDRIVE - EN10D2024-01-06T203028_81EF.vib: Parsed hash: cfaa3c0a459238fe929100eac1397b88
<snip>
DEBUG : sftp://redacted@redacted.your-storagebox.de:23/smbtest01/BCJ_ABP_EN10_CDRIVE_2_BR_SMBTEST01/ABP_EN10_CDRIVE - EN10: Not closing 9 unused connections as 1 sessions active
DEBUG : ABP_EN10_CDRIVE - EN10D2024-01-05T203022_D4E0.vib: Finished multi-thread copy with 142 parts of size 64Mi
DEBUG : sftp://redacted@redacted.your-storagebox.de:23/smbtest01/BCJ_ABP_EN10_CDRIVE_2_BR_SMBTEST01/ABP_EN10_CDRIVE - EN10: Shell path "/home/smbtest01/BCJ_ABP_EN10_CDRIVE_2_BR_SMBTEST01/ABP_EN10_CDRIVE - EN10/ABP_EN10_CDRIVE - EN10D2024-01-05T203022_D4E0.vib"
DEBUG : sftp://redacted@redacted.your-storagebox.de:23/smbtest01/BCJ_ABP_EN10_CDRIVE_2_BR_SMBTEST01/ABP_EN10_CDRIVE - EN10: Running remote command: md5 -r /home/smbtest01/BCJ_ABP_EN10_CDRIVE_2_BR_SMBTEST01/ABP_EN10_CDRIVE\ -\ EN10/ABP_EN10_CDRIVE\ -\ EN10D2024-01-05T203022_D4E0.vib
DEBUG : sftp://redacted@redacted.your-storagebox.de:23/smbtest01/BCJ_ABP_EN10_CDRIVE_2_BR_SMBTEST01/ABP_EN10_CDRIVE - EN10: Remote command result: 9f0be08cabd5ddee37cc940695ccc095 /home/smbtest01/BCJ_ABP_EN10_CDRIVE_2_BR_SMBTEST01/ABP_EN10_CDRIVE - EN10/ABP_EN10_CDRIVE - EN10D2024-01-05T203022_D4E0.vib
DEBUG : ABP_EN10_CDRIVE - EN10D2024-01-05T203022_D4E0.vib: Parsed hash: 9f0be08cabd5ddee37cc940695ccc095
DEBUG : ABP_EN10_CDRIVE - EN10D2024-01-05T203022_D4E0.vib: md5 = 9f0be08cabd5ddee37cc940695ccc095 OK
DEBUG : ABP_EN10_CDRIVE - EN10D2024-01-05T203022_D4E0.vib.deguwaz0.partial: renamed to: ABP_EN10_CDRIVE - EN10D2024-01-05T203022_D4E0.vib
INFO  : ABP_EN10_CDRIVE - EN10D2024-01-05T203022_D4E0.vib: Multi-thread Copied (new)
INFO  : 
Transferred:   	   15.272 GiB / 15.272 GiB, 100%, 26.086 KiB/s, ETA 0s
Transferred:            3 / 3, 100%
Elapsed time:      38m5.8s

DEBUG : 86 go routines active
DEBUG : sftp://redacted@redacted.your-storagebox.de:23/smbtest01/BCJ_ABP_EN10_CDRIVE_2_BR_SMBTEST01/ABP_EN10_CDRIVE - EN10: Closing 9 unused connections

kapitainsky · January 17, 2024, 5:19pm

By default rclone will use 64 of outstanding requests for one file. Maybe it is too much for your particular server?

try for example:

rclone copy sftp-server:/path/  $DEST/ -P --sftp-concurrency 16

CharonX · January 17, 2024, 5:57pm

I tried that already. My config looks like this right now:

[server]
type = sftp
host = server
user = myuser
port = 22
pass = mypass
use_insecure_cipher = false
disable_concurrent_reads = false
idle_timeout = 10
concurrency = 5
ciphers = aes256-ctr

asdffdsa · January 17, 2024, 6:00pm

can you do post that?

and that remote config, does not have shell_type

CharonX · January 17, 2024, 6:14pm

Here you go:

rclone copy -vv server:/src/ "/dest/" -P --transfers=3
2024/01/17 19:08:06 DEBUG : rclone: Version "v1.65.1" starting with parameters ["rclone" "copy" "-vv" "server:/src/" "/dest/" "-P" "--transfers=3"]
2024/01/17 19:08:06 DEBUG : Creating backend with remote "server:/src/"
2024/01/17 19:08:06 DEBUG : Using config file from "/root/.config/rclone/rclone.conf"
2024/01/17 19:08:07 DEBUG : sftp://myuser@server:22//src/: New connection 172.24.0.3:48112->xxx.xxx.xxx.xxx:22 to "SSH-2.0-OpenSSH_8.9p1 Ubuntu-3ubuntu0.5"
2024/01/17 19:08:07 DEBUG : sftp://myuser@server:22//src/: Shell type "unix" from config
2024/01/17 19:08:07 DEBUG : sftp://myuser@server:22//src/: Using root directory "/src"
2024/01/17 19:08:07 DEBUG : Creating backend with remote "/dest/"
2024/01/17 19:08:07 DEBUG : fs cache: renaming cache item "/dest/" to be canonical "/dest"
2024/01/17 19:08:07 DEBUG : test.img: Need to transfer - File not found at Destination
2024/01/17 19:08:07 DEBUG : test2.img: Need to transfer - File not found at Destination
2024/01/17 19:08:07 DEBUG : test23img: Need to transfer - File not found at Destination
2024/01/17 19:08:07 DEBUG : test24img: Need to transfer - File not found at Destination
2024/01/17 19:08:07 DEBUG : test25img: Need to transfer - File not found at Destination
2024/01/17 19:08:07 DEBUG : test.img: multi-thread copy: disabling buffering because destination uses OpenWriterAt
2024/01/17 19:08:07 DEBUG : test2.img: multi-thread copy: disabling buffering because destination uses OpenWriterAt
2024/01/17 19:08:07 DEBUG : test23img: multi-thread copy: disabling buffering because destination uses OpenWriterAt
2024/01/17 19:08:07 DEBUG : test.img: multi-thread copy: write buffer set to 131072
2024/01/17 19:08:07 DEBUG : test.img: multi-thread copy: using backend concurrency of 4 instead of --multi-thread-streams 4
2024/01/17 19:08:07 DEBUG : test.img: Starting multi-thread copy with 80 chunks of size 64Mi with 4 parallel streams
2024/01/17 19:08:07 DEBUG : test.img: multi-thread copy: chunk 4/80 (201326592-268435456) size 64Mi starting
2024/01/17 19:08:07 DEBUG : test.img: multi-thread copy: chunk 1/80 (0-67108864) size 64Mi starting
2024/01/17 19:08:07 DEBUG : test2.img: multi-thread copy: write buffer set to 131072
2024/01/17 19:08:07 DEBUG : test2.img: multi-thread copy: using backend concurrency of 4 instead of --multi-thread-streams 4
2024/01/17 19:08:07 DEBUG : test2.img: Starting multi-thread copy with 80 chunks of size 64Mi with 4 parallel streams
2024/01/17 19:08:07 DEBUG : test2.img: multi-thread copy: chunk 4/80 (201326592-268435456) size 64Mi starting
2024/01/17 19:08:07 DEBUG : test2.img: multi-thread copy: chunk 2/80 (67108864-134217728) size 64Mi starting
2024/01/17 19:08:07 DEBUG : test2.img: multi-thread copy: chunk 3/80 (134217728-201326592) size 64Mi starting
2024/01/17 19:08:07 DEBUG : test.img: multi-thread copy: chunk 2/80 (67108864-134217728) size 64Mi starting
2024/01/17 19:08:07 DEBUG : test.img: multi-thread copy: chunk 3/80 (134217728-201326592) size 64Mi starting
2024/01/17 19:08:07 DEBUG : test23img: multi-thread copy: write buffer set to 131072
2024/01/17 19:08:07 DEBUG : test23img: multi-thread copy: using backend concurrency of 4 instead of --multi-thread-streams 4
2024/01/17 19:08:07 DEBUG : test23img: Starting multi-thread copy with 80 chunks of size 64Mi with 4 parallel streams
2024/01/17 19:08:07 DEBUG : test23img: multi-thread copy: chunk 4/80 (201326592-268435456) size 64Mi starting
2024/01/17 19:08:07 DEBUG : test2.img: multi-thread copy: chunk 1/80 (0-67108864) size 64Mi starting
2024/01/17 19:08:07 DEBUG : test23img: multi-thread copy: chunk 1/80 (0-67108864) size 64Mi starting
2024/01/17 19:08:07 DEBUG : test23img: multi-thread copy: chunk 2/80 (67108864-134217728) size 64Mi starting
2024/01/17 19:08:07 DEBUG : test23img: multi-thread copy: chunk 3/80 (134217728-201326592) size 64Mi starting

I do not have acess to change ssh config on the destination server. The only parameter I never saw before is this (sshd_config):

MaxStartups 30:60:120

But as far as I figured out it should not be the problem.

kapitainsky · January 17, 2024, 6:30pm

BTW have you tried the same transfer using different SFTP client? FileZilla or similar.

Also:

what sort of the system it is?

This kernel is not supported for years and ubuntu 22.04 was released with kernel v5.15. Kernel 4.4 was in use in Ubuntu 14.04... in 2016.

CharonX · January 17, 2024, 6:42pm

No. But I give it a try later. Good idea

Oh wait. I didnt mention yet I am using rclone inside of a docker container. Thats the Ubuntu 22. The kernel 4.4 ist from my host which is a Synology NAS. Unfortunately they do not offer newer Kernels.

asdffdsa · January 17, 2024, 7:10pm

fwiw, never had issues with sftp on a synbox, but never tried with rclone in docker.
so you tested rclone without docker, what was the result?

was that inside docker or what?