Backup-Benachrichtigung ohne DKIM gesendet

[tab-kh]

Ich bin sicher, dass die Ursache des Problems bei KeyHelp liegt
(Probleme ohne KeyHelp-Bezug gehören ins Offtopic-Forum)
Nein

Server-Betriebssystem + Version
Debian 12.12 (64-bit)


Eingesetzte Server-Virtualisierung-Technologie
KVM


KeyHelp-Version + Build-Nummer
25.3 (Build 3565)


Problembeschreibung / Fehlermeldungen
Heute um ca 3:50 wurde die Benachrichtigung über das duchgeführte tägliche Server-Backup (erfolgreich) mit RESTIC ohne DKIM-Signatur versendet. Das war bisher noch nie so, auch gestern Nacht, also schon mit der neuen Keyhelp-Version, ging diese Mail mit DKIM-Signatur raus

Erwartetes Ergebnis
DKIM-signierte Mail

Tatsächliches Ergebnis
Keine DKIM-Signatur

Schritte zur Reproduktion
Eventuell mit Durchführung weiterer Backups. Aber bisher und auch gestern ging es ja noch. Scheint eher ein Glitch zu sein. Morgen früh nach dem nächsten Backup weiss ich eventuell mehr.

Zusätzliche Informationen
Update der Keyhelp-Version in der Nacht zum 10.12. ab ca 3:50 Uhr. Die Uhrzeit ist auffällig ähnlich zum Auftreten des Fehlers, aber der Tag passt nicht. Allerdings wird die Suche nach Updates täglich um etwa diese Zeit ausgeführt. Aber wohl eher Koinzidenz als Korrelation?

Im Journal habe ich eine Zeile, die wohl das aufgetretene Problem anzeigt, nachfolgend der Ablauf des Mailversands:

Code: Select all

Dez 12 03:50:55 mail.tabserver.de postfix/pickup[1946400]: 917775F214: uid=0 from=<root@mail.tabserver.de>
Dez 12 03:50:55 mail.tabserver.de postfix/cleanup[1957521]: warning: connect to Milter service inet:localhost:11332: Connection refused
Dez 12 03:50:55 mail.tabserver.de postfix/cleanup[1957521]: 917775F214: message-id=<QlSepZCCGrkuAAVFsvBhKfA0oUPSWmT7phs23kscAc@mail.tabserver.de>
Dez 12 03:50:55 mail.tabserver.de postfix/qmgr[819287]: 917775F214: from=<root@mail.tabserver.de>, size=17065, nrcpt=1 (queue active)
Dez 12 03:51:02 mail.tabserver.de postfix/smtp[1957530]: 917775F214: to=<[meine Empfängeradresse]>, relay=mail.meinedomain.de[xx.xxx.4xx.xx]:25, delay=6.9, delays=0.07/0.02/6.1/0.8, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as B6E302205D1)
Dez 12 03:51:02 mail.tabserver.de postfix/qmgr[819287]: 917775F214: removed

Sehr wahrscheinlich ist die nicht erfolgreiche Verbindung zum Milter service die Ursache des Problems. Die Mail ging danach aber trotzdem raus und kam auch an. Diese Mails werden dann automatisch an ein anderes Mailkonto bei GMX weitergeleitet. Auch dort kam die Mail - wohl dank Whitelist - an, wurde aber wegen fehlendem DKIM in den Spamordner gesteckt. So bin ich auch überhaupt darauf aufmerksam geworden.

In der rspamd Weboberfläche auf mail.tabserver.de taucht die Mail in der Historie nicht auf, an anderen Tagen allerdings schon. Also dürfte der Milter service wohl ein Teil von rspamd sein, der die Mail signiert und heute Nacht eben nicht ausgeführt wurde, weil die Verbindung abgelehnt wurde - aus welchen Gründen auch immer.

Ich schaue dann morgen, ob es wieder so passiert ist. Der Bericht von logwatch kam einige Stunden später bei gleichem Absender und Empfänger mit korrekter DKIM-Signatur an. Diese Mail ist auch in der Historie von rspamd aufgeführt.

[Florian]

Hallo,

ja rspamd ist für die DKIM Signatur verantwortlich. Wenn die Verbindung zum Milter nicht geklappt hat wurden daher die Mails auch nicht signiert

[tab-kh]

Soweit so gut. Ich frage mich mittlerweile eher, warum diese Verbindung nicht zustande kam. Den Server habe ich seit ca einem Jahr und in der ganzen Zeit ist das nie vorgekommen. Gibt es irgendwelche dafür irgendwelche bekannten oder vermuteten Ursachen? Könnte es theoretisch mit der fast zeitgleichen Abfrage auf Keyhelp-Updates zusammenhängen, obwohl es heute Nacht kein Update zu installieren gab? Ist das außer mir auch schon anderen passiert? Es ist ein ARM basierter Server, falls das irgendeine Rolle spielen könnte.

Ich warte mal ab, ob es ein einmaliger Zwischenfall war oder ob das jetzt regelmäßig auftritt.

[Florian]

Hallo,

dann solltest du mal ins Log schauen (syslog, rspamd Log) ob da ggf eine Ursache steht warum der Dienst da offenbar nicht lief oder erreichbar war.

[Alexander]

Wäre es zum Zeitpunkt des Updates passiert, dann könnte es daran liegen, dass im Zuge des Updates von 25.2 auf 25.3 Rspamd neu gestartet wurde. Ggf. hätte es so zu Überschneidungen während des Mailversands führen können.

Eine weitere Möglichkeit wäre, dass sich in der Rspamd-Konfiguration eine manuelle Änderung befand, die bislang nicht aktiv war, weil noch kein Neustart bzw. Neuladen der Konfiguration durchgeführt wurde.
Durch das Update und den damit verbundenen Rspamd-Neustart wurde diese manuelle Anpassung aktiviert und führt nun möglicherweise zu einem anderen Verhalten als zuvor.

[tab-kh]

Danke. Ja, ins rspamd-Log habe ich noch nicht geschaut, da schau ich mal rein. Vielleicht findet sich ja da die Erklärung. "Connection refused" klingt eigentlich eher so, als ob der Service lief, aber keine Verbindung zugelassen hat in dem Moment. Die Meldung findet sich im Internet öfter mal, aber eher so, dass das dann bei jeder Mail passiert und nicht nur sporadisch.

Wie auch immer. Habe gerade mal in das rspamd.log reingeschaut. Irgendwas ist da wohl faul im Moment mit DNS oder diversen Blocklisten,auf die rspamd zugreift, auf mehreren Servern ähnlich. Sowohl mit lokalem Unbound als auch mit den Nameservern von Ionos.

Hier ein Auszug aus dem Log des fraglichen Servers mit lokalem Unbound

Code: Select all

2025-12-12 21:49:49 #1957551(controller) <s4ti79>; monitored; rspamd_monitored_dns_cb: DNS reply returned 'no error' for score.senderscore.com while 'no records with this name' was expected when querying for '1.0.0.127.score.senderscore.com'(likely DNS spoofing or BL internal issues)
2025-12-12 21:50:14 #1957551(controller) <5a4rsg>; monitored; rspamd_monitored_propagate_error: servfail on resolving bl.blocklist.de, disable object
2025-12-12 21:50:14 #1957551(controller) <7c7kyd>; cfg; rspamd_worker_monitored_on_change: broadcast monitored update for 5a4rsg9izzi9xgkw1x4umr6yjsyaoao: dead
2025-12-12 21:50:14 #1957552(normal) <7c7kyd>; cfg; rspamd_worker_monitored_handler: updated monitored status for 5a4rsg9izzi9xgkw1x4umr6yjsyaoao: dead
2025-12-12 21:50:14 #1957553(normal) <7c7kyd>; cfg; rspamd_worker_monitored_handler: updated monitored status for 5a4rsg9izzi9xgkw1x4umr6yjsyaoao: dead
2025-12-12 21:50:14 #1957555(normal) <7c7kyd>; cfg; rspamd_worker_monitored_handler: updated monitored status for 5a4rsg9izzi9xgkw1x4umr6yjsyaoao: dead
2025-12-12 21:50:14 #1957554(normal) <7c7kyd>; cfg; rspamd_worker_monitored_handler: updated monitored status for 5a4rsg9izzi9xgkw1x4umr6yjsyaoao: dead
2025-12-12 22:00:30 #1957551(controller) <5a4rsg>; monitored; rspamd_monitored_propagate_success: restoring bl.blocklist.de after 615.9 seconds of downtime, total downtime: 44120.0
2025-12-12 22:00:30 #1957551(controller) <7c7kyd>; cfg; rspamd_worker_monitored_on_change: broadcast monitored update for 5a4rsg9izzi9xgkw1x4umr6yjsyaoao: alive
2025-12-12 22:00:30 #1957552(normal) <7c7kyd>; cfg; rspamd_worker_monitored_handler: updated monitored status for 5a4rsg9izzi9xgkw1x4umr6yjsyaoao: alive
2025-12-12 22:00:30 #1957553(normal) <7c7kyd>; cfg; rspamd_worker_monitored_handler: updated monitored status for 5a4rsg9izzi9xgkw1x4umr6yjsyaoao: alive
2025-12-12 22:00:30 #1957555(normal) <7c7kyd>; cfg; rspamd_worker_monitored_handler: updated monitored status for 5a4rsg9izzi9xgkw1x4umr6yjsyaoao: alive
2025-12-12 22:00:30 #1957554(normal) <7c7kyd>; cfg; rspamd_worker_monitored_handler: updated monitored status for 5a4rsg9izzi9xgkw1x4umr6yjsyaoao: alive

Ich leere da jetzt mal die ganzen Caches von Unbound, auch wenn ich nicht glaube, dass der Fehler im Resolver liegt. Ähnliches bekomme ich auch mit den Resolvern von Ionos. Da werden aber auch noch zusätzlich viele Abfragen geblockt, wahrscheinlich zuviele Abfragen von den Resolvern bei den Listen. Naja, Mail will ich da eh nur für Benachrichtigungen und logwatch nutzen, ansonsten nur Webserver. Ich überlege sogar, den per Default gesperrten Port 25 gar nicht aufmachen zu lassen ausgehend. Hängt nur noch an Logwatch, die Benachrichtigungen verschicke ich da schon über den Mailserver. Aber vielleicht spendiere ich dem neuen Ionos Server dann auch noch ein Unbound wenn sich rspamd dann besser fühlt.