massively incorrect output from Postfix log?

[Joost van Baal]

Hello Bill,

Thanks a lot for you bugreport!  I've downloaded your log (thanks for
offering that one, it surely helped tracking the problem).

On Sun, Mar 03, 2002 at 06:29:06AM -0600, Bill Bradford wrote:
> 
> The output of pflogsumm shows MUCH more mail having been
> delivered than logreport/lire does.
> 
> Here's the output from pflogsumm (blank lines removed):
> 
> http://mailstats.sunhelp.org/text/postfix-pf-03-03-02.txt
> 
> Grand Totals
> ------------
> messages
<snip>
>   84917k  bytes delivered
<snip>
> 
> and here's the output from lire (extra blank lines removed):
> 
> http://mailstats.sunhelp.org/text/postfix-03-03-02.txt
<snip>
> 
>   Volume Delivered By 1d Period
>    2002-03-03 ........................................... 588.0k
> 
> 
> I'd say that ~84 megabytes (according to pflogsumm) is a LOT
> different than 588k (as reported by lire).

You've hit a bug in Lire.  The problem seems to be related to the '[ID
197553 mail.info]' thingies in your logs.  I believe Lire does not yet
fully support these.  I've hacked the patch below.  This gives

Volume Delivered By 1d Period

2002-03-03 ............................................. 4.9M

from the 2002-03-03 00:06:49 CET - 2002-03-03 06:27:32 CET log you've
uploaded.

However, this is not a final solution.  I'll get to that one tomorrow.
(It's 01:12 am now in my timezone; I'm going to bed...)

A better solution is probably to get rid of the harcoded 6 in

 if (!open IN, "sort -k 6,6 |") {

.

I just commited the patch to our cvs.  So, instead of applying the patch
from this email message, you could also checkout our cvs from sourceforge.

After patching your email/script/postfix2dlf.in from our tarball (or
cvs), you should rerun configure , make and make install.  Please let us
know if you encounter any difficulties with this.

I'll get back to you asap, with a more elegant solution.

----------------------------------------------------------------------

Index: postfix2dlf.in
===================================================================
RCS file: /cvsroot/logreport/service/email/script/postfix2dlf.in,v
retrieving revision 1.24
diff -u -r1.24 postfix2dlf.in
--- postfix2dlf.in      2 Feb 2002 11:27:12 -0000       1.24
+++ postfix2dlf.in      4 Mar 2002 00:04:25 -0000
@@ -28,6 +28,8 @@
 #
 # we should get this thing in Lire::Email .... XXX ...
 #
+# returns 1 if in fact printing, 0 otherwise.
+#
 sub print_dlf
 {
     my $c = shift;
@@ -38,7 +40,13 @@
         lr_warn "$subroutine would want to print dlf " .
          "about ' " . (defined $c->{'queueid'} ? $c->{'queueid'} : '-') . 
             "', but didn't find recipients, skipping";
+        return 0;
+    } elsif ($c->{recipients} < 1) {
+        debug("print_dlf: no recipients, skipping (queueid '" .
+            ( $c->{'queueid'} || "UNDEF" ) . "'\n");
+        return 0;
     } else {
+        debug("print_dlf: nof recipients is '" . $c->{recipients} . "'\n");
        foreach my $i ( 0 .. $c->{recipients} - 1 ) {
            my %dlf = map { $_ => $c->{$_} } 
              qw/time logrelay queueid msgid from_user from_domain 
@@ -48,10 +56,13 @@
            {
                $dlf{$f} = $c->{$f}[$i];
            }
+            debug("print_dlf: qid is '" . $dlf{'queueid'} . "', size is '" .
+              ( $dlf{'size'} || 'UNDEF' ) . "'\n");
            my $dlf = $dlf_maker->( \%dlf );
            print join( " ", @$dlf ), "\n";
            $dlflines++;
        }
+        return 1;
     }
 }
 
@@ -112,7 +123,7 @@
     }
 
     my $tmp;
-    sanitize( 'emailadress', $log->{'to'}, $tmp);
+    sanitize('emailadress', $log->{'to'}, $tmp);
 
     my ($touser, $todomain) = splitemailadress($tmp);
 
@@ -167,6 +178,7 @@
     sanitize('emailadress', $log->{'from'}, $tmp);
     ( $msgs{$qid}{'from_user'}, 
       $msgs{$qid}{'from_domain'}) = splitemailadress($tmp);
+
 }
 
 sub parse_postfix {
@@ -242,12 +254,18 @@
     if ($oldqid and $qid ne $oldqid) {
         # flush it
 
-        debug("parse_postfix: gonna print $oldqid dlf\n");
-        print_dlf( $msgs{$oldqid} );
-        delete $msgs{$oldqid};
+        debug("parse_postfix: gonna call print_dlf for $oldqid dlf, " .
+          "size is '" . ($msgs{$oldqid}{'size'} || 'UNDEF') . "'\n");
+        print_dlf( $msgs{$oldqid} ) and delete $msgs{$oldqid};
     }
 }
 
+#
+# 6th field should be queueid.  however, in logs which look like
+#   'Mar  3 00:07:08 host.example.net postfix/nqmgr[15927]:
+#     [ID 197553 mail.info] 38B08AB33D: .....'
+# this fails .... :(
+#
 if (!open IN, "sort -k 6,6 |") {
     lr_err "stopped: cannot open sort input pipe";
 }


----------------------------------------------------------------------

Thanks again for your bugreport!

Bye,

Joost

-- 
Joost van Baal              . .           http://www.logreport.org/
                           .   .
/^LogReport$/               . .               joostvb at logreport.org

-------------- next part --------------
A non-text attachment was scrubbed...
Name: not available
Type: application/pgp-signature
Size: 189 bytes
Desc: not available
Url : http://lists.logreport.org/pipermail/questions/attachments/20020304/6f1880e0/attachment.bin