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

Reply via email to