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