Timeouts can get reported in many different ways depending on whether they are detected by TestLauncher, the WineRun* script or the Engine. That makes a simple error matching or grep impossible. So provide specific support for checking that a task timed out.
Signed-off-by: Francois Gouget fgouget@codeweavers.com --- testbot/tests/TestWTBS | 94 +++++++++++++++++++++++++++++++++--------- 1 file changed, 74 insertions(+), 20 deletions(-)
diff --git a/testbot/tests/TestWTBS b/testbot/tests/TestWTBS index 67b1c8f96..6f78406ad 100755 --- a/testbot/tests/TestWTBS +++ b/testbot/tests/TestWTBS @@ -402,7 +402,10 @@ sub LoadTestInfo($) my $Status = ($TestInfo->{job}->{Status} ne 'completed' or $TestInfo->{win32}->{TestFailures} or $TestInfo->{win64}->{TestFailures} or - $TestInfo->{wine}->{TestFailures}) ? "Failed" : "OK"; + $TestInfo->{wine}->{TestFailures} or + $TestInfo->{win32}->{HasTimeout} or + $TestInfo->{win64}->{HasTimeout} or + $TestInfo->{wine}->{HasTimeout}) ? "Failed" : "OK"; SetDefault($TestInfo, "webpatch", "Status", $Status); }
@@ -555,6 +558,16 @@ sub IsMailingListJob($) return $Job->Remarks =~ /^[\Q$PatchesMailingList\E] /; }
+sub IsTimeoutError($$) +{ + my ($GroupName, $Error) = @_; + + return (($GroupName ne "" and # Test dll or Report validation errors + $Error =~ /^[_a-z0-9]+: Timeout$/) or # Test unit + ($GroupName eq "" and # testbot.log case + $Error eq "The task timed out")); +} + =pod =item <tasks.(report|log|testbot).groupname>
@@ -584,17 +597,19 @@ directives, win32 will not inherit anything from the win category.
=cut
-sub CheckLogErrors($$$) +sub CheckLogErrors($$$$) { - my ($LogInfo, $RefInfo, $LogKey) = @_; + my ($LogInfo, $RefInfo, $LogKey, $IgnoreTimeouts) = @_;
+ my $HasTimeout; foreach my $GroupName (@{$LogInfo->{ErrGroupNames}}) { my $LogGroup = $LogInfo->{ErrGroups}->{$GroupName}; - - my $RefGroup = $RefInfo->{ErrGroups}->{$GroupName}; + # Prevent $RefInfo from springing into existence + my $RefGroup = $RefInfo ? $RefInfo->{ErrGroups}->{$GroupName} : undef; if ($RefGroup) { + # Match the log errors to the expected errors for this group my $Diff = Algorithm::Diff->new($LogGroup->{Errors}, $RefGroup->{Errors}, { keyGen => &WineTestBot::LogUtils::_GetLineKey }); my ($LogIndex, $RefIndex) = (0, 0); @@ -613,6 +628,12 @@ sub CheckLogErrors($$$) foreach (1..$ExtraCount) { next if (!$LogGroup->{IsNew}->[$LogIndex]); + if ($IgnoreTimeouts and + IsTimeoutError($GroupName, $LogGroup->{Errors}->[$LogIndex])) + { + next; + } + fail("$LogKey has an unexpected new error in $GroupName: $LogGroup->{Errors}->[$LogIndex]"); $LogIndex++; } @@ -626,27 +647,39 @@ sub CheckLogErrors($$$) } } } - else + + # Check for timeouts and new errors if no error was expected for that group + foreach my $ErrIndex (0..@{$LogGroup->{Errors}} - 1) { - # Check that the log's extra errors are old errors - foreach my $ErrIndex (0..@{$LogGroup->{Errors}} - 1) + if (IsTimeoutError($GroupName, $LogGroup->{Errors}->[$ErrIndex])) + { + $HasTimeout = 1; + next if ($IgnoreTimeouts); # ignore expected timeouts + } + if ($RefInfo and !$RefGroup and $LogGroup->{IsNew}->[$ErrIndex]) { - next if (!$LogGroup->{IsNew}->[$ErrIndex]); fail("$LogKey has an unexpected new error in $GroupName: $LogGroup->{Errors}->[$ErrIndex]"); } } } - foreach my $GroupName (@{$RefInfo->{ErrGroupNames}}) - { - my $LogGroup = $LogInfo->{ErrGroups}->{$GroupName}; - next if ($LogGroup);
- my $RefGroup = $RefInfo->{ErrGroups}->{$GroupName}; - foreach my $Error (@{$RefGroup->{Errors}}) + if ($RefInfo) + { + # Check for groups missing from the log file + foreach my $GroupName (@{$RefInfo->{ErrGroupNames}}) { - fail("$LogKey is missing an error in $GroupName: $Error"); + my $LogGroup = $LogInfo->{ErrGroups}->{$GroupName}; + next if ($LogGroup); + + my $RefGroup = $RefInfo->{ErrGroups}->{$GroupName}; + foreach my $Error (@{$RefGroup->{Errors}}) + { + fail("$LogKey is missing an error in $GroupName: $Error"); + } } } + + return $HasTimeout; }
sub GrepFile($$$$;$) @@ -716,6 +749,18 @@ By default the Status field should be 'completed'. Checks the value of the task's TestFailures field. By default the TestFailures field is not checked.
+=item <tasks.HasTimeout> + +When true verifies that the task timed out. +This also disables reporting timeout errors as unexpected errors. + +Use this instead of looking for a specific error in the report because +timeouts can get reported in many different ways depending whether they are +detected by TestLauncher, the WineRun* script or the Engine. It can also +depend on whether the test was the last one run by the task (in the Wine case). +By default this check is skipped and timeout errors are reported like any +other unexpected error. + =item <tasks.(report|log|testbot).Grep> =item <tasks.(report|log|testbot).GrepV>
@@ -754,7 +799,10 @@ sub CheckTask($$$$) $TestUnits->{$TaskType}->{"*skipped*"} = 1; }
- my ($ReportCount, $NewFailures) = (0, 0); + my $CheckTimeouts = ($Task->Status eq "completed" and + CheckValue($TaskInfo->{HasTimeout})); + + my ($ReportCount, $TimeoutCount, $NewFailures) = (0, 0, 0); foreach my $LogName (@{GetLogFileNames($Task->GetDir())}) { my $LogPath = $Task->GetDir() ."/$LogName"; @@ -777,13 +825,19 @@ sub CheckTask($$$$) $LogType = "testbot"; }
- if ($TaskInfo->{"$LogType.errors"}) + if ($TaskInfo->{"$LogType.errors"} or $CheckTimeouts) { - CheckLogErrors($LogInfo, $TaskInfo->{"$LogType.errors"}, - TaskKeyStr($Task) ."/$LogName"); + my $HasTimeout = CheckLogErrors($LogInfo, $TaskInfo->{"$LogType.errors"}, + TaskKeyStr($Task) ."/$LogName", + $TaskInfo->{HasTimeout}); + $TimeoutCount++ if ($HasTimeout); } GrepTaskLog($Task, $LogName, $TaskInfo, "$LogType."); } + if ($CheckTimeouts) + { + ok($TimeoutCount >= $ReportCount, "Expecting 1+ timeout per report: $TimeoutCount timeouts, $ReportCount reports"); + } if ($Task->Status eq "completed" and CheckValue($TaskInfo->{TestFailures})) { # Scale the expected TestFailures count with the number of times the test