line |
stmt |
bran |
cond |
sub |
pod |
time |
code |
1
|
|
|
|
|
|
|
package Benchmark::Timer; |
2
|
|
|
|
|
|
|
require 5.005; |
3
|
5
|
|
|
5
|
|
84397
|
use strict; |
|
5
|
|
|
|
|
9
|
|
|
5
|
|
|
|
|
201
|
|
4
|
|
|
|
|
|
|
|
5
|
5
|
|
|
5
|
|
24
|
use Carp; |
|
5
|
|
|
|
|
6
|
|
|
5
|
|
|
|
|
400
|
|
6
|
5
|
|
|
5
|
|
2020
|
use Time::HiRes qw( gettimeofday tv_interval ); |
|
5
|
|
|
|
|
5142
|
|
|
5
|
|
|
|
|
23
|
|
7
|
|
|
|
|
|
|
|
8
|
5
|
|
|
5
|
|
871
|
use vars qw($VERSION); |
|
5
|
|
|
|
|
7
|
|
|
5
|
|
|
|
|
373
|
|
9
|
|
|
|
|
|
|
$VERSION = sprintf "%d.%02d%02d", q/0.71.7/ =~ /(\d+)/g; |
10
|
|
|
|
|
|
|
|
11
|
5
|
|
|
5
|
|
25
|
use constant BEFORE => 0; |
|
5
|
|
|
|
|
7
|
|
|
5
|
|
|
|
|
360
|
|
12
|
5
|
|
|
5
|
|
22
|
use constant ELAPSED => 1; |
|
5
|
|
|
|
|
5
|
|
|
5
|
|
|
|
|
202
|
|
13
|
5
|
|
|
5
|
|
20
|
use constant LASTTAG => 2; |
|
5
|
|
|
|
|
5
|
|
|
5
|
|
|
|
|
201
|
|
14
|
5
|
|
|
5
|
|
26
|
use constant TAGS => 3; |
|
5
|
|
|
|
|
13
|
|
|
5
|
|
|
|
|
207
|
|
15
|
5
|
|
|
5
|
|
19
|
use constant SKIP => 4; |
|
5
|
|
|
|
|
9
|
|
|
5
|
|
|
|
|
187
|
|
16
|
5
|
|
|
5
|
|
50
|
use constant MINIMUM => 5; |
|
5
|
|
|
|
|
9
|
|
|
5
|
|
|
|
|
191
|
|
17
|
5
|
|
|
5
|
|
21
|
use constant SKIPCOUNT => 6; |
|
5
|
|
|
|
|
15
|
|
|
5
|
|
|
|
|
213
|
|
18
|
5
|
|
|
5
|
|
19
|
use constant CONFIDENCE => 7; |
|
5
|
|
|
|
|
7
|
|
|
5
|
|
|
|
|
184
|
|
19
|
5
|
|
|
5
|
|
16
|
use constant ERROR => 8; |
|
5
|
|
|
|
|
7
|
|
|
5
|
|
|
|
|
260
|
|
20
|
5
|
|
|
5
|
|
26
|
use constant STAT => 9; |
|
5
|
|
|
|
|
5
|
|
|
5
|
|
|
|
|
11019
|
|
21
|
|
|
|
|
|
|
|
22
|
|
|
|
|
|
|
# ------------------------------------------------------------------------ |
23
|
|
|
|
|
|
|
# Constructor |
24
|
|
|
|
|
|
|
|
25
|
|
|
|
|
|
|
sub new { |
26
|
14
|
|
|
14
|
1
|
7190
|
my $class = shift; |
27
|
14
|
|
|
|
|
34
|
my $self = []; |
28
|
14
|
|
|
|
|
33
|
bless $self, $class; |
29
|
14
|
|
|
|
|
40
|
return $self->reset(@_); |
30
|
|
|
|
|
|
|
} |
31
|
|
|
|
|
|
|
|
32
|
|
|
|
|
|
|
|
33
|
|
|
|
|
|
|
# ------------------------------------------------------------------------ |
34
|
|
|
|
|
|
|
# Public methods |
35
|
|
|
|
|
|
|
|
36
|
|
|
|
|
|
|
sub reset { |
37
|
17
|
|
|
17
|
1
|
458
|
my $self = shift; |
38
|
17
|
|
|
|
|
39
|
my %args = @_; |
39
|
|
|
|
|
|
|
|
40
|
17
|
|
|
|
|
50
|
$self->[BEFORE] = {}; # [ gettimeofday ] storage |
41
|
17
|
|
|
|
|
30
|
$self->[ELAPSED] = {}; # elapsed fractional seconds |
42
|
17
|
|
|
|
|
22
|
$self->[LASTTAG] = undef; # what the last tag was |
43
|
17
|
|
|
|
|
23
|
$self->[TAGS] = []; # keep list of tags in order seen |
44
|
17
|
|
|
|
|
24
|
$self->[SKIP] = 0; # how many samples to skip |
45
|
17
|
|
|
|
|
26
|
$self->[MINIMUM] = 1; # the minimum number of trails to run |
46
|
17
|
|
|
|
|
26
|
$self->[SKIPCOUNT] = {}; # trial skip storage |
47
|
17
|
|
|
|
|
74
|
delete $self->[CONFIDENCE]; # confidence factor |
48
|
17
|
|
|
|
|
18
|
delete $self->[ERROR]; # allowable error |
49
|
17
|
|
|
|
|
21
|
delete $self->[STAT]; # stat objects for each tag |
50
|
|
|
|
|
|
|
|
51
|
17
|
100
|
|
|
|
45
|
if(exists $args{skip}) { |
52
|
8
|
100
|
100
|
|
|
371
|
croak 'argument skip must be a non-negative integer' |
|
|
|
66
|
|
|
|
|
53
|
|
|
|
|
|
|
unless defined $args{skip} |
54
|
|
|
|
|
|
|
and $args{skip} !~ /\D/ |
55
|
|
|
|
|
|
|
and int $args{skip} == $args{skip}; |
56
|
5
|
|
|
|
|
8
|
$self->[SKIP] = $args{skip}; |
57
|
5
|
|
|
|
|
10
|
delete $args{skip}; |
58
|
|
|
|
|
|
|
} |
59
|
|
|
|
|
|
|
|
60
|
14
|
50
|
|
|
|
32
|
if(exists $args{minimum}) { |
61
|
0
|
0
|
0
|
|
|
0
|
croak 'argument minimum must be a non-negative integer' |
|
|
|
0
|
|
|
|
|
62
|
|
|
|
|
|
|
unless defined $args{minimum} |
63
|
|
|
|
|
|
|
and $args{minimum} !~ /\D/ |
64
|
|
|
|
|
|
|
and int $args{minimum} == $args{minimum}; |
65
|
0
|
0
|
0
|
|
|
0
|
croak 'argument minimum must greater than or equal to skip' |
66
|
|
|
|
|
|
|
unless defined $args{minimum} |
67
|
|
|
|
|
|
|
and $args{minimum} >= $self->[SKIP]; |
68
|
0
|
|
|
|
|
0
|
$self->[MINIMUM] = $args{minimum}; |
69
|
0
|
|
|
|
|
0
|
delete $args{minimum}; |
70
|
|
|
|
|
|
|
} |
71
|
|
|
|
|
|
|
|
72
|
14
|
|
0
|
|
|
54
|
my $confidence_is_valid = |
73
|
|
|
|
|
|
|
(defined $args{confidence} |
74
|
|
|
|
|
|
|
and $args{confidence} =~ /^\d*\.?\d*$/ |
75
|
|
|
|
|
|
|
and $args{confidence} > 0 |
76
|
|
|
|
|
|
|
and $args{confidence} < 100); |
77
|
|
|
|
|
|
|
|
78
|
14
|
|
0
|
|
|
53
|
my $error_is_valid = |
79
|
|
|
|
|
|
|
(defined $args{error} |
80
|
|
|
|
|
|
|
and $args{error} =~ /^\d*\.?\d*$/ |
81
|
|
|
|
|
|
|
and $args{error} > 0 |
82
|
|
|
|
|
|
|
and $args{error} < 100); |
83
|
|
|
|
|
|
|
|
84
|
14
|
50
|
33
|
|
|
125
|
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
|
0
|
0
|
|
|
|
0
|
croak 'Could not load the Statistics::PointEstimation module' |
100
|
|
|
|
|
|
|
unless eval "require Statistics::PointEstimation"; |
101
|
|
|
|
|
|
|
} |
102
|
|
|
|
|
|
|
|
103
|
14
|
100
|
|
|
|
29
|
if(%args) { |
104
|
1
|
|
|
|
|
85
|
carp 'skipping unknown arguments'; |
105
|
|
|
|
|
|
|
} |
106
|
|
|
|
|
|
|
|
107
|
14
|
|
|
|
|
43
|
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
|
1212
|
my $self = shift; |
116
|
65
|
|
50
|
|
|
126
|
my $tag = shift || $self->[LASTTAG] || '_default'; |
117
|
65
|
|
|
|
|
93
|
$self->[LASTTAG] = $tag; |
118
|
65
|
100
|
|
|
|
106
|
if(exists $self->[SKIPCOUNT]->{$tag}) { |
119
|
55
|
100
|
|
|
|
85
|
if($self->[SKIPCOUNT]->{$tag} > 1) { |
120
|
26
|
|
|
|
|
50
|
$self->[SKIPCOUNT]->{$tag}--; |
121
|
|
|
|
|
|
|
} else { |
122
|
29
|
|
|
|
|
33
|
$self->[SKIPCOUNT]->{$tag} = 0; |
123
|
29
|
|
|
|
|
23
|
push @{$self->[BEFORE]->{$tag}}, [ gettimeofday ]; |
|
29
|
|
|
|
|
114
|
|
124
|
|
|
|
|
|
|
} |
125
|
|
|
|
|
|
|
} else { |
126
|
10
|
|
|
|
|
13
|
push @{$self->[TAGS]}, $tag; |
|
10
|
|
|
|
|
18
|
|
127
|
10
|
|
|
|
|
35
|
$self->[SKIPCOUNT]->{$tag} = $self->[SKIP] + 1; |
128
|
10
|
100
|
|
|
|
26
|
if($self->[SKIPCOUNT]->{$tag} > 1) { |
129
|
4
|
|
|
|
|
12
|
$self->[SKIPCOUNT]->{$tag}--; |
130
|
|
|
|
|
|
|
} else { |
131
|
6
|
|
|
|
|
12
|
$self->[SKIPCOUNT]->{$tag} = 0; |
132
|
6
|
|
|
|
|
56
|
$self->[BEFORE]->{$tag} = [ [ gettimeofday ] ] |
133
|
|
|
|
|
|
|
} |
134
|
|
|
|
|
|
|
} |
135
|
|
|
|
|
|
|
} |
136
|
|
|
|
|
|
|
|
137
|
|
|
|
|
|
|
|
138
|
|
|
|
|
|
|
sub stop { |
139
|
67
|
|
|
67
|
1
|
265
|
my $after = [ gettimeofday ]; # minimize overhead |
140
|
67
|
|
|
|
|
66
|
my $self = shift; |
141
|
67
|
|
100
|
|
|
239
|
my $tag = shift || $self->[LASTTAG] || '_default'; |
142
|
|
|
|
|
|
|
|
143
|
67
|
100
|
|
|
|
327
|
croak 'must call $t->start($tag) before $t->stop($tag)' |
144
|
|
|
|
|
|
|
unless exists $self->[SKIPCOUNT]->{$tag}; |
145
|
|
|
|
|
|
|
|
146
|
66
|
100
|
|
|
|
152
|
return if $self->[SKIPCOUNT]->{$tag} > 0; |
147
|
|
|
|
|
|
|
|
148
|
28
|
|
|
|
|
41
|
my $i = exists $self->[ELAPSED]->{$tag} ? |
149
|
36
|
100
|
|
|
|
68
|
scalar @{$self->[ELAPSED]->{$tag}} : 0; |
150
|
36
|
|
|
|
|
50
|
my $before = $self->[BEFORE]->{$tag}->[$i]; |
151
|
36
|
100
|
|
|
|
143
|
croak 'timer out of sync' unless defined $before; |
152
|
|
|
|
|
|
|
|
153
|
|
|
|
|
|
|
# Create a stats object if we need to |
154
|
35
|
50
|
33
|
|
|
67
|
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
|
|
|
|
|
82
|
my $elapsed = tv_interval($before, $after); |
161
|
|
|
|
|
|
|
|
162
|
35
|
100
|
|
|
|
315
|
if($i > 0) { |
163
|
27
|
|
|
|
|
25
|
push @{$self->[ELAPSED]->{$tag}}, $elapsed; |
|
27
|
|
|
|
|
55
|
|
164
|
|
|
|
|
|
|
} else { |
165
|
8
|
|
|
|
|
21
|
$self->[ELAPSED]->{$tag} = [ $elapsed ]; |
166
|
|
|
|
|
|
|
} |
167
|
|
|
|
|
|
|
|
168
|
35
|
50
|
|
|
|
76
|
$self->[STAT]->{$tag}->add_data($elapsed) |
169
|
|
|
|
|
|
|
if defined $self->[STAT]->{$tag}; |
170
|
|
|
|
|
|
|
|
171
|
35
|
|
|
|
|
64
|
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
|
0
|
0
|
0
|
|
|
0
|
return 1 |
184
|
|
|
|
|
|
|
if !defined $self->[STAT]->{$tag} || |
185
|
|
|
|
|
|
|
$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
|
678
|
my $self = shift; |
202
|
9
|
|
50
|
|
|
22
|
my $tag = shift || $self->[LASTTAG] || '_default'; |
203
|
|
|
|
|
|
|
|
204
|
9
|
50
|
|
|
|
16
|
unless(exists $self->[ELAPSED]->{$tag}) { |
205
|
0
|
|
|
|
|
0
|
carp join ' ', 'tag', $tag, 'still running'; |
206
|
0
|
|
|
|
|
0
|
return; |
207
|
|
|
|
|
|
|
} |
208
|
|
|
|
|
|
|
|
209
|
9
|
|
|
|
|
16
|
return $self->_report($tag); |
210
|
|
|
|
|
|
|
} |
211
|
|
|
|
|
|
|
|
212
|
|
|
|
|
|
|
|
213
|
|
|
|
|
|
|
|
214
|
|
|
|
|
|
|
sub reports { |
215
|
4
|
|
|
4
|
1
|
1447
|
my $self = shift; |
216
|
|
|
|
|
|
|
|
217
|
4
|
100
|
|
|
|
7
|
if (wantarray) |
218
|
|
|
|
|
|
|
{ |
219
|
2
|
|
|
|
|
3
|
my @reports; |
220
|
|
|
|
|
|
|
|
221
|
2
|
|
|
|
|
3
|
foreach my $tag (@{$self->[TAGS]}) { |
|
2
|
|
|
|
|
3
|
|
222
|
3
|
|
|
|
|
4
|
push @reports, $tag; |
223
|
3
|
|
|
|
|
5
|
push @reports, $self->report($tag); |
224
|
|
|
|
|
|
|
} |
225
|
|
|
|
|
|
|
|
226
|
2
|
|
|
|
|
8
|
return @reports; |
227
|
|
|
|
|
|
|
} |
228
|
|
|
|
|
|
|
else |
229
|
|
|
|
|
|
|
{ |
230
|
2
|
|
|
|
|
2
|
my $report = ''; |
231
|
|
|
|
|
|
|
|
232
|
2
|
|
|
|
|
2
|
foreach my $tag (@{$self->[TAGS]}) { |
|
2
|
|
|
|
|
4
|
|
233
|
3
|
|
|
|
|
4
|
$report .= $self->report($tag); |
234
|
|
|
|
|
|
|
} |
235
|
|
|
|
|
|
|
|
236
|
2
|
|
|
|
|
5
|
return $report; |
237
|
|
|
|
|
|
|
} |
238
|
|
|
|
|
|
|
} |
239
|
|
|
|
|
|
|
|
240
|
|
|
|
|
|
|
|
241
|
|
|
|
|
|
|
sub _report { |
242
|
9
|
|
|
9
|
|
6
|
my $self = shift; |
243
|
9
|
|
|
|
|
7
|
my $tag = shift; |
244
|
|
|
|
|
|
|
|
245
|
9
|
50
|
|
|
|
14
|
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
|
|
|
|
|
7
|
my $report = ''; |
250
|
|
|
|
|
|
|
|
251
|
9
|
|
|
|
|
7
|
my @times = @{$self->[ELAPSED]->{$tag}}; |
|
9
|
|
|
|
|
18
|
|
252
|
9
|
|
|
|
|
6
|
my $n = scalar @times; |
253
|
9
|
|
|
|
|
6
|
my $total = 0; $total += $_ foreach @times; |
|
9
|
|
|
|
|
24
|
|
254
|
|
|
|
|
|
|
|
255
|
9
|
100
|
|
|
|
14
|
if ($n == 1) |
256
|
|
|
|
|
|
|
{ |
257
|
4
|
|
|
|
|
6
|
$report .= sprintf "\%d trial of \%s (\%s total)\n", |
258
|
|
|
|
|
|
|
$n, $tag, timestr($total); |
259
|
|
|
|
|
|
|
} |
260
|
|
|
|
|
|
|
else |
261
|
|
|
|
|
|
|
{ |
262
|
5
|
|
|
|
|
8
|
$report .= sprintf "\%d trials of \%s (\%s total), \%s/trial\n", |
263
|
|
|
|
|
|
|
$n, $tag, timestr($total), timestr($total / $n); |
264
|
|
|
|
|
|
|
} |
265
|
|
|
|
|
|
|
|
266
|
9
|
50
|
|
|
|
18
|
if (defined $self->[STAT]->{$tag}) |
267
|
|
|
|
|
|
|
{ |
268
|
0
|
|
|
|
|
0
|
my $delta = 0; |
269
|
0
|
0
|
|
|
|
0
|
$delta = $self->[STAT]->{$tag}->delta() |
270
|
|
|
|
|
|
|
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
|
|
|
|
|
21
|
return $report; |
277
|
|
|
|
|
|
|
} |
278
|
|
|
|
|
|
|
|
279
|
|
|
|
|
|
|
|
280
|
|
|
|
|
|
|
|
281
|
|
|
|
|
|
|
sub result { |
282
|
3
|
|
|
3
|
1
|
301
|
my $self = shift; |
283
|
3
|
|
50
|
|
|
12
|
my $tag = shift || $self->[LASTTAG] || '_default'; |
284
|
3
|
50
|
|
|
|
10
|
unless(exists $self->[ELAPSED]->{$tag}) { |
285
|
0
|
|
|
|
|
0
|
carp join ' ', 'tag', $tag, 'still running'; |
286
|
0
|
|
|
|
|
0
|
return; |
287
|
|
|
|
|
|
|
} |
288
|
3
|
|
|
|
|
4
|
my @times = @{$self->[ELAPSED]->{$tag}}; |
|
3
|
|
|
|
|
8
|
|
289
|
3
|
|
|
|
|
4
|
my $total = 0; $total += $_ foreach @times; |
|
3
|
|
|
|
|
12
|
|
290
|
3
|
|
|
|
|
11
|
return $total / @times; |
291
|
|
|
|
|
|
|
} |
292
|
|
|
|
|
|
|
|
293
|
|
|
|
|
|
|
|
294
|
|
|
|
|
|
|
sub results { |
295
|
2
|
|
|
2
|
1
|
850
|
my $self = shift; |
296
|
2
|
|
|
|
|
3
|
my @results; |
297
|
2
|
|
|
|
|
2
|
foreach my $tag (@{$self->[TAGS]}) { |
|
2
|
|
|
|
|
6
|
|
298
|
2
|
|
|
|
|
3
|
push @results, $tag; |
299
|
2
|
|
|
|
|
5
|
push @results, $self->result($tag); |
300
|
|
|
|
|
|
|
} |
301
|
2
|
100
|
|
|
|
9
|
return wantarray ? @results : \@results; |
302
|
|
|
|
|
|
|
} |
303
|
|
|
|
|
|
|
|
304
|
|
|
|
|
|
|
|
305
|
|
|
|
|
|
|
|
306
|
|
|
|
|
|
|
sub data { |
307
|
10
|
|
|
10
|
1
|
1487
|
my $self = shift; |
308
|
10
|
|
|
|
|
13
|
my $tag = shift; |
309
|
10
|
|
|
|
|
8
|
my @results; |
310
|
10
|
100
|
|
|
|
22
|
if($tag) { |
311
|
8
|
100
|
|
|
|
16
|
if(exists $self->[ELAPSED]->{$tag}) { |
312
|
6
|
|
|
|
|
9
|
@results = @{$self->[ELAPSED]->{$tag}}; |
|
6
|
|
|
|
|
19
|
|
313
|
|
|
|
|
|
|
} else { |
314
|
2
|
|
|
|
|
4
|
@results = (); |
315
|
|
|
|
|
|
|
} |
316
|
|
|
|
|
|
|
} else { |
317
|
2
|
|
50
|
|
|
12
|
@results = map { ( $_ => $self->[ELAPSED]->{$_} || [] ) } |
|
2
|
|
|
|
|
6
|
|
318
|
2
|
|
|
|
|
3
|
@{$self->[TAGS]}; |
319
|
|
|
|
|
|
|
} |
320
|
10
|
100
|
|
|
|
41
|
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
|
0
|
14
|
my $sec = shift; |
335
|
14
|
|
|
|
|
7
|
my $retstr; |
336
|
14
|
50
|
|
|
|
34
|
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
|
|
|
|
|
36
|
$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
|
|
|
|
|
32
|
$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
|
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 |