Parses for TIMING entries?

[Mark Martinec]

> Anybody got a parser for the TIMING entries:
> 
> Jun 10 13:45:46 mail amavis[21530]: (21530-14) TIMING [total 1125 ms]
> - SMTP greeting: 1 (0%)0, SMTP EHLO: 0 (0%)0, SMTP pre-MAIL: 0 (0%)0,
> SMTP pre-DATA-flush: 1 (0%)0, SMTP DATA: 0 (0%)0, check_init: 0 (0%)0,
> digest_hdr: 2 (0%)0, digest_body_dkim: 0 (0%)0, mime_decode: 12 (1%)2,
> get-file-type2: 73 (6%)8, decompose_part: 4 (0%)8, parts_decode: 0
> (0%)8, check_header: 1 (0%)9, AV-scan-1: 31 (3%)11, AV-scan-2: 193
> (17%)28, spam-wb-list: 1 (0%)29, SA parse: 4 (0%)29, SA check: 764
> (68%)97, decide_mail_destiny: 7 (1%)97, notif-quar: 0 (0%)97,
> fwd-connect: 3 (0%)98, fwd-xforward: 0 (0%)98, fwd-mail-pip: 1 (0%)98,
> fwd-rcpt-pip: 0 (0%)98, fwd-data-chkpnt: 0 (0%)98, write-header: 1
> (0%)98, fwd-data-contents: 0 (0%)98, fwd-end-chkpnt: 16 (1%)99,
> prepare-dsn: 0 (0%)99, main_log_entry: 4 (0%)100, update_snmp: 1
> (0%)100, SMTP pre-response: 0 (0%)100, SMTP response: 0 (0%)100,
> unlink-2-files: 0 (0%)100, rundown: 0 (0%)100
> 
> I want to graph these values using gnuplot. Preferrably I wanted to
> put size and TIMING into relation (how do the values change depending
> on the mailsize), but the TIMING line lacks the message size.

Try the attached parser. Adjust the list of required timing field names
in a print near the end of the program. I've hacked it from our more
general (but much uglier) yearly report generator.

As for the size, perhaps the easiest is just to modify the
generation of a TIMING log entry. I've needed it in the past,
it would probably make sense to just have this in the final 2.7.0:


--- amavisd~	2011-05-30 20:15:30.000000000 +0200
+++ amavisd	2011-06-10 14:44:07.000000000 +0200
@@ -19092,7 +19092,5 @@
         };  # end all OK
         $self->{tempdir}->clean;
-        # implicit RSET
-        # do_log(2, "size: %d, %s",
-        #           $msginfo->msg_size, Amavis::Timing::report());
+        my $msg_size = $msginfo->msg_size;
         $sender_unq = $sender_quo = undef; @recips = (); $got_rcpt = 0;
         undef $max_recip_size_limit; undef $msginfo;  # forget previous
@@ -19101,5 +19099,5 @@
         # report elapsed times by section for each transaction
         # (the time for a QUIT remains unaccounted for)
-        do_log(2, "%s", Amavis::Timing::report());
+        do_log(2, "size: %d, %s", $msg_size, Amavis::Timing::report());
         Amavis::Timing::init(); snmp_counters_init();
         $Amavis::last_task_completed_at = Time::HiRes::time;


Mark
-------------- next part --------------
A non-text attachment was scrubbed...
Name: parse-mail-log-timing.pl
Type: application/x-perl
Size: 2933 bytes
Desc: not available
URL: <http://lists.amavis.org/pipermail/amavis-users/attachments/20110610/48cf00d1/attachment.bin>