http://issues.apache.org/SpamAssassin/show_bug.cgi?id=5356
[EMAIL PROTECTED] changed:
What |Removed |Added
----------------------------------------------------------------------------
Status|NEW |RESOLVED
Resolution| |FIXED
------- Additional Comments From [EMAIL PROTECTED] 2007-08-16 07:47 -------
ok, I've just checked in an implementation... it returns this for a
"spamassassin -D -t < msg" run, for example:
[19933] dbg: timer: total 6506.99 msecs - init: 3133.62 (48.2%), parse: 3.76
(0.1%), extract_message_metadata: 21.25 (0.3%), get_uri_detail_list: 0.69
(0.0%), tests_pri_-1000: 11.86 (0.2%), tests_pri_-950: 4.72 (0.1%),
tests_pri_-900: 5.19 (0.1%), tests_pri_-400: 7.39 (0.1%), tests_pri_0: 3160.55
(48.6%), check_spf: 118.60 (1.8%), check_razor2: 1885.53 (29.0%), check_pyzor:
170.89 (2.6%), tests_pri_500: 89.06 (1.4%), tests_pri_1000: 25.22 (0.4%),
check_awl: 20.16 (0.3%)
Note that some of our timer events are nested inside other timers, so (A) the
percentages won't necessarily add up to 100%, and (B) we can't do that
"accumulated percentage so far" thing. I don't think that's a big loss for the
complexity it'd require -- we'd have to rearrange the timers so that timers
wouldn't overlap, which is messy and would mean that some things would be
un-timeable (let me know if I'm wrong).
currently, in terms of what's instrumented during the main check() loop, it just
instruments the single-threaded network tests like Razor/Pyzor, and each
priority level (rather than rule types *and* priorities, which gets noisy very
fast). (as you can see, that's an example of where two timer scopes are
nested.)
feel free to add in more
my $timer = $self->time_method("event_name");
instrumentation, to catch stuff that's time consuming...
------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.