In a previous article (IPTables Logging in JSON with NFLOG and ulogd2) we learned how to log certain IPTables rules to JSON log files.
Monitoring the logs in real-time on the command line, can also be very useful when debugging either the rules themselves or when analyzing certain issues. Rather than just looking at the logs, in some situations it might be useful to track the rate of the log messages. A self-written Perl script can be useful as it allows to be flexible when it comes to:
- parsing logs
- formatting the output (with colors or tables or …)
- calculating statistics
- …
The following Perl script uses a few modules which need to be present:
use IO::Async::Timer::Periodic; use IO::Async::Loop; use Time::HiRes qw/time/; use Term::ANSIColor qw(:constants); use Getopt::Long;
The first two modules can be installed on Debian systems with:
apt install libio-async-perl
The others are part of the normal Perl packages and do not require any extra installation.
Next the script will use a polling mechanism to read from standard output at fixed intervals, to calculate the rate of the unique log lines. The default polling rate is set to 2 seconds but it can be managed through command line parameters:
my $last_poll_time = time;
my $poll_rate = 2;
GetOptions (
'p|pollrate=i' => $poll_rate,
);
my $loop = IO::Async::Loop->new;
my $timer = IO::Async::Timer::Periodic->new(
interval => $poll_rate,
on_tick => \&log_rate
);
$timer->start;
$loop->add( $timer );
$loop->run;
Finally, the script will define a subroutine called log_rate, which will read from standard output (or even a file) at each poll interval. Important is of course that the log lines from standard output do not contain unique data such as timestamps. The output must be as generic as possible.
Example:
tail -qf /var/log/ulog/blocked_detailed.json /var/log/ulog/blocked.json /var/log/ulog/passed.json | jq -r --unbuffered '."oob.prefix"' blocked: invalid state blocked: invalid state blocked: invalid state blocked: invalid state blocked: invalid state action=blocked action=blocked action=blocked action=blocked action=blocked action=passed action=passed action=passed action=passed
The code snippit for log_rate could contain:
sub log_rate {
local $SIG{ALRM} = sub { die time, " time exceeded to read STDIN\n" };
alarm($poll_rate);
my $h;
eval {
local $| = 1;
while (my $line = <>) {
chomp($line);
$h->{$line}++;
}
};
alarm(0);
return unless keys %$h;
my $delta_time = time - $last_poll_time;
print DARK WHITE . sprintf("%d: ", time) . RESET;
print( BOLD WHITE . $_ ." [" . GREEN . sprintf("%.2f/s", $h->{$_}/$delta_time) . BOLD WHITE "] | " . RESET) foreach keys %$h;
print "\n";
$last_poll_time = time;
}
Line 2 will start with declaring the “ALARM” signal. This signal is called when the alarm timeout has been reached (see further below).
Line 4 defines the alarm timeout in seconds: meaning: if everything below line 4 (until the next alarm line) takes longer than the defined timeout in seconds, the “ALRM” signal handler defined at line 2 will be called, which basically stops the code execution with a die (which in theory should stop the script with an exit 1).
Line 5 defines a hash reference which is required down below, to temporarily store unique log lines.
Line 6 until 12 define an eval block. The eval block will catch the ALRM signal die (once reached) without stopping the script with an exit 1. Inside the eval block, the standard output will be read with the diamond operator (<>) and unique lines will be counted and stored in the $h hash reference.
Line 13, right after the eval block, sets to alarm timeout to 0 again, which means it is disabled. This allows that only execution of the eval block will be evaluated for timeout.
Line 15 ensures that only when log lines were discovered and stored in the temporary hash-ref $h, that rates will be printed to the screen.
The rest of the code will take care of printing the discovered log lines with their rates to the screen. Colors from Term::ANSIColor are used to make the output more vivid.
Example output:
The full version of the script can be found at: https://github.com/insani4c/perl_tools/tree/master/log_rate