Skip Menu |
 

This queue is for tickets about the Test-Harness CPAN distribution.

Report information
The Basics
Id: 67637
Status: open
Priority: 0/
Queue: Test-Harness

People
Owner: Nobody in particular
Requestors: PETEK [...] cpan.org (weekly)
SREZIC [...] cpan.org
Cc:
AdminCc:

Bug Information
Severity: Normal
Broken in:
  • 3.22
  • 3.23
Fixed in: (no value)



Subject: Timings do not work as expected with -j2
Download (untitled) / with headers
text/plain 1.7k
prove with -j2 does not report timings correctly in some instances. I can't pinpoint exactly when it does and does not time correctly, but I have reproduced the issue with the attached tarball: unpack and run "run-tests.sh". Expected: that the timings will be the same (+/- a few ms) Actual: timings are way off when running parallel tests Each test returns TAP; an "ok 1" when it starts and an "ok 2" after a timing loop. I avoided using sleep in the timing loop to simulate actual work being done. $ ./run-tests.sh Prove run 1, note times: [15:56:27] 01_2sec.t ..... ok 2368 ms [15:56:29] 02_1sec.t ..... ok 1151 ms [15:56:30] 03_instant.t .. ok 288 ms [15:56:30] 04_2sec.t ..... ok 2382 ms [15:56:33] 05_instant.t .. ok 2 ms [15:56:33] All tests successful. Files=5, Tests=10, 7 wallclock secs ( 0.06 usr 0.02 sys + 1.14 cusr 0.66 csys = 1.88 CPU) Result: PASS TAP Archive created at /home/pkrawczyk/provebug/arch-j1.tgz Prove run 2, note times: [15:56:36] 02_1sec.t ..... ok 3 ms [15:56:36] 03_instant.t .. ok 2 ms [15:56:36] 01_2sec.t ..... ok 3 ms [15:56:38] 05_instant.t .. ok 4 ms [15:56:38] 04_2sec.t ..... ok 5 ms [15:56:39] All tests successful. Files=5, Tests=10, 4 wallclock secs ( 0.05 usr 0.02 sys + 0.81 cusr 0.42 csys = 1.30 CPU) Result: PASS TAP Archive created at /home/pkrawczyk/provebug/arch-j2.tgz meta.yml meta.yml These should all be roughly equivalent: 01_2sec.t -j1 run: end_time: 1303332989.38403 start_time: 1303332987.01512 01_2sec.t -j2 run: end_time: 1303332996.66014 start_time: 1303332996.65696 02_1sec.t -j1 run: (clipped to save sanity)
Subject: provebug.tgz
Download provebug.tgz
application/x-gzip 649b

Message body not shown because it is not plain text.

Download (untitled) / with headers
text/plain 162b
It occurs to me that I have HARNESS_TIMER=1 set in my environment. run-tests.sh may need to add "--timer" to the prove calls to duplicate the environment I'm in.
Download (untitled) / with headers
text/plain 721b
On 2011-04-20 16:59:08, PETEK wrote: Show quoted text
> prove with -j2 does not report timings correctly in some instances. I > can't pinpoint exactly when it does and does not time correctly, but I > have reproduced the issue with the attached tarball: unpack and run > "run-tests.sh". > > Expected: that the timings will be the same (+/- a few ms) > Actual: timings are way off when running parallel tests
[...] I can reproduce the problem with a rather recent perl: $ prove --version TAP::Harness v3.26 and Perl v5.18.2 In my setup, if I run my test suite with "prove -j3 --timer", then some test script run times are reported to be even 1ms --- where the same test script running alone takes more than 100ms. Regards, Slaven


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

Please report any issues with rt.cpan.org to rt-cpan-admin@bestpractical.com.