Logging changed and made more coherent
authorMike Taylor <mike@indexdata.com>
Thu, 12 Oct 2006 16:54:13 +0000 (16:54 +0000)
committerMike Taylor <mike@indexdata.com>
Thu, 12 Oct 2006 16:54:13 +0000 (16:54 +0000)
lib/ZOOM/IRSpy.pm
lib/ZOOM/IRSpy/Connection.pm
lib/ZOOM/IRSpy/Record.pm
lib/ZOOM/IRSpy/Task/Connect.pm
lib/ZOOM/IRSpy/Task/Search.pm
lib/ZOOM/IRSpy/Test/Main.pm
lib/ZOOM/IRSpy/Test/Search/Main.pm
lib/ZOOM/IRSpy/Test/Search/Title.pm

index 362e8b0..8320c84 100644 (file)
@@ -1,4 +1,4 @@
-# $Id: IRSpy.pm,v 1.28 2006-10-12 15:51:37 mike Exp $
+# $Id: IRSpy.pm,v 1.29 2006-10-12 16:54:13 mike Exp $
 
 package ZOOM::IRSpy;
 
@@ -46,10 +46,11 @@ 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 {
@@ -299,8 +300,13 @@ sub check {
                    # 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 {
+                       $this->log("irspy_test", "checking for next test after '$address'");
+                       $nextaddr = $this->_next_test($address);
+                   }
                    if (!defined $nextaddr) {
                        $conn->log("irspy", "has no more tests: removing");
                        splice @conn, $i0, 1;
@@ -311,7 +317,7 @@ sub check {
                        or die "invalid nextaddr '$nextaddr'";
                    $conn->option(current_test_address => $nextaddr);
                    my $tname = $node->name();
-                   $conn->log("irspy", "starting test '$nextaddr' = $tname");
+                   $conn->log("irspy_test", "starting test '$nextaddr' = $tname");
                    my $tasks = $conn->tasks();
                    my $oldcount = @$tasks;
                    "ZOOM::IRSpy::Test::$tname"->start($conn);
@@ -320,14 +326,14 @@ 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");
+               $conn->log("irspy_task", "starting task $task");
                $conn->next_task(0);
                $conn->current_task($task);
                $task->run();
@@ -385,14 +391,14 @@ 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_test", "test completed ($x)");
            $conn->current_task(0);
            $conn->next_task(0);
            if ($res == ZOOM::IRSpy::Status::TEST_BAD) {
@@ -403,7 +409,7 @@ sub check {
        }
     }
 
-    $this->log("irspy_event", "no more events: finishing");
+    $this->log("irspy", "exiting main loop");
 
     #$this->_rewrite_records();
     return $nskipped;
@@ -443,8 +449,6 @@ 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";
index 656bd3b..86a8f84 100644 (file)
@@ -1,4 +1,4 @@
-# $Id: Connection.pm,v 1.3 2006-10-12 14:35:43 mike Exp $
+# $Id: Connection.pm,v 1.4 2006-10-12 16:54:13 mike Exp $
 
 package ZOOM::IRSpy::Connection;
 
@@ -73,7 +73,7 @@ sub current_task {
     my $old = $this->{current_task};
     if (defined $new) {
        $this->{current_task} = $new;
-       $this->log("irspy_debug", "set current task to $new");
+       $this->log("irspy_task", "set current task to $new");
     }
 
     return $old;
@@ -87,7 +87,7 @@ sub next_task {
     my $old = $this->{next_task};
     if (defined $new) {
        $this->{next_task} = $new;
-       $this->log("irspy_debug", "set next task to $new");
+       $this->log("irspy_task", "set next task to $new");
     }
 
     return $old;
@@ -108,7 +108,6 @@ sub irspy_connect {
 
     my $task = new ZOOM::IRSpy::Task::Connect($this, $udata, %cb);
     $this->add_task($task);
-    $this->log("irspy", "registered connect()");
 }
 
 
@@ -118,7 +117,6 @@ sub irspy_search_pqf {
 
     my $task = new ZOOM::IRSpy::Task::Search($query, $this, $udata, %cb);
     $this->add_task($task);
-    $this->log("irspy", "registered search_pqf($query)");
 }
 
 
@@ -129,7 +127,7 @@ sub add_task {
     my $tasks = $this->{tasks};
     $tasks->[-1]->{next} = $task if @$tasks > 0;
     push @$tasks, $task;
-    $this->log("irspy", "added task $task");
+    $this->log("irspy_task", "added task $task");
 }
 
 
index 1ab5033..d782384 100644 (file)
@@ -1,4 +1,4 @@
-# $Id: Record.pm,v 1.13 2006-09-26 09:08:09 mike Exp $
+# $Id: Record.pm,v 1.14 2006-10-12 16:54:13 mike Exp $
 
 package ZOOM::IRSpy::Record;
 
@@ -105,7 +105,7 @@ sub append_entry {
            if @nodes == 0;
     }
 
-    $this->{irspy}->log("irspy",
+    $this->{irspy}->log("warn",
                        scalar(@nodes), " matches for '$xpath': using first")
        if @nodes > 1;
 
index e850681..ba73cd4 100644 (file)
@@ -1,4 +1,4 @@
-# $Id: Connect.pm,v 1.2 2006-10-11 16:47:44 mike Exp $
+# $Id: Connect.pm,v 1.3 2006-10-12 16:54:13 mike Exp $
 
 # See ZOOM/IRSpy/Task/Search.pm for documentation
 
@@ -21,7 +21,7 @@ sub run {
     my $this = shift();
 
     my $conn = $this->conn();
-    $conn->log("irspy_test", "connecting");
+    $conn->log("irspy_task", "connecting");
     $conn->connect($conn->option("host"));
 }
 
index c0b4322..d9184be 100644 (file)
@@ -1,4 +1,4 @@
-# $Id: Search.pm,v 1.2 2006-10-11 16:48:19 mike Exp $
+# $Id: Search.pm,v 1.3 2006-10-12 16:54:13 mike Exp $
 
 package ZOOM::IRSpy::Task::Search;
 
@@ -38,7 +38,7 @@ sub run {
 
     my $conn = $this->conn();
     my $query = $this->{query};
-    $this->irspy()->log("irspy_test", $conn->option("host"),
+    $this->irspy()->log("irspy_task", $conn->option("host"),
                        " searching for '$query'");
     $this->{rs} = $conn->search_pqf($query);
 
@@ -54,7 +54,7 @@ sub run {
 
 sub render {
     my $this = shift();
-    return ref($this) . " " . $this->{query};
+    return ref($this) . "(" . $this->{query}. ")";
 }
 
 use overload '""' => \&render;
index 71cb9a7..5df65b8 100644 (file)
@@ -1,4 +1,4 @@
-# $Id: Main.pm,v 1.8 2006-10-11 16:46:37 mike Exp $
+# $Id: Main.pm,v 1.9 2006-10-12 16:54:13 mike Exp $
 
 package ZOOM::IRSpy::Test::Main;
 
@@ -30,7 +30,7 @@ sub start {
     my $class = shift();
     my($conn) = @_;
 
-    $conn->log("irspy", "Main test no-opping");
+    $conn->log("irspy_test", "Main test no-opping");
     # Do nothing -- this test is just a subtest container
 }
 
index c9166db..dd9371d 100644 (file)
@@ -1,4 +1,4 @@
-# $Id: Main.pm,v 1.2 2006-10-06 11:33:08 mike Exp $
+# $Id: Main.pm,v 1.3 2006-10-12 16:54:13 mike Exp $
 
 package ZOOM::IRSpy::Test::Search::Main;
 
@@ -12,6 +12,10 @@ our @ISA = qw(ZOOM::IRSpy::Test);
 sub subtests { qw(Search::Title Search::Bib1) }
 
 sub start {
+    my $class = shift();
+    my($conn) = @_;
+
+    $conn->log("irspy_test", "Main::Search test no-opping");
     # Do nothing -- this test is just a subtest container
 }
 
index 3bc6201..44ef9f8 100644 (file)
@@ -1,4 +1,4 @@
-# $Id: Title.pm,v 1.6 2006-10-12 14:38:27 mike Exp $
+# $Id: Title.pm,v 1.7 2006-10-12 16:54:13 mike Exp $
 
 # See the "Main" test package for documentation
 
@@ -39,7 +39,7 @@ sub found {
 sub error {
     my($conn, $task, $__UNUSED_udata, $exception) = @_;
 
-    $conn->log("irspy_test", "error: $exception");
+    $conn->log("irspy_test", "title search had error: $exception");
     my $rec = $conn->record();
     $rec->append_entry("irspy:status", "<irspy:search_title ok='0'>" .
                       isodate(time()) . "</irspy:search_title>");