[Dovecot] Dovecot IMAP is broken after upgrade from 2.1.2 to 2.1.3
Hello,
I just upgraded my servers from Dovecot 2.1.2 to Dovecot 2.1.3-0~auto+5 by using Debian binaries from "http://xi.rename-it.nl/debian/ stable-auto/dovecot-2.1 main".
The config was not touched but now IMAP connections are not possible anymore (LMTP works fine). When I try to connect to a mailbox, the connect fails.
Some log entries:
###############################################################################################################
Mar 23 21:45:28 imap-login: Warning: SSL: where=0x10, ret=1:
before/accept initialization [xxx.xxx.xxx.xxx]
Mar 23 21:45:28 imap-login: Warning: SSL: where=0x2001, ret=1:
before/accept initialization [xxx.xxx.xxx.xxx]
Mar 23 21:45:28 imap-login: Warning: SSL: where=0x2002, ret=-1: SSLv2/v3
read client hello A [xxx.xxx.xxx.xxx]
Mar 23 21:45:28 auth: Debug: auth client connected (pid=3431)
Mar 23 21:45:28 imap-login: Warning: SSL: where=0x2001, ret=1: SSLv3
read client hello A [xxx.xxx.xxx.xxx]
Mar 23 21:45:28 imap-login: Warning: SSL: where=0x2001, ret=1: SSLv3
write server hello A [xxx.xxx.xxx.xxx]
Mar 23 21:45:28 imap-login: Warning: SSL: where=0x2001, ret=1: SSLv3
write certificate A [xxx.xxx.xxx.xxx]
Mar 23 21:45:28 imap-login: Warning: SSL: where=0x2001, ret=1: SSLv3
write key exchange A [xxx.xxx.xxx.xxx]
Mar 23 21:45:28 imap-login: Warning: SSL: where=0x2001, ret=1: SSLv3
write server done A [xxx.xxx.xxx.xxx]
Mar 23 21:45:28 imap-login: Warning: SSL: where=0x2001, ret=1: SSLv3
flush data [xxx.xxx.xxx.xxx]
Mar 23 21:45:28 imap-login: Warning: SSL: where=0x2002, ret=-1: SSLv3
read client certificate A [xxx.xxx.xxx.xxx]
Mar 23 21:45:28 imap-login: Warning: SSL: where=0x2002, ret=-1: SSLv3
read client certificate A [xxx.xxx.xxx.xxx]
Mar 23 21:45:28 imap-login: Warning: SSL: where=0x2001, ret=1: SSLv3
read client key exchange A [xxx.xxx.xxx.xxx]
Mar 23 21:45:28 imap-login: Warning: SSL: where=0x2001, ret=1: SSLv3
read finished A [xxx.xxx.xxx.xxx]
Mar 23 21:45:28 imap-login: Warning: SSL: where=0x2001, ret=1: SSLv3
write session ticket A [xxx.xxx.xxx.xxx]
Mar 23 21:45:28 imap-login: Warning: SSL: where=0x2001, ret=1: SSLv3
write change cipher spec A [xxx.xxx.xxx.xxx]
Mar 23 21:45:28 imap-login: Warning: SSL: where=0x2001, ret=1: SSLv3
write finished A [xxx.xxx.xxx.xxx]
Mar 23 21:45:28 imap-login: Warning: SSL: where=0x2001, ret=1: SSLv3
flush data [xxx.xxx.xxx.xxx]
Mar 23 21:45:28 imap-login: Warning: SSL: where=0x20, ret=1: SSL
negotiation finished successfully [xxx.xxx.xxx.xxx]
Mar 23 21:45:28 imap-login: Warning: SSL: where=0x2002, ret=1: SSL
negotiation finished successfully [xxx.xxx.xxx.xxx]
Mar 23 21:45:28 auth: Debug: client in: AUTH 1 PLAIN
service=imap secured lip=yyy.yyy.yyy.yyy rip=xxx.xxx.xxx.xxx
lport=993 rport=51379
Mar 23 21:45:28 auth: Debug: client out: CONT 1
Mar 23 21:45:28 auth: Debug: client in: CONT 1
AG5lbWlAdmlzaXQtd29ybGQuZGUAUHJvNDUwLnN1
Mar 23 21:45:28 auth-worker(3433): Debug: Loading modules from
directory: /usr/lib/dovecot/modules/auth
Mar 23 21:45:28 auth-worker(3433): Debug: Module loaded:
/usr/lib/dovecot/modules/auth/libdriver_mysql.so
Mar 23 21:45:28 auth-worker(3433): Info: mysql(zzz.zzz.zzz.zzz):
Connected to database dovecot
Mar 23 21:45:28 auth-worker(3433): Debug: sql(username,xxx.xxx.xxx.xxx):
query: SELECT password, 'directory' AS userdb_home, 'mail' AS
userdb_uid, 'mail' AS userdb_gid FROM users WHERE username = 'username'
AND domain = 'domain' AND active = 'Y'
Mar 23 21:45:28 auth: Debug: client out: OK 1 user=username
Mar 23 21:45:28 auth: Debug: master in: REQUEST 2286813185 3394
1 4727968fd3514dd45f623ad9f944e305
Mar 23 21:45:28 auth-worker(3433): Debug: sql(username,xxx.xxx.xxx.xxx):
SELECT home, uid, gid FROM users WHERE username = 'username' AND domain
= 'domain'
Mar 23 21:45:28 auth: Debug: master out: USER 2286813185
username home=directory uid=8 gid=8
Mar 23 21:45:28 imap-login: Info: Login: user=<username>, method=PLAIN,
rip=xxx.xxx.xxx.xxx, lip=yyy.yyy.yyy.yyy, mpid=3434, TLS
Mar 23 21:45:28 imap-login: Warning: SSL alert: where=0x4008, ret=256:
warning close notify [xxx.xxx.xxx.xxx]
Mar 23 21:45:28 imap(username): Info: Connection closed in=0 out=303
###############################################################################################################
The MySQL authentification seems to work fine, but after this the connection is closed with the SSL alert. In Dovecot 2.1.2 everything worked fine. The SSL certifcate is also correct.
Any hints are welcome to identify the problem. Thanks in advance.
Beste wishes Michael
The problem starts just after authorization:
Console:
################################################################### openssl s_client -connect mailserver.com:993
- OK [CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE IDLE AUTH=PLAIN] Dovecot ready. a login "username" "password" closed ###################################################################
Here are the logs of this moment:
################################################################### Mar 24 13:48:46 imap-login: Info: Login: user=<username>, method=PLAIN, rip=xxx.xxx.xxx.xxx, lip=yyy.yyy.yyy.yyy, mpid=10662, TLS Mar 24 13:48:46 imap-login: Warning: SSL alert: where=0x4008, ret=256: warning close notify [xxx.xxx.xxx.xxx] Mar 24 13:48:46 imap(username): Info: Connection closed in=0 out=303 ###################################################################
So just after sucussful login with correct username / password the connection is closed.
On 24.3.2012, at 15.04, Michael Neubert wrote:
openssl s_client -connect mailserver.com:993
- OK [CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE IDLE AUTH=PLAIN] Dovecot ready. a login "username" "password" closed
And what happens without SSL? e.g. telnet localhost 143
And what happens without SSL? e.g. telnet localhost 143
Without SSL it is no problem:
############################################## telnet imap-server 143 Trying xxx.xxx.xxx.xxx... Connected to imap-server. Escape character is '^]'.
- OK [CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE IDLE STARTTLS AUTH=PLAIN] Dovecot ready. a login "username" "password" a OK [CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE IDLE SORT SORT=DISPLAY THREAD=REFERENCES THREAD=REFS MULTIAPPEND UNSELECT CHILDREN NAMESPACE UIDPLUS LIST-EXTENDED I18NLEVEL=1 CONDSTORE QRESYNC ESEARCH ESORT SEARCHRES WITHIN CONTEXT=SEARCH LIST-STATUS SPECIAL-USE QUOTA] Logged in b select inbox
- FLAGS (\Answered \Flagged \Deleted \Seen \Draft nonjunk $Forwarded)
- OK [PERMANENTFLAGS (\Answered \Flagged \Deleted \Seen \Draft nonjunk $Forwarded \*)] Flags permitted [...] ##############################################
On 23.3.2012, at 22.57, Michael Neubert wrote:
I just upgraded my servers from Dovecot 2.1.2 to Dovecot 2.1.3-0~auto+5 by using Debian binaries from "http://xi.rename-it.nl/debian/ stable-auto/dovecot-2.1 main".
So what exactly is this version? dovecot --version?
I just upgraded my servers from Dovecot 2.1.2 to Dovecot 2.1.3-0~auto+5 by using Debian binaries from "http://xi.rename-it.nl/debian/ stable-auto/dovecot-2.1 main". So what exactly is this version? dovecot --version?
At the moment the version is "2.1.3-0~auto+6" from rename-it.nl.
dovecot -n: # 2.1.3 (4ae85f573c93): /etc/dovecot/dovecot.conf # OS: Linux 2.6.32-5-amd64 x86_64 Debian 6.0.4 ocfs2
I just did some more tests with different binaries.
The problem occurs since:
Dovecot 2.1.3-0~auto+5 dovecot --version 2.1.3 (f30437ed63dc)
Dovecot 2.1.3-0~auto+4 works fine dovecot --version 2.1.3 (ff5c341f8838)
So my title is wrong. The problem only affects people "who like to live on the edge" of 2.1.3 release ;)
The stable Dovecot 2.1.3 release http://dovecot.org/list/dovecot-news/2012-March/000219.html is not affected.
On 23.3.2012, at 22.57, Michael Neubert wrote:
I just upgraded my servers from Dovecot 2.1.2 to Dovecot 2.1.3-0~auto+5 by using Debian binaries from "http://xi.rename-it.nl/debian/ stable-auto/dovecot-2.1 main".
Mar 23 21:45:28 imap-login: Warning: SSL alert: where=0x4008, ret=256: warning close notify [xxx.xxx.xxx.xxx]
participants (2)
-
Michael Neubert
-
Timo Sirainen