Cannot find stalled SpamAssassin rule

[Arrigo Triulzi]

On 24 Feb 2025, at 16:49, Damian <amavis at arcsin.de> wrote:
> Do you see any time gaps between log lines that come before? $sa_debug = 'all' should be useful, too.

Feb 24 15:59:20 bagheera amavis[13497]: (13497-03) Checking: LPn5Uzkc5tXp AM.PDP-SOCK [2607:f8b0:4864:20::a48] <3rX28ZxoKAN4NOREPLY-SMTP-TLS-REPORTINGGOOGLE.COM at smtp-tls-reporting.bounces.google.com> -> <security at alchemistowl.org>
Feb 24 15:59:20 bagheera amavis[13497]: (13497-03) p003 1 Content-Type: multipart/report
Feb 24 15:59:20 bagheera amavis[13497]: (13497-03) p001 1/1 Content-Type: text/plain, 7bit, size: 48, SHA1 digest: 80ecdc0cedc76cbcf1ff9903aaba3671c53fa4d2
Feb 24 15:59:20 bagheera amavis[13497]: (13497-03) p002 1/2 Content-Type: application/tlsrpt+gzip, base64, size: 333, SHA1 digest: e79a6d9439092a9e46f5be907d1c3556d0a4642f, name: google.com!alchemistowl.org!1740268800!1740355199!001.json.gz

Feb 24 16:04:21 bagheera amavis[13497]: (13497-03) _WARN: bayes: expire_old_tokens: __alarm__ignore__(154/::Plugin::Check::run_eval_tests/1028)
Feb 24 16:04:21 bagheera amavis[13497]: (13497-03) SA info: check: exceeded time limit in Mail::SpamAssassin::Plugin::Check::_eval_tests_type11_prineg90_set3, skipping further tests
Feb 24 16:04:21 bagheera amavis[13497]: (13497-03) _WARN: Use of uninitialized value $score in numeric ge (>=) at /usr/local/libdata/perl5/site_perl/Mail/SpamAssassin/PerMsgStatus.pm line 482.
Feb 24 16:04:21 bagheera amavis[13497]: (13497-03) _WARN: Use of uninitialized value $score in numeric le (<=) at /usr/local/libdata/perl5/site_perl/Mail/SpamAssassin/PerMsgStatus.pm line 482.
Feb 24 16:04:21 bagheera amavis[13497]: (13497-03) _WARN: Use of uninitialized value $score in sprintf at /usr/local/libdata/perl5/site_perl/Mail/SpamAssassin/PerMsgStatus.pm line 485.
Feb 24 16:04:21 bagheera amavis[13497]: (13497-03) Passed CLEAN {AcceptedInbound}, AM.PDP-SOCK [2607:f8b0:4864:20::a48] [2607:f8b0:4864:20::a48] <3rX28ZxoKAN4NOREPLY-SMTP-TLS-REPORTINGGOOGLE.COM at smtp-tls-reporting.bounces.google.com> -> <security at alchemistowl.org>, Queue-ID: 51OFxJhE047564, Message-ID: <67bc7dad.050a0220.314da7.bfb7tls at google.com>, mail_id: LPn5Uzkc5tXp, Hits: -7.6, size: 3968, 300903 ms
Feb 24 16:04:21 bagheera amavis[13497]: (13497-03) TIMING-SA total 300077 ms - parse: 7 (0.0%), extract_message_metadata: 14 (0.0%), tests_pri_-10000: 8 (0.0%), get_uri_detail_list: 3.5 (0.0%), tests_pri_-2000: 6 (0.0%), tests_pri_-1000: 6 (0.0%), tests_pri_-950: 2.7 (0.0%), tests_pri_-900: 2.6 (0.0%), tests_pri_-100: 1978 (0.7%), check_spf: 450 (0.2%), poll_dns_idle: 379 (0.1%), check_dkim_signature: 32 (0.0%), tests_pri_-90: 298012 (99.3%), check_bayes: 298009 (99.3%), b_tokenize: 13 (0.0%), b_tok_get_all: 15 (0.0%), b_comp_prob: 8 (0.0%), b_tok_touch_all: 1.41 (0.0%), b_finish: 297965 (99.3%), expire_bayes: 297910 (99.3%), get_report: 1.68 (0.0%)
Feb 24 16:04:21 bagheera amavis[13497]: (13497-03) size: 3968, TIMING [total 300912 ms] - got data: 0.0 (0%)0, check_init: 3.9 (0%)0, digest_hdr: 1.4 (0%)0, digest_body: 0.4 (0%)0, collect_info: 3.7 (0%)0, mkdir parts: 3.0 (0%)0, mime_decode: 30 (0%)0, get-file-type2: 270 (0%)0, decompose_part: 163 (0%)0, get-file-type1: 245 (0%)0, parts_decode: 0.8 (0%)0, check_header: 2.7 (0%)0, AV-scan-1: 63 (0%)0, spam-wb-list: 3.6 (0%)0, SA msg read: 2.0 (0%)0, SA parse: 11 (0%)0, SA check: 300060 (100%)100, decide_mail_destiny: 21 (0%)100, notif-quar: 1.1 (0%)100, prepare-dsn: 3.3 (0%)100, report: 3.3 (0%)100, main_log_entry: 11 (0%)100, update_snmp: 3.2 (0%)100, rundown: 3.7 (0%)100

There’s a good 5 minutes between the MIME separation and the warning…  I’ll turn on $sa_debug.