Domanda

For developing in PHP I use the PHPStorm IDE which has an embedded FTP client. Whenever I upload a file to the FTP Server, I get 2-5 second delays, which causes the file upload to take ~10-15 seconds. It has to be related to SSL, either the netotiation or the verification of the server certificate by the FTP client. Whenever I switch to FTP, the upload is lightning fast. I should also add that when I connect with a different client (FileZilla) uploading and downloading works perfectly fine. I have ruled out the UseIPv6 and IdentLookups options, turning them off has no effect. I connect in PASSIVE mode so that's not causing any problems either.

I'm out of ideas and could really use some help! Thanks.

The FTP server is proftpd 1.3.4a on a Debian Wheezy machine.

proftpd.conf:

Include /etc/proftpd/modules.conf
UseIPv6                         on
IdentLookups                    on
ServerName                      "domain.tld"
ServerType                      standalone
DeferWelcome                    on
MultilineRFC2228                on
DefaultServer                   on
ShowSymlinks                    on
TimeoutNoTransfer               600
TimeoutStalled                  600
TimeoutIdle                     1200
DisplayLogin                    welcome.msg
DisplayChdir                    .message true
ListOptions                     "-l"
DenyFilter                      \*.*/
DefaultRoot                     ~
RequireValidShell               on
Port                            21
PassivePorts                  49152 65534
MaxInstances                    30
Umask                           027  027
AllowOverwrite                  on
AuthOrder                       mod_sql.c
# UseSendFile                   off
<IfModule mod_quotatab.c>
    QuotaEngine off
</IfModule>

<IfModule mod_ratio.c>
    Ratios off
</IfModule>

<IfModule mod_delay.c>
    DelayEngine off
</IfModule>

#
# Alternative authentication frameworks
#
#Include /etc/proftpd/ldap.conf
Include /etc/proftpd/sql.conf

#
# This is used for FTPS connections
#
Include /etc/proftpd/tls.conf

tls.conf:

<IfModule mod_tls.c>
    TLSEngine                               on
    TLSLog                                  /var/log/proftpd/tls.log
    TLSProtocol                             SSLv3 TLSv1

    TLSRSACertificateFile                   /etc/ssl/localcerts/domain_tld.crt
    TLSRSACertificateKeyFile                /etc/ssl/localcerts/domain_tld.key
    TLSCACertificatePath                    /etc/ssl/certs/

    TLSOptions                      NoCertRequest EnableDiags NoSessionReuseRequired
    #TLSVerifyClient                         on
    TLSRequired                             auth

    #TLSRenegotiate                          required off
</IfModule>

And lastly, the tls.log from uploading a file through the PHPStorm IDE:

Aug 30 08:56:46 mod_tls/2.4.3[8365]: TLSOption EnableDiags enabled, setting diagnostics callback
Aug 30 08:56:46 mod_tls/2.4.3[8365]: TLS/TLS-C requested, starting TLS handshake
Aug 30 08:56:46 mod_tls/2.4.3[8365]: [info] accepting: before/accept initialization
Aug 30 08:56:46 mod_tls/2.4.3[8365]: [info] accepting: unknown state
Aug 30 08:56:46 mod_tls/2.4.3[8365]: [msg] received TLSv1 'ClientHello' Handshake message (149 bytes)
Aug 30 08:56:46 mod_tls/2.4.3[8365]: [info] accepting: SSLv3 read client hello A
Aug 30 08:56:46 mod_tls/2.4.3[8365]: [msg] sent TLSv1 'ServerHello' Handshake message (81 bytes)
Aug 30 08:56:46 mod_tls/2.4.3[8365]: [info] accepting: SSLv3 write server hello A
Aug 30 08:56:46 mod_tls/2.4.3[8365]: [msg] sent TLSv1 'Certificate' Handshake message (1299 bytes)
Aug 30 08:56:46 mod_tls/2.4.3[8365]: [info] accepting: SSLv3 write certificate A
Aug 30 08:56:46 mod_tls/2.4.3[8365]: [msg] sent TLSv1 'ServerHelloDone' Handshake message (4 bytes)
Aug 30 08:56:46 mod_tls/2.4.3[8365]: [info] accepting: SSLv3 write server done A
Aug 30 08:56:46 mod_tls/2.4.3[8365]: [info] accepting: SSLv3 flush data
Aug 30 08:56:46 mod_tls/2.4.3[8365]: [msg] received TLSv1 'ClientKeyExchange' Handshake message (262 bytes)
Aug 30 08:56:46 mod_tls/2.4.3[8365]: [info] accepting: SSLv3 read client key exchange A
Aug 30 08:56:46 mod_tls/2.4.3[8365]: [msg] received TLSv1 ChangeCipherSpec message (1 byte)
Aug 30 08:56:46 mod_tls/2.4.3[8365]: [msg] received TLSv1 'Finished' Handshake message (16 bytes)
Aug 30 08:56:46 mod_tls/2.4.3[8365]: [info] accepting: SSLv3 read finished A
Aug 30 08:56:46 mod_tls/2.4.3[8365]: [msg] sent TLSv1 ChangeCipherSpec message (1 byte)
Aug 30 08:56:46 mod_tls/2.4.3[8365]: [info] accepting: SSLv3 write change cipher spec A
Aug 30 08:56:46 mod_tls/2.4.3[8365]: [msg] sent TLSv1 'Finished' Handshake message (16 bytes)
Aug 30 08:56:46 mod_tls/2.4.3[8365]: [info] accepting: SSLv3 write finished A
Aug 30 08:56:46 mod_tls/2.4.3[8365]: [info] accepting: SSLv3 flush data
Aug 30 08:56:46 mod_tls/2.4.3[8365]: [info] ok: SSL negotiation finished successfully
Aug 30 08:56:46 mod_tls/2.4.3[8365]: [info] accepting: SSL negotiation finished successfully
Aug 30 08:56:46 mod_tls/2.4.3[8365]: client supports secure renegotiations
Aug 30 08:56:46 mod_tls/2.4.3[8365]: TLSv1/SSLv3 connection accepted, using cipher AES128-SHA (128 bits)
Aug 30 08:56:46 mod_tls/2.4.3[8365]: Protection set to Private
Aug 30 08:56:46 mod_tls/2.4.3[8365]: starting TLS negotiation on data connection
Aug 30 08:56:46 mod_tls/2.4.3[8365]: [info] accepting: before/accept initialization
Aug 30 08:56:46 mod_tls/2.4.3[8365]: [info] accepting: unknown state
Aug 30 08:56:50 mod_tls/2.4.3[8365]: [msg] received TLSv1 'ClientHello' Handshake message (149 bytes)
Aug 30 08:56:50 mod_tls/2.4.3[8365]: [info] accepting: SSLv3 read client hello A
Aug 30 08:56:50 mod_tls/2.4.3[8365]: [msg] sent TLSv1 'ServerHello' Handshake message (81 bytes)
Aug 30 08:56:50 mod_tls/2.4.3[8365]: [info] accepting: SSLv3 write server hello A
Aug 30 08:56:50 mod_tls/2.4.3[8365]: [msg] sent TLSv1 'Certificate' Handshake message (1299 bytes)
Aug 30 08:56:50 mod_tls/2.4.3[8365]: [info] accepting: SSLv3 write certificate A
Aug 30 08:56:50 mod_tls/2.4.3[8365]: [msg] sent TLSv1 'ServerHelloDone' Handshake message (4 bytes)
Aug 30 08:56:50 mod_tls/2.4.3[8365]: [info] accepting: SSLv3 write server done A
Aug 30 08:56:50 mod_tls/2.4.3[8365]: [info] accepting: SSLv3 flush data
Aug 30 08:56:50 mod_tls/2.4.3[8365]: [info] accepting: SSLv3 read client certificate A
Aug 30 08:56:50 mod_tls/2.4.3[8365]: [info] accepting: SSLv3 read client certificate A
Aug 30 08:56:50 mod_tls/2.4.3[8365]: [msg] received TLSv1 'ClientKeyExchange' Handshake message (262 bytes)
Aug 30 08:56:50 mod_tls/2.4.3[8365]: [info] accepting: SSLv3 read client key exchange A
Aug 30 08:56:50 mod_tls/2.4.3[8365]: [info] accepting: SSLv3 read certificate verify A
Aug 30 08:56:50 mod_tls/2.4.3[8365]: [msg] received TLSv1 ChangeCipherSpec message (1 byte)
Aug 30 08:56:50 mod_tls/2.4.3[8365]: [msg] received TLSv1 'Finished' Handshake message (16 bytes)
Aug 30 08:56:50 mod_tls/2.4.3[8365]: [info] accepting: SSLv3 read finished A
Aug 30 08:56:50 mod_tls/2.4.3[8365]: [msg] sent TLSv1 ChangeCipherSpec message (1 byte)
Aug 30 08:56:50 mod_tls/2.4.3[8365]: [info] accepting: SSLv3 write change cipher spec A
Aug 30 08:56:50 mod_tls/2.4.3[8365]: [msg] sent TLSv1 'Finished' Handshake message (16 bytes)
Aug 30 08:56:50 mod_tls/2.4.3[8365]: [info] accepting: SSLv3 write finished A
Aug 30 08:56:50 mod_tls/2.4.3[8365]: [info] accepting: SSLv3 flush data
Aug 30 08:56:50 mod_tls/2.4.3[8365]: TLSv1/SSLv3 renegotiation accepted, using cipher AES128-SHA (128 bits)
Aug 30 08:56:50 mod_tls/2.4.3[8365]: [info] ok: SSL negotiation finished successfully
Aug 30 08:56:50 mod_tls/2.4.3[8365]: [info] accepting: SSL negotiation finished successfully
Aug 30 08:56:50 mod_tls/2.4.3[8365]: TLSv1/SSLv3 data connection accepted, using cipher AES128-SHA (128 bits)
Aug 30 08:56:50 mod_tls/2.4.3[8365]: [msg] sent TLSv1 warning 'close_notify' Alert message (2 bytes)
Aug 30 08:56:50 mod_tls/2.4.3[8365]: [info] writing: SSL/TLS alert warning: close notify
Aug 30 08:56:50 mod_tls/2.4.3[8365]: starting TLS negotiation on data connection
Aug 30 08:56:50 mod_tls/2.4.3[8365]: [info] accepting: before/accept initialization
Aug 30 08:56:50 mod_tls/2.4.3[8365]: [info] accepting: unknown state
Aug 30 08:56:52 mod_tls/2.4.3[8365]: [msg] received TLSv1 'ClientHello' Handshake message (149 bytes)
Aug 30 08:56:52 mod_tls/2.4.3[8365]: [info] accepting: SSLv3 read client hello A
Aug 30 08:56:52 mod_tls/2.4.3[8365]: [msg] sent TLSv1 'ServerHello' Handshake message (81 bytes)
Aug 30 08:56:52 mod_tls/2.4.3[8365]: [info] accepting: SSLv3 write server hello A
Aug 30 08:56:52 mod_tls/2.4.3[8365]: [msg] sent TLSv1 'Certificate' Handshake message (1299 bytes)
Aug 30 08:56:52 mod_tls/2.4.3[8365]: [info] accepting: SSLv3 write certificate A
Aug 30 08:56:52 mod_tls/2.4.3[8365]: [msg] sent TLSv1 'ServerHelloDone' Handshake message (4 bytes)
Aug 30 08:56:52 mod_tls/2.4.3[8365]: [info] accepting: SSLv3 write server done A
Aug 30 08:56:52 mod_tls/2.4.3[8365]: [info] accepting: SSLv3 flush data
Aug 30 08:56:52 mod_tls/2.4.3[8365]: [info] accepting: SSLv3 read client certificate A
Aug 30 08:56:52 mod_tls/2.4.3[8365]: [info] accepting: SSLv3 read client certificate A
Aug 30 08:56:52 mod_tls/2.4.3[8365]: [msg] received TLSv1 'ClientKeyExchange' Handshake message (262 bytes)
Aug 30 08:56:52 mod_tls/2.4.3[8365]: [info] accepting: SSLv3 read client key exchange A
Aug 30 08:56:52 mod_tls/2.4.3[8365]: [info] accepting: SSLv3 read certificate verify A
Aug 30 08:56:52 mod_tls/2.4.3[8365]: [msg] received TLSv1 ChangeCipherSpec message (1 byte)
Aug 30 08:56:52 mod_tls/2.4.3[8365]: [msg] received TLSv1 'Finished' Handshake message (16 bytes)
Aug 30 08:56:52 mod_tls/2.4.3[8365]: [info] accepting: SSLv3 read finished A
Aug 30 08:56:52 mod_tls/2.4.3[8365]: [msg] sent TLSv1 ChangeCipherSpec message (1 byte)
Aug 30 08:56:52 mod_tls/2.4.3[8365]: [info] accepting: SSLv3 write change cipher spec A
Aug 30 08:56:52 mod_tls/2.4.3[8365]: [msg] sent TLSv1 'Finished' Handshake message (16 bytes)
Aug 30 08:56:52 mod_tls/2.4.3[8365]: [info] accepting: SSLv3 write finished A
Aug 30 08:56:52 mod_tls/2.4.3[8365]: [info] accepting: SSLv3 flush data
Aug 30 08:56:52 mod_tls/2.4.3[8365]: TLSv1/SSLv3 renegotiation accepted, using cipher AES128-SHA (128 bits)
Aug 30 08:56:52 mod_tls/2.4.3[8365]: [info] ok: SSL negotiation finished successfully
Aug 30 08:56:52 mod_tls/2.4.3[8365]: [info] accepting: SSL negotiation finished successfully
Aug 30 08:56:52 mod_tls/2.4.3[8365]: [msg] received TLSv1 warning 'close_notify' Alert message (2 bytes)
Aug 30 08:56:52 mod_tls/2.4.3[8365]: [info] reading: SSL/TLS alert warning: close notify
Aug 30 08:56:52 mod_tls/2.4.3[8365]: [msg] sent TLSv1 warning 'close_notify' Alert message (2 bytes)
Aug 30 08:56:52 mod_tls/2.4.3[8365]: [info] writing: SSL/TLS alert warning: close notify
Aug 30 08:56:52 mod_tls/2.4.3[8365]: starting TLS negotiation on data connection
Aug 30 08:56:52 mod_tls/2.4.3[8365]: [info] accepting: before/accept initialization
Aug 30 08:56:52 mod_tls/2.4.3[8365]: [info] accepting: unknown state
Aug 30 08:56:54 mod_tls/2.4.3[8365]: [msg] received TLSv1 'ClientHello' Handshake message (149 bytes)
Aug 30 08:56:54 mod_tls/2.4.3[8365]: [info] accepting: SSLv3 read client hello A
Aug 30 08:56:54 mod_tls/2.4.3[8365]: [msg] sent TLSv1 'ServerHello' Handshake message (81 bytes)
Aug 30 08:56:54 mod_tls/2.4.3[8365]: [info] accepting: SSLv3 write server hello A
Aug 30 08:56:54 mod_tls/2.4.3[8365]: [msg] sent TLSv1 'Certificate' Handshake message (1299 bytes)
Aug 30 08:56:54 mod_tls/2.4.3[8365]: [info] accepting: SSLv3 write certificate A
Aug 30 08:56:54 mod_tls/2.4.3[8365]: [msg] sent TLSv1 'ServerHelloDone' Handshake message (4 bytes)
Aug 30 08:56:54 mod_tls/2.4.3[8365]: [info] accepting: SSLv3 write server done A
Aug 30 08:56:54 mod_tls/2.4.3[8365]: [info] accepting: SSLv3 flush data
Aug 30 08:56:54 mod_tls/2.4.3[8365]: [info] accepting: SSLv3 read client certificate A
Aug 30 08:56:54 mod_tls/2.4.3[8365]: [info] accepting: SSLv3 read client certificate A
Aug 30 08:56:54 mod_tls/2.4.3[8365]: [msg] received TLSv1 'ClientKeyExchange' Handshake message (262 bytes)
Aug 30 08:56:54 mod_tls/2.4.3[8365]: [info] accepting: SSLv3 read client key exchange A
Aug 30 08:56:54 mod_tls/2.4.3[8365]: [info] accepting: SSLv3 read certificate verify A
Aug 30 08:56:54 mod_tls/2.4.3[8365]: [msg] received TLSv1 ChangeCipherSpec message (1 byte)
Aug 30 08:56:54 mod_tls/2.4.3[8365]: [msg] received TLSv1 'Finished' Handshake message (16 bytes)
Aug 30 08:56:54 mod_tls/2.4.3[8365]: [info] accepting: SSLv3 read finished A
Aug 30 08:56:54 mod_tls/2.4.3[8365]: [msg] sent TLSv1 ChangeCipherSpec message (1 byte)
Aug 30 08:56:54 mod_tls/2.4.3[8365]: [info] accepting: SSLv3 write change cipher spec A
Aug 30 08:56:54 mod_tls/2.4.3[8365]: [msg] sent TLSv1 'Finished' Handshake message (16 bytes)
Aug 30 08:56:54 mod_tls/2.4.3[8365]: [info] accepting: SSLv3 write finished A
Aug 30 08:56:54 mod_tls/2.4.3[8365]: [info] accepting: SSLv3 flush data
Aug 30 08:56:54 mod_tls/2.4.3[8365]: TLSv1/SSLv3 renegotiation accepted, using cipher AES128-SHA (128 bits)
Aug 30 08:56:54 mod_tls/2.4.3[8365]: [info] ok: SSL negotiation finished successfully
Aug 30 08:56:54 mod_tls/2.4.3[8365]: [info] accepting: SSL negotiation finished successfully
Aug 30 08:56:54 mod_tls/2.4.3[8365]: [msg] sent TLSv1 warning 'close_notify' Alert message (2 bytes)
Aug 30 08:56:54 mod_tls/2.4.3[8365]: [info] writing: SSL/TLS alert warning: close notify
È stato utile?

Soluzione

The root cause for this has been found; the ProFTPD Bugzilla has a report and a fix for this:

http://bugs.proftpd.org/show_bug.cgi?id=4108

Altri suggerimenti

Try changing the TLSProtocol configuration to TLSv1:

TLSProtocol TLSv1
Autorizzato sotto: CC-BY-SA insieme a attribuzione
Non affiliato a StackOverflow
scroll top