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 <[email protected]> wrote:

> On 15.11.2013, at 00:56, Timo Sirainen <[email protected]> wrote:
>> On 15.11.2013, at 0.52, Michael Grimm <[email protected]> wrote:
>>> On 15.11.2013, at 00:35, Timo Sirainen <[email protected]> wrote:
>>>> On 15.11.2013, at 0.25, Michael Grimm <[email protected]> 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 <[email protected]>
>       |# 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 <mail.info> 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=<[email protected]>
> postfix/qmgr[64303]: 3dLKn10bdfzFNF: from=<[email protected]>, 
> 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=<[email protected]>, 
> orig_to=<[email protected]>, 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.info> mail.example.invalid postfix/smtpd[66223]: 
> 3dLKn40f9wzFNG: client=example.org[10.100.100.200]
> Nov 15 01:14:32 <mail.info> mail.example.invalid postfix/cleanup[66227]: 
> 3dLKn40f9wzFNG: message-id=<[email protected]>
> Nov 15 01:14:32 <mail.info> example.org sendmail[66221]: rAF0ETps066221: 
> [email protected], 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.info> mail.example.invalid postfix/qmgr[64303]: 
> 3dLKn40f9wzFNG: from=<[email protected]>, size=616, nrcpt=1 (queue active)
> Nov 15 01:14:32 <mail.info> mail.example.invalid postfix/smtpd[66223]: 
> disconnect from example.org[10.100.100.200]
> Nov 15 01:14:32 <mail.info> mail.example.invalid amavis[66086]: (66086-01) 
> loaded policy bank "MYNETS"
> Nov 15 01:14:32 <mail.info> mail.example.invalid amavis[66086]: (66086-01) 
> LMTP::10024 /var/amavis/tmp/amavis-20131115T011432-66086-mM3ZSPVh: 
> <[email protected]> -> <[email protected]> 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 
> <[email protected]>; Fri, 15 Nov 2013 01:14:32 +0100 (CET)
> Nov 15 01:14:32 <mail.info> mail.example.invalid amavis[66086]: (66086-01) 
> Checking: CYYtr0l_C3qa MYNETS [10.100.100.200] <[email protected]> -> 
> <[email protected]>
> Nov 15 01:14:32 <mail.info> mail.example.invalid amavis[66086]: (66086-01) 
> p001 1 Content-Type: text/plain, size: 3 B, name:
> Nov 15 01:14:32 <mail.info> mail.example.invalid amavis[66086]: (66086-01) 
> wbl: whitelisted sender <[email protected]>
> Nov 15 01:14:32 <mail.info> mail.example.invalid amavis[66086]: (66086-01) 
> spam-tag, <[email protected]> -> <[email protected]>, No, score=x 
> tagged_above=-999 required=6.2 WHITELISTED tests=[] autolearn=unavailable
> Nov 15 01:14:32 <mail.info> mail.example.invalid postfix/smtpd[66232]: 
> connect from mail.example.invalid[10.100.100.1]
> Nov 15 01:14:32 <mail.info> 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.info> mail.example.invalid postfix/cleanup[66227]: 
> 3dLKn42SQHzFNR: message-id=<[email protected]>
> Nov 15 01:14:32 <mail.info> mail.example.invalid postfix/qmgr[64303]: 
> 3dLKn42SQHzFNR: from=<[email protected]>, size=1266, nrcpt=1 (queue active)
> Nov 15 01:14:32 <mail.info> mail.example.invalid amavis[66086]: (66086-01) 
> FWD from <[email protected]> -> <[email protected]>,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.info> mail.example.invalid dovecot: lmtp(66091): 
> Connect from local
> Nov 15 01:14:32 <mail.info> mail.example.invalid dovecot: lmtp(66091, 
> localuser): copy from <lmtp DATA>: box=INBOX, uid=475527, 
> msgid=<[email protected]>, flags=()
> Nov 15 01:14:32 <mail.info> mail.example.invalid dovecot: lmtp(66091, 
> localuser): QoteB2VnhVIrAgEASjbbSg: sieve: 
> msgid=<[email protected]>: stored mail into mailbox 
> 'INBOX'
> Nov 15 01:14:32 <mail.info> mail.example.invalid postfix/lmtp[66228]: 
> 3dLKn42SQHzFNR: to=<[email protected]>, 
> 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 <[email protected]> 
> QoteB2VnhVIrAgEASjbbSg Saved)
> Nov 15 01:14:32 <mail.info> mail.example.invalid dovecot: lmtp(66091): 
> Disconnect from local: Successful quit
> Nov 15 01:14:32 <mail.info> mail.example.invalid postfix/qmgr[64303]: 
> 3dLKn42SQHzFNR: removed
> Nov 15 01:14:32 <mail.notice> mail.example.invalid amavis[66086]: (66086-01) 
> Passed CLEAN {RelayedInternal}, MYNETS LOCAL [10.100.100.200]:40204 
> [10.100.100.200] <[email protected]> -> <[email protected]>, Queue-ID: 
> 3dLKn40f9wzFNG, Message-ID: <[email protected]>, 
> mail_id: CYYtr0l_C3qa, Hits: -, size: 608, queued_as: 3dLKn42SQHzFNR, 290 ms
> Nov 15 01:14:32 <mail.info> mail.example.invalid postfix/lmtp[66230]: 
> 3dLKn40f9wzFNG: to=<[email protected]>, orig_to=<[email protected]>, 
> 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.info> mail.example.invalid postfix/qmgr[64303]: 
> 3dLKn40f9wzFNG: removed
> 
> HTH,
> Michael
> 

Reply via email to