timestamp STDOUT

ping-check.pl

#!/usr/bin/env perl
use strict;
use warnings;

# apt-get install apache2-utils libyaml-syck-perl libtimedate-perl
use YAML::Syck;
use IO::File;
use Date::Parse;
use Time::Piece;

my $PING_LOG_PREFIX = "ping-log.";
my $STATE_FILE = "ping-check.state";

my $ICMP_REQ_MARGIN = 2;
my $TIMESTAMP_MARGIN = 3;
my $ICMP_ROLLOVER = 65535;

# get a list of all extant ping files
my %file;
foreach my $file (glob("${PING_LOG_PREFIX}*")) {
  $file{$file}{mtime} = (stat($file))[9];
}
# sort by mtime, sort of. if they're close, sort by number in file's name, if any
my @files = sort {
  # uncommon case
  if (abs($file{$a}{mtime} - $file{$b}{mtime}) < 300) {
    my $afile = $a;
    my $bfile = $b;
    $afile =~ s/^.*?(\d+)/$1/;
    $bfile =~ s/^.*?(\d+)/$1/;
    # if no numbers, fall back to mtime sort
    if ($afile and $bfile) {
      return $afile <=> $bfile
    }
  }
  $file{$a}{mtime} <=> $file{$b}{mtime}
} keys %file;


# open state file
my %data;
eval { %data = %{ LoadFile($STATE_FILE) } };


# open latest ping file we're monitoring
my $file = $data{'current logfile'} || $files[0];
my $fh = IO::File->new($file)
  or die "Couldn't open $file: $!";

# seek to where we last read
my $seek = $data{'seek'} || 0;
if ($seek) {
  $fh->setpos($seek);
}

my $icmp_req = $data{'icmp_req'} || 0;
my $timestamp = $data{'timestamp'} || 0;

my @outages;
my $last_line = $data{'last_line'} || '';
while (<$fh>) {
  next unless m/64 bytes from/;
  my ($ts, $icmp, $time) = m/^(.*) 64 bytes from .* icmp_(?:req|seq)=(\d+).* time=(.*)$/;
  unless ($ts =~ m/^\d+$/) {
    $ts = str2time($ts);
  }

  my $icmp_jump = 0;
  # check icmp_req jumps
  if ($icmp <= $icmp_req) {
    if ($icmp_req == $ICMP_ROLLOVER && $icmp == 0) {
      $icmp_req = -1;
    } else {
      warn "icmp non-sequential $icmp_req $icmp\n$last_line\n$_";
      $icmp_jump++;
    }
  }
  if ($icmp > $icmp_req + $ICMP_REQ_MARGIN) {
    warn "icmp_req jump $icmp_req $icmp\n$last_line\n$_";
    $icmp_jump++;
  }
  $icmp_req = $icmp;

  # check time jumps
  if ($timestamp == 0) {
    $timestamp = $ts - 1;
  }
  if ($icmp_jump and ($ts > $timestamp + $TIMESTAMP_MARGIN)) {
    my $delta = Time::Piece->new($ts) - Time::Piece->new($timestamp);
    $delta = $delta->pretty();
    warn "outage - $delta -- $timestamp $ts\n$last_line\n$_";
    my $line = $_;
    chomp($line);
    unshift @outages, [$last_line, $timestamp, $delta, $ts, $line];
  }
  $timestamp = $ts;

  $last_line = $_;
  chomp($last_line);
  $data{'last_line'} = $last_line;
}
my $now = time();

# check if there is a newer file than what we were just processing
my $num_files = scalar @files;
my $i = 1;
foreach my $f (@files) {
  last if $f eq $file;
  $i++;
}
# if so, save state so next run will process the next time
unless ($i == $num_files) {
  $data{'current logfile'} = $files[$i];
  $data{'seek'} = 0;
  $data{'icmp_req'} = $icmp_req;
  $data{'timestamp'} = $timestamp;
  unless (defined $data{'outages'}) {
    $data{'outages'} = \@outages;
  } else {
    unshift @{$data{'outages'}}, @outages;
  }
  DumpFile($STATE_FILE, \%data);
  exit 0;
}


# we're working on the latest file, so check if there is an ongoing outage
my $outage_recovery = 0;
if ($now - $timestamp > $TIMESTAMP_MARGIN) {
  unless ($data{'ongoing outage'} == $timestamp) {
    print "ongoing outage - last ping received $last_line\n";
    $data{'ongoing outage'} = $timestamp;
    $data{'outage notification'} = $now;
  }
  # reset if last notification > 20 minutes ago
  $data{'ongoing outage'} = 0
    if $now - $data{'outage notification'} >= 20 * 60;
} else {
  $outage_recovery = 1
    if $data{'ongoing outage'};
  $data{'ongoing outage'} = 0;
}


# save state
$data{'seek'} = $fh->getpos();
$data{'icmp_req'} = $icmp_req;
$data{'timestamp'} = $timestamp;
unless (defined $data{'outages'}) {
  $data{'outages'} = \@outages;
} else {
  unshift @{$data{'outages'}}, @outages;
}
DumpFile($STATE_FILE, \%data);


# note recent outages
if ($outage_recovery) {
  print "latest outages:\n";
  foreach my $outage (@{$data{'outages'}}) {
    print join "\n", @{$outage};
    print "\n\n";
    my $ts = $outage->[1];
    last if $now - $ts > 24 * 60 * 60;
  }
}


exit 1 if $data{'ongoing outage'} or $outage_recovery;
exit 0;

timestamp.pl

#!/usr/bin/perl
use strict;
use warnings;
use POSIX qw(strftime);

# emits timezone

$|++;

# Tue Nov  5 14:08:30 2019 EST
# %a %b %e %H:%M:%S %Y %Z
while (<>) {
  $_ = strftime("%a %b %e %H:%M:%S %Y %Z", localtime) . " $_";
} continue {
  print or die "-p destination: $!\n";
}

timestamp.sh

#!/bin/bash
# does not emit timezone
perl -pe '$|++; $_=(scalar localtime) . " $_"'

e.g. ping server | bin/timestamp | tee /dev/tty | rotatelogs ping-log 128M

e.g. while [[ 1 ]] ; do ./ping-check.pl | tee ping-mail ; if [[ -s ping-mail ]] ; then cat ping-mail | mail -s 'link outage' alert@example.com ; fi ; sleep 60 ; done