Warning on Connection time

classic Classic list List threaded Threaded
4 messages Options
Reply | Threaded
Open this post in threaded view
|

Warning on Connection time

John Schmerold

https://mxtoolbox.com/diagnostic.aspx reported a six second connection time, with total transaction time of nearly 9 seconds, so I dug into the issue. I suspect I have rbl issues (perhaps too many):

postscreen_dnsbl_sites = cbl.abuseat.org*2,dnsbl-1.uceprotect.net,zen.spamhaus.org*2,bl.spamcop.net*2,psbl.surriel.com*2,spamrbl.imp.ch*2,noptr.spamrats.com*2,escalations.dnsbl.sorbs.net*2,bl.score.senderscore.com*2,bl.spameatingmonkey.net*2,rbl.realtimeblacklist.com*2,dnsbl.dronebl.org*2,ix.dnsbl.manitu.net,b.barracudacentral.org,truncate.gbudb.net*2,bl.blocklist.de,sip-sip24.xxx.invaluement.com
postscreen_dnsbl_threshold = 3

Logs say:
Nov  2 15:07:58 stl-mx postfix/postscreen[31774]: CONNECT from [52.55.244.91]:25071 to [206.196.118.234]:25
Nov  2 15:08:04 stl-mx postfix/postscreen[31774]: PASS NEW [52.55.244.91]:25071
Nov  2 15:08:04 stl-mx pmg-smtp-filter[2151]: starting database maintainance
Nov  2 15:08:04 stl-mx postfix/smtpd[3017]: connect from keeper-us-east-1b.mxtoolbox.com[52.55.244.91]
Nov  2 15:08:06 stl-mx postfix/smtpd[3017]: NOQUEUE: reject: RCPT from keeper-us-east-1b.mxtoolbox.com[52.55.244.91]: 554 5.7.1 [hidden email]: Relay access denied; from=[hidden email] to=<test@mxtoolboxsmtpdiag$
Nov  2 15:08:06 stl-mx pmgpolicy[2902]: SPF says pass
Nov  2 15:08:06 stl-mx postfix/smtpd[3051]: NOQUEUE: reject: RCPT from mail-oln040092072060.outbound.protection.outlook.com[40.92.72.60]: 450 4.1.1 [hidden email]: Recipient address rejected: unverified address: Recipient add$
Nov  2 15:08:07 stl-mx postfix/smtpd[3051]: disconnect from mail-oln040092072060.outbound.protection.outlook.com[40.92.72.60] ehlo=2 starttls=1 mail=1 rcpt=0/1 quit=1 commands=5/6
Nov  2 15:08:07 stl-mx postfix/smtpd[3017]: disconnect from keeper-us-east-1b.mxtoolbox.com[52.55.244.91] ehlo=1 mail=1 rcpt=0/1 quit=1 commands=3/4

What is the best way to troubleshoot this issue?

-- 
John Schmerold
Katy Computer Systems, Inc
https://katycomputer.com
St Louis
Reply | Threaded
Open this post in threaded view
|

Re: Warning on Connection time

Matus UHLAR - fantomas
On 02.11.19 15:20, John Schmerold wrote:
>https://mxtoolbox.com/diagnostic.aspx reported a six second connection
>time, with total transaction time of nearly 9 seconds, so I dug into
>the issue. I suspect I have rbl issues (perhaps too many):
>
>postscreen_dnsbl_sites = cbl.abuseat.org*2,dnsbl-1.uceprotect.net,zen.spamhaus.org*2,bl.spamcop.net*2,psbl.surriel.com*2,spamrbl.imp.ch*2,noptr.spamrats.com*2,escalations.dnsbl.sorbs.net*2,bl.score.senderscore.com*2,bl.spameatingmonkey.net*2,rbl.realtimeblacklist.com*2,dnsbl.dronebl.org*2,ix.dnsbl.manitu.net,b.barracudacentral.org,truncate.gbudb.net*2,bl.blocklist.de,sip-sip24.xxx.invaluement.com
>postscreen_dnsbl_threshold = 3

standard time for waiting with ESMTP welcome screen is 6 seconds.
you didn't show ourput of dnsblog but is't possibl that dnsbl lookups last
too long.

>Logs say:
>Nov  2 15:07:58 stl-mx postfix/postscreen[31774]: CONNECT from
>[52.55.244.91]:25071 to [206.196.118.234]:25
>Nov  2 15:08:04 stl-mx postfix/postscreen[31774]: PASS NEW
>[52.55.244.91]:25071
>Nov  2 15:08:04 stl-mx pmg-smtp-filter[2151]: starting database maintainance
>Nov  2 15:08:04 stl-mx postfix/smtpd[3017]: connect from
>keeper-us-east-1b.mxtoolbox.com[52.55.244.91]
>Nov  2 15:08:06 stl-mx postfix/smtpd[3017]: NOQUEUE: reject: RCPT from
>keeper-us-east-1b.mxtoolbox.com[52.55.244.91]: 554 5.7.1
><[hidden email]>: Relay access denied;
>from=<[hidden email]> to=<test@mxtoolboxsmtpdiag$
>Nov  2 15:08:06 stl-mx pmgpolicy[2902]: SPF says pass
>Nov  2 15:08:06 stl-mx postfix/smtpd[3051]: NOQUEUE: reject: RCPT from
>mail-oln040092072060.outbound.protection.outlook.com[40.92.72.60]: 450
>4.1.1 <[hidden email]>: Recipient address rejected:
>unverified address: Recipient add$
>Nov  2 15:08:07 stl-mx postfix/smtpd[3051]: disconnect from
>mail-oln040092072060.outbound.protection.outlook.com[40.92.72.60]
>ehlo=2 starttls=1 mail=1 rcpt=0/1 quit=1 commands=5/6
>Nov  2 15:08:07 stl-mx postfix/smtpd[3017]: disconnect from
>keeper-us-east-1b.mxtoolbox.com[52.55.244.91] ehlo=1 mail=1 rcpt=0/1
>quit=1 commands=3/4

--
Matus UHLAR - fantomas, [hidden email] ; http://www.fantomas.sk/
Warning: I wish NOT to receive e-mail advertising to this address.
Varovanie: na tuto adresu chcem NEDOSTAVAT akukolvek reklamnu postu.
I don't have lysdexia. The Dog wouldn't allow that.
Reply | Threaded
Open this post in threaded view
|

Re: Warning on Connection time

Bill Cole-3
In reply to this post by John Schmerold
On 2 Nov 2019, at 16:20, John Schmerold wrote:

> https://mxtoolbox.com/diagnostic.aspx reported a six second connection
> time,

Feature, not bug. Postscreen's greeting pause puts 6 seconds between the
lines of the initial greeting for clients that are not cached. e.g.:

> Logs say:
> Nov  2 15:07:58 stl-mx postfix/postscreen[31774]: CONNECT from
> [52.55.244.91]:25071 to [206.196.118.234]:25
> Nov  2 15:08:04 stl-mx postfix/postscreen[31774]: PASS NEW
> [52.55.244.91]:25071


> with total transaction time of nearly 9 seconds, so I dug into the
> issue. I suspect I have rbl issues (perhaps too many):
>
> postscreen_dnsbl_sites =
> cbl.abuseat.org*2,dnsbl-1.uceprotect.net,zen.spamhaus.org*2,bl.spamcop.net*2,psbl.surriel.com*2,spamrbl.imp.ch*2,noptr.spamrats.com*2,escalations.dnsbl.sorbs.net*2,bl.score.senderscore.com*2,bl.spameatingmonkey.net*2,rbl.realtimeblacklist.com*2,dnsbl.dronebl.org*2,ix.dnsbl.manitu.net,b.barracudacentral.org,truncate.gbudb.net*2,bl.blocklist.de,sip-sip24.xxx.invaluement.com
> postscreen_dnsbl_threshold = 3

Too many isn't a problem so much as having one that is particularly
slow. However, since you are using all of the Spamhaus Zen response
values, using cbl.abuseat.org is redundant: the CBL has been fully
absorbed by Spamhaus and there's no latency issue as there was in the
past.

>
> Logs say:
> Nov  2 15:07:58 stl-mx postfix/postscreen[31774]: CONNECT from
> [52.55.244.91]:25071 to [206.196.118.234]:25
> Nov  2 15:08:04 stl-mx postfix/postscreen[31774]: PASS NEW
> [52.55.244.91]:25071
> Nov  2 15:08:04 stl-mx pmg-smtp-filter[2151]: starting database
> maintainance
> Nov  2 15:08:04 stl-mx postfix/smtpd[3017]: connect from
> keeper-us-east-1b.mxtoolbox.com[52.55.244.91]
> Nov  2 15:08:06 stl-mx postfix/smtpd[3017]: NOQUEUE: reject: RCPT
> from keeper-us-east-1b.mxtoolbox.com[52.55.244.91]: 554 5.7.1
> <[hidden email]>: Relay access denied;
> from=<[hidden email]> to=<test@mxtoolboxsmtpdiag$
> Nov  2 15:08:06 stl-mx pmgpolicy[2902]: SPF says pass
> Nov  2 15:08:06 stl-mx postfix/smtpd[3051]: NOQUEUE: reject: RCPT
> from
> mail-oln040092072060.outbound.protection.outlook.com[40.92.72.60]: 450
> 4.1.1 <[hidden email]>: Recipient address rejected:
> unverified address: Recipient add$
> Nov  2 15:08:07 stl-mx postfix/smtpd[3051]: disconnect from
> mail-oln040092072060.outbound.protection.outlook.com[40.92.72.60]
> ehlo=2 starttls=1 mail=1 rcpt=0/1 quit=1 commands=5/6
> Nov  2 15:08:07 stl-mx postfix/smtpd[3017]: disconnect from
> keeper-us-east-1b.mxtoolbox.com[52.55.244.91] ehlo=1 mail=1 rcpt=0/1
> quit=1 commands=3/4
>
> What is the best way to troubleshoot this issue?

To start with, I don't see this as a significant issue. Sites that send
you enough mail to stay cached will see substantially less delay on
average, with 9 seconds being the occasional maximum. If that's too
long, you're demanding too much of email.

However, you may be getting the bulk of the delay after the greeting
pause from an identifiable subset of the DNSBLs you're checking. You can
test that by timing fresh manual queries to each of them and seeing if
any stand out as persistently slow.


--
Bill Cole
[hidden email] or [hidden email]
(AKA @grumpybozo and many *@billmail.scconsult.com addresses)
Reply | Threaded
Open this post in threaded view
|

Re: Warning on Connection time

John Schmerold
In reply to this post by John Schmerold
On 11/2/2019 3:20 PM, John Schmerold wrote:

https://mxtoolbox.com/diagnostic.aspx reported a six second connection time, with total transaction time of nearly 9 seconds, so I dug into the issue. I suspect I have rbl issues (perhaps too many):

postscreen_dnsbl_sites = cbl.abuseat.org*2,dnsbl-1.uceprotect.net,zen.spamhaus.org*2,bl.spamcop.net*2,psbl.surriel.com*2,spamrbl.imp.ch*2,noptr.spamrats.com*2,escalations.dnsbl.sorbs.net*2,bl.score.senderscore.com*2,bl.spameatingmonkey.net*2,rbl.realtimeblacklist.com*2,dnsbl.dronebl.org*2,ix.dnsbl.manitu.net,b.barracudacentral.org,truncate.gbudb.net*2,bl.blocklist.de,sip-sip24.xxx.invaluement.com
postscreen_dnsbl_threshold = 3

Logs say:
Nov  2 15:07:58 stl-mx postfix/postscreen[31774]: CONNECT from [52.55.244.91]:25071 to [206.196.118.234]:25
Nov  2 15:08:04 stl-mx postfix/postscreen[31774]: PASS NEW [52.55.244.91]:25071
Nov  2 15:08:04 stl-mx pmg-smtp-filter[2151]: starting database maintainance
Nov  2 15:08:04 stl-mx postfix/smtpd[3017]: connect from keeper-us-east-1b.mxtoolbox.com[52.55.244.91]
Nov  2 15:08:06 stl-mx postfix/smtpd[3017]: NOQUEUE: reject: RCPT from keeper-us-east-1b.mxtoolbox.com[52.55.244.91]: 554 5.7.1 [hidden email]: Relay access denied; from=[hidden email] to=<test@mxtoolboxsmtpdiag$
Nov  2 15:08:06 stl-mx pmgpolicy[2902]: SPF says pass
Nov  2 15:08:06 stl-mx postfix/smtpd[3051]: NOQUEUE: reject: RCPT from mail-oln040092072060.outbound.protection.outlook.com[40.92.72.60]: 450 4.1.1 [hidden email]: Recipient address rejected: unverified address: Recipient add$
Nov  2 15:08:07 stl-mx postfix/smtpd[3051]: disconnect from mail-oln040092072060.outbound.protection.outlook.com[40.92.72.60] ehlo=2 starttls=1 mail=1 rcpt=0/1 quit=1 commands=5/6
Nov  2 15:08:07 stl-mx postfix/smtpd[3017]: disconnect from keeper-us-east-1b.mxtoolbox.com[52.55.244.91] ehlo=1 mail=1 rcpt=0/1 quit=1 commands=3/4

What is the best way to troubleshoot this issue?

-- 
John Schmerold
Katy Computer Systems, Inc
https://katycomputer.com
St Louis

I grepped mail.log and found that escalations.dnsbl.sorbs.net & rbl.realtimeblacklist.com were throwing off quite a few "Host or domain name not found. Name service error for name" error messages, so now I'll need to find a way to keep an eye on this issue.

New mxtoolbox stats:
SMTP Connection time: 0.719 seconds
SMTP Transaction time: 2.656 seconds