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