File Coverage

blib/lib/DashProfiler/Core.pm
Criterion Covered Total %
statement 203 225 90.2
branch 60 108 55.5
condition 24 39 61.5
subroutine 38 41 92.6
pod 15 16 93.7
total 340 429 79.2


line stmt bran cond sub pod time code
1             package DashProfiler::Core;
2              
3             =head1 NAME
4              
5             DashProfiler::Core - DashProfiler core object and sampler factory
6              
7             =head1 SYNOPSIS
8              
9             See L for a general introduction.
10              
11             DashProfiler::Core is currently viewed as an internal class. The interface may change.
12             The DashProfiler and DashProfiler::Import modules are the usual interfaces.
13              
14             =head1 DESCRIPTION
15              
16             A DashProfiler::Core objects are the core of the DashProfiler, naturally.
17             They sit between the 'samplers' that feed data into a core, and the DBI::Profile
18             objects that aggregate those samples. A core may have multiple samplers and
19             multiple profiles.
20              
21             =cut
22              
23 5     5   155399 use strict;
  5         13  
  5         337  
24              
25             our $VERSION = sprintf("1.%06d", q$Revision: 48 $ =~ /(\d+)/o);
26              
27 5     5   9613 use DBI 1.57 qw(dbi_time dbi_profile_merge);
  5         71347  
  5         810  
28 5     5   5662 use DBI::Profile;
  5         17247  
  5         423  
29 5     5   4485 use DBI::ProfileDumper;
  5         13089  
  5         230  
30 5     5   37 use Carp;
  5         11  
  5         463  
31              
32             our $ENDING = 0;
33              
34             BEGIN {
35             # use env var to control debugging at compile-time
36 5   50 5   74 my $debug = $ENV{DASHPROFILER_CORE_DEBUG} || $ENV{DASHPROFILER_DEBUG} || 0;
37 5 50       346 eval "sub DEBUG () { $debug }; 1;" or die; ## no critic
38             }
39             END {
40 5     5   2190 $ENDING = 1;
41             }
42              
43              
44             BEGIN {
45             # load Hash::Util for lock_keys()
46             # if Hash::Util isn't available then install a stub for lock_keys()
47 5     5   13 eval {
48 5         4641 require Hash::Util;
49 5         12394 Hash::Util->import('lock_keys');
50             };
51 5 50 33     327 die @$ if $@ && $@ !~ /^Can't locate Hash\/Util/;
52 5 50       13105 *lock_keys = sub { } if not defined &lock_keys;
  0         0  
53             }
54              
55              
56             # check for weaken support, used by ChildHandles
57             my $HAS_WEAKEN = eval {
58             require Scalar::Util;
59             # this will croak() if this Scalar::Util doesn't have a working weaken().
60             Scalar::Util::weaken( my $test = [] );
61             1;
62             };
63             *weaken = sub { croak "Can't weaken without Scalar::Util::weaken" }
64             unless $HAS_WEAKEN;
65              
66              
67             # On 2GHz OS X 10.5.2 laptop:
68             # sample_overhead_time = 0.000014s
69             # sample_inner_time = 0.000003s
70             my ($sample_overhead_time, $sample_inner_time) = estimate_sample_overheads();
71              
72              
73             =head1 CLASS METHODS
74              
75             =head2 new
76              
77             $obj = DashProfiler::Core->new( 'foo' );
78              
79             $obj = DashProfiler::Core->new( 'bar', { ...options... } );
80              
81             $obj = DashProfiler::Core->new( extsys => {
82             granularity => 10,
83             flush_interval => 300,
84             } );
85              
86             Creates and returns a DashProfiler::Core object.
87              
88             =head2 Options for new()
89              
90             =head3 disabled
91              
92             Set to a true value to prevent samples being added to this core. If true, the
93             prepare() method and the L new() method will return undef.
94              
95             Default false.
96              
97             Currently, any existing samples that were active will still be added when they
98             terminate. This behaviour may change.
99              
100             See also L.
101              
102             =head3 dbi_profile_class
103              
104             Specifies the class to use for creating DBI::Profile objects.
105             The default is C. Alternatives include C
106             and C.
107              
108             =head3 dbi_profile_args
109              
110             Specifies extra arguments to pass the new() method of the C
111             (e.g., C). The default is C<{ }>.
112              
113             =head3 flush_interval
114              
115             How frequently the DBI:Profiles associated with this core should be written out
116             and the data reset. Default is 0 - no regular flushing.
117              
118             =head3 flush_hook
119              
120             If set, this code reference is called when flush() is called and can influence
121             its behaviour. For example, this is the flush_hook used by L:
122              
123             flush_hook => sub {
124             my ($self, $dbi_profile_name) = @_;
125             warn $_ for $self->profile_as_text($dbi_profile_name);
126             return $self->reset_profile_data($dbi_profile_name);
127             },
128              
129             See L for more details.
130              
131             =head3 granularity
132              
133             The default C for the DBI::Profile objects doesn't include time.
134             The granularity option adds 'C' to the front of the Path.
135             So as time passes the samples are aggregated into new sub-trees.
136              
137             =head3 sample_class
138              
139             The sample_class option specifies which class should be used to take profile samples.
140             The default is C.
141             See the L method for more information.
142              
143             =head3 period_summary
144              
145             Specifies the name of an extra DBI Profile object to attach to the core.
146             This extra 'period summary' profile is enabled and reset by the start_sample_period()
147             method and disabled by the end_sample_period() method.
148              
149             The mechanism enables a single profile to be used to capture both long-running
150             sampling (often with C set) and single-period (e.g., for a 'debug'
151             footer on a generated web page)
152              
153             =head3 period_exclusive
154              
155             When using periods, via the start_sample_period() and end_sample_period() methods,
156             DashProfiler can add an additional sample representing the time between the
157             start_sample_period() and end_sample_period() method calls that I
158             accounted for by the samples.
159              
160             The period_exclusive option enables this extra sample. The value of the option
161             is used as the value for key1 and key2 in the Path.
162              
163             =head3 period_strict_start
164              
165             See L.
166              
167             =head3 period_strict_end
168              
169             See L.
170              
171             =head3 profile_as_text_args
172              
173             A reference to a hash containing default formatting arguments for the profile_as_text() method.
174              
175             =head3 extra_info
176              
177             Can be used to attach any extra information to the profiler core object. That can be useful sometimes in callbacks.
178              
179             =cut
180              
181             sub new {
182 12     12 1 706 my ($class, $profile_name, $opt_params) = @_;
183 12   50     39 $opt_params ||= {};
184 12 50 33     87 croak "No profile_name given" unless $profile_name && not ref $profile_name;
185 12 50       46 croak "$class->new($profile_name, $opt_params) options must be a hash reference"
186             if ref $opt_params ne 'HASH';
187              
188 12   100     89 our $opt_defaults ||= {
189             disabled => 0,
190             sample_class => 'DashProfiler::Sample',
191             dbi_profile_class => 'DBI::Profile',
192             dbi_profile_args => {},
193             flush_interval => 0,
194             flush_hook => undef,
195             granularity => 0,
196             period_exclusive => undef,
197             period_summary => undef,
198             period_strict_start => 0x01,
199             period_strict_end => 0x00,
200             profile_as_text_args => undef,
201             extra_info => undef, # for caller to hook in their own data
202             };
203 0         0 croak "Invalid options: ".join(', ', grep { !$opt_defaults->{$_} } keys %$opt_params)
  12         176  
204 12 50       17 if keys %{ { %$opt_defaults, %$opt_params } } > keys %$opt_defaults;
205              
206 12         106 my $time = dbi_time();
207 12         193 my $self = bless {
208             profile_name => $profile_name,
209             in_use => 0,
210             in_use_warning_given => 0,
211             dbi_handles_all => {},
212             dbi_handles_active => {},
213             flush_due_at_time => undef,
214             # for start_period
215             period_count => 0,
216             period_start_time => 0,
217             period_accumulated => 0,
218             exclusive_sampler => undef,
219             %$opt_defaults,
220             %$opt_params,
221             } => $class;
222 12         91 $self->{flush_due_at_time} = $time + $self->{flush_interval};
223              
224 12         119 lock_keys(%$self);
225              
226 12         178 _load_class($self->{sample_class});
227              
228 12 100       49 if (my $exclusive_name = $self->{period_exclusive}) {
229             # create the sampler through which period_exclusive samples are added
230             # by end_sample_period()
231 2         10 $self->{exclusive_sampler} = $self->prepare($exclusive_name, $exclusive_name);
232             }
233 12         56 my $dbi_profile = $self->_mk_dbi_profile($self->{dbi_profile_class}, $self->{granularity});
234 12         47 $self->attach_dbi_profile( $dbi_profile, "main", 0 );
235              
236 12 100       51 if (my $period_summary = $self->{period_summary}) {
237 1         4 my $dbi_profile = $self->_mk_dbi_profile("DashProfiler::DumpNowhere", 0);
238 1         3 my $dbh = $self->attach_dbi_profile( $dbi_profile, "period_summary", 0 );
239 1         5 $self->{dbi_handles_all}{period_summary} = $dbh;
240             # start_sample_period() will add handle to {dbi_handles_active}
241             }
242              
243             # mark as in_use if disabled as this allows the sampler to be more efficient
244 12 50       37 $self->{in_use} = -42 if $self->{disabled};
245              
246 12         34 return $self;
247             }
248              
249              
250             =head2 estimate_sample_overheads
251              
252             $sample_overhead_time = DashProfiler::Core->estimate_sample_overheads();
253              
254             ($sample_overhead_time, $sample_inner_time)
255             = DashProfiler::Core->estimate_sample_overheads();
256              
257             Estimates and returns the approximate minimum time overhead for taking a sample.
258             Two times are returned. The following timeline diagram explains the difference:
259              
260             previous statement -------------
261             |
262             sampler called |
263             sampler does work |
264             sampler reads time ----- |
265             sampler does work | |
266             return sample object | |
267             | |
268             (measured statements) | |
269             | |
270             sample DESTROY'd | |
271             sample does work v |
272             sample reads time ----- | = sample_inner_time
273             sample does work |
274             v
275             next statement ------------- = sample_overhead_time
276              
277             For estimate_sample_overheads() there are no I so the
278             times reflect the pure overheads.
279              
280             Note that because estimate_sample_overheads() uses a tight loop, the timings
281             returned are likely to be I smaller then the timings you'd get in
282             practice due to CPU L2 caches and other factors. This is okay.
283             On my 2GHz laptop running OS X 10.5.2 $sample_overhead_time is 0.000014 and
284             $sample_inner_time is 0.000003. (When doing occasional sampling the
285             sample_overhead_time is 0.000002 to 0.000003 higher, in case you care.)
286              
287             DashProfiler automatically calls estimate_sample_overheads() when loading and
288             records the returned values. It then uses the C to
289             adjust the L time to more accrately reflect the time not
290             covered by the accumulated samples. Currently the C is
291             I subtracted from the individual samples. That may change in future.
292              
293             =cut
294              
295             sub estimate_sample_overheads {
296 6     6 1 24 my ($self, $count) = @_;
297 6   50     44 $count ||= 1000;
298              
299 6         35 my $profile = __PACKAGE__->new('overhead',{ dbi_profile_class => 'DashProfiler::DumpNowhere' });
300 6         33 my $sampler = $profile->prepare('c1');
301             # It's okay that this is a tight loop so will tend to give lower times
302             # than would be experienced in practice because, while we want to get as
303             # close as possible to the true overhead, we don't want to overestimate it.
304 6         15 my ($i, $sum) = ($count, 0);
305 6         21 while ($i--) {
306 6000         10360 my $t0 = dbi_time(); # to compare with t1 below
307 6000         9502 my $t1 = dbi_time(); # time before sampling
308 6000         8924 my $ps1 = $sampler->("c2"); # begin sample
309 6000         7374 undef $ps1; # end sample
310 6000         13481 $sum += (dbi_time() - $t1) # time to perform full sample lifecycle
311             - ($t1 - $t0); # subtract cost of calling dbi_time()
312             }
313             # overhead is average of time spent calling sampler & DESTROY:
314 6         33 $sample_overhead_time = $sum / $count; # ~0.000014s on 2GHz OS X 10.5.2 laptop
315 6         36 $sample_inner_time = ($profile->get_dbi_profile->{Data}{c1}{c2}[1] / $count);
316              
317             # we could also subtract the time accumulated by the samples, like this:
318             # $sample_overhead_time -= $sample_inner_time
319             # but we don't because that's also a valid part of the overhead
320             # because there are no statements between the sample creation and destruction.
321              
322 6         11 warn sprintf "sample_overhead_time=%.7fs (sample_inner_time=%.7fs)\n",
323             $sample_overhead_time, $sample_inner_time if DEBUG();
324              
325 6         30 $profile->reset_profile_data;
326              
327 6 50       37 return $sample_overhead_time unless wantarray;
328 6         69 return ($sample_overhead_time, $sample_inner_time);
329             }
330              
331              
332              
333             =head1 OBJECT METHODS
334              
335             =head2 attach_dbi_profile
336              
337             $core->attach_dbi_profile( $dbi_profile, $name );
338              
339             Attaches a DBI Profile to a DashProfiler::Core object using the $name given.
340             Any later samples are also aggregated into this DBI Profile.
341              
342             Not normally called directly. The new() method calls attach_dbi_profile() to
343             attach the "main" profile and the C profile, if enabled.
344              
345             The $dbi_profile argument can be either a DBI::Profile object or a string
346             containing a DBI::Profile specification.
347              
348             The get_dbi_profile($name) method can be used to retrieve the profile.
349              
350             =cut
351              
352             sub attach_dbi_profile {
353 13     13 1 29 my ($self, $dbi_profile, $dbi_profile_name, $weakly) = @_;
354             # wrap DBI::Profile object/spec with a DBI handle
355 13 50       41 croak "No dbi_profile_name specified" unless defined $dbi_profile_name;
356 13         56 local $ENV{DBI_AUTOPROXY};
357 13         124 my $dbh = DBI->connect("dbi:DashProfiler:", "", "", {
358             Profile => $dbi_profile,
359             RaiseError => 1, PrintError => 1, TraceLevel => 0,
360             });
361 13         80 $dbh = tied %$dbh; # switch to inner handle
362 13         142 $dbh->{Profile}->empty; # discard FETCH&STOREs etc due to connect()
363 13         94 for my $handles ($self->{dbi_handles_all}, $self->{dbi_handles_active}) {
364             # clean out any dead weakrefs
365 26   33     78 defined $handles->{$_} or delete $handles->{$_} for keys %$handles;
366 26         62 $handles->{$dbi_profile_name} = $dbh;
367             # weaken($handles->{$dbi_profile_name}) if $weakly; # not currently documented or used
368             }
369 13         99 return $dbh;
370             }
371              
372              
373             sub _attach_new_temporary_plain_profile { # not currently documented or used
374 0     0   0 my ($self, $dbi_profile_name) = @_;
375             # create new DBI profile (with no time key) that doesn't flush anywhere
376 0         0 my $dbi_profile = $self->_mk_dbi_profile("DashProfiler::DumpNowhere", 0);
377             # attach to the profile, but only weakly
378 0         0 $self->attach_dbi_profile( $dbi_profile, $dbi_profile_name, 1 );
379             # return ref so caller can store till ready to discard
380 0         0 return $dbi_profile;
381             }
382              
383              
384             sub _mk_dbi_profile {
385 13     13   29 my ($self, $class, $granularity) = @_;
386              
387 13         38 _load_class($class);
388 13 100       71 my $Path = $granularity ? [ "!Time~$granularity", "!Statement", "!MethodName" ]
389             : [ "!Statement", "!MethodName" ];
390 13         150 my $dbi_profile = $class->new(
391             Path => $Path,
392             Quiet => 1,
393             Trace => 0,
394             File => "dashprofile.$self->{profile_name}",
395 13         42 %{ $self->{dbi_profile_args} },
396             );
397              
398 13         445 return $dbi_profile;
399             };
400              
401              
402             =head2 get_dbi_profile
403              
404             $dbi_profile = $core->get_dbi_profile( $dbi_profile_name );
405             @dbi_profiles = $core->get_dbi_profile( '*' );
406              
407             Returns a reference to the DBI Profile object that attached to the $core with the given name.
408             If $dbi_profile_name is undef then it defaults to "main".
409             Returns undef if there's no profile with that name atached.
410             If $dbi_profile_name is 'C<*>' then it returns all attached profiles.
411             See L.
412              
413             =cut
414              
415             sub get_dbi_profile {
416 55     55 1 798 my ($self, $name) = @_;
417 55 50       167 my $dbi_handles = $self->{dbi_handles_all}
418             or return;
419             # we take care to avoid auto-viv here
420 55   100     195 my $dbh = $dbi_handles->{ $name || 'main' };
421 55 100       269 return $dbh->{Profile} if $dbh;
422 13 100 66     120 return unless $name && $name eq '*';
423 9 50       27 croak "get_dbi_profile('*') called in scalar context" unless wantarray;
424 10 50       92 return map {
425 9         30 ($_->{Profile}) ? ($_->{Profile}) : ()
426             } values %$dbi_handles;
427             }
428              
429              
430             =head2 profile_as_text
431              
432             $core->profile_as_text();
433             $core->profile_as_text( $dbi_profile_name );
434             $core->profile_as_text( $dbi_profile_name, {
435             path => [ $self->{profile_name} ],
436             format => '%1$s: dur=%11$f count=%10$d (max=%14$f avg=%2$f)'."\n",
437             separator => ">",
438             } );
439              
440             Returns the aggregated data from the specified DBI Profile (default "main") formatted as a string.
441             Calls L to get the DBI Profile, then calls the C method on the profile.
442             See L for more details of the parameters.
443              
444             In list context it returns one item per profile leaf node, in scalar context
445             they're concatenated into a single string. Returns undef if the named DBI
446             Profile doesn't exist.
447              
448             =cut
449              
450             sub profile_as_text {
451 17     17 1 2393 my $self = shift;
452 17         23 my $name = shift;
453 17   50     90 my $default_args = $self->{profile_as_text_args} || {};
454 17 100       50 my %args = (%$default_args, %{ shift || {} });
  17         96  
455              
456 17   50     125 $args{path} ||= [ $self->{profile_name} ];
457 17   100     81 $args{format} ||= '%1$s: dur=%11$f count=%10$d (max=%14$f avg=%2$f)'."\n";
458 17   100     78 $args{separator} ||= ">";
459              
460 17 100       45 my $dbi_profile = $self->get_dbi_profile($name) or return;
461 15         74 return $dbi_profile->as_text(\%args);
462             }
463              
464              
465             =head2 reset_profile_data
466              
467             $core->reset_profile_data( $dbi_profile_name );
468              
469             Resets (discards) DBI Profile data and resets the period count to 0.
470             If $dbi_profile_name is false then it defaults to "main".
471             If $dbi_profile_name is "*" then all attached profiles are reset.
472             Returns a list of the affected DBI::Profile objects.
473              
474             =cut
475              
476             sub reset_profile_data {
477 16     16 1 12025 my ($self, $dbi_profile_name) = @_;
478 16         61 my @dbi_profiles = $self->get_dbi_profile($dbi_profile_name);
479 16         120 $_->empty for @dbi_profiles;
480 16         150 $self->{period_count} = 0;
481 16         158 return @dbi_profiles;
482             }
483              
484              
485             sub _visit_nodes { # depth first with lexical ordering
486 6     6   10 my ($self, $node, $path, $sub) = @_;
487 6 50       12 croak "No sub ref given" unless ref $sub eq 'CODE';
488 6 50       13 return unless $node;
489 6   100     11 $path ||= [];
490 6 100       14 if (ref $node eq 'HASH') { # recurse
491 4         8 $path = [ @$path, undef ];
492 5         9 return map {
493 4         14 $path->[-1] = $_;
494 5 50       28 ($node->{$_}) ? $self->_visit_nodes($node->{$_}, $path, $sub) : ()
495             } sort keys %$node;
496             }
497 2         4 return $sub->($node, $path);
498             }
499              
500              
501             =head2 visit_profile_nodes
502              
503             $core->visit_profile_nodes( $dbi_profile_name, sub { ... } )
504              
505             Calls the given subroutine for each leaf node in the named DBI Profile.
506             The name defaults to "main". If $dbi_profile_name is "*" then the leafs nodes
507             in all the attached profiles are visited.
508              
509             =cut
510              
511             sub visit_profile_nodes {
512 1     1 1 3 my ($self, $dbi_profile_name, $sub) = @_;
513 1         3 my @dbi_profiles = $self->get_dbi_profile($dbi_profile_name);
514 1         3 for my $dbi_profile (@dbi_profiles) {
515 1 50       4 my $data = $dbi_profile->{Data}
516             or next;
517 1         5 $self->_visit_nodes($data, undef, $sub)
518             }
519 1         3 return;
520             }
521              
522              
523             =head2 propagate_period_count
524              
525             $core->propagate_period_count( $dbi_profile_name )
526              
527             Sets the count field of all the leaf-nodes in the named DBI Profile to the
528             number of times start_sample_period() has been called since the last flush() or
529             reset_profile_data().
530              
531             If $dbi_profile_name is "*" then counts in all attached profiles are set.
532              
533             Resets the period count used.
534              
535             Does nothing but return 0 if the the period count is zero.
536              
537             This method is especially useful where the number of sample I are much
538             more relevant than the number of samples. This is typically the case where
539             sample periods correspond to major units of work, such as web requests.
540             Using propagate_period_count() lets you calculate averages based on the count
541             of I instead of samples.
542              
543             Imagine, for example, that you're instrumenting a web application and you have
544             a function that sends a request to some network service and another reads each
545             line of the response. You'd add DashProfiler sampler calls to each function.
546             The number of samples recorded in the leaf node will depends on the number of
547             lines in the response from the network service. You're much more likely to want
548             to know "average total time spent handling the network service per http request"
549             than "average time spent in a network service related function".
550              
551             This method is typically called just before a flush(), often via C.
552              
553             =cut
554              
555             sub propagate_period_count {
556 3     3 1 1631 my ($self, $dbi_profile_name) = @_;
557             # force count of all nodes to be count of periods instead of samples
558 3 100       12 my $count = $self->{period_count}
559             or return 0;
560 1         3 warn "propagate_period_count $self->{profile_name} count $count\n" if DEBUG();
561             # force count of all nodes to be count of periods
562 1 50   2   9 $self->visit_profile_nodes($dbi_profile_name, sub { return unless ref $_[0] eq 'ARRAY'; $_[0]->[0] = $count });
  2         6  
  2         13  
563 1         5 return $count;
564             }
565              
566              
567             =head2 flush
568              
569             $core->flush()
570             $core->flush( $dbi_profile_name )
571              
572             Calls the C code reference, if set, passing it $core and the
573             $dbi_profile_name augument (which is typically undef). If the C
574             code returns a non-empty list then flush() does nothing more except return that
575             list.
576              
577             If C wasn't set, or it returned an empty list, then the flush_to_disk()
578             method is called for the named DBI Profile (defaults to "main", use "*" for all).
579             In this case flush() returns a list of the DBI::Profile objects flushed.
580              
581             =cut
582              
583              
584             sub flush {
585 2     2 1 7 my ($self, $dbi_profile_name) = @_;
586 2 100       9 if (my $flush_hook = $self->{flush_hook}) {
587             # if flush_hook returns true then don't call flush_to_disk
588 1         4 my @ret = $flush_hook->($self, $dbi_profile_name);
589 1 50       6 return @ret if @ret;
590             # else fall through
591             }
592 1         3 my @dbi_profiles = $self->get_dbi_profile($dbi_profile_name);
593 1         6 $_->flush_to_disk for (@dbi_profiles);
594 1         16 return @dbi_profiles;
595             }
596              
597              
598             =head2 flush_if_due
599              
600             $core->flush_if_due()
601              
602             Returns nothing if C was not set.
603             Returns nothing if C was set but insufficient time has passed since
604             the last call to flush_if_due().
605             Otherwise notes the time the next flush will be due, and calls C.
606              
607             =cut
608              
609             sub flush_if_due {
610 1     1 1 1187 my ($self) = @_;
611 1 50       4 return unless $self->{flush_interval};
612 1 50       14 return if time() < $self->{flush_due_at_time};
613 0         0 $self->{flush_due_at_time} = time() + $self->{flush_interval};
614 0         0 return $self->flush();
615             }
616              
617              
618             =head2 has_profile_data
619              
620             $bool = $core->has_profile_data
621             $bool = $core->has_profile_data( $dbi_profile_name )
622              
623             Returns true if the named DBI Profile (default "main") contains any profile data.
624              
625             =cut
626              
627             sub has_profile_data {
628 9     9 1 21 my ($self, $dbi_profile_name) = @_;
629 9 50       29 my @dbi_profiles = $self->get_dbi_profile($dbi_profile_name)
630             or return undef; ## no critic
631 9 100 100     25 keys %{$_->{Data}||{}} && return 1 for (@dbi_profiles);
  10         91  
632 8         176 return 0;
633             }
634              
635              
636             =head2 start_sample_period
637              
638             $core->start_sample_period
639              
640             Marks the start of a series of related samples, e.g, within one http request.
641              
642             If end_sample_period() has not been called for this core since the last
643             start_sample_period() then the value of the C attribute
644             determines the actions taken:
645              
646             0 = restart the period, silently
647             1 = restart the period and issue a warning (this is the default)
648             2 = continue the current period, silently
649             3 = continue the current period and issue a warning
650             4 = call end_sample_period(), silently
651             5 = call end_sample_period() and issue a warning
652              
653             If the value is a CODE ref then it's called (and passed $core) and the return value used.
654              
655             Resets the C attribute to zero.
656             Sets C to the current dbi_time().
657             If C is enabled then the period_summary DBI Profile is enabled and reset.
658              
659             See also L, the C option, and L.
660              
661             =cut
662              
663             sub start_sample_period {
664 7     7 1 2884 my $self = shift;
665             # marks the start of a series of related samples, e.g, within one http request
666             # see end_sample_period()
667 7 50       31 if ($self->{period_start_time}) {
668 0 0       0 if (my $strictness = $self->{period_strict_start}) {
669 0 0       0 $strictness = $strictness->($self) if ref $strictness eq 'CODE';
670 0 0       0 carp "start_sample_period() called for $self->{profile_name} without preceeding end_sample_period()"
671             if $strictness & 0x01;
672             return
673 0 0       0 if $strictness & 0x02;
674 0 0       0 $self->end_sample_period()
675             if $strictness & 0x04;
676             }
677             }
678 7 100       93 if (my $period_summary_h = $self->{dbi_handles_all}{period_summary}) {
679             # ensure period_summary_h dbi profile will receive samples
680 2         6 $self->{dbi_handles_active}{period_summary} = $period_summary_h;
681 2         11 $period_summary_h->{Profile}->empty; # start period empty
682             }
683 7         20 $self->{period_accumulated} = 0;
684 7         23 $self->{period_start_time} = dbi_time();
685 7         16 return;
686             }
687              
688              
689             =head2 end_sample_period
690              
691             $core->end_sample_period
692              
693             Marks the end of a series of related samples, e.g, within one http request.
694              
695             If start_sample_period() has not been called for this core since the last
696             end_sample_period() (or the start of the script) then the value of the
697             C attribute determines the actions taken:
698              
699             0 = do nothing, silently (this is the default)
700             1 = do nothing but warn
701             2 = call start_sample_period(), silently
702             3 = call start_sample_period() and warn
703              
704             If the value is a CODE ref then it's called (and passed $core) and the return value used.
705             If start_sample_period() isn't called then end_sample_period() just returns.
706              
707             The C attribute is incremented.
708              
709             If C is enabled then a sample is added with a duration
710             caclulated to be the time since start_sample_period() was called to now, minus
711             the time accumulated by samples since start_sample_period() was called.
712              
713             Resets the C attribute to 0. If C is
714             enabled then the C DBI Profile is disabled and returned, else
715             undef is returned.
716              
717             See also L, C and L.
718              
719             =cut
720              
721             sub end_sample_period {
722 7     7 1 1000216 my $self = shift;
723              
724 7 50       33 if (not $self->{period_start_time}) {
725 0 0       0 if (my $strictness = $self->{period_strict_end}) {
726 0 0       0 $strictness = $strictness->($self) if ref $strictness eq 'CODE';
727 0 0       0 carp "end_sample_period() called for $self->{profile_name} without preceeding start_sample_period()"
728             if $strictness & 0x01;
729 0 0       0 $self->start_sample_period()
730             if $strictness & 0x02;
731             }
732             # return if we didn't start a period
733 0 0       0 return if not $self->{period_start_time};
734             }
735              
736 7         14 $self->{period_count}++;
737              
738             # disconnect period_summary dbi profile from receiving any more samples
739 7         23 my $period_summary_dbh = delete $self->{dbi_handles_active}{period_summary};
740 7         12 my $period_summary_profile = $period_summary_dbh->{Profile};
741              
742 7 100       26 if (my $exclusive_sampler = $self->{exclusive_sampler}) {
743             # Calculate how much time between $self->{period_start_time} and now
744             # is not accounted for by $self->{period_accumulated}.
745             # Add a sample with the start time forced to be period_start_time
746             # shifted forward by the accumulated sample durations + sampling overheads.
747             # This accounts for all the time between start_sample_period and
748             # end_sample_period that hasn't been accounted for by normal samples.
749              
750             # calculate overhead of taking samples
751 4         5 my $overhead;
752 4 50       10 if ($period_summary_profile) {
753             # if period_summary is enabled then we can use the count of
754             # samples this period to scale the overhead correctly
755 0         0 dbi_profile_merge(my $total=[], $period_summary_profile->{Data});
756             # scale overhead by number of samples in period
757 0         0 $overhead = $sample_overhead_time * $total->[0];
758             }
759             else {
760             # if period_summary is not enabled then we can't do much
761 4         8 $overhead = $sample_overhead_time;
762             }
763              
764 4         5 warn sprintf "%s period end: overhead %.6fs (%.0f * %.6fs)\n",
765             $self->{profile_name}, $overhead, $overhead/$sample_overhead_time, $sample_overhead_time
766             if DEBUG() && DEBUG() >= 3;
767              
768 4         22 $exclusive_sampler->(undef, $self->{period_start_time} + $self->{period_accumulated} + $overhead);
769              
770             # sample gets destroyed, and so counted, immediately.
771             }
772              
773 7         25 $self->{period_start_time} = 0;
774             # $self->{period_accumulated} will be reset by start_sample_period()
775              
776 7         30 return $period_summary_profile;
777             }
778              
779              
780             =head2 period_start_time
781              
782             $time = $core->period_start_time;
783              
784             Returns the time the current sample period was started (typically the time
785             L was called) or 0 if there's no period active.
786              
787             =cut
788              
789             sub period_start_time {
790 3     3 1 35 return shift->{period_start_time};
791             }
792              
793              
794             =head2 prepare
795              
796             $sampler_code_ref = $core->prepare( $context1 )
797             $sampler_code_ref = $core->prepare( $context1, $context2 )
798             $sampler_code_ref = $core->prepare( $context1, $context2, %meta )
799              
800             $sampler_code_ref->( $context2 )
801             $sampler_code_ref->( $context2, $start_time )
802              
803             Returns a reference to a subroutine that will create sampler objects.
804             In effect the prepare() method creates a 'factory'.
805              
806             The sampler objects created by the returned code reference are pre-set to use
807             $context1, and optionally $context2, as their context values.
808              
809             If the appropriate value for C won't be available until the end of
810             the sample you can set $context2 to a code reference. The reference will be
811             executed at the end of the sample. See L.
812              
813             XXX needs more info about %meta - see the code for now, it's not very complex.
814              
815             See L for more information.
816              
817             =cut
818              
819             sub prepare {
820 15     15 1 1734322 my ($self, $context1, $context2, %meta) = @_;
821             # return undef if profile exists but is disabled
822 15 50       51 return undef if $self->{disabled}; ## no critic
823              
824             # return a light wrapper around the profile, containing the context1
825 15   33     80 my $sample_class = $meta{sample_class} || $self->{sample_class};
826             # use %meta to carry context info into sample object factory
827 15         32 $meta{_dash_profile} = $self;
828 15         28 $meta{_context1} = $context1;
829 15         24 $meta{_context2} = $context2;
830             # skip method lookup
831 15   50     157 my $coderef = $sample_class->can("new") || "new";
832             return sub { # closure over $sample_class, %meta and $coderef
833 9213     9213   6736845 $sample_class->$coderef(\%meta, @_)
834 15         107 };
835             }
836              
837              
838             sub DESTROY {
839 9     9   46 my $self = shift;
840             # global destruction shouldn't be relied upon because often the
841             # dbi profile data will have been already destroyed
842 9 50       34 $self->end_sample_period() if $self->{period_start_time};
843 9 100       39 $self->flush if $self->has_profile_data("*");
844             }
845              
846              
847             sub _load_class {
848 25     25   38 my ($class) = @_;
849             ## no critic
850 5     5   46 no strict 'refs';
  5         12  
  5         688  
851 25 100       27 return 1 if keys %{"$class\::"}; # already loaded
  25         132  
852 5         1260 (my $file = $class) =~ s/::/\//g;
853 5         3057 require "$file.pm";
854             }
855              
856              
857             =head2 DEBUG
858            
859             The DEBUG subroutine is a constant that returns whatever the value of
860              
861             $ENV{DASHPROFILER_CORE_DEBUG} || $ENV{DASHPROFILER_DEBUG} || 0;
862              
863             was when the modle was loaded.
864              
865             =cut
866              
867              
868              
869             # --- DBI::ProfileDumper subclass that doesn't flush_to_disk
870             # Used by period_summary
871             {
872             package DashProfiler::DumpNowhere;
873 5     5   43 use strict;
  5         55  
  5         151  
874 5     5   28 use base qw(DBI::ProfileDumper);
  5         9  
  5         1696  
875 7     7   133 sub flush_to_disk { return }
876             }
877              
878              
879             # --- ultra small 'null' driver for DBI ---
880             # This is really just for the custom dbh DESTROY method below
881              
882             {
883             package DBD::DashProfiler;
884             our $drh; # holds driver handle once initialised
885             sub driver{
886 5 50   5 0 2828 return $drh if $drh;
887 5         12 my ($class, $attr) = @_;
888 5         7 $DBD::DashProfiler::db::imp_data_size = 0;
889 5         8 $DBD::DashProfiler::dr::imp_data_size = 0;
890 5         44 return DBI::_new_drh($class."::dr", {
891             Name => 'DashProfiler', Version => $DashProfiler::Core::VERSION,
892             });
893             }
894 0     0   0 sub CLONE { undef $drh }
895             }
896             { package DBD::DashProfiler::dr;
897             our $imp_data_size = 0;
898 0     0   0 sub DESTROY { undef }
899             }
900             { package DBD::DashProfiler::db;
901             our $imp_data_size = 0;
902 5     5   28 use strict;
  5         8  
  5         822  
903             sub STORE {
904 91     91   3088 my ($dbh, $attrib, $value) = @_;
905 91 50       308 $value = ($value) ? -901 : -900 if $attrib eq 'AutoCommit';
    100          
906 91         953 return $dbh->SUPER::STORE($attrib, $value);
907             }
908             sub DESTROY {
909 10     10   43 my $dbh = shift;
910 10         23 $dbh->{Profile} = undef; # don't profile the DESTROY
911 10         653 return $dbh->SUPER::DESTROY;
912             }
913             }
914             { package DBD::DashProfiler::st;
915             our $imp_data_size = 0;
916             }
917             # fake the %INC entry so DBI install_driver won't try to load it
918 5     5   194 BEGIN { $INC{"DBD/DashProfiler.pm"} = __FILE__ }
919              
920              
921              
922             1;
923              
924             =head1 AUTHOR
925              
926             DashProfiler by Tim Bunce, L and
927             L
928              
929             =head1 COPYRIGHT
930              
931             The DashProfiler distribution is Copyright (c) 2007-2008 Tim Bunce. Ireland.
932             All rights reserved.
933              
934             You may distribute under the terms of either the GNU General Public
935             License or the Artistic License, as specified in the Perl README file.
936              
937             =cut
938