[perl #73560] [PATCH] Fix typos in Pod::Functions
[p5sagit/p5-mst-13.2.git] / lib / Benchmark.pm
CommitLineData
a0d0e21e 1package Benchmark;
2
53aa2791 3use strict;
4
5
f06db76b 6=head1 NAME
7
8a4f6ac2 8Benchmark - benchmark running times of Perl code
431d98c2 9
f06db76b 10=head1 SYNOPSIS
11
f36484b0 12 use Benchmark qw(:all) ;
13
f06db76b 14 timethis ($count, "code");
15
523cc92b 16 # Use Perl code in strings...
f06db76b 17 timethese($count, {
18 'Name1' => '...code1...',
19 'Name2' => '...code2...',
20 });
21
523cc92b 22 # ... or use subroutine references.
23 timethese($count, {
24 'Name1' => sub { ...code1... },
25 'Name2' => sub { ...code2... },
26 });
27
431d98c2 28 # cmpthese can be used both ways as well
29 cmpthese($count, {
30 'Name1' => '...code1...',
31 'Name2' => '...code2...',
32 });
33
34 cmpthese($count, {
35 'Name1' => sub { ...code1... },
36 'Name2' => sub { ...code2... },
37 });
38
39 # ...or in two stages
40 $results = timethese($count,
41 {
42 'Name1' => sub { ...code1... },
43 'Name2' => sub { ...code2... },
44 },
45 'none'
46 );
47 cmpthese( $results ) ;
48
f06db76b 49 $t = timeit($count, '...other code...')
50 print "$count loops of other code took:",timestr($t),"\n";
51
431d98c2 52 $t = countit($time, '...other code...')
53 $count = $t->iters ;
54 print "$count loops of other code took:",timestr($t),"\n";
55
e3d6de9a 56 # enable hires wallclock timing if possible
57 use Benchmark ':hireswallclock';
58
f06db76b 59=head1 DESCRIPTION
60
61The Benchmark module encapsulates a number of routines to help you
62figure out how long it takes to execute some code.
63
8a4f6ac2 64timethis - run a chunk of code several times
65
66timethese - run several chunks of code several times
67
68cmpthese - print results of timethese as a comparison chart
69
70timeit - run a chunk of code and see how long it goes
71
72countit - see how many times a chunk of code runs in a given time
73
74
f06db76b 75=head2 Methods
76
77=over 10
78
79=item new
80
81Returns the current time. Example:
82
83 use Benchmark;
2b393bf4 84 $t0 = Benchmark->new;
f06db76b 85 # ... your code here ...
2b393bf4 86 $t1 = Benchmark->new;
f06db76b 87 $td = timediff($t1, $t0);
a24a9dfe 88 print "the code took:",timestr($td),"\n";
f06db76b 89
90=item debug
91
92Enables or disable debugging by setting the C<$Benchmark::Debug> flag:
93
2b393bf4 94 Benchmark->debug(1);
f06db76b 95 $t = timeit(10, ' 5 ** $Global ');
2b393bf4 96 Benchmark->debug(0);
f06db76b 97
431d98c2 98=item iters
99
100Returns the number of iterations.
101
f06db76b 102=back
103
104=head2 Standard Exports
105
523cc92b 106The following routines will be exported into your namespace
f06db76b 107if you use the Benchmark module:
108
109=over 10
110
111=item timeit(COUNT, CODE)
112
523cc92b 113Arguments: COUNT is the number of times to run the loop, and CODE is
114the code to run. CODE may be either a code reference or a string to
115be eval'd; either way it will be run in the caller's package.
116
117Returns: a Benchmark object.
118
119=item timethis ( COUNT, CODE, [ TITLE, [ STYLE ]] )
120
121Time COUNT iterations of CODE. CODE may be a string to eval or a
122code reference; either way the CODE will run in the caller's package.
123Results will be printed to STDOUT as TITLE followed by the times.
124TITLE defaults to "timethis COUNT" if none is provided. STYLE
125determines the format of the output, as described for timestr() below.
126
6ee623d5 127The COUNT can be zero or negative: this means the I<minimum number of
128CPU seconds> to run. A zero signifies the default of 3 seconds. For
129example to run at least for 10 seconds:
130
131 timethis(-10, $code)
132
133or to run two pieces of code tests for at least 3 seconds:
134
135 timethese(0, { test1 => '...', test2 => '...'})
136
137CPU seconds is, in UNIX terms, the user time plus the system time of
138the process itself, as opposed to the real (wallclock) time and the
139time spent by the child processes. Less than 0.1 seconds is not
140accepted (-0.01 as the count, for example, will cause a fatal runtime
141exception).
142
143Note that the CPU seconds is the B<minimum> time: CPU scheduling and
144other operating system factors may complicate the attempt so that a
145little bit more time is spent. The benchmark output will, however,
146also tell the number of C<$code> runs/second, which should be a more
147interesting number than the actually spent seconds.
148
149Returns a Benchmark object.
150
523cc92b 151=item timethese ( COUNT, CODEHASHREF, [ STYLE ] )
f06db76b 152
523cc92b 153The CODEHASHREF is a reference to a hash containing names as keys
154and either a string to eval or a code reference for each value.
155For each (KEY, VALUE) pair in the CODEHASHREF, this routine will
156call
f06db76b 157
523cc92b 158 timethis(COUNT, VALUE, KEY, STYLE)
f06db76b 159
1d2dff63 160The routines are called in string comparison order of KEY.
161
162The COUNT can be zero or negative, see timethis().
6ee623d5 163
72372890 164Returns a hash reference of Benchmark objects, keyed by name.
3c6312e9 165
523cc92b 166=item timediff ( T1, T2 )
f06db76b 167
523cc92b 168Returns the difference between two Benchmark times as a Benchmark
169object suitable for passing to timestr().
f06db76b 170
6ee623d5 171=item timestr ( TIMEDIFF, [ STYLE, [ FORMAT ] ] )
f06db76b 172
523cc92b 173Returns a string that formats the times in the TIMEDIFF object in
174the requested STYLE. TIMEDIFF is expected to be a Benchmark object
175similar to that returned by timediff().
176
3c6312e9 177STYLE can be any of 'all', 'none', 'noc', 'nop' or 'auto'. 'all' shows
178each of the 5 times available ('wallclock' time, user time, system time,
523cc92b 179user time of children, and system time of children). 'noc' shows all
180except the two children times. 'nop' shows only wallclock and the
181two children times. 'auto' (the default) will act as 'all' unless
182the children times are both zero, in which case it acts as 'noc'.
3c6312e9 183'none' prevents output.
523cc92b 184
185FORMAT is the L<printf(3)>-style format specifier (without the
186leading '%') to use to print the times. It defaults to '5.2f'.
f06db76b 187
188=back
189
190=head2 Optional Exports
191
192The following routines will be exported into your namespace
193if you specifically ask that they be imported:
194
195=over 10
196
523cc92b 197=item clearcache ( COUNT )
198
199Clear the cached time for COUNT rounds of the null loop.
200
201=item clearallcache ( )
f06db76b 202
523cc92b 203Clear all cached times.
f06db76b 204
8962dfd6 205=item cmpthese ( COUNT, CODEHASHREF, [ STYLE ] )
ac8eabc1 206
d1083c7a 207=item cmpthese ( RESULTSHASHREF, [ STYLE ] )
ac8eabc1 208
d1083c7a 209Optionally calls timethese(), then outputs comparison chart. This:
ac8eabc1 210
d1083c7a 211 cmpthese( -1, { a => "++\$i", b => "\$i *= 2" } ) ;
212
213outputs a chart like:
214
215 Rate b a
216 b 2831802/s -- -61%
217 a 7208959/s 155% --
218
219This chart is sorted from slowest to fastest, and shows the percent speed
220difference between each pair of tests.
221
3b46207f 222C<cmpthese> can also be passed the data structure that timethese() returns:
d1083c7a 223
224 $results = timethese( -1, { a => "++\$i", b => "\$i *= 2" } ) ;
ac8eabc1 225 cmpthese( $results );
226
d1083c7a 227in case you want to see both sets of results.
72372890 228If the first argument is an unblessed hash reference,
229that is RESULTSHASHREF; otherwise that is COUNT.
d1083c7a 230
231Returns a reference to an ARRAY of rows, each row is an ARRAY of cells from the
232above chart, including labels. This:
233
234 my $rows = cmpthese( -1, { a => '++$i', b => '$i *= 2' }, "none" );
235
236returns a data structure like:
237
238 [
239 [ '', 'Rate', 'b', 'a' ],
240 [ 'b', '2885232/s', '--', '-59%' ],
241 [ 'a', '7099126/s', '146%', '--' ],
242 ]
243
244B<NOTE>: This result value differs from previous versions, which returned
245the C<timethese()> result structure. If you want that, just use the two
246statement C<timethese>...C<cmpthese> idiom shown above.
247
248Incidently, note the variance in the result values between the two examples;
249this is typical of benchmarking. If this were a real benchmark, you would
250probably want to run a lot more iterations.
ac8eabc1 251
252=item countit(TIME, CODE)
253
254Arguments: TIME is the minimum length of time to run CODE for, and CODE is
255the code to run. CODE may be either a code reference or a string to
256be eval'd; either way it will be run in the caller's package.
257
258TIME is I<not> negative. countit() will run the loop many times to
259calculate the speed of CODE before running it for TIME. The actual
260time run for will usually be greater than TIME due to system clock
261resolution, so it's best to look at the number of iterations divided
262by the times that you are concerned with, not just the iterations.
263
264Returns: a Benchmark object.
265
523cc92b 266=item disablecache ( )
f06db76b 267
523cc92b 268Disable caching of timings for the null loop. This will force Benchmark
269to recalculate these timings for each new piece of code timed.
270
271=item enablecache ( )
272
273Enable caching of timings for the null loop. The time taken for COUNT
274rounds of the null loop will be calculated only once for each
275different COUNT used.
f06db76b 276
ac8eabc1 277=item timesum ( T1, T2 )
278
279Returns the sum of two Benchmark times as a Benchmark object suitable
280for passing to timestr().
281
f06db76b 282=back
283
e3d6de9a 284=head2 :hireswallclock
285
286If the Time::HiRes module has been installed, you can specify the
287special tag C<:hireswallclock> for Benchmark (if Time::HiRes is not
288available, the tag will be silently ignored). This tag will cause the
289wallclock time to be measured in microseconds, instead of integer
702fa71c 290seconds. Note though that the speed computations are still conducted
291in CPU time, not wallclock time.
e3d6de9a 292
f06db76b 293=head1 NOTES
294
295The data is stored as a list of values from the time and times
523cc92b 296functions:
f06db76b 297
431d98c2 298 ($real, $user, $system, $children_user, $children_system, $iters)
f06db76b 299
300in seconds for the whole loop (not divided by the number of rounds).
301
302The timing is done using time(3) and times(3).
303
304Code is executed in the caller's package.
305
f06db76b 306The time of the null loop (a loop with the same
307number of rounds but empty loop body) is subtracted
308from the time of the real loop.
309
3c6312e9 310The null loop times can be cached, the key being the
f06db76b 311number of rounds. The caching can be controlled using
312calls like these:
313
523cc92b 314 clearcache($key);
f06db76b 315 clearallcache();
316
523cc92b 317 disablecache();
f06db76b 318 enablecache();
319
3c6312e9 320Caching is off by default, as it can (usually slightly) decrease
321accuracy and does not usually noticably affect runtimes.
322
54e82ce5 323=head1 EXAMPLES
324
325For example,
326
14393033 327 use Benchmark qw( cmpthese ) ;
328 $x = 3;
329 cmpthese( -5, {
330 a => sub{$x*$x},
331 b => sub{$x**2},
332 } );
54e82ce5 333
334outputs something like this:
335
336 Benchmark: running a, b, each for at least 5 CPU seconds...
14393033 337 Rate b a
338 b 1559428/s -- -62%
339 a 4152037/s 166% --
340
54e82ce5 341
342while
343
14393033 344 use Benchmark qw( timethese cmpthese ) ;
345 $x = 3;
346 $r = timethese( -5, {
347 a => sub{$x*$x},
348 b => sub{$x**2},
349 } );
350 cmpthese $r;
54e82ce5 351
352outputs something like this:
353
14393033 354 Benchmark: running a, b, each for at least 5 CPU seconds...
355 a: 10 wallclock secs ( 5.14 usr + 0.13 sys = 5.27 CPU) @ 3835055.60/s (n=20210743)
356 b: 5 wallclock secs ( 5.41 usr + 0.00 sys = 5.41 CPU) @ 1574944.92/s (n=8520452)
357 Rate b a
358 b 1574945/s -- -59%
359 a 3835056/s 144% --
54e82ce5 360
361
f06db76b 362=head1 INHERITANCE
363
364Benchmark inherits from no other class, except of course
365for Exporter.
366
367=head1 CAVEATS
368
80eab818 369Comparing eval'd strings with code references will give you
431d98c2 370inaccurate results: a code reference will show a slightly slower
80eab818 371execution time than the equivalent eval'd string.
372
f06db76b 373The real time timing is done using time(2) and
374the granularity is therefore only one second.
375
376Short tests may produce negative figures because perl
523cc92b 377can appear to take longer to execute the empty loop
378than a short test; try:
f06db76b 379
380 timethis(100,'1');
381
382The system time of the null loop might be slightly
383more than the system time of the loop with the actual
a24a9dfe 384code and therefore the difference might end up being E<lt> 0.
f06db76b 385
8a4f6ac2 386=head1 SEE ALSO
387
388L<Devel::DProf> - a Perl code profiler
389
f06db76b 390=head1 AUTHORS
391
5aabfad6 392Jarkko Hietaniemi <F<jhi@iki.fi>>, Tim Bunce <F<Tim.Bunce@ig.co.uk>>
f06db76b 393
394=head1 MODIFICATION HISTORY
395
396September 8th, 1994; by Tim Bunce.
397
523cc92b 398March 28th, 1997; by Hugo van der Sanden: added support for code
399references and the already documented 'debug' method; revamped
400documentation.
f06db76b 401
6ee623d5 402April 04-07th, 1997: by Jarkko Hietaniemi, added the run-for-some-time
403functionality.
404
3c6312e9 405September, 1999; by Barrie Slaymaker: math fixes and accuracy and
406efficiency tweaks. Added cmpthese(). A result is now returned from
431d98c2 407timethese(). Exposed countit() (was runfor()).
3c6312e9 408
0e74ff8e 409December, 2001; by Nicholas Clark: make timestr() recognise the style 'none'
410and return an empty string. If cmpthese is calling timethese, make it pass the
411style in. (so that 'none' will suppress output). Make sub new dump its
412debugging output to STDERR, to be consistent with everything else.
413All bugs found while writing a regression test.
414
e3d6de9a 415September, 2002; by Jarkko Hietaniemi: add ':hireswallclock' special tag.
416
33e4b5a9 417February, 2004; by Chia-liang Kao: make cmpthese and timestr use time
418statistics for children instead of parent when the style is 'nop'.
419
ebfe4dae 420November, 2007; by Christophe Grosjean: make cmpthese and timestr compute
421time consistently with style argument, default is 'all' not 'noc' any more.
422
523cc92b 423=cut
a0d0e21e 424
3f943bd9 425# evaluate something in a clean lexical environment
53aa2791 426sub _doeval { no strict; eval shift }
3f943bd9 427
428#
429# put any lexicals at file scope AFTER here
430#
431
4aa0a1f7 432use Carp;
a0d0e21e 433use Exporter;
53aa2791 434
435our(@ISA, @EXPORT, @EXPORT_OK, %EXPORT_TAGS, $VERSION);
436
437@ISA=qw(Exporter);
ac8eabc1 438@EXPORT=qw(timeit timethis timethese timediff timestr);
439@EXPORT_OK=qw(timesum cmpthese countit
440 clearcache clearallcache disablecache enablecache);
f36484b0 441%EXPORT_TAGS=( all => [ @EXPORT, @EXPORT_OK ] ) ;
a0d0e21e 442
af048c18 443$VERSION = 1.11;
e3d6de9a 444
445# --- ':hireswallclock' special handling
446
447my $hirestime;
448
449sub mytime () { time }
8a4f6ac2 450
359218de 451init();
a0d0e21e 452
e3d6de9a 453sub BEGIN {
454 if (eval 'require Time::HiRes') {
455 import Time::HiRes qw(time);
456 $hirestime = \&Time::HiRes::time;
457 }
458}
459
460sub import {
461 my $class = shift;
462 if (grep { $_ eq ":hireswallclock" } @_) {
463 @_ = grep { $_ ne ":hireswallclock" } @_;
92dfaf87 464 local $^W=0;
e3d6de9a 465 *mytime = $hirestime if defined $hirestime;
466 }
467 Benchmark->export_to_level(1, $class, @_);
468}
469
53aa2791 470our($Debug, $Min_Count, $Min_CPU, $Default_Format, $Default_Style,
471 %_Usage, %Cache, $Do_Cache);
472
a0d0e21e 473sub init {
53aa2791 474 $Debug = 0;
475 $Min_Count = 4;
476 $Min_CPU = 0.4;
477 $Default_Format = '5.2f';
478 $Default_Style = 'auto';
a0d0e21e 479 # The cache can cause a slight loss of sys time accuracy. If a
480 # user does many tests (>10) with *very* large counts (>10000)
481 # or works on a very slow machine the cache may be useful.
359218de 482 disablecache();
483 clearallcache();
a0d0e21e 484}
485
53aa2791 486sub debug { $Debug = ($_[1] != 0); }
487
488sub usage {
489 my $calling_sub = (caller(1))[3];
490 $calling_sub =~ s/^Benchmark:://;
491 return $_Usage{$calling_sub} || '';
492}
493
bba8fca5 494# The cache needs two branches: 's' for strings and 'c' for code. The
359218de 495# empty loop is different in these two cases.
53aa2791 496
f695f0e6 497$_Usage{clearcache} = <<'USAGE';
498usage: clearcache($count);
499USAGE
500
501sub clearcache {
502 die usage unless @_ == 1;
53aa2791 503 delete $Cache{"$_[0]c"}; delete $Cache{"$_[0]s"};
504}
505
f695f0e6 506$_Usage{clearallcache} = <<'USAGE';
507usage: clearallcache();
508USAGE
509
510sub clearallcache {
511 die usage if @_;
53aa2791 512 %Cache = ();
513}
514
f695f0e6 515$_Usage{enablecache} = <<'USAGE';
516usage: enablecache();
517USAGE
518
519sub enablecache {
520 die usage if @_;
53aa2791 521 $Do_Cache = 1;
522}
523
f695f0e6 524$_Usage{disablecache} = <<'USAGE';
525usage: disablecache();
526USAGE
527
528sub disablecache {
529 die usage if @_;
53aa2791 530 $Do_Cache = 0;
531}
532
a0d0e21e 533
a0d0e21e 534# --- Functions to process the 'time' data type
535
e3d6de9a 536sub new { my @t = (mytime, times, @_ == 2 ? $_[1] : 0);
53aa2791 537 print STDERR "new=@t\n" if $Debug;
6ee623d5 538 bless \@t; }
a0d0e21e 539
540sub cpu_p { my($r,$pu,$ps,$cu,$cs) = @{$_[0]}; $pu+$ps ; }
541sub cpu_c { my($r,$pu,$ps,$cu,$cs) = @{$_[0]}; $cu+$cs ; }
542sub cpu_a { my($r,$pu,$ps,$cu,$cs) = @{$_[0]}; $pu+$ps+$cu+$cs ; }
543sub real { my($r,$pu,$ps,$cu,$cs) = @{$_[0]}; $r ; }
431d98c2 544sub iters { $_[0]->[5] ; }
a0d0e21e 545
53aa2791 546
547$_Usage{timediff} = <<'USAGE';
548usage: $result_diff = timediff($result1, $result2);
549USAGE
550
523cc92b 551sub timediff {
a0d0e21e 552 my($a, $b) = @_;
53aa2791 553
554 die usage unless ref $a and ref $b;
555
523cc92b 556 my @r;
3f943bd9 557 for (my $i=0; $i < @$a; ++$i) {
a0d0e21e 558 push(@r, $a->[$i] - $b->[$i]);
559 }
e68ec53f 560 #die "Bad timediff(): ($r[1] + $r[2]) <= 0 (@$a[1,2]|@$b[1,2])\n"
561 # if ($r[1] + $r[2]) < 0;
a0d0e21e 562 bless \@r;
563}
564
53aa2791 565$_Usage{timesum} = <<'USAGE';
566usage: $sum = timesum($result1, $result2);
567USAGE
568
705cc255 569sub timesum {
53aa2791 570 my($a, $b) = @_;
571
572 die usage unless ref $a and ref $b;
573
574 my @r;
575 for (my $i=0; $i < @$a; ++$i) {
705cc255 576 push(@r, $a->[$i] + $b->[$i]);
53aa2791 577 }
578 bless \@r;
705cc255 579}
580
53aa2791 581
582$_Usage{timestr} = <<'USAGE';
583usage: $formatted_result = timestr($result1);
584USAGE
585
523cc92b 586sub timestr {
a0d0e21e 587 my($tr, $style, $f) = @_;
53aa2791 588
589 die usage unless ref $tr;
590
523cc92b 591 my @t = @$tr;
6ee623d5 592 warn "bad time value (@t)" unless @t==6;
593 my($r, $pu, $ps, $cu, $cs, $n) = @t;
ce9550df 594 my($pt, $ct, $tt) = ($tr->cpu_p, $tr->cpu_c, $tr->cpu_a);
53aa2791 595 $f = $Default_Format unless defined $f;
a0d0e21e 596 # format a time in the required style, other formats may be added here
53aa2791 597 $style ||= $Default_Style;
0e74ff8e 598 return '' if $style eq 'none';
523cc92b 599 $style = ($ct>0) ? 'all' : 'noc' if $style eq 'auto';
600 my $s = "@t $style"; # default for unknown style
e3d6de9a 601 my $w = $hirestime ? "%2g" : "%2d";
ebfe4dae 602 $s = sprintf("$w wallclock secs (%$f usr %$f sys + %$f cusr %$f csys = %$f CPU)",
ce9550df 603 $r,$pu,$ps,$cu,$cs,$tt) if $style eq 'all';
ebfe4dae 604 $s = sprintf("$w wallclock secs (%$f usr + %$f sys = %$f CPU)",
7be077a2 605 $r,$pu,$ps,$pt) if $style eq 'noc';
ebfe4dae 606 $s = sprintf("$w wallclock secs (%$f cusr + %$f csys = %$f CPU)",
7be077a2 607 $r,$cu,$cs,$ct) if $style eq 'nop';
ebfe4dae 608 my $elapsed = do {
609 if ($style eq 'nop') {$cu+$cs}
610 elsif ($style eq 'noc') {$pu+$ps}
611 else {$cu+$cs+$pu+$ps}
612 };
613 $s .= sprintf(" @ %$f/s (n=$n)",$n/($elapsed)) if $n && $elapsed;
a0d0e21e 614 $s;
615}
523cc92b 616
617sub timedebug {
a0d0e21e 618 my($msg, $t) = @_;
53aa2791 619 print STDERR "$msg",timestr($t),"\n" if $Debug;
a0d0e21e 620}
621
a0d0e21e 622# --- Functions implementing low-level support for timing loops
623
53aa2791 624$_Usage{runloop} = <<'USAGE';
625usage: runloop($number, [$string | $coderef])
626USAGE
627
a0d0e21e 628sub runloop {
629 my($n, $c) = @_;
4aa0a1f7 630
631 $n+=0; # force numeric now, so garbage won't creep into the eval
523cc92b 632 croak "negative loopcount $n" if $n<0;
53aa2791 633 confess usage unless defined $c;
a0d0e21e 634 my($t0, $t1, $td); # before, after, difference
635
636 # find package of caller so we can execute code there
523cc92b 637 my($curpack) = caller(0);
638 my($i, $pack)= 0;
a0d0e21e 639 while (($pack) = caller(++$i)) {
640 last if $pack ne $curpack;
641 }
642
3f943bd9 643 my ($subcode, $subref);
644 if (ref $c eq 'CODE') {
645 $subcode = "sub { for (1 .. $n) { local \$_; package $pack; &\$c; } }";
646 $subref = eval $subcode;
647 }
648 else {
649 $subcode = "sub { for (1 .. $n) { local \$_; package $pack; $c;} }";
650 $subref = _doeval($subcode);
651 }
4aa0a1f7 652 croak "runloop unable to compile '$c': $@\ncode: $subcode\n" if $@;
53aa2791 653 print STDERR "runloop $n '$subcode'\n" if $Debug;
a0d0e21e 654
3c6312e9 655 # Wait for the user timer to tick. This makes the error range more like
656 # -0.01, +0. If we don't wait, then it's more like -0.01, +0.01. This
657 # may not seem important, but it significantly reduces the chances of
658 # getting a too low initial $n in the initial, 'find the minimum' loop
431d98c2 659 # in &countit. This, in turn, can reduce the number of calls to
bba8fca5 660 # &runloop a lot, and thus reduce additive errors.
661 my $tbase = Benchmark->new(0)->[1];
277427cf 662 while ( ( $t0 = Benchmark->new(0) )->[1] == $tbase ) {} ;
f265d4df 663 $subref->();
6ee623d5 664 $t1 = Benchmark->new($n);
a0d0e21e 665 $td = &timediff($t1, $t0);
a0d0e21e 666 timedebug("runloop:",$td);
667 $td;
668}
669
53aa2791 670$_Usage{timeit} = <<'USAGE';
671usage: $result = timeit($count, 'code' ); or
672 $result = timeit($count, sub { code } );
673USAGE
a0d0e21e 674
675sub timeit {
676 my($n, $code) = @_;
677 my($wn, $wc, $wd);
678
53aa2791 679 die usage unless defined $code and
680 (!ref $code or ref $code eq 'CODE');
681
682 printf STDERR "timeit $n $code\n" if $Debug;
3c6312e9 683 my $cache_key = $n . ( ref( $code ) ? 'c' : 's' );
53aa2791 684 if ($Do_Cache && exists $Cache{$cache_key} ) {
685 $wn = $Cache{$cache_key};
523cc92b 686 } else {
6bf773bc 687 $wn = &runloop($n, ref( $code ) ? sub { } : '' );
3c6312e9 688 # Can't let our baseline have any iterations, or they get subtracted
689 # out of the result.
690 $wn->[5] = 0;
53aa2791 691 $Cache{$cache_key} = $wn;
a0d0e21e 692 }
693
694 $wc = &runloop($n, $code);
695
696 $wd = timediff($wc, $wn);
a0d0e21e 697 timedebug("timeit: ",$wc);
698 timedebug(" - ",$wn);
699 timedebug(" = ",$wd);
700
701 $wd;
702}
703
6ee623d5 704
705my $default_for = 3;
706my $min_for = 0.1;
707
3c6312e9 708
53aa2791 709$_Usage{countit} = <<'USAGE';
710usage: $result = countit($time, 'code' ); or
711 $result = countit($time, sub { code } );
712USAGE
713
431d98c2 714sub countit {
715 my ( $tmax, $code ) = @_;
6ee623d5 716
53aa2791 717 die usage unless @_;
718
6ee623d5 719 if ( not defined $tmax or $tmax == 0 ) {
720 $tmax = $default_for;
721 } elsif ( $tmax < 0 ) {
722 $tmax = -$tmax;
723 }
724
431d98c2 725 die "countit($tmax, ...): timelimit cannot be less than $min_for.\n"
6ee623d5 726 if $tmax < $min_for;
727
3c6312e9 728 my ($n, $tc);
6ee623d5 729
bba8fca5 730 # First find the minimum $n that gives a significant timing.
e68ec53f 731 my $zeros=0;
3c6312e9 732 for ($n = 1; ; $n *= 2 ) {
733 my $td = timeit($n, $code);
734 $tc = $td->[1] + $td->[2];
e68ec53f 735 if ( $tc <= 0 and $n > 1024 ) {
736 ++$zeros > 16
737 and die "Timing is consistently zero in estimation loop, cannot benchmark. N=$n\n";
738 } else {
739 $zeros = 0;
740 }
3c6312e9 741 last if $tc > 0.1;
742 }
6ee623d5 743
3c6312e9 744 my $nmin = $n;
745
746 # Get $n high enough that we can guess the final $n with some accuracy.
747 my $tpra = 0.1 * $tmax; # Target/time practice.
748 while ( $tc < $tpra ) {
749 # The 5% fudge is to keep us from iterating again all
750 # that often (this speeds overall responsiveness when $tmax is big
751 # and we guess a little low). This does not noticably affect
752 # accuracy since we're not couting these times.
753 $n = int( $tpra * 1.05 * $n / $tc ); # Linear approximation.
754 my $td = timeit($n, $code);
c5d57293 755 my $new_tc = $td->[1] + $td->[2];
756 # Make sure we are making progress.
757 $tc = $new_tc > 1.2 * $tc ? $new_tc : 1.2 * $tc;
6ee623d5 758 }
759
3c6312e9 760 # Now, do the 'for real' timing(s), repeating until we exceed
761 # the max.
762 my $ntot = 0;
763 my $rtot = 0;
764 my $utot = 0.0;
765 my $stot = 0.0;
766 my $cutot = 0.0;
767 my $cstot = 0.0;
768 my $ttot = 0.0;
769
770 # The 5% fudge is because $n is often a few % low even for routines
771 # with stable times and avoiding extra timeit()s is nice for
772 # accuracy's sake.
773 $n = int( $n * ( 1.05 * $tmax / $tc ) );
e68ec53f 774 $zeros=0;
3c6312e9 775 while () {
776 my $td = timeit($n, $code);
777 $ntot += $n;
778 $rtot += $td->[0];
779 $utot += $td->[1];
780 $stot += $td->[2];
6ee623d5 781 $cutot += $td->[3];
782 $cstot += $td->[4];
3c6312e9 783 $ttot = $utot + $stot;
784 last if $ttot >= $tmax;
e68ec53f 785 if ( $ttot <= 0 ) {
786 ++$zeros > 16
787 and die "Timing is consistently zero, cannot benchmark. N=$n\n";
788 } else {
789 $zeros = 0;
790 }
c5d57293 791 $ttot = 0.01 if $ttot < 0.01;
3c6312e9 792 my $r = $tmax / $ttot - 1; # Linear approximation.
bba8fca5 793 $n = int( $r * $ntot );
6ee623d5 794 $n = $nmin if $n < $nmin;
6ee623d5 795 }
796
797 return bless [ $rtot, $utot, $stot, $cutot, $cstot, $ntot ];
798}
799
a0d0e21e 800# --- Functions implementing high-level time-then-print utilities
801
6ee623d5 802sub n_to_for {
803 my $n = shift;
804 return $n == 0 ? $default_for : $n < 0 ? -$n : undef;
805}
806
53aa2791 807$_Usage{timethis} = <<'USAGE';
808usage: $result = timethis($time, 'code' ); or
809 $result = timethis($time, sub { code } );
810USAGE
811
a0d0e21e 812sub timethis{
813 my($n, $code, $title, $style) = @_;
53aa2791 814 my($t, $forn);
815
816 die usage unless defined $code and
817 (!ref $code or ref $code eq 'CODE');
6ee623d5 818
819 if ( $n > 0 ) {
820 croak "non-integer loopcount $n, stopped" if int($n)<$n;
821 $t = timeit($n, $code);
822 $title = "timethis $n" unless defined $title;
823 } else {
53aa2791 824 my $fort = n_to_for( $n );
431d98c2 825 $t = countit( $fort, $code );
6ee623d5 826 $title = "timethis for $fort" unless defined $title;
827 $forn = $t->[-1];
828 }
523cc92b 829 local $| = 1;
523cc92b 830 $style = "" unless defined $style;
3c6312e9 831 printf("%10s: ", $title) unless $style eq 'none';
53aa2791 832 print timestr($t, $style, $Default_Format),"\n" unless $style eq 'none';
6ee623d5 833
834 $n = $forn if defined $forn;
523cc92b 835
a0d0e21e 836 # A conservative warning to spot very silly tests.
837 # Don't assume that your benchmark is ok simply because
838 # you don't get this warning!
839 print " (warning: too few iterations for a reliable count)\n"
53aa2791 840 if $n < $Min_Count
a0d0e21e 841 || ($t->real < 1 && $n < 1000)
53aa2791 842 || $t->cpu_a < $Min_CPU;
a0d0e21e 843 $t;
844}
845
53aa2791 846
847$_Usage{timethese} = <<'USAGE';
848usage: timethese($count, { Name1 => 'code1', ... }); or
849 timethese($count, { Name1 => sub { code1 }, ... });
850USAGE
851
a0d0e21e 852sub timethese{
853 my($n, $alt, $style) = @_;
53aa2791 854 die usage unless ref $alt eq 'HASH';
855
523cc92b 856 my @names = sort keys %$alt;
857 $style = "" unless defined $style;
3c6312e9 858 print "Benchmark: " unless $style eq 'none';
6ee623d5 859 if ( $n > 0 ) {
860 croak "non-integer loopcount $n, stopped" if int($n)<$n;
3c6312e9 861 print "timing $n iterations of" unless $style eq 'none';
6ee623d5 862 } else {
3c6312e9 863 print "running" unless $style eq 'none';
6ee623d5 864 }
3c6312e9 865 print " ", join(', ',@names) unless $style eq 'none';
6ee623d5 866 unless ( $n > 0 ) {
867 my $for = n_to_for( $n );
df7779cf 868 print ", each" if $n > 1 && $style ne 'none';
869 print " for at least $for CPU seconds" unless $style eq 'none';
6ee623d5 870 }
3c6312e9 871 print "...\n" unless $style eq 'none';
523cc92b 872
873 # we could save the results in an array and produce a summary here
a0d0e21e 874 # sum, min, max, avg etc etc
3c6312e9 875 my %results;
4dbb2df9 876 foreach my $name (@names) {
3c6312e9 877 $results{$name} = timethis ($n, $alt -> {$name}, $name, $style);
4dbb2df9 878 }
3c6312e9 879
880 return \%results;
a0d0e21e 881}
882
53aa2791 883
884$_Usage{cmpthese} = <<'USAGE';
885usage: cmpthese($count, { Name1 => 'code1', ... }); or
886 cmpthese($count, { Name1 => sub { code1 }, ... }); or
887 cmpthese($result, $style);
888USAGE
889
3c6312e9 890sub cmpthese{
53aa2791 891 my ($results, $style);
892
72372890 893 # $count can be a blessed object.
894 if ( ref $_[0] eq 'HASH' ) {
53aa2791 895 ($results, $style) = @_;
896 }
897 else {
898 my($count, $code) = @_[0,1];
899 $style = $_[2] if defined $_[2];
900
901 die usage unless ref $code eq 'HASH';
902
903 $results = timethese($count, $code, ($style || "none"));
904 }
3c6312e9 905
d1083c7a 906 $style = "" unless defined $style;
3c6312e9 907
908 # Flatten in to an array of arrays with the name as the first field
909 my @vals = map{ [ $_, @{$results->{$_}} ] } keys %$results;
910
911 for (@vals) {
912 # The epsilon fudge here is to prevent div by 0. Since clock
913 # resolutions are much larger, it's below the noise floor.
ebfe4dae 914 my $elapsed = do {
915 if ($style eq 'nop') {$_->[4]+$_->[5]}
916 elsif ($style eq 'noc') {$_->[2]+$_->[3]}
917 else {$_->[2]+$_->[3]+$_->[4]+$_->[5]}
918 };
919 my $rate = $_->[6]/(($elapsed)+0.000000000000001);
3c6312e9 920 $_->[7] = $rate;
921 }
922
923 # Sort by rate
924 @vals = sort { $a->[7] <=> $b->[7] } @vals;
925
926 # If more than half of the rates are greater than one...
d598cef2 927 my $display_as_rate = @vals ? ($vals[$#vals>>1]->[7] > 1) : 0;
3c6312e9 928
929 my @rows;
930 my @col_widths;
931
932 my @top_row = (
933 '',
934 $display_as_rate ? 'Rate' : 's/iter',
935 map { $_->[0] } @vals
936 );
937
938 push @rows, \@top_row;
939 @col_widths = map { length( $_ ) } @top_row;
940
941 # Build the data rows
942 # We leave the last column in even though it never has any data. Perhaps
943 # it should go away. Also, perhaps a style for a single column of
944 # percentages might be nice.
945 for my $row_val ( @vals ) {
946 my @row;
947
948 # Column 0 = test name
949 push @row, $row_val->[0];
950 $col_widths[0] = length( $row_val->[0] )
951 if length( $row_val->[0] ) > $col_widths[0];
952
953 # Column 1 = performance
954 my $row_rate = $row_val->[7];
955
956 # We assume that we'll never get a 0 rate.
53aa2791 957 my $rate = $display_as_rate ? $row_rate : 1 / $row_rate;
3c6312e9 958
959 # Only give a few decimal places before switching to sci. notation,
960 # since the results aren't usually that accurate anyway.
961 my $format =
53aa2791 962 $rate >= 100 ?
3c6312e9 963 "%0.0f" :
53aa2791 964 $rate >= 10 ?
3c6312e9 965 "%0.1f" :
53aa2791 966 $rate >= 1 ?
3c6312e9 967 "%0.2f" :
53aa2791 968 $rate >= 0.1 ?
3c6312e9 969 "%0.3f" :
970 "%0.2e";
971
972 $format .= "/s"
973 if $display_as_rate;
53aa2791 974
975 my $formatted_rate = sprintf( $format, $rate );
976 push @row, $formatted_rate;
977 $col_widths[1] = length( $formatted_rate )
978 if length( $formatted_rate ) > $col_widths[1];
3c6312e9 979
980 # Columns 2..N = performance ratios
981 my $skip_rest = 0;
982 for ( my $col_num = 0 ; $col_num < @vals ; ++$col_num ) {
983 my $col_val = $vals[$col_num];
984 my $out;
985 if ( $skip_rest ) {
986 $out = '';
987 }
988 elsif ( $col_val->[0] eq $row_val->[0] ) {
989 $out = "--";
990 # $skip_rest = 1;
991 }
992 else {
993 my $col_rate = $col_val->[7];
994 $out = sprintf( "%.0f%%", 100*$row_rate/$col_rate - 100 );
995 }
996 push @row, $out;
997 $col_widths[$col_num+2] = length( $out )
998 if length( $out ) > $col_widths[$col_num+2];
999
1000 # A little wierdness to set the first column width properly
1001 $col_widths[$col_num+2] = length( $col_val->[0] )
1002 if length( $col_val->[0] ) > $col_widths[$col_num+2];
1003 }
1004 push @rows, \@row;
1005 }
1006
d1083c7a 1007 return \@rows if $style eq "none";
1008
3c6312e9 1009 # Equalize column widths in the chart as much as possible without
1010 # exceeding 80 characters. This does not use or affect cols 0 or 1.
1011 my @sorted_width_refs =
1012 sort { $$a <=> $$b } map { \$_ } @col_widths[2..$#col_widths];
1013 my $max_width = ${$sorted_width_refs[-1]};
1014
277427cf 1015 my $total = @col_widths - 1 ;
3c6312e9 1016 for ( @col_widths ) { $total += $_ }
1017
1018 STRETCHER:
1019 while ( $total < 80 ) {
1020 my $min_width = ${$sorted_width_refs[0]};
1021 last
1022 if $min_width == $max_width;
1023 for ( @sorted_width_refs ) {
1024 last
1025 if $$_ > $min_width;
1026 ++$$_;
1027 ++$total;
1028 last STRETCHER
1029 if $total >= 80;
1030 }
1031 }
1032
1033 # Dump the output
1034 my $format = join( ' ', map { "%${_}s" } @col_widths ) . "\n";
1035 substr( $format, 1, 0 ) = '-';
1036 for ( @rows ) {
1037 printf $format, @$_;
1038 }
1039
d1083c7a 1040 return \@rows ;
3c6312e9 1041}
1042
1043
a0d0e21e 10441;