hMailServer Backup-MX acting weird!

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
User avatar
SorenR
Senior user
Senior user
Posts: 4197
Joined: 2006-08-21 15:38
Location: Denmark

hMailServer Backup-MX acting weird!

Post by SorenR » 2021-01-03 01:33

I have two hMailServers 5.6.8 B2505.RvdH+. One is "PrimaryServer" and one is "BackupServer" - each server have their own internet router.

Code: Select all

             --- Fiber (primary) Router #1 ---
            /                                 \
Internet ---                                   --- LAN
            \                                 /
             ---  4G (backup)    Router #2 ---
Both servers share the same LAN but with different Default gateways (Router #1 and Router #2). Both servers have AUTH disabled on port 25. "BackupServer" have no domains, only route to "PrimaryServer". IP Ranges are configured identical on both servers.

When emails come in from the Internet I see:

1. --> 220 "PrimaryServer" ESMTP
2. <-- EHLO "InternetServer"
3. --> 250-"PrimaryServer"[nl]250-"CAPABILITIES"[nl]250 STARTTLS
4. <-- STARTTSL
5. --> 220 Ready to start TLS
6. <-- EHLO "InternetServer"
7. --> 250-"PrimaryServer"[nl]250-"CAPABILITIES"[nl]250 SIZE
8. <-- MAIL FROM

and when I send to the Internet I see:

1. <-- 220 "InternetServer" ESMTP
2. --> EHLO "PrimaryServer"
3. <-- 250-"InternetServer"[nl]250-"CAPABILITIES"[nl]250 STARTTLS
4. --> STARTTSL
5. <-- 220 Go ahead with TLS
6. --> EHLO "PrimaryServer"
7. <-- 250-"InternetServer"[nl]250-"CAPABILITIES"[nl]250 SIZE
8. --> MAIL FROM ....

BUT! When emails come in from my BackupServer:

1. --> 220 "PrimaryServer" ESMTP
2. <-- EHLO "BackupServer"
3. --> 250-"PrimaryServer"[nl]250-"CAPABILITIES"[nl]250 STARTTLS
4. <-- STARTTSL
5. --> 220 Ready to start TLS
6. --> 250-"PrimaryServer"[nl]250-"CAPABILITIES"[nl]250 SIZE
7. <-- HELO "BackupServer"
8. --> 250 Hello.
9. <-- MAIL FROM ....

WFT? Line 6. is completely out of order breaking ESMTP.
SørenR.

Algorithm (noun.)
Word used by programmers when they do not want to explain what they did.

User avatar
mattg
Moderator
Moderator
Posts: 21268
Joined: 2007-06-14 05:12
Location: 'The Outback' Australia

Re: hMailServer Backup-MX acting weird!

Post by mattg » 2021-01-03 02:59

I'm sure that you checked all of these settings, but just getting how this works out of my head and written down...

So it has to be one of the settings specific to the IP address of your backup server, as shown on your Primary server, and different to the internet IP range
OR
It could be in the SMTP route created on your backup server

Primary server:-
Check IP ranges, especially settings about requiring SSL for AUTH
Is that IP set in 'Incoming relays'?

Backup Server:-
Check the SMTP route settings (is StartTLS Required set?)
Just 'cause I link to a page and say little else doesn't mean I am not being nice.
https://www.hmailserver.com/documentation

User avatar
SorenR
Senior user
Senior user
Posts: 4197
Joined: 2006-08-21 15:38
Location: Denmark

Re: hMailServer Backup-MX acting weird!

Post by SorenR » 2021-01-03 04:15

mattg wrote:
2021-01-03 02:59
I'm sure that you checked all of these settings, but just getting how this works out of my head and written down...

So it has to be one of the settings specific to the IP address of your backup server, as shown on your Primary server, and different to the internet IP range
OR
It could be in the SMTP route created on your backup server

Primary server:-
Check IP ranges, especially settings about requiring SSL for AUTH
Is that IP set in 'Incoming relays'?

Backup Server:-
Check the SMTP route settings (is StartTLS Required set?)
It is "PrimaryServer" that is out of order... "BackupServer" is not doing anything out of order.

On "BackupServer" Route is defined as "acme.inc", Port 25, STARTTLS optional and both sender/recipient match as "local address"

1: Everything is run on Port 25 with StartTLS optional.
2: hMailserver.ini -> DisableAUTHList=25.
3: Valid certificates on both servers.
4: Authentication is not an issue as AUTH LOGIN is not advertised.
5: I currently have the IP Range on "PrimaryServer" for "BackupServer" identical to "Internet".
6: I have changed IP Ranges on "PrimaryServer" to include IP of "BackupServer" in any way I could come up with - no change.
7: I have tried with and without setting "BackupServer" as Incoming Relay - no change.
8: "PrimaryServer" is equal to DNS "acme.inc" MX 10 "mx.acme.inc".
9: "BackupServer" is equal to DNS "acme.inc" MX 20 "mail.acme.inc".
10: On "PrimaryServer" I have domain aliases (Names) listed as "mx.acme.inc" and "mail.acme.inc".

One of the settings I tried was to only have "Internet" IP range on "PrimaryServer" ... NO change.

It is probably something simple that I have not thought of ... I just don't have a clue.

Note: "acme.inc" substitute my personal domain active since 2003.
SørenR.

Algorithm (noun.)
Word used by programmers when they do not want to explain what they did.

User avatar
mattg
Moderator
Moderator
Posts: 21268
Joined: 2007-06-14 05:12
Location: 'The Outback' Australia

Re: hMailServer Backup-MX acting weird!

Post by mattg » 2021-01-03 05:38

Try with StartTLS Required on port 25 on your backup server's SMTP route
Just 'cause I link to a page and say little else doesn't mean I am not being nice.
https://www.hmailserver.com/documentation

mikedibella
Senior user
Senior user
Posts: 390
Joined: 2016-12-08 02:21

Re: hMailServer Backup-MX acting weird!

Post by mikedibella » 2021-01-03 06:12

Post the log from the backup.

User avatar
jim.bus
Senior user
Senior user
Posts: 630
Joined: 2011-05-28 11:49
Location: US

Re: hMailServer Backup-MX acting weird!

Post by jim.bus » 2021-01-03 07:29

SorenR wrote:
2021-01-03 04:15

It is "PrimaryServer" that is out of order... "BackupServer" is not doing anything out of order.

On "BackupServer" Route is defined as "acme.inc", Port 25, STARTTLS optional and both sender/recipient match as "local address"

1: Everything is run on Port 25 with StartTLS optional.
2: hMailserver.ini -> DisableAUTHList=25.
3: Valid certificates on both servers.
4: Authentication is not an issue as AUTH LOGIN is not advertised.
5: I currently have the IP Range on "PrimaryServer" for "BackupServer" identical to "Internet".
6: I have changed IP Ranges on "PrimaryServer" to include IP of "BackupServer" in any way I could come up with - no change.
7: I have tried with and without setting "BackupServer" as Incoming Relay - no change.
8: "PrimaryServer" is equal to DNS "acme.inc" MX 10 "mx.acme.inc".
9: "BackupServer" is equal to DNS "acme.inc" MX 20 "mail.acme.inc".
10: On "PrimaryServer" I have domain aliases (Names) listed as "mx.acme.inc" and "mail.acme.inc".
SorenR, this is probably a stupid queston on my part. But on lines 8 and 9, it looks like you are saying your PrimaryServer Domain of Acme.inc MX 10 Record points to a Server Host Name of 'mx.acme.inc' and the BackupServe Domain of Acme.inc MX 20 Record points to a Server Host Name of 'mail.acme.inc'. I would have guessed your PrimaryServe host name would probably be 'mail.acme.inc' and your BackupServer host name would probably be 'mx.acme.inc'. If my guess is correct then wouldn't you be pointing the PrimaryServer and BackupServer to the wrong Server host names. They would have to be the other way around. But if my guess is correct, I don't see how that would cause the issue you are pointing out but still if I am correct then this might be yet another problem.

User avatar
SorenR
Senior user
Senior user
Posts: 4197
Joined: 2006-08-21 15:38
Location: Denmark

Re: hMailServer Backup-MX acting weird!

Post by SorenR » 2021-01-03 11:33

jim.bus wrote:
2021-01-03 07:29
SorenR wrote:
2021-01-03 04:15

It is "PrimaryServer" that is out of order... "BackupServer" is not doing anything out of order.

On "BackupServer" Route is defined as "acme.inc", Port 25, STARTTLS optional and both sender/recipient match as "local address"

1: Everything is run on Port 25 with StartTLS optional.
2: hMailserver.ini -> DisableAUTHList=25.
3: Valid certificates on both servers.
4: Authentication is not an issue as AUTH LOGIN is not advertised.
5: I currently have the IP Range on "PrimaryServer" for "BackupServer" identical to "Internet".
6: I have changed IP Ranges on "PrimaryServer" to include IP of "BackupServer" in any way I could come up with - no change.
7: I have tried with and without setting "BackupServer" as Incoming Relay - no change.
8: "PrimaryServer" is equal to DNS "acme.inc" MX 10 "mx.acme.inc".
9: "BackupServer" is equal to DNS "acme.inc" MX 20 "mail.acme.inc".
10: On "PrimaryServer" I have domain aliases (Names) listed as "mx.acme.inc" and "mail.acme.inc".
SorenR, this is probably a stupid queston on my part. But on lines 8 and 9, it looks like you are saying your PrimaryServer Domain of Acme.inc MX 10 Record points to a Server Host Name of 'mx.acme.inc' and the BackupServe Domain of Acme.inc MX 20 Record points to a Server Host Name of 'mail.acme.inc'. I would have guessed your PrimaryServe host name would probably be 'mail.acme.inc' and your BackupServer host name would probably be 'mx.acme.inc'. If my guess is correct then wouldn't you be pointing the PrimaryServer and BackupServer to the wrong Server host names. They would have to be the other way around. But if my guess is correct, I don't see how that would cause the issue you are pointing out but still if I am correct then this might be yet another problem.
Yes, it is a stupid question.
FQDN's point to correct servers and in the correct order. All tested and verified.
Actually "mx.acme.inc" has been called that since 2006 and "mail.acme.inc" was previously handled by my ISP as "backup-mx.tele.dk" - a 3 server round robin service.

The issue is not the FQDN names but the fact that "PrimaryServer" break ESMTP when mails come in via "BackupServer".
SørenR.

Algorithm (noun.)
Word used by programmers when they do not want to explain what they did.

User avatar
SorenR
Senior user
Senior user
Posts: 4197
Joined: 2006-08-21 15:38
Location: Denmark

Re: hMailServer Backup-MX acting weird!

Post by SorenR » 2021-01-03 11:37

mikedibella wrote:
2021-01-03 06:12
Post the log from the backup.
I have had the two logs side by side on screen and they match.
SørenR.

Algorithm (noun.)
Word used by programmers when they do not want to explain what they did.

User avatar
SorenR
Senior user
Senior user
Posts: 4197
Joined: 2006-08-21 15:38
Location: Denmark

Re: hMailServer Backup-MX acting weird!

Post by SorenR » 2021-01-03 11:49

mattg wrote:
2021-01-03 05:38
Try with StartTLS Required on port 25 on your backup server's SMTP route
I could do that but what would that show? It is "PrimaryServer" that send capabilities out of sync after switching to TLS when it should be waiting for "BackupServer" to send EHLO first.

For some reason I fail to pinpoint the exact flow in the source code since I have not figured out why it only happen when the backup server connect.
SørenR.

Algorithm (noun.)
Word used by programmers when they do not want to explain what they did.

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

Re: hMailServer Backup-MX acting weird!

Post by jimimaseye » 2021-01-03 11:59

SorenR wrote:
2021-01-03 11:49
For some reason I fail to pinpoint the exact flow in the source code since I have not figured out why it only happen when the backup server connect.
Is it always and only from your backup server?

Also, as you say:
I have had the two logs side by side on screen and they match.
Do you mean they match as you reported above? (Just to clarify)
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
SorenR
Senior user
Senior user
Posts: 4197
Joined: 2006-08-21 15:38
Location: Denmark

Re: hMailServer Backup-MX acting weird!

Post by SorenR » 2021-01-03 12:09

jimimaseye wrote:
2021-01-03 11:59
SorenR wrote:
2021-01-03 11:49
For some reason I fail to pinpoint the exact flow in the source code since I have not figured out why it only happen when the backup server connect.
Is it always and only from your backup server?

Also, as you say:
I have had the two logs side by side on screen and they match.
Do you mean they match as you reported above? (Just to clarify)
I have only observed it when "BackupServer" connects.

I have tail'd the two logs side by side and they show the same conversation.
SørenR.

Algorithm (noun.)
Word used by programmers when they do not want to explain what they did.

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

Re: hMailServer Backup-MX acting weird!

Post by jimimaseye » 2021-01-03 12:33

Is there a possibility that the output to the logging is skewed (due to timing)? i.e the conversation goes in the correct order but the log output is slightly delayed and appears in the wrong order?
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
SorenR
Senior user
Senior user
Posts: 4197
Joined: 2006-08-21 15:38
Location: Denmark

Re: hMailServer Backup-MX acting weird!

Post by SorenR » 2021-01-03 12:40

jimimaseye wrote:
2021-01-03 12:33
Is there a possibility that the output to the logging is skewed (due to timing)? i.e the conversation goes in the correct order but the log output is slightly delayed and appears in the wrong order?
I believe not. The fact that "PrimaryServer" respond with capabilities out-of-sync after negotiating TLS does trigger "BackupServer" to respond with HELO and not EHLO as expected from the greeting with ESMTP.
SørenR.

Algorithm (noun.)
Word used by programmers when they do not want to explain what they did.

User avatar
SorenR
Senior user
Senior user
Posts: 4197
Joined: 2006-08-21 15:38
Location: Denmark

Re: hMailServer Backup-MX acting weird!

Post by SorenR » 2021-01-03 12:52

Hmm... I believed my certificates to be in order as there has been no indications otherwise ... but ...
"TCPConnection - TLS/SSL handshake failed. Session Id: 584, Remote IP: 192.168.0.6, Error code: 336151576, Message: tlsv1 alert unknown ca"
They are both LetsEncrypt and generated at the same time.

Changed "PrimaryServer" to use specific certificate and not "fullchain" certificate. Error went away, problem persists.
SørenR.

Algorithm (noun.)
Word used by programmers when they do not want to explain what they did.

User avatar
SorenR
Senior user
Senior user
Posts: 4197
Joined: 2006-08-21 15:38
Location: Denmark

Re: hMailServer Backup-MX acting weird!

Post by SorenR » 2021-01-03 13:10

It appears I have misread one line. I believed the line breaking ESMTP was "capabilities" where it in fact is "the ESMTP greeting" ... However the problem persists.

Actual domain names have been changed...

"BackupServer" receiving from "outside.mail"

Code: Select all

"SMTPD"	4984	510	"2021-01-03 11:50:10.867"	"209.85.219.181"	"SENT: 220 mail.acme.inc ESMTP"
"SMTPD"	6940	510	"2021-01-03 11:50:10.992"	"209.85.219.181"	"RECEIVED: EHLO mail-yb1-f181.outside.mail"
"SMTPD"	6940	510	"2021-01-03 11:50:10.992"	"209.85.219.181"	"SENT: 250-mail.acme.inc[nl]250-SIZE[nl]250 STARTTLS"
"SMTPD"	4984	510	"2021-01-03 11:50:11.101"	"209.85.219.181"	"RECEIVED: STARTTLS"
"SMTPD"	4984	510	"2021-01-03 11:50:11.101"	"209.85.219.181"	"SENT: 220 Ready to start TLS"
"SMTPD"	4984	510	"2021-01-03 11:50:11.476"	"209.85.219.181"	"RECEIVED: EHLO mail-yb1-f181.outside.mail"
"SMTPD"	4984	510	"2021-01-03 11:50:11.476"	"209.85.219.181"	"SENT: 250-mail.acme.inc[nl]250 SIZE"
"SMTPD"	5464	510	"2021-01-03 11:50:11.695"	"209.85.219.181"	"RECEIVED: MAIL FROM:<soren@outside.mail> SIZE=2306"
"SMTPD"	5464	510	"2021-01-03 11:50:11.898"	"209.85.219.181"	"SENT: 250 OK"
"SMTPD"	4984	510	"2021-01-03 11:50:12.023"	"209.85.219.181"	"RECEIVED: RCPT TO:<soren@acme.inc>"
"SMTPD"	4984	510	"2021-01-03 11:50:12.023"	"209.85.219.181"	"SENT: 250 OK"
"SMTPD"	6940	510	"2021-01-03 11:50:12.132"	"209.85.219.181"	"RECEIVED: DATA"
"SMTPD"	6940	510	"2021-01-03 11:50:12.132"	"209.85.219.181"	"SENT: 354 OK, send."
"SMTPD"	4636	510	"2021-01-03 11:50:12.304"	"209.85.219.181"	"SENT: 250 Queued (0.128 seconds)"
"SMTPD"	5464	510	"2021-01-03 11:50:12.429"	"209.85.219.181"	"RECEIVED: QUIT"
"SMTPD"	5464	510	"2021-01-03 11:50:12.429"	"209.85.219.181"	"SENT: 221 goodbye"
"BackupServer" sending to "PrimaryServer"

Code: Select all

"SMTPC"	4984	512	"2021-01-03 11:50:12.351"	"192.168.0.5"	"RECEIVED: 220 mx.acme.inc ESMTP"
"SMTPC"	4984	512	"2021-01-03 11:50:12.351"	"192.168.0.5"	"SENT: EHLO mail.acme.inc"
"SMTPC"	6940	512	"2021-01-03 11:50:12.367"	"192.168.0.5"	"RECEIVED: 250-mx.acme.inc[nl]250-SIZE[nl]250 STARTTLS"
"SMTPC"	6940	512	"2021-01-03 11:50:12.367"	"192.168.0.5"	"SENT: STARTTLS"
"SMTPC"	5464	512	"2021-01-03 11:50:12.367"	"192.168.0.5"	"RECEIVED: 220 Ready to start TLS"
"SMTPC"	6940	513	"2021-01-03 11:50:12.429"	"192.168.0.5"	"RECEIVED: 220 mx.acme.inc ESMTP"
"SMTPC"	6940	513	"2021-01-03 11:50:12.429"	"192.168.0.5"	"SENT: HELO mail.acme.inc"
"SMTPC"	6396	513	"2021-01-03 11:50:12.429"	"192.168.0.5"	"RECEIVED: 250 Hello."
"SMTPC"	6396	513	"2021-01-03 11:50:12.429"	"192.168.0.5"	"SENT: MAIL FROM:<soren@outside.mail>"
"SMTPC"	4984	513	"2021-01-03 11:50:12.429"	"192.168.0.5"	"RECEIVED: 250 OK"
"SMTPC"	4984	513	"2021-01-03 11:50:12.429"	"192.168.0.5"	"SENT: RCPT TO:<soren@acme.inc>"
"SMTPC"	5464	513	"2021-01-03 11:50:12.445"	"192.168.0.5"	"RECEIVED: 250 OK"
"SMTPC"	5464	513	"2021-01-03 11:50:12.445"	"192.168.0.5"	"SENT: DATA"
"SMTPC"	4984	513	"2021-01-03 11:50:12.445"	"192.168.0.5"	"RECEIVED: 354 OK, send."
"SMTPC"	4984	513	"2021-01-03 11:50:12.445"	"192.168.0.5"	"SENT: [nl]."
"SMTPC"	6396	513	"2021-01-03 11:50:14.601"	"192.168.0.5"	"RECEIVED: 250 Queued (1.664 seconds)"
"SMTPC"	6396	513	"2021-01-03 11:50:14.601"	"192.168.0.5"	"SENT: QUIT"
"PrimaryServer" receiving from "BackupServer"

Code: Select all

"SMTPD"	4084	608	"2021-01-03 11:50:12.282"	"192.168.0.6"	"SENT: 220 mx.acme.inc ESMTP"
"SMTPD"	2428	608	"2021-01-03 11:50:12.282"	"192.168.0.6"	"RECEIVED: EHLO mail.acme.inc"
"SMTPD"	2428	608	"2021-01-03 11:50:12.282"	"192.168.0.6"	"SENT: 250-mx.acme.inc[nl]250-SIZE[nl]250 STARTTLS"
"SMTPD"	4084	608	"2021-01-03 11:50:12.282"	"192.168.0.6"	"RECEIVED: STARTTLS"
"SMTPD"	4084	608	"2021-01-03 11:50:12.282"	"192.168.0.6"	"SENT: 220 Ready to start TLS"
"SMTPD"	4084	616	"2021-01-03 11:50:12.345"	"192.168.0.6"	"SENT: 220 mx.acme.inc ESMTP"
"SMTPD"	1980	616	"2021-01-03 11:50:12.345"	"192.168.0.6"	"RECEIVED: HELO mail.acme.inc"
"SMTPD"	1980	616	"2021-01-03 11:50:12.360"	"192.168.0.6"	"SENT: 250 Hello."
"SMTPD"	4084	616	"2021-01-03 11:50:12.360"	"192.168.0.6"	"RECEIVED: MAIL FROM:<soren@outside.mail>"
"SMTPD"	4084	616	"2021-01-03 11:50:12.360"	"192.168.0.6"	"SENT: 250 OK"
"SMTPD"	1980	616	"2021-01-03 11:50:12.360"	"192.168.0.6"	"RECEIVED: RCPT TO:<soren@acme.inc>"
"SMTPD"	1980	616	"2021-01-03 11:50:12.360"	"192.168.0.6"	"SENT: 250 OK"
"SMTPD"	2428	616	"2021-01-03 11:50:12.360"	"192.168.0.6"	"RECEIVED: DATA"
"SMTPD"	2428	616	"2021-01-03 11:50:12.360"	"192.168.0.6"	"SENT: 354 OK, send."
"SMTPD"	3912	616	"2021-01-03 11:50:14.532"	"192.168.0.6"	"SENT: 250 Queued (1.664 seconds)"
"SMTPD"	740	616	"2021-01-03 11:50:14.532"	"192.168.0.6"	"RECEIVED: QUIT"
"PrimaryServer" receiving from "outside.mail"

Code: Select all

"SMTPD"	4084	636	"2021-01-03 12:14:53.835"	"209.85.219.169"	"SENT: 220 mx.acme.inc ESMTP"
"SMTPD"	3468	636	"2021-01-03 12:14:53.975"	"209.85.219.169"	"RECEIVED: EHLO mail-yb1-f169.outside.mail"
"SMTPD"	3468	636	"2021-01-03 12:14:54.022"	"209.85.219.169"	"SENT: 250-mx.acme.inc[nl]250-SIZE[nl]250 STARTTLS"
"SMTPD"	4084	636	"2021-01-03 12:14:54.163"	"209.85.219.169"	"RECEIVED: STARTTLS"
"SMTPD"	4084	636	"2021-01-03 12:14:54.163"	"209.85.219.169"	"SENT: 220 Ready to start TLS"
"SMTPD"	1116	636	"2021-01-03 12:14:54.663"	"209.85.219.169"	"RECEIVED: EHLO mail-yb1-f169.outside.mail"
"SMTPD"	1116	636	"2021-01-03 12:14:54.710"	"209.85.219.169"	"SENT: 250-mx.acme.inc[nl]250 SIZE"
"SMTPD"	2428	636	"2021-01-03 12:14:54.975"	"209.85.219.169"	"RECEIVED: MAIL FROM:<soren@outside.mail> SIZE=2329"
"SMTPD"	2428	636	"2021-01-03 12:14:55.381"	"209.85.219.169"	"SENT: 250 OK"
"SMTPD"	4084	636	"2021-01-03 12:14:55.522"	"209.85.219.169"	"RECEIVED: RCPT TO:<soren@acme.inc>"
"SMTPD"	4084	636	"2021-01-03 12:14:55.522"	"209.85.219.169"	"SENT: 250 OK"
"SMTPD"	3292	636	"2021-01-03 12:14:55.678"	"209.85.219.169"	"RECEIVED: DATA"
"SMTPD"	3292	636	"2021-01-03 12:14:55.678"	"209.85.219.169"	"SENT: 354 OK, send."
"SMTPD"	4008	636	"2021-01-03 12:14:57.709"	"209.85.219.169"	"SENT: 250 Queued (1.664 seconds)"
"SMTPD"	3244	636	"2021-01-03 12:14:57.850"	"209.85.219.169"	"RECEIVED: QUIT"
SørenR.

Algorithm (noun.)
Word used by programmers when they do not want to explain what they did.

User avatar
SorenR
Senior user
Senior user
Posts: 4197
Joined: 2006-08-21 15:38
Location: Denmark

Re: hMailServer Backup-MX acting weird!

Post by SorenR » 2021-01-03 13:49

SOLVED !

Well, sort of... Removed selection from "Verify remote server...." from hMailAdmin -> Settings -> Advanced -> SSL/TLS

Never had any problems verifying certificates before. Apparently my servers do not like each other.

Mattg trigged me to try the STARTTLS REQUIRED on the SMTP Route and after enabling debug logging a pattern emerged :mrgreen:

Code: Select all

Received: from mail.acme.inc (mail.acme.inc [192.168.0.6]) by mx.acme.inc with ESMTPS (version=TLSv1.3 cipher=TLS_AES_256_GCM_SHA384 bits=256) ; Sun, 3 Jan 2021 12:40:23 +0100
Received: from mail-yb1-f172.outside.mail (mail-yb1-f172.outside.mail [209.85.219.172]) by mail.acme.inc with ESMTPS (version=TLSv1.3 cipher=TLS_AES_128_GCM_SHA256 bits=128) ; Sun, 3 Jan 2021 12:40:23 +0100
Received: by mail-yb1-f172.outside.mail with SMTP id o144so23423498ybc.0 for <soren@mail.acme.inc>; Sun, 03 Jan 2021 03:40:22 -0800 (PST)
SørenR.

Algorithm (noun.)
Word used by programmers when they do not want to explain what they did.

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

Re: hMailServer Backup-MX acting weird!

Post by jimimaseye » 2021-01-03 15:43

So the backup couldn't verify the primary certificate so defaulted to HELO?
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
SorenR
Senior user
Senior user
Posts: 4197
Joined: 2006-08-21 15:38
Location: Denmark

Re: hMailServer Backup-MX acting weird!

Post by SorenR » 2021-01-03 19:26

jimimaseye wrote:
2021-01-03 15:43
So the backup couldn't verify the primary certificate so defaulted to HELO?
That appear to be the case.

I use standard certificates from Let's Encrypt, one for each server and one for my webserver (no wildcard).

I normally use the "fullchain.cer" but hMailServer debug logging revealed the certificate CA could not be verified so I switched to the single certificate.

I have just done some digging into this AND it seems I need to do more debugging on how hMailserver verifies a certificate. - Again my domain is replaced with "acme.inc"

Single certificate:

Code: Select all

root - ~ openssl s_client -starttls smtp -showcerts -connect mx.acme.inc:25 -servername mx.acme.inc
CONNECTED(00000003)
depth=0 CN = mx.acme.inc
verify error:num=20:unable to get local issuer certificate
verify return:1
depth=0 CN = mx.acme.inc
verify error:num=21:unable to verify the first certificate
verify return:1
---
Certificate chain
 0 s:/CN=mx.acme.inc
   i:/C=US/O=Let's Encrypt/CN=R3
-----BEGIN CERTIFICATE-----
Fullchain certificate:

Code: Select all

root - ~ openssl s_client -starttls smtp -showcerts -connect mx.acme.inc:25 -servername mx.acme.inc
CONNECTED(00000003)
depth=2 O = Digital Signature Trust Co., CN = DST Root CA X3
verify return:1
depth=1 C = US, O = Let's Encrypt, CN = R3
verify return:1
depth=0 CN = mx.acme.inc
verify return:1
---
Certificate chain
 0 s:/CN=mx.acme.inc
   i:/C=US/O=Let's Encrypt/CN=R3
-----BEGIN CERTIFICATE-----
SørenR.

Algorithm (noun.)
Word used by programmers when they do not want to explain what they did.

User avatar
SorenR
Senior user
Senior user
Posts: 4197
Joined: 2006-08-21 15:38
Location: Denmark

Re: hMailServer Backup-MX acting weird!

Post by SorenR » 2021-01-03 19:32

SørenR.

Algorithm (noun.)
Word used by programmers when they do not want to explain what they did.

User avatar
jim.bus
Senior user
Senior user
Posts: 630
Joined: 2011-05-28 11:49
Location: US

Re: hMailServer Backup-MX acting weird!

Post by jim.bus » 2021-01-03 21:23

I am using version 5.6.8-B2501 and I believe I get the same type of EHLO followed by a HELO from, in this case, a site trying to SPAM me. I see something like this all the time. Not sure but I may have seen this also on 5.6.7-B2425. See my Log Entries:

"TCPIP" 12384 "2021-01-03 05:58:07.989" "TCP - 23.129.64.185 connected to 192.168.2.5:25."
"DEBUG" 12384 "2021-01-03 05:58:07.990" "TCP connection started for session 17"
"SMTPD" 12384 17 "2021-01-03 05:58:07.991" "23.129.64.185" "SENT: 220 Pleased To Meet You"
"SMTPD" 12388 17 "2021-01-03 05:58:10.835" "23.129.64.185" "RECEIVED: EHLO example.com"
"SMTPD" 12388 17 "2021-01-03 05:58:14.137" "23.129.64.185" "SENT: 250-mail.jb.com[nl]250-SIZE 25600000[nl]250-STARTTLS[nl]250 HELP"
"SMTPD" 12392 17 "2021-01-03 05:58:14.137" "23.129.64.185" "RECEIVED: HELO example.com"
"SMTPD" 12392 17 "2021-01-03 05:58:14.138" "23.129.64.185" "SENT: 250 Hello."
"SMTPD" 12392 17 "2021-01-03 05:58:14.138" "23.129.64.185" "RECEIVED: STARTTLS"
"SMTPD" 12392 17 "2021-01-03 05:58:14.138" "23.129.64.185" "SENT: 220 Ready to start TLS"
"DEBUG" 12396 "2021-01-03 05:58:14.139" "Performing SSL/TLS handshake for session 17. Verify certificate: False"
"TCPIP" 12396 "2021-01-03 05:58:14.822" "TCPConnection - TLS/SSL handshake failed. Session Id: 17, Remote IP: 23.129.64.185, Error code: 1, Message: stream truncated"
"DEBUG" 12396 "2021-01-03 05:58:14.822" "Ending session 17"

User avatar
SorenR
Senior user
Senior user
Posts: 4197
Joined: 2006-08-21 15:38
Location: Denmark

Re: hMailServer Backup-MX acting weird!

Post by SorenR » 2021-01-03 21:35

jim.bus wrote:
2021-01-03 21:23
I am using version 5.6.8-B2501 and I believe I get the same type of EHLO followed by a HELO from, in this case, a site trying to SPAM me. I see something like this all the time. Not sure but I may have seen this also on 5.6.7-B2425. See my Log Entries:

"TCPIP" 12384 "2021-01-03 05:58:07.989" "TCP - 23.129.64.185 connected to 192.168.2.5:25."
"DEBUG" 12384 "2021-01-03 05:58:07.990" "TCP connection started for session 17"
"SMTPD" 12384 17 "2021-01-03 05:58:07.991" "23.129.64.185" "SENT: 220 Pleased To Meet You"
"SMTPD" 12388 17 "2021-01-03 05:58:10.835" "23.129.64.185" "RECEIVED: EHLO example.com"
"SMTPD" 12388 17 "2021-01-03 05:58:14.137" "23.129.64.185" "SENT: 250-mail.jb.com[nl]250-SIZE 25600000[nl]250-STARTTLS[nl]250 HELP"
"SMTPD" 12392 17 "2021-01-03 05:58:14.137" "23.129.64.185" "RECEIVED: HELO example.com"
"SMTPD" 12392 17 "2021-01-03 05:58:14.138" "23.129.64.185" "SENT: 250 Hello."
"SMTPD" 12392 17 "2021-01-03 05:58:14.138" "23.129.64.185" "RECEIVED: STARTTLS"
"SMTPD" 12392 17 "2021-01-03 05:58:14.138" "23.129.64.185" "SENT: 220 Ready to start TLS"
"DEBUG" 12396 "2021-01-03 05:58:14.139" "Performing SSL/TLS handshake for session 17. Verify certificate: False"
"TCPIP" 12396 "2021-01-03 05:58:14.822" "TCPConnection - TLS/SSL handshake failed. Session Id: 17, Remote IP: 23.129.64.185, Error code: 1, Message: stream truncated"
"DEBUG" 12396 "2021-01-03 05:58:14.822" "Ending session 17"
I see them too and in 99,99% of the cases my defences will have banned them from other reasons. One being Snowshoe SPAM...

One of the reasons I am looking into modifying OnHELO() is so I can trap an EHLO followed by a HELO from the same IP in less than 1 second.
SørenR.

Algorithm (noun.)
Word used by programmers when they do not want to explain what they did.

User avatar
mattg
Moderator
Moderator
Posts: 21268
Joined: 2007-06-14 05:12
Location: 'The Outback' Australia

Re: hMailServer Backup-MX acting weird!

Post by mattg » 2021-01-03 23:39

SorenR wrote:
2021-01-03 13:49
... Removed selection from "Verify remote server...." from hMailAdmin -> Settings -> Advanced -> SSL/TLS
'Verify' isn't actually used much.
It is used on SMTP routes, and for upstream 'External Account POP3' connections and not much else
https://www.hmailserver.com/forum/viewt ... 0f#p182087

SorenR wrote:
2021-01-03 19:26
I use standard certificates from Let's Encrypt, one for each server and one for my webserver (no wildcard).

I normally use the "fullchain.cer" but hMailServer debug logging revealed the certificate CA could not be verified so I switched to the single certificate.
I need to use the 'full chain' for email clients like thunderbird and outlook to like the certificates.
In your case I would get ONE certificate from lets encrypt that covers both domains, and use it on both servers.

If your server can't verify the CA, perhaps your Windows certificate store needs updated trust certificates
If I remember correctly, you run older versions of Windows?
Just 'cause I link to a page and say little else doesn't mean I am not being nice.
https://www.hmailserver.com/documentation

User avatar
jim.bus
Senior user
Senior user
Posts: 630
Joined: 2011-05-28 11:49
Location: US

Re: hMailServer Backup-MX acting weird!

Post by jim.bus » 2021-01-03 23:53

mattg wrote:
2021-01-03 23:39

I normally use the "fullchain.cer" but hMailServer debug logging revealed the certificate CA could not be verified so I switched to the single certificate.
I need to use the 'full chain' for email clients like thunderbird and outlook to like the certificates.
In your case I would get ONE certificate from lets encrypt that covers both domains, and use it on both servers.


[/quote]

mattg, I use Let's Encrypt Certificates but only use the 'cert.pem' and 'privkey.pem' files in hMailServer. I do not use the 'chain.pem' file because for some reason the expiration date in the 'chain.pem' file is always expired.

However, while I don't have any Thunderbird Clients, I do use an Outlook Client and have no problems with Outlook Clients connecting to my hMailServer.

User avatar
SorenR
Senior user
Senior user
Posts: 4197
Joined: 2006-08-21 15:38
Location: Denmark

Re: hMailServer Backup-MX acting weird!

Post by SorenR » 2021-01-03 23:59

mattg wrote:
2021-01-03 23:39
SorenR wrote:
2021-01-03 13:49
... Removed selection from "Verify remote server...." from hMailAdmin -> Settings -> Advanced -> SSL/TLS
'Verify' isn't actually used much.
It is used on SMTP routes, and for upstream 'External Account POP3' connections and not much else
https://www.hmailserver.com/forum/viewt ... 0f#p182087
Yeah, I noticed that when dissecting the source ;-)
mattg wrote:
2021-01-03 23:39
SorenR wrote:
2021-01-03 19:26
I use standard certificates from Let's Encrypt, one for each server and one for my webserver (no wildcard).

I normally use the "fullchain.cer" but hMailServer debug logging revealed the certificate CA could not be verified so I switched to the single certificate.
I need to use the 'full chain' for email clients like thunderbird and outlook to like the certificates.
In your case I would get ONE certificate from lets encrypt that covers both domains, and use it on both servers.

If your server can't verify the CA, perhaps your Windows certificate store needs updated trust certificates
If I remember correctly, you run older versions of Windows?
Everything is switched back to Fullchain.cer again on both servers.

"PrimaryServer" is a Windows Server 2003 R2 and "BackupServer" is a Windows Server 2019 Essential.
The W2K3R2 server will be phased out eventually. Recently the geoIP service I use switched to an encryption level not supported by Msxml2.ServerXMLHTTP.6.0 on the W2K3R2 so I had to rewrite it to use Curl ... :roll:

The openssl verification was done from a 'nix box.
SørenR.

Algorithm (noun.)
Word used by programmers when they do not want to explain what they did.

User avatar
mattg
Moderator
Moderator
Posts: 21268
Joined: 2007-06-14 05:12
Location: 'The Outback' Australia

Re: hMailServer Backup-MX acting weird!

Post by mattg » 2021-01-04 00:09

jim.bus wrote:
2021-01-03 23:53
mattg, I use Let's Encrypt Certificates but only use the 'cert.pem' and 'privkey.pem' files in hMailServer. I do not use the 'chain.pem' file because for some reason the expiration date in the 'chain.pem' file is always expired.

However, while I don't have any Thunderbird Clients, I do use an Outlook Client and have no problems with Outlook Clients connecting to my hMailServer.
I get my Lets Encrypt certificates on my Ubuntu server using certbot

Just checked my mailserver certificates.

cert.pem modified on 13 Dec 2020
chain.pem modified on 13 Dec 2020
fullchain.pem modified on 13 Dec 2020
privkey.pem modified on 13 Dec 2020

I use Fullchain.pem and privkey.pem in my hmailserver
Just 'cause I link to a page and say little else doesn't mean I am not being nice.
https://www.hmailserver.com/documentation

User avatar
jim.bus
Senior user
Senior user
Posts: 630
Joined: 2011-05-28 11:49
Location: US

Re: hMailServer Backup-MX acting weird!

Post by jim.bus » 2021-01-04 00:16

mattg wrote:
2021-01-04 00:09
jim.bus wrote:
2021-01-03 23:53
mattg, I use Let's Encrypt Certificates but only use the 'cert.pem' and 'privkey.pem' files in hMailServer. I do not use the 'chain.pem' file because for some reason the expiration date in the 'chain.pem' file is always expired.

However, while I don't have any Thunderbird Clients, I do use an Outlook Client and have no problems with Outlook Clients connecting to my hMailServer.
I get my Lets Encrypt certificates on my Ubuntu server using certbot

Just checked my mailserver certificates.

cert.pem modified on 13 Dec 2020
chain.pem modified on 13 Dec 2020
fullchain.pem modified on 13 Dec 2020
privkey.pem modified on 13 Dec 2020

I use Fullchain.pem and privkey.pem in my hmailserver
I get my Let's Encrypt Certificates from my Synology NAS Device using Synology DSM running on the NAS' Linux OS (DSM has internal utility to produce the Let's Encrypt Certificates). It returns only Certificates with 3 files 'cert.pem', 'chain.pem', and 'privkey.pem'.

User avatar
SorenR
Senior user
Senior user
Posts: 4197
Joined: 2006-08-21 15:38
Location: Denmark

Re: hMailServer Backup-MX acting weird!

Post by SorenR » 2021-01-04 00:22

mattg wrote:
2021-01-04 00:09
jim.bus wrote:
2021-01-03 23:53
mattg, I use Let's Encrypt Certificates but only use the 'cert.pem' and 'privkey.pem' files in hMailServer. I do not use the 'chain.pem' file because for some reason the expiration date in the 'chain.pem' file is always expired.

However, while I don't have any Thunderbird Clients, I do use an Outlook Client and have no problems with Outlook Clients connecting to my hMailServer.
I get my Lets Encrypt certificates on my Ubuntu server using certbot

Just checked my mailserver certificates.

cert.pem modified on 13 Dec 2020
chain.pem modified on 13 Dec 2020
fullchain.pem modified on 13 Dec 2020
privkey.pem modified on 13 Dec 2020

I use Fullchain.pem and privkey.pem in my hmailserver
Certbot hmm.... I use acme.sh on my Synology (DSM 4.2). I log on to the NAS using SSH and do the commandline sh*t ;-)

I also have Ubuntu 20.04 running in the Linux subsystem on my WS2019E. Perhaps I should put that into good use 8)
SørenR.

Algorithm (noun.)
Word used by programmers when they do not want to explain what they did.

Post Reply