Connection Speed Drop with rclone copy after *exactly* 2 Minutes

Help and Support
1

What is the problem you are having with rclone?

Hi rclone community,

I've been encountering an issue with rclone that I'm hoping someone can shed some light on.
I'm attempting to copy data from my VPS to a Hetzner Storage Box but after exactly 2 minutes of copying, the connection speed drops to almost 0kbps, following a period of uploading at the maximum speed from the server

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: 5.15.0-25-generic (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)

Hetzner Storage Box

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

rclone copy -P /media storagebox:/media

Attempted Parameters (in various combinations):

  • --transfers 1-10
  • --checkers 1-10
  • --tpslimit 1-10
  • --buffer-size 64M
  • --sftp-concurrency 1-10
  • --bwlimit 10M

Observations:

  • The VPS, which doesn't exhibit such issues during other uploads/downloads, maintains full speed for the initial 120 seconds
  • After canceling the copy operation, the SSH terminal freezes after a few seconds. This behavior is unique to this rclone operation and doesn't happen with other SSH sessions

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

[storagebox]
type = sftp
host = XXX
user = XXX
pass = XXX
md5sum_command = none
sha1sum_command = none
shell_type = unix

[storagebox_encrypted]
type = crypt
password = XXX
remote = storagebox:/

A log from the command that you were trying to run with the -vv flag

server@vmd12345:~$ rclone copy -vv /media storagebox:/media
2024/01/22 17:18:23 DEBUG : rclone: Version "v1.65.1" starting with parameters ["rclone" "copy" "-vv" "/media" "storagebox:/media"]
2024/01/22 17:18:23 DEBUG : Creating backend with remote "/media"
2024/01/22 17:18:23 DEBUG : Using config file from "/home/server/.config/rclone/rclone.conf"
2024/01/22 17:18:23 DEBUG : fs cache: renaming cache item "/media" to be canonical "/media"
2024/01/22 17:18:23 DEBUG : Creating backend with remote "storagebox:/media"
2024/01/22 17:18:23 DEBUG : sftp://u123456@u123456.your-storagebox.de:22//media: New connection 1.2.3.4:37084->5.6.7.8:22 to "SSH-2.0-mod_sftp"
2024/01/22 17:18:23 DEBUG : sftp://u123456@u123456.your-storagebox.de:22//media: Shell type "unix" from config
2024/01/22 17:18:23 DEBUG : sftp://u123456@u123456.your-storagebox.de:22//media: Using root directory "/media"

... A lot of  "<media names> ... Need to transfer - File not found at Destination" ...

2024/01/22 17:18:23 DEBUG : sftp://u123456@u123456.your-storagebox.de:22//media: Waiting for checks to finish
2024/01/22 17:18:23 DEBUG : sftp://u123456@u123456.your-storagebox.de:22//media: Waiting for transfers to finish
2024/01/22 17:18:23 DEBUG : sftp://u123456@u123456.your-storagebox.de:22//media: New connection 1.2.3.4:37086->5.6.7.8:22 to "SSH-2.0-mod_sftp"
2024/01/22 17:18:23 DEBUG : sftp://u123456@u123456.your-storagebox.de:22//media: New connection 1.2.3.4:37088->5.6.7.8:22 to "SSH-2.0-mod_sftp"
2024/01/22 17:18:23 DEBUG : sftp://u123456@u123456.your-storagebox.de:22//media: New connection 1.2.3.4:37090->5.6.7.8:22 to "SSH-2.0-mod_sftp"
2024/01/22 17:18:46 DEBUG : xxxxx.mp4.ruqutak5.partial: renamed to: xxxxx.mp4
2024/01/22 17:18:46 INFO  : xxxxx.mp4: Copied (new)
2024/01/22 17:18:46 DEBUG : xxxxx.mp4.segelaj8.partial: renamed to: xxxxx.mp4
2024/01/22 17:18:46 INFO  : xxxxx.mp4: Copied (new)
2024/01/22 17:18:46 DEBUG : xxxxx.mp4.musivix9.partial: renamed to: xxxxx.mp4
2024/01/22 17:18:46 INFO  : xxxxx.mp4: Copied (new)
2024/01/22 17:18:51 DEBUG : xxxxx.mkv.qebijij5.partial: renamed to: xxxxx.mkv
2024/01/22 17:18:51 INFO  : xxxxx.mkv: Copied (new)
2024/01/22 17:19:09 DEBUG : xxxxx.mp4.dejijuy1.partial: renamed to: xxxxx.mp4
2024/01/22 17:19:09 INFO  : xxxxx.mp4: Copied (new)
2024/01/22 17:19:14 DEBUG : xxxxx.mkv.yuhucec1.partial: renamed to: xxxxx.mkv
2024/01/22 17:19:14 INFO  : xxxxx.mkv: Copied (new)
2024/01/22 17:19:23 INFO  :
Transferred:   	    5.922 GiB / 252.835 GiB, 2%, 100.977 MiB/s, ETA 41m43s
Transferred:            6 / 232, 3%
Elapsed time:       1m0.1s
Transferring:
 * xxxxx.mkv: 77% /1.211Gi, 26.081Mi/s, 10s
 * xxxxx.mkv: 96% /806.087Mi, 24.433Mi/s, 1s
 * xxxxx.mkv: 28% /1.193Gi, 25.374Mi/s, 34s
 * xxxxx.mkv: 17% /1.204Gi, 25.154Mi/s, 40s

2024/01/22 17:19:24 DEBUG : xxxxx.mkv.ciweruv5.partial: renamed to: xxxxx.mkv
2024/01/22 17:19:24 INFO  : xxxxx.mkv: Copied (new)
2024/01/22 17:19:34 DEBUG : xxxxx.mkv.donasuq0.partial: renamed to: xxxxx.mkv
2024/01/22 17:19:34 INFO  : xxxxx.mkv: Copied (new)
2024/01/22 17:19:57 DEBUG : xxxxx.mkv.bupamey2.partial: renamed to: xxxxx.mkv
2024/01/22 17:19:57 INFO  : xxxxx.mkv: Copied (new)
2024/01/22 17:20:03 DEBUG : xxxxx.mkv.qiyiyur1.partial: renamed to: xxxxx.mkv
2024/01/22 17:20:03 INFO  : xxxxx.mkv: Copied (new)
2024/01/22 17:20:13 DEBUG : xxxxx.yuzopuc3.partial: renamed to: xxxxx
2024/01/22 17:20:13 INFO  : xxxxx: Copied (new)
2024/01/22 17:20:22 DEBUG : xxxxx.mkv.jirugun3.partial: renamed to: xxxxx.mkv
2024/01/22 17:20:22 INFO  : xxxxx.mkv: Copied (new)
2024/01/22 17:20:23 INFO  :
Transferred:   	   11.900 GiB / 252.835 GiB, 5%, 101.799 MiB/s, ETA 40m23s
Transferred:           12 / 232, 5%
Elapsed time:       2m0.1s
Transferring:
 * xxxxx.mkv: 91% /724.603Mi, 25.710Mi/s, 2s
 * xxxxx.mkv: 41% /1.204Gi, 25.373Mi/s, 28s
 * xxxxx.mkv: 36% /676.477Mi, 24.243Mi/s, 17s
 * xxxxx.mkv:  2% /710.431Mi, 0/s, -

2024/01/22 17:21:22 DEBUG : sftp://u123456@u123456.your-storagebox.de:22//media: Not closing 0 unused connections as 4 sessions active
2024/01/22 17:21:23 INFO  :
Transferred:   	   12.013 GiB / 252.835 GiB, 5%, 2.460 MiB/s, ETA 1d3h50m
Transferred:           12 / 232, 5%
Elapsed time:       3m0.1s
Transferring:
 * xxxxx.mkv: 95% /724.603Mi, 597.900Ki/s, 52s
 * xxxxx.mkv: 43% /1.204Gi, 604.333Ki/s, 19m30s
 * xxxxx.mkv: 40% /676.477Mi, 547.122Ki/s, 12m29s
 * xxxxx.mkv:  6% /710.431Mi, 192.546Ki/s, 58m35s

2024/01/22 17:22:22 DEBUG : sftp://u123456@u123456.your-storagebox.de:22//media: Not closing 0 unused connections as 4 sessions active
2024/01/22 17:22:23 INFO  :
Transferred:   	   12.015 GiB / 252.835 GiB, 5%, 98.720 KiB/s, ETA 4w1d14h
Transferred:           12 / 232, 5%
Elapsed time:       4m0.1s
Transferring:
 * xxxxx.mkv: 95% /724.603Mi, 23.801Ki/s, 21m40s
 * xxxxx.mkv: 44% /1.204Gi, 24.280Ki/s, 8h5m5s
 * xxxxx.mkv: 40% /676.477Mi, 19.339Ki/s, 5h52m57s
 * xxxxx.mkv:  7% /710.431Mi, 18.950Ki/s, 9h54m35s


### here I aborted the process with ^C ###


^C2024/01/22 17:22:50 INFO  : Signal received: interrupt
2024/01/22 17:22:51 DEBUG : sftp://u123456@u123456.your-storagebox.de:22//media: New connection 1.2.3.4:37092->5.6.7.8:22 to "SSH-2.0-mod_sftp"
2024/01/22 17:22:51 INFO  : xxxxx.mkv.vowirel3.partial: Removing failed copy
2024/01/22 17:22:51 INFO  : xxxxx.mkv.fukuhuk7.partial: Removing failed copy
2024/01/22 17:22:51 INFO  : xxxxx.mkv.teherih5.partial: Removing failed copy
2024/01/22 17:22:51 INFO  : xxxxx.mkv.bayapid9.partial: Removing failed copy
2024/01/22 17:22:51 INFO  : Exiting...

If anyone has experienced a similar issue or has any insights into what might be causing this behavior, I would greatly appreciate your help!

2

welcome to the forum,

i use hetzner storage box, running rclone on a cheap hetzner vm.
you did not mention where the VPS is hosted at?

should use port 23, not port 22.
rclone can verify file transfers using checksums.

this is what my config looks like

[remote]
type = sftp
host = redaced your-storagebox.de
port = 23
key_file = C:\data\c\combined\hetzner\keys\id_ed25519
user = redacted
shell_type = unix
md5sum_command = md5 -r
sha1sum_command = sha1 -r

fwiw, might try webdav

[remote]
type = webdav
vendor = other
url = https://redacted-sub2.your-storagebox.de
user = redacted
pass = redacted
3

Using port 23 fixed the problem! Thank you.
Unfortunately if I now mount the remote, I don't have access to the mount directory anymore, even as root.

server@vmd12345:~$ rclone -vv mount --config=/home/server/.config/rclone/rclone.conf storagebox_encrypted: /mnt/storagebox/ --allow-other --poll-interval 10m --cache-db-purge
2024/01/23 09:56:15 DEBUG : rclone: Version "v1.65.1" starting with parameters ["rclone" "-vv" "mount" "--config=/home/server/.config/rclone/rclone.conf" "storagebox_encrypted:" "/mnt/storagebox/" "--allow-other" "--poll-interval" "10m" "--cache-db-purge"]
2024/01/23 09:56:15 DEBUG : Creating backend with remote "storagebox_encrypted:"
2024/01/23 09:56:15 DEBUG : Using config file from "/home/server/.config/rclone/rclone.conf"
2024/01/23 09:56:15 DEBUG : Creating backend with remote "storagebox:/"
2024/01/23 09:56:16 DEBUG : sftp://u123456@u123456.your-storagebox.de:23//: New connection 1.2.3.4:36988->5.6.7.8 to "SSH-2.0-OpenSSH_9.3 FreeBSD-20230719"
2024/01/23 09:56:16 DEBUG : sftp://u123456@u123456.your-storagebox.de:23//: Shell type "unix" from config
2024/01/23 09:56:16 DEBUG : sftp://u123456@u123456.your-storagebox.de:23//: Using root directory "/"
2024/01/23 09:56:16 INFO  : Encrypted drive 'storagebox_encrypted:': poll-interval is not supported by this remote
2024/01/23 09:56:16 DEBUG : Encrypted drive 'storagebox_encrypted:': Mounting on "/mnt/storagebox/"
2024/01/23 09:56:16 DEBUG : : Root:
2024/01/23 09:56:16 DEBUG : : >Root: node=/, err=<nil>
2024/01/23 09:56:20 DEBUG : /: Attr:
2024/01/23 09:56:20 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2024/01/23 09:56:20 DEBUG : /: ReadDirAll:
2024/01/23 09:56:20 DEBUG : sftp://u123456@u123456.your-storagebox.de:23//: Connection OK after error: permission denied
2024/01/23 09:56:20 DEBUG : : Dir.ReadDirAll error: error listing "": permission denied
2024/01/23 09:56:20 DEBUG : /: >ReadDirAll: item=-1, err=operation not permitted
2024/01/23 09:56:28 DEBUG : /: Attr:
2024/01/23 09:56:28 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>

root@vmd12345:/mnt# ls storagebox/
ls: reading directory 'storagebox/': Operation not permitted
4

I got it working, the problem was I tried to access the root directory with the trailing /, so I just removed it and now its working fine.

5

This topic was automatically closed 30 days after the last reply. New replies are no longer allowed.