Re: bailing out in tap tests nearly always a bad idea

On 2/22/22 13:19, Andres Freund wrote:
> Hi,
>
> On 2022-02-22 09:28:37 -0800, Andres Freund wrote:
>> On 2022-02-14 09:46:20 -0800, Andres Freund wrote:
>>>> t/die-immediately.t .... aieee at t/die-immediately.t line 1.
>>>> t/die-immediately.t .... Dubious, test returned 255 (wstat 65280, 0xff00)
>>>> No subtests run
>>> Hm. Looks different when a test is including our test helpers.
>>>
>>> t/000_die_pg_test_utils.pl .. Dubious, test returned 25 (wstat 6400, 0x1900)
>>> No subtests run
>>> t/000_die_test_more.pl ...... error at t/000_die_test_more.pl line 2.
>>> t/000_die_test_more.pl ...... Dubious, test returned 255 (wstat 65280, 0xff00)
>>> No subtests run
>>>
>>> So I think we broke something... I think it's the log file redirection stuff
>>> in INIT.
>> Any chance somebody with more perl knowledge could look into this? Clearly our
>> effort to copy all the output the original file descriptors isn't successful
>> here.
>>
>> $ perl -I /home/andres/src/postgresql/src/test/perl/ -e "use PostgreSQL::Test::Utils; die 'blorb';"
>> $ perl -I /home/andres/src/postgresql/src/test/perl/ -e "use Test::More; die 'blorb';"
>> blorb at -e line 1.
> So the problem is that die just outputs to stderr, but we've decided to have
> stderr connected to the output going to tap for some reason. I guess that
> prevents us from messing up the tap output, but it's still weird. Because of
> that redirection, die printing to stderr isn't visible to tap.
>
> Seems we can use black magic to "fix" that... Putting the following into
> INIT{} seems to do the trick:
>
> # Because of the above redirection the tap output wouldn't contain
> # information about tests failing due to die etc. Fix that by also
> # printing the failure to the original stderr.
> $SIG{__DIE__} = sub
> {
> # Don't redirect if it's a syntax error ($^S is undefined) or in an
> # eval block ($^S == 1).
> if (defined $^S and $^S == 0)
> {
> print $orig_stderr "$_[0]\n";
> #fail("died: $_[0]");
> #done_testing();
> }
> };
>
>
> $ cat /tmp/die_pg_utils.pl
> use PostgreSQL::Test::Utils;
> use Test::More;
>
> ok(1, "foo");
> die 'blorb';
> done_testing();
>
> With the print we get something like:
>
> $ perl -I /home/andres/src/postgresql/src/test/perl/ /tmp/die_pg_utils.pl
> ok 1 - foo
> blorb at /tmp/die_pg_utils.pl line 5.
>
> # Tests were run but no plan was declared and done_testing() was not seen.
> # Looks like your test exited with 25 just after 1.
>
> With the fail() and done_testing() we get
>
> $ perl -I /home/andres/src/postgresql/src/test/perl/ /tmp/die_pg_utils.pl
> ok 1 - foo
> not ok 2 - died: blorb at /tmp/die_pg_utils.pl line 5.
> #
> # Failed test 'died: blorb at /tmp/die_pg_utils.pl line 5.
> # '
> # at /home/andres/src/postgresql/src/test/perl/PostgreSQL/Test/Utils.pm line 235.
> 1..2
> # Looks like your test exited with 25 just after 2.
>
>
> The latter output doesn't confuse with stuff about plans and exit codes. But
> contains redundant messages (whatever) and it doesn't seem particularly clean
> to hijack a "test number".
>

I'll be surprised if we can't come up with something cleaner than that.

cheers

andrew

--
Andrew Dunstan
EDB: https://www.enterprisedb.com