Problem with OpenSMTPD/Amavisd and mails with multiple recipients.

[Reio Remma]

Hello all!

Finally managed to upgrade our server from QMail to OpenSMTPD/Dovecot. 
After ironing out a few small kinks I'm still left with a problem.

Our mail comes in and is relayed to Amavisd port 10024, then back to 
OpenSMTPD port 10025.

Everything works except when a mail comes in with multiple recipients - 
below are logs.

OpenSMTPD gives an error ("Remote host sent too much data") on the 2nd 
recipient when the mail is coming back from Amavisd.

Both the recipients' mails are delivered, however the 2nd recipient's 
mail is stuck in the queue on both sending and receiving servers.

In a couple of minutes they both work the queue and the 2nd recipient 
ends up  with 3 messages total.

Is there a setting I should change in either OpenSMTPD or Amavisd to 
avoid this?

Thanks!
Reio

Apr  2 15:27:35 host smtpd[3363]: a1ee25494b874d98 smtp event=connected 
address=192.168.1.4 host=sender.example.org
Apr  2 15:27:35 host smtpd[3363]: a1ee25494b874d98 smtp event=starttls 
address=192.168.1.4 host=sender.example.org ciphers="version=TLSv1.2, 
cipher=ECDHE-RSA-AES256-GCM-SHA384, bits=256"
Apr  2 15:27:35 host smtpd[3363]: a1ee25494b874d98 smtp event=message 
address=192.168.1.4 host=sender.example.org msgid=989362f2 
from=<per...@sender.org> to=<recipie...@example.org> size=1911 ndest=1 
proto=ESMTP
Apr  2 15:27:35 host smtpd[3363]: a1ee25494b874d98 smtp event=message 
address=192.168.1.4 host=sender.example.org msgid=989362f2 
from=<per...@sender.org> to=<recipie...@example.org> size=1911 ndest=1 
proto=ESMTP
Apr  2 15:27:35 host smtpd[3363]: a1ee254c29485cd9 mta event=connecting 
address=lmtp://127.0.0.1:10024 host=localhost
Apr  2 15:27:35 host smtpd[3363]: a1ee254c29485cd9 mta event=connected
Apr  2 15:27:36 host smtpd[3363]: a1ee253d696ec8c5 smtp event=message 
address=127.0.0.1 host=localhost msgid=ff083fd6 from=<per...@sender.org> 
to=<recipie...@example.org> size=2349 ndest=1 proto=ESMTP
Apr  2 15:27:36 host smtpd[3363]: a1ee253d696ec8c5 smtp event=message 
address=127.0.0.1 host=localhost msgid=ff083fd6 from=<per...@sender.org> 
to=<recipie...@example.org> size=2349 ndest=1 proto=ESMTP
Apr  2 15:27:36 host dovecot: lmtp(4131): Connect from local
Apr  2 15:27:36 host amavis[3767]: (03767-08) Passed CLEAN 
{RelayedInbound}, [127.0.0.1] <per...@sender.org> -> 
<recipie...@example.org>,<recipie...@example.org>, Message-ID: 
<f24104b0-b461-4ab0-7778-b06e37975...@sender.org>, mail_id: 
nLJzF6CeDChQ, Hits: -3.179, size: 1947, queued_as: 250 2.0.0: ff083fd6 
Message accepted for delivery, 702 ms
Apr  2 15:27:36 host dovecot: lmtp(4136): Connect from local
Apr  2 15:27:36 host smtpd[3363]: a1ee254c29485cd9 mta event=delivery 
evpid=989362f2561abf5b from=<per...@sender.org> 
to=<recipie...@example.org> rcpt=<-> source="127.0.0.1" relay="127.0.0.1 
(localhost)" delay=1s result="Ok" stat="250 2.0.0 from 
MTA(smtp:[127.0.0.1]:10025): 250 2.0.0: ff083fd6 Message accepted for 
delivery"
Apr  2 15:27:36 host smtpd[3363]: smtp-out: Error on session 
a1ee254c29485cd9 after 1 message sent: Remote host sent too much data
Apr  2 15:27:36 host smtpd[3363]: a1ee254c29485cd9 mta event=delivery 
evpid=989362f25851fa3e from=<per...@sender.org> 
to=<recipie...@example.org> rcpt=<-> source="127.0.0.1" relay="127.0.0.1 
(localhost)" delay=1s result="TempFail" stat="Remote host sent too much 
data"
Apr  2 15:27:36 host smtpd[3363]: a1ee253d696ec8c5 smtp event=closed 
address=127.0.0.1 host=localhost reason=quit
Apr  2 15:27:36 host dovecot: lmtp(recipie...@example.org): 
msgid=<f24104b0-b461-4ab0-7778-b06e37975...@sender.org>: saved mail to INBOX
Apr  2 15:27:36 host dovecot: lmtp(4131): Disconnect from local: Client 
has quit the connection (state = READY)
Apr  2 15:27:36 host smtpd[3363]: 0000000000000000 mda event=delivery 
evpid=ff083fd626620393 from=<per...@sender.org> 
to=<recipie...@example.org> user=recipient2_example.org method=lmtp 
delay=0s result=Ok stat=Delivered
Apr  2 15:27:36 host dovecot: lmtp(recipie...@example.org): 
msgid=<f24104b0-b461-4ab0-7778-b06e37975...@sender.org>: saved mail to INBOX
Apr  2 15:27:36 host dovecot: lmtp(4136): Disconnect from local: Client 
has quit the connection (state = READY)
Apr  2 15:27:36 host smtpd[3363]: 0000000000000000 mda event=delivery 
evpid=ff083fd6e2c78bfd from=<per...@sender.org> 
to=<recipie...@example.org> user=recipient1_example.org method=lmtp 
delay=0s result=Ok stat=Delivered
Apr  2 15:27:45 host smtpd[3363]: a1ee25494b874d98 smtp event=closed 
address=192.168.1.4 host=sender.example.org reason=quit


Sender:
b7cd2df5d9ca94ec|inet4|mta|auth|per...@sender.org|recipie...@example.org|recipie...@example.org|1522673542|1523019142|0|1|pending|353|Remote 
host sent too much data
Recipient:
754dc784cae717d2|inet4|mta||per...@sender.org|recipie...@example.org|recipie...@example.org|1522673543|1523019143|0|1|pending|340|Remote 
host sent too much data


Apr  2 15:34:14 host smtpd[3363]: a1ee256e785cc841 smtp event=connected 
address=192.168.1.4 host=sender.example.org
Apr  2 15:34:14 host smtpd[3363]: a1ee256e785cc841 smtp event=starttls 
address=192.168.1.4 host=sender.example.org ciphers="version=TLSv1.2, 
cipher=ECDHE-RSA-AES256-GCM-SHA384, bits=256"
Apr  2 15:34:14 host smtpd[3363]: a1ee256e785cc841 smtp event=message 
address=192.168.1.4 host=sender.example.org msgid=e245a476 
from=<per...@sender.org> to=<recipie...@example.org> size=2004 ndest=1 
proto=ESMTP
Apr  2 15:34:14 host smtpd[3363]: a1ee2571543ee07d mta event=connecting 
address=lmtp://127.0.0.1:10024 host=localhost
Apr  2 15:34:14 host smtpd[3363]: a1ee2571543ee07d mta event=connected
Apr  2 15:34:15 host smtpd[3363]: a1ee2572eadf1ee6 smtp event=connected 
address=127.0.0.1 host=localhost
Apr  2 15:34:15 host smtpd[3363]: a1ee2572eadf1ee6 smtp event=message 
address=127.0.0.1 host=localhost msgid=9d4bd574 from=<per...@sender.org> 
to=<recipie...@example.org> size=2504 ndest=1 proto=ESMTP
Apr  2 15:34:15 host amavis[3624]: (03624-16) Passed CLEAN 
{RelayedInbound}, [127.0.0.1] <per...@sender.org> -> 
<recipie...@example.org>, Message-ID: 
<f24104b0-b461-4ab0-7778-b06e37975...@sender.org>, mail_id: 
V6N9QkDUiUdB, Hits: -2.926, size: 2043, queued_as: 250 2.0.0: 9d4bd574 
Message accepted for delivery, 580 ms
Apr  2 15:34:15 host smtpd[3363]: a1ee2571543ee07d mta event=delivery 
evpid=e245a4768eb97ec1 from=<per...@sender.org> 
to=<recipie...@example.org> rcpt=<-> source="127.0.0.1" relay="127.0.0.1 
(localhost)" delay=1s result="Ok" stat="250 2.0.0 from 
MTA(smtp:[127.0.0.1]:10025): 250 2.0.0: 9d4bd574 Message accepted for 
delivery"
Apr  2 15:34:15 host dovecot: lmtp(4166): Connect from local
Apr  2 15:34:15 host dovecot: lmtp(recipie...@example.org): 
msgid=<f24104b0-b461-4ab0-7778-b06e37975...@sender.org>: saved mail to INBOX
Apr  2 15:34:15 host dovecot: lmtp(4166): Disconnect from local: Client 
has quit the connection (state = READY)
Apr  2 15:34:15 host smtpd[3363]: 0000000000000000 mda event=delivery 
evpid=9d4bd574d7f14c2f from=<per...@sender.org> 
to=<recipie...@example.org> user=recipient2_example.org method=lmtp 
delay=0s result=Ok stat=Delivered
Apr  2 15:34:15 host smtpd[3363]: a1ee2572eadf1ee6 smtp event=message 
address=127.0.0.1 host=localhost msgid=6d82ebcd from=<per...@sender.org> 
to=<recipie...@example.org> size=2399 ndest=1 proto=ESMTP
Apr  2 15:34:15 host dovecot: lmtp(4166): Connect from local
Apr  2 15:34:16 host amavis[3624]: (03624-16-2) Passed CLEAN 
{RelayedInbound}, [127.0.0.1] <per...@sender.org> -> 
<recipie...@example.org>, Message-ID: 
<f24104b0-b461-4ab0-7778-b06e37975...@sender.org>, mail_id: 
GYBRJw-WsU6T, Hits: -2.926, size: 1947, queued_as: 250 2.0.0: 6d82ebcd 
Message accepted for delivery, 554 ms
Apr  2 15:34:16 host smtpd[3363]: a1ee2571543ee07d mta event=delivery 
evpid=989362f25851fa3e from=<per...@sender.org> 
to=<recipie...@example.org> rcpt=<-> source="127.0.0.1" relay="127.0.0.1 
(localhost)" delay=6m41s result="Ok" stat="250 2.0.0 from 
MTA(smtp:[127.0.0.1]:10025): 250 2.0.0: 6d82ebcd Message accepted for 
delivery"
Apr  2 15:34:16 host dovecot: lmtp(recipie...@example.org): 
msgid=<f24104b0-b461-4ab0-7778-b06e37975...@sender.org>: saved mail to INBOX
Apr  2 15:34:16 host dovecot: lmtp(4166): Disconnect from local: Client 
has quit the connection (state = READY)
Apr  2 15:34:16 host smtpd[3363]: 0000000000000000 mda event=delivery 
evpid=6d82ebcd60244358 from=<per...@sender.org> 
to=<recipie...@example.org> user=recipient1_example.org method=lmtp 
delay=1s result=Ok stat=Delivered


--
You received this mail because you are subscribed to misc@opensmtpd.org
To unsubscribe, send a mail to: misc+unsubscr...@opensmtpd.org