Rclone FTPS (Explicit) + rclone touch / empty files + ProFTPD => Unable to build data connection: Operation not permitted

icom · February 26, 2021, 2:52pm

Hello Rclone Community!

What is the problem you are having with rclone?

I have created an Rclone FTPS connection to another server, but I cannot use the "rclone touch" command, nor can I upload an empty file (with copy, copyto, move, moveto).
However, coping files with content works. Also using a plain FTP (without explicit_tls) connection works too.

I receive the error: "Unable to build data connection: Operation not permitted"

What is your rclone version (output from `rclone version`)

rclone v1.54.0

os/arch: linux/amd64
go version: go1.15.7

Which OS you are using and how many bits?

Ubuntu 18.04 (64-bit)

Which cloud storage system are you using?

FTP

The command you were trying to run?

rclone touch my-ftp-dev13:files/my-test-files/test --retries 1 -vv

rclone copyto empty-file my-ftp-dev13:files/my-test-files/empty-file --retries 1 -vv

The rclone config contents with secrets removed.

[my-ftp-dev13]
type = ftp
host = dev13.keymachine.de
port = 21
user = test
pass = <secret_password>
explicit_tls = true

A log from the command with the `-vv` flag

Using the touch command:

2021/02/26 15:29:12 DEBUG : rclone: Version "v1.54.0" starting with parameters ["rclone" "touch" "my-ftp-dev13:files/my-test-files/test" "--retries" "1" "-vv"]
2021/02/26 15:29:12 DEBUG : Creating backend with remote "my-ftp-dev13:files/my-test-files/"
2021/02/26 15:29:12 DEBUG : Using config file from "/root/.config/rclone/rclone.conf"
2021/02/26 15:29:12 DEBUG : ftp://dev13.keymachine.de:21/files/my-test-files: Connecting to FTP server
2021/02/26 15:29:13 DEBUG : ftp://dev13.keymachine.de:21/files/my-test-files: Connecting to FTP server
2021/02/26 15:29:14 DEBUG : test: Removed after failed upload: 425 Unable to build data connection: Operation not permitted
2021/02/26 15:29:14 ERROR : Attempt 1/1 failed with 1 errors and: update stor: 425 Unable to build data connection: Operation not permitted
2021/02/26 15:29:14 DEBUG : 2 go routines active
2021/02/26 15:29:14 Failed to touch: update stor: 425 Unable to build data connection: Operation not permitted

Using the copyto command:

2021/02/26 15:51:28 DEBUG : rclone: Version "v1.54.0" starting with parameters ["rclone" "copyto" "empty-file" "my-ftp-dev13:files/my-test-files/empty-file" "--retries" "1" "-vv"]
2021/02/26 15:51:28 DEBUG : Creating backend with remote "empty-file"
2021/02/26 15:51:28 DEBUG : Using config file from "/root/.config/rclone/rclone.conf"
2021/02/26 15:51:28 DEBUG : fs cache: adding new entry for parent of "empty-file", "/root"
2021/02/26 15:51:28 DEBUG : Creating backend with remote "my-ftp-dev13:files/my-test-files/"
2021/02/26 15:51:28 DEBUG : ftp://dev13.keymachine.de:21/files/my-test-files: Connecting to FTP server
2021/02/26 15:51:28 DEBUG : empty-file: Need to transfer - File not found at Destination
2021/02/26 15:51:29 DEBUG : ftp://dev13.keymachine.de:21/files/my-test-files: Connecting to FTP server
2021/02/26 15:51:29 DEBUG : empty-file: Removed after failed upload: 425 Unable to build data connection: Operation not permitted
2021/02/26 15:51:29 ERROR : empty-file: Failed to copy: update stor: 425 Unable to build data connection: Operation not permitted
2021/02/26 15:51:29 ERROR : Attempt 1/1 failed with 1 errors and: update stor: 425 Unable to build data connection: Operation not permitted
2021/02/26 15:51:29 INFO  : 
Transferred:   	         0 / 0 Bytes, -, 0 Bytes/s, ETA -
Errors:                 1 (retrying may help)
Elapsed time:         1.2s

2021/02/26 15:51:29 DEBUG : 3 go routines active
2021/02/26 15:51:29 Failed to copyto: update stor: 425 Unable to build data connection: Operation not permitted

##############################################################

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

I have also tested letting the server connect with itself and various other things, but the errors above remains always the same

Here are the log outputs of /var/log/proftpd/tls.log, each containing a line, where they complain about an TLS issue (unable to accept TLS connection).

Log output of /var/log/proftpd/tls.log (Ubuntu 18.04 - proFTPD 1.3.5e)

2021-02-26 15:29:12,787 mod_tls/2.6[18013]: TLS/TLS-C requested, starting TLS handshake
2021-02-26 15:29:12,851 mod_tls/2.6[18013]: TLSv1.3 renegotiation accepted, using cipher TLS_CHACHA20_POLY1305_SHA256 (256 bits)
2021-02-26 15:29:12,852 mod_tls/2.6[18013]: TLSv1.3 renegotiation accepted, using cipher TLS_CHACHA20_POLY1305_SHA256 (256 bits)
2021-02-26 15:29:12,852 mod_tls/2.6[18013]: TLSv1.3 connection accepted, using cipher TLS_CHACHA20_POLY1305_SHA256 (256 bits)
2021-02-26 15:29:12,877 mod_tls/2.6[18013]: Protection set to Private
2021-02-26 15:29:12,879 mod_tls/2.6[18013]: starting TLS negotiation on data connection
2021-02-26 15:29:12,893 mod_tls/2.6[18013]: TLSv1.3 renegotiation accepted, using cipher TLS_CHACHA20_POLY1305_SHA256 (256 bits)
2021-02-26 15:29:12,894 mod_tls/2.6[18013]: TLSv1.3 renegotiation accepted, using cipher TLS_CHACHA20_POLY1305_SHA256 (256 bits)
2021-02-26 15:29:12,894 mod_tls/2.6[18013]: TLSv1.3 data connection accepted, using cipher TLS_CHACHA20_POLY1305_SHA256 (256 bits)
2021-02-26 15:29:12,897 mod_tls/2.6[18013]: starting TLS negotiation on data connection
2021-02-26 15:29:12,910 mod_tls/2.6[18013]: TLSv1.3 renegotiation accepted, using cipher TLS_CHACHA20_POLY1305_SHA256 (256 bits)
2021-02-26 15:29:12,910 mod_tls/2.6[18013]: TLSv1.3 renegotiation accepted, using cipher TLS_CHACHA20_POLY1305_SHA256 (256 bits)
2021-02-26 15:29:12,913 mod_tls/2.6[18013]: starting TLS negotiation on data connection
2021-02-26 15:29:12,928 mod_tls/2.6[18013]: TLSv1.3 renegotiation accepted, using cipher TLS_CHACHA20_POLY1305_SHA256 (256 bits)
2021-02-26 15:29:12,928 mod_tls/2.6[18013]: TLSv1.3 renegotiation accepted, using cipher TLS_CHACHA20_POLY1305_SHA256 (256 bits)
2021-02-26 15:29:12,931 mod_tls/2.6[18013]: starting TLS negotiation on data connection
2021-02-26 15:29:12,931 mod_tls/2.6[18013]: unable to accept TLS connection: system call error: [0] Success
2021-02-26 15:29:12,931 mod_tls/2.6[18013]: SSL_shutdown error: SSL: 
  (1) error:140E0197:SSL routines:SSL_shutdown:shutdown while in init
2021-02-26 15:29:12,931 mod_tls/2.6[18013]: unable to open data connection: TLS negotiation failed
2021-02-26 15:29:13,940 mod_tls/2.6[18014]: TLS/TLS-C requested, starting TLS handshake
2021-02-26 15:29:13,957 mod_tls/2.6[18014]: TLSv1.3 renegotiation accepted, using cipher TLS_CHACHA20_POLY1305_SHA256 (256 bits)
2021-02-26 15:29:13,958 mod_tls/2.6[18014]: TLSv1.3 renegotiation accepted, using cipher TLS_CHACHA20_POLY1305_SHA256 (256 bits)
2021-02-26 15:29:13,958 mod_tls/2.6[18014]: TLSv1.3 connection accepted, using cipher TLS_CHACHA20_POLY1305_SHA256 (256 bits)
2021-02-26 15:29:13,983 mod_tls/2.6[18014]: Protection set to Private
2021-02-26 15:29:13,984 mod_tls/2.6[18014]: starting TLS negotiation on data connection
2021-02-26 15:29:13,998 mod_tls/2.6[18014]: TLSv1.3 renegotiation accepted, using cipher TLS_CHACHA20_POLY1305_SHA256 (256 bits)
2021-02-26 15:29:13,998 mod_tls/2.6[18014]: TLSv1.3 renegotiation accepted, using cipher TLS_CHACHA20_POLY1305_SHA256 (256 bits)
2021-02-26 15:29:13,998 mod_tls/2.6[18014]: TLSv1.3 data connection accepted, using cipher TLS_CHACHA20_POLY1305_SHA256 (256 bits)

Log output of /var/log/proftpd/tls.log (Ubuntu 20.04 - proFTPD 1.3.6c)

2021-02-26 15:33:19,984 mod_tls/2.7[6488]: TLS/TLS-C requested, starting TLS handshake
2021-02-26 15:33:20,054 mod_tls/2.7[6488]: TLSv1.3 connection accepted, using cipher TLS_CHACHA20_POLY1305_SHA256 (256 bits)
2021-02-26 15:33:20,088 mod_tls/2.7[6488]: Protection set to Private
2021-02-26 15:33:20,090 mod_tls/2.7[6488]: starting TLS negotiation on data connection
2021-02-26 15:33:20,105 mod_tls/2.7[6488]: TLSv1.3 data connection accepted, using cipher TLS_CHACHA20_POLY1305_SHA256 (256 bits)
2021-02-26 15:33:20,108 mod_tls/2.7[6488]: starting TLS negotiation on data connection
2021-02-26 15:33:20,126 mod_tls/2.7[6488]: starting TLS negotiation on data connection
2021-02-26 15:33:20,151 mod_tls/2.7[6488]: starting TLS negotiation on data connection
2021-02-26 15:33:20,151 mod_tls/2.7[6488]: unable to accept TLS connection: system call error: [0] Success
2021-02-26 15:33:20,151 mod_tls/2.7[6488]: unable to open data connection: TLS negotiation failed
2021-02-26 15:33:21,167 mod_tls/2.7[6489]: TLS/TLS-C requested, starting TLS handshake
2021-02-26 15:33:21,184 mod_tls/2.7[6489]: TLSv1.3 connection accepted, using cipher TLS_CHACHA20_POLY1305_SHA256 (256 bits)
2021-02-26 15:33:21,211 mod_tls/2.7[6489]: Protection set to Private
2021-02-26 15:33:21,213 mod_tls/2.7[6489]: starting TLS negotiation on data connection
2021-02-26 15:33:21,227 mod_tls/2.7[6489]: TLSv1.3 data connection accepted, using cipher TLS_CHACHA20_POLY1305_SHA256 (256 bits)

Thank you very much for your help!
Alex

jcastill · February 27, 2021, 3:48am

Have you tried using this flag? " --ftp-no-check-certificate"

ncw · February 27, 2021, 9:14pm

Interesting...

ProFTP is one of the things rclone integration tests with and the empty file uploads work properly there. It doesn't use FTPS though so that may be the difference.

I wonder if this is some incompatibility between rclone and the SSL layer in proftpd..

We should check the basics though - does rclone lsf work and show a directory listing?

If it does then could you try this and post the output

rclone touch my-ftp-dev13:files/my-test-files/test --retries 1 -vv  --dump bodies

if it doesn't work then it is probably an SSL/TLS problem.

icom · March 1, 2021, 8:38am

Hey there,

-> This will still produce the error.

-> This works.
It seems that only empty files / "touch" causes problems, while I can use other commands without problems (however I did not test all of them).

Here comes the result of the command:

rclone touch my-ftp-dev13:files/my-test-files/test --retries 1 -vv  --dump bodies

2021/03/01 09:37:04 DEBUG : rclone: Version "v1.54.0" starting with parameters ["rclone" "touch" "my-ftp-dev13:files/my-test-files/test" "--retries" "1" "-vv" "--dump" "bodies"]
2021/03/01 09:37:04 DEBUG : Creating backend with remote "my-ftp-dev13:files/my-test-files/"
2021/03/01 09:37:04 DEBUG : Using config file from "/root/.config/rclone/rclone.conf"
2021/03/01 09:37:04 DEBUG : ftp://dev13.keymachine.de:21/files/my-test-files: Connecting to FTP server
2021/03/01 09:37:04 DEBUG : FTP Rx: "220 ProFTPD 1.3.5e Server (dev13.keymachine.de FTP-Server) [::ffff:62.141.56.78]"
2021/03/01 09:37:04 DEBUG : FTP Tx: "AUTH TLS"
2021/03/01 09:37:04 DEBUG : FTP Rx: "234 AUTH TLS successful"
2021/03/01 09:37:04 DEBUG : FTP Tx: "USER test"
2021/03/01 09:37:04 DEBUG : FTP Rx: "331 Password required for test"
2021/03/01 09:37:04 DEBUG : FTP Tx: PASS *****
2021/03/01 09:37:04 DEBUG : FTP Rx: "230 User test logged in"
2021/03/01 09:37:04 DEBUG : FTP Tx: "FEAT"
2021/03/01 09:37:04 DEBUG : FTP Rx: "211-Features:"
2021/03/01 09:37:04 DEBUG : FTP Rx: " CCC"
2021/03/01 09:37:04 DEBUG : FTP Rx: " SITE MKDIR"
2021/03/01 09:37:04 DEBUG : FTP Rx: " PBSZ"
2021/03/01 09:37:04 DEBUG : FTP Rx: " AUTH TLS"
2021/03/01 09:37:04 DEBUG : FTP Rx: " MFF modify;UNIX.group;UNIX.mode;"
2021/03/01 09:37:04 DEBUG : FTP Rx: " REST STREAM"
2021/03/01 09:37:04 DEBUG : FTP Rx: " MLST modify*;perm*;size*;type*;unique*;UNIX.group*;UNIX.mode*;UNIX.owner*;"
2021/03/01 09:37:04 DEBUG : FTP Rx: " UTF8"
2021/03/01 09:37:04 DEBUG : FTP Rx: " LANG en-US.UTF-8;en-US"
2021/03/01 09:37:04 DEBUG : FTP Rx: " EPRT"
2021/03/01 09:37:04 DEBUG : FTP Rx: " SITE SYMLINK"
2021/03/01 09:37:04 DEBUG : FTP Rx: " EPSV"
2021/03/01 09:37:04 DEBUG : FTP Rx: " SITE UTIME"
2021/03/01 09:37:04 DEBUG : FTP Rx: " MDTM"
2021/03/01 09:37:04 DEBUG : FTP Rx: " SITE RMDIR"
2021/03/01 09:37:04 DEBUG : FTP Rx: " SSCN"
2021/03/01 09:37:04 DEBUG : FTP Rx: " TVFS"
2021/03/01 09:37:04 DEBUG : FTP Rx: " MFMT"
2021/03/01 09:37:04 DEBUG : FTP Rx: " SIZE"
2021/03/01 09:37:04 DEBUG : FTP Rx: " PROT"
2021/03/01 09:37:04 DEBUG : FTP Rx: "211 End"
2021/03/01 09:37:04 DEBUG : FTP Tx: "TYPE I"
2021/03/01 09:37:04 DEBUG : FTP Rx: "200 Type set to I"
2021/03/01 09:37:04 DEBUG : FTP Tx: "OPTS UTF8 ON"
2021/03/01 09:37:04 DEBUG : FTP Rx: "200 UTF8 set to on"
2021/03/01 09:37:04 DEBUG : FTP Tx: "PBSZ 0"
2021/03/01 09:37:04 DEBUG : FTP Rx: "200 PBSZ 0 successful"
2021/03/01 09:37:04 DEBUG : FTP Tx: "PROT P"
2021/03/01 09:37:04 DEBUG : FTP Rx: "200 Protection set to Private"
2021/03/01 09:37:04 DEBUG : FTP Tx: "EPSV"
2021/03/01 09:37:04 DEBUG : FTP Rx: "229 Entering Extended Passive Mode (|||30415|)"
2021/03/01 09:37:04 DEBUG : FTP Tx: "MLSD files/my-test-files"
2021/03/01 09:37:04 DEBUG : FTP Rx: "150 Opening BINARY mode data connection for MLSD"
2021/03/01 09:37:04 DEBUG : FTP Rx: "226 Transfer complete"
2021/03/01 09:37:04 DEBUG : FTP Tx: "EPSV"
2021/03/01 09:37:04 DEBUG : FTP Rx: "229 Entering Extended Passive Mode (|||30092|)"
2021/03/01 09:37:04 DEBUG : FTP Tx: "MLSD files/my-test-files"
2021/03/01 09:37:04 DEBUG : FTP Rx: "150 Opening BINARY mode data connection for MLSD"
2021/03/01 09:37:04 DEBUG : FTP Rx: "226 Transfer complete"
2021/03/01 09:37:04 DEBUG : FTP Tx: "EPSV"
2021/03/01 09:37:04 DEBUG : FTP Rx: "229 Entering Extended Passive Mode (|||30016|)"
2021/03/01 09:37:04 DEBUG : FTP Tx: "MLSD files"
2021/03/01 09:37:04 DEBUG : FTP Rx: "150 Opening BINARY mode data connection for MLSD"
2021/03/01 09:37:04 DEBUG : FTP Rx: "226 Transfer complete"
2021/03/01 09:37:04 DEBUG : FTP Tx: "EPSV"
2021/03/01 09:37:04 DEBUG : FTP Rx: "229 Entering Extended Passive Mode (|||30244|)"
2021/03/01 09:37:04 DEBUG : FTP Tx: "STOR files/my-test-files/test"
2021/03/01 09:37:04 DEBUG : FTP Rx: "150 Opening BINARY mode data connection for files/my-test-files/test"
2021/03/01 09:37:04 DEBUG : FTP Rx: "425 Unable to build data connection: Operation not permitted"
2021/03/01 09:37:04 DEBUG : FTP Tx: "QUIT"
2021/03/01 09:37:05 DEBUG : ftp://dev13.keymachine.de:21/files/my-test-files: Connecting to FTP server
2021/03/01 09:37:05 DEBUG : FTP Rx: "220 ProFTPD 1.3.5e Server (dev13.keymachine.de FTP-Server) [::ffff:62.141.57.78]"
2021/03/01 09:37:05 DEBUG : FTP Tx: "AUTH TLS"
2021/03/01 09:37:05 DEBUG : FTP Rx: "234 AUTH TLS successful"
2021/03/01 09:37:05 DEBUG : FTP Tx: "USER test"
2021/03/01 09:37:05 DEBUG : FTP Rx: "331 Password required for test"
2021/03/01 09:37:05 DEBUG : FTP Tx: PASS *****
2021/03/01 09:37:05 DEBUG : FTP Rx: "230 User test logged in"
2021/03/01 09:37:05 DEBUG : FTP Tx: "FEAT"
2021/03/01 09:37:05 DEBUG : FTP Rx: "211-Features:"
2021/03/01 09:37:05 DEBUG : FTP Rx: " CCC"
2021/03/01 09:37:05 DEBUG : FTP Rx: " SITE MKDIR"
2021/03/01 09:37:05 DEBUG : FTP Rx: " PBSZ"
2021/03/01 09:37:05 DEBUG : FTP Rx: " AUTH TLS"
2021/03/01 09:37:05 DEBUG : FTP Rx: " MFF modify;UNIX.group;UNIX.mode;"
2021/03/01 09:37:05 DEBUG : FTP Rx: " REST STREAM"
2021/03/01 09:37:05 DEBUG : FTP Rx: " MLST modify*;perm*;size*;type*;unique*;UNIX.group*;UNIX.mode*;UNIX.owner*;"
2021/03/01 09:37:05 DEBUG : FTP Rx: " UTF8"
2021/03/01 09:37:05 DEBUG : FTP Rx: " LANG en-US.UTF-8;en-US"
2021/03/01 09:37:05 DEBUG : FTP Rx: " EPRT"
2021/03/01 09:37:05 DEBUG : FTP Rx: " SITE SYMLINK"
2021/03/01 09:37:05 DEBUG : FTP Rx: " EPSV"
2021/03/01 09:37:05 DEBUG : FTP Rx: " SITE UTIME"
2021/03/01 09:37:05 DEBUG : FTP Rx: " MDTM"
2021/03/01 09:37:05 DEBUG : FTP Rx: " SITE RMDIR"
2021/03/01 09:37:05 DEBUG : FTP Rx: " SSCN"
2021/03/01 09:37:05 DEBUG : FTP Rx: " TVFS"
2021/03/01 09:37:05 DEBUG : FTP Rx: " MFMT"
2021/03/01 09:37:05 DEBUG : FTP Rx: " SIZE"
2021/03/01 09:37:05 DEBUG : FTP Rx: " PROT"
2021/03/01 09:37:05 DEBUG : FTP Rx: "211 End"
2021/03/01 09:37:05 DEBUG : FTP Tx: "TYPE I"
2021/03/01 09:37:05 DEBUG : FTP Rx: "200 Type set to I"
2021/03/01 09:37:05 DEBUG : FTP Tx: "OPTS UTF8 ON"
2021/03/01 09:37:05 DEBUG : FTP Rx: "200 UTF8 set to on"
2021/03/01 09:37:05 DEBUG : FTP Tx: "PBSZ 0"
2021/03/01 09:37:05 DEBUG : FTP Rx: "200 PBSZ 0 successful"
2021/03/01 09:37:05 DEBUG : FTP Tx: "PROT P"
2021/03/01 09:37:05 DEBUG : FTP Rx: "200 Protection set to Private"
2021/03/01 09:37:05 DEBUG : FTP Tx: "EPSV"
2021/03/01 09:37:05 DEBUG : FTP Rx: "229 Entering Extended Passive Mode (|||30368|)"
2021/03/01 09:37:05 DEBUG : FTP Tx: "MLSD files/my-test-files"
2021/03/01 09:37:05 DEBUG : FTP Rx: "150 Opening BINARY mode data connection for MLSD"
2021/03/01 09:37:06 DEBUG : FTP Rx: "226 Transfer complete"
2021/03/01 09:37:06 DEBUG : FTP Tx: "DELE files/my-test-files/test"
2021/03/01 09:37:06 DEBUG : FTP Rx: "250 DELE command successful"
2021/03/01 09:37:06 DEBUG : test: Removed after failed upload: 425 Unable to build data connection: Operation not permitted
2021/03/01 09:37:06 ERROR : Attempt 1/1 failed with 1 errors and: update stor: 425 Unable to build data connection: Operation not permitted
2021/03/01 09:37:06 DEBUG : 2 go routines active
2021/03/01 09:37:06 Failed to touch: update stor: 425 Unable to build data connection: Operation not permitted

ncw · March 1, 2021, 9:50am

I found this article which may/may not be relevant

icom · March 1, 2021, 10:35am

The ProFTPD configuration parameter was the first thing I checked when I first encountered the problem. But all my test servers are equipped with it:

TLSOptions NoSessionReuseRequired

Unfortunately the cause of the problem must be somewhere else

icom · March 1, 2021, 10:56am

I have checked, what Filezilla is doing, when uploading an empty file.

It uses ASCII mode:

11:52:18	Command:	STOR empty-file
11:52:18	Response:	150 Opening ASCII mode data connection for empty-file
11:52:18	Response:	226 Transfer complete

While rclone uses Binary:

2021/03/01 09:37:04 DEBUG : FTP Tx: "STOR files/my-test-files/test"
2021/03/01 09:37:04 DEBUG : FTP Rx: "150 Opening BINARY mode data connection for files/my-test-files/test"
2021/03/01 09:37:04 DEBUG : FTP Rx: "425 Unable to build data connection: Operation not permitted"

Maybe this helps.

Thank you very much.

ncw · March 1, 2021, 11:00am

Can you try uploading a file with binary format with Filezilla? Perhaps call your file emptyfile.bin or something like that?

icom · March 1, 2021, 11:04am

I have switched transfer type to Binary, but this also works with Filezilla

12:01:55	Command:	STOR empty-file
12:01:55	Response:	150 Opening BINARY mode data connection for empty-file
12:01:55	Response:	226 Transfer complete

ncw · March 1, 2021, 11:22am

OK, that was worth trying!

I think this is an incompatibility at the SSL layer. You said already that without explicit_tls = true it works OK.

It works OK with FIleZilla so we are talking about a specific incompatibility between Go's TLS stack and Proftpd.

Probably the next thing to do would be to use wireshark to capture the failed connection and examine the TLS handshake to see what goes wrong.

icom · March 1, 2021, 12:14pm

I have captured the wireshark outputs, which can be downloaded here:

http://rclone.dev01.keymachine.de/rclone.pcapng

For comparision, the capture of Filezilla.
http://rclone.dev01.keymachine.de/filezilla.pcapng

Should I rather turn to the Go-Community?
(I am not a Go-guy, afraid I would not be much of a help for them)

ncw · March 1, 2021, 4:09pm

Hmm, this is quite difficult to debug, but what I think happened is that rclone opened a stream to upload the file and sent 0 bytes, but didn't do a TLS negotiation

The documentation for the tls.Connection makes me think that this is heading in the right direction

Handshake runs the client or server handshake protocol if it has not yet been run.

Most uses of this package need not call Handshake explicitly: the first Read or Write will call it automatically.

So I'm guessing that the connection is made, but Write() is never called on it because there is no data.

I looked at the library and this isn't too difficult to fix.

Can you try this

v1.55.0-beta.5242.73653f0bd.fix-ftp-tls-zero-length on branch fix-ftp-tls-zero-length (uploaded in 15-30 mins)

If that works, then I'll submit an upstream patch to https://github.com/jlaffaye/ftp which is the library rclone uses

icom · March 2, 2021, 7:18am

Wow perfect, that did the trick, "touch" and uploading empty files are working now.

Thank you for this awesome piece of software ;).

ncw · March 2, 2021, 9:21am

Thanks for testing

I'll submit that patch upstream and it will go back into rclone when it gets merged.

ncw · March 2, 2021, 3:15pm

Patch submitted here: https://github.com/jlaffaye/ftp/pull/221

system · March 5, 2021, 3:15pm

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

ncw · March 5, 2021, 4:04pm

This has been merged upstream now and the fix merged back into the latest beta This will be released in 1.55