[SOLVED] Unexplained bounces

KatyComputer · Sep 18, 2023

We moved pmg to a new server. We use PMG to protect 20 domains, most of the domains receive their email on Microsoft 365.

Since the move, if one of the 20 domains tries to send email to one of the other domains, the message is resent 8 times then rejected on the 9th attempt.

What could I have misconfigured?

The first attempt looks like this:

Code:

2023-09-18T09:23:04.657983-05:00 mx-03 postfix/smtpd[119126]: connect from mail-bn7nam10on2102.outbound.protection.outlook.com[40.107.92.102]
2023-09-18T09:23:04.719761-05:00 mx-03 postfix/smtpd[119126]: Anonymous TLS connection established from mail-bn7nam10on2102.outbound.protection.outlook.com[40.107.92.102]: TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)
2023-09-18T09:23:05.639916-05:00 mx-03 postfix/smtpd[119126]: NOQUEUE: client=mail-bn7nam10on2102.outbound.protection.outlook.com[40.107.92.102]
2023-09-18T09:23:05.757670-05:00 mx-03 pmg-smtp-filter[120983]: 609F765085D49B8020: new mail message-id=<PH7PR19MB56359F90F833FBE13DACEF7FFBFBA@PH7PR19MB5635.namprd19.prod.outlook.com>#012
2023-09-18T09:23:06.143947-05:00 mx-03 pmg-smtp-filter[120983]: 609F765085D49B8020: SA score=0/5 time=0.352 bayes=0.00 autolearn=ham autolearn_force=no hits=ARC_SIGNED(0.001),ARC_VALID(0.001),AWL(8.500),BAYES_00(-1.9),HTML_MESSAGE(0.001),KAM_DMARC_STATUS(0.01),LOCAL__H_firm1(-15),RCVD_IN_DNSWL_NONE(-0.0001),RCVD_IN_MSPIKE_H2(-0.001),SPF_HELO_PASS(-0.001),SPF_PASS(-0.001),USER_IN_SPF_WELCOMELIST(-0.01),USER_IN_SPF_WHITELIST(-100)
2023-09-18T09:23:06.146469-05:00 mx-03 postfix/smtpd[119746]: connect from localhost[127.0.0.1]
2023-09-18T09:23:06.147152-05:00 mx-03 postfix/smtpd[119746]: 23E92410AE: client=localhost[127.0.0.1], orig_client=mail-bn7nam10on2102.outbound.protection.outlook.com[40.107.92.102]
2023-09-18T09:23:06.147674-05:00 mx-03 postfix/cleanup[119852]: 23E92410AE: message-id=<PH7PR19MB56359F90F833FBE13DACEF7FFBFBA@PH7PR19MB5635.namprd19.prod.outlook.com>
2023-09-18T09:23:06.192872-05:00 mx-03 postfix/qmgr[30674]: 23E92410AE: from=<client1@firm1.com>, size=32159, nrcpt=1 (queue active)
2023-09-18T09:23:06.193350-05:00 mx-03 postfix/smtpd[119746]: disconnect from localhost[127.0.0.1] ehlo=1 xforward=1 mail=1 rcpt=1 data=1 commands=5
2023-09-18T09:23:06.193488-05:00 mx-03 pmg-smtp-filter[120983]: 609F765085D49B8020: accept mail to <client2@firm2.com> (23E92410AE) (rule: Whitelist)
2023-09-18T09:23:06.198117-05:00 mx-03 pmg-smtp-filter[120983]: 609F765085D49B8020: processing time: 0.439 seconds (0.352, 0.022, 0)
2023-09-18T09:23:06.198363-05:00 mx-03 postfix/smtpd[119126]: proxy-accept: END-OF-MESSAGE: 250 2.5.0 OK (609F765085D49B8020); from=<client1@firm1.com> to=<client2@firm2.com> proto=ESMTP helo=<NAM10-BN7-obe.outbound.protection.outlook.com>
2023-09-18T09:23:06.266503-05:00 mx-03 postfix/smtpd[119126]: disconnect from mail-bn7nam10on2102.outbound.protection.outlook.com[40.107.92.102] ehlo=2 starttls=1 mail=1 rcpt=1 bdat=1 quit=1 commands=7
2023-09-18T09:23:06.354123-05:00 mx-03 postfix/smtp[119853]: Trusted TLS connection established to firm2-com.mail.protection.outlook.com[52.101.9.12]:25: TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)
2023-09-18T09:23:07.835399-05:00 mx-03 postfix/smtp[119853]: 23E92410AE: to=<client2@firm2.com>, relay=firm2-com.mail.protection.outlook.com[52.101.9.12]:25, delay=1.7, delays=0.05/0/0.17/1.5, dsn=2.6.0, status=sent (250 2.6.0 <PH7PR19MB56359F90F833FBE13DACEF7FFBFBA@PH7PR19MB5635.namprd19.prod.outlook.com> [InternalId=157977487098484, Hostname=BY5PR19MB3924.namprd19.prod.outlook.com] 41394 bytes in 0.275, 146.569 KB/sec Queued mail for delivery)
2023-09-18T09:23:07.835538-05:00 mx-03 postfix/qmgr[30674]: 23E92410AE: removed

The final bounce looks like this:

Code:

2023-09-18T09:24:43.250788-05:00 mx-03 postfix/smtpd[119634]: connect from mail-bn7nam10on2115.outbound.protection.outlook.com[40.107.92.115]
2023-09-18T09:24:43.311133-05:00 mx-03 postfix/smtpd[119634]: Anonymous TLS connection established from mail-bn7nam10on2115.outbound.protection.outlook.com[40.107.92.115]: TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)
2023-09-18T09:24:43.843848-05:00 mx-03 postfix/smtpd[119634]: NOQUEUE: client=mail-bn7nam10on2115.outbound.protection.outlook.com[40.107.92.115]
2023-09-18T09:24:43.951855-05:00 mx-03 pmg-smtp-filter[120788]: 609F765085DABE6DEC: new mail message-id=<PH7PR19MB56359F90F833FBE13DACEF7FFBFBA@PH7PR19MB5635.namprd19.prod.outlook.com>#012
2023-09-18T09:24:44.314500-05:00 mx-03 pmg-smtp-filter[120788]: 609F765085DABE6DEC: SA score=0/5 time=0.336 bayes=0.00 autolearn=unavailable autolearn_force=no hits=ARC_SIGNED(0.001),ARC_VALID(0.001),AWL(4.533),BAYES_00(-1.9),HTML_MESSAGE(0.001),KAM_DMARC_STATUS(0.01),LOCAL__H_firm1(-15),RCVD_IN_DNSWL_NONE(-0.0001),RCVD_IN_MSPIKE_H2(-0.001),SPF_HELO_PASS(-0.001),SPF_PASS(-0.001),USER_IN_SPF_WELCOMELIST(-0.01),USER_IN_SPF_WHITELIST(-100)
2023-09-18T09:24:44.316657-05:00 mx-03 postfix/smtpd[121134]: connect from localhost[127.0.0.1]
2023-09-18T09:24:44.317041-05:00 mx-03 postfix/smtpd[121134]: 4D634410AE: client=localhost[127.0.0.1], orig_client=mail-bn7nam10on2115.outbound.protection.outlook.com[40.107.92.115]
2023-09-18T09:24:44.317998-05:00 mx-03 postfix/cleanup[121109]: 4D634410AE: message-id=<PH7PR19MB56359F90F833FBE13DACEF7FFBFBA@PH7PR19MB5635.namprd19.prod.outlook.com>
2023-09-18T09:24:44.365399-05:00 mx-03 postfix/qmgr[30674]: 4D634410AE: from=<client1@firm1.com>, size=61863, nrcpt=1 (queue active)
2023-09-18T09:24:44.365478-05:00 mx-03 postfix/smtpd[121134]: disconnect from localhost[127.0.0.1] ehlo=1 xforward=1 mail=1 rcpt=1 data=1 commands=5
2023-09-18T09:24:44.365524-05:00 mx-03 pmg-smtp-filter[120788]: 609F765085DABE6DEC: accept mail to <client2@firm2.com> (4D634410AE) (rule: Whitelist)
2023-09-18T09:24:44.370289-05:00 mx-03 pmg-smtp-filter[120788]: 609F765085DABE6DEC: processing time: 0.419 seconds (0.336, 0.012, 0)
2023-09-18T09:24:44.370438-05:00 mx-03 postfix/smtpd[119634]: proxy-accept: END-OF-MESSAGE: 250 2.5.0 OK (609F765085DABE6DEC); from=<client1@firm1.com> to=<client2@firm2.com> proto=ESMTP helo=<NAM10-BN7-obe.outbound.protection.outlook.com>
2023-09-18T09:24:44.434052-05:00 mx-03 postfix/smtpd[119634]: disconnect from mail-bn7nam10on2115.outbound.protection.outlook.com[40.107.92.115] ehlo=2 starttls=1 mail=1 rcpt=1 bdat=1 quit=1 commands=7
2023-09-18T09:24:44.723672-05:00 mx-03 postfix/smtp[119849]: Trusted TLS connection established to firm2-com.mail.protection.outlook.com[52.101.8.42]:25: TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)
2023-09-18T09:24:45.211953-05:00 mx-03 postfix/smtp[119849]: 4D634410AE: to=<client2@firm2.com>, relay=firm2-com.mail.protection.outlook.com[52.101.8.42]:25, delay=0.89, delays=0.05/0/0.4/0.44, dsn=5.4.14, status=bounced (host firm2-com.mail.protection.outlook.com[52.101.8.42] said: 554 5.4.14 Hop count exceeded - possible mail loop ATTR1 [DS1PEPF0001708F.namprd03.prod.outlook.com 2023-09-18T14:24:45.180Z 08DBB4441826DC3C] (in reply to end of DATA command))
2023-09-18T09:24:45.216150-05:00 mx-03 postfix/qmgr[30674]: 4D634410AE: removed

KatyComputer · Sep 18, 2023

It doesn't help me solve the puzzle, however, Message trace tells me client1@firm1's M365 server sends the email to PMG 9 times.

Stoiko Ivanov · Sep 19, 2023

This looks like a mail-loop somewhere:

KatyComputer said:
554 5.4.14 Hop count exceeded - possible mail loop

my guess is that client2@firm2.com has it configured somehow that all mail for them gets sent to PMG - however if the mail comes from PMG this should not happen

KatyComputer · Sep 19, 2023

Completely external mail, for example, random@gmail.com is correctly delivered to firm1.com & firm2.com recipients, only messages where both organizations share our pmg as their MX record have this issue.

What setting(s) could be causing this behavior?

Stoiko Ivanov · Sep 19, 2023

KatyComputer said:
What setting(s) could be causing this behavior?

my guess the scanning settings for firm2.com - in their downstream server (since I assume this is where the loop starts)

as I don't have any experience with online exchange - I hope the following links are helpful:
https://learn.microsoft.com/en-us/e...-code-5-4-6-through-5-4-20-in-exchange-online
https://learn.microsoft.com/en-us/e...ailflow/hop-count-exceeded-possible-mail-loop

technikbs · Oct 2, 2023

has anyone solved this problem?

KatyComputer · Oct 2, 2023

Not to my knowledge - I wish there was a solution. I may have something mis-configured, OTOH, I have been using Proxmox since before Covid and everything worked fine on v7, I moved PMG to a new server running v8, now I have the problem.

Stoiko Ivanov · Oct 3, 2023

KatyComputer said:
Not to my knowledge - I wish there was a solution. I may have something mis-configured, OTOH, I have been using Proxmox since before Covid and everything worked fine on v7, I moved PMG to a new server running v8, now I have the problem.

I don't think anything related to mail-routing changed that might cause this between v7 and v8

Did the links above help - did you try following the advices there?

KatyComputer · Oct 15, 2023

I think I have solved the mystery - we were using /etc/postfix/sender_relay incorrectly resulting in difficult to track down loops.

Search

Search

[SOLVED] Unexplained bounces

KatyComputer

Active Member

KatyComputer

Active Member

Stoiko Ivanov

Proxmox Staff Member

KatyComputer

Active Member

Stoiko Ivanov

Proxmox Staff Member

technikbs

Member

KatyComputer

Active Member

Stoiko Ivanov

Proxmox Staff Member

KatyComputer

Active Member