hires_cxreport.pl

#!/usr/bin/perl
package main;
if (defined $ENV{DEBUG}) {
   use strict;
   use warnings;
   use diagnostics;
   use Carp;
   use Data::Dumper;
}
use Time::HiRes qw(usleep ualarm gettimeofday stat lstat utime);
#use Time::Format qw/%time/;

# use lib prepends to @INC, so put lower priority first
# This is before run-time, so cannot condition this with normal 'if' logic.
use lib '/home/lanforge/scripts';
use lib "./";

use LANforge::Utils;
use Net::Telnet ();
use Getopt::Long;
our $quiet = 1;

my $report_filename = "/tmp/hires_report.txt";
my $duration_sec = 60;
my $cx = "rdtest";


our $lfmgr_host = 'localhost';
our $lfmgr_port = 4001;
$| = 1;
my $t = new Net::Telnet(Prompt => '/default\@btbits\>\>/',
                    Timeout => 60);

$t->open(Host    => $::lfmgr_host,
        Port    => $::lfmgr_port,
        Timeout => 10);

$t->max_buffer_length(16 * 1024 * 1000); # 16 MB buffer
$t->waitfor("/btbits\>\>/");

# Configure our utils.
our $utils = new LANforge::Utils();
$::utils->telnet($t);         # Set our telnet object.
if ($::utils->isQuiet()) {
 if (defined $ENV{'LOG_CLI'} && $ENV{'LOG_CLI'} ne "") {
   $::utils->cli_send_silent(0);
 }
 else {
   $::utils->cli_send_silent(1); # Do not show input to telnet
 }
 $::utils->cli_rcv_silent(1);  # Repress output from telnet
}
else {
 $::utils->cli_send_silent(0); # Show input to telnet
 $::utils->cli_rcv_silent(0);  # Show output from telnet
}
#$::utils->log_cli("# $0 ".`date "+%Y-%m-%d %H:%M:%S"`);

$SIG{'INT'} = sub {
   $::utils->doCmd("set_cx_state all $cx STOPPED");
   exit 0;
};

# start rdtest
my %times = ();
$times{gettimeofday().'_before_set_cx_state'} = gettimeofday() ." before_start_cx 0 0";
$::utils->doCmd("set_cx_report_timer all $cx 250");
$::utils->doCmd("set_cx_state all $cx RUNNING");
$times{gettimeofday().'_after_set_cx_state'} = gettimeofday() ." after_start_cx 0 0";

my $timelimit = $duration_sec + time();

my $show_cx_str = '';
my $lastline = '';
my $lasttime = 0;
my @hunks = ();
my $delta = 0;
my $tod = gettimeofday();
my $last_a = 0;
my $last_b = 0;
my $step_a = 0;
my $step_b = 0;
while ($tod < $timelimit) {
# the command below does not indicate last reported timestamp, skip it
#   $show_cx_str = $::utils->doAsyncCmd("show_cxe all $cx");
#   $times{gettimeofday()."_show_cxe"} = $show_cx_str;
   $tod = gettimeofday();
   $lastline=`tail -1 /home/lanforge/lf_reports/${cx}-A*`;
   @hunks = split(',', $lastline);
   $hunks[0] = $hunks[0]/1000 if ($hunks[0] > 0);
   $last_a = $hunks[0] if ($last_a == 0);
   if ($hunks[0] gt $last_a){
      print "\nnew report A entry!\n";
      $step_a = $hunks[0] - $last_a;
      $last_a = $hunks[0];
      $delta = $tod - $hunks[0];
      $times{"${tod}_tail_csv-A"} = "$hunks[0] $hunks[1] $step_a $delta";
   }
   $lastline=`tail -1 /home/lanforge/lf_reports/${cx}-B*`;
   @hunks = split(',', $lastline);
   $hunks[0] = $hunks[0]/1000 if ($hunks[0] > 0);
   $last_b = $hunks[0] if ($last_b == 0);
   if ($hunks[0] gt $last_b) {
      print "\nnew report B entry!\n";
      $step_b = $hunks[0] - $last_b;
      $last_b = $hunks[0];
      $delta = $tod - $hunks[0];
      $times{"${tod}_tail_csv-B"} = "$hunks[0] $hunks[1] $step_b $delta";
   }
   usleep(125);
   if (time() gt $lasttime) {
      print "\r".($timelimit - time())." sec remaining ";
      $lasttime = time();
   }
} #~while
$::utils->doCmd("set_cx_state all $cx STOPPED");
print "...collected.\n";
die unless open(my $fh, ">", $report_filename);
#print $fh "TimeKeyInput csv_record_tstampsecs endpoint sec_since_last_report seconds_lag_since_last_report\n";
print $fh "clock          csv_tstamp_secs           endpoint     sec_btwn_reports  tstamp_lag_sec\n";
foreach $key (sort {$a cmp $b} (keys %times)) {
   my ($clock) = $key =~ m/^([^_]+)/;
   @hunks = split(' ', $times{$key});
   print$fh sprintf "%14.3f %15.3f %18s %20.3f %15.3f\n", 0.0+$clock, $hunks[0], $hunks[1], $hunks[2], $hunks[3];
}
close $fh;
print "View the report at $report_filename\n";


#eof