I'm sending this patchset here for review and to provide an overview of what's to come. It's quite large so it shouldn't be committed in one go on the TestBot production system (hence the lack of the 'PATCH' prefix and signing off, those will go with the actual submission of the final patches).
The main goal of this patchset is to reduce the "new error" false positives caused by intermittent failures (bug 47998). But fixing this has a number of impacts which makes the patchset larger.
Some context: the TestBot detects new failures introduced by a patch by comparing its result to that of the last WineTest run. Any failure not present in the WineTest run is considered to be caused by the patch. This breaks down when a failure is intermittent and just happens on the patch's test run.
To avoid this the pathset modifies the TestBot to use all past WineTest runs as the comparison point. Only failures not present in any of them are considered new and attributed to the patch.
But the TestBot does the new failures detection when generating the JobDetails page (and also when sending the emails). This means parsing the WineTest results (600KB to 1.5MB) to extract failures, the same for the test results, and diffing them, for each test configuration (typically about 20), every time the page is loaded or refreshed. This results in typical load times between 0.2 and 2 seconds on my test system (up to 5 seconds on the official TestBot) (bug 48035). Annoying but not a major issue. But these can put quite a load on the web server when a rogue spider decides to crawl the TestBot site as happened a few times in december. Using all WineTest results on record instead of just the latest would increase the average load times by a factor of 20. This would make the page load time unacceptable and put too much load on the web server.
This means the JobDetails performance issues must be tackled first. Initially my idea was to just cache the errors lists. But in fact it's just as easy to also cache whether each error is new and thus do the detection only once. So the patchset introduces .errors files which contain only the errors extracted from a given task's log, whether each error is new, and its line number in the full report which allows for some future enhancements. With this change, generating the JobDetails page takes 0.01 to 0.15 seconds on my test system.
The structures used to manipulate the error lists were not practical and hardly extensible. In particular there was not a single list with a flag denoting new errors, but two lists, one with all the errors and another with only the new errors (see TagNewErrors()). Furthermore the error groups and errors in each group were returned separately (see GetLogErrors()), making them annoying to pass around and even harder to extend with more information such as line numbers. So the early patches rework the way errors are stored in memory to simplify usage and make their representation more extensible.
Before the patchset the WineRun* scripts would parse the test reports and store the extra validation errors in .err files (e.g. the too much output errors). But it's just as easy to store those in the .errors files, making the .err ones redundant. So they are removed on upgrade.
The web server is the wrong place to generate these 'cache' .errors files, in part because it does not have write access to the jobs/ directory. It's more logical to have each WineRun* script generate those when it completes. Then the .errors files are available when WineSendLog and JobDetails need them.
Because the new failures detection was performed each time JobDetails was run, it could happen long after the job completed. By that time there could be new WineTest results so simply using the latest ones would have changed the list of new failures of past jobs which would have made no sense. With the .errors files the new failures detection is performed only once when a task completes. So keeping a copy of the WineTest reference files is not really necessary anymore. But it's still useful to have them to diagnose issues.
The WineRunBuild script used to copy the latest WineTest reports to each of the job's step directories when the build completed. Instead it's much more logical to have each WineRun* script capture the WineTest reports it needs when it completes its task and to store them in the task's directory.
The reference WineTest results are stored in the latest/ directory so each needs a unique name. That name used to be of the form '<vmname>_<reportname>', for instance debian10_win32_fr_FR.report'. So this naming scheme was updated to allow for more than one report per test configuration. Specifically it now includes the job id since there's only one report per job for a given test configuration and this makes it easy to know where the reference report is coming from. Also underscores are allowed in both the VM names and report names which makes it hard to split the filename into its components. So the underscore was replaced by dashes. So that gives 'debian10-job63174-win32_fr_FR.report'.
The Engine used to perform the renaming / upgrade operations on startup. But generating the .errors files for every single job takes several minutes which makes it inappropriate as an Engine startup task. Also in order to work on the patchset it is necessary to be able to test code both before and after files were moved around and .errors files added.
So a new tool, UpdateTaskLogs was added that can rebuild all generated files from scratch and allows dealing with upgrades and downgrades. It's introduced before any changes to the way the logs are handled and updated to perform the required renames and to rebuild the generated files. This allows upgrading the content of the latest/ and jobs/ directories when needed. Also when reverting to an earlier version of the code it can mostly restore the content of these directories to their original state, thus making it possible to test the old code. And should things go wrong on the production server this will also provide a way to roll back the state of the TestBot.
The TestBot engine redirects the WineRun* scripts stderr to log.err in order to capture Perl errors. This makes log.err different from all other .err files since it cannot be rebuilt from the content of the corresponding log file. So the patchset renames log and log.err to task.log and testbot.log respectively. Of course UpdateTaskLogs deals with the needed renames on upgrade. This is also the reason for the 'mostly' in the previous section: UpdateTaskLogs does not revert these renames on downgrades (but that's easy to deal with with a find -exec command).
Another issue is that the WineRun* scripts obviously cannot generate the .errors file for testbot.log. So instead this file is generated by WineSendLog which is called as soon as the overall job is complete. Normally testbot.log is empty and thus ignored anyway. Also the JobDetails page needs to deal with cases where the .errors file is missing in any case. So when that happens it simply points the user to the full log.
Finally, if we have two WineTest reports, one with errors A and B, and an older one with only error B, then the second report is useless as far as detecting new failures go. So one can speed up new failure detection by only keeping the useful reports. With the new/old status being stored in the .errors file this is not really crucial since it only slows down the WineRun* scripts. The patchset still includes a patch to prune the redundant WineTest reports. However it's not very effective because some tests produce errors that change with every run. Those will clearly need to be fixed.
Francois Gouget (25): testbot: Standardize building the reference report filenames. testbot/LogUtils: Don't rename the old logs on Engine startup. testbot/UpdateTaskLogs: Delete, rebuild or add reference reports. testbot/LogUtils: Tag new errors instead of filtering them. testbot/LogUtils: Return the log errors as a single object. testbot/LogUtils: Add _AddLogError() and _AddLogGroup(). testbot/LogUtils: Rename the $Summary variables to $LogInfo. testbot/LogUtils: Tweak ParseTaskLog() to reduce the indentation level. testbot/LogUtils: Return the ParseWineTestReport() results as a single object. testbot/LogUtils: Add BadRef/NoRef to TagNewErrors(). testbot/LogUtils: Rename the ParseTaskLog() NoLog error field to BadLog. testbot/JobDetails: Highlight new errors in the full log too. testbot/LogUtils: Keep track of the first line of each error group. testbot/LogUtils: Store the filename in the $LogInfo structures. testbot: Share code to access the latest reference WineTest reports. testbot/UpdateTaskLogs: Delete reference reports that are not supposed to exist. testbot: Move reference logs to the task and prepare for having more than one. testbot: Separate the per-task task and testbot logs. testbot/LogUtils: Reorder the functions to get a more logical grouping. testbot: Cache the log error lists in .errors files. testbot/JobDetails: Improve the error reporting. testbot/LogUtils: Share code between _SaveLogErrors() and _DumpErrors(). testbot/LogUtils: Return the errors in the Parse*() $LogInfo structure. testbot: Take into account multiple WineTest reports. testbot/LogUtils: Deduplicate the latest WineTest reports.
testbot/bin/Engine.pl | 14 - testbot/bin/Janitor.pl | 9 +- testbot/bin/UpdateTaskLogs | 559 +++++++++++++ testbot/bin/WineRunBuild.pl | 49 +- testbot/bin/WineRunReconfig.pl | 24 +- testbot/bin/WineRunTask.pl | 78 +- testbot/bin/WineRunWineTest.pl | 118 +-- testbot/bin/WineSendLog.pl | 143 ++-- testbot/lib/WineTestBot/LogUtils.pm | 1161 ++++++++++++++++++--------- testbot/lib/WineTestBot/Tasks.pm | 50 +- testbot/web/JobDetails.pl | 146 +++- testbot/web/WineTestBot.css | 2 + 12 files changed, 1700 insertions(+), 653 deletions(-) create mode 100755 testbot/bin/UpdateTaskLogs
--- testbot/bin/WineRunBuild.pl | 2 +- testbot/bin/WineRunTask.pl | 2 +- testbot/bin/WineRunWineTest.pl | 2 +- testbot/bin/WineSendLog.pl | 7 ++++--- testbot/lib/WineTestBot/StepsTasks.pm | 7 +++++++ testbot/lib/WineTestBot/Tasks.pm | 6 ++++++ testbot/web/JobDetails.pl | 4 ++-- 7 files changed, 22 insertions(+), 8 deletions(-)
diff --git a/testbot/bin/WineRunBuild.pl b/testbot/bin/WineRunBuild.pl index f33b7bde6..ce8f40f05 100755 --- a/testbot/bin/WineRunBuild.pl +++ b/testbot/bin/WineRunBuild.pl @@ -510,7 +510,7 @@ foreach my $TestStep (@{$Job->Steps->GetItems()}) { foreach my $TestTask (@{$TestStep->Tasks->GetItems()}) { - my $RefReport = $TestTask->VM->Name ."_". $TestStep->FileType .".report"; + my $RefReport = $TestTask->GetRefReportName($TestStep->FileType .".report"); for my $Suffix ("", ".err") { if (-f "$LatestDir/$RefReport$Suffix") diff --git a/testbot/bin/WineRunTask.pl b/testbot/bin/WineRunTask.pl index cef7a5caa..62bd162ee 100755 --- a/testbot/bin/WineRunTask.pl +++ b/testbot/bin/WineRunTask.pl @@ -305,7 +305,7 @@ sub WrapUpAndExit($;$$$$) if (-f "$TaskDir/$RptFileName" and !-z "$TaskDir/$RptFileName") { # Update the VM's reference WineTest results for WineSendLog.pl - my $RefReport = "$DataDir/latest/". $Task->VM->Name ."_$RptFileName"; + my $RefReport = "$DataDir/latest/". $Task->GetRefReportName($RptFileName); unlink($RefReport); link("$TaskDir/$RptFileName", $RefReport);
diff --git a/testbot/bin/WineRunWineTest.pl b/testbot/bin/WineRunWineTest.pl index 1cf9541cf..245128a73 100755 --- a/testbot/bin/WineRunWineTest.pl +++ b/testbot/bin/WineRunWineTest.pl @@ -630,7 +630,7 @@ if ($NewStatus eq 'completed') foreach my $Mission (@{$TaskMissions->{Missions}}) { my $RptFileName = GetMissionBaseName($Mission) .".report"; - my $RefReport = $Task->VM->Name ."_$RptFileName"; + my $RefReport = $Task->GetRefReportName($RptFileName); for my $Suffix ("", ".err") { if (-f "$LatestDir/$RefReport$Suffix") diff --git a/testbot/bin/WineSendLog.pl b/testbot/bin/WineSendLog.pl index 98bfc4c0f..1ec7db1bd 100755 --- a/testbot/bin/WineSendLog.pl +++ b/testbot/bin/WineSendLog.pl @@ -238,8 +238,9 @@ Content-Type: text/plain; charset="UTF-8" MIME-Version: 1.0 Content-Transfer-Encoding: 8bit EOF + # Prepend the VM name to get unique attachment filenames for this email. print $Sendmail "Content-Disposition: attachment; filename=", - $StepTask->VM->Name, "_$LogName\n\n"; + $StepTask->VM->Name, "-$LogName\n\n"; if ($Debug) { print $Sendmail "Not dumping logs in debug mode\n"; @@ -290,8 +291,8 @@ EOF # Skip if there are no errors next if (!$LogErrors->{Groups});
- my $RefFileName = $StepTask->GetFullFileName($StepTask->VM->Name ."_$LogName"); - my ($NewGroups, $NewErrors, $_NewIndices) = GetNewLogErrors($RefFileName, $LogErrors->{Groups}, $LogErrors->{Errors}); + my $RefReportPath = $StepTask->GetFullFileName($StepTask->GetRefReportName($LogName)); + my ($NewGroups, $NewErrors, $_NewIndices) = GetNewLogErrors($RefReportPath, $LogErrors->{Groups}, $LogErrors->{Errors}); if (!$NewGroups) { # Test reports should have reference WineTest results and if not diff --git a/testbot/lib/WineTestBot/StepsTasks.pm b/testbot/lib/WineTestBot/StepsTasks.pm index 463f15078..bad0e2437 100644 --- a/testbot/lib/WineTestBot/StepsTasks.pm +++ b/testbot/lib/WineTestBot/StepsTasks.pm @@ -67,6 +67,13 @@ sub GetTaskDir($) return $self->GetStepDir() ."/". $self->TaskNo; }
+# Keep in sync with WineTestBot::Task::GetRefReportName() +sub GetRefReportName($$) +{ + my ($self, $ReportName) = @_; + return $self->VM->Name ."_$ReportName"; +} + sub GetTitle($) { my ($self) = @_; diff --git a/testbot/lib/WineTestBot/Tasks.pm b/testbot/lib/WineTestBot/Tasks.pm index f9e84d471..0c26904e1 100644 --- a/testbot/lib/WineTestBot/Tasks.pm +++ b/testbot/lib/WineTestBot/Tasks.pm @@ -108,6 +108,12 @@ sub RmTree($) rmtree($Dir); }
+sub GetRefReportName($$) +{ + my ($self, $ReportName) = @_; + return $self->VM->Name ."_$ReportName"; +} + sub _SetupTask($$) { my ($VM, $self) = @_; diff --git a/testbot/web/JobDetails.pl b/testbot/web/JobDetails.pl index a59fa000d..4d08a862c 100644 --- a/testbot/web/JobDetails.pl +++ b/testbot/web/JobDetails.pl @@ -529,8 +529,8 @@ EOF if ($LogName =~ /.report$/) { # Identify new errors in test reports - my $RefFileName = $StepTask->GetFullFileName($VM->Name ."_$LogName"); - (my $_NewGroups, my $_NewErrors, $New) = GetNewLogErrors($RefFileName, $Summary->{Groups}, $Summary->{Errors}); + my $RefReportPath = $StepTask->GetFullFileName($StepTask->GetRefReportName($LogName)); + (my $_NewGroups, my $_NewErrors, $New) = GetNewLogErrors($RefReportPath, $Summary->{Groups}, $Summary->{Errors}); }
foreach my $GroupName (@{$Summary->{Groups}})
All the logs have been renamed by now. --- testbot/bin/Engine.pl | 14 --------- testbot/lib/WineTestBot/LogUtils.pm | 44 ----------------------------- 2 files changed, 58 deletions(-)
diff --git a/testbot/bin/Engine.pl b/testbot/bin/Engine.pl index aed0e51d3..49347b559 100755 --- a/testbot/bin/Engine.pl +++ b/testbot/bin/Engine.pl @@ -103,20 +103,6 @@ sub Cleanup($;$$) { my ($Starting, $KillTasks, $KillVMs) = @_;
- # FIXME Temporary: Rename the old logs so they follow the new naming scheme - # and can be identified by WineSendLog.pl and JobDetails.pl. - RenameReferenceLogs(); - foreach my $Job (@{CreateJobs()->GetItems()}) - { - foreach my $Step (@{$Job->Steps->GetItems()}) - { - foreach my $Task (@{$Step->Tasks->GetItems()}) - { - RenameTaskLogs($Task->GetDir()); - } - } - } - # Verify that the running tasks are still alive and requeue them if not. # Ignore the Job and Step status fields because they may be a bit out of date. my %RunningVMs; diff --git a/testbot/lib/WineTestBot/LogUtils.pm b/testbot/lib/WineTestBot/LogUtils.pm index 1b9b1bfb6..f52af6704 100644 --- a/testbot/lib/WineTestBot/LogUtils.pm +++ b/testbot/lib/WineTestBot/LogUtils.pm @@ -29,7 +29,6 @@ WineTestBot::LogUtils - Provides functions to parse task logs use Exporter 'import'; our @EXPORT = qw(GetLogFileNames GetLogLabel GetLogErrors GetNewLogErrors GetLogLineCategory GetReportLineCategory - RenameReferenceLogs RenameTaskLogs ParseTaskLog ParseWineTestReport);
use Algorithm::Diff; @@ -567,49 +566,6 @@ sub GetReportLineCategory($) # Log querying and formatting #
-sub RenameReferenceLogs() -{ - if (opendir(my $dh, "$DataDir/latest")) - { - # We will be renaming files so read the directory in one go - my @Entries = readdir($dh); - close($dh); - foreach my $Entry (@Entries) - { - if ($Entry =~ /^([a-z0-9._]+)$/) - { - my $NewName = $Entry = $1; - $NewName =~ s/.log$/.report/; - $NewName =~ s/(_[a-z0-9]+).err$/$1.report.err/; - $NewName =~ s/_(32|64).report/_exe$1.report/; - if ($Entry ne $NewName and !-f "$DataDir/latest/$NewName") - { - rename "$DataDir/latest/$Entry", "$DataDir/latest/$NewName"; - } - } - } - } -} - -sub RenameTaskLogs($) -{ - my ($Dir) = @_; - - if (-f "$Dir/err" and !-f "$Dir/log.err") - { - rename "$Dir/err", "$Dir/log.err"; - } - - if (-f "$Dir/log.old" and !-f "$Dir/old_log") - { - rename "$Dir/log.old", "$Dir/old_log"; - } - if (-f "$Dir/err.old" and !-f "$Dir/old_log.err") - { - rename "$Dir/err.old", "$Dir/old_log.err"; - } -} - =pod =over 12
The reference reports are created from the the reports of the WineTest tasks, based on their completion time. Note that it is not possible to recreate reference reports for tasks that are older than the first completed WineTest task but such issues should go away when they are expired on the next day.
This allows fixing up the reference reports after an upgrade or a downgrade. For instance for a downgrade one could run 'UpdateTaskLogs --delete' first to delete files specific to the new code, then downgrade and run 'UpdateTaskLogs' to regenerate the files needed by the old code. Note however that this does not undo any rename operations done when upgrading. Those would need to be reverted by hand. --- testbot/bin/UpdateTaskLogs | 463 +++++++++++++++++++++++++++++++++++++ 1 file changed, 463 insertions(+) create mode 100755 testbot/bin/UpdateTaskLogs
diff --git a/testbot/bin/UpdateTaskLogs b/testbot/bin/UpdateTaskLogs new file mode 100755 index 000000000..d4c67bd87 --- /dev/null +++ b/testbot/bin/UpdateTaskLogs @@ -0,0 +1,463 @@ +#!/usr/bin/perl -Tw +# -*- Mode: Perl; perl-indent-level: 2; indent-tabs-mode: nil -*- +# +# Updates or recreates the reference reports for the specified tasks and the +# latest directory. +# +# Copyright 2019 Francois Gouget +# +# This library is free software; you can redistribute it and/or +# modify it under the terms of the GNU Lesser General Public +# License as published by the Free Software Foundation; either +# version 2.1 of the License, or (at your option) any later version. +# +# This library is distributed in the hope that it will be useful, +# but WITHOUT ANY WARRANTY; without even the implied warranty of +# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU +# Lesser General Public License for more details. +# +# You should have received a copy of the GNU Lesser General Public +# License along with this library; if not, write to the Free Software +# Foundation, Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301, USA + +use strict; + +sub BEGIN +{ + if ($0 !~ m=^/=) + { + # Turn $0 into an absolute path so it can safely be used in @INC + require Cwd; + $0 = Cwd::cwd() . "/$0"; + } + if ($0 =~ m=^(/.*)/[^/]+/[^/]+$=) + { + $::RootDir = $1; + unshift @INC, "$::RootDir/lib"; + } +} +my $Name0 = $0; +$Name0 =~ s+^.*/++; + + +use File::Basename; + +use WineTestBot::Config; +use WineTestBot::Jobs; +use WineTestBot::Log; +use WineTestBot::LogUtils; + + +# +# Logging and error handling helpers +# + +my $Debug; +sub Debug(@) +{ + print STDERR @_ if ($Debug); +} + +my $LogOnly; +sub Error(@) +{ + print STDERR "$Name0:error: ", @_ if (!$LogOnly); + LogMsg @_; +} + + +# +# Setup and command line processing +# + +my $Usage; +sub ValidateNumber($$) +{ + my ($Name, $Value) = @_; + + # Validate and untaint the value + return $1 if ($Value =~ /^(\d+)$/); + Error "$Value is not a valid $Name\n"; + $Usage = 2; + return undef; +} + +my ($OptDelete, $OptRebuild, $OptJobId, $OptStepNo, $OptTaskNo); +while (@ARGV) +{ + my $Arg = shift @ARGV; + if ($Arg eq "--delete") + { + $OptDelete = 1; + } + elsif ($Arg eq "--rebuild") + { + $OptRebuild = 1; + } + elsif ($Arg eq "--debug") + { + $Debug = 1; + } + elsif ($Arg eq "--log-only") + { + $LogOnly = 1; + } + elsif ($Arg =~ /^(?:-?|-h|--help)$/) + { + $Usage = 0; + last; + } + elsif ($Arg =~ /^-/) + { + Error "unknown option '$Arg'\n"; + $Usage = 2; + last; + } + elsif (!defined $OptJobId) + { + $OptJobId = ValidateNumber('job id', $Arg); + } + elsif (!defined $OptStepNo) + { + $OptStepNo = ValidateNumber('step number', $Arg); + } + elsif (!defined $OptTaskNo) + { + $OptTaskNo = ValidateNumber('task number', $Arg); + } + else + { + Error "unexpected argument '$Arg'\n"; + $Usage = 2; + last; + } +} + +# Check parameters +if (!defined $Usage) +{ + if ($OptDelete and $OptRebuild) + { + Error "--delete and --rebuild are mutually exclusive\n"; + $Usage = 2; + } +} +if (defined $Usage) +{ + print "Usage: $Name0 [--rebuild] [--log-only] [--debug] [--help] [JOBID [STEPNO [TASKNO]]]\n"; + print "\n"; + print "Deletes, upgrades or recreates the reference reports and .err files for the specified tasks and the latest directory.\n"; + print "\n"; + print "Where:\n"; + print " --delete Delete generated files of both the latest directory and the\n"; + print " tasks.\n"; + print " --rebuild Delete and recreate the generated files of both the latest\n"; + print " directory and the tasks from the reports of the WineTest tasks,\n"; + print " based on their completion time. For tasks older than the first\n"; + print " completed WineTest task, the individual tasks' reference\n"; + print " reports are preserved. If these tasks don't have reference\n"; + print " reports, an error is shown.\n"; + print " Without this option only the missing reference reports and\n"; + print " .err files are added.\n"; + print " JOBID STEPNO TASKNO Only the tasks matching the specified JOBID, STEPNO and\n"; + print " TASKNO will be modified.\n"; + print " --log-only Only print errors to the log. By default they also go to stderr.\n"; + print " --debug Print additional debugging information.\n"; + print " --help Shows this usage message.\n"; + + exit $Usage; +} + +sub TaskKeyStr($) +{ + my ($Task) = @_; + return join("/", @{$Task->GetMasterKey()}); +} + +sub Path2TaskKey($) +{ + my ($Path) = @_; + + return "latest" if (!defined $Path); + return "latest" if ($Path =~ m~/latest(?:/|$)~); + $Path =~ s~^.*/jobs/(\d+/\d+/\d+)(/.*)?$~$1~; + return $Path; +} + +sub BuildErrFile($$$$) +{ + my ($Dir, $ReportName, $IsWineTest, $TaskTimedOut) = @_; + + my $TaskKey = Path2TaskKey($Dir); + + my ($TestUnitCount, $TimeoutCount, $LogFailures, $LogErrors) = ParseWineTestReport("$Dir/$ReportName", $IsWineTest, $TaskTimedOut); + if (!defined $LogFailures and @$LogErrors == 1) + { + return "Unable to open '$TaskKey/$ReportName' for reading: $!"; + } + return undef if (!@$LogErrors); + + Debug("$TaskKey: Creating $ReportName.err\n"); + if (open(my $Log, ">", "$Dir/$ReportName.err")) + { + # Save the extra errors detected by ParseWineTestReport() in + # $ReportName.err (see WineRunWineTest.pl). + print $Log "$_\n" for (@$LogErrors); + close($Log); + return undef; + } + return "Unable to open '$TaskKey/$ReportName' for reading: $!"; +} + +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; + } + + my $Rc = 0; + if ($LatestRebuilds{$RefReportName}) + { + # Add the reference report to latest/ + Debug("latest: Adding $RefReportName from ". Path2TaskKey($SrcReportPath) ."\n"); + + foreach my $Suffix ("", ".err") + { + unlink("$LatestReportPath$Suffix"); + if (-f "$SrcReportPath$Suffix" and + !link("$SrcReportPath$Suffix", "$LatestReportPath$Suffix")) + { + Error "Could not replace 'latest/$RefReportName$Suffix': $!\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; +} + +sub ProcessTaskLogs($$$) +{ + my ($Step, $Task, $CollectOnly) = @_; + + my $Rc = 0; + my $StepDir = $Step->GetDir(); + my $TaskDir = $Task->GetDir(); + + if (($OptDelete or $OptRebuild) and !$CollectOnly) + { + # Save / delete the task's reference reports + foreach my $LogName (@{GetLogFileNames($TaskDir)}) + { + next if ($LogName !~ /.report$/); + + my $RefReportName = $Task->GetRefReportName($LogName); + my $RefReportPath = "$StepDir/$RefReportName"; + + if (-f $RefReportPath or -f "$RefReportPath.err") + { + if (!-f "$RefReportPath.err") + { + # (Re)Build the err file before adding the reference report to + # latest/. + my $ErrMessage = BuildErrFile($StepDir, $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, $LogName, $RefReportPath); + + Debug(TaskKeyStr($Task) .": Deleting ../$RefReportName\n"); + } + foreach my $Suffix ("", ".err") + { + if (!unlink "$RefReportPath$Suffix" and -e "$RefReportPath$Suffix") + { + Error "Could not delete '$RefReportPath$Suffix': $!\n"; + $Rc = 1; + } + } + + next if (!-f "$TaskDir/$LogName.err"); + Debug(TaskKeyStr($Task) .": Deleting $LogName.err\n"); + if (!unlink "$TaskDir/$LogName.err") + { + Error "Could not delete '$LogName.err': $!\n"; + $Rc = 1; + } + } + } + + if (!$OptDelete and !$CollectOnly and $Task->Status eq "completed") + { + # Take a snapshot of the latest reference reports + foreach my $LogName (@{GetLogFileNames($TaskDir)}) + { + next if ($LogName !~ /.report$/); + my $RefReportName = $Task->GetRefReportName($LogName); + next if (-f "$StepDir/$RefReportName"); + + my $LatestReportPath = $LatestReports{$RefReportName}; + if (!defined $LatestReportPath) + { + Error TaskKeyStr($Task) .": Missing '$RefReportName' reference report\n"; + $Rc = 1; + } + else + { + Debug(TaskKeyStr($Task) .": Snapshotting $RefReportName from ". Path2TaskKey($LatestReportPath) ."\n"); + foreach my $Suffix ("", ".err") + { + unlink "$StepDir/$RefReportName$Suffix"; + if (-f "$LatestReportPath$Suffix" and + !link("$LatestReportPath$Suffix", "$StepDir/$RefReportName$Suffix")) + { + Error "Could not link '$RefReportName$Suffix': $!\n"; + $Rc = 1; + } + } + } + } + + # And (re)build the .err files + if ($Task->Status !~ /^(?:queued|running)$/) + { + my ($IsWineTest, $TaskTimedOut); + if ($Task->Started and $Task->Ended) + { + my $Duration = $Task->Ended - $Task->Started; + $TaskTimedOut = $Duration > $Task->Timeout; + $IsWineTest = ($Step->Type eq "patch" or $Step->Type eq "suite"); + } + foreach my $LogName (@{GetLogFileNames($TaskDir)}) + { + next if ($LogName !~ /.report$/); + next if (-f "$TaskDir/$LogName.err"); + my $ErrMessage = BuildErrFile($TaskDir, $LogName, $IsWineTest, $TaskTimedOut); + if (defined $ErrMessage) + { + Error "$ErrMessage\n"; + $Rc = 1; + } + } + } + } + + if (!$OptDelete and $Task->Status eq "completed" and $Step->Type eq "suite") + { + # Update the latest reference reports + # WineTest runs that timed out are missing results which would cause false + # positives. So don't use them as reference results. Also note that + # WineTest tasks have a single WineTest run so a task timeout is the same + # as a WineTest timeout. + my $Duration = $Task->Ended - $Task->Started; + if ($Duration < $Task->Timeout) + { + foreach my $LogName (@{GetLogFileNames($TaskDir)}) + { + next if ($LogName !~ /.report$/); + next if (-z "$TaskDir/$LogName"); + $Rc += DoUpdateLatestReport($Task, $LogName, "$TaskDir/$LogName"); + } + } + } + + return $Rc; +} + +sub ProcessLatestReports() +{ + my $Rc = 0; + my $LatestGlob = "$DataDir/latest/*.report"; + + # Perform cleanups and updates + foreach my $LatestReportPath (glob("$LatestGlob $LatestGlob.err")) + { + my $RefReportName = basename($LatestReportPath); + next if ($RefReportName !~ /^([a-zA-Z0-9_]+.report)(?:.err)?$/); + $RefReportName = $1; # untaint + $LatestReportPath = "$DataDir/latest/$RefReportName"; + + if ($OptDelete or $OptRebuild) + { + # Delete the reports so they are rebuilt from scratch if appropriate + foreach my $Suffix ("", ".err") + { + next if (!-f "$LatestReportPath$Suffix"); + Debug("latest: Deleting $RefReportName$Suffix\n"); + next if (unlink "$LatestReportPath$Suffix"); + Error "Could not delete '$LatestReportPath$Suffix': $!\n"; + $Rc = 1; + } + } + elsif (!-f "$LatestReportPath") + { + Debug("latest: Deleting orphaned $RefReportName.err\n"); + if (!unlink "$LatestReportPath.err") + { + Error "Could not delete orphaned '$LatestReportPath.err': $!\n"; + $Rc = 1; + } + } + elsif (!$OptDelete and !-f "$LatestReportPath.err") + { + # Build the missing .err file + my $ErrMessage = BuildErrFile("$DataDir/latest", $RefReportName, 1, 0); + if (defined $ErrMessage) + { + Error "$ErrMessage\n"; + $Rc = 1; + } + } + } + + return $Rc; +} + +my $Rc = 0; +$Rc = ProcessLatestReports() if (!defined $OptJobId); + +my @AllTasks; +foreach my $Job (@{CreateJobs()->GetItems()}) +{ + foreach my $Step (@{$Job->Steps->GetItems()}) + { + foreach my $Task (@{$Step->Tasks->GetItems()}) + { + push @AllTasks, $Task if ($Task->Status !~ /^(?:queued|running)$/); + } + } +} + +# Process the tasks in completion order so the reference logs +# are updated in the right order. +my $Jobs = CreateJobs(); +foreach my $Task (sort { ($a->Ended || 0) <=> ($b->Ended || 0) } @AllTasks) +{ + my ($JobId, $StepNo, $TaskNo) = @{$Task->GetMasterKey()}; + my $Step = $Jobs->GetItem($JobId)->Steps->GetItem($StepNo); + my $CollectOnly = ((defined $OptJobId and $OptJobId ne $JobId) or + (defined $OptStepNo and $OptStepNo ne $StepNo) or + (defined $OptTaskNo and $OptTaskNo ne $TaskNo)); + $Rc += ProcessTaskLogs($Step, $Task, $CollectOnly); +} + +exit $Rc ? 1 : 0;
TagNewErrors() replaces GetNewLogErrors() and tags new errors in the provided error list instead of returning a new list containing only the new errors. --- testbot/bin/WineSendLog.pl | 27 +++++--- testbot/lib/WineTestBot/LogUtils.pm | 103 +++++++++++++++++----------- testbot/web/JobDetails.pl | 10 +-- 3 files changed, 85 insertions(+), 55 deletions(-)
diff --git a/testbot/bin/WineSendLog.pl b/testbot/bin/WineSendLog.pl index 1ec7db1bd..d61b403b9 100755 --- a/testbot/bin/WineSendLog.pl +++ b/testbot/bin/WineSendLog.pl @@ -218,7 +218,7 @@ EOF foreach my $GroupName (@$Groups) { print $Sendmail ($GroupName ? "\n$GroupName:\n" : "\n"); - print $Sendmail "$_\n" for (@{$Errors->{$GroupName}}); + print $Sendmail "$_\n" for (@{$Errors->{$GroupName}->{Errors}}); } } } @@ -251,7 +251,7 @@ EOF } } } - + print $Sendmail "\n--$PART_BOUNDARY--\n"; close($Sendmail);
@@ -291,19 +291,19 @@ EOF # Skip if there are no errors next if (!$LogErrors->{Groups});
+ my $AllNew; my $RefReportPath = $StepTask->GetFullFileName($StepTask->GetRefReportName($LogName)); - my ($NewGroups, $NewErrors, $_NewIndices) = GetNewLogErrors($RefReportPath, $LogErrors->{Groups}, $LogErrors->{Errors}); - if (!$NewGroups) + my $NewCount = TagNewErrors($RefReportPath, $LogErrors->{Groups}, $LogErrors->{Errors}); + if (!defined $NewCount) { # Test reports should have reference WineTest results and if not # reporting the errors as new would cause false positives. next if ($LogName =~ /.report$/);
# Build logs don't have reference logs so for them every error is new. - $NewGroups = $LogErrors->{Groups}; - $NewErrors = $LogErrors->{Errors}; + $AllNew = 1; } - if (!$NewGroups or !@$NewGroups) + elsif (!$NewCount) { # There is no new error next; @@ -311,10 +311,19 @@ EOF
push @Messages, "\n=== ". GetTitle($StepTask, $LogName) ." ===\n";
- foreach my $GroupName (@$NewGroups) + foreach my $GroupName (@{$LogErrors->{Groups}}) { + my $Group = $LogErrors->{Errors}->{$GroupName}; + next if (!$AllNew and !$Group->{NewCount}); + push @Messages, ($GroupName ? "\n$GroupName:\n" : "\n"); - push @Messages, "$_\n" for (@{$NewErrors->{$GroupName}}); + foreach my $ErrIndex (0..@{$Group->{Errors}} - 1) + { + if ($AllNew or $Group->{IsNew}->[$ErrIndex]) + { + push @Messages, "$Group->{Errors}->[$ErrIndex]\n"; + } + } } } } diff --git a/testbot/lib/WineTestBot/LogUtils.pm b/testbot/lib/WineTestBot/LogUtils.pm index f52af6704..3141cb286 100644 --- a/testbot/lib/WineTestBot/LogUtils.pm +++ b/testbot/lib/WineTestBot/LogUtils.pm @@ -1,5 +1,5 @@ # -*- Mode: Perl; perl-indent-level: 2; indent-tabs-mode: nil -*- -# Copyright 2018 Francois Gouget +# Copyright 2018-2019 Francois Gouget # # This library is free software; you can redistribute it and/or # modify it under the terms of the GNU Lesser General Public @@ -27,7 +27,7 @@ WineTestBot::LogUtils - Provides functions to parse task logs
use Exporter 'import'; -our @EXPORT = qw(GetLogFileNames GetLogLabel GetLogErrors GetNewLogErrors +our @EXPORT = qw(GetLogFileNames GetLogLabel GetLogErrors TagNewErrors GetLogLineCategory GetReportLineCategory ParseTaskLog ParseWineTestReport);
@@ -669,7 +669,7 @@ sub _DumpErrors($$$) foreach my $GroupName (@$Groups) { print STDERR " [$GroupName]\n"; - print STDERR " [$_]\n" for (@{$Errors->{$GroupName}}); + print STDERR " [$_]\n" for (@{$Errors->{$GroupName}->{Errors}}); } }
@@ -682,7 +682,7 @@ sub _AddErrorGroup($$$) if (!$Errors->{$GroupName}) { push @$Groups, $GroupName; - $Errors->{$GroupName} = []; + $Errors->{$GroupName} = {Errors => []}; } return $Errors->{$GroupName}; } @@ -745,7 +745,7 @@ sub GetLogErrors($) { $CurrentGroup = _AddErrorGroup($Groups, $Errors, $CurrentModule); } - push @$CurrentGroup, $Line; + push @{$CurrentGroup->{Errors}}, $Line; } close($LogFile); } @@ -753,7 +753,7 @@ sub GetLogErrors($) { $NoLog = 0; my $Group = _AddErrorGroup($Groups, $Errors, "TestBot errors"); - push @$Group, "Could not open '". basename($LogFileName) ."' for reading: $!"; + $Group->{Errors} = ["Could not open '". basename($LogFileName) ."' for reading: $!"]; }
if (open(my $LogFile, "<", "$LogFileName.err")) @@ -771,7 +771,7 @@ sub GetLogErrors($) my $GroupName = $IsReport ? "Report errors" : "Task errors"; $CurrentGroup = _AddErrorGroup($Groups, $Errors, $GroupName); } - push @$CurrentGroup, $Line; + push @{$CurrentGroup->{Errors}}, $Line; } close($LogFile); } @@ -779,7 +779,7 @@ sub GetLogErrors($) { $NoLog = 0; my $Group = _AddErrorGroup($Groups, $Errors, "TestBot errors"); - push @$Group, "Could not open '". basename($LogFileName) .".err' for reading: $!"; + $Group->{Errors} = ["Could not open '". basename($LogFileName) .".err' for reading: $!"]; }
return $NoLog ? (undef, undef) : ($Groups, $Errors); @@ -812,8 +812,9 @@ sub _DumpDiff($$)
=item C<_GetLineKey()>
-This is a helper for GetNewLogErrors(). It reformats the log lines so they can -meaningfully be compared to the reference log even if line numbers change, etc. +This is a helper for TagNewErrors(). It reformats the log lines so they +can meaningfully be compared to the reference log even if line numbers change, +etc.
=back =cut @@ -844,63 +845,83 @@ sub _GetLineKey($) =pod =over 12
-=item C<GetNewLogErrors()> +=item C<TagNewErrors()>
-Compares the specified errors to the reference log and returns only the ones -that are new. +Compares the specified errors to the reference report to identify new errors.
-Returns a list of error groups containing new errors, a hashtable containing -the list of new errors for each group, and a hashtable containing the indices -of the new errors in the input errors list for each group. +Adds two fields to each error group: +=over + +=item NewCount +A count of the new errors. + +=item IsNew +An array where entries are set to true to identify new errors. + +=back + +Returns a global count of the new errors. Returns undef if there is no +reference log to identify the new errors.
=back =cut
-sub GetNewLogErrors($$$) +sub TagNewErrors($$$) { - my ($RefFileName, $Groups, $Errors) = @_; + my ($RefLogPath, $Groups, $Errors) = @_;
- my (@NewGroups, %NewErrors, %NewIndices); - return (@NewGroups, %NewErrors, %NewIndices) if (!$Groups or !@$Groups); + return 0 if (!$Groups or !@$Groups);
- my ($RefGroups, $RefErrors) = GetLogErrors($RefFileName); - return (undef, undef) if (!$RefGroups); + my ($RefGroups, $RefErrors) = GetLogErrors($RefLogPath); + return undef if (!$RefGroups);
+ my $NewCount = 0; foreach my $GroupName (@$Groups) { + my $Group = $Errors->{$GroupName}; + $Group->{NewCount} = 0; + if ($RefErrors->{$GroupName}) { - my $Diff = Algorithm::Diff->new($RefErrors->{$GroupName}, - $Errors->{$GroupName}, + my $Diff = Algorithm::Diff->new($RefErrors->{$GroupName}->{Errors}, + $Group->{Errors}, { keyGen => &_GetLineKey }); - my ($CurrentGroup, $CurrentIndices); + my $ErrIndex = 0; while ($Diff->Next()) { - # Skip if there are no new lines - next if ($Diff->Same() or !$Diff->Items(2)); - - if (!$CurrentGroup) + my $SameCount = $Diff->Same(); + if ($SameCount) + { + $ErrIndex += $SameCount; + } + else { - push @NewGroups, $GroupName; - $CurrentGroup = $NewErrors{$GroupName} = []; - $CurrentIndices = $NewIndices{$GroupName} = {}; + # Added lines are the new errors + my $AddedCount = $Diff->Items(2); + $Group->{NewCount} += $AddedCount; + foreach (1..$AddedCount) + { + $Group->{IsNew}->[$ErrIndex] = 1; + $ErrIndex++; + } } - push @$CurrentGroup, $Diff->Items(2); - $CurrentIndices->{$_} = 1 for ($Diff->Range(2)); } } else { - # This group did not have errors before, so every error is new - push @NewGroups, $GroupName; - $NewErrors{$GroupName} = $Errors->{$GroupName}; - $NewIndices{$GroupName} = {}; - my $Last = @{$Errors->{$GroupName}} - 1; - $NewIndices{$GroupName}->{$_} = 1 for (0..$Last); + $Group->{NewCount} = @{$Group->{Errors}}; + if ($Group->{NewCount}) + { + foreach my $ErrIndex (0..$Group->{NewCount} - 1) + { + $Group->{IsNew}->[$ErrIndex] = 1; + } + } } + $NewCount += $Group->{NewCount}; }
- return (@NewGroups, %NewErrors, %NewIndices); + return $NewCount; }
1; diff --git a/testbot/web/JobDetails.pl b/testbot/web/JobDetails.pl index 4d08a862c..f3105d019 100644 --- a/testbot/web/JobDetails.pl +++ b/testbot/web/JobDetails.pl @@ -525,12 +525,11 @@ EOF }
my $Summary = $LogSummaries->{$LogName}; - my $New; if ($LogName =~ /.report$/) { - # Identify new errors in test reports + # For test reports try to identify the new errors my $RefReportPath = $StepTask->GetFullFileName($StepTask->GetRefReportName($LogName)); - (my $_NewGroups, my $_NewErrors, $New) = GetNewLogErrors($RefReportPath, $Summary->{Groups}, $Summary->{Errors}); + TagNewErrors($RefReportPath, $Summary->{Groups}, $Summary->{Errors}); }
foreach my $GroupName (@{$Summary->{Groups}}) @@ -539,9 +538,10 @@ EOF
print "<pre><code>"; my $ErrIndex = 0; - foreach my $Line (@{$Summary->{Errors}->{$GroupName}}) + my $Group = $Summary->{Errors}->{$GroupName}; + foreach my $Line (@{$Group->{Errors}}) { - if ($New and $New->{$GroupName}->{$ErrIndex}) + if ($Group->{IsNew}->[$ErrIndex]) { print "<span class='log-new'>", $self->escapeHTML($Line), "</span>\n"; }
--- testbot/bin/WineSendLog.pl | 26 +++---- testbot/lib/WineTestBot/LogUtils.pm | 103 +++++++++++++++++----------- testbot/web/JobDetails.pl | 21 +++--- 3 files changed, 86 insertions(+), 64 deletions(-)
diff --git a/testbot/bin/WineSendLog.pl b/testbot/bin/WineSendLog.pl index d61b403b9..89e90c40f 100755 --- a/testbot/bin/WineSendLog.pl +++ b/testbot/bin/WineSendLog.pl @@ -207,18 +207,18 @@ EOF $JobErrors->{$Key}->{LogNames} = $LogNames; foreach my $LogName (@$LogNames) { - my ($Groups, $Errors) = GetLogErrors("$TaskDir/$LogName"); - next if (!$Groups or !@$Groups); + my $LogInfo = GetLogErrors("$TaskDir/$LogName"); + next if (!$LogInfo->{ErrCount}); $JobErrors->{$Key}->{HasErrors} = 1; - $JobErrors->{$Key}->{$LogName}->{Groups} = $Groups; - $JobErrors->{$Key}->{$LogName}->{Errors} = $Errors; + $JobErrors->{$Key}->{$LogName} = $LogInfo;
print $Sendmail "\n=== ", GetTitle($StepTask, $LogName), " ===\n";
- foreach my $GroupName (@$Groups) + foreach my $GroupName (@{$LogInfo->{ErrGroupNames}}) { print $Sendmail ($GroupName ? "\n$GroupName:\n" : "\n"); - print $Sendmail "$_\n" for (@{$Errors->{$GroupName}->{Errors}}); + my $Group = $LogInfo->{ErrGroups}->{$GroupName}; + print $Sendmail "$_\n" for (@{$Group->{Errors}}); } } } @@ -287,14 +287,14 @@ EOF
foreach my $LogName (@{$JobErrors->{$Key}->{LogNames}}) { - my $LogErrors = $JobErrors->{$Key}->{$LogName}; + my $LogInfo = $JobErrors->{$Key}->{$LogName}; # Skip if there are no errors - next if (!$LogErrors->{Groups}); + next if (!$LogInfo->{ErrCount});
my $AllNew; my $RefReportPath = $StepTask->GetFullFileName($StepTask->GetRefReportName($LogName)); - my $NewCount = TagNewErrors($RefReportPath, $LogErrors->{Groups}, $LogErrors->{Errors}); - if (!defined $NewCount) + TagNewErrors($RefReportPath, $LogInfo); + if (!defined $LogInfo->{NewCount}) { # Test reports should have reference WineTest results and if not # reporting the errors as new would cause false positives. @@ -303,7 +303,7 @@ EOF # Build logs don't have reference logs so for them every error is new. $AllNew = 1; } - elsif (!$NewCount) + elsif (!$LogInfo->{NewCount}) { # There is no new error next; @@ -311,9 +311,9 @@ EOF
push @Messages, "\n=== ". GetTitle($StepTask, $LogName) ." ===\n";
- foreach my $GroupName (@{$LogErrors->{Groups}}) + foreach my $GroupName (@{$LogInfo->{ErrGroupNames}}) { - my $Group = $LogErrors->{Errors}->{$GroupName}; + my $Group = $LogInfo->{ErrGroups}->{$GroupName}; next if (!$AllNew and !$Group->{NewCount});
push @Messages, ($GroupName ? "\n$GroupName:\n" : "\n"); diff --git a/testbot/lib/WineTestBot/LogUtils.pm b/testbot/lib/WineTestBot/LogUtils.pm index 3141cb286..d3aa82c2e 100644 --- a/testbot/lib/WineTestBot/LogUtils.pm +++ b/testbot/lib/WineTestBot/LogUtils.pm @@ -673,18 +673,18 @@ sub _DumpErrors($$$) } }
-sub _AddErrorGroup($$$) +sub _AddErrorGroup($$) { - my ($Groups, $Errors, $GroupName) = @_; + my ($LogInfo, $GroupName) = @_;
# In theory the error group names are all unique. But, just in case, make - # sure we don't overwrite $Errors->{$GroupName}. - if (!$Errors->{$GroupName}) + # sure we don't overwrite $LogInfo->{ErrGroups}->{$GroupName}. + if (!$LogInfo->{ErrGroups}->{$GroupName}) { - push @$Groups, $GroupName; - $Errors->{$GroupName} = {Errors => []}; + push @{$LogInfo->{ErrGroupNames}}, $GroupName; + $LogInfo->{ErrGroups}->{$GroupName} = { Errors => [] }; } - return $Errors->{$GroupName}; + return $LogInfo->{ErrGroups}->{$GroupName}; }
=pod @@ -696,8 +696,24 @@ Analyzes the specified log and associated error file to filter out unimportant messages and only return the errors, split by module (for Wine reports that's per dll / program being tested).
-Returns a list of modules containing errors, and a hashtable containing the list of errors for each module. +Returns a hashtable containing: +=over + +=item ErrCount +The number of errors. This is undefined if no log file was found. + +=item ErrGroupNames +An array containing the names of all the error groups. + +=item ErrGroups +A hashtable indexed by the error group name. Each entry contains:
+=over +=item Errors +An array containing the error messages. +=back + +=back =back =cut
@@ -716,12 +732,14 @@ sub GetLogErrors($) $GetCategory = &GetLogLineCategory; }
- my $NoLog = 1; - my $Groups = []; - my $Errors = {}; + my $LogInfo = { + ErrCount => undef, # until we open a log + ErrGroupNames => [], + ErrGroups => {}, + }; if (open(my $LogFile, "<", $LogFileName)) { - $NoLog = 0; + $LogInfo->{ErrCount} ||= 0; my $CurrentModule = ""; my $CurrentGroup; foreach my $Line (<$LogFile>) @@ -743,22 +761,23 @@ sub GetLogErrors($) } if (!$CurrentGroup) { - $CurrentGroup = _AddErrorGroup($Groups, $Errors, $CurrentModule); + $CurrentGroup = _AddErrorGroup($LogInfo, $CurrentModule); } push @{$CurrentGroup->{Errors}}, $Line; + $LogInfo->{ErrCount}++; } close($LogFile); } elsif (-f $LogFileName) { - $NoLog = 0; - my $Group = _AddErrorGroup($Groups, $Errors, "TestBot errors"); - $Group->{Errors} = ["Could not open '". basename($LogFileName) ."' for reading: $!"]; + my $Group = _AddErrorGroup($LogInfo, "TestBot errors"); + push @{$Group->{Errors}}, "Could not open '". basename($LogFileName) ."' for reading: $!"; + $LogInfo->{ErrCount}++; }
if (open(my $LogFile, "<", "$LogFileName.err")) { - $NoLog = 0; + $LogInfo->{ErrCount} ||= 0; # Add the related extra errors my $CurrentGroup; foreach my $Line (<$LogFile>) @@ -769,20 +788,21 @@ sub GetLogErrors($) # Note: $GroupName must not depend on the previous content as this # would break diffs. my $GroupName = $IsReport ? "Report errors" : "Task errors"; - $CurrentGroup = _AddErrorGroup($Groups, $Errors, $GroupName); + $CurrentGroup = _AddErrorGroup($LogInfo, $GroupName); } push @{$CurrentGroup->{Errors}}, $Line; + $LogInfo->{ErrCount}++; } close($LogFile); } elsif (-f "$LogFileName.err") { - $NoLog = 0; - my $Group = _AddErrorGroup($Groups, $Errors, "TestBot errors"); - $Group->{Errors} = ["Could not open '". basename($LogFileName) .".err' for reading: $!"]; + my $Group = _AddErrorGroup($LogInfo, "TestBot errors"); + push @{$Group->{Errors}}, "Could not open '". basename($LogFileName) .".err' for reading: $!"; + $LogInfo->{ErrCount}++; }
- return $NoLog ? (undef, undef) : ($Groups, $Errors); + return $LogInfo; }
sub _DumpDiff($$) @@ -849,6 +869,9 @@ sub _GetLineKey($)
Compares the specified errors to the reference report to identify new errors.
+Sets $LogInfo->{NewCount} to the total number of new errors. If there is no +reference log to identify the new errors this field is left undefined. + Adds two fields to each error group: =over
@@ -859,32 +882,33 @@ A count of the new errors. An array where entries are set to true to identify new errors.
=back - -Returns a global count of the new errors. Returns undef if there is no -reference log to identify the new errors. - =back =cut
-sub TagNewErrors($$$) +sub TagNewErrors($$) { - my ($RefLogPath, $Groups, $Errors) = @_; + my ($RefLogPath, $LogInfo) = @_;
- return 0 if (!$Groups or !@$Groups); + if (!$LogInfo->{ErrCount}) + { + $LogInfo->{NewCount} = 0; + return; + }
- my ($RefGroups, $RefErrors) = GetLogErrors($RefLogPath); - return undef if (!$RefGroups); + my $RefInfo = GetLogErrors($RefLogPath); + # Don't tag the errors as new if there is no reference log + return if (!defined $RefInfo->{ErrCount});
- my $NewCount = 0; - foreach my $GroupName (@$Groups) + $LogInfo->{NewCount} = 0; + foreach my $GroupName (@{$LogInfo->{ErrGroupNames}}) { - my $Group = $Errors->{$GroupName}; + my $Group = $LogInfo->{ErrGroups}->{$GroupName}; $Group->{NewCount} = 0;
- if ($RefErrors->{$GroupName}) + my $RefGroup = $RefInfo->{ErrGroups}->{$GroupName}; + if ($RefGroup) { - my $Diff = Algorithm::Diff->new($RefErrors->{$GroupName}->{Errors}, - $Group->{Errors}, + my $Diff = Algorithm::Diff->new($RefGroup->{Errors}, $Group->{Errors}, { keyGen => &_GetLineKey }); my $ErrIndex = 0; while ($Diff->Next()) @@ -909,6 +933,7 @@ sub TagNewErrors($$$) } else { + # All errors in this group are new $Group->{NewCount} = @{$Group->{Errors}}; if ($Group->{NewCount}) { @@ -918,10 +943,8 @@ sub TagNewErrors($$$) } } } - $NewCount += $Group->{NewCount}; + $LogInfo->{NewCount} += $Group->{NewCount}; } - - return $NewCount; }
1; diff --git a/testbot/web/JobDetails.pl b/testbot/web/JobDetails.pl index f3105d019..48d511ccb 100644 --- a/testbot/web/JobDetails.pl +++ b/testbot/web/JobDetails.pl @@ -500,21 +500,20 @@ EOF #
# Figure out which logs / reports actually have errors - my $LogSummaries; + my $LogInfos; foreach my $LogName (@{$MoreInfo->{Logs}}) { next if ($LogName =~ /^old_/); - my ($Groups, $Errors) = GetLogErrors("$TaskDir/$LogName"); - next if (!$Groups or !@$Groups); - $LogSummaries->{$LogName}->{Groups} = $Groups; - $LogSummaries->{$LogName}->{Errors} = $Errors; + my $LogInfo = GetLogErrors("$TaskDir/$LogName"); + next if (!$LogInfo->{ErrCount}); + $LogInfos->{$LogName} = $LogInfo; } - my $ShowLogName = ($ReportCount > 1 or scalar(keys %$LogSummaries) > 1); + my $ShowLogName = ($ReportCount > 1 or scalar(keys %$LogInfos) > 1);
my $LogIsEmpty = 1; foreach my $LogName (@{$MoreInfo->{Logs}}) { - next if (!$LogSummaries->{$LogName}); + next if (!$LogInfos->{$LogName}); $LogIsEmpty = 0;
if ($ShowLogName) @@ -524,21 +523,21 @@ EOF print "<div class='HrTitle'>$Label<div class='HrLine'></div></div>\n"; }
- my $Summary = $LogSummaries->{$LogName}; + my $LogInfo = $LogInfos->{$LogName}; if ($LogName =~ /.report$/) { # For test reports try to identify the new errors my $RefReportPath = $StepTask->GetFullFileName($StepTask->GetRefReportName($LogName)); - TagNewErrors($RefReportPath, $Summary->{Groups}, $Summary->{Errors}); + TagNewErrors($RefReportPath, $LogInfo); }
- foreach my $GroupName (@{$Summary->{Groups}}) + foreach my $GroupName (@{$LogInfo->{ErrGroupNames}}) { print "<div class='LogDllName'>$GroupName</div>\n" if ($GroupName);
print "<pre><code>"; my $ErrIndex = 0; - my $Group = $Summary->{Errors}->{$GroupName}; + my $Group = $LogInfo->{ErrGroups}->{$GroupName}; foreach my $Line (@{$Group->{Errors}}) { if ($Group->{IsNew}->[$ErrIndex])
This simplifies registering an additional log error. Also rename _AddErrorGroup() to _AddLogGroup() to match. --- testbot/lib/WineTestBot/LogUtils.pm | 30 ++++++++++++++++------------- 1 file changed, 17 insertions(+), 13 deletions(-)
diff --git a/testbot/lib/WineTestBot/LogUtils.pm b/testbot/lib/WineTestBot/LogUtils.pm index d3aa82c2e..787d450b5 100644 --- a/testbot/lib/WineTestBot/LogUtils.pm +++ b/testbot/lib/WineTestBot/LogUtils.pm @@ -673,7 +673,7 @@ sub _DumpErrors($$$) } }
-sub _AddErrorGroup($$) +sub _AddLogGroup($$) { my ($LogInfo, $GroupName) = @_;
@@ -687,6 +687,14 @@ sub _AddErrorGroup($$) return $LogInfo->{ErrGroups}->{$GroupName}; }
+sub _AddLogError($$$) +{ + my ($LogInfo, $ErrGroup, $Line) = @_; + + push @{$ErrGroup->{Errors}}, $Line; + $LogInfo->{ErrCount}++; +} + =pod =over 12
@@ -761,18 +769,16 @@ sub GetLogErrors($) } if (!$CurrentGroup) { - $CurrentGroup = _AddErrorGroup($LogInfo, $CurrentModule); + $CurrentGroup = _AddLogGroup($LogInfo, $CurrentModule); } - push @{$CurrentGroup->{Errors}}, $Line; - $LogInfo->{ErrCount}++; + _AddLogError($LogInfo, $CurrentGroup, $Line); } close($LogFile); } elsif (-f $LogFileName) { - my $Group = _AddErrorGroup($LogInfo, "TestBot errors"); - push @{$Group->{Errors}}, "Could not open '". basename($LogFileName) ."' for reading: $!"; - $LogInfo->{ErrCount}++; + my $Group = _AddLogGroup($LogInfo, "TestBot errors"); + _AddLogError($LogInfo, $Group, "Could not open '". basename($LogFileName) ."' for reading: $!"); }
if (open(my $LogFile, "<", "$LogFileName.err")) @@ -788,18 +794,16 @@ sub GetLogErrors($) # Note: $GroupName must not depend on the previous content as this # would break diffs. my $GroupName = $IsReport ? "Report errors" : "Task errors"; - $CurrentGroup = _AddErrorGroup($LogInfo, $GroupName); + $CurrentGroup = _AddLogGroup($LogInfo, $GroupName); } - push @{$CurrentGroup->{Errors}}, $Line; - $LogInfo->{ErrCount}++; + _AddLogError($LogInfo, $CurrentGroup, $Line); } close($LogFile); } elsif (-f "$LogFileName.err") { - my $Group = _AddErrorGroup($LogInfo, "TestBot errors"); - push @{$Group->{Errors}}, "Could not open '". basename($LogFileName) .".err' for reading: $!"; - $LogInfo->{ErrCount}++; + my $Group = _AddLogGroup($LogInfo, "TestBot errors"); + _AddLogError($LogInfo, $Group, "Could not open '". basename($LogFileName) .".err' for reading: $!"); }
return $LogInfo;
ParseTaskLog() will eventually return the same information as GetLogErrors() so name the resulting structures to match. --- testbot/bin/WineRunBuild.pl | 10 +++++----- testbot/bin/WineRunReconfig.pl | 16 ++++++++-------- testbot/bin/WineRunWineTest.pl | 12 ++++++------ testbot/lib/WineTestBot/LogUtils.pm | 16 ++++++++-------- 4 files changed, 27 insertions(+), 27 deletions(-)
diff --git a/testbot/bin/WineRunBuild.pl b/testbot/bin/WineRunBuild.pl index ce8f40f05..cf6428ae4 100755 --- a/testbot/bin/WineRunBuild.pl +++ b/testbot/bin/WineRunBuild.pl @@ -419,23 +419,23 @@ if (!defined $TA->Wait($Pid, $Task->Timeout, 60)) Debug(Elapsed($Start), " Retrieving 'Build.log'\n"); if ($TA->GetFile("Build.log", "$TaskDir/log")) { - my $Summary = ParseTaskLog("$TaskDir/log"); - if ($Summary->{Task} eq "ok") + my $LogInfo = ParseTaskLog("$TaskDir/log"); + if ($LogInfo->{Task} eq "ok") { # We must have gotten the full log and the build did succeed. # So forget any prior error. $NewStatus = "completed"; $TAError = $ErrMessage = undef; } - elsif ($Summary->{Task} eq "badpatch") + elsif ($LogInfo->{Task} eq "badpatch") { # This too is conclusive enough to ignore other errors. $NewStatus = "badpatch"; $TAError = $ErrMessage = undef; } - elsif ($Summary->{NoLog}) + elsif ($LogInfo->{NoLog}) { - FatalError("$Summary->{NoLog}\n", "retry"); + FatalError("$LogInfo->{NoLog}\n", "retry"); } else { diff --git a/testbot/bin/WineRunReconfig.pl b/testbot/bin/WineRunReconfig.pl index 9b0b479ee..c16c40a5a 100755 --- a/testbot/bin/WineRunReconfig.pl +++ b/testbot/bin/WineRunReconfig.pl @@ -416,21 +416,21 @@ if (!defined $TA->Wait($Pid, $Task->Timeout, 60)) } }
-my $Summary; +my $LogInfo; Debug(Elapsed($Start), " Retrieving 'Reconfig.log'\n"); if ($TA->GetFile("Reconfig.log", "$TaskDir/log")) { - $Summary = ParseTaskLog("$TaskDir/log"); - if ($Summary->{Task} eq "ok") + $LogInfo = ParseTaskLog("$TaskDir/log"); + if ($LogInfo->{Task} eq "ok") { # We must have gotten the full log and the build did succeed. # So forget any prior error. $NewStatus = "completed"; $TAError = $ErrMessage = undef; } - elsif ($Summary->{NoLog}) + elsif ($LogInfo->{NoLog}) { - FatalError("$Summary->{NoLog}\n", "retry"); + FatalError("$LogInfo->{NoLog}\n", "retry"); } else { @@ -438,7 +438,7 @@ if ($TA->GetFile("Reconfig.log", "$TaskDir/log")) # probably already have an error message that explains why. NotifyAdministrator("The ". $VM->Name ." build failed", "The ". $VM->Name ." build failed:\n\n". - "$Summary->{Task}\n\n". + "$LogInfo->{Task}\n\n". "See the link below for more details:\n". MakeSecureURL(GetTaskURL($JobId, $StepNo, $TaskNo)) ."\n"); $NewStatus = "badbuild"; @@ -469,7 +469,7 @@ if ($NewStatus eq "completed") "latest/wine-parentsrc.txt") { my $BaseName = basename($FileName); - if ($FileName !~ m~^latest/~ and !$Summary->{$BaseName} and + if ($FileName !~ m~^latest/~ and !$LogInfo->{$BaseName} and -f "$DataDir/latest/$BaseName") { # This file was not updated so there is no point in redownloading it. @@ -486,7 +486,7 @@ if ($NewStatus eq "completed") } }
- if ($Summary->{"testagentd"}) + if ($LogInfo->{"testagentd"}) { # Restart the TestAgent server from the new binary # Note that the privileged TestAgent server is usually run with diff --git a/testbot/bin/WineRunWineTest.pl b/testbot/bin/WineRunWineTest.pl index 245128a73..fecbab009 100755 --- a/testbot/bin/WineRunWineTest.pl +++ b/testbot/bin/WineRunWineTest.pl @@ -527,8 +527,8 @@ if (!defined $TA->Wait($Pid, $Task->Timeout, 60)) Debug(Elapsed($Start), " Retrieving 'Task.log'\n"); if ($TA->GetFile("Task.log", "$TaskDir/log")) { - my $Summary = ParseTaskLog("$TaskDir/log"); - if ($Summary->{Task} eq "ok") + my $LogInfo = ParseTaskLog("$TaskDir/log"); + if ($LogInfo->{Task} eq "ok") { # We must have gotten the full log and the task completed successfully # (with or without test failures). So clear any previous errors, including @@ -536,17 +536,17 @@ if ($TA->GetFile("Task.log", "$TaskDir/log")) $NewStatus = "completed"; $TaskFailures = $TAError = $ErrMessage = $PossibleCrash = undef; } - elsif ($Summary->{Task} eq "badpatch") + elsif ($LogInfo->{Task} eq "badpatch") { # This too is conclusive enough to ignore other errors. $NewStatus = "badpatch"; $TaskFailures = $TAError = $ErrMessage = $PossibleCrash = undef; } - elsif ($Summary->{NoLog}) + elsif ($LogInfo->{NoLog}) { - FatalError("$Summary->{NoLog}\n", "retry"); + FatalError("$LogInfo->{NoLog}\n", "retry"); } - elsif ($Summary->{Type} eq "build") + elsif ($LogInfo->{Type} eq "build") { # The error happened before the tests started so blame the build. $NewStatus = "badbuild"; diff --git a/testbot/lib/WineTestBot/LogUtils.pm b/testbot/lib/WineTestBot/LogUtils.pm index 787d450b5..dd8228e69 100644 --- a/testbot/lib/WineTestBot/LogUtils.pm +++ b/testbot/lib/WineTestBot/LogUtils.pm @@ -94,35 +94,35 @@ sub ParseTaskLog($)
if (open(my $LogFile, "<", $FileName)) { - my $Summary = {Type => "build"}; + my $LogInfo = {Type => "build"}; foreach my $Line (<$LogFile>) { chomp $Line; if ($Line eq "Task: tests") { - $Summary->{Type} = "tests"; + $LogInfo->{Type} = "tests"; } elsif ($Line eq "Task: ok") { - $Summary->{Task} ||= "ok"; + $LogInfo->{Task} ||= "ok"; } elsif ($Line eq "Task: Patch failed to apply") { - $Summary->{Task} = "badpatch"; + $LogInfo->{Task} = "badpatch"; last; # Should be the last and most specific message } elsif ($Line =~ /^Task: Updated ([a-zA-Z0-9.]+)$/) { - $Summary->{$1} = "updated"; + $LogInfo->{$1} = "updated"; } elsif ($Line =~ /^Task: / or _IsPerlError($Line)) { - $Summary->{Task} = "failed"; + $LogInfo->{Task} = "failed"; } } close($LogFile); - $Summary->{Task} ||= "missing"; - return $Summary; + $LogInfo->{Task} ||= "missing"; + return $LogInfo; } return {NoLog => "Unable to open the task log for reading: $!"}; }
It also better matches the ParseWineTestReport() structure. --- testbot/lib/WineTestBot/LogUtils.pm | 60 +++++++++++++++-------------- 1 file changed, 31 insertions(+), 29 deletions(-)
diff --git a/testbot/lib/WineTestBot/LogUtils.pm b/testbot/lib/WineTestBot/LogUtils.pm index dd8228e69..4d1ddda8c 100644 --- a/testbot/lib/WineTestBot/LogUtils.pm +++ b/testbot/lib/WineTestBot/LogUtils.pm @@ -92,39 +92,41 @@ sub ParseTaskLog($) { my ($FileName) = @_;
- if (open(my $LogFile, "<", $FileName)) + my $LogFile; + if (!open($LogFile, "<", $FileName)) { - my $LogInfo = {Type => "build"}; - foreach my $Line (<$LogFile>) + return {NoLog => "Unable to open the task log for reading: $!"}; + } + + my $LogInfo = {Type => "build"}; + foreach my $Line (<$LogFile>) + { + chomp $Line; + if ($Line eq "Task: tests") { - chomp $Line; - if ($Line eq "Task: tests") - { - $LogInfo->{Type} = "tests"; - } - elsif ($Line eq "Task: ok") - { - $LogInfo->{Task} ||= "ok"; - } - elsif ($Line eq "Task: Patch failed to apply") - { - $LogInfo->{Task} = "badpatch"; - last; # Should be the last and most specific message - } - elsif ($Line =~ /^Task: Updated ([a-zA-Z0-9.]+)$/) - { - $LogInfo->{$1} = "updated"; - } - elsif ($Line =~ /^Task: / or _IsPerlError($Line)) - { - $LogInfo->{Task} = "failed"; - } + $LogInfo->{Type} = "tests"; + } + elsif ($Line eq "Task: ok") + { + $LogInfo->{Task} ||= "ok"; + } + elsif ($Line eq "Task: Patch failed to apply") + { + $LogInfo->{Task} = "badpatch"; + last; # Should be the last and most specific message + } + elsif ($Line =~ /^Task: Updated ([a-zA-Z0-9.]+)$/) + { + $LogInfo->{$1} = "updated"; + } + elsif ($Line =~ /^Task: / or _IsPerlError($Line)) + { + $LogInfo->{Task} = "failed"; } - close($LogFile); - $LogInfo->{Task} ||= "missing"; - return $LogInfo; } - return {NoLog => "Unable to open the task log for reading: $!"}; + close($LogFile); + $LogInfo->{Task} ||= "missing"; + return $LogInfo; }
Rename the variable holding it to $LogInfo for consistency with the other functions as it plays the same role and may eventually carry the same information. Store the extra errors in the $LogInfo->{Extra} field and rename _AddError() to _AddExtra() to avoid confusion with AddLogError(). --- testbot/bin/UpdateTaskLogs | 11 +- testbot/bin/WineRunTask.pl | 18 ++-- testbot/bin/WineRunWineTest.pl | 18 ++-- testbot/lib/WineTestBot/LogUtils.pm | 155 +++++++++++++++++----------- 4 files changed, 114 insertions(+), 88 deletions(-)
diff --git a/testbot/bin/UpdateTaskLogs b/testbot/bin/UpdateTaskLogs index d4c67bd87..758c5a7e6 100755 --- a/testbot/bin/UpdateTaskLogs +++ b/testbot/bin/UpdateTaskLogs @@ -190,19 +190,16 @@ sub BuildErrFile($$$$)
my $TaskKey = Path2TaskKey($Dir);
- my ($TestUnitCount, $TimeoutCount, $LogFailures, $LogErrors) = ParseWineTestReport("$Dir/$ReportName", $IsWineTest, $TaskTimedOut); - if (!defined $LogFailures and @$LogErrors == 1) - { - return "Unable to open '$TaskKey/$ReportName' for reading: $!"; - } - return undef if (!@$LogErrors); + my $LogInfo = ParseWineTestReport("$Dir/$ReportName", $IsWineTest, $TaskTimedOut); + return "$TaskKey: $LogInfo->{BadLog}" if ($LogInfo->{BadLog}); + return undef if (!@{$LogInfo->{Errors}});
Debug("$TaskKey: Creating $ReportName.err\n"); if (open(my $Log, ">", "$Dir/$ReportName.err")) { # Save the extra errors detected by ParseWineTestReport() in # $ReportName.err (see WineRunWineTest.pl). - print $Log "$_\n" for (@$LogErrors); + print $Log "$_\n" for (@{$LogInfo->{Errors}}); close($Log); return undef; } diff --git a/testbot/bin/WineRunTask.pl b/testbot/bin/WineRunTask.pl index 62bd162ee..645798bbb 100755 --- a/testbot/bin/WineRunTask.pl +++ b/testbot/bin/WineRunTask.pl @@ -556,24 +556,24 @@ if ($TA->GetFile($RptFileName, "$TaskDir/$RptFileName")) { chmod 0664, "$TaskDir/$RptFileName";
- my ($TestUnitCount, $TimeoutCount, $LogFailures, $LogErrors) = ParseWineTestReport("$TaskDir/$RptFileName", $IsWineTest, $TaskTimedOut); - $TaskTimedOut = 1 if ($TestUnitCount == $TimeoutCount); - if (!defined $LogFailures and @$LogErrors == 1) + my $LogInfo = ParseWineTestReport("$TaskDir/$RptFileName", $IsWineTest, $TaskTimedOut); + $TaskTimedOut = 1 if ($LogInfo->{TestUnitCount} == $LogInfo->{TimeoutCount}); + if ($LogInfo->{BadLog}) { # Could not open the file $NewStatus = 'boterror'; - Error "$LogErrors->[0]\n"; - LogTaskError("$LogErrors->[0]\n"); + Error "$LogInfo->{BadLog}\n"; + LogTaskError("$LogInfo->{BadLog}\n"); } else { - # $LogFailures can legitimately be undefined in case of a timeout - $TaskFailures += $LogFailures || 0; - if (@$LogErrors and open(my $Log, ">", "$TaskDir/$RptFileName.err")) + # $LogInfo->{Failures} can legitimately be undefined in case of a timeout + $TaskFailures += $LogInfo->{Failures} || 0; + if (@{$LogInfo->{Extra}} and open(my $Log, ">", "$TaskDir/$RptFileName.err")) { # Save the extra errors detected by ParseWineTestReport() in # $RptFileName.err (see WineRunWineTest.pl). - print $Log "$_\n" for (@$LogErrors); + print $Log "$_\n" for (@{$LogInfo->{Extra}}); close($Log); } } diff --git a/testbot/bin/WineRunWineTest.pl b/testbot/bin/WineRunWineTest.pl index fecbab009..66df9acec 100755 --- a/testbot/bin/WineRunWineTest.pl +++ b/testbot/bin/WineRunWineTest.pl @@ -578,20 +578,20 @@ foreach my $Mission (@{$TaskMissions->{Missions}}) { chmod 0664, "$TaskDir/$RptFileName";
- my ($TestUnitCount, $TimeoutCount, $LogFailures, $LogErrors) = ParseWineTestReport("$TaskDir/$RptFileName", $Step->FileType eq "patch", $TaskTimedOut); - $TaskTimedOut = 1 if ($TestUnitCount == $TimeoutCount); - if (!defined $LogFailures and @$LogErrors == 1) + my $LogInfo = ParseWineTestReport("$TaskDir/$RptFileName", $Step->FileType eq "patch", $TaskTimedOut); + $TaskTimedOut = 1 if ($LogInfo->{TestUnitCount} == $LogInfo->{TimeoutCount}); + if ($LogInfo->{BadLog}) { # Could not open the file $NewStatus = 'boterror'; - Error "$LogErrors->[0]\n"; - LogTaskError("$LogErrors->[0]\n"); + Error "$LogInfo->{BadLog}\n"; + LogTaskError("$LogInfo->{BadLog}\n"); } else { - # $LogFailures can legitimately be undefined in case of a timeout - $TaskFailures += $LogFailures || 0; - if (@$LogErrors and open(my $Log, ">", "$TaskDir/$RptFileName.err")) + # $LogInfo->{Failures} can legitimately be undefined in case of a timeout + $TaskFailures += $LogInfo->{Failures} || 0; + if (@{$LogInfo->{Extra}} and open(my $Log, ">", "$TaskDir/$RptFileName.err")) { # Save the extra errors detected by ParseWineTestReport() in # $RptFileName.err: @@ -600,7 +600,7 @@ foreach my $Mission (@{$TaskMissions->{Missions}}) # if there are multiple .report files in the directory. # - The .err file can be moved to the latest directory next to the # reference report. - print $Log "$_\n" for (@$LogErrors); + print $Log "$_\n" for (@{$LogInfo->{Extra}}); close($Log); } } diff --git a/testbot/lib/WineTestBot/LogUtils.pm b/testbot/lib/WineTestBot/LogUtils.pm index 4d1ddda8c..3714941fc 100644 --- a/testbot/lib/WineTestBot/LogUtils.pm +++ b/testbot/lib/WineTestBot/LogUtils.pm @@ -232,56 +232,56 @@ sub _NewCurrentUnit($$) }; }
-sub _AddError($$;$) +sub _AddExtra($$;$) { - my ($Parser, $Error, $Cur) = @_; + my ($LogInfo, $Error, $Cur) = @_;
$Error = "$Cur->{Dll}:$Cur->{Unit} $Error" if (defined $Cur); - push @{$Parser->{Errors}}, $Error; - $Parser->{Failures}++; + push @{$LogInfo->{Extra}}, $Error; + $LogInfo->{Failures}++; }
sub _CheckUnit($$$$) { - my ($Parser, $Cur, $Unit, $Type) = @_; + my ($LogInfo, $Cur, $Unit, $Type) = @_;
if ($Cur->{Units}->{$Unit} or $Cur->{Unit} eq "") { - $Parser->{IsWineTest} = 1; + $LogInfo->{IsWineTest} = 1; } # To avoid issuing many duplicate errors, # only report the first misplaced message. - elsif ($Parser->{IsWineTest} and !$Cur->{IsBroken}) + elsif ($LogInfo->{IsWineTest} and !$Cur->{IsBroken}) { - _AddError($Parser, "contains a misplaced $Type message for $Unit", $Cur); + _AddExtra($LogInfo, "contains a misplaced $Type message for $Unit", $Cur); $Cur->{IsBroken} = 1; } }
sub _CheckSummaryCounter($$$$) { - my ($Parser, $Cur, $Field, $Type) = @_; + my ($LogInfo, $Cur, $Field, $Type) = @_;
if ($Cur->{"Line$Field"} != 0 and $Cur->{"Summary$Field"} == 0) { - _AddError($Parser, "has unaccounted for $Type messages", $Cur); + _AddExtra($LogInfo, "has unaccounted for $Type messages", $Cur); } elsif ($Cur->{"Line$Field"} == 0 and $Cur->{"Summary$Field"} != 0) { - _AddError($Parser, "is missing some $Type messages", $Cur); + _AddExtra($LogInfo, "is missing some $Type messages", $Cur); } }
sub _CloseTestUnit($$$) { - my ($Parser, $Cur, $Last) = @_; + my ($LogInfo, $Cur, $Last) = @_;
# Verify the summary lines if (!$Cur->{IsBroken}) { - _CheckSummaryCounter($Parser, $Cur, "Failures", "failure"); - _CheckSummaryCounter($Parser, $Cur, "Todos", "todo"); - _CheckSummaryCounter($Parser, $Cur, "Skips", "skip"); + _CheckSummaryCounter($LogInfo, $Cur, "Failures", "failure"); + _CheckSummaryCounter($LogInfo, $Cur, "Todos", "todo"); + _CheckSummaryCounter($LogInfo, $Cur, "Skips", "skip"); }
# Note that the summary lines may count some failures twice @@ -290,7 +290,7 @@ sub _CloseTestUnit($$$)
if ($Cur->{UnitSize} > $MaxUnitSize) { - _AddError($Parser, "prints too much data ($Cur->{UnitSize} bytes)", $Cur); + _AddExtra($LogInfo, "prints too much data ($Cur->{UnitSize} bytes)", $Cur); } if (!$Cur->{IsBroken} and defined $Cur->{Rc}) { @@ -298,31 +298,31 @@ sub _CloseTestUnit($$$) # after the 'done' line (e.g. by subprocesses). if ($Cur->{LineFailures} != 0 and $Cur->{Rc} == 0) { - _AddError($Parser, "returned success despite having failures", $Cur); + _AddExtra($LogInfo, "returned success despite having failures", $Cur); } - elsif (!$Parser->{IsWineTest} and $Cur->{Rc} != 0) + elsif (!$LogInfo->{IsWineTest} and $Cur->{Rc} != 0) { - _AddError($Parser, "The test returned a non-zero exit code"); + _AddExtra($LogInfo, "The test returned a non-zero exit code"); } - elsif ($Parser->{IsWineTest} and $Cur->{LineFailures} == 0 and $Cur->{Rc} != 0) + elsif ($LogInfo->{IsWineTest} and $Cur->{LineFailures} == 0 and $Cur->{Rc} != 0) { - _AddError($Parser, "returned a non-zero exit code despite reporting no failures", $Cur); + _AddExtra($LogInfo, "returned a non-zero exit code despite reporting no failures", $Cur); } } # For executables TestLauncher's done line may not be recognizable. - elsif ($Parser->{IsWineTest} and !defined $Cur->{Rc}) + elsif ($LogInfo->{IsWineTest} and !defined $Cur->{Rc}) { if (!$Last) { - _AddError($Parser, "has no done line (or it is garbled)", $Cur); + _AddExtra($LogInfo, "has no done line (or it is garbled)", $Cur); } - elsif ($Last and !$Parser->{TaskTimedOut}) + elsif ($Last and !$LogInfo->{TaskTimedOut}) { - _AddError($Parser, "The report seems to have been truncated"); + _AddExtra($LogInfo, "The report seems to have been truncated"); } }
- $Parser->{Failures} += $Cur->{LineFailures}; + $LogInfo->{Failures} += $Cur->{LineFailures}; }
=pod @@ -330,9 +330,32 @@ sub _CloseTestUnit($$$)
=item C<ParseWineTestReport()>
-Parses a Wine test report and returns the number of failures and extra errors, -a list of extra errors, and whether the test timed out. +Returns a hashtable containing a summary of the WineTest report: +=over + +=item IsWineTest +True if this is a regular Wine test report, false if this is some other Windows +binary. + +=item TaskTimedOut +True if the overall task timed out waiting for the test to complete. + +=item TestUnitCount +The number of test units. + +=item TimeoutCount +The number of test units that timed out.
+=item Failures +The number of failed tests. + +=item Extra +An array containing the extra errors detected during the inconsistency check. + +=item BadLog +Contains an error message if the report could not be read. + +=back =back =cut
@@ -343,18 +366,18 @@ sub ParseWineTestReport($$$) my $LogFile; if (!open($LogFile, "<", $FileName)) { - my $BaseName = basename($FileName); - return (undef, undef, undef, ["Unable to open '$BaseName' for reading: $!"]); + my $LogName = basename($FileName); + return {BadLog => "Unable to open '$LogName' for reading: $!"}; }
- my $Parser = { + my $LogInfo = { IsWineTest => $IsWineTest, TaskTimedOut => $TaskTimedOut,
TestUnitCount => 0, TimeoutCount => 0, Failures => undef, - Errors => [], + Extra => [], };
my $Cur = _NewCurrentUnit("", ""); @@ -366,9 +389,9 @@ sub ParseWineTestReport($$$) my ($Dll, $Unit, $Type) = ($1, $2, $3);
# Close the previous test unit - _CloseTestUnit($Parser, $Cur, 0) if ($Cur->{Dll} ne ""); + _CloseTestUnit($LogInfo, $Cur, 0) if ($Cur->{Dll} ne ""); $Cur = _NewCurrentUnit($Dll, $Unit); - $Parser->{TestUnitCount}++; + $LogInfo->{TestUnitCount}++;
# Recognize skipped messages in case we need to skip tests in the VMs $Cur->{Rc} = 0 if ($Type eq "skipped"); @@ -383,21 +406,21 @@ sub ParseWineTestReport($$$) } else { - _AddError($Parser, "Misplaced $SubUnit subtest\n"); + _AddExtra($LogInfo, "Misplaced $SubUnit subtest\n"); } } elsif (($Cur->{Unit} ne "" and $Line =~ /($Cur->{UnitsRE}).c:\d+: Test (?:failed|succeeded inside todo block): /) or $Line =~ /^([_a-z0-9]+).c:\d+: Test (?:failed|succeeded inside todo block): /) { - _CheckUnit($Parser, $Cur, $1, "failure"); + _CheckUnit($LogInfo, $Cur, $1, "failure"); $Cur->{LineFailures}++; } elsif (($Cur->{Unit} ne "" and $Line =~ /($Cur->{UnitsRE}).c:\d+: Test marked todo: /) or $Line =~ /^([_a-z0-9]+).c:\d+: Test marked todo: /) { - _CheckUnit($Parser, $Cur, $1, "todo"); + _CheckUnit($LogInfo, $Cur, $1, "todo"); $Cur->{LineTodos}++; } elsif (($Cur->{Unit} ne "" and @@ -417,7 +440,7 @@ sub ParseWineTestReport($$$) # This also replaces a test summary line. $Cur->{Pids}->{0} = 1; $Cur->{SummaryFailures}++; - $Parser->{IsWineTest} = 1; + $LogInfo->{IsWineTest} = 1;
$Cur->{LineFailures}++; } @@ -433,7 +456,7 @@ sub ParseWineTestReport($$$) $Cur->{Pids}->{$Pid || 0} = 1; $Cur->{SummaryFailures}++; } - _CheckUnit($Parser, $Cur, $Unit, "unhandled exception"); + _CheckUnit($LogInfo, $Cur, $Unit, "unhandled exception"); $Cur->{LineFailures}++; } elsif (($Cur->{Unit} ne "" and @@ -451,11 +474,11 @@ sub ParseWineTestReport($$$) $Cur->{SummaryFailures} += $Failures; $Cur->{SummaryTodos} += $Todos; $Cur->{SummarySkips} += $Skips; - $Parser->{IsWineTest} = 1; + $LogInfo->{IsWineTest} = 1; } else { - _CheckUnit($Parser, $Cur, $Unit, "test summary") if ($Todos or $Failures); + _CheckUnit($LogInfo, $Cur, $Unit, "test summary") if ($Todos or $Failures); } } elsif (($Cur->{Dll} ne "" and @@ -464,17 +487,17 @@ sub ParseWineTestReport($$$) { my ($Dll, $Unit, $Pid, $Rc) = ($1, $2, $3, $4);
- if ($Parser->{IsWineTest} and ($Dll ne $Cur->{Dll} or $Unit ne $Cur->{Unit})) + if ($LogInfo->{IsWineTest} and ($Dll ne $Cur->{Dll} or $Unit ne $Cur->{Unit})) { # First close the current test unit taking into account # it may have been polluted by the new one. $Cur->{IsBroken} = 1; - _CloseTestUnit($Parser, $Cur, 0); + _CloseTestUnit($LogInfo, $Cur, 0);
# Then switch to the new one, warning it's missing a start line, # and that its results may be inconsistent. ($Cur->{Dll}, $Cur->{Unit}) = ($Dll, $Unit); - _AddError($Parser, "had no start line (or it is garbled)", $Cur); + _AddExtra($LogInfo, "had no start line (or it is garbled)", $Cur); $Cur->{IsBroken} = 1; }
@@ -482,9 +505,9 @@ sub ParseWineTestReport($$$) { # The done line will already be shown as a timeout (see JobDetails) # so record the failure but don't add an error message. - $Parser->{Failures}++; + $LogInfo->{Failures}++; $Cur->{IsBroken} = 1; - $Parser->{TimeoutCount}++; + $LogInfo->{TimeoutCount}++; } elsif ((!$Pid and !%{$Cur->{Pids}}) or ($Pid and !$Cur->{Pids}->{$Pid} and !$Cur->{Pids}->{0})) @@ -492,12 +515,12 @@ sub ParseWineTestReport($$$) # The main summary line is missing if ($Rc & 0xc0000000) { - _AddError($Parser, sprintf("%s:%s crashed (%08x)", $Dll, $Unit, $Rc & 0xffffffff)); + _AddExtra($LogInfo, sprintf("%s:%s crashed (%08x)", $Dll, $Unit, $Rc & 0xffffffff)); $Cur->{IsBroken} = 1; } - elsif ($Parser->{IsWineTest} and !$Cur->{IsBroken}) + elsif ($LogInfo->{IsWineTest} and !$Cur->{IsBroken}) { - _AddError($Parser, "$Dll:$Unit has no test summary line (early exit of the main process?)"); + _AddExtra($LogInfo, "$Dll:$Unit has no test summary line (early exit of the main process?)"); } } elsif ($Rc & 0xc0000000) @@ -511,12 +534,11 @@ sub ParseWineTestReport($$$) $Cur->{Rc} = $Rc; } } - $Cur->{IsBroken} = 1 if ($Parser->{TaskTimedOut}); - _CloseTestUnit($Parser, $Cur, 1); + $Cur->{IsBroken} = 1 if ($LogInfo->{TaskTimedOut}); + _CloseTestUnit($LogInfo, $Cur, 1); close($LogFile);
- return ($Parser->{TestUnitCount}, $Parser->{TimeoutCount}, - $Parser->{Failures}, $Parser->{Errors}); + return $LogInfo; }
@@ -660,18 +682,20 @@ sub GetLogLabel($) }
-sub _DumpErrors($$$) +sub _DumpErrors($$) { - my ($Label, $Groups, $Errors) = @_; + my ($Label, $LogInfo) = @_;
- print STDERR "$Label:\n"; - print STDERR " Groups=", scalar(@$Groups), " [", join(",", @$Groups), "]\n"; - my @ErrorKeys = sort keys %$Errors; + print STDERR "$Label: ", join(" ", keys %$LogInfo), "\n"; + my $GroupNames = $LogInfo->{ErrGroupNames}; + print STDERR " Groups=", scalar(@$GroupNames), " [", join(",", @$GroupNames), "]\n"; + my @ErrorKeys = sort keys %{$LogInfo->{Groups}}; print STDERR " Errors=", scalar(@ErrorKeys), " [", join(",", @ErrorKeys), "]\n"; - foreach my $GroupName (@$Groups) + foreach my $GroupName (@$GroupNames) { print STDERR " [$GroupName]\n"; - print STDERR " [$_]\n" for (@{$Errors->{$GroupName}->{Errors}}); + my $Group = $LogInfo->{Groups}->{$GroupName}; + print STDERR " [$_]\n" for (@{$Group->{Errors}}); } }
@@ -875,10 +899,13 @@ sub _GetLineKey($)
Compares the specified errors to the reference report to identify new errors.
-Sets $LogInfo->{NewCount} to the total number of new errors. If there is no -reference log to identify the new errors this field is left undefined. +The $LogInfo structure is augmented with the following fields: +=over
-Adds two fields to each error group: +=item NewCount +The total number of new errors or undef if the reference log could not be read. + +=item ErrGroups =over
=item NewCount @@ -887,6 +914,8 @@ A count of the new errors. =item IsNew An array where entries are set to true to identify new errors.
+=back + =back =back =cut
Hi,
While running your changed tests, I think I found new failures. Being a bot and all I'm not very good at pattern recognition, so I might be wrong, but could you please double-check?
Full results can be found at: https://testbot.winehq.org/JobDetails.pl?Key=63180
Your paranoid android.
=== debian10 (build log) ===
Task: Patch failed to apply
=== debian10 (build log) ===
Task: Patch failed to apply
These two fields make it easier to detect and handle cases where there was no usable reference log for the new error detection. --- testbot/bin/WineSendLog.pl | 2 +- testbot/lib/WineTestBot/LogUtils.pm | 26 ++++++++++++++++++-------- 2 files changed, 19 insertions(+), 9 deletions(-)
diff --git a/testbot/bin/WineSendLog.pl b/testbot/bin/WineSendLog.pl index 89e90c40f..b31d1f5d3 100755 --- a/testbot/bin/WineSendLog.pl +++ b/testbot/bin/WineSendLog.pl @@ -294,7 +294,7 @@ EOF my $AllNew; my $RefReportPath = $StepTask->GetFullFileName($StepTask->GetRefReportName($LogName)); TagNewErrors($RefReportPath, $LogInfo); - if (!defined $LogInfo->{NewCount}) + if ($LogInfo->{NoRef}) { # Test reports should have reference WineTest results and if not # reporting the errors as new would cause false positives. diff --git a/testbot/lib/WineTestBot/LogUtils.pm b/testbot/lib/WineTestBot/LogUtils.pm index 3714941fc..dd98024bd 100644 --- a/testbot/lib/WineTestBot/LogUtils.pm +++ b/testbot/lib/WineTestBot/LogUtils.pm @@ -902,14 +902,22 @@ Compares the specified errors to the reference report to identify new errors. The $LogInfo structure is augmented with the following fields: =over
+=item BadRef +Contains an error message if the reference log could not be read. + +=item NoRef +True if there was no usable reference log. This could either mean that there +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 or undef if the reference log could not be read. +The total number of new errors if any.
=item ErrGroups =over
=item NewCount -A count of the new errors. +A count of the group's new errors if any.
=item IsNew An array where entries are set to true to identify new errors. @@ -924,16 +932,18 @@ sub TagNewErrors($$) { my ($RefLogPath, $LogInfo) = @_;
- if (!$LogInfo->{ErrCount}) + return if (!$LogInfo->{ErrCount}); + + my $RefInfo = GetLogErrors($RefLogPath); + if ($RefInfo->{BadLog}) { - $LogInfo->{NewCount} = 0; + # 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 = GetLogErrors($RefLogPath); - # Don't tag the errors as new if there is no reference log - return if (!defined $RefInfo->{ErrCount}); - $LogInfo->{NewCount} = 0; foreach my $GroupName (@{$LogInfo->{ErrGroupNames}}) {
The log file may exist but not be readable. This makes it consistent with the BadRef / NoRef terminology of TagNewErrors(). --- testbot/bin/WineRunBuild.pl | 4 ++-- testbot/bin/WineRunReconfig.pl | 4 ++-- testbot/bin/WineRunWineTest.pl | 4 ++-- testbot/lib/WineTestBot/LogUtils.pm | 5 +++-- 4 files changed, 9 insertions(+), 8 deletions(-)
diff --git a/testbot/bin/WineRunBuild.pl b/testbot/bin/WineRunBuild.pl index cf6428ae4..5bc3815c5 100755 --- a/testbot/bin/WineRunBuild.pl +++ b/testbot/bin/WineRunBuild.pl @@ -433,9 +433,9 @@ if ($TA->GetFile("Build.log", "$TaskDir/log")) $NewStatus = "badpatch"; $TAError = $ErrMessage = undef; } - elsif ($LogInfo->{NoLog}) + elsif ($LogInfo->{BadLog}) { - FatalError("$LogInfo->{NoLog}\n", "retry"); + FatalError("$LogInfo->{BadLog}\n", "retry"); } else { diff --git a/testbot/bin/WineRunReconfig.pl b/testbot/bin/WineRunReconfig.pl index c16c40a5a..c82d5fcb5 100755 --- a/testbot/bin/WineRunReconfig.pl +++ b/testbot/bin/WineRunReconfig.pl @@ -428,9 +428,9 @@ if ($TA->GetFile("Reconfig.log", "$TaskDir/log")) $NewStatus = "completed"; $TAError = $ErrMessage = undef; } - elsif ($LogInfo->{NoLog}) + elsif ($LogInfo->{BadLog}) { - FatalError("$LogInfo->{NoLog}\n", "retry"); + FatalError("$LogInfo->{BadLog}\n", "retry"); } else { diff --git a/testbot/bin/WineRunWineTest.pl b/testbot/bin/WineRunWineTest.pl index 66df9acec..ea13ca02d 100755 --- a/testbot/bin/WineRunWineTest.pl +++ b/testbot/bin/WineRunWineTest.pl @@ -542,9 +542,9 @@ if ($TA->GetFile("Task.log", "$TaskDir/log")) $NewStatus = "badpatch"; $TaskFailures = $TAError = $ErrMessage = $PossibleCrash = undef; } - elsif ($LogInfo->{NoLog}) + elsif ($LogInfo->{BadLog}) { - FatalError("$LogInfo->{NoLog}\n", "retry"); + FatalError("$LogInfo->{BadLog}\n", "retry"); } elsif ($LogInfo->{Type} eq "build") { diff --git a/testbot/lib/WineTestBot/LogUtils.pm b/testbot/lib/WineTestBot/LogUtils.pm index dd98024bd..52bf60d93 100644 --- a/testbot/lib/WineTestBot/LogUtils.pm +++ b/testbot/lib/WineTestBot/LogUtils.pm @@ -81,7 +81,7 @@ Either 'ok' if the task was successful or a code indicating why it failed. Entries named after the binaries and files of interest to the TestBot that have been updated.
-=item NoLog +=item BadLog Contains an error message if the task log could not be read.
=back @@ -95,7 +95,8 @@ sub ParseTaskLog($) my $LogFile; if (!open($LogFile, "<", $FileName)) { - return {NoLog => "Unable to open the task log for reading: $!"}; + my $LogName = basename($FileName); + return {BadLog => "Unable to open '$LogName' for reading: $!"}; }
my $LogInfo = {Type => "build"};
--- testbot/lib/WineTestBot/LogUtils.pm | 20 +++++++++---- testbot/web/JobDetails.pl | 46 +++++++++++++++++++++++++---- testbot/web/WineTestBot.css | 1 + 3 files changed, 57 insertions(+), 10 deletions(-)
diff --git a/testbot/lib/WineTestBot/LogUtils.pm b/testbot/lib/WineTestBot/LogUtils.pm index 52bf60d93..9dbe6cf0b 100644 --- a/testbot/lib/WineTestBot/LogUtils.pm +++ b/testbot/lib/WineTestBot/LogUtils.pm @@ -709,16 +709,17 @@ sub _AddLogGroup($$) if (!$LogInfo->{ErrGroups}->{$GroupName}) { push @{$LogInfo->{ErrGroupNames}}, $GroupName; - $LogInfo->{ErrGroups}->{$GroupName} = { Errors => [] }; + $LogInfo->{ErrGroups}->{$GroupName} = { LineNos => [], Errors => [] }; } return $LogInfo->{ErrGroups}->{$GroupName}; }
-sub _AddLogError($$$) +sub _AddLogError($$$;$) { - my ($LogInfo, $ErrGroup, $Line) = @_; + my ($LogInfo, $ErrGroup, $Line, $LineNo) = @_;
push @{$ErrGroup->{Errors}}, $Line; + push @{$ErrGroup->{LineNos}}, $LineNo || 0; $LogInfo->{ErrCount}++; }
@@ -744,8 +745,13 @@ An array containing the names of all the error groups. A hashtable indexed by the error group name. Each entry contains:
=over + =item Errors An array containing the error messages. + +=item LineNos +An array containing the line number of the error in the log file. + =back
=back @@ -777,8 +783,10 @@ sub GetLogErrors($) $LogInfo->{ErrCount} ||= 0; my $CurrentModule = ""; my $CurrentGroup; + my $LineNo = 0; foreach my $Line (<$LogFile>) { + $LineNo++; $Line =~ s/\s*$//; if ($IsReport and $Line =~ /^([_.a-z0-9-]+):[_a-z0-9]* start /) { @@ -798,7 +806,7 @@ sub GetLogErrors($) { $CurrentGroup = _AddLogGroup($LogInfo, $CurrentModule); } - _AddLogError($LogInfo, $CurrentGroup, $Line); + _AddLogError($LogInfo, $CurrentGroup, $Line, $LineNo); } close($LogFile); } @@ -813,8 +821,10 @@ sub GetLogErrors($) $LogInfo->{ErrCount} ||= 0; # Add the related extra errors my $CurrentGroup; + my $LineNo = 0; foreach my $Line (<$LogFile>) { + $LineNo++; $Line =~ s/\s*$//; if (!$CurrentGroup) { @@ -823,7 +833,7 @@ sub GetLogErrors($) my $GroupName = $IsReport ? "Report errors" : "Task errors"; $CurrentGroup = _AddLogGroup($LogInfo, $GroupName); } - _AddLogError($LogInfo, $CurrentGroup, $Line); + _AddLogError($LogInfo, $CurrentGroup, $Line, $LineNo); } close($LogFile); } diff --git a/testbot/web/JobDetails.pl b/testbot/web/JobDetails.pl index 48d511ccb..fc18c866f 100644 --- a/testbot/web/JobDetails.pl +++ b/testbot/web/JobDetails.pl @@ -351,19 +351,42 @@ sub GetErrorCategory($) return "error"; }
-sub GenerateFullLog($$$;$) +sub GenerateFullLog($$$$;$) { - my ($self, $FileName, $HideLog, $Header) = @_; + my ($self, $FileName, $HideLog, $LogInfo, $Header) = @_; + + my %NewLineNos; + if ($LogInfo and $LogInfo->{NewCount}) + { + foreach my $GroupName (@{$LogInfo->{ErrGroupNames}}) + { + my $Group = $LogInfo->{ErrGroups}->{$GroupName}; + next if (!$Group->{NewCount}); + if (($FileName =~ /.err$/) == + ($GroupName =~ /^(?:Report errors|Task errors|TestBot errors)$/)) + { + for my $ErrIndex (0..@{$Group->{Errors}} - 1) + { + if ($Group->{IsNew}->[$ErrIndex]) + { + $NewLineNos{$Group->{LineNos}->[$ErrIndex]} = 1; + } + } + } + } + }
my $GetCategory = $FileName =~ /.err$/ ? &GetErrorCategory : $FileName =~ /.report$/ ? &GetReportLineCategory : &GetLogLineCategory;
+ my $LineNo = 0; my $IsEmpty = 1; if (open(my $LogFile, "<", $FileName)) { foreach my $Line (<$LogFile>) { + $LineNo++; $Line =~ s/\s*$//; if ($IsEmpty) { @@ -372,8 +395,8 @@ sub GenerateFullLog($$$;$) $IsEmpty = 0; }
- my $Category = $GetCategory->($Line); my $Html = $self->escapeHTML($Line); + my $Category = $NewLineNos{$LineNo} ? "fullnew" : $GetCategory->($Line); if ($Category ne "none") { $Html =~ s~^(.*\S)\s*\r?$~<span class='log-$Category'>$1</span>~; @@ -463,11 +486,24 @@ EOF # Show this log in full, highlighting the important lines #
+ my $LogInfo; + my $LogFileName = "$TaskDir/$MoreInfo->{Full}"; + if ($MoreInfo->{Full} =~ /.report$/) + { + $LogInfo = GetLogErrors($LogFileName); + if ($LogInfo->{ErrCount}) + { + # Identify new errors in test reports + my $RefReportPath = $StepTask->GetFullFileName($StepTask->GetRefReportName($MoreInfo->{Full})); + TagNewErrors($RefReportPath, $LogInfo); + } + } + my ($Action, $Url) = $self->GetMoreInfoLink($Key, GetLogLabel($MoreInfo->{Full}), "Full", $MoreInfo->{Full}); $Url = $self->CGI->escapeHTML($Url); my $HideLog = $Action eq "Hide" ? " ondblclick='HideLog(event, "$Url")'" : "";
- my $LogIsEmpty = $self->GenerateFullLog("$TaskDir/$MoreInfo->{Full}", $HideLog); + my $LogIsEmpty = $self->GenerateFullLog($LogFileName, $HideLog, $LogInfo); my $EmptyDiag; if ($LogIsEmpty) { @@ -490,7 +526,7 @@ EOF my $ErrHeader = $MoreInfo->{Full} =~ /.report/ ? "report" : "task"; $ErrHeader = "old $ErrHeader" if ($MoreInfo->{Full} =~ /^old_/); $ErrHeader = "<div class='HrTitle'>". ucfirst($ErrHeader) ." errors<div class='HrLine'></div></div>"; - my $ErrIsEmpty = $self->GenerateFullLog("$TaskDir/$MoreInfo->{Full}.err", $HideLog, $ErrHeader); + my $ErrIsEmpty = $self->GenerateFullLog("$LogFileName.err", $HideLog, $LogInfo, $ErrHeader); print $EmptyDiag if ($ErrIsEmpty and defined $EmptyDiag); } else diff --git a/testbot/web/WineTestBot.css b/testbot/web/WineTestBot.css index f58835583..9a23f5fa8 100644 --- a/testbot/web/WineTestBot.css +++ b/testbot/web/WineTestBot.css @@ -402,6 +402,7 @@ pre .log-boterror { color: #cc0052; } .log-diag { color: #e56300; } .log-new { color: #e56e00; font-weight: bold; } +.log-fullnew { color: red; font-weight: bold; }
a.title { color:inherit; text-decoration: none; }
This will make it possible to jump to the first line of a test unit that contains failures. --- testbot/lib/WineTestBot/LogUtils.pm | 21 +++++++++++++++------ 1 file changed, 15 insertions(+), 6 deletions(-)
diff --git a/testbot/lib/WineTestBot/LogUtils.pm b/testbot/lib/WineTestBot/LogUtils.pm index 9dbe6cf0b..3fcb9ac41 100644 --- a/testbot/lib/WineTestBot/LogUtils.pm +++ b/testbot/lib/WineTestBot/LogUtils.pm @@ -700,16 +700,20 @@ sub _DumpErrors($$) } }
-sub _AddLogGroup($$) +sub _AddLogGroup($$;$) { - my ($LogInfo, $GroupName) = @_; + my ($LogInfo, $GroupName, $LineNo) = @_;
# In theory the error group names are all unique. But, just in case, make # sure we don't overwrite $LogInfo->{ErrGroups}->{$GroupName}. if (!$LogInfo->{ErrGroups}->{$GroupName}) { push @{$LogInfo->{ErrGroupNames}}, $GroupName; - $LogInfo->{ErrGroups}->{$GroupName} = { LineNos => [], Errors => [] }; + $LogInfo->{ErrGroups}->{$GroupName} = { + LineNo => $LineNo || 0, + LineNos => [], + Errors => [] + }; } return $LogInfo->{ErrGroups}->{$GroupName}; } @@ -746,6 +750,10 @@ A hashtable indexed by the error group name. Each entry contains:
=over
+=item LineNo +The line number of the start of this error group. Note that this is normally +different from the line of the first error in that group. + =item Errors An array containing the error messages.
@@ -781,7 +789,7 @@ sub GetLogErrors($) if (open(my $LogFile, "<", $LogFileName)) { $LogInfo->{ErrCount} ||= 0; - my $CurrentModule = ""; + my ($CurrentModule, $ModuleLineNo) = ("", 0); my $CurrentGroup; my $LineNo = 0; foreach my $Line (<$LogFile>) @@ -790,6 +798,7 @@ sub GetLogErrors($) $Line =~ s/\s*$//; if ($IsReport and $Line =~ /^([_.a-z0-9-]+):[_a-z0-9]* start /) { + $ModuleLineNo = $LineNo; $CurrentModule = $1; $CurrentGroup = undef; next; @@ -804,7 +813,7 @@ sub GetLogErrors($) } if (!$CurrentGroup) { - $CurrentGroup = _AddLogGroup($LogInfo, $CurrentModule); + $CurrentGroup = _AddLogGroup($LogInfo, $CurrentModule, $ModuleLineNo); } _AddLogError($LogInfo, $CurrentGroup, $Line, $LineNo); } @@ -831,7 +840,7 @@ sub GetLogErrors($) # Note: $GroupName must not depend on the previous content as this # would break diffs. my $GroupName = $IsReport ? "Report errors" : "Task errors"; - $CurrentGroup = _AddLogGroup($LogInfo, $GroupName); + $CurrentGroup = _AddLogGroup($LogInfo, $GroupName, $LineNo); } _AddLogError($LogInfo, $CurrentGroup, $Line, $LineNo); }
--- testbot/lib/WineTestBot/LogUtils.pm | 55 ++++++++++++++++++----------- 1 file changed, 34 insertions(+), 21 deletions(-)
diff --git a/testbot/lib/WineTestBot/LogUtils.pm b/testbot/lib/WineTestBot/LogUtils.pm index 3fcb9ac41..3e93c95c7 100644 --- a/testbot/lib/WineTestBot/LogUtils.pm +++ b/testbot/lib/WineTestBot/LogUtils.pm @@ -90,16 +90,22 @@ Contains an error message if the task log could not be read.
sub ParseTaskLog($) { - my ($FileName) = @_; + my ($LogPath) = @_; + + my $LogName = basename($LogPath); + my $LogInfo = { + LogName => $LogName, + LogPath => $LogPath, + };
my $LogFile; - if (!open($LogFile, "<", $FileName)) + if (!open($LogFile, "<", $LogPath)) { - my $LogName = basename($FileName); - return {BadLog => "Unable to open '$LogName' for reading: $!"}; + $LogInfo->{BadLog} = "Unable to open '$LogName' for reading: $!"; + return $LogInfo; }
- my $LogInfo = {Type => "build"}; + $LogInfo->{Type} = "build"; foreach my $Line (<$LogFile>) { chomp $Line; @@ -362,16 +368,12 @@ Contains an error message if the report could not be read.
sub ParseWineTestReport($$$) { - my ($FileName, $IsWineTest, $TaskTimedOut) = @_; - - my $LogFile; - if (!open($LogFile, "<", $FileName)) - { - my $LogName = basename($FileName); - return {BadLog => "Unable to open '$LogName' for reading: $!"}; - } + my ($LogPath, $IsWineTest, $TaskTimedOut) = @_;
+ my $LogName = basename($LogPath); my $LogInfo = { + LogName => $LogName, + LogPath => $LogPath, IsWineTest => $IsWineTest, TaskTimedOut => $TaskTimedOut,
@@ -381,6 +383,13 @@ sub ParseWineTestReport($$$) Extra => [], };
+ my $LogFile; + if (!open($LogFile, "<", $LogPath)) + { + $LogInfo->{BadLog} = "Unable to open '$LogName' for reading: $!"; + return $LogInfo; + } + my $Cur = _NewCurrentUnit("", ""); foreach my $Line (<$LogFile>) { @@ -768,10 +777,10 @@ An array containing the line number of the error in the log file.
sub GetLogErrors($) { - my ($LogFileName) = @_; + my ($LogPath) = @_;
my ($IsReport, $GetCategory); - if ($LogFileName =~ /.report$/) + if ($LogPath =~ /.report$/) { $IsReport = 1; $GetCategory = &GetReportLineCategory; @@ -781,12 +790,16 @@ sub GetLogErrors($) $GetCategory = &GetLogLineCategory; }
+ my $LogName = basename($LogPath); my $LogInfo = { + LogName => $LogName, + LogPath => $LogPath, + ErrCount => undef, # until we open a log ErrGroupNames => [], ErrGroups => {}, }; - if (open(my $LogFile, "<", $LogFileName)) + if (open(my $LogFile, "<", $LogPath)) { $LogInfo->{ErrCount} ||= 0; my ($CurrentModule, $ModuleLineNo) = ("", 0); @@ -819,13 +832,13 @@ sub GetLogErrors($) } close($LogFile); } - elsif (-f $LogFileName) + elsif (-f $LogPath) { my $Group = _AddLogGroup($LogInfo, "TestBot errors"); - _AddLogError($LogInfo, $Group, "Could not open '". basename($LogFileName) ."' for reading: $!"); + _AddLogError($LogInfo, $Group, "Could not open '$LogName' for reading: $!"); }
- if (open(my $LogFile, "<", "$LogFileName.err")) + if (open(my $LogFile, "<", "$LogPath.err")) { $LogInfo->{ErrCount} ||= 0; # Add the related extra errors @@ -846,10 +859,10 @@ sub GetLogErrors($) } close($LogFile); } - elsif (-f "$LogFileName.err") + elsif (-f "$LogPath.err") { my $Group = _AddLogGroup($LogInfo, "TestBot errors"); - _AddLogError($LogInfo, $Group, "Could not open '". basename($LogFileName) .".err' for reading: $!"); + _AddLogError($LogInfo, $Group, "Could not open '$LogName.err' for reading: $!"); }
return $LogInfo;
Also take the latest WineTest reports snapshot when the corresponding task completes rather than when the build task they depend on completes. This way the snapshot is taken closest to when the reference reports are needed. --- testbot/bin/UpdateTaskLogs | 12 ++-- testbot/bin/WineRunBuild.pl | 31 --------- testbot/bin/WineRunTask.pl | 34 ++++----- testbot/bin/WineRunWineTest.pl | 65 +++-------------- testbot/lib/WineTestBot/LogUtils.pm | 104 +++++++++++++++++++++++++++- testbot/lib/WineTestBot/Tasks.pm | 30 ++++++++ 6 files changed, 160 insertions(+), 116 deletions(-)
diff --git a/testbot/bin/UpdateTaskLogs b/testbot/bin/UpdateTaskLogs index 758c5a7e6..e0af09768 100755 --- a/testbot/bin/UpdateTaskLogs +++ b/testbot/bin/UpdateTaskLogs @@ -226,15 +226,11 @@ sub DoUpdateLatestReport($$$) # Add the reference report to latest/ Debug("latest: Adding $RefReportName from ". Path2TaskKey($SrcReportPath) ."\n");
- foreach my $Suffix ("", ".err") + my $ErrMessages = UpdateLatestReport($Task, $ReportName, $SrcReportPath); + foreach my $ErrMessage (@$ErrMessages) { - unlink("$LatestReportPath$Suffix"); - if (-f "$SrcReportPath$Suffix" and - !link("$SrcReportPath$Suffix", "$LatestReportPath$Suffix")) - { - Error "Could not replace 'latest/$RefReportName$Suffix': $!\n"; - $Rc = 1; - } + Error "$ErrMessage\n"; + $Rc = 1; } $LatestReports{$RefReportName} = $LatestReportPath; } diff --git a/testbot/bin/WineRunBuild.pl b/testbot/bin/WineRunBuild.pl index 5bc3815c5..afbc5ec78 100755 --- a/testbot/bin/WineRunBuild.pl +++ b/testbot/bin/WineRunBuild.pl @@ -496,37 +496,6 @@ Debug(Elapsed($Start), " Disconnecting\n"); $TA->Disconnect();
-# -# Grab a copy of the reference logs -# - -# Note that this may be a bit inaccurate right after a Wine commit. -# See WineSendLog.pl for more details. -my $LatestDir = "$DataDir/latest"; -foreach my $TestStep (@{$Job->Steps->GetItems()}) -{ - if (($TestStep->PreviousNo || 0) == $Step->No and - $TestStep->FileType =~ /^exe/) - { - foreach my $TestTask (@{$TestStep->Tasks->GetItems()}) - { - my $RefReport = $TestTask->GetRefReportName($TestStep->FileType .".report"); - for my $Suffix ("", ".err") - { - if (-f "$LatestDir/$RefReport$Suffix") - { - unlink "$StepDir/$RefReport$Suffix"; - if (!link "$LatestDir/$RefReport$Suffix", "$StepDir/$RefReport$Suffix") - { - Error "Could not link '$RefReport$Suffix': $!\n"; - } - } - } - } - } -} - - # # Wrap up # diff --git a/testbot/bin/WineRunTask.pl b/testbot/bin/WineRunTask.pl index 645798bbb..ee910cdf0 100755 --- a/testbot/bin/WineRunTask.pl +++ b/testbot/bin/WineRunTask.pl @@ -45,7 +45,6 @@ use WineTestBot::Engine::Notify; use WineTestBot::Jobs; use WineTestBot::Log; use WineTestBot::LogUtils; -use WineTestBot::Missions; use WineTestBot::Utils; use WineTestBot::VMs;
@@ -195,7 +194,6 @@ my $OldUMask = umask(002); my $TaskDir = $Task->CreateDir(); umask($OldUMask); my $VM = $Task->VM; -my $RptFileName = $Step->FileType .".report";
my $Start = Time(); @@ -224,6 +222,8 @@ sub LogTaskError($) umask($OldUMask); }
+my $ReportNames; + sub WrapUpAndExit($;$$$$) { my ($Status, $TestFailures, $Retry, $TimedOut, $Reason) = @_; @@ -299,22 +299,11 @@ sub WrapUpAndExit($;$$$$) $VM->Save(); }
+ # Update the 'latest/' reference WineTest results if ($Step->Type eq 'suite' and $Status eq 'completed' and !$TimedOut) { - # Keep the old report if the new one is missing - if (-f "$TaskDir/$RptFileName" and !-z "$TaskDir/$RptFileName") - { - # Update the VM's reference WineTest results for WineSendLog.pl - my $RefReport = "$DataDir/latest/". $Task->GetRefReportName($RptFileName); - unlink($RefReport); - link("$TaskDir/$RptFileName", $RefReport); - - unlink("$RefReport.err"); - if (-f "$TaskDir/$RptFileName.err" and !-z "$TaskDir/$RptFileName.err") - { - link("$TaskDir/$RptFileName.err", "$RefReport.err"); - } - } + my $ErrMessages = UpdateLatestReports($Task, $ReportNames); + Error("$_\n") for (@$ErrMessages); }
my $Result = $VM->Name .": ". $VM->Status ." Status: $Status Failures: ". (defined $TestFailures ? $TestFailures : "unset"); @@ -420,12 +409,11 @@ if ($Step->FileType ne "exe32" and $Step->FileType ne "exe64") FatalError("Unexpected file type '". $Step->FileType ."' found for ". $Step->Type ." step\n"); }
-my ($ErrMessage, $Missions) = ParseMissionStatement($Task->Missions); +(my $ErrMessage, $ReportNames, my $TaskMissions) = $Task->GetReportNames(); FatalError "$ErrMessage\n" if (defined $ErrMessage); -FatalError "Empty mission statement\n" if (!@$Missions); -FatalError "Cannot specify missions for multiple tasks\n" if (@$Missions > 1); -FatalError "Cannot specify multiple missions\n" if (@{$Missions->[0]->{Missions}} > 1); -my $Mission = $Missions->[0]->{Missions}->[0]; +FatalError "Cannot specify multiple missions\n" if (@{$TaskMissions->{Missions}} > 1); +my $Mission = $TaskMissions->{Missions}->[0]; +my $RptFileName = $ReportNames->[0];
# @@ -567,6 +555,10 @@ if ($TA->GetFile($RptFileName, "$TaskDir/$RptFileName")) } else { + # Grab a copy of the reference report + my $ErrMessages = SnapshotLatestReport($Task, $RptFileName); + LogTaskError("$_\n") for (@$ErrMessages); + # $LogInfo->{Failures} can legitimately be undefined in case of a timeout $TaskFailures += $LogInfo->{Failures} || 0; if (@{$LogInfo->{Extra}} and open(my $Log, ">", "$TaskDir/$RptFileName.err")) diff --git a/testbot/bin/WineRunWineTest.pl b/testbot/bin/WineRunWineTest.pl index ea13ca02d..46e85ec47 100755 --- a/testbot/bin/WineRunWineTest.pl +++ b/testbot/bin/WineRunWineTest.pl @@ -43,7 +43,6 @@ $Name0 =~ s+^.*/++; use WineTestBot::Config; use WineTestBot::Engine::Notify; use WineTestBot::Jobs; -use WineTestBot::Missions; use WineTestBot::PatchUtils; use WineTestBot::Log; use WineTestBot::LogUtils; @@ -218,7 +217,7 @@ sub LogTaskError($) } }
-my $TaskMissions; +my $ReportNames;
sub WrapUpAndExit($;$$$$) { @@ -295,26 +294,11 @@ sub WrapUpAndExit($;$$$$) $VM->Save(); }
+ # Update the 'latest/' reference WineTest results if ($Step->Type eq 'suite' and $Status eq 'completed' and !$TimedOut) { - foreach my $Mission (@{$TaskMissions->{Missions}}) - { - # Keep the old report if the new one is missing - my $RptFileName = GetMissionBaseName($Mission) .".report"; - if (-f "$TaskDir/$RptFileName" and !-z "$TaskDir/$RptFileName") - { - # Update the VM's reference WineTest results for WineSendLog.pl - my $RefReport = "$DataDir/latest/". $Task->VM->Name ."_$RptFileName"; - unlink($RefReport); - link("$TaskDir/$RptFileName", $RefReport); - - unlink("$RefReport.err"); - if (-f "$TaskDir/$RptFileName.err" and !-z "$TaskDir/$RptFileName.err") - { - link("$TaskDir/$RptFileName.err", "$RefReport.err"); - } - } - } + my $ErrMessages = UpdateLatestReports($Task, $ReportNames); + Error("$_\n") for (@$ErrMessages); }
my $Result = $VM->Name .": ". $VM->Status ." Status: $Status Failures: ". (defined $TestFailures ? $TestFailures : "unset"); @@ -421,11 +405,8 @@ if (($Step->Type eq "suite" and $Step->FileType ne "none") or FatalError("Unexpected file type '". $Step->FileType ."' found for ". $Step->Type ." step\n"); }
-my ($ErrMessage, $Missions) = ParseMissionStatement($Task->Missions); +(my $ErrMessage, $ReportNames, my $_TaskMissions) = $Task->GetReportNames(); FatalError "$ErrMessage\n" if (defined $ErrMessage); -FatalError "Empty mission statement\n" if (!@$Missions); -FatalError "Cannot specify missions for multiple tasks\n" if (@$Missions > 1); -$TaskMissions = $Missions->[0];
# @@ -570,9 +551,8 @@ elsif (!defined $TAError) # Grab the test reports if any #
-foreach my $Mission (@{$TaskMissions->{Missions}}) +foreach my $RptFileName (@$ReportNames) { - my $RptFileName = GetMissionBaseName($Mission) .".report"; Debug(Elapsed($Start), " Retrieving '$RptFileName'\n"); if ($TA->GetFile($RptFileName, "$TaskDir/$RptFileName")) { @@ -589,6 +569,10 @@ foreach my $Mission (@{$TaskMissions->{Missions}}) } else { + # Grab a copy of the reference report + my $ErrMessages = SnapshotLatestReport($Task, $RptFileName); + LogTaskError("$_\n") for (@$ErrMessages); + # $LogInfo->{Failures} can legitimately be undefined in case of a timeout $TaskFailures += $LogInfo->{Failures} || 0; if (@{$LogInfo->{Extra}} and open(my $Log, ">", "$TaskDir/$RptFileName.err")) @@ -617,35 +601,6 @@ Debug(Elapsed($Start), " Disconnecting\n"); $TA->Disconnect();
-# -# Grab a copy of the reference logs -# - -# Note that this may be a bit inaccurate right after a Wine commit. -# See WineSendLog.pl for more details. -if ($NewStatus eq 'completed') -{ - my $LatestDir = "$DataDir/latest"; - my $StepDir = $Step->GetDir(); - foreach my $Mission (@{$TaskMissions->{Missions}}) - { - my $RptFileName = GetMissionBaseName($Mission) .".report"; - my $RefReport = $Task->GetRefReportName($RptFileName); - for my $Suffix ("", ".err") - { - if (-f "$LatestDir/$RefReport$Suffix") - { - unlink "$StepDir/$RefReport$Suffix"; - if (!link "$LatestDir/$RefReport$Suffix", "$StepDir/$RefReport$Suffix") - { - Error "Could not link '$RefReport$Suffix': $!\n"; - } - } - } - } -} - - # # Wrap up # diff --git a/testbot/lib/WineTestBot/LogUtils.pm b/testbot/lib/WineTestBot/LogUtils.pm index 3e93c95c7..764330281 100644 --- a/testbot/lib/WineTestBot/LogUtils.pm +++ b/testbot/lib/WineTestBot/LogUtils.pm @@ -29,7 +29,8 @@ WineTestBot::LogUtils - Provides functions to parse task logs use Exporter 'import'; our @EXPORT = qw(GetLogFileNames GetLogLabel GetLogErrors TagNewErrors GetLogLineCategory GetReportLineCategory - ParseTaskLog ParseWineTestReport); + ParseTaskLog ParseWineTestReport + SnapshotLatestReport UpdateLatestReport UpdateLatestReports);
use Algorithm::Diff; use File::Basename; @@ -868,6 +869,11 @@ sub GetLogErrors($) return $LogInfo; }
+ +# +# New error detection +# + sub _DumpDiff($$) { my ($Label, $Diff) = @_; @@ -1025,4 +1031,100 @@ sub TagNewErrors($$) } }
+ +# +# Reference report management +# + +=pod +=over 12 + +=item C<SnapshotLatestReport()> + +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). + +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. +See WineSendLog.pl for more details. + +=back +=cut + +sub SnapshotLatestReport($$) +{ + my ($Task, $ReportName) = @_; + + my @ErrMessages; + my $TaskDir = $Task->GetDir(); + my $RefReportName = $Task->GetRefReportName($ReportName); + foreach my $Suffix ("", ".err") + { + next if (!-f "$DataDir/latest/$RefReportName$Suffix"); + + # FIXME: The reference reports are stored at the step level! + if (!link("$DataDir/latest/$RefReportName$Suffix", + "$TaskDir/../$RefReportName$Suffix")) + { + push @ErrMessages, "Could not create the '../$RefReportName$Suffix' link: $!"; + } + } + + return @ErrMessages; +} + +sub UpdateLatestReport($$$) +{ + my ($Task, $ReportName, $SrcReportPath) = @_; + my @ErrMessages; + + my $RefReportName = $Task->GetRefReportName($ReportName); + foreach my $Suffix ("", ".err") + { + # Add the new reference file even if it is empty. + next if (!-f "$SrcReportPath$Suffix"); + + unlink "$DataDir/latest/$RefReportName$Suffix"; + if (!link("$SrcReportPath$Suffix", + "$DataDir/latest/$RefReportName$Suffix")) + { + push @ErrMessages, "Could not create the '$RefReportName$Suffix' link: $!"; + } + } + + return @ErrMessages; +} + +=pod +=over 12 + +=item C<UpdateLatestReports()> + +Adds the Task's WineTest results to the set of reference reports. + +The reference reports will then be used to detect new failures in the other +tasks. + +This must be called after SnapshotLatestReport() otherwise a WineTest task +would compare its results to itself. + +=back +=cut + +sub UpdateLatestReports($$) +{ + my ($Task, $ReportNames) = @_; + + my @ErrMessages; + my $TaskDir = $Task->GetDir(); + foreach my $ReportName (@$ReportNames) + { + next if (!-f "$TaskDir/$ReportName" or -z _); + push @ErrMessages, @{UpdateLatestReport($Task, $ReportName, "$TaskDir/$ReportName")}; + } + return @ErrMessages; +} + 1; diff --git a/testbot/lib/WineTestBot/Tasks.pm b/testbot/lib/WineTestBot/Tasks.pm index 0c26904e1..1a46f0d57 100644 --- a/testbot/lib/WineTestBot/Tasks.pm +++ b/testbot/lib/WineTestBot/Tasks.pm @@ -70,6 +70,7 @@ our @ISA = qw(WineTestBot::WineTestBotItem); use File::Path; use ObjectModel::BackEnd; use WineTestBot::Config; +use WineTestBot::Missions;
sub InitializeNew($$) @@ -108,6 +109,35 @@ sub RmTree($) rmtree($Dir); }
+sub GetReportNames($) +{ + my ($self) = @_; + + my ($ErrMessage, $Missions) = ParseMissionStatement($self->Missions); + return ($ErrMessage, undef, undef) if (defined $ErrMessage); + if (!@$Missions) + { + my @TaskKey = $self->GetMasterKey(); + return ("Task @TaskKey has no mission", undef, undef); + } + if (@$Missions > 1) + { + my @TaskKey = $self->GetMasterKey(); + return ("Task @TaskKey should not have missions for multiple tasks\n", undef); + } + my $TaskMissions = $Missions->[0]; + + my @ReportNames; + foreach my $Mission (@{$TaskMissions->{Missions}}) + { + if ($Mission->{test} ne "build") + { + push @ReportNames, GetMissionBaseName($Mission) .".report"; + } + } + return (undef, @ReportNames, $TaskMissions); +} + sub GetRefReportName($$) { my ($self, $ReportName) = @_;
Hi,
While running your changed tests, I think I found new failures. Being a bot and all I'm not very good at pattern recognition, so I might be wrong, but could you please double-check?
Full results can be found at: https://testbot.winehq.org/JobDetails.pl?Key=63181
Your paranoid android.
=== debian10 (build log) ===
Task: Patch failed to apply
=== debian10 (build log) ===
Task: Patch failed to apply
WineRunBuild used to take a snapshot of the reference logs for all the other tasks even if the build failed. Thus there could be reference logs even when the matching log does not exist. This patch ensures that 'UpdateTaskLogs --delete' still finds and deletes those. --- testbot/bin/UpdateTaskLogs | 25 +++++++++++++++---------- 1 file changed, 15 insertions(+), 10 deletions(-)
diff --git a/testbot/bin/UpdateTaskLogs b/testbot/bin/UpdateTaskLogs index e0af09768..2ce192f0b 100755 --- a/testbot/bin/UpdateTaskLogs +++ b/testbot/bin/UpdateTaskLogs @@ -252,12 +252,17 @@ sub ProcessTaskLogs($$$)
if (($OptDelete or $OptRebuild) and !$CollectOnly) { - # Save / delete the task's reference reports - foreach my $LogName (@{GetLogFileNames($TaskDir)}) + # Save / delete the task's reference reports... all of them, + # even if they were not supposed to exist (e.g. failed builds). + my ($ErrMessage, $ReportNames, $_TaskMissions) = $Task->GetReportNames(); + if ($ErrMessage) { - next if ($LogName !~ /.report$/); - - my $RefReportName = $Task->GetRefReportName($LogName); + Error "$ErrMessage\n"; + $Rc = 1; + } + foreach my $ReportName (@$ReportNames) + { + my $RefReportName = $Task->GetRefReportName($ReportName); my $RefReportPath = "$StepDir/$RefReportName";
if (-f $RefReportPath or -f "$RefReportPath.err") @@ -276,7 +281,7 @@ sub ProcessTaskLogs($$$)
# 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, $LogName, $RefReportPath); + $Rc += DoUpdateLatestReport($Task, $ReportName, $RefReportPath);
Debug(TaskKeyStr($Task) .": Deleting ../$RefReportName\n"); } @@ -289,11 +294,11 @@ sub ProcessTaskLogs($$$) } }
- next if (!-f "$TaskDir/$LogName.err"); - Debug(TaskKeyStr($Task) .": Deleting $LogName.err\n"); - if (!unlink "$TaskDir/$LogName.err") + next if (!-f "$TaskDir/$ReportName.err"); + Debug(TaskKeyStr($Task) .": Deleting $ReportName.err\n"); + if (!unlink "$TaskDir/$ReportName.err") { - Error "Could not delete '$LogName.err': $!\n"; + Error "Could not delete '$ReportName.err': $!\n"; $Rc = 1; } }
Hi,
While running your changed tests, I think I found new failures. Being a bot and all I'm not very good at pattern recognition, so I might be wrong, but could you please double-check?
Full results can be found at: https://testbot.winehq.org/JobDetails.pl?Key=63182
Your paranoid android.
=== debian10 (build log) ===
Task: Patch failed to apply
=== debian10 (build log) ===
Task: Patch failed to apply
The old reference report filename format was '<vmname>_<reportname>' which means there could only be one per report. Each job should only have one report of a given type per VM so add it to the reference filename. Also the use of an underscore as the separator made it hard to split the components apart as <reportname> could contain underscores too such as in 'win32_fr_FR.report'. Dashes are a better choice since they are not allowed in either the VM name nor in the report name. So the new refeence filename format is '<vmname>-job<jobid>-<reportname>'.
Note: This requires running UpdateTaskLogs to move and rename the existing reference reports. --- testbot/bin/Janitor.pl | 2 +- testbot/bin/UpdateTaskLogs | 71 ++++++++++++++++++++++++--- testbot/bin/WineSendLog.pl | 2 +- testbot/lib/WineTestBot/LogUtils.pm | 5 +- testbot/lib/WineTestBot/StepsTasks.pm | 2 +- testbot/lib/WineTestBot/Tasks.pm | 2 +- testbot/web/JobDetails.pl | 4 +- 7 files changed, 73 insertions(+), 15 deletions(-)
diff --git a/testbot/bin/Janitor.pl b/testbot/bin/Janitor.pl index 579a43275..ecae5be5a 100755 --- a/testbot/bin/Janitor.pl +++ b/testbot/bin/Janitor.pl @@ -314,7 +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_]+)_(?:exe|win|wow)(?:32|64)[a-zA-Z0-9_]*.report(?:.err)?$/) + if ($Entry =~ /^([a-zA-Z0-9_]+)-job[0-9]+-[a-zA-Z0-9_]+.report(?:.err)?$/) { # Keep the reference WineTest reports for all VMs even if they are # retired or scheduled for deletion. diff --git a/testbot/bin/UpdateTaskLogs b/testbot/bin/UpdateTaskLogs index 2ce192f0b..70a3dd2c1 100755 --- a/testbot/bin/UpdateTaskLogs +++ b/testbot/bin/UpdateTaskLogs @@ -242,6 +242,46 @@ sub DoUpdateLatestReport($$$) return $Rc; }
+sub MoveRefReport($$;$) +{ + my ($RefDir, $RefName, $NewDir) = @_; + + my $RefPath = "$RefDir/$RefName"; + + my $Rc = 0; + if (-f $RefPath) + { + $NewDir ||= $RefDir; + my $NewName = $RefName; + if ($RefName =~ /^([a-zA-Z0-9_]+)_((?:exe|win|wow)(?:32|64)[a-zA-Z0-9_]*.report(?:.err)?)$/) + { + # We don't know which job generated this reference log. + # So use a fixed, arbitrary JobId. + $NewName = "$1-job000000-$2"; + } + + my $NewPath = "$NewDir/$NewName"; + if (-f $NewPath) + { + Error "Could not move '$RefName' because the '$NewPath' target already exists\n"; + $Rc = 1; + } + elsif ($RefPath ne $NewPath) + { + my $TaskKey = Path2TaskKey($NewDir); + my $RelRefDir = ($RefDir eq $NewDir) ? "" : "../"; + Debug("$TaskKey: $RelRefDir$RefName -> $NewName\n"); + if (!rename($RefPath, $NewPath)) + { + Error "Could not move '$RefPath' to '$NewName': $!\n"; + $Rc = 1; + } + } + } + + return $Rc; +} + sub ProcessTaskLogs($$$) { my ($Step, $Task, $CollectOnly) = @_; @@ -250,6 +290,20 @@ sub ProcessTaskLogs($$$) my $StepDir = $Step->GetDir(); my $TaskDir = $Task->GetDir();
+ if (!$CollectOnly) + { + # Upgrade the naming scheme of the task's old reference reports + foreach my $LogName (@{GetLogFileNames($TaskDir)}) + { + next if ($LogName !~ /.report$/); + my $StepReportName = $Task->VM->Name ."_$LogName"; + foreach my $Suffix ("", ".err") + { + $Rc += MoveRefReport($StepDir, "$StepReportName$Suffix", $TaskDir); + } + } + } + if (($OptDelete or $OptRebuild) and !$CollectOnly) { # Save / delete the task's reference reports... all of them, @@ -263,7 +317,7 @@ sub ProcessTaskLogs($$$) foreach my $ReportName (@$ReportNames) { my $RefReportName = $Task->GetRefReportName($ReportName); - my $RefReportPath = "$StepDir/$RefReportName"; + my $RefReportPath = "$TaskDir/$RefReportName";
if (-f $RefReportPath or -f "$RefReportPath.err") { @@ -283,7 +337,7 @@ sub ProcessTaskLogs($$$) # (this would be the case for the oldest tasks with --rebuild) $Rc += DoUpdateLatestReport($Task, $ReportName, $RefReportPath);
- Debug(TaskKeyStr($Task) .": Deleting ../$RefReportName\n"); + Debug(TaskKeyStr($Task) .": Deleting $RefReportName*\n"); } foreach my $Suffix ("", ".err") { @@ -311,7 +365,7 @@ sub ProcessTaskLogs($$$) { next if ($LogName !~ /.report$/); my $RefReportName = $Task->GetRefReportName($LogName); - next if (-f "$StepDir/$RefReportName"); + next if (-f "$TaskDir/$RefReportName");
my $LatestReportPath = $LatestReports{$RefReportName}; if (!defined $LatestReportPath) @@ -324,9 +378,9 @@ sub ProcessTaskLogs($$$) Debug(TaskKeyStr($Task) .": Snapshotting $RefReportName from ". Path2TaskKey($LatestReportPath) ."\n"); foreach my $Suffix ("", ".err") { - unlink "$StepDir/$RefReportName$Suffix"; + unlink "$TaskDir/$RefReportName$Suffix"; if (-f "$LatestReportPath$Suffix" and - !link("$LatestReportPath$Suffix", "$StepDir/$RefReportName$Suffix")) + !link("$LatestReportPath$Suffix", "$TaskDir/$RefReportName$Suffix")) { Error "Could not link '$RefReportName$Suffix': $!\n"; $Rc = 1; @@ -396,7 +450,7 @@ sub ProcessLatestReports()
if ($OptDelete or $OptRebuild) { - # Delete the reports so they are rebuilt from scratch if appropriate + # Delete the reports that should be deleted / rebuilt foreach my $Suffix ("", ".err") { next if (!-f "$LatestReportPath$Suffix"); @@ -425,6 +479,11 @@ sub ProcessLatestReports() $Rc = 1; } } + else + { + # Upgrade the naming scheme of the task's old reference reports + $Rc += MoveRefReport("$DataDir/latest", $RefReportName); + } }
return $Rc; diff --git a/testbot/bin/WineSendLog.pl b/testbot/bin/WineSendLog.pl index b31d1f5d3..393c76a0e 100755 --- a/testbot/bin/WineSendLog.pl +++ b/testbot/bin/WineSendLog.pl @@ -292,7 +292,7 @@ EOF next if (!$LogInfo->{ErrCount});
my $AllNew; - my $RefReportPath = $StepTask->GetFullFileName($StepTask->GetRefReportName($LogName)); + my $RefReportPath = "$TaskDir/". $StepTask->GetRefReportName($LogName); TagNewErrors($RefReportPath, $LogInfo); if ($LogInfo->{NoRef}) { diff --git a/testbot/lib/WineTestBot/LogUtils.pm b/testbot/lib/WineTestBot/LogUtils.pm index 764330281..08c9911d9 100644 --- a/testbot/lib/WineTestBot/LogUtils.pm +++ b/testbot/lib/WineTestBot/LogUtils.pm @@ -1064,11 +1064,10 @@ sub SnapshotLatestReport($$) { next if (!-f "$DataDir/latest/$RefReportName$Suffix");
- # FIXME: The reference reports are stored at the step level! if (!link("$DataDir/latest/$RefReportName$Suffix", - "$TaskDir/../$RefReportName$Suffix")) + "$TaskDir/$RefReportName$Suffix")) { - push @ErrMessages, "Could not create the '../$RefReportName$Suffix' link: $!"; + push @ErrMessages, "Could not create the '$RefReportName$Suffix' link: $!"; } }
diff --git a/testbot/lib/WineTestBot/StepsTasks.pm b/testbot/lib/WineTestBot/StepsTasks.pm index bad0e2437..f65e6a632 100644 --- a/testbot/lib/WineTestBot/StepsTasks.pm +++ b/testbot/lib/WineTestBot/StepsTasks.pm @@ -71,7 +71,7 @@ sub GetTaskDir($) sub GetRefReportName($$) { my ($self, $ReportName) = @_; - return $self->VM->Name ."_$ReportName"; + return $self->VM->Name ."-job000000-$ReportName"; }
sub GetTitle($) diff --git a/testbot/lib/WineTestBot/Tasks.pm b/testbot/lib/WineTestBot/Tasks.pm index 1a46f0d57..7b9ac9b81 100644 --- a/testbot/lib/WineTestBot/Tasks.pm +++ b/testbot/lib/WineTestBot/Tasks.pm @@ -141,7 +141,7 @@ sub GetReportNames($) sub GetRefReportName($$) { my ($self, $ReportName) = @_; - return $self->VM->Name ."_$ReportName"; + return $self->VM->Name ."-job000000-$ReportName"; }
sub _SetupTask($$) diff --git a/testbot/web/JobDetails.pl b/testbot/web/JobDetails.pl index fc18c866f..a4179c705 100644 --- a/testbot/web/JobDetails.pl +++ b/testbot/web/JobDetails.pl @@ -494,7 +494,7 @@ EOF if ($LogInfo->{ErrCount}) { # Identify new errors in test reports - my $RefReportPath = $StepTask->GetFullFileName($StepTask->GetRefReportName($MoreInfo->{Full})); + my $RefReportPath = "$TaskDir/". $StepTask->GetRefReportName($MoreInfo->{Full}); TagNewErrors($RefReportPath, $LogInfo); } } @@ -563,7 +563,7 @@ EOF if ($LogName =~ /.report$/) { # For test reports try to identify the new errors - my $RefReportPath = $StepTask->GetFullFileName($StepTask->GetRefReportName($LogName)); + my $RefReportPath = "$TaskDir/". $StepTask->GetRefReportName($LogName); TagNewErrors($RefReportPath, $LogInfo); }
Hi,
While running your changed tests, I think I found new failures. Being a bot and all I'm not very good at pattern recognition, so I might be wrong, but could you please double-check?
Full results can be found at: https://testbot.winehq.org/JobDetails.pl?Key=63183
Your paranoid android.
=== debian10 (build log) ===
Task: Patch failed to apply
=== debian10 (build log) ===
Task: Patch failed to apply
Each task has pairs of xxx.report and xxx.report.err files where the .err file contains extra errors detected while parsing xxx.report and can thus be rebuilt from the report files. They also have log and log.err files but log.err is completely independent from the log file: * log contains the traces printed by the script running on the VM, typically the build log or batch file commands. * log.err contains errors that occurred on the TestBot-server side, such as perl errors in the WineRun* scripts, or messages when the TestBot had to kill a stuck task. So rename log to task.log and log.err to testbot.log. This way their purpose is clearer and log.err does not run the risk of being confused with the other .err files. --- testbot/bin/UpdateTaskLogs | 24 ++++++++++++++++++++++++ testbot/bin/WineRunBuild.pl | 8 ++++---- testbot/bin/WineRunReconfig.pl | 8 ++++---- testbot/bin/WineRunTask.pl | 6 +++--- testbot/bin/WineRunWineTest.pl | 8 ++++---- testbot/lib/WineTestBot/LogUtils.pm | 22 ++++++++++++---------- testbot/lib/WineTestBot/Tasks.pm | 10 +++++----- 7 files changed, 56 insertions(+), 30 deletions(-)
diff --git a/testbot/bin/UpdateTaskLogs b/testbot/bin/UpdateTaskLogs index 70a3dd2c1..b069e892e 100755 --- a/testbot/bin/UpdateTaskLogs +++ b/testbot/bin/UpdateTaskLogs @@ -302,6 +302,30 @@ sub ProcessTaskLogs($$$) $Rc += MoveRefReport($StepDir, "$StepReportName$Suffix", $TaskDir); } } + + my %LogMap = ( + "log" => "task.log", + "log.err" => "testbot.log", + "old_log" => "old_task.log", + "old_log.err" => "old_testbot.log"); + while (my ($OldName, $NewName) = each %LogMap) + { + if (-f "$TaskDir/$OldName" and !-f "$TaskDir/$NewName" and + !rename("$TaskDir/$OldName", "$TaskDir/$NewName")) + { + Error TaskKey($Task) .": Could not rename $OldName because $NewName already exists\n"; + $Rc = 1; + } + } + + # testbot.log is the only log which we expect to be empty. + # There is not much point keeping it if that's the case. + my $TestBotLog = "$TaskDir/testbot.log"; + if (-z $TestBotLog) + { + Debug(TaskKeyStr($Task) .": Deleting empty testbot.log\n"); + unlink $TestBotLog; + } }
if (($OptDelete or $OptRebuild) and !$CollectOnly) diff --git a/testbot/bin/WineRunBuild.pl b/testbot/bin/WineRunBuild.pl index afbc5ec78..b9698a9fd 100755 --- a/testbot/bin/WineRunBuild.pl +++ b/testbot/bin/WineRunBuild.pl @@ -181,14 +181,14 @@ sub LogTaskError($) Debug("$Name0:error: ", $ErrMessage);
my $OldUMask = umask(002); - if (open(my $ErrFile, ">>", "$TaskDir/log.err")) + if (open(my $ErrFile, ">>", "$TaskDir/testbot.log")) { print $ErrFile $ErrMessage; close($ErrFile); } else { - Error "Unable to open 'log.err' for writing: $!\n"; + Error "Unable to open 'testbot.log' for writing: $!\n"; } umask($OldUMask); } @@ -417,9 +417,9 @@ if (!defined $TA->Wait($Pid, $Task->Timeout, 60)) }
Debug(Elapsed($Start), " Retrieving 'Build.log'\n"); -if ($TA->GetFile("Build.log", "$TaskDir/log")) +if ($TA->GetFile("Build.log", "$TaskDir/task.log")) { - my $LogInfo = ParseTaskLog("$TaskDir/log"); + my $LogInfo = ParseTaskLog("$TaskDir/task.log"); if ($LogInfo->{Task} eq "ok") { # We must have gotten the full log and the build did succeed. diff --git a/testbot/bin/WineRunReconfig.pl b/testbot/bin/WineRunReconfig.pl index c82d5fcb5..bf6fc6ff4 100755 --- a/testbot/bin/WineRunReconfig.pl +++ b/testbot/bin/WineRunReconfig.pl @@ -182,14 +182,14 @@ sub LogTaskError($) Debug("$Name0:error: ", $ErrMessage);
my $OldUMask = umask(002); - if (open(my $ErrFile, ">>", "$TaskDir/log.err")) + if (open(my $ErrFile, ">>", "$TaskDir/testbot.log")) { print $ErrFile $ErrMessage; close($ErrFile); } else { - Error "Unable to open 'log.err' for writing: $!\n"; + Error "Unable to open 'testbot.log' for writing: $!\n"; } umask($OldUMask); } @@ -418,9 +418,9 @@ if (!defined $TA->Wait($Pid, $Task->Timeout, 60))
my $LogInfo; Debug(Elapsed($Start), " Retrieving 'Reconfig.log'\n"); -if ($TA->GetFile("Reconfig.log", "$TaskDir/log")) +if ($TA->GetFile("Reconfig.log", "$TaskDir/task.log")) { - $LogInfo = ParseTaskLog("$TaskDir/log"); + $LogInfo = ParseTaskLog("$TaskDir/task.log"); if ($LogInfo->{Task} eq "ok") { # We must have gotten the full log and the build did succeed. diff --git a/testbot/bin/WineRunTask.pl b/testbot/bin/WineRunTask.pl index ee910cdf0..5bd13cc7a 100755 --- a/testbot/bin/WineRunTask.pl +++ b/testbot/bin/WineRunTask.pl @@ -210,14 +210,14 @@ sub LogTaskError($) Debug("$Name0:error: ", $ErrMessage);
my $OldUMask = umask(002); - if (open(my $ErrFile, ">>", "$TaskDir/log.err")) + if (open(my $ErrFile, ">>", "$TaskDir/testbot.log")) { print $ErrFile $ErrMessage; close($ErrFile); } else { - Error "Unable to open 'log.err' for writing: $!\n"; + Error "Unable to open 'testbot.log' for writing: $!\n"; } umask($OldUMask); } @@ -534,7 +534,7 @@ if (!defined $TA->Wait($Pid, $Timeout, $Keepalive)) }
Debug(Elapsed($Start), " Retrieving 'Task.log'\n"); -if (!$TA->GetFile("Task.log", "$TaskDir/log") and !defined $TAError) +if (!$TA->GetFile("Task.log", "$TaskDir/task.log") and !defined $TAError) { $TAError = "An error occurred while retrieving the task log: ". $TA->GetLastError(); } diff --git a/testbot/bin/WineRunWineTest.pl b/testbot/bin/WineRunWineTest.pl index 46e85ec47..6db75a7c5 100755 --- a/testbot/bin/WineRunWineTest.pl +++ b/testbot/bin/WineRunWineTest.pl @@ -206,14 +206,14 @@ sub LogTaskError($) my ($ErrMessage) = @_; Debug("$Name0:error: ", $ErrMessage);
- if (open(my $ErrFile, ">>", "$TaskDir/log.err")) + if (open(my $ErrFile, ">>", "$TaskDir/testbot.log")) { print $ErrFile $ErrMessage; close($ErrFile); } else { - Error "Unable to open 'log.err' for writing: $!\n"; + Error "Unable to open 'testbot.log' for writing: $!\n"; } }
@@ -506,9 +506,9 @@ if (!defined $TA->Wait($Pid, $Task->Timeout, 60)) }
Debug(Elapsed($Start), " Retrieving 'Task.log'\n"); -if ($TA->GetFile("Task.log", "$TaskDir/log")) +if ($TA->GetFile("Task.log", "$TaskDir/task.log")) { - my $LogInfo = ParseTaskLog("$TaskDir/log"); + my $LogInfo = ParseTaskLog("$TaskDir/task.log"); if ($LogInfo->{Task} eq "ok") { # We must have gotten the full log and the task completed successfully diff --git a/testbot/lib/WineTestBot/LogUtils.pm b/testbot/lib/WineTestBot/LogUtils.pm index 08c9911d9..9f4035be2 100644 --- a/testbot/lib/WineTestBot/LogUtils.pm +++ b/testbot/lib/WineTestBot/LogUtils.pm @@ -622,8 +622,8 @@ sub GetLogFileNames($;$) win32.report win32_*.report wow32.report wow32_*.report wow64.report wow64_*.report - log); - push @Globs, "old_log" if ($IncludeOld); + task.log testbot.log); + push @Globs, ("old_task.log", "old_testbot.log") if ($IncludeOld);
my (@Logs, %Seen); foreach my $Glob (@Globs) @@ -637,7 +637,7 @@ sub GetLogFileNames($;$) { $LogName = $1; # untaint } - elsif ($LogName eq $Glob) # log and old_log cases + elsif ($LogName eq $Glob) # (old_) task.log and testbot.log cases { $LogName = $Glob; # untaint } @@ -659,13 +659,15 @@ sub GetLogFileNames($;$) }
my %_LogFileLabels = ( - "exe32.report" => '32 bit%s report', - "exe64.report" => '64 bit%s report', - "win32.report" => '32 bit%s report', - "wow32.report" => '32 bit%s WoW report', - "wow64.report" => '64 bit%s WoW report', - "log" => 'task%s log', - "old_log" => 'old%s logs', + "exe32.report" => '32 bit%s report', + "exe64.report" => '64 bit%s report', + "win32.report" => '32 bit%s report', + "wow32.report" => '32 bit%s WoW report', + "wow64.report" => '64 bit%s WoW report', + "task.log" => 'task%s log', + "testbot.log" => 'testbot%s log', + "old_task.log" => 'old%s task logs', + "old_testbot.log" => 'old%s testbot logs', );
=pod diff --git a/testbot/lib/WineTestBot/Tasks.pm b/testbot/lib/WineTestBot/Tasks.pm index 7b9ac9b81..541b5558e 100644 --- a/testbot/lib/WineTestBot/Tasks.pm +++ b/testbot/lib/WineTestBot/Tasks.pm @@ -153,7 +153,7 @@ sub _SetupTask($$) if (-d $Dir) { mkpath("$Dir.new", 0, 0775); - foreach my $Filename ("log", "log.err") + foreach my $Filename ("task.log", "testbot.log") { if (-f "$Dir/old_$Filename") { @@ -178,9 +178,9 @@ sub _SetupTask($$) rename("$Dir.new", $Dir); }
- # Capture Perl errors in the task's generic error log + # Capture Perl errors in the per-task TestBot log my $TaskDir = $self->CreateDir(); - if (open(STDERR, ">>", "$TaskDir/log.err")) + if (open(STDERR, ">>", "$TaskDir/testbot.log")) { # Make sure stderr still flushes after each print my $tmp=select(STDERR); @@ -190,7 +190,7 @@ sub _SetupTask($$) else { require WineTestBot::Log; - WineTestBot::Log::LogMsg("unable to redirect stderr to '$TaskDir/log.err': $!\n"); + WineTestBot::Log::LogMsg("unable to redirect stderr to '$TaskDir/testbot.log': $!\n"); } }
@@ -253,7 +253,7 @@ sub UpdateStatus($$) my ($JobId, $StepNo, $TaskNo) = @{$self->GetMasterKey()}; my $OldUMask = umask(002); my $TaskDir = $self->CreateDir(); - if (open TASKLOG, ">>$TaskDir/log.err") + if (open TASKLOG, ">>$TaskDir/testbot.log") { print TASKLOG "TestBot process got stuck or died unexpectedly\n"; close TASKLOG;
Hi,
While running your changed tests, I think I found new failures. Being a bot and all I'm not very good at pattern recognition, so I might be wrong, but could you please double-check?
Full results can be found at: https://testbot.winehq.org/JobDetails.pl?Key=63184
Your paranoid android.
=== debian10 (build log) ===
Task: Patch failed to apply
=== debian10 (build log) ===
Task: Patch failed to apply
Add headers to each section. --- testbot/lib/WineTestBot/LogUtils.pm | 185 ++++++++++++++-------------- 1 file changed, 92 insertions(+), 93 deletions(-)
diff --git a/testbot/lib/WineTestBot/LogUtils.pm b/testbot/lib/WineTestBot/LogUtils.pm index 9f4035be2..da73423bd 100644 --- a/testbot/lib/WineTestBot/LogUtils.pm +++ b/testbot/lib/WineTestBot/LogUtils.pm @@ -63,6 +63,78 @@ sub _IsPerlError($) $Str =~ /^Possible precedence issue /; }
+=pod +=over 12 + +=item C<GetLogLineCategory()> + +Identifies the category of the given log line: an error message, a Wine +diagnostic line, a TestBot error, etc. + +The category can then be used to decide whether to hide the line or, on +the contrary, highlight it. + +=back +=cut + +sub GetLogLineCategory($) +{ + my ($Line) = @_; + + if (# Build messages + $Line =~ /^+ \S/ or + $Line =~ /^LANG=/ or + $Line =~ /^Running (?:the tests|WineTest) / or + $Line =~ /^Task: (?:ok|tests|Updated)/) + { + return "info"; + } + if (# Git errors + $Line =~ /^CONFLICT / or + $Line =~ /^error: patch failed:/ or + $Line =~ /^error: corrupt patch / or + # Build errors + $Line =~ /: error: / or + $Line =~ /: undefined reference to `/ or + $Line =~ /^make: [*]{3} No rule to make target / or + $Line =~ /^Makefile:[0-9]+: recipe for target .* failed$/ or + $Line =~ /^Task: / or + # Typical perl errors + _IsPerlError($Line)) + { + return "error"; + } + if ($Line =~ /:winediag:/) + { + if (# Normally CorIsLatestSvc() would not be called but mscoree:mscoree + # calls it as a test. + $Line =~ /CorIsLatestSvc If this function is called,/ or + # VMs and most test machines don't have a midi port. + $Line =~ /No software synthesizer midi port found,/ or + # Most VMs have limited OpenGL support. + $Line =~ /None of the requested D3D feature levels is supported / or + # The tests are not run as root. + $Line =~ /this requires special permissions/) + { + return "diag"; + } + return "error"; + } + if (# TestBot script error messages + $Line =~ /^[a-zA-Z.]+:error: / or + # TestBot error + $Line =~ /^BotError:/ or + $Line =~ /^Error:/ or + # X errors + $Line =~ /^X Error of failed request: / or + $Line =~ / opcode of failed request: /) + { + return "boterror"; + } + + return "none"; +} +
=pod =over 12 @@ -138,13 +210,17 @@ sub ParseTaskLog($) }
+# +# WineTest report parser +# + =pod =over 12
-=item C<GetLogLineCategory()> +=item C<GetReportLineCategory()>
-Identifies the category of the given log line: an error message, a Wine -diagnostic line, a TestBot error, etc. +Identifies the category of the given test report line: an error message, +a todo, just an informational message or none of these.
The category can then be used to decide whether to hide the line or, on the contrary, highlight it. @@ -152,69 +228,36 @@ the contrary, highlight it. =back =cut
-sub GetLogLineCategory($) +sub GetReportLineCategory($) { my ($Line) = @_;
- if (# Build messages - $Line =~ /^+ \S/ or - $Line =~ /^LANG=/ or - $Line =~ /^Running (?:the tests|WineTest) / or - $Line =~ /^Task: (?:ok|tests|Updated)/) + if ($Line =~ /: Test marked todo: /) { - return "info"; + return "todo"; } - if (# Git errors - $Line =~ /^CONFLICT / or - $Line =~ /^error: patch failed:/ or - $Line =~ /^error: corrupt patch / or - # Build errors - $Line =~ /: error: / or - $Line =~ /: undefined reference to `/ or - $Line =~ /^make: [*]{3} No rule to make target / or - $Line =~ /^Makefile:[0-9]+: recipe for target .* failed$/ or - $Line =~ /^Task: / or - # Typical perl errors - _IsPerlError($Line)) + if ($Line =~ /: Tests skipped: / or + $Line =~ /^[_.a-z0-9-]+:[_a-z0-9]* skipped /) { - return "error"; + return "skip"; } - if ($Line =~ /:winediag:/) + if ($Line =~ /: Test (?:failed|succeeded inside todo block): / or + $Line =~ /Fatal: test .* does not exist/ or + $Line =~ / done (258)/ or + $Line =~ /: unhandled exception [0-9a-fA-F]{8} at / or + $Line =~ /^Unhandled exception: /) { - if (# Normally CorIsLatestSvc() would not be called but mscoree:mscoree - # calls it as a test. - $Line =~ /CorIsLatestSvc If this function is called,/ or - # VMs and most test machines don't have a midi port. - $Line =~ /No software synthesizer midi port found,/ or - # Most VMs have limited OpenGL support. - $Line =~ /None of the requested D3D feature levels is supported / or - # The tests are not run as root. - $Line =~ /this requires special permissions/) - { - return "diag"; - } return "error"; } - if (# TestBot script error messages - $Line =~ /^[a-zA-Z.]+:error: / or - # TestBot error - $Line =~ /^BotError:/ or - $Line =~ /^Error:/ or - # X errors - $Line =~ /^X Error of failed request: / or - $Line =~ / opcode of failed request: /) + if ($Line =~ /^[_.a-z0-9-]+:[_a-z0-9]* start /) { - return "boterror"; + return "info"; }
return "none"; }
-# -# WineTest report parser -# - sub _NewCurrentUnit($$) { my ($Dll, $Unit) = @_; @@ -553,50 +596,6 @@ sub ParseWineTestReport($$$) }
-=pod -=over 12 - -=item C<GetReportLineCategory()> - -Identifies the category of the given test report line: an error message, -a todo, just an informational message or none of these. - -The category can then be used to decide whether to hide the line or, on -the contrary, highlight it. - -=back -=cut - -sub GetReportLineCategory($) -{ - my ($Line) = @_; - - if ($Line =~ /: Test marked todo: /) - { - return "todo"; - } - if ($Line =~ /: Tests skipped: / or - $Line =~ /^[_.a-z0-9-]+:[_a-z0-9]* skipped /) - { - return "skip"; - } - if ($Line =~ /: Test (?:failed|succeeded inside todo block): / or - $Line =~ /Fatal: test .* does not exist/ or - $Line =~ / done (258)/ or - $Line =~ /: unhandled exception [0-9a-fA-F]{8} at / or - $Line =~ /^Unhandled exception: /) - { - return "error"; - } - if ($Line =~ /^[_.a-z0-9-]+:[_a-z0-9]* start /) - { - return "info"; - } - - return "none"; -} - - # # Log querying and formatting #
Prior to this patch the log files needed to be parsed every time the error list is needed. Parsing the reference report and diffing its errors also needs to be repeated every time the list of new errors is needed. Both of these have a significant impact on the JobDetails page load time. So this patch lets the task scripts (WineRun*) extract the log file errors when they complete, detect the new errors, and saves the result in a .errors file stored next to the original log file. All that's needed then is to read the small .errors file to get the full errors list along with their status (old or new) which speeds up WineSendLog and JobDetails. However the task scripts cannot generate the errors cache file for the testbot.log file because that file is complete only once the task scripts exits. So the errors cache file for it is generated by the WineSendLog script once the job completes. Furthermore the .err files were used to store the validation errors detected by the ParseWineTestReport() function. These are now stored as the '.Extra' error group in the .errors files, making the .err files redundant. Then instead of showing the content of the xxx and xxx.err file in succession, the scripts either just iterate over all the error groups, or present the full content of the log first and then show the 'extra' error groups, that is those that are not tied to a specific log line number.
Note: This requires running UpdateTaskLogs to create the new .errors files and to delete the obsolete .err files.
Wine-Bug: https://bugs.winehq.org/show_bug.cgi?id=48035 --- testbot/bin/Janitor.pl | 2 +- testbot/bin/UpdateTaskLogs | 153 ++++++++------ testbot/bin/WineRunBuild.pl | 2 + testbot/bin/WineRunReconfig.pl | 2 + testbot/bin/WineRunTask.pl | 21 +- testbot/bin/WineRunWineTest.pl | 16 +- testbot/bin/WineSendLog.pl | 117 +++++++---- testbot/lib/WineTestBot/LogUtils.pm | 277 ++++++++++++++++++++++---- testbot/lib/WineTestBot/StepsTasks.pm | 7 - testbot/lib/WineTestBot/Tasks.pm | 3 + testbot/web/JobDetails.pl | 93 ++++----- 11 files changed, 477 insertions(+), 216 deletions(-)
diff --git a/testbot/bin/Janitor.pl b/testbot/bin/Janitor.pl index ecae5be5a..a4ba817ff 100755 --- a/testbot/bin/Janitor.pl +++ b/testbot/bin/Janitor.pl @@ -314,7 +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(?:.err)?$/) + 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. diff --git a/testbot/bin/UpdateTaskLogs b/testbot/bin/UpdateTaskLogs index b069e892e..fb0037c91 100755 --- a/testbot/bin/UpdateTaskLogs +++ b/testbot/bin/UpdateTaskLogs @@ -184,26 +184,17 @@ sub Path2TaskKey($) return $Path; }
-sub BuildErrFile($$$$) +sub BuildErrorsCache($$$$;$) { - my ($Dir, $ReportName, $IsWineTest, $TaskTimedOut) = @_; + my ($Dir, $LogName, $IsWineTest, $TaskTimedOut, $Task) = @_;
my $TaskKey = Path2TaskKey($Dir); + Debug("$TaskKey: Creating $LogName.errors\n");
- my $LogInfo = ParseWineTestReport("$Dir/$ReportName", $IsWineTest, $TaskTimedOut); - return "$TaskKey: $LogInfo->{BadLog}" if ($LogInfo->{BadLog}); - return undef if (!@{$LogInfo->{Errors}}); - - Debug("$TaskKey: Creating $ReportName.err\n"); - if (open(my $Log, ">", "$Dir/$ReportName.err")) - { - # Save the extra errors detected by ParseWineTestReport() in - # $ReportName.err (see WineRunWineTest.pl). - print $Log "$_\n" for (@{$LogInfo->{Errors}}); - close($Log); - return undef; - } - return "Unable to open '$TaskKey/$ReportName' for reading: $!"; + my $LogInfo = $LogName =~ /.report$/ ? + ParseWineTestReport("$Dir/$LogName", $IsWineTest, $TaskTimedOut) : + ParseTaskLog("$Dir/$LogName"); + return CreateLogErrorsCache($LogInfo, $Task); }
my %LatestReports; @@ -247,6 +238,7 @@ sub MoveRefReport($$;$) my ($RefDir, $RefName, $NewDir) = @_;
my $RefPath = "$RefDir/$RefName"; + my $TaskKey = Path2TaskKey($NewDir);
my $Rc = 0; if (-f $RefPath) @@ -268,7 +260,6 @@ sub MoveRefReport($$;$) } elsif ($RefPath ne $NewPath) { - my $TaskKey = Path2TaskKey($NewDir); my $RelRefDir = ($RefDir eq $NewDir) ? "" : "../"; Debug("$TaskKey: $RelRefDir$RefName -> $NewName\n"); if (!rename($RefPath, $NewPath)) @@ -279,6 +270,16 @@ sub MoveRefReport($$;$) } }
+ if (-f "$RefPath.err") + { + Debug("$TaskKey: Deleting $RefName.err\n"); + if (!unlink("$RefPath.err")) + { + Error "Could not delete '$RefName.err': $!\n"; + $Rc = 1; + } + } + return $Rc; }
@@ -297,10 +298,7 @@ sub ProcessTaskLogs($$$) { next if ($LogName !~ /.report$/); my $StepReportName = $Task->VM->Name ."_$LogName"; - foreach my $Suffix ("", ".err") - { - $Rc += MoveRefReport($StepDir, "$StepReportName$Suffix", $TaskDir); - } + $Rc += MoveRefReport($StepDir, $StepReportName, $TaskDir); }
my %LogMap = ( @@ -321,10 +319,10 @@ sub ProcessTaskLogs($$$) # testbot.log is the only log which we expect to be empty. # There is not much point keeping it if that's the case. my $TestBotLog = "$TaskDir/testbot.log"; - if (-z $TestBotLog) + if (-z $TestBotLog and (!-f "$TestBotLog.errors" or -z _)) { - Debug(TaskKeyStr($Task) .": Deleting empty testbot.log\n"); - unlink $TestBotLog; + Debug(TaskKeyStr($Task) .": Deleting empty testbot.log*\n"); + unlink $TestBotLog, "$TestBotLog.errors"; } }
@@ -343,13 +341,13 @@ sub ProcessTaskLogs($$$) my $RefReportName = $Task->GetRefReportName($ReportName); my $RefReportPath = "$TaskDir/$RefReportName";
- if (-f $RefReportPath or -f "$RefReportPath.err") + if (-f $RefReportPath or -f "$RefReportPath.errors") { - if (!-f "$RefReportPath.err") + if (!$OptDelete and !-f "$RefReportPath.errors") { - # (Re)Build the err file before adding the reference report to + # (Re)Build the errors file before adding the reference report to # latest/. - my $ErrMessage = BuildErrFile($StepDir, $RefReportName, 1, 0); + my $ErrMessage = BuildErrorsCache($TaskDir, $RefReportName, 1, 0); if (defined $ErrMessage) { Error "$ErrMessage\n"; @@ -363,7 +361,7 @@ sub ProcessTaskLogs($$$)
Debug(TaskKeyStr($Task) .": Deleting $RefReportName*\n"); } - foreach my $Suffix ("", ".err") + foreach my $Suffix ("", ".err", ".errors") { if (!unlink "$RefReportPath$Suffix" and -e "$RefReportPath$Suffix") { @@ -380,9 +378,24 @@ sub ProcessTaskLogs($$$) $Rc = 1; } } + + # And clean up the files derived from the task's logs + foreach my $LogName (@{GetLogFileNames($TaskDir, "+old")}) + { + foreach my $Suffix (".err", ".errors") + { + next if (!-f "$TaskDir/$LogName$Suffix"); + Debug(TaskKeyStr($Task) .": Deleting $LogName$Suffix\n"); + if (!unlink "$TaskDir/$LogName$Suffix") + { + Error "Could not delete '$LogName$Suffix': $!\n"; + $Rc = 1; + } + } + } }
- if (!$OptDelete and !$CollectOnly and $Task->Status eq "completed") + if (!$OptDelete and !$CollectOnly) { # Take a snapshot of the latest reference reports foreach my $LogName (@{GetLogFileNames($TaskDir)}) @@ -400,7 +413,7 @@ sub ProcessTaskLogs($$$) else { Debug(TaskKeyStr($Task) .": Snapshotting $RefReportName from ". Path2TaskKey($LatestReportPath) ."\n"); - foreach my $Suffix ("", ".err") + foreach my $Suffix ("", ".errors") { unlink "$TaskDir/$RefReportName$Suffix"; if (-f "$LatestReportPath$Suffix" and @@ -413,7 +426,7 @@ sub ProcessTaskLogs($$$) } }
- # And (re)build the .err files + # And (re)build the .errors files if ($Task->Status !~ /^(?:queued|running)$/) { my ($IsWineTest, $TaskTimedOut); @@ -423,15 +436,33 @@ sub ProcessTaskLogs($$$) $TaskTimedOut = $Duration > $Task->Timeout; $IsWineTest = ($Step->Type eq "patch" or $Step->Type eq "suite"); } - foreach my $LogName (@{GetLogFileNames($TaskDir)}) + foreach my $LogName (@{GetLogFileNames($TaskDir, "+old")}) { - next if ($LogName !~ /.report$/); - next if (-f "$TaskDir/$LogName.err"); - my $ErrMessage = BuildErrFile($TaskDir, $LogName, $IsWineTest, $TaskTimedOut); - if (defined $ErrMessage) + if ($LogName =~ /.report$/) { - Error "$ErrMessage\n"; - $Rc = 1; + # 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") + { + my $ErrMessage = BuildErrorsCache($TaskDir, $LogName, $IsWineTest, $TaskTimedOut, $Task); + if (defined $ErrMessage) + { + Error "$ErrMessage\n"; + $Rc = 1; + } } } } @@ -464,18 +495,30 @@ sub ProcessLatestReports() my $Rc = 0; my $LatestGlob = "$DataDir/latest/*.report";
- # Perform cleanups and updates + # Upgrade the naming scheme of the old reference reports + # and delete the obsolete .err files foreach my $LatestReportPath (glob("$LatestGlob $LatestGlob.err")) { my $RefReportName = basename($LatestReportPath); - next if ($RefReportName !~ /^([a-zA-Z0-9_]+.report)(?:.err)?$/); + next if ($RefReportName !~ /^([a-zA-Z0-9_]+_[a-zA-Z0-9_]+.report)(?:.err)?$/); + $RefReportName = $1; # untaint + + # MoveRefReport() also deletes .err files + $Rc += MoveRefReport("$DataDir/latest", $RefReportName); + } + + # Then perform cleanups and updates + foreach my $LatestReportPath (glob("$LatestGlob $LatestGlob.errors")) + { + my $RefReportName = basename($LatestReportPath); + next if ($RefReportName !~ /^([a-zA-Z0-9_]+-job[0-9]+-[a-zA-Z0-9_]+.report)(?:.errors)?$/); $RefReportName = $1; # untaint $LatestReportPath = "$DataDir/latest/$RefReportName";
if ($OptDelete or $OptRebuild) { # Delete the reports that should be deleted / rebuilt - foreach my $Suffix ("", ".err") + foreach my $Suffix ("", ".errors") { next if (!-f "$LatestReportPath$Suffix"); Debug("latest: Deleting $RefReportName$Suffix\n"); @@ -486,28 +529,26 @@ sub ProcessLatestReports() } elsif (!-f "$LatestReportPath") { - Debug("latest: Deleting orphaned $RefReportName.err\n"); - if (!unlink "$LatestReportPath.err") + Debug("latest: Deleting orphaned $RefReportName.errors\n"); + if (!unlink "$LatestReportPath.errors") { - Error "Could not delete orphaned '$LatestReportPath.err': $!\n"; + Error "Could not delete orphaned '$LatestReportPath.errors': $!\n"; $Rc = 1; } } - elsif (!$OptDelete and !-f "$LatestReportPath.err") + else { - # Build the missing .err file - my $ErrMessage = BuildErrFile("$DataDir/latest", $RefReportName, 1, 0); - if (defined $ErrMessage) + if (!-f "$LatestReportPath.errors") { - Error "$ErrMessage\n"; - $Rc = 1; + # Build the missing .errors file + my $ErrMessage = BuildErrorsCache("$DataDir/latest", $RefReportName, 1, 0); + if (defined $ErrMessage) + { + Error "$ErrMessage\n"; + $Rc = 1; + } } } - else - { - # Upgrade the naming scheme of the task's old reference reports - $Rc += MoveRefReport("$DataDir/latest", $RefReportName); - } }
return $Rc; diff --git a/testbot/bin/WineRunBuild.pl b/testbot/bin/WineRunBuild.pl index b9698a9fd..c1728c66f 100755 --- a/testbot/bin/WineRunBuild.pl +++ b/testbot/bin/WineRunBuild.pl @@ -443,6 +443,8 @@ if ($TA->GetFile("Build.log", "$TaskDir/task.log")) # that explains why. $NewStatus = "badbuild"; } + my $ErrMessage = CreateLogErrorsCache($LogInfo); + LogTaskError("$ErrMessage\n") if (defined $ErrMessage); } elsif (!defined $TAError) { diff --git a/testbot/bin/WineRunReconfig.pl b/testbot/bin/WineRunReconfig.pl index bf6fc6ff4..627c96b46 100755 --- a/testbot/bin/WineRunReconfig.pl +++ b/testbot/bin/WineRunReconfig.pl @@ -443,6 +443,8 @@ if ($TA->GetFile("Reconfig.log", "$TaskDir/task.log")) MakeSecureURL(GetTaskURL($JobId, $StepNo, $TaskNo)) ."\n"); $NewStatus = "badbuild"; } + my $ErrMessage = CreateLogErrorsCache($LogInfo); + LogTaskError("$ErrMessage\n") if (defined $ErrMessage); } elsif (!defined $TAError) { diff --git a/testbot/bin/WineRunTask.pl b/testbot/bin/WineRunTask.pl index 5bd13cc7a..100857572 100755 --- a/testbot/bin/WineRunTask.pl +++ b/testbot/bin/WineRunTask.pl @@ -534,7 +534,17 @@ if (!defined $TA->Wait($Pid, $Timeout, $Keepalive)) }
Debug(Elapsed($Start), " Retrieving 'Task.log'\n"); -if (!$TA->GetFile("Task.log", "$TaskDir/task.log") and !defined $TAError) +if ($TA->GetFile("Task.log", "$TaskDir/task.log")) +{ + my $LogInfo = ParseTaskLog("$TaskDir/task.log"); + if (!$LogInfo->{BadLog}) + { + my $ErrMessage = CreateLogErrorsCache($LogInfo); + LogTaskError("$ErrMessage\n") if (defined $ErrMessage); + } + # else ignore the error because this log is not critical +} +elsif (!defined $TAError) { $TAError = "An error occurred while retrieving the task log: ". $TA->GetLastError(); } @@ -561,13 +571,8 @@ if ($TA->GetFile($RptFileName, "$TaskDir/$RptFileName"))
# $LogInfo->{Failures} can legitimately be undefined in case of a timeout $TaskFailures += $LogInfo->{Failures} || 0; - if (@{$LogInfo->{Extra}} and open(my $Log, ">", "$TaskDir/$RptFileName.err")) - { - # Save the extra errors detected by ParseWineTestReport() in - # $RptFileName.err (see WineRunWineTest.pl). - print $Log "$_\n" for (@{$LogInfo->{Extra}}); - close($Log); - } + my $ErrMessage = CreateLogErrorsCache($LogInfo, $Task); + LogTaskError("$ErrMessage\n") if (defined $ErrMessage); } } elsif (!defined $TAError) diff --git a/testbot/bin/WineRunWineTest.pl b/testbot/bin/WineRunWineTest.pl index 6db75a7c5..8a222f352 100755 --- a/testbot/bin/WineRunWineTest.pl +++ b/testbot/bin/WineRunWineTest.pl @@ -540,6 +540,8 @@ if ($TA->GetFile("Task.log", "$TaskDir/task.log")) $TaskFailures = undef; $PossibleCrash = 1; } + my $ErrMessage = CreateLogErrorsCache($LogInfo); + LogTaskError("$ErrMessage\n") if (defined $ErrMessage); } elsif (!defined $TAError) { @@ -575,18 +577,8 @@ foreach my $RptFileName (@$ReportNames)
# $LogInfo->{Failures} can legitimately be undefined in case of a timeout $TaskFailures += $LogInfo->{Failures} || 0; - if (@{$LogInfo->{Extra}} and open(my $Log, ">", "$TaskDir/$RptFileName.err")) - { - # Save the extra errors detected by ParseWineTestReport() in - # $RptFileName.err: - # - This keep the .report file clean. - # - Each .err file can be matched to its corresponding .report, even - # if there are multiple .report files in the directory. - # - The .err file can be moved to the latest directory next to the - # reference report. - print $Log "$_\n" for (@{$LogInfo->{Extra}}); - close($Log); - } + my $ErrMessage = CreateLogErrorsCache($LogInfo, $Task); + LogTaskError("$ErrMessage\n") if (defined $ErrMessage); } } elsif (!defined $TAError and diff --git a/testbot/bin/WineSendLog.pl b/testbot/bin/WineSendLog.pl index 393c76a0e..84309cced 100755 --- a/testbot/bin/WineSendLog.pl +++ b/testbot/bin/WineSendLog.pl @@ -77,6 +77,60 @@ sub Error(@) }
+# +# Log errors caching +# + +sub ParseTaskLogs($$) +{ + my ($Step, $Task) = @_; + + my $TaskDir = $Task->GetDir(); + + # testbot.log is the only log which we expect to be empty. + # There is not much point keeping it if that's the case. + my $TestBotLog = "$TaskDir/testbot.log"; + unlink $TestBotLog if (-z $TestBotLog and !-f "$TestBotLog.errors"); + + my ($IsWineTest, $TaskTimedOut); + if ($Task->Started and $Task->Ended) + { + my $Duration = $Task->Ended - $Task->Started; + $TaskTimedOut = $Duration > $Task->Timeout; + $IsWineTest = ($Step->Type eq "patch" or $Step->Type eq "suite"); + } + foreach my $LogName (@{GetLogFileNames($TaskDir, "+old")}) + { + next if (-f "$TaskDir/$LogName.errors"); + + my $LogInfo; + if ($LogName =~ /.report$/) + { + $LogInfo = ParseWineTestReport("$TaskDir/$LogName", $IsWineTest, $TaskTimedOut); + } + else + { + $LogInfo = ParseTaskLog("$TaskDir/$LogName"); + } + my $ErrMessage = CreateLogErrorsCache($LogInfo, $Task); + Error "$ErrMessage\n" if (defined $ErrMessage); + } +} + +sub ParseJobLogs($) +{ + my ($Job) = @_; + + foreach my $Step (@{$Job->Steps->GetItems()}) + { + foreach my $Task (@{$Step->Tasks->GetItems()}) + { + ParseTaskLogs($Step, $Task); + } + } +} + + # # Reporting # @@ -97,27 +151,28 @@ sub GetTitle($$)
sub DumpLogAndErr($$) { - my ($File, $Path) = @_; + my ($File, $LogPath) = @_;
- my $PrintSeparator; - foreach my $FileName ($Path, "$Path.err") + if (open(my $LogFile, "<", $LogPath)) { - if (open(my $LogFile, "<", $FileName)) + foreach my $Line (<$LogFile>) { - my $First = 1; - foreach my $Line (<$LogFile>) - { - $Line =~ s/\s*$//; - if ($First and $PrintSeparator) - { - print $File "\n"; - $First = 0; - } - print $File "$Line\n"; - } - close($LogFile); - $PrintSeparator = 1; + $Line =~ s/\s*$//; + print $File "$Line\n"; } + close($LogFile); + } + + # And append the extra errors + my $LogInfo = LoadLogErrors($LogPath); + foreach my $GroupName (@{$LogInfo->{ErrGroupNames}}) + { + my $Group = $LogInfo->{ErrGroups}->{$GroupName}; + # Extra groups don't have a line number + next if ($Group->{LineNo}); + + print $File "\n$GroupName\n"; + print $File "$_\n" for (@{$Group->{Errors}}); } }
@@ -207,12 +262,13 @@ EOF $JobErrors->{$Key}->{LogNames} = $LogNames; foreach my $LogName (@$LogNames) { - my $LogInfo = GetLogErrors("$TaskDir/$LogName"); - next if (!$LogInfo->{ErrCount}); + my $LogInfo = LoadLogErrors("$TaskDir/$LogName"); + next if (!defined $LogInfo->{BadLog} and !$LogInfo->{ErrCount}); $JobErrors->{$Key}->{HasErrors} = 1; $JobErrors->{$Key}->{$LogName} = $LogInfo;
print $Sendmail "\n=== ", GetTitle($StepTask, $LogName), " ===\n"; + print $Sendmail "$LogInfo->{BadLog}\n" if (defined $LogInfo->{BadLog});
foreach my $GroupName (@{$LogInfo->{ErrGroupNames}}) { @@ -291,35 +347,17 @@ EOF # Skip if there are no errors next if (!$LogInfo->{ErrCount});
- my $AllNew; - my $RefReportPath = "$TaskDir/". $StepTask->GetRefReportName($LogName); - TagNewErrors($RefReportPath, $LogInfo); - if ($LogInfo->{NoRef}) - { - # Test reports should have reference WineTest results and if not - # reporting the errors as new would cause false positives. - next if ($LogName =~ /.report$/); - - # Build logs don't have reference logs so for them every error is new. - $AllNew = 1; - } - elsif (!$LogInfo->{NewCount}) - { - # There is no new error - next; - } - push @Messages, "\n=== ". GetTitle($StepTask, $LogName) ." ===\n";
foreach my $GroupName (@{$LogInfo->{ErrGroupNames}}) { my $Group = $LogInfo->{ErrGroups}->{$GroupName}; - next if (!$AllNew and !$Group->{NewCount}); + next if (!$Group->{NewCount});
push @Messages, ($GroupName ? "\n$GroupName:\n" : "\n"); foreach my $ErrIndex (0..@{$Group->{Errors}} - 1) { - if ($AllNew or $Group->{IsNew}->[$ErrIndex]) + if ($Group->{IsNew}->[$ErrIndex]) { push @Messages, "$Group->{Errors}->[$ErrIndex]\n"; } @@ -510,6 +548,7 @@ if (!defined $Job) # Analyze the log, notify the developer and the Patches website #
+ParseJobLogs($Job); SendLog($Job);
LogMsg "Log for job $JobId sent\n"; diff --git a/testbot/lib/WineTestBot/LogUtils.pm b/testbot/lib/WineTestBot/LogUtils.pm index da73423bd..8c2fea41f 100644 --- a/testbot/lib/WineTestBot/LogUtils.pm +++ b/testbot/lib/WineTestBot/LogUtils.pm @@ -27,10 +27,11 @@ WineTestBot::LogUtils - Provides functions to parse task logs
use Exporter 'import'; -our @EXPORT = qw(GetLogFileNames GetLogLabel GetLogErrors TagNewErrors +our @EXPORT = qw(GetLogFileNames GetLogLabel GetLogLineCategory GetReportLineCategory ParseTaskLog ParseWineTestReport - SnapshotLatestReport UpdateLatestReport UpdateLatestReports); + SnapshotLatestReport UpdateLatestReport UpdateLatestReports + CreateLogErrorsCache LoadLogErrors);
use Algorithm::Diff; use File::Basename; @@ -624,14 +625,12 @@ sub GetLogFileNames($;$) task.log testbot.log); push @Globs, ("old_task.log", "old_testbot.log") if ($IncludeOld);
- my (@Logs, %Seen); + my @Logs; foreach my $Glob (@Globs) { - foreach my $FileName (glob("'$Dir/$Glob*'")) + foreach my $FileName (glob("'$Dir/$Glob'")) { my $LogName = basename($FileName); - $LogName =~ s/.err$//; - next if ($Seen{$LogName}); if ($LogName =~ /^([a-zA-Z0-9_]+.report)$/) { $LogName = $1; # untaint @@ -645,13 +644,8 @@ sub GetLogFileNames($;$) # Not a valid log filename (where does this file come from?) next; } - $Seen{$LogName} = 1;
- if ((-f "$Dir/$LogName" and !-z "$Dir/$LogName") or - (-f "$Dir/$LogName.err" and !-z "$Dir/$LogName.err")) - { - push @Logs, $LogName; - } + push @Logs, $LogName if (-f "$Dir/$LogName" and !-z _); } } return @Logs; @@ -729,13 +723,20 @@ sub _AddLogGroup($$;$) return $LogInfo->{ErrGroups}->{$GroupName}; }
-sub _AddLogError($$$;$) +sub _AddLogError($$$;$$) { - my ($LogInfo, $ErrGroup, $Line, $LineNo) = @_; + my ($LogInfo, $ErrGroup, $Line, $LineNo, $IsNew) = @_;
push @{$ErrGroup->{Errors}}, $Line; push @{$ErrGroup->{LineNos}}, $LineNo || 0; $LogInfo->{ErrCount}++; + if ($IsNew) + { + my $ErrIndex = @{$ErrGroup->{Errors}} - 1; + $ErrGroup->{IsNew}->[$ErrIndex] = 1; + $ErrGroup->{NewCount}++; + $LogInfo->{NewCount}++; + } }
=pod @@ -743,9 +744,8 @@ sub _AddLogError($$$;$)
=item C<GetLogErrors()>
-Analyzes the specified log and associated error file to filter out unimportant -messages and only return the errors, split by module (for Wine reports that's -per dll / program being tested). +Extracts the errors from the specified log file, split by module (for Wine +reports that's per dll / program being tested).
Returns a hashtable containing: =over @@ -840,36 +840,177 @@ sub GetLogErrors($) _AddLogError($LogInfo, $Group, "Could not open '$LogName' for reading: $!"); }
- if (open(my $LogFile, "<", "$LogPath.err")) + return $LogInfo; +} + + +# +# Log errors caching [Part 1] +# + +=pod +=over 12 + +=item C<LoadLogErrors()> + +Loads the specified log errors file. + +The file contains two types of lines: +* GroupName lines + <GroupName> + Where <GroupName> is a unique string which would typically be the name of a + WineTest dll or program, but may also be empty or be used to specify an + extra group errors. It must not start with a space. + +* Error lines + <Space> <New> <SrcLineNo> <Error> + Where: + - <Space> is a space, as well as the spaces in the line above. + - <New> is either 'n' for new errors, or 'o' for old ones. + - <SrcLineNo> is the 1-base line number of the error in the source log file. + If there is no source line then this should be 0. + - <Error> is the error message. + +Returns the errors in the same format as TagNewErrors(). + +=back +=cut + +sub LoadLogErrors($) +{ + my ($LogPath) = @_; + + $LogPath .= ".errors"; + my $LogName = basename($LogPath); + my $LogInfo = { + LogName => $LogName, + LogPath => $LogPath, + + ErrGroupNames => [], + ErrGroups => {}, + }; + + my $ErrorsFile; + if (!open($ErrorsFile, "<", $LogPath)) + { + $LogInfo->{BadLog} = "Unable to open '$LogName' for reading: $!"; + return $LogInfo; + } + + my $CurrentGroup; + foreach my $Line (<$ErrorsFile>) { - $LogInfo->{ErrCount} ||= 0; - # Add the related extra errors - my $CurrentGroup; - my $LineNo = 0; - foreach my $Line (<$LogFile>) + chomp $Line; + my ($Type, $Property, $Value) = split / /, $Line, 3; + if ($Type eq "p") { - $LineNo++; - $Line =~ s/\s*$//; - if (!$CurrentGroup) + if (!defined $LogInfo->{$Property}) { - # Note: $GroupName must not depend on the previous content as this - # would break diffs. - my $GroupName = $IsReport ? "Report errors" : "Task errors"; - $CurrentGroup = _AddLogGroup($LogInfo, $GroupName, $LineNo); + $LogInfo->{$Property} = $Value; + } + else + { + $LogInfo->{BadLog} = "Cannot set $Property = $Value because it is already set to $LogInfo->{$Property}"; + last; } - _AddLogError($LogInfo, $CurrentGroup, $Line, $LineNo); } - close($LogFile); - } - elsif (-f "$LogPath.err") - { - my $Group = _AddLogGroup($LogInfo, "TestBot errors"); - _AddLogError($LogInfo, $Group, "Could not open '$LogName.err' for reading: $!"); + elsif ($Type eq "g") + { + $CurrentGroup = _AddLogGroup($LogInfo, $Value, $Property); + } + elsif (!$CurrentGroup) + { + $LogInfo->{BadLog} = "Got a $Type line with no group"; + last; + } + elsif ($Type eq "o") + { + _AddLogError($LogInfo, $CurrentGroup, $Value, $Property); + } + elsif ($Type eq "n") + { + _AddLogError($LogInfo, $CurrentGroup, $Value, $Property, "new"); + } + else + { + $LogInfo->{BadLog} = "Found an unknown line type ($Type)"; + last; + } } + close($ErrorsFile);
return $LogInfo; }
+=pod +=over 12 + +=item C<_SaveLogErrors()> + +Saves the LogInfo structure to <LogName>.errors. + +The file contains lines of the form: + <type> <value1> <value2> + +The values depend on the <type> of the line. <type> and <value1> must not +contain spaces while <value2> runs to the end of the line. More specifically +the line formats are: +=over + +=item p <name> <value> +Property lines contain (name, value) pairs. +Note that properties which can be calculated while reading the errors file +are not saved (e.g. ErrCount and NewCount). + +=item g <lineno> <groupname> +Group lines contain the group name and the line number of the first line of +the group in the log. Note that the first line would typically not be an +error line. +A group line should be followed by the old and new error lines in this group. + +=item o <lineno> <line> +Old error lines contain the line number of the error in the log and a verbatim +copy of that line (with CR/LF converted to a simple LF). + +=item n <lineno> <line> +The format for new error lines is identical to that for old errors but with a +different type. + +=back +=back +=cut + +sub _SaveLogErrors($) +{ + my ($LogInfo) = @_; + + my $ErrorsPath = "$LogInfo->{LogPath}.errors"; + if (open(my $ErrorsFile, ">", $ErrorsPath)) + { + foreach my $Name ("BadRef", "NoRef") + { + next if (!defined $LogInfo->{$Name}); + print $ErrorsFile "p $Name $LogInfo->{$Name}\n"; + } + foreach my $GroupName (@{$LogInfo->{ErrGroupNames}}) + { + my $Group = $LogInfo->{ErrGroups}->{$GroupName}; + print $ErrorsFile "g $Group->{LineNo} $GroupName\n"; + foreach my $Index (0..@{$Group->{Errors}} - 1) + { + my $IsNew = $Group->{IsNew}->[$Index] ? "n" : "o"; + print $ErrorsFile "$IsNew $Group->{LineNos}->[$Index] $Group->{Errors}->[$Index]\n"; + } + } + close($ErrorsFile); + + # Set the mtime so Janitor reaps both at the same time + utime time(), GetMTime($LogInfo->{LogPath}), $ErrorsPath; + return undef; + } + return "Could not open '$LogInfo->{LogName}.errors' for writing: $!"; +} +
# # New error detection @@ -897,6 +1038,18 @@ sub _DumpDiff($$) } }
+sub MarkAllErrorsAsNew($) +{ + my ($LogInfo) = @_; + + foreach my $Group (values %{$LogInfo->{ErrGroups}}) + { + $Group->{NewCount} = @{$Group->{Errors}}; + $Group->{IsNew}->[$_] = 1 for (0..$Group->{NewCount} - 1); + } + $LogInfo->{NewCount} = $LogInfo->{ErrCount}; +} + =pod =over 12
@@ -974,7 +1127,7 @@ sub TagNewErrors($$)
return if (!$LogInfo->{ErrCount});
- my $RefInfo = GetLogErrors($RefLogPath); + my $RefInfo = LoadLogErrors($RefLogPath); if ($RefInfo->{BadLog}) { # Save the BadLog error but do not tag the errors as new: this is up to @@ -1033,6 +1186,49 @@ sub TagNewErrors($$) }
+# +# Log errors caching [Part 2] +# + +sub CreateLogErrorsCache($;$) +{ + my ($ParsedInfo, $Task) = @_; + + my $LogInfo = GetLogErrors($ParsedInfo->{LogPath}); + + # Store the parser's extra errors into their own group + my $ExtraCount = $ParsedInfo->{Errors} ? @{$ParsedInfo->{Errors}} : 0; + if ($ExtraCount) + { + my $ExtraName = ($LogInfo->{LogName} =~ /.report(?:.errors)?$/) ? "report validation" : "task"; + $ExtraName = ucfirst($ExtraName) ." errors"; + my $Group = _AddLogGroup($LogInfo, $ExtraName); + $Group->{Errors} = $ParsedInfo->{Errors}; + my @LineNos = (0) x $ExtraCount; + $Group->{LineNos} = @LineNos; + $LogInfo->{ErrCount} += $ExtraCount; + } + + return $LogInfo->{BadLog} if ($LogInfo->{BadLog}); + + if ($LogInfo->{LogName} !~ /.report$/) + { + # Only test reports have reference WineTest results. + # So for other logs all errors are new. + MarkAllErrorsAsNew($LogInfo); + } + elsif ($Task and $LogInfo->{ErrCount}) + { + my $RefReportPath = $Task->GetDir() ."/". $Task->GetRefReportName($LogInfo->{LogName}); + TagNewErrors($RefReportPath, $LogInfo); + # Don't mark the errors as new if there is no reference WineTest report + # as this would cause false positives. + } + + return _SaveLogErrors($LogInfo); +} + + # # Reference report management # @@ -1061,7 +1257,7 @@ sub SnapshotLatestReport($$) my @ErrMessages; my $TaskDir = $Task->GetDir(); my $RefReportName = $Task->GetRefReportName($ReportName); - foreach my $Suffix ("", ".err") + foreach my $Suffix ("", ".errors") { next if (!-f "$DataDir/latest/$RefReportName$Suffix");
@@ -1081,9 +1277,10 @@ sub UpdateLatestReport($$$) my @ErrMessages;
my $RefReportName = $Task->GetRefReportName($ReportName); - foreach my $Suffix ("", ".err") + foreach my $Suffix ("", ".errors") { # Add the new reference file even if it is empty. + # This is important for .errors files. next if (!-f "$SrcReportPath$Suffix");
unlink "$DataDir/latest/$RefReportName$Suffix"; diff --git a/testbot/lib/WineTestBot/StepsTasks.pm b/testbot/lib/WineTestBot/StepsTasks.pm index f65e6a632..463f15078 100644 --- a/testbot/lib/WineTestBot/StepsTasks.pm +++ b/testbot/lib/WineTestBot/StepsTasks.pm @@ -67,13 +67,6 @@ sub GetTaskDir($) return $self->GetStepDir() ."/". $self->TaskNo; }
-# Keep in sync with WineTestBot::Task::GetRefReportName() -sub GetRefReportName($$) -{ - my ($self, $ReportName) = @_; - return $self->VM->Name ."-job000000-$ReportName"; -} - sub GetTitle($) { my ($self) = @_; diff --git a/testbot/lib/WineTestBot/Tasks.pm b/testbot/lib/WineTestBot/Tasks.pm index 541b5558e..87c501025 100644 --- a/testbot/lib/WineTestBot/Tasks.pm +++ b/testbot/lib/WineTestBot/Tasks.pm @@ -172,6 +172,9 @@ sub _SetupTask($$) } close($Src); } + + my $LogInfo = ParseTaskLog("$Dir.new/old_$Filename"); + CreateLogErrorsCache($LogInfo); }
$self->RmTree(); diff --git a/testbot/web/JobDetails.pl b/testbot/web/JobDetails.pl index a4179c705..eee8df2df 100644 --- a/testbot/web/JobDetails.pl +++ b/testbot/web/JobDetails.pl @@ -346,43 +346,36 @@ sub GenerateMoreInfoLink($$$$;$$) print "<div class='TaskMoreInfoLink'>$Html</div>\n"; }
-sub GetErrorCategory($) +sub GenerateFullLog($$$$) { - return "error"; -} + my ($self, $Dir, $LogName, $HideLog) = @_;
-sub GenerateFullLog($$$$;$) -{ - my ($self, $FileName, $HideLog, $LogInfo, $Header) = @_; + my $LogInfo = LoadLogErrors("$Dir/$LogName");
my %NewLineNos; - if ($LogInfo and $LogInfo->{NewCount}) + if ($LogInfo->{ErrCount}) { foreach my $GroupName (@{$LogInfo->{ErrGroupNames}}) { my $Group = $LogInfo->{ErrGroups}->{$GroupName}; next if (!$Group->{NewCount}); - if (($FileName =~ /.err$/) == - ($GroupName =~ /^(?:Report errors|Task errors|TestBot errors)$/)) + for my $ErrIndex (0..@{$Group->{Errors}} - 1) { - for my $ErrIndex (0..@{$Group->{Errors}} - 1) + if ($Group->{IsNew}->[$ErrIndex]) { - if ($Group->{IsNew}->[$ErrIndex]) - { - $NewLineNos{$Group->{LineNos}->[$ErrIndex]} = 1; - } + $NewLineNos{$Group->{LineNos}->[$ErrIndex]} = 1; } } } }
- my $GetCategory = $FileName =~ /.err$/ ? &GetErrorCategory : - $FileName =~ /.report$/ ? &GetReportLineCategory : + my $GetCategory = $LogName =~ /.report$/ ? &GetReportLineCategory : &GetLogLineCategory;
my $LineNo = 0; my $IsEmpty = 1; - if (open(my $LogFile, "<", $FileName)) + my $LineNo = 0; + if (open(my $LogFile, "<", "$Dir/$LogName")) { foreach my $Line (<$LogFile>) { @@ -390,7 +383,6 @@ sub GenerateFullLog($$$$;$) $Line =~ s/\s*$//; if ($IsEmpty) { - print $Header if (defined $Header); print "<pre$HideLog><code>"; $IsEmpty = 0; } @@ -405,8 +397,32 @@ sub GenerateFullLog($$$$;$) } close($LogFile); } - print "</code></pre>\n" if (!$IsEmpty);
+ # And append the extra errors + foreach my $GroupName (@{$LogInfo->{ErrGroupNames}}) + { + my $Group = $LogInfo->{ErrGroups}->{$GroupName}; + # Extra groups don't have a line number + next if ($Group->{LineNo}); + + print "<div class='LogDllName'>$GroupName</div>\n"; + my $i = 0; + for my $i (0..@{$Group->{Errors}} - 1) + { + if ($IsEmpty) + { + print "<pre$HideLog><code>"; + $IsEmpty = 0; + } + + my $Line = $Group->{Errors}->[$i]; + my $Category = $Group->{IsNew}->[$i] ? "new" : "error"; + my $Html = $self->escapeHTML($Line); + print "<span class='log-$Category'>$Html</span>\n"; + } + } + + print "</code></pre>\n" if (!$IsEmpty); return $IsEmpty; }
@@ -486,48 +502,26 @@ EOF # Show this log in full, highlighting the important lines #
- my $LogInfo; - my $LogFileName = "$TaskDir/$MoreInfo->{Full}"; - if ($MoreInfo->{Full} =~ /.report$/) - { - $LogInfo = GetLogErrors($LogFileName); - if ($LogInfo->{ErrCount}) - { - # Identify new errors in test reports - my $RefReportPath = "$TaskDir/". $StepTask->GetRefReportName($MoreInfo->{Full}); - TagNewErrors($RefReportPath, $LogInfo); - } - } - my ($Action, $Url) = $self->GetMoreInfoLink($Key, GetLogLabel($MoreInfo->{Full}), "Full", $MoreInfo->{Full}); $Url = $self->CGI->escapeHTML($Url); my $HideLog = $Action eq "Hide" ? " ondblclick='HideLog(event, "$Url")'" : "";
- my $LogIsEmpty = $self->GenerateFullLog($LogFileName, $HideLog, $LogInfo); - my $EmptyDiag; + my $LogIsEmpty = $self->GenerateFullLog($TaskDir, $MoreInfo->{Full}, $HideLog); if ($LogIsEmpty) { if ($StepTask->Status eq "canceled") { - $EmptyDiag = "No log, task was canceled\n"; + print "No log, task was canceled\n"; } elsif ($StepTask->Status eq "skipped") { - $EmptyDiag = "No log, task skipped\n"; + print "No log, task skipped\n"; } else { print "Empty log\n"; - $LogIsEmpty = 0; } } - - # And append the associated extra errors - my $ErrHeader = $MoreInfo->{Full} =~ /.report/ ? "report" : "task"; - $ErrHeader = "old $ErrHeader" if ($MoreInfo->{Full} =~ /^old_/); - $ErrHeader = "<div class='HrTitle'>". ucfirst($ErrHeader) ." errors<div class='HrLine'></div></div>"; - my $ErrIsEmpty = $self->GenerateFullLog("$LogFileName.err", $HideLog, $LogInfo, $ErrHeader); - print $EmptyDiag if ($ErrIsEmpty and defined $EmptyDiag); } else { @@ -540,7 +534,7 @@ EOF foreach my $LogName (@{$MoreInfo->{Logs}}) { next if ($LogName =~ /^old_/); - my $LogInfo = GetLogErrors("$TaskDir/$LogName"); + my $LogInfo = LoadLogErrors("$TaskDir/$LogName"); next if (!$LogInfo->{ErrCount}); $LogInfos->{$LogName} = $LogInfo; } @@ -560,16 +554,9 @@ EOF }
my $LogInfo = $LogInfos->{$LogName}; - if ($LogName =~ /.report$/) - { - # For test reports try to identify the new errors - my $RefReportPath = "$TaskDir/". $StepTask->GetRefReportName($LogName); - TagNewErrors($RefReportPath, $LogInfo); - } - foreach my $GroupName (@{$LogInfo->{ErrGroupNames}}) { - print "<div class='LogDllName'>$GroupName</div>\n" if ($GroupName); + print "<div class='LogDllName'>$GroupName</div>\n";
print "<pre><code>"; my $ErrIndex = 0;
Hi,
While running your changed tests, I think I found new failures. Being a bot and all I'm not very good at pattern recognition, so I might be wrong, but could you please double-check?
Full results can be found at: https://testbot.winehq.org/JobDetails.pl?Key=63185
Your paranoid android.
=== debian10 (build log) ===
Task: Patch failed to apply
=== debian10 (build log) ===
Task: Patch failed to apply
Clearly indicate when the log or its errors cache could not be read. Also show a note when new errors could not be detected, either because there is no reference WineTest results (which would typically happen shortly after a new test configuration has been added), or because there was an issue reading one or more of the reference reports. --- testbot/web/JobDetails.pl | 46 +++++++++++++++++++++++++++++++++++-- testbot/web/WineTestBot.css | 1 + 2 files changed, 45 insertions(+), 2 deletions(-)
diff --git a/testbot/web/JobDetails.pl b/testbot/web/JobDetails.pl index eee8df2df..7fc90bf20 100644 --- a/testbot/web/JobDetails.pl +++ b/testbot/web/JobDetails.pl @@ -351,6 +351,22 @@ sub GenerateFullLog($$$$) my ($self, $Dir, $LogName, $HideLog) = @_;
my $LogInfo = LoadLogErrors("$Dir/$LogName"); + if (defined $LogInfo->{BadLog}) + { + print "<pre class='log-note'>Could not highlight new errors: ", ($LogInfo->{BadRef} || $LogInfo->{BadLog}), "</pre>\n"; + } + elsif ($LogInfo->{NoRef} and !defined $LogInfo->{BadRef}) + { + print "<pre class='log-note'>No WineTest results are available to detect new errors</pre>\n"; + } + elsif ($LogInfo->{NoRef}) + { + print "<pre class='log-note'>Could not detect new errors: $LogInfo->{BadRef}</pre>\n"; + } + elsif (defined $LogInfo->{BadRef}) + { + print "<pre class='log-note'>Some WineTest results could not be used to detect new errors: $LogInfo->{BadRef}</pre>\n"; + }
my %NewLineNos; if ($LogInfo->{ErrCount}) @@ -397,6 +413,11 @@ sub GenerateFullLog($$$$) } close($LogFile); } + else + { + print "<pre class='log-error'><code>Unable to open '$LogName' for reading: $!</code></pre>\n"; + $IsEmpty = 0; + }
# And append the extra errors foreach my $GroupName (@{$LogInfo->{ErrGroupNames}}) @@ -535,8 +556,11 @@ EOF { next if ($LogName =~ /^old_/); my $LogInfo = LoadLogErrors("$TaskDir/$LogName"); - next if (!$LogInfo->{ErrCount}); - $LogInfos->{$LogName} = $LogInfo; + if ($LogInfo->{ErrCount} or + (defined $LogInfo->{BadLog} and !-z "$TaskDir/$LogName")) + { + $LogInfos->{$LogName} = $LogInfo; + } } my $ShowLogName = ($ReportCount > 1 or scalar(keys %$LogInfos) > 1);
@@ -554,6 +578,24 @@ EOF }
my $LogInfo = $LogInfos->{$LogName}; + if (defined $LogInfo->{BadLog}) + { + my ($_Action, $Url) = $self->GetMoreInfoLink($Key, GetLogLabel($LogName), "Full", $LogName); + print "<pre class='log-note'>The error summary is not available (<a href='$Url'>see full log instead</a>): $LogInfo->{BadLog}</pre>\n"; + } + elsif ($LogInfo->{NoRef} and !defined $LogInfo->{BadRef}) + { + print "<pre class='log-note'>No WineTest results are available to detect new errors</pre>\n"; + } + elsif ($LogInfo->{NoRef}) + { + print "<pre class='log-note'>Could not detect new errors: $LogInfo->{BadRef}</pre>\n"; + } + elsif (defined $LogInfo->{BadRef}) + { + print "<pre class='log-note'>Some WineTest results could not be used to detect new errors: $LogInfo->{BadRef}</pre>\n"; + } + foreach my $GroupName (@{$LogInfo->{ErrGroupNames}}) { print "<div class='LogDllName'>$GroupName</div>\n"; diff --git a/testbot/web/WineTestBot.css b/testbot/web/WineTestBot.css index 9a23f5fa8..3fccbd265 100644 --- a/testbot/web/WineTestBot.css +++ b/testbot/web/WineTestBot.css @@ -395,6 +395,7 @@ pre .userdisabled { color: red; } .userdeleted { color: red; }
+.log-note { font-style: italic; color: blue; } .log-info { background-color: #d9ffcc; } .log-skip { color: blue; } .log-todo { color: #d08000; }
_SaveLogErrors() provides more details about the errors than the old _DumpErrors() code did. --- testbot/lib/WineTestBot/LogUtils.pm | 90 +++++++++++++---------------- 1 file changed, 39 insertions(+), 51 deletions(-)
diff --git a/testbot/lib/WineTestBot/LogUtils.pm b/testbot/lib/WineTestBot/LogUtils.pm index 8c2fea41f..88386310a 100644 --- a/testbot/lib/WineTestBot/LogUtils.pm +++ b/testbot/lib/WineTestBot/LogUtils.pm @@ -687,24 +687,6 @@ sub GetLogLabel($) return defined $Label ? sprintf($Label, $Extra) : $LogFileName; }
- -sub _DumpErrors($$) -{ - my ($Label, $LogInfo) = @_; - - print STDERR "$Label: ", join(" ", keys %$LogInfo), "\n"; - my $GroupNames = $LogInfo->{ErrGroupNames}; - print STDERR " Groups=", scalar(@$GroupNames), " [", join(",", @$GroupNames), "]\n"; - my @ErrorKeys = sort keys %{$LogInfo->{Groups}}; - print STDERR " Errors=", scalar(@ErrorKeys), " [", join(",", @ErrorKeys), "]\n"; - foreach my $GroupName (@$GroupNames) - { - print STDERR " [$GroupName]\n"; - my $Group = $LogInfo->{Groups}->{$GroupName}; - print STDERR " [$_]\n" for (@{$Group->{Errors}}); - } -} - sub _AddLogGroup($$;$) { my ($LogInfo, $GroupName, $LineNo) = @_; @@ -855,21 +837,7 @@ sub GetLogErrors($)
Loads the specified log errors file.
-The file contains two types of lines: -* GroupName lines - <GroupName> - Where <GroupName> is a unique string which would typically be the name of a - WineTest dll or program, but may also be empty or be used to specify an - extra group errors. It must not start with a space. - -* Error lines - <Space> <New> <SrcLineNo> <Error> - Where: - - <Space> is a space, as well as the spaces in the line above. - - <New> is either 'n' for new errors, or 'o' for old ones. - - <SrcLineNo> is the 1-base line number of the error in the source log file. - If there is no source line then this should be 0. - - <Error> is the error message. +See _WriteLogErrors() for the format of the errors file.
Returns the errors in the same format as TagNewErrors().
@@ -945,11 +913,11 @@ sub LoadLogErrors($) =pod =over 12
-=item C<_SaveLogErrors()> +=item C<_WriteLogErrors()>
-Saves the LogInfo structure to <LogName>.errors. +Writes the LogInfo structure in text form to the specified file descriptor.
-The file contains lines of the form: +All lines follow are of the following form: <type> <value1> <value2>
The values depend on the <type> of the line. <type> and <value1> must not @@ -980,6 +948,27 @@ different type. =back =cut
+sub _WriteLogErrors($$) +{ + my ($Fh, $LogInfo) = @_; + + foreach my $Name ("BadRef", "NoRef") + { + next if (!defined $LogInfo->{$Name}); + print $Fh "p $Name $LogInfo->{$Name}\n"; + } + foreach my $GroupName (@{$LogInfo->{ErrGroupNames}}) + { + my $Group = $LogInfo->{ErrGroups}->{$GroupName}; + print $Fh "g $Group->{LineNo} $GroupName\n"; + foreach my $Index (0..@{$Group->{Errors}} - 1) + { + my $IsNew = $Group->{IsNew}->[$Index] ? "n" : "o"; + print $Fh "$IsNew $Group->{LineNos}->[$Index] $Group->{Errors}->[$Index]\n"; + } + } +} + sub _SaveLogErrors($) { my ($LogInfo) = @_; @@ -987,21 +976,7 @@ sub _SaveLogErrors($) my $ErrorsPath = "$LogInfo->{LogPath}.errors"; if (open(my $ErrorsFile, ">", $ErrorsPath)) { - foreach my $Name ("BadRef", "NoRef") - { - next if (!defined $LogInfo->{$Name}); - print $ErrorsFile "p $Name $LogInfo->{$Name}\n"; - } - foreach my $GroupName (@{$LogInfo->{ErrGroupNames}}) - { - my $Group = $LogInfo->{ErrGroups}->{$GroupName}; - print $ErrorsFile "g $Group->{LineNo} $GroupName\n"; - foreach my $Index (0..@{$Group->{Errors}} - 1) - { - my $IsNew = $Group->{IsNew}->[$Index] ? "n" : "o"; - print $ErrorsFile "$IsNew $Group->{LineNos}->[$Index] $Group->{Errors}->[$Index]\n"; - } - } + _WriteLogErrors($ErrorsFile, $LogInfo); close($ErrorsFile);
# Set the mtime so Janitor reaps both at the same time @@ -1011,6 +986,19 @@ sub _SaveLogErrors($) return "Could not open '$LogInfo->{LogName}.errors' for writing: $!"; }
+sub _DumpErrors($$) +{ + my ($Label, $LogInfo) = @_; + + print STDERR "$Label:\n"; + foreach my $Key (sort keys %{$LogInfo}) + { + next if ($Key =~ /^(?:ErrGroupNames|ErrGroups|NewCount)$/); + print STDERR "+ $Key $LogInfo->{$Key}\n"; + } + _WriteLogErrors(*STDERR, $LogInfo); +} +
# # New error detection
This avoids parsing the logs twice: once for the consistency checks and a second time to extract the errors. This also simplifies CreateLogErrorsCache() and allows removing _GetLogErrors(). --- testbot/lib/WineTestBot/LogUtils.pm | 282 ++++++++++++---------------- 1 file changed, 118 insertions(+), 164 deletions(-)
diff --git a/testbot/lib/WineTestBot/LogUtils.pm b/testbot/lib/WineTestBot/LogUtils.pm index 88386310a..af57603df 100644 --- a/testbot/lib/WineTestBot/LogUtils.pm +++ b/testbot/lib/WineTestBot/LogUtils.pm @@ -137,6 +137,40 @@ sub GetLogLineCategory($) }
+sub _AddLogGroup($$;$) +{ + my ($LogInfo, $GroupName, $LineNo) = @_; + + # In theory the error group names are all unique. But, just in case, make + # sure we don't overwrite $LogInfo->{ErrGroups}->{$GroupName}. + if (!$LogInfo->{ErrGroups}->{$GroupName}) + { + push @{$LogInfo->{ErrGroupNames}}, $GroupName; + $LogInfo->{ErrGroups}->{$GroupName} = { + LineNo => $LineNo || 0, + LineNos => [], + Errors => [] + }; + } + return $LogInfo->{ErrGroups}->{$GroupName}; +} + +sub _AddLogError($$$;$$) +{ + my ($LogInfo, $ErrGroup, $Line, $LineNo, $IsNew) = @_; + + push @{$ErrGroup->{Errors}}, $Line; + push @{$ErrGroup->{LineNos}}, $LineNo || 0; + $LogInfo->{ErrCount}++; + if ($IsNew) + { + my $ErrIndex = @{$ErrGroup->{Errors}} - 1; + $ErrGroup->{IsNew}->[$ErrIndex] = 1; + $ErrGroup->{NewCount}++; + $LogInfo->{NewCount}++; + } +} + =pod =over 12
@@ -158,6 +192,29 @@ have been updated. =item BadLog Contains an error message if the task log could not be read.
+=item ErrCount +The number of errors if any. + +=item ErrGroupNames +An array containing the names of all the error groups. + += ErrGroups +A hashtable indexed by the error group name. Each entry contains: + +=over + +=item LineNo +The line number of the start of this error group. Note that this is normally +different from the line of the first error in that group. + +=item Errors +An array containing the error messages. + +=item LineNos +An array containing the line number of the error in the log file. + +=back + =back =back =cut @@ -170,6 +227,9 @@ sub ParseTaskLog($) my $LogInfo = { LogName => $LogName, LogPath => $LogPath, + + ErrGroupNames => [], + ErrGroups => {}, };
my $LogFile; @@ -179,10 +239,20 @@ sub ParseTaskLog($) return $LogInfo; }
+ my $ErrGroup; + my $LineNo = 0; $LogInfo->{Type} = "build"; foreach my $Line (<$LogFile>) { - chomp $Line; + $LineNo++; + $Line =~ s/\s*$//; # chomp \r, \n and more + + if (GetLogLineCategory($Line) eq "error") + { + $ErrGroup = _AddLogGroup($LogInfo, "", $LineNo) if (!$ErrGroup); + _AddLogError($LogInfo, $ErrGroup, $Line, $LineNo); + } + if ($Line eq "Task: tests") { $LogInfo->{Type} = "tests"; @@ -401,11 +471,8 @@ The number of test units that timed out. =item Failures The number of failed tests.
-=item Extra -An array containing the extra errors detected during the inconsistency check. - -=item BadLog -Contains an error message if the report could not be read. +=item ErrCount, ErrGroupNames, ErrGroups, BadLog +See ParseTaskLog() for details.
=back =back @@ -425,6 +492,10 @@ sub ParseWineTestReport($$$) TestUnitCount => 0, TimeoutCount => 0, Failures => undef, + + ErrGroupNames => [], + ErrGroups => {}, + Extra => [], };
@@ -435,10 +506,32 @@ sub ParseWineTestReport($$$) return $LogInfo; }
+ my $LineNo = 0; + my ($GroupName, $GroupLineNo) = ("", 0); + my $ErrGroup; my $Cur = _NewCurrentUnit("", ""); foreach my $Line (<$LogFile>) { + $LineNo++; $Cur->{UnitSize} += length($Line); + $Line =~ s/\s*$//; # chomp \r, \n and more + + if (GetReportLineCategory($Line) eq "error") + { + # Make the timeout messages more user-friendly + if ($Line =~ m/^[^:]+:([^:]*):[0-9a-f]+ done (258)/) + { + my $Unit = $1; + $Line = $Unit ne "" ? "$Unit: Timeout" : "Timeout"; + } + + if (!$ErrGroup) + { + $ErrGroup = _AddLogGroup($LogInfo, $GroupName, $GroupLineNo); + } + _AddLogError($LogInfo, $ErrGroup, $Line, $LineNo); + } + if ($Line =~ m%^([_.a-z0-9-]+):([_a-z0-9]*) (start|skipped) (?:-|[/_.a-z0-9-]+) (?:-|[.0-9a-f]+)\r?$%) { my ($Dll, $Unit, $Type) = ($1, $2, $3); @@ -450,6 +543,11 @@ sub ParseWineTestReport($$$)
# Recognize skipped messages in case we need to skip tests in the VMs $Cur->{Rc} = 0 if ($Type eq "skipped"); + + # The next error will be in a new error group + $GroupName = $Dll; + $GroupLineNo = $LineNo; + $ErrGroup = undef; } elsif ($Line =~ /^([_.a-z0-9-]+).c:\d+: Subtest ([_.a-z0-9-]+)\r?$/) { @@ -593,6 +691,17 @@ sub ParseWineTestReport($$$) _CloseTestUnit($LogInfo, $Cur, 1); close($LogFile);
+ # Move the extra errors into their own error group + my $ExtraCount = @{$LogInfo->{Extra}}; + if ($ExtraCount) + { + my $Group = _AddLogGroup($LogInfo, ".Extra"); + $Group->{Errors} = $LogInfo->{Extra}; + my @LineNos = (0) x $ExtraCount; + $Group->{LineNos} = @LineNos; + $LogInfo->{ErrCount} += $ExtraCount; + } + return $LogInfo; }
@@ -687,145 +796,6 @@ sub GetLogLabel($) return defined $Label ? sprintf($Label, $Extra) : $LogFileName; }
-sub _AddLogGroup($$;$) -{ - my ($LogInfo, $GroupName, $LineNo) = @_; - - # In theory the error group names are all unique. But, just in case, make - # sure we don't overwrite $LogInfo->{ErrGroups}->{$GroupName}. - if (!$LogInfo->{ErrGroups}->{$GroupName}) - { - push @{$LogInfo->{ErrGroupNames}}, $GroupName; - $LogInfo->{ErrGroups}->{$GroupName} = { - LineNo => $LineNo || 0, - LineNos => [], - Errors => [] - }; - } - return $LogInfo->{ErrGroups}->{$GroupName}; -} - -sub _AddLogError($$$;$$) -{ - my ($LogInfo, $ErrGroup, $Line, $LineNo, $IsNew) = @_; - - push @{$ErrGroup->{Errors}}, $Line; - push @{$ErrGroup->{LineNos}}, $LineNo || 0; - $LogInfo->{ErrCount}++; - if ($IsNew) - { - my $ErrIndex = @{$ErrGroup->{Errors}} - 1; - $ErrGroup->{IsNew}->[$ErrIndex] = 1; - $ErrGroup->{NewCount}++; - $LogInfo->{NewCount}++; - } -} - -=pod -=over 12 - -=item C<GetLogErrors()> - -Extracts the errors from the specified log file, split by module (for Wine -reports that's per dll / program being tested). - -Returns a hashtable containing: -=over - -=item ErrCount -The number of errors. This is undefined if no log file was found. - -=item ErrGroupNames -An array containing the names of all the error groups. - -=item ErrGroups -A hashtable indexed by the error group name. Each entry contains: - -=over - -=item LineNo -The line number of the start of this error group. Note that this is normally -different from the line of the first error in that group. - -=item Errors -An array containing the error messages. - -=item LineNos -An array containing the line number of the error in the log file. - -=back - -=back -=back -=cut - -sub GetLogErrors($) -{ - my ($LogPath) = @_; - - my ($IsReport, $GetCategory); - if ($LogPath =~ /.report$/) - { - $IsReport = 1; - $GetCategory = &GetReportLineCategory; - } - else - { - $GetCategory = &GetLogLineCategory; - } - - my $LogName = basename($LogPath); - my $LogInfo = { - LogName => $LogName, - LogPath => $LogPath, - - ErrCount => undef, # until we open a log - ErrGroupNames => [], - ErrGroups => {}, - }; - if (open(my $LogFile, "<", $LogPath)) - { - $LogInfo->{ErrCount} ||= 0; - my ($CurrentModule, $ModuleLineNo) = ("", 0); - my $CurrentGroup; - my $LineNo = 0; - foreach my $Line (<$LogFile>) - { - $LineNo++; - $Line =~ s/\s*$//; - if ($IsReport and $Line =~ /^([_.a-z0-9-]+):[_a-z0-9]* start /) - { - $ModuleLineNo = $LineNo; - $CurrentModule = $1; - $CurrentGroup = undef; - next; - } - - next if ($GetCategory->($Line) !~ /error/); - - if ($Line =~ m/^[^:]+:([^:]*):[0-9a-f]+ done (258)/) - { - my $Unit = $1; - $Line = $Unit ne "" ? "$Unit: Timeout" : "Timeout"; - } - if (!$CurrentGroup) - { - $CurrentGroup = _AddLogGroup($LogInfo, $CurrentModule, $ModuleLineNo); - } - _AddLogError($LogInfo, $CurrentGroup, $Line, $LineNo); - } - close($LogFile); - } - elsif (-f $LogPath) - { - my $Group = _AddLogGroup($LogInfo, "TestBot errors"); - _AddLogError($LogInfo, $Group, "Could not open '$LogName' for reading: $!"); - } - - return $LogInfo; -} - - # # Log errors caching [Part 1] # @@ -1066,9 +1036,8 @@ sub _GetLineKey($) # The exact amount of data printed does not change the error $Line =~ s/^([_.a-z0-9-]+:[_a-z0-9]* prints too much data )([0-9]+ bytes)$/$1/;
- # Note: Only the 'done (258)' lines are reported as errors and they are - # modified by GetLogErrors() so that they no longer contain the pid. - # So there is no need to remove the pid from the done lines. + # Note: The 'done (258)' lines are modified by ParseWineTestReport() and + # no longer contain the pid. So they need no further change here.
return $Line; } @@ -1180,22 +1149,7 @@ sub TagNewErrors($$)
sub CreateLogErrorsCache($;$) { - my ($ParsedInfo, $Task) = @_; - - my $LogInfo = GetLogErrors($ParsedInfo->{LogPath}); - - # Store the parser's extra errors into their own group - my $ExtraCount = $ParsedInfo->{Errors} ? @{$ParsedInfo->{Errors}} : 0; - if ($ExtraCount) - { - my $ExtraName = ($LogInfo->{LogName} =~ /.report(?:.errors)?$/) ? "report validation" : "task"; - $ExtraName = ucfirst($ExtraName) ." errors"; - my $Group = _AddLogGroup($LogInfo, $ExtraName); - $Group->{Errors} = $ParsedInfo->{Errors}; - my @LineNos = (0) x $ExtraCount; - $Group->{LineNos} = @LineNos; - $LogInfo->{ErrCount} += $ExtraCount; - } + my ($LogInfo, $Task) = @_;
return $LogInfo->{BadLog} if ($LogInfo->{BadLog});
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($$)
Hi,
While running your changed tests, I think I found new failures. Being a bot and all I'm not very good at pattern recognition, so I might be wrong, but could you please double-check?
Full results can be found at: https://testbot.winehq.org/JobDetails.pl?Key=63186
Your paranoid android.
=== debian10 (build log) ===
Task: Patch failed to apply
=== debian10 (build log) ===
Task: Patch failed to apply
There is no need to keep old logs if they don't contain errors that are already present in the latest one. It cuts down on the number of reports that test results need to be compared to to detect new failures. --- testbot/bin/UpdateTaskLogs | 6 ++ testbot/lib/WineTestBot/LogUtils.pm | 92 ++++++++++++++++++++++++++++- 2 files changed, 95 insertions(+), 3 deletions(-)
diff --git a/testbot/bin/UpdateTaskLogs b/testbot/bin/UpdateTaskLogs index e1746e09a..553bda989 100755 --- a/testbot/bin/UpdateTaskLogs +++ b/testbot/bin/UpdateTaskLogs @@ -197,6 +197,9 @@ sub BuildErrorsCache($$$$;$) return CreateLogErrorsCache($LogInfo, $Task); }
+# The list of files in latest/. This includes files deleted for redundancy. +my %LatestFiles; + sub DoUpdateLatestReport($$$) { my ($Task, $ReportName, $SrcReportPath) = @_; @@ -205,6 +208,8 @@ sub DoUpdateLatestReport($$$) my $SrcIsRef = ($SrcReportPath =~ /-job\d+-/); my $RefReportName = $SrcIsRef ? basename($SrcReportPath) : $Task->GetRefReportName($ReportName); + return 0 if ($LatestFiles{$RefReportName}); + $LatestFiles{$RefReportName} = 1;
my $Rc = 0; my $LatestReportPath = "$DataDir/latest/$RefReportName"; @@ -506,6 +511,7 @@ sub ProcessLatestReports() } else { + $LatestFiles{$RefReportName} = 1; if (!-f "$LatestReportPath.errors") { # Build the missing .errors file diff --git a/testbot/lib/WineTestBot/LogUtils.pm b/testbot/lib/WineTestBot/LogUtils.pm index 037387277..6177c666f 100644 --- a/testbot/lib/WineTestBot/LogUtils.pm +++ b/testbot/lib/WineTestBot/LogUtils.pm @@ -1013,9 +1013,9 @@ sub MarkAllErrorsAsNew($)
=item C<_GetLineKey()>
-This is a helper for TagNewErrors(). It reformats the log lines so they -can meaningfully be compared to the reference log even if line numbers change, -etc. +This is a helper for _DeduplicateLatestReport() and TagNewErrors(). It +reformats the log lines so they can meaningfully be compared to the reference +log even if line numbers change, etc.
=back =cut @@ -1235,6 +1235,89 @@ sub SnapshotLatestReport($$) return @ErrMessages; }
+sub _IsReportRedundant($$) +{ + my ($RefInfo, $LogInfo) = @_; + + return undef if (($RefInfo->{ErrCount} || 0) < ($LogInfo->{ErrCount} || 0)); + return 1 if (($LogInfo->{ErrCount} || 0) == 0); + + foreach my $GroupName (@{$LogInfo->{ErrGroupNames}}) + { + my $LogGroup = $LogInfo->{ErrGroups}->{$GroupName}; + my $RefGroup = $RefInfo->{ErrGroups}->{$GroupName}; + return undef if (!$RefGroup); + + my $Diff = Algorithm::Diff->new($RefGroup->{Errors}, $LogGroup->{Errors}, + { keyGen => &_GetLineKey }); + while ($Diff->Next()) + { + # Same() > 0 => Items(2) > 0 despite there being no new lines + if (!$Diff->Same() and $Diff->Items(2) > 0) + { + # This old log has errors not present in the latest one so keep it + return undef; + } + } + } + + return 1; +} + +sub _DeduplicateLatestReport($$$) +{ + my ($RefReportName, $VMName, $ReportName) = @_; + + my $LatestGlob = "$DataDir/latest/$VMName-job*-$ReportName"; + my @LatestPaths = glob("$LatestGlob"); + return undef if (@LatestPaths <= 1); + + my $RefReportPath = "$DataDir/latest/$RefReportName"; + my $RefInfo = LoadLogErrors($RefReportPath); + return $RefInfo->{BadLog} if (defined $RefInfo->{BadLog}); + + my %LatestAges; + foreach my $LogPath (@LatestPaths) + { + $LatestAges{$LogPath} = -M $LogPath || 0; + } + my $RefAge = $LatestAges{$RefReportPath}; + + my $ErrMessage; + foreach my $LogPath (sort { $LatestAges{$a} <=> $LatestAges{$b} } @LatestPaths) + { + my $LogName = basename($LogPath); + next if ($LogName eq $RefReportName); + next if ($LogName !~ /^(\Q$VMName\E-job[0-9]+-\Q$ReportName\E)$/); + $LogName = $1; # untaint + $LogPath = "$DataDir/latest/$LogName"; + + my $LogInfo = LoadLogErrors($LogPath); + if ($LogInfo->{BadLog}) + { + # Take note of the error but continue to try deduplicating + $ErrMessage = $LogInfo->{BadLog}; + next; + } + if ($RefAge < $LatestAges{$LogPath}) + { + if (_IsReportRedundant($RefInfo, $LogInfo)) + { + unlink $LogPath, "$LogPath.errors"; + } + } + else + { + if (_IsReportRedundant($LogInfo, $RefInfo)) + { + unlink $RefReportPath, "$RefReportPath.errors"; + last; + } + } + } + return $ErrMessage; +} + sub UpdateLatestReport($$$) { my ($Task, $ReportName, $SrcReportPath) = @_; @@ -1255,6 +1338,9 @@ sub UpdateLatestReport($$$) } }
+ my $ErrMessage = _DeduplicateLatestReport($RefReportName, $Task->VM->Name, $ReportName); + push @ErrMessages, $ErrMessage if (defined $ErrMessage); + return @ErrMessages; }
Hi,
While running your changed tests, I think I found new failures. Being a bot and all I'm not very good at pattern recognition, so I might be wrong, but could you please double-check?
Full results can be found at: https://testbot.winehq.org/JobDetails.pl?Key=63187
Your paranoid android.
=== debian10 (build log) ===
Task: Patch failed to apply
=== debian10 (build log) ===
Task: Patch failed to apply
-
Francois Gouget -
Marvin