opensource/podman
1
0
Fork 0
mirror of https://github.com/containers/podman.git synced 2025-07-14 01:50:02 +08:00
Code Issues Packages Projects Releases Wiki Activity

WIP: logformatter: handle ginkgo v2 logs

Browse Source 
Checkpoint as of Thursday April 13 afternoon.

Please do not merge with this; the .t file (tests) needs to
be updated, and there are probably many more fixes/improvements
I still need to make.

Signed-off-by: Ed Santiago <santiago@redhat.com>
This commit is contained in:
Ed Santiago
2023-04-13 09:45:48 -06:00
committed by Paul Holzinger
parent b3424f3708
commit 914ff01f94
2 changed files with 238 additions and 174 deletions
Download Patch File Download Diff File Expand all files Collapse all files

169
contrib/cirrus/logformatter
View File

@ -18,7 +18,7 @@ use warnings;
(our $ME = $0) =~ s|.*/||; (our $ME = $0) =~ s|.*/||;
our $VERSION = '0.2'; our $VERSION = '0.3';
# Autoflush stdout # Autoflush stdout
$| = 1; $| = 1;
@ -46,8 +46,12 @@ table.synopsis { border: none; border-collapse: collapse; margin-left: 2em; marg
.log-debug { color: #999; } .log-debug { color: #999; }
.log-info { color: #333; } .log-info { color: #333; }
.log-warning { color: #f60; } .log-warning { color: #f60; }
.log-error { color: #900; font-weight: bold; } .log-error { background: #fee; color: #900; font-weight: bold; }
.log-skip { color: #F90; } .error-retry { color: #c33; font-size: 125%; font-weight: bold; border-top: 1px solid #f00; }
.log-passed { color: #393; }
.log-failed { color: #F00; font-weight: bold; font-size: 150%; }
.log-skipped { color: #F90; }
.log-flakey { background: #f93; font-weight: bold; font-size: 150%; }
.log-slow { background: #FF0; color: #000; font-weight: bold; } .log-slow { background: #FF0; color: #000; font-weight: bold; }
.subtest { background: #eee; } .subtest { background: #eee; }
.subsubtest { color: #F39; font-weight: bold; } .subsubtest { color: #F39; font-weight: bold; }
@ -55,6 +59,22 @@ table.synopsis { border: none; border-collapse: collapse; margin-left: 2em; marg
.command { font-weight: bold; color: #000; } .command { font-weight: bold; color: #000; }
.changed { color: #000; font-weight: bold; } .changed { color: #000; font-weight: bold; }
/* Ginkgo "Enter/Exit [foo]": visually separate from each other */
.ginkgo-timeline { margin-top: 1ex; margin-bottom: 1ex; }
/* BeforeEach and AfterEach tend to be boring. Gray them out. */
.ginkgo-beforeeach { background: #f0f0f0; color: #999; }
.ginkgo-aftereach { background: #f0f0f0; color: #999; }
.ginkgo-beforeeach b { color: #000; }
.ginkgo-aftereach b { color: #000; }
/* [It] is where the test happens but we don't need any special highlights */
.ginkgo-it { }
/* Finall summary line at bottom */
.ginkgo-final-success { background: #393; font-weight: bold; font-size: 150%; }
.ginkgo-final-fail { background: #f00; font-weight: bold; font-size: 150%; }
/* links to source files: not as prominent as links to errors */ /* links to source files: not as prominent as links to errors */
a.codelink:link { color: #000; } a.codelink:link { color: #000; }
a.codelink:visited { color: #666; } a.codelink:visited { color: #666; }
@ -67,6 +87,7 @@ a.timing { text-decoration: none; }
/* BATS styles */ /* BATS styles */
.bats-passed { color: #393; } .bats-passed { color: #393; }
.bats-failed { color: #F00; font-weight: bold; } .bats-failed { color: #F00; font-weight: bold; }
.bats-flaked { color: #F93; font-weight: bold; }
.bats-skipped { color: #F90; } .bats-skipped { color: #F90; }
.bats-log { color: #933; } .bats-log { color: #933; }
.bats-log-failblock { color: #b00; background-color: #fee; display: inline-flex; margin: 0 -500%; padding: 0 500% !important; } .bats-log-failblock { color: #b00; background-color: #fee; display: inline-flex; margin: 0 -500%; padding: 0 500% !important; }
@ -210,6 +231,7 @@ END_HTML
my $previous_timestamp = ''; # timestamp of previous line my $previous_timestamp = ''; # timestamp of previous line
my $cirrus_task; # Cirrus task number, used for linking my $cirrus_task; # Cirrus task number, used for linking
my $git_commit; # git SHA, used for linking to source files my $git_commit; # git SHA, used for linking to source files
my $subtest_status; # pass, fail, skip, flake - for each subtest
my $in_failure; # binary flag: are we in an error dump? my $in_failure; # binary flag: are we in an error dump?
my $in_timing; # binary flag: are we in the timing section? my $in_timing; # binary flag: are we in the timing section?
my $after_divider = 0; # Count of lines after seeing '-----' my $after_divider = 0; # Count of lines after seeing '-----'
@ -230,6 +252,12 @@ END_HTML
# Main loop: read input, one line at a time, and write out reformatted # Main loop: read input, one line at a time, and write out reformatted
LINE: LINE:
while (my $line = <STDIN>) { while (my $line = <STDIN>) {
# ARGH. Some log files have NUL characters , apparently because
# certain tests write tar to stdout. Bleagh. Although it seems
# rude to strip those from our (purportedly untouched) log,
# it's worse to read log files with random NULs.
$line =~ s/\0//g;
print $line; # Immediately dump back to stdout print $line; # Immediately dump back to stdout
$Prompt = '$' if $line =~ /Runner executing .* as rootless /; $Prompt = '$' if $line =~ /Runner executing .* as rootless /;
@ -238,7 +266,6 @@ END_HTML
next LINE if ! $out_fh; next LINE if ! $out_fh;
chomp $line; chomp $line;
$line =~ s/\0//g; # Some log files have NULs????
$line = escapeHTML($line); $line = escapeHTML($line);
# Temporarily strip off leading timestamp # Temporarily strip off leading timestamp
@ -251,8 +278,8 @@ END_HTML
$previous_timestamp = $timestamp; $previous_timestamp = $timestamp;
} }
# Helper function for printing a formatted line. This should always # Helper function for printing a formatted line. This should almost
# be followed by 'next LINE'. # always be followed by 'next LINE'.
my $print_line = sub { my $print_line = sub {
my $css = shift; my $css = shift;
@ -264,6 +291,20 @@ END_HTML
print { $out_fh } "\n"; print { $out_fh } "\n";
}; };
# ARGH! Special case for tests that run 'cat /proc/self/attr/current:
# that file terminates with NUL, so ginkgo logs concatenate the next
# output line, which is usually "Running: next-podman-command".
# This makes the log readable by splitting into two lines.
if ($line =~ /^(\s*)(\S+_u:\S+_t:\S+:c\S+)(Running:.*)/) {
my ($indent, $selinux, $nextline) = ($1||'', $2, $3);
# Print the SELinux line, unmodified...
$line = $indent . $selinux;
$print_line->();
# ...then forget that, and continue processing (fall through)
# with the 'Running' line.
$line = $indent . $nextline;
}
# Try to identify the git commit we're working with... # Try to identify the git commit we're working with...
if ($line =~ m!/define.gitCommit=([0-9a-f]+)!) { if ($line =~ m!/define.gitCommit=([0-9a-f]+)!) {
$git_commit = $1; $git_commit = $1;
@ -384,18 +425,51 @@ END_HTML
next LINE; next LINE;
} }
#
# Must be ginkgo
#
if ($line =~ s!^(\s*)(&[gl]t;)\s+(Enter|Exit)\s+\[(\w+)\]!!) {
my ($indent, $arrow, $action, $block) = ($1, $2, $3, $4);
if ($action eq 'Enter') {
printf { $out_fh } "<div class=\"ginkgo-timeline ginkgo-%s\">",
lc($block);
$line = "$indent&rarr; Enter [<b>$block</b>]$line";
$print_line->();
}
else {
# Can be a div within a div
if ($in_failure) {
$in_failure = 0;
print { $out_fh } "</div>";
}
$line = "$indent&larr; Exit [$block]$line";
$print_line->();
print { $out_fh } "</div>";
}
next LINE;
}
# Ginkgo v2 nicely lumps all retries for the same given test
if ($line =~ /^\s*Attempt\s+\#\d+\s+Failed\.\s+Retr/) {
$print_line->("error-retry");
next LINE;
}
# Timing section at the bottom of the page # Timing section at the bottom of the page
if ($line =~ / timing results\s*$/) { if ($line =~ / timing results\s*$/) {
$in_timing = 1; $in_timing = 1;
} }
elsif ($in_timing) { elsif ($in_timing) {
if ($line =~ /^(\S.*\S)\s+(\d+\.\d+)\s*$/) { if ($line =~ /^\s*(\S.*\S)\s+(\d+\.\d+)\s*$/) {
my ($name, $time) = ($1, $2); my ($name, $time) = ($1, $2);
my $id = make_id($1, 'timing'); my $id = make_id($1, 'timing');
# Try to column-align the timing numbers. Some test names # Try to column-align the timing numbers. Some test names
# will be longer than our max - oh well. # will be longer than our max - oh well.
my $spaces = 80 - length(unescapeHTML($name)); my $spaces = 90 - length(unescapeHTML($name));
$spaces = 1 if $spaces < 1; $spaces = 1 if $spaces < 1;
$spaces++ if $time < 10; $spaces++ if $time < 10;
my $spacing = ' ' x $spaces; my $spacing = ' ' x $spaces;
@ -406,10 +480,38 @@ END_HTML
} }
} }
# Ginkgo summary line. Colorize Passed, Failed, Flaked, Skipped
if ($line =~ /^(\s*)(FAIL|SUCCESS)!(\s+--\s+)(.*\d+\sPassed.*)/) {
my ($indent, $status, $dashes, $rhs) = ($1, $2, $3, $4);
my @counts = split('\|', $rhs);
my @formatted;
for my $c (@counts) {
$c =~ /^(\s*)(\d+)\s+(\w+)(\s*)$/
or warn "$ME: line $.: WEIRD: '$c' in '$rhs' from '$line'";
my ($lhs, $n, $category, $rhs) = ($1||'', $2, $3, $4||'');
# Only highlight if count > 0, so "0 Failed" doesn't yell
if ($n > 0) {
# Yes, we use 'bats-xxxx' classes even though we're ginkgo.
push @formatted, sprintf("%s<span class=\"bats-%s\"><b>%d</b> %s</span>%s",
$lhs, lc($category), $n, $category, $rhs);
}
else {
# Zero. Leave unhighlighted.
push @formatted, $c;
}
}
$line = sprintf("%s<span class=\"ginkgo-final-%s\">%s!</span>%s%s",
$indent,
lc($status), $status,
$dashes, join('|', @formatted));
$print_line->();
next LINE;
}
# #
# Ginkgo error reformatting # Ginkgo error reformatting
# #
if ($line =~ /^.{1,4} (Failure|Panic)( in .*)? \[/) { if ($line =~ /^\s*\[(FAILED|PANICKED)\]/) {
# Begins a block of multiple lines including a stack trace # Begins a block of multiple lines including a stack trace
print { $out_fh } "<div class='log-error'>\n"; print { $out_fh } "<div class='log-error'>\n";
$in_failure = 1; $in_failure = 1;
@ -428,7 +530,7 @@ END_HTML
next LINE; next LINE;
} }
# (bindings test sometimes emits 'Running' with leading bullet char) # (bindings test sometimes emits 'Running' with leading bullet char)
elsif ($line =~ s!^•?Running:!<span class="boring">$Prompt</span>!) { elsif ($line =~ s!^•?(\s*)Running:!<span class="boring">$1$Prompt</span>!) {
# Highlight the important (non-boilerplate) podman command. # Highlight the important (non-boilerplate) podman command.
$line =~ s/\s+--remote\s+/ /g; # --remote takes no args $line =~ s/\s+--remote\s+/ /g; # --remote takes no args
# Strip out the global podman options, but show them on hover # Strip out the global podman options, but show them on hover
@ -449,15 +551,7 @@ END_HTML
$current_output = ''; $current_output = '';
} }
# Grrr. 'output:' usually just tells us what we already know. elsif ($line =~ /^\s*Error:/ || $line =~ / level=(warning|error) /) {
elsif ($line =~ /^output:/) {
$current_output =~ s!^\s+|\s+$!!g; # Trim leading/trailing blanks
$current_output =~ s/\s+/ /g; # Collapse multiple spaces
if ($line eq "output: $current_output" || $line eq 'output: ') {
next LINE;
}
}
elsif ($line =~ /^Error:/ || $line =~ / level=(warning|error) /) {
$line = "<span class='log-warning'>" . $line . "</span>"; $line = "<span class='log-warning'>" . $line . "</span>";
} }
elsif ($line =~ /^panic:/) { elsif ($line =~ /^panic:/) {
@ -467,23 +561,35 @@ END_HTML
$current_output .= ' ' . $line; $current_output .= ' ' . $line;
} }
# One line after each divider, there's a status/timing line.
if ($after_divider == 1) {
$line =~ s{(\[(\d+)\.\d+\s+seconds\])}{
if ($2 > 5) { "<b><span class='log-slow'>$1</span></b>" }
else { "<b>$1</b>" }
}e;
# Two lines after each divider, there's a test name. Make it # Make FAILED and SKIPPING visible
$subtest_status = 'passed';
if ($line =~ s!^(.*\[(SKIPPED|FAILED|FLAKEY).*\].*)!<span class="log-\L$2\E">$1</span>!) {
$subtest_status = lc($2);
}
# FIXME: gray out entire block if it's skipped?
}
# Four lines after each divider, there's a test name. Make it
# an anchor so we can link to it later. # an anchor so we can link to it later.
if ($after_divider++ == 2) { if ($after_divider == 4) {
# Sigh. There is no actual marker. Assume that anything with # Sigh. There is no actual marker. Assume that anything with
## two leading spaces then alpha or hyphen (not slashes) is ## two leading spaces then alpha or hyphen (not slashes) is
## a test name. ## a test name.
if ($line =~ /^ [a-zA-Z-]/) { if ($line =~ /^ (\[It\]\s*)?([a-zA-Z-].*\S)/) {
my $id = make_id($line, 'anchor'); my $id = make_id($2, 'anchor');
$line = "<a name='t--$id'><h2>$line</h2></a>"; $line = "<a name='t--$id'><h2 class=\"log-$subtest_status\">$line</h2></a>";
} }
} }
++$after_divider;
# Make SKIPPING and SLOW TEST visible
$line =~ s!(\[SKIPPING\].*)!<span class="log-skip">$1</span>!;
$line =~ s!(\[SLOW TEST.*\])!<span class="log-slow">$1</span>!;
# Highlight test name when it appears in the middle of commands. # Highlight test name when it appears in the middle of commands.
# But make it boring, because we already have the test name in large # But make it boring, because we already have the test name in large
@ -491,12 +597,12 @@ END_HTML
$line =~ s!^(\s*)(\[It\]\s+.*)!$1<span class="testname">$2</span>!; $line =~ s!^(\s*)(\[It\]\s+.*)!$1<span class="testname">$2</span>!;
# Failure name corresponds to a previously-seen block. # Failure name corresponds to a previously-seen block.
# 1 2 2 3 3 14 4 # 1 2 2 3 3 14 4
if ($line =~ /^(\[(Fail|Panic!)\] .* \[(It|BeforeEach)\] )([A-Za-z-].*)/) { if ($line =~ /^(\s*\[(FAIL|PANIC!)\] .* \[(It|BeforeEach|AfterEach)\] )([A-Za-z-].*)/) {
my ($lhs, $type, $ginkgo_fluff, $testname) = ($1, $2, $3, $4); my ($lhs, $type, $ginkgo_fluff, $testname) = ($1, $2, $3, $4);
my $id = make_id($testname, 'link'); my $id = make_id($testname, 'link');
$line = "<b>$lhs<a href='#t--$id'>$testname</a></b>"; $line = "<span class=\"log-error\">$lhs<a href='#t--$id'>$testname</a></span>";
} }
print { $out_fh } "<span class=\"timestamp\">$timestamp</span>" print { $out_fh } "<span class=\"timestamp\">$timestamp</span>"
@ -603,6 +709,7 @@ sub make_id {
state %counter; state %counter;
$name =~ s/^\s+|\s+$//g; # strip leading/trailing whitespace $name =~ s/^\s+|\s+$//g; # strip leading/trailing whitespace
$name =~ s/^\[It\]\s*//; # strip leading "[It] "
$name =~ s/\&#\d+;//g; # 'doesn&#39;t' -> 'doesnt' $name =~ s/\&#\d+;//g; # 'doesn&#39;t' -> 'doesnt'
$name =~ s/\&quot;/-/g; # '&quot;path&quot;' -> '-path-' $name =~ s/\&quot;/-/g; # '&quot;path&quot;' -> '-path-'
$name =~ s/[^a-zA-Z0-9_-]/-/g; # Convert non-alphanumeric to dash $name =~ s/[^a-zA-Z0-9_-]/-/g; # Convert non-alphanumeric to dash

243
contrib/cirrus/logformatter.t
View File

@ -123,165 +123,122 @@ ok 4 blah
== simple ginkgo == simple ginkgo
<<< <<<
$SCRIPT_BASE/integration_test.sh |& ${TIMESTAMP} [05:47:08] START - All [+xxxx] lines that follow are relative to 2023-04-17T05:47:08.
[08:26:19] START - All [+xxxx] lines that follow are relative to right now. [+0004s] CGO_ENABLED=1 GOOS=linux GOARCH=amd64 go build -ldflags '-X github.com/containers/podman/v4/libpod/define.gitCommit=074143b0fac7af72cd92048d27931a92fe745084 -X github.com/containers/podman/v4/libpod/define.buildInfo=1681728432 -X github.com/containers/podman/v4/libpod/config._installPrefix=/usr/local -X github.com/containers/podman/v4/libpod/config._etcDir=/usr/local/etc -X github.com/containers/podman/v4/pkg/systemd/quadlet._binDir=/usr/local/bin -X github.com/containers/common/pkg/config.additionalHelperBinariesDir= ' -tags " selinux systemd exclude_graphdriver_devicemapper seccomp" -o test/checkseccomp/checkseccomp ./test/checkseccomp
[+0002s] GO111MODULE=on go build -mod=vendor -gcflags 'all=-trimpath=/var/tmp/go/src/github.com/containers/podman' -asmflags 'all=-trimpath=/var/tmp/go/src/github.com/containers/podman' -ldflags '-X github.com/containers/podman/libpod/define.gitCommit=40f5d8b1becd381c4e8283ed3940d09193e4fe06 -X github.com/containers/podman/libpod/define.buildInfo=1582809981 -X github.com/containers/podman/libpod/config._installPrefix=/usr/local -X github.com/containers/podman/libpod/config._etcDir=/etc -extldflags ""' -tags " selinux systemd exclude_graphdriver_devicemapper seccomp varlink" -o bin/podman github.com/containers/podman/cmd/podman [+0006s] CGO_ENABLED=1 GOOS=linux GOARCH=amd64 go build -ldflags '-X github.com/containers/podman/v4/libpod/define.gitCommit=074143b0fac7af72cd92048d27931a92fe745084 -X github.com/containers/podman/v4/libpod/define.buildInfo=1681728434 -X github.com/containers/podman/v4/libpod/config._installPrefix=/usr/local -X github.com/containers/podman/v4/libpod/config._etcDir=/usr/local/etc -X github.com/containers/podman/v4/pkg/systemd/quadlet._binDir=/usr/local/bin -X github.com/containers/common/pkg/config.additionalHelperBinariesDir= ' -o test/goecho/goecho ./test/goecho
[+0103s] • [+0006s] ./hack/install_catatonit.sh
[+0103s] ------------------------------ [+0270s] ------------------------------
[+0103s] Podman pod restart [+0271s] • [3.327 seconds]
[+0103s] podman pod restart single empty pod [+0271s] Podman restart
[+0103s] /var/tmp/go/src/github.com/containers/podman/test/e2e/pod_restart_test.go:41 [+0271s] /var/tmp/go/src/github.com/containers/podman/test/e2e/restart_test.go:14
[+0103s] [BeforeEach] Podman pod restart [+0271s] podman restart non-stop container with short timeout
[+0103s] /var/tmp/go/src/github.com/containers/podman/test/e2e/pod_restart_test.go:18 [+0271s] /var/tmp/go/src/github.com/containers/podman/test/e2e/restart_test.go:148
[+0103s] [It] podman pod restart single empty pod [+0271s]
[+0103s] /var/tmp/go/src/github.com/containers/podman/test/e2e/pod_restart_test.go:41 [+0271s] Timeline >>
[+0103s] Running: /var/tmp/go/src/github.com/containers/podman/bin/quadlet -no-kmsg-log /tmp/podman_test620310100/generated with QUADLET_UNIT_DIRS=/tmp/podman_test620310100/quadlet [+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
[+0103s] quadlet-generator[98757]: Error converting 'range.less-subnet.network', ignoring: cannot set more ranges than subnets [+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)
[+0103s] Running: /var/tmp/go/src/github.com/containers/podman/bin/podman --network-backend netavark --storage-opt vfs.imagestore=/tmp/podman/imagecachedir --root /tmp/podman_test553496330/crio --runroot /tmp/podman_test553496330/crio-run --runtime /usr/bin/runc --conmon /usr/bin/conmon --network-config-dir /etc/cni/net.d --cgroup-manager systemd --tmpdir /tmp/podman_test553496330 --events-backend file --storage-driver vfs pod create --infra=false --share [+0271s] > Enter [It] podman restart non-stop container with short timeout - /var/tmp/go/src/github.com/containers/podman/test/e2e/restart_test.go:148 @ 04/17/23 10:00:28.653
[+0103s] 4810be0cfbd42241e349dbe7d50fbc54405cd320a6637c65fd5323f34d64af89 [+0271s] Running: /var/tmp/go/src/github.com/containers/podman/bin/podman --storage-opt vfs.imagestore=/tmp/imagecachedir --root /tmp/podman_test2968516396/root --runroot /tmp/podman_test2968516396/runroot --runtime crun --conmon /usr/bin/conmon --network-config-dir /tmp/podman_test2968516396/root/etc/networks --network-backend netavark --cgroup-manager systemd --tmpdir /tmp/podman_test2968516396 --events-backend file --db-backend sqlite --storage-driver vfs run -d --name test1 --env STOPSIGNAL=SIGKILL quay.io/libpod/alpine:latest sleep 999
[+0103s] output: 4810be0cfbd42241e349dbe7d50fbc54405cd320a6637c65fd5323f34d64af89 [+0271s] 7f5f8fb3d043984cdff65994d14c4fd157479d20e0a0fcf769c35b50e8975edc
[+0103s] Running: /var/tmp/go/src/github.com/containers/podman/bin/podman --storage-opt vfs.imagestore=/tmp/podman/imagecachedir --root /tmp/podman_test553496330/crio --runroot /tmp/podman_test553496330/crio-run --runtime /usr/bin/runc --conmon /usr/bin/conmon --network-config-dir /etc/cni/net.d --cgroup-manager systemd --tmpdir /tmp/podman_test553496330 --events-backend file --storage-driver vfs pod restart 4810be0cfbd42241e349dbe7d50fbc54405cd320a6637c65fd5323f34d64af89 [+0271s] Running: /var/tmp/go/src/github.com/containers/podman/bin/podman --storage-opt vfs.imagestore=/tmp/imagecachedir --root /tmp/podman_test2968516396/root --runroot /tmp/podman_test2968516396/runroot --runtime crun --conmon /usr/bin/conmon --network-config-dir /tmp/podman_test2968516396/root/etc/networks --network-backend netavark --cgroup-manager systemd --tmpdir /tmp/podman_test2968516396 --events-backend file --db-backend sqlite --storage-driver vfs restart -t 2 test1
[+0103s] Error: no containers in pod 4810be0cfbd42241e349dbe7d50fbc54405cd320a6637c65fd5323f34d64af89 have no dependencies, cannot start pod: no such container [+0271s] time="2023-04-17T10:00:31-05:00" level=warning msg="StopSignal SIGTERM failed to stop container test1 in 2 seconds, resorting to SIGKILL"
[+0103s] output: [+0271s] test1
[+0103s] [AfterEach] Podman pod restart [+0271s] < Exit [It] podman restart non-stop container with short timeout - /var/tmp/go/src/github.com/containers/podman/test/e2e/restart_test.go:148 @ 04/17/23 10:00:31.334 (2.681s)
[+0103s] /var/tmp/go/src/github.com/containers/podman/test/e2e/pod_restart_test.go:28 [+0271s] > Enter [AfterEach] Podman restart - /var/tmp/go/src/github.com/containers/podman/test/e2e/restart_test.go:30 @ 04/17/23 10:00:31.334
[+0103s] Running: /var/tmp/go/src/github.com/containers/podman/bin/podman --storage-opt vfs.imagestore=/tmp/podman/imagecachedir --root /tmp/podman_test553496330/crio --runroot /tmp/podman_test553496330/crio-run --runtime /usr/bin/runc --conmon /usr/bin/conmon --network-config-dir /etc/cni/net.d --cgroup-manager systemd --tmpdir /tmp/podman_test553496330 --events-backend file --storage-driver vfs pod rm -fa [+0271s] Running: /var/tmp/go/src/github.com/containers/podman/bin/podman --storage-opt vfs.imagestore=/tmp/imagecachedir --root /tmp/podman_test2968516396/root --runroot /tmp/podman_test2968516396/runroot --runtime crun --conmon /usr/bin/conmon --network-config-dir /tmp/podman_test2968516396/root/etc/networks --network-backend netavark --cgroup-manager systemd --tmpdir /tmp/podman_test2968516396 --events-backend file --db-backend sqlite --storage-driver vfs stop --all -t 0
[+0103s] 4810be0cfbd42241e349dbe7d50fbc54405cd320a6637c65fd5323f34d64af89 [+0271s] 7f5f8fb3d043984cdff65994d14c4fd157479d20e0a0fcf769c35b50e8975edc
[+0104s] Running: /var/tmp/go/src/github.com/containers/libpod/bin/podman-remote --storage-opt vfs.imagestore=/tmp/podman/imagecachedir --root /tmp/podman_test553496330/crio --runroot /tmp/podman_test553496330/crio-run --runtime /usr/bin/runc --conmon /usr/bin/conmon --network-config-dir /etc/cni/net.d --cgroup-manager systemd --tmpdir /tmp/podman_test553496330 --events-backend file --storage-driver vfs --remote --url unix:/run/user/12345/podman-xyz.sock pod rm -fa [+0271s] Running: /var/tmp/go/src/github.com/containers/podman/bin/podman --storage-opt vfs.imagestore=/tmp/imagecachedir --root /tmp/podman_test2968516396/root --runroot /tmp/podman_test2968516396/runroot --runtime crun --conmon /usr/bin/conmon --network-config-dir /tmp/podman_test2968516396/root/etc/networks --network-backend netavark --cgroup-manager systemd --tmpdir /tmp/podman_test2968516396 --events-backend file --db-backend sqlite --storage-driver vfs pod rm -fa -t 0
[+0104s] 4810be0cfbd42241e349dbe7d50fbc54405cd320a6637c65fd5323f34d64af89 again [+0271s] Running: /var/tmp/go/src/github.com/containers/podman/bin/podman --storage-opt vfs.imagestore=/tmp/imagecachedir --root /tmp/podman_test2968516396/root --runroot /tmp/podman_test2968516396/runroot --runtime crun --conmon /usr/bin/conmon --network-config-dir /tmp/podman_test2968516396/root/etc/networks --network-backend netavark --cgroup-manager systemd --tmpdir /tmp/podman_test2968516396 --events-backend file --db-backend sqlite --storage-driver vfs rm -fa -t 0
[+0271s] 7f5f8fb3d043984cdff65994d14c4fd157479d20e0a0fcf769c35b50e8975edc
[+0271s] < Exit [AfterEach] Podman restart - /var/tmp/go/src/github.com/containers/podman/test/e2e/restart_test.go:30 @ 04/17/23 10:00:31.979 (645ms)
[+0107s] • [+0271s] << Timeline
[+0523s] ------------------------------
[+0523s] Podman play kube with build
[+0523s] --build should override image in store
[+0523s] /var/tmp/go/src/github.com/containers/podman/test/e2e/play_build_test.go:215
[+0479s] •
[+0479s] ------------------------------
[+0479s] Podman pod rm
[+0479s] podman pod rm -a doesn't remove a running container
[+0479s] /var/tmp/go/src/github.com/containers/podman/test/e2e/pod_rm_test.go:119
[+1405s] •
[+1405s] ------------------------------
[+1405s] Podman run entrypoint
[+1405s] podman run entrypoint == [""]
[+1405s] /var/tmp/go/src/github.com/containers/podman/test/e2e/run_entrypoint_test.go:47
[+0184s] S [SKIPPING] [3.086 seconds]
[+1385s] S [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds]
[+1512s] Summarizing 6 Failures:
[+1512s]
[+1512s] [Fail] Podman play kube with build [It] --build should override image in store
[+1512s] /var/tmp/go/src/github.com/containers/podman/test/e2e/play_build_test.go:259
>>> >>>
$SCRIPT_BASE/integration_test.sh |&amp; ${TIMESTAMP} [05:47:08] START - All [+xxxx] lines that follow are relative to 2023-04-17T05:47:08.
[08:26:19] START - All [+xxxx] lines that follow are relative to right now. <span class="timestamp">[+0004s] </span>CGO_ENABLED=1 GOOS=linux GOARCH=amd64 go build -ldflags &#39;-X github.com/containers/podman/v4/libpod/define.gitCommit=074143b0fac7af72cd92048d27931a92fe745084 -X github.com/containers/podman/v4/libpod/define.buildInfo=1681728432 -X github.com/containers/podman/v4/libpod/config._installPrefix=/usr/local -X github.com/containers/podman/v4/libpod/config._etcDir=/usr/local/etc -X github.com/containers/podman/v4/pkg/systemd/quadlet._binDir=/usr/local/bin -X github.com/containers/common/pkg/config.additionalHelperBinariesDir= &#39; -tags &quot; selinux systemd exclude_graphdriver_devicemapper seccomp&quot; -o test/checkseccomp/checkseccomp ./test/checkseccomp
<span class="timestamp">[+0002s] </span>GO111MODULE=on go build -mod=vendor -gcflags &#39;all=-trimpath=/var/tmp/go/src/github.com/containers/podman&#39; -asmflags &#39;all=-trimpath=/var/tmp/go/src/github.com/containers/podman&#39; -ldflags &#39;-X github.com/containers/podman/libpod/define.gitCommit=40f5d8b1becd381c4e8283ed3940d09193e4fe06 -X github.com/containers/podman/libpod/define.buildInfo=1582809981 -X github.com/containers/podman/libpod/config._installPrefix=/usr/local -X github.com/containers/podman/libpod/config._etcDir=/etc -extldflags &quot;&quot;&#39; -tags &quot; selinux systemd exclude_graphdriver_devicemapper seccomp varlink&quot; -o bin/podman github.com/containers/podman/cmd/podman <span class="timestamp">[+0006s] </span>CGO_ENABLED=1 GOOS=linux GOARCH=amd64 go build -ldflags &#39;-X github.com/containers/podman/v4/libpod/define.gitCommit=074143b0fac7af72cd92048d27931a92fe745084 -X github.com/containers/podman/v4/libpod/define.buildInfo=1681728434 -X github.com/containers/podman/v4/libpod/config._installPrefix=/usr/local -X github.com/containers/podman/v4/libpod/config._etcDir=/usr/local/etc -X github.com/containers/podman/v4/pkg/systemd/quadlet._binDir=/usr/local/bin -X github.com/containers/common/pkg/config.additionalHelperBinariesDir= &#39; -o test/goecho/goecho ./test/goecho
<span class="timestamp">[+0103s] </span>• <span class="timestamp"> </span>./hack/install_catatonit.sh
</pre> </pre>
<hr /> <hr />
<pre> <pre>
<span class="timestamp">[+0103s] </span>Podman pod restart <span class="timestamp">[+0271s] </span>• <b>[3.327 seconds]</b>
<span class="timestamp"> </span><a name='t--podman-pod-restart-single-empty-pod--1'><h2> podman pod restart single empty pod</h2></a> <span class="timestamp"> </span>Podman restart
<span class="timestamp"> </span> /var/tmp/go/src/github.com<a class="codelink" href='https://github.com/containers/podman/blob/40f5d8b1becd381c4e8283ed3940d09193e4fe06/test/e2e/pod_restart_test.go#L41'>/containers/podman/test/e2e/pod_restart_test.go:41</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>[BeforeEach] Podman pod restart <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> /var/tmp/go/src/github.com<a class="codelink" href='https://github.com/containers/podman/blob/40f5d8b1becd381c4e8283ed3940d09193e4fe06/test/e2e/pod_restart_test.go#L18'>/containers/podman/test/e2e/pod_restart_test.go:18</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>
<span class="timestamp"> </span><span class="testname">[It] podman pod restart single empty pod</span> [+0271s]
<span class="timestamp"> </span> /var/tmp/go/src/github.com<a class="codelink" href='https://github.com/containers/podman/blob/40f5d8b1becd381c4e8283ed3940d09193e4fe06/test/e2e/pod_restart_test.go#L41'>/containers/podman/test/e2e/pod_restart_test.go:41</a> <span class="timestamp"> </span> Timeline &gt;&gt;
<span class="timestamp"> </span><span class="boring">#</span> <span title="/var/tmp/go/src/github.com/containers/podman/bin/quadlet"><b>quadlet -no-kmsg-log /tmp/podman_test620310100/generated</b></span><span class="boring"> with QUADLET_UNIT_DIRS=</span><b>/tmp/podman_test620310100/quadlet</b> <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>quadlet-generator[98757]: Error converting &#39;range.less-subnet.network&#39;, ignoring: cannot set more ranges than subnets <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)
<span class="timestamp"> </span><span class="boring">#</span> <span title="/var/tmp/go/src/github.com/containers/podman/bin/podman"><b>podman</b></span> <span class="boring" title="--network-backend netavark </div><div class="ginkgo-timeline ginkgo-it"><span class="timestamp"> </span> &rarr; Enter [<b>It</b>] podman restart non-stop container with short timeout - /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> @ 04/17/23 10:00:28.653
--storage-opt vfs.imagestore=/tmp/podman/imagecachedir <span class="timestamp"> </span><span class="boring"> #</span> <span title="/var/tmp/go/src/github.com/containers/podman/bin/podman"><b>podman</b></span> <span class="boring" title="--storage-opt vfs.imagestore=/tmp/imagecachedir
--root /tmp/podman_test553496330/crio --root /tmp/podman_test2968516396/root
--runroot /tmp/podman_test553496330/crio-run --runroot /tmp/podman_test2968516396/runroot
--runtime /usr/bin/runc --runtime crun
--conmon /usr/bin/conmon --conmon /usr/bin/conmon
--network-config-dir /etc/cni/net.d --network-config-dir /tmp/podman_test2968516396/root/etc/networks
--network-backend netavark
--cgroup-manager systemd --cgroup-manager systemd
--tmpdir /tmp/podman_test553496330 --tmpdir /tmp/podman_test2968516396
--events-backend file --events-backend file
--storage-driver vfs">[options]</span><b> pod create --infra=false --share</b> --db-backend sqlite
<span class="timestamp"> </span>4810be0cfbd42241e349dbe7d50fbc54405cd320a6637c65fd5323f34d64af89 --storage-driver vfs">[options]</span><b> run -d --name test1 --env STOPSIGNAL=SIGKILL quay.io/libpod/alpine:latest sleep 999</b>
<span class="timestamp"> </span><span class="boring">#</span> <span title="/var/tmp/go/src/github.com/containers/podman/bin/podman"><b>podman</b></span> <span class="boring" title="--storage-opt vfs.imagestore=/tmp/podman/imagecachedir <span class="timestamp"> </span> 7f5f8fb3d043984cdff65994d14c4fd157479d20e0a0fcf769c35b50e8975edc
--root /tmp/podman_test553496330/crio <span class="timestamp"> </span><span class="boring"> #</span> <span title="/var/tmp/go/src/github.com/containers/podman/bin/podman"><b>podman</b></span> <span class="boring" title="--storage-opt vfs.imagestore=/tmp/imagecachedir
--runroot /tmp/podman_test553496330/crio-run --root /tmp/podman_test2968516396/root
--runtime /usr/bin/runc --runroot /tmp/podman_test2968516396/runroot
--runtime crun
--conmon /usr/bin/conmon --conmon /usr/bin/conmon
--network-config-dir /etc/cni/net.d --network-config-dir /tmp/podman_test2968516396/root/etc/networks
--network-backend netavark
--cgroup-manager systemd --cgroup-manager systemd
--tmpdir /tmp/podman_test553496330 --tmpdir /tmp/podman_test2968516396
--events-backend file --events-backend file
--storage-driver vfs">[options]</span><b> pod restart 4810be0cfbd42241e349dbe7d50fbc54405cd320a6637c65fd5323f34d64af89</b> --db-backend sqlite
<span class="timestamp"> </span><span class='log-warning'>Error: no containers in pod 4810be0cfbd42241e349dbe7d50fbc54405cd320a6637c65fd5323f34d64af89 have no dependencies, cannot start pod: no such container</span> --storage-driver vfs">[options]</span><b> restart -t 2 test1</b>
<span class="timestamp"> </span>output: <span class="timestamp"> </span> time=<span class='log-warning'>&quot;2023-04-17T10:00:31-05:00&quot;</span> level=<span class='log-warning'>warning</span> msg=<span class='log-warning'>&quot;StopSignal SIGTERM failed to stop container test1 in 2 seconds, resorting to SIGKILL&quot;</span>
<span class="timestamp"> </span>[AfterEach] Podman pod restart <span class="timestamp"> </span> test1
<span class="timestamp"> </span> /var/tmp/go/src/github.com<a class="codelink" href='https://github.com/containers/podman/blob/40f5d8b1becd381c4e8283ed3940d09193e4fe06/test/e2e/pod_restart_test.go#L28'>/containers/podman/test/e2e/pod_restart_test.go:28</a> <span class="timestamp"> </span> &larr; Exit [It] podman restart non-stop container with short timeout - /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> @ 04/17/23 10:00:31.334 (2.681s)
<span class="timestamp"> </span><span class="boring">#</span> <span title="/var/tmp/go/src/github.com/containers/podman/bin/podman"><b>podman</b></span> <span class="boring" title="--storage-opt vfs.imagestore=/tmp/podman/imagecachedir </div><div class="ginkgo-timeline ginkgo-aftereach"><span class="timestamp"> </span> &rarr; Enter [<b>AfterEach</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#L30'>/containers/podman/test/e2e/restart_test.go:30</a> @ 04/17/23 10:00:31.334
--root /tmp/podman_test553496330/crio <span class="timestamp"> </span><span class="boring"> #</span> <span title="/var/tmp/go/src/github.com/containers/podman/bin/podman"><b>podman</b></span> <span class="boring" title="--storage-opt vfs.imagestore=/tmp/imagecachedir
--runroot /tmp/podman_test553496330/crio-run --root /tmp/podman_test2968516396/root
--runtime /usr/bin/runc --runroot /tmp/podman_test2968516396/runroot
--runtime crun
--conmon /usr/bin/conmon --conmon /usr/bin/conmon
--network-config-dir /etc/cni/net.d --network-config-dir /tmp/podman_test2968516396/root/etc/networks
--network-backend netavark
--cgroup-manager systemd --cgroup-manager systemd
--tmpdir /tmp/podman_test553496330 --tmpdir /tmp/podman_test2968516396
--events-backend file --events-backend file
--storage-driver vfs">[options]</span><b> pod rm -fa</b> --db-backend sqlite
<span class="timestamp"> </span>4810be0cfbd42241e349dbe7d50fbc54405cd320a6637c65fd5323f34d64af89 --storage-driver vfs">[options]</span><b> stop --all -t 0</b>
<span class="timestamp"> </span> 7f5f8fb3d043984cdff65994d14c4fd157479d20e0a0fcf769c35b50e8975edc
<span class="timestamp">[+0104s] </span><span class="boring">#</span> <span title="/var/tmp/go/src/github.com/containers/libpod/bin/podman-remote"><b>podman-remote</b></span> <span class="boring" title="--storage-opt vfs.imagestore=/tmp/podman/imagecachedir <span class="timestamp"> </span><span class="boring"> #</span> <span title="/var/tmp/go/src/github.com/containers/podman/bin/podman"><b>podman</b></span> <span class="boring" title="--storage-opt vfs.imagestore=/tmp/imagecachedir
--root /tmp/podman_test553496330/crio --root /tmp/podman_test2968516396/root
--runroot /tmp/podman_test553496330/crio-run --runroot /tmp/podman_test2968516396/runroot
--runtime /usr/bin/runc --runtime crun
--conmon /usr/bin/conmon --conmon /usr/bin/conmon
--network-config-dir /etc/cni/net.d --network-config-dir /tmp/podman_test2968516396/root/etc/networks
--network-backend netavark
--cgroup-manager systemd --cgroup-manager systemd
--tmpdir /tmp/podman_test553496330 --tmpdir /tmp/podman_test2968516396
--events-backend file --events-backend file
--storage-driver vfs --db-backend sqlite
--url unix:/run/user/12345/podman-xyz.sock">[options]</span><b> pod rm -fa</b> --storage-driver vfs">[options]</span><b> pod rm -fa -t 0</b>
<span class="timestamp"> </span>4810be0cfbd42241e349dbe7d50fbc54405cd320a6637c65fd5323f34d64af89 again <span class="timestamp"> </span><span class="boring"> #</span> <span title="/var/tmp/go/src/github.com/containers/podman/bin/podman"><b>podman</b></span> <span class="boring" title="--storage-opt vfs.imagestore=/tmp/imagecachedir
--root /tmp/podman_test2968516396/root
--runroot /tmp/podman_test2968516396/runroot
<span class="timestamp">[+0107s] </span>• --runtime crun
</pre> --conmon /usr/bin/conmon
<hr /> --network-config-dir /tmp/podman_test2968516396/root/etc/networks
<pre> --network-backend netavark
<span class="timestamp">[+0523s] </span>Podman play kube with build --cgroup-manager systemd
<span class="timestamp"> </span><a name='t----build-should-override-image-in-store--1'><h2> --build should override image in store</h2></a> --tmpdir /tmp/podman_test2968516396
<span class="timestamp"> </span> /var/tmp/go/src/github.com<a class="codelink" href='https://github.com/containers/podman/blob/40f5d8b1becd381c4e8283ed3940d09193e4fe06/test/e2e/play_build_test.go#L215'>/containers/podman/test/e2e/play_build_test.go:215</a> --events-backend file
--db-backend sqlite
--storage-driver vfs">[options]</span><b> rm -fa -t 0</b>
<span class="timestamp">[+0479s] </span>• <span class="timestamp"> </span> 7f5f8fb3d043984cdff65994d14c4fd157479d20e0a0fcf769c35b50e8975edc
</pre> <span class="timestamp"> </span> &larr; Exit [AfterEach] Podman restart - /var/tmp/go/src/github.com<a class="codelink" href='https://github.com/containers/podman/blob/074143b0fac7af72cd92048d27931a92fe745084/test/e2e/restart_test.go#L30'>/containers/podman/test/e2e/restart_test.go:30</a> @ 04/17/23 10:00:31.979 (645ms)
<hr /> </div><span class="timestamp"> </span> &lt;&lt; Timeline
<pre>
<span class="timestamp">[+0479s] </span>Podman pod rm
<span class="timestamp"> </span><a name='t--podman-pod-rm--a-doesnt-remove-a-running-container--1'><h2> podman pod rm -a doesn&#39;t remove a running container</h2></a>
<span class="timestamp"> </span> /var/tmp/go/src/github.com<a class="codelink" href='https://github.com/containers/podman/blob/40f5d8b1becd381c4e8283ed3940d09193e4fe06/test/e2e/pod_rm_test.go#L119'>/containers/podman/test/e2e/pod_rm_test.go:119</a>
<span class="timestamp">[+1405s] </span>•
</pre>
<hr />
<pre>
<span class="timestamp">[+1405s] </span>Podman run entrypoint
<span class="timestamp"> </span><a name='t--podman-run-entrypoint---1'><h2> podman run entrypoint == [&quot;&quot;]</h2></a>
<span class="timestamp"> </span> /var/tmp/go/src/github.com<a class="codelink" href='https://github.com/containers/podman/blob/40f5d8b1becd381c4e8283ed3940d09193e4fe06/test/e2e/run_entrypoint_test.go#L47'>/containers/podman/test/e2e/run_entrypoint_test.go:47</a>
<span class="timestamp">[+0184s] </span>S <span class="log-skip">[SKIPPING] [3.086 seconds]</span>
<span class="timestamp">[+1385s] </span>S <span class="log-skip">[SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds]</span>
<span class="timestamp">[+1512s] </span>Summarizing 6 Failures:
[+1512s]
<span class="timestamp"> </span><b>[Fail] Podman play kube with build [It] <a href='#t----build-should-override-image-in-store--1'>--build should override image in store</a></b>
<span class="timestamp"> </span>/var/tmp/go/src/github.com<a class="codelink" href='https://github.com/containers/podman/blob/40f5d8b1becd381c4e8283ed3940d09193e4fe06/test/e2e/play_build_test.go#L259'>/containers/podman/test/e2e/play_build_test.go:259</a>
== simple python == simple python