X-Git-Url: https://perl5.git.perl.org/perl5.git/blobdiff_plain/e5967bfdebacb7d726b3c12bcfbdae225de9e2ff..c1741bad1bfa5215302880114d7b0b580cf8f0c1:/lib/Benchmark.t

diff --git a/lib/Benchmark.t b/lib/Benchmark.t
index 22a91bc..73e09c6 100644
--- a/lib/Benchmark.t
+++ b/lib/Benchmark.t
@@ -2,17 +2,17 @@
 
 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 => 159;
+use Test::More tests => 194;
 
 use Benchmark qw(:all);
 
-my $delta = 0.2;
+my $delta = 0.4;
 
 # Some timing ballast
 sub fib {
@@ -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/;
+# Please don't trust the matching parentheses to be useful in this :-)
+my $Default_Pattern = qr/$All_Pattern|$Noc_Pattern/;
 
 my $t0 = new Benchmark;
 isa_ok ($t0, 'Benchmark', "Ensure we can create a benchmark object");
@@ -42,6 +42,11 @@ is ($foo, 5, "benchmarked code was run 5 times");
 isa_ok(timeit(5, '++$bar'), 'Benchmark', "timeit eval");
 is ($bar, 5, "benchmarked code was run 5 times");
 
+# is coderef called with spurious arguments?
+timeit( 1, sub { $foo = @_ });
+is ($foo, 0, "benchmarked code called without arguments");
+
+
 print "# Burning CPU to benchmark things will take time...\n";
 
 
@@ -59,7 +64,7 @@ my $in_threesecs = $threesecs->iters;
 print "# $in_threesecs iterations\n";
 ok ($in_threesecs > 0, "iters returned positive iterations");
 
-my $estimate = int ($in_threesecs / 3);
+my $estimate = int (100 * $in_threesecs / 3) / 100;
 print "# from the 3 second run estimate $estimate iterations in 1 second...\n";
 $baz = 0;
 my $onesec = countit(1, $coderef);
@@ -69,9 +74,12 @@ my $in_onesec = $onesec->iters;
 print "# $in_onesec iterations\n";
 ok ($in_onesec > 0, "iters returned positive iterations");
 
-my $difference = $in_onesec - $estimate;
-ok (abs ($difference / $in_onesec) < $delta,
-    "is $in_onesec within $delta of estimate ($estimate)");
+{
+  my $difference = $in_onesec - $estimate;
+  my $actual = abs ($difference / $in_onesec);
+  cmp_ok($actual, '<=', $delta, "is $in_onesec within $delta of estimate ($estimate)")
+    or diag("# $in_onesec is between " . ($delta / 2) . " and $delta of estimate. Not that safe.");
+}
 
 # I found that the eval'ed version was 3 times faster than the coderef.
 # (now it has a different ballast value)
@@ -98,12 +106,12 @@ 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");
+    is (timestr ($diff, 'none'), '', "none suppresses output");
 
     my $noc = timestr ($diff, 'noc');
     like ($noc, qr/$wallclock +wallclock secs? +\( *$usr +usr +\+ +$sys +sys += +$cpu +CPU\)/, 'timestr ($diff, "noc")');
@@ -134,7 +142,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);
@@ -145,7 +153,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;
@@ -157,7 +165,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;
@@ -169,7 +177,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;
@@ -214,7 +222,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)}};
@@ -252,10 +295,15 @@ sub check_graph_consistency {
         $slowr, $slowratet, $slowslow, $slowfastt,
         $fastr, $fastratet, $fastslowt, $fastfast)
         = @_;
-    is ($slowc, $slowr, "left col tag should be top row tag");
-    is ($fastc, $fastr, "right col tag should be bottom row tag");
-    like ($slowslow, qr/^-+/, "should be dash for comparing slow with slow");
-    is ($slowslow, $fastfast, "slow v slow should be same as fast v fast");
+    my $all_passed = 1;
+    $all_passed
+      &= is ($slowc, $slowr, "left col tag should be top row tag");
+    $all_passed
+      &= is ($fastc, $fastr, "right col tag should be bottom row tag");
+    $all_passed &=
+      like ($slowslow, qr/^-+/, "should be dash for comparing slow with slow");
+    $all_passed
+      &= is ($slowslow, $fastfast, "slow v slow should be same as fast v fast");
     my $slowrate = $slowratet;
     my $fastrate = $fastratet;
     my ($slow_is_rate, $fast_is_rate);
@@ -268,27 +316,42 @@ sub check_graph_consistency {
         $fastrate = 1/$fastrate if $fastrate;
     }
     if ($ratetext =~ /rate/i) {
-        ok ($slow_is_rate, "slow should be expressed as a rate");
-        ok ($fast_is_rate, "fast should be expressed as a rate");
+        $all_passed
+          &= ok ($slow_is_rate, "slow should be expressed as a rate");
+        $all_passed
+          &= ok ($fast_is_rate, "fast should be expressed as a rate");
     } else {
-        ok (!$slow_is_rate, "slow should be expressed as a iters per second");
-        ok (!$fast_is_rate, "fast should be expressed as a iters per second");
+        $all_passed &=
+          ok (!$slow_is_rate, "slow should be expressed as a iters per second");
+        $all_passed &=
+          ok (!$fast_is_rate, "fast should be expressed as a iters per second");
     }
 
     (my $slowfast = $slowfastt) =~ s!%!!;
     (my $fastslow = $fastslowt) =~ s!%!!;
     if ($slowrate < $fastrate) {
         pass ("slow rate is less than fast rate");
-        ok ($slowfast < 0 && $slowfast > -100,
-            "slowfast should be less than zero, and > -100");
-        ok ($fastslow > 100, "fastslow should be > 100") ||
+        unless (ok ($slowfast <= 0 && $slowfast >= -100,
+                    "slowfast should be less than or equal to zero, and >= -100")) {
+          print STDERR "# slowfast $slowfast\n";
+          $all_passed = 0;
+        }
+        unless (ok ($fastslow > 0, "fastslow should be > 0")) {
           print STDERR "# fastslow $fastslow\n";
+          $all_passed = 0;
+        }
     } else {
-        is ($slowrate, $fastrate,
-            "slow rate isn't less than fast rate, so should be the same");
-        is ($slowfast, 0, "slowfast should be zero");
-        is ($fastslow, 0, "fastslow should be zero");
+        $all_passed
+          &= is ($slowrate, $fastrate,
+                 "slow rate isn't less than fast rate, so should be the same");
+	# In OpenBSD the $slowfast is sometimes a really, really, really
+	# small number less than zero, and this gets stringified as -0.
+        $all_passed
+          &= like ($slowfast, qr/^-?0$/, "slowfast should be zero");
+        $all_passed
+          &= like ($fastslow, qr/^-?0$/, "fastslow should be zero");
     }
+    return $all_passed;
 }
 
 sub check_graph_vs_output {
@@ -297,13 +360,19 @@ sub check_graph_vs_output {
         $slowr, $slowratet, $slowslow, $slowfastt,
         $fastr, $fastratet, $fastslowt, $fastfast)
         = $got =~ $graph_dissassembly;
-    check_graph_consistency (        $ratetext, $slowc, $fastc,
-                             $slowr, $slowratet, $slowslow, $slowfastt,
-                             $fastr, $fastratet, $fastslowt, $fastfast);
-    is_deeply ($chart, [['', $ratetext, $slowc, $fastc],
-                        [$slowr, $slowratet, $slowslow, $slowfastt],
-                        [$fastr, $fastratet, $fastslowt, $fastfast]],
-               "check the chart layout matches the formatted output");
+    my $all_passed
+      = check_graph_consistency (        $ratetext, $slowc, $fastc,
+                                 $slowr, $slowratet, $slowslow, $slowfastt,
+                                 $fastr, $fastratet, $fastslowt, $fastfast);
+    $all_passed
+      &= is_deeply ($chart, [['', $ratetext, $slowc, $fastc],
+                             [$slowr, $slowratet, $slowslow, $slowfastt],
+                             [$fastr, $fastratet, $fastslowt, $fastfast]],
+                    "check the chart layout matches the formatted output");
+    unless ($all_passed) {
+      print STDERR "# Something went wrong there. I got this chart:\n";
+      print STDERR "# $_\n" foreach split /\n/, $got;
+    }
 }
 
 sub check_graph {
@@ -318,7 +387,7 @@ sub check_graph {
 {
     select(OUT);
     my $start = times;
-    my $chart = cmpthese( -0.1, { a => "++\$i", b => "\$i *= 2" } ) ;
+    my $chart = cmpthese( -0.1, { a => "++\$i", b => "\$i = sqrt(\$i++)" }, "auto" ) ;
     my $end = times;
     select(STDOUT);
     ok (($end - $start) > 0.05, "benchmarked code ran for over 0.05 seconds");
@@ -331,7 +400,29 @@ 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);
+}
+
+# Not giving auto should suppress timethese results.
+{
+    select(OUT);
+    my $start = times;
+    my $chart = cmpthese( -0.1, { a => "++\$i", b => "\$i = sqrt(\$i++)" } ) ;
+    my $end = times;
+    select(STDOUT);
+    ok (($end - $start) > 0.05, "benchmarked code ran for over 0.05 seconds");
+
+    $got = $out->read();
+    # Remove any warnings about having too few iterations.
+    $got =~ s/\(warning:[^\)]+\)//gs;
+
+    unlike ($got, qr/running\W+a\W+b.*?for at least 0\.1 CPU second/s,
+          'should not have title');
+    # Remove the title
+    $got =~ s/.*\.\.\.//s;
+    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);
 }
@@ -351,7 +442,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);
 }
@@ -438,30 +529,69 @@ undef $debug;
 untie *STDERR;
 
 # To check the cache we are poking where we don't belong, inside the namespace.
-# The way benchmark is written We can't actually check whehter the cache is
+# The way benchmark is written we can't actually check whether the cache is
 # 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 {