todo_output IO handle confusion in persistent (SpeedyCGI) environment

[ribasushi]

Attached test file (modeled on this section of the DBIC leaktest) has differing STDERR output on stable and dev Test::More as can be seen below:

rabbit@Ahasver:/dev/shm/scgi$ cpanm Test::More --reinstall
--> Working on Test::More
Fetching http://www.cpan.org/authors/id/E/EX/EXODIST/Test-Simple-1.001014.tar.gz ... OK
Configuring Test-Simple-1.001014 ... OK
Building and testing Test-Simple-1.001014 ... OK
Successfully installed Test-Simple-1.001014 (downgraded from 1.302014_003)
1 distribution installed

rabbit@Ahasver:/dev/shm/scgi$ prove scgi.t
scgi.t .. # Testing on perl 5.022000 with SpeedyCGI from git://github.com/dbsrgits/cgi-speedycgi.git on Test::More 1.001014
scgi.t .. ok   
All tests successful.
Files=1, Tests=8,  1 wallclock secs ( 0.03 usr  0.00 sys +  0.03 cusr  0.01 csys =  0.07 CPU)
Result: PASS

rabbit@Ahasver:/dev/shm/scgi$ cpanm Test::More --reinstall --dev
--> Working on Test::More
Fetching http://cpan.metacpan.org/authors/id/E/EX/EXODIST/Test-Simple-1.302014_003.tar.gz ... OK
Configuring Test-Simple-1.302014_003 ... OK
Building and testing Test-Simple-1.302014_003 ... OK
Successfully installed Test-Simple-1.302014_003 (upgraded from 1.001014)
1 distribution installed

rabbit@Ahasver:/dev/shm/scgi$ prove scgi.t
scgi.t .. # Testing on perl 5.022000 with SpeedyCGI from git://github.com/dbsrgits/cgi-speedycgi.git on Test::More 1.302014003
scgi.t .. 1/? 
#   Failed test 'MY LITTLE PONY IS OK!'
#   at /home/rabbit/perl5/perlbrew/perls/5.22.0_rcf/lib/site_perl/5.22.0/Test/Builder.pm line 136.

#   Failed test 'MY LITTLE PONY IS OK!'
#   at /home/rabbit/perl5/perlbrew/perls/5.22.0_rcf/lib/site_perl/5.22.0/Test/Builder.pm line 136.
scgi.t .. ok   
All tests successful.
Files=1, Tests=8,  1 wallclock secs ( 0.04 usr  0.00 sys +  0.06 cusr  0.00 csys =  0.10 CPU)
Result: PASS

[exodist]

Thanks for the report, I will look into it asap.

[exodist]

Do you have an easy way to reproduce that does not involve installing SpeedyCGI? My distribution does not have an easy way to install SpeedyCGI, and the cpan module looks porrly maintained, old, and failing on most cpantesters reports.

Without SpeedyCGI the test does not express the problem.

If there is no easier reproduction case then I will jump through the necessary hoops, but if I can avoid installing speedycgi I would like to.

[ribasushi]

From above:

... with SpeedyCGI from git://github.com/dbsrgits/cgi-speedycgi.git ...

cpanm -n -v git://github.com/dbsrgits/cgi-speedycgi.git is all you need to get going.

[exodist]

thanks!

[ribasushi]

Do you have an easy way to reproduce that does not involve installing SpeedyCGI

I have not looked into what is causing the actual problem. Once the problem is identified, I am certain a case without SCGI can be constructed.

[exodist]

That also doesn't compile for me, lots of c errors, looking to see if maybe I am missing a library or something.

https://gist.github.com/exodist/ea882cec5d8874b0b173eee6f64bb738

[ribasushi]

Looks like it has not been updated for gcc-5 (reproduced it locally). Try with gcc-4.x, which works for me locally and on all 3 travis flavors.

[ribasushi]

@exodist Were you able to reproduce it? Let me know if you are stuck, before I "swapped out" the context of the entire thing.

[exodist]

At the moment my attention is on other things. Getting an environment up with an older gcc is beyond what I can do today with my limited equipment/time. I am planning to wait until I get home post-qa hackathon to have the environment I need to reproduce this.

[exodist]

mst gave me access to a gcc 4 box, and I was able to track it down.

A while back it was reported that using caller() in an END block results in a SEGV if you have generated code: Test-More/Test2-deprecated-#16

To fix this I talked with the toolchain group and we decided having a flag that gets flipped by an END block was the right solution. This flag makes Test2/Test::Builder avoid using caller in ways that can trip the SEGV if the END block has run.

In the test case you have, the persistent environment runs once, including running the END blocks. This causes the flag to be set. On the next iteration it is still set, so caller does not look deep enough which means it cannot find the $TODO. Without todo being seen it prints not ok, and the debugging goes to STDERR.

I talked to MST to get his opinions on the best way forward. He agrees the caller protection is important (and if we did not go with Test2 it would be backported to Test::Builder, still breaking you). I can and will add an api for resetting the flag. The remaining question is this:

Should we automatically clear the flag in $TB->reset, or should it be a manual thing. @ribasushi: mst and I are curious about your opinion on if the flag reset should be part of TB->reset (so existing persistent code works as it always has) or should we make it manual with you updating your tests?

[ribasushi]

I do not have a good solution for this.

All I can do is offer my own anecdotal evidence: I have only ever had to reach for ->reset when I was about to "rerun this perl code", so an implicit "reset-on-reset" may make sense.

Separately you can just lift this (no longer used but still valid) way of detecting SCGI, and make the ->reset apply only in this case.

[exodist]

I decided to have Test::Builder->reset toggle the flag to off. I think it probably is the least surprising behavior. I am currently running my exhaustive downstream testing as a canary. Assuming it all passes there will be a new dev release this evening.