"No SMTP response to data-dot"-message and delivered the message like 10 times

[Michael Meier]

Hi all

I've got my own server using postfix and amavis (2.10.1-2~deb8u1) under 
the current debian stable (8).
Yesterday I received a big jpg-file (11MB) which I wanted to resend 
using Thunderbird.
I've sent the jpg to 3 receivers, of which 2 are on my own server and 1 
is on hotmail.
After a while a got a mail from my mail delivery system, saying 3 times, 
for every receiver:

<user3 at hotmail.com>: host 127.0.0.1[127.0.0.1] said: 451 4.5.0
     id=09573-03 - Temporary MTA failure on relaying, from
     MTA(smtp:[127.0.0.1]:10025): No resp. to data-dot (in reply to end 
of DATA
     command)


But at the least the receivers of my server received the mail anyway 
(i'm not sure about the hotmail account, I think there it arrived only 
once). The problem is, that the server tried to resend the mail several 
times. At the end I received the same email 12 times!
Each time it tried to resend it, the log files looked like that:

Apr  6 13:56:25 rmm amavis[22678]: (22678-17) (!)rw_loop: leaving rw 
loop, no progress, last event (select) 60.058 s ago
Apr  6 13:56:25 rmm amavis[22678]: (22678-17) No SMTP response to 
data-dot (<user1 at example.com>, etc.), dt: 60.058 s
Apr  6 13:56:25 rmm amavis[22678]: (22678-17) (!)U_MtABwr2Q_e FWD from 
<user2 at example.com> -> <user1 at example.com>,<user2 at example.com>, 
BODY=7BIT 451 4.5.0 from MTA(smtp:[127.0.0.1]:10025): No resp. to 
data-dot
Apr  6 13:56:25 rmm amavis[22678]: (22678-17) Passed MTA-BLOCKED 
{TempFailedInbound,TempFailedOpenRelay}, [213.193.81.54]:49780 
[213.193.81.54] <user2 at example.com> -> <user3 at hotmail.com>,
Queue-ID: EFB7C2E1317, Message-ID: 
<5b76c430-e8a4-4a57-26b1-ae1c4b4f6ba8 at example.com>, mail_id: 
U_MtABwr2Q_e, Hits: -2.79, size: 15512712, queued_as: 2F1A02E1318, 
526874 ms
Apr  6 13:56:25 rmm amavis[22678]: (22678-17) Blocked MTA-BLOCKED 
{TempFailedInbound,TempFailedOpenRelay}, [213.193.81.54]:49780 
[213.193.81.54] <user2 at example.com> -> 
<user1 at example.com>,<user2 at example.com>, Queue-ID: EFB7C2E1317, 
Message-ID: <5b76c430-e8a4-4a57-26b1-ae1c4b4f6ba8 at example.com>, mail_id: 
U_MtABwr2Q_e, Hits: -2.79, size: 15512712, 526874 ms
Apr  6 13:56:25 rmm postfix/smtp[8176]: EFB7C2E1317: 
to=<user3 at hotmail.com>, relay=127.0.0.1[127.0.0.1]:10024, delay=802, 
delays=275/0.01/0/527, dsn=4.5.0, status=deferred (host 
127.0.0.1[127.0.0.1] said: 451 4.5.0 id=22678-17 - Temporary MTA failure 
on relaying, from MTA(smtp:[127.0.0.1]:10025): No resp. to data-dot (in 
reply to end of DATA command))
Apr  6 13:56:25 rmm postfix/smtp[8176]: EFB7C2E1317: 
to=<user1 at example.com>, relay=127.0.0.1[127.0.0.1]:10024, delay=802, 
delays=275/0.01/0/527, dsn=4.5.0, status=deferred (host 
127.0.0.1[127.0.0.1] said: 451 4.5.0 id=22678-17 - Temporary MTA failure 
on relaying, from MTA(smtp:[127.0.0.1]:10025): No resp. to data-dot (in 
reply to end of DATA command))
Apr  6 13:56:26 rmm postfix/smtp[8176]: EFB7C2E1317: 
to=<user2 at example.com>, relay=127.0.0.1[127.0.0.1]:10024, delay=802, 
delays=275/0.01/0/527, dsn=4.5.0, status=deferred (host 
127.0.0.1[127.0.0.1] said: 451 4.5.0 id=22678-17 - Temporary MTA failure 
on relaying, from MTA(smtp:[127.0.0.1]:10025): No resp. to data-dot (in 
reply to end of DATA command))
Apr  6 13:56:54 rmm postfix/smtpd[8182]: disconnect from 
localhost[127.0.0.1]
Apr  6 13:56:54 rmm postfix/qmgr[3223]: B70932E137C: 
from=<user2 at example.com>, size=15513333, nrcpt=2 (queue active)
Apr  6 13:56:54 rmm dovecot: lmtp(8284): Connect from local
Apr  6 13:56:56 rmm dovecot: lmtp(8284, user1): txN7CAYt5lhcIAAAFCq16w: 
sieve: msgid=<5b76c430-e8a4-4a57-26b1-ae1c4b4f6ba8 at example.com>: stored 
mail into mailbox 'INBOX'
Apr  6 13:56:56 rmm postfix/lmtp[8283]: B70932E137C: 
to=<user1 at example.com>, relay=example.com[private/dovecot-lmtp], 
delay=287, delays=285/0.01/0.01/1.9, dsn=2.0.0, status=sent (250 2.0.0 
<user1 at example.com> txN7CAYt5lhcIAAAFCq16w Saved)
Apr  6 13:56:56 rmm dovecot: lmtp(8284, user2): txN7CAYt5lhcIAAAFCq16w: 
sieve: msgid=<5b76c430-e8a4-4a57-26b1-ae1c4b4f6ba8 at example.com>: stored 
mail into mailbox 'INBOX'
Apr  6 13:56:56 rmm postfix/lmtp[8283]: B70932E137C: 
to=<user2 at example.com>, relay=example.com[private/dovecot-lmtp], 
delay=288, delays=285/0.01/0.01/2.7, dsn=2.0.0, status=sent (250 2.0.0 
<user2 at example.com> txN7CAYt5lhcIAAAFCq16w Saved)
Apr  6 13:56:56 rmm dovecot: lmtp(8284): Disconnect from local: 
Successful quit

I guess amavis got some problem with the big attachment?
Could there be some kind of missconfiguration?
So far I never had problems with amavis. Well, it was the first time, 
that I accidentally send an e-mail to myself, otherwise I wouldn't have 
noticed the whole problem...

thanks in advance for any hints
Michael