5 Benchmark - benchmark running times of code
7 timethis - run a chunk of code several times
9 timethese - run several chunks of code several times
11 timeit - run a chunk of code and see how long it goes
15 timethis ($count, "code");
17 # Use Perl code in strings...
19 'Name1' => '...code1...',
20 'Name2' => '...code2...',
23 # ... or use subroutine references.
25 'Name1' => sub { ...code1... },
26 'Name2' => sub { ...code2... },
29 $t = timeit($count, '...other code...')
30 print "$count loops of other code took:",timestr($t),"\n";
34 The Benchmark module encapsulates a number of routines to help you
35 figure out how long it takes to execute some code.
43 Returns the current time. Example:
47 # ... your code here ...
49 $td = timediff($t1, $t0);
50 print "the code took:",timestr($td),"\n";
54 Enables or disable debugging by setting the C<$Benchmark::Debug> flag:
57 $t = timeit(10, ' 5 ** $Global ');
62 =head2 Standard Exports
64 The following routines will be exported into your namespace
65 if you use the Benchmark module:
69 =item timeit(COUNT, CODE)
71 Arguments: COUNT is the number of times to run the loop, and CODE is
72 the code to run. CODE may be either a code reference or a string to
73 be eval'd; either way it will be run in the caller's package.
75 Returns: a Benchmark object.
77 =item timethis ( COUNT, CODE, [ TITLE, [ STYLE ]] )
79 Time COUNT iterations of CODE. CODE may be a string to eval or a
80 code reference; either way the CODE will run in the caller's package.
81 Results will be printed to STDOUT as TITLE followed by the times.
82 TITLE defaults to "timethis COUNT" if none is provided. STYLE
83 determines the format of the output, as described for timestr() below.
85 The COUNT can be zero or negative: this means the I<minimum number of
86 CPU seconds> to run. A zero signifies the default of 3 seconds. For
87 example to run at least for 10 seconds:
91 or to run two pieces of code tests for at least 3 seconds:
93 timethese(0, { test1 => '...', test2 => '...'})
95 CPU seconds is, in UNIX terms, the user time plus the system time of
96 the process itself, as opposed to the real (wallclock) time and the
97 time spent by the child processes. Less than 0.1 seconds is not
98 accepted (-0.01 as the count, for example, will cause a fatal runtime
101 Note that the CPU seconds is the B<minimum> time: CPU scheduling and
102 other operating system factors may complicate the attempt so that a
103 little bit more time is spent. The benchmark output will, however,
104 also tell the number of C<$code> runs/second, which should be a more
105 interesting number than the actually spent seconds.
107 Returns a Benchmark object.
109 =item timethese ( COUNT, CODEHASHREF, [ STYLE ] )
111 The CODEHASHREF is a reference to a hash containing names as keys
112 and either a string to eval or a code reference for each value.
113 For each (KEY, VALUE) pair in the CODEHASHREF, this routine will
116 timethis(COUNT, VALUE, KEY, STYLE)
118 The routines are called in string comparison order of KEY.
120 The COUNT can be zero or negative, see timethis().
122 Returns a hash of Benchmark objects, keyed by name.
124 =item timediff ( T1, T2 )
126 Returns the difference between two Benchmark times as a Benchmark
127 object suitable for passing to timestr().
129 =item timesum ( T1, T2 )
131 Returns the sum of two Benchmark times as a Benchmark object suitable
132 for passing to timestr().
134 =item timestr ( TIMEDIFF, [ STYLE, [ FORMAT ] ] )
136 Returns a string that formats the times in the TIMEDIFF object in
137 the requested STYLE. TIMEDIFF is expected to be a Benchmark object
138 similar to that returned by timediff().
140 STYLE can be any of 'all', 'none', 'noc', 'nop' or 'auto'. 'all' shows
141 each of the 5 times available ('wallclock' time, user time, system time,
142 user time of children, and system time of children). 'noc' shows all
143 except the two children times. 'nop' shows only wallclock and the
144 two children times. 'auto' (the default) will act as 'all' unless
145 the children times are both zero, in which case it acts as 'noc'.
146 'none' prevents output.
148 FORMAT is the L<printf(3)>-style format specifier (without the
149 leading '%') to use to print the times. It defaults to '5.2f'.
153 =head2 Optional Exports
155 The following routines will be exported into your namespace
156 if you specifically ask that they be imported:
160 =item clearcache ( COUNT )
162 Clear the cached time for COUNT rounds of the null loop.
164 =item clearallcache ( )
166 Clear all cached times.
168 =item cmpthese ( COUT, CODEHASHREF, [ STYLE ] )
170 =item cmpthese ( RESULTSHASHREF )
172 Optionally calls timethese(), then outputs comparison chart. This
173 chart is sorted from slowest to highest, and shows the percent
174 speed difference between each pair of tests. Can also be passed
175 the data structure that timethese() returns:
177 $results = timethese( .... );
178 cmpthese( $results );
180 Returns the data structure returned by timethese().
182 =item disablecache ( )
184 Disable caching of timings for the null loop. This will force Benchmark
185 to recalculate these timings for each new piece of code timed.
187 =item enablecache ( )
189 Enable caching of timings for the null loop. The time taken for COUNT
190 rounds of the null loop will be calculated only once for each
191 different COUNT used.
197 The data is stored as a list of values from the time and times
200 ($real, $user, $system, $children_user, $children_system)
202 in seconds for the whole loop (not divided by the number of rounds).
204 The timing is done using time(3) and times(3).
206 Code is executed in the caller's package.
208 The time of the null loop (a loop with the same
209 number of rounds but empty loop body) is subtracted
210 from the time of the real loop.
212 The null loop times can be cached, the key being the
213 number of rounds. The caching can be controlled using
222 Caching is off by default, as it can (usually slightly) decrease
223 accuracy and does not usually noticably affect runtimes.
227 Benchmark inherits from no other class, except of course
232 Comparing eval'd strings with code references will give you
233 inaccurate results: a code reference will show a slower
234 execution time than the equivalent eval'd string.
236 The real time timing is done using time(2) and
237 the granularity is therefore only one second.
239 Short tests may produce negative figures because perl
240 can appear to take longer to execute the empty loop
241 than a short test; try:
245 The system time of the null loop might be slightly
246 more than the system time of the loop with the actual
247 code and therefore the difference might end up being E<lt> 0.
251 Jarkko Hietaniemi <F<jhi@iki.fi>>, Tim Bunce <F<Tim.Bunce@ig.co.uk>>
253 =head1 MODIFICATION HISTORY
255 September 8th, 1994; by Tim Bunce.
257 March 28th, 1997; by Hugo van der Sanden: added support for code
258 references and the already documented 'debug' method; revamped
261 April 04-07th, 1997: by Jarkko Hietaniemi, added the run-for-some-time
264 September, 1999; by Barrie Slaymaker: math fixes and accuracy and
265 efficiency tweaks. Added cmpthese(). A result is now returned from
270 # evaluate something in a clean lexical environment
271 sub _doeval { eval shift }
274 # put any lexicals at file scope AFTER here
280 @EXPORT=qw(timeit timethis timethese timediff timesum timestr);
281 @EXPORT_OK=qw(clearcache clearallcache cmpthese disablecache enablecache);
289 $defaultfmt = '5.2f';
290 $defaultstyle = 'auto';
291 # The cache can cause a slight loss of sys time accuracy. If a
292 # user does many tests (>10) with *very* large counts (>10000)
293 # or works on a very slow machine the cache may be useful.
298 sub debug { $debug = ($_[1] != 0); }
300 # The cache needs two branches: 's' for strings and 'c' for code. The
301 # emtpy loop is different in these two cases.
302 sub clearcache { delete $cache{"$_[0]c"}; delete $cache{"$_[0]s"}; }
303 sub clearallcache { %cache = (); }
304 sub enablecache { $cache = 1; }
305 sub disablecache { $cache = 0; }
307 # --- Functions to process the 'time' data type
309 sub new { my @t = (time, times, @_ == 2 ? $_[1] : 0);
310 print "new=@t\n" if $debug;
313 sub cpu_p { my($r,$pu,$ps,$cu,$cs) = @{$_[0]}; $pu+$ps ; }
314 sub cpu_c { my($r,$pu,$ps,$cu,$cs) = @{$_[0]}; $cu+$cs ; }
315 sub cpu_a { my($r,$pu,$ps,$cu,$cs) = @{$_[0]}; $pu+$ps+$cu+$cs ; }
316 sub real { my($r,$pu,$ps,$cu,$cs) = @{$_[0]}; $r ; }
321 for (my $i=0; $i < @$a; ++$i) {
322 push(@r, $a->[$i] - $b->[$i]);
330 for (my $i=0; $i < @$a; ++$i) {
331 push(@r, $a->[$i] + $b->[$i]);
337 my($tr, $style, $f) = @_;
339 warn "bad time value (@t)" unless @t==6;
340 my($r, $pu, $ps, $cu, $cs, $n) = @t;
341 my($pt, $ct, $t) = ($tr->cpu_p, $tr->cpu_c, $tr->cpu_a);
342 $f = $defaultfmt unless defined $f;
343 # format a time in the required style, other formats may be added here
344 $style ||= $defaultstyle;
345 $style = ($ct>0) ? 'all' : 'noc' if $style eq 'auto';
346 my $s = "@t $style"; # default for unknown style
347 $s=sprintf("%2d wallclock secs (%$f usr %$f sys + %$f cusr %$f csys = %$f CPU)",
348 @t,$t) if $style eq 'all';
349 $s=sprintf("%2d wallclock secs (%$f usr + %$f sys = %$f CPU)",
350 $r,$pu,$ps,$pt) if $style eq 'noc';
351 $s=sprintf("%2d wallclock secs (%$f cusr + %$f csys = %$f CPU)",
352 $r,$cu,$cs,$ct) if $style eq 'nop';
353 $s .= sprintf(" @ %$f/s (n=$n)", $n / ( $pu + $ps )) if $n;
359 print STDERR "$msg",timestr($t),"\n" if $debug;
362 # --- Functions implementing low-level support for timing loops
367 $n+=0; # force numeric now, so garbage won't creep into the eval
368 croak "negative loopcount $n" if $n<0;
369 confess "Usage: runloop(number, [string | coderef])" unless defined $c;
370 my($t0, $t1, $td); # before, after, difference
372 # find package of caller so we can execute code there
373 my($curpack) = caller(0);
375 while (($pack) = caller(++$i)) {
376 last if $pack ne $curpack;
379 my ($subcode, $subref);
380 if (ref $c eq 'CODE') {
381 $subcode = "sub { for (1 .. $n) { local \$_; package $pack; &\$c; } }";
382 $subref = eval $subcode;
385 $subcode = "sub { for (1 .. $n) { local \$_; package $pack; $c;} }";
386 $subref = _doeval($subcode);
388 croak "runloop unable to compile '$c': $@\ncode: $subcode\n" if $@;
389 print STDERR "runloop $n '$subcode'\n" if $debug;
391 # Wait for the user timer to tick. This makes the error range more like
392 # -0.01, +0. If we don't wait, then it's more like -0.01, +0.01. This
393 # may not seem important, but it significantly reduces the chances of
394 # getting a too low initial $n in the initial, 'find the minimum' loop
395 # in &runfor. This, in turn, can reduce the number of calls to
396 # &runloop a lot, and thus reduce additive errors.
397 my $tbase = Benchmark->new(0)->[1];
399 $t0 = Benchmark->new(0);
400 } while ( $t0->[1] == $tbase );
402 $t1 = Benchmark->new($n);
403 $td = &timediff($t1, $t0);
404 timedebug("runloop:",$td);
413 printf STDERR "timeit $n $code\n" if $debug;
414 my $cache_key = $n . ( ref( $code ) ? 'c' : 's' );
415 if ($cache && exists $cache{$cache_key} ) {
416 $wn = $cache{$cache_key};
418 $wn = &runloop($n, ref( $code ) ? sub { undef } : '' );
419 # Can't let our baseline have any iterations, or they get subtracted
422 $cache{$cache_key} = $wn;
425 $wc = &runloop($n, $code);
427 $wd = timediff($wc, $wn);
428 timedebug("timeit: ",$wc);
429 timedebug(" - ",$wn);
430 timedebug(" = ",$wd);
441 my ($code, $tmax) = @_;
443 if ( not defined $tmax or $tmax == 0 ) {
444 $tmax = $default_for;
445 } elsif ( $tmax < 0 ) {
449 die "runfor(..., $tmax): timelimit cannot be less than $min_for.\n"
454 # First find the minimum $n that gives a significant timing.
455 for ($n = 1; ; $n *= 2 ) {
456 my $td = timeit($n, $code);
457 $tc = $td->[1] + $td->[2];
463 # Get $n high enough that we can guess the final $n with some accuracy.
464 my $tpra = 0.1 * $tmax; # Target/time practice.
465 while ( $tc < $tpra ) {
466 # The 5% fudge is to keep us from iterating again all
467 # that often (this speeds overall responsiveness when $tmax is big
468 # and we guess a little low). This does not noticably affect
469 # accuracy since we're not couting these times.
470 $n = int( $tpra * 1.05 * $n / $tc ); # Linear approximation.
471 my $td = timeit($n, $code);
472 $tc = $td->[1] + $td->[2];
475 # Now, do the 'for real' timing(s), repeating until we exceed
485 # The 5% fudge is because $n is often a few % low even for routines
486 # with stable times and avoiding extra timeit()s is nice for
488 $n = int( $n * ( 1.05 * $tmax / $tc ) );
491 my $td = timeit($n, $code);
498 $ttot = $utot + $stot;
499 last if $ttot >= $tmax;
501 my $r = $tmax / $ttot - 1; # Linear approximation.
502 $n = int( $r * $ntot );
503 $n = $nmin if $n < $nmin;
506 return bless [ $rtot, $utot, $stot, $cutot, $cstot, $ntot ];
509 # --- Functions implementing high-level time-then-print utilities
513 return $n == 0 ? $default_for : $n < 0 ? -$n : undef;
517 my($n, $code, $title, $style) = @_;
521 croak "non-integer loopcount $n, stopped" if int($n)<$n;
522 $t = timeit($n, $code);
523 $title = "timethis $n" unless defined $title;
525 $fort = n_to_for( $n );
526 $t = runfor($code, $fort);
527 $title = "timethis for $fort" unless defined $title;
531 $style = "" unless defined $style;
532 printf("%10s: ", $title) unless $style eq 'none';
533 print timestr($t, $style, $defaultfmt),"\n" unless $style eq 'none';
535 $n = $forn if defined $forn;
537 # A conservative warning to spot very silly tests.
538 # Don't assume that your benchmark is ok simply because
539 # you don't get this warning!
540 print " (warning: too few iterations for a reliable count)\n"
542 || ($t->real < 1 && $n < 1000)
543 || $t->cpu_a < $min_cpu;
548 my($n, $alt, $style) = @_;
549 die "usage: timethese(count, { 'Name1'=>'code1', ... }\n"
550 unless ref $alt eq HASH;
551 my @names = sort keys %$alt;
552 $style = "" unless defined $style;
553 print "Benchmark: " unless $style eq 'none';
555 croak "non-integer loopcount $n, stopped" if int($n)<$n;
556 print "timing $n iterations of" unless $style eq 'none';
558 print "running" unless $style eq 'none';
560 print " ", join(', ',@names) unless $style eq 'none';
562 my $for = n_to_for( $n );
563 print ", each for at least $for CPU seconds" unless $style eq 'none';
565 print "...\n" unless $style eq 'none';
567 # we could save the results in an array and produce a summary here
568 # sum, min, max, avg etc etc
570 foreach my $name (@names) {
571 $results{$name} = timethis ($n, $alt -> {$name}, $name, $style);
578 my $results = ref $_[0] ? $_[0] : timethese( @_ );
581 if defined $_[2] && $_[2] eq 'none';
583 # Flatten in to an array of arrays with the name as the first field
584 my @vals = map{ [ $_, @{$results->{$_}} ] } keys %$results;
587 # The epsilon fudge here is to prevent div by 0. Since clock
588 # resolutions are much larger, it's below the noise floor.
589 my $rate = $_->[6] / ( $_->[2] + $_->[3] + 0.000000000000001 );
594 @vals = sort { $a->[7] <=> $b->[7] } @vals;
596 # If more than half of the rates are greater than one...
597 my $display_as_rate = $vals[$#vals>>1]->[7] > 1;
604 $display_as_rate ? 'Rate' : 's/iter',
605 map { $_->[0] } @vals
608 push @rows, \@top_row;
609 @col_widths = map { length( $_ ) } @top_row;
611 # Build the data rows
612 # We leave the last column in even though it never has any data. Perhaps
613 # it should go away. Also, perhaps a style for a single column of
614 # percentages might be nice.
615 for my $row_val ( @vals ) {
618 # Column 0 = test name
619 push @row, $row_val->[0];
620 $col_widths[0] = length( $row_val->[0] )
621 if length( $row_val->[0] ) > $col_widths[0];
623 # Column 1 = performance
624 my $row_rate = $row_val->[7];
626 # We assume that we'll never get a 0 rate.
627 my $a = $display_as_rate ? $row_rate : 1 / $row_rate;
629 # Only give a few decimal places before switching to sci. notation,
630 # since the results aren't usually that accurate anyway.
644 # Using $b here due to optimizing bug in _58 through _61
645 my $b = sprintf( $format, $a );
647 $col_widths[1] = length( $b )
648 if length( $b ) > $col_widths[1];
650 # Columns 2..N = performance ratios
652 for ( my $col_num = 0 ; $col_num < @vals ; ++$col_num ) {
653 my $col_val = $vals[$col_num];
658 elsif ( $col_val->[0] eq $row_val->[0] ) {
663 my $col_rate = $col_val->[7];
664 $out = sprintf( "%.0f%%", 100*$row_rate/$col_rate - 100 );
667 $col_widths[$col_num+2] = length( $out )
668 if length( $out ) > $col_widths[$col_num+2];
670 # A little wierdness to set the first column width properly
671 $col_widths[$col_num+2] = length( $col_val->[0] )
672 if length( $col_val->[0] ) > $col_widths[$col_num+2];
677 # Equalize column widths in the chart as much as possible without
678 # exceeding 80 characters. This does not use or affect cols 0 or 1.
679 my @sorted_width_refs =
680 sort { $$a <=> $$b } map { \$_ } @col_widths[2..$#col_widths];
681 my $max_width = ${$sorted_width_refs[-1]};
684 for ( @col_widths ) { $total += $_ }
687 while ( $total < 80 ) {
688 my $min_width = ${$sorted_width_refs[0]};
690 if $min_width == $max_width;
691 for ( @sorted_width_refs ) {
702 my $format = join( ' ', map { "%${_}s" } @col_widths ) . "\n";
703 substr( $format, 1, 0 ) = '-';