Perl Notes/processing time.pl
From Federal Burro of Information
Jump to navigationJump to search
Mail processing time , for postfix logs.
Non streaming version.
cat /var/log/maillog to this and it makes a report sorted by start time.
#!/usr/bin/perl -w
use strict;
use Time::Local;
use Data::Dumper;
my $DEBUG = 1;
# This script will tell you how long each message took to process so that you can figure out what's taking so long.
# Mar 18 04:02:33 amazon postfix/smtpd[6001]: D675E1E4184: client=esa-annu.mail.domain.ca[131.104.91.36]
# Mar 18 04:02:33 amazon postfix/cleanup[29358]: D675E1E4184: message-id=<702030269448694818992@LENOVO-3C887B0D>
# Mar 18 04:02:33 amazon postfix/qmgr[17756]: D675E1E4184: from=<mail@prophecy.info>, size=22995, nrcpt=1 (queue active)
# Mar 18 04:02:36 amazon postfix/smtp[9802]: D675E1E4184: to=<jonesth@domain.ca>, orig_to=<thomas.jones@domain2.ca>, relay=127.0.0.1[127.0.0.1]:10024, delay=2.7, delays=0.06/0/0.07/2.5, dsn=2.0.0, status=sent (250 2.0.0 Ok, id=08738-03, from MTA([127.0.0.
]:10025): 250 2.0.0 Ok: queued as 6FEE71E418E)
# Mar 18 04:02:36 amazon postfix/qmgr[17756]: D675E1E4184: removed
my %month = ( 'Jan' => '0', 'Feb' => '1', 'Mar' => '2', 'Apr' => '3', 'May' => '4', 'Jun' => '5', 'Jul' => '6', 'Aug' => '7', 'Sep' => '8', 'Oct' => '9', 'Nov' => '10', 'Dec' => '11' );
# Woo dirty!
my $year = "2012";
my %messages ;
my %noqueue;
my $total = 0;
my $failed = 0 ;
my $parsed = 0 ; # log lines
my $parsedmess = 0 ; # parsed messages
while (<>) {
chop;
$total++;
if ( /(\w+)\s+(\d+)\s+(\d{2}):(\d{2}):(\d{2})\s+(\S+)\s(\S+)\s+(\S+):\s+(.*)$/ ) {
# Month day hh: mm: ss host process messid mess
$DEBUG && print $_."\n";
my $mon = '';
my $day = '';
my $hour = '';
my $min = '';
my $sec = '';
my $host = '';
my $process = '';
my $messid ='';
my $mess = '';
# A log line!
$mon = $1; $day = $2;
$hour = $3; $min = $4; $sec = $5;
$host = $6; $process = $7; $messid = $8; $mess = $9;
$parsed++;
# $DEBUG && print "Mon $mon Day $day Hour $hour Min $min Sec $sec Host $host Process $process ID $messid Message $mess\n";
my $epoch = timelocal($sec,$min,$hour,$day,$month{$mon},$year);
# $DEBUG && print "Epoch $epoch Time ".localtime($epoch)."\n";
if ( /NOQUEUE/ ) {
$noqueue{$messid} = $_;
next;
}
if ( $messages{$messid}->{'start'} && $mess =~ /removed/ ) {
$messages{$messid}->{'elapsed'} = $epoch - $messages{$messid}->{'start'};
$DEBUG && print "End of message $messid elapsed: $messages{$messid}->{'elapsed'}\n";
$parsedmess++;
}
if ( ! $messages{$messid}->{'start'} ) {
$messages{$messid}->{'start'} = $epoch;
$DEBUG && print "Start of message $messid\n";
} else {
print "message messid defined \n";
print Dumper($messages{$messid});
}
# $DEBUG && print "Adding message line to messag record\n";
$messages{$messid}->{'body'} .= $_."\n";
} elsif ( /(\w+)\s+(\d+)\s+(\d{2}):(\d{2}):(\d{2})\s+(\S+):\sconnect\sfrom/ ) {
# Mar 18 04:02:14 amazon postfix/smtpd[10247]: connect from localhost.localdomain[127.0.0.1]
#$DEBUG && print "CONNECT: ".$_ ."\n";
} else {
$failed++;
#$DEBUG && print "FAILED: ". $_."\n"
}
}
print "##################################################\n";
print "Total $total\nparsed lines $parsed\nFailed $failed\n";
print "Parsed messages $parsedmess\n";
print "##################################################\n";
foreach my $value ( keys %messages) {
if ( ! defined $messages{$value}->{'start'} ) { delete $messages{$value};}
if ( $messages{$value} && ! defined ( $messages{$value}->{'elapsed'} ) ) { delete $messages{$value};}
}
print "Value Message\n";
foreach my $value (sort {$messages{$a}->{'start'} <=> $messages{$b}->{'start'} } keys %messages)
{
if ( $messages{$value}->{'start'} && $messages{$value}->{'elapsed'} ) {
print "$messages{$value}->{'start'} $messages{$value}->{'elapsed'}\n";
# print $messages{$value};
}
}
print Dumper(%noqueue);
streaming version:
tail -F /var/log/maillog and whatch whats up on you mail server in real-time.
#!/usr/bin/perl -w
use strict;
use Time::Local;
use Data::Dumper;
my $DEBUG = 1;
# This script will tell you how long each message took to process so that you can figure out what's taking so long.
# Mar 18 04:02:33 amazon postfix/smtpd[6001]: D675E1E4184: client=esa-annu.mail.domain.ca[131.104.91.36]
# Mar 18 04:02:33 amazon postfix/cleanup[29358]: D675E1E4184: message-id=<702030269448694818992@LENOVO-3C887B0D>
# Mar 18 04:02:33 amazon postfix/qmgr[17756]: D675E1E4184: from=<mail@prophecy.info>, size=22995, nrcpt=1 (queue active)
# Mar 18 04:02:36 amazon postfix/smtp[9802]: D675E1E4184: to=<jonesth@domain.ca>, orig_to=<thomas.jones@domain2.ca>, relay=127.0.0.1[127.0.0.1]:10024, delay=2.7, delays=0.06/0/0.07/2.5, dsn=2.0.0, status=sent (250 2.0.0 Ok, id=08738-03, from MTA([127.0.0.
]:10025): 250 2.0.0 Ok: queued as 6FEE71E418E)
# Mar 18 04:02:36 amazon postfix/qmgr[17756]: D675E1E4184: removed
my %month = ( 'Jan' => '0', 'Feb' => '1', 'Mar' => '2', 'Apr' => '3', 'May' => '4', 'Jun' => '5', 'Jul' => '6', 'Aug' => '7', 'Sep' => '8', 'Oct' => '9', 'Nov' => '10', 'Dec' => '11' );
# Woo dirty!
my $year = "2012";
my %messages ;
my %noqueue;
my $total = 0;
my $failed = 0 ;
my $parsed = 0 ; # log lines
my $parsedmess = 0 ; # parsed messages
while (<>) {
chop;
$total++;
if ( /(\w+)\s+(\d+)\s+(\d{2}):(\d{2}):(\d{2})\s+(\S+)\s(\S+)\s+(\S+):\s+(.*)$/ ) {
# Month day hh: mm: ss host process messid mess
# $DEBUG && print $_."\n";
my $mon = '';
my $day = '';
my $hour = '';
my $min = '';
my $sec = '';
my $host = '';
my $process = '';
my $messid ='';
my $mess = '';
# A log line!
$mon = $1; $day = $2;
$hour = $3; $min = $4; $sec = $5;
$host = $6; $process = $7; $messid = $8; $mess = $9;
$parsed++;
# $DEBUG && print "Mon $mon Day $day Hour $hour Min $min Sec $sec Host $host Process $process ID $messid Message $mess\n";
my $epoch = timelocal($sec,$min,$hour,$day,$month{$mon},$year);
# $DEBUG && print "Epoch $epoch Time ".localtime($epoch)."\n";
if ( /NOQUEUE/ ) {
$noqueue{$messid} = $_;
next;
}
if ( $messages{$messid}->{'start'} && $mess =~ /removed/ ) {
$messages{$messid}->{'elapsed'} = $epoch - $messages{$messid}->{'start'};
# $DEBUG && print "End of message $messid elapsed: $messages{$messid}->{'elapsed'}\n";
print $messages{$messid}->{'start'} . " " . $messages{$messid}->{'elapsed'} ." " . keys( %messages ). "\n";
delete $messages{$messid} ;
$parsedmess++;
}
if ( ! $messages{$messid}->{'start'} ) {
$messages{$messid}->{'start'} = $epoch;
# $DEBUG && print "Start of message $messid\n";
}
# $DEBUG && print "Adding message line to messag record\n";
# $messages{$messid}->{'body'} .= $_."\n";
} elsif ( /(\w+)\s+(\d+)\s+(\d{2}):(\d{2}):(\d{2})\s+(\S+):\sconnect\sfrom/ ) {
# Mar 18 04:02:14 amazon postfix/smtpd[10247]: connect from localhost.localdomain[127.0.0.1]
$DEBUG && print "CONNECT: ".$_ ."\n";
print ".\n";
} else {
$failed++;
#$DEBUG && print "FAILED: ". $_."\n"
# print "F $_\n";
}
}
