| Subject: | Timings do not work as expected with -j2 |
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 |
Message body not shown because it is not plain text.