water has asked for the wisdom of the Perl Monks concerning the following question:

I'm using Test::Harness to runa test suite. One of the test uses system to run a child process that, intentionally, dies. The death sends noise STDERR. While the test script runs fine and successful as  perl test.t, when run via the harness, a series of Confused test output: test 11 answered after test 11 errors are produced.

What's the relationship between Test::Harness, system, and STDERR? Is this what is causing Test::Harness to fail on a script that passes when run as  perl test.t, ands what can I do get this test running happily w/in the harness?

more befuddled than usual --

H2O

Replies are listed 'Best First'.
Re: test::harness, stderr, and child processes
by adrianh (Chancellor) on Aug 27, 2004 at 08:41 UTC
    What's the relationship between Test::Harness, system, and STDERR?

    It ignores it completely.

    Is this what is causing Test::Harness to fail on a script that passes when run as  perl test.t, ands what can I do get this test running happily w/in the harness?

    It sounds like you have tests running out of order. Is your test script forking and both parent an child printing test results? Can you show us your test script and the output (with TEST_VERBOSE) from T::H that's giving you the error. I'd expect to see something like:

    ... ok 9 ok 11 ok 10 ...

      [sand 526 water@zippy:~/dev/PerlCode/lib/Test]$ prove -v highlander.t highlander....1..19 ok 1 - use Util; ok 2 - -f /home/water/dev/PerlCode/lib/Test/HighlanderTests/death.pl ok 3 - -f /home/water/dev/PerlCode/lib/Test/HighlanderTests/simple.pl ok 4 - /tmp/water/highlander.ok old is now gone death at /home/water/dev/PerlCode/lib/Test/HighlanderTests/death.pl li +ne 6. perl /home/water/dev/PerlCode/lib/Test/HighlanderTests/death.pl || tou +ch /tmp/water/highlander.okok 5 - death is a failure, test went as pl +anned ok 6 - /tmp/water/highlander.ok old is now gone ok 7 - simple alone, test went as planned Confused test output: test 6 answered after test 6 ok 8 - /tmp/water/highlander.ok old is now gone Confused test output: test 7 answered after test 7 Died at /home/water/dev/PerlCode/lib/Test/HighlanderTests/simple.pl li +ne 9. # Looks like your test died before it could output anything. ok 9 - double simple short sleep, test went as planned Confused test output: test 8 answered after test 8 ok 10 - /tmp/water/highlander.ok old is now gone Confused test output: test 9 answered after test 9 Died at /home/water/dev/PerlCode/lib/Test/HighlanderTests/simple.pl li +ne 9. # Looks like your test died before it could output anything. ok 11 - double simple long sleep, test went as planned Confused test output: test 10 answered after test 10 ok 12 - -f /home/water/dev/PerlCode/lib/Test/HighlanderTests/reportbui +lder.pl Confused test output: test 11 answered after test 11 ok 13 - /tmp/water/highlander.ok old is now gone Confused test output: test 12 answered after test 12 ok 14 - $rpl lives, test went as planned Confused test output: test 13 answered after test 13 ok 15 - /tmp/water/highlander.ok old is now gone Confused test output: test 14 answered after test 14 FATAL: aborting as another instance running! at /home/water/dev/PerlCo +de/lib/MyLog.pm line 43. Compilation failed in require at /home/water/dev/PerlCode/lib/Test/Hig +hlanderTests/reportbuilder.pl line 14. BEGIN failed--compilation aborted at /home/water/dev/PerlCode/lib/Test +/HighlanderTests/reportbuilder.pl line 14. # Looks like your test died before it could output anything. ok 16 - double rpl short pause to let the other one load, test went as + planned Confused test output: test 15 answered after test 15 ok 17 - /tmp/water/highlander.ok old is now gone Confused test output: test 16 answered after test 16 ok 18 - double $rpl with a nice pause, test went as planned Confused test output: test 17 answered after test 17 ok 19 - /tmp/water/highlander.ok old is now gone Confused test output: test 18 answered after test 18 FAILED test 5 Failed 1/19 tests, 94.74% okay Failed Test Stat Wstat Total Fail Failed List of Failed ---------------------------------------------------------------------- +--------- highlander.t 19 1 5.26% 5 Failed 1/1 test scripts, 0.00% okay. 1/19 subtests failed, 94.74% okay +.

      #!/usr/bin/perl -w # NOTE IT RELIES ON TIMING AND COULD FAIL IF MACHINE # HEAVILY LOADED WHEN TEST RUNS use strict; use warnings FATAL => 'all', NONFATAL => 'redefine'; use Test::More tests => 19; use Test::Exception; use Dirs qw(CODELIB_DIR MYTMP_DIR); use Path::Class; my $death = file( CODELIB_DIR, 'Test', 'HighlanderTests', 'death.pl' +); my $simple = file( CODELIB_DIR, 'Test', 'HighlanderTests', 'simple.pl' + ); use_ok( 'Util', qw(another_instance_running) ); ok( -f $death, "-f $death" ); ok( -f $simple, "-f $simple" ); my $okfile = file( MYTMP_DIR, 'highlander.ok' ); my $PASSES = "&& touch $okfile"; my $FAILS = "|| touch $okfile"; &remove; my $x = "perl $death $FAILS"; print $x; my $rc = system("perl $death $FAILS"); file_present('death is a failure'); &remove; $rc = system("perl $simple $PASSES"); file_present('simple alone'); &remove; $rc = system("(perl $simple&); sleep 1; perl $simple $FAILS"); file_present('double simple short sleep'); &remove; $rc = system("(perl $simple&); sleep 4; perl $simple $PASSES"); file_present('double simple long sleep'); my $rpl = file( CODELIB_DIR, 'Test', 'HighlanderTests', 'reportbuilder +.pl' ); ok( -f $simple, "-f $rpl" ); &remove; $rc = system("perl $rpl $PASSES"); file_present('$rpl lives'); sleep(5); # gotta sleep to let previous instance finish &remove; $rc = system("(perl $rpl&); sleep 1; perl $rpl $FAILS"); file_present('double rpl short pause to let the other one load'); sleep(5); # gotta sleep to let previous instance finish &remove; $rc = system("(perl $rpl&); sleep 4; perl $rpl $PASSES"); file_present('double $rpl with a nice pause'); &remove; my $count = 0; sub remove { unlink $okfile; ok( !-f $okfile, $okfile . ' old is now gone' ); } sub file_present { my $msg = shift; ok( -f $okfile, $msg . ', test went as planned' ); }

        Thanks. Odd. After a quick skim it looks like it should work.

        Can you tell me what version of the Test::Simple distro you're using? If you're not using the latest (0.47) that might be your problem since there have been several fork-related bug fixes.

        Also, I can't tell from the output whether the non-test related output is going to STDOUT or STDERR. If the bit before the ok here:

        perl /home/water/dev/PerlCode/lib/Test/HighlanderTests/death.pl || tou +ch /tmp/water/highlander.okok 5 - death is a failure, test went as pl +anned

        is going to STDOUT then Test::Harness will miss the "ok 5".

        If not, let me know and I'll dig further.

Re: test::harness, stderr, and child processes
by PodMaster (Abbot) on Aug 27, 2004 at 07:19 UTC
    Test::Harness does not care about STDERR.
    C:\>more bad-test.t warn "1..22\n"; warn "not ok 22\n"; print "1..5\n"; print "ok 1\n"; print "ok 5\n"; print "ok 2\n"; print "ok 3\n"; print "ok 4\n"; C:\>prove bad-test.t bad-test....1..22 not ok 22 bad-test....ok 3/5Confused test output: test 3 answered after test 5 bad-test....ok 4/5Test output counter mismatch [test 4] bad-test....ok 5/5Test output counter mismatch [test 5] bad-test....ok All tests successful. Files=1, Tests=5, 0 wallclock secs ( 0.00 cusr + 0.00 csys = 0.00 C +PU) C:\>
    So if you system child is printing to STDOUT, there could be trouble.

    MJD says "you can't just make shit up and expect the computer to know what you mean, retardo!"
    I run a Win32 PPM repository for perl 5.6.x and 5.8.x -- I take requests (README).
    ** The third rule of perl club is a statement of fact: pod is sexy.