Beefy Boxes and Bandwidth Generously Provided by pair Networks
No such thing as a small change
 
PerlMonks  

Re^2: Test::Harness bug ? ... or author idiocy ?

by syphilis (Archbishop)
on Nov 06, 2021 at 06:37 UTC ( #11138492=note: print w/replies, xml ) Need Help??


in reply to Re: Test::Harness bug ? ... or author idiocy ?
in thread Test::Harness bug ? ... or author idiocy ?

If you can supply a reproducible test case then no doubt others could test and determine if it is indeed an MSWin32-only issue.

Actually I can (and just have) tested it out on Ubuntu, perl-5.34.0 and it's the same issue.

Here's an Inline::C demo of the problem:
Firstly, with the printf() statement commented out:
use strict; use warnings; use Inline C => <<'EOC'; SV * foo( SV * in ) { /* printf("# %s\n", SvPV_nolen(in)); */ return newSVpv(SvPV_nolen(in), 0); } EOC my $ok = 1; print "1..1\n"; for(1 .. 1000) { my $n = int(rand(10000000)); $ok = 0 if foo("$n") ne "$n"; } if($ok) { print "ok 1\n" } else { print "not ok 1\n"; } __END__
I first run perl try.pl to compile the script, and then I run:
$ perl -MTAP::Harness -e '$h = TAP::Harness->new(); $h->runtests("./tr +y.pl");' ./try.pl .. ok All tests successful. Files=1, Tests=1, 0 wallclock secs ( 0.04 usr 0.01 sys + 0.06 cusr + 0.01 csys = 0.12 CPU) Result: PASS
As you can see, everything is fine. But if I then include the printf() statement and run perl try.pl (to recompile the script), upon re-testing I get:
$ perl -MTAP::Harness -e '$h = TAP::Harness->new(); $h->runtests("./t +ry.pl");' ./try.pl .. All 1 subtests passed Test Summary Report ------------------- ./try.pl (Wstat: 0 Tests: 1 Failed: 0) Parse errors: No plan found in TAP output Files=1, Tests=1, 1 wallclock secs ( 0.11 usr 0.01 sys + 0.05 cusr + 0.02 csys = 0.19 CPU) Result: FAIL
Cheers,
Rob

Replies are listed 'Best First'.
Re^3: Test::Harness bug ? ... or author idiocy ?
by hippo (Bishop) on Nov 06, 2021 at 12:04 UTC

    Thanks for this example. I have run your code with the printf uncommented and reproduced your findings (on Linux) but only on some runs. The result is inconsistent. Here is the output from 2 runs within a few seconds of each other:

    10045 $ perl -MTAP::Harness -e '$h = TAP::Harness->new(); $h->runtests +("./11138492.pl");' ./11138492.pl .. ok All tests successful. Files=1, Tests=1, 0 wallclock secs ( 0.06 usr 0.00 sys + 0.04 cusr + 0.00 csys = 0.10 CPU) Result: PASS 10046 $ perl -MTAP::Harness -e '$h = TAP::Harness->new(); $h->runtests +("./11138492.pl");' ./11138492.pl .. All 1 subtests passed Test Summary Report ------------------- ./11138492.pl (Wstat: 0 Tests: 1 Failed: 0) Parse errors: No plan found in TAP output Files=1, Tests=1, 0 wallclock secs ( 0.06 usr 0.01 sys + 0.04 cusr + 0.00 csys = 0.11 CPU) Result: FAIL

    However, upon inspection the problem is not with TAP::Harness. The output of just running the script shows that the plan can appear in the middle of your data. Again, running a few times gives:

    10046 $ perl 11138492.pl | grep -Fn 1..1 830:# 79678951..1 10047 $ perl 11138492.pl | grep -Fn 1..1 830:# 691..1 10047 $ perl 11138492.pl | grep -Fn 1..1 829:# 5056771..1

    So this looks to be a buffering issue. If I simply modify your code to include $|++; before the plan is printed then the script runs fine, the plan is printed at the top and the test harness has no complaints.

    Not a bug in Test::Harness after all.


    🦛

      Not a bug in Test::Harness after all.

      Cool ... creating bug reports always ends up in being more work than one anticipates.
      Thank you !!

      If I simply modify your code to include $|++; before the plan is printed then the script runs fine

      I thought that print "1..1\n" should flush the buffer immediately (because of the "\n") without any need to increment $|.
      And this notion is supported by the following one-liner that prints out a "." followed by a newline every second for 10 seconds:
      $ perl -e 'for(1..10) {print ".\n"; sleep 1}'
      whereas this next one-liner (as expected) prints nothing for 10 seconds, and then immediately prints out all 10 dots:
      $ perl -e 'for(1..10) {print "."; sleep 1}'
      I don't doubt that I'm missing something pretty basic ... and I shudder to think what the answer might be .... but I'll ask the question "what is it that I'm missing ?", anyway ;-)

      Cheers,
      Rob

        Your trivial examples are printing to the shell, presumably in a terminal. That is what makes it default to autoflush. Redirect that output and it's a different story. Compare:

        $ perl -e 'for(1..10) {print ".\n"; sleep 1}' | sed -e 's/\./#/g'

        with

        $ perl -e '$|++; for(1..10) {print ".\n"; sleep 1}' | sed -e 's/\./#/g +'

        See the excellent Suffering from Buffering (particularly the section Hot and Not Hot) for more on this.

        When something else is wrapping the STDOUT, like your test harness for example, then the autoflushing is no longer applied by default. Everything in Perl should still be printed in the right order but I expect that the printf output in the C part is bypassing the higher-level buffer (just a guess - I don't know enough about how Inline::C works to say for sure).


        🦛

Re^3: Test::Harness bug ? ... or author idiocy ?
by Anonymous Monk on Nov 06, 2021 at 07:19 UTC
      Plan has to go first

      Sorry - I'm not clever enough to grasp your point.
      AFAICS, the "Plan" is in exactly the same location, irrespective of whether the printf() statement is included or not.

      Cheers,
      Rob

Log In?
Username:
Password:

What's my password?
Create A New User
Domain Nodelet?
Node Status?
node history
Node Type: note [id://11138492]
help
Chatterbox?
and the web crawler heard nothing...

How do I use this? | Other CB clients
Other Users?
Others scrutinizing the Monastery: (4)
As of 2022-06-27 11:29 GMT
Sections?
Information?
Find Nodes?
Leftovers?
    Voting Booth?
    My most frequent journeys are powered by:









    Results (88 votes). Check out past polls.

    Notices?