Testing mail-server with mxtoolbox -- SMTP connection time over 5 seconds?

Question

We're having intermittent problems receiving e-mails from one company, and their side are pointing out, that our server takes just over 5 seconds to respond to incoming SMTP connections, whereas their limit is 5...

Indeed, testing our server with MXToolbox, I do see:

	Test	Result
⚠️	SMTP Banner Check	Reverse DNS does not match SMTP Banner
⚠️	SMTP Connection Time	5.221 seconds - Warning on Connection time
⚠️	SMTP Transaction Time	5.624 seconds - Warning on Transaction Time
✅	SMTP Reverse DNS Mismatch	OK - my.ip.add.res resolves to fios-hostname.verizon.net
✅	SMTP Valid Hostname	OK - Reverse DNS is a valid Hostname
✅	SMTP TLS	OK - Supports TLS.
✅	SMTP Open Relay	OK - Not an open relay.

So, the tool does report 5+ seconds of connection time, but all I see in the log on the server-side is one second:

Sep  4 10:43:32 x skem[15255]: connection from keeper-us-east-1d.mxtoolbox.com (18.209.86.113)
Sep  4 10:43:33 x sm-mta[27774]: 484EhW8u027774: ruleset=check_rcpt, arg1=<[email protected]>, relay=keeper-us-east-1d.mxtoolbox.com [18.209.86.113], reject=550 5.7.1 <[email protected]>... Relaying denied

SKEM is the first "milter" in our line of defenses Where would that five-second delay come from? Are they counting the time it takes to establish the TCP connection itself? Is it "fair" to blame us for any delays with that?

We do use DNSBL:

FEATURE(`dnsbl', `cbl.abuseat.org', `"550 Mail from " $&{client_addr} " rejected - see https://check.spamhaus.org/listed/?searchterm=" $&{client_addr}')
FEATURE(`enhdnsbl', `bl.spamcop.net', `"Spam blocked see: http://spamcop.net/bl.shtml?"$&{client_addr}', `t')dnl

but in my own testing both of those reply almost instantaneously. What else could be the problem?

---

Update: when I try time telnet our.ser.ver.net < /dev/null from a remote machine in a different city (and on a different Internet-provider's network), I get 2 seconds the first time, and 0.1 second subsequently (as the DNS information gets into local cache).

Where are the other 3 second coming from?

Answer 1

all I see in the log on the server-side is one second:

The log only begins once the TCP connection has been made – the SMTP service remains unaware of it while the OS is doing the handshake. (Therefore it also doesn't do any DNSBL checks during the TCP handshake; it's done after.)

Use a packet capture tool (such as Wireshark or tcpdump) to see the individual packets. For example:

tcpdump -n -i eth0 "host 18.209.86.113 and port 25"

Are they counting the time it takes to establish the TCP connection itself? Is it "fair" to blame us for any delays with that?

If they do, then yes it would be "fair", because the time it takes to establish a TCP connection is usually one RTT (the time it takes for one SYN / SYN exchange), or in other words almost exactly the same as your "ping" to the client, and that rarely if ever reaches 0.5s – even if the connection is made across continents, so your physical location is not the issue, while most other sources of latency (especially as high as this) would usually be under your control, whether it is running a server on LTE connection or on a massively overloaded CPU.

But my own guess is that your DNS entry has multiple IP addresses (A and/or AAAA records) and some of them are incorrect, causing the client to wait for a 5s timeout before trying the next address.

So instead of a high-level SMTP tester, take the time to test the individual parts that make up the connection. Measure the time it takes to look up your domain via DNS (some of your authoritative nameservers may be down). Verify that DNS returns the correct MX and that it returns the correct A/AAAA for that. (Run the domain through DNSViz just in case.) Verify that a raw TCP connection (e.g. nc -vvz) to each of those IP addresses is established quickly. Only then start measuring how long it takes from the TCP connection to the syslog message and the SMTP greeting line to show up. (Again tcpdump would be able to show this.)