Proftpd FTPS/FTPES Read Timeout

[cykotix]

Hello,

I'm currently switching from vsftpd to proftpd for various reasons and I cannot get FTPES to work properly on Foldersync.  It appears to work fine using any of my desktop clients, however.  I've attached the logfile from app.

Additionally, the TLS logging from proftpd shows the following when Foldersync connects:

Jul 09 13:24:17 mod_tls/2.4.2[20319]: using default OpenSSL verification locations (see $SSL_CERT_DIR environment variable)

Jul 09 13:24:18 mod_tls/2.4.2[20319]: TLS/TLS-C requested, starting TLS handshake

Jul 09 13:24:18 mod_tls/2.4.2[20319]: TLSv1/SSLv3 connection accepted, using cipher RC4-MD5 (128 bits)

Jul 09 12:24:18 mod_tls/2.4.2[20319]: Protection set to Private

Proftpd logging:

Jul 09 13:28:59 name.domain.tld proftpd[20369] name.domain.tld (remote.host.tld [::ffff:123.456.789.012]): FTP session opened.

Jul 09 12:29:00 name.domain.tld proftpd[20369] name.domain.tld (remote.host.tld [::ffff:123.456.789.012]): Preparing to chroot to directory '/home/android'

Jul 09 12:29:00 name.domain.tld proftpd[20369] name.domain.tld (remote.host.tld [::ffff:123.456.789.012]): USER android: Login successful.

Jul 09 12:31:25 name.domain.tld proftpd[20277] name.domain.tld (remote.host.tld [::ffff:123.456.789.012]): FTP session closed.

So as you can tell, from the server side of things, it appears to authenticate/connect successfully but not according to Foldersync.  Here are the same entries for Filezilla (which does work).

TLS logging:

Jul 09 13:40:16 mod_tls/2.4.2[20396]: using default OpenSSL verification locations (see $SSL_CERT_DIR environment variable)

Jul 09 13:40:16 mod_tls/2.4.2[20396]: TLS/TLS-C requested, starting TLS handshake

Jul 09 13:40:16 mod_tls/2.4.2[20396]: TLSv1/SSLv3 connection accepted, using cipher DHE-RSA-AES128-SHA (128 bits)

Jul 09 12:40:17 mod_tls/2.4.2[20396]: Protection set to Private

Proftpd logging:

Jul 09 13:37:51 name.domain.tld proftpd[20384] name.domain.tld (remote.host.tld [::ffff:123.456.789.012]): FTP session opened.

Jul 09 12:37:52 name.domain.tld proftpd[20384] name.domain.tld (remote.host.tld [::ffff:123.456.789.012]): Preparing to chroot to directory '/home/android'

Jul 09 12:37:52 name.domain.tld proftpd[20384] name.domain.tld (remote.host.tld [::ffff:123.456.789.012]): USER android: Login successful.

I can provide more verbose logging if necessary.  Any ideas on how to get this to work?

Thanks

[cykotix]

Here is verbose TLS logging of Foldersync:

Jul 09 13:45:51 mod_tls/2.4.2[20443]: TLSOption EnableDiags enabled, setting diagnostics callback

Jul 09 13:45:51 mod_tls/2.4.2[20443]: using default OpenSSL verification locations (see $SSL_CERT_DIR environment variable)

Jul 09 13:45:51 mod_tls/2.4.2[20443]: TLS/TLS-C requested, starting TLS handshake

Jul 09 13:45:51 mod_tls/2.4.2[20443]: [info] accepting: before/accept initialization

Jul 09 13:45:51 mod_tls/2.4.2[20443]: [info] accepting: SSLv2/v3 read client hello A

Jul 09 13:45:51 mod_tls/2.4.2[20443]: [msg] received TLSv1 'ClientHello' Handshake message (184 bytes)

Jul 09 13:45:51 mod_tls/2.4.2[20443]: [info] accepting: SSLv3 read client hello A

Jul 09 13:45:51 mod_tls/2.4.2[20443]: [msg] sent TLSv1 'ServerHello' Handshake message (81 bytes)

Jul 09 13:45:51 mod_tls/2.4.2[20443]: [info] accepting: SSLv3 write server hello A

Jul 09 13:45:51 mod_tls/2.4.2[20443]: [msg] sent TLSv1 'Certificate' Handshake message (944 bytes)

Jul 09 13:45:51 mod_tls/2.4.2[20443]: [info] accepting: SSLv3 write certificate A

Jul 09 13:45:51 mod_tls/2.4.2[20443]: [msg] sent TLSv1 'ServerHelloDone' Handshake message (4 bytes)

Jul 09 13:45:51 mod_tls/2.4.2[20443]: [info] accepting: SSLv3 write server done A

Jul 09 13:45:51 mod_tls/2.4.2[20443]: [info] accepting: SSLv3 flush data

Jul 09 13:45:51 mod_tls/2.4.2[20443]: [msg] received TLSv1 'ClientKeyExchange' Handshake message (134 bytes)

Jul 09 13:45:51 mod_tls/2.4.2[20443]: [info] accepting: SSLv3 read client key exchange A

Jul 09 13:45:51 mod_tls/2.4.2[20443]: [msg] received TLSv1 ChangeCipherSpec message (1 byte)

Jul 09 13:45:51 mod_tls/2.4.2[20443]: [msg] received TLSv1 'Finished' Handshake message (16 bytes)

Jul 09 13:45:51 mod_tls/2.4.2[20443]: [info] accepting: SSLv3 read finished A

Jul 09 13:45:51 mod_tls/2.4.2[20443]: [msg] sent TLSv1 ChangeCipherSpec message (1 byte)

Jul 09 13:45:51 mod_tls/2.4.2[20443]: [info] accepting: SSLv3 write change cipher spec A

Jul 09 13:45:51 mod_tls/2.4.2[20443]: [msg] sent TLSv1 'Finished' Handshake message (16 bytes)

Jul 09 13:45:51 mod_tls/2.4.2[20443]: [info] accepting: SSLv3 write finished A

Jul 09 13:45:51 mod_tls/2.4.2[20443]: [info] accepting: SSLv3 flush data

Jul 09 13:45:51 mod_tls/2.4.2[20443]: [info] ok: SSL negotiation finished successfully

Jul 09 13:45:51 mod_tls/2.4.2[20443]: [info] accepting: SSL negotiation finished successfully

Jul 09 13:45:51 mod_tls/2.4.2[20443]: TLSv1/SSLv3 connection accepted, using cipher RC4-MD5 (128 bits)

Jul 09 12:45:51 mod_tls/2.4.2[20443]: Protection set to Private

and verbose TLS logging of Filezilla:

Jul 09 13:47:13 mod_tls/2.4.2[20448]: TLSOption EnableDiags enabled, setting diagnostics callback

Jul 09 13:47:13 mod_tls/2.4.2[20448]: using default OpenSSL verification locations (see $SSL_CERT_DIR environment variable)

Jul 09 13:47:13 mod_tls/2.4.2[20448]: TLS/TLS-C requested, starting TLS handshake

Jul 09 13:47:13 mod_tls/2.4.2[20448]: [info] accepting: before/accept initialization

Jul 09 13:47:13 mod_tls/2.4.2[20448]: [info] accepting: SSLv2/v3 read client hello A

Jul 09 13:47:13 mod_tls/2.4.2[20448]: [msg] received TLSv1 'ClientHello' Handshake message (106 bytes)

Jul 09 13:47:13 mod_tls/2.4.2[20448]: [info] accepting: SSLv3 read client hello A

Jul 09 13:47:13 mod_tls/2.4.2[20448]: [msg] sent TLSv1 'ServerHello' Handshake message (81 bytes)

Jul 09 13:47:13 mod_tls/2.4.2[20448]: [info] accepting: SSLv3 write server hello A

Jul 09 13:47:13 mod_tls/2.4.2[20448]: [msg] sent TLSv1 'Certificate' Handshake message (944 bytes)

Jul 09 13:47:13 mod_tls/2.4.2[20448]: [info] accepting: SSLv3 write certificate A

Jul 09 13:47:13 mod_tls/2.4.2[20448]: [msg] sent TLSv1 'ServerKeyExchange' Handshake message (397 bytes)

Jul 09 13:47:13 mod_tls/2.4.2[20448]: [info] accepting: SSLv3 write key exchange A

Jul 09 13:47:13 mod_tls/2.4.2[20448]: [msg] sent TLSv1 'ServerHelloDone' Handshake message (4 bytes)

Jul 09 13:47:13 mod_tls/2.4.2[20448]: [info] accepting: SSLv3 write server done A

Jul 09 13:47:13 mod_tls/2.4.2[20448]: [info] accepting: SSLv3 flush data

Jul 09 13:47:13 mod_tls/2.4.2[20448]: [msg] received TLSv1 'ClientKeyExchange' Handshake message (134 bytes)

Jul 09 13:47:13 mod_tls/2.4.2[20448]: [info] accepting: SSLv3 read client key exchange A

Jul 09 13:47:13 mod_tls/2.4.2[20448]: [msg] received TLSv1 ChangeCipherSpec message (1 byte)

Jul 09 13:47:13 mod_tls/2.4.2[20448]: [msg] received TLSv1 'Finished' Handshake message (16 bytes)

Jul 09 13:47:13 mod_tls/2.4.2[20448]: [info] accepting: SSLv3 read finished A

Jul 09 13:47:13 mod_tls/2.4.2[20448]: [msg] sent TLSv1 ChangeCipherSpec message (1 byte)

Jul 09 13:47:13 mod_tls/2.4.2[20448]: [info] accepting: SSLv3 write change cipher spec A

Jul 09 13:47:13 mod_tls/2.4.2[20448]: [msg] sent TLSv1 'Finished' Handshake message (16 bytes)

Jul 09 13:47:13 mod_tls/2.4.2[20448]: [info] accepting: SSLv3 write finished A

Jul 09 13:47:13 mod_tls/2.4.2[20448]: [info] accepting: SSLv3 flush data

Jul 09 13:47:13 mod_tls/2.4.2[20448]: [info] ok: SSL negotiation finished successfully

Jul 09 13:47:13 mod_tls/2.4.2[20448]: [info] accepting: SSL negotiation finished successfully

Jul 09 13:47:13 mod_tls/2.4.2[20448]: TLSv1/SSLv3 connection accepted, using cipher DHE-RSA-AES128-SHA (128 bits)

Jul 09 12:47:14 mod_tls/2.4.2[20448]: Protection set to Private

So it seems Foldersync negotiates the connection but I can't tell where it's dying.

[cykotix]

Lastly, it appears FTP isn't working as well.  I've attached another log from Foldersync.  These attempts are normal FTP, port 2211, charset Default, allow self signed cert is still enabled from FTPES testing.

First attempt: unchecked Disable Compression, unchecked Legacy library

Second attempt: checked Disable Compression, unchecked Legacy library

Third attempt (notice connect timeout to random port despite being set to 2211): unchecked Disable Compression, checked Legacy library.

Also, I apologize for not including my device in the first post.  I'm running Galaxy Nexus on Jelly Bean 4.1.

[Support User]

Have you by some chance enable active mode? That will most often not work well, and is the only reason I can see for using the random port - although for passive ftp the server might also define random port for data connection.

Best regards

Anders Carlsen

Software Developer

If you like our apps, please give them a 5-star rating. Thanks. :-)

 

Tacit Dynamics

www.tacit.dk - Android Market - Support

[cykotix]

Nope, I was using passive over wifi.  From the same connection, passive connections from desktop clients worked without issue.  I've since moved onto using Google Drive instead because I couldn't figure this out.  Very bizarre.