| 1 | #!./perl -w
|
|---|
| 2 |
|
|---|
| 3 | BEGIN {
|
|---|
| 4 | chdir 't' if -d 't';
|
|---|
| 5 | @INC = ('../lib');
|
|---|
| 6 | }
|
|---|
| 7 |
|
|---|
| 8 | use warnings;
|
|---|
| 9 | use strict;
|
|---|
| 10 | use vars qw($foo $bar $baz $ballast);
|
|---|
| 11 | use Test::More tests => 194;
|
|---|
| 12 |
|
|---|
| 13 | use Benchmark qw(:all);
|
|---|
| 14 |
|
|---|
| 15 | my $delta = 0.4;
|
|---|
| 16 |
|
|---|
| 17 | # Some timing ballast
|
|---|
| 18 | sub fib {
|
|---|
| 19 | my $n = shift;
|
|---|
| 20 | return $n if $n < 2;
|
|---|
| 21 | fib($n-1) + fib($n-2);
|
|---|
| 22 | }
|
|---|
| 23 | $ballast = 15;
|
|---|
| 24 |
|
|---|
| 25 | my $All_Pattern =
|
|---|
| 26 | qr/(\d+) +wallclock secs? +\( *(-?\d+\.\d\d) +usr +(-?\d+\.\d\d) +sys +\+ +(-?\d+\.\d\d) +cusr +(-?\d+\.\d\d) +csys += +(-?\d+\.\d\d) +CPU\)/;
|
|---|
| 27 | my $Noc_Pattern =
|
|---|
| 28 | qr/(\d+) +wallclock secs? +\( *(-?\d+\.\d\d) +usr +\+ +(-?\d+\.\d\d) +sys += +(-?\d+\.\d\d) +CPU\)/;
|
|---|
| 29 | my $Nop_Pattern =
|
|---|
| 30 | qr/(\d+) +wallclock secs? +\( *(-?\d+\.\d\d) +cusr +\+ +(-?\d+\.\d\d) +csys += +\d+\.\d\d +CPU\)/;
|
|---|
| 31 | # Please don't trust the matching parenthises to be useful in this :-)
|
|---|
| 32 | my $Default_Pattern = qr/$All_Pattern|$Noc_Pattern/;
|
|---|
| 33 |
|
|---|
| 34 | my $t0 = new Benchmark;
|
|---|
| 35 | isa_ok ($t0, 'Benchmark', "Ensure we can create a benchmark object");
|
|---|
| 36 |
|
|---|
| 37 | # We use the benchmark object once we've done some work:
|
|---|
| 38 |
|
|---|
| 39 | isa_ok(timeit(5, sub {++$foo}), 'Benchmark', "timeit CODEREF");
|
|---|
| 40 | is ($foo, 5, "benchmarked code was run 5 times");
|
|---|
| 41 |
|
|---|
| 42 | isa_ok(timeit(5, '++$bar'), 'Benchmark', "timeit eval");
|
|---|
| 43 | is ($bar, 5, "benchmarked code was run 5 times");
|
|---|
| 44 |
|
|---|
| 45 | # is coderef called with spurious arguments?
|
|---|
| 46 | timeit( 1, sub { $foo = @_ });
|
|---|
| 47 | is ($foo, 0, "benchmarked code called without arguments");
|
|---|
| 48 |
|
|---|
| 49 |
|
|---|
| 50 | print "# Burning CPU to benchmark things will take time...\n";
|
|---|
| 51 |
|
|---|
| 52 |
|
|---|
| 53 |
|
|---|
| 54 | # We need to do something fairly slow in the coderef.
|
|---|
| 55 | # Same coderef. Same place in memory.
|
|---|
| 56 | my $coderef = sub {$baz += fib($ballast)};
|
|---|
| 57 |
|
|---|
| 58 | # The default is three.
|
|---|
| 59 | $baz = 0;
|
|---|
| 60 | my $threesecs = countit(0, $coderef);
|
|---|
| 61 | isa_ok($threesecs, 'Benchmark', "countit 0, CODEREF");
|
|---|
| 62 | isnt ($baz, 0, "benchmarked code was run");
|
|---|
| 63 | my $in_threesecs = $threesecs->iters;
|
|---|
| 64 | print "# $in_threesecs iterations\n";
|
|---|
| 65 | ok ($in_threesecs > 0, "iters returned positive iterations");
|
|---|
| 66 |
|
|---|
| 67 | my $estimate = int (100 * $in_threesecs / 3) / 100;
|
|---|
| 68 | print "# from the 3 second run estimate $estimate iterations in 1 second...\n";
|
|---|
| 69 | $baz = 0;
|
|---|
| 70 | my $onesec = countit(1, $coderef);
|
|---|
| 71 | isa_ok($onesec, 'Benchmark', "countit 1, CODEREF");
|
|---|
| 72 | isnt ($baz, 0, "benchmarked code was run");
|
|---|
| 73 | my $in_onesec = $onesec->iters;
|
|---|
| 74 | print "# $in_onesec iterations\n";
|
|---|
| 75 | ok ($in_onesec > 0, "iters returned positive iterations");
|
|---|
| 76 |
|
|---|
| 77 | {
|
|---|
| 78 | my $difference = $in_onesec - $estimate;
|
|---|
| 79 | my $actual = abs ($difference / $in_onesec);
|
|---|
| 80 | ok ($actual < $delta, "is $in_onesec within $delta of estimate ($estimate)");
|
|---|
| 81 | print "# $in_onesec is between " . ($delta / 2) .
|
|---|
| 82 | " and $delta of estimate. Not that safe.\n" if $actual > $delta/2;
|
|---|
| 83 | }
|
|---|
| 84 |
|
|---|
| 85 | # I found that the eval'ed version was 3 times faster than the coderef.
|
|---|
| 86 | # (now it has a different ballast value)
|
|---|
| 87 | $baz = 0;
|
|---|
| 88 | my $again = countit(1, '$baz += fib($ballast)');
|
|---|
| 89 | isa_ok($onesec, 'Benchmark', "countit 1, eval");
|
|---|
| 90 | isnt ($baz, 0, "benchmarked code was run");
|
|---|
| 91 | my $in_again = $again->iters;
|
|---|
| 92 | print "# $in_again iterations\n";
|
|---|
| 93 | ok ($in_again > 0, "iters returned positive iterations");
|
|---|
| 94 |
|
|---|
| 95 |
|
|---|
| 96 | my $t1 = new Benchmark;
|
|---|
| 97 | isa_ok ($t1, 'Benchmark', "Create another benchmark object now we're finished");
|
|---|
| 98 |
|
|---|
| 99 | my $diff = timediff ($t1, $t0);
|
|---|
| 100 | isa_ok ($diff, 'Benchmark', "Get the time difference");
|
|---|
| 101 | isa_ok (timesum ($t0, $t1), 'Benchmark', "check timesum");
|
|---|
| 102 |
|
|---|
| 103 | my $default = timestr ($diff);
|
|---|
| 104 | isnt ($default, '', 'timestr ($diff)');
|
|---|
| 105 | my $auto = timestr ($diff, 'auto');
|
|---|
| 106 | is ($auto, $default, 'timestr ($diff, "auto") matches timestr ($diff)');
|
|---|
| 107 |
|
|---|
| 108 | {
|
|---|
| 109 | my $all = timestr ($diff, 'all');
|
|---|
| 110 | like ($all, $All_Pattern, 'timestr ($diff, "all")');
|
|---|
| 111 | print "# $all\n";
|
|---|
| 112 |
|
|---|
| 113 | my ($wallclock, $usr, $sys, $cusr, $csys, $cpu) = $all =~ $All_Pattern;
|
|---|
| 114 |
|
|---|
| 115 | is (timestr ($diff, 'none'), '', "none supresses output");
|
|---|
| 116 |
|
|---|
| 117 | my $noc = timestr ($diff, 'noc');
|
|---|
| 118 | like ($noc, qr/$wallclock +wallclock secs? +\( *$usr +usr +\+ +$sys +sys += +$cpu +CPU\)/, 'timestr ($diff, "noc")');
|
|---|
| 119 |
|
|---|
| 120 | my $nop = timestr ($diff, 'nop');
|
|---|
| 121 | like ($nop, qr/$wallclock +wallclock secs? +\( *$cusr +cusr +\+ +$csys +csys += +\d+\.\d\d +CPU\)/, 'timestr ($diff, "nop")');
|
|---|
| 122 |
|
|---|
| 123 | if ($auto eq $noc) {
|
|---|
| 124 | pass ('"auto" is "noc"');
|
|---|
| 125 | } else {
|
|---|
| 126 | is ($auto, $all, '"auto" isn\'t "noc", so should be eq to "all"');
|
|---|
| 127 | }
|
|---|
| 128 |
|
|---|
| 129 | like (timestr ($diff, 'all', 'E'),
|
|---|
| 130 | qr/(\d+) +wallclock secs? +\( *\d\.\d+E[-+]?\d\d\d? +usr +\d\.\d+E[-+]?\d\d\d? +sys +\+ +\d\.\d+E[-+]?\d\d\d? +cusr +\d\.\d+E[-+]?\d\d\d? +csys += +\d\.\d+E[-+]?\d\d\d? +CPU\)/, 'timestr ($diff, "all", "E") [sprintf format of "E"]');
|
|---|
| 131 | }
|
|---|
| 132 |
|
|---|
| 133 | my $out = tie *OUT, 'TieOut';
|
|---|
| 134 |
|
|---|
| 135 | my $iterations = 3;
|
|---|
| 136 |
|
|---|
| 137 | $foo = 0;
|
|---|
| 138 | select(OUT);
|
|---|
| 139 | my $got = timethis($iterations, sub {++$foo});
|
|---|
| 140 | select(STDOUT);
|
|---|
| 141 | isa_ok($got, 'Benchmark', "timethis CODEREF");
|
|---|
| 142 | is ($foo, $iterations, "benchmarked code was run $iterations times");
|
|---|
| 143 |
|
|---|
| 144 | $got = $out->read();
|
|---|
| 145 | like ($got, qr/^timethis $iterations/, 'default title');
|
|---|
| 146 | like ($got, $Default_Pattern, 'default format is all or noc');
|
|---|
| 147 |
|
|---|
| 148 | $bar = 0;
|
|---|
| 149 | select(OUT);
|
|---|
| 150 | $got = timethis($iterations, '++$bar');
|
|---|
| 151 | select(STDOUT);
|
|---|
| 152 | isa_ok($got, 'Benchmark', "timethis eval");
|
|---|
| 153 | is ($bar, $iterations, "benchmarked code was run $iterations times");
|
|---|
| 154 |
|
|---|
| 155 | $got = $out->read();
|
|---|
| 156 | like ($got, qr/^timethis $iterations/, 'default title');
|
|---|
| 157 | like ($got, $Default_Pattern, 'default format is all or noc');
|
|---|
| 158 |
|
|---|
| 159 | my $title = 'lies, damn lies and benchmarks';
|
|---|
| 160 | $foo = 0;
|
|---|
| 161 | select(OUT);
|
|---|
| 162 | $got = timethis($iterations, sub {++$foo}, $title);
|
|---|
| 163 | select(STDOUT);
|
|---|
| 164 | isa_ok($got, 'Benchmark', "timethis with title");
|
|---|
| 165 | is ($foo, $iterations, "benchmarked code was run $iterations times");
|
|---|
| 166 |
|
|---|
| 167 | $got = $out->read();
|
|---|
| 168 | like ($got, qr/^$title:/, 'specify title');
|
|---|
| 169 | like ($got, $Default_Pattern, 'default format is all or noc');
|
|---|
| 170 |
|
|---|
| 171 | # default is auto, which is all or noc. nop can never match the default
|
|---|
| 172 | $foo = 0;
|
|---|
| 173 | select(OUT);
|
|---|
| 174 | $got = timethis($iterations, sub {++$foo}, $title, 'nop');
|
|---|
| 175 | select(STDOUT);
|
|---|
| 176 | isa_ok($got, 'Benchmark', "timethis with format");
|
|---|
| 177 | is ($foo, $iterations, "benchmarked code was run $iterations times");
|
|---|
| 178 |
|
|---|
| 179 | $got = $out->read();
|
|---|
| 180 | like ($got, qr/^$title:/, 'specify title');
|
|---|
| 181 | like ($got, $Nop_Pattern, 'specify format as nop');
|
|---|
| 182 |
|
|---|
| 183 | {
|
|---|
| 184 | $foo = 0;
|
|---|
| 185 | select(OUT);
|
|---|
| 186 | my $start = time;
|
|---|
| 187 | $got = timethis(-2, sub {$foo+= fib($ballast)}, $title, 'none');
|
|---|
| 188 | my $end = time;
|
|---|
| 189 | select(STDOUT);
|
|---|
| 190 | isa_ok($got, 'Benchmark',
|
|---|
| 191 | "timethis, at least 2 seconds with format 'none'");
|
|---|
| 192 | ok ($foo > 0, "benchmarked code was run");
|
|---|
| 193 | ok ($end - $start > 1, "benchmarked code ran for over 1 second");
|
|---|
| 194 |
|
|---|
| 195 | $got = $out->read();
|
|---|
| 196 | # Remove any warnings about having too few iterations.
|
|---|
| 197 | $got =~ s/\(warning:[^\)]+\)//gs;
|
|---|
| 198 | $got =~ s/^[ \t\n]+//s; # Remove all the whitespace from the beginning
|
|---|
| 199 |
|
|---|
| 200 | is ($got, '', "format 'none' should suppress output");
|
|---|
| 201 | }
|
|---|
| 202 |
|
|---|
| 203 | $foo = $bar = $baz = 0;
|
|---|
| 204 | select(OUT);
|
|---|
| 205 | $got = timethese($iterations, { Foo => sub {++$foo}, Bar => '++$bar',
|
|---|
| 206 | Baz => sub {++$baz} });
|
|---|
| 207 | select(STDOUT);
|
|---|
| 208 | is(ref ($got), 'HASH', "timethese should return a hashref");
|
|---|
| 209 | isa_ok($got->{Foo}, 'Benchmark', "Foo value");
|
|---|
| 210 | isa_ok($got->{Bar}, 'Benchmark', "Bar value");
|
|---|
| 211 | isa_ok($got->{Baz}, 'Benchmark', "Baz value");
|
|---|
| 212 | eq_set([keys %$got], [qw(Foo Bar Baz)], 'should be exactly three objects');
|
|---|
| 213 | is ($foo, $iterations, "Foo code was run $iterations times");
|
|---|
| 214 | is ($bar, $iterations, "Bar code was run $iterations times");
|
|---|
| 215 | is ($baz, $iterations, "Baz code was run $iterations times");
|
|---|
| 216 |
|
|---|
| 217 | $got = $out->read();
|
|---|
| 218 | # Remove any warnings about having too few iterations.
|
|---|
| 219 | $got =~ s/\(warning:[^\)]+\)//gs;
|
|---|
| 220 |
|
|---|
| 221 | like ($got, qr/timing $iterations iterations of\s+Bar\W+Baz\W+Foo\W*?\.\.\./s,
|
|---|
| 222 | 'check title');
|
|---|
| 223 | # Remove the title
|
|---|
| 224 | $got =~ s/.*\.\.\.//s;
|
|---|
| 225 | like ($got, qr/\bBar\b.*\bBaz\b.*\bFoo\b/s, 'check output is in sorted order');
|
|---|
| 226 | like ($got, $Default_Pattern, 'should find default format somewhere');
|
|---|
| 227 |
|
|---|
| 228 |
|
|---|
| 229 | { # ensure 'use strict' does not leak from Benchmark.pm into benchmarked code
|
|---|
| 230 | no strict;
|
|---|
| 231 | select OUT;
|
|---|
| 232 |
|
|---|
| 233 | eval {
|
|---|
| 234 | timethese( 1,
|
|---|
| 235 | { undeclared_var => q{ $i++; $i-- },
|
|---|
| 236 | symbolic_ref => q{ $bar = 42;
|
|---|
| 237 | $foo = 'bar';
|
|---|
| 238 | $q = ${$foo} },
|
|---|
| 239 | },
|
|---|
| 240 | 'none'
|
|---|
| 241 | );
|
|---|
| 242 |
|
|---|
| 243 | };
|
|---|
| 244 | is( $@, '', q{no strict leakage in name => 'code'} );
|
|---|
| 245 |
|
|---|
| 246 | eval {
|
|---|
| 247 | timethese( 1,
|
|---|
| 248 | { undeclared_var => sub { $i++; $i-- },
|
|---|
| 249 | symbolic_ref => sub { $bar = 42;
|
|---|
| 250 | $foo = 'bar';
|
|---|
| 251 | return ${$foo} },
|
|---|
| 252 | },
|
|---|
| 253 | 'none'
|
|---|
| 254 | );
|
|---|
| 255 | };
|
|---|
| 256 | is( $@, '', q{no strict leakage in name => sub { code }} );
|
|---|
| 257 |
|
|---|
| 258 | # clear out buffer
|
|---|
| 259 | $out->read;
|
|---|
| 260 | }
|
|---|
| 261 |
|
|---|
| 262 |
|
|---|
| 263 | my $code_to_test = { Foo => sub {$foo+=fib($ballast-2)},
|
|---|
| 264 | Bar => sub {$bar+=fib($ballast)}};
|
|---|
| 265 | # Keep these for later.
|
|---|
| 266 | my $results;
|
|---|
| 267 | {
|
|---|
| 268 | $foo = $bar = 0;
|
|---|
| 269 | select(OUT);
|
|---|
| 270 | my $start = times;
|
|---|
| 271 | $results = timethese(-0.1, $code_to_test, 'none');
|
|---|
| 272 | my $end = times;
|
|---|
| 273 | select(STDOUT);
|
|---|
| 274 |
|
|---|
| 275 | is(ref ($results), 'HASH', "timethese should return a hashref");
|
|---|
| 276 | isa_ok($results->{Foo}, 'Benchmark', "Foo value");
|
|---|
| 277 | isa_ok($results->{Bar}, 'Benchmark', "Bar value");
|
|---|
| 278 | eq_set([keys %$results], [qw(Foo Bar)], 'should be exactly two objects');
|
|---|
| 279 | ok ($foo > 0, "Foo code was run");
|
|---|
| 280 | ok ($bar > 0, "Bar code was run");
|
|---|
| 281 |
|
|---|
| 282 | ok (($end - $start) > 0.1, "benchmarked code ran for over 0.1 seconds");
|
|---|
| 283 |
|
|---|
| 284 | $got = $out->read();
|
|---|
| 285 | # Remove any warnings about having too few iterations.
|
|---|
| 286 | $got =~ s/\(warning:[^\)]+\)//gs;
|
|---|
| 287 | is ($got =~ tr/ \t\n//c, 0, "format 'none' should suppress output");
|
|---|
| 288 | }
|
|---|
| 289 | my $graph_dissassembly =
|
|---|
| 290 | qr!^[ \t]+(\S+)[ \t]+(\w+)[ \t]+(\w+)[ \t]* # Title line
|
|---|
| 291 | \n[ \t]*(\w+)[ \t]+([0-9.]+(?:/s)?)[ \t]+(-+)[ \t]+(-?\d+%)[ \t]*
|
|---|
| 292 | \n[ \t]*(\w+)[ \t]+([0-9.]+(?:/s)?)[ \t]+(-?\d+%)[ \t]+(-+)[ \t]*$!xm;
|
|---|
| 293 |
|
|---|
| 294 | sub check_graph_consistency {
|
|---|
| 295 | my ( $ratetext, $slowc, $fastc,
|
|---|
| 296 | $slowr, $slowratet, $slowslow, $slowfastt,
|
|---|
| 297 | $fastr, $fastratet, $fastslowt, $fastfast)
|
|---|
| 298 | = @_;
|
|---|
| 299 | my $all_passed = 1;
|
|---|
| 300 | $all_passed
|
|---|
| 301 | &= is ($slowc, $slowr, "left col tag should be top row tag");
|
|---|
| 302 | $all_passed
|
|---|
| 303 | &= is ($fastc, $fastr, "right col tag should be bottom row tag");
|
|---|
| 304 | $all_passed &=
|
|---|
| 305 | like ($slowslow, qr/^-+/, "should be dash for comparing slow with slow");
|
|---|
| 306 | $all_passed
|
|---|
| 307 | &= is ($slowslow, $fastfast, "slow v slow should be same as fast v fast");
|
|---|
| 308 | my $slowrate = $slowratet;
|
|---|
| 309 | my $fastrate = $fastratet;
|
|---|
| 310 | my ($slow_is_rate, $fast_is_rate);
|
|---|
| 311 | unless ($slow_is_rate = $slowrate =~ s!/s!!) {
|
|---|
| 312 | # Slow is expressed as iters per second.
|
|---|
| 313 | $slowrate = 1/$slowrate if $slowrate;
|
|---|
| 314 | }
|
|---|
| 315 | unless ($fast_is_rate = $fastrate =~ s!/s!!) {
|
|---|
| 316 | # Fast is expressed as iters per second.
|
|---|
| 317 | $fastrate = 1/$fastrate if $fastrate;
|
|---|
| 318 | }
|
|---|
| 319 | if ($ratetext =~ /rate/i) {
|
|---|
| 320 | $all_passed
|
|---|
| 321 | &= ok ($slow_is_rate, "slow should be expressed as a rate");
|
|---|
| 322 | $all_passed
|
|---|
| 323 | &= ok ($fast_is_rate, "fast should be expressed as a rate");
|
|---|
| 324 | } else {
|
|---|
| 325 | $all_passed &=
|
|---|
| 326 | ok (!$slow_is_rate, "slow should be expressed as a iters per second");
|
|---|
| 327 | $all_passed &=
|
|---|
| 328 | ok (!$fast_is_rate, "fast should be expressed as a iters per second");
|
|---|
| 329 | }
|
|---|
| 330 |
|
|---|
| 331 | (my $slowfast = $slowfastt) =~ s!%!!;
|
|---|
| 332 | (my $fastslow = $fastslowt) =~ s!%!!;
|
|---|
| 333 | if ($slowrate < $fastrate) {
|
|---|
| 334 | pass ("slow rate is less than fast rate");
|
|---|
| 335 | unless (ok ($slowfast <= 0 && $slowfast >= -100,
|
|---|
| 336 | "slowfast should be less than or equal to zero, and >= -100")) {
|
|---|
| 337 | print STDERR "# slowfast $slowfast\n";
|
|---|
| 338 | $all_passed = 0;
|
|---|
| 339 | }
|
|---|
| 340 | unless (ok ($fastslow > 0, "fastslow should be > 0")) {
|
|---|
| 341 | print STDERR "# fastslow $fastslow\n";
|
|---|
| 342 | $all_passed = 0;
|
|---|
| 343 | }
|
|---|
| 344 | } else {
|
|---|
| 345 | $all_passed
|
|---|
| 346 | &= is ($slowrate, $fastrate,
|
|---|
| 347 | "slow rate isn't less than fast rate, so should be the same");
|
|---|
| 348 | # In OpenBSD the $slowfast is sometimes a really, really, really
|
|---|
| 349 | # small number less than zero, and this gets stringified as -0.
|
|---|
| 350 | $all_passed
|
|---|
| 351 | &= like ($slowfast, qr/^-?0$/, "slowfast should be zero");
|
|---|
| 352 | $all_passed
|
|---|
| 353 | &= like ($fastslow, qr/^-?0$/, "fastslow should be zero");
|
|---|
| 354 | }
|
|---|
| 355 | return $all_passed;
|
|---|
| 356 | }
|
|---|
| 357 |
|
|---|
| 358 | sub check_graph_vs_output {
|
|---|
| 359 | my ($chart, $got) = @_;
|
|---|
| 360 | my ( $ratetext, $slowc, $fastc,
|
|---|
| 361 | $slowr, $slowratet, $slowslow, $slowfastt,
|
|---|
| 362 | $fastr, $fastratet, $fastslowt, $fastfast)
|
|---|
| 363 | = $got =~ $graph_dissassembly;
|
|---|
| 364 | my $all_passed
|
|---|
| 365 | = check_graph_consistency ( $ratetext, $slowc, $fastc,
|
|---|
| 366 | $slowr, $slowratet, $slowslow, $slowfastt,
|
|---|
| 367 | $fastr, $fastratet, $fastslowt, $fastfast);
|
|---|
| 368 | $all_passed
|
|---|
| 369 | &= is_deeply ($chart, [['', $ratetext, $slowc, $fastc],
|
|---|
| 370 | [$slowr, $slowratet, $slowslow, $slowfastt],
|
|---|
| 371 | [$fastr, $fastratet, $fastslowt, $fastfast]],
|
|---|
| 372 | "check the chart layout matches the formatted output");
|
|---|
| 373 | unless ($all_passed) {
|
|---|
| 374 | print STDERR "# Something went wrong there. I got this chart:\n";
|
|---|
| 375 | print STDERR "# $_\n" foreach split /\n/, $got;
|
|---|
| 376 | }
|
|---|
| 377 | }
|
|---|
| 378 |
|
|---|
| 379 | sub check_graph {
|
|---|
| 380 | my ($title, $row1, $row2) = @_;
|
|---|
| 381 | is (scalar @$title, 4, "Four entries in title row");
|
|---|
| 382 | is (scalar @$row1, 4, "Four entries in first row");
|
|---|
| 383 | is (scalar @$row2, 4, "Four entries in second row");
|
|---|
| 384 | is (shift @$title, '', "First entry of output graph should be ''");
|
|---|
| 385 | check_graph_consistency (@$title, @$row1, @$row2);
|
|---|
| 386 | }
|
|---|
| 387 |
|
|---|
| 388 | {
|
|---|
| 389 | select(OUT);
|
|---|
| 390 | my $start = times;
|
|---|
| 391 | my $chart = cmpthese( -0.1, { a => "++\$i", b => "\$i = sqrt(\$i++)" }, "auto" ) ;
|
|---|
| 392 | my $end = times;
|
|---|
| 393 | select(STDOUT);
|
|---|
| 394 | ok (($end - $start) > 0.05, "benchmarked code ran for over 0.05 seconds");
|
|---|
| 395 |
|
|---|
| 396 | $got = $out->read();
|
|---|
| 397 | # Remove any warnings about having too few iterations.
|
|---|
| 398 | $got =~ s/\(warning:[^\)]+\)//gs;
|
|---|
| 399 |
|
|---|
| 400 | like ($got, qr/running\W+a\W+b.*?for at least 0\.1 CPU second/s,
|
|---|
| 401 | 'check title');
|
|---|
| 402 | # Remove the title
|
|---|
| 403 | $got =~ s/.*\.\.\.//s;
|
|---|
| 404 | like ($got, $Default_Pattern, 'should find default format somewhere');
|
|---|
| 405 | like ($got, $graph_dissassembly, "Should find the output graph somewhere");
|
|---|
| 406 | check_graph_vs_output ($chart, $got);
|
|---|
| 407 | }
|
|---|
| 408 |
|
|---|
| 409 | # Not giving auto should suppress timethese results.
|
|---|
| 410 | {
|
|---|
| 411 | select(OUT);
|
|---|
| 412 | my $start = times;
|
|---|
| 413 | my $chart = cmpthese( -0.1, { a => "++\$i", b => "\$i = sqrt(\$i++)" } ) ;
|
|---|
| 414 | my $end = times;
|
|---|
| 415 | select(STDOUT);
|
|---|
| 416 | ok (($end - $start) > 0.05, "benchmarked code ran for over 0.05 seconds");
|
|---|
| 417 |
|
|---|
| 418 | $got = $out->read();
|
|---|
| 419 | # Remove any warnings about having too few iterations.
|
|---|
| 420 | $got =~ s/\(warning:[^\)]+\)//gs;
|
|---|
| 421 |
|
|---|
| 422 | unlike ($got, qr/running\W+a\W+b.*?for at least 0\.1 CPU second/s,
|
|---|
| 423 | 'should not have title');
|
|---|
| 424 | # Remove the title
|
|---|
| 425 | $got =~ s/.*\.\.\.//s;
|
|---|
| 426 | unlike ($got, $Default_Pattern, 'should not find default format somewhere');
|
|---|
| 427 | like ($got, $graph_dissassembly, "Should find the output graph somewhere");
|
|---|
| 428 | check_graph_vs_output ($chart, $got);
|
|---|
| 429 | }
|
|---|
| 430 |
|
|---|
| 431 | {
|
|---|
| 432 | $foo = $bar = 0;
|
|---|
| 433 | select(OUT);
|
|---|
| 434 | my $chart = cmpthese( 10, $code_to_test, 'nop' ) ;
|
|---|
| 435 | select(STDOUT);
|
|---|
| 436 | ok ($foo > 0, "Foo code was run");
|
|---|
| 437 | ok ($bar > 0, "Bar code was run");
|
|---|
| 438 |
|
|---|
| 439 | $got = $out->read();
|
|---|
| 440 | # Remove any warnings about having too few iterations.
|
|---|
| 441 | $got =~ s/\(warning:[^\)]+\)//gs;
|
|---|
| 442 | like ($got, qr/timing 10 iterations of\s+Bar\W+Foo\W*?\.\.\./s,
|
|---|
| 443 | 'check title');
|
|---|
| 444 | # Remove the title
|
|---|
| 445 | $got =~ s/.*\.\.\.//s;
|
|---|
| 446 | like ($got, $Nop_Pattern, 'specify format as nop');
|
|---|
| 447 | like ($got, $graph_dissassembly, "Should find the output graph somewhere");
|
|---|
| 448 | check_graph_vs_output ($chart, $got);
|
|---|
| 449 | }
|
|---|
| 450 |
|
|---|
| 451 | {
|
|---|
| 452 | $foo = $bar = 0;
|
|---|
| 453 | select(OUT);
|
|---|
| 454 | my $chart = cmpthese( 10, $code_to_test, 'none' ) ;
|
|---|
| 455 | select(STDOUT);
|
|---|
| 456 | ok ($foo > 0, "Foo code was run");
|
|---|
| 457 | ok ($bar > 0, "Bar code was run");
|
|---|
| 458 |
|
|---|
| 459 | $got = $out->read();
|
|---|
| 460 | # Remove any warnings about having too few iterations.
|
|---|
| 461 | $got =~ s/\(warning:[^\)]+\)//gs;
|
|---|
| 462 | $got =~ s/^[ \t\n]+//s; # Remove all the whitespace from the beginning
|
|---|
| 463 | is ($got, '', "format 'none' should suppress output");
|
|---|
| 464 | is (ref $chart, 'ARRAY', "output should be an array ref");
|
|---|
| 465 | # Some of these will go bang if the preceding test fails. There will be
|
|---|
| 466 | # a big clue as to why, from the previous test's diagnostic
|
|---|
| 467 | is (ref $chart->[0], 'ARRAY', "output should be an array of arrays");
|
|---|
| 468 | check_graph (@$chart);
|
|---|
| 469 | }
|
|---|
| 470 |
|
|---|
| 471 | {
|
|---|
| 472 | $foo = $bar = 0;
|
|---|
| 473 | select(OUT);
|
|---|
| 474 | my $chart = cmpthese( $results ) ;
|
|---|
| 475 | select(STDOUT);
|
|---|
| 476 | is ($foo, 0, "Foo code was not run");
|
|---|
| 477 | is ($bar, 0, "Bar code was not run");
|
|---|
| 478 |
|
|---|
| 479 | $got = $out->read();
|
|---|
| 480 | ok ($got !~ /\.\.\./s, 'check that there is no title');
|
|---|
| 481 | like ($got, $graph_dissassembly, "Should find the output graph somewhere");
|
|---|
| 482 | check_graph_vs_output ($chart, $got);
|
|---|
| 483 | }
|
|---|
| 484 |
|
|---|
| 485 | {
|
|---|
| 486 | $foo = $bar = 0;
|
|---|
| 487 | select(OUT);
|
|---|
| 488 | my $chart = cmpthese( $results, 'none' ) ;
|
|---|
| 489 | select(STDOUT);
|
|---|
| 490 | is ($foo, 0, "Foo code was not run");
|
|---|
| 491 | is ($bar, 0, "Bar code was not run");
|
|---|
| 492 |
|
|---|
| 493 | $got = $out->read();
|
|---|
| 494 | is ($got, '', "'none' should suppress all output");
|
|---|
| 495 | is (ref $chart, 'ARRAY', "output should be an array ref");
|
|---|
| 496 | # Some of these will go bang if the preceding test fails. There will be
|
|---|
| 497 | # a big clue as to why, from the previous test's diagnostic
|
|---|
| 498 | is (ref $chart->[0], 'ARRAY', "output should be an array of arrays");
|
|---|
| 499 | check_graph (@$chart);
|
|---|
| 500 | }
|
|---|
| 501 |
|
|---|
| 502 | ###}my $out = tie *OUT, 'TieOut'; my ($got); ###
|
|---|
| 503 |
|
|---|
| 504 | my $debug = tie *STDERR, 'TieOut';
|
|---|
| 505 |
|
|---|
| 506 | $bar = 0;
|
|---|
| 507 | isa_ok(timeit(5, '++$bar'), 'Benchmark', "timeit eval");
|
|---|
| 508 | is ($bar, 5, "benchmarked code was run 5 times");
|
|---|
| 509 | is ($debug->read(), '', "There was no debug output");
|
|---|
| 510 |
|
|---|
| 511 | Benchmark->debug(1);
|
|---|
| 512 |
|
|---|
| 513 | $bar = 0;
|
|---|
| 514 | select(OUT);
|
|---|
| 515 | $got = timeit(5, '++$bar');
|
|---|
| 516 | select(STDOUT);
|
|---|
| 517 | isa_ok($got, 'Benchmark', "timeit eval");
|
|---|
| 518 | is ($bar, 5, "benchmarked code was run 5 times");
|
|---|
| 519 | is ($out->read(), '', "There was no STDOUT output with debug enabled");
|
|---|
| 520 | isnt ($debug->read(), '', "There was STDERR debug output with debug enabled");
|
|---|
| 521 |
|
|---|
| 522 | Benchmark->debug(0);
|
|---|
| 523 |
|
|---|
| 524 | $bar = 0;
|
|---|
| 525 | isa_ok(timeit(5, '++$bar'), 'Benchmark', "timeit eval");
|
|---|
| 526 | is ($bar, 5, "benchmarked code was run 5 times");
|
|---|
| 527 | is ($debug->read(), '', "There was no debug output debug disabled");
|
|---|
| 528 |
|
|---|
| 529 | undef $debug;
|
|---|
| 530 | untie *STDERR;
|
|---|
| 531 |
|
|---|
| 532 | # To check the cache we are poking where we don't belong, inside the namespace.
|
|---|
| 533 | # The way benchmark is written We can't actually check whehter the cache is
|
|---|
| 534 | # being used, merely what's become cached.
|
|---|
| 535 |
|
|---|
| 536 | clearallcache();
|
|---|
| 537 | my @before_keys = keys %Benchmark::Cache;
|
|---|
| 538 | $bar = 0;
|
|---|
| 539 | isa_ok(timeit(5, '++$bar'), 'Benchmark', "timeit eval");
|
|---|
| 540 | is ($bar, 5, "benchmarked code was run 5 times");
|
|---|
| 541 | my @after5_keys = keys %Benchmark::Cache;
|
|---|
| 542 | $bar = 0;
|
|---|
| 543 | isa_ok(timeit(10, '++$bar'), 'Benchmark', "timeit eval");
|
|---|
| 544 | is ($bar, 10, "benchmarked code was run 10 times");
|
|---|
| 545 | ok (!eq_array ([keys %Benchmark::Cache], \@after5_keys), "10 differs from 5");
|
|---|
| 546 |
|
|---|
| 547 | clearcache(10);
|
|---|
| 548 | # Hash key order will be the same if there are the same keys.
|
|---|
| 549 | is_deeply ([keys %Benchmark::Cache], \@after5_keys,
|
|---|
| 550 | "cleared 10, only cached results for 5 should remain");
|
|---|
| 551 |
|
|---|
| 552 | clearallcache();
|
|---|
| 553 | is_deeply ([keys %Benchmark::Cache], \@before_keys,
|
|---|
| 554 | "back to square 1 when we clear the cache again?");
|
|---|
| 555 |
|
|---|
| 556 |
|
|---|
| 557 | { # Check usage error messages
|
|---|
| 558 | my %usage = %Benchmark::_Usage;
|
|---|
| 559 | delete $usage{runloop}; # not public, not worrying about it just now
|
|---|
| 560 |
|
|---|
| 561 | my @takes_no_args = qw(clearallcache disablecache enablecache);
|
|---|
| 562 |
|
|---|
| 563 | my %cmpthese = ('forgot {}' => 'cmpthese( 42, foo => sub { 1 } )',
|
|---|
| 564 | 'not result' => 'cmpthese(42)',
|
|---|
| 565 | 'array ref' => 'cmpthese( 42, [ foo => sub { 1 } ] )',
|
|---|
| 566 | );
|
|---|
| 567 | while( my($name, $code) = each %cmpthese ) {
|
|---|
| 568 | eval $code;
|
|---|
| 569 | is( $@, $usage{cmpthese}, "cmpthese usage: $name" );
|
|---|
| 570 | }
|
|---|
| 571 |
|
|---|
| 572 | my %timethese = ('forgot {}' => 'timethese( 42, foo => sub { 1 } )',
|
|---|
| 573 | 'no code' => 'timethese(42)',
|
|---|
| 574 | 'array ref' => 'timethese( 42, [ foo => sub { 1 } ] )',
|
|---|
| 575 | );
|
|---|
| 576 |
|
|---|
| 577 | while( my($name, $code) = each %timethese ) {
|
|---|
| 578 | eval $code;
|
|---|
| 579 | is( $@, $usage{timethese}, "timethese usage: $name" );
|
|---|
| 580 | }
|
|---|
| 581 |
|
|---|
| 582 |
|
|---|
| 583 | while( my($func, $usage) = each %usage ) {
|
|---|
| 584 | next if grep $func eq $_, @takes_no_args;
|
|---|
| 585 | eval "$func()";
|
|---|
| 586 | is( $@, $usage, "$func usage: no args" );
|
|---|
| 587 | }
|
|---|
| 588 |
|
|---|
| 589 | foreach my $func (@takes_no_args) {
|
|---|
| 590 | eval "$func(42)";
|
|---|
| 591 | is( $@, $usage{$func}, "$func usage: with args" );
|
|---|
| 592 | }
|
|---|
| 593 | }
|
|---|
| 594 |
|
|---|
| 595 |
|
|---|
| 596 | package TieOut;
|
|---|
| 597 |
|
|---|
| 598 | sub TIEHANDLE {
|
|---|
| 599 | my $class = shift;
|
|---|
| 600 | bless(\( my $ref = ''), $class);
|
|---|
| 601 | }
|
|---|
| 602 |
|
|---|
| 603 | sub PRINT {
|
|---|
| 604 | my $self = shift;
|
|---|
| 605 | $$self .= join('', @_);
|
|---|
| 606 | }
|
|---|
| 607 |
|
|---|
| 608 | sub PRINTF {
|
|---|
| 609 | my $self = shift;
|
|---|
| 610 | $$self .= sprintf shift, @_;
|
|---|
| 611 | }
|
|---|
| 612 |
|
|---|
| 613 | sub read {
|
|---|
| 614 | my $self = shift;
|
|---|
| 615 | return substr($$self, 0, length($$self), '');
|
|---|
| 616 | }
|
|---|
