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

273 lines
6.0 KiB
Perl

#!/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);
}