Re: [PATCH 6/7] test-lib: make --verbose output valid TAP

On Tue, Mar 09 2021, SZEDER Gábor wrote:

On Tue, Mar 09, 2021 at 05:02:18PM +0100, Ævar Arnfjörð Bjarmason wrote:

quoted

Make the --verbose output be valid TAP, making it machine-readable for
TAP parsers again.

Both the verbose and non-verbose test outputs were valid TAP back when
I added support for TAP in 5099b99d25f (test-lib: Adjust output to be
valid TAP format, 2010-06-24).

Sometime after that the --verbose output broke due to some tests
emitting their own lines starting "ok" (or otherwise invalidate the
TAP). That was noticed and fixed in 452320f1f5 (test-lib: add
--verbose-log option, 2016-10-21) and "fixed" by simply turning off
the verbose mode when we were running under TAP::Harness (e.g. under
"prove").

That solution worked for running under Travis CI. After that fix it
was made to use the --verbose-log option in 041c72de109 (travis: use
--verbose-log test option, 2016-10-21), see 522354d70f4 (Add Travis CI
support, 2015-11-27) for the "cat t/test-results/*.out" code that was
aimed at.

But that solution and others discussed in 452320f1f5 closed the door
on us having reliable machine-readable TAP output.

Let's instead revert the work done in 452320f1f5 and, as well as the
follow-up commits 88c6e9d31c (test-lib: --valgrind should not override
--verbose-log, 2017-09-05) and f5ba2de6bc (test-lib: make "-x" work
with "--verbose-log", 2017-12-08), which were only needed to work
around bugs in the the previous --verbose-log implementation.

Replace it with a simple method for ensuring that we have valid TAP
both on stdout, and in any verbose output we write. When we detect
that we're running under "prove" we prefix all legitimate TAP
directives with "GIT_TEST_TEE_STARTED":

    $ GIT_TEST_TEE_STARTED=1 ./t5547-push-quarantine.sh
    GIT_TEST_TEE_STARTED ok 1 - create picky dest repo
    GIT_TEST_TEE_STARTED ok 2 - accepted objects work
    [...]
    GIT_TEST_TEE_STARTED 1..6

Then, instead of piping the output to "tee -a" we pipe it to a helper
which first converts "ok" and other TAP syntax to e.g. "\ok", and then
strips that "GIT_TEST_TEE_STARTED " prefix from the start of the line.

The end result is that we're guaranteed to have valid TAP syntax on
stdout.

We can thus get rid of the --verbose-log special-case. Since that
option was meant to get around the TAP issue let's simply make it an
alias for "--verbose --tee".

Signed-off-by: Ævar Arnfjörð Bjarmason <redacted>

[Relpying to both replies in this sub-thread]

After applying this patch series there is still one place where we
look at $verbose_log:

  $ git grep -C4 verbose_log -- test-lib.sh
  test-lib.sh-
  test-lib.sh-exec 5>&1
  test-lib.sh-exec 6<&0
  test-lib.sh-exec 7>&2
  test-lib.sh:if test "$verbose_log" = "t"
  test-lib.sh-then
  test-lib.sh-    exec 3>>"$GIT_TEST_TEE_OUTPUT_FILE" 4>&3
  test-lib.sh-elif test "$verbose" = "t"
  test-lib.sh-then

Yes, well spotted. The way this patch is implemented that exec branch
should have been deleted. I just missed it.

[From your [ref]]:

quoted

diff --git a/t/README b/t/README
index 2cc8cbc7185..f09d94e754e 100644
--- a/t/README
+++ b/t/README

@@ -157,10 +157,13 @@ appropriately before running "make". Short options can be bundled, i.e.
 
 -V::
 --verbose-log::
-	Write verbose output to the same logfile as `--tee`, but do
-	_not_ write it to stdout. Unlike `--tee --verbose`, this option
+	An alias for `--verbose --tee`. This option
 	is safe to use when stdout is being consumed by a TAP parser
-	like `prove`. Implies `--tee` and `--verbose`.
+	like `prove`.
+	Historically this option was different from `--verbose --tee`
+	and would not write any verbose output to stdout to ensure the
+	TAP-correctness of the output. The TAP-correctness of the
+	output is now sanity checked by the test library,

Not everyone is using a TAP harness to run the tests, and, therefore,
'--verbose-log' should not spew out verbose output to the terminal.

IOW even though --verbose-log was meant as a hack to make prove happy,
you've since come to like the "verbose in log, but not stdout" mode and
want that kept?

Yes, this patch takes that mode away.

Yes, I can change it.

Would your use-case for this be satisfied by having prove(1) just emit
different output for you in this scenario, so you'd need to invoke this
as something like:

    prove <test> :: --verbose --tee # or --verbose-log

Becuse the advantage of this series is that that sort of thing becomes
really trivial without everything needing to be hardcoded in
test-lib.sh, observe (this is with my series):

    
    0 $ PERL5LIB=. prove -v --formatter=SZEDERVerboseLog ./t0201-gettext-fallbacks.sh :: --verbose-log
    # lib-gettext: No is_IS UTF-8 locale available
    # lib-gettext: No is_IS ISO-8859-1 locale available
    ok 1 - sanity: $GIT_INTERNAL_GETTEXT_SH_SCHEME is set (to fallthrough)
    ok 2 - sanity: $GIT_INTERNAL_GETTEXT_TEST_FALLBACKS is set
    ok 3 - sanity: $GIT_INTERNAL_GETTEXT_SH_SCHEME" is fallthrough
    ok 4 - gettext: our gettext() fallback has pass-through semantics
    ok 5 - eval_gettext: our eval_gettext() fallback has pass-through semantics
    ok 6 - eval_gettext: our eval_gettext() fallback can interpolate variables
    ok 7 - eval_gettext: our eval_gettext() fallback can interpolate variables with spaces
    ok 8 - eval_gettext: our eval_gettext() fallback can interpolate variables with spaces and quotes
    # passed all 8 test(s)
    1..8
    ok
    All tests successful.
    Files=1, Tests=8,  1 wallclock secs ( 0.01 usr  0.01 sys +  0.07 cusr  0.01 csys =  0.10 CPU)
    Result: PASS
    $ wc -l test-results/t0201-gettext-fallbacks.out 
    75 test-results/t0201-gettext-fallbacks.out

All without any patching on top to the test-lib.sh, just:
    
    $ cat SZEDERVerboseLog.pm 
    package SZEDERVerboseLog::Session;
    use base 'TAP::Formatter::Console::Session';
    
    sub result {
        my ($self, $result) = @_;
        return if $result->is_unknown;
        return $self->SUPER::result($result);
    }
    
    package SZEDERVerboseLog;
    use strict;
    use warnings;
    use base 'TAP::Formatter::Console';
    
    sub open_test {
        my ($self, $test, $parser) = @_;
        my $session = SZEDERVerboseLog::Session->new( {
            name            => $test,
            formatter       => $self,
            parser          => $parser,
        } );
        return $session;
    }
    
    1;

The "is_unknown" is everything that's not TAP syntax.