node_history.in 16.6 KB
Newer Older
1 2
#!/usr/bin/perl -w
#
3
# Copyright (c) 2005-2015, 2019 University of Utah and the Flux Group.
4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22
# 
# {{{EMULAB-LICENSE
# 
# This file is part of the Emulab network testbed software.
# 
# This file is free software: you can redistribute it and/or modify it
# under the terms of the GNU Affero General Public License as published by
# the Free Software Foundation, either version 3 of the License, or (at
# your option) any later version.
# 
# This file is distributed in the hope that it will be useful, but WITHOUT
# ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
# FITNESS FOR A PARTICULAR PURPOSE.  See the GNU Affero General Public
# License for more details.
# 
# You should have received a copy of the GNU Affero General Public License
# along with this file.  If not, see <http://www.gnu.org/licenses/>.
# 
# }}}
23 24 25
#
use English;
use Getopt::Std;
26 27
use Date::Parse;
use Time::Local;
28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55

#
# Drill down the node history data in the DB
#

# un-taint path
$ENV{'PATH'} = '/bin:/usr/bin:/usr/local/bin:/usr/site/bin';
delete @ENV{'IFS', 'CDPATH', 'ENV', 'BASH_ENV'};

#
# Turn off line buffering on output
#
$| = 1; 

# Load the Testbed support stuff.
use lib "@prefix@/lib";
use libdb;

use POSIX qw(ctime);

#
# Magic: Wed Jan 12 13:59:00 2005
# When Leigh implemented the history log.
#
my $epoch = 1105563540;

sub usage {
    print("Usage: $0 [-ARalrsvw] [node ...]\n".
56
    "  -A       print history of all nodes (you do NOT want to do this)\n".
57
    "  -T type  print history of all nodes of a given type\n".  
58 59 60 61 62 63 64 65
    "  -R       print raw records (default is to combine some records)\n".
    "  -S field sort list by field (date, node, pideid, uid, elapsed)\n".
    "  -a       show only when allocated to experiment\n".
    "  -l       list records\n".
    "  -n num   report on only the first num records (after sorting)\n".
    "             use negative value for last num records\n".
    "  -r       reverse order (most recent first)\n".
    "  -s       show a summary of node's past usage\n".
66 67
    "  -d date  Start at YYYY-MM-DD HH:MM:SS\n".
    "  -c       used with -d, show current status of all nodes\n".
68 69
    "  -v       verbose output\n".
    "  -w       print warnings about anomolous records\n");
70 71 72
    exit(1);
}

73
my $optlist = "AT:RS:aln:rswvd:i:ct:x:m:";
74 75 76
my $warnme = 0;
my $verbose = 0;
my $showall = 0;
77
my $showtype = "";
78
my $showcurrent = 0;
79 80 81 82
my $showalloconly = 0;
my $list = 0;
my $summary = 0;
my $raw = 0;
83
my $numrecs = 0;
84
my $datetime;
85 86
my $datelimit;
my $startrecord;
87
my $ip;
88
my $mac;
Leigh Stoller's avatar
Leigh Stoller committed
89
my @nodes = ();
90 91 92 93 94

#
# Sort stuff.  sortby value should correspond to record field format:
#
my %sortmap = (
95 96 97 98 99
    "node"    => 0,
    "pideid"  => 6,
    "uid"     => 3,
    "date"    => 1,
    "elapsed" => 2
100 101 102
);
my $sortbydate = $sortmap{date};
my $sortby = $sortbydate;
103 104
my $revorder = 0;

105 106 107 108 109 110 111 112 113 114 115 116 117 118 119 120 121 122
# Sort function: first by indicated field, secondarily by date
sub byfield()
{
    # already sorted by date
    return 0 if ($sortby == $sortbydate);

    # int compare for elapsed
    if ($sortby == $sortmap{elapsed}) {
	return @$a[$sortby] <=> @$b[$sortby] ||
	    @$a[$sortbydate] <=> @$b[$sortbydate];
    }

    # string compare for everything else
    return @$a[$sortby] cmp @$b[$sortby] ||
	@$a[$sortbydate] <=> @$b[$sortbydate];
}


123 124 125 126 127 128 129 130 131 132
#
# Parse command arguments.
#
%options = ();
if (! getopts($optlist, \%options)) {
    usage();
}
if (defined($options{"A"})) {
    $showall = 1;
}
133 134 135
if (defined($options{"T"})) {
    $showtype = $options{"T"};
}
136 137 138
if (defined($options{"R"})) {
    $raw = 1;
}
139
if (defined($options{"S"})) {
140
    if (!exists($sortmap{$options{"S"}})) {
141 142 143 144 145
	print STDERR "invalid sort field '$options{S}'\n";
	usage();
    }
    $sortby = $sortmap{$options{"S"}};
}
146 147 148 149 150 151
if (defined($options{"a"})) {
    $showalloconly = 1;
}
if (defined($options{"l"})) {
    $list = 1;
}
152 153 154
if (defined($options{"n"})) {
    $numrecs = $options{"n"};
}
155 156 157 158 159 160
if (defined($options{"r"})) {
    $revorder = 1;
}
if (defined($options{"s"})) {
    $summary = 1;
}
161
if (defined($options{"d"})) {
162 163 164 165 166
    $datetime = $options{"d"};
    
    if ($datetime !~ /^\d+$/) {
	$datetime = timelocal(strptime($datetime));
    }
167 168
    $summary  = 0;
}
169 170 171 172
if (defined($options{"x"})) {
    $startrecord = $options{"x"};
    $summary  = 0;
}
173 174 175 176 177 178 179 180 181
if (defined($options{"t"})) {
    if (!defined($datetime)) {
	$datetime  = time() - $options{"t"};
    }
    else {
	$datelimit = $datetime;
	$datetime  = $datetime - $options{"t"};
    }
}
182 183 184 185 186
if (defined($options{"c"})) {
    $showcurrent = 1;
    usage()
	if (!defined($datetime));
}
187 188 189 190
if (defined($options{"i"})) {
    $ip = $options{"i"};
    $summary  = 0;
}
191 192 193 194 195
if (defined($options{"m"})) {
    $mac = $options{"m"};
    $mac =~ s/://g;
    $summary  = 0;
}
196 197 198 199 200 201
if (defined($options{"w"})) {
    $warnme = 1;
}
if (defined($options{"v"})) {
    $verbose = 1;
}
202 203
if (!($showall || $showtype) &&
    @ARGV == 0 && !(defined($ip) || defined($mac))) {
204 205
    usage();
}
206 207 208 209 210 211 212 213 214 215 216

if ($showtype) {
    my $query_result =
	DBQueryFatal("SELECT node_id FROM nodes where type='$showtype'");
    while (my %row = $query_result->fetchhash()) {
	push @nodes, $row{node_id};
    }
} else {
    @nodes = @ARGV
	if (! (defined($ip) || defined($mac)));
}
217 218 219 220 221

if (!$list && !$summary) {
    $list = 1;
}

222 223 224 225
my %nodeinfo;	# [ expt, starttime, uid ]
my @rawrecords;
my %startinfo;

226 227 228 229
#
# Common case: a single node.
# Just fetch data for it, otherwise fetch data for all.
# 
230 231 232 233 234 235 236 237 238 239
#
# If we have a datetime, then we want to start with records greater
# then the stamp, but we will not know the state at that point, since
# it will be the most recent record *before* the requested stamp, that
# says what the node is doing at the time. So, this query does some
# amazing magic to find those records without an explosion of terms
# that takes forever. Kudos to Gary for figuring out this query. 
#
if ($datetime) {
    my $querymod = "";
240
    
241 242 243 244 245 246 247
    if (@nodes) {
	$querymod = " AND (" .
	            join(" or ", map {"h1.node_id='$_'"} @nodes) . ")";
    }
    elsif (defined($ip)) {
	$querymod = " AND h1.cnet_ip='$ip'";
    }
248 249 250
    elsif (defined($mac)) {
	$querymod = " AND h1.cnet_mac='$mac'";
    }
251 252 253

    my $query_result =
	DBQueryFatal("SELECT h1.node_id,h1.op,h1.stamp,h1.uid,h1.exptidx,".
254
		     "       s.pid,s.eid,history_id ".
255 256 257
		     "    FROM node_history as h1 ".
		     "JOIN (SELECT h3.node_id,MAX(h3.stamp) as stamp ".
		     "         FROM node_history as h3 ".
258 259
		     "      WHERE stamp < $datetime ".
		     "      GROUP BY h3.node_id ".
260 261 262 263 264 265 266 267 268 269 270 271 272 273 274 275 276 277
		     "     ) AS h2 ON h1.node_id=h2.node_id AND ".
		     "                h1.stamp = h2.stamp ".
		     "left join nodes as n on n.node_id=h1.node_id ".
		     "left join node_types as t on t.type=n.type ".
		     "left join experiment_stats as s on s.exptidx=h1.exptidx ".
		     "where t.isplabdslice=0 and t.isplabphysnode=0 and ".
		     "      (n.role='testnode' or n.role='virtnode') ".
		     "$querymod order by h1.node_id");
    
    while (my %row = $query_result->fetchhash()) {
	my $pid = $row{pid};
	my $eid = $row{eid};
	my $pideid = "$pid/$eid";
	my $exptidx = $row{"exptidx"};
	my $node = $row{node_id};
	my $stamp = $row{stamp};
	my $uid = $row{uid};
	my $op = $row{op};
278
	my $history_id = $row{"history_id"};
279 280 281 282 283 284 285 286 287 288 289 290 291
	my $cstamp = ctime($stamp);
	my $diff = $datetime - $stamp;
	chomp($cstamp);

	if ($op eq "alloc" || $op eq "move" || $op eq "create") {
	    if ($showcurrent) {
		next
		    if ($pid eq TBOPSPID());

		if ($verbose) {
		    print "$node '$stamp' $diff $uid $pid $eid\n";
		}
		else {
292 293
		    print "$node REC $stamp $diff $uid $pid $eid ".
			"$exptidx $history_id\n";
294 295 296
		}
	    }
	    else {
297
		$nodeinfo{$node} =
298
		    [ $pideid, $exptidx, $stamp, $uid, $history_id ];
299 300 301 302
	    }
	}
	elsif ($op eq "free" || $op eq "destroy") {
	    if (!$showcurrent) {
303
		$nodeinfo{$node} = [ "", undef, $stamp, $uid, $history_id ];
304 305 306 307 308 309 310
	    }
	}
    }
}
exit(0)
    if ($showcurrent);

311 312 313 314 315 316 317 318 319 320 321 322 323 324 325 326 327 328 329 330 331 332 333 334 335 336 337 338
#
# If nodes are specified, get the node inception date to limit the
# initial record. This really only matters for summary stats.
#
my %nodestarts = ();
if (@nodes > 0) {
    my $nlist = "(" . join(" or ", map {"node_id='$_'"} @nodes) . ")";

    my $query_result =
	DBQueryFatal("SELECT node_id,UNIX_TIMESTAMP(inception) as tstamp ".
		     " FROM nodes WHERE $nlist");
    while (my %row = $query_result->fetchhash()) {
	my $node = $row{'node_id'};

	# use most recent of inception date...
	my $ts = $row{'tstamp'};
	# ...and specified date...
	if ($datetime && $ts < $datetime) {
	    $ts = $datetime;
	}
	# ...and epoch
	if ($ts < $epoch) {
	    $ts = $epoch;
	}
	$nodestarts{$node} = $ts;
    }
}

339
my $querymod = "";
340
if ($startrecord) {
341 342 343 344 345
    if ($revorder) {
	$querymod = " AND history_id<='$startrecord'";
    } else {
	$querymod = " AND history_id>='$startrecord'";
    }
346
}
347
if (@nodes) {
348
    $querymod .= " AND (" . join(" or ", map {"node_id='$_'"} @nodes) . ")";
349
}
350
elsif (defined($ip)) {
351
    $querymod .= " AND cnet_ip='$ip'";
352
}
353 354 355
elsif (defined($mac)) {
    $querymod .= " AND cnet_mac='$mac'";
}
356

357 358 359 360 361 362 363
if ($datetime) {
    $querymod .= " AND stamp>='$datetime'";
}
if ($datelimit) {
    $querymod .= " AND stamp<='$datelimit'";
}

364
# Bogus, but reading the entire table is nuts! Millions of rows. 
365
my $limitby = ($showall && $numrecs ? "limit " . $numrecs * 10 : "");
366

367 368 369 370 371 372 373 374 375 376 377 378 379 380 381 382 383 384 385 386 387 388 389 390 391
#
# If we are not getting all the records and we want the most recent
# then we have to reverse the initial DB sort and then reverse again
# using mysql sub-query fu.
#
my $query_result;
if ($revorder && $limitby) {
    my $orderby = " ORDER BY stamp DESC";
    $query_result =
	DBQueryFatal("SELECT * from (SELECT node_id,stamp,op,uid,pid,eid, ".
		     "  experiment_stats.exptidx,cnet_ip,phys_nodeid, ".
		     "  history_id ".
		     "FROM node_history,experiment_stats ".
		     "WHERE node_history.exptidx=experiment_stats.exptidx ".
		     "$querymod $orderby $limitby) SUB ORDER BY stamp ASC");
} else {
    my $orderby = " ORDER BY stamp ASC";
    $query_result =
	DBQueryFatal("SELECT node_id,stamp,op,uid,pid,eid, ".
		     "  experiment_stats.exptidx,cnet_ip,phys_nodeid, ".
		     "  history_id ".
		     "FROM node_history,experiment_stats ".
		     "WHERE node_history.exptidx=experiment_stats.exptidx ".
		     "$querymod $orderby $limitby");
}
392

393 394
my $lastid = 0;
my $laststamp = 0;
395 396
while (my %row = $query_result->fetchhash()) {
    my $pideid = "$row{pid}/$row{eid}";
397
    my $exptidx = $row{"exptidx"};
398 399 400
    my $node = $row{node_id};
    my $stamp = $row{stamp};
    my $uid = $row{uid};
401
    my $history_id = $row{"history_id"};
402

403 404 405 406 407 408
    if ($stamp < $laststamp) {
	print STDERR "$node ($pideid): timestamp decrease $laststamp (ID:$lastid) to $stamp (ID: $history_id)\n" if ($warnme);
    }
    $lastid = $history_id;
    $laststamp = $stamp;

409 410
    #
    # XXX if this is the first record for a node, consider it as free
411
    # from the epoch (or the low date specified) til now.
412
    #
413
    if (!exists($nodeinfo{$node})) {
414 415 416
	my $ts = $nodestarts{$node};
	$nodeinfo{$node} = [ "", undef, ($ts ? $ts : $epoch),
			     "root", $history_id ];
417 418
    }

419
    my ($opideid, $oidx, $ostamp, $ouid, $ohistory_id) = @{$nodeinfo{$node}};
420 421 422 423 424 425 426
    my $elapsed = $stamp - $ostamp;

    #
    # Allocating node to experiment.
    # Should currently be free.
    #
    if ($row{op} eq "alloc") {
427
	if ($opideid ne "") {
428
	    print STDERR "$node (ID: $history_id): dup alloc: already allocated to $opideid\n"
429 430 431
		if ($warnme);
	    # XXX possibly missing state in the DB, treat as move
	}
432
	$nodeinfo{$node} = [ $pideid, $exptidx, $stamp, $uid, $history_id ];
433 434 435 436 437 438 439
    }

    #
    # Free or move terminates a node's time in an experiment.
    #
    elsif ($row{op} eq "free") {
	if ($opideid ne $pideid) {
440
	    print STDERR "$node (ID: $history_id): mismatched alloc,free records: $opideid,$pideid\n"
441 442
		if ($warnme);
	}
443
	$nodeinfo{$node} = [ "", undef, $stamp, $uid, $history_id ];
444 445 446 447 448 449
    }
    elsif ($row{op} eq "move") {
	if (!$raw) {
	    # Moves from reloadpending to reloading are combined as reloading
	    if ($opideid eq "emulab-ops/reloadpending" &&
		$pideid eq "emulab-ops/reloading") {
450 451
		$nodeinfo{$node} = [ $pideid, $exptidx, $ostamp, $ouid,
				     $history_id ];
452 453 454
		next;
	    }
	}
455
	$nodeinfo{$node} = [ $pideid, $exptidx, $stamp, $uid, $history_id ];
456
    }
457 458
    elsif ($row{op} eq "create") {
	if ($opideid ne "") {
459
	    print STDERR "$node (ID: $history_id): dup alloc: already allocated to $opideid\n"
460 461 462
		if ($warnme);
	    # XXX possibly missing state in the DB.
	}
463
	$nodeinfo{$node} = [ $pideid, $exptidx, $stamp, $uid, $history_id ];
464 465 466
    }
    elsif ($row{op} eq "destroy") {
	if ($opideid ne $pideid) {
467
	    print STDERR "$node (ID: $history_id): mismatched create,destroy records: ".
468 469 470
		"$opideid,$pideid\n"
		if ($warnme);
	}
471
	$nodeinfo{$node} = [ "", undef, $stamp, $uid, $history_id ];
472
    }
473 474
    #print "R: $node, $opideid, $oidx, $ouid, $ostamp, $elapsed\n";
    
475
    # save off the record
476 477
    push(@rawrecords,
	 [ $node, $opideid, $oidx, $ouid, $ostamp, $elapsed, $ohistory_id ]);
478 479
}

480
if (! ($datelimit || $startrecord)) {
481 482
    # Include the current state of nodes in a final record
    my $stamp = time();
483
    for $node (sort(keys(%nodeinfo))) {
484
	my ($opideid, $oidx, $ostamp, $ouid, $ohistory_id)= @{$nodeinfo{$node}};
485
	my $elapsed = $stamp - $ostamp;
486 487
	push(@rawrecords,
	     [ $node, $opideid, $oidx, $ouid, $ostamp, $elapsed, $ohistory_id]);
488 489 490 491
    }
}

#
492 493
# Loop over the raw records, computing summary stats and creating
# a another set of records to print (if desired).
494
#
495 496 497
my @records = ();

for my $rec (@rawrecords) {
498
    my ($node, $pideid, $exptidx, $uid, $stamp, $elapsed, $history_id)= @{$rec};
499

500 501
    #print "RR: $node, $elapsed\n";

502
    if (!exists($nodestats{$node})) {
503 504
	$nodestats{$node} = [ 0, 0, 0, 0 ];
    }
505 506
    my ($ftime, $atime, $rtime, $dtime) = @{$nodestats{$node}};
    my $isalloced = 0;
507
    if ($pideid eq "") {
508
	$ftime += $elapsed;
509 510
    } elsif ($pideid eq "emulab-ops/reloadpending" ||
	     $pideid eq "emulab-ops/reloading") {
511
	$rtime += $elapsed;
512
    } elsif ($pideid eq "emulab-ops/hwdown") {
513 514 515 516 517 518 519 520
	$dtime += $elapsed;
    } else {
	$atime += $elapsed;
	$isalloced = 1;
    }
    $nodestats{$node} = [ $ftime, $atime, $rtime, $dtime ];

    if ($list) {
521 522 523 524 525 526 527 528
	my ($pid, $eid);
	if ($pideid eq "") {
	    $pid = $eid = "<FREE>";
	    $exptidx = 0;
	} else {
	    ($pid, $eid) = split("/", $pideid);
	}
	push(@records,
529 530 531
	     [$node, $stamp, $elapsed, $uid, $pid, $eid, $exptidx,
	      # For sort
	      "$pid/$eid", $history_id])
532 533 534
	    if (!$showalloconly || $isalloced);
    }
}
535

536 537 538 539 540 541 542
# Sort the list as desired
if ($sortby ne $sortbydate) {
    @records = sort byfield @records;
}
if ($revorder) {
    @records = reverse(@records);
}
543

544 545 546 547 548 549 550 551
# Prune to the proper number of entries (first/last $numrecs entries)
if ($numrecs && $numrecs < $#records) {
    if ($numrecs > 0) {
	@records = @records[0 .. $numrecs-1];
    } else {
	@records = @records[$numrecs .. -1 ];
    }
}
552

553 554
if (@records) {
    foreach my $record (@records) {
555 556
	my ($node, $stamp, $elapsed, $uid, $pid, $eid,
	    $exptidx, undef, $history_id) = @$record;
557

558 559 560 561 562 563
	if ($verbose) {
	    $stamp = ctime($stamp);
	    chomp($stamp);
	    print "$node '$stamp' $elapsed $uid $pid $eid\n";
	}
	else {
564 565
	    print "$node REC $stamp $elapsed $uid $pid $eid ".
		"$exptidx $history_id\n";
566 567 568 569
	}
    }
}

570
#
571
# Print out summary information
572
#
573
my ($t_ftime, $t_atime, $t_rtime, $t_dtime) = (0, 0, 0, 0);
574
for $node (sort keys(%nodestats)) {
575
    if ($summary) {
576 577 578 579 580 581 582 583
	my ($ftime, $atime, $rtime, $dtime) = @{$nodestats{$node}};
	my $ttime = $ftime + $atime + $rtime + $dtime;

	if ($verbose) {
	    my $pct;
	    print "$node SUMMARY\n";
	    if ($atime > 0) {
		$pct = ($atime * 100) / $ttime;
584
		printf("  Allocated: %9d sec (%5.1f%%)\n", $atime, $pct);
585
		$t_atime += $atime;
586 587 588 589
	    }
	    if ($ftime > 0) {
		$pct = ($ftime * 100) / $ttime;
		printf("  Free:      %9d sec (%5.1f%%)\n", $ftime, $pct);
590
		$t_ftime += $ftime;
591 592 593 594
	    }
	    if ($rtime > 0) {
		$pct = ($rtime * 100) / $ttime;
		printf("  Reloading: %9d sec (%5.1f%%)\n", $rtime, $pct);
595
		$t_rtime += $rtime;
596 597 598 599
	    }
	    if ($dtime > 0) {
		$pct = ($dtime * 100) / $ttime;
		printf("  Down:      %9d sec (%5.1f%%)\n", $dtime, $pct);
600
		$t_dtime += $dtime;
601 602 603
	    }
	} else {
	    print "$node SUM $atime $ftime $rtime $dtime\n";
604 605 606
	}
    }
}
607 608 609 610 611
if ($verbose) {
    my $ttime = $t_ftime + $t_atime + $t_rtime + $t_dtime;
    my $n = scalar(keys %nodestats);
    my $pct;

612 613 614 615 616 617 618 619
    print "TOTAL ($n nodes";
    if ($datelimit) {
	print " from ", scalar(localtime($datetime)),
	      " to ", scalar(localtime($datelimit));
    } elsif ($datetime) {
	print " since ", scalar(localtime($datetime));
    }
    print ")\n";
620 621 622 623 624 625 626 627 628 629 630 631 632 633 634 635 636
    if ($t_atime > 0) {
	$pct = ($t_atime * 100) / $ttime;
	printf("  Allocted:  %9d sec (%5.1f%%)\n", $t_atime, $pct);
    }
    if ($t_ftime > 0) {
	$pct = ($t_ftime * 100) / $ttime;
	printf("  Free:      %9d sec (%5.1f%%)\n", $t_ftime, $pct);
    }
    if ($t_rtime > 0) {
	$pct = ($t_rtime * 100) / $ttime;
	printf("  Reloading: %9d sec (%5.1f%%)\n", $t_rtime, $pct);
    }
    if ($t_dtime > 0) {
	$pct = ($t_dtime * 100) / $ttime;
	printf("  Down:      %9d sec (%5.1f%%)\n", $t_dtime, $pct);
    }
}
637 638

exit(0);