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
1 #!./perl -w
2
3 BEGIN {
4     chdir 't' if -d 't';
5     @INC = ('../lib');
6 }
7
8 use warnings;
9 use strict;
10 use vars qw($foo $bar $baz $ballast);
11 use Test::More tests => 197;
12
13 use Benchmark qw(:all);
14
15 my $DELTA = 0.4;
16
17 # Some timing ballast
18 sub fib {
19   my $n = shift;
20   return $n if $n < 2;
21   fib($n-1) + fib($n-2);
22 }
23 $ballast = 15;
24
25 my $All_Pattern =
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\)/;
27 my $Noc_Pattern =
28     qr/(\d+) +wallclock secs? +\( *(-?\d+\.\d\d) +usr +\+ +(-?\d+\.\d\d) +sys += +(-?\d+\.\d\d) +CPU\)/;
29 my $Nop_Pattern =
30     qr/(\d+) +wallclock secs? +\( *(-?\d+\.\d\d) +cusr +\+ +(-?\d+\.\d\d) +csys += +\d+\.\d\d +CPU\)/;
31 # Please don't trust the matching parentheses to be useful in this :-)
32 my $Default_Pattern = qr/$All_Pattern|$Noc_Pattern/;
33
34 # see if the ratio of two integer values is within (1+$delta)
35
36 sub 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
43 my $t0 = new Benchmark;
44 isa_ok ($t0, 'Benchmark', "Ensure we can create a benchmark object");
45
46 # We use the benchmark object once we've done some work:
47
48 isa_ok(timeit(5, sub {++$foo}), 'Benchmark', "timeit CODEREF");
49 is ($foo, 5, "benchmarked code was run 5 times");
50
51 isa_ok(timeit(5, '++$bar'), 'Benchmark', "timeit eval");
52 is ($bar, 5, "benchmarked code was run 5 times");
53
54 # is coderef called with spurious arguments?
55 timeit( 1, sub { $foo = @_ });
56 is ($foo, 0, "benchmarked code called without arguments");
57
58
59 print "# Burning CPU to see if clock is consistent...\n";
60
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
64
65 my $INCONSISTENT_CLOCK = 0;
66 my $calibration;
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
106     # we use 0.7 of $DELTA so that we err on the side of assuming
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
110     unless (cmp_delta(3*$td1, $td3, 0.7*$DELTA)) {
111         print "# INCONSISTENT CLOCK! - will skip timing-related tests\n";
112         $INCONSISTENT_CLOCK = 1;
113     }
114     $calibration = $td3/(3*$td1); # for diag output
115
116 }
117 ok(!$INCONSISTENT_CLOCK, "temporary calibration test");
118
119
120 print "# Burning CPU to benchmark things; will take time...\n";
121
122 # We need to do something fairly slow in the coderef.
123 # Same coderef. Same place in memory.
124 my $coderef = sub {$baz += fib($ballast)};
125
126 # The default is three.
127 $baz = 0;
128 my $threesecs = countit(0, $coderef);
129 isa_ok($threesecs, 'Benchmark', "countit 0, CODEREF");
130 isnt ($baz, 0, "benchmarked code was run");
131 my $in_threesecs = $threesecs->iters;
132 print "# in_threesecs=$in_threesecs iterations\n";
133 ok ($in_threesecs > 0, "iters returned positive iterations");
134 my $cpu3 = $threesecs->[1]; # user
135 my $sys3 = $threesecs->[2]; # sys
136 cmp_ok($cpu3+$sys3, '>=', 3.0, "3s cpu3 is at least 3s");
137 my $in_threesecs_adj = $in_threesecs;
138 $in_threesecs_adj *= (3/$cpu3); # adjust because may not have run for exactly 3s
139 print "# in_threesecs_adj=$in_threesecs_adj adjusted iterations\n";
140
141 my $estimate = int (100 * $in_threesecs_adj / 3) / 100;
142 print "# from the 3 second run estimate $estimate iterations in 1 second...\n";
143 $baz = 0;
144 my $onesec = countit(1, $coderef);
145 isa_ok($onesec, 'Benchmark', "countit 1, CODEREF");
146 isnt ($baz, 0, "benchmarked code was run");
147 my $in_onesec = $onesec->iters;
148 print "# in_onesec=$in_onesec iterations\n";
149 ok ($in_onesec > 0, "iters returned positive iterations");
150 my $cpu1 = $onesec->[1]; # user
151 my $sys1 = $onesec->[2]; # sys
152 cmp_ok($cpu1+$sys1, '>=', 1.0, "is cpu1 is at least 1s");
153 my $in_onesec_adj = $in_onesec;
154 $in_onesec_adj *= (1/$cpu1); # adjust because may not have run for exactly 1s
155 print "# in_onesec_adj=$in_onesec_adj adjusted iterations\n";
156
157 SKIP: {
158     skip(1, "INCONSISTENT CLOCK") if $INCONSISTENT_CLOCK;
159
160     ok(cmp_delta($in_onesec_adj, $estimate, $DELTA),
161                 "is $in_onesec_adj within $DELTA of estimate ($estimate)?")
162     or do {
163         diag("  in_threesecs     = $in_threesecs");
164         diag("  in_threesecs_adj = $in_threesecs_adj");
165         diag("  cpu3             = $cpu3");
166         diag("  sys3             = $sys3");
167         diag("  estimate         = $estimate");
168         diag("  in_onesec        = $in_onesec");
169         diag("  in_onesec_adj    = $in_onesec_adj");
170         diag("  cpu1             = $cpu1");
171         diag("  sys1             = $sys1");
172         diag("  calibration      = $calibration");
173     };
174 }
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;
179 my $again = countit(1, '$baz += fib($ballast)');
180 isa_ok($onesec, 'Benchmark', "countit 1, eval");
181 isnt ($baz, 0, "benchmarked code was run");
182 my $in_again = $again->iters;
183 print "# $in_again iterations\n";
184 ok ($in_again > 0, "iters returned positive iterations");
185
186
187 my $t1 = new Benchmark;
188 isa_ok ($t1, 'Benchmark', "Create another benchmark object now we're finished");
189
190 my $diff = timediff ($t1, $t0);
191 isa_ok ($diff, 'Benchmark', "Get the time difference");
192 isa_ok (timesum ($t0, $t1), 'Benchmark', "check timesum");
193
194 my $default = timestr ($diff);
195 isnt ($default, '', 'timestr ($diff)');
196 my $auto = timestr ($diff, 'auto');
197 is ($auto, $default, 'timestr ($diff, "auto") matches timestr ($diff)');
198
199 {
200     my $all = timestr ($diff, 'all');
201     like ($all, $All_Pattern, 'timestr ($diff, "all")');
202     print "# $all\n";
203
204     my ($wallclock, $usr, $sys, $cusr, $csys, $cpu) = $all =~ $All_Pattern;
205
206     is (timestr ($diff, 'none'), '', "none suppresses output");
207
208     my $noc = timestr ($diff, 'noc');
209     like ($noc, qr/$wallclock +wallclock secs? +\( *$usr +usr +\+ +$sys +sys += +\d+\.\d\d +CPU\)/, 'timestr ($diff, "noc")');
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
224 my $out = tie *OUT, 'TieOut';
225
226 my $iterations = 3;
227
228 $foo = 0;
229 select(OUT);
230 my $got = timethis($iterations, sub {++$foo});
231 select(STDOUT);
232 isa_ok($got, 'Benchmark', "timethis CODEREF");
233 is ($foo, $iterations, "benchmarked code was run $iterations times");
234
235 $got = $out->read();
236 like ($got, qr/^timethis $iterations/, 'default title');
237 like ($got, $Default_Pattern, 'default format is all or noc');
238
239 $bar = 0;
240 select(OUT);
241 $got = timethis($iterations, '++$bar');
242 select(STDOUT);
243 isa_ok($got, 'Benchmark', "timethis eval");
244 is ($bar, $iterations, "benchmarked code was run $iterations times");
245
246 $got = $out->read();
247 like ($got, qr/^timethis $iterations/, 'default title');
248 like ($got, $Default_Pattern, 'default format is all or noc');
249
250 my $title = 'lies, damn lies and benchmarks';
251 $foo = 0;
252 select(OUT);
253 $got = timethis($iterations, sub {++$foo}, $title);
254 select(STDOUT);
255 isa_ok($got, 'Benchmark', "timethis with title");
256 is ($foo, $iterations, "benchmarked code was run $iterations times");
257
258 $got = $out->read();
259 like ($got, qr/^$title:/, 'specify title');
260 like ($got, $Default_Pattern, 'default format is all or noc');
261
262 # default is auto, which is all or noc. nop can never match the default
263 $foo = 0;
264 select(OUT);
265 $got = timethis($iterations, sub {++$foo}, $title, 'nop');
266 select(STDOUT);
267 isa_ok($got, 'Benchmark', "timethis with format");
268 is ($foo, $iterations, "benchmarked code was run $iterations times");
269
270 $got = $out->read();
271 like ($got, qr/^$title:/, 'specify title');
272 like ($got, $Nop_Pattern, 'specify format as nop');
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;
295 select(OUT);
296 $got = timethese($iterations, { Foo => sub {++$foo}, Bar => '++$bar',
297                                 Baz => sub {++$baz} });
298 select(STDOUT);
299 is(ref ($got), 'HASH', "timethese should return a hashref");
300 isa_ok($got->{Foo}, 'Benchmark', "Foo value");
301 isa_ok($got->{Bar}, 'Benchmark', "Bar value");
302 isa_ok($got->{Baz}, 'Benchmark', "Baz value");
303 eq_set([keys %$got], [qw(Foo Bar Baz)], 'should be exactly three objects');
304 is ($foo, $iterations, "Foo code was run $iterations times");
305 is ($bar, $iterations, "Bar code was run $iterations times");
306 is ($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
312 like ($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;
316 like ($got, qr/\bBar\b.*\bBaz\b.*\bFoo\b/s, 'check output is in sorted order');
317 like ($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
353
354 my $code_to_test =  { Foo => sub {$foo+=fib($ballast-2)},
355                       Bar => sub {$bar+=fib($ballast)}};
356 # Keep these for later.
357 my $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 }
380 my $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
385 sub check_graph_consistency {
386     my (        $ratetext, $slowc, $fastc,
387         $slowr, $slowratet, $slowslow, $slowfastt,
388         $fastr, $fastratet, $fastslowt, $fastfast)
389         = @_;
390     note("calling check_graph_consistency from line " . (caller(1))[2]);
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");
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) {
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");
416     } else {
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");
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");
427         unless (ok ($slowfast <= 0 && $slowfast >= -100,
428                     "slowfast should be less than or equal to zero, and >= -100")) {
429           print STDERR "# slowfast $slowfast\n";
430           $all_passed = 0;
431         }
432         unless (ok ($fastslow > 0, "fastslow should be > 0")) {
433           print STDERR "# fastslow $fastslow\n";
434           $all_passed = 0;
435         }
436     } else {
437         $all_passed
438           &= is ($slowrate, $fastrate,
439                  "slow rate isn't less than fast rate, so should be the same");
440         # In OpenBSD the $slowfast is sometimes a really, really, really
441         # small number less than zero, and this gets stringified as -0.
442         $all_passed
443           &= like ($slowfast, qr/^-?0$/, "slowfast should be zero");
444         $all_passed
445           &= like ($fastslow, qr/^-?0$/, "fastslow should be zero");
446     }
447     return $all_passed;
448 }
449
450 sub 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;
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     }
469 }
470
471 sub 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;
483     my $chart = cmpthese( -0.1, { a => "++\$i", b => "\$i = sqrt(\$i++)" }, "auto" ) ;
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;
496     like ($got, $Default_Pattern, 'should find default format somewhere');
497     like ($got, $graph_dissassembly, "Should find the output graph somewhere");
498     check_graph_vs_output ($chart, $got);
499 }
500
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;
518     unlike ($got, $Default_Pattern, 'should not find default format somewhere');
519     like ($got, $graph_dissassembly, "Should find the output graph somewhere");
520     check_graph_vs_output ($chart, $got);
521 }
522
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;
538     like ($got, $Nop_Pattern, 'specify format as nop');
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
596 my $debug = tie *STDERR, 'TieOut';
597
598 $bar = 0;
599 isa_ok(timeit(5, '++$bar'), 'Benchmark', "timeit eval");
600 is ($bar, 5, "benchmarked code was run 5 times");
601 is ($debug->read(), '', "There was no debug output");
602
603 Benchmark->debug(1);
604
605 $bar = 0;
606 select(OUT);
607 $got = timeit(5, '++$bar');
608 select(STDOUT);
609 isa_ok($got, 'Benchmark', "timeit eval");
610 is ($bar, 5, "benchmarked code was run 5 times");
611 is ($out->read(), '', "There was no STDOUT output with debug enabled");
612 isnt ($debug->read(), '', "There was STDERR debug output with debug enabled");
613
614 Benchmark->debug(0);
615
616 $bar = 0;
617 isa_ok(timeit(5, '++$bar'), 'Benchmark', "timeit eval");
618 is ($bar, 5, "benchmarked code was run 5 times");
619 is ($debug->read(), '', "There was no debug output debug disabled");
620
621 undef $debug;
622 untie *STDERR;
623
624 # To check the cache we are poking where we don't belong, inside the namespace.
625 # The way benchmark is written we can't actually check whether the cache is
626 # being used, merely what's become cached.
627
628 clearallcache();
629 my @before_keys = keys %Benchmark::Cache;
630 $bar = 0;
631 isa_ok(timeit(5, '++$bar'), 'Benchmark', "timeit eval");
632 is ($bar, 5, "benchmarked code was run 5 times");
633 my @after5_keys = keys %Benchmark::Cache;
634 $bar = 0;
635 isa_ok(timeit(10, '++$bar'), 'Benchmark', "timeit eval");
636 is ($bar, 10, "benchmarked code was run 10 times");
637 ok (!eq_array ([keys %Benchmark::Cache], \@after5_keys), "10 differs from 5");
638
639 clearcache(10);
640 # Hash key order will be the same if there are the same keys.
641 is_deeply ([keys %Benchmark::Cache], \@after5_keys,
642            "cleared 10, only cached results for 5 should remain");
643
644 clearallcache();
645 is_deeply ([keys %Benchmark::Cache], \@before_keys,
646            "back to square 1 when we clear the cache again?");
647
648
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)";
683         is( $@, $usage{$func}, "$func usage: with args" );
684     }
685 }
686
687
688 package TieOut;
689
690 sub TIEHANDLE {
691     my $class = shift;
692     bless(\( my $ref = ''), $class);
693 }
694
695 sub PRINT {
696     my $self = shift;
697     $$self .= join('', @_);
698 }
699
700 sub PRINTF {
701     my $self = shift;
702     $$self .= sprintf shift, @_;
703 }
704
705 sub read {
706     my $self = shift;
707     return substr($$self, 0, length($$self), '');
708 }