dovecot - Mar 2012 - 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

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]
Fixed: http://hg.dovecot.org/dovecot-2.1/rev/339b1337aab0