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 --- testbot/bin/Janitor.pl | 9 +- testbot/bin/UpdateTaskLogs | 134 +++++++++++----------------- testbot/bin/WineRunTask.pl | 5 ++ testbot/bin/WineRunWineTest.pl | 5 ++ testbot/lib/WineTestBot/LogUtils.pm | 118 ++++++++++++++---------- testbot/lib/WineTestBot/Tasks.pm | 3 +- 6 files changed, 134 insertions(+), 140 deletions(-)
diff --git a/testbot/bin/Janitor.pl b/testbot/bin/Janitor.pl index a4ba817ff..09f009c53 100755 --- a/testbot/bin/Janitor.pl +++ b/testbot/bin/Janitor.pl @@ -314,14 +314,7 @@ if (opendir(my $dh, "$DataDir/latest")) my $Age = int((-M $FileName) + 0.5); my $TTL = $JobPurgeDays ? $JobPurgeDays - $Age : undef;
- 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 fb0037c91..e1746e09a 100755 --- a/testbot/bin/UpdateTaskLogs +++ b/testbot/bin/UpdateTaskLogs @@ -197,22 +197,18 @@ sub BuildErrorsCache($$$$;$) return CreateLogErrorsCache($LogInfo, $Task); }
-my %LatestReports; -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"); @@ -223,13 +219,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; }
@@ -338,35 +329,46 @@ sub ProcessTaskLogs($$$) } foreach my $ReportName (@$ReportNames) { - my $RefReportName = $Task->GetRefReportName($ReportName); - my $RefReportPath = "$TaskDir/$RefReportName"; - - if (-f $RefReportPath or -f "$RefReportPath.errors") + my %Seen; + # Also match the files related/derived from the report for the cleanup + my $Glob = "$TaskDir/". $Task->VM->Name ."-job*-$ReportName*"; + # Sort the filenames to make the log easier to analyse. + foreach my $RefReportPath (sort { $b cmp $a } glob($Glob)) { - if (!$OptDelete and !-f "$RefReportPath.errors") + my $RefReportName = basename($RefReportPath); + next if ($RefReportName !~ /^([a-zA-Z0-9_]+-job[0-9]+-[a-zA-Z0-9_]*.report)(?:.err|.errors)?$/); + $RefReportName = $1; # untaint + next if ($Seen{$RefReportName}); + $Seen{$RefReportName} = 1; + + $RefReportPath = "$TaskDir/$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; + # Build the errors cache 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); + }
Debug(TaskKeyStr($Task) .": Deleting $RefReportName*\n"); - } - foreach my $Suffix ("", ".err", ".errors") - { - if (!unlink "$RefReportPath$Suffix" and -e "$RefReportPath$Suffix") + foreach my $Suffix ("", ".err", ".errors") { - Error "Could not delete '$RefReportPath$Suffix': $!\n"; - $Rc = 1; + if (!unlink "$RefReportPath$Suffix" and -e "$RefReportPath$Suffix") + { + Error "Could not delete '$RefReportPath$Suffix': $!\n"; + $Rc = 1; + } } }
@@ -397,33 +399,18 @@ sub ProcessTaskLogs($$$)
if (!$OptDelete and !$CollectOnly) { - # Take a snapshot of the latest reference reports + # Take a snapshot of the reference reports older than this Task foreach my $LogName (@{GetLogFileNames($TaskDir)}) { next if ($LogName !~ /.report$/); - my $RefReportName = $Task->GetRefReportName($LogName); - next if (-f "$TaskDir/$RefReportName");
- my $LatestReportPath = $LatestReports{$RefReportName}; - if (!defined $LatestReportPath) + Debug(TaskKeyStr($Task) .": Snapshotting the reference reports for $LogName\n"); + my $ErrMessages = SnapshotLatestReport($Task, $LogName); + 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; - } - } - } }
# And (re)build the .errors files @@ -438,31 +425,12 @@ sub ProcessTaskLogs($$$) } foreach my $LogName (@{GetLogFileNames($TaskDir, "+old")}) { - if ($LogName =~ /.report$/) - { - # First for the reference report - my $RefReportName = $Task->GetRefReportName($LogName); - if (!-f "$TaskDir/$RefReportName.errors" and - -f "$TaskDir/$RefReportName") - { - my $ErrMessage = BuildErrorsCache($TaskDir, $RefReportName, 1, 0); - if (defined $ErrMessage) - { - Error "$ErrMessage\n"; - $Rc = 1; - } - } - } - - # Then for the report / log itself - if (!-f "$TaskDir/$LogName.errors") + next if (-f "$TaskDir/$LogName.errors"); + my $ErrMessage = BuildErrorsCache($TaskDir, $LogName, $IsWineTest, $TaskTimedOut, $Task); + if (defined $ErrMessage) { - my $ErrMessage = BuildErrorsCache($TaskDir, $LogName, $IsWineTest, $TaskTimedOut, $Task); - if (defined $ErrMessage) - { - Error "$ErrMessage\n"; - $Rc = 1; - } + Error "$ErrMessage\n"; + $Rc = 1; } } } @@ -515,7 +483,7 @@ sub ProcessLatestReports() $RefReportName = $1; # untaint $LatestReportPath = "$DataDir/latest/$RefReportName";
- if ($OptDelete or $OptRebuild) + if (!$OptJobId and ($OptDelete or $OptRebuild)) { # Delete the reports that should be deleted / rebuilt foreach my $Suffix ("", ".errors") @@ -555,7 +523,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 100857572..bcf78e508 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 8a222f352..98352bdfd 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 af57603df..037387277 100644 --- a/testbot/lib/WineTestBot/LogUtils.pm +++ b/testbot/lib/WineTestBot/LogUtils.pm @@ -695,7 +695,7 @@ sub ParseWineTestReport($$$) my $ExtraCount = @{$LogInfo->{Extra}}; if ($ExtraCount) { - my $Group = _AddLogGroup($LogInfo, ".Extra"); + my $Group = _AddLogGroup($LogInfo, "Report validation errors"); $Group->{Errors} = $LogInfo->{Extra}; my @LineNos = (0) x $ExtraCount; $Group->{LineNos} = @LineNos; @@ -1080,65 +1080,80 @@ An array where entries are set to true to identify new errors.
sub TagNewErrors($$) { - my ($RefLogPath, $LogInfo) = @_; + my ($LogInfo, $Task) = @_;
return if (!$LogInfo->{ErrCount});
- my $RefInfo = LoadLogErrors($RefLogPath); - if ($RefInfo->{BadLog}) + # Then iterate over the reference logs + my $HasRef; + my $TaskDir = $Task->GetDir(); + my $VMName = $Task->VM->Name; + my $TaskGlob = "$TaskDir/$VMName-job*-$LogInfo->{LogName}"; + reflog: foreach my $RefLogPath (glob("$TaskGlob")) { - # 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; - } + next if ($RefLogPath !~ m~^(\Q$TaskDir/$VMName\E-job[0-9]+-\Q$LogInfo->{LogName}\E)$~); + $RefLogPath = $1; # untaint
- $LogInfo->{NewCount} = 0; - foreach my $GroupName (@{$LogInfo->{ErrGroupNames}}) - { - my $Group = $LogInfo->{ErrGroups}->{$GroupName}; - $Group->{NewCount} = 0; + my $RefInfo = LoadLogErrors($RefLogPath); + if ($RefInfo->{BadLog}) + { + # Only save the first BadLog error + $RefInfo->{BadRef} ||= $RefInfo->{BadLog}; + next; + } + $HasRef = 1; + next if (!$RefInfo->{ErrCount}); + + # 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()) + diff: 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 diff 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; } }
@@ -1161,8 +1176,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. } @@ -1182,8 +1196,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. @@ -1198,15 +1212,23 @@ sub SnapshotLatestReport($$)
my @ErrMessages; my $TaskDir = $Task->GetDir(); - my $RefReportName = $Task->GetRefReportName($ReportName); - foreach my $Suffix ("", ".errors") + my $ReportAge = -M "$TaskDir/$ReportName"; + + # Keep the glob in sync with WineTestBot::Task::GetRefReportName() + my $RefGlob = $Task->VM->Name ."-job*-$ReportName*"; + foreach my $LatestReportPath (glob("$DataDir/latest/$RefGlob")) { - next if (!-f "$DataDir/latest/$RefReportName$Suffix"); + my $RefReportName = basename($LatestReportPath); + next if ($RefReportName !~ /^([a-zA-Z0-9_]+-job[0-9]+-[a-zA-Z0-9_]*.report(?:.errors)?)$/); + $RefReportName = $1; # untaint + + # Ignore reference results more recent than the report + next if ($ReportAge and -M "$DataDir/latest/$RefReportName" <= $ReportAge);
- if (!link("$DataDir/latest/$RefReportName$Suffix", - "$TaskDir/$RefReportName$Suffix")) + unlink "$TaskDir/$RefReportName"; + if (!link("$DataDir/latest/$RefReportName", "$TaskDir/$RefReportName")) { - push @ErrMessages, "Could not create the '$RefReportName$Suffix' link: $!"; + push @ErrMessages, "Could not create the '$RefReportName' link: $!"; } }
diff --git a/testbot/lib/WineTestBot/Tasks.pm b/testbot/lib/WineTestBot/Tasks.pm index 87c501025..3d743f782 100644 --- a/testbot/lib/WineTestBot/Tasks.pm +++ b/testbot/lib/WineTestBot/Tasks.pm @@ -141,7 +141,8 @@ 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 _SetupTask($$)