--- Begin Message ---
Package: exim4
Version: 4.80-7
Severity: important
Dear Maintainer,
This is probably an upstream bug.
When exim4 is configured with dovecot authenticator, it blocks at some point,
apparently expecting some information from dovecot. Dovecot on its side is
expecting additional information from exim. None of the two parties move
forward and exim do not respond to the SMTp client. After some unspecified
time, the MUA terminates the connection, because no response is sent from the
server.
Exim is configured with:
begin authenticators
dovecot_plain:
driver = dovecot
public_name = PLAIN
server_socket = /var/run/dovecot/auth-userdb
server_set_id = $auth1
dovecot_login:
driver = dovecot
public_name = LOGIN
server_socket = /var/run/dovecot/auth-userdb
server_set_id = $auth1
Dovecot configuration is left as default. It is:
service auth {
unix_listener auth-userdb {}
}
Both daemons in full debug mode (-d+all for exim and auth_verbose,
auth_verbose_passwords, auth_debug, auth_debug_passwords activated in dovecot).
The last debug log from exim is:
@4000000053d5e25003272ac4 05:40:22 61 SMTP<< EHLO toto
@4000000053d5e250032853a4 05:40:22 61 toto in helo_lookup_domains? no (end
of list)
@4000000053d5e25003292694 05:40:22 61 sender_fullhost = (toto) [172.17.42.1]
@4000000053d5e250032a0d0c 05:40:22 61 sender_rcvhost = [172.17.42.1]
(helo=toto)
@4000000053d5e250032ad82c 05:40:22 61 set_process_info: 61 handling
incoming connection from (toto) [172.17.42.1]
@4000000053d5e250032baf04 05:40:22 61 host in pipelining_advertise_hosts?
yes (matched "*")
@4000000053d5e250032c6a84 05:40:22 61 host in auth_advertise_hosts? yes
(matched "*")
@4000000053d5e250032d2dd4 05:40:22 61 host in tls_advertise_hosts? yes
(matched "*")
@4000000053d5e250032df8f4 05:40:22 61 SMTP>> 250-4a5b0a328ab7 Hello toto
[172.17.42.1]
@4000000053d5e250032df8f4 05:40:22 61 250-SIZE 52428800
@4000000053d5e250032dfcdc 05:40:22 61 250-8BITMIME
@4000000053d5e250032dfcdc 05:40:22 61 250-PIPELINING
@4000000053d5e250032dfcdc 05:40:22 61 250-AUTH PLAIN LOGIN
@4000000053d5e250032dfcdc 05:40:22 61 250-STARTTLS
@4000000053d5e250032e00c4 05:40:22 61 250 HELP
@4000000053d5e26322f6eb8c 05:40:41 61 SMTP<< AUTH PLAIN
AG1AbWFpbHRlc3QubWlsZHJlZC5mcgAxMjM=
@4000000053d5e26322f7d204 05:40:41 61 dovecot authentication
@4000000053d5e26322fe8cac 05:40:41 61 received: VERSION 1 1
@4000000053d5e26322ff6b54 05:40:41 61 received: SPID 48
(no debug log from dovecot at this point)
Running strace on exim leads to the following output for the AUTH PLAIN command:
[pid 10113] read(10, "AUTH PLAIN AG1AbWFpbHRlc3QubWlsZ"..., 8192) = 48
[pid 10113] alarm(0) = 288
[pid 10113] rt_sigaction(SIGALRM, {0x7fb417616690, [], SA_RESTORER,
0x7fb414d17030}, NULL, 8) = 0
[pid 10113] stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=118, ...}) = 0
[pid 10113] write(2, "05:40:41 61 SMTP<< AUTH PLAIN"..., 70) = 70
[pid 10113] stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=118, ...}) = 0
[pid 10113] write(2, "05:40:41 61 dovecot authentic"..., 38) = 38
[pid 10113] socket(PF_LOCAL, SOCK_STREAM, 0) = 3
[pid 10113] connect(3, {sa_family=AF_LOCAL,
sun_path="/var/run/dovecot/auth-userdb"}, 110) = 0
[pid 10113] read(3, "VERSION\t1\t1\nSPID\t48\n", 256) = 20
[pid 10113] stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=118, ...}) = 0
[pid 10113] write(2, "05:40:41 61 received: VERSION"..., 37) = 37
[pid 10113] stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=118, ...}) = 0
[pid 10113] write(2, "05:40:41 61 received: SPID\t48"..., 33) = 33
[pid 10113] read(3,
(blocked)
strace for dovecot auth process shows:
epoll_wait(13, {{EPOLLIN, {u32=967924496, u64=140021196741392}}}, 12, -1) = 1
accept(10, {sa_family=AF_LOCAL, NULL}, [2]) = 19
fcntl(19, F_GETFL) = 0x2 (flags O_RDWR)
fcntl(19, F_SETFL, O_RDWR|O_NONBLOCK) = 0
write(5, "0\0\0\0\5\0\0\0\345\3\0\0", 12) = 12
fstat(19, {st_mode=S_IFSOCK|0777, st_size=0, ...}) = 0
lseek(19, 0, SEEK_CUR) = -1 ESPIPE (Illegal seek)
getsockname(19, {sa_family=AF_LOCAL,
sun_path="/var/run/dovecot/auth-userY\177"}, [31]) = 0
epoll_ctl(13, EPOLL_CTL_ADD, 19, {EPOLLIN|EPOLLPRI|EPOLLERR|EPOLLHUP,
{u32=967948080, u64=140021196764976}}) = 0
write(19, "VERSION\t1\t1\nSPID\t48\n", 20) = 20
getsockopt(19, SOL_SOCKET, SO_PEERCRED, {pid=61, uid=103, gid=104}, [12]) = 0
epoll_wait(13,
(blocked)
We deduce the following AUTH protocol log:
exim connects to dovecot auth
dovecot VERSION 1 1
dovecot SPID 48
According to <http://wiki2.dovecot.org/Design/AuthProtocol>, the protocol log
should start with the client (exim here) issuing the VERSION and CPID commands.
Dovecot should then reply with VERSION, SPID, CUID, COOKIE, MECH and DONE.
Unfortunately, according to exim code (src/auths/dovecot.c around line 220),
exim waits the DONE from dovecot to send VERSION and CPID. I believe exim is
wrong here.
exim version: 4.80 (debconf not used at all)
dovecot version: 2.1.7
Note: I have another server running successfully in this configuration. The
auth protocol log (found using strace again) is:
exim connects to dovecot auth
dovecot VERSION 1 1
dovecot MECH PLAIN plaintext
dovecot SPID 10905
dovecot CUID 1
dovecot COOKIE d3861d29441f06d962490eab8549fd46
dovecot DONE
exim VERSION 1 0
exim CPID 10619
exim AUTH 1 PLAIN service=smtp secured
rip=82.247.184.53 lip=80.67.179.36 nologin resp=<base64 encoded
string>
Dovecot is version 2.1.17, but it worked with earler versions. Exim is version
4.80
In any case, relying to the fact that the auth server will send its handshake
first is wrong as it doesn't seem to be always the case (and the documentation
says that the client is to start the handshake).
-- Package-specific info:
Exim version 4.80 #2 built 02-Jan-2013 18:59:17
Copyright (c) University of Cambridge, 1995 - 2012
(c) The Exim Maintainers and contributors in ACKNOWLEDGMENTS file, 2007 - 2012
Berkeley DB: Berkeley DB 5.1.29: (October 25, 2011)
Support for: crypteq iconv() IPv6 PAM Perl Expand_dlfunc GnuTLS
move_frozen_messages Content_Scanning DKIM Old_Demime
Lookups (built-in): lsearch wildlsearch nwildlsearch iplsearch cdb dbm dbmjz
dbmnz dnsdb dsearch ldap ldapdn ldapm mysql nis nis0 passwd pgsql sqlite
Authenticators: cram_md5 cyrus_sasl dovecot plaintext spa
Routers: accept dnslookup ipliteral iplookup manualroute queryprogram redirect
Transports: appendfile/maildir/mailstore/mbx autoreply lmtp pipe smtp
Fixed never_users: 0
Size of off_t: 8
Configuration file is /var/lib/exim4/config.autogenerated
# /etc/exim4/update-exim4.conf.conf
#
# Edit this file and /etc/mailname by hand and execute update-exim4.conf
# yourself or use 'dpkg-reconfigure exim4-config'
#
# Please note that this is _not_ a dpkg-conffile and that automatic changes
# to this file might happen. The code handling this will honor your local
# changes, so this is usually fine, but will break local schemes that mess
# around with multiple versions of the file.
#
# update-exim4.conf uses this file to determine variable values to generate
# exim configuration macros for the configuration file.
#
# Most settings found in here do have corresponding questions in the
# Debconf configuration, but not all of them.
#
# This is a Debian specific file
dc_eximconfig_configtype='local'
dc_other_hostnames='153560522c87'
dc_local_interfaces='127.0.0.1 ; ::1'
dc_readhost=''
dc_relay_domains=''
dc_minimaldns='false'
dc_relay_nets=''
dc_smarthost=''
CFILEMODE='644'
dc_use_split_config='false'
dc_hide_mailname=''
dc_mailname_in_oh='true'
dc_localdelivery='mail_spool'
mailname:153560522c87
-- System Information:
Debian Release: 7.5
APT prefers stable-updates
APT policy: (500, 'stable-updates'), (500, 'stable')
Architecture: amd64 (x86_64)
Kernel: Linux 3.15.5-1-ARCH (SMP w/8 CPU cores; PREEMPT)
Locale: LANG=C, LC_CTYPE=C (charmap=ANSI_X3.4-1968)
Shell: /bin/sh linked to /bin/dash
Versions of packages exim4 depends on:
ii debconf [debconf-2.0] 1.5.49
ii exim4-base 4.80-7
ii exim4-daemon-heavy 4.80-7
exim4 recommends no packages.
exim4 suggests no packages.
-- debconf information excluded
--- End Message ---
