隨機獲取 Postfix SSL_accept 錯誤/Dovecot TLS 握手斷開連接

幾天/幾週以來，我遇到了這個非常奇怪的問題：越來越多的人報告在 SSL 模式下連接到郵件伺服器（Dovecot IMAP 和 POP3 以及 Postfix SMTP）時出現問題。它們執行在兩個獨立的 Debian 6.ßsqueeze 伺服器上，具有相同的配置和相同的 SSL 證書，它們是 RapidSSL 萬用字元證書。該配置執行了 2 年多，並且最近根本沒有更改。我只能說，在 12 月底我更新了 SSL 證書。當然，我會保持所有 Debian 軟體包都是最新的。

我一直無法找到重現該問題的常見方案，它發生在各種客戶端（Mozilla Thunderbird、Windows Live Mail、Apple Mail）上，並且非常隨機發生，並且僅針對某些使用者。基本上，客戶端報告伺服器意外終止連接。但是，如果您在幾秒鐘後重試，它就會起作用。奇怪的是，這會影響 Postfix 和 Dovecot，但是 Apache 似乎使用相同的證書執行良好。

在其中一台伺服器上只有我的郵箱，因此我可以排除任何伺服器過載或達到的限制。

所以我在 Postfix 和 Dovecot 上都啟用了調試日誌。

Mar  5 20:15:24 mercury postfix/smtpd[24551]: connect from xxx.kabel-badenwuerttemberg.de[46.xxx.xxx.xxx]
Mar  5 20:15:24 mercury postfix/smtpd[24551]: setting up TLS connection from xxx.kabel-badenwuerttemberg.de[46.xxx.xxx.xxx]
Mar  5 20:15:24 mercury postfix/smtpd[24551]: xxx.kabel-badenwuerttemberg.de[46.xxx.xxx.xxx]: TLS cipher list "ALL:+RC4:@STRENGTH"
Mar  5 20:15:24 mercury postfix/smtpd[24551]: SSL_accept:before/accept initialization
Mar  5 20:15:24 mercury postfix/smtpd[24551]: SSL_accept:SSLv3 read client hello B
Mar  5 20:15:24 mercury postfix/smtpd[24551]: SSL_accept:SSLv3 write server hello A
Mar  5 20:15:24 mercury postfix/smtpd[24551]: SSL_accept:SSLv3 write certificate A
Mar  5 20:15:24 mercury postfix/smtpd[24551]: SSL_accept:SSLv3 write server done A
Mar  5 20:15:24 mercury postfix/smtpd[24551]: SSL_accept:SSLv3 flush data
Mar  5 20:15:24 mercury postfix/smtpd[24551]: **SSL_accept error** from xxx.kabel-badenwuerttemberg.de[46.xxx.xxx.xxx]: -1
Mar  5 20:15:24 mercury postfix/smtpd[24551]: lost connection after STARTTLS from xxx.kabel-badenwuerttemberg.de[46.xxx.xxx.xxx]
Mar  5 20:15:24 mercury postfix/smtpd[24551]: disconnect from xxx.kabel-badenwuerttemberg.de[46.xxx.xxx.xxx]
Mar  5 20:15:24 mercury postfix/smtpd[24551]: connect from xxx.kabel-badenwuerttemberg.de[46.xxx.xxx.xxx]
Mar  5 20:15:24 mercury postfix/smtpd[24551]: lost connection after MAIL from xxx.kabel-badenwuerttemberg.de[46.xxx.xxx.xxx]
Mar  5 20:15:24 mercury postfix/smtpd[24551]: disconnect from xxx.kabel-badenwuerttemberg.de[46.xxx.xxx.xxx]

幾分鐘後通訊成功。同一個客戶。

Mar  5 20:18:53 mercury postfix/smtpd[24710]: initializing the server-side TLS engine
Mar  5 20:18:53 mercury postfix/smtpd[24710]: connect from xxx.kabel-badenwuerttemberg.de[46.xxx.xxx.xxx]
Mar  5 20:18:53 mercury postfix/smtpd[24710]: setting up TLS connection from xxx.kabel-badenwuerttemberg.de[46.xxx.xxx.xxx]
Mar  5 20:18:53 mercury postfix/smtpd[24710]: xxx.kabel-badenwuerttemberg.de[46.xxx.xxx.xxx]: TLS cipher list "ALL:+RC4:@STRENGTH"
Mar  5 20:18:53 mercury postfix/smtpd[24710]: SSL_accept:before/accept initialization
Mar  5 20:18:53 mercury postfix/smtpd[24710]: SSL_accept:SSLv3 read client hello B
Mar  5 20:18:53 mercury postfix/smtpd[24710]: SSL_accept:SSLv3 write server hello A
Mar  5 20:18:53 mercury postfix/smtpd[24710]: SSL_accept:SSLv3 write certificate A
Mar  5 20:18:53 mercury postfix/smtpd[24710]: SSL_accept:SSLv3 write server done A
Mar  5 20:18:53 mercury postfix/smtpd[24710]: SSL_accept:SSLv3 flush data
Mar  5 20:18:53 mercury postfix/smtpd[24710]: SSL_accept:SSLv3 read client key exchange A
Mar  5 20:18:53 mercury postfix/smtpd[24710]: SSL_accept:SSLv3 read finished A
Mar  5 20:18:53 mercury postfix/smtpd[24710]: SSL_accept:SSLv3 write session ticket A
Mar  5 20:18:53 mercury postfix/smtpd[24710]: SSL_accept:SSLv3 write change cipher spec A
Mar  5 20:18:53 mercury postfix/smtpd[24710]: SSL_accept:SSLv3 write finished A
Mar  5 20:18:53 mercury postfix/smtpd[24710]: SSL_accept:SSLv3 flush data
Mar  5 20:18:53 mercury postfix/smtpd[24710]: Anonymous TLS connection established from xxx.kabel-badenwuerttemberg.de[46.xxx.xxx.xxx]: TLSv1 with cipher AES128-SHA (128/128 bits)
Mar  5 20:18:53 mercury postfix/smtpd[24710]: 9B3C93FA2C: client=xxx.kabel-badenwuerttemberg.de[46.xxx.xxx.xxx], sasl_method=LOGIN, sasl_username=xxx
Mar  5 20:18:53 mercury postfix/cleanup[24712]: 9B3C93FA2C: message-id=<A1DEE5BBBD1F4E4CB5BF9AD0D3B1F98F@Angus>
Mar  5 20:18:53 mercury postfix/qmgr[24412]: 9B3C93FA2C: from=<foo@bar.tld>, size=1303, nrcpt=1 (queue active)
Mar  5 20:18:53 mercury postfix/smtpd[24710]: disconnect from xxx.kabel-badenwuerttemberg.de[46.xxx.xxx.xxx]
Mar  5 20:18:53 mercury postfix/smtp[24713]: 9B3C93FA2C: to=<foo@devnull.tld>, relay=xxx.xxx.xxx[188.xxx.xxx.xxx]:25, delay=0.38, delays=0.19/0.01/0.12/0.06, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as E8FC024534)
Mar  5 20:18:53 mercury postfix/qmgr[24412]: 9B3C93FA2C: remove

Dovecot 不太善於交流，這就是它在失敗時所說的：

Mar  5 22:18:23 mercury dovecot: imap-login: Disconnected (no auth attempts): rip=46.xxx.xxx.xxx, lip=188.xxx.xxx.xxx, TLS: Disconnected
Mar  5 22:18:25 mercury dovecot: imap-login: Disconnected (no auth attempts): rip=46.xxx.xxx.xxx, lip=188.xxx.xxx.xxx, TLS handshaking: Disconnected

我拼命地試圖了解發生了什麼。這是我的新證書產生的問題嗎？來自 debian 的最新安全更新 openssl 庫是否存在問題？我重新啟動了機器，仔細檢查了證書的正確性，禁用了防火牆，這一切都沒有幫助……最奇怪的是這種行為的完全隨機性：只有一些使用者/客戶端出現問題，而且有時它適用於他們也是。真的很奇怪…

到目前為止，所有證據都指向客戶端的問題，所以我就這樣說吧。

附加資訊：

根據this page，建立安全通道有9個步驟。

Step 1: Client sends ClientHello message proposing SSL options.
Step 2: Server responds with ServerHello message selecting the SSL options.
Step 3: Server sends its public key information in ServerKeyExchange message.
Step 4: Server concludes its part of the negotiation with ServerHelloDone message.
Step 5: Client sends session key information (encrypted with server’s public key) in ClientKeyExchange message.
Step 6: Client sends ChangeCipherSpec message to activate the negotiated options for all future messages it will send.
Step 7: Client sends Finished message to let the server check the newly activated options.
Step 8: Server sends ChangeCipherSpec message to activate the negotiated options for all future messages it will send.
Step 9: Server sends Finished message to let the client check the newly activated options.

根據郵件日誌，“儀式”在第 4 步後被客戶中止。

如何進一步調試

要了解實際發生的情況，您應該在伺服器端啟動 tcpdump 並比較成功案例和不成功案例。

另一個附加步驟是在 postfix 中啟用 SSL 詳細程度 main.cf。查看參數smtpd_tls_loglevel。此處給出了日誌級別表

level | information
0       Disable logging of TLS activity.
1       Log only a summary message on TLS handshake completion — no logging of client certificate trust-chain verification errors if client certificate verification is not required.
2       Also log levels during TLS negotiation.
3       Also log hexadecimal and ASCII dump of TLS negotiation process.
4       Also log hexadecimal and ASCII dump of complete transmission after STARTTLS.TTLS.

將此參數設置為**> 3**將轉儲您需要的所有內容。

引用自：https://serverfault.com/questions/366828