smeserver-qpsmtpd/root/usr/local/bin/qplogsumm.pl

#!/usr/bin/perl
#

=pod

=head1 SUMMARY

Works with multilog to analyse and summarise log entries generated by the logterse plugin.  It is designed
to be invoked by multilog at log-rotation time.  This is specified by an argument to multilog similar to:

=over 4

multilog t !/path/to/qplogsumm ./main

=back

When qplogsumm is invoked, each line will be echoed, meaning the stored log is unchanged, but summary
information will be written to fd 5 and so stored in the 'state' file by multilog.

This file is fed in on fd 4 at the beginning of the next log rotation, so running totals, etc can be maintained.

=head1 State file format:

One entry per line containing three fields separated by whitespace:

=over 4

=item 1. Disposition (plugin) name.

=item 2. tai64n timestamp recording the first time it was seen in a log.

=item 3. long-term running total.

=back

A disposition is effectively the plugin name that called DENY or the string 'queued' for
messages that made it through.

A line containing a disposition name of LOGFILE_EPOCH and a timestamp for the earliest known log entry.

Other derived data, such as percentages etc. can also appear in the file, commented
by a # character.  This will be ignored on the next intake.

=head1 AUTHOR

Charles Butcher

=head1 VERSION

This is release 1.0

=cut

use strict;
use POSIX qw(strftime);


my $FS = "\t";	# field separator used by logterse plugin
my %disp;   	# hash of dispositions

if (open PREVIOUS, "<&4")
{
    while (<PREVIOUS>)
    {
	chomp();
	next if m/^#/;
	next if m/^\s*$/;
	my ($plug_name, $plug_epoch, $plug_cumulative) = split /\s+/;
	my $c = { epoch => $plug_epoch, cum => $plug_cumulative, curr => 0 };
	$disp{$plug_name} = $c;
    }

    close PREVIOUS;
}

my $first_timestamp = 0;
my $last_timestamp  = 0;


while (<>)
{
    print;
    chomp;
    next unless m/terse plugin/;

    my ($timestamp_part, $log_part) = split '`';
    my ($current_timestamp) = split /\s/, $timestamp_part;
    $first_timestamp = $current_timestamp unless $first_timestamp;
    $last_timestamp = $current_timestamp;

    my (@log_items) = split $FS, $log_part;
    my $disposition = $log_items[5];
    next unless defined $disposition;
    
    if ($disp{$disposition})
    {
	$disp{$disposition}->{curr} += 1;
    }
    else  # a new plugin -- make a note of when it first appeared
    {
	my $c = { epoch => $current_timestamp, cum => 0, curr => 1 };
	$disp{$disposition} = $c;
    }
}


#
# Set overall epoch
#
if (!exists $disp{'LOGFILE_EPOCH'})
{
    my $c = { epoch => $first_timestamp, cum => 0, curr => 0};
    $disp{'LOGFILE_EPOCH'} = $c;
}

my $current_total    = 0;
my $cumulative_total = 0;

open HOLDOVER, ">&5" and select HOLDOVER;

#
# Output cumulative values for intake the next time a log is processed
#
for my $c (keys %disp)
{
    $disp{$c}->{cum} += $disp{$c}->{curr};
    $current_total += $disp{$c}->{curr};
    $cumulative_total += $disp{$c}->{cum};

    printf "%-30.30s %s %12d\n", $c, $disp{$c}->{epoch}, $disp{$c}->{cum};
}

#
# Output current logfile stats
#

my $current_elapsed = tai64diff($last_timestamp, $first_timestamp);
exit 0 if ($current_elapsed == 0);

printf "#
# Most recent logfile
# -------------------
#
# Start  : %s
# Finish : %s
# Elapsed: %s
#
# Total transactions : %9d
# Average tx per hour: %9d
",
    tai64utc($first_timestamp),
    tai64utc($last_timestamp),
    seconds_to_days($current_elapsed),
    $current_total,
    $current_total / ($current_elapsed / 3600),
    ;

#
# Output cumulative log stats
#
my $cumulative_elapsed = tai64diff($last_timestamp, $disp{'LOGFILE_EPOCH'}->{epoch});

printf "#
# Cumulative Totals
# -----------------
#
# Start  : %s
# Finish : %s
# Elapsed: %s
#
# Total transactions : %12d
# Average tx per hour: %12d
",
    tai64utc($disp{'LOGFILE_EPOCH'}->{epoch}),
    tai64utc($last_timestamp),
    seconds_to_days($cumulative_elapsed),
    $cumulative_total,
    $cumulative_total / ($cumulative_elapsed / 3600),
    ;


# 
# Output per-plugin stats
#

print "#
#                                 Most Recent Logfile      Cumulative Totals
# Disposition (plugin)            Total       Avg/Day      Total       Avg/Day
# ----------------------------------------------------------------------------\n"; 

my $printf_format = "# %-30.30s %6d %3d%% %8d %10d %3d%% %8d\n";

foreach my $c (sort { $disp{$b}->{curr} <=> $disp{$a}->{curr} } keys %disp)
{
    next if ($c eq 'LOGFILE_EPOCH');

    printf $printf_format, 
    $c,
    $disp{$c}->{curr},
    $disp{$c}->{curr} / $current_total * 100,
    $disp{$c}->{curr} / ($current_elapsed / 86400),
    $disp{$c}->{cum},
    $disp{$c}->{cum} / $cumulative_total * 100,
    $disp{$c}->{cum} / (tai64diff($last_timestamp, $disp{$c}->{epoch}) / 86400),
    ;
}

print "# ----------------------------------------------------------------------------\n";
printf $printf_format, 
    'TOTALS',
    $current_total,
    100,
    $current_total / ($current_elapsed / 86400),
    $cumulative_total,
    100,
    $cumulative_total / ($cumulative_elapsed / 86400),
    ;

exit 0;


sub tai64utc {
    my ($s) = @_;

    # @400000003f6c7bc5253bf98c
    # 0123456789012345678901234
    # 0         1         2
    #   |-------------||------|
    if (substr($s, 0, 2) eq '@4') {
        my $ts = hex(substr($s, 2, 15));
        $s = strftime('%Y-%m-%d %H:%M:%S', gmtime($ts));
    }
    return $s;
}

#
# Return difference in seconds
#
sub tai64diff
{
    my ($s1, $s2) = @_;

    # @400000003f6c7bc5253bf98c
    # 0123456789012345678901234
    # 0         1         2
    #   |-------------||------|
    if (substr($s1, 0, 2) eq '@4' and substr($s2, 0, 2) eq '@4')
    {
        my $ts1 = hex(substr($s1, 2, 15));
        my $ts2 = hex(substr($s2, 2, 15));
	return $ts1 - $ts2;
    }
    else
    {
	return 0;
    }
}


#
# Return an english phrase representing a number of seconds
#
sub seconds_to_days
{
    my ($secs) = @_;

    my $phrase = sprintf "%d days, ", ($secs / 86400);
    $secs %= 86400;
    $phrase .= sprintf "%d hours, ", ($secs / 3600);
    $secs %= 3600;
    $phrase .= sprintf "%d mins, %d secs", ($secs / 60), ($secs % 60);
}