Gentoo Forums
Gentoo Forums
Gentoo Forums
Quick Search: in
amavis Blocked MTA-BLOCKED {TempFailedInbound} [SOLVED]
View unanswered posts
View posts from last 24 hours

 
Reply to topic    Gentoo Forums Forum Index Networking & Security
View previous topic :: View next topic  
Author Message
epig
n00b
n00b


Joined: 16 Feb 2005
Posts: 70

PostPosted: Thu Apr 04, 2019 4:17 pm    Post subject: amavis Blocked MTA-BLOCKED {TempFailedInbound} [SOLVED] Reply with quote

Hi,

Over the past couple of days I have gotten an alarming number of these in my mail server logs:

Code:
Apr 04 18:05:04 [postfix/smtpd] NOQUEUE: client=a15-169.smtp-out.amazonses.com[54.240.15.169]
Apr 04 18:05:04 [amavis] (26846-01) ESMTP [127.0.0.1]:10024 /var/amavis/tmp/amavis-20190404T180504-26846-eDOmmg0R: <20190404160438258321cd3c9a4f159c5f68289030p0na-C2NU3DE64IDCD0@bounces.audible.com> -> <user@domain.com> Received: from grond.domain.net ([127.0.0.1]) by localhost (grond.domain.net [127.0.0.1]) (amavisd-new, port 10024) with ESMTP for <user@domain.com>; Thu,  4 Apr 2019 18:05:04 +0200 (CEST)
Apr 04 18:05:04 [amavis] (26846-01) Checking: AAw0SV1AsyyY [54.240.15.169] <20190404160438258321cd3c9a4f159c5f68289030p0na-C2NU3DE64IDCD0@bounces.audible.com> -> <user@domain.com>
Apr 04 18:05:04 [amavis] (26846-01) p003 1 Content-Type: multipart/alternative
Apr 04 18:05:04 [amavis] (26846-01) p001 1/1 Content-Type: text/plain, QP, size: 2092, SHA1 digest: 49dce2508cd6989cd1736e186a8d094951324203
Apr 04 18:05:04 [amavis] (26846-01) p002 1/2 Content-Type: text/html, QP, size: 39081, SHA1 digest: c3968e59b7c521460780d01256f601bbd240c5f3
Apr 04 18:05:40 [amavis] (26846-01) (!)rw_loop: leaving rw loop, no progress, last event (select) 35.035 s ago
Apr 04 18:05:40 [amavis] (26846-01) mail_via_smtp: session failed: No greeting, dt: 35.036 s
Apr 04 18:05:40 [amavis] (26846-01) (!)AAw0SV1AsyyY FWD from <20190404160438258321cd3c9a4f159c5f68289030p0na-C2NU3DE64IDCD0@bounces.audible.com> -> <user@domain.com>,  451 4.5.0 From MTA() during fwd-connect (No greeting, dt: 35.036 s): id=26846-01
Apr 04 18:05:40 [amavis] (26846-01) Blocked MTA-BLOCKED {TempFailedInbound}, [54.240.15.169]:57680 [54.240.15.169] <20190404160438258321cd3c9a4f159c5f68289030p0na-C2NU3DE64IDCD0@bounces.audible.com> -> <user@domain.com>, Message-ID: <01000169e9184ec4-bab465e3-f879-4e7b-8212-ab6d0d36aac4-000000@email.amazonses.com>, mail_id: AAw0SV1AsyyY, Hits: -3.144, size: 51053, 36562 ms
Apr 04 18:05:40 [amavis] (26846-01) TIMING-SA total 864 ms - parse: 4.1 (0.5%), extract_message_metadata: 43 (5.0%), get_uri_detail_list: 28 (3.3%), tests_pri_-1000: 6 (0.7%), tests_pri_-950: 1.22 (0.1%), tests_pri_-900: 3.0 (0.3%), tests_pri_-90: 109 (12.6%), check_bayes: 101 (11.7%), b_tokenize: 59 (6.9%), b_tok_get_all: 26 (3.0%), b_comp_prob: 10 (1.2%), b_tok_touch_all: 0.59 (0.1%), b_finish: 1.03 (0.1%), tests_pri_0: 497 (57.6%), check_dkim_signature: 129 (15.0%), poll_dns_idle: 117 (13.5%), tests_pri_20: 1.66 (0.2%), tests_pri_30: 1.37 (0.2%), check_pyzor: 0.15 (0.0%), tests_pri_500: 3.6 (0.4%), learn: 154 (17.8%), b_learn: 140 (16.2%), b_count_change: 59 (6.8%), get_report: 0.65 (0.1%)
Apr 04 18:05:41 [postfix/smtpd] proxy-reject: END-OF-MESSAGE: 451 4.5.0 id=26846-01 - Temporary MTA failure on relaying, From MTA() during fwd-connect (No greeting, dt: 35.036 s): id=26846-01; from=<20190404160438258321cd3c9a4f159c5f68289030p0na-C2NU3DE64IDCD0@bounces.audible.com> to=<user@domain.com> proto=ESMTP helo=<a15-169.smtp-out.amazonses.com>
Apr 04 18:05:41 [amavis] (26846-01) size: 51053, TIMING [total 36568 ms] - SMTP greeting: 10 (0%)0, SMTP EHLO: 1.1 (0%)0, SMTP pre-MAIL: 0.7 (0%)0, mkdir tempdir: 1.5 (0%)0, create email.txt: 0.3 (0%)0, SMTP MAIL: 1.9 (0%)0, SMTP pre-DATA-flush: 116 (0%)0, SMTP DATA: 345 (1%)1, check_init: 0.8 (0%)1, digest_hdr: 1.2 (0%)1, digest_body: 0.7 (0%)1, collect_info: 2.5 (0%)1, mkdir parts: 1.3 (0%)1, mime_decode: 20 (0%)1, get-file-type2: 23 (0%)1, decompose_part: 0.6 (0%)1, parts_decode: 0.0 (0%)1, check_header: 0.5 (0%)1, AV-scan-1: 118 (0%)2, spam-wb-list: 1.3 (0%)2, SA msg read: 0.4 (0%)2, SA parse: 4.9 (0%)2, SA check: 857 (2%)4, decide_mail_destiny: 5 (0%)4, notif-quar: 0.3 (0%)4, fwd-end-chkpnt: 35039 (96%)100, prepare-dsn: 2.0 (0%)100, report: 1.8 (0%)100, main_log_entry: 6 (0%)100, update_snmp: 3.1 (0%)100, SMTP pre-response: 0.4 (0%)100, SMTP response: 0.6 (0%)100, unlink-2-files: 0.7 (0%)100, rundown: 0.6 (0%)100
Apr 04 18:06:01 [postfix/smtpd] disconnect from a15-169.smtp-out.amazonses.com[54.240.15.169] ehlo=2 starttls=1 mail=1 rcpt=1 data=0/1 rset=1 quit=1 commands=7/8
Apr 04 18:06:39 [postfix/anvil] statistics: max connection rate 1/60s for (smtps:192.168.0.46) at Apr  4 17:56:39
Apr 04 18:06:39 [postfix/anvil] statistics: max connection count 1 for (smtps:192.168.0.46) at Apr  4 17:56:39
Apr 04 18:06:39 [postfix/anvil] statistics: max cache size 4 at Apr  4 18:05:01
Apr 04 18:06:43 [postfix/smtpd] connect from localhost[127.0.0.1]
Apr 04 18:06:43 [postfix/smtpd] lost connection after CONNECT from localhost[127.0.0.1]
Apr 04 18:06:43 [postfix/smtpd] disconnect from localhost[127.0.0.1] commands=0/0
Apr 04 18:07:04 [imapd-ssl] Connection, ip=[::ffff:81.167.160.221]
                - Last output repeated twice -


Can't really remember any changes mase in the last few days, and it has been a while since amavis of postfix were updated.

The weird thing is that the problem does not seem to be consistant, and just shows up from time to time.

I have confirmed that:

Disks are not full
Disks are not mounted RO
Restarted postfix, amavis and clamd, all come back up just fine.

(The server is a VMware VM on a SSD data store, no other VMs on the same data store seem to have problems, but I moved it elsewhere just in case)

I am drawing a blank. Can anyone in here maybe point me in the right direction?


Last edited by epig on Sat Apr 13, 2019 4:48 pm; edited 1 time in total
Back to top
View user's profile Send private message
doublehelix
n00b
n00b


Joined: 06 Apr 2019
Posts: 5

PostPosted: Sat Apr 06, 2019 11:09 am    Post subject: Reply with quote

It seems the problem is with amavis sending the messsage via SMTP back to postfix after checking it successfully.
That attempt fails with SMTP code 451.

So I'd think amavisd itself is fine and postfix is the problem.
Can you find any errors in postfix' logfile?
Back to top
View user's profile Send private message
epig
n00b
n00b


Joined: 16 Feb 2005
Posts: 70

PostPosted: Sun Apr 07, 2019 9:41 am    Post subject: Reply with quote

Here are a cople of postfix entries from today's log file:

Code:
Apr 07 11:03:45 [postfix/smtpd] connect from nia-glo-vpn.agillic.eu[92.62.195.254]
Apr 07 11:03:45 [postfix/smtpd] lost connection after CONNECT from nia-glo-vpn.agillic.eu[92.62.195.254]
Apr 07 11:03:45 [postfix/smtpd] disconnect from nia-glo-vpn.agillic.eu[92.62.195.254] commands=0/0
Apr 07 11:04:09 [postfix/smtpd] connect from nia-glo-del10.agillic.eu[92.62.195.221]
Apr 07 11:04:09 [postfix/smtpd] Anonymous TLS connection established from nia-glo-del10.agillic.eu[92.62.195.221]: TLSv1.2 with cipher AECDH-AES256-SHA (256/256 bits)
Apr 07 11:04:09 [postfix/smtpd] NOQUEUE: client=nia-glo-del10.agillic.eu[92.62.195.221]
Apr 07 11:04:46 [postfix/smtpd] proxy-reject: END-OF-MESSAGE: 451 4.5.0 id=09741-11 - Temporary MTA failure on relaying, From MTA() during fwd-connect (No greeting, dt: 35.036 s): id=09741-11; from=<bounce-ngr-meny-prod-e17cx38x3lxehp9dng@nyhetsbrev.meny.no> to=<user2@domain.com> proto=ESMTP helo=<nia-glo-del10.agillic.eu>
Apr 07 11:04:46 [postfix/smtpd] disconnect from nia-glo-del10.agillic.eu[92.62.195.221] ehlo=2 starttls=1 mail=1 rcpt=1 data=0/1 quit=1 commands=6/7
Apr 07 11:04:46 [postfix/smtpd] connect from unknown[104.148.64.156]
Apr 07 11:04:46 [postfix/smtpd] NOQUEUE: client=unknown[104.148.64.156]
Apr 07 11:05:22 [postfix/smtpd] proxy-reject: END-OF-MESSAGE: 451 4.5.0 Error in processing, id=12576-07, quar+notif FAILED: temporarily unable to quarantine: 451 4.5.0 From MTA() during fwd-connect (No greeting, dt: 35.003 s): id=12576-07 at /usr/sbin/amavisd line 17584.; from=<mary-lewis-user=domain.com@faerwald.pro> to=<user@domain.com> proto=ESMTP helo=<mail.faerwald.pro>
Apr 07 11:05:22 [postfix/smtpd] disconnect from unknown[104.148.64.156] ehlo=1 mail=1 rcpt=1 data=0/1 quit=1 commands=4/5
Apr 07 11:07:32 [postfix/smtpd] connect from localhost[127.0.0.1]
Apr 07 11:07:32 [postfix/smtpd] lost connection after CONNECT from localhost[127.0.0.1]
Apr 07 11:07:32 [postfix/smtpd] disconnect from localhost[127.0.0.1] commands=0/0
Apr 07 11:07:32 [postfix/smtpd] connect from localhost[127.0.0.1]
Apr 07 11:07:32 [postfix/smtpd] lost connection after CONNECT from localhost[127.0.0.1]
Apr 07 11:07:32 [postfix/smtpd] disconnect from localhost[127.0.0.1] commands=0/0
Apr 07 11:08:42 [postfix/anvil] statistics: max connection rate 1/60s for (smtp:92.62.195.254) at Apr  7 11:03:45
Apr 07 11:08:42 [postfix/anvil] statistics: max connection count 1 for (smtp:92.62.195.254) at Apr  7 11:03:45
Apr 07 11:08:42 [postfix/anvil] statistics: max cache size 2 at Apr  7 11:04:09
Apr 07 11:13:35 [postfix/smtpd] warning: hostname hosted-by.eksenbilisim.com.tr does not resolve to address 185.174.23.53
Apr 07 11:13:35 [postfix/smtpd] connect from unknown[185.174.23.53]
Apr 07 11:13:35 [postfix/smtpd] NOQUEUE: client=unknown[185.174.23.53]
Apr 07 11:14:11 [postfix/smtpd] proxy-reject: END-OF-MESSAGE: 451 4.5.0 Error in processing, id=10726-08, quar+notif FAILED: temporarily unable to quarantine: 451 4.5.0 From MTA() during fwd-connect (No greeting, dt: 35.037 s): id=10726-08 at /usr/sbin/amavisd line 17584.; from=<3332-24-45567-578-user3=domain.com@mail.droppedalmost.bid> to=<user3@domain.com> proto=ESMTP helo=<loop.droppedalmost.bid>
Apr 07 11:14:11 [postfix/smtpd] NOQUEUE: client=unknown[185.174.23.53]
Apr 07 11:14:47 [postfix/smtpd] proxy-reject: END-OF-MESSAGE: 451 4.5.0 Error in processing, id=12576-08, quar+notif FAILED: temporarily unable to quarantine: 451 4.5.0 From MTA() during fwd-connect (No greeting, dt: 35.033 s): id=12576-08 at /usr/sbin/amavisd line 17584.; from=<3332-24-607175-578-user=domain.com@mail.droppedalmost.bid> to=<user@domain.com> proto=ESMTP helo=<loop.droppedalmost.bid>
Apr 07 11:14:47 [postfix/smtpd] disconnect from unknown[185.174.23.53] ehlo=1 mail=2 rcpt=2 data=0/2 rset=1 quit=1 commands=7/9
Apr 07 11:14:47 [postfix/smtpd] connect from nia-glo-del10.agillic.eu[92.62.195.221]
Apr 07 11:14:48 [postfix/smtpd] Anonymous TLS connection established from nia-glo-del10.agillic.eu[92.62.195.221]: TLSv1.2 with cipher AECDH-AES256-SHA (256/256 bits)
Apr 07 11:14:48 [postfix/smtpd] NOQUEUE: client=nia-glo-del10.agillic.eu[92.62.195.221]
Apr 07 11:15:24 [postfix/smtpd] proxy-reject: END-OF-MESSAGE: 451 4.5.0 id=13380-01 - Temporary MTA failure on relaying, From MTA() during fwd-connect (No greeting, dt: 35.036 s): id=13380-01; from=<bounce-ngr-meny-prod-e17cx38x3lxehp9dng@nyhetsbrev.meny.no> to=<paal@domain.com> proto=ESMTP helo=<nia-glo-del10.agillic.eu>
Apr 07 11:15:24 [postfix/smtpd] disconnect from nia-glo-del10.agillic.eu[92.62.195.221] ehlo=2 starttls=1 mail=1 rcpt=1 data=0/1 quit=1 commands=6/7
Apr 07 11:16:14 [postfix/smtpd] connect from localhost[127.0.0.1]
Apr 07 11:16:14 [postfix/smtpd] lost connection after CONNECT from localhost[127.0.0.1]
Apr 07 11:16:14 [postfix/smtpd] disconnect from localhost[127.0.0.1] commands=0/0
Apr 07 11:16:14 [postfix/smtpd] connect from localhost[127.0.0.1]
Apr 07 11:16:14 [postfix/smtpd] lost connection after CONNECT from localhost[127.0.0.1]
Apr 07 11:16:14 [postfix/smtpd] disconnect from localhost[127.0.0.1] commands=0/0
Apr 07 11:16:14 [postfix/smtpd] connect from localhost[127.0.0.1]
Apr 07 11:16:14 [postfix/smtpd] lost connection after CONNECT from localhost[127.0.0.1]
Apr 07 11:16:14 [postfix/smtpd] disconnect from localhost[127.0.0.1] commands=0/0
Apr 07 11:16:45 [postfix/smtpd] connect from unknown[104.148.64.157]
Apr 07 11:16:48 [postfix/smtpd] NOQUEUE: client=unknown[104.148.64.157]
Apr 07 11:16:49 [postfix/smtpd] connect from localhost[127.0.0.1]
Apr 07 11:16:49 [postfix/smtpd] DA29614495A: client=localhost[127.0.0.1]
Apr 07 11:16:49 [postfix/cleanup] DA29614495A: message-id=<0.0.0.1E.1D4ED221D9C85B2.84582E@mail.taralyn.world>
Apr 07 11:16:49 [postfix/qmgr] DA29614495A: from=<>, size=11764, nrcpt=1 (queue active)
Apr 07 11:16:49 [postfix/smtpd] disconnect from localhost[127.0.0.1] ehlo=1 mail=1 rcpt=1 data=1 quit=1 commands=5
Apr 07 11:16:49 [postfix/local] DA29614495A: to=<amavis@domain.com>, relay=local, delay=0.4, delays=0.39/0.01/0/0, dsn=2.0.0, status=sent (delivered to maildir)
Apr 07 11:16:49 [postfix/qmgr] DA29614495A: removed
Apr 07 11:16:49 [postfix/smtpd] proxy-accept: END-OF-MESSAGE: 250 2.7.0 Ok, discarded, id=07476-19 - spam; from=<amora_coffee-user=domain.com@taralyn.world> to=<user@domain.com> proto=ESMTP helo=<mail.taralyn.world>
Apr 07 11:16:50 [postfix/smtpd] disconnect from unknown[104.148.64.157] ehlo=1 mail=1 rcpt=1 data=1 quit=1 commands=5
Back to top
View user's profile Send private message
doublehelix
n00b
n00b


Joined: 06 Apr 2019
Posts: 5

PostPosted: Sun Apr 07, 2019 2:16 pm    Post subject: Reply with quote

This sticks out to me:
Code:
FAILED: temporarily unable to quarantine: 451 4.5.0 From MTA() during fwd-connect


So I'd check how quarantining is configured in your amavisd /etc/amavisd.conf.
Maybe the folder it uses doesn't exist or something similar.

Since I don't use quarantining in amavisd I can't help you further, I'm afraid. Good luck!
Back to top
View user's profile Send private message
epig
n00b
n00b


Joined: 16 Feb 2005
Posts: 70

PostPosted: Mon Apr 08, 2019 8:07 am    Post subject: Reply with quote

doublehelix wrote:
This sticks out to me:
Code:
FAILED: temporarily unable to quarantine: 451 4.5.0 From MTA() during fwd-connect


So I'd check how quarantining is configured in your amavisd /etc/amavisd.conf.
Maybe the folder it uses doesn't exist or something similar.

Since I don't use quarantining in amavisd I can't help you further, I'm afraid. Good luck!


Cant't find anything that sticks out htere, nor have I change anything in the last several years.
Quarantined items are delivered to the amais user's mailbox.

Now, if this didn't work at all, it would be a config issue. However, it works 75% of the time.
The non consistency is what drives me nuts here.

Some google-work revealed that amavis can be set up with too many children, causing postfix to reject connections.
I have played around with settings on this, but that didn't seem to do anything so I went back to the default settings.
Back to top
View user's profile Send private message
mofm
n00b
n00b


Joined: 13 Apr 2019
Posts: 1

PostPosted: Sat Apr 13, 2019 2:16 pm    Post subject: Reply with quote

Hi epig,

Completely the same problem. Did you find a solution?
Back to top
View user's profile Send private message
epig
n00b
n00b


Joined: 16 Feb 2005
Posts: 70

PostPosted: Sat Apr 13, 2019 4:47 pm    Post subject: Reply with quote

mofm wrote:
Hi epig,

Completely the same problem. Did you find a solution?


DISCLAMER: This is semi educated guess work:
It seems to have a connection to how many processes postfix is willing to accept from the local proxy. So the trick is to have amavis spawn fewer processes than postfix wants to accept.

I played with the settings on amavis (/etc/amavis.conf) and their children, and this works:

Code:
$max_servers = 5;     # num of pre-forked children (2..30 is common), -m
$max_requests = 10;   # retire a child after that many accepts (default 20)


While keeping the default settings for maxprocs in master.cf

Code:
## Amavisd-new virus scanner
smtp-amavis unix -      -       n     -       -  smtp
        -o smtp_data_done_timeout=1200
        -o disable_dns_lookups=yes
127.0.0.1:10025 inet n  -       n     -       -  smtpd
        -o content_filter=
        -o local_recipient_maps=
        -o relay_recipient_maps=
        -o smtpd_restriction_classes=
        -o smtpd_client_restrictions=
        -o smtpd_helo_restrictions=
        -o smtpd_sender_restrictions=
        -o smtpd_recipient_restrictions=permit_mynetworks,reject
        -o mynetworks=127.0.0.0/8
        -o strict_rfc821_envelopes=yes



Has worked fine for a week or so, no problems.
Back to top
View user's profile Send private message
Display posts from previous:   
Reply to topic    Gentoo Forums Forum Index Networking & Security All times are GMT
Page 1 of 1

 
Jump to:  
You cannot post new topics in this forum
You cannot reply to topics in this forum
You cannot edit your posts in this forum
You cannot delete your posts in this forum
You cannot vote in polls in this forum