Page 1 of 1

SMTPD timeouts, one particular server farm

Posted: 2019-11-20 12:21
by RvdH
I have been busy monitoring SMTPD connections that seem to have trouble receiving mail right our hmailserver instance sends the DATA command to the external (sending) server, below an example:
"SMTPD" 6376 119919 "2019-11-20 09:34:08.238" "66.117.17.55" "SENT: 220 mail.domain.com ESMTP"
"SMTPD" 1064 119919 "2019-11-20 09:34:08.253" "66.117.17.55" "RECEIVED: EHLO r55.p26.neolane.net"
"SMTPD" 1064 119919 "2019-11-20 09:34:08.441" "66.117.17.55" "SENT: 250-mail.domain.com[nl]250-SIZE 51200000[nl]250-STARTTLS[nl]250 HELP"
"SMTPD" 2568 119919 "2019-11-20 09:34:08.456" "66.117.17.55" "RECEIVED: MAIL FROM:<adobeemea@mail.adobe.com>"
"SMTPD" 2568 119919 "2019-11-20 09:34:08.597" "66.117.17.55" "SENT: 250 OK"
"SMTPD" 2568 119919 "2019-11-20 09:34:08.628" "66.117.17.55" "RECEIVED: RCPT TO:<receiver@domain.com>"
"SMTPD" 2568 119919 "2019-11-20 09:34:08.628" "66.117.17.55" "SENT: 250 OK"
"SMTPD" 7160 119919 "2019-11-20 09:34:08.643" "66.117.17.55" "RECEIVED: DATA"
"SMTPD" 7160 119919 "2019-11-20 09:34:09.236" "66.117.17.55" "SENT: 354 OK, send."
"SMTPD" 6376 119919 "2019-11-20 10:04:09.411" "66.117.17.55" "SENT: 421 Connection timeout."
66.117.17.55 = ASN/ISP: AS15224 Adobe Systems Inc.
The above IP resolves to r55.info.adobesystems.com, and i have seen more connections like this designating from IP's owned by Adobe, eg:
"SMTPD" 3980 75470 "2019-11-19 00:05:11.302" "172.82.232.130" "SENT: 220 mail.domain.com ESMTP"
"SMTPD" 3984 75470 "2019-11-19 00:05:11.314" "172.82.232.130" "RECEIVED: EHLO r130.email.hm.com"
"SMTPD" 3984 75470 "2019-11-19 00:05:11.361" "172.82.232.130" "SENT: 250-mail.domain.com[nl]250-SIZE 51200000[nl]250-STARTTLS[nl]250 HELP"
"SMTPD" 3984 75470 "2019-11-19 00:05:11.388" "172.82.232.130" "RECEIVED: MAIL FROM:<hetm-mid@email.hm.com>"
"SMTPD" 3984 75470 "2019-11-19 00:05:11.517" "172.82.232.130" "SENT: 250 OK"
"SMTPD" 3964 75470 "2019-11-19 00:05:11.533" "172.82.232.130" "RECEIVED: RCPT TO:<receiver@domain.com>"
"SMTPD" 3964 75470 "2019-11-19 00:05:11.548" "172.82.232.130" "SENT: 250 OK"
"SMTPD" 3984 75470 "2019-11-19 00:05:11.580" "172.82.232.130" "RECEIVED: DATA"
"SMTPD" 3984 75470 "2019-11-19 00:05:11.580" "172.82.232.130" "SENT: 354 OK, send."
"SMTPD" 3956 75470 "2019-11-19 00:35:11.625" "172.82.232.130" "SENT: 421 Connection timeout."
172.82.232.130 = ASN/ISP: AS15224 Adobe Systems Inc.


Anyone has a idea what might be going on here? Or anyone has same issues with mail designating from Adobe servers?


In the meantime i disconnect everything immediately coming from a known adobe host in the OnHelo handler, after a while i noticed the message are eventually coming through using the backup MX
the backup MX doesn't seem to have issues with receiving those messages and relaying them to our clients

Re: SMTPD timeouts, one particular server farm

Posted: 2019-11-20 12:35
by mattg
Is this ALL mail from them

Is this caught in one of your filters?

Re: SMTPD timeouts, one particular server farm

Posted: 2019-11-20 12:46
by RvdH
These are just 2 examples i see regularly....but this is going on for a few months. I assume these are simply marketing e-mails

In OnSMTPData i have no more then the check(s) that block mail when the message is not sent from the authenticated account/domain (eg: only checks are for authenticated users)
Other checks, like spamassassin are not executed as the connection times-out before that and no data, or not all data is completely received

Re: SMTPD timeouts, one particular server farm

Posted: 2019-11-20 14:14
by Dravion
Some MTAs are configured for sending only while other MTAs are configured for inbound only mail.

Re: SMTPD timeouts, one particular server farm

Posted: 2019-11-20 15:27
by RvdH
Dravion wrote:
2019-11-20 14:14
Some MTAs are configured for sending only while other MTAs are configured for inbound only mail.
I talking about our own hmailserver instance that is allowed to send and receive
I have dozens of log entries like the above designating from Adobe owned servers trying to send to our hmailserver instance.... not entirely sure what you are tying to say, but much sense it doesn't make

Re: SMTPD timeouts, one particular server farm

Posted: 2019-11-20 16:22
by SorenR
Are you using the Wait() function in your script?

Some bulk senders are not happy being told to "wait a second while we waste your time" :mrgreen:

Re: SMTPD timeouts, one particular server farm

Posted: 2019-11-20 16:34
by RvdH
Nope, no wait()

Or at least not directly within OnSMTPData, I use that lockfile function in OnHELO for AddGreyList(oClient.IPAddress, oClient.HELO) for my dynamic greywhitelisting function, but even that function is not triggered on those domains

Re: SMTPD timeouts, one particular server farm

Posted: 2019-11-20 16:54
by RvdH
To make it more confusing, this one came thru without a glitch... but then again, apart from similar HELO (i am monitoring troublesome host by their HELO message) this ip doesn't seem designated to Adobe
"SMTPD" 6376 124993 "2019-11-20 15:19:30.215" "62.210.194.156" "SENT: 220 mail.domain.com ESMTP"
"SMTPD" 4360 124993 "2019-11-20 15:19:30.231" "62.210.194.156" "RECEIVED: EHLO r156.p4.neolane.net"
"SMTPD" 4360 124993 "2019-11-20 15:19:30.231" "62.210.194.156" "SENT: 250-mail.domain.com[nl]250-SIZE 51200000[nl]250-STARTTLS[nl]250 HELP"
"SMTPD" 1828 124993 "2019-11-20 15:19:30.246" "62.210.194.156" "RECEIVED: MAIL FROM:<christies@emails.christies.com>"
"SMTPD" 1828 124993 "2019-11-20 15:19:30.403" "62.210.194.156" "SENT: 250 OK"
"SMTPD" 1828 124993 "2019-11-20 15:19:30.419" "62.210.194.156" "RECEIVED: RCPT TO:<receiver@domain.com>"
"SMTPD" 1828 124993 "2019-11-20 15:19:30.466" "62.210.194.156" "SENT: 250 OK"
"SMTPD" 6376 124993 "2019-11-20 15:19:30.466" "62.210.194.156" "RECEIVED: DATA"
"SMTPD" 6376 124993 "2019-11-20 15:19:30.528" "62.210.194.156" "SENT: 354 OK, send."
"SMTPD" 7076 124993 "2019-11-20 15:19:31.292" "62.210.194.156" "SENT: 250 Queued (0.704 seconds)"
"SMTPD" 6376 124993 "2019-11-20 15:19:37.009" "62.210.194.156" "RECEIVED: QUIT"
"SMTPD" 6376 124993 "2019-11-20 15:19:37.009" "62.210.194.156" "SENT: 221 goodbye"

Re: SMTPD timeouts, one particular server farm

Posted: 2019-11-20 17:38
by Dravion
Looks like the receiving MTA doesn't get the mandatory "." character which should (under normal circumstances) initiate a Socketshutdown procedure and normal Disconnect.

But hMailServer SMTP never receives the final "."
char and waits until the normal SMTP-Transaction threshold is reached which triggers a forcefull disconnect by hMailServer.

IMHO:
The only way to really understand whats going on is to run Wireshark and capure the entire traffic on port 25 and compare the difference between normal and timeout causing connections.

Re: SMTPD timeouts, one particular server farm

Posted: 2019-11-20 20:24
by mikedibella
Are SURBL queries blocking? Could they introduce a delay of 30 seconds, enough to trigger a TCP receive timeout?

Re: SMTPD timeouts, one particular server farm

Posted: 2019-11-20 23:27
by Dravion
PS:
If possible, run Wireshark in cases where incomning connections are timing out, logged by hMailServer, stop
Wireshark and attach your resulting Wireshark *.pcap log file as a zipped archive in your next reply. I will take a look into it.

Re: SMTPD timeouts, one particular server farm

Posted: 2019-11-21 02:18
by RvdH
mikedibella wrote:
2019-11-20 20:24
Are SURBL queries blocking? Could they introduce a delay of 30 seconds, enough to trigger a TCP receive timeout?
Nah, SURBL check are done by SpamAssassin, none enabled in hmailserver itself.... and btw, it's a 30 minutes delay until the timeout, not 30 seconds
Dravion wrote:
2019-11-20 23:27
PS:
If possible, run Wireshark in cases where incomning connections are timing out, logged by hMailServer, stop
Wireshark and attach your resulting Wireshark *.pcap log file as a zipped archive in your next reply. I will take a look into it.
Think this will be difficult...don't think my boss likes me to install a packet sniffer on a production server