DevHeads.net

Finding why outbound mail is delayed

Running postfix-3.2.4 here on Slackware-14.2. I am a professional services
sole practitioner, not a professional system or network admin.

After several years having outbound mail forwarded through my ISP's mail
server I changed ISPs and now have a static IP address. The other recent change
here is replacing the old Netgear FVS318 router with a Ubiquiti EdgeRouter-X
fast enough to take advantage of the 15/5Mbps speeds of my fiber connection.

Since the end of last week I find many messages delayed 1-2 days; several
hundred are listed in logwatch's daily report. These delayed messages
include may body_check rejections. However, since Friday pflogsumm is also
delayed rather than delivered. There are now 2 messages in the mail queue:

# mailq
-Queue ID- --Size-- ----Arrival Time---- -Sender/Recipient-------
5E148991FE 182118 Mon Nov 13 03:10:26 root
<a href="mailto:rshepard@appl-ecosys.com">rshepard@appl-ecosys.com</a>

EF1E2991FD 815 Mon Nov 13 06:59:09 <a href="mailto:rshepard@appl-ecosys.com">rshepard@appl-ecosys.com</a>
(connect to AAAAA.AAAAA.AAA[DDD.DDD.D.DD]:25: Connection timed out)
<a href="mailto:mail-list- ... at mail dot list.org">mail-list- ... at mail dot list.org</a>

The output of postdconf -Mf is attached. So is the output of the DDD log
generated after I modified master.cf by appending '-D' to the smtp line.

I need to learn how to locate the source of this problem and how to fix
it. If more information is needed let me know and I'll provide it.

TIA,

Rich

Comments

Re: Finding why outbound mail is delayed

By Simon Matthews at 11/13/2017 - 13:39

On Mon, Nov 13, 2017 at 10:02 AM, Rich Shepard <rshepard@appl-ecosys.com> wrote:
I would hazard a guess that your outbound email packets are being
dropped somewhere. Try using telnet on your mail server to connect to
port 25 of the remote mail server (mail.appl-ecosys.com.) and see what
happens.

Also, check your mail log file.

You may have to have a list of domains that you continue to relay
through your ISP's mail server. You would do this with a transport
map.

Simon

Re: Finding why outbound mail is delayed

By Rich Shepard at 11/13/2017 - 13:57

Simon,

I can telnet to port 25 of this desktop server/workstation.

My reply to Victor's message has information for only one of the three
delayed messages.

I don't relay outbound mail any longer. Frontier Communications opens Port
25 by default on business accounts, and some messages are delivered.

Thanks,

Rich

Re: Finding why outbound mail is delayed

By Simon Matthews at 11/13/2017 - 14:41

On Mon, Nov 13, 2017 at 10:57 AM, Rich Shepard <rshepard@appl-ecosys.com> wrote:
That's not what I asked.

Just because your ISP isn't blocking outgoing port 25 doesn't mean
that the recipient mail server is accepting connections from your mail
server.

I have a virtual machine that is hosted in a datacenter and I find
that some remote mail servers will not talk to it.

Simon

Re: Finding why outbound mail is delayed

By John Stoffel at 11/13/2017 - 14:12

Could it be that you mail server is looking up and finding IPv6
addresses, but you don't have IPv6 enabled on your setup? Try forcing
postfix to only use IPv4.

John

Re: Finding why outbound mail is delayed

By Rich Shepard at 11/13/2017 - 14:28

John,

I will check. A new router was installed Friday and these delays showed up
starting Saturday. I've put the old router back in service, but messages to
one mail list are still delayed.

Thanks,

Rich

Re: Finding why outbound mail is delayed

By Viktor Dukhovni at 11/13/2017 - 13:35

<a href="http://www.postfix.org/DEBUG_README.html#mail" title="http://www.postfix.org/DEBUG_README.html#mail">http://www.postfix.org/DEBUG_README.html#mail</a>

Include logs showing the complete history of a delayed message (all
log entries with the problem queue-id).

Logs are much more useful than mailq output.

The main.cf settings (as reported by postconf -n) are much more useful.

The smtpd(8) process handles inbound mail, and is not relevant in solving
outbound delivery delays. There's no need to run anything under a debugger,
the problem you have is almost certainly not a software defect.

Post configuration information and logging for a few sample problem messages.

<a href="http://www.postfix.org/DEBUG_README.html#mail" title="http://www.postfix.org/DEBUG_README.html#mail">http://www.postfix.org/DEBUG_README.html#mail</a>

Re: Finding why outbound mail is delayed

By Rich Shepard at 11/13/2017 - 13:54

Victor,

I had looked at that page and checked many of the items.

The only one found in /var/log/maillog has these entries:

Nov 13 06:59:09 salmo postfix/smtpd[19953]: EF1E2991FD: client=salmo.appl-ecosys.com[192.168.55.1]
Nov 13 06:59:10 salmo postfix/cleanup[19606]: EF1E2991FD: message-id=<alpine.LNX.2.20.1711130649350. ... at salmo dot appl-ecosys.com>
Nov 13 06:59:10 salmo postfix/qmgr[1937]: EF1E2991FD: from=<rshepard@appl-ecosys.com>, size=815, nrcpt=1 (queue active)
Nov 13 06:59:10 salmo postfix/smtpd[19953]: disconnect from salmo.appl-ecosys.com[192.168.55.1] ehlo=1 mail=1 rcpt=1 data=1 quit=1 commands=5
Nov 13 06:59:40 salmo postfix/smtp[19954]: connect to
aaaaa.aaaaa.aaa[ddd.ddd.d.dd]:25: Connection timed out
Nov 13 06:59:40 salmo postfix/smtp[19954]: EF1E2991FD:
to=<aaa- ... at aaaaa dot aaa.aaa>, relay=none, delay=31, delays=0.09/0.69/30/0, dsn=4.4.1, status=deferred (connect to
aaaaa.aaaaaa.aaa[ddd.ddd.d.dd]:25: Connection timed out)

The above repeats every hour.

I checked using a testing site and I'm not on any blacklists and there are
no reports of my IP address being greylisted. And this does not explain the
delay on an internally-generated maillog report produced at 3:10 am today.

On the DEBUG_README page I read to use -Mf rather than -n with versions
greater than 2.9; postconf -n results attached.

Thanks for clarifying.

Regards,

Rich

Re: Finding why outbound mail is delayed

By Viktor Dukhovni at 11/13/2017 - 14:16

Where should the mail be going? Is the obfuscated host[ip] to which
connections are failing the right destination?

Your configuration shows:

body_checks = regexp:/etc/postfix/body_checks
header_checks = regexp:/etc/postfix/header_checks

Do either of these have any patterns with a "FILTER" action?

mydestination = $myhostname, mail.$mydomain, localhost.$mydomain, localhost.$mydomain, $mydomain, /etc/postfix/local/localdomains
mydomain = appl-ecosys.com

This domain is listed in $mydestination, and should have been handed
off to the "local" transport, and yet it seems it is going out via
smtp(8). So either we're not looking at the right configuration,
or there's a transport override (or FILTER action) hiding somewhere.

smtpd_client_restrictions =
check_client_access hash:/etc/postfix/internal_network,
permit_mynetworks,
check_sender_access hash:/etc/postfix/sender_no_greylist,
check_sender_mx_access cidr:/etc/postfix/bogus_mx,
check_sender_access hash:/etc/postfix/rhsbl_sender_exceptions,
check_client_access hash:/etc/postfix/badaddr,
check_client_access cidr:/etc/postfix/badip,
check_sender_access hash:/etc/postfix/common_spam_senderdomains,
check_client_access cidr:/etc/postfix/cidr/africa.cidr,
check_client_access cidr:/etc/postfix/cidr/central-asia.cidr,
check_client_access cidr:/etc/postfix/cidr/east-asia.cidr,
check_client_access cidr:/etc/postfix/cidr/east-europe.cidr,
check_client_access cidr:/etc/postfix/cidr/spammers.cidr,
check_client_access cidr:/etc/postfix/cidr/latin-america.cidr,
check_client_access cidr:/etc/postfix/cidr/middle-east.cidr,
reject_rbl_client zen.spamhaus.org,
reject_rbl_client dul.dnsbl.sorbs.net,
reject_rbl_client sbl-xbl.spamhaus.org,
reject_rbl_client combined.njabl.org,
reject_rbl_client psbl.surriel.com,
reject_rbl_client bl.spamcop.net,
reject_rhsbl_sender dsn.rfc-ignorant.org,
permit

Any FILTER actions in any of the access tables above? [BTW,
IIRC sbl-xbl.spamhaus.org is a subset of zen.spamhaus.org,
so you should not also query the former when using the latter]

smtpd_recipient_restrictions =
permit_sasl_authenticated,
permit_mynetworks,
reject_unauth_destination,
check_recipient_access hash:/etc/postfix/roleaccount_exceptions,
check_recipient_access hash:/etc/postfix/recipients,
check_helo_access pcre:/etc/postfix/helo_checks,
reject_non_fqdn_recipient,
reject_non_fqdn_sender,
reject_unknown_client_hostname,
reject_unknown_reverse_client_hostname,
reject_non_fqdn_hostname,
reject_invalid_hostname,
permit
reject_multi_recipient_bounce

Any FILTER actions in the above? [BTW rules after "permit"
can't possibly do anything]

soft_bounce = yes

This can make messages linger that should have bounced. Should
not be on long-term.

Re: Finding why outbound mail is delayed

By Rich Shepard at 11/13/2017 - 14:26

Victor,

They are a mail list. It doesn't really need obfuscation:
thales.memphis.edu[141.225.8.55]:25

No, neither does.

I've not changed main.cf (other than applying updates from new versions of
postfix) and this delay issue appeared only over the weekend. If there's a
change to be made, please tell me and I'll make it.

If there's a FILTER action it's not been added by me.

I've removed sbl-xbl.spamhaus.org. Thank you.

No FILTERs I've added; the final line is the end of this one:
#smtp_data_restrictions = reject_multi_recipient_bounce
Now on one line again.

Thank you. Changed to 'no'.

Rich

Re: Finding why outbound mail is delayed

By Viktor Dukhovni at 11/13/2017 - 14:39

IIRC your original message showed a delayed message addressed to
you. I failed to notice that this one was addressed to a different
domain...

That host is down. Not much you can do about that:

$ posttls-finger thales.memphis.edu
posttls-finger: Failed to establish session to thales.memphis.edu via thales.memphis.edu: connect to thales.memphis.edu[141.225.8.55]:25: Operation timed out

If you have delivery issues with some other mail, post logs
for that.

Re: Finding why outbound mail is delayed

By Rich Shepard at 11/13/2017 - 15:05

Victor,

Yes, one of the delayed messages was the pflogsumm report; it was
delivered when I took the new router off-line and replaced it with the old
(DSL-capable) one.

Oh. Thanks. I didn't think to check with everything else going on.

No, I think the brand-new Ubiquiti EdgeRouter-X failed the day after it
was put into service. I've contacted Amazon and they're sending a
replacement.

My thanks to everyone,

Rich