Hello Rclone Community!
What is the problem you are having with rclone?
I have created an Rclone FTPS (explicit mode) connection to another server.
When trying to transfer files from the source server to the destination server, the file transfer very often ends with an error message:
Failed to copy: update stor: 450 Transfer aborted. Link to file server lost
There are cases, where it works, but in most cases, the error is thrown.
Unsecured FTP transfer works like a charm.
Various other Rclone storage configs work like a charm.
What is your rclone version (output from rclone version
)
rclone v1.55.1
- os/type: linux
- os/arch: amd64
- go/version: go1.16.3
- go/linking: static
- go/tags: none
I have also tested the latest Beta (v1.56.0-beta.5531.41f561bf2), but without success.
Which OS you are using and how many bits (eg Windows 7, 64 bit)
Ubuntu 18.04 - 64 bit
Which cloud storage system are you using? (eg Google Drive)
FTPS in explicit mode.
The command you were trying to run (eg rclone copy /tmp remote:tmp
)
rclone --retries 1 -vv copy /home/users/alex/www/godot-3.3.1-stable.zip rclone-storage:/files/alex/www
The rclone config contents with secrets removed.
I have tried with "no_check_certificate = false" and "no_check_certificate = true". But the results remains the same.
[rclone-storage]
type = ftp
host = dev14.keymachine.de
user = backup_test
pass = <secret_password>
explicit_tls = true
no_check_certificate = false
[rclone-storage]
type = ftp
host = dev14.keymachine.de
user = backup_test
pass = <secret_password>
explicit_tls = true
no_check_certificate = true
A log from the command with the -vv
flag
2021/06/07 16:33:25 DEBUG : Using config file from "/root/.config/rclone/rclone.conf"
2021/06/07 16:33:25 DEBUG : rclone: Version "v1.55.1" starting with parameters ["rclone" "--retries" "1" "-vv" "copy" "/home/users/alex/www/godot-3.3.1-stable.zip" "rclone-storage:/files/alex/www"]
2021/06/07 16:33:25 DEBUG : Creating backend with remote "/home/users/alex/www/godot-3.3.1-stable.zip"
2021/06/07 16:33:25 DEBUG : fs cache: adding new entry for parent of "/home/users/alex/www/godot-3.3.1-stable.zip", "/home/users/alex/www"
2021/06/07 16:33:25 DEBUG : Creating backend with remote "rclone-storage:/files/alex/www"
2021/06/07 16:33:25 DEBUG : ftp://dev14.keymachine.de:21/files/alex/www: Connecting to FTP server
2021/06/07 16:33:25 DEBUG : godot-3.3.1-stable.zip: Need to transfer - File not found at Destination
2021/06/07 16:33:27 DEBUG : ftp://dev14.keymachine.de:21/files/alex/www: Connecting to FTP server
2021/06/07 16:33:27 DEBUG : godot-3.3.1-stable.zip: Removed after failed upload: 450 Transfer aborted. Link to file server lost
2021/06/07 16:33:27 ERROR : godot-3.3.1-stable.zip: Failed to copy: update stor: 450 Transfer aborted. Link to file server lost
2021/06/07 16:33:27 ERROR : Attempt 1/1 failed with 1 errors and: update stor: 450 Transfer aborted. Link to file server lost
2021/06/07 16:33:27 INFO :
Transferred: 33.692M / 33.692 MBytes, 100%, 15.539 MBytes/s, ETA 0s
Errors: 1 (retrying may help)
Elapsed time: 2.5s
2021/06/07 16:33:27 DEBUG : 2 go routines active
2021/06/07 16:33:27 Failed to copy: update stor: 450 Transfer aborted. Link to file server lost
A log from the command with the --dump bodies -vv
flag
2021/06/07 16:20:18 DEBUG : Using config file from "/root/.config/rclone/rclone.conf"
2021/06/07 16:20:18 DEBUG : rclone: Version "v1.55.1" starting with parameters ["rclone" "--dump" "bodies" "--retries" "1" "-vv" "copy" "/home/users/alex/www/godot-3.3.1-stable.zip" "rclone-storage:/files/alex/www"]
2021/06/07 16:20:18 DEBUG : Creating backend with remote "/home/users/alex/www/godot-3.3.1-stable.zip"
2021/06/07 16:20:18 DEBUG : fs cache: adding new entry for parent of "/home/users/alex/www/godot-3.3.1-stable.zip", "/home/users/alex/www"
2021/06/07 16:20:18 DEBUG : Creating backend with remote "rclone-storage:/files/alex/www"
2021/06/07 16:20:18 DEBUG : ftp://dev14.keymachine.de:21/files/alex/www: Connecting to FTP server
2021/06/07 16:20:18 DEBUG : FTP Rx: "220 ProFTPD Server (dev14.keymachine.de FTP-Server) [::ffff:62.141.57.77]"
2021/06/07 16:20:18 DEBUG : FTP Tx: "AUTH TLS"
2021/06/07 16:20:18 DEBUG : FTP Rx: "234 AUTH TLS successful"
2021/06/07 16:20:18 DEBUG : FTP Tx: "USER backup_test"
2021/06/07 16:20:18 DEBUG : FTP Rx: "331 Password required for backup_test"
2021/06/07 16:20:18 DEBUG : FTP Tx: PASS *****
2021/06/07 16:20:18 DEBUG : FTP Rx: "230 User backup_test logged in"
2021/06/07 16:20:18 DEBUG : FTP Tx: "FEAT"
2021/06/07 16:20:18 DEBUG : FTP Rx: "211-Features:"
2021/06/07 16:20:18 DEBUG : FTP Rx: "211-AUTH TLS"
2021/06/07 16:20:18 DEBUG : FTP Rx: "211-CCC"
2021/06/07 16:20:18 DEBUG : FTP Rx: "211-CLNT"
2021/06/07 16:20:18 DEBUG : FTP Rx: "211-EPRT"
2021/06/07 16:20:18 DEBUG : FTP Rx: "211-EPSV"
2021/06/07 16:20:18 DEBUG : FTP Rx: "211-HOST"
2021/06/07 16:20:18 DEBUG : FTP Rx: "211-LANG en-US.UTF-8;en-US"
2021/06/07 16:20:18 DEBUG : FTP Rx: "211-MDTM"
2021/06/07 16:20:18 DEBUG : FTP Rx: "211-MFF modify;UNIX.group;UNIX.mode;"
2021/06/07 16:20:18 DEBUG : FTP Rx: "211-MFMT"
2021/06/07 16:20:18 DEBUG : FTP Rx: "211-MLST modify*;perm*;size*;type*;unique*;UNIX.group*;UNIX.groupname*;UNIX.mode*;UNIX.owner*;UNIX.ownername*;"
2021/06/07 16:20:18 DEBUG : FTP Rx: "211-PBSZ"
2021/06/07 16:20:18 DEBUG : FTP Rx: "211-PROT"
2021/06/07 16:20:18 DEBUG : FTP Rx: "211-REST STREAM"
2021/06/07 16:20:18 DEBUG : FTP Rx: "211-SITE MKDIR"
2021/06/07 16:20:18 DEBUG : FTP Rx: "211-SITE RMDIR"
2021/06/07 16:20:18 DEBUG : FTP Rx: "211-SITE SYMLINK"
2021/06/07 16:20:18 DEBUG : FTP Rx: "211-SITE UTIME"
2021/06/07 16:20:18 DEBUG : FTP Rx: "211-SIZE"
2021/06/07 16:20:18 DEBUG : FTP Rx: "211-SSCN"
2021/06/07 16:20:18 DEBUG : FTP Rx: "211-TVFS"
2021/06/07 16:20:18 DEBUG : FTP Rx: "211-UTF8"
2021/06/07 16:20:18 DEBUG : FTP Rx: "211 End"
2021/06/07 16:20:18 DEBUG : FTP Tx: "TYPE I"
2021/06/07 16:20:18 DEBUG : FTP Rx: "200 Type set to I"
2021/06/07 16:20:18 DEBUG : FTP Tx: "PBSZ 0"
2021/06/07 16:20:18 DEBUG : FTP Rx: "200 PBSZ 0 successful"
2021/06/07 16:20:18 DEBUG : FTP Tx: "PROT P"
2021/06/07 16:20:18 DEBUG : FTP Rx: "200 Protection set to Private"
2021/06/07 16:20:18 DEBUG : FTP Tx: "EPSV"
2021/06/07 16:20:18 DEBUG : FTP Rx: "229 Entering Extended Passive Mode (|||30019|)"
2021/06/07 16:20:18 DEBUG : FTP Tx: "LIST /files/alex"
2021/06/07 16:20:18 DEBUG : FTP Rx: "150 Opening BINARY mode data connection for file list"
2021/06/07 16:20:18 DEBUG : FTP Rx: "226 Transfer complete"
2021/06/07 16:20:18 DEBUG : FTP Tx: "EPSV"
2021/06/07 16:20:18 DEBUG : FTP Rx: "229 Entering Extended Passive Mode (|||30118|)"
2021/06/07 16:20:18 DEBUG : FTP Tx: "LIST /files/alex/www"
2021/06/07 16:20:18 DEBUG : FTP Rx: "150 Opening BINARY mode data connection for file list"
2021/06/07 16:20:18 DEBUG : FTP Rx: "226 Transfer complete"
2021/06/07 16:20:18 DEBUG : godot-3.3.1-stable.zip: Need to transfer - File not found at Destination
2021/06/07 16:20:18 DEBUG : FTP Tx: "EPSV"
2021/06/07 16:20:18 DEBUG : FTP Rx: "229 Entering Extended Passive Mode (|||30283|)"
2021/06/07 16:20:18 DEBUG : FTP Tx: "LIST /files/alex"
2021/06/07 16:20:18 DEBUG : FTP Rx: "150 Opening BINARY mode data connection for file list"
2021/06/07 16:20:18 DEBUG : FTP Rx: "226 Transfer complete"
2021/06/07 16:20:18 DEBUG : FTP Tx: "EPSV"
2021/06/07 16:20:18 DEBUG : FTP Rx: "229 Entering Extended Passive Mode (|||30372|)"
2021/06/07 16:20:18 DEBUG : FTP Tx: "STOR /files/alex/www/godot-3.3.1-stable.zip"
2021/06/07 16:20:18 DEBUG : FTP Rx: "150 Opening BINARY mode data connection for /files/alex/www/godot-3.3.1-stable.zip"
2021/06/07 16:20:19 DEBUG : FTP Rx: "450 Transfer aborted. Link to file server lost"
2021/06/07 16:20:19 DEBUG : FTP Tx: "QUIT"
2021/06/07 16:20:20 DEBUG : ftp://dev14.keymachine.de:21/files/alex/www: Connecting to FTP server
2021/06/07 16:20:20 DEBUG : FTP Rx: "220 ProFTPD Server (dev14.keymachine.de FTP-Server) [::ffff:62.141.57.77]"
2021/06/07 16:20:20 DEBUG : FTP Tx: "AUTH TLS"
2021/06/07 16:20:20 DEBUG : FTP Rx: "234 AUTH TLS successful"
2021/06/07 16:20:20 DEBUG : FTP Tx: "USER backup_test"
2021/06/07 16:20:20 DEBUG : FTP Rx: "331 Password required for backup_test"
2021/06/07 16:20:20 DEBUG : FTP Tx: PASS *****
2021/06/07 16:20:20 DEBUG : FTP Rx: "230 User backup_test logged in"
2021/06/07 16:20:20 DEBUG : FTP Tx: "FEAT"
2021/06/07 16:20:20 DEBUG : FTP Rx: "211-Features:"
2021/06/07 16:20:20 DEBUG : FTP Rx: "211-AUTH TLS"
2021/06/07 16:20:20 DEBUG : FTP Rx: "211-CCC"
2021/06/07 16:20:20 DEBUG : FTP Rx: "211-CLNT"
2021/06/07 16:20:20 DEBUG : FTP Rx: "211-EPRT"
2021/06/07 16:20:20 DEBUG : FTP Rx: "211-EPSV"
2021/06/07 16:20:20 DEBUG : FTP Rx: "211-HOST"
2021/06/07 16:20:20 DEBUG : FTP Rx: "211-LANG en-US.UTF-8;en-US"
2021/06/07 16:20:20 DEBUG : FTP Rx: "211-MDTM"
2021/06/07 16:20:20 DEBUG : FTP Rx: "211-MFF modify;UNIX.group;UNIX.mode;"
2021/06/07 16:20:20 DEBUG : FTP Rx: "211-MFMT"
2021/06/07 16:20:20 DEBUG : FTP Rx: "211-MLST modify*;perm*;size*;type*;unique*;UNIX.group*;UNIX.groupname*;UNIX.mode*;UNIX.owner*;UNIX.ownername*;"
2021/06/07 16:20:20 DEBUG : FTP Rx: "211-PBSZ"
2021/06/07 16:20:20 DEBUG : FTP Rx: "211-PROT"
2021/06/07 16:20:20 DEBUG : FTP Rx: "211-REST STREAM"
2021/06/07 16:20:20 DEBUG : FTP Rx: "211-SITE MKDIR"
2021/06/07 16:20:20 DEBUG : FTP Rx: "211-SITE RMDIR"
2021/06/07 16:20:20 DEBUG : FTP Rx: "211-SITE SYMLINK"
2021/06/07 16:20:20 DEBUG : FTP Rx: "211-SITE UTIME"
2021/06/07 16:20:20 DEBUG : FTP Rx: "211-SIZE"
2021/06/07 16:20:20 DEBUG : FTP Rx: "211-SSCN"
2021/06/07 16:20:20 DEBUG : FTP Rx: "211-TVFS"
2021/06/07 16:20:20 DEBUG : FTP Rx: "211-UTF8"
2021/06/07 16:20:20 DEBUG : FTP Rx: "211 End"
2021/06/07 16:20:20 DEBUG : FTP Tx: "TYPE I"
2021/06/07 16:20:20 DEBUG : FTP Rx: "200 Type set to I"
2021/06/07 16:20:20 DEBUG : FTP Tx: "PBSZ 0"
2021/06/07 16:20:20 DEBUG : FTP Rx: "200 PBSZ 0 successful"
2021/06/07 16:20:20 DEBUG : FTP Tx: "PROT P"
2021/06/07 16:20:20 DEBUG : FTP Rx: "200 Protection set to Private"
2021/06/07 16:20:20 DEBUG : FTP Tx: "EPSV"
2021/06/07 16:20:20 DEBUG : FTP Rx: "229 Entering Extended Passive Mode (|||30265|)"
2021/06/07 16:20:20 DEBUG : FTP Tx: "LIST /files/alex/www"
2021/06/07 16:20:20 DEBUG : FTP Rx: "150 Opening BINARY mode data connection for file list"
2021/06/07 16:20:20 DEBUG : FTP Rx: "226 Transfer complete"
2021/06/07 16:20:20 DEBUG : FTP Tx: "DELE /files/alex/www/godot-3.3.1-stable.zip"
2021/06/07 16:20:20 DEBUG : FTP Rx: "250 DELE command successful"
2021/06/07 16:20:20 DEBUG : godot-3.3.1-stable.zip: Removed after failed upload: 450 Transfer aborted. Link to file server lost
2021/06/07 16:20:20 ERROR : godot-3.3.1-stable.zip: Failed to copy: update stor: 450 Transfer aborted. Link to file server lost
2021/06/07 16:20:20 ERROR : Attempt 1/1 failed with 1 errors and: update stor: 450 Transfer aborted. Link to file server lost
2021/06/07 16:20:20 INFO :
Transferred: 33.692M / 33.692 MBytes, 100%, 16.092 MBytes/s, ETA 0s
Errors: 1 (retrying may help)
Elapsed time: 2.4s
2021/06/07 16:20:20 DEBUG : 2 go routines active
2021/06/07 16:20:20 Failed to copy: update stor: 450 Transfer aborted. Link to file server lost
Remote servers
On the remote side, I'm using ProFTPD. I tested 3 different operating systems with each an other version of ProFTPD.
- an Ubuntu 20 - ProFTPD Version 1.3.6c
- an Ubuntu 18 - ProFTPD Version 1.3.5e
- a Debian 10 - ProFTPD Version 1.3.6
The error remains the same.
All servers have a valid Let's Encrypt certificate which is used also to protect the ProFTPD server.
FTP on these servers is running fine, besides when using Rclone + FTPS in explicit mode.
ProFTPD Log output of a remote server | Ubuntu 20.04 - ProFTPD 1.3.6e
/var/log/proftpd/tls.log
2021-06-07 14:07:55,733 mod_tls/2.7[2741251]: TLS/TLS-C requested, starting TLS handshake
2021-06-07 14:07:55,800 mod_tls/2.7[2741251]: TLSv1.3 connection accepted, using cipher TLS_CHACHA20_POLY1305_SHA256 (256 bits)
2021-06-07 14:07:55,990 mod_tls/2.7[2741251]: Protection set to Private
2021-06-07 14:07:55,994 mod_tls/2.7[2741251]: starting TLS negotiation on data connection
2021-06-07 14:07:56,009 mod_tls/2.7[2741251]: TLSv1.3 data connection accepted, using cipher TLS_CHACHA20_POLY1305_SHA256 (256 bits)
2021-06-07 14:07:56,013 mod_tls/2.7[2741251]: starting TLS negotiation on data connection
2021-06-07 14:07:56,031 mod_tls/2.7[2741251]: starting TLS negotiation on data connection
2021-06-07 14:07:56,050 mod_tls/2.7[2741251]: starting TLS negotiation on data connection
2021-06-07 14:07:57,726 mod_tls/2.7[2741252]: TLS/TLS-C requested, starting TLS handshake
2021-06-07 14:07:57,743 mod_tls/2.7[2741252]: TLSv1.3 connection accepted, using cipher TLS_CHACHA20_POLY1305_SHA256 (256 bits)
2021-06-07 14:07:57,926 mod_tls/2.7[2741252]: Protection set to Private
2021-06-07 14:07:57,928 mod_tls/2.7[2741252]: starting TLS negotiation on data connection
2021-06-07 14:07:57,942 mod_tls/2.7[2741252]: TLSv1.3 data connection accepted, using cipher TLS_CHACHA20_POLY1305_SHA256 (256 bits)
/var/log/proftpd/proftpd.log
2021-06-07 14:07:56,707 dev14.keymachine.de proftpd[2741251] dev14.keymachine.de (ns2.dev01.keymachine.de[62.141.57.104]): notice: user backup_test: aborting transfer: Link to file server lost
/var/log/proftpd/xferlog
Mon Jun 07 14:07:56 2021 0 ns2.dev01.keymachine.de 34844672 /home/users/backup_test/files/alex/www/godot-3.3.1-stable.zip b _ i r backup_test ftps 0 * i
Mon Jun 07 14:07:57 2021 0 ns2.dev01.keymachine.de 34844672 /home/users/backup_test/files/alex/www/godot-3.3.1-stable.zip b _ d r backup_test ftps 0 * c
Further note
EDIT: I have found this Rclone copy to FTP: rclone sends a QUIT and never ends itself - #12 by ivandeex, at least I am not alone with this issue ;).
Thank you very much for your help!
Alex