Hello,
Could someone please help me troubleshooting why my spamassassin setup
suddenly stopped adding headers to my messages?
My setup consist of a spamd deamon being called from postfix using
spamass-milter. Spamassassin is supposed to add headers (which it did
properly until recently) which are then used later to filter spams through
the use of dovecot sieve filters.
My platform is a Debian 10, thus spamassassin 3.4.2-1 and spamass-milter
0.4.0-1+b1
I've enabled debugging, and, while I can see spamd working and properly
identifying spam/ham I don't see anything related to header addition, or
message tagging.
Example of logs:
...
Nov 25 07:27:04 bollu spamd[14716]: learn: auto-learn: message score:
18.269, computed score for autolearn: 16.294
Nov 25 07:27:04 bollu spamd[14716]: learn: auto-learn? ham=0.1, spam=12,
body-points=0.001, head-points=16.293, learned-points=3.7
Nov 25 07:27:04 bollu spamd[14716]: learn: auto-learn: autolearn_force not
flagged for a rule. Body Only Points: 0.001 (3 req'd) / Head Only Points:
16.293 (3 req'd)
Nov 25 07:27:04 bollu spamd[14716]: learn: auto-learn? no: scored as spam
but too few body points (0.001 < 3)
Nov 25 07:27:04 bollu spamd[14716]: check: is spam? score=18.269 required=5
Nov 25 07:27:04 bollu spamd[14716]: check:
tests=ADVANCE_FEE_3_NEW,AXB_XMAILER_MIMEOLE_OL_024C2,BAYES_99,BAYES_999,DEAR_BENEFICIARY,FORGED_MUA_OUTLOOK,FROM_MISSP_EH_MATCH,FROM_MISSP_MSFT,FROM_MISSP_PHISH,FROM_MISSP_XPRIO,FSL_CTYPE_WIN1251,FSL_NEW_HELO_USER,MISSING_HEADERS,MSOE_MID_WRONG_CASE,REPLYTO_WITHOUT_TO_CC,TO_NO_BRKTS_FROM_MSSP,T_FILL_THIS_FORM_SHORT,UNPARSEABLE_RELAY,UNWANTED_LANGUAGE_BODY,URIBL_BLOCKED
Nov 25 07:27:04 bollu spamd[14716]: check:
subtests=__ADVANCE_FEE_2_NEW,__ADVANCE_FEE_3_NEW,__AFF_LOTTERY,__ANY_OUTLOOK_MUA,__ANY_TEXT_ATTACH,__ANY_TEXT_ATTACH_DOC,__AXB_MO_OL_024C2,__AXB_XM_OL_024C2,__BENEFICIARY,__BODY_TEXT_LINE,__BODY_TEXT_LINE,__BODY_TEXT_LINE,__CT,__CTE,__CTYPE_CHARSET_QUOTED,__CT_TEXT_PLAIN,__DKIM_DEPENDABLE,__DOS_RCVD_THU,__DOS_RCVD_WED,__ENV_AND_HDR_FROM_MATCH,__FILL_THIS_FORM_LOAN1,__FILL_THIS_FORM_PARTIAL,__FILL_THIS_FORM_PARTIAL,__FILL_THIS_FORM_PARTIAL,__FILL_THIS_FORM_PARTIAL_RAW,__FILL_THIS_FORM_PARTIAL_RAW,__FILL_THIS_FORM_PARTIAL_RAW,__FILL_THIS_FORM_SHORT,__FORGED_OE,__FORM_FRAUD,__FORM_FRAUD_3,__FROM_BANK_LOOSE,__FROM_FULL_NAME,__FROM_MISSPACED,__FROM_MISSP_EH_MATCH,__FROM_MISSP_PHISH,__FROM_MISSP_REPLYTO,__FROM_RUNON,__FROM_RUNON_UNCODED,__FSL_HELO_USER_2,__HAS_ANY_EMAIL,__HAS_DATE,__HAS_FROM,__HAS_MESSAGE_ID,__HAS_MIMEOLE,__HAS_MSGID,__HAS_MSMAIL_PRI,__HAS_RCVD,__HAS_REPLY_TO,__HAS_SUBJECT,__HAS_URI,__HAS_XMAIL,__HAS_X_MAILER,__LCL__ENV_AND_HDR_FROM_MATCH,__LOTTO_RELATED,__MIMEOLE_MS,__MIME_VERSION,__MISSING_REF,__MISSING_REPLY,__MSGID_OK_DIGITS,__MSGID_OK_HOST,__MSOE_MID_WRONG_CASE,__NONEMPTY_BODY,__NOT_SPOOFED,__NO_INR_YES_REF,__OE_MUA,__REPLYTO_EXISTS,__SANE_MSGID,__SUBJ_NOT_SHORT,__TO_NO_ARROWS_R,__TO_NO_BRKTS_FROM_MSSP,__TO_NO_BRKTS_FROM_RUNON,__TO_NO_BRKTS_MSFT,__TVD_MIME_ATT_TP,__UNPARSEABLE_RELAY_COUNT,__URI_MAILTO,__XM_MSOE6,__XM_MS_IN_GENERAL,__XM_OUTLOOK_EXPRESS,__XPRIO,__XPRIO_MINFP,__YOUR_FUND
Nov 25 07:27:04 bollu spamd[14716]: spamd: identified spam (18.3/5.0) for
cyrille:65534 in 0.6 seconds, 4435 bytes.
Nov 25 07:27:04 bollu spamd[14716]: spamd: result: Y 18 -
ADVANCE_FEE_3_NEW,AXB_XMAILER_MIMEOLE_OL_024C2,BAYES_99,BAYES_999,DEAR_BENEFICIARY,FORGED_MUA_OUTLOOK,FROM_MISSP_EH_MATCH,FROM_MISSP_MSFT,FROM_MISSP_PHISH,FROM_MISSP_XPRIO,FSL_CTYPE_WIN1251,FSL_NEW_HELO_USER,MISSING_HEADERS,MSOE_MID_WRONG_CASE,REPLYTO_WITHOUT_TO_CC,TO_NO_BRKTS_FROM_MSSP,T_FILL_THIS_FORM_SHORT,UNPARSEABLE_RELAY,UNWANTED_LANGUAGE_BODY,URIBL_BLOCKED
scantime=0.6,size=4435,user=cyrille,uid=65534,required_score=5.0,rhost=::1,raddr=::1,rport=36368,mid=<20211124140722.7F7D780887CE0@mail.daesangagung.co.id>,bayes=1.000000,autolearn=no
autolearn_force=no
Nov 25 07:27:04 bollu spamd[14716]: check: tagrun - tag DKIMDOMAIN is still
blocking action 0
Nov 25 07:27:04 bollu spamd[14716]: config: copying current conf from
backup
Nov 25 07:27:04 bollu postfix/qmgr[1008]: 31DF9E086E:
from=<info@daesangagung.co.id>, size=4418, nrcpt=1 (queue active)
Nov 25 07:27:04 bollu postfix/smtpd[10172]: disconnect from
mail.daesangagung.co.id[117.54.218.101] ehlo=2 starttls=1 mail=1 rcpt=1
data=1 quit=1 commands=7
Nov 25 07:27:04 bollu dovecot: lmtp(10164): Connect from local
Nov 25 07:27:04 bollu postfix/lmtp[10163]: 31DF9E086E:
to=<foobar@bollu.be>, relay=bollu.be[private/dovecot-lmtp], delay=0.98,
delays=0.97/0/0/0.01, dsn=2.0.0, status=sent (250 2.0.0 <foobar@bollu.be>
mFa9Osg6n2G0JwAAPk7Pew Saved)
Nov 25 07:27:04 bollu dovecot: lmtp(foobar)<10164><mFa9Osg6n2G0JwAAPk7Pew>:
sieve: msgid=<20211124140722.7F7D780887CE0@mail.daesangagung.co.id>: stored
mail into mailbox 'INBOX'
Nov 25 07:27:04 bollu dovecot: lmtp(10164): Disconnect from local: Client
has quit the connection (state=READY)
Nov 25 07:27:04 bollu postfix/qmgr[1008]: 31DF9E086E: removed
Nov 25 07:27:05 bollu spamd[14716]: timing: total 627 ms -
signal_user_changed: 1.75 (0.3%), parse: 1.14 (0.2%),
extract_message_metadata: 38 (6.1%), get_uri_detail_list: 1.14 (0.2%),
tests_pri_-1000: 15 (2.4%), tests_pri_-950: 1.92 (0.3%), tests_pri_-900:
2.3 (0.4%), tests_pri_-400: 23 (3.6%), check_bayes: 20 (3.2%), b_tokenize:
7 (1.1%), b_tok_get_all: 4.9 (0.8%), b_comp_prob: 4.5 (0.7%),
b_tok_touch_all: 0.51 (0.1%), b_finish: 1.55 (0.2%), tests_pri_0: 473
(75.4%), check_dkim_signature: 0.85 (0.1%), check_dkim_adsp: 355 (56.6%),
poll_dns_idle: 312 (49.7%), check_spf: 1.37 (0.2%), check_pyzor: 0.38
(0.1%), tests_pri_500: 11 (1.7%), get_report: 0.60 (0.1%), copy_config: 46
(7.4%)
Eventualy, I can see in my dovecot Maildir that the messages don't have the
X-Spam headers since November 17th.
Additional note: If I run spamassassin from the command line on one of my
received messages, the resulting message has the X-Spam headers
Can someone help me? I have no idea what's going wrong, and no idea how to
troubleshoot further.
Best regards,
--
Cyrille Bollu
Could someone please help me troubleshooting why my spamassassin setup
suddenly stopped adding headers to my messages?
My setup consist of a spamd deamon being called from postfix using
spamass-milter. Spamassassin is supposed to add headers (which it did
properly until recently) which are then used later to filter spams through
the use of dovecot sieve filters.
My platform is a Debian 10, thus spamassassin 3.4.2-1 and spamass-milter
0.4.0-1+b1
I've enabled debugging, and, while I can see spamd working and properly
identifying spam/ham I don't see anything related to header addition, or
message tagging.
Example of logs:
...
Nov 25 07:27:04 bollu spamd[14716]: learn: auto-learn: message score:
18.269, computed score for autolearn: 16.294
Nov 25 07:27:04 bollu spamd[14716]: learn: auto-learn? ham=0.1, spam=12,
body-points=0.001, head-points=16.293, learned-points=3.7
Nov 25 07:27:04 bollu spamd[14716]: learn: auto-learn: autolearn_force not
flagged for a rule. Body Only Points: 0.001 (3 req'd) / Head Only Points:
16.293 (3 req'd)
Nov 25 07:27:04 bollu spamd[14716]: learn: auto-learn? no: scored as spam
but too few body points (0.001 < 3)
Nov 25 07:27:04 bollu spamd[14716]: check: is spam? score=18.269 required=5
Nov 25 07:27:04 bollu spamd[14716]: check:
tests=ADVANCE_FEE_3_NEW,AXB_XMAILER_MIMEOLE_OL_024C2,BAYES_99,BAYES_999,DEAR_BENEFICIARY,FORGED_MUA_OUTLOOK,FROM_MISSP_EH_MATCH,FROM_MISSP_MSFT,FROM_MISSP_PHISH,FROM_MISSP_XPRIO,FSL_CTYPE_WIN1251,FSL_NEW_HELO_USER,MISSING_HEADERS,MSOE_MID_WRONG_CASE,REPLYTO_WITHOUT_TO_CC,TO_NO_BRKTS_FROM_MSSP,T_FILL_THIS_FORM_SHORT,UNPARSEABLE_RELAY,UNWANTED_LANGUAGE_BODY,URIBL_BLOCKED
Nov 25 07:27:04 bollu spamd[14716]: check:
subtests=__ADVANCE_FEE_2_NEW,__ADVANCE_FEE_3_NEW,__AFF_LOTTERY,__ANY_OUTLOOK_MUA,__ANY_TEXT_ATTACH,__ANY_TEXT_ATTACH_DOC,__AXB_MO_OL_024C2,__AXB_XM_OL_024C2,__BENEFICIARY,__BODY_TEXT_LINE,__BODY_TEXT_LINE,__BODY_TEXT_LINE,__CT,__CTE,__CTYPE_CHARSET_QUOTED,__CT_TEXT_PLAIN,__DKIM_DEPENDABLE,__DOS_RCVD_THU,__DOS_RCVD_WED,__ENV_AND_HDR_FROM_MATCH,__FILL_THIS_FORM_LOAN1,__FILL_THIS_FORM_PARTIAL,__FILL_THIS_FORM_PARTIAL,__FILL_THIS_FORM_PARTIAL,__FILL_THIS_FORM_PARTIAL_RAW,__FILL_THIS_FORM_PARTIAL_RAW,__FILL_THIS_FORM_PARTIAL_RAW,__FILL_THIS_FORM_SHORT,__FORGED_OE,__FORM_FRAUD,__FORM_FRAUD_3,__FROM_BANK_LOOSE,__FROM_FULL_NAME,__FROM_MISSPACED,__FROM_MISSP_EH_MATCH,__FROM_MISSP_PHISH,__FROM_MISSP_REPLYTO,__FROM_RUNON,__FROM_RUNON_UNCODED,__FSL_HELO_USER_2,__HAS_ANY_EMAIL,__HAS_DATE,__HAS_FROM,__HAS_MESSAGE_ID,__HAS_MIMEOLE,__HAS_MSGID,__HAS_MSMAIL_PRI,__HAS_RCVD,__HAS_REPLY_TO,__HAS_SUBJECT,__HAS_URI,__HAS_XMAIL,__HAS_X_MAILER,__LCL__ENV_AND_HDR_FROM_MATCH,__LOTTO_RELATED,__MIMEOLE_MS,__MIME_VERSION,__MISSING_REF,__MISSING_REPLY,__MSGID_OK_DIGITS,__MSGID_OK_HOST,__MSOE_MID_WRONG_CASE,__NONEMPTY_BODY,__NOT_SPOOFED,__NO_INR_YES_REF,__OE_MUA,__REPLYTO_EXISTS,__SANE_MSGID,__SUBJ_NOT_SHORT,__TO_NO_ARROWS_R,__TO_NO_BRKTS_FROM_MSSP,__TO_NO_BRKTS_FROM_RUNON,__TO_NO_BRKTS_MSFT,__TVD_MIME_ATT_TP,__UNPARSEABLE_RELAY_COUNT,__URI_MAILTO,__XM_MSOE6,__XM_MS_IN_GENERAL,__XM_OUTLOOK_EXPRESS,__XPRIO,__XPRIO_MINFP,__YOUR_FUND
Nov 25 07:27:04 bollu spamd[14716]: spamd: identified spam (18.3/5.0) for
cyrille:65534 in 0.6 seconds, 4435 bytes.
Nov 25 07:27:04 bollu spamd[14716]: spamd: result: Y 18 -
ADVANCE_FEE_3_NEW,AXB_XMAILER_MIMEOLE_OL_024C2,BAYES_99,BAYES_999,DEAR_BENEFICIARY,FORGED_MUA_OUTLOOK,FROM_MISSP_EH_MATCH,FROM_MISSP_MSFT,FROM_MISSP_PHISH,FROM_MISSP_XPRIO,FSL_CTYPE_WIN1251,FSL_NEW_HELO_USER,MISSING_HEADERS,MSOE_MID_WRONG_CASE,REPLYTO_WITHOUT_TO_CC,TO_NO_BRKTS_FROM_MSSP,T_FILL_THIS_FORM_SHORT,UNPARSEABLE_RELAY,UNWANTED_LANGUAGE_BODY,URIBL_BLOCKED
scantime=0.6,size=4435,user=cyrille,uid=65534,required_score=5.0,rhost=::1,raddr=::1,rport=36368,mid=<20211124140722.7F7D780887CE0@mail.daesangagung.co.id>,bayes=1.000000,autolearn=no
autolearn_force=no
Nov 25 07:27:04 bollu spamd[14716]: check: tagrun - tag DKIMDOMAIN is still
blocking action 0
Nov 25 07:27:04 bollu spamd[14716]: config: copying current conf from
backup
Nov 25 07:27:04 bollu postfix/qmgr[1008]: 31DF9E086E:
from=<info@daesangagung.co.id>, size=4418, nrcpt=1 (queue active)
Nov 25 07:27:04 bollu postfix/smtpd[10172]: disconnect from
mail.daesangagung.co.id[117.54.218.101] ehlo=2 starttls=1 mail=1 rcpt=1
data=1 quit=1 commands=7
Nov 25 07:27:04 bollu dovecot: lmtp(10164): Connect from local
Nov 25 07:27:04 bollu postfix/lmtp[10163]: 31DF9E086E:
to=<foobar@bollu.be>, relay=bollu.be[private/dovecot-lmtp], delay=0.98,
delays=0.97/0/0/0.01, dsn=2.0.0, status=sent (250 2.0.0 <foobar@bollu.be>
mFa9Osg6n2G0JwAAPk7Pew Saved)
Nov 25 07:27:04 bollu dovecot: lmtp(foobar)<10164><mFa9Osg6n2G0JwAAPk7Pew>:
sieve: msgid=<20211124140722.7F7D780887CE0@mail.daesangagung.co.id>: stored
mail into mailbox 'INBOX'
Nov 25 07:27:04 bollu dovecot: lmtp(10164): Disconnect from local: Client
has quit the connection (state=READY)
Nov 25 07:27:04 bollu postfix/qmgr[1008]: 31DF9E086E: removed
Nov 25 07:27:05 bollu spamd[14716]: timing: total 627 ms -
signal_user_changed: 1.75 (0.3%), parse: 1.14 (0.2%),
extract_message_metadata: 38 (6.1%), get_uri_detail_list: 1.14 (0.2%),
tests_pri_-1000: 15 (2.4%), tests_pri_-950: 1.92 (0.3%), tests_pri_-900:
2.3 (0.4%), tests_pri_-400: 23 (3.6%), check_bayes: 20 (3.2%), b_tokenize:
7 (1.1%), b_tok_get_all: 4.9 (0.8%), b_comp_prob: 4.5 (0.7%),
b_tok_touch_all: 0.51 (0.1%), b_finish: 1.55 (0.2%), tests_pri_0: 473
(75.4%), check_dkim_signature: 0.85 (0.1%), check_dkim_adsp: 355 (56.6%),
poll_dns_idle: 312 (49.7%), check_spf: 1.37 (0.2%), check_pyzor: 0.38
(0.1%), tests_pri_500: 11 (1.7%), get_report: 0.60 (0.1%), copy_config: 46
(7.4%)
Eventualy, I can see in my dovecot Maildir that the messages don't have the
X-Spam headers since November 17th.
Additional note: If I run spamassassin from the command line on one of my
received messages, the resulting message has the X-Spam headers
Can someone help me? I have no idea what's going wrong, and no idea how to
troubleshoot further.
Best regards,
--
Cyrille Bollu