[SOLVED] lost connection with ... while receiving the STARTTLS response

P

proxmoxuser0815

Active Member
Mar 16, 2018
58
5
28
45
Hallo,

wir können an 2 Empfänger keine Mails zustellen (mxtoolbox.com sagt sowohl bei uns, also auch beim Empfänger, alles OK). Folgende Fehlermeldung kommt:

Remote Server returned '554 4.4.2 < #4.4.2 X-Proxmox; lost connection with mail.empfaenger.de[IP-Adresse] while receiving the STARTTLS response>'

Wie gesagt, es sind (bis jetzt) nur zwei Empfänger. Kann es vielleicht sein, dass manche Mails ablehnen, wenn man ein selbst signiertes (bzw. von Proxmox) Zertifikat benutzt?

Aus der Log:
Jul 1 10:35:23 mail1 postfix/smtp[11815]: 8CC558611FF: lost connection with mail.empfaenger.de[IP-Adresse] while receiving the STARTTLS response
Jul 1 10:35:23 mail1 postfix/smtp[11815]: 8CC558611FF: to=<testmail@empfaenger.de>, relay=mail.empfaenger.de[P-Adresse]:25, delay=2142, delays=2141/0/0.72/0, dsn=4.4.2, status=deferred (lost connection with mail.empfaenger.de[P-Adresse] while receiving the STARTTLS response)

In den TLS-Settings ist eingestellt:
Enable TLS: Yes
Enable TLS-Logging: Yes
Add TLS received header: Yes

Sonst nix. Proxmox-Version: 5.2-7 ; Upgrade auf 6.x folgt demnächst.
 
Ich würde sagen, dass das allgemeine default Verhalten ist, selbst signierte Zertifikate nicht abzulehnen und ich würde mich wundern, wenn das doch der Fall ist.

Etwas ähnliches habe ich doch bei Exchange erlebt, als er E-Mails an E-Mail Server geschickt hat, wo TLS erzwungen war (das stoßt gegen RFC 2487). Und offenbar deswegen hat es nicht geklappt, und ich denke, es hatte etwas mit den Cipher-Suites zu tun, aber ich habe nicht herausgefunden, was das Problem eigentlich war. Aber der Fehler lautet sehr ähnlich. Vielleicht kannst du das Log Level erhöhen? Oder sogar besser, wenn du direkt mit dem Admin von dem empfangenden E-Mail Server darüber reden könntest und ihm nach der Logs fragen würdest, vielleicht würdest du genau verstehen, woran das Problem liegt.
 
  • Like
Reactions: proxmoxuser0815
Es sind in der Zwischenzeit einige Empfänger hinzugekommen, die wir mit TLS nicht erreichen können (ohne TLS geht es). Habe mal so einen Fall mit tcpdump aufgezeichnet:

Code: 
tcpdump -w /tmp/dump -s 0 host ZIELIP and port 25

14:40:53.712665 IP meinserver.de.56274 > mx2a.zielserver.de.smtp: Flags [S], seq 4121175097, win 64240, options [mss 1460,sackOK,TS val 2194639165 ecr 0,nop,wscale 7], length 0
14:40:53.713371 IP mx2a.zielserver.de.smtp > meinserver.de.56274: Flags [S.], seq 1287649257, ack 4121175098, win 43690, options [mss 1460,nop,nop,sackOK,nop,wscale 7], length 0
14:40:53.713400 IP meinserver.de.56274 > mx2a.zielserver.de.smtp: Flags [.], ack 1, win 502, length 0
14:40:53.901530 IP mx2a.zielserver.de.smtp > meinserver.de.56274: Flags [P.], seq 1:44, ack 1, win 342, length 43: SMTP: 220 mx2a.zielserver.de ESMTP Service ready
14:40:53.901548 IP meinserver.de.56274 > mx2a.zielserver.de.smtp: Flags [.], ack 44, win 502, length 0
14:40:53.901634 IP meinserver.de.56274 > mx2a.zielserver.de.smtp: Flags [P.], seq 1:25, ack 44, win 502, length 24: SMTP: EHLO meinserver.de
14:40:53.902137 IP mx2a.zielserver.de.smtp > meinserver.de.56274: Flags [.], ack 25, win 342, length 0
14:40:54.058212 IP mx2a.zielserver.de.smtp > meinserver.de.56274: Flags [P.], seq 44:142, ack 25, win 342, length 98: SMTP: 250-Requested mail action okay, completed
14:40:54.058222 IP meinserver.de.56274 > mx2a.zielserver.de.smtp: Flags [.], ack 142, win 502, length 0
14:40:54.058328 IP meinserver.de.56274 > mx2a.zielserver.de.smtp: Flags [P.], seq 25:35, ack 142, win 502, length 10: SMTP: STARTTLS
14:40:54.058792 IP mx2a.zielserver.de.smtp > meinserver.de.56274: Flags [.], ack 35, win 342, length 0
14:40:54.078679 IP mx2a.zielserver.de.smtp > meinserver.de.56274: Flags [P.], seq 142:149, ack 35, win 342, length 7: SMTP
14:40:54.078690 IP meinserver.de.56274 > mx2a.zielserver.de.smtp: Flags [.], ack 149, win 502, length 0
14:40:54.078698 IP mx2a.zielserver.de.smtp > meinserver.de.56274: Flags [FP.], seq 149:200, ack 35, win 342, length 51: SMTP: 421 internal can't stack B channel SSL Filter [1]
14:40:54.078822 IP meinserver.de.56274 > mx2a.zielserver.de.smtp: Flags [F.], seq 35, ack 201, win 502, length 0
14:40:54.079373 IP mx2a.zielserver.de.smtp > meinserver.de.56274: Flags [.], ack 36, win 342, length 0


SMTP: 421 internal can't stack B channel SSL Filter

sagt mir leider nix. Oder sollte man anders loggen?
 
Hab mal das Postfix-Logging im Debug Level 4 laufen lassen. Adressen geändert. Leider werde ich daraus nicht schlau. Weiß jemand mehr?

Code: 
Jul 24 10:18:04 mail1 pmg-smtp-filter[7281]: 410255F1A993C1B374: accept mail to <test@zieladresse> (20BFD41133) (rule: default-accept)
Jul 24 10:18:04 mail1 postfix/smtp[7608]: smtp_stream_setup: maxtime=300 enable_deadline=0
Jul 24 10:18:04 mail1 pmg-smtp-filter[7281]: 410255F1A993C1B374: processing time: 0.133 seconds (0, 0.016, 0)
Jul 24 10:18:04 mail1 postfix/lmtp[7603]: 065B940FBF: to=<test@zieladresse>, relay=127.0.0.1[127.0.0.1]:10023, delay=0.25, delays=0.08/0/0/0.17, dsn=2.5.0, status=sent (250 2.5.0 OK (410255F1A993C1B374))
Jul 24 10:18:04 mail1 postfix/qmgr[7578]: 065B940FBF: removed
Jul 24 10:18:04 mail1 postfix/smtp[7608]: vstream_buf_get_ready: fd 18 got 43
Jul 24 10:18:04 mail1 postfix/smtp[7608]: < mx2a.zielserver.de[195.22.22.22]:25: 220 mx2a.zielserver.de ESMTP Service ready
Jul 24 10:18:04 mail1 postfix/smtp[7608]: > mx2a.zielserver.de[195.22.22.22]:25: EHLO mail1.meinserver.de
Jul 24 10:18:04 mail1 postfix/smtp[7608]: vstream_fflush_some: fd 18 flush 24
Jul 24 10:18:04 mail1 postfix/smtp[7608]: vstream_buf_get_ready: fd 18 got 98
Jul 24 10:18:04 mail1 postfix/smtp[7608]: < mx2a.zielserver.de[195.22.22.22]:25: 250-Requested mail action okay, completed
Jul 24 10:18:04 mail1 postfix/smtp[7608]: < mx2a.zielserver.de[195.22.22.22]:25: 250-8BITMIME
Jul 24 10:18:04 mail1 postfix/smtp[7608]: < mx2a.zielserver.de[195.22.22.22]:25: 250-SIZE 20971520
Jul 24 10:18:04 mail1 postfix/smtp[7608]: < mx2a.zielserver.de[195.22.22.22]:25: 250-STARTTLS
Jul 24 10:18:04 mail1 postfix/smtp[7608]: < mx2a.zielserver.de[195.22.22.22]:25: 250 OK
Jul 24 10:18:04 mail1 postfix/smtp[7608]: server features: 0x101b size 20971520
Jul 24 10:18:04 mail1 postfix/smtp[7608]: smtp_stream_setup: maxtime=300 enable_deadline=0
Jul 24 10:18:04 mail1 postfix/smtp[7608]: > mx2a.zielserver.de[195.22.22.22]:25: STARTTLS
Jul 24 10:18:04 mail1 postfix/smtp[7608]: vstream_fflush_some: fd 18 flush 10
Jul 24 10:18:04 mail1 postfix/smtp[7608]: vstream_buf_get_ready: fd 18 got 58
Jul 24 10:18:04 mail1 postfix/smtp[7608]: < mx2a.zielserver.de[195.22.22.22]:25: ???
Jul 24 10:18:04 mail1 postfix/smtp[7608]: smtp_get: EOF
Jul 24 10:18:04 mail1 postfix/smtp[7608]: 20BFD41133: lost connection with mx2a.zielserver.de[195.22.22.22] while receiving the STARTTLS response
Jul 24 10:18:04 mail1 postfix/smtp[7608]: name_mask: resource
Jul 24 10:18:04 mail1 postfix/smtp[7608]: name_mask: software
Jul 24 10:18:04 mail1 postfix/smtp[7608]: smtp_stream_setup: maxtime=300 enable_deadline=0
Jul 24 10:18:04 mail1 postfix/smtp[7608]: vstream_buf_get_ready: fd 18 got 43
Jul 24 10:18:04 mail1 postfix/smtp[7608]: < mx1a.zielserver.de[195.22.22.23]:25: 220 mx1a.zielserver.de ESMTP Service ready
Jul 24 10:18:04 mail1 postfix/smtp[7608]: > mx1a.zielserver.de[195.22.22.23]:25: EHLO mail1.meinserver.de
Jul 24 10:18:04 mail1 postfix/smtp[7608]: vstream_fflush_some: fd 18 flush 24
Jul 24 10:18:04 mail1 postfix/smtp[7608]: vstream_buf_get_ready: fd 18 got 98
Jul 24 10:18:04 mail1 postfix/smtp[7608]: < mx1a.zielserver.de[195.22.22.23]:25: 250-Requested mail action okay, completed
Jul 24 10:18:04 mail1 postfix/smtp[7608]: < mx1a.zielserver.de[195.22.22.23]:25: 250-8BITMIME
Jul 24 10:18:04 mail1 postfix/smtp[7608]: < mx1a.zielserver.de[195.22.22.23]:25: 250-SIZE 20971520
Jul 24 10:18:04 mail1 postfix/smtp[7608]: < mx1a.zielserver.de[195.22.22.23]:25: 250-STARTTLS
Jul 24 10:18:04 mail1 postfix/smtp[7608]: < mx1a.zielserver.de[195.22.22.23]:25: 250 OK
Jul 24 10:18:04 mail1 postfix/smtp[7608]: server features: 0x101b size 20971520
Jul 24 10:18:04 mail1 postfix/smtp[7608]: smtp_stream_setup: maxtime=300 enable_deadline=0
Jul 24 10:18:04 mail1 postfix/smtp[7608]: > mx1a.zielserver.de[195.22.22.23]:25: STARTTLS
Jul 24 10:18:04 mail1 postfix/smtp[7608]: vstream_fflush_some: fd 18 flush 10
Jul 24 10:18:04 mail1 postfix/smtp[7608]: vstream_buf_get_ready: fd 18 got 7
Jul 24 10:18:04 mail1 postfix/smtp[7608]: vstream_buf_get_ready: fd 18 got 51
Jul 24 10:18:04 mail1 postfix/smtp[7608]: < mx1a.zielserver.de[195.22.22.23]:25: ???
Jul 24 10:18:04 mail1 postfix/smtp[7608]: smtp_get: EOF
Jul 24 10:18:04 mail1 postfix/smtp[7608]: connect to subsystem private/defer
Jul 24 10:18:04 mail1 postfix/smtp[7608]: send attr nrequest = 0
Jul 24 10:18:04 mail1 postfix/smtp[7608]: send attr flags = 0
Jul 24 10:18:04 mail1 postfix/smtp[7608]: send attr queue_id = 20BFD41133
Jul 24 10:18:04 mail1 postfix/smtp[7608]: send attr original_recipient = test@zieladresse
Jul 24 10:18:04 mail1 postfix/smtp[7608]: send attr recipient = test@zieladresse
Jul 24 10:18:04 mail1 postfix/smtp[7608]: send attr offset = 739
Jul 24 10:18:04 mail1 postfix/smtp[7608]: send attr dsn_orig_rcpt = rfc822;test@zieladresse
Jul 24 10:18:04 mail1 postfix/smtp[7608]: send attr notify_flags = 0
Jul 24 10:18:04 mail1 postfix/smtp[7608]: send attr status = 4.4.2
Jul 24 10:18:04 mail1 postfix/smtp[7608]: send attr diag_type =
Jul 24 10:18:04 mail1 postfix/smtp[7608]: send attr diag_text =
Jul 24 10:18:04 mail1 postfix/smtp[7608]: send attr mta_type =
Jul 24 10:18:04 mail1 postfix/smtp[7608]: send attr mta_mname =
Jul 24 10:18:04 mail1 postfix/smtp[7608]: send attr action = delayed
Jul 24 10:18:04 mail1 postfix/smtp[7608]: send attr reason = lost connection with mx1a.zielserver.de[195.22.22.23] while receiving the STARTTLS response
Jul 24 10:18:04 mail1 postfix/smtp[7608]: vstream_fflush_some: fd 19 flush 352
Jul 24 10:18:05 mail1 postfix/smtp[7608]: vstream_buf_get_ready: fd 19 got 10
Jul 24 10:18:05 mail1 postfix/smtp[7608]: private/defer socket: wanted attribute: status
Jul 24 10:18:05 mail1 postfix/smtp[7608]: input attribute name: status
Jul 24 10:18:05 mail1 postfix/smtp[7608]: input attribute value: 0
Jul 24 10:18:05 mail1 postfix/smtp[7608]: private/defer socket: wanted attribute: (list terminator)
Jul 24 10:18:05 mail1 postfix/smtp[7608]: input attribute name: (end)
Jul 24 10:18:05 mail1 postfix/smtp[7608]: 20BFD41133: to=<test@zieladresse>, relay=mx1a.zielserver.de[195.22.22.23]:25, delay=0.86, delays=0.11/0/0.75/0, dsn=4.4.2, status=deferred (lost connection with mx1a.zielserver.de[195.22.22.23] while receiving the STARTTLS response)
Jul 24 10:18:05 mail1 postfix/smtp[7608]: flush_add: site zieladresse id 20BFD41133
Jul 24 10:18:05 mail1 postfix/smtp[7608]: match_hostname: fast_flush_domains: zieladresse ~? hash:/etc/pmg/domains(0,lock|utf8_request)
Jul 24 10:18:05 mail1 postfix/smtp[7608]: match_hostname: fast_flush_domains: lookup hash:/etc/pmg/domains.db zieladresse: notfound
Jul 24 10:18:05 mail1 postfix/smtp[7608]: match_hostname: fast_flush_domains: lookup hash:/etc/pmg/domains.db bund.de: notfound
Jul 24 10:18:05 mail1 postfix/smtp[7608]: match_hostname: fast_flush_domains: lookup hash:/etc/pmg/domains.db de: notfound
Jul 24 10:18:05 mail1 postfix/smtp[7608]: match_list_match: zieladresse: no match
Jul 24 10:18:05 mail1 postfix/smtp[7608]: flush_add: site zieladresse id 20BFD41133 status 4
Jul 24 10:18:05 mail1 postfix/smtp[7608]: name_mask: resource
Jul 24 10:18:05 mail1 postfix/smtp[7608]: name_mask: software
 
In dem fall
proxmoxuser0815 said:
Jul 24 10:18:04 mail1 postfix/smtp[7608]: > mx1a.zielserver.de[195.22.22.23]:25: STARTTLS
Jul 24 10:18:04 mail1 postfix/smtp[7608]: < mx1a.zielserver.de[195.22.22.23]:25: ???
Click to expand...
Sieht danach aus, dass die Gegenseite mit STARTTLS (und dem nachfolgenden TLS handshake) nicht zurecht kommt:
* was ist auf der Gegenseite für ein SMTP server?
* vl. mal kurz online nach Besonderheiten des SMTP servers auf der Gegenseite suchen (insbesondere punkto TLS konfiguration)

funktioniert der Empfang bei abgeschaltetem TLS?
 
  • Like
Reactions: proxmoxuser0815
Hi,

vielen Dank für deine Antwort. Ich habe mal unsere Domäne hier getestet: https://www.checktls.com/TestReceiver

Bei uns kommt

Code: 
Cert VALIDATION ERROR(S): self signed certificate
So email is encrypted but the recipient domain is not verified
Cert Hostname DOES NOT VERIFY (mail1.meinedomaine.de != *.meinedomaine.de)
(see RFC-2818 section 3.1 paragraph 4 for info on wildcard ("*") matching)
So email is encrypted but the host is not verified

Das ist aber bei einem selbst signierten Zertifikat wohl normal?

Ich habe die problematischen Empfänger-Adressen ebenfalls gecheckt. Außer, dass sie TLS 1.2 statt 1.3 nutzen, ist bei denen alles grün. Eine problematische Adresse ist mri.bund.de (eine Behörde, also nix geheimes).
 
proxmoxuser0815 said:
Das ist aber bei einem selbst signierten Zertifikat wohl normal?
Click to expand...
nehme ich auch an

Wie weit kommt ein:
Code: 
swaks --server mx1a.maxrubner.de. --tls --quit-after RCPT --to test@bund.mri.de
dafür muss swaks auf dem PMG installiert werden (`apt install swaks`)
(test@bund.mri.de gegebenenfalls durch die Empfängeradresse austauschen)
 
  • Like
Reactions: proxmoxuser0815
Unglaublich, genau dasselbe Problem hatte ich mit irgendwelchem bundes landkreis-was-auch-immer. Ich glaube, viele davon benutzen den selben/die selben Mail-Relay. Leider erinnere ich mich an weitere Einzelheiten nicht mehr, aber ihr Aufbau war echt komisch und irgendwie erst ihr dritte MX (also empfangender E-Mail Server) hatte sich darüber beschwert, dass unser E-Mail Server nichts mehr antworten würde nach dem STARTTLS. Ich habe noch nicht wirklich verstanden, wie die E-Mail an den dritten Mail-Relay gelandet war...

Ich denke es war mforward.dtag.de (ich habe gerade nachgeschlagen)
 
  • Like
Reactions: proxmoxuser0815
proxmoxuser0815 said:
Ach Mist. Lag an der Firewall. "Enable STARTTLS for Content Inspection" deaktiviert und nun funzt alles. Sorry für die Umstände...
Click to expand...
Uff - ja die issues mit middleboxen, die tls intercepten... - gut dass es so schnell gefunden wurde! Danke für das Update und Teilen der Lösung!
 
  • Like
Reactions: proxmoxuser0815
Der erste Anhaltspunkt, die Fehlermeldung aus der tcpdump-Aufzeichnung "SMTP: 421 internal can't stack B channel SSL Filter" kam jetzt auch bei swaks. Also nochmal gegoogelt und irgendwas mit Watchguard gefunden und dann sofort in die Richtung Firewall gedacht... Merke: Wenn niemand sonst das gleiche Problem hat, ist es meistens die Firewall :)

Wie immer, vielen lieben Dank für deine Hilfe und Mühe, Stoiko :)
 
  • Like
Reactions: Stoiko Ivanov
You must log in or register to reply here.

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!

Quick Navigation

Home Get Subscription Wiki Downloads Proxmox Customer Portal About

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!
Community platform by XenForo® © 2010-2024 XenForo Ltd.
Top Bottom
Back