http://qs1969.pair.com?node_id=11138498


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

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.


🦛

Replies are listed 'Best First'.
Re^4: Test::Harness bug ? ... or author idiocy ?
by syphilis (Archbishop) on Nov 06, 2021 at 12:57 UTC
    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).


      🦛

        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</>

        Yeah ... that (and other points you make) seems reasonable.
        Thanks.

        I think it has now been shown to be a case of "author idiocy". (Not surprising, really.)

        Cheers,
        Rob