This is a live mirror of the Perl 5 development currently hosted at https://github.com/perl/perl5
Benchmark.t: fix skip() call
[perl5.git] / lib / Benchmark.t
CommitLineData
0e74ff8e
JH
1#!./perl -w
2
3BEGIN {
4 chdir 't' if -d 't';
53aa2791 5 @INC = ('../lib');
0e74ff8e
JH
6}
7
8use warnings;
9use strict;
10use vars qw($foo $bar $baz $ballast);
f12bac97 11use Test::More tests => 197;
0e74ff8e
JH
12
13use Benchmark qw(:all);
14
8a753380 15my $DELTA = 0.4;
0e74ff8e
JH
16
17# Some timing ballast
18sub fib {
19 my $n = shift;
20 return $n if $n < 2;
21 fib($n-1) + fib($n-2);
22}
23$ballast = 15;
24
53aa2791 25my $All_Pattern =
0e74ff8e 26 qr/(\d+) +wallclock secs? +\( *(-?\d+\.\d\d) +usr +(-?\d+\.\d\d) +sys +\+ +(-?\d+\.\d\d) +cusr +(-?\d+\.\d\d) +csys += +(-?\d+\.\d\d) +CPU\)/;
53aa2791 27my $Noc_Pattern =
0e74ff8e 28 qr/(\d+) +wallclock secs? +\( *(-?\d+\.\d\d) +usr +\+ +(-?\d+\.\d\d) +sys += +(-?\d+\.\d\d) +CPU\)/;
53aa2791 29my $Nop_Pattern =
0e74ff8e 30 qr/(\d+) +wallclock secs? +\( *(-?\d+\.\d\d) +cusr +\+ +(-?\d+\.\d\d) +csys += +\d+\.\d\d +CPU\)/;
98dc9551 31# Please don't trust the matching parentheses to be useful in this :-)
53aa2791 32my $Default_Pattern = qr/$All_Pattern|$Noc_Pattern/;
0e74ff8e 33
8a753380
DM
34# see if the ratio of two integer values is within (1+$delta)
35
36sub cmp_delta {
37 my ($min, $max, $delta) = @_;
38 ($min, $max) = ($max, $min) if $max < $min;
39 return 0 if $min < 1; # avoid / 0
40 return $max/$min <= (1+$delta);
41}
42
0e74ff8e
JH
43my $t0 = new Benchmark;
44isa_ok ($t0, 'Benchmark', "Ensure we can create a benchmark object");
45
46# We use the benchmark object once we've done some work:
47
48isa_ok(timeit(5, sub {++$foo}), 'Benchmark', "timeit CODEREF");
49is ($foo, 5, "benchmarked code was run 5 times");
50
51isa_ok(timeit(5, '++$bar'), 'Benchmark', "timeit eval");
52is ($bar, 5, "benchmarked code was run 5 times");
53
f265d4df
AS
54# is coderef called with spurious arguments?
55timeit( 1, sub { $foo = @_ });
56is ($foo, 0, "benchmarked code called without arguments");
57
58
1ebabb47 59print "# Burning CPU to see if clock is consistent...\n";
0e74ff8e 60
1ebabb47
DM
61# Run some code for approx 3 secs, then for 1 sec. If the first doesn't
62# take appoex 3 times longer than the second, then skip any tests which
63# require a consistent clock
0e74ff8e 64
1ebabb47 65my $INCONSISTENT_CLOCK = 0;
e95cc2cf 66my $calibration;
1ebabb47
DM
67
68{
69 my ($t0, $t1, $tdelta);
70
71 $t0 = times; 1 while times == $t0; # wait for OS clock to tick
72
73 # guess approx n for code to run for 1 sec
74 my $n = 1;
75 while ($n < 1_000_000_000) { # eventually stop in worst case
76 $t0 = times;
77 fib($ballast) for 1..$n;
78 $t1 = times;
79 $tdelta = ($t1 - $t0);
80 last if ($tdelta) >= 1.0;
81 $n *= 2;
82 }
83 print "# did $n iterations in $tdelta sec\n";
84
85 # adjust n for exactly one second
86 $n /= $tdelta;
87
88 # now run enough loops for approx 3 secs
89
90 $t0 = times; 1 while times == $t0; # wait for OS clock to tick
91 $t0 = times;
92 fib($ballast) for 1..($n*3);
93 $t1 = times;
94 my $td3 = ($t1 - $t0);
95 print "# approx 3 sec delta is $td3 secs\n";
96
97 # now run enough loops for approx 1 sec
98
99 $t0 = times; 1 while times == $t0; # wait for OS clock to tick
100 $t0 = times;
101 fib($ballast) for 1..$n;
102 $t1 = times;
103 my $td1 = ($t1 - $t0);
104 print "# approx 1 sec delta is $td1 secs\n";
105
8a753380 106 # we use 0.7 of $DELTA so that we err on the side of assuming
1ebabb47
DM
107 # a bad clock and skip tests; otherwise we might be just within the
108 # delta here, and just outside the delta on tests, and so get random
109 # failures
8a753380 110 unless (cmp_delta(3*$td1, $td3, 0.7*$DELTA)) {
1ebabb47
DM
111 print "# INCONSISTENT CLOCK! - will skip timing-related tests\n";
112 $INCONSISTENT_CLOCK = 1;
113 }
e95cc2cf 114 $calibration = $td3/(3*$td1); # for diag output
1ebabb47
DM
115
116}
f12bac97 117ok(!$INCONSISTENT_CLOCK, "temporary calibration test");
1ebabb47
DM
118
119
120print "# Burning CPU to benchmark things; will take time...\n";
0e74ff8e
JH
121
122# We need to do something fairly slow in the coderef.
123# Same coderef. Same place in memory.
124my $coderef = sub {$baz += fib($ballast)};
125
126# The default is three.
127$baz = 0;
128my $threesecs = countit(0, $coderef);
129isa_ok($threesecs, 'Benchmark', "countit 0, CODEREF");
130isnt ($baz, 0, "benchmarked code was run");
131my $in_threesecs = $threesecs->iters;
d684718b 132print "# in_threesecs=$in_threesecs iterations\n";
0e74ff8e 133ok ($in_threesecs > 0, "iters returned positive iterations");
0d66b88d
DM
134my $cpu3 = $threesecs->[1]; # user
135my $sys3 = $threesecs->[2]; # sys
136cmp_ok($cpu3+$sys3, '>=', 3.0, "3s cpu3 is at least 3s");
bb6c6e4b
DM
137my $in_threesecs_adj = $in_threesecs;
138$in_threesecs_adj *= (3/$cpu3); # adjust because may not have run for exactly 3s
139print "# in_threesecs_adj=$in_threesecs_adj adjusted iterations\n";
0e74ff8e 140
58747404 141my $estimate = int (100 * $in_threesecs_adj / 3) / 100;
0e74ff8e
JH
142print "# from the 3 second run estimate $estimate iterations in 1 second...\n";
143$baz = 0;
144my $onesec = countit(1, $coderef);
145isa_ok($onesec, 'Benchmark', "countit 1, CODEREF");
146isnt ($baz, 0, "benchmarked code was run");
147my $in_onesec = $onesec->iters;
d684718b 148print "# in_onesec=$in_onesec iterations\n";
0e74ff8e 149ok ($in_onesec > 0, "iters returned positive iterations");
0d66b88d
DM
150my $cpu1 = $onesec->[1]; # user
151my $sys1 = $onesec->[2]; # sys
152cmp_ok($cpu1+$sys1, '>=', 1.0, "is cpu1 is at least 1s");
bb6c6e4b
DM
153my $in_onesec_adj = $in_onesec;
154$in_onesec_adj *= (1/$cpu1); # adjust because may not have run for exactly 1s
155print "# in_onesec_adj=$in_onesec_adj adjusted iterations\n";
0e74ff8e 156
8a753380 157SKIP: {
5c39bf19 158 skip(1, "INCONSISTENT CLOCK") if $INCONSISTENT_CLOCK;
1ebabb47 159
8a753380
DM
160 ok(cmp_delta($in_onesec_adj, $estimate, $DELTA),
161 "is $in_onesec_adj within $DELTA of estimate ($estimate)?")
bb6c6e4b
DM
162 or do {
163 diag(" in_threesecs = $in_threesecs");
164 diag(" in_threesecs_adj = $in_threesecs_adj");
165 diag(" cpu3 = $cpu3");
0d66b88d 166 diag(" sys3 = $sys3");
bb6c6e4b
DM
167 diag(" estimate = $estimate");
168 diag(" in_onesec = $in_onesec");
169 diag(" in_onesec_adj = $in_onesec_adj");
170 diag(" cpu1 = $cpu1");
0d66b88d 171 diag(" sys1 = $sys1");
e95cc2cf 172 diag(" calibration = $calibration");
bb6c6e4b 173 };
ab43e786 174}
0e74ff8e
JH
175
176# I found that the eval'ed version was 3 times faster than the coderef.
177# (now it has a different ballast value)
178$baz = 0;
179my $again = countit(1, '$baz += fib($ballast)');
180isa_ok($onesec, 'Benchmark', "countit 1, eval");
181isnt ($baz, 0, "benchmarked code was run");
182my $in_again = $again->iters;
183print "# $in_again iterations\n";
184ok ($in_again > 0, "iters returned positive iterations");
185
186
187my $t1 = new Benchmark;
188isa_ok ($t1, 'Benchmark', "Create another benchmark object now we're finished");
189
190my $diff = timediff ($t1, $t0);
191isa_ok ($diff, 'Benchmark', "Get the time difference");
192isa_ok (timesum ($t0, $t1), 'Benchmark', "check timesum");
193
194my $default = timestr ($diff);
195isnt ($default, '', 'timestr ($diff)');
196my $auto = timestr ($diff, 'auto');
197is ($auto, $default, 'timestr ($diff, "auto") matches timestr ($diff)');
198
199{
200 my $all = timestr ($diff, 'all');
53aa2791 201 like ($all, $All_Pattern, 'timestr ($diff, "all")');
0e74ff8e
JH
202 print "# $all\n";
203
53aa2791 204 my ($wallclock, $usr, $sys, $cusr, $csys, $cpu) = $all =~ $All_Pattern;
0e74ff8e 205
98dc9551 206 is (timestr ($diff, 'none'), '', "none suppresses output");
0e74ff8e
JH
207
208 my $noc = timestr ($diff, 'noc');
bd9f0ebf 209 like ($noc, qr/$wallclock +wallclock secs? +\( *$usr +usr +\+ +$sys +sys += +\d+\.\d\d +CPU\)/, 'timestr ($diff, "noc")');
0e74ff8e
JH
210
211 my $nop = timestr ($diff, 'nop');
212 like ($nop, qr/$wallclock +wallclock secs? +\( *$cusr +cusr +\+ +$csys +csys += +\d+\.\d\d +CPU\)/, 'timestr ($diff, "nop")');
213
214 if ($auto eq $noc) {
215 pass ('"auto" is "noc"');
216 } else {
217 is ($auto, $all, '"auto" isn\'t "noc", so should be eq to "all"');
218 }
219
220 like (timestr ($diff, 'all', 'E'),
221 qr/(\d+) +wallclock secs? +\( *\d\.\d+E[-+]?\d\d\d? +usr +\d\.\d+E[-+]?\d\d\d? +sys +\+ +\d\.\d+E[-+]?\d\d\d? +cusr +\d\.\d+E[-+]?\d\d\d? +csys += +\d\.\d+E[-+]?\d\d\d? +CPU\)/, 'timestr ($diff, "all", "E") [sprintf format of "E"]');
222}
223
224my $out = tie *OUT, 'TieOut';
225
226my $iterations = 3;
227
228$foo = 0;
229select(OUT);
230my $got = timethis($iterations, sub {++$foo});
231select(STDOUT);
232isa_ok($got, 'Benchmark', "timethis CODEREF");
233is ($foo, $iterations, "benchmarked code was run $iterations times");
234
235$got = $out->read();
236like ($got, qr/^timethis $iterations/, 'default title');
53aa2791 237like ($got, $Default_Pattern, 'default format is all or noc');
0e74ff8e
JH
238
239$bar = 0;
240select(OUT);
241$got = timethis($iterations, '++$bar');
242select(STDOUT);
243isa_ok($got, 'Benchmark', "timethis eval");
244is ($bar, $iterations, "benchmarked code was run $iterations times");
245
246$got = $out->read();
247like ($got, qr/^timethis $iterations/, 'default title');
53aa2791 248like ($got, $Default_Pattern, 'default format is all or noc');
0e74ff8e
JH
249
250my $title = 'lies, damn lies and benchmarks';
251$foo = 0;
252select(OUT);
253$got = timethis($iterations, sub {++$foo}, $title);
254select(STDOUT);
255isa_ok($got, 'Benchmark', "timethis with title");
256is ($foo, $iterations, "benchmarked code was run $iterations times");
257
258$got = $out->read();
259like ($got, qr/^$title:/, 'specify title');
53aa2791 260like ($got, $Default_Pattern, 'default format is all or noc');
0e74ff8e
JH
261
262# default is auto, which is all or noc. nop can never match the default
263$foo = 0;
264select(OUT);
265$got = timethis($iterations, sub {++$foo}, $title, 'nop');
266select(STDOUT);
267isa_ok($got, 'Benchmark', "timethis with format");
268is ($foo, $iterations, "benchmarked code was run $iterations times");
269
270$got = $out->read();
271like ($got, qr/^$title:/, 'specify title');
53aa2791 272like ($got, $Nop_Pattern, 'specify format as nop');
0e74ff8e
JH
273
274{
275 $foo = 0;
276 select(OUT);
277 my $start = time;
278 $got = timethis(-2, sub {$foo+= fib($ballast)}, $title, 'none');
279 my $end = time;
280 select(STDOUT);
281 isa_ok($got, 'Benchmark',
282 "timethis, at least 2 seconds with format 'none'");
283 ok ($foo > 0, "benchmarked code was run");
284 ok ($end - $start > 1, "benchmarked code ran for over 1 second");
285
286 $got = $out->read();
287 # Remove any warnings about having too few iterations.
288 $got =~ s/\(warning:[^\)]+\)//gs;
289 $got =~ s/^[ \t\n]+//s; # Remove all the whitespace from the beginning
290
291 is ($got, '', "format 'none' should suppress output");
292}
293
294$foo = $bar = $baz = 0;
295select(OUT);
296$got = timethese($iterations, { Foo => sub {++$foo}, Bar => '++$bar',
297 Baz => sub {++$baz} });
298select(STDOUT);
299is(ref ($got), 'HASH', "timethese should return a hashref");
300isa_ok($got->{Foo}, 'Benchmark', "Foo value");
301isa_ok($got->{Bar}, 'Benchmark', "Bar value");
302isa_ok($got->{Baz}, 'Benchmark', "Baz value");
303eq_set([keys %$got], [qw(Foo Bar Baz)], 'should be exactly three objects');
304is ($foo, $iterations, "Foo code was run $iterations times");
305is ($bar, $iterations, "Bar code was run $iterations times");
306is ($baz, $iterations, "Baz code was run $iterations times");
307
308$got = $out->read();
309# Remove any warnings about having too few iterations.
310$got =~ s/\(warning:[^\)]+\)//gs;
311
312like ($got, qr/timing $iterations iterations of\s+Bar\W+Baz\W+Foo\W*?\.\.\./s,
313 'check title');
314# Remove the title
315$got =~ s/.*\.\.\.//s;
316like ($got, qr/\bBar\b.*\bBaz\b.*\bFoo\b/s, 'check output is in sorted order');
53aa2791
MS
317like ($got, $Default_Pattern, 'should find default format somewhere');
318
319
320{ # ensure 'use strict' does not leak from Benchmark.pm into benchmarked code
321 no strict;
322 select OUT;
323
324 eval {
325 timethese( 1,
326 { undeclared_var => q{ $i++; $i-- },
327 symbolic_ref => q{ $bar = 42;
328 $foo = 'bar';
329 $q = ${$foo} },
330 },
331 'none'
332 );
333
334 };
335 is( $@, '', q{no strict leakage in name => 'code'} );
336
337 eval {
338 timethese( 1,
339 { undeclared_var => sub { $i++; $i-- },
340 symbolic_ref => sub { $bar = 42;
341 $foo = 'bar';
342 return ${$foo} },
343 },
344 'none'
345 );
346 };
347 is( $@, '', q{no strict leakage in name => sub { code }} );
348
349 # clear out buffer
350 $out->read;
351}
352
0e74ff8e
JH
353
354my $code_to_test = { Foo => sub {$foo+=fib($ballast-2)},
355 Bar => sub {$bar+=fib($ballast)}};
356# Keep these for later.
357my $results;
358{
359 $foo = $bar = 0;
360 select(OUT);
361 my $start = times;
362 $results = timethese(-0.1, $code_to_test, 'none');
363 my $end = times;
364 select(STDOUT);
365
366 is(ref ($results), 'HASH', "timethese should return a hashref");
367 isa_ok($results->{Foo}, 'Benchmark', "Foo value");
368 isa_ok($results->{Bar}, 'Benchmark', "Bar value");
369 eq_set([keys %$results], [qw(Foo Bar)], 'should be exactly two objects');
370 ok ($foo > 0, "Foo code was run");
371 ok ($bar > 0, "Bar code was run");
372
373 ok (($end - $start) > 0.1, "benchmarked code ran for over 0.1 seconds");
374
375 $got = $out->read();
376 # Remove any warnings about having too few iterations.
377 $got =~ s/\(warning:[^\)]+\)//gs;
378 is ($got =~ tr/ \t\n//c, 0, "format 'none' should suppress output");
379}
380my $graph_dissassembly =
381 qr!^[ \t]+(\S+)[ \t]+(\w+)[ \t]+(\w+)[ \t]* # Title line
382 \n[ \t]*(\w+)[ \t]+([0-9.]+(?:/s)?)[ \t]+(-+)[ \t]+(-?\d+%)[ \t]*
383 \n[ \t]*(\w+)[ \t]+([0-9.]+(?:/s)?)[ \t]+(-?\d+%)[ \t]+(-+)[ \t]*$!xm;
384
385sub check_graph_consistency {
386 my ( $ratetext, $slowc, $fastc,
387 $slowr, $slowratet, $slowslow, $slowfastt,
388 $fastr, $fastratet, $fastslowt, $fastfast)
389 = @_;
ca55f232 390 note("calling check_graph_consistency from line " . (caller(1))[2]);
23c50b23
NC
391 my $all_passed = 1;
392 $all_passed
393 &= is ($slowc, $slowr, "left col tag should be top row tag");
394 $all_passed
395 &= is ($fastc, $fastr, "right col tag should be bottom row tag");
396 $all_passed &=
397 like ($slowslow, qr/^-+/, "should be dash for comparing slow with slow");
398 $all_passed
399 &= is ($slowslow, $fastfast, "slow v slow should be same as fast v fast");
0e74ff8e
JH
400 my $slowrate = $slowratet;
401 my $fastrate = $fastratet;
402 my ($slow_is_rate, $fast_is_rate);
403 unless ($slow_is_rate = $slowrate =~ s!/s!!) {
404 # Slow is expressed as iters per second.
405 $slowrate = 1/$slowrate if $slowrate;
406 }
407 unless ($fast_is_rate = $fastrate =~ s!/s!!) {
408 # Fast is expressed as iters per second.
409 $fastrate = 1/$fastrate if $fastrate;
410 }
411 if ($ratetext =~ /rate/i) {
23c50b23
NC
412 $all_passed
413 &= ok ($slow_is_rate, "slow should be expressed as a rate");
414 $all_passed
415 &= ok ($fast_is_rate, "fast should be expressed as a rate");
0e74ff8e 416 } else {
23c50b23
NC
417 $all_passed &=
418 ok (!$slow_is_rate, "slow should be expressed as a iters per second");
419 $all_passed &=
420 ok (!$fast_is_rate, "fast should be expressed as a iters per second");
0e74ff8e
JH
421 }
422
423 (my $slowfast = $slowfastt) =~ s!%!!;
424 (my $fastslow = $fastslowt) =~ s!%!!;
425 if ($slowrate < $fastrate) {
426 pass ("slow rate is less than fast rate");
07e88136
JH
427 unless (ok ($slowfast <= 0 && $slowfast >= -100,
428 "slowfast should be less than or equal to zero, and >= -100")) {
2d684b7a 429 print STDERR "# slowfast $slowfast\n";
23c50b23
NC
430 $all_passed = 0;
431 }
432 unless (ok ($fastslow > 0, "fastslow should be > 0")) {
e5967bfd 433 print STDERR "# fastslow $fastslow\n";
23c50b23
NC
434 $all_passed = 0;
435 }
0e74ff8e 436 } else {
23c50b23
NC
437 $all_passed
438 &= is ($slowrate, $fastrate,
439 "slow rate isn't less than fast rate, so should be the same");
620b59a5
JH
440 # In OpenBSD the $slowfast is sometimes a really, really, really
441 # small number less than zero, and this gets stringified as -0.
23c50b23 442 $all_passed
620b59a5 443 &= like ($slowfast, qr/^-?0$/, "slowfast should be zero");
23c50b23 444 $all_passed
620b59a5 445 &= like ($fastslow, qr/^-?0$/, "fastslow should be zero");
0e74ff8e 446 }
23c50b23 447 return $all_passed;
0e74ff8e
JH
448}
449
450sub check_graph_vs_output {
451 my ($chart, $got) = @_;
452 my ( $ratetext, $slowc, $fastc,
453 $slowr, $slowratet, $slowslow, $slowfastt,
454 $fastr, $fastratet, $fastslowt, $fastfast)
455 = $got =~ $graph_dissassembly;
23c50b23
NC
456 my $all_passed
457 = check_graph_consistency ( $ratetext, $slowc, $fastc,
458 $slowr, $slowratet, $slowslow, $slowfastt,
459 $fastr, $fastratet, $fastslowt, $fastfast);
460 $all_passed
461 &= is_deeply ($chart, [['', $ratetext, $slowc, $fastc],
462 [$slowr, $slowratet, $slowslow, $slowfastt],
463 [$fastr, $fastratet, $fastslowt, $fastfast]],
464 "check the chart layout matches the formatted output");
465 unless ($all_passed) {
466 print STDERR "# Something went wrong there. I got this chart:\n";
467 print STDERR "# $_\n" foreach split /\n/, $got;
468 }
0e74ff8e
JH
469}
470
471sub check_graph {
472 my ($title, $row1, $row2) = @_;
473 is (scalar @$title, 4, "Four entries in title row");
474 is (scalar @$row1, 4, "Four entries in first row");
475 is (scalar @$row2, 4, "Four entries in second row");
476 is (shift @$title, '', "First entry of output graph should be ''");
477 check_graph_consistency (@$title, @$row1, @$row2);
478}
479
480{
481 select(OUT);
482 my $start = times;
8962dfd6 483 my $chart = cmpthese( -0.1, { a => "++\$i", b => "\$i = sqrt(\$i++)" }, "auto" ) ;
0e74ff8e
JH
484 my $end = times;
485 select(STDOUT);
486 ok (($end - $start) > 0.05, "benchmarked code ran for over 0.05 seconds");
487
488 $got = $out->read();
489 # Remove any warnings about having too few iterations.
490 $got =~ s/\(warning:[^\)]+\)//gs;
491
492 like ($got, qr/running\W+a\W+b.*?for at least 0\.1 CPU second/s,
493 'check title');
494 # Remove the title
495 $got =~ s/.*\.\.\.//s;
53aa2791 496 like ($got, $Default_Pattern, 'should find default format somewhere');
0e74ff8e
JH
497 like ($got, $graph_dissassembly, "Should find the output graph somewhere");
498 check_graph_vs_output ($chart, $got);
499}
500
8962dfd6
A
501# Not giving auto should suppress timethese results.
502{
503 select(OUT);
504 my $start = times;
505 my $chart = cmpthese( -0.1, { a => "++\$i", b => "\$i = sqrt(\$i++)" } ) ;
506 my $end = times;
507 select(STDOUT);
508 ok (($end - $start) > 0.05, "benchmarked code ran for over 0.05 seconds");
509
510 $got = $out->read();
511 # Remove any warnings about having too few iterations.
512 $got =~ s/\(warning:[^\)]+\)//gs;
513
514 unlike ($got, qr/running\W+a\W+b.*?for at least 0\.1 CPU second/s,
515 'should not have title');
516 # Remove the title
517 $got =~ s/.*\.\.\.//s;
53aa2791 518 unlike ($got, $Default_Pattern, 'should not find default format somewhere');
8962dfd6
A
519 like ($got, $graph_dissassembly, "Should find the output graph somewhere");
520 check_graph_vs_output ($chart, $got);
521}
522
0e74ff8e
JH
523{
524 $foo = $bar = 0;
525 select(OUT);
526 my $chart = cmpthese( 10, $code_to_test, 'nop' ) ;
527 select(STDOUT);
528 ok ($foo > 0, "Foo code was run");
529 ok ($bar > 0, "Bar code was run");
530
531 $got = $out->read();
532 # Remove any warnings about having too few iterations.
533 $got =~ s/\(warning:[^\)]+\)//gs;
534 like ($got, qr/timing 10 iterations of\s+Bar\W+Foo\W*?\.\.\./s,
535 'check title');
536 # Remove the title
537 $got =~ s/.*\.\.\.//s;
53aa2791 538 like ($got, $Nop_Pattern, 'specify format as nop');
0e74ff8e
JH
539 like ($got, $graph_dissassembly, "Should find the output graph somewhere");
540 check_graph_vs_output ($chart, $got);
541}
542
543{
544 $foo = $bar = 0;
545 select(OUT);
546 my $chart = cmpthese( 10, $code_to_test, 'none' ) ;
547 select(STDOUT);
548 ok ($foo > 0, "Foo code was run");
549 ok ($bar > 0, "Bar code was run");
550
551 $got = $out->read();
552 # Remove any warnings about having too few iterations.
553 $got =~ s/\(warning:[^\)]+\)//gs;
554 $got =~ s/^[ \t\n]+//s; # Remove all the whitespace from the beginning
555 is ($got, '', "format 'none' should suppress output");
556 is (ref $chart, 'ARRAY', "output should be an array ref");
557 # Some of these will go bang if the preceding test fails. There will be
558 # a big clue as to why, from the previous test's diagnostic
559 is (ref $chart->[0], 'ARRAY', "output should be an array of arrays");
560 check_graph (@$chart);
561}
562
563{
564 $foo = $bar = 0;
565 select(OUT);
566 my $chart = cmpthese( $results ) ;
567 select(STDOUT);
568 is ($foo, 0, "Foo code was not run");
569 is ($bar, 0, "Bar code was not run");
570
571 $got = $out->read();
572 ok ($got !~ /\.\.\./s, 'check that there is no title');
573 like ($got, $graph_dissassembly, "Should find the output graph somewhere");
574 check_graph_vs_output ($chart, $got);
575}
576
577{
578 $foo = $bar = 0;
579 select(OUT);
580 my $chart = cmpthese( $results, 'none' ) ;
581 select(STDOUT);
582 is ($foo, 0, "Foo code was not run");
583 is ($bar, 0, "Bar code was not run");
584
585 $got = $out->read();
586 is ($got, '', "'none' should suppress all output");
587 is (ref $chart, 'ARRAY', "output should be an array ref");
588 # Some of these will go bang if the preceding test fails. There will be
589 # a big clue as to why, from the previous test's diagnostic
590 is (ref $chart->[0], 'ARRAY', "output should be an array of arrays");
591 check_graph (@$chart);
592}
593
594###}my $out = tie *OUT, 'TieOut'; my ($got); ###
595
596my $debug = tie *STDERR, 'TieOut';
597
598$bar = 0;
599isa_ok(timeit(5, '++$bar'), 'Benchmark', "timeit eval");
600is ($bar, 5, "benchmarked code was run 5 times");
601is ($debug->read(), '', "There was no debug output");
602
603Benchmark->debug(1);
604
605$bar = 0;
606select(OUT);
607$got = timeit(5, '++$bar');
608select(STDOUT);
609isa_ok($got, 'Benchmark', "timeit eval");
610is ($bar, 5, "benchmarked code was run 5 times");
611is ($out->read(), '', "There was no STDOUT output with debug enabled");
612isnt ($debug->read(), '', "There was STDERR debug output with debug enabled");
613
614Benchmark->debug(0);
615
616$bar = 0;
617isa_ok(timeit(5, '++$bar'), 'Benchmark', "timeit eval");
618is ($bar, 5, "benchmarked code was run 5 times");
619is ($debug->read(), '', "There was no debug output debug disabled");
620
621undef $debug;
622untie *STDERR;
623
624# To check the cache we are poking where we don't belong, inside the namespace.
98dc9551 625# The way benchmark is written we can't actually check whether the cache is
0e74ff8e
JH
626# being used, merely what's become cached.
627
628clearallcache();
53aa2791 629my @before_keys = keys %Benchmark::Cache;
0e74ff8e
JH
630$bar = 0;
631isa_ok(timeit(5, '++$bar'), 'Benchmark', "timeit eval");
632is ($bar, 5, "benchmarked code was run 5 times");
53aa2791 633my @after5_keys = keys %Benchmark::Cache;
0e74ff8e
JH
634$bar = 0;
635isa_ok(timeit(10, '++$bar'), 'Benchmark', "timeit eval");
636is ($bar, 10, "benchmarked code was run 10 times");
53aa2791 637ok (!eq_array ([keys %Benchmark::Cache], \@after5_keys), "10 differs from 5");
0e74ff8e
JH
638
639clearcache(10);
640# Hash key order will be the same if there are the same keys.
53aa2791 641is_deeply ([keys %Benchmark::Cache], \@after5_keys,
0e74ff8e
JH
642 "cleared 10, only cached results for 5 should remain");
643
644clearallcache();
53aa2791 645is_deeply ([keys %Benchmark::Cache], \@before_keys,
0e74ff8e
JH
646 "back to square 1 when we clear the cache again?");
647
648
53aa2791
MS
649{ # Check usage error messages
650 my %usage = %Benchmark::_Usage;
651 delete $usage{runloop}; # not public, not worrying about it just now
652
653 my @takes_no_args = qw(clearallcache disablecache enablecache);
654
655 my %cmpthese = ('forgot {}' => 'cmpthese( 42, foo => sub { 1 } )',
656 'not result' => 'cmpthese(42)',
657 'array ref' => 'cmpthese( 42, [ foo => sub { 1 } ] )',
658 );
659 while( my($name, $code) = each %cmpthese ) {
660 eval $code;
661 is( $@, $usage{cmpthese}, "cmpthese usage: $name" );
662 }
663
664 my %timethese = ('forgot {}' => 'timethese( 42, foo => sub { 1 } )',
665 'no code' => 'timethese(42)',
666 'array ref' => 'timethese( 42, [ foo => sub { 1 } ] )',
667 );
668
669 while( my($name, $code) = each %timethese ) {
670 eval $code;
671 is( $@, $usage{timethese}, "timethese usage: $name" );
672 }
673
674
675 while( my($func, $usage) = each %usage ) {
676 next if grep $func eq $_, @takes_no_args;
677 eval "$func()";
678 is( $@, $usage, "$func usage: no args" );
679 }
680
681 foreach my $func (@takes_no_args) {
682 eval "$func(42)";
f695f0e6 683 is( $@, $usage{$func}, "$func usage: with args" );
53aa2791
MS
684 }
685}
686
687
0e74ff8e
JH
688package TieOut;
689
690sub TIEHANDLE {
691 my $class = shift;
692 bless(\( my $ref = ''), $class);
693}
694
695sub PRINT {
696 my $self = shift;
697 $$self .= join('', @_);
698}
699
700sub PRINTF {
701 my $self = shift;
702 $$self .= sprintf shift, @_;
703}
704
705sub read {
706 my $self = shift;
707 return substr($$self, 0, length($$self), '');
708}