Skip Menu |
Report information
Id: 132867
Status: resolved
Priority: 0/
Queue: perl5

Owner: Nobody
Requestors: jkeenan [at] pobox.com
Cc:
AdminCc:

Operating System: (no value)
PatchStatus: (no value)
Severity: low
Type: unknown
Perl Version: (no value)
Fixed In: (no value)



CC: Jarkko Hietaniemi <jhi [...] iki.fi>
Subject: t/io/openpid.t makes test harness sluggish; reduce sleep time
From: James E Keenan <jkeenan [...] pobox.com>
Date: Wed, 14 Feb 2018 10:45:31 -0500
To: perlbug [...] perl.org
Download (untitled) / with headers
text/plain 512b
When you run 'make test_harness' often enough, you quickly become aware that, despite setting $TEST_JOBS to an appropriate value, certain test files are slow and block the forward movement of the harness. The first such file I notice is t/io/openpid.t, which contains two commands which each sleep for 30 seconds. The amount of 'sleep' requested has been unchanged since commit c8fc8fb0 in 2003. Do we still need to sleep so much? If not, please review patch attached. Thank you very much. Jim Keenan
Download perl_V.txt
text/plain 3k

Message body is not shown because sender requested not to inline it.

Message body is not shown because sender requested not to inline it.

Subject: Re: [perl #132867] t/io/openpid.t makes test harness sluggish; reduce sleep time
Date: Wed, 14 Feb 2018 16:56:31 +0100
From: "H.Merijn Brand" <h.m.brand [...] xs4all.nl>
To: perl5-porters [...] perl.org
Download (untitled) / with headers
text/plain 1.1k
On Wed, 14 Feb 2018 07:46:04 -0800, James E Keenan (via RT) <perlbug-followup@perl.org> wrote: Show quoted text
> # <URL: https://rt.perl.org/Ticket/Display.html?id=132867 > > > When you run 'make test_harness' often enough, you quickly become aware > that, despite setting $TEST_JOBS to an appropriate value, certain test > files are slow and block the forward movement of the harness. The first > such file I notice is t/io/openpid.t, which contains two commands which > each sleep for 30 seconds.
Hum, my oldest box still takes 4½ hours per configuration adding op to over 1½ day for a full smoke. Would it start failing then? Are their any tests that "measure" allowed delays and set them dynamically instead of hard-coded? Show quoted text
> The amount of 'sleep' requested has been unchanged since commit c8fc8fb0 > in 2003. Do we still need to sleep so much? If not, please review > patch attached. > > Thank you very much. > Jim Keenan
-- H.Merijn Brand http://tux.nl Perl Monger http://amsterdam.pm.org/ using perl5.00307 .. 5.27 porting perl5 on HP-UX, AIX, and openSUSE http://mirrors.develooper.com/hpux/ http://www.test-smoke.org/ http://qa.perl.org http://www.goldmark.org/jeff/stupid-disclaimers/
Download (untitled)
application/pgp-signature 473b

Message body not shown because it is not plain text.

RT-Send-CC: perl5-porters [...] perl.org
Download (untitled) / with headers
text/plain 1.6k
On Wed, 14 Feb 2018 07:46:03 -0800, jkeenan@pobox.com wrote: Show quoted text
> When you run 'make test_harness' often enough, you quickly become aware > that, despite setting $TEST_JOBS to an appropriate value, certain test > files are slow and block the forward movement of the harness. The first > such file I notice is t/io/openpid.t, which contains two commands which > each sleep for 30 seconds. > > The amount of 'sleep' requested has been unchanged since commit c8fc8fb0 > in 2003. Do we still need to sleep so much? If not, please review > patch attached.
There's some sort of interaction between harness and this test causing the delay. If you run the test directly: tony@mars:.../perl/t$ time ./perl io/openpid.t 1..10 ok 1 - first process started ok 2 - second ok 3 - third ok 4 - fourth # pids were 1662, 1663, 1666, 1667 ok 5 - message from first process ok 6 - first process killed ok 7 - message from second process ok 8 - killing procs 2 & 3 # waiting for process 1667 to exit ok 9 - text sent to fourth process ok 10 - fourth process reaped real 0m0.033s user 0m0.008s sys 0m0.016s or under TEST: tony@mars:.../perl/t$ time ./perl TEST io/openpid.t t/io/openpid ... ok All tests successful. Elapsed: 0 sec u=0.01 s=0.00 cu=0.02 cs=0.00 scripts=1 tests=10 real 0m0.041s user 0m0.032s sys 0m0.000s the test completes immediately. Only under harness does it take a long time: tony@mars:.../perl/t$ time ./perl harness io/openpid.t io/openpid.t .. ok All tests successful. Files=1, Tests=10, 30 wallclock secs ( 0.01 usr 0.01 sys + 0.02 cusr 0.00 csys = 0.04 CPU) Result: PASS real 0m30.123s user 0m0.112s sys 0m0.012s Tony
RT-Send-CC: perl5-porters [...] perl.org
Download (untitled) / with headers
text/plain 865b
On Wed, 14 Feb 2018 14:38:26 -0800, tonyc wrote: Show quoted text
> On Wed, 14 Feb 2018 07:46:03 -0800, jkeenan@pobox.com wrote:
> > When you run 'make test_harness' often enough, you quickly become > > aware > > that, despite setting $TEST_JOBS to an appropriate value, certain > > test > > files are slow and block the forward movement of the harness. The > > first > > such file I notice is t/io/openpid.t, which contains two commands > > which > > each sleep for 30 seconds. > > > > The amount of 'sleep' requested has been unchanged since commit > > c8fc8fb0 > > in 2003. Do we still need to sleep so much? If not, please review > > patch attached.
> > There's some sort of interaction between harness and this test causing > the delay.
I thought this was familiar, please try the attached patch. List form pipe has been implemented since the discussion in #121028. Tony
Subject: 0001-perl-121028-avoid-creating-a-shell-process.patch
From 38350e53702d28f072f80311bc943afead03ef89 Mon Sep 17 00:00:00 2001 From: Tony Cook <tony@develop-help.com> Date: Tue, 28 Jan 2014 15:52:22 +1100 Subject: [perl #121028] avoid creating a shell process --- t/io/openpid.t | 20 +++++++++++++++----- 1 file changed, 15 insertions(+), 5 deletions(-) diff --git a/t/io/openpid.t b/t/io/openpid.t index d3fcf7869a..634330ded7 100644 --- a/t/io/openpid.t +++ b/t/io/openpid.t @@ -23,11 +23,15 @@ watchdog(15, $^O eq 'MSWin32' ? "alarm" : ''); use Config; $| = 1; $SIG{PIPE} = 'IGNORE'; +# reset the handler in case the shell has set a broken default +$SIG{HUP} = 'DEFAULT'; $SIG{HUP} = 'IGNORE' if $^O eq 'interix'; my $perl = which_perl(); $perl .= qq[ "-I../lib"]; +my @perl = ( which_perl(), "-I../lib" ); + # # commands run 4 perl programs. Two of these programs write a # short message to STDOUT and exit. Two of these programs @@ -35,16 +39,22 @@ $perl .= qq[ "-I../lib"]; # the other reader reads one line, waits a few seconds and then # exits to test the waitpid function. # -$cmd1 = qq/$perl -e "\$|=1; print qq[first process\\n]; sleep 30;"/; -$cmd2 = qq/$perl -e "\$|=1; print qq[second process\\n]; sleep 30;"/; +# Using 4+ arg open for the children that sleep so that that we're +# killing the perl process instead of an intermediate shell, this +# allows harness to see the file handles closed sooner. I didn't +# convert them all since I wanted 3-arg open to continue to be +# exercised here. +# +@cmd1 = ( @perl, "-e", "\$|=1; print qq[first process\\n]; sleep 30;" ); +@cmd2 = ( @perl, "-e", "\$|=1; print qq[second process\\n]; sleep 30;" ); $cmd3 = qq/$perl -e "print <>;"/; # hangs waiting for end of STDIN $cmd4 = qq/$perl -e "print scalar <>;"/; -#warn "#$cmd1\n#$cmd2\n#$cmd3\n#$cmd4\n"; +#warn "#@cmd1\n#@cmd2\n#$cmd3\n#$cmd4\n"; # start the processes -ok( $pid1 = open(FH1, "$cmd1 |"), 'first process started'); -ok( $pid2 = open(FH2, "$cmd2 |"), ' second' ); +ok( $pid1 = open(FH1, "-|", @cmd1), 'first process started'); +ok( $pid2 = open(FH2, "-|", @cmd2), ' second' ); { no warnings 'once'; ok( $pid3 = open(FH3, "| $cmd3"), ' third' ); -- 2.11.0
CC: Perl5 Porters <perl5-porters [...] perl.org>
To: perlbug <perlbug-followup [...] perl.org>
Date: Thu, 15 Feb 2018 00:39:22 +0100
Subject: Re: [perl #132867] t/io/openpid.t makes test harness sluggish; reduce sleep time
From: Leon Timmermans <fawaka [...] gmail.com>
Download (untitled) / with headers
text/plain 2.6k
On Thu, Feb 15, 2018 at 12:31 AM, Tony Cook via RT <perlbug-followup@perl.org> wrote: Show quoted text
> I thought this was familiar, please try the attached patch. > > List form pipe has been implemented since the discussion in #121028. > > Tony > > --- > via perlbug: queue: perl5 status: open > https://rt.perl.org/Ticket/Display.html?id=132867 > > From 38350e53702d28f072f80311bc943afead03ef89 Mon Sep 17 00:00:00 2001 > From: Tony Cook <tony@develop-help.com> > Date: Tue, 28 Jan 2014 15:52:22 +1100 > Subject: [perl #121028] avoid creating a shell process > > --- > t/io/openpid.t | 20 +++++++++++++++----- > 1 file changed, 15 insertions(+), 5 deletions(-) > > diff --git a/t/io/openpid.t b/t/io/openpid.t > index d3fcf7869a..634330ded7 100644 > --- a/t/io/openpid.t > +++ b/t/io/openpid.t > @@ -23,11 +23,15 @@ watchdog(15, $^O eq 'MSWin32' ? "alarm" : ''); > use Config; > $| = 1; > $SIG{PIPE} = 'IGNORE'; > +# reset the handler in case the shell has set a broken default > +$SIG{HUP} = 'DEFAULT'; > $SIG{HUP} = 'IGNORE' if $^O eq 'interix'; > > my $perl = which_perl(); > $perl .= qq[ "-I../lib"]; > > +my @perl = ( which_perl(), "-I../lib" ); > + > # > # commands run 4 perl programs. Two of these programs write a > # short message to STDOUT and exit. Two of these programs > @@ -35,16 +39,22 @@ $perl .= qq[ "-I../lib"]; > # the other reader reads one line, waits a few seconds and then > # exits to test the waitpid function. > # > -$cmd1 = qq/$perl -e "\$|=1; print qq[first process\\n]; sleep 30;"/; > -$cmd2 = qq/$perl -e "\$|=1; print qq[second process\\n]; sleep 30;"/; > +# Using 4+ arg open for the children that sleep so that that we're > +# killing the perl process instead of an intermediate shell, this > +# allows harness to see the file handles closed sooner. I didn't > +# convert them all since I wanted 3-arg open to continue to be > +# exercised here. > +# > +@cmd1 = ( @perl, "-e", "\$|=1; print qq[first process\\n]; sleep 30;" ); > +@cmd2 = ( @perl, "-e", "\$|=1; print qq[second process\\n]; sleep 30;" ); > $cmd3 = qq/$perl -e "print <>;"/; # hangs waiting for end of STDIN > $cmd4 = qq/$perl -e "print scalar <>;"/; > > -#warn "#$cmd1\n#$cmd2\n#$cmd3\n#$cmd4\n"; > +#warn "#@cmd1\n#@cmd2\n#$cmd3\n#$cmd4\n"; > > # start the processes > -ok( $pid1 = open(FH1, "$cmd1 |"), 'first process started'); > -ok( $pid2 = open(FH2, "$cmd2 |"), ' second' ); > +ok( $pid1 = open(FH1, "-|", @cmd1), 'first process started'); > +ok( $pid2 = open(FH2, "-|", @cmd2), ' second' ); > { > no warnings 'once'; > ok( $pid3 = open(FH3, "| $cmd3"), ' third' ); > -- > 2.11.0
Fix looks sensible to me, and I can indeed reproduce this issue once I run the test under nohup. Leon
RT-Send-CC: perl5-porters [...] perl.org
Download (untitled) / with headers
text/plain 1.5k
On Wed, 14 Feb 2018 23:31:43 GMT, tonyc wrote: Show quoted text
> On Wed, 14 Feb 2018 14:38:26 -0800, tonyc wrote:
> > On Wed, 14 Feb 2018 07:46:03 -0800, jkeenan@pobox.com wrote:
> > > When you run 'make test_harness' often enough, you quickly become > > > aware > > > that, despite setting $TEST_JOBS to an appropriate value, certain > > > test > > > files are slow and block the forward movement of the harness. The > > > first > > > such file I notice is t/io/openpid.t, which contains two commands > > > which > > > each sleep for 30 seconds. > > > > > > The amount of 'sleep' requested has been unchanged since commit > > > c8fc8fb0 > > > in 2003. Do we still need to sleep so much? If not, please review > > > patch attached.
> > > > There's some sort of interaction between harness and this test causing > > the delay.
> > I thought this was familiar, please try the attached patch. > > List form pipe has been implemented since the discussion in #121028. > > Tony
Looks good to me. After applying your patch: ##### # Branch: 132867-openpid $ time ./perl -Ilib t/io/openpid.t 1..10 ... ok 10 - fourth process reaped real 0m0.036s user 0m0.020s sys 0m0.004s $ cd t;time ./perl harness -v io/openpid.t; cd - ok 1 - first process started ... ok 10 - fourth process reaped ok All tests successful. Files=1, Tests=10, 0 wallclock secs ( 0.01 usr + 0.00 sys = 0.01 CPU) Result: PASS real 0m0.067s user 0m0.064s sys 0m0.004s ##### Please apply unless someone raises an objection. Thank you very much. -- James E Keenan (jkeenan@cpan.org)
RT-Send-CC: perl5-porters [...] perl.org
Download (untitled) / with headers
text/plain 207b
On Wed, 14 Feb 2018 17:26:53 -0800, jkeenan wrote: Show quoted text
> Please apply unless someone raises an objection. Thank you very much.
Thanks for testing it. Applied as b6811f8d3a5c4826ad03be7b9dc69f5f3dc939be. Tony
From: "H.Merijn Brand" <h.m.brand [...] xs4all.nl>
Date: Thu, 15 Feb 2018 08:46:29 +0100
Subject: Re: [perl #132867] t/io/openpid.t makes test harness sluggish; reduce sleep time
To: perl5-porters [...] perl.org
CC: perlbug-followup [...] perl.org
Download (untitled) / with headers
text/plain 1.2k
On Wed, 14 Feb 2018 15:31:43 -0800, "Tony Cook via RT" <perlbug-followup@perl.org> wrote: Show quoted text
> On Wed, 14 Feb 2018 14:38:26 -0800, tonyc wrote:
> > On Wed, 14 Feb 2018 07:46:03 -0800, jkeenan@pobox.com wrote:
> > > When you run 'make test_harness' often enough, you quickly become > > > aware > > > that, despite setting $TEST_JOBS to an appropriate value, certain > > > test > > > files are slow and block the forward movement of the harness. The > > > first > > > such file I notice is t/io/openpid.t, which contains two commands > > > which > > > each sleep for 30 seconds. > > > > > > The amount of 'sleep' requested has been unchanged since commit > > > c8fc8fb0 > > > in 2003. Do we still need to sleep so much? If not, please review > > > patch attached.
> > > > There's some sort of interaction between harness and this test causing > > the delay.
> > I thought this was familiar, please try the attached patch.
+1 Show quoted text
> List form pipe has been implemented since the discussion in #121028. > > Tony
-- H.Merijn Brand http://tux.nl Perl Monger http://amsterdam.pm.org/ using perl5.00307 .. 5.27 porting perl5 on HP-UX, AIX, and openSUSE http://mirrors.develooper.com/hpux/ http://www.test-smoke.org/ http://qa.perl.org http://www.goldmark.org/jeff/stupid-disclaimers/
Download (untitled)
application/pgp-signature 473b

Message body not shown because it is not plain text.

Subject: Re: [perl #132867] t/io/openpid.t makes test harness sluggish; reduce sleep time
Date: Thu, 15 Feb 2018 21:35:56 -0600
To: Craig Berry via RT <perlbug-followup [...] perl.org>
CC: "Perl5 Porters (E-mail)" <perl5-porters [...] perl.org>
From: "Craig A. Berry" <craig.a.berry [...] gmail.com>
Download (untitled) / with headers
text/plain 469b
On Wed, Feb 14, 2018 at 9:44 PM, Tony Cook via RT <perlbug-followup@perl.org> wrote: Show quoted text
> On Wed, 14 Feb 2018 17:26:53 -0800, jkeenan wrote:
>> Please apply unless someone raises an objection. Thank you very much.
> > Thanks for testing it. > > Applied as b6811f8d3a5c4826ad03be7b9dc69f5f3dc939be.
The test now fails like so on VMS: $ perl io/openpid.t 1..10 List form of piped open not implemented at io/openpid.t line 56. # Looks like you planned 10 tests but ran 0.
From: "Craig A. Berry" <craig.a.berry [...] gmail.com>
Date: Fri, 16 Feb 2018 15:04:19 -0600
Subject: Re: [perl #132867] t/io/openpid.t makes test harness sluggish; reduce sleep time
To: Craig Berry via RT <perlbug-followup [...] perl.org>
Download (untitled) / with headers
text/plain 883b
On Thu, Feb 15, 2018 at 9:35 PM, Craig A. Berry <craig.a.berry@gmail.com> wrote: Show quoted text
> On Wed, Feb 14, 2018 at 9:44 PM, Tony Cook via RT > <perlbug-followup@perl.org> wrote:
>> On Wed, 14 Feb 2018 17:26:53 -0800, jkeenan wrote:
>>> Please apply unless someone raises an objection. Thank you very much.
>> >> Thanks for testing it. >> >> Applied as b6811f8d3a5c4826ad03be7b9dc69f5f3dc939be.
> > The test now fails like so on VMS: > > $ perl io/openpid.t > 1..10 > List form of piped open not implemented at io/openpid.t line 56. > # Looks like you planned 10 tests but ran 0.
As of 0970cf267152b660e I have hacked up the test to run the old way on VMS only. As far as I can see, what Windows does for list open is just paste the arguments together to form a command line, and there's no reason in principle that couldn't be done on VMS as well -- just a few dozen round tuits missing.
Download (untitled) / with headers
text/plain 317b
Thank you for filing this report. You have helped make Perl better. With the release yesterday of Perl 5.28.0, this and 185 other issues have been resolved. Perl 5.28.0 may be downloaded via: https://metacpan.org/release/XSAWYERX/perl-5.28.0 If you find that the problem persists, feel free to reopen this ticket.


This service is sponsored and maintained by Best Practical Solutions and runs on Perl.org infrastructure.

For issues related to this RT instance (aka "perlbug"), please contact perlbug-admin at perl.org