Score:1

Postfix not sending emails with no error messages

in flag

I have a customer attempting to use postfix to send emails with SMTP. It appears that postfix will parse the email attributes correctly, but before sending the email it begins processing it again. This happens in an endless loop. I've put postfix into debug mode and produced a log file that looks almost exactly the same as a log file produced with my own system up to the point where it repeats the parsing of the email.

The customer's end-of-log:

postfix/smtpd[29586]: connection closed
postfix/smtpd[29586]: connection established

My end-of-log:

postfix/smtpd[20539]: connection closed
postfix/smtp[20543]: 0D65814D: to=<[email protected]>, relay=10.2.253.96[10.2.253.96]:25, delay=0.17, delays=0.03/0.07/0/0.06, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as O)
postfix/qmgr[19812]: 0D65814D: removed

The main.cf file has

mydomain = localhost
alias_maps = hash:/etc/aliases
queue_directory = /var/spool/postfix
command_directory = /usr/sbin
daemon_directory = /usr/libexec/postfix
mail_owner = postfix
myorigin = $mydomain
unknown_local_recipient_reject_code = 550
mynetworks = 127.0.0.0/8, [::1]/128
debug_peer_level = 2
sendmail_path = /usr/sbin/sendmail
newaliases_path = /usr/bin/newaliases
mailq_path = /usr/bin/mailq
setgid_group = postdrop
html_directory = no
manpage_directory = /usr/local/man
sample_directory = /etc/postfix
readme_directory = no
virtual_mailbox_domains = sciencelogic.em7
virtual_mailbox_base = /var/mail
virtual_mailbox_maps = hash:/etc/postfix/silo.virtual-mailbox
virtual_uid_maps = hash:/etc/postfix/silo.virtual-uid
virtual_gid_maps = hash:/etc/postfix/silo.virtual-gid
mailbox_size_limit = 0
relayhost = authnz.proofpoint.com:587
smtp_sasl_auth_enable = yes
smtp_sasl_password_maps = hash:/etc/postfix/smtp_password
smtpd_recipient_restrictions = permit_mynetworks
local_recipient_maps =

There is no information about the email being rejected in the queue log. Running mailq > mailqueue.txt did not produce any meaningful information. I've also had the customer flush the queue with postqueue -f and restart postfix, but nothing has helped.

What is causing postfix to repeat parsing the email instead of sending it?

EDIT:

The master.cf file states (shortened for space to remove all commented-out lines):

smtp      inet  n   -   n   -   -   smtpd -v
pickup    unix  n   -   n   60  1   pickup
cleanup   unix  n   -   n   -   0   cleanup
qmgr      unix  n   -   n   300     1   qmgr
tlsmgr    unix  -   -   n   1000?   1   tlsmgr
rewrite   unix  -   -   n   -   -   trivial-rewrite
bounce    unix  -   -   n   -   0   bounce
defer     unix  -   -   n   -   0   bounce
trace     unix  -   -   n   -   0   bounce
verify    unix  -   -   n   -   1   verify
flush     unix  n   -   n   1000?   0   flush
proxymap  unix  -   -   n   -   -   proxymap
proxywrite unix -   -   n   -   1   proxymap
smtp      unix  -   -   n   -   -   smtp
relay     unix  -   -   n   -   -   smtp
showq     unix  n   -   n   -   -   showq
error     unix  -   -   n   -   -   error
retry     unix  -   -   n   -   -   error
discard   unix  -   -   n   -   -   discard
local     unix  -   n   n   -   -   local
virtual   unix  -   n   n   -   -   virtual
lmtp      unix  -   -   n   -   -   lmtp
anvil     unix  -   -   n   -   1   anvil
scache    unix  -   -   n   -   1   scache

EDIT:

postqueue -p produces:

[root@sc-sl02-lab01 ~]# postqueue -p
-Queue ID- --Size-- ----Arrival Time---- -Sender/Recipient-------
8687E226F6E*     936 Tue May 10 19:46:06  [email protected]
                                         [email protected]

88630226F70*     935 Tue May 10 19:46:06  [email protected]
                                         [email protected]

92456226F71*     933 Tue May 10 19:46:06  [email protected]
                                         [email protected]

E0986226F74*     942 Tue May 10 19:46:06  [email protected]
                                         [email protected]

EF72C36B12*     930 Tue May 10 19:46:06  [email protected]
                                         [email protected]

F1631226F78*     930 Tue May 10 19:46:06  [email protected]
                                         [email protected]

3DE91226F77*    3072 Tue May 10 19:46:11  MAILER-DAEMON
                                         [email protected]

sudo postcat -qhbe 3DE91226F77:

-- 40 Kbytes in 17 Requests.
[root@sc-sl02-lab01 ~]# sudo postcat -qhbe 3DE91226F77
*** ENVELOPE RECORDS active/3DE91226F77 ***
message_size:            3072             221               1               0            3072
message_arrival_time: Tue May 10 19:46:11 2022
create_time: Tue May 10 19:46:11 2022
named_attribute: log_message_origin=local
named_attribute: trace_flags=0
sender:
original_recipient: [email protected]
recipient: [email protected]
*** MESSAGE CONTENTS active/3DE91226F77 ***
Received: by sc-sl02-lab01.localhost (Postfix)
        id 3DE91226F77; Tue, 10 May 2022 19:46:11 +0000 (UTC)
Date: Tue, 10 May 2022 19:46:11 +0000 (UTC)
From: [email protected] (Mail Delivery System)
Subject: Undelivered Mail Returned to Sender
To: [email protected]
Auto-Submitted: auto-replied
MIME-Version: 1.0
Content-Type: multipart/report; report-type=delivery-status;
        boundary="0A32B226F7D.1652211971/sc-sl02-lab01.localhost"
Message-Id: <[email protected]>

This is a MIME-encapsulated message.

--0A32B226F7D.1652211971/sc-sl02-lab01.localhost
Content-Description: Notification
Content-Type: text/plain; charset=us-ascii

This is the mail system at host sc-sl02-lab01.localhost.

I'm sorry to have to inform you that your message could not
be delivered to one or more recipients. It's attached below.

For further assistance, please send mail to postmaster.

If you do so, please include this problem report. You can
delete your own text from the attached returned message.

                   The mail system

<[email protected]>: host
    authnz.prod-c15a-awsuse.proofpoint.com[205.220.189.150] said: 530 5.7.0
    Authentication required (in reply to MAIL FROM command)

--0A32B226F7D.1652211971/sc-sl02-lab01.localhost
Content-Description: Delivery report
Content-Type: message/delivery-status

Reporting-MTA: dns; sc-sl02-lab01.localhost
X-Postfix-Queue-ID: 0A32B226F7D
X-Postfix-Sender: rfc822; [email protected]
Arrival-Date: Tue, 10 May 2022 19:46:07 +0000 (UTC)

Final-Recipient: rfc822; [email protected]
Original-Recipient: rfc822;[email protected]
Action: failed
Status: 5.7.0
Remote-MTA: dns; authnz.prod-c15a-awsuse.proofpoint.com
Diagnostic-Code: smtp; 530 5.7.0 Authentication required

--0A32B226F7D.1652211971/sc-sl02-lab01.localhost
Content-Description: Undelivered Message
Content-Type: message/rfc822

Return-Path: <[email protected]>
Received: from [172.16.0.1] (localhost [IPv6:::1])
        by sc-sl02-lab01.localhost (Postfix) with ESMTP id 0A32B226F7D
        for <[email protected]>; Tue, 10 May 2022 19:46:07 +0000 (UTC)
MIME-Version: 1.0
Content-Type: text/plain; charset="us-ascii"
Content-Transfer-Encoding: 7bit
Subject: MAJOR Event: Load average alert,
 (Load-15) state: (True) is running above the threshold of (None)
From: EM7 LAB Event Notifier<[email protected]>
To:
CC:
X-Priority: 3
Date: Tue, 10 May 2022 19:46:07 +0000
Message-Id: <[email protected]>

Severity: MAJOR
First Occurred: 2022-05-09 11:48:18 UTC
Last Occurred: 2022-05-10 19:44:22 UTC
Occurrences: 954
Source: Dynamic
Organization: ScienceLogic Org
Device: sc-sl01-db01

Message: Load average alert, (Load-15) state: (True) is running above the threshold of (None)

Sent by Automation Action: Send Email External

View this event at: http://em7.mydomain.com/em7/index.em7?exec=events&q_type=aid&q_arg=3988100&q_sev=1&q_sort=0&q_oper=0

--0A32B226F7D.1652211971/sc-sl02-lab01.localhost--
*** HEADER EXTRACTED active/3DE91226F77 ***
*** MESSAGE FILE END active/3DE91226F77 ***
[root@sc-sl02-lab01 ~]# sudo postcat -qhbe 14CBC226F76
*** ENVELOPE RECORDS active/14CBC226F76 ***
message_size:            2962             220               1               0            2962
message_arrival_time: Tue May 10 19:46:10 2022
create_time: Tue May 10 19:46:10 2022
named_attribute: log_message_origin=local
named_attribute: trace_flags=0
sender:
original_recipient: [email protected]
recipient: [email protected]
*** MESSAGE CONTENTS active/14CBC226F76 ***
Received: by sc-sl02-lab01.localhost (Postfix)
        id 14CBC226F76; Tue, 10 May 2022 19:46:10 +0000 (UTC)
Date: Tue, 10 May 2022 19:46:10 +0000 (UTC)
From: [email protected] (Mail Delivery System)
Subject: Undelivered Mail Returned to Sender
To: [email protected]
Auto-Submitted: auto-replied
MIME-Version: 1.0
Content-Type: multipart/report; report-type=delivery-status;
        boundary="000EC226F79.1652211970/sc-sl02-lab01.localhost"
Message-Id: <[email protected]>

This is a MIME-encapsulated message.

--000EC226F79.1652211970/sc-sl02-lab01.localhost
Content-Description: Notification
Content-Type: text/plain; charset=us-ascii

This is the mail system at host sc-sl02-lab01.localhost.

I'm sorry to have to inform you that your message could not
be delivered to one or more recipients. It's attached below.

For further assistance, please send mail to postmaster.

If you do so, please include this problem report. You can
delete your own text from the attached returned message.

                   The mail system

<[email protected]>: host
    authnz.prod-c15a-awsuse.proofpoint.com[205.220.189.192] said: 530 5.7.0
    Authentication required (in reply to MAIL FROM command)

--000EC226F79.1652211970/sc-sl02-lab01.localhost
Content-Description: Delivery report
Content-Type: message/delivery-status

Reporting-MTA: dns; sc-sl02-lab01.localhost
X-Postfix-Queue-ID: 000EC226F79
X-Postfix-Sender: rfc822; [email protected]
Arrival-Date: Tue, 10 May 2022 19:46:06 +0000 (UTC)

Final-Recipient: rfc822; [email protected]
Original-Recipient: rfc822;[email protected]
Action: failed
Status: 5.7.0
Remote-MTA: dns; authnz.prod-c15a-awsuse.proofpoint.com
Diagnostic-Code: smtp; 530 5.7.0 Authentication required

--000EC226F79.1652211970/sc-sl02-lab01.localhost
Content-Description: Undelivered Message
Content-Type: message/rfc822

Return-Path: <[email protected]>
Received: from [172.16.0.1] (localhost [IPv6:::1])
        by sc-sl02-lab01.localhost (Postfix) with ESMTP id 000EC226F79
        for <[email protected]>; Tue, 10 May 2022 19:46:06 +0000 (UTC)
MIME-Version: 1.0
Content-Type: text/plain; charset="us-ascii"
Content-Transfer-Encoding: 7bit
Subject: MAJOR Event: Device Service Risk is High: 75
From: EM7 LAB Event Notifier<[email protected]>
To:
CC:
X-Priority: 3
Date: Tue, 10 May 2022 19:46:06 +0000
Message-Id: <[email protected]>

Severity: MAJOR
First Occurred: 2022-05-09 01:00:16 UTC
Last Occurred: 2022-05-10 19:45:18 UTC
Occurrences: 172
Source: Internal
Organization: System
Device: test device service

Message: Device Service Risk is High: 75

Sent by Automation Action: Send Email External

View this event at: http://em7.mydomain.com/em7/index.em7?exec=events&q_type=aid&q_arg=3987958&q_sev=1&q_sort=0&q_oper=0

--000EC226F79.1652211970/sc-sl02-lab01.localhost--
*** HEADER EXTRACTED active/14CBC226F76 ***
*** MESSAGE FILE END active/14CBC226F76 ***
anx avatar
fr flag
anx
Please add your postfix configuration as recommended in the tag, and an example of how the message appears in the queue, both might contain helpful clues. (use `postqueue -p` to list, use `postcat -qhbe QID` to review a single entry, and get more context in logs to distinguish the sender just sending the message multiple times from a malfunction on your end).
anx avatar
fr flag
anx
Other than the odd domains I don't see anything immediately obvious in your config. Where are you getting that *"It appears that"* idea from. Please share more log context and a sample message as it appears in the queue, there may actually be a clue as to what exactly postfix is doing.
in flag
Please see the edited post that includes the `master.cf` file. The `main.cf` file is the postfix configuration. I also included the `postqueue -p` and `postcat -qhbe` commands.
Nikita Kipriyanov avatar
za flag
add grep's with mail ID (e.g. `grep 0D65814D mail.log` to enhance the log excerpt in the question)
jp flag
What's the 10.2.253.96?
in flag
That is the relay for the test email I was using on my end `mailsac.com`.
anx avatar
fr flag
anx
Unrelated, but you should probably fix that `localhost` bit. Names clearly belonging to locally-administered naming schemes/roots? A-OK. But receiving mail from `localhost.localhost` containing little information which originator/relay is associated with which org/branch/room/machine? Very annoying to anyone diagnosing mail issues in the future!
Nikita Kipriyanov avatar
za flag
The best is to set real `myhostname` and leave `myorigin=$myhostname` (the default).
Score:0
fr flag
anx

authnz.prod-c15a-awsuse.proofpoint.com[205.220.189.150] said: 530 5.7.0 Authentication required (in reply to MAIL FROM command)

That sounds a lot like you are not authenticating to the relay you have configured.

relayhost = authnz.proofpoint.com:587
smtp_sasl_auth_enable = yes
smtp_sasl_password_maps = hash:/etc/postfix/smtp_password

Check the contents of /etc/postfix/smtp_password. Specifically, postfix instruct you to match the format between relayhost value and map lookup key.

If you specify a non-default TCP Port (such as ":submission" or ":587") in the relayhost destination, then you must use the same form in the smtp_sasl_password_maps file.

If this turns out to indeed be a problem with that password map, don't forget to update the indexed cache by issuing postmap /etc/postfix/smtp_password - and consider what should happen to the yet-to-be-delivered messages in your queue, you may want to update the affected recipients and senders through some other route than delivering (possibly a lot) non-delivery notifications.

mangohost

Post an answer

Most people don’t grasp that asking a lot of questions unlocks learning and improves interpersonal bonding. In Alison’s studies, for example, though people could accurately recall how many questions had been asked in their conversations, they didn’t intuit the link between questions and liking. Across four studies, in which participants were engaged in conversations themselves or read transcripts of others’ conversations, people tended not to realize that question asking would influence—or had influenced—the level of amity between the conversationalists.