From: Michael G. Schwern Date: Sun, 3 Aug 2003 16:12:35 +0000 (-0700) Subject: Re: [PATCH] Re: [perl #23206] Benchmark::cmpthese usage message wrong X-Git-Url: http://git.shadowcat.co.uk/gitweb/gitweb.cgi?a=commitdiff_plain;h=53aa2791f2814657eac3bbbec321e82f3209ae86;p=p5sagit%2Fp5-mst-13.2.git Re: [PATCH] Re: [perl #23206] Benchmark::cmpthese usage message wrong Message-ID: <20030803231235.GJ24350@windhund.schwern.org> p4raw-id: //depot/perl@20463 --- diff --git a/lib/Benchmark.pm b/lib/Benchmark.pm index 2907e69..3d154bc 100644 --- a/lib/Benchmark.pm +++ b/lib/Benchmark.pm @@ -1,5 +1,8 @@ package Benchmark; +use strict; + + =head1 NAME Benchmark - benchmark running times of Perl code @@ -412,7 +415,7 @@ September, 2002; by Jarkko Hietaniemi: add ':hireswallclock' special tag. =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 @@ -420,13 +423,16 @@ 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.0501; +$VERSION = 1.051; # --- ':hireswallclock' special handling @@ -452,12 +458,15 @@ sub import { 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. @@ -465,19 +474,59 @@ sub init { &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; } + +$_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 = (mytime, times, @_ == 2 ? $_[1] : 0); - print STDERR "new=@t\n" if $debug; + print STDERR "new=@t\n" if $Debug; bless \@t; } sub cpu_p { my($r,$pu,$ps,$cu,$cs) = @{$_[0]}; $pu+$ps ; } @@ -486,8 +535,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]); @@ -495,24 +552,39 @@ 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 @@ -529,17 +601,21 @@ sub timestr { 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 @@ -559,7 +635,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 @@ -576,21 +652,28 @@ sub runloop { $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 { } : '' ); # 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); @@ -608,9 +691,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 ) { @@ -687,16 +777,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]; @@ -704,7 +802,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; @@ -712,16 +810,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'; @@ -749,10 +853,27 @@ 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, $style) = - ref $_ [0] ? @_ - : (timethese (@_ [0, 1], @_ > 2 ? $_ [2] : "none"), $_ [2]); + my ($results, $style); + + if( ref $_[0] ) { + ($results, $style) = @_; + } + else { + my($count, $code) = @_[0,1]; + $style = $_[2] if defined $_[2]; + + die usage unless ref $code eq 'HASH'; + + $results = timethese($count, $code, ($style || "none")); + } $style = "" unless defined $style; @@ -800,28 +921,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; diff --git a/lib/Benchmark.t b/lib/Benchmark.t index 36bccd7..8081476 100644 --- a/lib/Benchmark.t +++ b/lib/Benchmark.t @@ -2,13 +2,13 @@ BEGIN { chdir 't' if -d 't'; - @INC = '../lib'; + @INC = ('../lib'); } use warnings; use strict; use vars qw($foo $bar $baz $ballast); -use Test::More tests => 173; +use Test::More tests => 193; use Benchmark qw(:all); @@ -22,14 +22,14 @@ sub fib { } $ballast = 15; -my $all_pattern = +my $All_Pattern = qr/(\d+) +wallclock secs? +\( *(-?\d+\.\d\d) +usr +(-?\d+\.\d\d) +sys +\+ +(-?\d+\.\d\d) +cusr +(-?\d+\.\d\d) +csys += +(-?\d+\.\d\d) +CPU\)/; -my $noc_pattern = +my $Noc_Pattern = qr/(\d+) +wallclock secs? +\( *(-?\d+\.\d\d) +usr +\+ +(-?\d+\.\d\d) +sys += +(-?\d+\.\d\d) +CPU\)/; -my $nop_pattern = +my $Nop_Pattern = qr/(\d+) +wallclock secs? +\( *(-?\d+\.\d\d) +cusr +\+ +(-?\d+\.\d\d) +csys += +\d+\.\d\d +CPU\)/; # Please don't trust the matching parenthises to be useful in this :-) -my $default_pattern = qr/$all_pattern|$noc_pattern/; +my $Default_Pattern = qr/$All_Pattern|$Noc_Pattern/; my $t0 = new Benchmark; isa_ok ($t0, 'Benchmark', "Ensure we can create a benchmark object"); @@ -102,10 +102,10 @@ is ($auto, $default, 'timestr ($diff, "auto") matches timestr ($diff)'); { my $all = timestr ($diff, 'all'); - like ($all, $all_pattern, 'timestr ($diff, "all")'); + like ($all, $All_Pattern, 'timestr ($diff, "all")'); print "# $all\n"; - my ($wallclock, $usr, $sys, $cusr, $csys, $cpu) = $all =~ $all_pattern; + my ($wallclock, $usr, $sys, $cusr, $csys, $cpu) = $all =~ $All_Pattern; is (timestr ($diff, 'none'), '', "none supresses output"); @@ -138,7 +138,7 @@ is ($foo, $iterations, "benchmarked code was run $iterations times"); $got = $out->read(); like ($got, qr/^timethis $iterations/, 'default title'); -like ($got, $default_pattern, 'default format is all or noc'); +like ($got, $Default_Pattern, 'default format is all or noc'); $bar = 0; select(OUT); @@ -149,7 +149,7 @@ is ($bar, $iterations, "benchmarked code was run $iterations times"); $got = $out->read(); like ($got, qr/^timethis $iterations/, 'default title'); -like ($got, $default_pattern, 'default format is all or noc'); +like ($got, $Default_Pattern, 'default format is all or noc'); my $title = 'lies, damn lies and benchmarks'; $foo = 0; @@ -161,7 +161,7 @@ is ($foo, $iterations, "benchmarked code was run $iterations times"); $got = $out->read(); like ($got, qr/^$title:/, 'specify title'); -like ($got, $default_pattern, 'default format is all or noc'); +like ($got, $Default_Pattern, 'default format is all or noc'); # default is auto, which is all or noc. nop can never match the default $foo = 0; @@ -173,7 +173,7 @@ is ($foo, $iterations, "benchmarked code was run $iterations times"); $got = $out->read(); like ($got, qr/^$title:/, 'specify title'); -like ($got, $nop_pattern, 'specify format as nop'); +like ($got, $Nop_Pattern, 'specify format as nop'); { $foo = 0; @@ -218,7 +218,42 @@ like ($got, qr/timing $iterations iterations of\s+Bar\W+Baz\W+Foo\W*?\.\.\./s, # Remove the title $got =~ s/.*\.\.\.//s; like ($got, qr/\bBar\b.*\bBaz\b.*\bFoo\b/s, 'check output is in sorted order'); -like ($got, $default_pattern, 'should find default format somewhere'); +like ($got, $Default_Pattern, 'should find default format somewhere'); + + +{ # ensure 'use strict' does not leak from Benchmark.pm into benchmarked code + no strict; + select OUT; + + eval { + timethese( 1, + { undeclared_var => q{ $i++; $i-- }, + symbolic_ref => q{ $bar = 42; + $foo = 'bar'; + $q = ${$foo} }, + }, + 'none' + ); + + }; + is( $@, '', q{no strict leakage in name => 'code'} ); + + eval { + timethese( 1, + { undeclared_var => sub { $i++; $i-- }, + symbolic_ref => sub { $bar = 42; + $foo = 'bar'; + return ${$foo} }, + }, + 'none' + ); + }; + is( $@, '', q{no strict leakage in name => sub { code }} ); + + # clear out buffer + $out->read; +} + my $code_to_test = { Foo => sub {$foo+=fib($ballast-2)}, Bar => sub {$bar+=fib($ballast)}}; @@ -361,7 +396,7 @@ sub check_graph { 'check title'); # Remove the title $got =~ s/.*\.\.\.//s; - like ($got, $default_pattern, 'should find default format somewhere'); + like ($got, $Default_Pattern, 'should find default format somewhere'); like ($got, $graph_dissassembly, "Should find the output graph somewhere"); check_graph_vs_output ($chart, $got); } @@ -383,7 +418,7 @@ sub check_graph { 'should not have title'); # Remove the title $got =~ s/.*\.\.\.//s; - unlike ($got, $default_pattern, 'should not find default format somewhere'); + unlike ($got, $Default_Pattern, 'should not find default format somewhere'); like ($got, $graph_dissassembly, "Should find the output graph somewhere"); check_graph_vs_output ($chart, $got); } @@ -403,7 +438,7 @@ sub check_graph { 'check title'); # Remove the title $got =~ s/.*\.\.\.//s; - like ($got, $nop_pattern, 'specify format as nop'); + like ($got, $Nop_Pattern, 'specify format as nop'); like ($got, $graph_dissassembly, "Should find the output graph somewhere"); check_graph_vs_output ($chart, $got); } @@ -494,26 +529,65 @@ untie *STDERR; # being used, merely what's become cached. clearallcache(); -my @before_keys = keys %Benchmark::cache; +my @before_keys = keys %Benchmark::Cache; $bar = 0; isa_ok(timeit(5, '++$bar'), 'Benchmark', "timeit eval"); is ($bar, 5, "benchmarked code was run 5 times"); -my @after5_keys = keys %Benchmark::cache; +my @after5_keys = keys %Benchmark::Cache; $bar = 0; isa_ok(timeit(10, '++$bar'), 'Benchmark', "timeit eval"); is ($bar, 10, "benchmarked code was run 10 times"); -ok (!eq_array ([keys %Benchmark::cache], \@after5_keys), "10 differs from 5"); +ok (!eq_array ([keys %Benchmark::Cache], \@after5_keys), "10 differs from 5"); clearcache(10); # Hash key order will be the same if there are the same keys. -is_deeply ([keys %Benchmark::cache], \@after5_keys, +is_deeply ([keys %Benchmark::Cache], \@after5_keys, "cleared 10, only cached results for 5 should remain"); clearallcache(); -is_deeply ([keys %Benchmark::cache], \@before_keys, +is_deeply ([keys %Benchmark::Cache], \@before_keys, "back to square 1 when we clear the cache again?"); +{ # Check usage error messages + my %usage = %Benchmark::_Usage; + delete $usage{runloop}; # not public, not worrying about it just now + + my @takes_no_args = qw(clearallcache disablecache enablecache); + + my %cmpthese = ('forgot {}' => 'cmpthese( 42, foo => sub { 1 } )', + 'not result' => 'cmpthese(42)', + 'array ref' => 'cmpthese( 42, [ foo => sub { 1 } ] )', + ); + while( my($name, $code) = each %cmpthese ) { + eval $code; + is( $@, $usage{cmpthese}, "cmpthese usage: $name" ); + } + + my %timethese = ('forgot {}' => 'timethese( 42, foo => sub { 1 } )', + 'no code' => 'timethese(42)', + 'array ref' => 'timethese( 42, [ foo => sub { 1 } ] )', + ); + + while( my($name, $code) = each %timethese ) { + eval $code; + is( $@, $usage{timethese}, "timethese usage: $name" ); + } + + + while( my($func, $usage) = each %usage ) { + next if grep $func eq $_, @takes_no_args; + eval "$func()"; + is( $@, $usage, "$func usage: no args" ); + } + + foreach my $func (@takes_no_args) { + eval "$func(42)"; + is( $@, $usage{$func}, "$func usage: with args" ); + } +} + + package TieOut; sub TIEHANDLE {