[SOLVED] Performance Probleme

luke5sky · May 26, 2019

Hallo,

ich habe seit letzten Freitag (24.05.2019) Probleme mit hoher CPU Last bei 2 Proxmox PMMG Maschinen (OHNE Cluster und an 2 verschiedenen Standorten). Beide Maschinen sind auf VMware virtualisiert (aber eben auch 2 verschiedene Hosts) und beide sind auf Version 5.2-2.
Gateways sind seit Juli 2018 und September 2018 im Einsatz (bis jetzt keine Probleme gehabt).

Beide Gateways haben ungefähr zur selben Zeit angefangen diese Lastspitzen zu zeigen (ca 10 Minuten Abstand).
Neustart der Gateways hat leider auch nichts gebracht.

Diese Lastspitzen fangen ca 1 mal pro Stunde an und dauern ca. 20-30 Minuten.
Das Mail-Volumen bleibt gleich, RAM bleibt gleich und Netzwerk-Spitzen sehe ich auch keine, eben nur CPU (maximum war eine load von 31, Standard ist eine load von 5-8 )

top zeigt mir, dass es das Service pmg-smtp-filter ist, weiß aber leider nicht, wo ich noch nachsehen könnte was das Problem genau ist.

Die Maschinen wurden mit dem offiziellen Debian ISO von proxmox.com aufgesetzt (hier möchte ich noch anmerken, dass ich nur bei der Mail processing time und eben an der CPU sehe, dass es der Maschine nicht gut geht. Sowohl das Web-Interface als auch das Terminal sind performant als wäre alles OK, was wirklich spitze ist

).

Mail processing time erhöht sich damit leider von 1,30 sec. auf 56 sec. was schon etwas im Herzen weh tut

.

Im Anhang noch diverse Screenshots, hoffentlich kann mir hier jemand helfen.

Vielen Dank
Lukas

luke5sky · May 26, 2019

Hier noch ein pmgversion -v:
proxmox-mailgateway: 5.2-1 (API: 5.2-2/9f7b563c, running kernel: 4.15.18-14-pve)
pmg-api: 5.2-2
pmg-gui: 1.0-45
pve-kernel-4.15: 5.4-2
pve-kernel-4.13: 5.1-45
pve-kernel-4.15.18-14-pve: 4.15.18-39
pve-kernel-4.15.18-13-pve: 4.15.18-37
pve-kernel-4.15.18-12-pve: 4.15.18-36
pve-kernel-4.15.18-11-pve: 4.15.18-33
pve-kernel-4.15.18-10-pve: 4.15.18-31
pve-kernel-4.15.18-7-pve: 4.15.18-27
pve-kernel-4.13.16-3-pve: 4.13.16-49
pve-kernel-4.13.13-5-pve: 4.13.13-38
libarchive-perl: 3.2.1-1
libpve-apiclient-perl: 2.0-5
libpve-common-perl: 5.0-51
libpve-http-server-perl: 2.0-12
libxdgmime-perl: 0.01-3
lvm2: 2.02.168-2
pmg-docs: 5.2-1
proxmox-spamassassin: 3.4.2-2
proxmox-widget-toolkit: 1.0-26
pve-firmware: 2.0-5
pve-xtermjs: 3.10.1-2
zfsutils-linux: 0.7.13-pve1~bpo1

Screenshot von E-Mail Volume (12 Stunden) angehängt

Stoiko Ivanov · May 27, 2019

Steht in den logs vl. etwas auffälliges? (`journalctl --since 2019-05-24` für die logs seit letztem Freitag)?

luke5sky · May 27, 2019

Vielen Dank für die Antwort, er zeigt mir hier leider nur logs von heute an, da es aber regelmäßig auftritt, habe ich die ersten 5 Minuten rausgenommen wo das Problem bestanden hat ich habe jetzt nur nach pmg-smtp-filter gesucht, da alle anderen Einträge normal ausgesehen haben:

Code:

May 27 10:39:57 mail pmg-smtp-filter[20074]: fast exit to reduce server load (free 5955584 bytes)
May 27 10:40:05 mail pmg-smtp-filter[10183]: starting database maintainance
May 27 10:40:05 mail pmg-smtp-filter[10183]: end database maintainance (22 ms)
May 27 10:40:54 mail pmg-smtp-filter[10183]: Starting "1" children
May 27 10:40:54 mail pmg-smtp-filter[20223]: 2019/05/27-10:40:54 CONNECT TCP Peer: "[127.0.0.1]:52086" Local: "[127.0.0.1]:10024"
May 27 10:40:54 mail pmg-smtp-filter[10183]: Starting "1" children
May 27 10:40:54 mail pmg-smtp-filter[20157]: xxxxA35CEBA296937B1: new mail message-id=<xxxxxxxx-CEF7-45AC-981C-30989D6D19E5@xxxxxxxx.xx>
May 27 10:40:54 mail pmg-smtp-filter[20123]: xxxx405CEBA296958F2: new mail message-id=<xxxxxxxx-4DD6-4E89-9F70-CBBA35F91D27@xxxxxxxx.xx>
May 27 10:40:54 mail pmg-smtp-filter[20069]: xxxxC55CEBA296939DE: new mail message-id=<xxxxxxxx-4DD6-4E89-9F70-CBBA35F91D27@xxxxxxxx.xx>
May 27 10:40:54 mail pmg-smtp-filter[20221]: xxxxEB5CEBA2969D00E: new mail message-id=<xxxxxxxx-4DD6-4E89-9F70-CBBA35F91D27@xxxxxxxx.xx>
May 27 10:40:54 mail pmg-smtp-filter[20223]: xxxxF85CEBA296A4393: new mail message-id=<xxxxxxxx-CEF7-45AC-981C-30989D6D19E5@xxxxxxxx.xx>
May 27 10:40:54 mail pmg-smtp-filter[20069]: 2019/05/27-10:40:54 CONNECT TCP Peer: "[127.0.0.1]:52074" Local: "[127.0.0.1]:10024"
May 27 10:40:54 mail pmg-smtp-filter[20157]: 2019/05/27-10:40:54 CONNECT TCP Peer: "[127.0.0.1]:52076" Local: "[127.0.0.1]:10024"
May 27 10:40:54 mail pmg-smtp-filter[10183]: Starting "1" children
May 27 10:40:54 mail pmg-smtp-filter[20123]: 2019/05/27-10:40:54 CONNECT TCP Peer: "[127.0.0.1]:52078" Local: "[127.0.0.1]:10024"
May 27 10:40:54 mail pmg-smtp-filter[20221]: 2019/05/27-10:40:54 CONNECT TCP Peer: "[127.0.0.1]:52080" Local: "[127.0.0.1]:10024"
May 27 10:40:54 mail pmg-smtp-filter[10183]: Starting "1" children
May 27 10:40:54 mail pmg-smtp-filter[20223]: 2019/05/27-10:40:54 CONNECT TCP Peer: "[127.0.0.1]:52086" Local: "[127.0.0.1]:10024"
May 27 10:40:54 mail pmg-smtp-filter[10183]: Starting "1" children
May 27 10:40:54 mail pmg-smtp-filter[20157]: xxxxA35CEBA296937B1: new mail message-id=<xxxxxxxx-CEF7-45AC-981C-30989D6D19E5@xxxxxxxx.xx>
May 27 10:40:54 mail pmg-smtp-filter[20123]: xxxx405CEBA296958F2: new mail message-id=<xxxxxxxx-4DD6-4E89-9F70-CBBA35F91D27@xxxxxxxx.xx>
May 27 10:40:54 mail pmg-smtp-filter[20069]: xxxxC55CEBA296939DE: new mail message-id=<xxxxxxxx-4DD6-4E89-9F70-CBBA35F91D27@xxxxxxxx.xx>
May 27 10:40:54 mail pmg-smtp-filter[20221]: xxxxEB5CEBA2969D00E: new mail message-id=<xxxxxxxx-4DD6-4E89-9F70-CBBA35F91D27@xxxxxxxx.xx>
May 27 10:40:54 mail pmg-smtp-filter[20223]: xxxxF85CEBA296A4393: new mail message-id=<xxxxxxxx-CEF7-45AC-981C-30989D6D19E5@xxxxxxxx.xx>
May 27 10:41:02 mail pmg-smtp-filter[20225]: 2019/05/27-10:41:02 CONNECT TCP Peer: "[127.0.0.1]:60490" Local: "[127.0.0.1]:10023"
May 27 10:41:02 mail pmg-smtp-filter[10183]: Starting "1" children
May 27 10:41:02 mail pmg-smtp-filter[20225]: xxxxD95CEBA29E0EEA2: new mail message-id=<xxxxxxxxxe7409fb2ea9ec5da5268bb@xxx.xxxx.xx>
May 27 10:41:02 mail pmg-smtp-filter[20225]: xxxxD95CEBA29E0EEA2: accept mail to <xxxxx.xxxxx@xxxxx.at> (xxx255810DB)
May 27 10:41:02 mail pmg-smtp-filter[20225]: xxxxD95CEBA29E0EEA2: processing time: 0.167 seconds (0, 0.091, 0)
May 27 10:41:32 mail pmg-smtp-filter[10183]: Killing "1" children
May 27 10:41:40 mail pmg-smtp-filter[10183]: Starting "1" children
May 27 10:41:40 mail pmg-smtp-filter[20240]: 2019/05/27-10:41:40 CONNECT TCP Peer: "[127.0.0.1]:60496" Local: "[127.0.0.1]:10023"
May 27 10:41:40 mail pmg-smtp-filter[20240]: xxxxEC5CEBA2C48AD22: new mail message-id=<xxxxxx19bc554effa9d352c7a11b5887@xxx.xxxx.xx>
May 27 10:41:40 mail pmg-smtp-filter[20240]: xxxxEC5CEBA2C48AD22: accept mail to <xxxxxx@xxxxx-xxxx.xx> (xxx70581106)
May 27 10:41:40 mail pmg-smtp-filter[20240]: xxxxEC5CEBA2C48AD22: processing time: 0.152 seconds (0, 0.068, 0)
May 27 10:42:10 mail pmg-smtp-filter[10183]: Killing "1" children
May 27 10:42:20 mail pmg-smtp-filter[10183]: starting database maintainance
May 27 10:42:20 mail pmg-smtp-filter[10183]: end database maintainance (22 ms)
May 27 10:42:27 mail pmg-smtp-filter[10183]: Starting "1" children
May 27 10:42:27 mail pmg-smtp-filter[20240]: 2019/05/27-10:42:27 CONNECT TCP Peer: "[127.0.0.1]:60504" Local: "[127.0.0.1]:10023"
May 27 10:42:27 mail pmg-smtp-filter[20240]: xxxx585CEBA2F32EF70: new mail message-id=<xxxxxxx-I5DzD-omMAAJr8AQCBTwEAVRPI1aPI-xxxx@xxxx.xxx.xx>
May 27 10:42:31 mail pmg-smtp-filter[20240]: xxxx585CEBA2F32EF70: accept mail to <x.xxxxxx@xxxxx.xxx> (xxxFD58115D)
May 27 10:42:31 mail pmg-smtp-filter[20240]: xxxx585CEBA2F32EF70: processing time: 3.773 seconds (0, 3.349, 0)
May 27 10:43:01 mail pmg-smtp-filter[10183]: Killing "1" children
May 27 10:43:18 mail pmg-smtp-filter[10183]: Starting "1" children
May 27 10:43:18 mail pmg-smtp-filter[20240]: 2019/05/27-10:43:18 CONNECT TCP Peer: "[127.0.0.1]:60510" Local: "[127.0.0.1]:10023"
May 27 10:43:18 mail pmg-smtp-filter[20240]: xxxx4E5CEBA326427EB: new mail message-id=<xxxxxxx-BuuCv-jwYAAJz8AQCePwEAVQaAaeCX-xxxx@xxxx.xxx.xx>
May 27 10:43:18 mail pmg-smtp-filter[20240]: xxxx4E5CEBA326427EB: accept mail to <xxxxxxxx.xxxxxxxxx@xxxxx.xx.xx> (xxx70581268)
May 27 10:43:18 mail pmg-smtp-filter[20240]: xxxx4E5CEBA326427EB: processing time: 0.136 seconds (0, 0.067, 0)
May 27 10:43:20 mail pmg-smtp-filter[20265]: 2019/05/27-10:43:20 CONNECT TCP Peer: "[127.0.0.1]:60516" Local: "[127.0.0.1]:10023"
May 27 10:43:21 mail pmg-smtp-filter[20265]: xxxx4E5CEBA328ED78B: new mail message-id=<xxxx6ed3372f4da1b9a8d986d60d5e36@xxx.xxxx.xx>
May 27 10:43:21 mail pmg-smtp-filter[20265]: xxxx4E5CEBA328ED78B: accept mail to <xxx@xxx-xx.xx> (xxx9F581268)
May 27 10:43:21 mail pmg-smtp-filter[20265]: xxxx4E5CEBA328ED78B: processing time: 0.6 seconds (0, 0.489, 0)
May 27 10:43:51 mail pmg-smtp-filter[10183]: Killing "1" children
May 27 10:43:52 mail pmg-smtp-filter[20265]: 2019/05/27-10:43:52 CONNECT TCP Peer: "[127.0.0.1]:60522" Local: "[127.0.0.1]:10023"
May 27 10:43:52 mail pmg-smtp-filter[10183]: Starting "1" children
May 27 10:43:52 mail pmg-smtp-filter[20265]: xxxx735CEBA348C097E: new mail message-id=<xxxxxxx-mhoAx-khwAAJ38AQCDTwEAVa2pSkge-xxxx@xxxx.xxx.xx>
May 27 10:43:52 mail pmg-smtp-filter[20265]: xxxx735CEBA348C097E: accept mail to <xxxxxxx.xxxxxxx@xxx.xxx> (xxxE3581279)
May 27 10:43:52 mail pmg-smtp-filter[20265]: xxxx735CEBA348C097E: processing time: 0.142 seconds (0, 0.076, 0)
May 27 10:44:13 mail pmg-smtp-filter[20275]: 2019/05/27-10:44:13 CONNECT TCP Peer: "[127.0.0.1]:60528" Local: "[127.0.0.1]:10023"
May 27 10:44:13 mail pmg-smtp-filter[20275]: xxxx2E5CEBA35D57093: new mail message-id=<xxxxxxxf0f5146d2a0e5b52672223d1c@xxx.xxxx.xx>
May 27 10:44:19 mail pmg-smtp-filter[20275]: xxxx2E5CEBA35D57093: accept mail to <x.xx@xxx.xx> (xxx8C58132F)
May 27 10:44:19 mail pmg-smtp-filter[20275]: xxxx2E5CEBA35D57093: processing time: 5.841 seconds (0, 5.292, 0)
May 27 10:44:29 mail pmg-smtp-filter[10183]: starting database maintainance
May 27 10:44:29 mail pmg-smtp-filter[10183]: end database maintainance (23 ms)
May 27 10:44:49 mail pmg-smtp-filter[10183]: Killing "1" children
May 27 10:44:51 mail pmg-smtp-filter[10183]: Starting "1" children
May 27 10:44:51 mail pmg-smtp-filter[20275]: 2019/05/27-10:44:51 CONNECT TCP Peer: "[127.0.0.1]:60534" Local: "[127.0.0.1]:10023"
May 27 10:44:51 mail pmg-smtp-filter[20275]: xxxx555CEBA3831F556: new mail message-id=<xxxxxxx-Wopms-1gYAAJ/8AQCKTwEAVZ0K3dTz-xxxxx@xxx.xx>
May 27 10:44:51 mail pmg-smtp-filter[20275]: xxxx555CEBA3831F556: accept mail to <xxxxxx@xxx.xxx> (xxxC758141D)
May 27 10:44:51 mail pmg-smtp-filter[20275]: xxxx555CEBA3831F556: processing time: 0.101 seconds (0, 0.042, 0)
May 27 10:45:13 mail pmg-smtp-filter[20286]: 2019/05/27-10:45:13 CONNECT TCP Peer: "[127.0.0.1]:60540" Local: "[127.0.0.1]:10023"
May 27 10:45:13 mail pmg-smtp-filter[20286]: xxxx555CEBA39940939: new mail message-id=<xxxxxxxbfb85460680042c844221d0b2@xxx.xxxx.xx>
May 27 10:45:13 mail pmg-smtp-filter[20286]: xxxx555CEBA39940939: accept mail to <xxxxxxxx@xxxxx.xxxx> (xxx4058141D)
May 27 10:45:13 mail pmg-smtp-filter[20286]: xxxx555CEBA39940939: processing time: 0.122 seconds (0, 0.049, 0)
May 27 10:45:25 mail pmg-smtp-filter[20275]: 2019/05/27-10:45:25 CONNECT TCP Peer: "[127.0.0.1]:60548" Local: "[127.0.0.1]:10023"

luke5sky · May 27, 2019

Ich habe doch noch etwas gefunden, kurz bevor die load wieder normal wird habe ich diese Warnings in den Logs:

Code:

May 27 12:17:58 mail pmg-smtp-filter[23027]: WARNING: Use of uninitialized value $score in concatenation (.) or string at /usr/share/perl5/PMG/RuleDB/Spam.pm line 432.
May 27 12:17:58 mail pmg-smtp-filter[23027]: xxxx065CEBB5566A262: SA score=0/5 time=1024.213 bayes=0 autolearn=unavailable hits=BAYES_00(-1.9),HTML_MESSAGE(0.001),MISSING_HEADERS(1.021),RCVD_IN_DNSWL_NONE(-0.00
May 27 12:17:58 mail pmg-smtp-filter[23027]: WARNING: Use of uninitialized value in sprintf at /usr/bin/pmg-smtp-filter line 210.
May 27 12:18:07 mail pmg-smtp-filter[23123]: WARNING: Use of uninitialized value $score in concatenation (.) or string at /usr/share/perl5/PMG/RuleDB/Spam.pm line 432.
May 27 12:18:07 mail pmg-smtp-filter[23123]: xxxxE75CEBB55668947: SA score=0/5 time=1032.544 bayes=0 autolearn=unavailable hits=BAYES_00(-1.9),HTML_MESSAGE(0.001),MISSING_HEADERS(1.021),RCVD_IN_DNSWL_NONE(-0.00
May 27 12:18:07 mail pmg-smtp-filter[23123]: WARNING: Use of uninitialized value in sprintf at /usr/bin/pmg-smtp-filter line 210.
May 27 12:18:08 mail pmg-smtp-filter[23148]: WARNING: Use of uninitialized value $score in concatenation (.) or string at /usr/share/perl5/PMG/RuleDB/Spam.pm line 432.
May 27 12:18:08 mail pmg-smtp-filter[23148]: xxxx505CEBB5567176F: SA score=0/5 time=1033.699 bayes=0 autolearn=unavailable hits=BAYES_00(-1.9),HTML_MESSAGE(0.001),MISSING_HEADERS(1.021),RCVD_IN_DNSWL_NONE(-0.00
May 27 12:18:08 mail pmg-smtp-filter[23148]: WARNING: Use of uninitialized value in sprintf at /usr/bin/pmg-smtp-filter line 210.
May 27 12:18:09 mail pmg-smtp-filter[23022]: WARNING: Use of uninitialized value $score in concatenation (.) or string at /usr/share/perl5/PMG/RuleDB/Spam.pm line 432.
May 27 12:18:09 mail pmg-smtp-filter[23022]: xxxxEB5CEBB556698DE: SA score=0/5 time=1034.701 bayes=0 autolearn=unavailable hits=BAYES_00(-1.9),HTML_MESSAGE(0.001),MISSING_HEADERS(1.021),RCVD_IN_DNSWL_NONE(-0.00
May 27 12:18:09 mail pmg-smtp-filter[23022]: WARNING: Use of uninitialized value in sprintf at /usr/bin/pmg-smtp-filter line 210.

Auf beiden Gateways das selbe Verhalten, kann es sein, dass hier das pmg-smtp-filter Service in ein Timeout läuft und daher die Load wieder normal wird?

luke5sky · May 27, 2019

diese Warnings beginnen am 24.05 um 11:28 (GW1) und um 11:35 (GW2), passt also zeitlich zusammen.

Letztes Update wurde am 17.05 eingespielt, seitdem sollte nichts am System verändert worden sein, bis auf Auto-Updates Spam und antivirus.

Stoiko Ivanov · May 27, 2019

Hm - scheint als wäre da ein Problem in der Spamassassin config:
* wurden Anpassungen an spamassassin oder im Regelsystem vorgenommen? (z.b. custom spamassassin config wie in 4.8 des pmg-admin-guides beschrieben - https://www.proxmox.com/images/download/pmg/docs/pmg-admin-guide.pdf)
* besteht das problem weiterhin auch wen das `pmg-smtp-filter.service` neugestartet wurde?

luke5sky said:
May 27 12:18:09 mail pmg-smtp-filter[23022]: xxxxEB5CEBB556698DE: SA score=0/5 time=1034.701 bayes=0 autolearn=unavailable hits=BAYES_00(-1.9),HTML_MESSAGE(0.001),MISSING_HEADERS(1.021),RCVD_IN_DNSWL_NONE(-0.00

die Zeile sieht so aus als waere sie abgeschnitten, da sollten noch einige weitere regeln vorkommen - die gesamte Zeile würde sehr helfen das Problem besser einzugrenzen.

luke5sky · May 27, 2019

sorry, hier die ganze zeile:

Code:

May 27 12:18:09 mail pmg-smtp-filter[23022]: WARNING: Use of uninitialized value $score in concatenation (.) or string at /usr/share/perl5/PMG/RuleDB/Spam.pm line 432.
May 27 12:18:09 mail pmg-smtp-filter[23022]: xxxxEB5CEBB556698DE: SA score=0/5 time=1034.701 bayes=0 autolearn=unavailable hits=BAYES_00(-1.9),HTML_MESSAGE(0.001),MISSING_HEADERS(1.021),RCVD_IN_DNSWL_NONE(-0.0001),SPF_HELO_NONE(0.001),SPF_NONE(0.001),TIME_LIMIT_EXCEEDED()
May 27 12:18:09 mail pmg-smtp-filter[23022]: WARNING: Use of uninitialized value in sprintf at /usr/bin/pmg-smtp-filter line 210.

ja es gibt eine rules in custom.cf hier würde mir nur auf die schnelle auffallen, dass manche Rules mit score 10 und nicht score 10.0 bewertet werden, ich teste mal, das umzustellen

Stoiko Ivanov · May 27, 2019

Danke! Sieht so aus als würden die 'uninitialized values' von der "rule" TIME_LIMIT_EXCEEDED kommen - und das widerrum spricht, dafür, dass SpamAssassin jetzt deutlich mehr zeit braucht als zuvor - wäre es möglich die custom.cf zu sharen? (wenn notwendig anonymisiert)

luke5sky · May 27, 2019

hier die custom.cf (ist auf beiden Gateways die selbe):

Code:

body __ADMINRULE_xxx_UNSUB /unsubscribe/i
body __ADMINRULE_xxx_SHOP /shop/i
body __ADMINRULE_xxx_ADDRESSBOOK /to your Address Book/i
header __ADMINRULE_xxx_TO TO =~ /\@xxxxx\-xxxxx\.at/i
meta ADMINRULE_xxx_SHOP_ADDRESS (__ADMINRULE_xxx_UNSUB && (__ADMINRULE_xxx_SHOP || __ADMINRULE_xxx_ADDRESSBOOK) && __ADMINRULE_xxx_TO)
describe ADMINRULE_xxx_SHOP_ADDRESS      Contains the word unsubscribe and shop in body and was sent to @xxxx-xxxx.at
score ADMINRULE_xxx_SHOP_ADDRESS 10.0

body __ADMINRULE_xxx2_UNSUB /unsubscribe/i
body __ADMINRULE_xxx2_SALE /sale/i
header __ADMINRULE_xxx2_TO TO =~ /\@xxxx\-xxxx\.at/i
meta ADMINRULE_xxx_SALE (__ADMINRULE_xxx2_UNSUB && __ADMINRULE_xxx2_SALE && __ADMINRULE_xxx2_TO)
describe ADMINRULE_xxx_SALE      Contains the word unsubscribe and sale in body and was sent to @xxxx-xxxx.at
score ADMINRULE_xxx_SALE 10.0

body __ADMINRULE_xxx3_UNSUB /unsubscribe/i
body __ADMINRULE_xxx3_LM /LAST\sMINUTE/i
header __ADMINRULE_xxx3_TO TO =~ /\@xxxx\-xxxx\.at/i
meta ADMINRULE_xxx_LASTMINUTE (__ADMINRULE_xxx3_UNSUB && __ADMINRULE_xxx3_LM && __ADMINRULE_xxx3_TO)
describe ADMINRULE_xxx_LASTMINUTE        Contains the word unsubscribe and LAST MINUTE in body and was sent to @xxxx-xxxx.at
score ADMINRULE_xxx_LASTMINUTE 10.0

body __ADMINRULE_xxx4_UNSUB /unsubscribe/i
body __ADMINRULE_xxx4_SUBSCR /update\ssubscription\spreferences/i
header __ADMINRULE_xxx4_TO TO =~ /\@xxxx\-xxxx\.at/i
meta ADMINRULE_xxx_SUBPREFERENCE (__ADMINRULE_xxx4_UNSUB && __ADMINRULE_xxx4_SUBSCR && __ADMINRULE_xxx4_TO)
describe ADMINRULE_xxx_SUBPREFERENCE     Contains the word unsubscribe and update subscription preferences in body and was sent to @xxxx-xxxx.at
score ADMINRULE_xxx_SUBPREFERENCE 10.0

body __ADMINRULE_xxx5_UNSUB /unsubscribe/i
body __ADMINRULE_xxx5_SUBSCR /manage\syour\ssubscription/i
header __ADMINRULE_xxx5_TO TO =~ /\@xxxx\-xxxx\.at/i
meta ADMINRULE_xxx_MANAGE (__ADMINRULE_xxx5_UNSUB && __ADMINRULE_xxx5_SUBSCR && __ADMINRULE_xxx5_TO)
describe ADMINRULE_xxx_MANAGE    Contains the word unsubscribe and manage your subscription in body and was sent to @xxxx-xxxx.at
score ADMINRULE_xxx_MANAGE 10.0

body __ADMINRULE_xxx6_UNSUB /unsubscribe/i
body __ADMINRULE_xxx6_RECEIVE /receiving\sthis\semail\sbecause/i
header __ADMINRULE_xxx6_TO TO =~ /\@xxxx\-xxxx\.at/i
meta ADMINRULE_xxx_SIGNEDUP (__ADMINRULE_xxx6_UNSUB && __ADMINRULE_xxx6_RECEIVE && __ADMINRULE_xxx6_TO)
describe ADMINRULE_xxx_SIGNEDUP  Contains the word unsubscribe and receiving this email because in body and was sent to @xxxx-xxxx.at
score ADMINRULE_xxx_SIGNEDUP 10.0

body __ADMINRULE_xxx7_UNSUB /unsubscribe/i
body __ADMINRULE_xxx7_CLICK /Click\sHere\sto/i
header __ADMINRULE_xxx7_TO TO =~ /\@xxxx\-xxxx\.at/i
meta ADMINRULE_xxx_CLICK (__ADMINRULE_xxx7_UNSUB && __ADMINRULE_xxx7_CLICK && __ADMINRULE_xxx7_TO)
describe ADMINRULE_xxx_CLICK     Contains the word unsubscribe and click here to in body and was sent to @xxxx-xxxx.at
score ADMINRULE_xxx_CLICK 10.0

rawbody __ADMINRULE_RUSSIAN_CHARS_xxx /(д|ж|з|и|й)/i
header __ADMINRULE_RUSSIAN_xxx_TO TO =~ /\@xxxx\-xxxx\.at/i
meta ADMINRULE_xxx_RUSSIAN (__ADMINRULE_RUSSIAN_CHARS_xxx && __ADMINRULE_RUSSIAN_xxx_TO)
describe ADMINRULE_xxx_RUSSIAN   Russian characters in header
score ADMINRULE_xxx_RUSSIAN 10.0

header __ADMINRULE_CHINESE_xxx1 From =~ /=?utf-8?B?/
header __ADMINRULE_CHINESE_xxx2 From =~ /\.cn>/i
header __ADMINRULE_CHINESE_xxx_TO TO =~ /\@xxxx\-xxxx\.at/i
describe ADMINRULE_xxx_CHINESE   Chinese characters in header
meta ADMINRULE_xxx_CHINESE (__ADMINRULE_CHINESE_xxx1 && __ADMINRULE_CHINESE_xxx_TO && !__ADMINRULE_CHINESE_xxx2)
score ADMINRULE_xxx_CHINESE 10.0

header __ADMINRULE_ALL_ARZNEI Subject =~ /Arzneimittel/i
header __ADMINRULE_ALL_EREKT Subject =~ /Erektionsdysfunktion/i
meta ADMINRULE_ALL_VIAGRA (__ADMINRULE_ALL_ARZNEI && __ADMINRULE_ALL_EREKT)
describe ADMINRULE_ALL_VIAGRA   Contains the word Arzneimittel and Erektionsdysfunktion in Subject
score ADMINRULE_ALL_VIAGRA 10.0

header __ADMINRULE_ALL_SICHERHEIT Subject =~ /Es\sgeht\sum\sIhre\sSicherheit/i
body __ADMINRULE_ALL_RAT /RAT\-Software/i
meta ADMINRULE_ALL_SICHERHEIT (__ADMINRULE_ALL_RAT && __ADMINRULE_ALL_SICHERHEIT)
describe ADMINRULE_ALL_SICHERHEIT       Contains the phrase Es geht um Ihre Sicherheit in Subject and RAT-Software in Body
score ADMINRULE_ALL_SICHERHEIT 10.0

body __ADMINRULE_ALL_VIRUS /Virus/i
body __ADMINRULE_ALL_BITCOIN /Bitcoin\sWallet/i
meta ADMINRULE_ALL_BITCOIN_VIRUS (__ADMINRULE_ALL_VIRUS && __ADMINRULE_ALL_BITCOIN)
describe ADMINRULE_ALL_BITCOIN_VIRUS    Contains the phrase VIRUS and BITCOIN WALLET in Body
score ADMINRULE_ALL_BITCOIN_VIRUS 10.0

body __ADMINRULE_ALL_UNSUB_HOT /unsubscribe/i
body __ADMINRULE_ALL_HOT_GIRL /hot\sgirl/i
meta ADMINRULE_ALL_HOT (__ADMINRULE_ALL_UNSUB_HOT && __ADMINRULE_ALL_HOT_GIRL)
describe ADMINRULE_ALL_HOT      Contains the phrase Unsubscribe and Hot Girl in Body
score ADMINRULE_ALL_HOT 10.0

body __ADMINRULE_ALL_PENIS /penis/i
body __ADMINRULE_ALL_PORN /porn/i
meta ADMINRULE_ALL_PORN_PENIS (__ADMINRULE_ALL_PENIS && __ADMINRULE_ALL_PORN)
describe ADMINRULE_ALL_PORN_PENIS       Contains the phrase PENIS and PORN in Body
score ADMINRULE_ALL_PORN_PENIS 10.0

body __ADMINRULE_ALL_PILLEN /pillen/i
body __ADMINRULE_ALL_SEX /sex/i
meta ADMINRULE_ALL_SEX_PILLEN (__ADMINRULE_ALL_PILLEN && __ADMINRULE_ALL_SEX)
describe ADMINRULE_ALL_SEX_PILLEN       Contains the phrase PILLEN and SEX in Body
score ADMINRULE_ALL_SEX_PILLEN 10.0

ifplugin Mail::SpamAssassin::Plugin::HashBL
header HASHBL_EMAIL eval:check_hashbl_emails('ebl.msbl.org')
describe HASHBL_EMAIL   Message contains email address found on EBL
score HASHBL_EMAIL 3.0
endif

mimeheader ADMINRULE_ALL_BADDOC Content-Type =~ /="[^"]+\.(?:doc?|rtf)"/i
describe ADMINRULE_ALL_BADDOC   Contains a doc File
score ADMINRULE_ALL_BADDOC 1.0

header __ADMINRULE_ALL_BEWERBUNG Subject =~ /bewerbung/i
mimeheader __ADMINRULE_ALL_DOC Content-Type =~ /="[^"]+\.(?:doc?|rtf)"/i
meta ADMINRULE_ALL_BAD_BEWERBUNG (__ADMINRULE_ALL_BEWERBUNG && __ADMINRULE_ALL_DOC)
describe ADMINRULE_ALL_BAD_BEWERBUNG Contains the phrase BEWERBUNG in Subject and a .doc file as attachment
score ADMINRULE_ALL_BAD_BEWERBUNG 10.0

header ADMINRULE_FRIEND_EMAIL FROM =~ /FRIEND\.EMAIL/i
describe ADMINRULE_FRIEND_EMAIL Contains the words FRIEND.EMAIL in HEADER from
score ADMINRULE_FRIEND_EMAIL 10.0

Stoiko Ivanov · May 27, 2019

Sind doch einige eigene regeln, bitte mal ohne die custom config testen, ob es immer noch zu einem TIME_EXCEEDED kommt.
falls nicht -> die custom.cf schritt für schritt hinzufügen, damit identifiziert wird wo das problem hinzukommt

Stoiko Ivanov · May 27, 2019

Da wir gerade einen ähnlichen Fall reproduzieren konnten - falls es nicht an der custom.cf liegt, könnte es auch an dem letzten Update liegen und an der Regel `__STYLE_GIBBERISH_1` .
Diese kann mittels folgendem Eintrag

Code:

score __STYLE_GIBBERISH_1 0

deaktiviert werden.

Wären für feedback woran es lag dankbar!

luke5sky · May 27, 2019

Super vielen Dank, wollte morgen früh mal mit der custom.cf beginnen, aber dann probier ich mal diese rule zu deaktivieren. Nur zur Sicherheit, in welchem File finde ich diese Regel? Oder einfach in der custom.cf hinzufügen?

Vielen Dank

Stoiko Ivanov · May 27, 2019

In der `/etc/mail/spamassassin/custom.cf` hinzufügen sollte reichen (pmg-smtp-filter danach neu starten!)

luke5sky · May 28, 2019

Schaut leider eher schlecht aus, habe jetzt alle Regeln (auf einem Gateway) entfernt und nur score __STYLE_GIBBERISH_1 0 eingetragen, pmg-smtp-filter neu gestartet.

War während einer Last-Spitze die noch immer nicht vorbei ist, CPU geht nach 1-2 Minuten wieder auf 100 % und 12 pmg-smtp-filter Prozesse.

ich warte mal ab, bis diese Spitze vorbei und ob eine neue kommt

luke5sky · May 28, 2019

Vielleicht noch wichtig: es läuft PowerDNS (nur recursor) auf beiden Gateways (für DNSBL).

Stoiko Ivanov · May 28, 2019

luke5sky said:
Schaut leider eher schlecht aus, habe jetzt alle Regeln (auf einem Gateway) entfernt und nur score __STYLE_GIBBERISH_1 0 eingetragen, pmg-smtp-filter neu gestartet.

hmm - schade - da sich das debuggen bei spamassassin eher mühsam gestalten kann:
* eine mail, welche die Lastspitzen verursacht im gesamten Quelltext speichern:
- wenn sie sich noch in einer postfix queue befindet geht das mit `postcat -q <queueid>` (queueid steht im output von `mailq`)
- dort den text zw. `*** MESSAGE CONTENTS xxxxx***` und der nächsten Zeile die mit `***` beginnt nehmen.
* diese dann mit spamassassin verarbeiten und das debug-output beobachten:
```
spamassassin -D < <mailfile.txt>
```

Das output gibt mal einen ersten Hinweis wo das Problem sein könnte.

luke5sky said:
Vielleicht noch wichtig: es läuft PowerDNS (nur recursor) auf beiden Gateways (für DNSBL).

Würde ich initial mal ausschließen, da wenn der DNS nicht funktionieren sollte, SpamAssassin ein relative kurzes Timeout hat, welches nicht zu TIME_EXCEEDED führt.

Hoffe das hilft

luke5sky · May 28, 2019

Problem ist momentan gelöst, es waren 10 - 20 Mails (war ein und der selbe Newsletter an mehrerer Personen), die in der Queue gehangen sind.
Ich habe sie dort manuell rausgelöscht, danach kam das Problem nicht mehr
Header von einer dieser Mails:

Code:

Received-SPF: none (xxxx-xxxx.xx: No applicable sender policy available) receiver=mail.xxxx-xxxx.xx; identity=mailfrom; envelope-from="xxxx@xxxx-xxxx.xx"; helo=xxxxx.xxxxx.xx; client-ip=xx.xx.xx.xx
Received: from xxxxx.xxxxx.xx (xxxxx.xxxxx.xx [xx.xx.xx.xx])
    (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits))
    (No client certificate requested)
    by mail.xxxx-xxxx.xx (Proxmox) with ESMTPS id xxxxxxxxxxxx
    for <xxxxx@xxxxxxx.xx>; Fri, 24 May 2019 10:55:51 +0200 (CEST)
X-PDA-ORIGIN: xxxxx.xxxxx.xx
Received: (qmail 12194 invoked from network); 24 May 2019 08:55:41 -0000
Received: by simscan 1.4.0 ppid: 12084, pid: 12189, t: 1.0058s
         scanners: clamav: 0.101.1/m:58/d:25379
Received: from unknown (HELO ?192.168.0.154?) (office@xxxxx.xx@xx.xx.xx.xx)
  by xxxxx.xxxxx.xx with ESMTPS (DHE-RSA-AES256-SHA encrypted); 24 May 2019 08:55:40 -0000
From: <xxxxx@xxx-xxx.xx>
Content-Type: multipart/alternative; boundary="Apple-Mail=_xxxxxxx-C746-4706-BBD2-2B85BF0C695A"
Date: Fri, 24 May 2019 10:55:25 +0200
Subject: xxxxx
Message-Id: <xxxxxxx-CEF7-45AC-981C-30989D6D19E5@frei-zeit.tv>
Mime-Version: 1.0 (Mac OS X Mail 9.3 \(3124\))
X-Mailer: Apple Mail (2.3124)

Ich werde die nächsten Tage mal probieren die custom.cf wieder zu befüllen und werde bis dahin auch beobachten ob vom selbem Absender wieder so ein Newsletter kommt.

Vielen Dank für die Hilfe

Stoiko Ivanov · May 28, 2019

hm - leider hab ich die cpu-last mit den headern alleine nicht nachstellen koennen - aber ja - es war auch im anderen fall eine einzelne mail, die zu dem problem gefuehrt hat.

Sollte das problem nochmal auftauchen hier wieder melden (oder durch den spamassassin debugger jagen).

Viel Erfolg!

luke5sky · May 28, 2019

Das nächste mal jag ich das fix mal durch den Debugger und poste hier den output. Danke

[SOLVED] Performance Probleme

Member

Attachments

Member

Attachments

Proxmox Staff Member

Member

Member

Member

Proxmox Staff Member

Member

Proxmox Staff Member

Member

Proxmox Staff Member

Proxmox Staff Member

Member

Proxmox Staff Member

Member

Member

Proxmox Staff Member

Member

Proxmox Staff Member

Member