Replies... some duplication of conversation on "mimedefang".
> On Nov 15, 2021, at 10:34 PM, Bill Cole > <sausers-20150...@billmail.scconsult.com> wrote: > > On 2021-11-15 at 18:08:20 UTC-0500 (Mon, 15 Nov 2021 16:08:20 -0700) > Philip Prindeville <philipp_s...@redfish-solutions.com> > is rumored to have said: > >>> On Nov 12, 2021, at 8:49 PM, John Hardin <jhar...@impsec.org> wrote: >>> >>> On Fri, 12 Nov 2021, Philip Prindeville wrote: >>> >>>> I got the message, saved it to a flat file, and ran "spamassassin -t -D >>>> rules < netdev.eml" and saw: >>>> >>>> ... >>>> Nov 12 11:45:38.048 [36367] dbg: rules: ran eval rule >>>> __ANY_TEXT_ATTACH_DOC ======> got hit (1) >>>> ... >>>> Nov 12 11:45:38.063 [36367] dbg: rules: ran eval rule __ANY_TEXT_ATTACH >>>> ======> got hit (1) >>>> Nov 12 11:49:58.565 [36367] info: check: exceeded time limit in >>>> Mail::SpamAssassin::Plugin::Check::_eval_tests_type11_pri0_set1, skipping >>>> further tests >>>> ... >>>> >>>> Am I correct that __ANY_TEXT_ATTACH alone took 4:30s? >>> >>> "ran ... got hit" is past tense. And it needs to complete the rule to know >>> whether it got a hit. >>> >>> 11:45:38.048 -> 11:45:38.063 = less than 20 msec. >>> >>> The next rule, whatever that was, is the one that timed out after 4m20s. >> >> >> Ah, the rule _eval_tests_type11_pri0_set1() took 4:20. >> >> Why can't I even find the rule? > > That "rule" is actually a subroutine that is assembled and named at runtime > in M:SA:Check from set 1 (probably the only set) of the "body eval" (type 11) > rules running at priority 0. Yeah, if we can get the source file and line # that's almost as good as a function name (since there isn't one, if it's an anonymous sub block). > > Which suggests a tough bit of troubleshooting. > >>>> Could there be rules that *aren't* matching but are taking a while? >>> >>> It's timing out on a rule that's running away. The timeout triggers before >>> "hit/no hit" is known. >>> >>> What would be helpful here would be logging of when a rule *starts* >>> evaluation. Normally that would be painful, but for tracking a runaway it >>> would be useful. Perhaps I can code up something to capture that and log it >>> on a timeout... >> >> >> Whenever a rule gets started, you could save the name and start time, and >> then burp that during timeout handling, right? > > I like that idea. I have no idea how feasible it is. Me neither. I use Perl less and less everyday, and my fu is fading almost as fast as new features are coming in. -Philip