From: Francois Gouget Subject: [23/25] testbot/LogUtils: Return the errors in the Parse*() $LogInfo structure. Message-Id: <743552dd117de0ebd6ba2b6e5ad6dad67c7d49fc.1579000229.git.fgouget@codeweavers.com> Date: Tue, 14 Jan 2020 16:43:24 +0100 (CET) In-Reply-To: References: 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 - -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}); -- 2.20.1