[tools 1/2] testbot/UpdateTaskLogs: Fix moving reference reports to latest/.

[Francois Gouget]

When saving an existing reference report from a task directory to the
latest/ directory, its file name should be preserved to avoid
duplicating it. This means UpdateLatestReport() should not rebuild it
from scratch.
Fortunately this bug has been hidden so far because GetRefReportName()
does not yet depend on the Task's job id.

Signed-off-by: Francois Gouget <fgouget(a)codeweavers.com>
---
 testbot/bin/UpdateTaskLogs          | 2 +-
 testbot/lib/WineTestBot/LogUtils.pm | 8 ++++----
 2 files changed, 5 insertions(+), 5 deletions(-)

diff --git a/testbot/bin/UpdateTaskLogs b/testbot/bin/UpdateTaskLogs
index d29b42afb2..395c2029c7 100755
--- a/testbot/bin/UpdateTaskLogs
+++ b/testbot/bin/UpdateTaskLogs
@@ -234,7 +234,7 @@ sub DoUpdateLatestReport($$$)
     # Add the reference report to latest/
     Debug("latest: Adding $RefReportName from ". Path2TaskKey($SrcReportPath) ."\n");
 
-    my $ErrMessages = UpdateLatestReport($Task, $ReportName, $SrcReportPath);
+    my $ErrMessages = UpdateLatestReport($RefReportName, $SrcReportPath);
     foreach my $ErrMessage (@$ErrMessages)
     {
       Error "$ErrMessage\n";
diff --git a/testbot/lib/WineTestBot/LogUtils.pm b/testbot/lib/WineTestBot/LogUtils.pm
index 601ff0fcd8..dc2accaf32 100644
--- a/testbot/lib/WineTestBot/LogUtils.pm
+++ b/testbot/lib/WineTestBot/LogUtils.pm
@@ -1225,12 +1225,11 @@ sub SnapshotLatestReport($$)
   return \@ErrMessages;
 }
 
-sub UpdateLatestReport($$$)
+sub UpdateLatestReport($$)
 {
-  my ($Task, $ReportName, $SrcReportPath) = @_;
+  my ($RefReportName, $SrcReportPath) = @_;
   my @ErrMessages;
 
-  my $RefReportName = $Task->GetRefReportName($ReportName);
   foreach my $Suffix ("", ".errors")
   {
     # Add the new reference file even if it is empty.
@@ -1272,7 +1271,8 @@ sub UpdateLatestReports($$)
   foreach my $ReportName (@$ReportNames)
   {
     next if (!-f "$TaskDir/$ReportName" or -z _);
-    push @ErrMessages, @{UpdateLatestReport($Task, $ReportName, "$TaskDir/$ReportName")};
+    my $RefReportName = $Task->GetRefReportName($ReportName);
+    push @ErrMessages, @{UpdateLatestReport($RefReportName, "$TaskDir/$ReportName")};
   }
   return \@ErrMessages;
 }
-- 
2.20.1

[tools 2/2] testbot: Take into account multiple WineTest reports.

[Francois Gouget]

Instead of keeping only the latest WineTest results, keep all of them
and only consider an error new if it does not appears in one of the
WineTest results. This minimizes the risk of tagging a failure as new
when it happens intermitently.
However it also means the number of reference WineTest results can grow
without bounds so purge them after $JobPurgeDays.
Since all reference reports end up in the latest/ directory this also
makes it unnecessary to go fishing for them in the jobs/ directory when
running UpdateTaskLogs on a specific job. Also filtering reference
reports to only use those older than the task can be done based on the
reference report mtime instead of having to keep trust the jobid order.

Note: UpdateTaskLog can optionally be run to update the new/old status
in the errors cache files.

Wine-Bug: https://bugs.winehq.org/show_bug.cgi?id=47998
Signed-off-by: Francois Gouget <fgouget(a)codeweavers.com>
---

As mentioned above, running UpdateTaskLog is optional: the TestBot will 
continue working with just one reference report, then it will use two 
after the next WineTest run and so on; and things will gradually get 
better.

But running UpdateTaskLog --rebuild brings those benefits right away so 
it is quite recommended. As usual it's best to keep a trace of what 
happened:

cd testbot/var
../bin/UpdateTaskLogs --debug --rebuild 2>&1 | tee UpdateTaskLogs.log


Also this really requires part 1 (the workaround being to first run 
--delete then --rebuild).

 testbot/bin/Janitor.pl              |   9 +--
 testbot/bin/UpdateTaskLogs          | 107 ++++++++++----------------
 testbot/bin/WineRunTask.pl          |   5 ++
 testbot/bin/WineRunWineTest.pl      |   5 ++
 testbot/lib/WineTestBot/LogUtils.pm | 113 ++++++++++++++++------------
 testbot/lib/WineTestBot/Tasks.pm    |  25 +++++-
 6 files changed, 140 insertions(+), 124 deletions(-)

diff --git a/testbot/bin/Janitor.pl b/testbot/bin/Janitor.pl
index 8d50349c3d..bc9b87603c 100755
--- a/testbot/bin/Janitor.pl
+++ b/testbot/bin/Janitor.pl
@@ -328,14 +328,7 @@ if (opendir(my $dh, "$DataDir/latest"))
     my $TTL = $JobPurgeDays ? $JobPurgeDays - $Age : undef;
 
     # Keep the regexp in sync with WineTestBot::Task::GetRefReportName()
-    if ($Entry =~ /^([a-zA-Z0-9_]+)-job[0-9]+-[a-zA-Z0-9_]+\.report(?:\.errors)?$/)
-    {
-      # Keep the reference WineTest reports for all VMs even if they are
-      # retired or scheduled for deletion.
-      my $VMName = $1;
-      next if ($AllVMs->GetItem($VMName));
-    }
-    else
+    if ($Entry !~ /^[a-zA-Z0-9_]+-job[0-9]+-[a-zA-Z0-9_]+\.report(?:\.errors)?$/)
     {
       my $Deletion = defined $TTL ? " (deletion in $TTL days)" : "";
       Error "Found a suspicious file$Deletion: latest/$Entry\n";
diff --git a/testbot/bin/UpdateTaskLogs b/testbot/bin/UpdateTaskLogs
index 395c2029c7..49f3c2e817 100755
--- a/testbot/bin/UpdateTaskLogs
+++ b/testbot/bin/UpdateTaskLogs
@@ -210,26 +210,18 @@ sub BuildErrorsCache($$$$;$)
   return CreateLogErrorsCache($LogInfo, $Task);
 }
 
-# Maps the reference report name to its full pathname.
-# Note that the file may not be in latest/.
-my %LatestReports;
-
-# The set of latest/ reference report files to rebuild.
-my %LatestRebuilds;
-
 sub DoUpdateLatestReport($$$)
 {
   my ($Task, $ReportName, $SrcReportPath) = @_;
 
-  my $RefReportName = $Task->GetRefReportName($ReportName);
-  my $LatestReportPath = "$DataDir/latest/$RefReportName";
-  if (!defined $OptJobId and !$OptDelete and !-f $LatestReportPath)
-  {
-    $LatestRebuilds{$RefReportName} = 1;
-  }
+  # Keep the name as is when saving an existing reference report
+  my $SrcIsRef = ($SrcReportPath =~ /-job\d+-/);
+  my $RefReportName = $SrcIsRef ? basename($SrcReportPath) :
+                                  $Task->GetRefReportName($ReportName);
 
   my $Rc = 0;
-  if ($LatestRebuilds{$RefReportName})
+  my $LatestReportPath = "$DataDir/latest/$RefReportName";
+  if (!defined $OptJobId and !$OptDelete and !-f $LatestReportPath)
   {
     # Add the reference report to latest/
     Debug("latest: Adding $RefReportName from ". Path2TaskKey($SrcReportPath) ."\n");
@@ -240,13 +232,8 @@ sub DoUpdateLatestReport($$$)
       Error "$ErrMessage\n";
       $Rc = 1;
     }
-    $LatestReports{$RefReportName} = $LatestReportPath;
-  }
-  # else only add task reports, not their own reference reports
-  elsif ($SrcReportPath =~ m~/\Q$ReportName\E$~)
-  {
-    $LatestReports{$RefReportName} = $SrcReportPath;
   }
+
   return $Rc;
 }
 
@@ -365,30 +352,35 @@ sub ProcessTaskLogs($$$)
     # even if they were not supposed to exist (e.g. failed builds).
     foreach my $ReportName (@$ReportNames)
     {
-      my $RefReportName = $Task->GetRefReportName($ReportName);
-      my $RefReportPath = "$TaskDir/$RefReportName";
-
-      if (-f $RefReportPath or -f "$RefReportPath.errors")
+      # Also match the files related/derived from the report for the cleanup
+      my $RefReportPaths = $Task->GetRefReportPaths($ReportName, "(?:\.err|\.errors)?");
+      # Sort the filenames to make the log easier to analyse.
+      foreach my $RefReportName (sort { $b cmp $a } keys %$RefReportPaths)
       {
-        if (!$OptDelete and !-f "$RefReportPath.errors")
+        my $RefReportPath = $RefReportPaths->{$RefReportName};
+        if (!$OptDelete and (-f $RefReportPath or -f "$RefReportPath.errors"))
         {
-          # (Re)Build the .errors file before adding the reference report to
-          # latest/.
-          my $ErrMessage = BuildErrorsCache($TaskDir, $RefReportName, 1, 0);
-          if (defined $ErrMessage)
+          if (!-f "$RefReportPath.errors")
           {
-            Error "$ErrMessage\n";
-            $Rc = 1;
+            # (Re)Build the .errors file before adding the reference report to
+            # latest/.
+            my $ErrMessage = BuildErrorsCache($TaskDir, $RefReportName, 1, 0);
+            if (defined $ErrMessage)
+            {
+              Error "$ErrMessage\n";
+              $Rc = 1;
+            }
           }
-        }
 
-        # Save this report to latest/ in case it's not already present there
-        # (this would be the case for the oldest tasks with --rebuild)
-        $Rc += DoUpdateLatestReport($Task, $ReportName, $RefReportPath);
+          # Save this report to latest/ in case it's not already present there
+          # (this would be the case for the oldest tasks with --rebuild)
+          $Rc += DoUpdateLatestReport($Task, $ReportName, $RefReportPath);
+        }
+        $Rc += Delete($RefReportPath);
+        $Rc += Delete("$RefReportPath.err");
+        $Rc += Delete("$RefReportPath.errors");
       }
-      $Rc += Delete($RefReportPath);
-      $Rc += Delete("$RefReportPath.err");
-      $Rc += Delete("$RefReportPath.errors");
+
       $Rc += Delete("$TaskDir/$ReportName.err");
     }
 
@@ -402,35 +394,18 @@ sub ProcessTaskLogs($$$)
 
   if (!$OptDelete and !$CollectOnly and $Task->Status eq "completed")
   {
-    # Take a snapshot of the latest reference reports
+    # Take a snapshot of the reference reports older than this Task
     foreach my $ReportName (@{GetLogFileNames($TaskDir)})
     {
       next if ($ReportName !~ /\.report$/);
 
-      my $RefReportName = $Task->GetRefReportName($ReportName);
-      $Rc += Delete("$TaskDir/$RefReportName.err");
-      next if (-f "$TaskDir/$RefReportName");
-
-      my $LatestReportPath = $LatestReports{$RefReportName};
-      if (!defined $LatestReportPath)
+      Debug(TaskKeyStr($Task) .": Snapshotting the reference reports for $ReportName\n");
+      my $ErrMessages = SnapshotLatestReport($Task, $ReportName);
+      foreach my $ErrMessage (@$ErrMessages)
       {
-        Error TaskKeyStr($Task) .": Missing '$RefReportName' reference report\n";
+        Error "$ErrMessage\n";
         $Rc = 1;
       }
-      else
-      {
-        Debug(TaskKeyStr($Task) .": Snapshotting $RefReportName from ". Path2TaskKey($LatestReportPath) ."\n");
-        foreach my $Suffix ("", ".errors")
-        {
-          unlink "$TaskDir/$RefReportName$Suffix";
-          if (-f "$LatestReportPath$Suffix" and
-              !link("$LatestReportPath$Suffix", "$TaskDir/$RefReportName$Suffix"))
-          {
-            Error "Could not link '$RefReportName$Suffix': $!\n";
-            $Rc = 1;
-          }
-        }
-      }
     }
   }
 
@@ -450,11 +425,11 @@ sub ProcessTaskLogs($$$)
       $Rc += Delete("$TaskDir/$LogName.err");
       if ($LogName =~ /\.report$/)
       {
-        # First for the reference report if any
-        my $RefReportName = $Task->GetRefReportName($LogName);
-        if (!-f "$TaskDir/$RefReportName.errors" and
-            -f "$TaskDir/$RefReportName")
+        my $RefReportPaths = $Task->GetRefReportPaths($LogName);
+        while (my ($RefReportName, $RefReportPath) = each %$RefReportPaths)
         {
+          $Rc += Delete("$RefReportPath.err");
+          next if (-f "$RefReportPath.errors");
           my $ErrMessage = BuildErrorsCache($TaskDir, $RefReportName, 1, 0);
           if (defined $ErrMessage)
           {
@@ -534,7 +509,7 @@ sub ProcessLatestReports()
     $LatestReportPath = "$DataDir/latest/$RefReportName";
     $Rc += Delete("$LatestReportPath.err");
 
-    if ($OptDelete or $OptRebuild)
+    if (!$OptJobId and ($OptDelete or $OptRebuild))
     {
       # These can be rebuilt from the task reports
       $Rc += Delete($LatestReportPath);
@@ -560,7 +535,7 @@ sub ProcessLatestReports()
 }
 
 my $Rc = 0;
-$Rc = ProcessLatestReports() if (!defined $OptJobId);
+$Rc = ProcessLatestReports();
 
 my @AllTasks;
 foreach my $Job (@{CreateJobs()->GetItems()})
diff --git a/testbot/bin/WineRunTask.pl b/testbot/bin/WineRunTask.pl
index f55fa9f706..3036488076 100755
--- a/testbot/bin/WineRunTask.pl
+++ b/testbot/bin/WineRunTask.pl
@@ -300,6 +300,11 @@ sub WrapUpAndExit($;$$$$)
   }
 
   # Update the 'latest/' reference WineTest results
+  # Note that if the WineTest run timed out the missing test results would
+  # cause false positives. This can only be compensated by having a complete
+  # reference report from another run. But if only incomplete reports are
+  # available there would still be false positives. So ignore the report in
+  # case of a timeout.
   if ($Step->Type eq 'suite' and $Status eq 'completed' and !$TimedOut)
   {
     my $ErrMessages = UpdateLatestReports($Task, $ReportNames);
diff --git a/testbot/bin/WineRunWineTest.pl b/testbot/bin/WineRunWineTest.pl
index f6e6c977d4..bcf89bfa7d 100755
--- a/testbot/bin/WineRunWineTest.pl
+++ b/testbot/bin/WineRunWineTest.pl
@@ -295,6 +295,11 @@ sub WrapUpAndExit($;$$$$)
   }
 
   # Update the 'latest/' reference WineTest results
+  # Note that if the WineTest run timed out the missing test results would
+  # cause false positives. This can only be compensated by having a complete
+  # reference report from another run. But if only incomplete reports are
+  # available there would still be false positives. So ignore the report in
+  # case of a timeout.
   if ($Step->Type eq 'suite' and $Status eq 'completed' and !$TimedOut)
   {
     my $ErrMessages = UpdateLatestReports($Task, $ReportNames);
diff --git a/testbot/lib/WineTestBot/LogUtils.pm b/testbot/lib/WineTestBot/LogUtils.pm
index dc2accaf32..5ed45633d8 100644
--- a/testbot/lib/WineTestBot/LogUtils.pm
+++ b/testbot/lib/WineTestBot/LogUtils.pm
@@ -1072,7 +1072,7 @@ was no reference log or that the reference log could not be read in which case
 BadRef would be set.
 
 =item NewCount
-The total number of new errors if any.
+The total number of new errors.
 
 =item ErrGroups
 =over
@@ -1081,8 +1081,7 @@ The total number of new errors if any.
 A count of the group's new errors.
 
 =item IsNew
-An array indicating which entries in the group's Errors array are new
-or undef if there are no new errors in this group.
+An array indicating which entries in the group's Errors array are new.
 
 =back
 
@@ -1092,65 +1091,75 @@ or undef if there are no new errors in this group.
 
 sub TagNewErrors($$)
 {
-  my ($RefLogPath, $LogInfo) = @_;
+  my ($LogInfo, $Task) = @_;
 
   return if (!$LogInfo->{ErrCount});
 
-  my $RefInfo = LoadLogErrors($RefLogPath);
-  if (defined $RefInfo->{BadLog})
+  # Then iterate over the reference logs
+  my $HasRef;
+  my $RefReportPaths = $Task->GetRefReportPaths($LogInfo->{LogName});
+ reflog: foreach my $RefReportPath (values %$RefReportPaths)
   {
-    # Save the BadLog error but do not tag the errors as new: this is up to
-    # the caller.
-    $LogInfo->{BadRef} = $RefInfo->{BadLog} if (-e $RefLogPath);
-    $LogInfo->{NoRef} = 1;
-    return;
-  }
+    my $RefInfo = LoadLogErrors($RefReportPath);
+    if (defined $RefInfo->{BadLog})
+    {
+      # Only save the first BadLog error
+      $RefInfo->{BadRef} ||= $RefInfo->{BadLog};
+      next;
+    }
+    $HasRef = 1;
+    next if (!$RefInfo->{ErrCount});
 
-  $LogInfo->{NewCount} = 0;
-  foreach my $GroupName (@{$LogInfo->{ErrGroupNames}})
-  {
-    my $Group = $LogInfo->{ErrGroups}->{$GroupName};
-    $Group->{NewCount} = 0;
+    # Initially mark all errors as new if and only if we found a reference
+    # report.
+    MarkAllErrorsAsNew($LogInfo) if (!exists $LogInfo->{NewCount});
 
-    my $RefGroup = $RefInfo->{ErrGroups}->{$GroupName};
-    if ($RefGroup)
+    # And unmark any error already present in the reference log
+    foreach my $GroupName (@{$LogInfo->{ErrGroupNames}})
     {
+      my $Group = $LogInfo->{ErrGroups}->{$GroupName};
+      next if (!$Group->{NewCount});
+
+      my $RefGroup = $RefInfo->{ErrGroups}->{$GroupName};
+      next if (!$RefGroup);
+
       my $Diff = Algorithm::Diff->new($RefGroup->{Errors}, $Group->{Errors},
                                       { keyGen => \&_GetLineKey });
+      #_DumpDiff($GroupName, $Diff);
       my $ErrIndex = 0;
       while ($Diff->Next())
       {
         my $SameCount = $Diff->Same();
         if ($SameCount)
         {
-          $ErrIndex += $SameCount;
-        }
-        else
-        {
-          # Added lines are the new errors
-          my $AddedCount = $Diff->Items(2);
-          $Group->{NewCount} += $AddedCount;
-          foreach (1..$AddedCount)
+          # Mark identical lines as not new
+          while ($SameCount--)
           {
-            $Group->{IsNew}->[$ErrIndex] = 1;
+            if ($Group->{IsNew}->[$ErrIndex])
+            {
+              $Group->{IsNew}->[$ErrIndex] = undef;
+              $Group->{NewCount}--;
+              $LogInfo->{NewCount}--;
+              last if (!$Group->{NewCount});
+            }
             $ErrIndex++;
           }
         }
-      }
-    }
-    else
-    {
-      # All errors in this group are new
-      $Group->{NewCount} = @{$Group->{Errors}};
-      if ($Group->{NewCount})
-      {
-        foreach my $ErrIndex (0..$Group->{NewCount} - 1)
+        else
         {
-          $Group->{IsNew}->[$ErrIndex] = 1;
+          # Found zero or more new lines, skip over them
+          $ErrIndex += $Diff->Items(2);
         }
       }
+
+      # Stop here if no group has new errors anymore
+      last reflog if (!$LogInfo->{NewCount});
     }
-    $LogInfo->{NewCount} += $Group->{NewCount};
+  }
+  if (!$HasRef)
+  {
+    # Do not tag the errors as new: this is up to the caller.
+    $LogInfo->{NoRef} = 1;
   }
 }
 
@@ -1173,8 +1182,7 @@ sub CreateLogErrorsCache($;$)
   }
   elsif ($Task and $LogInfo->{ErrCount})
   {
-    my $RefReportPath = $Task->GetDir() ."/". $Task->GetRefReportName($LogInfo->{LogName});
-    TagNewErrors($RefReportPath, $LogInfo);
+    TagNewErrors($LogInfo, $Task);
     # Don't mark the errors as new if there is no reference WineTest report
     # as this would cause false positives.
   }
@@ -1194,8 +1202,8 @@ sub CreateLogErrorsCache($;$)
 
 Takes a snapshot of the reference WineTest results for the specified Task.
 
-The reference report is used to identify new failures, even long after the task has been
-run (and the reference report replaced by a newer version).
+The reference reports are used to identify new failures, even long after the task has
+been run.
 
 Note also that comparing reports in this way may be a bit inaccurate right
 after a Wine commit due to delays in getting new WineTest results, etc.
@@ -1210,15 +1218,22 @@ sub SnapshotLatestReport($$)
 
   my @ErrMessages;
   my $TaskDir = $Task->GetDir();
-  my $RefReportName = $Task->GetRefReportName($ReportName);
-  foreach my $Suffix ("", ".errors")
+  my $ReportAge = -M "$TaskDir/$ReportName";
+
+  my $RefReportPaths = $Task->GetRefReportPaths($ReportName, "(?:\.errors)?",
+                                                "$DataDir/latest");
+  while (my ($RefReportName, $RefReportPath) = each %$RefReportPaths)
   {
-    next if (!-f "$DataDir/latest/$RefReportName$Suffix");
+    # Ignore reference results more recent than the report
+    next if ($ReportAge and -M $RefReportPath <= $ReportAge);
 
-    if (!link("$DataDir/latest/$RefReportName$Suffix",
-              "$TaskDir/$RefReportName$Suffix"))
+    foreach my $Suffix ("", ".errors")
     {
-      push @ErrMessages, "Could not create the '$RefReportName$Suffix' link: $!";
+      unlink "$TaskDir/$RefReportName$Suffix";
+      if (!link("$RefReportPath$Suffix", "$TaskDir/$RefReportName$Suffix"))
+      {
+        push @ErrMessages, "Could not create the '$RefReportName$Suffix' link: $!";
+      }
     }
   }
 
diff --git a/testbot/lib/WineTestBot/Tasks.pm b/testbot/lib/WineTestBot/Tasks.pm
index f8b91d1c31..3568c9b8be 100644
--- a/testbot/lib/WineTestBot/Tasks.pm
+++ b/testbot/lib/WineTestBot/Tasks.pm
@@ -142,7 +142,30 @@ sub GetReportNames($)
 sub GetRefReportName($$)
 {
   my ($self, $ReportName) = @_;
-  return $self->VM->Name ."-job000000-$ReportName";
+  my ($JobId, $_StepNo, $_TaskNo) = @{$self->GetMasterKey()};
+  return sprintf("%s-job%06d-%s", $self->VM->Name, $JobId, $ReportName);
+}
+
+sub GetRefReportPaths($$;$$)
+{
+  my ($self, $ReportName, $ExtraRE, $Dir) = @_;
+
+  $ExtraRE ||= "";
+  $Dir ||= $self->GetDir();
+  my $VMName = $self->VM->Name;
+  # Keep the glob and regexp in sync with WineTestBot::Task::GetRefReportName()
+  my $RefGlob = "$Dir/$VMName-job*-$ReportName";
+  $RefGlob .= "*" if ($ExtraRE ne "");
+
+  my %RefReportPaths;
+  foreach my $RefReportPath (glob($RefGlob))
+  {
+    next if ($RefReportPath !~ m~^\Q$Dir\E/(\Q$VMName\E-job[0-9]+-\Q$ReportName\E)$ExtraRE$~);
+    my $RefReportName = $1; # untaint
+    next if ($RefReportPaths{$RefReportName});
+    $RefReportPaths{$RefReportName} = "$Dir/$RefReportName";
+  }
+  return \%RefReportPaths;
 }
 
 sub _SetupTask($$)
-- 
2.20.1