stalwartlabs / mail-server

Secure & Modern All-in-One Mail Server (IMAP, JMAP, POP3, SMTP)
https://stalw.art
4.86k stars 198 forks source link

[bug]: STARTTLS was not advertised by host #191

Closed s0xDk closed 8 months ago

s0xDk commented 9 months ago

What happened?

Version: 0.5.1

Whenever I try to send an email to any domain, I get the following error:

INFO delivery{id=26527524893 return_path="<REDACTED>" nrcpt=1 size=949}:attempt{domain="proton.me" attempt_number=0}: smtp::outbound::delivery: context="tls" event="unavailable" mx="mail.protonmail.ch" reason="STARTTLS was not advertised by host"
INFO delivery{id=26527524893 return_path="<REDACTED>" nrcpt=1 size=949}:attempt{domain="proton.me" attempt_number=0}: smtp::outbound::delivery: context="tls" event="unavailable" mx="mailsec.protonmail.ch" reason="STARTTLS was not advertised by host"

But Proton Mail servers are 100% advertising STARTTLS:

220 mailin026.protonmail.ch ESMTP Postfix [179 ms]
EHLO keeper-us-east-1d.mxtoolbox.com
250-mailin026.protonmail.ch
250-PIPELINING
250-SIZE 36480000
250-STARTTLS
250-ENHANCEDSTATUSCODES
250-8BITMIME
250 CHUNKING [196 ms]

How can we reproduce the problem?

Send an email via stalwart.

Version

v0.5.x

What database are you using?

SQLite

What blob storage are you using?

Filesystem

Where is your directory located?

SQL

What operating system are you using?

Linux

Relevant log output

No response

Code of Conduct

mdecimus commented 9 months ago

Hi, I can't reproduce this issue. I've tested sending emails to both proton.me and protonmail.ch and not only STARTTLS is used but also DANE and MTA-STS. Here are the logs:

2024-01-09T11:45:38.754252Z DEBUG delivery{id=758115938 return_path="john@example.org" nrcpt=1 size=4074}:attempt{domain="protonmail.ch" attempt_number=0}: smtp::outbound::delivery: context="tlsrpt" event="record-fetched" record=TlsRpt { rua: [Http("https://reports.proton.me/reports/smtptls")] }
2024-01-09T11:45:39.009180Z DEBUG delivery{id=758115938 return_path="john@example.org" nrcpt=1 size=4074}:attempt{domain="protonmail.ch" attempt_number=0}: smtp::outbound::delivery: context="sts" event="policy-fetched" policy=Policy { id: "190906205100Z", mode: Enforce, mx: [Equals("mail.protonmail.ch"), Equals("mailsec.protonmail.ch")], max_age: 604800 }
2024-01-09T11:45:39.358229Z DEBUG delivery{id=758115938 return_path="john@example.org" nrcpt=1 size=4074}:attempt{domain="protonmail.ch" attempt_number=0}: smtp::outbound::delivery: context="dane" event="record-fetched" mx="mail.protonmail.ch" record=Tlsa { entries: [TlsaEntry { is_end_entity: true, is_sha256: true, is_spki: true, data: [118, 187, 102, 113, 29, 164, 22, 67, 60, 168, 144, 165, 178, 229, 160, 83, 60, 96, 6, 71, 143, 125, 16, 164, 70, 154, 148, 122, 204, 131, 153, 225] }, TlsaEntry { is_end_entity: true, is_sha256: true, is_spki: true, data: [97, 17, 165, 105, 141, 35, 200, 158, 9, 195, 111, 248, 51, 193, 72, 126, 220, 27, 12, 132, 31, 135, 196, 157, 174, 143, 122, 9, 225, 30, 151, 158] }], has_end_entities: true, has_intermediates: false }
2024-01-09T11:45:39.408360Z DEBUG delivery{id=758115938 return_path="john@example.org" nrcpt=1 size=4074}:attempt{domain="protonmail.ch" attempt_number=0}: smtp::outbound::delivery: context="connect" event="success" mx="mail.protonmail.ch" source_ip=0.0.0.0 remote_ip=176.119.200.128 remote_port=25
2024-01-09T11:45:45.295999Z DEBUG delivery{id=758115938 return_path="john@example.org" nrcpt=1 size=4074}:attempt{domain="protonmail.ch" attempt_number=0}: smtp::outbound::delivery: context="tls" event="success" mx="mail.protonmail.ch" protocol=Some(TLSv1_3) cipher=Some(TLS13_AES_256_GCM_SHA384)
2024-01-09T11:45:45.296838Z DEBUG delivery{id=758115938 return_path="john@example.org" nrcpt=1 size=4074}:attempt{domain="protonmail.ch" attempt_number=0}: smtp::outbound::dane::verify: Matched TLSA record with hash [76, bb, 66, 71, 1d, a4, 16, 43, 3c, a8, 90, a5, b2, e5, a0, 53, 3c, 60, 6, 47, 8f, 7d, 10, a4, 46, 9a, 94, 7a, cc, 83, 99, e1]. context="dane" event="info" mx="mail.protonmail.ch" certificate="end-entity"
2024-01-09T11:45:45.296919Z  INFO delivery{id=758115938 return_path="john@example.org" nrcpt=1 size=4074}:attempt{domain="protonmail.ch" attempt_number=0}: smtp::outbound::dane::verify: DANE authentication successful. context="dane" event="authenticated" mx="mail.protonmail.ch"
2024-01-09T11:45:48.122142Z  INFO delivery{id=758115938 return_path="john@example.org" nrcpt=1 size=4074}:attempt{domain="protonmail.ch" attempt_number=0}: smtp::outbound::session: context="rcpt" event="delivered" rcpt="info@protonmail.ch" mx="mail.protonmail.ch" response=Delivered: Code: 250, Enhanced code: 2.1.5, Message: Ok

Can you describe your setup? Have you changed any settings? Are you behind a proxy perhaps?

mdecimus commented 8 months ago

Issue can't be reproduced, closing.