[PATCH 1/2] testbot: Add history records for mutable task results.

[Francois Gouget]

When a task fails due to a transient error it is re-run and the fact
that a transient error happened cannot be recovered from the final Task
object.
Similarly the final Task object does not clearly identify timeouts.
Furthermore all one can recover from the VM status history is that a
Task was run more than once but not the reason why.
So save abnormal task termination information in the history record.

Signed-off-by: Francois Gouget 
---
 testbot/bin/WineRunBuild.pl    | 20 ++++++++++++++++----
 testbot/bin/WineRunReconfig.pl | 20 ++++++++++++++++----
 testbot/bin/WineRunTask.pl     | 19 ++++++++++++++++---
 testbot/lib/WineTestBot/VMs.pm | 29 +++++++++++++++++++++++++++++
 4 files changed, 77 insertions(+), 11 deletions(-)

diff --git a/testbot/bin/WineRunBuild.pl b/testbot/bin/WineRunBuild.pl
index b91d594b..e4295c8e 100755
--- a/testbot/bin/WineRunBuild.pl
+++ b/testbot/bin/WineRunBuild.pl
@@ -45,6 +45,7 @@ use WineTestBot::Config;
 use WineTestBot::Jobs;
 use WineTestBot::VMs;
 use WineTestBot::Log;
+use WineTestBot::RecordGroups;
 use WineTestBot::Engine::Notify;

@@ -192,10 +193,13 @@ sub LogTaskError($)
   umask($OldUMask);
 }

-sub WrapUpAndExit($;$)
+sub WrapUpAndExit($;$$)
 {
-  my ($Status, $Retry) = @_;
+  my ($Status, $Retry, $Timeout) = @_;
   my $NewVMStatus = $Status eq 'queued' ? 'offline' : 'dirty';
+  my $VMResult = $Status eq "boterror" ? "boterror" :
+                 $Status eq "queued" ? "error" :
+                 $Timeout ? "timeout" : "";

my $TestFailures;
   my $Tries = $Task->TestFailures || 0;
@@ -219,6 +223,13 @@ sub WrapUpAndExit($;$)
     LogTaskError("The previous $Tries run(s) terminated abnormally\n");
   }

+  # Record result details that may be lost or overwritten by a later run
+  if ($VMResult)
+  {
+    $VMResult .= " $Tries $MaxTaskTries" if ($Retry);
+    $VM->RecordResult(undef, $VMResult);
+  }
+
   # Update the Task and Job
   $Task->Status($Status);
   $Task->TestFailures($TestFailures);
@@ -373,7 +384,7 @@ if (!$Pid)
 # log before giving up
 #

-my ($NewStatus, $ErrMessage, $TAError);
+my ($NewStatus, $ErrMessage, $TAError, $TaskTimedOut);
 Debug(Elapsed($Start), " Waiting for the script (", $Task->Timeout, "s timeout)\n");
 if (!defined $TA->Wait($Pid, $Task->Timeout, 60))
 {
@@ -382,6 +393,7 @@ if (!defined $TA->Wait($Pid, $Task->Timeout, 60))
   {
     $ErrMessage = "The build timed out\n";
     $NewStatus = "badbuild";
+    $TaskTimedOut = 1;
   }
   else
   {
@@ -480,4 +492,4 @@ $TA->Disconnect();
 # Wrap up
 #

-WrapUpAndExit($NewStatus);
+WrapUpAndExit($NewStatus, undef, $TaskTimedOut);
diff --git a/testbot/bin/WineRunReconfig.pl b/testbot/bin/WineRunReconfig.pl
index ff99fb7c..4eefa171 100755
--- a/testbot/bin/WineRunReconfig.pl
+++ b/testbot/bin/WineRunReconfig.pl
@@ -45,6 +45,7 @@ use WineTestBot::Config;
 use WineTestBot::Jobs;
 use WineTestBot::VMs;
 use WineTestBot::Log;
+use WineTestBot::RecordGroups;
 use WineTestBot::Engine::Notify;

@@ -192,11 +193,14 @@ sub LogTaskError($)
   umask($OldUMask);
 }

-sub WrapUpAndExit($;$)
+sub WrapUpAndExit($;$$)
 {
-  my ($Status, $Retry) = @_;
+  my ($Status, $Retry, $Timeout) = @_;
   my $NewVMStatus = $Status eq 'queued' ? 'offline' :
                     $Status eq 'completed' ? 'idle' : 'dirty';
+  my $VMResult = $Status eq "boterror" ? "boterror" :
+                 $Status eq "queued" ? "error" :
+                 $Timeout ? "timeout" : "";

my $TestFailures;
   my $Tries = $Task->TestFailures || 0;
@@ -220,6 +224,13 @@ sub WrapUpAndExit($;$)
     LogTaskError("The previous $Tries run(s) terminated abnormally\n");
   }

+  # Record result details that may be lost or overwritten by a later run
+  if ($VMResult)
+  {
+    $VMResult .= " $Tries $MaxTaskTries" if ($Retry);
+    $VM->RecordResult(undef, $VMResult);
+  }
+
   # Update the Task and Job
   $Task->Status($Status);
   $Task->TestFailures($TestFailures);
@@ -338,7 +349,7 @@ if (!$Pid)
 # log before giving up
 #

-my ($NewStatus, $ErrMessage, $TAError);
+my ($NewStatus, $ErrMessage, $TAError, $TaskTimedOut);
 Debug(Elapsed($Start), " Waiting for the script (", $Task->Timeout, "s timeout)\n");
 if (!defined $TA->Wait($Pid, $Task->Timeout, 60))
 {
@@ -347,6 +358,7 @@ if (!defined $TA->Wait($Pid, $Task->Timeout, 60))
   {
     $ErrMessage = "The build timed out\n";
     $NewStatus = "badbuild";
+    $TaskTimedOut = 1;
   }
   else
   {
@@ -470,4 +482,4 @@ if ($NewStatus eq 'completed')
 # Wrap up
 #

-WrapUpAndExit($NewStatus);
+WrapUpAndExit($NewStatus, undef, $TaskTimedOut);
diff --git a/testbot/bin/WineRunTask.pl b/testbot/bin/WineRunTask.pl
index 3807a182..65faf725 100755
--- a/testbot/bin/WineRunTask.pl
+++ b/testbot/bin/WineRunTask.pl
@@ -44,6 +44,7 @@ use WineTestBot::Config;
 use WineTestBot::Jobs;
 use WineTestBot::VMs;
 use WineTestBot::Log;
+use WineTestBot::RecordGroups;
 use WineTestBot::Engine::Notify;

@@ -219,10 +220,13 @@ sub LogTaskError($)
   umask($OldUMask);
 }

-sub WrapUpAndExit($;$$)
+sub WrapUpAndExit($;$$$)
 {
-  my ($Status, $TestFailures, $Retry) = @_;
+  my ($Status, $TestFailures, $Retry, $Timeout) = @_;
   my $NewVMStatus = $Status eq 'queued' ? 'offline' : 'dirty';
+  my $VMResult = $Status eq "boterror" ? "boterror" :
+                 $Status eq "queued" ? "error" :
+                 $Timeout ? "timeout" : "";

Debug(Elapsed($Start), " Taking a screenshot\n");
   TakeScreenshot($VM, $FullScreenshotFileName);
@@ -248,6 +252,13 @@ sub WrapUpAndExit($;$$)
     LogTaskError("The previous $Tries run(s) terminated abnormally\n");
   }

+  # Record result details that may be lost or overwritten by a later run
+  if ($VMResult)
+  {
+    $VMResult .= " $Tries $MaxTaskTries" if ($Retry);
+    $VM->RecordResult(undef, $VMResult);
+  }
+
   # Update the Task and Job
   $Task->Status($Status);
   $Task->TestFailures($TestFailures);
@@ -489,6 +500,7 @@ if (!defined $TA->Wait($Pid, $Timeout, $Keepalive))
   }
 }

+my $TimedOut;
 Debug(Elapsed($Start), " Retrieving the report file to '$FullLogFileName'\n");
 if ($TA->GetFile($RptFileName, $FullLogFileName))
 {
@@ -712,6 +724,7 @@ if ($TA->GetFile($RptFileName, $FullLogFileName))
           # so record the failure but don't add an error message.
           $LogFailures++;
           $CurrentIsBroken = 1;
+          $TimedOut = ($Step->Type ne "suite");
         }
         elsif ((!$Pid and !%CurrentPids) or
                ($Pid and !$CurrentPids{$Pid} and !$CurrentPids{0}))
@@ -767,4 +780,4 @@ FatalTAError(undef, $TAError, $PossibleCrash) if (defined $TAError);
 # Wrap up
 #

-WrapUpAndExit($NewStatus, $TaskFailures);
+WrapUpAndExit($NewStatus, $TaskFailures, undef, $TaskTimedOut || $TimedOut);
diff --git a/testbot/lib/WineTestBot/VMs.pm b/testbot/lib/WineTestBot/VMs.pm
index 961be52f..2ba6b4b5 100644
--- a/testbot/lib/WineTestBot/VMs.pm
+++ b/testbot/lib/WineTestBot/VMs.pm
@@ -566,6 +566,35 @@ sub RecordStatus($$;$)
   }
 }

+=pod
+=over 12
+
+=item C<RecordStatus()>
+
+Adds a Record of the specified VM process result.
+
+Also resets the last known VM status so a new one will be recorded even if
+it matches the current one, for instance if a new revert is started after the
+first one failed.
+
+=back
+=cut
+
+sub RecordResult($$$)
+{
+  my ($self, $Records, $Result) = @_;
+
+  if ($Records)
+  {
+    $Records->AddRecord("vmresult", $self->GetRecordName(), $Result);
+  }
+  else
+  {
+    SaveRecord("vmresult", $self->GetRecordName(), $Result);
+  }
+  delete $_VMStatuses{$self->Name};
+}
+

package WineTestBot::VMs;