| line |
stmt |
bran |
cond |
sub |
pod |
time |
code |
|
1
|
|
|
|
|
|
|
package DashProfiler::Sample; |
|
2
|
|
|
|
|
|
|
|
|
3
|
|
|
|
|
|
|
=head1 NAME |
|
4
|
|
|
|
|
|
|
|
|
5
|
|
|
|
|
|
|
DashProfiler::Sample - encapsulates the acquisition of a single sample |
|
6
|
|
|
|
|
|
|
|
|
7
|
|
|
|
|
|
|
=head1 DESCRIPTION |
|
8
|
|
|
|
|
|
|
|
|
9
|
|
|
|
|
|
|
Firstly, read L for a general introduction. |
|
10
|
|
|
|
|
|
|
|
|
11
|
|
|
|
|
|
|
A DashProfiler::Sample object is returned from the prepare() method of DashProfiler::Core, |
|
12
|
|
|
|
|
|
|
or from the functions imported by DashProfiler::Import. |
|
13
|
|
|
|
|
|
|
|
|
14
|
|
|
|
|
|
|
The object, and this class, are rarely used directly. |
|
15
|
|
|
|
|
|
|
|
|
16
|
|
|
|
|
|
|
=head1 METHODS |
|
17
|
|
|
|
|
|
|
|
|
18
|
|
|
|
|
|
|
=cut |
|
19
|
|
|
|
|
|
|
|
|
20
|
5
|
|
|
5
|
|
24
|
use strict; |
|
|
5
|
|
|
|
|
11
|
|
|
|
5
|
|
|
|
|
308
|
|
|
21
|
|
|
|
|
|
|
|
|
22
|
|
|
|
|
|
|
our $VERSION = sprintf("1.%06d", q$Revision: 48 $ =~ /(\d+)/o); |
|
23
|
|
|
|
|
|
|
|
|
24
|
5
|
|
|
5
|
|
26
|
use DBI; |
|
|
5
|
|
|
|
|
7
|
|
|
|
5
|
|
|
|
|
196
|
|
|
25
|
5
|
|
|
5
|
|
26
|
use DBI::Profile qw(dbi_profile dbi_time); |
|
|
5
|
|
|
|
|
7
|
|
|
|
5
|
|
|
|
|
360
|
|
|
26
|
5
|
|
|
5
|
|
24
|
use constant DBI_GE_1603 => ($DBI::VERSION >= 2.603); |
|
|
5
|
|
|
|
|
11
|
|
|
|
5
|
|
|
|
|
321
|
|
|
27
|
5
|
|
|
5
|
|
31
|
use Carp; |
|
|
5
|
|
|
|
|
13
|
|
|
|
5
|
|
|
|
|
480
|
|
|
28
|
|
|
|
|
|
|
|
|
29
|
|
|
|
|
|
|
BEGIN { |
|
30
|
|
|
|
|
|
|
# use env var to control debugging at compile-time |
|
31
|
|
|
|
|
|
|
# see pod for DEBUG at end |
|
32
|
5
|
|
50
|
5
|
|
112
|
my $debug = $ENV{DASHPROFILER_SAMPLE_DEBUG} || $ENV{DASHPROFILER_DEBUG} || 0; |
|
33
|
5
|
50
|
|
|
|
488
|
eval "sub DEBUG () { $debug }; 1;" or die; ## no critic |
|
34
|
|
|
|
|
|
|
} |
|
35
|
|
|
|
|
|
|
|
|
36
|
|
|
|
|
|
|
|
|
37
|
|
|
|
|
|
|
=head2 new |
|
38
|
|
|
|
|
|
|
|
|
39
|
|
|
|
|
|
|
This method is normally only called by the code reference returned from the |
|
40
|
|
|
|
|
|
|
DashProfiler::Core prepare() method, and not directly. |
|
41
|
|
|
|
|
|
|
|
|
42
|
|
|
|
|
|
|
$sample = DashProfiler::Sample->new($meta, $context2); |
|
43
|
|
|
|
|
|
|
$sample = DashProfiler::Sample->new($meta, $context2, $start_time, $allow_overlap); |
|
44
|
|
|
|
|
|
|
|
|
45
|
|
|
|
|
|
|
The returned object encapsulates the time of its creation and the supplied arguments. |
|
46
|
|
|
|
|
|
|
|
|
47
|
|
|
|
|
|
|
The $meta parameter must be a hash reference containing at least a |
|
48
|
|
|
|
|
|
|
'C<_dash_profile>' element which must be a reference to a DashProfiler::Core |
|
49
|
|
|
|
|
|
|
object. The new() method marks the profile as 'in use'. |
|
50
|
|
|
|
|
|
|
|
|
51
|
|
|
|
|
|
|
If the $context2 is false then $meta->{_context2} is used instead. |
|
52
|
|
|
|
|
|
|
|
|
53
|
|
|
|
|
|
|
If $start_time false, which it normally is, then the value returned by dbi_time() is used instead. |
|
54
|
|
|
|
|
|
|
|
|
55
|
|
|
|
|
|
|
If $allow_overlap is false, which it normally is, then if the DashProfiler |
|
56
|
|
|
|
|
|
|
refered to by the 'C<_dash_profile>' element of %$meta is marked as 'in use' |
|
57
|
|
|
|
|
|
|
then a warning is given (just once) and C returns undef, so no sample is |
|
58
|
|
|
|
|
|
|
taken. |
|
59
|
|
|
|
|
|
|
|
|
60
|
|
|
|
|
|
|
If $allow_overlap is true, then overlaping samples can be taken. However, if |
|
61
|
|
|
|
|
|
|
samples do overlap then C is disabled for that DashProfiler. |
|
62
|
|
|
|
|
|
|
|
|
63
|
|
|
|
|
|
|
=cut |
|
64
|
|
|
|
|
|
|
|
|
65
|
|
|
|
|
|
|
sub new { |
|
66
|
|
|
|
|
|
|
# ($class, $meta, $context2, $start_time, $allow_overlap) |
|
67
|
9213
|
|
|
9213
|
1
|
15626
|
my $profile_ref = $_[1]->{_dash_profile}; # $meta->_dash_profile |
|
68
|
9213
|
100
|
|
|
|
21801
|
if ($profile_ref->{in_use}++) { |
|
69
|
1
|
50
|
|
|
|
4
|
if ($profile_ref->{disabled}) { |
|
70
|
0
|
|
|
|
|
0
|
$profile_ref->{in_use}--; # undo the increment we did above |
|
71
|
0
|
|
|
|
|
0
|
return; |
|
72
|
|
|
|
|
|
|
} |
|
73
|
1
|
50
|
|
|
|
4
|
if ($_[4]) { # allow_overlaping_use |
|
74
|
|
|
|
|
|
|
# can't use exclusive timer with nested samples |
|
75
|
0
|
|
|
|
|
0
|
undef $profile_ref->{exclusive_sampler}; |
|
76
|
|
|
|
|
|
|
} |
|
77
|
|
|
|
|
|
|
else { |
|
78
|
1
|
50
|
|
|
|
218
|
Carp::cluck("$_[0] $profile_ref->{profile_name} already active") |
|
79
|
|
|
|
|
|
|
unless $profile_ref->{in_use_warning_given}++; # warn once |
|
80
|
1
|
|
|
|
|
89
|
return; # don't double count |
|
81
|
|
|
|
|
|
|
} |
|
82
|
|
|
|
|
|
|
} |
|
83
|
|
|
|
|
|
|
# to help debug nested profile samples you can uncomment this |
|
84
|
|
|
|
|
|
|
# and remove the ++ from the if() above and tweak the cluck message |
|
85
|
|
|
|
|
|
|
#$profile_ref->{in_use} = Carp::longmess(""); |
|
86
|
9212
|
|
66
|
|
|
72178
|
return bless [ |
|
|
|
|
66
|
|
|
|
|
|
87
|
|
|
|
|
|
|
$_[1], |
|
88
|
|
|
|
|
|
|
$_[2] || $_[1]->{_context2}, |
|
89
|
|
|
|
|
|
|
$_[3] || dbi_time(), # do this as late as practical |
|
90
|
|
|
|
|
|
|
] => $_[0]; |
|
91
|
|
|
|
|
|
|
} |
|
92
|
|
|
|
|
|
|
|
|
93
|
|
|
|
|
|
|
|
|
94
|
|
|
|
|
|
|
=head2 current_sample_duration |
|
95
|
|
|
|
|
|
|
|
|
96
|
|
|
|
|
|
|
$ps = foo_profiler(...); |
|
97
|
|
|
|
|
|
|
my $duration = $ps->current_sample_duration(); |
|
98
|
|
|
|
|
|
|
|
|
99
|
|
|
|
|
|
|
Returns the amount of time since the sample was created. |
|
100
|
|
|
|
|
|
|
|
|
101
|
|
|
|
|
|
|
=cut |
|
102
|
|
|
|
|
|
|
|
|
103
|
|
|
|
|
|
|
sub current_sample_duration { |
|
104
|
25063
|
|
|
25063
|
1
|
1100168
|
return dbi_time() - shift->[2]; |
|
105
|
|
|
|
|
|
|
} |
|
106
|
|
|
|
|
|
|
|
|
107
|
|
|
|
|
|
|
|
|
108
|
|
|
|
|
|
|
=head2 DESTROY |
|
109
|
|
|
|
|
|
|
|
|
110
|
|
|
|
|
|
|
When the DashProiler::Sample object is destroyed it: |
|
111
|
|
|
|
|
|
|
|
|
112
|
|
|
|
|
|
|
- calls dbi_time() to get the time of the end of the sample |
|
113
|
|
|
|
|
|
|
|
|
114
|
|
|
|
|
|
|
- marks the profile as no longer 'in use' |
|
115
|
|
|
|
|
|
|
|
|
116
|
|
|
|
|
|
|
- adds the timespan of the sample to the 'period_accumulated' of the DashProiler |
|
117
|
|
|
|
|
|
|
|
|
118
|
|
|
|
|
|
|
- extracts context2 from the DashProiler::Sample object. If it's a code reference |
|
119
|
|
|
|
|
|
|
then it's executed and the return value is used as context2. |
|
120
|
|
|
|
|
|
|
This is very useful where the value of context2 can't be determined |
|
121
|
|
|
|
|
|
|
at the time the sample is started. |
|
122
|
|
|
|
|
|
|
|
|
123
|
|
|
|
|
|
|
- if the $meta hash reference (passed to new()) contained a 'C' |
|
124
|
|
|
|
|
|
|
code reference then it's called and passed context2 and $meta. |
|
125
|
|
|
|
|
|
|
The return value is used as context2. |
|
126
|
|
|
|
|
|
|
|
|
127
|
|
|
|
|
|
|
- calls DBI::Profile::dbi_profile(handle, context1, context2, start time, end time) |
|
128
|
|
|
|
|
|
|
for each DBI profile currently attached to the DashProiler. |
|
129
|
|
|
|
|
|
|
|
|
130
|
|
|
|
|
|
|
=cut |
|
131
|
|
|
|
|
|
|
|
|
132
|
|
|
|
|
|
|
sub DESTROY { |
|
133
|
9212
|
|
|
9212
|
|
33795
|
my $end_time = dbi_time(); # get timestamp as early as practical |
|
134
|
|
|
|
|
|
|
|
|
135
|
|
|
|
|
|
|
# Any fatal errors won't be reported because we're in a DESTROY. |
|
136
|
|
|
|
|
|
|
# This can make debugging hard. If you suspect a problem then uncomment this: |
|
137
|
|
|
|
|
|
|
#local $SIG{__DIE__} = sub { warn @_ } if DEBUG(); ## no critic |
|
138
|
|
|
|
|
|
|
# Note that throwing an exception can be used by the context2edit hook |
|
139
|
|
|
|
|
|
|
# to 'veto' the sample. |
|
140
|
|
|
|
|
|
|
|
|
141
|
9212
|
|
|
|
|
9171
|
my ($meta, $context2, $start_time) = @{+shift}; |
|
|
9212
|
|
|
|
|
15826
|
|
|
142
|
|
|
|
|
|
|
|
|
143
|
9212
|
|
|
|
|
12676
|
my $profile_ref = $meta->{_dash_profile}; |
|
144
|
9212
|
|
|
|
|
10607
|
undef $profile_ref->{in_use}; |
|
145
|
9212
|
|
|
|
|
13206
|
$profile_ref->{period_accumulated} += $end_time - $start_time; |
|
146
|
|
|
|
|
|
|
|
|
147
|
9212
|
50
|
|
|
|
16679
|
$context2 = $context2->($meta) |
|
148
|
|
|
|
|
|
|
if ref $context2 eq 'CODE'; |
|
149
|
9212
|
50
|
|
|
|
16377
|
$context2 = $meta->{context2edit}->($context2, $meta) |
|
150
|
|
|
|
|
|
|
if ref $meta->{context2edit} eq 'CODE'; |
|
151
|
|
|
|
|
|
|
|
|
152
|
9212
|
|
|
|
|
7870
|
carp(sprintf "%s: %s %s: %f - %f = %f", |
|
153
|
|
|
|
|
|
|
$profile_ref->{profile_name}, $meta->{_context1}, $context2, $start_time, $end_time, $end_time-$start_time |
|
154
|
|
|
|
|
|
|
) if DEBUG() and DEBUG() >= 4; |
|
155
|
|
|
|
|
|
|
|
|
156
|
9212
|
|
|
|
|
8610
|
if (DBI_GE_1603()) { # use more functional dbi_profile() if available |
|
157
|
|
|
|
|
|
|
dbi_profile($profile_ref->{dbi_handles_active}, $meta->{_context1}, $context2, $start_time, $end_time); |
|
158
|
|
|
|
|
|
|
} |
|
159
|
|
|
|
|
|
|
else { |
|
160
|
|
|
|
|
|
|
# if you get an sv_dump ("SV = RV(0x181aa80) at 0x1889a80 ...") to stderr |
|
161
|
|
|
|
|
|
|
# it probably means %$dbi_handles_active contains a plain hash ref not a dbh |
|
162
|
9212
|
|
|
|
|
8571
|
for (values %{$profile_ref->{dbi_handles_active}}) { |
|
|
9212
|
|
|
|
|
22126
|
|
|
163
|
9213
|
50
|
|
|
|
16581
|
next unless defined; # skip any dead weakrefs |
|
164
|
9213
|
|
|
|
|
47229
|
dbi_profile($_, $meta->{_context1}, $context2, $start_time, $end_time); |
|
165
|
|
|
|
|
|
|
} |
|
166
|
|
|
|
|
|
|
} |
|
167
|
|
|
|
|
|
|
|
|
168
|
9212
|
|
|
|
|
1052633
|
return; |
|
169
|
|
|
|
|
|
|
} |
|
170
|
|
|
|
|
|
|
|
|
171
|
|
|
|
|
|
|
|
|
172
|
|
|
|
|
|
|
1; |
|
173
|
|
|
|
|
|
|
|
|
174
|
|
|
|
|
|
|
=head2 DEBUG |
|
175
|
|
|
|
|
|
|
|
|
176
|
|
|
|
|
|
|
The DEBUG subroutine is a constant that returns whatever the value of |
|
177
|
|
|
|
|
|
|
|
|
178
|
|
|
|
|
|
|
$ENV{DASHPROFILER_SAMPLE_DEBUG} || $ENV{DASHPROFILER_DEBUG} || 0; |
|
179
|
|
|
|
|
|
|
|
|
180
|
|
|
|
|
|
|
was when the modle was loaded. |
|
181
|
|
|
|
|
|
|
|
|
182
|
|
|
|
|
|
|
=head1 AUTHOR |
|
183
|
|
|
|
|
|
|
|
|
184
|
|
|
|
|
|
|
DashProfiler by Tim Bunce, L and |
|
185
|
|
|
|
|
|
|
L |
|
186
|
|
|
|
|
|
|
|
|
187
|
|
|
|
|
|
|
=head1 COPYRIGHT |
|
188
|
|
|
|
|
|
|
|
|
189
|
|
|
|
|
|
|
The DashProfiler distribution is Copyright (c) 2007-2008 Tim Bunce. Ireland. |
|
190
|
|
|
|
|
|
|
All rights reserved. |
|
191
|
|
|
|
|
|
|
|
|
192
|
|
|
|
|
|
|
You may distribute under the terms of either the GNU General Public |
|
193
|
|
|
|
|
|
|
License or the Artistic License, as specified in the Perl README file. |
|
194
|
|
|
|
|
|
|
|
|
195
|
|
|
|
|
|
|
=cut |
|
196
|
|
|
|
|
|
|
|