Panic: file auth-request.c

Sun Sep 18 06:06:20 UTC 2016

> On September 17, 2016 at 9:15 PM Chris Wik <chris at 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/6c969ac21a43cc10ee1f1a91a4f39e4864c886cb

Aki Tuomi
Dovecot oy