doveconf -n and postconf -n output might shed some light?

On 2013-07-19 11:11 AM, Peer Heinlein <p.heinlein@heinlein-support.de> wrote:

Hi,

looks like we detected a serious bug in dovecot's lmtp proxying where e-mails are delivered to the wrong user.

The setup is:

*) Dovecot is configured with "lmtp_proxy=yes"

Support proxying to other LMTP/SMTP servers by performing passdb lookups.

lmtp_proxy = yes

*) Postfix uses "dynamic recipient verification", so Postfix starts sending a (verify) mail by LMTP to dovecot, but quits the lmtp-session right after the RCPT TO:. No DATA-stage is reached in the protocol and no real e-mail is sent. But Postfix had a LMTP-connection for "user1".

*) Just some seconds later a "real" e-mail to "user2" has to be delivered to dovecot by LMTP. But Dovecot will deliver this mail to the wrong "user1" instead of "user2". Looks like dovecot re-uses the (still opened?) lmtp-proxy-connection from "user1" to deliver an e-mail to "user2".

Have a log at the protocol:

1. There's a verify call to user1 from Postfix:

Jul 19 13:49:49 mailms postfix/lmtp[9842]: DE653280C51: to=<user1@example.com>, relay=localhost[127.0.0.1]:24, conn_use=2, delay=120, delays=117/0.45/0/2.5, dsn=2.1.5, status=deliverable (250 2.1.5 OK)

2. Just five seconds later the e-mail to user2 (see Postfix' point of view in the last line) is delivered to user2 (see result from Dovecot in the last line):

Jul 19 13:50:04 mailms dovecot: lmtp(10965, kraemer): save: box=INBOX, uid=49880, msgid=<59798276-E5D1-4053-A570-9901B731DF5D@example.come>, size=11020 Jul 19 13:50:04 mailms dovecot: lmtp(10965, kraemer): 1zTeKrMn6VHVKgAAhyqEuA: msgid=<59798276-E5D1-4053-A570-9901B731DF5D@example.com>: saved mail to INBOX Jul 19 13:50:04 mailms postfix/lmtp[10953]: C25FC280BE5: to=<user2@example.com>, relay=localhost[127.0.0.1]:24, conn_use=19, delay=116, delays=115/0.53/0/0.33, dsn=2.0.0, status=sent (250 2.0.0 <user2> 1zTeKrMn6VHVKgAAhyqEuA Saved)

Same with user3 and user4:

Jul 19 14:47:53 mailms postfix/lmtp[10845]: C389A2809D7: to=<user3@example.com>, relay=localhost[127.0.0.1]:24, delay=4.7, delays=3.7/0.87/0/0.19, dsn=2.1.5, status=deliverable (250 2.1.5 OK) Jul 19 14:47:55 mailms dovecot: lmtp(26546, fs211113): save: box=INBOX, uid=8504, msgid=<928729810.113.1374238063381@example.com>, size=233151 Jul 19 14:47:55 mailms dovecot: lmtp(26546, fs211113): MbMvI2816VGyZwAAhyqEuA: msgid=<928729810.113.1374238063381@example.com>: saved mail to INBOX Jul 19 14:47:55 mailms postfix/lmtp[22524]: 6F0D2280A6E: to=<user4@example.com>, relay=localhost[127.0.0.1]:24, conn_use=2, delay=10, delays=8.4/1/0/0.8, dsn=2.0.0, status=sent (250 2.0.0 <user3> MbMvI2816VGyZwAAhyqEuA Saved)

The user itself is quite normal in the user database (but has a mailhost=127.0.0.1 set):

root@mailms:/etc/dovecot/conf.d# doveadm user user2@example.com userdb: user2@example.com uid : 5000 gid : 5000 home : /srv/mail/user2

root@mailms:/etc/dovecot/conf.d# doveadm auth user2@example.com Password: passdb: user2@example.com auth failed extra fields: user=user2

Peer

--

Best regards,

Charles Marcus I.T. Director Media Brokers International, Inc. 678.514.6224 | 678.514.6299 fax

On 19.7.2013, at 18.11, Peer Heinlein <p.heinlein@heinlein-support.de> wrote:

looks like we detected a serious bug in dovecot's lmtp proxying where e-mails are delivered to the wrong user.

The setup is:

*) Dovecot is configured with "lmtp_proxy=yes"

Support proxying to other LMTP/SMTP servers by performing passdb lookups.

lmtp_proxy = yes

*) Postfix uses "dynamic recipient verification", so Postfix starts sending a (verify) mail by LMTP to dovecot, but quits the lmtp-session right after the RCPT TO:. No DATA-stage is reached in the protocol and no real e-mail is sent. But Postfix had a LMTP-connection for "user1".

*) Just some seconds later a "real" e-mail to "user2" has to be delivered to dovecot by LMTP. But Dovecot will deliver this mail to the wrong "user1" instead of "user2". Looks like dovecot re-uses the (still opened?) lmtp-proxy-connection from "user1" to deliver an e-mail to "user2".

As others mentioned, seeing what Postfix <-> Dovecot (and Dovecot proxy <-> Dovecot backend) talk to each others would help. I can't reproduce this in an easy way and the code looks correct also: All proxied connections are dropped on LHLO and RSET. The proxy connections also aren't being reused between different incoming LMTP connections.