[Solved] Opnsense MailGW, Postfix und Rspamd

[nukularso]

Hallo zusammen,

vielleicht kann mir jemand helfen. Ich nutze eine OPNSense VM als MailGW und Reverseproxy für Exchange. Funktioniert soweit bestens inkl. Zertifikatabholung über Let´s Encrypt. Leider bekomme ich sporadisch immer folgende Meldung im Log:

09:34:25.416  10.1.230.3  mail.warn      Jan  9 09:34:25 GATE.domain.de postfix/cleanup[18785]: warning: milter inet:localhost:11332: can't read SMFIC_BODYEOB reply packet header: Operation timed out

System:
OPNsense 19.7.8-amd64
FreeBSD 11.2-RELEASE-p16-HBSD
OpenSSL 1.0.2t 10 Sep 2019




Plugins auch alle in aktueller Version.

Mein Ergooglen zu dem Thema war leider nicht sehr erfolgreich. Habe schon ein paar Lösungsansätze wie z.B. Probleme durch Bayes in rspamd getestet. Keine Änderung.

Grüße


EDIT: oh, neu ist jetzt 10:40:49.929  10.1.230.3  mail.warn      Jan  9 10:40:49 GATE.domain.de postfix/cleanup[76939]: warning: milter inet:localhost:11332: error writing command: Broken pipe

[mimugmail]

In Postfix im Reiter Antispam, da mal die Protokollversion bitte ändern.

[nukularso]

 
Wenn ich dort von IPv6 auf 4 umstelle bekomme ich direkt in 10 sekündlichen Abständen die beiden Meldungen nach Postfixneustart:

17:20:20.863  10.1.230.3  mail.warn      Jan  9 17:20:20 GATE.domain.de postfix/smtpd[49276]: warning: milter inet:localhost:11332: can't read SMFIC_OPTNEG reply packet header: No error: 0
17:20:20.863  10.1.230.3  mail.warn      Jan  9 17:20:20 GATE.domain.de postfix/smtpd[49276]: warning: milter inet:localhost:11332: read error in initial handshake

[nukularso]

Muss das Topic noch mal hoch holen.

Noch mal zu dem Vorschlag der IP Protokollumstellung. Mit IPv6 läuft das bis auf den sporadischen fehler ganz gut. IPv4 besser? Bekomme da aber scheinbar den Fehler nicht weg. Eine Idee?

Mir fiel jetzt aber auf, dass mein Problem vermutlich mit bestimmten Spamversendern zusammenhängt. Ich poste mal das Log, vielleicht hat jemand eine Idee:

Code Select Expand

07:34:29.704  10.1.230.3  mail.info      Jan 29 07:34:29 GATE.domain.de postfix/smtpd[21498]: [b]connect from 88-118-131-30.static.zebra.lt[88.118.131.30][/b]
[b]07:34:30.688  10.1.230.3  mail.info      Jan 29 07:34:30 GATE.domain.de postfix/smtpd[21498]: A23D7D2A2F3: client=88-118-131-30.static.zebra.lt[88.118.131.30]
07:34:33.579  10.1.230.3  mail.info      Jan 29 07:34:33 GATE.domain.de postfix/cleanup[14559]: A23D7D2A2F3: message-id=<DC78ABEC.4B9EB467@zebra.lt>[/b]
07:35:21.678  10.1.230.3  mail.info      Jan 29 07:35:21 GATE.domain.de postfix/cleanup[67548]: B7556D2A2F9: milter-reject: END-OF-MESSAGE from static-71-122-164-51.tampfl.fios.frontiernet.net[71.122.164.51]: 5.7.1 Spam message rejected; from=<AgataAbhoernchen@frontiernet.net> to=<@domain.de> proto=ESMTP helo=<static-71-122-164-51.tampfl.fios.frontiernet.net>
07:35:21.678  10.1.230.3  mail.info      Jan 29 07:35:21 GATE.domain.de postfix/smtpd[40846]: disconnect from static-71-122-164-51.tampfl.fios.frontiernet.net[71.122.164.51] ehlo=1 mail=1 rcpt=12 data=0/1 commands=14/15
07:36:05.891  10.1.230.3  mail.info      Jan 29 07:36:05 GATE.domain.de postfix/smtpd[56758]: connect from ps.nis.nnov.su[212.67.0.150]
07:36:08.048  10.1.230.3  mail.info      Jan 29 07:36:08 GATE.domain.de postfix/smtpd[56758]: NOQUEUE: reject: RCPT from ps.nis.nnov.su[212.67.0.150]: 450 4.1.8 <PeterHarris@nnov.su>: Sender address rejected: Domain not found; from=<PeterHarris@nnov.su> to=<@domain.de> proto=ESMTP helo=<ps.nis.nnov.su>
07:36:08.720  10.1.230.3  mail.info      Jan 29 07:36:08 GATE.domain.de postfix/smtpd[56758]: AB3F3D2A293: client=ps.nis.nnov.su[212.67.0.150]
07:36:10.923  10.1.230.3  mail.info      Jan 29 07:36:10 GATE.domain.de postfix/cleanup[67548]: AB3F3D2A293: message-id=<900BA714.940D006E@nnov.su>
07:36:11.376  10.1.230.3  mail.info      Jan 29 07:36:11 GATE.domain.de postfix/cleanup[67548]: AB3F3D2A293: milter-reject: END-OF-MESSAGE from ps.nis.nnov.su[212.67.0.150]: 5.7.1 Spam message rejected; from=<PeterHarris@nnov.su> to=<@domain.de> proto=ESMTP helo=<ps.nis.nnov.su>
07:36:12.016  10.1.230.3  mail.info      Jan 29 07:36:11 GATE.domain.de postfix/smtpd[56758]: disconnect from ps.nis.nnov.su[212.67.0.150] ehlo=1 mail=1 rcpt=2/3 data=0/1 commands=4/6
07:37:32.889  10.1.230.3  mail.info      Jan 29 07:37:32 GATE.domain.de postfix/smtpd[56758]: connect from unknown[85.172.107.1]
07:37:33.764  10.1.230.3  mail.info      Jan 29 07:37:33 GATE.domain.de postfix/smtpd[56758]: B6E0ED2A24A: client=unknown[85.172.107.1]
07:37:34.858  10.1.230.3  mail.info      Jan 29 07:37:34 GATE.domain.de postfix/cleanup[67548]: B6E0ED2A24A: message-id=<954F1890.38718C00@looneytours.it>
07:37:35.342  10.1.230.3  mail.info      Jan 29 07:37:35 GATE.domain.de postfix/cleanup[67548]: B6E0ED2A24A: milter-reject: END-OF-MESSAGE from unknown[85.172.107.1]: 5.7.1 Spam message rejected; from=<NicholasMiller@looneytours.it> to=<@domain.de> proto=ESMTP helo=<looneytours.it>
07:37:35.787  10.1.230.3  mail.info      Jan 29 07:37:35 GATE.domain.de postfix/smtpd[56758]: disconnect from unknown[85.172.107.1] ehlo=1 mail=1 rcpt=2 data=0/1 commands=4/5
07:38:08.676  10.1.230.3  mail.info      Jan 29 07:38:08 GATE.domain.de postfix/smtpd[56758]: connect from unknown[88.203.202.102]
07:38:11.098  10.1.230.3  mail.info      Jan 29 07:38:11 GATE.domain.de postfix/smtpd[56758]: 13B4DD2A293: client=unknown[88.203.202.102]
07:38:12.348  10.1.230.3  mail.info      Jan 29 07:38:12 GATE.domain.de postfix/cleanup[67548]: 13B4DD2A293: message-id=<3DF66FA2.670CD687@lorgat.it>
07:38:14.524  10.1.230.3  mail.info      Jan 29 07:38:14 GATE.domain.de postfix/smtpd[65448]: connect from unknown[89.46.235.200]
07:38:15.091  10.1.230.3  mail.info      Jan 29 07:38:15 GATE.domain.de postfix/smtpd[65448]: 10E8ED2A2D1: client=unknown[89.46.235.200]
07:38:16.239  10.1.230.3  mail.info      Jan 29 07:38:16 GATE.domain.de postfix/cleanup[21218]: 10E8ED2A2D1: message-id=<0050EB2F.9B8C8ED4@lparchitects.it>
07:38:18.192  10.1.230.3  mail.info      Jan 29 07:38:18 GATE.domain.de postfix/cleanup[21218]: 10E8ED2A2D1: milter-reject: END-OF-MESSAGE from unknown[89.46.235.200]: 5.7.1 Spam message rejected; from=<BillyCollins@lparchitects.it> to=<@domain.de> proto=ESMTP helo=<lparchitects.it>
07:38:18.317  10.1.230.3  mail.info      Jan 29 07:38:18 GATE.domain.de postfix/smtpd[65448]: disconnect from unknown[89.46.235.200] ehlo=1 mail=1 rcpt=2 data=0/1 commands=4/5
07:39:29.744  10.1.230.3  mail.info      Jan 29 07:39:29 GATE.domain.de postfix/cleanup[67548]: 13B4DD2A293: milter-reject: END-OF-MESSAGE from unknown[88.203.202.102]: 5.7.1 Spam message rejected; from=<CharlesHarris@lorgat.it> to=<@domain.de> proto=ESMTP helo=<lorgat.it>
07:39:29.744  10.1.230.3  mail.info      Jan 29 07:39:29 GATE.domain.de postfix/smtpd[56758]: disconnect from unknown[88.203.202.102] ehlo=1 mail=1 rcpt=1 data=0/1 commands=3/4
[i][b]07:39:33.594  10.1.230.3  mail.warn      Jan 29 07:39:33 GATE.domain.de postfix/cleanup[14559]: warning: milter inet:localhost:11332: can't read SMFIC_BODYEOB reply packet header: Operation timed out[/b][/i]
[b]07:39:33.601  10.1.230.3  mail.info      Jan 29 07:39:33 GATE.domain.de postfix/qmgr[6675]: A23D7D2A2F3: from=<SusanneAckerknecht@zebra.lt>, size=3447, nrcpt=12 (queue active)
07:39:33.601  10.1.230.3  mail.info      Jan 29 07:39:33 GATE.domain.de postfix/smtpd[21498]: disconnect from 88-118-131-30.static.zebra.lt[88.118.131.30] ehlo=1 mail=1 rcpt=12 data=1 commands=15
07:39:33.804  10.1.230.3  mail.info      Jan 29 07:39:33 GATE.domain.de postfix/smtp[12279]: A23D7D2A2F3: to=<a@domain.de>, relay=10.1.230.4[10.1.230.4]:25, delay=304, delays=303/0.02/0/0.19, dsn=2.6.0, status=sent (250 2.6.0 <DC78ABEC.4B9EB467@zebra.lt> [InternalId=8018703941646, Hostname=EXCHANGE.domain.de] 4725 bytes in 0.104, 44,228 KB/sec Queued mail for delivery)
07:39:33.804  10.1.230.3  mail.info      Jan 29 07:39:33 GATE.domain.de postfix/smtp[12279]: A23D7D2A2F3: to=<b@domain.de>, relay=10.1.230.4[10.1.230.4]:25, delay=304, delays=303/0.02/0/0.19, dsn=2.6.0, status=sent (250 2.6.0 <DC78ABEC.4B9EB467@zebra.lt> [InternalId=8018703941646, Hostname=EXCHANGE.domain.de] 4725 bytes in 0.104, 44,228 KB/sec Queued mail for delivery)
07:39:33.804  10.1.230.3  mail.info      Jan 29 07:39:33 GATE.domain.de postfix/smtp[12279]: A23D7D2A2F3: to=<c@domain.de>, relay=10.1.230.4[10.1.230.4]:25, delay=304, delays=303/0.02/0/0.19, dsn=2.6.0, status=sent (250 2.6.0 <DC78ABEC.4B9EB467@zebra.lt> [InternalId=8018703941646, Hostname=EXCHANGE.domain.de] 4725 bytes in 0.104, 44,228 KB/sec Queued mail for delivery)
07:39:33.804  10.1.230.3  mail.info      Jan 29 07:39:33 GATE.domain.de postfix/smtp[12279]: A23D7D2A2F3: to=<d@domain.de>, relay=10.1.230.4[10.1.230.4]:25, delay=304, delays=303/0.02/0/0.19, dsn=2.6.0, status=sent (250 2.6.0 <DC78ABEC.4B9EB467@zebra.lt> [InternalId=8018703941646, Hostname=EXCHANGE.domain.de] 4725 bytes in 0.104, 44,228 KB/sec Queued mail for delivery)
07:39:33.804  10.1.230.3  mail.info      Jan 29 07:39:33 GATE.domain.de postfix/smtp[12279]: A23D7D2A2F3: to=<e@domain.de>, relay=10.1.230.4[10.1.230.4]:25, delay=304, delays=303/0.02/0/0.19, dsn=2.6.0, status=sent (250 2.6.0 <DC78ABEC.4B9EB467@zebra.lt> [InternalId=8018703941646, Hostname=EXCHANGE.domain.de] 4725 bytes in 0.104, 44,228 KB/sec Queued mail for delivery)
07:39:33.804  10.1.230.3  mail.info      Jan 29 07:39:33 GATE.domain.de postfix/smtp[12279]: A23D7D2A2F3: to=<f@domain.de>, relay=10.1.230.4[10.1.230.4]:25, delay=304, delays=303/0.02/0/0.19, dsn=2.6.0, status=sent (250 2.6.0 <DC78ABEC.4B9EB467@zebra.lt> [InternalId=8018703941646, Hostname=EXCHANGE.domain.de] 4725 bytes in 0.104, 44,228 KB/sec Queued mail for delivery)
07:39:33.804  10.1.230.3  mail.info      Jan 29 07:39:33 GATE.domain.de postfix/smtp[12279]: A23D7D2A2F3: to=<h@domain.de>, relay=10.1.230.4[10.1.230.4]:25, delay=304, delays=303/0.02/0/0.19, dsn=2.6.0, status=sent (250 2.6.0 <DC78ABEC.4B9EB467@zebra.lt> [InternalId=8018703941646, Hostname=EXCHANGE.domain.de] 4725 bytes in 0.104, 44,228 KB/sec Queued mail for delivery)
07:39:33.804  10.1.230.3  mail.info      Jan 29 07:39:33 GATE.domain.de postfix/smtp[12279]: A23D7D2A2F3: to=<i@domain.de>, relay=10.1.230.4[10.1.230.4]:25, delay=304, delays=303/0.02/0/0.19, dsn=2.6.0, status=sent (250 2.6.0 <DC78ABEC.4B9EB467@zebra.lt> [InternalId=8018703941646, Hostname=EXCHANGE.domain.de] 4725 bytes in 0.104, 44,228 KB/sec Queued mail for delivery)
07:39:33.804  10.1.230.3  mail.info      Jan 29 07:39:33 GATE.domain.de postfix/smtp[12279]: A23D7D2A2F3: to=<j@domain.de>, relay=10.1.230.4[10.1.230.4]:25, delay=304, delays=303/0.02/0/0.19, dsn=2.6.0, status=sent (250 2.6.0 <DC78ABEC.4B9EB467@zebra.lt> [InternalId=8018703941646, Hostname=EXCHANGE.domain.de] 4725 bytes in 0.104, 44,228 KB/sec Queued mail for delivery)
07:39:33.804  10.1.230.3  mail.info      Jan 29 07:39:33 GATE.domain.de postfix/qmgr[6675]: A23D7D2A2F3: removed[/b]

Die Mails kommen immer nach dem Fehler durch. Auffällig ist, dass es sich dabei meist um Mails an mehrere Empfänger bei uns handelt. Leider immer von anderen IPs. Das Problem häuft sich jedoch.

[mimugmail]

Das muss irgendwas mit dem lokalen Resolver zu tun haben dass er localhost mal mit 127.0.0.1 und mal mit ::1 auflöst. Wie ist da dein Setup?

[fabian]

Was ganz interessant ist, ist die Tatsache dass du bei den Mails die durchgehen keine Milter-Results hast. Rspamd ist über dieses Protokoll am Postfix angebunden .

[nukularso]

Was ganz interessant ist, ist die Tatsache dass du bei den Mails die durchgehen keine Milter-Results hast. Rspamd ist über dieses Protokoll am Postfix angebunden .

Genau. Spammails ohne Result mit dem Log verglichen und auf meinen Fehler aus dem ersten Post gestoßen. Exchange ordnet bei den Mails auch interessanterweise Newsletter zu und bietet "Abo beenden" an.

Habe ich irgendwo die Möglichkeit, die Empfängeranzahl zu begrenzen? In Postfix oder testweise im Rspamd z.B. im Rate Limit?

[/quote]

Das muss irgendwas mit dem lokalen Resolver zu tun haben dass er localhost mal mit 127.0.0.1 und mal mit ::1 auflöst. Wie ist da dein Setup?

WAN und LAN feste IPs, IPv6 deaktiviert. Zwei Gateways eingerichtet, WAN GW als Upstream, beide auch nur IPv4. DNS:



Postfix auch IPv4 bis auf Milter. Stelle ich dort um auf Ipv4 bekomme ich wie im anderen Beitrag beschrieben  Fehler.

[mimugmail]

Machst du mit Unbound irgenwelche Rewrites oder DNSBL?

[nukularso]

Weder noch, nein.

[mimugmail]

Dann von deinem Screenshot den ersten Hake bei DNS raus und beim zweiten rein :)

[nukularso]

Dann von deinem Screenshot den ersten Hake bei DNS raus und beim zweiten rein :)

Oh man  :)   Das sieht sehr gut aus. Direkt nach der Umstellung gestern noch ein paar Fehler, nach Neustart gestern abend bis jetzt keine mehr.  Vielen Dank!

[uzilurcs]

Moin zusammen,

ich stehe vor dem gleichen Problem und habe das exakt gleiche Fehlerbild.
Einziger Unterschied ist die Opnsense Version. Ich bin auf OPNsense 20.1.1

Welcher Haken muss wo raus und welcher wo rein? Hier sehe im Thread leider keinen passenden Screenshot.

Vielen Dank

[mimugmail]

System : Settings : General

Haken rein dass der lokale DNS Server NICHT genutzt wird, Haken raus dass Provider DNS überschreiben darf, manuell DNS setzen