Index: trunk/pstamp/scripts/pstamp_checkdependent.pl
===================================================================
--- trunk/pstamp/scripts/pstamp_checkdependent.pl	(revision 37772)
+++ trunk/pstamp/scripts/pstamp_checkdependent.pl	(revision 37784)
@@ -24,4 +24,7 @@
 my $ra_max_3PI_hours = 22.5;  # disable updates for skycells with ra greater than this (hours)
 my $ra_max_3PI = $ra_max_3PI_hours * 15 * 3.14149 / 180.; # rawExp.ra is in radians
+
+# verbose flag for parse commands
+my $parse_verbose = 0;
 
 # XXX: put this in a module somewhere
@@ -49,4 +52,5 @@
     'dbserver=s'    =>  \$ps_dbserver,  # postage stamp server dbserver
     'verbose'       =>  \$verbose,
+    'parse-verbose' =>  \$parse_verbose,
     'save-temps'    =>  \$save_temps,
     'no-update'     =>  \$no_update,
@@ -78,4 +82,6 @@
 }
 
+print "\n==== Starting dependency checking for $dep_id $stage $stage_id $component at " . (scalar localtime) . ". ====\n";
+
 if ($label) {
     # rlabel is deprecated. Use one based on the supplied label parameter which is the current label 
@@ -84,4 +90,5 @@
     # (and formerly in pstampparse.pl) is not particularly clean but it's simple.
     my $new_rlabel = 'ps_ud_' . $label;
+    $rlabel = "undefined" if !defined $rlabel;
     if ($new_rlabel ne $rlabel) {
         print "Notice: using $new_rlabel instead of $rlabel for update label.\n";
@@ -120,5 +127,5 @@
 }
 
-my $it = runToolAndParseExpectOne($cmd, $verbose);
+my $it = runToolAndParseExpectOne($cmd, $parse_verbose);
 
 my_die("no components found", $PS_EXIT_PROG_ERROR) if ( !$it);
@@ -136,4 +143,5 @@
 }
 
+
 # magic is no longer rquired
 $need_magic = 0;
@@ -142,4 +150,5 @@
 if ((($it->{state} eq 'full') or ($it->{state} eq 'update')) and ($it->{data_state} eq 'full')) {
 
+    print "\nDependency Satisfied for $stage $stage_id $component\n";
     # This Dependency is satisfied. All done. Release the pstampJobs
     #
@@ -178,5 +187,5 @@
         }
 
-        # assume the fault is transient.
+        # hope the fault is transient.
         # fault the dependent to give the fault a chance to correct itself
         my_die("Component faulted on update dep_id: $dep_id", $PS_EXIT_SYS_ERROR);
@@ -279,5 +288,5 @@
             ($fault eq $PSTAMP_GONE)) {
 
-            print "chipRun state is $chip->{chip_id} has state: $state data_state: $data_state fault: $fault cannot update\n";
+            print "chipRun state is $chip->{chip_id} has state: $state class_id $chip->{class_id} data_state: $data_state fault: $fault cannot update.\n";
             my $error_code;
             if (($state eq 'error_cleaned') or ($data_state ='error_cleaned')) {
@@ -291,10 +300,10 @@
         } elsif ($chip->{state} eq 'goto_cleaned') {
 
-            # we don't need to check for full data_state
-            # if ($chip->{data_state} eq 'full') {
             {
+                print "dependent chip is in state goto_cleaned, changing state to update.\n";
+
                 # cleanup must not be running. Set state to update. If this chip is not 'full' it will be
                 # set to be updated the next time this script is invoked
-                # XXX: In the very rare case that this chip run is actually in the running cleanup pantasks
+                # XXX: In the very unlikely case that this chip run is actually in the running cleanup pantasks
                 # queue things may get confused but we can live with that
                 my $command = "$chiptool -updaterun -set_state update -chip_id $chip_id";
@@ -313,4 +322,6 @@
             }
         } elsif (($chip->{data_state} ne 'update') and ($chip->{data_state} ne 'full')) {
+
+            print "Setting chip imfile $chip_id $chip->{class_id} to be updated.\n";
 
             # chiptool does more state checking to insure this isn't done prematurely.
@@ -343,4 +354,5 @@
             # we've had a number of runs in this limbo state
 
+            print "Changing chip run $chip_id to state update for $chip->{class_id} which is in data_state update.\n";
             my $command = "$chiptool -updaterun -set_state update -chip_id $chip_id";
             $command .= " -set_label $rlabel" if $rlabel;
@@ -364,5 +376,5 @@
                 return $PSTAMP_GONE;
             } elsif ($fault_count > $max_fault_count) {
-                print "$stage $stage_id has faulted $fault_count times. Giving up\n";
+                print "Dependency for $stage $stage_id has been found in fault state $fault_count times. Giving up. Fault: $fault\n";
                 # XXX: stop faulting chips for now
 #                $fault = $PSTAMP_GONE;
@@ -421,5 +433,5 @@
     if (($state =~ /error/) or ($state =~ /purged/) or ($state =~ /scrubbed/) or ($state eq 'drop') or
          ($data_state =~ /error/) or ($data_state =~ /purged/) or ($data_state =~ /scrubbed/) or ($data_state eq 'drop')) {
-        print STDERR "warpRun $warp_id $skycell_id has state $state $data_state faulting jobs\n";
+        print STDERR "warpRun $warp_id $skycell_id has state $state $data_state faulting jobs.\n";
         my $error_code;
         if (($state eq 'error_cleaned') or ($data_state eq 'error_cleaned')) {
@@ -430,12 +442,14 @@
         return $error_code
     }
-    if (($data_state eq 'full') and ($metadata->{fault})) {
+    if ((($data_state eq 'full') or ($data_state eq 'update')) and ($metadata->{fault})) {
         # fault dependent.
         my $fault = $metadata->{fault};
-        print STDERR "warp $warp_id $skycell_id faulted: $fault";
+        print STDERR "warp $warp_id $skycell_id faulted with code: $fault.";
+        # XXX: TODO maybe: If ($fault != 2 and $fault != $PSTAMP_GONE) revert the skycell. The warp task only reverts fault 2
+        # and sometimes warps will fault due to nfs problems that end up with fault = 4;.
         return $fault;
     }
     if ($metadata->{quality} ne 0) {
-        print STDERR "warp $warp_id $skycell_id bad quality on update: $metadata->{quality}\n";
+        print STDERR "warp $warp_id $skycell_id bad quality on update: $metadata->{quality}.\n";
         return $PSTAMP_GONE;
     }
@@ -448,4 +462,5 @@
         # It's "safe" to set the state to update. If the skycell is not full it will be set to update
         # the next time this task runs
+        print "Change state of warp $warp_id to update.\n";
         my $command = "$warptool -updaterun -set_state update -warp_id $warp_id";
         $command .= " -set_label $rlabel" if $rlabel;
@@ -465,10 +480,10 @@
     # get the list of input chips for this skycell
     my $command = "$warptool -scmap -warp_id $warp_id -skycell_id $skycell_id";
-    my $data = runToolAndParse($command, $verbose);
+    my $data = runToolAndParse($command, $parse_verbose);
     if (!$data or scalar @$data == 0) {
         # This happens if the chipProcessedImfile disappears which happened when earlier
         # versions of chiptool -revertprocessedimfile didn't check the chipRun.state before
         # deleting the row. 
-        print STDERR "failed to find warpSkyCelllMap for warpRun $warp_id skycell_id $skycell_id";
+        print STDERR "failed to find warpSkyCellMap for warpRun $warp_id skycell_id $skycell_id";
         return $PSTAMP_GONE;
     }
@@ -478,4 +493,5 @@
     my $chip_id;
     foreach my $chip (@$data) {
+        # XXX: change tools to include cam_state (camRun.state). If it is not full the warp updates will never run.
         my $cam_fault = $chip->{cam_fault};
         if (defined $cam_fault and $cam_fault > 0) {
@@ -488,7 +504,7 @@
         $chip->{decl} = $metadata->{decl};
 
+if (0) {
         # if chip has been magicked before require it to be magicked again
         # because the warp pending query requires it.
-if (0) {
         if ($chip->{magicked} < 0) {
             print "Input has been destreaked so we must destreak before warping\n";
@@ -514,4 +530,5 @@
         # the reason we defer setting the warp to update is so that we can handle error conditions at previous
         # stages more easily.
+        print "Chips are ready for warp $warp_id $skycell->{skycell_id}. Setting skycell to be updated.\n";
         my $command = "$warptool -setskyfiletoupdate -warp_id $warp_id -skycell_id $skycell->{skycell_id}";
         $command .= " -set_label $rlabel" if $rlabel;
@@ -527,4 +544,5 @@
         }
     } elsif ($chips_ready and $skycell->{data_state} eq 'update' and $skycell->{state} ne 'update') {
+        print "Chips are ready for warp $warp_id $skycell->{skycell_id} but run state is $skycell->{state}. Changing state to update.\n";
         my $command = "$warptool -updaterun -warp_id $warp_id -set_state update";
         $command .= " -set_label $rlabel" if $rlabel;
@@ -566,9 +584,8 @@
     my $skycell_id = $skycell->{skycell_id};
 
-    # if ($metadata->{state} eq 'goto_cleaned' and $metadata->{data_state} eq 'full') {
     if ($metadata->{state} eq 'goto_cleaned') {
         # cleanup must not be running. Set state to update. If the skycell is not 'full' it will be
-        # set to be updated the next time this script is invoked
-        print "changing state of diffRun $diff_id from goto_cleaned to update. skycell $skycell_id is full\n";
+        # set to be updated the next time this script is invoked.
+        print "Changing state of diffRun $diff_id from goto_cleaned to update.\n";
         my $command = "$difftool -updaterun -set_state update -diff_id $diff_id";
         $command .= " -set_label $rlabel" if $rlabel;
@@ -589,5 +606,5 @@
         # check the state of the template stack
         my $command = "$stacktool -sumskyfile -stack_id $skycell->{stack2}";
-        my $stack = runToolAndParseExpectOne($command, $verbose);
+        my $stack = runToolAndParseExpectOne($command, $parse_verbose);
         my_die("failed to find stackSumSkyfile for stack_id $skycell->{stack2}", $PS_EXIT_UNKNOWN_ERROR) if !$stack;
 
@@ -597,8 +614,9 @@
             return $PSTAMP_GONE;
         }
+        print " Stack $skycell->{stack2} is ready.\n";
 
         # now check the warp
         $command = "$warptool -warped -warp_id $skycell->{warp1} -skycell_id $skycell_id";
-        my $warp = runToolAndParseExpectOne($command, $verbose);
+        my $warp = runToolAndParseExpectOne($command, $parse_verbose);
         my_die("failed to find warpSkyfile for warpRun $skycell->{warp1} skycell_id $skycell_id", $PS_EXIT_UNKNOWN_ERROR) if !$warp;
 
@@ -615,7 +633,8 @@
         }
         # warps are ready fall through and queue the diff update
+        print " Warp $skycell->{warp1} $skycell_id is ready.\n";
     } elsif ($diff_mode eq $IPP_DIFF_MODE_WARP_WARP) {
         my $command = "$warptool -warped -warp_id $skycell->{warp1} -skycell_id $skycell_id";
-        my $warp1 = runToolAndParseExpectOne($command, $verbose);
+        my $warp1 = runToolAndParseExpectOne($command, $parse_verbose);
         my_die("failed to find warpSkyfile for warpRun $skycell->{warp1} skycell_id $skycell_id", $PS_EXIT_UNKNOWN_ERROR) if !$warp1;
 
@@ -637,5 +656,5 @@
 	}
         $command = "$warptool -warped -warp_id $skycell->{warp2} -skycell_id $skycell_id";
-        my $warp2 = runToolAndParseExpectOne($command, $verbose);
+        my $warp2 = runToolAndParseExpectOne($command, $parse_verbose);
         my_die("failed to find warpSkyfile for warpRun $skycell->{warp2} skycell_id $skycell_id", $PS_EXIT_UNKNOWN_ERROR) if !$warp2;
 
@@ -661,5 +680,5 @@
         # check the state of the input stack
         my $command = "$stacktool -sumskyfile -stack_id $skycell->{stack1}";
-        my $stack1 = runToolAndParseExpectOne($command, $verbose);
+        my $stack1 = runToolAndParseExpectOne($command, $parse_verbose);
         my_die("failed to find stackSumSkyfile for stack_id $skycell->{stack1}", $PS_EXIT_UNKNOWN_ERROR) if !$stack1;
 
@@ -671,5 +690,5 @@
         # check the state of the template stack
         $command = "$stacktool -sumskyfile -stack_id $skycell->{stack2}";
-        my $stack2 = runToolAndParseExpectOne($command, $verbose);
+        my $stack2 = runToolAndParseExpectOne($command, $parse_verbose);
         my_die("failed to find stackSumSkyfile for stack_id $skycell->{stack2}", $PS_EXIT_UNKNOWN_ERROR) if !$stack2;
 
@@ -684,5 +703,5 @@
         # check the state of the input stack
         my $command = "$stacktool -sumskyfile -stack_id $skycell->{stack1}";
-        my $stack = runToolAndParseExpectOne($command, $verbose);
+        my $stack = runToolAndParseExpectOne($command, $parse_verbose);
         my_die("failed to find stackSumSkyfile for stack_id $skycell->{stack1}", $PS_EXIT_UNKNOWN_ERROR) if !$stack;
 
@@ -695,5 +714,5 @@
         # now check the template warp
         $command = "$warptool -warped -warp_id $skycell->{warp2} -skycell_id $skycell_id";
-        my $warp = runToolAndParseExpectOne($command, $verbose);
+        my $warp = runToolAndParseExpectOne($command, $parse_verbose);
         my_die("failed to find warpSkyfile for warpRun $skycell->{warp2} skycell_id $skycell_id", $PS_EXIT_UNKNOWN_ERROR) if !$warp;
 
@@ -736,4 +755,6 @@
             print "skipping $command\n";
         }
+    } else {
+        print " diff is in update state\n";
     }
 
@@ -763,5 +784,7 @@
     my $now = DateTime->now->mjd;
     my $dtime_tool = (DateTime->now->mjd - $start_tool) * 86400.;
-    print "Time to run $program: $dtime_tool\n";
+    if ($dtime_tool > 0.1) {
+        print "Time to run $program: $dtime_tool\n";
+    }
 
     my $buf = join "", @$stdout_buf;
@@ -777,5 +800,7 @@
 
     my $dtime_parse = (DateTime->now->mjd - $start_parse) * 86400.;
-    print "Time to parse results from $program: $dtime_parse\n";
+    if ($dtime_parse > 0.1) {
+        print "Time to parse results from $program: $dtime_parse\n";
+    }
 
     return $results;
@@ -848,5 +873,5 @@
     if (!$dsRun_state) {
         my $command = "$chiptool -listrun -chip_id $stage_id";
-        my $data = runToolAndParse($command, $verbose);
+        my $data = runToolAndParse($command, $parse_verbose);
         my $chipRun = $data->[0];
         $dsRun_state = $chipRun->{dsRun_state};
@@ -862,5 +887,5 @@
             foreach my $c (@$components) {
                 my $command = "$magicdstool -destreakedfile -magic_ds_id $magic_ds_id -component $c";
-                my $dsfile = runToolAndParseExpectOne($command, $verbose);
+                my $dsfile = runToolAndParseExpectOne($command, $parse_verbose);
                 if (!$dsfile) {
                     my_die("failed to find magicDSFile for ${stage}Run $stage_id $c", $PS_EXIT_UNKNOWN_ERROR);