------- You are receiving this mail because: -------
You are on the CC list for the bug.
http://bugs.exim.org/show_bug.cgi?id=1512
Summary: dovecot authenticator waits for server's DONE before
sending DATA
Product: Exim
Version: 4.83
Platform: Other
URL: http://bugs.debian.org/756258
OS/Version: Linux
Status: NEW
Severity: bug
Priority: medium
Component: SMTP Authentication
AssignedTo: pdp@???
ReportedBy: eximusers@???
CC: exim-dev@???
Hello,
this is <
http://bugs.debian.org/756258> as submitted by Mildred Ki'Lya:
<Quote>
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).
<Unquote>
In a later message Mildred confirmed that the problem was still present in
4.83.
--
Configure bugmail:
http://bugs.exim.org/userprefs.cgi?tab=email
