Return to Revisions

#!/usr/bin/perl

use strict;

use Date::Parse;
use Date::Format;

# hash arrays to keep the start and ending times for each request id.
my %start = ();
my %end = ();

# the @order array is used to preserve the order that we saw request ids,
# so we can print them out in the same order.
my @order;

while(<>) {
  # skip lines we're not interested in
  next unless (m/incoming request:|candidate list sent for:/);
  chomp;  # strip trailing linefeed

  # split input line into array @F on white-space separated fields.
  my @F = split;
  # and get the timestamp of the log entry
  my $timestamp = join(" ", @F[0..1]);

  if (m/incoming request:/) {
    my $reqid = $F[5];
    if (!defined($start{$reqid})) { push @order, $reqid };

    $start{$reqid} = $timestamp;

  } elsif (m/candidate list sent for:/) {
    my $reqid = $F[7];
    $end{$reqid} = $timestamp;
  };

};

foreach my $reqid (@order) {
    my $seconds = str2time($end{$reqid}) - str2time($start{$reqid});
    my $hms = time2str("%H:%M:%S", $seconds, "0");
    my $s = time2str("%H:%M:%S", str2time($start{$reqid}));
    my $e = time2str("%H:%M:%S", str2time($end{$reqid}));

    print <<__EOF__
Map $reqid
Start $s
Finish $e
Took $seconds seconds
Took $hms
=========================================================================

__EOF__
}

Save this as, e.g. anil.pl and make it executable with chmod +x anil.pl.

Output from the sample input is:

$ ./anil.pl a8.svrf.ear 
Map 1dd5.073f.5d5f0397
Start 00:05:27
Finish 00:05:29
Took 2 seconds
Took 00:00:02
=========================================================================

The same algorithm can be implemented in bash, but (IMO) it's a lot harder to read and understand, and bash array variables are a pain to work with because of how they need to be quoted. And it will run a lot slower:

For example:

#!/bin/bash

declare -A start end
declare -a order

while read -r -a F ; do

  [ "${F[3]} ${F[4]}" != "incoming request:" ] \
    && [ "${F[3]} ${F[6]}" != "candidate for:" ] \
    && continue

  ts="${F[0]} ${F[1]}"

  if [ "${F[3]}" = "incoming" ] ; then
    reqid="${F[5]}"
    [ -v start[$reqid] ] || order+=( "$reqid" )
    start["$reqid"]="$ts"

  elif [ "${F[3]}" = "candidate" ] ; then
    reqid="${F[7]}"
    end["$reqid"]="$ts"
  fi

done <(cat "$@")

for reqid in "${order[@]}"; do
  start=$(date -d "${start[$reqid]}" +%s)
  end=$(date -d "${end[$reqid]}" +%s)
  seconds=$(( $end - $start ))
  hms=$(TZ=UTC date -d "@$seconds" "+%H:%M:%S")
  s=$(date -d "${start[$reqid]}" "+%H:%M:%S")
  e=$(date -d "${end[$reqid]}" "+%H:%M:%S")

cat <<__EOF__
Map $reqid
Start $s
Finish $e
Took $seconds seconds
Took $hms
=========================================================================

__EOF__

done

Note: this requires bash v4.3 or newer for the -v test operator to check if a variable exists.