[PATCH] testbot: Improve the log naming scheme.
Francois Gouget
fgouget at codeweavers.com
Thu Aug 23 03:48:29 CDT 2018
Tasks generate multiple types of logs and reports:
* 32 bit and / or 64 bit test reports(in *.report).
* A list of inconsistencies found in each test report (in err).
* A build or task log (in log).
* A list of task errors (in err).
* When a TestBot error occurs and a task gets restarted, the old task
logs are preserved in *.old files.
So far a task would generate either a single .report file or the log
file which is why the above scheme was sufficient. However this is
bound to change and there are additional constraints to accommodate:
* Running the tests on Wine will generate both a build log and a test
report.
* It may also be desirable to run both the 32 and 64 bit WoW Wine
tests in a single task which would result in it having both a
wow32.report and a wow64.report file in addition to the log one.
* If a task has two test reports the corresponding inconsistencies must
be easily identifiable and kept separate. This also means not mixing
them with the generic task errors.
* WineTest's reference logs are stored in 'vmname_*.log' files where the
variable part is computed differently for the Windows and Wine
reports.
So this patch tweaks the log and report naming scheme to avoid mixing
messages from different sources and to make it easier to match logs and
error files:
* For each log or report called 'xxx', any additional error message
will go to 'xxx.err'. This means any inconsistencies found in
'wow32.report' will go to 'wow32.report.err' and will not be mixed
with those of the 64 bit report.
* Old versions of a log, report or error file called 'xxx' will be
concatenated in 'old_xxx' (and the corresponding old errors would be
in 'old_xxx.err').
* The reference version of a report, log or error file called 'xxx' will
be stored in 'vmname_xxx'.
Signed-off-by: Francois Gouget <fgouget at codeweavers.com>
---
testbot/bin/Engine.pl | 15 ++++++++
testbot/bin/Janitor.pl | 2 +-
testbot/bin/WineRunBuild.pl | 4 +--
testbot/bin/WineRunReconfig.pl | 4 +--
testbot/bin/WineRunTask.pl | 27 ++++++++-------
testbot/bin/WineRunWineTest.pl | 32 ++++++++++-------
testbot/bin/WineSendLog.pl | 22 ++++++------
testbot/lib/WineTestBot/LogUtils.pm | 54 ++++++++++++++++++++++++++---
testbot/lib/WineTestBot/Tasks.pm | 16 +++++----
testbot/web/JobDetails.pl | 4 +--
testbot/web/Munin.pl | 2 +-
11 files changed, 127 insertions(+), 55 deletions(-)
diff --git a/testbot/bin/Engine.pl b/testbot/bin/Engine.pl
index 4478d479b..79b25fac0 100755
--- a/testbot/bin/Engine.pl
+++ b/testbot/bin/Engine.pl
@@ -51,6 +51,7 @@ use WineTestBot::Engine::Notify;
use WineTestBot::Engine::Scheduler;
use WineTestBot::Jobs;
use WineTestBot::Log;
+use WineTestBot::LogUtils; # FIXME Temporary, for the log renaming
use WineTestBot::Patches;
use WineTestBot::PendingPatchSets;
use WineTestBot::RecordGroups;
@@ -102,6 +103,20 @@ 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/bin/Janitor.pl b/testbot/bin/Janitor.pl
index 18bbc3dea..120845121 100755
--- a/testbot/bin/Janitor.pl
+++ b/testbot/bin/Janitor.pl
@@ -311,7 +311,7 @@ if (opendir(my $dh, "$DataDir/latest"))
{
next if ($Entry eq "." or $Entry eq "..");
- if ($Entry =~ /^(.*)_[a-z0-9]+\.(?:err|log)$/)
+ if ($Entry =~ /^(.*)_[a-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/WineRunBuild.pl b/testbot/bin/WineRunBuild.pl
index b246164e5..cca96b92a 100755
--- a/testbot/bin/WineRunBuild.pl
+++ b/testbot/bin/WineRunBuild.pl
@@ -183,14 +183,14 @@ sub LogTaskError($)
Debug("$Name0:error: ", $ErrMessage);
my $OldUMask = umask(002);
- if (open(my $ErrFile, ">>", "$TaskDir/err"))
+ if (open(my $ErrFile, ">>", "$TaskDir/log.err"))
{
print $ErrFile $ErrMessage;
close($ErrFile);
}
else
{
- Error "Unable to open 'err' for writing: $!\n";
+ Error "Unable to open 'log.err' for writing: $!\n";
}
umask($OldUMask);
}
diff --git a/testbot/bin/WineRunReconfig.pl b/testbot/bin/WineRunReconfig.pl
index 3fec02b89..19f5ed467 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/err"))
+ if (open(my $ErrFile, ">>", "$TaskDir/log.err"))
{
print $ErrFile $ErrMessage;
close($ErrFile);
}
else
{
- Error "Unable to open 'err' for writing: $!\n";
+ Error "Unable to open 'log.err' for writing: $!\n";
}
umask($OldUMask);
}
diff --git a/testbot/bin/WineRunTask.pl b/testbot/bin/WineRunTask.pl
index c602979b1..5ff3fc4a5 100755
--- a/testbot/bin/WineRunTask.pl
+++ b/testbot/bin/WineRunTask.pl
@@ -214,14 +214,14 @@ sub LogTaskError($)
Debug("$Name0:error: ", $ErrMessage);
my $OldUMask = umask(002);
- if (open(my $ErrFile, ">>", "$TaskDir/err"))
+ if (open(my $ErrFile, ">>", "$TaskDir/log.err"))
{
print $ErrFile $ErrMessage;
close($ErrFile);
}
else
{
- Error "Unable to open 'err' for writing: $!\n";
+ Error "Unable to open 'log.err' for writing: $!\n";
}
umask($OldUMask);
}
@@ -296,15 +296,15 @@ sub WrapUpAndExit($;$$$)
# Keep the old report if the new one is missing
if (-f "$TaskDir/$RptFileName" and !-z "$TaskDir/$RptFileName")
{
- # Update the reference VM suite results for WineSendLog.pl
- my $LatestBaseName = join("", "$DataDir/latest/", $Task->VM->Name, "_",
- $Step->FileType eq "exe64" ? "64" : "32");
- unlink("$LatestBaseName.log");
- link("$TaskDir/$RptFileName", "$LatestBaseName.log");
- unlink("$LatestBaseName.err");
- if (-f "$TaskDir/err" and !-z "$TaskDir/err")
+ # 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/err", "$LatestBaseName.err");
+ link("$TaskDir/$RptFileName.err", "$RefReport.err");
}
}
}
@@ -541,9 +541,12 @@ if ($TA->GetFile($RptFileName, "$TaskDir/$RptFileName"))
{
# $LogFailures can legitimately be undefined in case of a timeout
$TaskFailures += $LogFailures || 0;
- foreach my $Error (@$LogErrors)
+ if (@$LogErrors and open(my $Log, ">", "$TaskDir/$RptFileName.err"))
{
- LogTaskError("$Error\n");
+ # Save the extra errors detected by ParseWineTestReport() in
+ # $RptFileName.err (see WineRunWineTest.pl).
+ print $Log "$_\n" for (@$LogErrors);
+ close($Log);
}
}
}
diff --git a/testbot/bin/WineRunWineTest.pl b/testbot/bin/WineRunWineTest.pl
index 2552a7c9d..0363a26b3 100755
--- a/testbot/bin/WineRunWineTest.pl
+++ b/testbot/bin/WineRunWineTest.pl
@@ -209,14 +209,14 @@ sub LogTaskError($)
my ($ErrMessage) = @_;
Debug("$Name0:error: ", $ErrMessage);
- if (open(my $ErrFile, ">>", "$TaskDir/err"))
+ if (open(my $ErrFile, ">>", "$TaskDir/log.err"))
{
print $ErrFile $ErrMessage;
close($ErrFile);
}
else
{
- Error "Unable to open 'err' for writing: $!\n";
+ Error "Unable to open 'log.err' for writing: $!\n";
}
}
@@ -295,15 +295,15 @@ sub WrapUpAndExit($;$$$)
my $RptFileName = "$Build.report";
if (-f "$TaskDir/$RptFileName" and !-z "$TaskDir/$RptFileName")
{
- # Update the reference VM suite results for WineSendLog.pl
- my $LatestBaseName = join("", "$DataDir/latest/", $Task->VM->Name,
- "_$Build");
- unlink("$LatestBaseName.log");
- link("$TaskDir/$RptFileName", "$LatestBaseName.log");
- unlink("$LatestBaseName.err");
- if (-f "$TaskDir/err" and !-z "$TaskDir/err")
+ # 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/err", "$LatestBaseName.err");
+ link("$TaskDir/$RptFileName.err", "$RefReport.err");
}
}
}
@@ -560,9 +560,17 @@ if ($Step->Type ne "build")
{
# $LogFailures can legitimately be undefined in case of a timeout
$TaskFailures += $LogFailures || 0;
- foreach my $Error (@$LogErrors)
+ if (@$LogErrors and open(my $Log, ">", "$TaskDir/$RptFileName.err"))
{
- LogTaskError("$Error\n");
+ # 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 (@$LogErrors);
+ close($Log);
}
}
}
diff --git a/testbot/bin/WineSendLog.pl b/testbot/bin/WineSendLog.pl
index 368d830de..2127eadb7 100755
--- a/testbot/bin/WineSendLog.pl
+++ b/testbot/bin/WineSendLog.pl
@@ -327,7 +327,7 @@ EOF
}
close LOGFILE;
- if (open ERRFILE, "<$TaskDir/err")
+ if (open ERRFILE, "<$TaskDir/log.err")
{
my $First = 1;
while (defined($Line = <ERRFILE>))
@@ -365,7 +365,7 @@ EOF
push @FailureKeys, $Key;
}
}
- elsif (open ERRFILE, "<$TaskDir/err")
+ elsif (open ERRFILE, "<$TaskDir/log.err")
{
my $HasErrEntries = !1;
my $Line;
@@ -419,7 +419,7 @@ EOF
close LOGFILE;
}
- if (open ERRFILE, "<$TaskDir/err")
+ if (open ERRFILE, "<$TaskDir/log.err")
{
my $Line;
while (defined($Line = <ERRFILE>))
@@ -456,12 +456,12 @@ EOF
my $StepTask = $StepsTasks->GetItem($Key);
my $TaskDir = $StepTask->GetTaskDir();
- my ($BotFailure, $MessagesFromErr) = CheckErrLog("$TaskDir/err");
+ my ($BotFailure, $MessagesFromErr) = CheckErrLog("$TaskDir/log.err");
if ($BotFailure)
{
# TestBot errors are not the developer's fault and prevent us from doing
# any meaningful analysis. So skip.
- Error "A TestBot error was found in $TaskDir/err\n";
+ Error "A TestBot error was found in $TaskDir/log.err\n";
next;
}
@@ -470,9 +470,7 @@ EOF
my $LogName = $LogFiles->[0] || "log";
if ($LogName =~ /\.report$/)
{
- $StepTask->FileName =~ m/^(.*)_test(64)?\.exe$/;
- my ($BaseName, $Bits) = ($1, $2 || "32");
- my $LatestName = "$DataDir/latest/" . $StepTask->VM->Name . "_$Bits";
+ my $LatestName = "$DataDir/latest/". $StepTask->VM->Name ."_$LogName";
my ($LatestBotFailure, $Dummy) = CheckErrLog("$LatestName.err");
if (! $LatestBotFailure)
{
@@ -481,13 +479,15 @@ EOF
# Filter out failures that happened in the full test suite:
# the test suite is run against code which is already in Wine
# so any failure it reported is not caused by this patch.
- $MessagesFromLog = CompareLogs("$LatestName.log", "$TaskDir/$LogName",
+ $StepTask->FileName =~ m/^(.*)_test/;
+ my $BaseName = $1;
+ $MessagesFromLog = CompareLogs($LatestName, "$TaskDir/$LogName",
$BaseName, $StepTask->CmdLineArg);
}
}
else
{
- Error "BotFailure found in ${LatestName}.err\n";
+ Error "BotFailure found in $LatestName.err\n";
}
}
elsif (open(my $LogFile, "<", "$TaskDir/$LogName"))
@@ -596,7 +596,7 @@ EOF
close($logfile);
}
- if (open(my $errfile, "<", "$TaskDir/err"))
+ if (open(my $errfile, "<", "$TaskDir/log.err"))
{
my $Line;
while (defined($Line = <$errfile>))
diff --git a/testbot/lib/WineTestBot/LogUtils.pm b/testbot/lib/WineTestBot/LogUtils.pm
index e05afb605..6f7cef5e8 100644
--- a/testbot/lib/WineTestBot/LogUtils.pm
+++ b/testbot/lib/WineTestBot/LogUtils.pm
@@ -29,6 +29,7 @@ WineTestBot::LogUtils - Provides functions to parse task logs
use Exporter 'import';
our @EXPORT = qw(GetLogFileNames GetLogLabel
GetLogLineCategory GetReportLineCategory
+ RenameReferenceLogs RenameTaskLogs
ParseTaskLog ParseWineTestReport);
use File::Basename;
@@ -485,6 +486,49 @@ 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
@@ -503,8 +547,8 @@ sub GetLogFileNames($;$)
my @Candidates = ("exe32.report", "exe64.report",
"win32.report", "wow32.report", "wow64.report",
- "log", "err");
- push @Candidates, "log.old", "err.old" if ($IncludeOld);
+ "log", "log.err");
+ push @Candidates, "old_log", "old_log.err" if ($IncludeOld);
my @Logs;
foreach my $FileName (@Candidates)
@@ -521,9 +565,9 @@ my %_LogFileLabels = (
"wow32.report" => "32 bit WoW Wine report",
"wow64.report" => "64 bit Wow Wine report",
"log" => "task log",
- "err" => "task errors",
- "log.old" => "old logs",
- "err.old" => "old task errors",
+ "log.err" => "task errors",
+ "old_log" => "old logs",
+ "old_log.err" => "old task errors",
);
=pod
diff --git a/testbot/lib/WineTestBot/Tasks.pm b/testbot/lib/WineTestBot/Tasks.pm
index 70b620544..084784a3b 100644
--- a/testbot/lib/WineTestBot/Tasks.pm
+++ b/testbot/lib/WineTestBot/Tasks.pm
@@ -117,13 +117,15 @@ sub _SetupTask($$)
if (-d $Dir)
{
mkpath("$Dir.new", 0, 0775);
- rename "$Dir/log.old", "$Dir.new/log.old" if (-f "$Dir/log.old");
- rename "$Dir/err.old", "$Dir.new/err.old" if (-f "$Dir/err.old");
- foreach my $Filename ("log", "err")
+ foreach my $Filename ("log", "log.err")
{
+ if (-f "$Dir/old_$Filename")
+ {
+ rename "$Dir/old_$Filename", "$Dir.new/old_$Filename";
+ }
if (open(my $Src, "<", "$Dir/$Filename"))
{
- if (open(my $Dst, ">>", "$Dir.new/$Filename.old"))
+ if (open(my $Dst, ">>", "$Dir.new/old_$Filename"))
{
print $Dst "----- Run ", ($self->TestFailures || 0), " $Filename\n";
while (my $Line = <$Src>)
@@ -142,7 +144,7 @@ sub _SetupTask($$)
# Capture Perl errors in the task's generic error log
my $TaskDir = $self->CreateDir();
- if (open(STDERR, ">>", "$TaskDir/err"))
+ if (open(STDERR, ">>", "$TaskDir/log.err"))
{
# Make sure stderr still flushes after each print
my $tmp=select(STDERR);
@@ -152,7 +154,7 @@ sub _SetupTask($$)
else
{
require WineTestBot::Log;
- WineTestBot::Log::LogMsg("unable to redirect stderr to '$TaskDir/err': $!\n");
+ WineTestBot::Log::LogMsg("unable to redirect stderr to '$TaskDir/log.err': $!\n");
}
}
@@ -215,7 +217,7 @@ sub UpdateStatus($$)
my ($JobId, $StepNo, $TaskNo) = @{$self->GetMasterKey()};
my $OldUMask = umask(002);
my $TaskDir = $self->CreateDir();
- if (open TASKLOG, ">>$TaskDir/err")
+ if (open TASKLOG, ">>$TaskDir/log.err")
{
print TASKLOG "TestBot process got stuck or died unexpectedly\n";
close TASKLOG;
diff --git a/testbot/web/JobDetails.pl b/testbot/web/JobDetails.pl
index ee4e53930..e1fe20f18 100644
--- a/testbot/web/JobDetails.pl
+++ b/testbot/web/JobDetails.pl
@@ -393,7 +393,7 @@ sub GenerateBody($)
print "</div>\n";
my $LogName = $MoreInfo->{Full} || $MoreInfo->{Logs}->[0] || "log";
- my $ErrName = $LogName eq "log.old" ? "err.old" : "err";
+ my $ErrName = "$LogName.err";
my ($EmptyDiag, $LogFirst) = (undef, 1);
if (open(my $LogFile, "<", "$TaskDir/$LogName"))
@@ -472,7 +472,7 @@ sub GenerateBody($)
if (!$LogFirst)
{
print "<div class='HrTitle'>".
- ($ErrName eq "err" ? "Other errors" : "Old errors") .
+ ($ErrName =~ /^old_/ ? "Old errors" : "Extra errors") .
"<div class='HrLine'></div></div>\n";
}
print "<pre><code>";
diff --git a/testbot/web/Munin.pl b/testbot/web/Munin.pl
index 840d912f1..35160a159 100755
--- a/testbot/web/Munin.pl
+++ b/testbot/web/Munin.pl
@@ -441,7 +441,7 @@ sub GetOutput($)
foreach my $VM (@SortedVMs)
{
next if ($VM->Type ne "win32" and $VM->Type ne "win64");
- my $Filename = "$DataDir/latest/". $VM->Name ."_$Bitness.log";
+ my $Filename = "$DataDir/latest/". $VM->Name ."_exe$Bitness.report";
my $Size = -s $Filename;
if (defined $Size)
{
--
2.18.0
More information about the wine-devel
mailing list