[SOLVED] Quarantäne Benachrichtigungen doppelt

[sudoer]

Hallo,
unsere user bekommen immer 2 identische Benachrichtigungen (Mails) für ihre Quarantäne.
Ich kann die Mails weder im postfix log noch im Tracking Center finden. Wir betreiben einen 2 Node Cluster (proxmox-mailgateway: 6.0-1 (API: 6.0-6/b0c1ded4, running kernel: 5.0.21-2-pve). Wie kann ich dem Problem auf den Grund gehen?
Danke.

 

[tom]

Im Tracking Center bitte "Include NDR" auswählen, dann werden auch die Daily Reports angezeigt, ev. zeigen die Logs mehr Details.

 

[sudoer]

Es dürfte sich um diese Mails handeln, beide an denselben Empfänger (Beispiel). Leider bringen mich die Log einträge nicht weiter:

 

[tom]

Quarantäne email werden immer um 0:05 versendet, also diese logs sinds wohl nicht.

 

[sudoer]

Scheint aber hier nicht so zu sein:

 

[sudoer]

Hier z. B. 3 Empfänger einer Domain mit doppelten Emails:





PS: die Zeit ist übrigens am Gateway korrekt eingestellt.

 

[Stoiko Ivanov]

der spamreport wird normalerweise durch das 'pmgspamreport.service' verschickt, welches vom 'pmgspamreport.timer' gesteuert wird:

root@pmg6:/# systemctl cat pmgspamreport.service
# /lib/systemd/system/pmgspamreport.service
[Unit]
Description=Send Daily Spam Report Mails
ConditionPathExists=/usr/bin/pmgqm

[Service]
Type=oneshot
ExecStart=/usr/bin/pmgqm send --timespan yesterday
ExecStartPost=/usr/bin/pmgqm purge

root@pmg6:/# systemctl cat pmgspamreport.timer
# /lib/systemd/system/pmgspamreport.timer
[Unit]
Description=Send Daily Spam Report Mails

[Timer]
OnCalendar=00:05
Persistent=true  

[Install]
WantedBy=timers.target

Eine Möglichkeit wäre, dass ein weiterer timer oder cronjob ebenfalls `pmgqm` aufruft - da ist es hilfreich sich das gesamte journal auf der commandline anzusehen zu dem Zeitpunkt an dem die mails verschickt werden:
`journalctl --since "2019-09-12 22:30"`

Ich hoffe das hilft!

 

[sudoer]

Konfiguration von Service und timer ist hier exact gleich. Nur die Ausführung erfolgt zu anderen Zeitpunkten:

Oct 15 00:47:35 mx11 systemd[1]: Starting Send Daily Spam Report Mails...
Oct 14 22:48:54 mx11 pmgqm[30210]: purging database
Oct 14 22:48:55 mx11 pmgqm[30210]: removed 118 spam quarantine files
Oct 14 22:48:56 mx11 systemd[1]: pmgspamreport.service: Succeeded.
Oct 14 22:48:56 mx11 systemd[1]: Started Send Daily Spam Report Mails.
Oct 15 00:49:25 mx11 systemd[1]: Starting Send Daily Spam Report Mails...
Oct 14 22:50:43 mx11 pmgqm[30384]: purging database
Oct 14 22:50:43 mx11 systemd[1]: pmgspamreport.service: Succeeded.
Oct 14 22:50:43 mx11 systemd[1]: Started Send Daily Spam Report Mails.

root@mx11:~# systemctl cat pmgspamreport.timer
# /lib/systemd/system/pmgspamreport.timer
[Unit]
Description=Send Daily Spam Report Mails

[Timer]
OnCalendar=00:05
Persistent=true

[Install]
WantedBy=timers.target

Bin etwas ratlos wie systemd zu diesen Ausführungszeiten kommt. Um :05 wird gar nicht gestartet. Zeiteinstellungen sind ok:

root@mx11:~# timedatectl status
               Local time: Tue 2019-10-15 09:12:00 CEST
           Universal time: Tue 2019-10-15 07:12:00 UTC
                 RTC time: Tue 2019-10-15 07:12:00
                Time zone: Europe/Vienna (CEST, +0200)
System clock synchronized: yes
              NTP service: active
          RTC in local TZ: no

 

[Stoiko Ivanov]

Wie sind die logs zustandegekommen (die durchmischten Zeiten von 15.10. 00:47 und 14.10. 22:4x sind etwas seltsam)?

 

[sudoer]

sorry, command übersehen beim pasten:

root@mx11:/etc# journalctl -u pmgspamreport.service
-- Logs begin at Mon 2019-10-14 11:13:36 CEST, end at Tue 2019-10-15 10:33:14 CEST. --
Oct 15 00:47:35 mx11 systemd[1]: Starting Send Daily Spam Report Mails...
Oct 14 22:48:54 mx11 pmgqm[30210]: purging database
Oct 14 22:48:55 mx11 pmgqm[30210]: removed 118 spam quarantine files
Oct 14 22:48:56 mx11 systemd[1]: pmgspamreport.service: Succeeded.
Oct 14 22:48:56 mx11 systemd[1]: Started Send Daily Spam Report Mails.
Oct 15 00:49:25 mx11 systemd[1]: Starting Send Daily Spam Report Mails...
Oct 14 22:50:43 mx11 pmgqm[30384]: purging database
Oct 14 22:50:43 mx11 systemd[1]: pmgspamreport.service: Succeeded.
Oct 14 22:50:43 mx11 systemd[1]: Started Send Daily Spam Report Mails.

 

[Stoiko Ivanov]

Hmm - es wirkt so als würde etwas die Zeit in dem System um 2 Stunden nach vorne und nach hinten bewegen...
(die einzigen 2 Einträge, welche am 15.10 00:4x sind, sind jene wo der timer feststellt, dass der job um 00:05 nicht gelaufen ist und diesen startet, danach ist die zeit wieder auf 22:4x, der job läuft fertig - zeit springt wieder nach vorne, job wird erneut gestartet).

Ich würde mal die Einstellungen am hypervisor (wenn PMG virtualisiert läuft) überprüfen und das gesamte journal ansehen, ob sich etwas mit der Systemzeit tut.

Ich hoffe das hilft!

 

[sudoer]

Danke für den Hinweis. Es lag tatsächlich ein Problem mit der Zeiteinstellung am Hypervisor vor. Ausserdem habe ich NTP am ProxMox Gateway eingerichtet, das zusammen hat das Problem gelöst.