From 1be8a34f5e86c3174681f2a5ffa7bdca176a1137 Mon Sep 17 00:00:00 2001 From: Ed Santiago Date: Fri, 17 Apr 2020 08:00:17 -0600 Subject: Log formatter: add BATS summary line BATS emits a summary line (number of tests passed/failed)... but only on a tty or when run with --pretty! In our CI context, with TAP output, it gives no end summary. Fix that. Keep track of 'ok', 'not ok', and 'skipped', and display the counts at the end. Also: add a regression test. You don't need to review or even read it: it's stark, and I'm not even enabling it for CI because it almost certainly won't run due to missing Perl library modules. It's just something I need on my end. Signed-off-by: Ed Santiago --- contrib/cirrus/logformatter | 47 +++++++++-- contrib/cirrus/logformatter.t | 189 ++++++++++++++++++++++++++++++++++++++++++ 2 files changed, 227 insertions(+), 9 deletions(-) create mode 100755 contrib/cirrus/logformatter.t diff --git a/contrib/cirrus/logformatter b/contrib/cirrus/logformatter index 738d2e19d..4bfe7b97f 100755 --- a/contrib/cirrus/logformatter +++ b/contrib/cirrus/logformatter @@ -52,12 +52,14 @@ a.codelink:hover { background: #000; color: #999; } a.timing { text-decoration: none; } /* BATS styles */ -.bats-ok { color: #393; } -.bats-notok { color: #F00; font-weight: bold; } -.bats-skip { color: #F90; } +.bats-passed { color: #393; } +.bats-failed { color: #F00; font-weight: bold; } +.bats-skipped { color: #F90; } .bats-log { color: #900; } .bats-log-esm { color: #b00; font-weight: bold; } +.bats-summary { font-size: 150%; } + /* error titles: display next to timestamp, not on separate line */ h2 { display: inline; } END_CSS @@ -169,7 +171,7 @@ window.addEventListener("load", scrollToBottom, false); -
+
 
 END_HTML
 
     # State variables
@@ -181,6 +183,7 @@ END_HTML
     my $after_divider = 0;        # Count of lines after seeing '-----'
     my $current_output;           # for removing duplication
     my $looks_like_bats;          # binary flag: for detecting BATS results
+    my %bats_count;               # For summary line: count of pass/fail/skip
 
     # Main loop: read input, one line at a time, and write out reformatted
   LINE:
@@ -221,15 +224,16 @@ END_HTML
         }
 
         # BATS handling (used also for apiv2 tests, which emit TAP output)
-        if ($line =~ /^1\.\.\d+$/ || $line =~ m!/test-apiv2!) {
+        if ($line =~ /^1\.\.(\d+)$/ || $line =~ m!/test-apiv2!) {
             $looks_like_bats = 1;
+            $bats_count{expected_total} = $1;
         }
         if ($looks_like_bats) {
             my $css;
 
-            if    ($line =~ /^ok\s.*\s# skip/) { $css = 'skip'    }
-            elsif ($line =~ /^ok\s/)           { $css = 'ok'      }
-            elsif ($line =~ /^not\s+ok\s/)     { $css = 'notok'   }
+            if    ($line =~ /^ok\s.*\s# skip/) { $css = 'skipped' }
+            elsif ($line =~ /^ok\s/)           { $css = 'passed'  }
+            elsif ($line =~ /^not\s+ok\s/)     { $css = 'failed'  }
             elsif ($line =~ /^#\s#\|\s/)       { $css = 'log-esm' }
             elsif ($line =~ /^#\s/)            { $css = 'log'     }
 
@@ -239,6 +243,8 @@ END_HTML
                     $line = sprintf("%s", $2, $line);
                 }
                 $line = "$line";
+
+                $bats_count{$css}++;
             }
 
             print { $out_fh } "$timestamp"
@@ -354,7 +360,30 @@ END_HTML
     my $have_formatted_log;     # Set on success
 
     if ($out_fh) {
-        print { $out_fh } "
\n";
+        # Summary line for BATS tests
+        if (keys %bats_count) {
+            print { $out_fh } "
Summary:";
+            my $total = 0;
+            my $comma = '';
+            for my $class (qw(passed failed skipped)) {
+                if (my $n = $bats_count{$class}) {
+                    printf { $out_fh } "%s %d %s",
+                        $comma, $class, $n, ucfirst($class);
+                    $total += $n;
+                    $comma = ',';
+                }
+            }
+
+            printf { $out_fh } ". Total tests: $total";
+            if (my $expected_total = $bats_count{expected_total}) {
+                if ($total != $expected_total) {
+                    print { $out_fh } " (WARNING: expected $expected_total)";
+                }
+            }
+            print { $out_fh } "\n";
+        }
+
+        print { $out_fh } "
\n"; # Did we find a cirrus task? Link back. if ($cirrus_task) { diff --git a/contrib/cirrus/logformatter.t b/contrib/cirrus/logformatter.t new file mode 100755 index 000000000..79c4563c2 --- /dev/null +++ b/contrib/cirrus/logformatter.t @@ -0,0 +1,189 @@ +#!/usr/bin/perl +# +# tests for logformatter +# +(our $ME = $0) =~ s|^.*/||; + +use v5.14; +use strict; +use warnings; + +use FindBin; +use File::Temp qw(tempdir); +use Test::More; + +# +# Read the test cases (see __END__ section below) +# +my @tests; +my $context = ''; +while (my $line = ) { + chomp $line; + + if ($line =~ /^==\s+(.*)/) { + push @tests, { name => $1, input => [], expect => [] }; + $context = ''; + } + elsif ($line =~ /^<<>>/) { + $context = 'expect'; + } + elsif (@tests && $line) { + push @{ $tests[-1]{$context} }, $line; + } +} + +plan tests => scalar(@tests); + +my $tempdir = tempdir("logformatter-test.XXXXXX", TMPDIR => 1, CLEANUP => !$ENV{DEBUG}); + +chdir $tempdir + or die "$ME: Could not cd $tempdir: $!\n"; + +for my $t (@tests) { + my $name = $t->{name}; + (my $fname = $name) =~ s/\s+/_/g; + + open my $fh_out, '>', "$fname.txt" + or die "$ME: Cannot create $tempdir/$fname.txt: $!\n"; + print { $fh_out } "$_\n" for @{$t->{input}}; + close $fh_out + or die "$ME: Error writing $tempdir/$fname.txt: $!\n"; + + system("$FindBin::Bin/logformatter $fname <$fname.txt >/dev/null"); + open my $fh_in, '<', "$fname.log.html" + or die "$ME: Fatal: $fname: logformatter did not create .log.html\n"; + my @actual; + while (my $line = <$fh_in>) { + chomp $line; + push @actual, $line if $line =~ / begin processed output / .. $line =~ / end processed output /; + } + close $fh_in; + + # Strip off leading and trailing "
"
+    shift @actual; pop @actual;
+
+    # For debugging: preserve expected results
+    if ($ENV{DEBUG}) {
+        open my $fh_out, '>', "$fname.expect";
+        print { $fh_out } "$_\n" for @{$t->{expect}};
+        close $fh_out;
+    }
+
+    is_deeply \@actual, $t->{expect}, $name;
+}
+
+chdir '/';
+
+
+
+__END__
+
+== simple bats
+
+<<<
+1..4
+ok 1 hi
+ok 2 bye # skip no reason
+not ok 3 fail
+ok 4 blah
+>>>
+1..4
+ok 1 hi
+ok 2 bye # skip no reason
+not ok 3 fail
+ok 4 blah
+
Summary: 2 Passed, 1 Failed, 1 Skipped. Total tests: 4
+
+
+
+
+
+
+
+== simple ginkgo
+
+<<<
+$SCRIPT_BASE/integration_test.sh |& ${TIMESTAMP}
+[08:26:19] START - All [+xxxx] lines that follow are relative to right now.
+[+0002s] GO111MODULE=on go build -mod=vendor  -gcflags 'all=-trimpath=/var/tmp/go/src/github.com/containers/libpod' -asmflags 'all=-trimpath=/var/tmp/go/src/github.com/containers/libpod' -ldflags '-X github.com/containers/libpod/libpod/define.gitCommit=40f5d8b1becd381c4e8283ed3940d09193e4fe06 -X github.com/containers/libpod/libpod/define.buildInfo=1582809981 -X github.com/containers/libpod/libpod/config._installPrefix=/usr/local -X github.com/containers/libpod/libpod/config._etcDir=/etc -extldflags ""' -tags "   selinux systemd exclude_graphdriver_devicemapper seccomp varlink" -o bin/podman github.com/containers/libpod/cmd/podman
+[+0103s] •
+[+0103s] ------------------------------
+[+0103s] Podman pod restart
+[+0103s]   podman pod restart single empty pod
+[+0103s]   /var/tmp/go/src/github.com/containers/libpod/test/e2e/pod_restart_test.go:41
+[+0103s] [BeforeEach] Podman pod restart
+[+0103s]   /var/tmp/go/src/github.com/containers/libpod/test/e2e/pod_restart_test.go:18
+[+0103s] [It] podman pod restart single empty pod
+[+0103s]   /var/tmp/go/src/github.com/containers/libpod/test/e2e/pod_restart_test.go:41
+[+0103s] Running: /var/tmp/go/src/github.com/containers/libpod/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 --cni-config-dir /etc/cni/net.d --cgroup-manager systemd --tmpdir /tmp/podman_test553496330 --events-backend file --storage-driver vfs pod create --infra=false --share
+[+0103s] 4810be0cfbd42241e349dbe7d50fbc54405cd320a6637c65fd5323f34d64af89
+[+0103s] output: 4810be0cfbd42241e349dbe7d50fbc54405cd320a6637c65fd5323f34d64af89
+[+0103s] Running: /var/tmp/go/src/github.com/containers/libpod/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 --cni-config-dir /etc/cni/net.d --cgroup-manager systemd --tmpdir /tmp/podman_test553496330 --events-backend file --storage-driver vfs pod restart 4810be0cfbd42241e349dbe7d50fbc54405cd320a6637c65fd5323f34d64af89
+[+0103s] Error: no containers in pod 4810be0cfbd42241e349dbe7d50fbc54405cd320a6637c65fd5323f34d64af89 have no dependencies, cannot start pod: no such container
+[+0103s] output:
+[+0103s] [AfterEach] Podman pod restart
+[+0103s]   /var/tmp/go/src/github.com/containers/libpod/test/e2e/pod_restart_test.go:28
+[+0103s] Running: /var/tmp/go/src/github.com/containers/libpod/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 --cni-config-dir /etc/cni/net.d --cgroup-manager systemd --tmpdir /tmp/podman_test553496330 --events-backend file --storage-driver vfs pod rm -fa
+[+0103s] 4810be0cfbd42241e349dbe7d50fbc54405cd320a6637c65fd5323f34d64af89
+[+0107s] •
+[+0107s] ------------------------------
+[+0107s] podman system reset
+>>>
+$SCRIPT_BASE/integration_test.sh |& ${TIMESTAMP}
+[08:26:19] START - All [+xxxx] lines that follow are relative to right now.
+[+0002s] GO111MODULE=on go build -mod=vendor  -gcflags 'all=-trimpath=/var/tmp/go/src/github.com/containers/libpod' -asmflags 'all=-trimpath=/var/tmp/go/src/github.com/containers/libpod' -ldflags '-X github.com/containers/libpod/libpod/define.gitCommit=40f5d8b1becd381c4e8283ed3940d09193e4fe06 -X github.com/containers/libpod/libpod/define.buildInfo=1582809981 -X github.com/containers/libpod/libpod/config._installPrefix=/usr/local -X github.com/containers/libpod/libpod/config._etcDir=/etc -extldflags ""' -tags "   selinux systemd exclude_graphdriver_devicemapper seccomp varlink" -o bin/podman github.com/containers/libpod/cmd/podman
+[+0103s] •
+
+
+
+[+0103s] Podman pod restart
+         
  podman pod restart single empty pod

+           /var/tmp/go/src/github.com/containers/libpod/test/e2e/pod_restart_test.go:41
+         [BeforeEach] Podman pod restart
+           /var/tmp/go/src/github.com/containers/libpod/test/e2e/pod_restart_test.go:18
+         [It] podman pod restart single empty pod
+           /var/tmp/go/src/github.com/containers/libpod/test/e2e/pod_restart_test.go:41
+         Running: podman [options] pod create --infra=false --share
+         4810be0cfbd42241e349dbe7d50fbc54405cd320a6637c65fd5323f34d64af89
+         Running: podman [options] pod restart 4810be0cfbd42241e349dbe7d50fbc54405cd320a6637c65fd5323f34d64af89
+         Error: no containers in pod 4810be0cfbd42241e349dbe7d50fbc54405cd320a6637c65fd5323f34d64af89 have no dependencies, cannot start pod: no such container
+         output:
+         [AfterEach] Podman pod restart
+           /var/tmp/go/src/github.com/containers/libpod/test/e2e/pod_restart_test.go:28
+         Running: podman [options] pod rm -fa
+         4810be0cfbd42241e349dbe7d50fbc54405cd320a6637c65fd5323f34d64af89
+[+0107s] •
+
+
+
+[+0107s] podman system reset
-- 
cgit v1.2.3-54-g00ecf