X-Git-Url: http://git.shadowcat.co.uk/gitweb/gitweb.cgi?a=blobdiff_plain;f=lib%2FBenchmark.pm;h=ad04a754bbbab1b5dc8bebdc787e5b183db74eb9;hb=d0c833c6b6d161774fa9ee0c74b6748675c48591;hp=4d3b3e24249fe33ac62f27e7aa45e970c4f1285d;hpb=d6a466d771dbdc293e3f83b595b03cf44617cabb;p=p5sagit%2Fp5-mst-13.2.git diff --git a/lib/Benchmark.pm b/lib/Benchmark.pm index 4d3b3e2..ad04a75 100644 --- a/lib/Benchmark.pm +++ b/lib/Benchmark.pm @@ -1,11 +1,16 @@ package Benchmark; +use strict; + + =head1 NAME Benchmark - benchmark running times of Perl code =head1 SYNOPSIS + use Benchmark qw(:all) ; + timethis ($count, "code"); # Use Perl code in strings... @@ -48,6 +53,9 @@ Benchmark - benchmark running times of Perl code $count = $t->iters ; print "$count loops of other code took:",timestr($t),"\n"; + # enable hires wallclock timing if possible + use Benchmark ':hireswallclock'; + =head1 DESCRIPTION The Benchmark module encapsulates a number of routines to help you @@ -194,19 +202,50 @@ Clear the cached time for COUNT rounds of the null loop. Clear all cached times. -=item cmpthese ( COUT, CODEHASHREF, [ STYLE ] ) +=item cmpthese ( COUNT, CODEHASHREF, [ STYLE ] ) + +=item cmpthese ( RESULTSHASHREF, [ STYLE ] ) + +Optionally calls timethese(), then outputs comparison chart. This: -=item cmpthese ( RESULTSHASHREF ) + cmpthese( -1, { a => "++\$i", b => "\$i *= 2" } ) ; -Optionally calls timethese(), then outputs comparison chart. This -chart is sorted from slowest to fastest, and shows the percent -speed difference between each pair of tests. Can also be passed -the data structure that timethese() returns: +outputs a chart like: - $results = timethese( .... ); + Rate b a + b 2831802/s -- -61% + a 7208959/s 155% -- + +This chart is sorted from slowest to fastest, and shows the percent speed +difference between each pair of tests. + +c can also be passed the data structure that timethese() returns: + + $results = timethese( -1, { a => "++\$i", b => "\$i *= 2" } ) ; cmpthese( $results ); -Returns the data structure returned by timethese() (or passed in). +in case you want to see both sets of results. + +Returns a reference to an ARRAY of rows, each row is an ARRAY of cells from the +above chart, including labels. This: + + my $rows = cmpthese( -1, { a => '++$i', b => '$i *= 2' }, "none" ); + +returns a data structure like: + + [ + [ '', 'Rate', 'b', 'a' ], + [ 'b', '2885232/s', '--', '-59%' ], + [ 'a', '7099126/s', '146%', '--' ], + ] + +B: This result value differs from previous versions, which returned +the C result structure. If you want that, just use the two +statement C...C idiom shown above. + +Incidently, note the variance in the result values between the two examples; +this is typical of benchmarking. If this were a real benchmark, you would +probably want to run a lot more iterations. =item countit(TIME, CODE) @@ -240,6 +279,15 @@ for passing to timestr(). =back +=head2 :hireswallclock + +If the Time::HiRes module has been installed, you can specify the +special tag C<:hireswallclock> for Benchmark (if Time::HiRes is not +available, the tag will be silently ignored). This tag will cause the +wallclock time to be measured in microseconds, instead of integer +seconds. Note though that the speed computations are still conducted +in CPU time, not wallclock time. + =head1 NOTES The data is stored as a list of values from the time and times @@ -274,29 +322,39 @@ accuracy and does not usually noticably affect runtimes. For example, - use Benchmark;$x=3;cmpthese(-5,{a=>sub{$x*$x},b=>sub{$x**2}}) + use Benchmark qw( cmpthese ) ; + $x = 3; + cmpthese( -5, { + a => sub{$x*$x}, + b => sub{$x**2}, + } ); outputs something like this: Benchmark: running a, b, each for at least 5 CPU seconds... - a: 10 wallclock secs ( 5.14 usr + 0.13 sys = 5.27 CPU) @ 3835055.60/s (n=20210743) - b: 5 wallclock secs ( 5.41 usr + 0.00 sys = 5.41 CPU) @ 1574944.92/s (n=8520452) - Rate b a - b 1574945/s -- -59% - a 3835056/s 144% -- + Rate b a + b 1559428/s -- -62% + a 4152037/s 166% -- + while - use Benchmark; - $x=3; - $r=timethese(-5,{a=>sub{$x*$x},b=>sub{$x**2}},'none'); - cmpthese($r); + use Benchmark qw( timethese cmpthese ) ; + $x = 3; + $r = timethese( -5, { + a => sub{$x*$x}, + b => sub{$x**2}, + } ); + cmpthese $r; outputs something like this: - Rate b a - b 1559428/s -- -62% - a 4152037/s 166% -- + Benchmark: running a, b, each for at least 5 CPU seconds... + a: 10 wallclock secs ( 5.14 usr + 0.13 sys = 5.27 CPU) @ 3835055.60/s (n=20210743) + b: 5 wallclock secs ( 5.41 usr + 0.00 sys = 5.41 CPU) @ 1574944.92/s (n=8520452) + Rate b a + b 1574945/s -- -59% + a 3835056/s 144% -- =head1 INHERITANCE @@ -346,10 +404,21 @@ September, 1999; by Barrie Slaymaker: math fixes and accuracy and efficiency tweaks. Added cmpthese(). A result is now returned from timethese(). Exposed countit() (was runfor()). +December, 2001; by Nicholas Clark: make timestr() recognise the style 'none' +and return an empty string. If cmpthese is calling timethese, make it pass the +style in. (so that 'none' will suppress output). Make sub new dump its +debugging output to STDERR, to be consistent with everything else. +All bugs found while writing a regression test. + +September, 2002; by Jarkko Hietaniemi: add ':hireswallclock' special tag. + +February, 2004; by Chia-liang Kao: make cmpthese and timestr use time +statistics for children instead of parent when the style is 'nop'. + =cut # evaluate something in a clean lexical environment -sub _doeval { eval shift } +sub _doeval { no strict; eval shift } # # put any lexicals at file scope AFTER here @@ -357,41 +426,109 @@ sub _doeval { eval shift } use Carp; use Exporter; -@ISA=(Exporter); + +our(@ISA, @EXPORT, @EXPORT_OK, %EXPORT_TAGS, $VERSION); + +@ISA=qw(Exporter); @EXPORT=qw(timeit timethis timethese timediff timestr); @EXPORT_OK=qw(timesum cmpthese countit clearcache clearallcache disablecache enablecache); +%EXPORT_TAGS=( all => [ @EXPORT, @EXPORT_OK ] ) ; -$VERSION = 1.01; +$VERSION = 1.07; -&init; +# --- ':hireswallclock' special handling + +my $hirestime; + +sub mytime () { time } + +init(); + +sub BEGIN { + if (eval 'require Time::HiRes') { + import Time::HiRes qw(time); + $hirestime = \&Time::HiRes::time; + } +} + +sub import { + my $class = shift; + if (grep { $_ eq ":hireswallclock" } @_) { + @_ = grep { $_ ne ":hireswallclock" } @_; + *mytime = $hirestime if defined $hirestime; + } + Benchmark->export_to_level(1, $class, @_); +} + +our($Debug, $Min_Count, $Min_CPU, $Default_Format, $Default_Style, + %_Usage, %Cache, $Do_Cache); sub init { - $debug = 0; - $min_count = 4; - $min_cpu = 0.4; - $defaultfmt = '5.2f'; - $defaultstyle = 'auto'; + $Debug = 0; + $Min_Count = 4; + $Min_CPU = 0.4; + $Default_Format = '5.2f'; + $Default_Style = 'auto'; # The cache can cause a slight loss of sys time accuracy. If a # user does many tests (>10) with *very* large counts (>10000) # or works on a very slow machine the cache may be useful. - &disablecache; - &clearallcache; + disablecache(); + clearallcache(); } -sub debug { $debug = ($_[1] != 0); } +sub debug { $Debug = ($_[1] != 0); } + +sub usage { + my $calling_sub = (caller(1))[3]; + $calling_sub =~ s/^Benchmark:://; + return $_Usage{$calling_sub} || ''; +} # The cache needs two branches: 's' for strings and 'c' for code. The -# emtpy loop is different in these two cases. -sub clearcache { delete $cache{"$_[0]c"}; delete $cache{"$_[0]s"}; } -sub clearallcache { %cache = (); } -sub enablecache { $cache = 1; } -sub disablecache { $cache = 0; } +# empty loop is different in these two cases. + +$_Usage{clearcache} = <<'USAGE'; +usage: clearcache($count); +USAGE + +sub clearcache { + die usage unless @_ == 1; + delete $Cache{"$_[0]c"}; delete $Cache{"$_[0]s"}; +} + +$_Usage{clearallcache} = <<'USAGE'; +usage: clearallcache(); +USAGE + +sub clearallcache { + die usage if @_; + %Cache = (); +} + +$_Usage{enablecache} = <<'USAGE'; +usage: enablecache(); +USAGE + +sub enablecache { + die usage if @_; + $Do_Cache = 1; +} + +$_Usage{disablecache} = <<'USAGE'; +usage: disablecache(); +USAGE + +sub disablecache { + die usage if @_; + $Do_Cache = 0; +} + # --- Functions to process the 'time' data type -sub new { my @t = (time, times, @_ == 2 ? $_[1] : 0); - print "new=@t\n" if $debug; +sub new { my @t = (mytime, times, @_ == 2 ? $_[1] : 0); + print STDERR "new=@t\n" if $Debug; bless \@t; } sub cpu_p { my($r,$pu,$ps,$cu,$cs) = @{$_[0]}; $pu+$ps ; } @@ -400,8 +537,16 @@ sub cpu_a { my($r,$pu,$ps,$cu,$cs) = @{$_[0]}; $pu+$ps+$cu+$cs ; } sub real { my($r,$pu,$ps,$cu,$cs) = @{$_[0]}; $r ; } sub iters { $_[0]->[5] ; } + +$_Usage{timediff} = <<'USAGE'; +usage: $result_diff = timediff($result1, $result2); +USAGE + sub timediff { my($a, $b) = @_; + + die usage unless ref $a and ref $b; + my @r; for (my $i=0; $i < @$a; ++$i) { push(@r, $a->[$i] - $b->[$i]); @@ -409,49 +554,71 @@ sub timediff { bless \@r; } +$_Usage{timesum} = <<'USAGE'; +usage: $sum = timesum($result1, $result2); +USAGE + sub timesum { - my($a, $b) = @_; - my @r; - for (my $i=0; $i < @$a; ++$i) { + my($a, $b) = @_; + + die usage unless ref $a and ref $b; + + my @r; + for (my $i=0; $i < @$a; ++$i) { push(@r, $a->[$i] + $b->[$i]); - } - bless \@r; + } + bless \@r; } + +$_Usage{timestr} = <<'USAGE'; +usage: $formatted_result = timestr($result1); +USAGE + sub timestr { my($tr, $style, $f) = @_; + + die usage unless ref $tr; + my @t = @$tr; warn "bad time value (@t)" unless @t==6; my($r, $pu, $ps, $cu, $cs, $n) = @t; my($pt, $ct, $tt) = ($tr->cpu_p, $tr->cpu_c, $tr->cpu_a); - $f = $defaultfmt unless defined $f; + $f = $Default_Format unless defined $f; # format a time in the required style, other formats may be added here - $style ||= $defaultstyle; + $style ||= $Default_Style; + return '' if $style eq 'none'; $style = ($ct>0) ? 'all' : 'noc' if $style eq 'auto'; my $s = "@t $style"; # default for unknown style - $s=sprintf("%2d wallclock secs (%$f usr %$f sys + %$f cusr %$f csys = %$f CPU)", + my $w = $hirestime ? "%2g" : "%2d"; + $s=sprintf("$w wallclock secs (%$f usr %$f sys + %$f cusr %$f csys = %$f CPU)", $r,$pu,$ps,$cu,$cs,$tt) if $style eq 'all'; - $s=sprintf("%2d wallclock secs (%$f usr + %$f sys = %$f CPU)", + $s=sprintf("$w wallclock secs (%$f usr + %$f sys = %$f CPU)", $r,$pu,$ps,$pt) if $style eq 'noc'; - $s=sprintf("%2d wallclock secs (%$f cusr + %$f csys = %$f CPU)", + $s=sprintf("$w wallclock secs (%$f cusr + %$f csys = %$f CPU)", $r,$cu,$cs,$ct) if $style eq 'nop'; - $s .= sprintf(" @ %$f/s (n=$n)", $n / ( $pu + $ps )) if $n && $pu+$ps; + $s .= sprintf(" @ %$f/s (n=$n)", $n / ( $style eq 'nop' ? $cu + $cs : $pu + $ps )) + if $n && ($style eq 'nop' ? $cu+$cs : $pu+$ps); $s; } sub timedebug { my($msg, $t) = @_; - print STDERR "$msg",timestr($t),"\n" if $debug; + print STDERR "$msg",timestr($t),"\n" if $Debug; } # --- Functions implementing low-level support for timing loops +$_Usage{runloop} = <<'USAGE'; +usage: runloop($number, [$string | $coderef]) +USAGE + sub runloop { my($n, $c) = @_; $n+=0; # force numeric now, so garbage won't creep into the eval croak "negative loopcount $n" if $n<0; - confess "Usage: runloop(number, [string | coderef])" unless defined $c; + confess usage unless defined $c; my($t0, $t1, $td); # before, after, difference # find package of caller so we can execute code there @@ -471,7 +638,7 @@ sub runloop { $subref = _doeval($subcode); } croak "runloop unable to compile '$c': $@\ncode: $subcode\n" if $@; - print STDERR "runloop $n '$subcode'\n" if $debug; + print STDERR "runloop $n '$subcode'\n" if $Debug; # Wait for the user timer to tick. This makes the error range more like # -0.01, +0. If we don't wait, then it's more like -0.01, +0.01. This @@ -481,28 +648,35 @@ sub runloop { # &runloop a lot, and thus reduce additive errors. my $tbase = Benchmark->new(0)->[1]; while ( ( $t0 = Benchmark->new(0) )->[1] == $tbase ) {} ; - &$subref; + $subref->(); $t1 = Benchmark->new($n); $td = &timediff($t1, $t0); timedebug("runloop:",$td); $td; } +$_Usage{timeit} = <<'USAGE'; +usage: $result = timeit($count, 'code' ); or + $result = timeit($count, sub { code } ); +USAGE sub timeit { my($n, $code) = @_; my($wn, $wc, $wd); - printf STDERR "timeit $n $code\n" if $debug; + die usage unless defined $code and + (!ref $code or ref $code eq 'CODE'); + + printf STDERR "timeit $n $code\n" if $Debug; my $cache_key = $n . ( ref( $code ) ? 'c' : 's' ); - if ($cache && exists $cache{$cache_key} ) { - $wn = $cache{$cache_key}; + if ($Do_Cache && exists $Cache{$cache_key} ) { + $wn = $Cache{$cache_key}; } else { - $wn = &runloop($n, ref( $code ) ? sub { undef } : '' ); + $wn = &runloop($n, ref( $code ) ? sub { } : '' ); # Can't let our baseline have any iterations, or they get subtracted # out of the result. $wn->[5] = 0; - $cache{$cache_key} = $wn; + $Cache{$cache_key} = $wn; } $wc = &runloop($n, $code); @@ -520,9 +694,16 @@ my $default_for = 3; my $min_for = 0.1; +$_Usage{countit} = <<'USAGE'; +usage: $result = countit($time, 'code' ); or + $result = countit($time, sub { code } ); +USAGE + sub countit { my ( $tmax, $code ) = @_; + die usage unless @_; + if ( not defined $tmax or $tmax == 0 ) { $tmax = $default_for; } elsif ( $tmax < 0 ) { @@ -599,16 +780,24 @@ sub n_to_for { return $n == 0 ? $default_for : $n < 0 ? -$n : undef; } +$_Usage{timethis} = <<'USAGE'; +usage: $result = timethis($time, 'code' ); or + $result = timethis($time, sub { code } ); +USAGE + sub timethis{ my($n, $code, $title, $style) = @_; - my($t, $for, $forn); + my($t, $forn); + + die usage unless defined $code and + (!ref $code or ref $code eq 'CODE'); if ( $n > 0 ) { croak "non-integer loopcount $n, stopped" if int($n)<$n; $t = timeit($n, $code); $title = "timethis $n" unless defined $title; } else { - $fort = n_to_for( $n ); + my $fort = n_to_for( $n ); $t = countit( $fort, $code ); $title = "timethis for $fort" unless defined $title; $forn = $t->[-1]; @@ -616,7 +805,7 @@ sub timethis{ local $| = 1; $style = "" unless defined $style; printf("%10s: ", $title) unless $style eq 'none'; - print timestr($t, $style, $defaultfmt),"\n" unless $style eq 'none'; + print timestr($t, $style, $Default_Format),"\n" unless $style eq 'none'; $n = $forn if defined $forn; @@ -624,16 +813,22 @@ sub timethis{ # Don't assume that your benchmark is ok simply because # you don't get this warning! print " (warning: too few iterations for a reliable count)\n" - if $n < $min_count + if $n < $Min_Count || ($t->real < 1 && $n < 1000) - || $t->cpu_a < $min_cpu; + || $t->cpu_a < $Min_CPU; $t; } + +$_Usage{timethese} = <<'USAGE'; +usage: timethese($count, { Name1 => 'code1', ... }); or + timethese($count, { Name1 => sub { code1 }, ... }); +USAGE + sub timethese{ my($n, $alt, $style) = @_; - die "usage: timethese(count, { 'Name1'=>'code1', ... }\n" - unless ref $alt eq HASH; + die usage unless ref $alt eq 'HASH'; + my @names = sort keys %$alt; $style = "" unless defined $style; print "Benchmark: " unless $style eq 'none'; @@ -646,7 +841,8 @@ sub timethese{ print " ", join(', ',@names) unless $style eq 'none'; unless ( $n > 0 ) { my $for = n_to_for( $n ); - print ", each for at least $for CPU seconds" unless $style eq 'none'; + print ", each" if $n > 1 && $style ne 'none'; + print " for at least $for CPU seconds" unless $style eq 'none'; } print "...\n" unless $style eq 'none'; @@ -660,11 +856,29 @@ sub timethese{ return \%results; } + +$_Usage{cmpthese} = <<'USAGE'; +usage: cmpthese($count, { Name1 => 'code1', ... }); or + cmpthese($count, { Name1 => sub { code1 }, ... }); or + cmpthese($result, $style); +USAGE + sub cmpthese{ - my $results = ref $_[0] ? $_[0] : timethese( @_ ); + my ($results, $style); + + if( ref $_[0] ) { + ($results, $style) = @_; + } + else { + my($count, $code) = @_[0,1]; + $style = $_[2] if defined $_[2]; - return $results - if defined $_[2] && $_[2] eq 'none'; + die usage unless ref $code eq 'HASH'; + + $results = timethese($count, $code, ($style || "none")); + } + + $style = "" unless defined $style; # Flatten in to an array of arrays with the name as the first field my @vals = map{ [ $_, @{$results->{$_}} ] } keys %$results; @@ -672,7 +886,8 @@ sub cmpthese{ for (@vals) { # The epsilon fudge here is to prevent div by 0. Since clock # resolutions are much larger, it's below the noise floor. - my $rate = $_->[6] / ( $_->[2] + $_->[3] + 0.000000000000001 ); + my $rate = $_->[6] / (( $style eq 'nop' ? $_->[4] + $_->[5] + : $_->[2] + $_->[3]) + 0.000000000000001 ); $_->[7] = $rate; } @@ -680,7 +895,7 @@ sub cmpthese{ @vals = sort { $a->[7] <=> $b->[7] } @vals; # If more than half of the rates are greater than one... - my $display_as_rate = $vals[$#vals>>1]->[7] > 1; + my $display_as_rate = @vals ? ($vals[$#vals>>1]->[7] > 1) : 0; my @rows; my @col_widths; @@ -710,28 +925,28 @@ sub cmpthese{ my $row_rate = $row_val->[7]; # We assume that we'll never get a 0 rate. - my $a = $display_as_rate ? $row_rate : 1 / $row_rate; + my $rate = $display_as_rate ? $row_rate : 1 / $row_rate; # Only give a few decimal places before switching to sci. notation, # since the results aren't usually that accurate anyway. my $format = - $a >= 100 ? + $rate >= 100 ? "%0.0f" : - $a >= 10 ? + $rate >= 10 ? "%0.1f" : - $a >= 1 ? + $rate >= 1 ? "%0.2f" : - $a >= 0.1 ? + $rate >= 0.1 ? "%0.3f" : "%0.2e"; $format .= "/s" if $display_as_rate; - # Using $b here due to optimizing bug in _58 through _61 - my $b = sprintf( $format, $a ); - push @row, $b; - $col_widths[1] = length( $b ) - if length( $b ) > $col_widths[1]; + + my $formatted_rate = sprintf( $format, $rate ); + push @row, $formatted_rate; + $col_widths[1] = length( $formatted_rate ) + if length( $formatted_rate ) > $col_widths[1]; # Columns 2..N = performance ratios my $skip_rest = 0; @@ -760,6 +975,8 @@ sub cmpthese{ push @rows, \@row; } + return \@rows if $style eq "none"; + # Equalize column widths in the chart as much as possible without # exceeding 80 characters. This does not use or affect cols 0 or 1. my @sorted_width_refs = @@ -791,7 +1008,7 @@ sub cmpthese{ printf $format, @$_; } - return $results; + return \@rows ; }