Files are transferred and immediatly deleted on FTP backend

What is the problem you are having with rclone?

Situation:

  • RClone mount (via fstab) that uses FTP backend with explicit TLS
  • Backend is a Synology NAS (lftp server)
  • Most files are handled exact the way that is expected

Problem:

  • Sometimes a file does not get transferred. Like I have on now that is used for further descriptions. In the attached logs you will find the following:
  • The file export-2023-02-28_backup_3.zip was created locally and is not yet transferred to ftp://192.168.2.102:21/dms_backup
  • To force some reactions the file export-2023-02-28_backup_3.zip is copied locally to export20230228backup3.zip.
  • After the transfer began there was an error (see logs below) followed by ongoing errors for every new transfer-attempt.

When I connect to the FTP backend with Filezilla in the meanwhile there is a short timeframe when both files seem to be present at the backend:

My interpretation of this obervation and the logs is that the files are really stored temporarily and then get deleted afterwards.

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

rclone v1.61.0
- os/version: debian 11.5 (64 bit)
- os/kernel: 5.15.64-1-pve (x86_64)
- os/type: linux
- os/arch: amd64
- go/version: go1.19.4
- go/linking: static
- go/tags: none

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

FTP with explicit TLS on local Synology

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

fstab mount

The rclone config contents with secrets removed.

[nas_dms]
type = ftp
host = 192.168.2.102
user = ....
pass = ...
explicit_tls = true
no_check_certificate = true

A log from the command with the -vv flag

Log when the file was freshly copied:

[...]

2023/03/03 13:21:10 DEBUG : &{export20230228backup3.zip (rw)}: >Write: written=112983, err=<nil>
2023/03/03 13:21:10 DEBUG : &{export20230228backup3.zip (rw)}: Flush: 
2023/03/03 13:21:10 DEBUG : export20230228backup3.zip(0xc000359a80): RWFileHandle.Flush
2023/03/03 13:21:10 DEBUG : &{export20230228backup3.zip (rw)}: >Flush: err=<nil>
2023/03/03 13:21:10 DEBUG : &{export20230228backup3.zip (rw)}: Release: 
2023/03/03 13:21:10 DEBUG : &{export-2023-02-28_backup_3.zip (rw)}: Flush: 
2023/03/03 13:21:10 DEBUG : export20230228backup3.zip(0xc000359a80): RWFileHandle.Release
2023/03/03 13:21:10 DEBUG : export-2023-02-28_backup_3.zip(0xc000359980): RWFileHandle.Flush
2023/03/03 13:21:10 DEBUG : export20230228backup3.zip(0xc000359a80): close: 
2023/03/03 13:21:10 DEBUG : &{export-2023-02-28_backup_3.zip (rw)}: >Flush: err=<nil>
2023/03/03 13:21:10 DEBUG : &{export-2023-02-28_backup_3.zip (rw)}: Release: 
2023/03/03 13:21:10 DEBUG : export-2023-02-28_backup_3.zip(0xc000359980): RWFileHandle.Release
2023/03/03 13:21:10 DEBUG : export-2023-02-28_backup_3.zip(0xc000359980): close: 
2023/03/03 13:21:10 DEBUG : vfs cache: looking for range={Pos:0 Size:21608791} in [{Pos:0 Size:21608791}] - present true
2023/03/03 13:21:10 DEBUG : export20230228backup3.zip: vfs cache: setting modification time to 2023-03-03 13:21:10.672726844 +0100 CET m=+16552.994441777
2023/03/03 13:21:10 INFO  : export20230228backup3.zip: vfs cache: queuing for upload in 5s
2023/03/03 13:21:10 DEBUG : export-2023-02-28_backup_3.zip: vfs cache: setting modification time to 2023-03-03 13:09:17.600887116 +0100 CET m=+15839.922602049
2023/03/03 13:21:10 INFO  : export-2023-02-28_backup_3.zip: vfs cache: queuing for upload in 5s
2023/03/03 13:21:10 DEBUG : export-2023-02-28_backup_3.zip(0xc000359980): >close: err=<nil>
2023/03/03 13:21:10 DEBUG : &{export-2023-02-28_backup_3.zip (rw)}: >Release: err=<nil>
2023/03/03 13:21:10 DEBUG : export20230228backup3.zip(0xc000359a80): >close: err=<nil>
2023/03/03 13:21:10 DEBUG : &{export20230228backup3.zip (rw)}: >Release: err=<nil>
2023/03/03 13:21:12 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item export-2023-02-28_backup.zip not removed, freed 0 bytes
2023/03/03 13:21:12 INFO  : vfs cache: cleaned: objects 1 (was 1) in use 1, to upload 1, uploading 0, total size 20.608Mi (was 20.608Mi)
2023/03/03 13:21:15 DEBUG : export-2023-02-28_backup_3.zip: vfs cache: starting upload
2023/03/03 13:21:15 DEBUG : export20230228backup3.zip: vfs cache: starting upload
2023/03/03 13:21:15 DEBUG : ftp://192.168.2.102:21/dms_backup: Connecting to FTP server
2023/03/03 13:21:15 DEBUG : ftp://192.168.2.102:21/dms_backup: dial("tcp","192.168.2.102:21")
2023/03/03 13:21:15 DEBUG : ftp://192.168.2.102:21/dms_backup: > dial: conn=*fshttp.timeoutConn, err=<nil>
2023/03/03 13:21:15 DEBUG : ftp://192.168.2.102:21/dms_backup: dial("tcp","192.168.2.102:55884")
2023/03/03 13:21:15 DEBUG : ftp://192.168.2.102:21/dms_backup: > dial: conn=*tls.Conn, err=<nil>
2023/03/03 13:21:15 DEBUG : ftp://192.168.2.102:21/dms_backup: dial("tcp","192.168.2.102:55733")
2023/03/03 13:21:15 DEBUG : ftp://192.168.2.102:21/dms_backup: > dial: conn=*tls.Conn, err=<nil>
2023/03/03 13:21:16 DEBUG : ftp://192.168.2.102:21/dms_backup: Connecting to FTP server
2023/03/03 13:21:16 DEBUG : ftp://192.168.2.102:21/dms_backup: dial("tcp","192.168.2.102:21")
2023/03/03 13:21:16 DEBUG : ftp://192.168.2.102:21/dms_backup: > dial: conn=*fshttp.timeoutConn, err=<nil>
2023/03/03 13:21:17 DEBUG : export-2023-02-28_backup_3.zip: Removed after failed upload: 1 error occurred:
2023/03/03 13:21:17 ERROR : export-2023-02-28_backup_3.zip: Failed to copy: update stor: 1 error occurred:
2023/03/03 13:21:17 ERROR : export-2023-02-28_backup_3.zip: vfs cache: failed to upload try #8, will retry in 5m0s: vfs cache: failed to transfer file from cache to remote: update stor: 1 error occurred:
2023/03/03 13:21:17 DEBUG : export20230228backup3.zip: Removed after failed upload: 1 error occurred:
2023/03/03 13:21:17 ERROR : export20230228backup3.zip: Failed to copy: update stor: 1 error occurred:
2023/03/03 13:21:17 ERROR : export20230228backup3.zip: vfs cache: failed to upload try #1, will retry in 10s: vfs cache: failed to transfer file from cache to remote: update stor: 1 error occurred:
2023/03/03 13:21:17 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item export20230228backup3.zip not removed, freed 0 bytes
2023/03/03 13:21:17 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item export20230228backup3.zip not removed, freed 0 bytes
2023/03/03 13:21:17 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item export-2023-02-28_backup.zip not removed, freed 0 bytes
2023/03/03 13:21:17 DEBUG : vfs cache RemoveNotInUse (maxAge=3600000000000, emptyOnly=false): item export-2023-02-28_backup_3.zip not removed, freed 0 bytes
2023/03/03 13:21:17 INFO  : vfs cache: cleaned: objects 4 (was 4) in use 4, to upload 4, uploading 0, total size 82.431Mi (was 82.431Mi)
2023/03/03 13:21:20 DEBUG : : Statfs: 
2023/03/03 13:21:20 DEBUG : : >Statfs: stat={Blocks:274877906944 Bfree:274877906944 Bavail:274877906944 Files:1000000000 Ffree:1000000000 Bsize:4096 Namelen:255 Frsize:4096}, err=<nil>
2023/03/03 13:21:27 DEBUG : export20230228backup3.zip: vfs cache: starting upload
2023/03/03 13:21:27 DEBUG : ftp://192.168.2.102:21/dms_backup: dial("tcp","192.168.2.102:55740")
2023/03/03 13:21:27 DEBUG : ftp://192.168.2.102:21/dms_backup: > dial: conn=*tls.Conn, err=<nil>
2023/03/03 13:21:28 DEBUG : ftp://192.168.2.102:21/dms_backup: Connecting to FTP server
2023/03/03 13:21:28 DEBUG : ftp://192.168.2.102:21/dms_backup: dial("tcp","192.168.2.102:21")
2023/03/03 13:21:28 DEBUG : ftp://192.168.2.102:21/dms_backup: > dial: conn=*fshttp.timeoutConn, err=<nil>
2023/03/03 13:21:28 DEBUG : export20230228backup3.zip: Removed after failed upload: 1 error occurred:
2023/03/03 13:21:28 ERROR : export20230228backup3.zip: Failed to copy: update stor: 1 error occurred:
2023/03/03 13:21:28 ERROR : export20230228backup3.zip: vfs cache: failed to upload try #2, will retry in 20s: vfs cache: failed to transfer file from cache to remote: update stor: 1 error occurred:
2023/03/03 13:21:48 DEBUG : export20230228backup3.zip: vfs cache: starting upload
2023/03/03 13:21:48 DEBUG : ftp://192.168.2.102:21/dms_backup: dial("tcp","192.168.2.102:55616")
2023/03/03 13:21:48 DEBUG : ftp://192.168.2.102:21/dms_backup: > dial: conn=*tls.Conn, err=<nil>
2023/03/03 13:21:49 DEBUG : ftp://192.168.2.102:21/dms_backup: Connecting to FTP server
2023/03/03 13:21:49 DEBUG : ftp://192.168.2.102:21/dms_backup: dial("tcp","192.168.2.102:21")
2023/03/03 13:21:49 DEBUG : ftp://192.168.2.102:21/dms_backup: > dial: conn=*fshttp.timeoutConn, err=<nil>
2023/03/03 13:21:49 DEBUG : export20230228backup3.zip: Removed after failed upload: 1 error occurred:
2023/03/03 13:21:49 ERROR : export20230228backup3.zip: Failed to copy: update stor: 1 error occurred:
2023/03/03 13:21:49 ERROR : export20230228backup3.zip: vfs cache: failed to upload try #3, will retry in 40s: vfs cache: failed to transfer file from cache to remote: update stor: 1 error occurred:
2023/03/03 13:21:50 DEBUG : : Statfs: 
2023/03/03 13:21:50 DEBUG : : >Statfs: stat={Blocks:274877906944 Bfree:274877906944 Bavail:274877906944 Files:1000000000 Ffree:1000000000 Bsize:4096 Namelen:255 Frsize:4096}, err=<nil>

Repeated errors after the file was copied:

2023/03/03 15:41:50 DEBUG : export-2023-02-28_backup_3.zip: vfs cache: starting upload
2023/03/03 15:41:50 DEBUG : ftp://192.168.2.102:21/dms_backup: dial("tcp","192.168.2.102:55896")
2023/03/03 15:41:50 DEBUG : ftp://192.168.2.102:21/dms_backup: > dial: conn=*tls.Conn, err=<nil>
2023/03/03 15:41:50 DEBUG : : Statfs: 
2023/03/03 15:41:50 DEBUG : : >Statfs: stat={Blocks:274877906944 Bfree:274877906944 Bavail:274877906944 Files:1000000000 Ffree:1000000000 Bsize:4096 Namelen:255 Frsize:4096}, err=<nil>
2023/03/03 15:41:51 DEBUG : ftp://192.168.2.102:21/dms_backup: Connecting to FTP server
2023/03/03 15:41:51 DEBUG : ftp://192.168.2.102:21/dms_backup: dial("tcp","192.168.2.102:21")
2023/03/03 15:41:51 DEBUG : ftp://192.168.2.102:21/dms_backup: > dial: conn=*fshttp.timeoutConn, err=<nil>
2023/03/03 15:41:51 DEBUG : export-2023-02-28_backup_3.zip: Removed after failed upload: 1 error occurred:
        * 426 Data connection: No such file or directory.

2023/03/03 15:41:51 ERROR : export-2023-02-28_backup_3.zip: Failed to copy: update stor: 1 error occurred:
        * 426 Data connection: No such file or directory.

2023/03/03 15:41:51 ERROR : export-2023-02-28_backup_3.zip: vfs cache: failed to upload try #36, will retry in 5m0s: vfs cache: failed to transfer file from cache to remote: update stor: 1 error occurred:
        * 426 Data connection: No such file or directory.

2023/03/03 15:42:05 DEBUG : export20230228backup3.zip: vfs cache: starting upload
2023/03/03 15:42:05 DEBUG : ftp://192.168.2.102:21/dms_backup: dial("tcp","192.168.2.102:55810")
2023/03/03 15:42:05 DEBUG : ftp://192.168.2.102:21/dms_backup: > dial: conn=*tls.Conn, err=<nil>
2023/03/03 15:42:06 DEBUG : ftp://192.168.2.102:21/dms_backup: Connecting to FTP server
2023/03/03 15:42:06 DEBUG : ftp://192.168.2.102:21/dms_backup: dial("tcp","192.168.2.102:21")
2023/03/03 15:42:06 DEBUG : ftp://192.168.2.102:21/dms_backup: > dial: conn=*fshttp.timeoutConn, err=<nil>
2023/03/03 15:42:06 DEBUG : export20230228backup3.zip: Removed after failed upload: 1 error occurred:
        * 426 Data connection: No such file or directory.

Rclone doesn't beleive the transfer was successful so it deleted it.

However the error message is empty which is a bit suspicious.

Can you try uploading single files with rclone copy -vv --retries 1 --dump headers file.bin nas_dms: and see whether that works and report the log if it doesn't.

hello and welcome to the forum,
off topic: on synology, i prefer sftp over ftp.
as that enables file transfer verification using md5 hash and with rclone check

1 Like

Thanks for passing by!

The following command
sudo rclone copy -vv --retries 1 --config /root/.config/rclone/rclone.conf --dump headers /mnt/paperless_ngx/backup/export20230228backup3.zip nas_dms:dms_backup

produces:

2023/03/03 16:59:14 DEBUG : rclone: Version "v1.61.0" starting with parameters ["rclone" "copy" "-vv" "--retries" "1" "--config" "/root/.config/rclone/rclone.conf" "--dump" "headers" "/mnt/<LOCAL_PATH>/backup/export20230228backup3.zip" "nas_dms:dms_backup"]
2023/03/03 16:59:14 DEBUG : Creating backend with remote "/mnt/<LOCAL_PATH>/backup/export20230228backup3.zip"
2023/03/03 16:59:14 DEBUG : Using config file from "/root/.config/rclone/rclone.conf"
2023/03/03 16:59:15 DEBUG : fs cache: adding new entry for parent of "/mnt/<LOCAL_PATH>/backup/export20230228backup3.zip", "/mnt/<LOCAL_PATH>/backup"
2023/03/03 16:59:15 DEBUG : Creating backend with remote "nas_dms:dms_backup"
2023/03/03 16:59:15 DEBUG : ftp://192.168.2.102:21/dms_backup: Connecting to FTP server
2023/03/03 16:59:15 DEBUG : ftp://192.168.2.102:21/dms_backup: dial("tcp","192.168.2.102:21")
2023/03/03 16:59:15 DEBUG : ftp://192.168.2.102:21/dms_backup: > dial: conn=*fshttp.timeoutConn, err=<nil>
2023/03/03 16:59:15 DEBUG : FTP Rx: "220 nas3 FTP server ready."
2023/03/03 16:59:15 DEBUG : FTP Tx: "AUTH TLS"
2023/03/03 16:59:15 DEBUG : FTP Rx: "234 AUTH TLS command successful."
2023/03/03 16:59:15 DEBUG : FTP Tx: "USER <USERID>"
2023/03/03 16:59:15 DEBUG : FTP Rx: "331 Password required for <USERID>."
2023/03/03 16:59:15 DEBUG : FTP Tx: PASS *****
2023/03/03 16:59:15 DEBUG : FTP Rx: "230 User <USERID> logged in."
2023/03/03 16:59:15 DEBUG : FTP Tx: "FEAT"
2023/03/03 16:59:15 DEBUG : FTP Rx: "211- Extensions supported:"
2023/03/03 16:59:15 DEBUG : FTP Rx: " AUTH TLS"
2023/03/03 16:59:15 DEBUG : FTP Rx: " PBSZ"
2023/03/03 16:59:15 DEBUG : FTP Rx: " PROT"
2023/03/03 16:59:15 DEBUG : FTP Rx: " CCC"
2023/03/03 16:59:15 DEBUG : FTP Rx: " SIZE"
2023/03/03 16:59:15 DEBUG : FTP Rx: " MDTM"
2023/03/03 16:59:15 DEBUG : FTP Rx: " REST STREAM"
2023/03/03 16:59:15 DEBUG : FTP Rx: " MFMT"
2023/03/03 16:59:15 DEBUG : FTP Rx: " TVFS"
2023/03/03 16:59:15 DEBUG : FTP Rx: " MLST modify*;type*;unique*;size*;UNIX.mode*;UNIX.owner*;UNIX.group*;"
2023/03/03 16:59:15 DEBUG : FTP Rx: " MLSD modify*;type*;unique*;size*;UNIX.mode*;UNIX.owner*;UNIX.group*;"
2023/03/03 16:59:15 DEBUG : FTP Rx: " UTF8"
2023/03/03 16:59:15 DEBUG : FTP Rx: "211 End."
2023/03/03 16:59:15 DEBUG : FTP Tx: "TYPE I"
2023/03/03 16:59:15 DEBUG : FTP Rx: "200 Type set to I."
2023/03/03 16:59:15 DEBUG : FTP Tx: "OPTS UTF8 ON"
2023/03/03 16:59:15 DEBUG : FTP Rx: "200 OK, UTF-8 enabled"
2023/03/03 16:59:15 DEBUG : FTP Tx: "PBSZ 0"
2023/03/03 16:59:15 DEBUG : FTP Rx: "200 PBSZ command successful (PBSZ=0)."
2023/03/03 16:59:15 DEBUG : FTP Tx: "PROT P"
2023/03/03 16:59:15 DEBUG : FTP Rx: "200 Protection level set to Private."
2023/03/03 16:59:15 DEBUG : FTP Tx: "MLST dms_backup"
2023/03/03 16:59:15 DEBUG : FTP Rx: "250- Start of list for dms_backup"
2023/03/03 16:59:15 DEBUG : FTP Rx: " modify=20230303155828;type=dir;unique=31U100;size=226;UNIX.mode=0777;UNIX.owner=root;UNIX.group=root; /dms_backup"
2023/03/03 16:59:15 DEBUG : FTP Rx: "250 End of list"
2023/03/03 16:59:15 DEBUG : FTP Tx: "MLST dms_backup/export20230228backup3.zip"
2023/03/03 16:59:15 DEBUG : FTP Rx: "550 dms_backup/export20230228backup3.zip can't be listed"
2023/03/03 16:59:15 DEBUG : export20230228backup3.zip: Need to transfer - File not found at Destination
2023/03/03 16:59:15 DEBUG : FTP Tx: "MLST dms_backup"
2023/03/03 16:59:15 DEBUG : FTP Rx: "250- Start of list for dms_backup"
2023/03/03 16:59:15 DEBUG : FTP Rx: " modify=20230303155828;type=dir;unique=31U100;size=226;UNIX.mode=0777;UNIX.owner=root;UNIX.group=root; /dms_backup"
2023/03/03 16:59:15 DEBUG : FTP Rx: "250 End of list"
2023/03/03 16:59:15 DEBUG : FTP Tx: "EPSV"
2023/03/03 16:59:15 DEBUG : FTP Rx: "229 Entering Extended Passive Mode (|||55838|)"
2023/03/03 16:59:15 DEBUG : ftp://192.168.2.102:21/dms_backup: dial("tcp","192.168.2.102:55838")
2023/03/03 16:59:15 DEBUG : ftp://192.168.2.102:21/dms_backup: > dial: conn=*tls.Conn, err=<nil>
2023/03/03 16:59:15 DEBUG : FTP Tx: "STOR dms_backup/export20230228backup3.zip"
2023/03/03 16:59:15 DEBUG : FTP Rx: "150 Opening BINARY mode SSL data connection for 'dms_backup/export20230228backup3.zip'."
2023/03/03 16:59:15 DEBUG : FTP Rx: "426 Data connection: No such file or directory."
2023/03/03 16:59:15 DEBUG : FTP Tx: "QUIT"
2023/03/03 16:59:16 DEBUG : ftp://192.168.2.102:21/dms_backup: Connecting to FTP server
2023/03/03 16:59:16 DEBUG : ftp://192.168.2.102:21/dms_backup: dial("tcp","192.168.2.102:21")
2023/03/03 16:59:16 DEBUG : ftp://192.168.2.102:21/dms_backup: > dial: conn=*fshttp.timeoutConn, err=<nil>
2023/03/03 16:59:16 DEBUG : FTP Rx: "220 nas3 FTP server ready."
2023/03/03 16:59:16 DEBUG : FTP Tx: "AUTH TLS"
2023/03/03 16:59:16 DEBUG : FTP Rx: "234 AUTH TLS command successful."
2023/03/03 16:59:16 DEBUG : FTP Tx: "USER <USERID>"
2023/03/03 16:59:16 DEBUG : FTP Rx: "331 Password required for <USERID>."
2023/03/03 16:59:16 DEBUG : FTP Tx: PASS *****
2023/03/03 16:59:16 DEBUG : FTP Rx: "230 User <USERID> logged in."
2023/03/03 16:59:16 DEBUG : FTP Tx: "FEAT"
2023/03/03 16:59:16 DEBUG : FTP Rx: "211- Extensions supported:"
2023/03/03 16:59:16 DEBUG : FTP Rx: " AUTH TLS"
2023/03/03 16:59:16 DEBUG : FTP Rx: " PBSZ"
2023/03/03 16:59:16 DEBUG : FTP Rx: " PROT"
2023/03/03 16:59:16 DEBUG : FTP Rx: " CCC"
2023/03/03 16:59:16 DEBUG : FTP Rx: " SIZE"
2023/03/03 16:59:16 DEBUG : FTP Rx: " MDTM"
2023/03/03 16:59:16 DEBUG : FTP Rx: " REST STREAM"
2023/03/03 16:59:16 DEBUG : FTP Rx: " MFMT"
2023/03/03 16:59:16 DEBUG : FTP Rx: " TVFS"
2023/03/03 16:59:16 DEBUG : FTP Rx: " MLST modify*;type*;unique*;size*;UNIX.mode*;UNIX.owner*;UNIX.group*;"
2023/03/03 16:59:16 DEBUG : FTP Rx: " MLSD modify*;type*;unique*;size*;UNIX.mode*;UNIX.owner*;UNIX.group*;"
2023/03/03 16:59:16 DEBUG : FTP Rx: " UTF8"
2023/03/03 16:59:16 DEBUG : FTP Rx: "211 End."
2023/03/03 16:59:16 DEBUG : FTP Tx: "TYPE I"
2023/03/03 16:59:16 DEBUG : FTP Rx: "200 Type set to I."
2023/03/03 16:59:16 DEBUG : FTP Tx: "OPTS UTF8 ON"
2023/03/03 16:59:16 DEBUG : FTP Rx: "200 OK, UTF-8 enabled"
2023/03/03 16:59:16 DEBUG : FTP Tx: "PBSZ 0"
2023/03/03 16:59:16 DEBUG : FTP Rx: "200 PBSZ command successful (PBSZ=0)."
2023/03/03 16:59:16 DEBUG : FTP Tx: "PROT P"
2023/03/03 16:59:16 DEBUG : FTP Rx: "200 Protection level set to Private."
2023/03/03 16:59:16 DEBUG : FTP Tx: "MLST dms_backup/export20230228backup3.zip"
2023/03/03 16:59:16 DEBUG : FTP Rx: "250- Start of list for dms_backup/export20230228backup3.zip"
2023/03/03 16:59:16 DEBUG : FTP Rx: " modify=20230303155915;type=file;unique=31UAED;size=19836928;UNIX.mode=0777;UNIX.owner=<USERID>;UNIX.group=users; /dms_backup/export20230228backup3.zip"
2023/03/03 16:59:16 DEBUG : FTP Rx: "250 End of list"
2023/03/03 16:59:16 DEBUG : FTP Tx: "DELE dms_backup/export20230228backup3.zip"
2023/03/03 16:59:16 DEBUG : FTP Rx: "250 DELE command successful."
2023/03/03 16:59:16 DEBUG : export20230228backup3.zip: Removed after failed upload: 1 error occurred:
        * 426 Data connection: No such file or directory.

2023/03/03 16:59:16 ERROR : export20230228backup3.zip: Failed to copy: update stor: 1 error occurred:
        * 426 Data connection: No such file or directory.

2023/03/03 16:59:16 ERROR : Attempt 1/1 failed with 1 errors and: update stor: 1 error occurred:
        * 426 Data connection: No such file or directory.

2023/03/03 16:59:16 INFO  : 
Transferred:       20.608 MiB / 20.608 MiB, 100%, 20.589 MiB/s, ETA 0s
Errors:                 1 (retrying may help)
Elapsed time:         1.3s

2023/03/03 16:59:16 DEBUG : 3 go routines active
2023/03/03 16:59:16 DEBUG : ftp://192.168.2.102:21/dms_backup: closing 1 unused connections
2023/03/03 16:59:16 DEBUG : FTP Tx: "QUIT"
2023/03/03 16:59:16 Failed to copy: update stor: 1 error occurred:
        * 426 Data connection: No such file or directory.

Hi @ncw is there anything else I can provide? The error is still present.

Thats the underlying error. There is a post about this on the synology forum with no answers: https://community.synology.com/enu/forum/17/post/102994

I've got to think it is a bug - in the server maybe or rclone.

Can you use SFTP instead? That is normally much more reliable than FTP.

hi @ncw thank you very much. I will have a look if switching to SFTP is feasable. In the past I thought that especially the limitations mentioned concerning Synology NAS systems are good reasons to avoid it. Another user asked what I also wanted to ask a while ago: "On some SFTP servers (e.g. Synology) the paths are different for SSH and SFTP so the hashes can't be calculated properly" Maybe an update there will help me to figure out if SFTP is a good choice.

I also filed an issue here (because the FTP server on Synology NAS is a SmbFTPD): twbsd.org

I am also checking if all this is also related with issues in goftp like this one here: github dot com/jlaffaye/ftp/issues/249

There is never exactly the same issue but they seem to be nearly the same :wink:

i posted that link. i was just questioning the rclone documentation.
as you can see from the debug logs i posted, that hashing works fine.

1 Like

Thanks for sharing. This is good news. Concerning the docs: While switching a test remote to SFTP I unintentionally stumbled upon another question that I asked here: Documention still correct? "Note that some SFTP servers will need the leading / - Synology is a good example of this." I forgot to set the slash in front and it seems to work.
Maybe the docs are outdated here too.

As found here and there this did the trick for me too: disable-tls13 = true

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