On Saturday February 17 2007 03:01, Quinn Comendant wrote:
> How about an extensive statistics reporting tool, ..., that
> can show how well a current spamassassin installation is performing
> and where it needs improvements.

Well, not exactly by your words, but in the same spirit,
this time belonging to SA itsef:

Instrument SA with a couple of performance measuring probes,
providing some easier way to spot where bottlenecks lie.
Just something simple enough to tell, look, currently waiting
for Razor server response (or some RBL) is taking 80% of
elapsed time. Or, Bayes db is very sluggish, it is taking
5 seconds to provide a result.

A timing breakdown by subtasks is not that much work to provide,
but provides great insight into troubleshooting and performance
improvements.

Here is an example of a timing breakdown as currently provided
in the log (at log level 2) by amavisd-new, without getting into
specific details, except to say the numbers are elapsed time
for each subtask in milliseconds (and in percents, just for the
section, and then a cumulative percent of all sections so far):

TIMING [total 1840 ms] - SMTP pre-DATA-flush: 4 (0%)0, SMTP DATA: 95 (5%)5, 
check_init: 1 (0%)5, sql-enter: 69 (4%)9, mime_decode: 16 (1%)10,
get-file-type2: 26 (1%)11, parts_decode: 1 (0%)12, check_header: 3 (0%)12, 
AV-scan-1: 14 (1%)12, AV-scan-2: 20 (1%)14, spam-wb-list: 5 (0%)14,
SA call: 1517 (82%)96, update_cache: 3 (0%)97, decide_mail_destiny: 6 (0%)97,
^^^^^^^^^^^^^^^^^^^^^
write-header: 15 (1%)98, save-to-local-mailbox: 1 (0%)98,
prepare-dsn: 3 (0%)98, main_log_entry: 12 (1%)99, sql-update: 20 (1%)100,
update_snmp: 2 (0%)100, SMTP pre-response: 1 (0%)100, SMTP response: 1 (0%)
100, unlink-2-files: 1 (0%)100, rundown: 0 (0%)100

It tells at a glance that message checking and I/O for this particular
message took 1840 ms in total, that receiving a message over SMTP
for example took 5% of this, virus scaners were very quick (14 and 20 ms),
and SA call took 1517 ms, which is (82%) of all elapsed time,
all sections up to SA (cumulative) took 96% of total elapsed time.

Now, something of this relatively simple timing breakdown, but
drilled down into a SA call, telling the administrator where is it
worth spending his effort, or why all a sudden SA takes 10 seconds
instead of the usual 2.

  Mark

Reply via email to