Cannot recieve mail from microsoft protection to specific domain

opth

Hi.
I have a problem with my mailcow mailserver that I run for a local school.
I have multiple domains at that installation and all of them work flawlessly except for one.
For this specific domain, everything works except receiving mail from microsoft’s outlook services.
I have tried to update mailcow, restart it, went thru all the settings again, but I was still unable to find what is causing this particular issue. It seems not logical.

See the attached log from postfix:

Jan  7 10:51:23 82951a3ee468 postfix/postscreen[504]: CONNECT from [40.107.105.138]:5089 to [172.23.1.253]:25
Jan  7 10:51:23 82951a3ee468 postfix/postscreen[504]: WHITELISTED [40.107.105.138]:5089
Jan  7 10:51:24 82951a3ee468 postfix/smtpd[527]: connect from mail-am7eur03on2138.outbound.protection.outlook.com[40.107.105.138]
Jan  7 10:51:24 82951a3ee468 postfix/smtpd[527]: Anonymous TLS connection established from mail-am7eur03on2138.outbound.protection.outlook.com[40.107.105.138] to mail.domain.cz: TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)
Jan  7 10:51:24 82951a3ee468 postfix/smtpd[527]: disconnect from mail-am7eur03on2138.outbound.protection.outlook.com[40.107.105.138] ehlo=1 starttls=1 quit=1 commands=3
Jan  7 10:52:22 82951a3ee468 postfix/postscreen[504]: CONNECT from [40.107.8.108]:4418 to [172.23.1.253]:25
Jan  7 10:52:22 82951a3ee468 postfix/postscreen[504]: WHITELISTED [40.107.8.108]:4418
Jan  7 10:52:23 82951a3ee468 postfix/smtpd[527]: connect from mail-vi1eur04on2108.outbound.protection.outlook.com[40.107.8.108]
Jan  7 10:52:23 82951a3ee468 postfix/smtpd[527]: Anonymous TLS connection established from mail-vi1eur04on2108.outbound.protection.outlook.com[40.107.8.108] to mail.domain.cz: TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)
Jan  7 10:52:23 82951a3ee468 postfix/smtpd[527]: disconnect from mail-vi1eur04on2108.outbound.protection.outlook.com[40.107.8.108] ehlo=1 starttls=1 quit=1 commands=3
Jan  7 10:52:35 82951a3ee468 postfix/postscreen[504]: CONNECT from [40.107.8.117]:33170 to [172.23.1.253]:25
Jan  7 10:52:35 82951a3ee468 postfix/postscreen[504]: WHITELISTED [40.107.8.117]:33170
Jan  7 10:52:38 82951a3ee468 postfix/smtpd[527]: connect from mail-vi1eur04on2117.outbound.protection.outlook.com[40.107.8.117]
Jan  7 10:52:38 82951a3ee468 postfix/smtpd[527]: Anonymous TLS connection established from mail-vi1eur04on2117.outbound.protection.outlook.com[40.107.8.117] to mail.domain.cz: TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)
Jan  7 10:52:38 82951a3ee468 postfix/smtpd[527]: disconnect from mail-vi1eur04on2117.outbound.protection.outlook.com[40.107.8.117] ehlo=1 starttls=1 quit=1 commands=3

It doesnt make sense to me, i can recieve from microsoft to all domains except one on my mail server…

Can anybody help me with that?
Thanks

esackbauer

Sorry I don’t have that at hand.

opth WHITELISTED [40.107.105.138]:5089

So you did some whitelisting, are you sure that you do not have any sieve postscreen/extra.cf settings which have side effects on that one domain?

esackbauer

What error does the bounce message of Outlook say?
What does the rspamd log say?

opth

esackbauer Thanks for your reply.
It doesnt. I have verified from multiple sources, that outlook just outright ignores this behavior.
In Mailcow, the mail does not get past postfix, so there is no log of it in rspamd. I have checked that.

I have also checked the validity of my certificates with the mailcow helper.

helper-scripts/expiry-dates.sh
TLS expiry dates:
Postfix: Apr  6 09:33:16 2024 GMT
Dovecot: Apr  6 09:33:16 2024 GMT
Nginx:   Apr  6 09:33:16 2024 GMT

Or just to double check with another tool from a completely different machine.

sslscan --starttls-smtp --no-ciphersuites --no-heartbleed --no-groups --no-compression mail.myserver.cz:25
Version: 2.1.2
OpenSSL 3.2.0 23 Nov 2023

Connected to 194.182.91.5

Testing SSL server mail.zsmszdarky.cz on port 25 using SNI name mail.zsmszdarky.cz

  SSL/TLS Protocols:
SSLv2     disabled
SSLv3     disabled
TLSv1.0   enabled
TLSv1.1   enabled
TLSv1.2   enabled
TLSv1.3   enabled

  TLS Fallback SCSV:
Server supports TLS Fallback SCSV

  TLS renegotiation:
Secure session renegotiation supported


  SSL Certificate:
Signature Algorithm: sha256WithRSAEncryption
RSA Key Strength:    4096

Subject:  mail.zsmszdarky.cz
Altnames: DNS:mail.zsmszdarky.cz
Issuer:   R3

Not valid before: Jan  7 09:33:17 2024 GMT
Not valid after:  Apr  6 09:33:16 2024 GMT

I have also checked the validity of my certificates with the mailcow helper.

helper-scripts/expiry-dates.sh
TLS expiry dates:
Postfix: Apr  6 09:33:16 2024 GMT
Dovecot: Apr  6 09:33:16 2024 GMT
Nginx:   Apr  6 09:33:16 2024 GMT

Or just to double check with another tool from a completely different machine.

sslscan --starttls-smtp --no-ciphersuites --no-heartbleed --no-groups --no-compression mail.myserver.cz:25
Version: 2.1.2
OpenSSL 3.2.0 23 Nov 2023

Connected to 194.182.91.5

Testing SSL server mail.zsmszdarky.cz on port 25 using SNI name mail.zsmszdarky.cz

  SSL/TLS Protocols:
SSLv2     disabled
SSLv3     disabled
TLSv1.0   enabled
TLSv1.1   enabled
TLSv1.2   enabled
TLSv1.3   enabled

  TLS Fallback SCSV:
Server supports TLS Fallback SCSV

  TLS renegotiation:
Secure session renegotiation supported


  SSL Certificate:
Signature Algorithm: sha256WithRSAEncryption
RSA Key Strength:    4096

Subject:  mail.zsmszdarky.cz
Altnames: DNS:mail.zsmszdarky.cz
Issuer:   R3

Not valid before: Jan  7 09:33:17 2024 GMT
Not valid after:  Apr  6 09:33:16 2024 GMT

esackbauer

So you are saying you don’t get a bounce message in Outlook? How is this possible? How long have you waited? After 2-4 hours there should be a delay notification, and after 48 hours there should be the bounce that it couldnt be delivered.

opth

esackbauer
Yes, i do not get anything in outlook. it pretends that everything went fine.
This issue was actually reported by the users of my mailserver. I verified the issue and nothing happends on outlook’s end.
No notification, no nothing.

Outlook just sometimes connects (as seen in the first log snipped in this thread) and then immediately disconnects.

esackbauer

Again, since when is this issue? Are we talking about hours or days?
If its just hours, maybe DNS is not properly set up or records are not yet distributed to all servers.

If it is since days, then Outlook considers the mail delivered.
Maybe you fiddled around with some config files regarding postscreen or sieve, please undo any changes and revert to defaults. My users have no problem writing to mailcow from Outlook.com

opth

esackbauer
I have infact not changed any configs or so.
This has been happening for multiple days.
Nor have i changed any DNS settings.
What i suspect is some kind of change on the microsoft’s side. But i am unsure of that.

esackbauer

opth What i suspect is some kind of change on the microsoft’s side.

I wouldnt think so. If no bounce message is there, from Microsoft side the SMTP session is considered successful and the mail has from their point of view been delivered.
I just tested sending mails to my mailcow domains from outlook.com, and it is working.

opth

esackbauer
I agree.
Would you happen to know how to enable verbose debug level for postfix?
Ideally to log every SMTP command.

I have just figured the verbose logging out.

Take a look at this exchange between my mailcow server and outlook’s.

Jan  7 11:59:12 82951a3ee468 postfix/smtpd[395]: > mail-db5eur02on2091.outbound.protection.outlook.com[40.107.249.91]: 220 mail.mydomain.cz ESMTP Postcow
Jan  7 11:59:12 82951a3ee468 postfix/smtpd[395]: watchdog_pat: 0x55de708c3360
Jan  7 11:59:12 82951a3ee468 postfix/smtpd[395]: vstream_fflush_some: fd 11 flush 38
Jan  7 11:59:12 82951a3ee468 postfix/smtpd[395]: vstream_buf_get_ready: fd 11 got 52
Jan  7 11:59:12 82951a3ee468 postfix/smtpd[395]: < mail-db5eur02on2091.outbound.protection.outlook.com[40.107.249.91]: EHLO EUR02-DB5-obe.outbound.protection.outlook.com
Jan  7 11:59:12 82951a3ee468 postfix/smtpd[395]: report helo to all milters
Jan  7 11:59:12 82951a3ee468 postfix/smtpd[395]: milter_macro_lookup: "{tls_version}"
Jan  7 11:59:12 82951a3ee468 postfix/smtpd[395]: milter_macro_lookup: "{cipher}"
Jan  7 11:59:12 82951a3ee468 postfix/smtpd[395]: milter_macro_lookup: "{cipher_bits}"
Jan  7 11:59:12 82951a3ee468 postfix/smtpd[395]: milter_macro_lookup: "{cert_subject}"
Jan  7 11:59:12 82951a3ee468 postfix/smtpd[395]: milter_macro_lookup: "{cert_issuer}"
Jan  7 11:59:12 82951a3ee468 postfix/smtpd[395]: milter8_helo_event: milter inet:rspamd:9900: helo EUR02-DB5-obe.outbound.protection.outlook.com
Jan  7 11:59:12 82951a3ee468 postfix/smtpd[395]: event: SMFIC_HELO; macros: (none)
Jan  7 11:59:12 82951a3ee468 postfix/smtpd[395]: skipping reply for event SMFIC_HELO from milter inet:rspamd:9900
Jan  7 11:59:12 82951a3ee468 postfix/smtpd[395]: match_list_match: mail-db5eur02on2091.outbound.protection.outlook.com: no match
Jan  7 11:59:12 82951a3ee468 postfix/smtpd[395]: match_list_match: 40.107.249.91: no match
Jan  7 11:59:12 82951a3ee468 postfix/smtpd[395]: > mail-db5eur02on2091.outbound.protection.outlook.com[40.107.249.91]: 250-mail.zsmszdarky.cz
Jan  7 11:59:12 82951a3ee468 postfix/smtpd[395]: > mail-db5eur02on2091.outbound.protection.outlook.com[40.107.249.91]: 250-PIPELINING
Jan  7 11:59:12 82951a3ee468 postfix/smtpd[395]: > mail-db5eur02on2091.outbound.protection.outlook.com[40.107.249.91]: 250-SIZE 104857600
Jan  7 11:59:12 82951a3ee468 postfix/smtpd[395]: > mail-db5eur02on2091.outbound.protection.outlook.com[40.107.249.91]: 250-ETRN
Jan  7 11:59:12 82951a3ee468 postfix/smtpd[395]: > mail-db5eur02on2091.outbound.protection.outlook.com[40.107.249.91]: 250-STARTTLS
Jan  7 11:59:12 82951a3ee468 postfix/smtpd[395]: > mail-db5eur02on2091.outbound.protection.outlook.com[40.107.249.91]: 250-ENHANCEDSTATUSCODES
Jan  7 11:59:12 82951a3ee468 postfix/smtpd[395]: > mail-db5eur02on2091.outbound.protection.outlook.com[40.107.249.91]: 250-8BITMIME
Jan  7 11:59:12 82951a3ee468 postfix/smtpd[395]: > mail-db5eur02on2091.outbound.protection.outlook.com[40.107.249.91]: 250-DSN
Jan  7 11:59:12 82951a3ee468 postfix/smtpd[395]: > mail-db5eur02on2091.outbound.protection.outlook.com[40.107.249.91]: 250 CHUNKING
Jan  7 11:59:12 82951a3ee468 postfix/smtpd[395]: watchdog_pat: 0x55de708c3360
Jan  7 11:59:12 82951a3ee468 postfix/smtpd[395]: vstream_fflush_some: fd 11 flush 146
Jan  7 11:59:12 82951a3ee468 postfix/smtpd[395]: vstream_buf_get_ready: fd 11 got 10
Jan  7 11:59:12 82951a3ee468 postfix/smtpd[395]: < mail-db5eur02on2091.outbound.protection.outlook.com[40.107.249.91]: STARTTLS
Jan  7 11:59:12 82951a3ee468 postfix/smtpd[395]: query milter states for other event
Jan  7 11:59:12 82951a3ee468 postfix/smtpd[395]: milter8_other_event: milter inet:rspamd:9900
Jan  7 11:59:12 82951a3ee468 postfix/smtpd[395]: > mail-db5eur02on2091.outbound.protection.outlook.com[40.107.249.91]: 220 2.0.0 Ready to start TLS
Jan  7 11:59:12 82951a3ee468 postfix/smtpd[395]: vstream_fflush_some: fd 11 flush 30
Jan  7 11:59:12 82951a3ee468 postfix/smtpd[395]: abort all milters
Jan  7 11:59:12 82951a3ee468 postfix/smtpd[395]: milter8_abort: abort milter inet:rspamd:9900
Jan  7 11:59:12 82951a3ee468 postfix/smtpd[395]: auto_clnt_open: connected to private/tlsmgr
Jan  7 11:59:12 82951a3ee468 postfix/smtpd[395]: event_enable_read: fd 19
Jan  7 11:59:12 82951a3ee468 postfix/smtpd[395]: event_request_timer: set 0x7f70934968a0 0x55de7089c240 5
Jan  7 11:59:12 82951a3ee468 postfix/smtpd[395]: event_request_timer: set 0x7f70934968c0 0x55de7089c240 1000
Jan  7 11:59:12 82951a3ee468 postfix/smtpd[395]: send attr request = seed
Jan  7 11:59:12 82951a3ee468 postfix/smtpd[395]: send attr size = 32
Jan  7 11:59:12 82951a3ee468 postfix/smtpd[395]: vstream_fflush_some: fd 19 flush 22
Jan  7 11:59:12 82951a3ee468 postfix/smtpd[395]: vstream_buf_get_ready: fd 19 got 60
Jan  7 11:59:12 82951a3ee468 postfix/smtpd[395]: private/tlsmgr: wanted attribute: status
Jan  7 11:59:12 82951a3ee468 postfix/smtpd[395]: input attribute name: status
Jan  7 11:59:12 82951a3ee468 postfix/smtpd[395]: input attribute value: 0
Jan  7 11:59:12 82951a3ee468 postfix/smtpd[395]: private/tlsmgr: wanted attribute: seed
Jan  7 11:59:12 82951a3ee468 postfix/smtpd[395]: input attribute name: seed
Jan  7 11:59:12 82951a3ee468 postfix/smtpd[395]: input attribute value: 4QYX9lyV+wG9mUCTF9BqBiYpbJwNSGQe48MvpNxqU0A=
Jan  7 11:59:12 82951a3ee468 postfix/smtpd[395]: private/tlsmgr: wanted attribute: (list terminator)
Jan  7 11:59:12 82951a3ee468 postfix/smtpd[395]: input attribute name: (end)
Jan  7 11:59:12 82951a3ee468 postfix/smtpd[395]: maps_file_find: tls_server_sni_maps: hash:/opt/postfix/conf/sni.map(0,lock|fold_fix|src_rhs_is_file): mail.mydomain.cz = LS0tLS1CRUdJTiBQUklWQVRFIEtFWS0tLS0tCk1JSUpRZ0lCQURBTkJna3Foa2lHOXcwQkFRRUZBQVNDQ1N3d2dna29BZ0VBQW9J...
Jan  7 11:59:12 82951a3ee468 postfix/smtpd[395]: Anonymous TLS connection established from mail-db5eur02on2091.outbound.protection.outlook.com[40.107.249.91] to mail.zsmszdarky.cz: TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)
Jan  7 11:59:12 82951a3ee468 postfix/smtpd[395]: watchdog_pat: 0x55de708c3360
Jan  7 11:59:12 82951a3ee468 postfix/smtpd[395]: vstream_buf_get_ready: fd 11 got 6
Jan  7 11:59:12 82951a3ee468 postfix/smtpd[395]: < mail-db5eur02on2091.outbound.protection.outlook.com[40.107.249.91]: QUIT
Jan  7 11:59:12 82951a3ee468 postfix/smtpd[395]: > mail-db5eur02on2091.outbound.protection.outlook.com[40.107.249.91]: 221 2.0.0 Bye

opth

opth
What is weird, is that right after the TLS connection with STARTTLS is established, the micorosoft server sends QUIT and exits

opth

esackbauer
I did not setup any explicit whitelisting.
This is from the original mailcow postscreen config i believe.

[unknown] Yea.
It sucks that there is no additional error output from microsoft’s side.
Do you think that it’s worth it to try to contact micorosft support about this?

esackbauer

That is really strange. It looks indeed like Microsoft is somehow screwing up.

esackbauer

https://answers.microsoft.com/en-us/outlook_com/forum/all/mail-server-outboundprotectionoutlookcom-connect/6398c6e3-9451-4c5d-925d-dd465a1419be
https://forum.proxmox.com/threads/probleme-beim-empfang-von-outbound-protection-outlook-com.116030/
Could be that your TLSA record is not matching for that domain (see last postings).
Seems like you need to adjust the record each time after you got a new cert from Lets Encrypt.
I do not use DNSSEC/TLSA/DANE so I have no problems 😉

opth

esackbauer
You cracked it!
Thank sor the tip, it was the TLSA record.
Im am a dummy for overlooking that.

Closing the thread

IdrisK

Please find a very detail explanation how to Deal with DANE and Lets Encrypt.

https://dokuwiki.tachtler.net/doku.php?id=tachtler:let_s_encrypt_-_tlsa-record_-_dane