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
[download]

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
[download]

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}'
[download]

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}'
[download]

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'
[download]

with

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

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).

---

🦛

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