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 <santiago@redhat.com>
author: Ed Santiago <santiago@redhat.com> 2020-04-17 08:00:17 -0600
committer: Ed Santiago <santiago@redhat.com> 2020-04-17 08:12:09 -0600
commit: 1be8a34f5e86c3174681f2a5ffa7bdca176a1137 (patch)
tree: 295f26a13055deb6f9a460df9de65766926aedea
parent: d31dcb9bbd521fe8e3e78b0ebe2a893634ab2e6b (diff)
download: podman-1be8a34f5e86c3174681f2a5ffa7bdca176a1137.tar.gz
podman-1be8a34f5e86c3174681f2a5ffa7bdca176a1137.tar.bz2
podman-1be8a34f5e86c3174681f2a5ffa7bdca176a1137.zip
2 files changed, 227 insertions, 9 deletions
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);
 </script>
 </head>
 <body>
-<pre>
+<pre> <!-- begin processed output -->
 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("<a name='t--%05d'>%s</a>", $2, $line);
                 }
                 $line = "<span class='bats-$css'>$line</span>";
+
+                $bats_count{$css}++;
             }
 
             print { $out_fh } "<span class=\"timestamp\">$timestamp</span>"
@@ -354,7 +360,30 @@ END_HTML
     my $have_formatted_log;     # Set on success
 
     if ($out_fh) {
-        print { $out_fh } "</pre>\n";
+        # Summary line for BATS tests
+        if (keys %bats_count) {
+            print { $out_fh } "<hr/><span class='bats-summary'>Summary:";
+            my $total = 0;
+            my $comma = '';
+            for my $class (qw(passed failed skipped)) {
+                if (my $n = $bats_count{$class}) {
+                    printf { $out_fh } "%s <span class='bats-%s'>%d %s</span>",
+                        $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 } " <span class='bats-failed'>(WARNING: expected $expected_total)</span>";
+                }
+            }
+            print { $out_fh } "</span>\n";
+        }
+
+        print { $out_fh } "</pre>  <!-- end processed output -->\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 = <DATA>) {
+    chomp $line;
+
+    if ($line =~ /^==\s+(.*)/) {
+        push @tests, { name => $1, input => [], expect => [] };
+        $context = '';
+    }
+    elsif ($line =~ /^<<</) {
+        $context = 'input';
+    }
+    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 "<pre>"
+    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
+<span class='bats-passed'><a name='t--00001'>ok 1 hi</a></span>
+<span class='bats-skipped'><a name='t--00002'>ok 2 bye # skip no reason</a></span>
+<span class='bats-failed'><a name='t--00003'>not ok 3 fail</a></span>
+<span class='bats-passed'><a name='t--00004'>ok 4 blah</a></span>
+<hr/><span class='bats-summary'>Summary: <span class='bats-passed'>2 Passed</span>, <span class='bats-failed'>1 Failed</span>, <span class='bats-skipped'>1 Skipped</span>. Total tests: 4</span>
+
+
+
+
+
+
+
+== 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 |&amp; ${TIMESTAMP}
+[08:26:19] START - All [+xxxx] lines that follow are relative to right now.
+<span class="timestamp">[+0002s] </span>GO111MODULE=on go build -mod=vendor  -gcflags &#39;all=-trimpath=/var/tmp/go/src/github.com/containers/libpod&#39; -asmflags &#39;all=-trimpath=/var/tmp/go/src/github.com/containers/libpod&#39; -ldflags &#39;-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 &quot;&quot;&#39; -tags &quot;   selinux systemd exclude_graphdriver_devicemapper seccomp varlink&quot; -o bin/podman github.com/containers/libpod/cmd/podman
+<span class="timestamp">[+0103s] </span>•
+</pre>
+<hr />
+<pre>
+<span class="timestamp">[+0103s] </span>Podman pod restart
+<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>  /var/tmp/go/src/github.com<a class="codelink" href='https://github.com/containers/libpod/blob/40f5d8b1becd381c4e8283ed3940d09193e4fe06/test/e2e/pod_restart_test.go#L41'>/containers/libpod/test/e2e/pod_restart_test.go:41</a>
+<span class="timestamp">         </span>[BeforeEach] Podman pod restart
+<span class="timestamp">         </span>  /var/tmp/go/src/github.com<a class="codelink" href='https://github.com/containers/libpod/blob/40f5d8b1becd381c4e8283ed3940d09193e4fe06/test/e2e/pod_restart_test.go#L18'>/containers/libpod/test/e2e/pod_restart_test.go:18</a>
+<span class="timestamp">         </span>[It] podman pod restart single empty pod
+<span class="timestamp">         </span>  /var/tmp/go/src/github.com<a class="codelink" href='https://github.com/containers/libpod/blob/40f5d8b1becd381c4e8283ed3940d09193e4fe06/test/e2e/pod_restart_test.go#L41'>/containers/libpod/test/e2e/pod_restart_test.go:41</a>
+<span class="timestamp">         </span>Running: <span title="/var/tmp/go/src/github.com/containers/libpod/bin/podman"><b>podman</b></span> <span class="boring" title="--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">[options]</span><b> pod create --infra=false --share</b>
+<span class="timestamp">         </span>4810be0cfbd42241e349dbe7d50fbc54405cd320a6637c65fd5323f34d64af89
+<span class="timestamp">         </span>Running: <span title="/var/tmp/go/src/github.com/containers/libpod/bin/podman"><b>podman</b></span> <span class="boring" title="--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">[options]</span><b> pod restart 4810be0cfbd42241e349dbe7d50fbc54405cd320a6637c65fd5323f34d64af89</b>
+<span class="timestamp">         </span><span class='log-warn'>Error: no containers in pod 4810be0cfbd42241e349dbe7d50fbc54405cd320a6637c65fd5323f34d64af89 have no dependencies, cannot start pod: no such container</span>
+<span class="timestamp">         </span>output:
+<span class="timestamp">         </span>[AfterEach] Podman pod restart
+<span class="timestamp">         </span>  /var/tmp/go/src/github.com<a class="codelink" href='https://github.com/containers/libpod/blob/40f5d8b1becd381c4e8283ed3940d09193e4fe06/test/e2e/pod_restart_test.go#L28'>/containers/libpod/test/e2e/pod_restart_test.go:28</a>
+<span class="timestamp">         </span>Running: <span title="/var/tmp/go/src/github.com/containers/libpod/bin/podman"><b>podman</b></span> <span class="boring" title="--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">[options]</span><b> pod rm -fa</b>
+<span class="timestamp">         </span>4810be0cfbd42241e349dbe7d50fbc54405cd320a6637c65fd5323f34d64af89
+<span class="timestamp">[+0107s] </span>•
+</pre>
+<hr />
+<pre>
+<span class="timestamp">[+0107s] </span>podman system reset
author	Ed Santiago <santiago@redhat.com>	2020-04-17 08:00:17 -0600
committer	Ed Santiago <santiago@redhat.com>	2020-04-17 08:12:09 -0600
commit	1be8a34f5e86c3174681f2a5ffa7bdca176a1137 (patch)
tree	295f26a13055deb6f9a460df9de65766926aedea
parent	d31dcb9bbd521fe8e3e78b0ebe2a893634ab2e6b (diff)
download	podman-1be8a34f5e86c3174681f2a5ffa7bdca176a1137.tar.gz podman-1be8a34f5e86c3174681f2a5ffa7bdca176a1137.tar.bz2 podman-1be8a34f5e86c3174681f2a5ffa7bdca176a1137.zip