X-Git-Url: http://jsfdemo.indexdata.com/?a=blobdiff_plain;ds=inline;f=lib%2FZOOM%2FIRSpy.pm;h=7b7abd27eb03ea36edb9cb1fa0ec4f5900c477d8;hb=8b9eebbb053a985c82939b992d56d072a9d45b26;hp=362e8b0b4047ef23a5060d4730e4885c5b5f747a;hpb=e35b9fe1a224afd9005ae7f95b8c9e1b8e189217;p=irspy-moved-to-github.git
diff --git a/lib/ZOOM/IRSpy.pm b/lib/ZOOM/IRSpy.pm
index 362e8b0..7b7abd2 100644
--- a/lib/ZOOM/IRSpy.pm
+++ b/lib/ZOOM/IRSpy.pm
@@ -1,4 +1,3 @@
-# $Id: IRSpy.pm,v 1.28 2006-10-12 15:51:37 mike Exp $
package ZOOM::IRSpy;
@@ -6,15 +5,27 @@ use 5.008;
use strict;
use warnings;
-use Data::Dumper; # For debugging only
+use Data::Dumper; # For debugging only
+use File::Basename;
+use XML::LibXSLT;
+use XML::LibXML;
+use XML::LibXML::XPathContext;
use ZOOM;
use Net::Z3950::ZOOM 1.13; # For the ZOOM version-check only
use ZOOM::IRSpy::Node;
use ZOOM::IRSpy::Connection;
-use ZOOM::IRSpy::Record;
+use ZOOM::IRSpy::Stats;
+use ZOOM::IRSpy::Utils qw(cql_target render_record
+ irspy_xpath_context irspy_make_identifier
+ irspy_record2identifier calc_reliability_stats
+ modify_xml_document);
our @ISA = qw();
-our $VERSION = '0.02';
+our $VERSION = '1.02';
+our $irspy_to_zeerex_xsl = dirname(__FILE__) . '/../../xsl/irspy2zeerex.xsl';
+our $debug = 0;
+our $xslt_max_depth = 250;
+our $max_timeout_errors = 3;
# Enumeration for callback functions to return
@@ -23,6 +34,7 @@ sub OK { 29 } # No problems, task is still progressing
sub TASK_DONE { 18 } # Task is complete, next task should begin
sub TEST_GOOD { 8 } # Whole test is complete, and succeeded
sub TEST_BAD { 31 } # Whole test is complete, and failed
+sub TEST_SKIPPED { 12 } # Test couldn't be run
package ZOOM::IRSpy;
@@ -34,7 +46,9 @@ ZOOM::IRSpy - Perl extension for discovering and analysing IR services
use ZOOM::IRSpy;
$spy = new ZOOM::IRSpy("target/string/for/irspy/database");
- print $spy->report_status();
+ $spy->targets(@targets);
+ $spy->initialise("Main");
+ $res = $spy->check();
=head1 DESCRIPTION
@@ -46,15 +60,17 @@ protocols. It is a successor to the ZSpy program.
BEGIN {
ZOOM::Log::mask_str("irspy");
- ZOOM::Log::mask_str("irspy_test");
ZOOM::Log::mask_str("irspy_debug");
ZOOM::Log::mask_str("irspy_event");
ZOOM::Log::mask_str("irspy_unhandled");
+ ZOOM::Log::mask_str("irspy_test");
+ ZOOM::Log::mask_str("irspy_task");
}
sub new {
my $class = shift();
- my($dbname, $user, $password) = @_;
+ my($dbname, $user, $password, $activeSetSize) = @_;
+
my @options;
push @options, (user => $user, password => $password)
@@ -63,19 +79,74 @@ sub new {
my $conn = new ZOOM::Connection($dbname, 0, @options)
or die "$0: can't connection to IRSpy database 'dbname'";
+ my $xslt = new XML::LibXSLT;
+
+ # raise the maximum number of nested template calls and variables/params (default 250)
+ warn "raise the maximum number of nested template calls: $xslt_max_depth\n" if $debug;
+ $xslt->max_depth($xslt_max_depth);
+
+ $xslt->register_function($ZOOM::IRSpy::Utils::IRSPY_NS, 'strcmp',
+ \&ZOOM::IRSpy::Utils::xslt_strcmp);
+
+ my $libxml = new XML::LibXML;
+ warn "use irspy_to_zeerex_xsl xslt sheet: $irspy_to_zeerex_xsl\n" if $debug;
+ my $xsl_doc = $libxml->parse_file($irspy_to_zeerex_xsl);
+ my $irspy_to_zeerex_style = $xslt->parse_stylesheet($xsl_doc);
+
my $this = bless {
conn => $conn,
- allrecords => 1, # unless overridden by targets()
- query => undef, # filled in later
- targets => undef, # filled in later
- connections => undef, # filled in later
- tests => [], # stack of tests currently being executed
+ query => "cql.allRecords=1", # unless overridden
+ modn => undef, # Filled in by restrict_modulo()
+ modi => undef, # Filled in by restrict_modulo()
+ targets => undef, # Filled in later if targets() is
+ # called; used only to keep state from
+ # targets() until initialise() is
+ # called.
+ connections => undef, # Filled in by initialise()
+ queue => undef, # Filled in by initialise()
+ libxml => $libxml,
+ irspy_to_zeerex_style => $irspy_to_zeerex_style,
+ test => undef, # Filled in by initialise()
+ timeout => undef, # Filled in by initialise()
+ tests => undef, # Tree of tests to be executed
+ activeSetSize => defined $activeSetSize ? $activeSetSize : 10,
+ rules => [], # Can be filled by apply_rules()
+ vars => {}, # Will contain name, id, version, etc.
+ # May be written into by tests (mostly
+ # Ping, which gets the Init response)
+ # and read by tests for rules.
}, $class;
$this->log("irspy", "starting up with database '$dbname'");
return $this;
}
+# Read from and write to the set of vars
+sub var {
+ my $this = shift();
+ my($key, $newval) = @_;
+
+ if (defined $newval) {
+ $this->{vars}->{$key} = $newval;
+ #warn "$this: set '$key'='$newval'";
+ } else {
+ my $oldval = $this->{vars}->{$key};
+ $oldval = "" if !defined $oldval;
+ #warn "$this: got '$key'='$oldval'";
+ return $oldval;
+ }
+}
+
+# wrapper to read the IRSpy database name from environment variable / apache config
+sub connect_to_registry {
+ my %args = @_;
+
+ # XXX: we could also handle her: user, password, elementSetName
+
+ my $database = $ENV{IRSpyDbName} || "localhost:8018/IR-Explain---1";
+
+ return $database;
+}
sub log {
my $this = shift();
@@ -83,6 +154,14 @@ sub log {
}
+sub find_targets {
+ my $this = shift();
+ my($query) = @_;
+
+ $this->{query} = $query;
+}
+
+
# Explicitly nominate a set of targets to check, overriding the
# default which is to re-check everything in the database. Each
# target already in the database results in the existing record being
@@ -94,15 +173,15 @@ sub targets {
$this->log("irspy", "setting explicit list of targets ",
join(", ", map { "'$_'" } @targets));
- $this->{allrecords} = 0;
my @qlist;
foreach my $target (@targets) {
- my($host, $port, $db, $newtarget) = _parse_target_string($target);
+ my($protocol, $host, $port, $db, $newtarget) =
+ _parse_target_string($target);
if ($newtarget ne $target) {
$this->log("irspy_debug", "rewriting '$target' to '$newtarget'");
$target = $newtarget; # This is written through the ref
}
- push @qlist, (qq[(host="$host" and port="$port" and path="$db")]);
+ push @qlist, cql_target($protocol, $host, $port, $db);
}
$this->{targets} = \@targets;
@@ -114,141 +193,254 @@ sub targets {
sub _parse_target_string {
my($target) = @_;
- my($host, $port, $db) = ($target =~ /(.*?):(.*?)\/(.*)/);
+ my($protocol, $host, $port, $db) = ($target =~ /(.*?):(.*?):(.*?)\/(.*)/);
if (!defined $host) {
$port = 210;
- ($host, $db) = ($target =~ /(.*?)\/(.*)/);
- $target = "$host:$port/$db";
+ ($protocol, $host, $db) = ($target =~ /(.*?):(.*?)\/(.*)/);
+ $target = irspy_make_identifier($protocol, $host, $port, $db);
}
die "$0: invalid target string '$target'"
if !defined $host;
- return ($host, $port, $db, $target);
+ return ($protocol, $host, $port, $db, $target);
}
-# There are two cases.
-#
-# 1. A specific set of targets is nominated on the command line.
-# - Records must be fetched for those targets that are in the DB
-# - New, empty records must be made for those that are not.
-# - Updated records written to the DB may or may not be new.
-#
-# 2. All records in the database are to be checked.
-# - Records must be fetched for all targets in the DB
-# - Updated records written to the DB may not be new.
-#
-# That's all -- what could be simpler?
+sub restrict_modulo {
+ my $this = shift();
+ my($n, $i) = @_;
+
+ $this->{modn} = $n;
+ $this->{modi} = $i;
+}
+
+
+sub apply_rules {
+ my $this = shift();
+ my($fileName) = @_;
+
+ my $f = new IO::File("<$fileName")
+ or die "$0: can't open rules file '$fileName': $!";
+
+ while (my $line = <$f>) {
+ chomp $line;
+ $line =~ s/#.*//;
+ $line =~ s/\s+$//;
+ next if !$line;
+ my(@fields) = split /\s+/, $line;
+ my($name, $op, $val, $rule, @params) = @fields;
+ #warn "parsed name='$name', op='$op', val='$val', rule='$rule', params='@params'\n";
+ push @{ $this->{rules} }, [ @fields ];
+ }
+ $f->close();
+}
+
+# Records must be fetched for all records satisfying $this->{query} If
+# $this->{targets} is already set (i.e. a specific list of targets to
+# check was specified by a call to targets()), then new, empty records
+# will be made for any targets that are not already in the database.
#
sub initialise {
my $this = shift();
+ my($tname) = @_;
+
+ $tname = "Main" if !defined $tname;
+ $this->{test} = $tname;
+ $this->{tree} = $this->_gather_tests($tname)
+ or die "No tests defined for '$tname'";
+ $this->{tree}->resolve();
+ #$this->{tree}->print(0);
+
+ $this->{timeout} = "ZOOM::IRSpy::Test::$tname"->timeout();
- my %target2record;
- if ($this->{allrecords}) {
- # We need to check on every target in the database, which
- # means we need to do a "find all". According to the BIB-1
- # semantics document at
- # http://www.loc.gov/z3950/agency/bib1.html
- # the query
- # @attr 2=103 @attr 1=1035 x
- # should find all records, but it seems that Zebra doesn't
- # support this. Furthermore, when using the "alvis" filter
- # (as we do for IRSpy) it doesn't support the use of any BIB-1
- # access point -- not even 1035 "everywhere" -- so instead we
- # hack together a search that we know will find all records.
- $this->{query} = "port=?*";
+ my @targets;
+ my $targets = $this->{targets};
+ if (defined $targets) {
+ @targets = @$targets;
+ delete $this->{targets};
} else {
- # Prepopulate the target map with nulls so that after we fill
- # in what we can from the database query, we know which target
- # IDs we need new records for.
- foreach my $target (@{ $this->{targets} }) {
- $target2record{lc($target)} = undef;
+ my $rs = $this->{conn}->search(new ZOOM::Query::CQL($this->{query}));
+ $this->log("irspy", "'", $this->{query}, "' found ",
+ $rs->size(), " target records");
+ delete $this->{query};
+
+ foreach my $i (1 .. $rs->size()) {
+ push @targets, render_record($rs, $i-1, "id");
}
}
- $this->log("irspy_debug", "query '", $this->{query}, "'");
- my $rs = $this->{conn}->search(new ZOOM::Query::CQL($this->{query}));
- delete $this->{query}; # No longer needed at all
- $this->log("irspy_debug", "found ", $rs->size(), " target records");
- foreach my $i (1 .. $rs->size()) {
- my $target = _render_record($rs, $i-1, "id");
- my $zeerex = _render_record($rs, $i-1, "zeerex");
- #print STDERR "making '$target' record with '$zeerex'\n";
- $target2record{lc($target)} =
- new ZOOM::IRSpy::Record($this, $target, $zeerex);
- push @{ $this->{targets} }, $target
- if $this->{allrecords};
+ my $n = $this->{activeSetSize};
+ $n = @targets if $n == 0 || $n > @targets;
+
+ $this->{queue} = \@targets;
+ $this->{connections} = [];
+ while (@{ $this->{connections} } < $n) {
+ my $conn = $this->_next_connection();
+ last if !defined $conn;
+ push @{ $this->{connections} }, $conn;
}
+}
- # Make records for targets not previously in the database
- foreach my $target (keys %target2record) {
- my $record = $target2record{$target};
- if (!defined $record) {
- $this->log("irspy_debug", "made new record for '$target'");
- $target2record{$target} = new ZOOM::IRSpy::Record($this, $target);
- } else {
- $this->log("irspy_debug", "using existing record for '$target'");
+
+sub _next_connection {
+ my $this = shift();
+
+ my $target;
+ my $n = $this->{modn};
+ my $i = $this->{modi};
+ if (!defined $n) {
+ $target = shift @{ $this->{queue} };
+ return undef if !defined $target;
+ } else {
+ while (1) {
+ $target = shift @{ $this->{queue} };
+ return undef if !defined $target;
+ my $h = _hash($target);
+ my $hmodn = $h % $n;
+ last if $hmodn == $i;
+ #$this->log("irspy", "'$target' hash $h % $n = $hmodn != $i");
}
}
- my @connections;
- foreach my $target (@{ $this->{targets} }) {
- my $conn = create ZOOM::IRSpy::Connection($this, async => 1);
- $conn->option(host => $target);
- my $record = delete $target2record{lc($target)};
- $conn->record($record);
- push @connections, $conn;
+ die "oops -- target is undefined" if !defined $target;
+ return create ZOOM::IRSpy::Connection($this, $target, async => 1,
+ timeout => $this->{timeout});
+}
+
+
+sub _hash {
+ my($target) = @_;
+
+ my $n = 0;
+ foreach my $s (split //, $target) {
+ $n += ord($s);
}
- die("remaining target2record = { " .
- join(", ", map { "$_ ->'" . $target2record{$_}. "'" }
- sort keys %target2record) . " }")
- if %target2record;
- $this->{connections} = \@connections;
- delete $this->{targets}; # The information is now in {connections}
+ return $n;
}
-sub _render_record {
- my($rs, $which, $elementSetName) = @_;
+sub _irspy_to_zeerex {
+ my $this = shift();
+ my($conn) = @_;
- # There is a slight race condition here on the element-set name,
- # but it shouldn't be a problem as this is (currently) only called
- # from parts of the program that run single-threaded.
- my $old = $rs->option(elementSetName => $elementSetName);
- my $rec = $rs->record($which);
- $rs->option(elementSetName => $old);
+ my $save_xml = $ENV{IRSPY_SAVE_XML};
+ my $irspy_doc = $conn->record()->{zeerex}->ownerDocument;
- return $rec->render();
+ if ($save_xml) {
+ unlink('/tmp/irspy_orig.xml');
+ open FH, '>/tmp/irspy_orig.xml'
+ or die "can't write irspy_orig.xml: $!";
+ print FH $irspy_doc->toString();
+ close FH;
+ }
+ my %params = ();
+ my $result = $this->{irspy_to_zeerex_style}->transform($irspy_doc, %params);
+ if ($save_xml) {
+ unlink('/tmp/irspy_transformed.xml');
+ open FH, '>/tmp/irspy_transformed.xml'
+ or die "can't write irspy_transformed.xml: $!";
+ print FH $result->toString();
+ close FH;
+ }
+
+ return $result->documentElement();
}
-sub _rewrite_records {
+sub _rewrite_irspy_record {
my $this = shift();
+ my($conn) = @_;
- # Write modified records back to database
- foreach my $conn (@{ $this->{connections} }) {
- my $rec = $conn->record();
- my $p = $this->{conn}->package();
- $p->option(action => "specialUpdate");
- my $xml = $rec->{zeerex}->toString();
- $p->option(record => $xml);
- $p->send("update");
- $p->destroy();
-
- $p = $this->{conn}->package();
- $p->send("commit");
- $p->destroy();
- if (0) {
- $xml =~ s/&/&/g;
- $xml =~ s/</g;
- $xml =~ s/>/>/g;
- print "Updated with xml=
\n
$xml\n"; - } + $conn->log("irspy", "rewriting XML record"); + my $rec = $this->_irspy_to_zeerex($conn); + + # Since IRSpy can run for a long time between writes back to the + # database, it's quite possible for the server to have closed the + # connection as idle. So re-establish it if necessary. + $this->{conn}->connect($conn->option("host")); + + _rewrite_zeerex_record($this->{conn}, $rec); + $conn->log("irspy", "rewrote XML record"); +} + + +my $_reliabilityField = { + reliability => [ reliability => 0, + "Calculated reliability of server", + "e:serverInfo/e:reliability" ], +}; + +sub _rewrite_zeerex_record { + my($conn, $rec, $oldid) = @_; + + # Add reliability score + my $xc = irspy_xpath_context($rec); + my($nok, $nall, $percent) = calc_reliability_stats($xc); + modify_xml_document($xc, $_reliabilityField, { reliability => $percent }); + + my $p = $conn->package(); + $p->option(action => "specialUpdate"); + my $xml = $rec->toString(); + $p->option(record => $xml); + $p->send("update"); + $p->destroy(); + + # This is the expression in the ID-making stylesheet + # ../../zebra/zeerex2id.xsl + my $id = irspy_record2identifier($xc); + if (defined $oldid && $id ne $oldid) { + warn "IDs differ (old='$oldid' new='$id')"; + _delete_record($conn, $oldid); + } + + $p = $conn->package(); + $p->send("commit"); + $p->destroy(); + if (0) { + $xml =~ s/&/&/g; + $xml =~ s/</g; + $xml =~ s/>/>/g; + print "Updated $conn with xml=
$xml\n"; } } +sub _delete_record { + my($conn, $id) = @_; + + # We can't delete records using recordIdOpaque, since character + # sets are handled differently here in extended services from how + # they are used in the Alvis filter's record-parsing, and so + # non-ASCII characters come out differently in the two contexts. + # Instead, we must send a record whose contents indicate the ID of + # that which we wish to delete. There are two ways, both + # unsatisfactory: we could either fetch the actual record them + # resubmit it in the deletion request (which wastes a search and a + # fetch) or we could build a record by hand from the parsed-out + # components (which is error-prone and which I am not 100% certain + # will work since the other contents of the record will be + # different). The former evil seems to be the lesser. + + warn "$conn deleting record '$id'"; + + my $rs = $conn->search(new ZOOM::Query::CQL(cql_target($id))); + die "no such ID '$id'" if $rs->size() == 0; + my $rec = $rs->record(0); + my $xml = $rec->render(); + + my $p = $conn->package(); + $p->option(action => "recordDelete"); + $p->option(record => $xml); + $p->send("update"); + $p->destroy(); + + $p = $conn->package(); + $p->send("commit"); + $p->destroy(); +} + + # The approach: gather declarative information about test hierarchy, # then go into a loop. In the loop, we ensure that each connection is # running a test, and within that test a task, until its list of tests @@ -279,31 +471,60 @@ sub _rewrite_records { # sub check { my $this = shift(); - my($tname) = @_; - $tname = "Main" if !defined $tname; - $this->{tree} = $this->_gather_tests($tname) - or die "No tests defined"; - #$this->{tree}->print(0); - my $nskipped = 0; + my $topname = $this->{tree}->name(); + my $timeout = $this->{timeout}; + $this->log("irspy", "beginnning with test '$topname' (timeout $timeout)"); + my $nskipped = 0; my @conn = @{ $this->{connections} }; + my $nruns = 0; + ROUND_AND_ROUND_WE_GO: while (1) { my @copy_conn = @conn; # avoid alias problems after splice() + my $nconn = scalar(@copy_conn); + foreach my $i0 (0 .. $#copy_conn) { my $conn = $copy_conn[$i0]; - #print "connection $i0 of ", scalar(@copy_conn), " from ", scalar(@conn), " is $conn\n"; + #print "connection $i0 of $nconn/", scalar(@conn), " is $conn\n"; + next if !defined $conn; + if (!$conn->current_task()) { if (!$conn->next_task()) { # Out of tasks: we need a new test NEXT_TEST: my $address = $conn->option("current_test_address"); - my $nextaddr = defined $address ? - $this->_next_test($address) : ""; + my $nextaddr; + if (!defined $address) { + $nextaddr = ""; + } else { + $conn->log("irspy_test", + "checking for next test after '$address'"); + $nextaddr = $this->_next_test($address); + } + + if (ZOOM::IRSpy::Test::zoom_error_timeout_check($conn)) { + $conn->log("irspy", "Got to many timeouts, stop testing"); + undef $nextaddr; + } + if (!defined $nextaddr) { $conn->log("irspy", "has no more tests: removing"); - splice @conn, $i0, 1; + $this->_rewrite_irspy_record($conn); + $conn->option(rewrote_record => 1); + my $newconn = $this->_next_connection(); + if (!defined $newconn) { + # Do not destroy: needed for later sanity checks + splice @conn, $i0, 1; + } else { + $conn->destroy(); + $conn[$i0] = $newconn; + $conn[$i0]->option(current_test_address => ""); + $conn[$i0]->log("irspy", "entering active pool - ", + scalar(@{ $this->{queue} }), + " targets remain in queue"); + } next; } @@ -311,7 +532,15 @@ sub check { or die "invalid nextaddr '$nextaddr'"; $conn->option(current_test_address => $nextaddr); my $tname = $node->name(); - $conn->log("irspy", "starting test '$nextaddr' = $tname"); + if ($this->should_skip_test($tname)) { + $conn->log("irspy_test", + "skipping test '$nextaddr' = $tname due to rule"); + $nskipped += 1; + goto NEXT_TEST; + } + + $conn->log("irspy_test", + "starting test '$nextaddr' = $tname"); my $tasks = $conn->tasks(); my $oldcount = @$tasks; "ZOOM::IRSpy::Test::$tname"->start($conn); @@ -320,54 +549,62 @@ sub check { # Prepare to start the first of the newly added tasks $conn->next_task($tasks->[$oldcount]); } else { - $conn->log("irspy", "no tasks added by new test $tname"); + $conn->log("irspy_task", + "no tasks added by new test $tname"); goto NEXT_TEST; } } my $task = $conn->next_task(); die "no next task queued for $conn" if !defined $task; - $conn->log("irspy", "starting task $task"); + + # do not run the next task if we got too many timeouts + if (ZOOM::IRSpy::Test::zoom_error_timeout_check($conn)) { + $conn->log("irspy_task", "Got too many timeouts for this target, do not start a new task"); + next; + } + + $conn->log("irspy_task", "preparing task $task"); $conn->next_task(0); $conn->current_task($task); $task->run(); } - - # Do we need to test $conn->is_idle()? I don't think so! } + NEXT_EVENT: my $i0 = ZOOM::event(\@conn); - $this->log("irspy_event", "ZOOM_event(", scalar(@conn), " connections) = $i0"); - last if $i0 == 0 || $i0 == -3; # no events or no connections + $this->log("irspy_event", + "ZOOM_event(", scalar(@conn), " connections) = $i0"); + if ($i0 < 1) { + my %messages = ( + 0 => "no events remain", + -1 => "ZOOM::event() argument not a reference", + -2 => "ZOOM::event() reference not an array", + -3 => "no connections remain", + -4 => "too many connections for ZOOM::event()", + ); + my $message = $messages{$i0} || "ZOOM::event() returned $i0"; + $this->log("irspy", $message); + last; + } + my $conn = $conn[$i0-1]; my $ev = $conn->last_event(); my $evstr = ZOOM::event_str($ev); $conn->log("irspy_event", "event $ev ($evstr)"); + goto NEXT_EVENT if $ev != ZOOM::Event::ZEND; my $task = $conn->current_task(); die "$conn has no current task for event $ev ($evstr)" if !$task; - eval { $conn->_check() }; - if ($@ && - ($ev == ZOOM::Event::RECV_DATA || - $ev == ZOOM::Event::RECV_APDU || - $ev == ZOOM::Event::ZEND)) { - # An error in, say, a search response, becomes visible to - # ZOOM before the Receive Data event is sent and persists - # until after the End, which means that successive events - # each report the same error. So we just ignore errors on - # "unimportant" events. ### But this doesn't work for, - # say, a Connection Refused, as the only event that shows - # us this error is the End. - $conn->log("irspy_event", "ignoring error ", - "on event $ev ($evstr): $@"); - next; - } my $res; - if ($@) { + eval { $conn->check() }; + if ($@ && ref $@ && $@->isa("ZOOM::Exception")) { my $sub = $task->{cb}->{exception}; die $@ if !defined $sub; $res = &$sub($conn, $task, $task->udata(), $@); + } elsif ($@) { + die "Unexpected non-ZOOM exception: " . ref($@) . " ($@)"; } else { my $sub = $task->{cb}->{$ev}; if (!defined $sub) { @@ -385,31 +622,159 @@ sub check { my $task = $conn->current_task(); die "no task for TASK_DONE on $conn" if !$task; die "next task already defined for $conn" if $conn->next_task(); - $conn->log("irspy", "completed task $task"); + $conn->log("irspy_task", "completed task $task"); $conn->next_task($task->{next}); $conn->current_task(0); } elsif ($res == ZOOM::IRSpy::Status::TEST_GOOD || $res == ZOOM::IRSpy::Status::TEST_BAD) { my $x = ($res == ZOOM::IRSpy::Status::TEST_GOOD) ? "good" : "bad"; - $conn->log("irspy", "test completed ($x)"); + $conn->log("irspy_task", "test ended during task $task ($x)"); + $conn->log("irspy_test", "test completed ($x)"); $conn->current_task(0); $conn->next_task(0); if ($res == ZOOM::IRSpy::Status::TEST_BAD) { - ### Should skip over remaining sibling tests if TEST_BAD - ### Should count the number of skipped siblings - $nskipped += 1; + my $address = $conn->option('current_test_address'); + $conn->log("irspy", "top-level test failed!") + if $address eq ""; + my $node = $this->{tree}->select($address); + my $skipcount = 0; + while (defined $node->next() && + length($node->next()->address()) >= length($address)) { + $conn->log("irspy_debug", "skipping from '", + $node->address(), "' to '", + $node->next()->address(), "'"); + $node = $node->next(); + $skipcount++; + } + + $conn->option(current_test_address => $node->address()); + $conn->log("irspy_test", "skipped $skipcount tests"); + $nskipped += $skipcount; } + + } elsif ($res == ZOOM::IRSpy::Status::TEST_SKIPPED) { + $conn->log("irspy_test", "test skipped during task $task"); + $conn->current_task(0); + $conn->next_task(0); + $nskipped++; + + } else { + die "unknown callback return-value '$res'"; + } + } + + $this->log("irspy", "exiting main loop"); + + # Sanity checks: none of the following should ever happen + my $finished = 1; + $this->log("irspy", "performing end-of-run sanity-checks"); + foreach my $conn (@conn) { + my $test = $conn->option("current_test_address"); + my $next = $this->_next_test($test); + if (defined $next) { + $this->log("irspy", + "$conn (in test '$test') has queued test '$next'"); + $finished = 0; + } + if (my $task = $conn->current_task()) { + $this->log("irspy", "$conn still has an active task $task"); + $finished = 0; + } + if (my $task = $conn->next_task()) { + $this->log("irspy", "$conn still has a queued task $task"); + $finished = 0; + } + if (!$conn->is_idle()) { + $this->log("irspy", + "$conn still has ZOOM-C level tasks queued: see below"); + $finished = 0; + } + my $ev = $conn->peek_event(); + if ($ev != 0 && $ev != ZOOM::Event::ZEND) { + my $evstr = ZOOM::event_str($ev); + $this->log("irspy", "$conn has event $ev ($evstr) waiting"); + $finished = 0; + } + if (!$conn->option("rewrote_record")) { + $this->log("irspy", "$conn did not rewrite its ZeeRex record"); + $finished = 0; } } - $this->log("irspy_event", "no more events: finishing"); + # This really shouldn't be necessary, and in practice it rarely + # helps, but it's belt and braces. (For now, we don't do this + # hence the zero in the $nruns check). + if (!$finished) { + if (++$nruns < 0) { + $this->log("irspy", "back into main loop, ${nruns}th time"); + goto ROUND_AND_ROUND_WE_GO; + } else { + $this->log("irspy", "bailing after $nruns main-loop runs"); + } + } + + # This shouldn't happen emit anything either: + while ((my $i1 = ZOOM::event(\@conn)) > 0) { + my $conn = $conn[$i1-1]; + my $ev = $conn->last_event(); + my $evstr = ZOOM::event_str($ev); + $this->log("irspy", + "$conn still has ZOOM-C level task queued: $ev ($evstr)") + if $ev != ZOOM::Event::ZEND; + } - #$this->_rewrite_records(); return $nskipped; } +### This could of course call a much more general looping evaluator +sub should_skip_test { + my $this = shift(); + my($tname) = @_; + + foreach my $rule (@{ $this->{rules} }) { + my($name, $op, $val, $rule, @params) = @$rule; + #warn "using name='$name', op='$op', val='$val', rule='$rule', params='@params'\n"; + if ($op eq "~" && + $rule eq "skip" && + $params[0] eq $tname) { + my $re = $val; + $re =~ s/^\/(.*)\/$/$1/; + if ($this->var($name) =~ $re) { + #warn "$name '", $this->var($name), "' matches /$re/ -- skipping '$tname'"; + return 1; + } + } + } + + return 0; +} + + +# Exactly equivalent to ZOOM::event() except that it is tolerant to +# undefined values in the array being passed in. +# +sub __UNUSED_tolerant_ZOOM_event { + my($connref) = @_; + + my(@conn, @map); + foreach my $i (0 .. @$connref-1) { + my $conn = $connref->[$i]; + if (defined $conn) { + push @conn, $conn; + push @map, $i; + } + } + + my $res = ZOOM::event(\@conn); + return $res if $res <= 0; + my $res2 = $map[$res-1] + 1; + print STDERR "*** tolerant_ZOOM_event() returns $res->$res2\n"; + return $res2; +} + + sub _gather_tests { my $this = shift(); my($tname, @ancestors) = @_; @@ -418,11 +783,14 @@ sub _gather_tests { join(" -> ", @ancestors, $tname)) if grep { $_ eq $tname } @ancestors; + my $slashSeperatedTname = $tname; + $slashSeperatedTname =~ s/::/\//g; + my $fullName = "ZOOM/IRSpy/Test/$slashSeperatedTname.pm"; + eval { - my $slashSeperatedTname = $tname; - $slashSeperatedTname =~ s/::/\//g; - require "ZOOM/IRSpy/Test/$slashSeperatedTname.pm"; + require $fullName; }; if ($@) { + $this->log("irspy", "couldn't require '$fullName': $@"); $this->log("warn", "can't load test '$tname': skipping", $@ =~ /^Can.t locate/ ? () : " ($@)"); return undef; @@ -439,12 +807,11 @@ sub _gather_tests { } +# These next three should arguably be Node methods sub _next_test { my $this = shift(); my($address, $omit_child) = @_; - $this->log("irspy", "checking for next test after '$address'"); - # Try first child if (!$omit_child) { my $maybe = $address eq "" ? "0" : "$address:0"; @@ -455,7 +822,10 @@ sub _next_test { return undef if $address eq ""; # Try next sibling child - my @components = split /:/, $address; + # The use of a regexp in split() is to avoid confusing Emacs's + # Perl mode; the third colon is to avoid looking like a POSIX + # named character class ... *sigh* + my @components = split /[:::]/, $address; my $last = pop @components; my $maybe = join(":", @components, $last+1); return $maybe if $this->{tree}->select($maybe); @@ -465,6 +835,40 @@ sub _next_test { } +sub _last_sibling_test { + die "_last_sibling_test() called -- I thought that never happened?"; + my $this = shift(); + my($address) = @_; + + return undef + if !defined $this->_next_sibling_test($address); + + my $nskipped = 0; + while (1) { + my $maybe = $this->_next_sibling_test($address); + last if !defined $maybe; + $nskipped++; + $address = $maybe; + $this->log("irspy", "skipping $nskipped tests to '$address'"); + } + + return ($address, $nskipped); +} + + +sub _next_sibling_test { + die "_next_sibling_test() called -- I thought that never happened?"; + my $this = shift(); + my($address) = @_; + + my @components = split /[:::]/, $address; + my $last = pop @components; + my $maybe = join(":", @components, $last+1); + return $maybe if $this->{tree}->select($maybe); + return undef; +} + + =head1 SEE ALSO ZOOM::IRSpy::Record,