#!/usr/bin/perl -w ############################################################################## # File : MPSStatistics.pl # Description: Generate statistics for Intel(R) Management Presence Server # by parsing it's log file. # Copyright (C) Intel Corporation, 2006 - 2018. ############################################################################## use strict; use Time::Local; use Switch; # definitions my $TRUE = 1; my $FALSE = 0; # Header regular expression my $DAY_RE = '(Sun|Mon|Tue|Wed|Thu|Fri|Sat)'; my $MONTH_RE = '(Jan|Feb|Mar|Apr|May|Jun|Jul|Aug|Sep|Oct|Nov|Dec)'; my $M_DAY_RE = '(\d\d)'; my $YEAR_RE = '(\d+)'; my $TIME_RE = '(\d\d):(\d\d):(\d\d)\.\d{6}'; # Log type (ERROR|INFO|WARNING) regular expression my $ERROR_RE = 'LM_ERROR'; my $INFO_RE = 'LM_INFO'; my $WARNING_RE = 'LM_WARNING'; # Messages RE - LM_INFO my $MPS_START_RE = 'Management Presence Server has started'; # my $NEW_AMT_CONNECTION_RE = 'Intel remote client (.*) is now connected'; # my $AMT_DISCONECTED_RE = '\[(.*)\] Intel remote client has disconnected'; # my $PORT_FW_RE = 'Intel remote client (.*) started port forwarding to address'; # my $AUTH_FAIL_RE = '\[(.*)\] Failed to authenticate Intel remote client'; # my $BLOCKED_UDP_RE = '\[(.*)\] Did not send UDP to (.*) - not in filter list'; # my $BLOCKED_TCP_RE = '\[(.*)\] Did not send TCP to (.*) - not in filter list';# my $NEW_CHANNEL_RE = 'Channel between Intel remote client (.*) and managment-console (.*) opened'; # my $CHANNEL_CLOSE_RE = 'Channel between Intel remote client (.*) and managment-console (.*) closed.';# my $CHANNEL_CLOSE_UNEXPECT_RE = 'Managment-Console has shutdown unexpectedly'; # my $CHANNEL_SHUTDOWN_RE = 'Managment-Console has shutdown'; my $AMT_DISCONECTED_UNEXPECT_RE = 'Intel remote client has shutdown unexpectedly'; # # Messages RE - LM_WARNING my $READ_SOCKS_FAIL_RE = 'Failed to read SOCKS version message'; my $UNSUPPORTED_SOCKS_RE = 'Received unsupported SOCKS connection message'; my $SEND_SOCKS_FAIL_RE = 'Failed to send SOCKS version message'; my $SEND_SOCKS_NOTIFICATION_PORT_FW_FAIL_RE = 'Failed to send SOAP notification upon new port forwarding'; my $UNSUPPORTED_APF_RE = 'Unsupported APF version'; my $SEND_SOCKS_NOTIFICATION_PORT_FW_CANCEL_FAIL_RE = 'Failed to send SOAP notification on port forwarding cancellation'; my $SEND_UDP_FAIL_RE = 'Intel remote client failed to send UDP message to'; my $REJECT_CONN_REQUEST_RE = 'Intel remote client rejected connection request'; my $INVALID_SRV_DATA_RE = 'Invalid server data'; my $SOCKS_AUTH_FAIL_ERROR_RE = 'SOCKS authentication failed error'; #Lists for saving the events my @UUIDs; # UUIDs connection list my @AMT_AUTH_FAIL; # AMT Authentication failure my @SOCKS_AUTH_FAIL;# Socks Authentication failure my @PORT_FW; # Port forwarding my @BLOCKED_UDP;# Blocked UDP list my @BLOCKED_TCP;# Blocked TCP list my @OPEN_CHANNELS; # new Channels my @CLOSE_CHANNELS; # closed Channels #Counters my ($nTunnelsOpen, $nTunnelsClose,$nChannelsOpen, $nChannelsClose) = (0,0,0,0); my ($nAMTAuthFailure, $nSocksAuthFailure, $nBlockedUDP, $nBlockedTCP) = (0,0,0,0); my ($nConnErrors, $nGeneralError) = (0,0); ############################################################################### # Main starts here ############################################################################### # Read arguments from the command line. if ( ($#ARGV != 2) || ($ARGV[1] < 0) || ($ARGV[2] < 0) ) { usage(); exit(1); } my ($logFileName, $hoursToStat, $minutesToStat) = ($ARGV[0], $ARGV[1], $ARGV[2]); my ($endTime,$curTime); my ($finishedWithFirstFile,$finishedMaxFileSearch,$setEndTime,$finished) = ($FALSE,$FALSE,$FALSE,$FALSE); my ($line,$file,@files,$time, $i); my $totalSeconds = $hoursToStat*3600+$minutesToStat*60; #3600 seconds in an hour my $nextLogIndex = 1; my $latestFileIndex = 0; my $maxFileIndex = 0; my $maxTime = 0; my $fullLogFileName = $logFileName; while ($finished == $FALSE) { open(FILE, "<$fullLogFileName") || die "Failed to open log file: $fullLogFileName"; my $i=0; my @lines = reverse ; foreach $line (@lines) { chomp $line; $i++; # Parse the header section: for example: [Fri Apr 18 2008 11:45:45.202000] my %header; #($day, $month, $m_day, $year, $hour, $min, $sec); if ($line =~ s/\[$DAY_RE $MONTH_RE $M_DAY_RE $YEAR_RE $TIME_RE\]//i) { %header = ( 'day' => $1, 'month' => $2, 'm_day' => $3, 'year' => $4, 'hour' => $5, 'min' => $6, 'sec' => $7); if ( $setEndTime == $FALSE ) { # set the END time (that is, the latest operation of the MPS) $endTime = timelocal($7, $6, $5, $3, strMonth2numMonth($2), $4); $setEndTime = $TRUE; } $curTime = timelocal($7, $6, $5, $3, strMonth2numMonth($2), $4); if ( ($endTime - $curTime) >= $totalSeconds ) { $finished = $TRUE; last; } } else { next; } # If reached MPS start line, than finished its run if ($line =~ s/$MPS_START_RE//i) { $totalSeconds = $endTime - $curTime; #trace how much time we checked $finished = $TRUE; last; } # Get this line type (error|info|warning) if ($line =~ s/\[$ERROR_RE\]//i) { handle_error($line, \%header); } elsif ($line =~ s/\[$INFO_RE\]//i) { handle_info($line,\%header) } elsif ($line =~ s/\[$WARNING_RE\]//i) { handle_warning($line,\%header); } } if ($finished == $FALSE) { if ($finishedWithFirstFile == $FALSE) { $finishedWithFirstFile = $TRUE; #find most updated file after the first file. @files = <$fullLogFileName.*>; $maxFileIndex = scalar(@files); # perhaps there are no more files to read! In that case, finish. if ($maxFileIndex != 0) { $i = 1; foreach $file (@files) { open(FILE, "<$file") || die "Failed to open log file: $file"; while ($line = ) { if ($line =~ s/\[$DAY_RE $MONTH_RE $M_DAY_RE $YEAR_RE $TIME_RE\]//i) { $time = timelocal($7, $6, $5, $3, strMonth2numMonth($2), $4); if ($time > $maxTime) { $maxTime = $time; $latestFileIndex = $i; last; # found a line with time, can pass to next file. } else { # at least one of the previous files had larger time. therefore all the next files will have lower times than previous files. $finishedMaxFileSearch = $TRUE; } } else { next; } } if ($finishedMaxFileSearch == $TRUE) { last; } $i++; } $nextLogIndex = $latestFileIndex; } else { $totalSeconds = $endTime - $curTime; #trace how much time we checked $finished = $TRUE; } } else { --$nextLogIndex; if ($nextLogIndex == $latestFileIndex) #We're in a loop!!! No start of MPS can be found, and everything happened below the specified time length ==> Finish { $finished = $TRUE; $totalSeconds = $endTime - $curTime; #trace how much time we checked } elsif ($nextLogIndex < 1) { $nextLogIndex = $maxFileIndex; } } $fullLogFileName = "$logFileName.$nextLogIndex"; } } print_statistics($totalSeconds/3600); ############################################################################### # Convert a month name in string format to its numerical format (month 0 is January) ############################################################################### sub strMonth2numMonth { use Switch; my $strMonth = shift; my $ret = '-1'; switch ($strMonth) { case 'Jan' { $ret = 0; } case 'Feb' { $ret = 1; } case 'Mar' { $ret = 2; } case 'Apr' { $ret = 3; } case 'May' { $ret = 4; } case 'Jun' { $ret = 5; } case 'Jul' { $ret = 6; } case 'Aug' { $ret = 7; } case 'Sep' { $ret = 8; } case 'Oct' { $ret = 9; } case 'Nov' { $ret = 10; } case 'Dec' { $ret = 11; } } return $ret; } ############################################################################### # Handle Error message ############################################################################### sub usage { print "MPSStatistics.pl "; } ############################################################################### # Handle Error message ############################################################################### sub handle_error { my $line = shift; my $head_ref = shift; my $line_time = "$head_ref->{day} $head_ref->{month} $head_ref->{m_day} $head_ref->{year} $head_ref->{hour} $head_ref->{min} $head_ref->{sec}"; #check for general connection errors if (($line =~ s/Failed reading socks negotiation message//i) || ($line =~ s/Recieved SOCKS negotiation request with invalid command//i) || ($line =~ s/Recieved SOCKS negotiation request with address type NOT SUPPOTRED//i) || ($line =~ s/Recieved ILLEGAL SOCKS negotiation request//i) || ($line =~ s/Failed to send SOCKS authentication message//i) || ($line =~ s/TCP SUPPLIER = NULL//i) || ($line =~ s/Some general error occured while processing data from Intel client to MC//i) || ($line =~ s/Some general error occured while processing APF requst//i) ) { $nConnErrors++; } #check for any other errors elsif(($line =~ s/Acceptor::start () - open failed//i) || ($line =~ s/Unable to create reactor//i) || ($line =~ s/Unable to activate thread pool//i) || ($line =~ s/Unable to stop thread pool//i) || ($line =~ s/Unable to delete reactor//i) || ($line =~ s/Element (.*) is not found//i) || ($line =~ s/Element (.*) is NULL//i) || ($line =~ s/ACE_Configuration_Heap::open returned//i) || ($line =~ s/import failed//i) || ($line =~ s/Channel consumer could not find the requested tunnel//i) || ($line =~ s/Failed to listen on//i) || ($line =~ s/invalid//i) || ($line =~ s/Static config file is missing mandatory section//i) || ($line =~ s/Default element used for element//i) || ($line =~ s/does not appear in accepted formats//i) || ($line =~ s/Log file path is incorrect//i) || ($line =~ s/Failed opening log file for read\/write//i) || ($line =~ s/ConfigFormats have been given a bad format to retreive//i) || ($line =~ s/can't obtain peer's address//i) || ($line =~ s/Error while reading dynamic configuration file//i) || ($line =~ s/Error in initializing configuration file//i) || ($line =~ s/Error while reading static configuration file//i) || ($line =~ s/Creating Options instance failed//i) || ($line =~ s/Error while filling common elements//i) || ($line =~ s/Failed loading (.*) authentication dll - exit//i) || ($line =~ s/Log file path is incorrect//i) || ($line =~ s/Failed opening log file for read\/write//i) || ($line =~ s/Failed to initialize logger//i) || ($line =~ s/Failed to start dynamic configuration//i) ) { $nGeneralError++; } } ############################################################################### # Handle Info message ############################################################################### sub handle_info { my $line = shift; my $head_ref = shift; my $line_time = "$head_ref->{day} $head_ref->{month} $head_ref->{m_day} $head_ref->{year} $head_ref->{hour} $head_ref->{min} $head_ref->{sec}"; # Check for new connection line if ($line =~ s/$NEW_AMT_CONNECTION_RE//i) { $nTunnelsOpen++; push @UUIDs, ($1,$line_time); } # check for new port forwarding elsif ($line =~ s/$PORT_FW_RE//i) { push @PORT_FW, ($1,$line_time); } # check for disconnect elsif ($line =~ s/$AMT_DISCONECTED_RE//i) { $nTunnelsClose++; } #check for auth failure elsif ($line =~ s/$AUTH_FAIL_RE//i) { $nAMTAuthFailure++; push @AMT_AUTH_FAIL, ($1,$line_time); } # check for blocked UDP elsif ($line =~ s/$BLOCKED_UDP_RE//i) { $nBlockedUDP++; push @BLOCKED_UDP, ($1,$2,$line_time); } # check for blocked TCP elsif ($line =~ s/$BLOCKED_TCP_RE//i) { $nBlockedTCP++; push @BLOCKED_TCP, ($1,$2,$line_time); } # check for new channel elsif ($line =~ s/$NEW_CHANNEL_RE//i) { $nChannelsOpen++; push @OPEN_CHANNELS, ($1,$2, $line_time); } # check for channel close or unexpected close elsif ($line =~ s/$CHANNEL_CLOSE_RE//i) { $nChannelsClose++; push @CLOSE_CHANNELS, ($1,$2, $line_time); } #check or unexpected disconnect (AMT or Socks) elsif ( ($line =~ s/$AMT_DISCONECTED_UNEXPECT_RE//i) || ($line =~ s/$CHANNEL_CLOSE_UNEXPECT_RE//i) || ($line =~ s/$CHANNEL_SHUTDOWN_RE//i) ) { $nConnErrors++; } } ############################################################################### # Handle Warning message ############################################################################### sub handle_warning { my $line = shift; my $head_ref = shift; my $line_time = "$head_ref->{day} $head_ref->{month} $head_ref->{m_day} $head_ref->{year} $head_ref->{hour} $head_ref->{min} $head_ref->{sec}"; #check for all sorts of connection errors if (($line =~ s/$READ_SOCKS_FAIL_RE//i) || ($line =~ s/$UNSUPPORTED_SOCKS_RE//i) || ($line =~ s/$SEND_SOCKS_FAIL_RE//i) || ($line =~ s/$SEND_SOCKS_NOTIFICATION_PORT_FW_FAIL_RE//i) || ($line =~ s/$UNSUPPORTED_APF_RE//i) || ($line =~ s/$SEND_SOCKS_NOTIFICATION_PORT_FW_CANCEL_FAIL_RE//i) || ($line =~ s/$SEND_UDP_FAIL_RE//i) || ($line =~ s/$REJECT_CONN_REQUEST_RE//i) || ($line =~ s/$INVALID_SRV_DATA_RE//i) || ($line =~ s/$INVALID_SRV_DATA_RE//i) ) { $nConnErrors++; } #check for auth failure elsif ($line =~ s/$SOCKS_AUTH_FAIL_ERROR_RE//i) { $nSocksAuthFailure++; push @SOCKS_AUTH_FAIL, ($1,$line_time); } } ############################################################################### # Print statistics ############################################################################### sub print_statistics { my $hoursToStat = shift; print "\n"; print "Intel(R) MPS statistics\n"; print "-----------------------\n\n"; printf("Report period: %.3f hours\n", $hoursToStat); print "Number of Intel clients connections opened : $nTunnelsOpen\n"; print "Number of Intel clients connections closed : $nTunnelsClose\n"; print "Number of management-console connections opened : $nChannelsOpen\n"; print "Number of management-console connections closed : $nChannelsClose\n"; print "Number of AMT authentication failure : $nAMTAuthFailure\n"; print "Number of Socks authentication failure : $nSocksAuthFailure\n"; print "Number of non-filtered (blocked) UDP connections : $nBlockedUDP\n"; print "Number of non-filtered (blocked) TCP connections : $nBlockedTCP\n"; print "Number of connection errors : $nConnErrors\n"; print "Number of general errors : $nGeneralError\n"; }