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