No SA Scores

[ldiedrich]

Hey guys, I have made a clean install for proxmox 7.1, and migrated my SA rules to the new server, after the server migration it seems that SA is not working at all.
I have verified ports, configurations and other stuff and i can't figure why is not marking or reaching any SA rules.

Any ideas where to look for?



Sa lint compiled without errors, file is on /etc/mail/spamassassin/custom.cf;



My normal rules (blacklist) is working normally.

 

[Stoiko Ivanov]

Please share some logs (taken from journalctl output) of a mail, which should have some spamassassin hit, but does not reach enough points

 

[ldiedrich]

@Stoiko Ivanov That's shomenthing weird, it doesn´t seem to be htiting SA at all:

nov 03 07:21:49 mercurio postfix/smtp[3958775]: Anonymous TLS connection established to 10.0.0.23[10.0.0.23]:25: TLSv1.2 with cipher ADH-AES256-GCM-SHA384 (256/256 bits)
nov 03 07:21:49 mercurio postfix/smtpd[3960709]: connect from localhost.localdomain[127.0.0.1]
nov 03 07:21:49 mercurio postfix/smtpd[3960709]: 394D61232E8: client=localhost.localdomain[127.0.0.1], orig_client=mail-lf1-x12b.google.com[2a00:1450:4864:20::12b]
nov 03 07:21:49 mercurio postfix/smtp[3959024]: 2585C1232AA: to=<j@mydomain.edu.br>, relay=10.0.0.23[10.0.0.23]:25, delay=0.08, delays=0.01/0/0.05/0.02, dsn=5.7>
nov 03 07:21:49 mercurio postfix/cleanup[3961131]: 399DC1232E9: message-id=<20221103102149.399DC1232E9@mercurio.mydomain.edu.br>
nov 03 07:21:49 mercurio postfix/cleanup[3961208]: 394D61232E8: message-id=<CAEwF-T9yy-XwDc9fZO1NuWwu260UjTy6U_D6h8dcATy7Cd+hxw@mail.gmail.com>
nov 03 07:21:49 mercurio postfix/bounce[3961584]: 2585C1232AA: sender non-delivery notification: 399DC1232E9
nov 03 07:21:49 mercurio postfix/qmgr[1331018]: 399DC1232E9: from=<>, size=5106, nrcpt=1 (queue active)
nov 03 07:21:49 mercurio postfix/qmgr[1331018]: 2585C1232AA: removed
nov 03 07:21:49 mercurio postfix/smtp[3958775]: 315941232B3: to=<w@mydomain.edu.br>, relay=10.0.0.23[10.0.0.23]:25, delay=0.09, delays=0.01/0/0.05/0.02, dsn=5.>
nov 03 07:21:49 mercurio postfix/cleanup[3961533]: 46AA51232B1: message-id=<20221103102149.46AA51232B1@mercurio.mydomain.edu.br>
nov 03 07:21:49 mercurio postfix/qmgr[1331018]: 394D61232E8: from=<somerandom@gmail.com>, size=326870, nrcpt=1 (queue active)
nov 03 07:21:49 mercurio postfix/smtpd[3960709]: disconnect from localhost.localdomain[127.0.0.1] ehlo=1 xforward=1 mail=1 rcpt=1 data=1 commands=5
nov 03 07:21:49 mercurio pmg-smtp-filter[3961242]: 22A506363963D235D8: accept mail to <r@mydomain.edu.br> (394D61232E8) (rule: Whitelist)
nov 03 07:21:49 mercurio postfix/qmgr[1331018]: 46AA51232B1: from=<>, size=5138, nrcpt=1 (queue active)
nov 03 07:21:49 mercurio postfix/bounce[3961584]: 315941232B3: sender non-delivery notification: 46AA51232B1
nov 03 07:21:49 mercurio postfix/qmgr[1331018]: 315941232B3: removed
nov 03 07:21:49 mercurio pmg-smtp-filter[3961242]: 22A506363963D235D8: processing time: 0.143 seconds (0, 0.059, 0)
nov 03 07:21:49 mercurio postfix/smtpd[3961153]: proxy-accept: END-OF-MESSAGE: 250 2.5.0 OK (22A506363963D235D8); from=<somerandom@gmail.com> to=<r@unila.>
nov 03 07:21:49 mercurio postfix/smtp[3958975]: Anonymous TLS connection established to 10.0.0.23[10.0.0.23]:25: TLSv1.2 with cipher ADH-AES256-GCM-SHA384 (256/256 bits)
nov 03 07:21:49 mercurio postfix/smtp[3958976]: D174E1232D1: to=<somerandom@gmail.com>, relay=gmail-smtp-in.l.google.com[2800:3f0:4003:c00::1a]:25, delay=1.4, delays=0/0/1.>
nov 03 07:21:49 mercurio postfix/smtp[3958953]: Trusted TLS connection established to gmail-smtp-in.l.google.com[2800:3f0:4003:c00::1a]:25: TLSv1.3 with cipher TLS_AES_256_>
nov 03 07:21:49 mercurio postfix/smtp[3958975]: 394D61232E8: to=<r@mydomain.edu.br>, relay=10.0.0.23[10.0.0.23]:25, delay=0.13, delays=0.06/0/0.05/0.02, >
nov 03 07:21:49 mercurio postfix/cleanup[3961131]: 58531123314: message-id=<20221103102149.58531123314@mercurio.mydomain.edu.br>
nov 03 07:21:49 mercurio postfix/bounce[3961444]: 394D61232E8: sender non-delivery notification: 58531123314
nov 03 07:21:49 mercurio postfix/qmgr[1331018]: 58531123314: from=<>, size=5171, nrcpt=1 (queue active)
nov 03 07:21:49 mercurio postfix/qmgr[1331018]: 394D61232E8: removed
nov 03 07:21:49 mercurio postfix/smtpd[3960627]: Anonymous TLS connection established from mail-ed1-x529.google.com[2a00:1450:4864:20::529]: TLSv1.3 with cipher TLS_AES_128>
nov 03 07:21:49 mercurio postfix/smtp[3958778]: Trusted TLS connection established to gmail-smtp-in.l.google.com[64.233.186.26]:25: TLSv1.3 with cipher TLS_AES_256_GCM_SHA3>
nov 03 07:21:49 mercurio postfix/qmgr[1331018]: D174E1232D1: removed
nov 03 07:21:49 mercurio postfix/smtpd[3959180]: NOQUEUE: client=mail-ed1-x52c.google.com[2a00:1450:4864:20::52c]
nov 03 07:21:49 mercurio postfix/smtpd[3960637]: NOQUEUE: client=mail-ed1-x52d.google.com[2a00:1450:4864:20::52d]
nov 03 07:21:49 mercurio postfix/smtpd[3961152]: NOQUEUE: client=mail-ed1-x52d.google.com[2a00:1450:4864:20::52d]
nov 03 07:21:49 mercurio postfix/smtp[3958974]: Trusted TLS connection established to gmail-smtp-in.l.google.com[64.233.186.26]:25: TLSv1.3 with cipher TLS_AES_256_GCM_SHA3>
nov 03 07:21:49 mercurio postfix/smtp[3958967]: Trusted TLS connection established to gmail-smtp-in.l.google.com[64.233.186.26]:25: TLSv1.3 with cipher TLS_AES_256_GCM_SHA3>
nov 03 07:21:49 mercurio postfix/smtp[3958957]: 0F49B1232F1: to=<somerandom@gmail.com>, relay=gmail-smtp-in.l.google.com[2800:3f0:4003:c00::1a]:25, delay=1.6, delays=0/0/1.>
nov 03 07:21:49 mercurio postfix/qmgr[1331018]: 0F49B1232F1: removed
nov 03 07:21:49 mercurio postfix/smtp[3958887]: F3BA5123301: to=<somerandom@gmail.com>, relay=gmail-smtp-in.l.google.com[2800:3f0:4003:c00::1a]:25, delay=1.8, delays=0/0/1.>
nov 03 07:21:49 mercurio postfix/qmgr[1331018]: F3BA5123301: removed
nov 03 07:21:49 mercurio postfix/smtp[3958786]: Trusted TLS connection established to gmail-smtp-in.l.google.com[64.233.186.26]:25: TLSv1.3 with cipher TLS_AES_256_GCM_SHA3>
nov 03 07:21:49 mercurio postfix/smtp[3958768]: 4136E123307: to=<somerandom@gmail.com>, relay=gmail-smtp-in.l.google.com[64.233.186.26]:25, delay=1.5, delays=0/0/0.94/0.6, >
nov 03 07:21:49 mercurio postfix/qmgr[1331018]: 4136E123307: removed
nov 03 07:21:49 mercurio postfix/smtp[3958966]: Trusted TLS connection established to gmail-smtp-in.l.google.com[64.233.186.26]:25: TLSv1.3 with cipher TLS_AES_256_GCM_SHA3>

 

[ldiedrich]

@Stoiko Ivanov Any idea what could be wrong? I can't find anything related to Spam Score with Spamassassin in the logs, for me really seams that its not reaching there somehow.

 

[Stoiko Ivanov]

The logs for the message are not complete - pmg-smtp-filter at least also prints a line when it's receiving a connection

else - please make sure you have a rule which is evaluated (direction need to fit ) and has a what object with Spam Level assigned

 

[ldiedrich]

That's the problem i think, in the logs above you can check that muy blacklist rule is working, but no SA score at all.

Nov 7 07:19:30 dmyserver pmg-smtp-filter[966461]: 2022/11/07-07:19:30 CONNECT TCP Peer: "[127.0.0.1]:50408" Local: "[127.0.0.1]:10024"
Nov 7 07:19:30 dmyserver pmg-smtp-filter[966461]: 236B36368DBB26611F: new mail message-id=<YRjT-7daqDU2iA-3vFy-1guMjvtf5iMdelabV@email.metalpowderreport.com>#012
Nov 7 07:19:30 dmyserver pmg-smtp-filter[966461]: 236B36368DBB26611F: accept mail to <user1@mydomain> (80E151231C8) (rule: default-accept)
Nov 7 07:19:30 dmyserver pmg-smtp-filter[966461]: 236B36368DBB26611F: processing time: 0.117 seconds (0, 0.071, 0)
Nov 7 07:19:32 dmyserver pmg-smtp-filter[970205]: 2022/11/07-07:19:32 CONNECT TCP Peer: "[127.0.0.1]:41896" Local: "[127.0.0.1]:10023"
Nov 7 07:19:32 dmyserver pmg-smtp-filter[970205]: 236B36368DBB409A96: new mail message-id=<YRjT-7daqDU2iA-3vFy-1guMjvtf5iMdelabV@email.metalpowderreport.com>#012
Nov 7 07:19:32 dmyserver pmg-smtp-filter[970205]: 236B36368DBB409A96: accept mail to <basso@gmail.com> (187391231C8) (rule: default-accept)
Nov 7 07:19:32 dmyserver pmg-smtp-filter[970205]: 236B36368DBB409A96: processing time: 0.065 seconds (0, 0.036, 0)
Nov 7 07:19:57 dmyserver pmg-smtp-filter[966461]: 2022/11/07-07:19:57 CONNECT TCP Peer: "[127.0.0.1]:58778" Local: "[127.0.0.1]:10024"
Nov 7 07:19:57 dmyserver pmg-smtp-filter[966461]: 236B36368DBCD3BCAE: new mail message-id=<01000184519a7fed-3603da16-f716-4e80-9f3e-ff476c4396cc-000000@email.amazonses.com>#012
Nov 7 07:19:57 dmyserver pmg-smtp-filter[966461]: 236B36368DBCD3BCAE: block mail to <apollo.2019@aluno.mydomain> (rule: Blacklist)
Nov 7 07:19:57 dmyserver pmg-smtp-filter[966461]: 236B36368DBCD3BCAE: processing time: 0.074 seconds (0, 0.06, 0)
Nov 7 07:20:06 dmyserver pmg-smtp-filter[970205]: 2022/11/07-07:20:06 CONNECT TCP Peer: "[127.0.0.1]:55958" Local: "[127.0.0.1]:10023"
Nov 7 07:20:06 dmyserver pmg-smtp-filter[970205]: 236B36368DBD6D194E: new mail message-id=<1251947584.32852408.1667816406359.JavaMail.zimbra@mydomain>#012
Nov 7 07:20:06 dmyserver pmg-smtp-filter[970205]: 236B36368DBD6D194E: accept mail to <ccampo@id.antherdomain> (E17251231C8) (rule: default-accept)
Nov 7 07:20:06 dmyserver pmg-smtp-filter[970205]: 236B36368DBD6D194E: processing time: 0.111 seconds (0, 0.046, 0)

And i do have the rule with the Spam level.

 

[Stoiko Ivanov]

and migrated my SA rules to the new server, after the server migration it seems that SA is not working at all.

what modifications does your SpamAssassin configuration have?

any messages indicating issues in the journal when you restart pmg-smtp-filter?

 

[ldiedrich]

@Stoiko Ivanov, I changed the rule priority and now i started to see 'SA Score'

Nov 7 07:41:56 mercurio.unila.edu.br pmg-smtp-filter[991175]: 236B36368E0F41BC20: new mail message-id=<1483123848.10.1667817702612.JavaMail.admweb@dfcdsrvv3233>#012
Nov 7 07:42:00 mercurio.unila.edu.br pmg-smtp-filter[991175]: 236B36368E0F41BC20: SA score=0/5 time=4.274 bayes=undefined autolearn=disabled hits=DKIMWL_WL_HIGH(-0.001),DKIM_SIGNED(0.1),DKIM_VALID(-0.1),DKIM_VALID_AU(-0.1),DKIM_VALID_EF(-0.1),MISSING_DATE(1.396),RCVD_IN_DNSWL_MED(-2.3),RCVD_IN_MSPIKE_H2(-0.001),SPF_HELO_NONE(0.001),SPF_PASS(-0.001)