| line | stmt | bran | cond | sub | pod | time | code | 
| 1 |  |  |  |  |  |  | package Benchmark::Timer; | 
| 2 |  |  |  |  |  |  | require 5.005; | 
| 3 | 6 |  |  | 6 |  | 405167 | use strict; | 
|  | 6 |  |  |  |  | 66 |  | 
|  | 6 |  |  |  |  | 205 |  | 
| 4 |  |  |  |  |  |  |  | 
| 5 | 6 |  |  | 6 |  | 38 | use Carp; | 
|  | 6 |  |  |  |  | 16 |  | 
|  | 6 |  |  |  |  | 567 |  | 
| 6 | 6 |  |  | 6 |  | 2416 | use Time::HiRes qw( gettimeofday tv_interval ); | 
|  | 6 |  |  |  |  | 6728 |  | 
|  | 6 |  |  |  |  | 29 |  | 
| 7 |  |  |  |  |  |  |  | 
| 8 | 6 |  |  | 6 |  | 1407 | use vars qw($VERSION); | 
|  | 6 |  |  |  |  | 25 |  | 
|  | 6 |  |  |  |  | 542 |  | 
| 9 |  |  |  |  |  |  | $VERSION = sprintf "%d.%02d%02d", q/0.71.12/ =~ /(\d+)/g; | 
| 10 |  |  |  |  |  |  |  | 
| 11 | 6 |  |  | 6 |  | 47 | use constant BEFORE     => 0; | 
|  | 6 |  |  |  |  | 15 |  | 
|  | 6 |  |  |  |  | 705 |  | 
| 12 | 6 |  |  | 6 |  | 42 | use constant ELAPSED    => 1; | 
|  | 6 |  |  |  |  | 13 |  | 
|  | 6 |  |  |  |  | 349 |  | 
| 13 | 6 |  |  | 6 |  | 56 | use constant LASTTAG    => 2; | 
|  | 6 |  |  |  |  | 20 |  | 
|  | 6 |  |  |  |  | 304 |  | 
| 14 | 6 |  |  | 6 |  | 39 | use constant TAGS       => 3; | 
|  | 6 |  |  |  |  | 11 |  | 
|  | 6 |  |  |  |  | 357 |  | 
| 15 | 6 |  |  | 6 |  | 44 | use constant SKIP       => 4; | 
|  | 6 |  |  |  |  | 14 |  | 
|  | 6 |  |  |  |  | 305 |  | 
| 16 | 6 |  |  | 6 |  | 87 | use constant MINIMUM    => 5; | 
|  | 6 |  |  |  |  | 38 |  | 
|  | 6 |  |  |  |  | 328 |  | 
| 17 | 6 |  |  | 6 |  | 36 | use constant SKIPCOUNT  => 6; | 
|  | 6 |  |  |  |  | 12 |  | 
|  | 6 |  |  |  |  | 311 |  | 
| 18 | 6 |  |  | 6 |  | 34 | use constant CONFIDENCE => 7; | 
|  | 6 |  |  |  |  | 14 |  | 
|  | 6 |  |  |  |  | 313 |  | 
| 19 | 6 |  |  | 6 |  | 35 | use constant ERROR      => 8; | 
|  | 6 |  |  |  |  | 12 |  | 
|  | 6 |  |  |  |  | 320 |  | 
| 20 | 6 |  |  | 6 |  | 36 | use constant STAT       => 9; | 
|  | 6 |  |  |  |  | 9 |  | 
|  | 6 |  |  |  |  | 12668 |  | 
| 21 |  |  |  |  |  |  |  | 
| 22 |  |  |  |  |  |  | # ------------------------------------------------------------------------ | 
| 23 |  |  |  |  |  |  | # Constructor | 
| 24 |  |  |  |  |  |  |  | 
| 25 |  |  |  |  |  |  | sub new { | 
| 26 | 14 |  |  | 14 | 1 | 7148 | my $class = shift; | 
| 27 | 14 |  |  |  |  | 38 | my $self = []; | 
| 28 | 14 |  |  |  |  | 36 | bless $self, $class; | 
| 29 | 14 |  |  |  |  | 49 | return $self->reset(@_); | 
| 30 |  |  |  |  |  |  | } | 
| 31 |  |  |  |  |  |  |  | 
| 32 |  |  |  |  |  |  |  | 
| 33 |  |  |  |  |  |  | # ------------------------------------------------------------------------ | 
| 34 |  |  |  |  |  |  | # Public methods | 
| 35 |  |  |  |  |  |  |  | 
| 36 |  |  |  |  |  |  | sub reset { | 
| 37 | 17 |  |  | 17 | 1 | 625 | my $self = shift; | 
| 38 | 17 |  |  |  |  | 54 | my %args = @_; | 
| 39 |  |  |  |  |  |  |  | 
| 40 | 17 |  |  |  |  | 64 | $self->[BEFORE] = {};          # [ gettimeofday ] storage | 
| 41 | 17 |  |  |  |  | 43 | $self->[ELAPSED] = {};         # elapsed fractional seconds | 
| 42 | 17 |  |  |  |  | 42 | $self->[LASTTAG] = undef;      # what the last tag was | 
| 43 | 17 |  |  |  |  | 36 | $self->[TAGS] = [];            # keep list of tags in order seen | 
| 44 | 17 |  |  |  |  | 41 | $self->[SKIP] = 0;             # how many samples to skip | 
| 45 | 17 |  |  |  |  | 39 | $self->[MINIMUM] = 1;          # the minimum number of trails to run | 
| 46 | 17 |  |  |  |  | 41 | $self->[SKIPCOUNT] = {};       # trial skip storage | 
| 47 | 17 |  |  |  |  | 36 | delete $self->[CONFIDENCE];    # confidence factor | 
| 48 | 17 |  |  |  |  | 26 | delete $self->[ERROR];         # allowable error | 
| 49 | 17 |  |  |  |  | 27 | delete $self->[STAT];          # stat objects for each tag | 
| 50 |  |  |  |  |  |  |  | 
| 51 | 17 | 100 |  |  |  | 57 | if(exists $args{skip}) { | 
| 52 |  |  |  |  |  |  | croak 'argument skip must be a non-negative integer' | 
| 53 |  |  |  |  |  |  | unless defined $args{skip} | 
| 54 |  |  |  |  |  |  | and $args{skip} !~ /\D/ | 
| 55 | 8 | 100 | 100 |  |  | 430 | and int $args{skip} == $args{skip}; | 
|  |  |  | 66 |  |  |  |  | 
| 56 | 5 |  |  |  |  | 17 | $self->[SKIP] = $args{skip}; | 
| 57 | 5 |  |  |  |  | 14 | delete $args{skip}; | 
| 58 |  |  |  |  |  |  | } | 
| 59 |  |  |  |  |  |  |  | 
| 60 | 14 | 50 |  |  |  | 41 | if(exists $args{minimum}) { | 
| 61 |  |  |  |  |  |  | croak 'argument minimum must be a non-negative integer' | 
| 62 |  |  |  |  |  |  | unless defined $args{minimum} | 
| 63 |  |  |  |  |  |  | and $args{minimum} !~ /\D/ | 
| 64 | 0 | 0 | 0 |  |  | 0 | and int $args{minimum} == $args{minimum}; | 
|  |  |  | 0 |  |  |  |  | 
| 65 |  |  |  |  |  |  | croak 'argument minimum must greater than or equal to skip' | 
| 66 |  |  |  |  |  |  | unless defined $args{minimum} | 
| 67 | 0 | 0 | 0 |  |  | 0 | and $args{minimum} >= $self->[SKIP]; | 
| 68 | 0 |  |  |  |  | 0 | $self->[MINIMUM] = $args{minimum}; | 
| 69 | 0 |  |  |  |  | 0 | delete $args{minimum}; | 
| 70 |  |  |  |  |  |  | } | 
| 71 |  |  |  |  |  |  |  | 
| 72 |  |  |  |  |  |  | my $confidence_is_valid = | 
| 73 |  |  |  |  |  |  | (defined $args{confidence} | 
| 74 |  |  |  |  |  |  | and $args{confidence} =~ /^\d*\.?\d*$/ | 
| 75 |  |  |  |  |  |  | and $args{confidence} > 0 | 
| 76 | 14 |  | 0 |  |  | 53 | and $args{confidence} < 100); | 
| 77 |  |  |  |  |  |  |  | 
| 78 |  |  |  |  |  |  | my $error_is_valid = | 
| 79 |  |  |  |  |  |  | (defined $args{error} | 
| 80 |  |  |  |  |  |  | and $args{error} =~ /^\d*\.?\d*$/ | 
| 81 |  |  |  |  |  |  | and $args{error} > 0 | 
| 82 | 14 |  | 0 |  |  | 50 | and $args{error} < 100); | 
| 83 |  |  |  |  |  |  |  | 
| 84 | 14 | 50 | 33 |  |  | 138 | if ($confidence_is_valid && !$error_is_valid || | 
|  |  | 50 | 33 |  |  |  |  | 
|  |  |  | 33 |  |  |  |  | 
|  |  |  | 33 |  |  |  |  | 
| 85 |  |  |  |  |  |  | !$confidence_is_valid && $error_is_valid) | 
| 86 |  |  |  |  |  |  | { | 
| 87 | 0 |  |  |  |  | 0 | carp 'you must specify both confidence and error' | 
| 88 |  |  |  |  |  |  | } | 
| 89 |  |  |  |  |  |  | elsif ($confidence_is_valid && $error_is_valid) | 
| 90 |  |  |  |  |  |  | { | 
| 91 | 0 |  |  |  |  | 0 | $self->[CONFIDENCE] = $args{confidence}; | 
| 92 | 0 |  |  |  |  | 0 | delete $args{confidence}; | 
| 93 |  |  |  |  |  |  |  | 
| 94 | 0 |  |  |  |  | 0 | $self->[ERROR] = $args{error}; | 
| 95 | 0 |  |  |  |  | 0 | delete $args{error}; | 
| 96 |  |  |  |  |  |  |  | 
| 97 |  |  |  |  |  |  | # Demand load the module we need. We could just | 
| 98 |  |  |  |  |  |  | # require people to install it... | 
| 99 |  |  |  |  |  |  | croak 'Could not load the Statistics::PointEstimation module' | 
| 100 | 0 | 0 |  |  |  | 0 | unless eval {require Statistics::PointEstimation}; | 
|  | 0 |  |  |  |  | 0 |  | 
| 101 |  |  |  |  |  |  | } | 
| 102 |  |  |  |  |  |  |  | 
| 103 | 14 | 100 |  |  |  | 42 | if(%args) { | 
| 104 | 1 |  |  |  |  | 124 | carp 'skipping unknown arguments'; | 
| 105 |  |  |  |  |  |  | } | 
| 106 |  |  |  |  |  |  |  | 
| 107 | 14 |  |  |  |  | 60 | return $self; | 
| 108 |  |  |  |  |  |  | } | 
| 109 |  |  |  |  |  |  |  | 
| 110 |  |  |  |  |  |  |  | 
| 111 |  |  |  |  |  |  | # In this routine we try hard to make the [ gettimeofday ] take place | 
| 112 |  |  |  |  |  |  | # as late as possible to minimize Heisenberg problems. :) | 
| 113 |  |  |  |  |  |  |  | 
| 114 |  |  |  |  |  |  | sub start { | 
| 115 | 65 |  |  | 65 | 1 | 2109 | my $self = shift; | 
| 116 | 65 |  | 0 |  |  | 168 | my $tag = shift || $self->[LASTTAG] || '_default'; | 
| 117 | 65 |  |  |  |  | 130 | $self->[LASTTAG] = $tag; | 
| 118 | 65 | 100 |  |  |  | 149 | if(exists $self->[SKIPCOUNT]->{$tag}) { | 
| 119 | 55 | 100 |  |  |  | 119 | if($self->[SKIPCOUNT]->{$tag} > 1) { | 
| 120 | 26 |  |  |  |  | 57 | $self->[SKIPCOUNT]->{$tag}--; | 
| 121 |  |  |  |  |  |  | } else { | 
| 122 | 29 |  |  |  |  | 54 | $self->[SKIPCOUNT]->{$tag} = 0; | 
| 123 | 29 |  |  |  |  | 57 | push @{$self->[BEFORE]->{$tag}}, [ gettimeofday ]; | 
|  | 29 |  |  |  |  | 141 |  | 
| 124 |  |  |  |  |  |  | } | 
| 125 |  |  |  |  |  |  | } else { | 
| 126 | 10 |  |  |  |  | 19 | push @{$self->[TAGS]}, $tag; | 
|  | 10 |  |  |  |  | 34 |  | 
| 127 | 10 |  |  |  |  | 38 | $self->[SKIPCOUNT]->{$tag} = $self->[SKIP] + 1; | 
| 128 | 10 | 100 |  |  |  | 34 | if($self->[SKIPCOUNT]->{$tag} > 1) { | 
| 129 | 4 |  |  |  |  | 10 | $self->[SKIPCOUNT]->{$tag}--; | 
| 130 |  |  |  |  |  |  | } else { | 
| 131 | 6 |  |  |  |  | 16 | $self->[SKIPCOUNT]->{$tag} = 0; | 
| 132 | 6 |  |  |  |  | 43 | $self->[BEFORE]->{$tag} = [ [ gettimeofday ] ] | 
| 133 |  |  |  |  |  |  | } | 
| 134 |  |  |  |  |  |  | } | 
| 135 |  |  |  |  |  |  | } | 
| 136 |  |  |  |  |  |  |  | 
| 137 |  |  |  |  |  |  |  | 
| 138 |  |  |  |  |  |  | sub stop { | 
| 139 | 67 |  |  | 67 | 1 | 377 | my $after = [ gettimeofday ];    # minimize overhead | 
| 140 | 67 |  |  |  |  | 138 | my $self = shift; | 
| 141 | 67 |  | 100 |  |  | 286 | my $tag = shift || $self->[LASTTAG] || '_default'; | 
| 142 |  |  |  |  |  |  |  | 
| 143 |  |  |  |  |  |  | croak 'must call $t->start($tag) before $t->stop($tag)' | 
| 144 | 67 | 100 |  |  |  | 387 | unless exists $self->[SKIPCOUNT]->{$tag}; | 
| 145 |  |  |  |  |  |  |  | 
| 146 | 66 | 100 |  |  |  | 198 | return if $self->[SKIPCOUNT]->{$tag} > 0; | 
| 147 |  |  |  |  |  |  |  | 
| 148 |  |  |  |  |  |  | my $i = exists $self->[ELAPSED]->{$tag} ? | 
| 149 | 36 | 100 |  |  |  | 85 | scalar @{$self->[ELAPSED]->{$tag}} : 0; | 
|  | 28 |  |  |  |  | 61 |  | 
| 150 | 36 |  |  |  |  | 73 | my $before = $self->[BEFORE]->{$tag}->[$i]; | 
| 151 | 36 | 100 |  |  |  | 161 | croak 'timer out of sync' unless defined $before; | 
| 152 |  |  |  |  |  |  |  | 
| 153 |  |  |  |  |  |  | # Create a stats object if we need to | 
| 154 | 35 | 50 | 33 |  |  | 102 | if (defined $self->[CONFIDENCE] && !defined $self->[STAT]->{$tag}) | 
| 155 |  |  |  |  |  |  | { | 
| 156 | 0 |  |  |  |  | 0 | $self->[STAT]->{$tag} = Statistics::PointEstimation->new; | 
| 157 | 0 |  |  |  |  | 0 | $self->[STAT]->{$tag}->set_significance($self->[CONFIDENCE]); | 
| 158 |  |  |  |  |  |  | } | 
| 159 |  |  |  |  |  |  |  | 
| 160 | 35 |  |  |  |  | 114 | my $elapsed = tv_interval($before, $after); | 
| 161 |  |  |  |  |  |  |  | 
| 162 | 35 | 100 |  |  |  | 520 | if($i > 0) { | 
| 163 | 27 |  |  |  |  | 46 | push @{$self->[ELAPSED]->{$tag}}, $elapsed; | 
|  | 27 |  |  |  |  | 98 |  | 
| 164 |  |  |  |  |  |  | } else { | 
| 165 | 8 |  |  |  |  | 61 | $self->[ELAPSED]->{$tag} = [ $elapsed ]; | 
| 166 |  |  |  |  |  |  | } | 
| 167 |  |  |  |  |  |  |  | 
| 168 |  |  |  |  |  |  | $self->[STAT]->{$tag}->add_data($elapsed) | 
| 169 | 35 | 50 |  |  |  | 120 | if defined $self->[STAT]->{$tag}; | 
| 170 |  |  |  |  |  |  |  | 
| 171 | 35 |  |  |  |  | 115 | return $elapsed; | 
| 172 |  |  |  |  |  |  | } | 
| 173 |  |  |  |  |  |  |  | 
| 174 |  |  |  |  |  |  |  | 
| 175 |  |  |  |  |  |  | sub need_more_samples { | 
| 176 | 0 |  |  | 0 | 1 | 0 | my $self = shift; | 
| 177 | 0 |  | 0 |  |  | 0 | my $tag = shift || $self->[LASTTAG] || '_default'; | 
| 178 |  |  |  |  |  |  |  | 
| 179 | 0 | 0 |  |  |  | 0 | carp 'You must set the confidence and error in order to use need_more_samples' | 
| 180 |  |  |  |  |  |  | unless defined $self->[CONFIDENCE]; | 
| 181 |  |  |  |  |  |  |  | 
| 182 |  |  |  |  |  |  | # In case this function is called before any trials are run | 
| 183 |  |  |  |  |  |  | return 1 | 
| 184 |  |  |  |  |  |  | if !defined $self->[STAT]->{$tag} || | 
| 185 | 0 | 0 | 0 |  |  | 0 | $self->[STAT]->{$tag}->count < $self->[MINIMUM]; | 
| 186 |  |  |  |  |  |  |  | 
| 187 |  |  |  |  |  |  | # For debugging | 
| 188 |  |  |  |  |  |  | #    printf STDERR "Average: %.5f +/- %.5f, Samples: %d\n", | 
| 189 |  |  |  |  |  |  | #      $self->[STAT]->{$tag}->mean(), $self->[STAT]->{$tag}->delta(), | 
| 190 |  |  |  |  |  |  | #      $self->[STAT]->{$tag}->count; | 
| 191 |  |  |  |  |  |  | #    printf STDERR "Percent Error: %.5f > %.5f\n", | 
| 192 |  |  |  |  |  |  | #      $self->[STAT]->{$tag}->delta() / $self->[STAT]->{$tag}->mean() * 100, | 
| 193 |  |  |  |  |  |  | #      $self->[ERROR]; | 
| 194 |  |  |  |  |  |  |  | 
| 195 | 0 |  |  |  |  | 0 | return (($self->[STAT]->{$tag}->delta() / $self->[STAT]->{$tag}->mean() * 100) > | 
| 196 |  |  |  |  |  |  | $self->[ERROR]); | 
| 197 |  |  |  |  |  |  | } | 
| 198 |  |  |  |  |  |  |  | 
| 199 |  |  |  |  |  |  |  | 
| 200 |  |  |  |  |  |  | sub report { | 
| 201 | 9 |  |  | 9 | 1 | 613 | my $self = shift; | 
| 202 | 9 |  | 50 |  |  | 34 | my $tag = shift || $self->[LASTTAG] || '_default'; | 
| 203 |  |  |  |  |  |  |  | 
| 204 | 9 | 50 |  |  |  | 25 | unless(exists $self->[ELAPSED]->{$tag}) { | 
| 205 | 0 |  |  |  |  | 0 | carp join ' ', 'tag', $tag, 'still running'; | 
| 206 | 0 |  |  |  |  | 0 | return; | 
| 207 |  |  |  |  |  |  | } | 
| 208 |  |  |  |  |  |  |  | 
| 209 | 9 |  |  |  |  | 29 | return $self->_report($tag); | 
| 210 |  |  |  |  |  |  | } | 
| 211 |  |  |  |  |  |  |  | 
| 212 |  |  |  |  |  |  |  | 
| 213 |  |  |  |  |  |  |  | 
| 214 |  |  |  |  |  |  | sub reports { | 
| 215 | 4 |  |  | 4 | 1 | 2669 | my $self = shift; | 
| 216 |  |  |  |  |  |  |  | 
| 217 | 4 | 100 |  |  |  | 14 | if (wantarray) | 
| 218 |  |  |  |  |  |  | { | 
| 219 | 2 |  |  |  |  | 5 | my @reports; | 
| 220 |  |  |  |  |  |  |  | 
| 221 | 2 |  |  |  |  | 4 | foreach my $tag (@{$self->[TAGS]}) { | 
|  | 2 |  |  |  |  | 7 |  | 
| 222 | 3 |  |  |  |  | 9 | push @reports, $tag; | 
| 223 | 3 |  |  |  |  | 9 | push @reports, $self->report($tag); | 
| 224 |  |  |  |  |  |  | } | 
| 225 |  |  |  |  |  |  |  | 
| 226 | 2 |  |  |  |  | 15 | return @reports; | 
| 227 |  |  |  |  |  |  | } | 
| 228 |  |  |  |  |  |  | else | 
| 229 |  |  |  |  |  |  | { | 
| 230 | 2 |  |  |  |  | 5 | my $report = ''; | 
| 231 |  |  |  |  |  |  |  | 
| 232 | 2 |  |  |  |  | 12 | foreach my $tag (@{$self->[TAGS]}) { | 
|  | 2 |  |  |  |  | 8 |  | 
| 233 | 3 |  |  |  |  | 9 | $report .= $self->report($tag); | 
| 234 |  |  |  |  |  |  | } | 
| 235 |  |  |  |  |  |  |  | 
| 236 | 2 |  |  |  |  | 10 | return $report; | 
| 237 |  |  |  |  |  |  | } | 
| 238 |  |  |  |  |  |  | } | 
| 239 |  |  |  |  |  |  |  | 
| 240 |  |  |  |  |  |  |  | 
| 241 |  |  |  |  |  |  | sub _report { | 
| 242 | 9 |  |  | 9 |  | 12 | my $self = shift; | 
| 243 | 9 |  |  |  |  | 18 | my $tag = shift; | 
| 244 |  |  |  |  |  |  |  | 
| 245 | 9 | 50 |  |  |  | 20 | unless(exists $self->[ELAPSED]->{$tag}) { | 
| 246 | 0 |  |  |  |  | 0 | return "Tag $tag is still running or has not completed its skipped runs, skipping\n"; | 
| 247 |  |  |  |  |  |  | } | 
| 248 |  |  |  |  |  |  |  | 
| 249 | 9 |  |  |  |  | 16 | my $report = ''; | 
| 250 |  |  |  |  |  |  |  | 
| 251 | 9 |  |  |  |  | 17 | my @times = @{$self->[ELAPSED]->{$tag}}; | 
|  | 9 |  |  |  |  | 23 |  | 
| 252 | 9 |  |  |  |  | 20 | my $n = scalar @times; | 
| 253 | 9 |  |  |  |  | 27 | my $total = 0; $total += $_ foreach @times; | 
|  | 9 |  |  |  |  | 33 |  | 
| 254 |  |  |  |  |  |  |  | 
| 255 | 9 | 100 |  |  |  | 23 | if ($n == 1) | 
| 256 |  |  |  |  |  |  | { | 
| 257 | 4 |  |  |  |  | 12 | $report .= sprintf "\%d trial of \%s (\%s total)\n", | 
| 258 |  |  |  |  |  |  | $n, $tag, _timestr($total); | 
| 259 |  |  |  |  |  |  | } | 
| 260 |  |  |  |  |  |  | else | 
| 261 |  |  |  |  |  |  | { | 
| 262 | 5 |  |  |  |  | 13 | $report .= sprintf "\%d trials of \%s (\%s total), \%s/trial\n", | 
| 263 |  |  |  |  |  |  | $n, $tag, _timestr($total), _timestr($total / $n); | 
| 264 |  |  |  |  |  |  | } | 
| 265 |  |  |  |  |  |  |  | 
| 266 | 9 | 50 |  |  |  | 52 | if (defined $self->[STAT]->{$tag}) | 
| 267 |  |  |  |  |  |  | { | 
| 268 | 0 |  |  |  |  | 0 | my $delta = 0; | 
| 269 |  |  |  |  |  |  | $delta = $self->[STAT]->{$tag}->delta() | 
| 270 | 0 | 0 |  |  |  | 0 | if defined $self->[STAT]->{$tag}->delta(); | 
| 271 |  |  |  |  |  |  |  | 
| 272 | 0 |  |  |  |  | 0 | $report .= sprintf "Error: +/- \%.5f with \%s confidence\n", | 
| 273 |  |  |  |  |  |  | $delta, $self->[CONFIDENCE]; | 
| 274 |  |  |  |  |  |  | } | 
| 275 |  |  |  |  |  |  |  | 
| 276 | 9 |  |  |  |  | 37 | return $report; | 
| 277 |  |  |  |  |  |  | } | 
| 278 |  |  |  |  |  |  |  | 
| 279 |  |  |  |  |  |  |  | 
| 280 |  |  |  |  |  |  |  | 
| 281 |  |  |  |  |  |  | sub result { | 
| 282 | 3 |  |  | 3 | 1 | 364 | my $self = shift; | 
| 283 | 3 |  | 0 |  |  | 11 | my $tag = shift || $self->[LASTTAG] || '_default'; | 
| 284 | 3 | 50 |  |  |  | 13 | unless(exists $self->[ELAPSED]->{$tag}) { | 
| 285 | 0 |  |  |  |  | 0 | carp join ' ', 'tag', $tag, 'still running'; | 
| 286 | 0 |  |  |  |  | 0 | return; | 
| 287 |  |  |  |  |  |  | } | 
| 288 | 3 |  |  |  |  | 6 | my @times = @{$self->[ELAPSED]->{$tag}}; | 
|  | 3 |  |  |  |  | 9 |  | 
| 289 | 3 |  |  |  |  | 6 | my $total = 0; $total += $_ foreach @times; | 
|  | 3 |  |  |  |  | 12 |  | 
| 290 | 3 |  |  |  |  | 14 | return $total / @times; | 
| 291 |  |  |  |  |  |  | } | 
| 292 |  |  |  |  |  |  |  | 
| 293 |  |  |  |  |  |  |  | 
| 294 |  |  |  |  |  |  | sub results { | 
| 295 | 2 |  |  | 2 | 1 | 1170 | my $self = shift; | 
| 296 | 2 |  |  |  |  | 5 | my @results; | 
| 297 | 2 |  |  |  |  | 4 | foreach my $tag (@{$self->[TAGS]}) { | 
|  | 2 |  |  |  |  | 6 |  | 
| 298 | 2 |  |  |  |  | 6 | push @results, $tag; | 
| 299 | 2 |  |  |  |  | 7 | push @results, $self->result($tag); | 
| 300 |  |  |  |  |  |  | } | 
| 301 | 2 | 100 |  |  |  | 10 | return wantarray ? @results : \@results; | 
| 302 |  |  |  |  |  |  | } | 
| 303 |  |  |  |  |  |  |  | 
| 304 |  |  |  |  |  |  |  | 
| 305 |  |  |  |  |  |  |  | 
| 306 |  |  |  |  |  |  | sub data { | 
| 307 | 10 |  |  | 10 | 1 | 2056 | my $self = shift; | 
| 308 | 10 |  |  |  |  | 23 | my $tag = shift; | 
| 309 | 10 |  |  |  |  | 20 | my @results; | 
| 310 | 10 | 100 |  |  |  | 26 | if($tag) { | 
| 311 | 8 | 100 |  |  |  | 39 | if(exists $self->[ELAPSED]->{$tag}) { | 
| 312 | 6 |  |  |  |  | 12 | @results = @{$self->[ELAPSED]->{$tag}}; | 
|  | 6 |  |  |  |  | 20 |  | 
| 313 |  |  |  |  |  |  | } else { | 
| 314 | 2 |  |  |  |  | 6 | @results = (); | 
| 315 |  |  |  |  |  |  | } | 
| 316 |  |  |  |  |  |  | } else { | 
| 317 | 2 |  | 50 |  |  | 13 | @results = map { ( $_ => $self->[ELAPSED]->{$_} || [] ) } | 
| 318 | 2 |  |  |  |  | 5 | @{$self->[TAGS]}; | 
|  | 2 |  |  |  |  | 5 |  | 
| 319 |  |  |  |  |  |  | } | 
| 320 | 10 | 100 |  |  |  | 52 | return wantarray ? @results : \@results; | 
| 321 |  |  |  |  |  |  | } | 
| 322 |  |  |  |  |  |  |  | 
| 323 |  |  |  |  |  |  |  | 
| 324 |  |  |  |  |  |  | # ------------------------------------------------------------------------ | 
| 325 |  |  |  |  |  |  | # Internal utility subroutines | 
| 326 |  |  |  |  |  |  |  | 
| 327 |  |  |  |  |  |  | # _timestr($sec) takes a floating-point number of seconds and formats | 
| 328 |  |  |  |  |  |  | # it in a sensible way, commifying large numbers of seconds, and | 
| 329 |  |  |  |  |  |  | # converting to milliseconds if it makes sense. Since Time::HiRes has | 
| 330 |  |  |  |  |  |  | # at most microsecond resolution, no attempt is made to convert into | 
| 331 |  |  |  |  |  |  | # anything below that. A unit string is appended to the number. | 
| 332 |  |  |  |  |  |  |  | 
| 333 |  |  |  |  |  |  | sub _timestr { | 
| 334 | 14 |  |  | 14 |  | 31 | my $sec = shift; | 
| 335 | 14 |  |  |  |  | 20 | my $retstr; | 
| 336 | 14 | 50 |  |  |  | 62 | if($sec >= 1_000) { | 
|  |  | 50 |  |  |  |  |  | 
|  |  | 50 |  |  |  |  |  | 
|  |  | 50 |  |  |  |  |  | 
| 337 | 0 |  |  |  |  | 0 | $retstr = _commify(int $sec) . 's'; | 
| 338 |  |  |  |  |  |  | } elsif($sec >= 1) { | 
| 339 | 0 | 0 |  |  |  | 0 | $retstr = sprintf $sec == int $sec ? '%ds' : '%0.3fs', $sec; | 
| 340 |  |  |  |  |  |  | } elsif($sec >= 0.001) { | 
| 341 | 0 |  |  |  |  | 0 | my $ms = $sec * 1_000; | 
| 342 | 0 | 0 |  |  |  | 0 | $retstr = sprintf $ms == int $ms ? '%dms' : '%0.3fms', $ms; | 
| 343 |  |  |  |  |  |  | } elsif($sec >= 0.000001) { | 
| 344 | 14 |  |  |  |  | 54 | $retstr = sprintf '%dus', $sec * 1_000_000; | 
| 345 |  |  |  |  |  |  | } else { | 
| 346 |  |  |  |  |  |  | # I'll have whatever real-time OS she's having | 
| 347 | 0 |  |  |  |  | 0 | $retstr = $sec . 's'; | 
| 348 |  |  |  |  |  |  | } | 
| 349 | 14 |  |  |  |  | 61 | $retstr; | 
| 350 |  |  |  |  |  |  | } | 
| 351 |  |  |  |  |  |  |  | 
| 352 |  |  |  |  |  |  |  | 
| 353 |  |  |  |  |  |  | # _commify($num) inserts a grouping comma according to en-US standards | 
| 354 |  |  |  |  |  |  | # for numbers larger than 1000. For example, the integer 123456 would | 
| 355 |  |  |  |  |  |  | # be written 123,456. Any fractional part is left untouched. | 
| 356 |  |  |  |  |  |  |  | 
| 357 |  |  |  |  |  |  | sub _commify { | 
| 358 | 0 |  |  | 0 |  |  | my $num = shift; | 
| 359 | 0 | 0 |  |  |  |  | return unless $num =~ /\d/; | 
| 360 | 0 | 0 |  |  |  |  | return $num if $num < 1_000; | 
| 361 |  |  |  |  |  |  |  | 
| 362 | 0 |  |  |  |  |  | my $ip  = int $num; | 
| 363 | 0 |  |  |  |  |  | my($fp) = ($num =~ /\.(\d+)/); | 
| 364 |  |  |  |  |  |  |  | 
| 365 | 0 |  |  |  |  |  | $ip =~ s/(\d\d\d)$/,$1/; | 
| 366 | 0 |  |  |  |  |  | 1 while $ip =~ s/(\d)(\d\d\d),/$1,$2,/; | 
| 367 |  |  |  |  |  |  |  | 
| 368 | 0 | 0 |  |  |  |  | return $fp ? join '.', $ip, $fp : $ip; | 
| 369 |  |  |  |  |  |  | } | 
| 370 |  |  |  |  |  |  |  | 
| 371 |  |  |  |  |  |  | # ------------------------------------------------------------------------ | 
| 372 |  |  |  |  |  |  | # Return true for a valid Perl include | 
| 373 |  |  |  |  |  |  |  | 
| 374 |  |  |  |  |  |  | 1; | 
| 375 |  |  |  |  |  |  |  | 
| 376 |  |  |  |  |  |  | # --------------------------------------------------------------------------- | 
| 377 |  |  |  |  |  |  |  | 
| 378 |  |  |  |  |  |  | =head1 NAME | 
| 379 |  |  |  |  |  |  |  | 
| 380 |  |  |  |  |  |  | Benchmark::Timer - Benchmarking with statistical confidence | 
| 381 |  |  |  |  |  |  |  | 
| 382 |  |  |  |  |  |  |  | 
| 383 |  |  |  |  |  |  | =head1 SYNOPSIS | 
| 384 |  |  |  |  |  |  |  | 
| 385 |  |  |  |  |  |  | # Non-statistical usage | 
| 386 |  |  |  |  |  |  | use Benchmark::Timer; | 
| 387 |  |  |  |  |  |  | $t = Benchmark::Timer->new(skip => 1); | 
| 388 |  |  |  |  |  |  |  | 
| 389 |  |  |  |  |  |  | for(1 .. 1000) { | 
| 390 |  |  |  |  |  |  | $t->start('tag'); | 
| 391 |  |  |  |  |  |  | &long_running_operation(); | 
| 392 |  |  |  |  |  |  | $t->stop('tag'); | 
| 393 |  |  |  |  |  |  | } | 
| 394 |  |  |  |  |  |  | print $t->report; | 
| 395 |  |  |  |  |  |  |  | 
| 396 |  |  |  |  |  |  | # -------------------------------------------------------------------- | 
| 397 |  |  |  |  |  |  |  | 
| 398 |  |  |  |  |  |  | # Statistical usage | 
| 399 |  |  |  |  |  |  | use Benchmark::Timer; | 
| 400 |  |  |  |  |  |  | $t = Benchmark::Timer->new(skip => 1, confidence => 97.5, error => 2); | 
| 401 |  |  |  |  |  |  |  | 
| 402 |  |  |  |  |  |  | while($t->need_more_samples('tag')) { | 
| 403 |  |  |  |  |  |  | $t->start('tag'); | 
| 404 |  |  |  |  |  |  | &long_running_operation(); | 
| 405 |  |  |  |  |  |  | $t->stop('tag'); | 
| 406 |  |  |  |  |  |  | } | 
| 407 |  |  |  |  |  |  | print $t->report; | 
| 408 |  |  |  |  |  |  |  | 
| 409 |  |  |  |  |  |  | =head1 DESCRIPTION | 
| 410 |  |  |  |  |  |  |  | 
| 411 |  |  |  |  |  |  | The Benchmark::Timer class allows you to time portions of code | 
| 412 |  |  |  |  |  |  | conveniently, as well as benchmark code by allowing timings of repeated | 
| 413 |  |  |  |  |  |  | trials. It is perfect for when you need more precise information about the | 
| 414 |  |  |  |  |  |  | running time of portions of your code than the Benchmark module will give | 
| 415 |  |  |  |  |  |  | you, but don't want to go all out and profile your code. | 
| 416 |  |  |  |  |  |  |  | 
| 417 |  |  |  |  |  |  | The methodology is simple; create a Benchmark::Timer object, and wrap portions | 
| 418 |  |  |  |  |  |  | of code that you want to benchmark with C and C method calls. | 
| 419 |  |  |  |  |  |  | You can supply a tag to those methods if you plan to time multiple portions of | 
| 420 |  |  |  |  |  |  | code.  If you provide error and confidence values, you can also use | 
| 421 |  |  |  |  |  |  | C to determine, statistically, whether you need to | 
| 422 |  |  |  |  |  |  | collect more data. | 
| 423 |  |  |  |  |  |  |  | 
| 424 |  |  |  |  |  |  | After you have run your code, you can obtain information about the running | 
| 425 |  |  |  |  |  |  | time by calling the C method, or get a descriptive benchmark report | 
| 426 |  |  |  |  |  |  | by calling C.  If you run your code over multiple trials, the | 
| 427 |  |  |  |  |  |  | average time is reported.  This is wonderful for benchmarking time-critical | 
| 428 |  |  |  |  |  |  | portions of code in a rigorous way. You can also optionally choose to skip any | 
| 429 |  |  |  |  |  |  | number of initial trials to cut down on initial case irregularities. | 
| 430 |  |  |  |  |  |  |  | 
| 431 |  |  |  |  |  |  | =head1 METHODS | 
| 432 |  |  |  |  |  |  |  | 
| 433 |  |  |  |  |  |  | In all of the following methods, C<$tag> refers to the user-supplied name of | 
| 434 |  |  |  |  |  |  | the code being timed. Unless otherwise specified, $tag defaults to the tag of | 
| 435 |  |  |  |  |  |  | the last call to C, or "_default" if C was not previously | 
| 436 |  |  |  |  |  |  | called with a tag. | 
| 437 |  |  |  |  |  |  |  | 
| 438 |  |  |  |  |  |  | =over 4 | 
| 439 |  |  |  |  |  |  |  | 
| 440 |  |  |  |  |  |  | =item $t = Benchmark::Timer->new( [options] ); | 
| 441 |  |  |  |  |  |  |  | 
| 442 |  |  |  |  |  |  | Constructor for the Benchmark::Timer object; returns a reference to a | 
| 443 |  |  |  |  |  |  | timer object. Takes the following named arguments: | 
| 444 |  |  |  |  |  |  |  | 
| 445 |  |  |  |  |  |  | =over 4 | 
| 446 |  |  |  |  |  |  |  | 
| 447 |  |  |  |  |  |  | =item skip | 
| 448 |  |  |  |  |  |  |  | 
| 449 |  |  |  |  |  |  | The number of trials (if any) to skip before recording timing information. | 
| 450 |  |  |  |  |  |  |  | 
| 451 |  |  |  |  |  |  | =item minimum | 
| 452 |  |  |  |  |  |  |  | 
| 453 |  |  |  |  |  |  | The minimum number of trials to run. | 
| 454 |  |  |  |  |  |  |  | 
| 455 |  |  |  |  |  |  | =item error | 
| 456 |  |  |  |  |  |  |  | 
| 457 |  |  |  |  |  |  | A percentage between 0 and 100 which indicates how much error you are willing | 
| 458 |  |  |  |  |  |  | to tolerate in the average time measured by the benchmark.  For example, a | 
| 459 |  |  |  |  |  |  | value of 1 means that you want the reported average time to be within 1% of | 
| 460 |  |  |  |  |  |  | the real average time. C will use this value to determine | 
| 461 |  |  |  |  |  |  | when it is okay to stop collecting data. | 
| 462 |  |  |  |  |  |  |  | 
| 463 |  |  |  |  |  |  | If you specify an error you must also specify a confidence. | 
| 464 |  |  |  |  |  |  |  | 
| 465 |  |  |  |  |  |  | =item confidence | 
| 466 |  |  |  |  |  |  |  | 
| 467 |  |  |  |  |  |  | A percentage between 0 and 100 which indicates how confident you want to be in | 
| 468 |  |  |  |  |  |  | the error measured by the benchmark. For example, a value of 97.5 means that | 
| 469 |  |  |  |  |  |  | you want to be 97.5% confident that the real average time is within the error | 
| 470 |  |  |  |  |  |  | margin you have specified. C will use this value to | 
| 471 |  |  |  |  |  |  | compute the estimated error for the collected data, so that it can determine | 
| 472 |  |  |  |  |  |  | when it is okay to stop. | 
| 473 |  |  |  |  |  |  |  | 
| 474 |  |  |  |  |  |  | If you specify a confidence you must also specify an error. | 
| 475 |  |  |  |  |  |  |  | 
| 476 |  |  |  |  |  |  | =back | 
| 477 |  |  |  |  |  |  |  | 
| 478 |  |  |  |  |  |  | =item $t->reset; | 
| 479 |  |  |  |  |  |  |  | 
| 480 |  |  |  |  |  |  | Reset the timer object to the pristine state it started in. | 
| 481 |  |  |  |  |  |  | Erase all memory of tags and any previously accumulated timings. | 
| 482 |  |  |  |  |  |  | Returns a reference to the timer object. It takes the same arguments | 
| 483 |  |  |  |  |  |  | the constructor takes. | 
| 484 |  |  |  |  |  |  |  | 
| 485 |  |  |  |  |  |  | =item $t->start($tag); | 
| 486 |  |  |  |  |  |  |  | 
| 487 |  |  |  |  |  |  | Record the current time so that when C is called, we can calculate an | 
| 488 |  |  |  |  |  |  | elapsed time. | 
| 489 |  |  |  |  |  |  |  | 
| 490 |  |  |  |  |  |  | =item $t->stop($tag); | 
| 491 |  |  |  |  |  |  |  | 
| 492 |  |  |  |  |  |  | Record timing information. If $tag is supplied, it must correspond to one | 
| 493 |  |  |  |  |  |  | given to a previously called C call. It returns the elapsed time in | 
| 494 |  |  |  |  |  |  | milliseconds.  C croaks if the timer gets out of sync (e.g. the number | 
| 495 |  |  |  |  |  |  | of Cs does not match the number of Cs.) | 
| 496 |  |  |  |  |  |  |  | 
| 497 |  |  |  |  |  |  | =item $t->need_more_samples($tag); | 
| 498 |  |  |  |  |  |  |  | 
| 499 |  |  |  |  |  |  | Compute the estimated error in the average of the data collected thus far, and | 
| 500 |  |  |  |  |  |  | return true if that error exceeds the user-specified error. If a $tag is | 
| 501 |  |  |  |  |  |  | supplied, it must correspond to one given to a previously called C | 
| 502 |  |  |  |  |  |  | call. | 
| 503 |  |  |  |  |  |  |  | 
| 504 |  |  |  |  |  |  | This routine assumes that the data are normally distributed. | 
| 505 |  |  |  |  |  |  |  | 
| 506 |  |  |  |  |  |  | =item $t->report($tag); | 
| 507 |  |  |  |  |  |  |  | 
| 508 |  |  |  |  |  |  | Returns a string containing a simple report on the collected timings for $tag. | 
| 509 |  |  |  |  |  |  | This report contains the number of trials run, the total time taken, and, if | 
| 510 |  |  |  |  |  |  | more than one trial was run, the average time needed to run one trial and | 
| 511 |  |  |  |  |  |  | error information.  C will complain (via a warning) if a tag is | 
| 512 |  |  |  |  |  |  | still active. | 
| 513 |  |  |  |  |  |  |  | 
| 514 |  |  |  |  |  |  | =item $t->reports; | 
| 515 |  |  |  |  |  |  |  | 
| 516 |  |  |  |  |  |  | In a scalar context, returns a string containing a simple report on the | 
| 517 |  |  |  |  |  |  | collected timings for all tags. The report is a concatenation of the | 
| 518 |  |  |  |  |  |  | individual tag reports, in the original tag order. In an list context, returns | 
| 519 |  |  |  |  |  |  | a hash keyed by tag and containing reports for each tag. The return value is | 
| 520 |  |  |  |  |  |  | actually an array, so that the original tag order is preserved if you assign | 
| 521 |  |  |  |  |  |  | to an array instead of a hash. C will complain (via a warning) if a | 
| 522 |  |  |  |  |  |  | tag is still active. | 
| 523 |  |  |  |  |  |  |  | 
| 524 |  |  |  |  |  |  | =item $t->result($tag); | 
| 525 |  |  |  |  |  |  |  | 
| 526 |  |  |  |  |  |  | Return the time it took for $tag to elapse, or the mean time it took for $tag | 
| 527 |  |  |  |  |  |  | to elapse once, if $tag was used to time code more than once. C will | 
| 528 |  |  |  |  |  |  | complain (via a warning) if a tag is still active. | 
| 529 |  |  |  |  |  |  |  | 
| 530 |  |  |  |  |  |  | =item $t->results; | 
| 531 |  |  |  |  |  |  |  | 
| 532 |  |  |  |  |  |  | Returns the timing data as a hash keyed on tags where each value is | 
| 533 |  |  |  |  |  |  | the time it took to run that code, or the average time it took, | 
| 534 |  |  |  |  |  |  | if that code ran more than once. In scalar context it returns a reference | 
| 535 |  |  |  |  |  |  | to that hash. The return value is actually an array, so that the original | 
| 536 |  |  |  |  |  |  | tag order is preserved if you assign to an array instead of a hash. | 
| 537 |  |  |  |  |  |  |  | 
| 538 |  |  |  |  |  |  | =item $t->data($tag), $t->data; | 
| 539 |  |  |  |  |  |  |  | 
| 540 |  |  |  |  |  |  | These methods are useful if you want to recover the full internal timing | 
| 541 |  |  |  |  |  |  | data to roll your own reports. | 
| 542 |  |  |  |  |  |  |  | 
| 543 |  |  |  |  |  |  | If called with a $tag, returns the raw timing data for that $tag as | 
| 544 |  |  |  |  |  |  | an array (or a reference to an array if called in scalar context). This is | 
| 545 |  |  |  |  |  |  | useful for feeding to something like the Statistics::Descriptive package. | 
| 546 |  |  |  |  |  |  |  | 
| 547 |  |  |  |  |  |  | If called with no arguments, returns the raw timing data as a hash keyed | 
| 548 |  |  |  |  |  |  | on tags, where the values of the hash are lists of timings for that | 
| 549 |  |  |  |  |  |  | code. In scalar context, it returns a reference to that hash. As with | 
| 550 |  |  |  |  |  |  | C, the data is internally represented as an array so you can | 
| 551 |  |  |  |  |  |  | recover the original tag order by assigning to an array instead of a hash. | 
| 552 |  |  |  |  |  |  |  | 
| 553 |  |  |  |  |  |  | =back | 
| 554 |  |  |  |  |  |  |  | 
| 555 |  |  |  |  |  |  | =head1 BUGS | 
| 556 |  |  |  |  |  |  |  | 
| 557 |  |  |  |  |  |  | Benchmarking is an inherently futile activity, fraught with uncertainty | 
| 558 |  |  |  |  |  |  | not dissimilar to that experienced in quantum mechanics. But things are a | 
| 559 |  |  |  |  |  |  | little better if you apply statistics. | 
| 560 |  |  |  |  |  |  |  | 
| 561 |  |  |  |  |  |  | =head1 LICENSE | 
| 562 |  |  |  |  |  |  |  | 
| 563 |  |  |  |  |  |  | This code is distributed under the GNU General Public License (GPL) Version 2. | 
| 564 |  |  |  |  |  |  | See the file LICENSE in the distribution for details. | 
| 565 |  |  |  |  |  |  |  | 
| 566 |  |  |  |  |  |  | =head1 AUTHOR | 
| 567 |  |  |  |  |  |  |  | 
| 568 |  |  |  |  |  |  | The original code (written before April 20, 2001) was written by Andrew Ho | 
| 569 |  |  |  |  |  |  | Eandrew@zeuscat.comE, and is copyright (c) 2000-2001 Andrew Ho. | 
| 570 |  |  |  |  |  |  | Versions up to 0.5 are distributed under the same terms as Perl. | 
| 571 |  |  |  |  |  |  |  | 
| 572 |  |  |  |  |  |  | Maintenance of this module is now being done by David Coppit | 
| 573 |  |  |  |  |  |  | Edavid@coppit.orgE. | 
| 574 |  |  |  |  |  |  |  | 
| 575 |  |  |  |  |  |  | =head1 SEE ALSO | 
| 576 |  |  |  |  |  |  |  | 
| 577 |  |  |  |  |  |  | L, L, L, L | 
| 578 |  |  |  |  |  |  |  | 
| 579 |  |  |  |  |  |  | =cut |