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