Cannot start TLS: handshake failure

ewuewu

Renowned Member
Sep 14, 2010
61
0
71
Hamburg
We are currently testing the PMG and are already very convinced in many areas.
However, we receive the message “Cannot start TLS: handshake failure” several times a day when connecting to the mail servers of various customers.
The options
  • - Enable TLS
  • - Enable TLS Logging
  • - Add TLS Recieved Header
are all activated.
The mails all end up in the 'deferred queue'

Code:
postfix/smtp[1509]: setting up TLS connection to XXX.de.mail.protection.outlook.com[52.101.73.22]:25

postfix/smtp[1509]: XXX.de.mail.protection.outlook.com[52.101.73.22]:25: TLS cipher list "aNULL:-aNULL:HIGH:MEDIUM:+RC4:@STRENGTH"

postfix/smtp[1509]: looking for session
smtp&XXX.de&XXX.de.mail.protection.outlook.com&52.101.73.22&&8D5CCDD019FFBB67B0D124B3885F8A11381EC26ED7A9311767F41D6AA7410B61 in smtp cache

postfix/tlsmgr[946]: lookup smtp session id=smtp&XXX.de&XXX-
de01i.mail.protection.outlook.com&52.101.73.22&&8D5CCDD019FFBB67B0D124B3885F8A11381EC26ED7A9311767F41D6AA7410B61

postfix/smtp[1509]: SSL_connect error to XXX-de01i.mail.protection.outlook.com[52.101.73.22]:25: lost connection

postfix/smtp[1509]: remove session smtp&XXX.de&XXX-de01i.mail.protection.outlook.com&52.101.73.22&&8D5CCDD019FFBB67B0D124B3885F8A11381EC26ED7A9311767F41D6AA7410B61 from client cache

postfix/tlsmgr[946]: delete smtp session id=smtpXXX.de&XXX-de01i.mail.protection.outlook.com&52.101.73.22&&8D5CCDD019FFBB67B0D124B3885F8A11381EC26ED7A9311767F41D6AA7410B61

After a certain amount of time, the mails then disappear from the queue and are delivered. In some cases, however, we also receive bounces from the customer server with messages such as '<name.nachname@yyyy.de>: host mx1.yyyy.de[111.222.333.444] said: 530 #5.7.0
Must issue a STARTTLS command first (in reply to MAIL FROM command)'
 
as general connections to protection.outlook.com with a PMG do work (else we'd have quite a few more reports, given how many domains are handled by those machines) - do you have any customizations in place (TLS policies, custom postfix configurations,...), or a firewall in the middle that might try to strip starttls for content inspection?
 
We currently only have iptables running as a firewall.
All outgoing connections are allowed, we allow PORT 25, 26 and 8006 for incoming connections.

In the template main.cf.in I have only set the smtp_tls_loglevel and the smtpd_tls_loglevel to 2.

This error only happens with outgoing mails, i.e. from PMG to outlook.com
The TLS negotiation works immediately for incoming mails.

The outgoing mails are initially rejected. After a few minutes (sometimes more, sometimes less) the mails are accepted by outlook.com despite the TLS error.

Code:
2024-12-12T14:07 postfix/smtp[5071]: 69E631C118F: Cannot start TLS: handshake failure
2024-12-12T14:07 postfix/smtp[5071]: 69E631C118F: Cannot start TLS: handshake failure
2024-12-12T14:07 postfix/smtp[5071]: 69E631C118F: Cannot start TLS: handshake failure
2024-12-12T14:07 postfix/smtp[5071]: 69E631C118F: to=<xxx@mydomain.net>, relay=mydomain.mail.protection.outlook.com[52.101.68.32]:25, delay=0.55, delays=0.06/0.04/0.45/0, dsn=4.7.5, status=deferred (Cannot start TLS: handshake failure)
2024-12-12T14:07 postfix/smtp[5071]: 69E631C118F: to=<yyyy@mydomain.net>, relay=mydomain.mail.protection.outlook.com[52.101.68.32]:25, delay=0.55, delays=0.06/0.04/0.45/0, dsn=4.7.5, status=deferred (Cannot start TLS: handshake failure)
2024-12-12T14:07 postfix/smtp[5071]: 69E631C118F: to=<zzzz@mydomain.net>, relay=mydomain.mail.protection.outlook.com[52.101.68.32]:25, delay=0.55, delays=0.06/0.04/0.45/0, dsn=4.7.5, status=deferred (Cannot start TLS: handshake failure)

2024-12-12T14:17 postfix/qmgr[934]: 69E631C118F: from=<aaa.bbbb@ddddd.de>, size=13534, nrcpt=3 (queue active)
2024-12-12T14:17 postfix/smtp[5360]: 69E631C118F: Cannot start TLS: handshake failure
2024-12-12T14:17 postfix/smtp[5360]: 69E631C118F: to=<yyyy@mydomain.net>, relay=mydomain.mail.protection.outlook.com[52.101.68.18]:25, delay=593, delays=590/0.04/0.27/3, dsn=2.6.0, status=sent (250 2.6.0 <B42D1C7C33549B42B6E25B0326185AA435F8DDC2@myhost@mydomain.com> [InternalId=204852760164415, Hostname=DB8PR09MB4424.eurprd09.prod.outlook.com] 25308 bytes in 0.328, 75.350 KB/sec Queued mail for delivery)
2024-12-12T14:17 postfix/smtp[5360]: 69E631C118F: to=<xxxx@mydomain.net>, relay=mydomain.mail.protection.outlook.com[52.101.68.18]:25, delay=593, delays=590/0.04/0.27/3, dsn=2.6.0, status=sent (250 2.6.0 <B42D1C7C33549B42B6E25B0326185AA435F8DDC2@myhost@mydomain.com> [InternalId=204852760164415, Hostname=DB8PR09MB4424.eurprd09.prod.outlook.com] 25308 bytes in 0.328, 75.350 KB/sec Queued mail for delivery)
2024-12-12T14:17 postfix/smtp[5360]: 69E631C118F: to=<zzzz@mydomain.net>, relay=mydomain.mail.protection.outlook.com[52.101.68.18]:25, delay=593, delays=590/0.04/0.27/3, dsn=2.6.0, status=sent (250 2.6.0 <B42D1C7C33549B42B6E25B0326185AA435F8DDC2@myhost@mydomain.com> [InternalId=204852760164415, Hostname=DB8PR09MB4424.eurprd09.prod.outlook.com] 25308 bytes in 0.328, 75.350 KB/sec Queued mail for delivery)
2024-12-12T14:17 postfix/qmgr[934]: 69E631C118F: removed
 
Last edited:
you can try connecting to that machine with openssl - maybe this sheds some light:
Code:
openssl s_client -connect 52.101.73.22:25 -starttls smtp
(add the -debug flag, if this fails)
 
this works like charm.

Code:
CONNECTED(00000003)
Can't use SSL_get_servername
depth=2 C = US, O = DigiCert Inc, OU = www.digicert.com, CN = DigiCert Global Root CA
verify return:1
depth=1 C = US, O = DigiCert Inc, CN = DigiCert Cloud Services CA-1
verify return:1
depth=0 C = US, ST = Washington, L = Redmond, O = Microsoft Corporation, CN = mail.protection.outlook.com
verify return:1
---
Certificate chain
 0 s:C = US, ST = Washington, L = Redmond, O = Microsoft Corporation, CN = mail.protection.outlook.com
   i:C = US, O = DigiCert Inc, CN = DigiCert Cloud Services CA-1
   a:PKEY: rsaEncryption, 2048 (bit); sigalg: RSA-SHA256
   v:NotBefore: Sep 18 00:00:00 2024 GMT; NotAfter: Sep 17 23:59:59 2025 GMT
 1 s:C = US, O = DigiCert Inc, CN = DigiCert Cloud Services CA-1
   i:C = US, O = DigiCert Inc, OU = www.digicert.com, CN = DigiCert Global Root CA
   a:PKEY: rsaEncryption, 2048 (bit); sigalg: RSA-SHA256
   v:NotBefore: Sep 25 00:00:00 2020 GMT; NotAfter: Sep 24 23:59:59 2030 GMT
---
Server certificate
-----BEGIN CERTIFICATE-----
MIIJnzCCCIegAwIBAgIQBM8LWp1nqH4zl6yjIzf1ODANBgkqhkiG9w0BAQsFADBL
MQswCQYDVQQGEwJVUzEVMBMGA1UEChMMRGlnaUNlcnQgSW5jMSUwIwYDVQQDExxE
aWdpQ2VydCBDbG91ZCBTZXJ2aWNlcyBDQS0xMB4XDTI0MDkxODAwMDAwMFoXDTI1
MDkxNzIzNTk1OVowejELMAkGA1UEBhMCVVMxEzARBgNVBAgTCldhc2hpbmd0b24x
EDAOBgNVBAcTB1JlZG1vbmQxHjAcBgNVBAoTFU1pY3Jvc29mdCBDb3Jwb3JhdGlv
bjEkMCIGA1UEAxMbbWFpbC5wcm90ZWN0aW9uLm91dGxvb2suY29tMIIBIjANBgkq
hkiG9w0BAQEFAAOCAQ8AMIIBCgKCAQEAvc99UgnaTq4fC4Hq3bklkIUtW0ht0oqk
PtFH0X9HE7Ljlos8TTIhhgqsIGGTbWuhp5PJSSkIPTrQFBmrDJ6JL0OxKjmhqYft
RkmTwT2+t+OYsEohz4kic6fmiB1ktpFkrXgwk+Tu5o0BL7v00mOzrk6Di4X/hKoe
9CElsV4LWOi9PoxSufTxzwGGfoxJ2C6Ozs5t3OWlg8R2qbPKB4u5ZAhtdKIwmlMt
IRP1MwkuuLe2s4iayuELcHMSTtSXAOzwmPHMVJrT+pNuQ2K1RSVBpD6BWyxMswzt
B5u0n467pOpdQt/G34Z6XKsvNGNFQXfX9ivOpoqT3vL6xQc9vTxNcQIDAQABo4IG
TjCCBkowHwYDVR0jBBgwFoAU3VHQojFzqXOuj7QBfl2MV8uf8PcwHQYDVR0OBBYE
FID2pktuAi61jnfIyUZuLcUvHqxhMIIC+QYDVR0RBIIC8DCCAuyCG21haWwucHJv
dGVjdGlvbi5vdXRsb29rLmNvbYIVKi5tYWlsLmVvLm91dGxvb2suY29tgh0qLm1h
aWwucHJvdGVjdGlvbi5vdXRsb29rLmNvbYIcbWFpbC5tZXNzYWdpbmcubWljcm9z
b2Z0LmNvbYILb3V0bG9vay5jb22CHCoub2xjLnByb3RlY3Rpb24ub3V0bG9vay5j
b22CEyoucGFteDEuaG90bWFpbC5jb22CHCoubWFpbC5wcm90ZWN0aW9uLm91dGxv
b2suZGWCDioubXgubWljcm9zb2Z0ghMqLmstdjEubXgubWljcm9zb2Z0ghMqLm4t
djEubXgubWljcm9zb2Z0ghMqLnEtdjEubXgubWljcm9zb2Z0ghMqLnktdjEubXgu
bWljcm9zb2Z0ghMqLmQtdjEubXgubWljcm9zb2Z0ghMqLmUtdjEubXgubWljcm9z
b2Z0ghMqLmEtdjEubXgubWljcm9zb2Z0ghMqLnItdjEubXgubWljcm9zb2Z0ghMq
LnctdjEubXgubWljcm9zb2Z0ghMqLnAtdjEubXgubWljcm9zb2Z0ghMqLngtdjEu
bXgubWljcm9zb2Z0ghMqLmotdjEubXgubWljcm9zb2Z0ghMqLnMtdjEubXgubWlj
cm9zb2Z0ghMqLmMtdjEubXgubWljcm9zb2Z0ghMqLmItdjEubXgubWljcm9zb2Z0
ghMqLmYtdjEubXgubWljcm9zb2Z0ghMqLmktdjEubXgubWljcm9zb2Z0ghMqLnQt
djEubXgubWljcm9zb2Z0ghMqLm0tdjEubXgubWljcm9zb2Z0ghMqLm8tdjEubXgu
bWljcm9zb2Z0ghMqLmctdjEubXgubWljcm9zb2Z0ghMqLnYtdjEubXgubWljcm9z
b2Z0ghMqLmgtdjEubXgubWljcm9zb2Z0ghMqLmwtdjEubXgubWljcm9zb2Z0ghMq
LnUtdjEubXgubWljcm9zb2Z0MD4GA1UdIAQ3MDUwMwYGZ4EMAQICMCkwJwYIKwYB
BQUHAgEWG2h0dHA6Ly93d3cuZGlnaWNlcnQuY29tL0NQUzAOBgNVHQ8BAf8EBAMC
BaAwHQYDVR0lBBYwFAYIKwYBBQUHAwEGCCsGAQUFBwMCMIGNBgNVHR8EgYUwgYIw
P6A9oDuGOWh0dHA6Ly9jcmwzLmRpZ2ljZXJ0LmNvbS9EaWdpQ2VydENsb3VkU2Vy
dmljZXNDQS0xLWcxLmNybDA/oD2gO4Y5aHR0cDovL2NybDQuZGlnaWNlcnQuY29t
L0RpZ2lDZXJ0Q2xvdWRTZXJ2aWNlc0NBLTEtZzEuY3JsMHwGCCsGAQUFBwEBBHAw
bjAlBggrBgEFBQcwAYYZaHR0cDovL29jc3B4LmRpZ2ljZXJ0LmNvbTBFBggrBgEF
BQcwAoY5aHR0cDovL2NhY2VydHMuZGlnaWNlcnQuY29tL0RpZ2lDZXJ0Q2xvdWRT
ZXJ2aWNlc0NBLTEuY3J0MAwGA1UdEwEB/wQCMAAwggF+BgorBgEEAdZ5AgQCBIIB
bgSCAWoBaAB2ABLxTjS9U3JMhAYZw48/ehP457Vih4icbTAFhOvlhiY6AAABkgUr
HhgAAAQDAEcwRQIhAP30Wx8SLPKfdw0RKjN994pXMvga1N/W4cyjqhSzVMtAAiBa
6l1i2j2K9dJXOA7I9l6E218Ho0fd4QiM7Yu9LmgCkgB1AObSMWNAd4zBEEEG13G5
zsHSQPaWhIb7uocyHf0eN45QAAABkgUrHd4AAAQDAEYwRAIgUkVoXxUQCRnmh833
MmQe2H0nMcaAwV74izsPe0scAxECIGCnTb9sfmqAVBGwagBc5u7sp0EliewySyO4
nhIsn/jyAHcAzPsPaoVxCWX+lZtTzumyfCLphVwNl422qX5UwP5MDbAAAAGSBSsd
1AAABAMASDBGAiEAuNL3G2JGv3ywkOadFlDGcwvBnQdK3jsQCXg4V6DtQSYCIQCs
MMpOY7eCnnIRbz/Na9GyjCfnZaCJIq5WoeFJazE7GTANBgkqhkiG9w0BAQsFAAOC
AQEAZVstVOJ9PGgg8BOlGD23ifMDSd3aIeeJVP/1LuQNrYxPDlo+1F9V7YFLTUrT
r3RgFdAmVh21fe/I1/iuGBDfAgq7wQVJdMYqvnhVhtGBVelEU9ey4Fj2N7eHBz8g
wM26P3GIpeEBxOLrFkrFF18s7LOEB5f0nxGhdAMxdVBh+z6VB668Y1FPmkvp9UQQ
EmlJdlDNbHgPQvIh/1se39TCGi5/uxDZttJSe+D67W1v4dBvu/N0cAbD/vN2Q2wq
24vAvnw6DwfCvfOIN0x1VzQhQwlIrgJLBH4GOFi/KxOw4X2P9bJ5cC9jT0l5/V5K
1P98W5eP3I2YWc5VxfaEbL9RDA==
-----END CERTIFICATE-----
subject=C = US, ST = Washington, L = Redmond, O = Microsoft Corporation, CN = mail.protection.outlook.com
issuer=C = US, O = DigiCert Inc, CN = DigiCert Cloud Services CA-1
---
No client certificate CA names sent
Requested Signature Algorithms: RSA-PSS+SHA256:RSA-PSS+SHA384:RSA-PSS+SHA512:RSA+SHA256:RSA+SHA384:RSA+SHA1:ECDSA+SHA256:ECDSA+SHA384:ECDSA+SHA1:DSA+SHA1:RSA+SHA512:ECDSA+SHA512
Shared Requested Signature Algorithms: RSA-PSS+SHA256:RSA-PSS+SHA384:RSA-PSS+SHA512:RSA+SHA256:RSA+SHA384:ECDSA+SHA256:ECDSA+SHA384:RSA+SHA512:ECDSA+SHA512
Peer signing digest: SHA256
Peer signature type: RSA-PSS
Server Temp Key: ECDH, secp384r1, 384 bits

~# openssl s_client -connect 52.101.73.22:25 -starttls smtp

---
SSL handshake has read 4796 bytes and written 802 bytes
Verification: OK
---
New, TLSv1.3, Cipher is TLS_AES_256_GCM_SHA384
Server public key is 2048 bit
Secure Renegotiation IS NOT supported
Compression: NONE
Expansion: NONE
No ALPN negotiated
Early data was not sent
Verify return code: 0 (ok)
---
250 SMTPUTF8
---
Post-Handshake New Session Ticket arrived:
SSL-Session:
    Protocol  : TLSv1.3
    Cipher    : TLS_AES_256_GCM_SHA384
    Session-ID: 5A06CDE773A8740792B4A296272B043AE42CCADE92C72E9EEDB2E271A5642F9D
    Session-ID-ctx:
    Resumption PSK: BFE5E36F280E0203F46A382F34AE4990E5CA322B242DBF2E0369B4B86E99C684F4FD76322BF04B473E451717E25F2EF4
    PSK identity: None
    PSK identity hint: None
    SRP username: None
    TLS session ticket lifetime hint: 36000 (seconds)
    TLS session ticket:
    0000 - c0 0e 00 00 cf 31 44 a2-9b d6 ee ee 88 ae 97 d1   .....1D.........
    0010 - 88 40 c0 5e e9 12 5f 97-51 3c c4 5b 4f c0 30 49   .@.^.._.Q<.[O.0I

    Start Time: 1734023979
    Timeout   : 7200 (sec)
    Verify return code: 0 (ok)
    Extended master secret: no
    Max Early Data: 0
---
read R BLOCK
 
this works like charm.
ok - that would somewhat rule out something in the middle between your PMG and microsoft doing ssl-stripping or other things that would cause TLS-handshaking to fail....

Things I could still imagine - maybe some of the microsoft smtp-servers simply are not responding correctly temporarily (this happens with SMTP in various scenarios and usually is not noticeable, as the mail is accepted a few seconds/minutes later anyways)
The logs you shared show that the initial connection to 52.101.68.32 fails, the next one to 52.101.68.18 succeeds ...

if this happens regularly the next step for debugging I'd suggest is to enable the verbose flag for the smtp-line in master.cf.in:
https://www.postfix.org/DEBUG_README.html#verbose

(this generates quite a lot more output - so try to activate it for a short time until the issue happens - else searching the logs will be a bit cumbersome)

I hope this helps!
 

About

The Proxmox community has been around for many years and offers help and support for Proxmox VE, Proxmox Backup Server, and Proxmox Mail Gateway.
We think our community is one of the best thanks to people like you!

Get your subscription!

The Proxmox team works very hard to make sure you are running the best software and getting stable updates and security enhancements, as well as quick enterprise support. Tens of thousands of happy customers have a Proxmox subscription. Get yours easily in our online shop.

Buy now!