This is a live mirror of the Perl 5 development currently hosted at https://github.com/perl/perl5
cygwin32 update (untested adaptation of patch against 5.005_03)
[perl5.git] / lib / Benchmark.pm
CommitLineData
a0d0e21e
LW
1package Benchmark;
2
f06db76b
AD
3=head1 NAME
4
5Benchmark - benchmark running times of code
6
7timethis - run a chunk of code several times
8
9timethese - run several chunks of code several times
10
11timeit - run a chunk of code and see how long it goes
12
13=head1 SYNOPSIS
14
15 timethis ($count, "code");
16
523cc92b 17 # Use Perl code in strings...
f06db76b
AD
18 timethese($count, {
19 'Name1' => '...code1...',
20 'Name2' => '...code2...',
21 });
22
523cc92b
CS
23 # ... or use subroutine references.
24 timethese($count, {
25 'Name1' => sub { ...code1... },
26 'Name2' => sub { ...code2... },
27 });
28
f06db76b
AD
29 $t = timeit($count, '...other code...')
30 print "$count loops of other code took:",timestr($t),"\n";
31
32=head1 DESCRIPTION
33
34The Benchmark module encapsulates a number of routines to help you
35figure out how long it takes to execute some code.
36
37=head2 Methods
38
39=over 10
40
41=item new
42
43Returns the current time. Example:
44
45 use Benchmark;
46 $t0 = new Benchmark;
47 # ... your code here ...
48 $t1 = new Benchmark;
49 $td = timediff($t1, $t0);
a24a9dfe 50 print "the code took:",timestr($td),"\n";
f06db76b
AD
51
52=item debug
53
54Enables or disable debugging by setting the C<$Benchmark::Debug> flag:
55
523cc92b 56 debug Benchmark 1;
f06db76b 57 $t = timeit(10, ' 5 ** $Global ');
523cc92b 58 debug Benchmark 0;
f06db76b
AD
59
60=back
61
62=head2 Standard Exports
63
523cc92b 64The following routines will be exported into your namespace
f06db76b
AD
65if you use the Benchmark module:
66
67=over 10
68
69=item timeit(COUNT, CODE)
70
523cc92b
CS
71Arguments: COUNT is the number of times to run the loop, and CODE is
72the code to run. CODE may be either a code reference or a string to
73be eval'd; either way it will be run in the caller's package.
74
75Returns: a Benchmark object.
76
77=item timethis ( COUNT, CODE, [ TITLE, [ STYLE ]] )
78
79Time COUNT iterations of CODE. CODE may be a string to eval or a
80code reference; either way the CODE will run in the caller's package.
81Results will be printed to STDOUT as TITLE followed by the times.
82TITLE defaults to "timethis COUNT" if none is provided. STYLE
83determines the format of the output, as described for timestr() below.
84
6ee623d5
GS
85The COUNT can be zero or negative: this means the I<minimum number of
86CPU seconds> to run. A zero signifies the default of 3 seconds. For
87example to run at least for 10 seconds:
88
89 timethis(-10, $code)
90
91or to run two pieces of code tests for at least 3 seconds:
92
93 timethese(0, { test1 => '...', test2 => '...'})
94
95CPU seconds is, in UNIX terms, the user time plus the system time of
96the process itself, as opposed to the real (wallclock) time and the
97time spent by the child processes. Less than 0.1 seconds is not
98accepted (-0.01 as the count, for example, will cause a fatal runtime
99exception).
100
101Note that the CPU seconds is the B<minimum> time: CPU scheduling and
102other operating system factors may complicate the attempt so that a
103little bit more time is spent. The benchmark output will, however,
104also tell the number of C<$code> runs/second, which should be a more
105interesting number than the actually spent seconds.
106
107Returns a Benchmark object.
108
523cc92b 109=item timethese ( COUNT, CODEHASHREF, [ STYLE ] )
f06db76b 110
523cc92b
CS
111The CODEHASHREF is a reference to a hash containing names as keys
112and either a string to eval or a code reference for each value.
113For each (KEY, VALUE) pair in the CODEHASHREF, this routine will
114call
f06db76b 115
523cc92b 116 timethis(COUNT, VALUE, KEY, STYLE)
f06db76b 117
1d2dff63
GS
118The routines are called in string comparison order of KEY.
119
120The COUNT can be zero or negative, see timethis().
6ee623d5 121
523cc92b 122=item timediff ( T1, T2 )
f06db76b 123
523cc92b
CS
124Returns the difference between two Benchmark times as a Benchmark
125object suitable for passing to timestr().
f06db76b 126
705cc255
TB
127=item timesum ( T1, T2 )
128
129Returns the sum of two Benchmark times as a Benchmark object suitable
130for passing to timestr().
131
6ee623d5 132=item timestr ( TIMEDIFF, [ STYLE, [ FORMAT ] ] )
f06db76b 133
523cc92b
CS
134Returns a string that formats the times in the TIMEDIFF object in
135the requested STYLE. TIMEDIFF is expected to be a Benchmark object
136similar to that returned by timediff().
137
138STYLE can be any of 'all', 'noc', 'nop' or 'auto'. 'all' shows each
139of the 5 times available ('wallclock' time, user time, system time,
140user time of children, and system time of children). 'noc' shows all
141except the two children times. 'nop' shows only wallclock and the
142two children times. 'auto' (the default) will act as 'all' unless
143the children times are both zero, in which case it acts as 'noc'.
144
145FORMAT is the L<printf(3)>-style format specifier (without the
146leading '%') to use to print the times. It defaults to '5.2f'.
f06db76b
AD
147
148=back
149
150=head2 Optional Exports
151
152The following routines will be exported into your namespace
153if you specifically ask that they be imported:
154
155=over 10
156
523cc92b
CS
157=item clearcache ( COUNT )
158
159Clear the cached time for COUNT rounds of the null loop.
160
161=item clearallcache ( )
f06db76b 162
523cc92b 163Clear all cached times.
f06db76b 164
523cc92b 165=item disablecache ( )
f06db76b 166
523cc92b
CS
167Disable caching of timings for the null loop. This will force Benchmark
168to recalculate these timings for each new piece of code timed.
169
170=item enablecache ( )
171
172Enable caching of timings for the null loop. The time taken for COUNT
173rounds of the null loop will be calculated only once for each
174different COUNT used.
f06db76b
AD
175
176=back
177
178=head1 NOTES
179
180The data is stored as a list of values from the time and times
523cc92b 181functions:
f06db76b
AD
182
183 ($real, $user, $system, $children_user, $children_system)
184
185in seconds for the whole loop (not divided by the number of rounds).
186
187The timing is done using time(3) and times(3).
188
189Code is executed in the caller's package.
190
f06db76b
AD
191The time of the null loop (a loop with the same
192number of rounds but empty loop body) is subtracted
193from the time of the real loop.
194
195The null loop times are cached, the key being the
196number of rounds. The caching can be controlled using
197calls like these:
198
523cc92b 199 clearcache($key);
f06db76b
AD
200 clearallcache();
201
523cc92b 202 disablecache();
f06db76b
AD
203 enablecache();
204
205=head1 INHERITANCE
206
207Benchmark inherits from no other class, except of course
208for Exporter.
209
210=head1 CAVEATS
211
80eab818
CS
212Comparing eval'd strings with code references will give you
213inaccurate results: a code reference will show a slower
214execution time than the equivalent eval'd string.
215
f06db76b
AD
216The real time timing is done using time(2) and
217the granularity is therefore only one second.
218
219Short tests may produce negative figures because perl
523cc92b
CS
220can appear to take longer to execute the empty loop
221than a short test; try:
f06db76b
AD
222
223 timethis(100,'1');
224
225The system time of the null loop might be slightly
226more than the system time of the loop with the actual
a24a9dfe 227code and therefore the difference might end up being E<lt> 0.
f06db76b 228
f06db76b
AD
229=head1 AUTHORS
230
5aabfad6 231Jarkko Hietaniemi <F<jhi@iki.fi>>, Tim Bunce <F<Tim.Bunce@ig.co.uk>>
f06db76b
AD
232
233=head1 MODIFICATION HISTORY
234
235September 8th, 1994; by Tim Bunce.
236
523cc92b
CS
237March 28th, 1997; by Hugo van der Sanden: added support for code
238references and the already documented 'debug' method; revamped
239documentation.
f06db76b 240
6ee623d5
GS
241April 04-07th, 1997: by Jarkko Hietaniemi, added the run-for-some-time
242functionality.
243
523cc92b 244=cut
a0d0e21e 245
3f943bd9
GS
246# evaluate something in a clean lexical environment
247sub _doeval { eval shift }
248
249#
250# put any lexicals at file scope AFTER here
251#
252
4aa0a1f7 253use Carp;
a0d0e21e
LW
254use Exporter;
255@ISA=(Exporter);
256@EXPORT=qw(timeit timethis timethese timediff timestr);
257@EXPORT_OK=qw(clearcache clearallcache disablecache enablecache);
258
259&init;
260
261sub init {
262 $debug = 0;
263 $min_count = 4;
264 $min_cpu = 0.4;
265 $defaultfmt = '5.2f';
266 $defaultstyle = 'auto';
267 # The cache can cause a slight loss of sys time accuracy. If a
268 # user does many tests (>10) with *very* large counts (>10000)
269 # or works on a very slow machine the cache may be useful.
270 &disablecache;
271 &clearallcache;
272}
273
523cc92b
CS
274sub debug { $debug = ($_[1] != 0); }
275
a0d0e21e
LW
276sub clearcache { delete $cache{$_[0]}; }
277sub clearallcache { %cache = (); }
278sub enablecache { $cache = 1; }
279sub disablecache { $cache = 0; }
280
a0d0e21e
LW
281# --- Functions to process the 'time' data type
282
6ee623d5
GS
283sub new { my @t = (time, times, @_ == 2 ? $_[1] : 0);
284 print "new=@t\n" if $debug;
285 bless \@t; }
a0d0e21e
LW
286
287sub cpu_p { my($r,$pu,$ps,$cu,$cs) = @{$_[0]}; $pu+$ps ; }
288sub cpu_c { my($r,$pu,$ps,$cu,$cs) = @{$_[0]}; $cu+$cs ; }
289sub cpu_a { my($r,$pu,$ps,$cu,$cs) = @{$_[0]}; $pu+$ps+$cu+$cs ; }
290sub real { my($r,$pu,$ps,$cu,$cs) = @{$_[0]}; $r ; }
291
523cc92b 292sub timediff {
a0d0e21e 293 my($a, $b) = @_;
523cc92b 294 my @r;
3f943bd9 295 for (my $i=0; $i < @$a; ++$i) {
a0d0e21e
LW
296 push(@r, $a->[$i] - $b->[$i]);
297 }
298 bless \@r;
299}
300
705cc255
TB
301sub timesum {
302 my($a, $b) = @_;
303 my @r;
304 for (my $i=0; $i < @$a; ++$i) {
305 push(@r, $a->[$i] + $b->[$i]);
306 }
307 bless \@r;
308}
309
523cc92b 310sub timestr {
a0d0e21e 311 my($tr, $style, $f) = @_;
523cc92b 312 my @t = @$tr;
6ee623d5
GS
313 warn "bad time value (@t)" unless @t==6;
314 my($r, $pu, $ps, $cu, $cs, $n) = @t;
a0d0e21e 315 my($pt, $ct, $t) = ($tr->cpu_p, $tr->cpu_c, $tr->cpu_a);
523cc92b 316 $f = $defaultfmt unless defined $f;
a0d0e21e 317 # format a time in the required style, other formats may be added here
80eab818 318 $style ||= $defaultstyle;
523cc92b
CS
319 $style = ($ct>0) ? 'all' : 'noc' if $style eq 'auto';
320 my $s = "@t $style"; # default for unknown style
7be077a2 321 $s=sprintf("%2d wallclock secs (%$f usr %$f sys + %$f cusr %$f csys = %$f CPU)",
523cc92b 322 @t,$t) if $style eq 'all';
7be077a2
GS
323 $s=sprintf("%2d wallclock secs (%$f usr + %$f sys = %$f CPU)",
324 $r,$pu,$ps,$pt) if $style eq 'noc';
325 $s=sprintf("%2d wallclock secs (%$f cusr + %$f csys = %$f CPU)",
326 $r,$cu,$cs,$ct) if $style eq 'nop';
6ee623d5 327 $s .= sprintf(" @ %$f/s (n=$n)", $n / ( $pu + $ps )) if $n;
a0d0e21e
LW
328 $s;
329}
523cc92b
CS
330
331sub timedebug {
a0d0e21e 332 my($msg, $t) = @_;
523cc92b 333 print STDERR "$msg",timestr($t),"\n" if $debug;
a0d0e21e
LW
334}
335
a0d0e21e
LW
336# --- Functions implementing low-level support for timing loops
337
338sub runloop {
339 my($n, $c) = @_;
4aa0a1f7
AD
340
341 $n+=0; # force numeric now, so garbage won't creep into the eval
523cc92b
CS
342 croak "negative loopcount $n" if $n<0;
343 confess "Usage: runloop(number, [string | coderef])" unless defined $c;
a0d0e21e
LW
344 my($t0, $t1, $td); # before, after, difference
345
346 # find package of caller so we can execute code there
523cc92b
CS
347 my($curpack) = caller(0);
348 my($i, $pack)= 0;
a0d0e21e
LW
349 while (($pack) = caller(++$i)) {
350 last if $pack ne $curpack;
351 }
352
3f943bd9
GS
353 my ($subcode, $subref);
354 if (ref $c eq 'CODE') {
355 $subcode = "sub { for (1 .. $n) { local \$_; package $pack; &\$c; } }";
356 $subref = eval $subcode;
357 }
358 else {
359 $subcode = "sub { for (1 .. $n) { local \$_; package $pack; $c;} }";
360 $subref = _doeval($subcode);
361 }
4aa0a1f7 362 croak "runloop unable to compile '$c': $@\ncode: $subcode\n" if $@;
523cc92b 363 print STDERR "runloop $n '$subcode'\n" if $debug;
a0d0e21e 364
6ee623d5 365 $t0 = Benchmark->new(0);
a0d0e21e 366 &$subref;
6ee623d5 367 $t1 = Benchmark->new($n);
a0d0e21e
LW
368 $td = &timediff($t1, $t0);
369
370 timedebug("runloop:",$td);
371 $td;
372}
373
374
375sub timeit {
376 my($n, $code) = @_;
377 my($wn, $wc, $wd);
378
379 printf STDERR "timeit $n $code\n" if $debug;
380
523cc92b 381 if ($cache && exists $cache{$n}) {
a0d0e21e 382 $wn = $cache{$n};
523cc92b 383 } else {
a0d0e21e
LW
384 $wn = &runloop($n, '');
385 $cache{$n} = $wn;
386 }
387
388 $wc = &runloop($n, $code);
389
390 $wd = timediff($wc, $wn);
391
392 timedebug("timeit: ",$wc);
393 timedebug(" - ",$wn);
394 timedebug(" = ",$wd);
395
396 $wd;
397}
398
6ee623d5
GS
399
400my $default_for = 3;
401my $min_for = 0.1;
402
403sub runfor {
404 my ($code, $tmax) = @_;
405
406 if ( not defined $tmax or $tmax == 0 ) {
407 $tmax = $default_for;
408 } elsif ( $tmax < 0 ) {
409 $tmax = -$tmax;
410 }
411
412 die "runfor(..., $tmax): timelimit cannot be less than $min_for.\n"
413 if $tmax < $min_for;
414
415 my ($n, $td, $tc, $ntot, $rtot, $utot, $stot, $cutot, $cstot );
416
417 # First find the minimum $n that gives a non-zero timing.
418
419 my $nmin;
420
421 for ($n = 1, $tc = 0; $tc <= 0; $n *= 2 ) {
422 $td = timeit($n, $code);
423 $tc = $td->[1] + $td->[2];
424 }
425
426 $nmin = $n;
427
428 my $ttot = 0;
429 my $tpra = 0.05 * $tmax; # Target/time practice.
430
431 # Double $n until we have think we have practiced enough.
432 for ( $n = 1; $ttot < $tpra; $n *= 2 ) {
433 $td = timeit($n, $code);
434 $tc = $td->cpu_p;
435 $ntot += $n;
436 $rtot += $td->[0];
437 $utot += $td->[1];
438 $stot += $td->[2];
439 $ttot = $utot + $stot;
440 $cutot += $td->[3];
441 $cstot += $td->[4];
442 }
443
444 my $r;
445
446 # Then iterate towards the $tmax.
447 while ( $ttot < $tmax ) {
448 $r = $tmax / $ttot - 1; # Linear approximation.
449 $n = int( $r * $n );
450 $n = $nmin if $n < $nmin;
451 $td = timeit($n, $code);
452 $ntot += $n;
453 $rtot += $td->[0];
454 $utot += $td->[1];
455 $stot += $td->[2];
456 $ttot = $utot + $stot;
457 $cutot += $td->[3];
458 $cstot += $td->[4];
459 }
460
461 return bless [ $rtot, $utot, $stot, $cutot, $cstot, $ntot ];
462}
463
a0d0e21e
LW
464# --- Functions implementing high-level time-then-print utilities
465
6ee623d5
GS
466sub n_to_for {
467 my $n = shift;
468 return $n == 0 ? $default_for : $n < 0 ? -$n : undef;
469}
470
a0d0e21e
LW
471sub timethis{
472 my($n, $code, $title, $style) = @_;
6ee623d5
GS
473 my($t, $for, $forn);
474
475 if ( $n > 0 ) {
476 croak "non-integer loopcount $n, stopped" if int($n)<$n;
477 $t = timeit($n, $code);
478 $title = "timethis $n" unless defined $title;
479 } else {
480 $fort = n_to_for( $n );
481 $t = runfor($code, $fort);
482 $title = "timethis for $fort" unless defined $title;
483 $forn = $t->[-1];
484 }
523cc92b 485 local $| = 1;
523cc92b 486 $style = "" unless defined $style;
a0d0e21e 487 printf("%10s: ", $title);
6ee623d5
GS
488 print timestr($t, $style, $defaultfmt),"\n";
489
490 $n = $forn if defined $forn;
523cc92b 491
a0d0e21e
LW
492 # A conservative warning to spot very silly tests.
493 # Don't assume that your benchmark is ok simply because
494 # you don't get this warning!
495 print " (warning: too few iterations for a reliable count)\n"
523cc92b 496 if $n < $min_count
a0d0e21e 497 || ($t->real < 1 && $n < 1000)
523cc92b 498 || $t->cpu_a < $min_cpu;
a0d0e21e
LW
499 $t;
500}
501
a0d0e21e
LW
502sub timethese{
503 my($n, $alt, $style) = @_;
504 die "usage: timethese(count, { 'Name1'=>'code1', ... }\n"
505 unless ref $alt eq HASH;
523cc92b
CS
506 my @names = sort keys %$alt;
507 $style = "" unless defined $style;
6ee623d5
GS
508 print "Benchmark: ";
509 if ( $n > 0 ) {
510 croak "non-integer loopcount $n, stopped" if int($n)<$n;
511 print "timing $n iterations of";
512 } else {
513 print "running";
514 }
515 print " ", join(', ',@names);
516 unless ( $n > 0 ) {
517 my $for = n_to_for( $n );
518 print ", each for at least $for CPU seconds";
519 }
520 print "...\n";
523cc92b
CS
521
522 # we could save the results in an array and produce a summary here
a0d0e21e 523 # sum, min, max, avg etc etc
4dbb2df9
A
524 foreach my $name (@names) {
525 timethis ($n, $alt -> {$name}, $name, $style);
526 }
a0d0e21e
LW
527}
528
a0d0e21e 5291;