ssl - FTPS 2-5 秒延迟

Question

为了在 PHP 中进行开发，我使用具有嵌入式 FTP 客户端的 PHPStorm IDE。每当我将文件上传到 FTP 服务器时，都会有 2-5 秒的延迟，这导致文件上传需要大约 10-15 秒。它必须与 SSL 有关，无论是协议(protocol)还是 FTP 客户端对服务器证书的验证。每当我切换到 FTP 时，上传速度都快如闪电。我还应该补充一点，当我连接到不同的客户端 (FileZilla) 时，上传和下载工作得很好。我已经排除了 UseIPv6 和 IdentLookups 选项，关闭它们没有任何效果。我以 PASSIVE 模式连接，所以这也不会造成任何问题。

我没有想法，真的需要一些帮助!谢谢。

FTP 服务器是 Debian Wheezy 机器上的 proftpd 1.3.4a。

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>

最后，通过 PHPStorm IDE 上传文件的 tls.log:

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

Answer 1

找到了根本原因； ProFTPD Bugzilla 对此有一份报告和修复:

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