Maybe http://hg.dovecot.org/dovecot-2.2/rev/5f946b807706 solves this also? I’m not sure why it started happening with v2.2.7 though.
On 15.11.2013, at 2.31, Michael Grimm trashcan@odo.in-berlin.de wrote:
On 15.11.2013, at 00:56, Timo Sirainen tss@iki.fi wrote:
On 15.11.2013, at 0.52, Michael Grimm trashcan@odo.in-berlin.de wrote:
On 15.11.2013, at 00:35, Timo Sirainen tss@iki.fi wrote:
On 15.11.2013, at 0.25, Michael Grimm trashcan@odo.in-berlin.de wrote:
IMHO, it had been introduced by revision 10c0aae82d0d.
Hmm. What if you get the latest version and just reverse this one change?
How can I achieve that with hg, sorry I am not that familiar with hg. First "hg pull -u" and then?
cd …/dovecot-2.2 hg export 10c0aae82d0d > diff patch -p0 -R < diff
Done, but I had to do answer (-->):
mail> patch -p0 -R < diff Hmm... Looks like a unified diff to me... The text leading up to this was:
|# HG changeset patch |# User Timo Sirainen tss@iki.fi |# Date 1383514035 -7200 |# Sun Nov 03 23:27:15 2013 +0200 |# Node ID 10c0aae82d0dee0b0107c2262db50d5f6984c181 |# Parent 653d5a81a22e73ff91264f7e7277b1c0206574ec |ostream: Mark stream closed before handling its callback to avoid infinite loops. |The callback could call o_stream_copy_error_from_parent(), which in turn |would try to close the same ostream again. | |diff -r 653d5a81a22e -r 10c0aae82d0d src/lib/ostream.c |--- a/src/lib/ostream.c Sun Nov 03 22:04:53 2013 +0200 |+++ b/src/lib/ostream.c Sun Nov 03 23:27:15 2013 +0200
--> File to patch: src/lib/ostream.c Patching file src/lib/ostream.c using Plan A... Hunk #1 succeeded at 46. done
Dovecot v2.2.7 (87ff0023fe79+) starting up. And I can confirm, that again, no status=undeliverable show up.
And was this only with the Postfix user existence check or were LMTP deliveries in general failing?
It had been status=undeliverable, thus mails didn't become delivered in my case. Only after adding "warn_if_reject reject_unverified_recipient" in smtpd_recipient_restrictions they became delivered.
But I think there were two steps: 1) During SMTP RCPT TO, check is mail can be delivered via LMTP RCPT TO, 2) actually deliver mail via LMTP. Where 1) failed (except with warn_if_reject), but 2) succeeded? Where both were basically doing the same thing, except I suppose with some actual difference. Or were the mails really not delivered via LMTP but something else?
I am not sure, if I do understand you correctly. My setup is:
postfix smtpd dovecot/lmtp user authentication postfix --> amavisd amavisd/lmtp --> postfix final deliver by dovecot/lmtp
Here's a log excerpt with v2.2.7 (87ff0023fe79+):
postfix/smtpd[66223]: connect from example.org[10.100.100.200] postfix/smtpd[66223]: Anonymous TLS connection established from example.org[10.100.100.200]: TLSv1 with cipher DHE-RSA-AES256-SHA (256/256 bits) Nov 15 01:14:29
example.org sendmail[66221]: STARTTLS=client, relay=[10.100.100.1], version=TLSv1/SSLv3, verify=FAIL, cipher=DHE-RSA-AES256-SHA, bits=256/256 postfix/cleanup[66227]: 3dLKn10bdfzFNF: message-id=3dLKn10bdfzFNF@mx2.example.com postfix/qmgr[64303]: 3dLKn10bdfzFNF: from=double-bounce@example.com, size=241, nrcpt=1 (queue active) dovecot: lmtp(66091): Connect from local dovecot: lmtp(66091): Disconnect from local: Successful quit postfix/lmtp[66228]: 3dLKn10bdfzFNF: to=localuser@example.com, orig_to=example@example.com, relay=mx2.example.com[private/dovecot-lmtp], delay=0.04, delays=0.02/0/0/0.02, dsn=2.1.5, status=deliverable (250 2.1.5 OK) postfix/qmgr[64303]: 3dLKn10bdfzFNF: removed Nov 15 01:14:32 mail.example.invalid postfix/smtpd[66223]: 3dLKn40f9wzFNG: client=example.org[10.100.100.200] Nov 15 01:14:32 mail.example.invalid postfix/cleanup[66227]: 3dLKn40f9wzFNG: message-id=201311150014.rAF0ETps066221@example.org Nov 15 01:14:32 example.org sendmail[66221]: rAF0ETps066221: to=example@example.com, ctladdr=root (0/0), delay=00:00:03, xdelay=00:00:03, mailer=relay, pri=30047, relay=[10.100.100.1] [10.100.100.1], dsn=2.0.0, stat=Sent (Ok: queued as 3dLKn40f9wzFNG) Nov 15 01:14:32 mail.example.invalid postfix/qmgr[64303]: 3dLKn40f9wzFNG: from=root@example.org, size=616, nrcpt=1 (queue active) Nov 15 01:14:32 mail.example.invalid postfix/smtpd[66223]: disconnect from example.org[10.100.100.200] Nov 15 01:14:32 mail.example.invalid amavis[66086]: (66086-01) loaded policy bank "MYNETS" Nov 15 01:14:32 mail.example.invalid amavis[66086]: (66086-01) LMTP::10024 /var/amavis/tmp/amavis-20131115T011432-66086-mM3ZSPVh: root@example.net -> localuser@example.com SIZE=616 Received: from mx2.example.com ([10.100.100.1]) by mx2.example.com (mx2.example.com [10.100.100.1]) (amavisd-new, port 10024) with LMTP for localuser@example.com; Fri, 15 Nov 2013 01:14:32 +0100 (CET) Nov 15 01:14:32 mail.example.invalid amavis[66086]: (66086-01) Checking: CYYtr0l_C3qa MYNETS [10.100.100.200] root@example.net -> localuser@example.com Nov 15 01:14:32 mail.example.invalid amavis[66086]: (66086-01) p001 1 Content-Type: text/plain, size: 3 B, name: Nov 15 01:14:32 mail.example.invalid amavis[66086]: (66086-01) wbl: whitelisted sender root@example.net Nov 15 01:14:32 mail.example.invalid amavis[66086]: (66086-01) spam-tag, root@example.net -> localuser@example.com, No, score=x tagged_above=-999 required=6.2 WHITELISTED tests=[] autolearn=unavailable Nov 15 01:14:32 mail.example.invalid postfix/smtpd[66232]: connect from mail.example.invalid[10.100.100.1] Nov 15 01:14:32 mail.example.invalid postfix/smtpd[66232]: 3dLKn42SQHzFNR: client=mail.example.invalid[10.100.100.1], orig_queue_id=3dLKn40f9wzFNG, orig_client=example.org[10.100.100.200] Nov 15 01:14:32 mail.example.invalid postfix/cleanup[66227]: 3dLKn42SQHzFNR: message-id=201311150014.rAF0ETps066221@example.org Nov 15 01:14:32 mail.example.invalid postfix/qmgr[64303]: 3dLKn42SQHzFNR: from=root@example.net, size=1266, nrcpt=1 (queue active) Nov 15 01:14:32 mail.example.invalid amavis[66086]: (66086-01) FWD from root@example.net -> localuser@example.com,BODY=7BIT 250 2.0.0 from MTA(smtp:[10.100.100.1]:10025): 250 2.0.0 Ok: queued as 3dLKn42SQHzFNR Nov 15 01:14:32 mail.example.invalid dovecot: lmtp(66091): Connect from local Nov 15 01:14:32 mail.example.invalid dovecot: lmtp(66091, localuser): copy from <lmtp DATA>: box=INBOX, uid=475527, msgid=201311150014.rAF0ETps066221@example.org, flags=() Nov 15 01:14:32 mail.example.invalid dovecot: lmtp(66091, localuser): QoteB2VnhVIrAgEASjbbSg: sieve: msgid=201311150014.rAF0ETps066221@example.org: stored mail into mailbox 'INBOX' Nov 15 01:14:32 mail.example.invalid postfix/lmtp[66228]: 3dLKn42SQHzFNR: to=localuser@example.com, relay=mx2.example.com[private/dovecot-lmtp], delay=0.12, delays=0.02/0/0/0.1, dsn=2.0.0, status=sent (250 2.0.0 localuser@example.com QoteB2VnhVIrAgEASjbbSg Saved) Nov 15 01:14:32 mail.example.invalid dovecot: lmtp(66091): Disconnect from local: Successful quit Nov 15 01:14:32 mail.example.invalid postfix/qmgr[64303]: 3dLKn42SQHzFNR: removed Nov 15 01:14:32 mail.example.invalid amavis[66086]: (66086-01) Passed CLEAN {RelayedInternal}, MYNETS LOCAL [10.100.100.200]:40204 [10.100.100.200] root@example.net -> localuser@example.com, Queue-ID: 3dLKn40f9wzFNG, Message-ID: 201311150014.rAF0ETps066221@example.org, mail_id: CYYtr0l_C3qa, Hits: -, size: 608, queued_as: 3dLKn42SQHzFNR, 290 ms Nov 15 01:14:32 mail.example.invalid postfix/lmtp[66230]: 3dLKn40f9wzFNG: to=localuser@example.com, orig_to=example@example.com, relay=10.100.100.1[10.100.100.1]:10024, delay=3.4, delays=3.1/0/0/0.29, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[10.100.100.1]:10025): 250 2.0.0 Ok: queued as 3dLKn42SQHzFNR) Nov 15 01:14:32 mail.example.invalid postfix/qmgr[64303]: 3dLKn40f9wzFNG: removed HTH, Michael