This is a live mirror of the Perl 5 development currently hosted at https://github.com/perl/perl5
Comply with the 0x80th commandment
[perl5.git] / lib / Benchmark.pm
CommitLineData
a0d0e21e
LW
1package Benchmark;
2
53aa2791
MS
3use strict;
4
5
f06db76b
AD
6=head1 NAME
7
8a4f6ac2 8Benchmark - benchmark running times of Perl code
431d98c2 9
f06db76b
AD
10=head1 SYNOPSIS
11
f36484b0
BS
12 use Benchmark qw(:all) ;
13
f06db76b
AD
14 timethis ($count, "code");
15
523cc92b 16 # Use Perl code in strings...
f06db76b
AD
17 timethese($count, {
18 'Name1' => '...code1...',
19 'Name2' => '...code2...',
20 });
21
523cc92b
CS
22 # ... or use subroutine references.
23 timethese($count, {
24 'Name1' => sub { ...code1... },
25 'Name2' => sub { ...code2... },
26 });
27
431d98c2
BS
28 # cmpthese can be used both ways as well
29 cmpthese($count, {
30 'Name1' => '...code1...',
31 'Name2' => '...code2...',
32 });
33
34 cmpthese($count, {
35 'Name1' => sub { ...code1... },
36 'Name2' => sub { ...code2... },
37 });
38
39 # ...or in two stages
40 $results = timethese($count,
41 {
42 'Name1' => sub { ...code1... },
43 'Name2' => sub { ...code2... },
44 },
45 'none'
46 );
47 cmpthese( $results ) ;
48
f06db76b
AD
49 $t = timeit($count, '...other code...')
50 print "$count loops of other code took:",timestr($t),"\n";
51
431d98c2
BS
52 $t = countit($time, '...other code...')
53 $count = $t->iters ;
54 print "$count loops of other code took:",timestr($t),"\n";
55
e3d6de9a
JH
56 # enable hires wallclock timing if possible
57 use Benchmark ':hireswallclock';
58
f06db76b
AD
59=head1 DESCRIPTION
60
61The Benchmark module encapsulates a number of routines to help you
62figure out how long it takes to execute some code.
63
8a4f6ac2
GS
64timethis - run a chunk of code several times
65
66timethese - run several chunks of code several times
67
68cmpthese - print results of timethese as a comparison chart
69
70timeit - run a chunk of code and see how long it goes
71
72countit - see how many times a chunk of code runs in a given time
73
74
f06db76b
AD
75=head2 Methods
76
77=over 10
78
79=item new
80
81Returns the current time. Example:
82
83 use Benchmark;
84 $t0 = new Benchmark;
85 # ... your code here ...
86 $t1 = new Benchmark;
87 $td = timediff($t1, $t0);
a24a9dfe 88 print "the code took:",timestr($td),"\n";
f06db76b
AD
89
90=item debug
91
92Enables or disable debugging by setting the C<$Benchmark::Debug> flag:
93
523cc92b 94 debug Benchmark 1;
f06db76b 95 $t = timeit(10, ' 5 ** $Global ');
523cc92b 96 debug Benchmark 0;
f06db76b 97
431d98c2
BS
98=item iters
99
100Returns the number of iterations.
101
f06db76b
AD
102=back
103
104=head2 Standard Exports
105
523cc92b 106The following routines will be exported into your namespace
f06db76b
AD
107if you use the Benchmark module:
108
109=over 10
110
111=item timeit(COUNT, CODE)
112
523cc92b
CS
113Arguments: COUNT is the number of times to run the loop, and CODE is
114the code to run. CODE may be either a code reference or a string to
115be eval'd; either way it will be run in the caller's package.
116
117Returns: a Benchmark object.
118
119=item timethis ( COUNT, CODE, [ TITLE, [ STYLE ]] )
120
121Time COUNT iterations of CODE. CODE may be a string to eval or a
122code reference; either way the CODE will run in the caller's package.
123Results will be printed to STDOUT as TITLE followed by the times.
124TITLE defaults to "timethis COUNT" if none is provided. STYLE
125determines the format of the output, as described for timestr() below.
126
6ee623d5
GS
127The COUNT can be zero or negative: this means the I<minimum number of
128CPU seconds> to run. A zero signifies the default of 3 seconds. For
129example to run at least for 10 seconds:
130
131 timethis(-10, $code)
132
133or to run two pieces of code tests for at least 3 seconds:
134
135 timethese(0, { test1 => '...', test2 => '...'})
136
137CPU seconds is, in UNIX terms, the user time plus the system time of
138the process itself, as opposed to the real (wallclock) time and the
139time spent by the child processes. Less than 0.1 seconds is not
140accepted (-0.01 as the count, for example, will cause a fatal runtime
141exception).
142
143Note that the CPU seconds is the B<minimum> time: CPU scheduling and
144other operating system factors may complicate the attempt so that a
145little bit more time is spent. The benchmark output will, however,
146also tell the number of C<$code> runs/second, which should be a more
147interesting number than the actually spent seconds.
148
149Returns a Benchmark object.
150
523cc92b 151=item timethese ( COUNT, CODEHASHREF, [ STYLE ] )
f06db76b 152
523cc92b
CS
153The CODEHASHREF is a reference to a hash containing names as keys
154and either a string to eval or a code reference for each value.
155For each (KEY, VALUE) pair in the CODEHASHREF, this routine will
156call
f06db76b 157
523cc92b 158 timethis(COUNT, VALUE, KEY, STYLE)
f06db76b 159
1d2dff63
GS
160The routines are called in string comparison order of KEY.
161
162The COUNT can be zero or negative, see timethis().
6ee623d5 163
3c6312e9
BS
164Returns a hash of Benchmark objects, keyed by name.
165
523cc92b 166=item timediff ( T1, T2 )
f06db76b 167
523cc92b
CS
168Returns the difference between two Benchmark times as a Benchmark
169object suitable for passing to timestr().
f06db76b 170
6ee623d5 171=item timestr ( TIMEDIFF, [ STYLE, [ FORMAT ] ] )
f06db76b 172
523cc92b
CS
173Returns a string that formats the times in the TIMEDIFF object in
174the requested STYLE. TIMEDIFF is expected to be a Benchmark object
175similar to that returned by timediff().
176
3c6312e9
BS
177STYLE can be any of 'all', 'none', 'noc', 'nop' or 'auto'. 'all' shows
178each of the 5 times available ('wallclock' time, user time, system time,
523cc92b
CS
179user time of children, and system time of children). 'noc' shows all
180except the two children times. 'nop' shows only wallclock and the
181two children times. 'auto' (the default) will act as 'all' unless
182the children times are both zero, in which case it acts as 'noc'.
3c6312e9 183'none' prevents output.
523cc92b
CS
184
185FORMAT is the L<printf(3)>-style format specifier (without the
186leading '%') to use to print the times. It defaults to '5.2f'.
f06db76b
AD
187
188=back
189
190=head2 Optional Exports
191
192The following routines will be exported into your namespace
193if you specifically ask that they be imported:
194
195=over 10
196
523cc92b
CS
197=item clearcache ( COUNT )
198
199Clear the cached time for COUNT rounds of the null loop.
200
201=item clearallcache ( )
f06db76b 202
523cc92b 203Clear all cached times.
f06db76b 204
8962dfd6 205=item cmpthese ( COUNT, CODEHASHREF, [ STYLE ] )
ac8eabc1 206
d1083c7a 207=item cmpthese ( RESULTSHASHREF, [ STYLE ] )
ac8eabc1 208
d1083c7a 209Optionally calls timethese(), then outputs comparison chart. This:
ac8eabc1 210
d1083c7a
BS
211 cmpthese( -1, { a => "++\$i", b => "\$i *= 2" } ) ;
212
213outputs a chart like:
214
215 Rate b a
216 b 2831802/s -- -61%
217 a 7208959/s 155% --
218
219This chart is sorted from slowest to fastest, and shows the percent speed
220difference between each pair of tests.
221
222c<cmpthese> can also be passed the data structure that timethese() returns:
223
224 $results = timethese( -1, { a => "++\$i", b => "\$i *= 2" } ) ;
ac8eabc1
JH
225 cmpthese( $results );
226
d1083c7a
BS
227in case you want to see both sets of results.
228
229Returns a reference to an ARRAY of rows, each row is an ARRAY of cells from the
230above chart, including labels. This:
231
232 my $rows = cmpthese( -1, { a => '++$i', b => '$i *= 2' }, "none" );
233
234returns a data structure like:
235
236 [
237 [ '', 'Rate', 'b', 'a' ],
238 [ 'b', '2885232/s', '--', '-59%' ],
239 [ 'a', '7099126/s', '146%', '--' ],
240 ]
241
242B<NOTE>: This result value differs from previous versions, which returned
243the C<timethese()> result structure. If you want that, just use the two
244statement C<timethese>...C<cmpthese> idiom shown above.
245
246Incidently, note the variance in the result values between the two examples;
247this is typical of benchmarking. If this were a real benchmark, you would
248probably want to run a lot more iterations.
ac8eabc1
JH
249
250=item countit(TIME, CODE)
251
252Arguments: TIME is the minimum length of time to run CODE for, and CODE is
253the code to run. CODE may be either a code reference or a string to
254be eval'd; either way it will be run in the caller's package.
255
256TIME is I<not> negative. countit() will run the loop many times to
257calculate the speed of CODE before running it for TIME. The actual
258time run for will usually be greater than TIME due to system clock
259resolution, so it's best to look at the number of iterations divided
260by the times that you are concerned with, not just the iterations.
261
262Returns: a Benchmark object.
263
523cc92b 264=item disablecache ( )
f06db76b 265
523cc92b
CS
266Disable caching of timings for the null loop. This will force Benchmark
267to recalculate these timings for each new piece of code timed.
268
269=item enablecache ( )
270
271Enable caching of timings for the null loop. The time taken for COUNT
272rounds of the null loop will be calculated only once for each
273different COUNT used.
f06db76b 274
ac8eabc1
JH
275=item timesum ( T1, T2 )
276
277Returns the sum of two Benchmark times as a Benchmark object suitable
278for passing to timestr().
279
f06db76b
AD
280=back
281
e3d6de9a
JH
282=head2 :hireswallclock
283
284If the Time::HiRes module has been installed, you can specify the
285special tag C<:hireswallclock> for Benchmark (if Time::HiRes is not
286available, the tag will be silently ignored). This tag will cause the
287wallclock time to be measured in microseconds, instead of integer
702fa71c
HS
288seconds. Note though that the speed computations are still conducted
289in CPU time, not wallclock time.
e3d6de9a 290
f06db76b
AD
291=head1 NOTES
292
293The data is stored as a list of values from the time and times
523cc92b 294functions:
f06db76b 295
431d98c2 296 ($real, $user, $system, $children_user, $children_system, $iters)
f06db76b
AD
297
298in seconds for the whole loop (not divided by the number of rounds).
299
300The timing is done using time(3) and times(3).
301
302Code is executed in the caller's package.
303
f06db76b
AD
304The time of the null loop (a loop with the same
305number of rounds but empty loop body) is subtracted
306from the time of the real loop.
307
3c6312e9 308The null loop times can be cached, the key being the
f06db76b
AD
309number of rounds. The caching can be controlled using
310calls like these:
311
523cc92b 312 clearcache($key);
f06db76b
AD
313 clearallcache();
314
523cc92b 315 disablecache();
f06db76b
AD
316 enablecache();
317
3c6312e9
BS
318Caching is off by default, as it can (usually slightly) decrease
319accuracy and does not usually noticably affect runtimes.
320
54e82ce5
GS
321=head1 EXAMPLES
322
323For example,
324
14393033
BS
325 use Benchmark qw( cmpthese ) ;
326 $x = 3;
327 cmpthese( -5, {
328 a => sub{$x*$x},
329 b => sub{$x**2},
330 } );
54e82ce5
GS
331
332outputs something like this:
333
334 Benchmark: running a, b, each for at least 5 CPU seconds...
14393033
BS
335 Rate b a
336 b 1559428/s -- -62%
337 a 4152037/s 166% --
338
54e82ce5
GS
339
340while
341
14393033
BS
342 use Benchmark qw( timethese cmpthese ) ;
343 $x = 3;
344 $r = timethese( -5, {
345 a => sub{$x*$x},
346 b => sub{$x**2},
347 } );
348 cmpthese $r;
54e82ce5
GS
349
350outputs something like this:
351
14393033
BS
352 Benchmark: running a, b, each for at least 5 CPU seconds...
353 a: 10 wallclock secs ( 5.14 usr + 0.13 sys = 5.27 CPU) @ 3835055.60/s (n=20210743)
354 b: 5 wallclock secs ( 5.41 usr + 0.00 sys = 5.41 CPU) @ 1574944.92/s (n=8520452)
355 Rate b a
356 b 1574945/s -- -59%
357 a 3835056/s 144% --
54e82ce5
GS
358
359
f06db76b
AD
360=head1 INHERITANCE
361
362Benchmark inherits from no other class, except of course
363for Exporter.
364
365=head1 CAVEATS
366
80eab818 367Comparing eval'd strings with code references will give you
431d98c2 368inaccurate results: a code reference will show a slightly slower
80eab818
CS
369execution time than the equivalent eval'd string.
370
f06db76b
AD
371The real time timing is done using time(2) and
372the granularity is therefore only one second.
373
374Short tests may produce negative figures because perl
523cc92b
CS
375can appear to take longer to execute the empty loop
376than a short test; try:
f06db76b
AD
377
378 timethis(100,'1');
379
380The system time of the null loop might be slightly
381more than the system time of the loop with the actual
a24a9dfe 382code and therefore the difference might end up being E<lt> 0.
f06db76b 383
8a4f6ac2
GS
384=head1 SEE ALSO
385
386L<Devel::DProf> - a Perl code profiler
387
f06db76b
AD
388=head1 AUTHORS
389
5aabfad6 390Jarkko Hietaniemi <F<jhi@iki.fi>>, Tim Bunce <F<Tim.Bunce@ig.co.uk>>
f06db76b
AD
391
392=head1 MODIFICATION HISTORY
393
394September 8th, 1994; by Tim Bunce.
395
523cc92b
CS
396March 28th, 1997; by Hugo van der Sanden: added support for code
397references and the already documented 'debug' method; revamped
398documentation.
f06db76b 399
6ee623d5
GS
400April 04-07th, 1997: by Jarkko Hietaniemi, added the run-for-some-time
401functionality.
402
3c6312e9
BS
403September, 1999; by Barrie Slaymaker: math fixes and accuracy and
404efficiency tweaks. Added cmpthese(). A result is now returned from
431d98c2 405timethese(). Exposed countit() (was runfor()).
3c6312e9 406
0e74ff8e
JH
407December, 2001; by Nicholas Clark: make timestr() recognise the style 'none'
408and return an empty string. If cmpthese is calling timethese, make it pass the
409style in. (so that 'none' will suppress output). Make sub new dump its
410debugging output to STDERR, to be consistent with everything else.
411All bugs found while writing a regression test.
412
e3d6de9a
JH
413September, 2002; by Jarkko Hietaniemi: add ':hireswallclock' special tag.
414
33e4b5a9
CK
415February, 2004; by Chia-liang Kao: make cmpthese and timestr use time
416statistics for children instead of parent when the style is 'nop'.
417
523cc92b 418=cut
a0d0e21e 419
3f943bd9 420# evaluate something in a clean lexical environment
53aa2791 421sub _doeval { no strict; eval shift }
3f943bd9
GS
422
423#
424# put any lexicals at file scope AFTER here
425#
426
4aa0a1f7 427use Carp;
a0d0e21e 428use Exporter;
53aa2791
MS
429
430our(@ISA, @EXPORT, @EXPORT_OK, %EXPORT_TAGS, $VERSION);
431
432@ISA=qw(Exporter);
ac8eabc1
JH
433@EXPORT=qw(timeit timethis timethese timediff timestr);
434@EXPORT_OK=qw(timesum cmpthese countit
435 clearcache clearallcache disablecache enablecache);
f36484b0 436%EXPORT_TAGS=( all => [ @EXPORT, @EXPORT_OK ] ) ;
a0d0e21e 437
92dfaf87 438$VERSION = 1.08;
e3d6de9a
JH
439
440# --- ':hireswallclock' special handling
441
442my $hirestime;
443
444sub mytime () { time }
8a4f6ac2 445
359218de 446init();
a0d0e21e 447
e3d6de9a
JH
448sub BEGIN {
449 if (eval 'require Time::HiRes') {
450 import Time::HiRes qw(time);
451 $hirestime = \&Time::HiRes::time;
452 }
453}
454
455sub import {
456 my $class = shift;
457 if (grep { $_ eq ":hireswallclock" } @_) {
458 @_ = grep { $_ ne ":hireswallclock" } @_;
92dfaf87 459 local $^W=0;
e3d6de9a
JH
460 *mytime = $hirestime if defined $hirestime;
461 }
462 Benchmark->export_to_level(1, $class, @_);
463}
464
53aa2791
MS
465our($Debug, $Min_Count, $Min_CPU, $Default_Format, $Default_Style,
466 %_Usage, %Cache, $Do_Cache);
467
a0d0e21e 468sub init {
53aa2791
MS
469 $Debug = 0;
470 $Min_Count = 4;
471 $Min_CPU = 0.4;
472 $Default_Format = '5.2f';
473 $Default_Style = 'auto';
a0d0e21e
LW
474 # The cache can cause a slight loss of sys time accuracy. If a
475 # user does many tests (>10) with *very* large counts (>10000)
476 # or works on a very slow machine the cache may be useful.
359218de
JH
477 disablecache();
478 clearallcache();
a0d0e21e
LW
479}
480
53aa2791
MS
481sub debug { $Debug = ($_[1] != 0); }
482
483sub usage {
484 my $calling_sub = (caller(1))[3];
485 $calling_sub =~ s/^Benchmark:://;
486 return $_Usage{$calling_sub} || '';
487}
488
bba8fca5 489# The cache needs two branches: 's' for strings and 'c' for code. The
359218de 490# empty loop is different in these two cases.
53aa2791 491
f695f0e6
JH
492$_Usage{clearcache} = <<'USAGE';
493usage: clearcache($count);
494USAGE
495
496sub clearcache {
497 die usage unless @_ == 1;
53aa2791
MS
498 delete $Cache{"$_[0]c"}; delete $Cache{"$_[0]s"};
499}
500
f695f0e6
JH
501$_Usage{clearallcache} = <<'USAGE';
502usage: clearallcache();
503USAGE
504
505sub clearallcache {
506 die usage if @_;
53aa2791
MS
507 %Cache = ();
508}
509
f695f0e6
JH
510$_Usage{enablecache} = <<'USAGE';
511usage: enablecache();
512USAGE
513
514sub enablecache {
515 die usage if @_;
53aa2791
MS
516 $Do_Cache = 1;
517}
518
f695f0e6
JH
519$_Usage{disablecache} = <<'USAGE';
520usage: disablecache();
521USAGE
522
523sub disablecache {
524 die usage if @_;
53aa2791
MS
525 $Do_Cache = 0;
526}
527
a0d0e21e 528
a0d0e21e
LW
529# --- Functions to process the 'time' data type
530
e3d6de9a 531sub new { my @t = (mytime, times, @_ == 2 ? $_[1] : 0);
53aa2791 532 print STDERR "new=@t\n" if $Debug;
6ee623d5 533 bless \@t; }
a0d0e21e
LW
534
535sub cpu_p { my($r,$pu,$ps,$cu,$cs) = @{$_[0]}; $pu+$ps ; }
536sub cpu_c { my($r,$pu,$ps,$cu,$cs) = @{$_[0]}; $cu+$cs ; }
537sub cpu_a { my($r,$pu,$ps,$cu,$cs) = @{$_[0]}; $pu+$ps+$cu+$cs ; }
538sub real { my($r,$pu,$ps,$cu,$cs) = @{$_[0]}; $r ; }
431d98c2 539sub iters { $_[0]->[5] ; }
a0d0e21e 540
53aa2791
MS
541
542$_Usage{timediff} = <<'USAGE';
543usage: $result_diff = timediff($result1, $result2);
544USAGE
545
523cc92b 546sub timediff {
a0d0e21e 547 my($a, $b) = @_;
53aa2791
MS
548
549 die usage unless ref $a and ref $b;
550
523cc92b 551 my @r;
3f943bd9 552 for (my $i=0; $i < @$a; ++$i) {
a0d0e21e
LW
553 push(@r, $a->[$i] - $b->[$i]);
554 }
e68ec53f
YO
555 #die "Bad timediff(): ($r[1] + $r[2]) <= 0 (@$a[1,2]|@$b[1,2])\n"
556 # if ($r[1] + $r[2]) < 0;
a0d0e21e
LW
557 bless \@r;
558}
559
53aa2791
MS
560$_Usage{timesum} = <<'USAGE';
561usage: $sum = timesum($result1, $result2);
562USAGE
563
705cc255 564sub timesum {
53aa2791
MS
565 my($a, $b) = @_;
566
567 die usage unless ref $a and ref $b;
568
569 my @r;
570 for (my $i=0; $i < @$a; ++$i) {
705cc255 571 push(@r, $a->[$i] + $b->[$i]);
53aa2791
MS
572 }
573 bless \@r;
705cc255
TB
574}
575
53aa2791
MS
576
577$_Usage{timestr} = <<'USAGE';
578usage: $formatted_result = timestr($result1);
579USAGE
580
523cc92b 581sub timestr {
a0d0e21e 582 my($tr, $style, $f) = @_;
53aa2791
MS
583
584 die usage unless ref $tr;
585
523cc92b 586 my @t = @$tr;
6ee623d5
GS
587 warn "bad time value (@t)" unless @t==6;
588 my($r, $pu, $ps, $cu, $cs, $n) = @t;
ce9550df 589 my($pt, $ct, $tt) = ($tr->cpu_p, $tr->cpu_c, $tr->cpu_a);
53aa2791 590 $f = $Default_Format unless defined $f;
a0d0e21e 591 # format a time in the required style, other formats may be added here
53aa2791 592 $style ||= $Default_Style;
0e74ff8e 593 return '' if $style eq 'none';
523cc92b
CS
594 $style = ($ct>0) ? 'all' : 'noc' if $style eq 'auto';
595 my $s = "@t $style"; # default for unknown style
e3d6de9a
JH
596 my $w = $hirestime ? "%2g" : "%2d";
597 $s=sprintf("$w wallclock secs (%$f usr %$f sys + %$f cusr %$f csys = %$f CPU)",
ce9550df 598 $r,$pu,$ps,$cu,$cs,$tt) if $style eq 'all';
e3d6de9a 599 $s=sprintf("$w wallclock secs (%$f usr + %$f sys = %$f CPU)",
7be077a2 600 $r,$pu,$ps,$pt) if $style eq 'noc';
e3d6de9a 601 $s=sprintf("$w wallclock secs (%$f cusr + %$f csys = %$f CPU)",
7be077a2 602 $r,$cu,$cs,$ct) if $style eq 'nop';
33e4b5a9
CK
603 $s .= sprintf(" @ %$f/s (n=$n)", $n / ( $style eq 'nop' ? $cu + $cs : $pu + $ps ))
604 if $n && ($style eq 'nop' ? $cu+$cs : $pu+$ps);
a0d0e21e
LW
605 $s;
606}
523cc92b
CS
607
608sub timedebug {
a0d0e21e 609 my($msg, $t) = @_;
53aa2791 610 print STDERR "$msg",timestr($t),"\n" if $Debug;
a0d0e21e
LW
611}
612
a0d0e21e
LW
613# --- Functions implementing low-level support for timing loops
614
53aa2791
MS
615$_Usage{runloop} = <<'USAGE';
616usage: runloop($number, [$string | $coderef])
617USAGE
618
a0d0e21e
LW
619sub runloop {
620 my($n, $c) = @_;
4aa0a1f7
AD
621
622 $n+=0; # force numeric now, so garbage won't creep into the eval
523cc92b 623 croak "negative loopcount $n" if $n<0;
53aa2791 624 confess usage unless defined $c;
a0d0e21e
LW
625 my($t0, $t1, $td); # before, after, difference
626
627 # find package of caller so we can execute code there
523cc92b
CS
628 my($curpack) = caller(0);
629 my($i, $pack)= 0;
a0d0e21e
LW
630 while (($pack) = caller(++$i)) {
631 last if $pack ne $curpack;
632 }
633
3f943bd9
GS
634 my ($subcode, $subref);
635 if (ref $c eq 'CODE') {
636 $subcode = "sub { for (1 .. $n) { local \$_; package $pack; &\$c; } }";
637 $subref = eval $subcode;
638 }
639 else {
640 $subcode = "sub { for (1 .. $n) { local \$_; package $pack; $c;} }";
641 $subref = _doeval($subcode);
642 }
4aa0a1f7 643 croak "runloop unable to compile '$c': $@\ncode: $subcode\n" if $@;
53aa2791 644 print STDERR "runloop $n '$subcode'\n" if $Debug;
a0d0e21e 645
3c6312e9
BS
646 # Wait for the user timer to tick. This makes the error range more like
647 # -0.01, +0. If we don't wait, then it's more like -0.01, +0.01. This
648 # may not seem important, but it significantly reduces the chances of
649 # getting a too low initial $n in the initial, 'find the minimum' loop
431d98c2 650 # in &countit. This, in turn, can reduce the number of calls to
bba8fca5
BS
651 # &runloop a lot, and thus reduce additive errors.
652 my $tbase = Benchmark->new(0)->[1];
277427cf 653 while ( ( $t0 = Benchmark->new(0) )->[1] == $tbase ) {} ;
f265d4df 654 $subref->();
6ee623d5 655 $t1 = Benchmark->new($n);
a0d0e21e 656 $td = &timediff($t1, $t0);
a0d0e21e
LW
657 timedebug("runloop:",$td);
658 $td;
659}
660
53aa2791
MS
661$_Usage{timeit} = <<'USAGE';
662usage: $result = timeit($count, 'code' ); or
663 $result = timeit($count, sub { code } );
664USAGE
a0d0e21e
LW
665
666sub timeit {
667 my($n, $code) = @_;
668 my($wn, $wc, $wd);
669
53aa2791
MS
670 die usage unless defined $code and
671 (!ref $code or ref $code eq 'CODE');
672
673 printf STDERR "timeit $n $code\n" if $Debug;
3c6312e9 674 my $cache_key = $n . ( ref( $code ) ? 'c' : 's' );
53aa2791
MS
675 if ($Do_Cache && exists $Cache{$cache_key} ) {
676 $wn = $Cache{$cache_key};
523cc92b 677 } else {
6bf773bc 678 $wn = &runloop($n, ref( $code ) ? sub { } : '' );
3c6312e9
BS
679 # Can't let our baseline have any iterations, or they get subtracted
680 # out of the result.
681 $wn->[5] = 0;
53aa2791 682 $Cache{$cache_key} = $wn;
a0d0e21e
LW
683 }
684
685 $wc = &runloop($n, $code);
686
687 $wd = timediff($wc, $wn);
a0d0e21e
LW
688 timedebug("timeit: ",$wc);
689 timedebug(" - ",$wn);
690 timedebug(" = ",$wd);
691
692 $wd;
693}
694
6ee623d5
GS
695
696my $default_for = 3;
697my $min_for = 0.1;
698
3c6312e9 699
53aa2791
MS
700$_Usage{countit} = <<'USAGE';
701usage: $result = countit($time, 'code' ); or
702 $result = countit($time, sub { code } );
703USAGE
704
431d98c2
BS
705sub countit {
706 my ( $tmax, $code ) = @_;
6ee623d5 707
53aa2791
MS
708 die usage unless @_;
709
6ee623d5
GS
710 if ( not defined $tmax or $tmax == 0 ) {
711 $tmax = $default_for;
712 } elsif ( $tmax < 0 ) {
713 $tmax = -$tmax;
714 }
715
431d98c2 716 die "countit($tmax, ...): timelimit cannot be less than $min_for.\n"
6ee623d5
GS
717 if $tmax < $min_for;
718
3c6312e9 719 my ($n, $tc);
6ee623d5 720
bba8fca5 721 # First find the minimum $n that gives a significant timing.
e68ec53f 722 my $zeros=0;
3c6312e9
BS
723 for ($n = 1; ; $n *= 2 ) {
724 my $td = timeit($n, $code);
725 $tc = $td->[1] + $td->[2];
e68ec53f
YO
726 if ( $tc <= 0 and $n > 1024 ) {
727 ++$zeros > 16
728 and die "Timing is consistently zero in estimation loop, cannot benchmark. N=$n\n";
729 } else {
730 $zeros = 0;
731 }
3c6312e9
BS
732 last if $tc > 0.1;
733 }
6ee623d5 734
3c6312e9
BS
735 my $nmin = $n;
736
737 # Get $n high enough that we can guess the final $n with some accuracy.
738 my $tpra = 0.1 * $tmax; # Target/time practice.
739 while ( $tc < $tpra ) {
740 # The 5% fudge is to keep us from iterating again all
741 # that often (this speeds overall responsiveness when $tmax is big
742 # and we guess a little low). This does not noticably affect
743 # accuracy since we're not couting these times.
744 $n = int( $tpra * 1.05 * $n / $tc ); # Linear approximation.
745 my $td = timeit($n, $code);
c5d57293
A
746 my $new_tc = $td->[1] + $td->[2];
747 # Make sure we are making progress.
748 $tc = $new_tc > 1.2 * $tc ? $new_tc : 1.2 * $tc;
6ee623d5
GS
749 }
750
3c6312e9
BS
751 # Now, do the 'for real' timing(s), repeating until we exceed
752 # the max.
753 my $ntot = 0;
754 my $rtot = 0;
755 my $utot = 0.0;
756 my $stot = 0.0;
757 my $cutot = 0.0;
758 my $cstot = 0.0;
759 my $ttot = 0.0;
760
761 # The 5% fudge is because $n is often a few % low even for routines
762 # with stable times and avoiding extra timeit()s is nice for
763 # accuracy's sake.
764 $n = int( $n * ( 1.05 * $tmax / $tc ) );
e68ec53f 765 $zeros=0;
3c6312e9
BS
766 while () {
767 my $td = timeit($n, $code);
768 $ntot += $n;
769 $rtot += $td->[0];
770 $utot += $td->[1];
771 $stot += $td->[2];
6ee623d5
GS
772 $cutot += $td->[3];
773 $cstot += $td->[4];
3c6312e9
BS
774 $ttot = $utot + $stot;
775 last if $ttot >= $tmax;
e68ec53f
YO
776 if ( $ttot <= 0 ) {
777 ++$zeros > 16
778 and die "Timing is consistently zero, cannot benchmark. N=$n\n";
779 } else {
780 $zeros = 0;
781 }
c5d57293 782 $ttot = 0.01 if $ttot < 0.01;
3c6312e9 783 my $r = $tmax / $ttot - 1; # Linear approximation.
bba8fca5 784 $n = int( $r * $ntot );
6ee623d5 785 $n = $nmin if $n < $nmin;
6ee623d5
GS
786 }
787
788 return bless [ $rtot, $utot, $stot, $cutot, $cstot, $ntot ];
789}
790
a0d0e21e
LW
791# --- Functions implementing high-level time-then-print utilities
792
6ee623d5
GS
793sub n_to_for {
794 my $n = shift;
795 return $n == 0 ? $default_for : $n < 0 ? -$n : undef;
796}
797
53aa2791
MS
798$_Usage{timethis} = <<'USAGE';
799usage: $result = timethis($time, 'code' ); or
800 $result = timethis($time, sub { code } );
801USAGE
802
a0d0e21e
LW
803sub timethis{
804 my($n, $code, $title, $style) = @_;
53aa2791
MS
805 my($t, $forn);
806
807 die usage unless defined $code and
808 (!ref $code or ref $code eq 'CODE');
6ee623d5
GS
809
810 if ( $n > 0 ) {
811 croak "non-integer loopcount $n, stopped" if int($n)<$n;
812 $t = timeit($n, $code);
813 $title = "timethis $n" unless defined $title;
814 } else {
53aa2791 815 my $fort = n_to_for( $n );
431d98c2 816 $t = countit( $fort, $code );
6ee623d5
GS
817 $title = "timethis for $fort" unless defined $title;
818 $forn = $t->[-1];
819 }
523cc92b 820 local $| = 1;
523cc92b 821 $style = "" unless defined $style;
3c6312e9 822 printf("%10s: ", $title) unless $style eq 'none';
53aa2791 823 print timestr($t, $style, $Default_Format),"\n" unless $style eq 'none';
6ee623d5
GS
824
825 $n = $forn if defined $forn;
523cc92b 826
a0d0e21e
LW
827 # A conservative warning to spot very silly tests.
828 # Don't assume that your benchmark is ok simply because
829 # you don't get this warning!
830 print " (warning: too few iterations for a reliable count)\n"
53aa2791 831 if $n < $Min_Count
a0d0e21e 832 || ($t->real < 1 && $n < 1000)
53aa2791 833 || $t->cpu_a < $Min_CPU;
a0d0e21e
LW
834 $t;
835}
836
53aa2791
MS
837
838$_Usage{timethese} = <<'USAGE';
839usage: timethese($count, { Name1 => 'code1', ... }); or
840 timethese($count, { Name1 => sub { code1 }, ... });
841USAGE
842
a0d0e21e
LW
843sub timethese{
844 my($n, $alt, $style) = @_;
53aa2791
MS
845 die usage unless ref $alt eq 'HASH';
846
523cc92b
CS
847 my @names = sort keys %$alt;
848 $style = "" unless defined $style;
3c6312e9 849 print "Benchmark: " unless $style eq 'none';
6ee623d5
GS
850 if ( $n > 0 ) {
851 croak "non-integer loopcount $n, stopped" if int($n)<$n;
3c6312e9 852 print "timing $n iterations of" unless $style eq 'none';
6ee623d5 853 } else {
3c6312e9 854 print "running" unless $style eq 'none';
6ee623d5 855 }
3c6312e9 856 print " ", join(', ',@names) unless $style eq 'none';
6ee623d5
GS
857 unless ( $n > 0 ) {
858 my $for = n_to_for( $n );
df7779cf
T
859 print ", each" if $n > 1 && $style ne 'none';
860 print " for at least $for CPU seconds" unless $style eq 'none';
6ee623d5 861 }
3c6312e9 862 print "...\n" unless $style eq 'none';
523cc92b
CS
863
864 # we could save the results in an array and produce a summary here
a0d0e21e 865 # sum, min, max, avg etc etc
3c6312e9 866 my %results;
4dbb2df9 867 foreach my $name (@names) {
3c6312e9 868 $results{$name} = timethis ($n, $alt -> {$name}, $name, $style);
4dbb2df9 869 }
3c6312e9
BS
870
871 return \%results;
a0d0e21e
LW
872}
873
53aa2791
MS
874
875$_Usage{cmpthese} = <<'USAGE';
876usage: cmpthese($count, { Name1 => 'code1', ... }); or
877 cmpthese($count, { Name1 => sub { code1 }, ... }); or
878 cmpthese($result, $style);
879USAGE
880
3c6312e9 881sub cmpthese{
53aa2791
MS
882 my ($results, $style);
883
884 if( ref $_[0] ) {
885 ($results, $style) = @_;
886 }
887 else {
888 my($count, $code) = @_[0,1];
889 $style = $_[2] if defined $_[2];
890
891 die usage unless ref $code eq 'HASH';
892
893 $results = timethese($count, $code, ($style || "none"));
894 }
3c6312e9 895
d1083c7a 896 $style = "" unless defined $style;
3c6312e9
BS
897
898 # Flatten in to an array of arrays with the name as the first field
899 my @vals = map{ [ $_, @{$results->{$_}} ] } keys %$results;
900
901 for (@vals) {
902 # The epsilon fudge here is to prevent div by 0. Since clock
903 # resolutions are much larger, it's below the noise floor.
33e4b5a9
CK
904 my $rate = $_->[6] / (( $style eq 'nop' ? $_->[4] + $_->[5]
905 : $_->[2] + $_->[3]) + 0.000000000000001 );
3c6312e9
BS
906 $_->[7] = $rate;
907 }
908
909 # Sort by rate
910 @vals = sort { $a->[7] <=> $b->[7] } @vals;
911
912 # If more than half of the rates are greater than one...
d598cef2 913 my $display_as_rate = @vals ? ($vals[$#vals>>1]->[7] > 1) : 0;
3c6312e9
BS
914
915 my @rows;
916 my @col_widths;
917
918 my @top_row = (
919 '',
920 $display_as_rate ? 'Rate' : 's/iter',
921 map { $_->[0] } @vals
922 );
923
924 push @rows, \@top_row;
925 @col_widths = map { length( $_ ) } @top_row;
926
927 # Build the data rows
928 # We leave the last column in even though it never has any data. Perhaps
929 # it should go away. Also, perhaps a style for a single column of
930 # percentages might be nice.
931 for my $row_val ( @vals ) {
932 my @row;
933
934 # Column 0 = test name
935 push @row, $row_val->[0];
936 $col_widths[0] = length( $row_val->[0] )
937 if length( $row_val->[0] ) > $col_widths[0];
938
939 # Column 1 = performance
940 my $row_rate = $row_val->[7];
941
942 # We assume that we'll never get a 0 rate.
53aa2791 943 my $rate = $display_as_rate ? $row_rate : 1 / $row_rate;
3c6312e9
BS
944
945 # Only give a few decimal places before switching to sci. notation,
946 # since the results aren't usually that accurate anyway.
947 my $format =
53aa2791 948 $rate >= 100 ?
3c6312e9 949 "%0.0f" :
53aa2791 950 $rate >= 10 ?
3c6312e9 951 "%0.1f" :
53aa2791 952 $rate >= 1 ?
3c6312e9 953 "%0.2f" :
53aa2791 954 $rate >= 0.1 ?
3c6312e9
BS
955 "%0.3f" :
956 "%0.2e";
957
958 $format .= "/s"
959 if $display_as_rate;
53aa2791
MS
960
961 my $formatted_rate = sprintf( $format, $rate );
962 push @row, $formatted_rate;
963 $col_widths[1] = length( $formatted_rate )
964 if length( $formatted_rate ) > $col_widths[1];
3c6312e9
BS
965
966 # Columns 2..N = performance ratios
967 my $skip_rest = 0;
968 for ( my $col_num = 0 ; $col_num < @vals ; ++$col_num ) {
969 my $col_val = $vals[$col_num];
970 my $out;
971 if ( $skip_rest ) {
972 $out = '';
973 }
974 elsif ( $col_val->[0] eq $row_val->[0] ) {
975 $out = "--";
976 # $skip_rest = 1;
977 }
978 else {
979 my $col_rate = $col_val->[7];
980 $out = sprintf( "%.0f%%", 100*$row_rate/$col_rate - 100 );
981 }
982 push @row, $out;
983 $col_widths[$col_num+2] = length( $out )
984 if length( $out ) > $col_widths[$col_num+2];
985
986 # A little wierdness to set the first column width properly
987 $col_widths[$col_num+2] = length( $col_val->[0] )
988 if length( $col_val->[0] ) > $col_widths[$col_num+2];
989 }
990 push @rows, \@row;
991 }
992
d1083c7a
BS
993 return \@rows if $style eq "none";
994
3c6312e9
BS
995 # Equalize column widths in the chart as much as possible without
996 # exceeding 80 characters. This does not use or affect cols 0 or 1.
997 my @sorted_width_refs =
998 sort { $$a <=> $$b } map { \$_ } @col_widths[2..$#col_widths];
999 my $max_width = ${$sorted_width_refs[-1]};
1000
277427cf 1001 my $total = @col_widths - 1 ;
3c6312e9
BS
1002 for ( @col_widths ) { $total += $_ }
1003
1004 STRETCHER:
1005 while ( $total < 80 ) {
1006 my $min_width = ${$sorted_width_refs[0]};
1007 last
1008 if $min_width == $max_width;
1009 for ( @sorted_width_refs ) {
1010 last
1011 if $$_ > $min_width;
1012 ++$$_;
1013 ++$total;
1014 last STRETCHER
1015 if $total >= 80;
1016 }
1017 }
1018
1019 # Dump the output
1020 my $format = join( ' ', map { "%${_}s" } @col_widths ) . "\n";
1021 substr( $format, 1, 0 ) = '-';
1022 for ( @rows ) {
1023 printf $format, @$_;
1024 }
1025
d1083c7a 1026 return \@rows ;
3c6312e9
BS
1027}
1028
1029
a0d0e21e 10301;