Re: TAP output format in pg_regress

> On 23 Nov 2022, at 00:56, Andres Freund <andres(at)anarazel(dot)de> wrote:
> On 2022-11-22 23:17:44 +0100, Daniel Gustafsson wrote:
>> The attached v10 attempts to address the points raised above. Notes and
>> diagnostics are printed to stdout/stderr respectively and the TAP emitter is
>> changed to move more of the syntax into it making it less painful on the
>> translators.
>
> Thanks! I played a bit with it locally and it's nice.

Thanks for testing and reviewing!

> I think it might be worth adding a few more details to the output on stderr,
> e.g. a condensed list of failed tests, as that's then printed in the errorlogs
> summary in meson after running all tests. As we don't do that in the current
> output, that seems more like an optimization for later.

Since this patch already change the output verbosity it seems within the goal-
posts to do this now rather than later. I've added a first stab at this in the
attached patch.

> My compiler complains with:
>
> [6/80 7 7%] Compiling C object src/test/regress/pg_regress.p/pg_regress.c.o
> ../../../../home/andres/src/postgresql/src/test/regress/pg_regress.c: In function ‘emit_tap_output_v’:
> ../../../../home/andres/src/postgresql/src/test/regress/pg_regress.c:354:9: warning: function ‘emit_tap_output_v’ might be a candidate for ‘gnu_printf’ format attribute [-Wsuggest-attribute=format]
> 354 | vfprintf(fp, fmt, argp);
> | ^~~~~~~~
> ../../../../home/andres/src/postgresql/src/test/regress/pg_regress.c:356:17: warning: function ‘emit_tap_output_v’ might be a candidate for ‘gnu_printf’ format attribute [-Wsuggest-attribute=format]
> 356 | vfprintf(logfile, fmt, argp_logfile);
> | ^~~~~~~~
>
> Which seems justified and easily remedied via pg_attribute_printf().

Fixed.

> I think there might be something slightly wrong with 'tags' - understandable,
> since there's basically no comment explaining what it's supposed to do. I
> added an intentional failure to 'show.pgc', which then yielded the following
> tap output:
> ok 51 sql/quote 15 ms
> not ok 52 sql/show 9 ms
> # tags: stdout source ok 53 sql/insupd 11 ms
> ok 54 sql/parser 13 ms
>
> which then subsequently leads meson to complain that
> TAP parsing error: out of order test numbers
> TAP parsing error: Too few tests run (expected 62, got 61)
>
> Looks like all that's needed is a \n after "tags: %s"

Ugh, yes, I forgot to run my ecpg tests before submitting. Fixed.

> I think the patch is also missing a \n after in log_child_failure().

Fixed.

>> Subject: [PATCH v10 2/2] Experimental: meson: treat regress tests as TAP
>
> I'd just squash that in I think. Isn't really experimental either IMO ;)

Done.

>> + if (type == DIAG || type == BAIL)
>> + fp = stderr;
>
> Personally I'd move the initialization of fp to an else branch here, but
> that's a very minor taste thing.

I actually had it like that before, moved it and wasn't sure what I preferred.
Moved back.

>> + fprintf(stdout, "Bail Out!");
>> + if (logfile)
>> + fprintf(logfile, "Bail Out!");
>
> I think this needs a \n.

Fixed.

> I was wondering whether it's worth having an printf wrapper that does the
> vfprintf(); if (logfile) vfprintf() dance. But it's proably not.

Not sure if the saved lines of code justifies the loss of readability.

>> + /* Not using the normal bail() here as we want _exit */
>> + _bail(_("could not exec \"%s\": %s\n"), shellprog, strerror(errno));
>
> Not in love with _bail, but I don't immediately have a better idea.

Agreed on both counts.

>> + pg_log_error(_("# could not open file \"%s\" for reading: %s"),
>> + file, strerror(errno));
>
> Hm. Shouldn't this just use diag()?

It should. I've changed all uses of pg_log_error to be diag or bail for
consistency in output, except for the one in getopt.

>> + test_status_ok(tests[i], INSTR_TIME_GET_MILLISEC(stoptimes[i]), (num_tests > 1));
>>
>> if (statuses[i] != 0)
>> log_child_failure(statuses[i]);
>
> Hm. We probably shouldn't treat the test as a success if statuses[i] != 0?
> Although it sure looks like we did so far.

Thats a good point, I admittedly hadn't thought about it. 55de145d1cf6f1d1b9
doesn't mention why it's done this way, maybe it's assumed that if the process
died then the test would've failed anyways (which is likely true but not
guaranteed to be so).

As it's unrelated to the question of output format I'll open a new thread with
that question to keep it from being buried here.

>> - printf("%s ", tl->str);
>> + appendStringInfo(&tagbuf, "%s ", tl->str);
>
> Why does tagbuf exist? Afaict it just is handed off 1:1 to test_status_failed?

The relevant tags to print are collected in a StringInfo buffer in order to be
able to print them together with the failed status as they are only printed on
test failure. Another option, which I tried in the attached version, could be
to print them the loop above as we do with parallel tests in wait_for_tests().
To keep it simple and not invent new code for this narrow usecase I opted for
the simple solution of one tag per diag line, like this:

# tag: stdout
# tag: source
not ok 52 sql/show 152 ms

I personally think thats fine, but it can be tweaked to print "# tags: stdout,
source" instead if we want to keep it closer to the current format.

> While the above may sound like a fair bit of work, I think it's actually not
> that much work, and we should strive to get this committed pretty soon!

The attached v11 fixes the above and have had a pgindent run on it as it's
hopefully getting close to done. Thanks again for reviewing!

--
Daniel Gustafsson https://vmware.com/