Skip to content

Commit

Permalink
Merge pull request #18804 from edsantiago/logformatter_handle_levels
Browse files Browse the repository at this point in the history 
logformatter: better recognition of test names
  • Loading branch information
@openshift-merge-robot
openshift-merge-robot authored Jun 7, 2023
2 parents 76f4571 + 137c8ef commit 82caa10
Show file tree
Hide file tree
Showing 3 changed files with 67 additions and 19 deletions.
74 changes: 60 additions & 14 deletions contrib/cirrus/logformatter
View file
Original file line number Diff line number Diff line change
Expand Up @@ -234,6 +234,7 @@ END_HTML
my $cirrus_task; # Cirrus task number, used for linking
my $git_commit; # git SHA, used for linking to source files
my $subtest_status; # pass, fail, skip, flake - for each subtest
my $subtest_name; # assembled from two or more Describe()/It()s
my $in_failure; # binary flag: are we in an error dump?
my $in_timing; # binary flag: are we in the timing section?
my $after_divider = 999; # Count of lines after seeing '-----'
Expand Down Expand Up @@ -475,6 +476,10 @@ END_HTML
lc($block);
$line = "$indent&rarr; Enter [<b>$block</b>]$line";
$print_line->();

# machine tests, run without -p, don't have a blank line
# separating headers from logs; but this works just fine.
$after_divider = 999;
}
else {
# Can be a div within a div
Expand Down Expand Up @@ -564,6 +569,7 @@ END_HTML
}
$after_divider = 1;
$subtest_status = 'passed'; # until proven otherwise
$subtest_name = '';

print { $out_fh } "</pre>\n<hr />\n<pre>\n";
# Always show timestamp at start of each new test
Expand Down Expand Up @@ -622,16 +628,44 @@ END_HTML
# FIXME: gray out entire block if it's skipped?
}

# Three lines after each divider (four, if ginkgo is run with "-p",
# see above), there's a test name. Make it an anchor so we can link
# to it later.
if ($after_divider == 3) {
# Sigh. There is no actual marker. Assume that anything with
## two leading spaces then alpha or hyphen (not slashes) is
## a test name.
if ($line =~ /^ (\[It\]\s*)?([a-zA-Z-].*\S)/) {
my $id = make_id($2, 'anchor');

# Test name recognition, linking, and highlighting.
# The lines after each divider, until the first empty line, are
# one or more test name specifiers, a nested level of Description()
# and It() names:
# -----------
# * blah [N seconds] <<<---- only when run with -p
# Podman foo
# /var/tmp/go/src/path/to/this/file.go:lineno
# podman bar
# /var/tmp/go/src/path/to/this/file.go:lineno
#
# There may even be three nested levels (e.g., quadlet). We
# look for non-path lines and assemble them -- "Podman foo",
# " Podman foo podman bar" -- giving each an HTML anchor
# to which we can link from the summary section at bottom.
if ($after_divider <= 10) { # Assume no more than ~5 levels
if ($line =~ /^\s*$/) {
# Stop looking when we get to the blank line
$after_divider = 999;
}
elsif ($line =~ /span.*class=.boring./) {
# Sigh. Bindings tests run without -p, and have no blank line
# separator. Use the first command to signal real logs.
# FIXME: can we solve this with ReportBeforeEach()?
# https://onsi.github.io/ginkgo/#generating-reports-programmatically
$after_divider = 999;
}
elsif ($line =~ m!^\s*/\S+!) {
# Source code path: skip
}
elsif ($line =~ /<b/) {
# Already-formatted line (like the "N seconds" one): skip
}
elsif ($line =~ /^\s*(\[It\]\s*)?(.*)/) {
# Test description or name! Remove the "It", and make an anchor
$subtest_name .= " " if $subtest_name;
$subtest_name .= $2;
my $id = make_id($subtest_name, 'anchor');
$line = "<a name='t--$id'><h2 class=\"log-$subtest_status\">$line</h2></a>";
}
}
Expand All @@ -643,10 +677,10 @@ END_HTML
$line =~ s!^(\s*)(\[It\]\s+.*)!$1<span class="testname">$2</span>!;

# Failure name corresponds to a previously-seen block.
# 1 2 2 3 3 14 4
if ($line =~ /^(\s*\[(FAIL|PANIC!)\] .* \[(It|BeforeEach|AfterEach)\] )([A-Za-z-].*)/) {
my ($lhs, $type, $ginkgo_fluff, $testname) = ($1, $2, $3, $4);
my $id = make_id($testname, 'link');
# 1 2 2 3 3 4 4 15 5
if ($line =~ /^(\s*\[(FAIL|PANIC!)\] (.*) \[(It|BeforeEach|AfterEach)\] )([A-Za-z-].*)/) {
my ($lhs, $type, $desc, $ginkgo_fluff, $testname) = ($1, $2, $3, $4, $5);
my $id = make_id("$desc $testname", 'link');

$line = "<span class=\"log-error\">$lhs<a href='#t--$id'>$testname</a></span>";
}
Expand Down Expand Up @@ -812,6 +846,18 @@ END_SYNOPSIS
_a("{CIRRUS_BUILD_ID}", "https://cirrus-ci.com/build/{CIRRUS_BUILD_ID}"),
_a("{CIRRUS_TASK_ID}", "https://cirrus-ci.com/task/{CIRRUS_TASK_ID}")));

# Logs: link to original (unformatted) log; journal; and, if remote, server
my @logs = (
_a("main", "https://api.cirrus-ci.com/v1/task/{CIRRUS_TASK_ID}/logs/main.log"),
_a("journal", "https://api.cirrus-ci.com/v1/task/{CIRRUS_TASK_ID}/logs/journal.log"),
);

# System tests are single-threaded, and have a server log available
if ($test_name =~ /sys\s+remote\s/) {
push @logs, _a("remote server", "https://api.cirrus-ci.com/v1/artifact/task/{CIRRUS_TASK_ID}/server_log/podman-server.log");
}
$s .= _tr("Logs", join(" / ", @logs));

# BASE_SHA can tell us if our parent includes--or doesn't--a purported
# fix for a flake. Note that "commits", plural, links to a git history
# listing; if we used "commit", singular, that would be less useful.
Expand Down
10 changes: 6 additions & 4 deletions contrib/cirrus/logformatter.t
View file
Original file line number Diff line number Diff line change
Expand Up @@ -34,6 +34,8 @@ while (my $line = <DATA>) {
$context = 'expect';
}
elsif (@tests && $line) {
# Handles trailing spaces in log, because we can't have actual ones.
$line =~ s/\&TRAILINGSPACE;/ /g;
push @{ $tests[-1]{$context} }, $line;
}
}
Expand Down Expand Up @@ -189,7 +191,7 @@ ok 4 blah
[+0271s] /var/tmp/go/src/github.com/containers/podman/test/e2e/restart_test.go:14
[+0271s] podman restart non-stop container with short timeout
[+0271s] /var/tmp/go/src/github.com/containers/podman/test/e2e/restart_test.go:148
[+0271s]
[+0271s]&TRAILINGSPACE;
[+0271s] Timeline >>
[+0271s] > Enter [BeforeEach] Podman restart - /var/tmp/go/src/github.com/containers/podman/test/e2e/restart_test.go:21 @ 04/17/23 10:00:28.653
[+0271s] < Exit [BeforeEach] Podman restart - /var/tmp/go/src/github.com/containers/podman/test/e2e/restart_test.go:21 @ 04/17/23 10:00:28.653 (0s)
Expand Down Expand Up @@ -217,11 +219,11 @@ ok 4 blah
<hr />
<pre>
<span class="timestamp">[+0271s] </span>• <b>[3.327 seconds]</b>
<span class="timestamp"> </span>Podman restart
<span class="timestamp"> </span><a name='t--Podman-restart--1'><h2 class="log-passed">Podman restart</h2></a>
<span class="timestamp"> </span>/var/tmp/go/src/github.com<a class="codelink" href='https://github.com/containers/podman/blob/074143b0fac7af72cd92048d27931a92fe745084/test/e2e/restart_test.go#L14'>/containers/podman/test/e2e/restart_test.go:14</a>
<span class="timestamp"> </span><a name='t--podman-restart-non-stop-container-with-short-timeout--1'><h2 class="log-passed"> podman restart non-stop container with short timeout</h2></a>
<span class="timestamp"> </span><a name='t--Podman-restart-podman-restart-non-stop-container-with-short-timeout--1'><h2 class="log-passed"> podman restart non-stop container with short timeout</h2></a>
<span class="timestamp"> </span> /var/tmp/go/src/github.com<a class="codelink" href='https://github.com/containers/podman/blob/074143b0fac7af72cd92048d27931a92fe745084/test/e2e/restart_test.go#L148'>/containers/podman/test/e2e/restart_test.go:148</a>
[+0271s]
<span class="timestamp"> </span>
<span class="timestamp"> </span> Timeline &gt;&gt;
<div class="ginkgo-timeline ginkgo-beforeeach"><span class="timestamp"> </span> &rarr; Enter [<b>BeforeEach</b>] Podman restart - /var/tmp/go/src/github.com<a class="codelink" href='https://github.com/containers/podman/blob/074143b0fac7af72cd92048d27931a92fe745084/test/e2e/restart_test.go#L21'>/containers/podman/test/e2e/restart_test.go:21</a> @ 04/17/23 10:00:28.653
<span class="timestamp"> </span> &larr; Exit [BeforeEach] Podman restart - /var/tmp/go/src/github.com<a class="codelink" href='https://github.com/containers/podman/blob/074143b0fac7af72cd92048d27931a92fe745084/test/e2e/restart_test.go#L21'>/containers/podman/test/e2e/restart_test.go:21</a> @ 04/17/23 10:00:28.653 (0s)
Expand Down
2 changes: 1 addition & 1 deletion test/e2e/common_test.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -462,7 +462,7 @@ func (p *PodmanTestIntegration) InspectContainer(name string) []define.InspectCo
}

func processTestResult(r SpecReport) {
tr := testResult{length: r.RunTime.Seconds(), name: r.LeafNodeText}
tr := testResult{length: r.RunTime.Seconds(), name: r.FullText()}
testResultsMutex.Lock()
testResults = append(testResults, tr)
testResultsMutex.Unlock()
Expand Down

0 comments on commit 82caa10

Please sign in to comment.