Slow Response on Local NIC

Use this forum if you have installed hMailServer and want to ask a question related to a production release of hMailServer. Before posting, please read the troubleshooting guide. A large part of all reported issues are already described in detail here.
Post Reply
nicolasft
New user
New user
Posts: 20
Joined: 2019-03-27 20:44

Slow Response on Local NIC

Post by nicolasft » 2020-06-09 18:22

Hello everyone,
I have 2 servers both with independent internet connection, but with a direct network connection between the two 1Gb computers both machines have a 2Mb internet link

Machine 1 sends the STMP command to machine 2 that has HMailServer installed,

It happens that if machine 1 sends the command to machine 2 over the local 1Gb network, the response is extremely slow, but if sent via the internet link, the response is extremely fast,

The difference is 1 second for each request as can be seen in the logs below,

What could be happening? Since the internal 1Gb link is much faster than the internet?

Log sending over the internet see that the response time is 0.000

Code: Select all

"SMTPD"	3304	28	"2020-06-09 13:18:18.189"	"200.201.XXX.XXX"	"RECEIVED: DATA"
"SMTPD"	3304	28	"2020-06-09 13:18:18.189"	"200.201.XXX.XXX"	"SENT: 354 OK, send."
"DEBUG"	5272	"2020-06-09 13:18:18.189"	"Adding task AsynchronousTask to work queue Asynchronous task queue"
"DEBUG"	4360	"2020-06-09 13:18:18.189"	"Executing task AsynchronousTask in work queue Asynchronous task queue"
"DEBUG"	4360	"2020-06-09 13:18:18.189"	"Saving message: {C6E7E3A6-E5AF-470C-9AD3-D774BB0BBCD8}.eml"
"DEBUG"	4360	"2020-06-09 13:18:18.204"	"Requesting SMTPDeliveryManager to start message delivery"
"SMTPD"	4360	28	"2020-06-09 13:18:18.204"	"200.201.XXX.XXX"	"SENT: 250 Queued (0.000 seconds)"
Log sending over 1Gb network with direct connection 1.015 seconds)

Code: Select all

"SMTPD"	5272	30	"2020-06-09 13:19:29.229"	"10.10.0.20"	"RECEIVED: DATA"
"SMTPD"	5272	30	"2020-06-09 13:19:29.229"	"10.10.0.20"	"SENT: 354 OK, send."
"DEBUG"	3304	"2020-06-09 13:19:30.254"	"Adding task AsynchronousTask to work queue Asynchronous task queue"
"DEBUG"	4360	"2020-06-09 13:19:30.254"	"Executing task AsynchronousTask in work queue Asynchronous task queue"
"DEBUG"	4360	"2020-06-09 13:19:30.254"	"Saving message: {ACB5621A-7311-4F99-AF62-90602128B9A4}.eml"
"DEBUG"	4360	"2020-06-09 13:19:30.254"	"Requesting SMTPDeliveryManager to start message delivery"
"SMTPD"	4360	30	"2020-06-09 13:19:30.254"	"10.10.0.20"	"SENT: 250 Queued (1.015 seconds)"

User avatar
jimimaseye
Moderator
Moderator
Posts: 8727
Joined: 2011-09-08 17:48

Re: Slow Response on Local NIC

Post by jimimaseye » 2020-06-09 18:43

We need more detail other than what you have snipped. Please show the entire smtpd and debug logging. (I suspect it is anti-spam checking).

[Entered by mobile. Excuse my spelling.]
5.7 on test.
SpamassassinForWindows 3.4.0 spamd service
AV: Clamwin + Clamd service + sanesecurity defs : https://www.hmailserver.com/forum/viewtopic.php?f=21&t=26829

User avatar
johang
Senior user
Senior user
Posts: 323
Joined: 2008-09-01 09:20

Re: Slow Response on Local NIC

Post by johang » 2020-06-09 18:49

i second that ... more details needed ..

and my question is: are you sure it is mailserver related only?
( do you have the same experience if you transfer files between the 2 computers )
___________________________________________________________end of the line
spam filter appliance gateway: www.mailcleaner.org

nicolasft
New user
New user
Posts: 20
Joined: 2019-03-27 20:44

Re: Slow Response on Local NIC

Post by nicolasft » 2020-06-09 18:50

Of course, follow the entire log of the item that is slow, I don't do any SPAM or ANTIVIRUS queries

Code: Select all

"TCPIP"	2820	"2020-06-09 13:19:29.229"	"TCP - 10.10.0.20 connected to 10.10.0.10:8027."
"DEBUG"	2820	"2020-06-09 13:19:29.229"	"TCP connection started for session 30"
"SMTPD"	2820	30	"2020-06-09 13:19:29.229"	"10.10.0.20"	"SENT: 220 XXXXXXXXXXX"
"SMTPD"	5248	30	"2020-06-09 13:19:29.229"	"10.10.0.20"	"RECEIVED: EHLO TCSHLSPOA1AC09"
"SMTPD"	5248	30	"2020-06-09 13:19:29.229"	"10.10.0.20"	"SENT: 250-mx7.XXXXXXXXXX.com.br[nl]250-SIZE 20480000[nl]250-AUTH LOGIN PLAIN[nl]250 HELP"
"SMTPD"	5248	30	"2020-06-09 13:19:29.229"	"10.10.0.20"	"RECEIVED: AUTH login c2VzY29ucnNAdGNzZGlnaXRhbC5jb20uYnI="
"SMTPD"	5248	30	"2020-06-09 13:19:29.229"	"10.10.0.20"	"SENT: 334 UGFzc3dvcmQ6"
"SMTPD"	5272	30	"2020-06-09 13:19:29.229"	"10.10.0.20"	"RECEIVED: ***"
"SMTPD"	5272	30	"2020-06-09 13:19:29.229"	"10.10.0.20"	"SENT: 235 authenticated."
"SMTPD"	2820	30	"2020-06-09 13:19:29.229"	"10.10.0.20"	"RECEIVED: MAIL FROM:<XXXXXXXXX@XXXXXXXXXXXX.com.br>"
"SMTPD"	2820	30	"2020-06-09 13:19:29.229"	"10.10.0.20"	"SENT: 250 OK"
"SMTPD"	5248	30	"2020-06-09 13:19:29.229"	"10.10.0.20"	"RECEIVED: RCPT TO:<XXXXXXXXXX@XXXXXXXXXXXX.com.br>"
"SMTPD"	5248	30	"2020-06-09 13:19:29.229"	"10.10.0.20"	"SENT: 250 OK"
"SMTPD"	5272	30	"2020-06-09 13:19:29.229"	"10.10.0.20"	"RECEIVED: DATA"
"SMTPD"	5272	30	"2020-06-09 13:19:29.229"	"10.10.0.20"	"SENT: 354 OK, send."
"DEBUG"	3304	"2020-06-09 13:19:30.254"	"Adding task AsynchronousTask to work queue Asynchronous task queue"
"DEBUG"	4360	"2020-06-09 13:19:30.254"	"Executing task AsynchronousTask in work queue Asynchronous task queue"
"DEBUG"	4360	"2020-06-09 13:19:30.254"	"Saving message: {ACB5621A-7311-4F99-AF62-90602128B9A4}.eml"
"DEBUG"	4360	"2020-06-09 13:19:30.254"	"Requesting SMTPDeliveryManager to start message delivery"
[b]"SMTPD"	4360	30	"2020-06-09 13:19:30.254"	"10.10.0.20"	"SENT: 250 Queued (1.015 seconds)"[/b]
"DEBUG"	5220	"2020-06-09 13:19:30.254"	"Adding task DeliveryTask to work queue SMTP delivery queue"
"DEBUG"	540	"2020-06-09 13:19:30.254"	"Executing task DeliveryTask in work queue SMTP delivery queue"
"DEBUG"	540	"2020-06-09 13:19:30.254"	"Delivering message..."
"APPLICATION"	540	"2020-06-09 13:19:30.254"	"SMTPDeliverer - Message 10: Delivering message from XXXXXXXXX@XXXXXXXXXX.com.br to XXXXXXX@XXXXXXXXXX.com.br. File: C:\Program Files (x86)\hMailServer\Data\{ACB5621A-7311-4F99-AF62-90602128B9A4}.eml"
"DEBUG"	540	"2020-06-09 13:19:30.254"	"Applying rules"
"DEBUG"	540	"2020-06-09 13:19:30.254"	"Performing local delivery"
"DEBUG"	540	"2020-06-09 13:19:30.254"	"Local delivery completed"
"DEBUG"	540	"2020-06-09 13:19:30.254"	"Signing message using DKIM..."
"TCPIP"	540	"2020-06-09 13:19:30.269"	"DNS MX lookup: XXXXXXXXX.com.br"
"TCPIP"	540	"2020-06-09 13:19:30.426"	"DNS - MX Result: 2 IP addresses were found."
"DEBUG"	540	"2020-06-09 13:19:30.426"	"Starting external delivery process. Server: XXXXXXXXXXX-com-br.mail.protection.outlook.com (104.47.XXX.XXX), Port: 25, Security: 0, User name: "
"DEBUG"	540	"2020-06-09 13:19:30.426"	"Creating session 33"
"TCPIP"	540	"2020-06-09 13:19:30.426"	"Connecting to 104.47.XXX.XXX:25..."
"DEBUG"	5248	"2020-06-09 13:19:30.598"	"TCP connection started for session 33"
"SMTPC"	5248	33	"2020-06-09 13:19:30.839"	"104.47.XXX.XXX"	"RECEIVED: 220 MW2NAM10FT041.mail.protection.outlook.com Microsoft ESMTP MAIL Service ready at Tue, 9 Jun 2020 16:19:30 +0000"
"SMTPC"	5248	33	"2020-06-09 13:19:30.839"	"104.47.XXX.XXX"	"SENT: HELO mx7.XXXXXXXXXXXX.com.br"
"SMTPC"	3304	33	"2020-06-09 13:19:31.027"	"104.47.XXX.XXX"	"RECEIVED: 250 MW2NAM10FT041.mail.protection.outlook.com Hello [200.201.XXX.XXX]"
"SMTPC"	3304	33	"2020-06-09 13:19:31.027"	"104.47.XXX.XXX"	"SENT: MAIL FROM:<XXXXXXXXX@XXXXXXXXXXX.com.br>"
"SMTPC"	5036	33	"2020-06-09 13:19:31.199"	"104.47.XXX.XXX"	"RECEIVED: 250 2.1.0 Sender OK"
"SMTPC"	5036	33	"2020-06-09 13:19:31.199"	"104.47.XXX.XXX"	"SENT: RCPT TO:<XXXXXXXXXXX@XXXXXXXXX.com.br>"
"SMTPC"	5036	33	"2020-06-09 13:19:31.386"	"104.47.XXX.XXX"	"RECEIVED: 250 2.1.5 Recipient OK"
"SMTPC"	5036	33	"2020-06-09 13:19:31.386"	"104.47.XXX.XXX"	"SENT: DATA"
"SMTPC"	5248	33	"2020-06-09 13:19:31.565"	"104.47.XXX.XXX"	"RECEIVED: 354 Start mail input; end with <CRLF>.<CRLF>"
"SMTPC"	5248	33	"2020-06-09 13:19:31.565"	"104.47.XXX.XXX"	"SENT: [nl]."
"DEBUG"	3304	"2020-06-09 13:19:33.761"	"The read operation failed. Bytes transferred: 0 Remote IP: 10.10.0.20, Session: 30, Code: 10054, Message: An existing connection was forcibly closed by the remote host"
"DEBUG"	3304	"2020-06-09 13:19:33.761"	"Ending session 30"
"SMTPC"	3304	33	"2020-06-09 13:19:35.074"	"104.47.XXX.XXX"	"RECEIVED: 250 2.6.0 <7D127E8E-FF22-4048-BAC9-89B420E39900@mx7.XXXXXXXXXXXX.com.br> [InternalId=29605209573701, Hostname=FR1P152MB0471.LAMP152.PROD.OUTLOOK.COM] 38233 bytes in 0.311, 119.979 KB/sec Queued mail for delivery"
"SMTPC"	3304	33	"2020-06-09 13:19:35.074"	"104.47.XXX.XXX"	"SENT: QUIT"
"SMTPC"	2820	33	"2020-06-09 13:19:35.262"	"104.47.XXX.XXX"	"RECEIVED: 221 2.0.0 Service closing transmission channel"
"DEBUG"	2820	"2020-06-09 13:19:35.262"	"Ending session 33"
"DEBUG"	540	"2020-06-09 13:19:35.262"	"External delivery process completed"
"DEBUG"	540	"2020-06-09 13:19:35.262"	"Summarizing delivery result"
"DEBUG"	540	"2020-06-09 13:19:35.262"	"AWStats::LogDeliverySuccess"
"DEBUG"	540	"2020-06-09 13:19:35.262"	"Summarized delivery results"
"DEBUG"	540	"2020-06-09 13:19:35.262"	"Deleting message"
"DEBUG"	540	"2020-06-09 13:19:35.262"	"Deleting message file."
"APPLICATION"	540	"2020-06-09 13:19:35.262"	"SMTPDeliverer - Message 10: Message delivery thread completed."
Last edited by nicolasft on 2020-06-09 18:54, edited 1 time in total.

nicolasft
New user
New user
Posts: 20
Joined: 2019-03-27 20:44

Re: Slow Response on Local NIC

Post by nicolasft » 2020-06-09 18:52

johang wrote:
2020-06-09 18:49
i second that ... more details needed ..

and my question is: are you sure it is mailserver related only?
( do you have the same experience if you transfer files between the 2 computers )
Yes, only the HMailServer, if I make an FTP connection using the same network for example is extremely fast,
What I find most strange is that using the internet link which is slower, the response time is faster by hMailServer as seen in the first log

User avatar
RvdH
Senior user
Senior user
Posts: 1113
Joined: 2008-06-27 14:42
Location: Netherlands

Re: Slow Response on Local NIC

Post by RvdH » 2020-06-09 18:54

extremely slow :?: We are talking about 1 second right?
CIDR to RegEx: d-fault.nl/CIDRtoRegEx
DNS Lookup: d-fault.nl/DNSTools
DNSBL Lookup: d-fault.nl/DNSBLLookup
GEOIP Lookup: d-fault.nl/GeoipLookup

nicolasft
New user
New user
Posts: 20
Joined: 2019-03-27 20:44

Re: Slow Response on Local NIC

Post by nicolasft » 2020-06-09 18:55

RvdH wrote:
2020-06-09 18:54
extremely slow :?: We are talking about 1 second right?
Yes comparing 1 second to 0, in a single shot it seems little but in an average daily amount of 60 thousand the thing complicates

is 1 second for each request so the server is much slower it takes 1 second to give the answer while the other link is instantaneous, I believe it is some configuration beyond the HMailserver but I have no idea what it can be

User avatar
RvdH
Senior user
Senior user
Posts: 1113
Joined: 2008-06-27 14:42
Location: Netherlands

Re: Slow Response on Local NIC

Post by RvdH » 2020-06-09 19:01

nicolasft wrote:
2020-06-09 18:55
RvdH wrote:
2020-06-09 18:54
extremely slow :?: We are talking about 1 second right?
Yes comparing 1 second to 0, in a single shot it seems little but in an average daily amount of 60 thousand the thing complicates
That's just ridiculous...but if you really need to bring this down if i were you i would try to look for the cause on the client pc connecting, maybe a (real time) virus scanner that scans outgoing emails?
CIDR to RegEx: d-fault.nl/CIDRtoRegEx
DNS Lookup: d-fault.nl/DNSTools
DNSBL Lookup: d-fault.nl/DNSBLLookup
GEOIP Lookup: d-fault.nl/GeoipLookup

nicolasft
New user
New user
Posts: 20
Joined: 2019-03-27 20:44

Re: Slow Response on Local NIC

Post by nicolasft » 2020-06-09 19:15

RvdH wrote:
2020-06-09 19:01
nicolasft wrote:
2020-06-09 18:55
RvdH wrote:
2020-06-09 18:54
extremely slow :?: We are talking about 1 second right?
Yes comparing 1 second to 0, in a single shot it seems little but in an average daily amount of 60 thousand the thing complicates
That's just ridiculous...but if you really need to bring this down if i were you i would try to look for the cause on the client pc connecting, maybe a (real time) virus scanner that scans outgoing emails?
Ridiculous?
1 Second X 60 Thousand = 16 hours
while on the other network connection it takes 0 time

If it were a virus scan on the computer it would occur on both network cards and not just on one

User avatar
RvdH
Senior user
Senior user
Posts: 1113
Joined: 2008-06-27 14:42
Location: Netherlands

Re: Slow Response on Local NIC

Post by RvdH » 2020-06-09 19:25

nicolasft wrote:
2020-06-09 19:15
RvdH wrote:
2020-06-09 19:01
nicolasft wrote:
2020-06-09 18:55


Yes comparing 1 second to 0, in a single shot it seems little but in an average daily amount of 60 thousand the thing complicates
That's just ridiculous...but if you really need to bring this down if i were you i would try to look for the cause on the client pc connecting, maybe a (real time) virus scanner that scans outgoing emails?
Ridiculous?
1 Second X 60 Thousand = 16 hours
while on the other network connection it takes 0 time

If it were a virus scan on the computer it would occur on both network cards and not just on one
60 Thousand what? Wait....i don't care anymore, good luck
CIDR to RegEx: d-fault.nl/CIDRtoRegEx
DNS Lookup: d-fault.nl/DNSTools
DNSBL Lookup: d-fault.nl/DNSBLLookup
GEOIP Lookup: d-fault.nl/GeoipLookup

User avatar
jimimaseye
Moderator
Moderator
Posts: 8727
Joined: 2011-09-08 17:48

Re: Slow Response on Local NIC

Post by jimimaseye » 2020-06-09 19:53

client says "i have some data of email body for you"....

"SMTPD" 5272 30 "2020-06-09 13:19:29.229"
"10.10.0.20" "RECEIVED: DATA"



Server sends "ok, give me your data and tell me when you have finished with a double dot"...

"SMTPD" 5272 30 "2020-06-09 13:19:29.229" "10.10.0.20" "SENT: 354 OK, send."


Client sends the data and ends with double dot, so the server can continue with its tasks

"DEBUG" 3304 "2020-06-09 13:19:30.254" "Adding task AsynchronousTask to work queue Asynchronous task queue"

For me, this is a case of your sending (client) server taking time to send and complete the data and double dot. Does it have Av other protections on it?

[Entered by mobile. Excuse my spelling.]
5.7 on test.
SpamassassinForWindows 3.4.0 spamd service
AV: Clamwin + Clamd service + sanesecurity defs : https://www.hmailserver.com/forum/viewtopic.php?f=21&t=26829

Virinum
Normal user
Normal user
Posts: 113
Joined: 2018-11-23 14:42
Location: Germany

Re: Slow Response on Local NIC

Post by Virinum » 2020-06-09 19:55

Yes, that is a really strange behavior and I can understand why you want to finde the cause of that.

So it’s the step the client transfers the mail data to the server, which takes along time. Either the client is still doing something until it starts the transfer or the server is doing something (e.g. spam check) with the received file.

Have you configured an extra IP range in hMailServer for the local IP addresses? Can you test with another mail client on the sending machine? For example PHPMailer?

nicolasft
New user
New user
Posts: 20
Joined: 2019-03-27 20:44

Re: Slow Response on Local NIC

Post by nicolasft » 2020-06-09 21:15

OK I managed to solve

For those who are having this problem and who have a situation like mine where they have 2 computers connected locally

It was enough to disable Link-Local Multicast Name Resolution (LLMNR) on windows
Somehow it was impacting,
I was able to find this out using the Microsoft Network Monitor tool,

User avatar
jimimaseye
Moderator
Moderator
Posts: 8727
Joined: 2011-09-08 17:48

Re: Slow Response on Local NIC

Post by jimimaseye » 2020-06-09 21:22

Et voila!

Bravo.

Another one for the knowledgebase. :mrgreen:

[Entered by mobile. Excuse my spelling.]
5.7 on test.
SpamassassinForWindows 3.4.0 spamd service
AV: Clamwin + Clamd service + sanesecurity defs : https://www.hmailserver.com/forum/viewtopic.php?f=21&t=26829

Post Reply