Panic: file auth-request.c

[Chris Wik]

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