Bug #103130 for Proc-Daemon: Issue with test suite

Thu Mar 26 06:25:17 2015 remi [...] fedoraproject.org - Ticket created

Subject:	Issue with test suite - erratic results
Date:	Thu, 26 Mar 2015 11:24:53 +0100
To:	bug-Proc-Daemon [...] rt.cpan.org
From:	Remi Collet <remi [...] fedoraproject.org>

Hi, Trying to update the Fedora/EPEL package I notice erratic failure, probably related to builder power/charge. + make test PERL_DL_NONLAZY=1 /usr/bin/perl "-MExtUtils::Command::MM" "-e" "test_harness(0, 'blib/lib', 'blib/arch')" t/*.t t/01_loadmodule.t .. ok # Parent slept for 3 sec. # Proc::ProcessTable is installed and did find the right PID for 'perl /builddir/build/BUILD/Proc-Daemon-0.19/t/kid.pl': 15571 t/02_testmodule.t .. ok # Parent slept for 3 sec. # Proc::ProcessTable is installed and did find the right PID for 'perl /builddir/build/BUILD/Proc-Daemon-0.19/t/kid.pl': 15584 /builddir/build/BUILD/Proc-Daemon-0.19/t/02_testmodule.t did not return a true value at t/03_taintmode.t line 20. # Looks like your test exited with 2 just after 19. t/03_taintmode.t ... Dubious, test returned 2 (wstat 512, 0x200) All 19 subtests passed Test Summary Report ------------------- t/03_taintmode.t (Wstat: 512 Tests: 19 Failed: 0) Non-zero exit status: 2 Files=3, Tests=39, 10 wallclock secs ( 0.03 usr 0.00 sys + 0.13 cusr 0.04 csys = 0.20 CPU) Result: FAIL Failed 1/3 test programs. 0/39 subtests failed. I also encouter failure on local system (with lot of installed perl packages), always fails. + make test PERL_DL_NONLAZY=1 /usr/bin/perl "-MExtUtils::Command::MM" "-MTest::Harness" "-e" "undef *Test::Harness::Switches; test_harness(0, 'blib/lib', 'blib/arch')" t/*.t t/01_loadmodule.t .. ok t/02_testmodule.t .. 2/19 # Parent slept for 3 sec. # Proc::ProcessTable is installed and did find the right PID for 'perl /dev/shm/extras/BUILD/Proc-Daemon-0.19/t/kid.pl': 25881 t/02_testmodule.t .. ok t/03_taintmode.t ... 2/19 # Parent slept for 3 sec. t/03_taintmode.t ... 15/19 # Failed test ''kid.pl' daemon is still running' # at /dev/shm/extras/BUILD/Proc-Daemon-0.19/t/02_testmodule.t line 119. # Failed test 'stop daemon 'kid.pl'' # at /dev/shm/extras/BUILD/Proc-Daemon-0.19/t/02_testmodule.t line 122. Use of uninitialized value in numeric eq (==) at /dev/shm/extras/BUILD/Proc-Daemon-0.19/t/02_testmodule.t line 132. # Failed test 'the 'umask.file' has right permissions' # at /dev/shm/extras/BUILD/Proc-Daemon-0.19/t/02_testmodule.t line 132. /dev/shm/extras/BUILD/Proc-Daemon-0.19/t/02_testmodule.t did not return a true value at t/03_taintmode.t line 20. # Looks like you failed 3 tests of 19. # Looks like your test exited with 2 just after 19. t/03_taintmode.t ... Dubious, test returned 2 (wstat 512, 0x200) Failed 3/19 subtests Test Summary Report ------------------- t/03_taintmode.t (Wstat: 512 Tests: 19 Failed: 3) Failed tests: 15-16, 18 Non-zero exit status: 2 Files=3, Tests=39, 9 wallclock secs ( 0.02 usr 0.00 sys + 0.09 cusr 0.07 csys = 0.18 CPU) Result: FAIL Failed 1/3 test programs. 3/39 subtests failed. Makefile:838: recipe for target 'test_dynamic' failed make: *** [test_dynamic] Error 2 Any idea ? thanks.

Fri Apr 03 03:25:13 2015 ppisar [...] redhat.com - Correspondence added

From:

ppisar [...] redhat.com

Dne Čt 26.bře.2015 06:25:17, remi@fedoraproject.org napsal(a): Show quoted text

> + make test > PERL_DL_NONLAZY=1 /usr/bin/perl "-MExtUtils::Command::MM" "-e" > "test_harness(0, 'blib/lib', 'blib/arch')" t/*.t > t/01_loadmodule.t .. ok > # Parent slept for 3 sec. > # Proc::ProcessTable is installed and did find the right PID for 'perl > /builddir/build/BUILD/Proc-Daemon-0.19/t/kid.pl': 15571 > t/02_testmodule.t .. ok > # Parent slept for 3 sec. > # Proc::ProcessTable is installed and did find the right PID for 'perl > /builddir/build/BUILD/Proc-Daemon-0.19/t/kid.pl': 15584 > /builddir/build/BUILD/Proc-Daemon-0.19/t/02_testmodule.t did not > return a true value at t/03_taintmode.t line 20. > # Looks like your test exited with 2 just after 19. > t/03_taintmode.t ... > Dubious, test returned 2 (wstat 512, 0x200) > All 19 subtests passed > Test Summary Report > ------------------- > t/03_taintmode.t (Wstat: 512 Tests: 19 Failed: 0) > Non-zero exit status: 2 > Files=3, Tests=39, 10 wallclock secs ( 0.03 usr 0.00 sys + 0.13 cusr > 0.04 csys = 0.20 CPU) > Result: FAIL > Failed 1/3 test programs. 0/39 subtests failed. >

t/03_taintmode.t executes t/02_testmodule.t. t/02_testmodule.t is full of sleep()s and blind expectations that parent and child processes will advance in specific speed. The expectation is obviously wrong because CPU scheduler can delay any task unpredictably. For me, the most magic constant is "sleep( 3 );" (just before 'Parent slept for 3 sec.' message). If you add "sleep(10);" just after the original sleep (because of "stay alive vor 10 sec." assumption), the test will fail regularly: $ prove -v -b t/02_testmodule.t t/02_testmodule.t .. 1..19 ok 1 - child_1 was created with PID: 1728 ok 2 - child_1 process did exit within 1 sec. ok 3 - child_1 has created a 'pid.file' ok 4 - the 'pid.file' contains the right PID: 1728 ok 5 - the 'pid.file' has right permissions ok 6 - child_1 has created a 'output.file' ok 7 - the content of the 'output.file' was right. ok 8 - child_1 has created a 'error.file' ok 9 - child_1 has created the 'kid.pl' file ok 10 - child_2 was created with PID: 1732 ok 11 - child_2 created a 'pid_1.file' ok 12 - the 'pid_1.file' contains the right PID: 1732 ok 13 - child_2 created a 'output_1.file' ok 14 - child_2 created a 'error_1.file' # Parent slept for 3 sec. not ok 15 - 'kid.pl' daemon is still running not ok 16 - stop daemon 'kid.pl' ok 17 - 'kid.pl' daemon was stopped within 0 sec. ok 18 - the 'umask.file' has right permissions # Failed test ''kid.pl' daemon is still running' # at t/02_testmodule.t line 120. # Failed test 'stop daemon 'kid.pl'' # at t/02_testmodule.t line 123. ok 19 - the 'pid2.file' has right permissions via file_umask # Looks like you failed 2 tests of 19. I believe the reported failure is yet another race. Solution is either replace all sleep's with proper inter process synchronization or skip all time-sensitive tests if the tested work load does not finish in expected time.

Fri Apr 03 03:25:14 2015 The RT System itself - Status changed from 'new' to 'open'

Fri Jun 26 13:32:34 2015 AKREAL [...] cpan.org - Correspondence added

Hi, sorry for the delayed reply. Could you please try it with 0.20?

Fri Jun 26 13:32:35 2015 AKREAL [...] cpan.org - Taken

Sat Jun 27 03:33:47 2015 remi [...] fedoraproject.org - Correspondence added

Subject:	Re: [rt.cpan.org #103130] Issue with test suite - erratic results
Date:	Sat, 27 Jun 2015 09:33:24 +0200
To:	bug-Proc-Daemon [...] rt.cpan.org
From:	Remi Collet <remi [...] fedoraproject.org>

-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1 Le 26/06/2015 19:32, Pavel Denisov via RT a écrit : Show quoted text

> <URL: https://rt.cpan.org/Ticket/Display.html?id=103130 > > > Hi, sorry for the delayed reply. Could you please try it with > 0.20? >

On a quite slow computer (arm, perl 5.22), it seems OK See https://kojipkgs.fedoraproject.org//work/tasks/6456/10226456/build.l og On a clean chroot (perl 5.18, 5.20, 5.22), seems ok too But on my local computer (quite fast), On all run, it strangely fails look like some conflicts with some installed modules.. :( I just build it in Fedora rawhide, and will check our CI to see if any failure occurs... See: https://apps.fedoraproject.org/koschei/package/perl-Proc-Daemon Remi. P.S. local build failure + make test PERL_DL_NONLAZY=1 /usr/bin/perl "-MExtUtils::Command::MM" "-MTest::Harness" "-e" "undef *Test::Harness::Switches; test_harness(0, 'blib/lib', 'blib/arch')" t/*.t t/01_loadmodule.t .. ok t/02_testmodule.t .. 2/19 # Proc::ProcessTable is installed and did find the right PID for 'perl /dev/shm/extras/BUILD/Proc-Daemon-0.20/t/kid.pl': 28353 t/02_testmodule.t .. ok t/03_taintmode.t ... 2/19 # Failed test ''kid.pl' daemon is still running' # at /dev/shm/extras/BUILD/Proc-Daemon-0.20/t/02_testmodule.t line 116 . # Failed test 'stop daemon 'kid.pl'' # at /dev/shm/extras/BUILD/Proc-Daemon-0.20/t/02_testmodule.t line 119 . Use of uninitialized value in numeric eq (==) at /dev/shm/extras/BUILD/Proc-Daemon-0.20/t/02_testmodule.t line 129. # Failed test 'the 'umask.file' has right permissions' # at /dev/shm/extras/BUILD/Proc-Daemon-0.20/t/02_testmodule.t line 129 . t/03_taintmode.t ... 19/19 # Looks like you failed 3 tests of 19. t/03_taintmode.t ... Dubious, test returned 3 (wstat 768, 0x300) Failed 3/19 subtests Test Summary Report - ------------------- t/03_taintmode.t (Wstat: 768 Tests: 19 Failed: 3) Failed tests: 15-16, 18 Non-zero exit status: 3 Files=3, Tests=39, 7 wallclock secs ( 0.02 usr 0.00 sys + 0.09 cusr 0.06 csys = 0.17 CPU) Result: FAIL Failed 1/3 test programs. 3/39 subtests failed. Makefile:840: recipe for target 'test_dynamic' failed -----BEGIN PGP SIGNATURE----- Version: GnuPG v2 Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/ iEYEARECAAYFAlWOUcQACgkQYUppBSnxahiitwCgx+kmUo9c6bVVpTXuPoOA1wlL GFcAoPEjPC800Q0EwnDqyuifqGb6liL1 =XzI0 -----END PGP SIGNATURE-----

Mon Jul 20 11:33:18 2015 hakon.hagland [...] gmail.com - Correspondence added

Subject:	[rt.cpan.org #103130] Installation of Proc::Daemon : Failed test ''kid.pl' daemon is still running'
Date:	Mon, 20 Jul 2015 17:32:59 +0200
To:	bug-Proc-Daemon [...] rt.cpan.org
From:	Håkon Hægland <hakon.hagland [...] gmail.com>

Same problem observed on Ubuntu 14.10, perl v5.20, more details can be found here: http://stackoverflow.com/questions/31513538/failed-to-install-procdaemon-on-ubuntu-14-10

Sun Jul 26 20:42:02 2015 AKREAL [...] cpan.org - Correspondence added

RT-Send-CC:

hakon.hagland [...] gmail.com

Hey guys, I've created the branch with some debug output for this test, could you please try it and give me results? With cpanm it should be possible to do this way: cpanm --test-only git@github.com:akreal/Proc-Daemon.git@diag Without cpanm: git clone -b diag https://github.com/akreal/Proc-Daemon.git cd Proc-Daemon/ perl Makefile.PL make test

Mon Jul 27 15:11:03 2015 hakon.hagland [...] gmail.com - Correspondence added

Subject:	Re: [rt.cpan.org #103130] Issue with test suite - erratic results
Date:	Mon, 27 Jul 2015 21:10:47 +0200
To:	bug-Proc-Daemon [...] rt.cpan.org
From:	Håkon Hægland <hakon.hagland [...] gmail.com>

Here are my results: $ cpanm --test-only git@github.com:akreal/Proc-Daemon.git@diag Cloning git@github.com:akreal/Proc-Daemon.git ... OK --> Working on git@github.com:akreal/Proc-Daemon.git@diag Configuring /tmp/a0WpvKS3Y0 ... OK Building and testing Proc-Daemon-0.20 ... FAIL ! Testing git@github.com:akreal/Proc-Daemon.git@diag failed. See /home/hakon/.cpanm/work/1438023879.30314/build.log for details. Retry with --force to force install it. ' The log file '/home/hakon/.cpanm/work/1438023879.30314/build.log' is given here: http://pastebin.com/a3uLrvnn 2015-07-27 2:42 GMT+02:00 Pavel Denisov via RT <bug-Proc-Daemon@rt.cpan.org> : Show quoted text

> <URL: https://rt.cpan.org/Ticket/Display.html?id=103130 > > > Hey guys, I've created the branch with some debug output for this test, > could you please try it and give me results? > > With cpanm it should be possible to do this way: > > cpanm --test-only git@github.com:akreal/Proc-Daemon.git@diag > > Without cpanm: > > git clone -b diag https://github.com/akreal/Proc-Daemon.git > cd Proc-Daemon/ > perl Makefile.PL > make test > >

Mon Jul 27 23:07:09 2015 AKREAL [...] cpan.org - Correspondence added

RT-Send-CC:

hakon.hagland [...] gmail.com

Thank you, Håkon! Now I see where inconsistent test results come from -- people have different $PATH. The only unclear thing is how to fix it. Some web searching suggests that world-writable directory can cause this problem. I've added stripping of such directories from $PATH in 03_taintmode.t (same diag git branch). Could you please try same test again?

Tue Jul 28 05:51:22 2015 hakon.hagland [...] gmail.com - Correspondence added

Subject:	Re: [rt.cpan.org #103130] Issue with test suite - erratic results
Date:	Tue, 28 Jul 2015 11:51:12 +0200
To:	bug-Proc-Daemon [...] rt.cpan.org
From:	Håkon Hægland <hakon.hagland [...] gmail.com>

Here are new results (still failure): $ cpanm --test-only git@github.com:akreal/Proc-Daemon.git@diag Cloning git@github.com:akreal/Proc-Daemon.git ... OK --> Working on git@github.com:akreal/Proc-Daemon.git@diag Configuring /tmp/oYhOZK8Mm1 ... OK Building and testing Proc-Daemon-0.20 ... FAIL ! Testing git@github.com:akreal/Proc-Daemon.git@diag failed. See /home/hakon/.cpanm/work/1438076826.1565/build.log for details. Retry with --force to force install it. and the log file is here: http://pastebin.com/V4zpA9WA 2015-07-28 5:07 GMT+02:00 Pavel Denisov via RT <bug-Proc-Daemon@rt.cpan.org> : Show quoted text

> <URL: https://rt.cpan.org/Ticket/Display.html?id=103130 > > > Thank you, Håkon! Now I see where inconsistent test results come from -- > people have different $PATH. The only unclear thing is how to fix it. Some > web searching suggests that world-writable directory can cause this > problem. I've added stripping of such directories from $PATH in > 03_taintmode.t (same diag git branch). Could you please try same test again? > > >

Mon Aug 03 19:58:40 2015 AKREAL [...] cpan.org - Correspondence added

RT-Send-CC:

hakon.hagland [...] gmail.com

Could you please try the same again? I've changed $PATH untainting and added more debug output.

Tue Aug 04 04:44:36 2015 hakon.hagland [...] gmail.com - Correspondence added

Subject:	Re: [rt.cpan.org #103130] Issue with test suite - erratic results
Date:	Tue, 4 Aug 2015 10:44:19 +0200
To:	bug-Proc-Daemon [...] rt.cpan.org
From:	Håkon Hægland <hakon.hagland [...] gmail.com>

Still failure: $ cpanm --test-only git@github.com:akreal/Proc-Daemon.git@diag Cloning git@github.com:akreal/Proc-Daemon.git ... OK --> Working on git@github.com:akreal/Proc-Daemon.git@diag Configuring /tmp/azN1KlC9TJ ... OK Building and testing Proc-Daemon-0.20 ... FAIL ! Testing git@github.com:akreal/Proc-Daemon.git@diag failed. See /home/hakon/.cpanm/work/1438677661.23844/build.log for details. Retry with --force to force install it. Log file: http://pastebin.com/aKdGVikP 2015-08-04 1:58 GMT+02:00 Pavel Denisov via RT <bug-Proc-Daemon@rt.cpan.org> : Show quoted text

> <URL: https://rt.cpan.org/Ticket/Display.html?id=103130 > > > Could you please try the same again? I've changed $PATH untainting and > added more debug output. >

Wed Aug 05 22:56:07 2015 AKREAL [...] cpan.org - Correspondence added

RT-Send-CC:

hakon.hagland [...] gmail.com

$PATH is tweaked a bit more. May I ask you to test it once again please?

Thu Aug 06 04:26:37 2015 hakon.hagland [...] gmail.com - Correspondence added

Subject:	Re: [rt.cpan.org #103130] Issue with test suite - erratic results
Date:	Thu, 6 Aug 2015 10:26:27 +0200
To:	bug-Proc-Daemon [...] rt.cpan.org
From:	Håkon Hægland <hakon.hagland [...] gmail.com>

Still failure: $ cpanm --test-only git@github.com:akreal/Proc-Daemon.git@diag Cloning git@github.com:akreal/Proc-Daemon.git ... OK --> Working on git@github.com:akreal/Proc-Daemon.git@diag Configuring /tmp/HHZgchC1Xf ... OK Building and testing Proc-Daemon-0.20 ... FAIL ! Testing git@github.com:akreal/Proc-Daemon.git@diag failed. See /home/hakon/.cpanm/work/1438849416.5541/build.log for details. Retry with --force to force install it. Log file: http://pastebin.com/nftn2miH 2015-08-06 4:56 GMT+02:00 Pavel Denisov via RT <bug-Proc-Daemon@rt.cpan.org> : Show quoted text

> <URL: https://rt.cpan.org/Ticket/Display.html?id=103130 > > > $PATH is tweaked a bit more. May I ask you to test it once again please? >

Thu Aug 06 09:13:24 2015 AKREAL [...] cpan.org - Correspondence added

RT-Send-CC:

hakon.hagland [...] gmail.com

And one more time, please?

Thu Aug 06 09:58:40 2015 hakon.hagland [...] gmail.com - Correspondence added

Subject:	Re: [rt.cpan.org #103130] Issue with test suite - erratic results
Date:	Thu, 6 Aug 2015 15:58:31 +0200
To:	bug-Proc-Daemon [...] rt.cpan.org
From:	Håkon Hægland <hakon.hagland [...] gmail.com>

It works now! 2015-08-06 15:13 GMT+02:00 Pavel Denisov via RT <bug-Proc-Daemon@rt.cpan.org Show quoted text

>:

Show quoted text

> <URL: https://rt.cpan.org/Ticket/Display.html?id=103130 > > > And one more time, please? >

Thu Aug 06 10:03:47 2015 AKREAL [...] cpan.org - Correspondence added

RT-Send-CC:

hakon.hagland [...] gmail.com

Great, thanks for testing and reporting! Will release it later today or tomorrow.

Thu Aug 06 22:22:50 2015 AKREAL [...] cpan.org - Correspondence added

RT-Send-CC:

hakon.hagland [...] gmail.com

Released in 0.21. Hopefully it will work for you and (mostly) others.

Fri Aug 07 12:32:39 2015 remi [...] fedoraproject.org - Correspondence added

Subject:	Re: [rt.cpan.org #103130] Issue with test suite - erratic results
Date:	Fri, 7 Aug 2015 18:32:19 +0200
To:	bug-Proc-Daemon [...] rt.cpan.org
From:	Remi Collet <remi [...] fedoraproject.org>

-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1 Le 07/08/2015 04:22, Pavel Denisov via RT a écrit : Show quoted text

> <URL: https://rt.cpan.org/Ticket/Display.html?id=103130 > > > Released in 0.21. Hopefully it will work for you and (mostly) > others.

Version 0.21 seems ok :) (even the local build works) Thanks -----BEGIN PGP SIGNATURE----- Version: GnuPG v2 Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/ iEYEARECAAYFAlXE3ZMACgkQYUppBSnxahie3gCgu64sgMQFIzQYJ7wNYVI/kNGq 9PsAoMmT09e+UakW4WNQmIVrLjFHgMQc =Bz+z -----END PGP SIGNATURE-----

Fri Aug 07 12:55:38 2015 AKREAL [...] cpan.org - Correspondence added

OK, thanks for checking. Closing this ticket then.

Fri Aug 07 12:55:40 2015 AKREAL [...] cpan.org - Status changed from 'open' to 'resolved'

Fri Aug 07 12:55:40 2015 AKREAL [...] cpan.org - Fixed in 0.21 added

Bug #103130 for Proc-Daemon: Issue with test suite - erratic results