У меня возникла эта действительно странная проблема в течение нескольких дней / недель: все больше и больше людей сообщают о проблемах с подключением к почтовым серверам (Dovecot IMAP и POP3, а также Postfix SMTP) в режиме SSL. Они работают на двух отдельных серверах Debian 6.ß squeeze с идентичной конфигурацией и идентичными сертификатами SSL, которые являются сертификатами с подстановочными знаками RapidSSL. Конфигурация работала очень хорошо более 2 лет и в последнее время вообще не менялась. Могу только сказать, что в конце декабря я обновил и поэтому обновил сертификаты 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
Я отчаянно пытаюсь понять, что происходит. Это проблема, связанная с моим новым сертификатом? Это проблема с новейшей библиотекой openssl с обновленной безопасностью от debian? Я перезагрузил компьютер, дважды проверил правильность сертификатов, отключил брандмауэр, все это ничего не помогло ... Самое странное - это полная случайность такого поведения: проблема проявляется только у некоторых пользователей / клиентов, плюс иногда она работает для их тоже. Очень странно...
Все свидетельства указывают на проблему на стороне клиента, поэтому я просто оставлю это как есть.
Дополнительная информация:
В соответствии с эта страница, есть 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.
Согласно maillog, "ритуал" прерван клиентом после шага 4.
Чтобы понять, что произошло на самом деле, вы должны запустить tcpdump на стороне сервера и сравнить успешный случай с неудачным.
Еще один дополнительный шаг: включить подробное описание 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 сбросит все необходимое.