On September 17, 2016 at 9:15 PM Chris Wik chris@anu.net wrote:
Hello Dovecot list,
We've been running a really old CentOS 5 server with the stock dovecot from yum (1.0.7) for years and years with absolutely no problems. If it ain't broke, don't fix it, or something like that.
Well it finally broke, but only due to the server no longer being able to handle the load of the increasing user base (many thousands now, with hundreds of concurrent IMAP connections any any given time)
So we upgraded to a new CentOS 7 server with SSD RAID, fast CPUs and tons of RAM. No more load problems. We compiled the latest dovecot from source (as the version from CentOS yum repo is already quite old, figure we might as well run the latest version since we were upgrading anyway).
Thanks to excellent documentation on dovecot.org and fairly thorough testing, the upgrade was quite smooth. We kept all the message UUIDs intact and tried to match the supported authentication methods etc to the old setup, and we didn't have any problems with clients re-downloading or re-syncing mail.
We do however have one problem, which prompted me to join this list. It is the same problem as described in this thread from last month: http://dovecot.org/list/dovecot/2016-July/104899.html
Here's the excerpt from our maillog:
Sep 17 19:34:57 mail dovecot: auth: Panic: file auth-request.c: line 1049 (auth_request_lookup_credentials): assertion failed: (request->credentials_scheme == scheme) Sep 17 19:34:57 mail dovecot: auth: Error: Raw backtrace: /usr/local/lib/dovecot/libdovecot.so.0(+0x89470) [0x7fa9cb8af470] -> /usr/local/lib/dovecot/libdovecot.so.0(+0x8954e) [0x7fa9cb8af54e] -> /usr/local/lib/dovecot/libdovecot.so.0(i_fatal+0) [0x7fa9cb851f75] -> dovecot/auth() [0x4165bc] -> dovecot/auth() [0x4221fb] -> dovecot/auth() [0x41620b] -> dovecot/auth(auth_request_lookup_credentials_callback+0x58) [0x4162f8] -> dovecot/auth(passdb_handle_credentials+0x6a) [0x4254ba] -> dovecot/auth() [0x425b62] -> dovecot/auth() [0x41c1f8] -> /usr/local/lib/dovecot/libdovecot.so.0(io_loop_call_io+0x4c) [0x7fa9cb8c207c] -> /usr/local/lib/dovecot/libdovecot.so.0(io_loop_handler_run_internal+0xd7) [0x7fa9cb8c3377] -> /usr/local/lib/dovecot/libdovecot.so.0(io_loop_handler_run+0x25) [0x7fa9cb8c2105] -> /usr/local/lib/dovecot/libdovecot.so.0(io_loop_run+0x38) [0x7fa9cb8c22b8] -> /usr/local/lib/dovecot/libdovecot.so.0(master_service_run+0x13) [0x7fa9cb857f33] -> dovecot/auth(main+0x2eb) [0x40ccdb] -> /lib64/libc.so.6(__libc_start_main+0xf5) [0x7fa9c9dc2b15] -> dovecot/auth() [0x40cf15]
On the client side, it manifests as an authentication failure, and the user is prompted to re-enter their password. The reports we've had are all from users who have their passwords saved in a local password manager, so the client is definitely sending the correct password. It's not related to a particular mail client. It is also definitely not related to the particular user or password, as the user will authenticate many times successfully and then (seemingly) randomly be hit by this bug and prompted to re-enter their password.
We enabled verbose logging and even logging of passwords for failed authentication attempts in an attempt to find a pattern, but so far we have not found one.
Similar to the original poster in the above thread, we are using a MySQL backend, and CentOS 7 on x86_64
It happens quite frequently: in the past 6 days it happened 49175 times, according to a grep of the maillog. In the same period there were 294167 successful IMAP logins and 160322 POP3 logins.
For now we have downgraded to 2.2.4 and so far have not seen the crash recorded in the maillog.
What can we do to help track down and fix this bug?
# dovecot -n # 2.2.24 (a82c823): /usr/local/etc/dovecot/dovecot.conf # OS: Linux 3.10.0-327.28.3.el7.x86_64 x86_64 CentOS Linux release 7.2.1511 (Core) ext4 auth_debug = yes auth_debug_passwords = yes auth_mechanisms = plain login digest-md5 cram-md5 ntlm rpa apop auth_verbose = yes auth_verbose_passwords = plain debug_log_path = /var/log/dovecot-debug.log default_client_limit = 5000 default_process_limit = 1000 disable_plaintext_auth = no first_valid_uid = 89 mail_debug = yes mail_fsync = never mail_gid = 89 mail_location = maildir:/var/virtual/%d/%n mail_uid = 89 namespace inbox { inbox = yes location = mailbox Drafts { special_use = \Drafts } mailbox Junk { special_use = \Junk } mailbox Sent { special_use = \Sent } mailbox "Sent Messages" { special_use = \Sent } mailbox Trash { special_use = \Trash } prefix = } passdb { args = /usr/local/etc/dovecot/dovecot-sql.conf.ext driver = sql } pop3_client_workarounds = outlook-no-nuls oe-ns-eoh service auth { unix_listener /var/spool/postfix/private/auth { group = postfix mode = 0660 user = postfix } } ssl_ca = <*** ssl_cert = <*** ssl_key = <*** userdb { args = /usr/local/etc/dovecot/dovecot-sql.conf.ext driver = sql } verbose_ssl = yes protocol lmtp { mail_fsync = optimized } protocol lda { mail_fsync = optimized } protocol imap { mail_max_userip_connections = 50 } protocol pop3 { mail_max_userip_connections = 20 }
Chris Wik Anu Internet Services www.anu.net | www.cwik.ch
Hi!
This has been fixed with https://github.com/dovecot/core/commit/6c969ac21a43cc10ee1f1a91a4f39e4864c88...
Aki Tuomi Dovecot oy