📄 profile.pm
字号:
statements that match a certain pattern, or only profile certain methods.=head3 Subroutine SpecifierA Path element that begins with 'C<&>' is treated as the name of a subroutinein the DBI::ProfileSubs namespace and replaced with the corresponding code reference.Currently this only works when the Path is specified by the C<DBI_PROFILE>environment variable.Also, currently, the only subroutine in the DBI::ProfileSubs namespace isC<'&norm_std_n3'>. That's a very handy subroutine when profiling code thatdoesn't use placeholders. See L<DBI::ProfileSubs> for more information.=head3 Attribute SpecifierA string enclosed in braces, such as 'C<{Username}>', specifies that the currentvalue of the corresponding database handle attribute should be used at thatpoint in the Path.=head3 Reference to a ScalarSpecifies that the current value of the referenced scalar be used at that pointin the Path. This provides an efficient way to get 'contextual' values intoyour profile.=head3 Other ValuesAny other values are stringified and used literally.(References, and values that begin with punctuation characters are reserved.)=head1 REPORTING=head2 Report FormatThe current accumulated profile data can be formatted and output using print $h->{Profile}->format;To discard the profile data and start collecting fresh datayou can do: $h->{Profile}->{Data} = undef;The default results format looks like this: DBI::Profile: 0.001015s 42.7% (5 calls) programname @ YYYY-MM-DD HH:MM:SS '' => 0.000024s / 2 = 0.000012s avg (first 0.000015s, min 0.000009s, max 0.000015s) 'SELECT mode,size,name FROM table' => 0.000991s / 3 = 0.000330s avg (first 0.000678s, min 0.000009s, max 0.000678s)Which shows the total time spent inside the DBI, with a count ofthe total number of method calls and the name of the script beingrun, then a formated version of the profile data tree.If the results are being formated when the perl process is exiting(which is usually the case when the DBI_PROFILE environment variableis used) then the percentage of time the process spent inside theDBI is also shown. If the process is not exiting then the percentage iscalculated using the time between the first and last call to the DBI.In the example above the paths in the tree are only one level deep anduse the Statement text as the value (that's the default behaviour).The merged profile data at the 'leaves' of the tree are presentedas total time spent, count, average time spent (which is simply totaltime divided by the count), then the time spent on the first call,the time spent on the fastest call, and finally the time spent onthe slowest call.The 'avg', 'first', 'min' and 'max' times are not particularlyuseful when the profile data path only contains the statement text.Here's an extract of a more detailed example using both statementtext and method name in the path: 'SELECT mode,size,name FROM table' => 'FETCH' => 0.000076s 'fetchrow_hashref' => 0.036203s / 108 = 0.000335s avg (first 0.000490s, min 0.000152s, max 0.002786s)Here you can see the 'avg', 'first', 'min' and 'max' for the108 calls to fetchrow_hashref() become rather more interesting.Also the data for FETCH just shows a time value because it was onlycalled once.Currently the profile data is output sorted by branch names. Thatmay change in a later version so the leaf nodes are sorted by totaltime per leaf node.=head2 Report DestinationThe default method of reporting is for the DESTROY method of theProfile object to format the results and write them using: DBI->trace_msg($results, 0); # see $ON_DESTROY_DUMP belowto write them to the DBI trace() filehandle (which defaults toSTDERR). To direct the DBI trace filehandle to write to a filewithout enabling tracing the trace() method can be called with atrace level of 0. For example: DBI->trace(0, $filename);The same effect can be achieved without changing the code bysetting the C<DBI_TRACE> environment variable to C<0=filename>.The $DBI::Profile::ON_DESTROY_DUMP variable holds a code refthat's called to perform the output of the formatted results.The default value is: $ON_DESTROY_DUMP = sub { DBI->trace_msg($results, 0) };Apart from making it easy to send the dump elsewhere, it can alsobe useful as a simple way to disable dumping results.=head1 CHILD HANDLESChild handles inherit a reference to the Profile attribute valueof their parent. So if profiling is enabled for a database handlethen by default the statement handles created from it all contributeto the same merged profile data tree.=head1 PROFILE OBJECT METHODS=head2 formatSee L</REPORTING>.=head2 as_node_path_list @ary = $dbh->{Profile}->as_node_path_list(); @ary = $dbh->{Profile}->as_node_path_list($node, $path);Returns the collected data ($dbh->{Profile}{Data}) restructured into a list ofarray refs, one for each leaf node in the Data tree. This 'flat' structure isoften much simpler for applications to work with.The first element of each array ref is a reference to the leaf node.The remaining elements are the 'path' through the data tree to that node.For example, given a data tree like this: {key1a}{key2a}[node1] {key1a}{key2b}[node2] {key1b}{key2a}{key3a}[node3]The as_node_path_list() method will return this list: [ [node1], 'key1a', 'key2a' ] [ [node2], 'key1a', 'key2b' ] [ [node3], 'key1b', 'key2a', 'key3a' ]The nodes are ordered by key, depth-first.The $node argument can be used to focus on a sub-tree.If not specified it defaults to $dbh->{Profile}{Data}.The $path argument can be used to specify a list of path elements that will beadded to each element of the returned list. If not specified it defaults to a aref to an empty array.=head2 as_text @txt = $dbh->{Profile}->as_text(); $txt = $dbh->{Profile}->as_text({ node => undef, path => [], separator => " > ", format => '%1$s: %11$fs / %10$d = %2$fs avg (first %12$fs, min %13$fs, max %14$fs)'."\n"; sortsub => sub { ... }, );Returns the collected data ($dbh->{Profile}{Data}) reformatted into a list of formatted strings.In scalar context the list is returned as a single contatenated string.A hashref can be used to pass in arguments, the default values are shown in the example above.The C<node> and <path> arguments are passed to as_node_path_list().The C<separator> argument is used to join the elemets of the path for each leaf node.The C<sortsub> argument is used to pass in a ref to a sub that will order the list.The subroutine will be passed a reference to the array returned by as_node_path_list().The C<format> argument is a C<sprintf> format string that specifies the formatto use for each leaf node. It uses the explicit format parameter indexmechanism to specify which of the arguments should appear where in the string.The arguments to sprintf are: 1: path to node, joined with the separator 2: average duration (total/count) (3 thru 9 are currently unused) 10: count 11: total duration 12: first_duration 13: smallest duration 14: largest duration 15: time of first call 16: time of first call=head1 CUSTOM DATA MANIPULATIONRecall that C<$h->{Profile}->{Data}> is a reference to the collected data.Either to a 'leaf' array (when the Path is empty, i.e., DBI_PROFILE env var is 1),or a reference to hash containing values that are either further hashreferences or leaf array references.Sometimes it's useful to be able to summarise some or all of the collected data.The dbi_profile_merge_nodes() function can be used to merge leaf node values.=head2 dbi_profile_merge_nodes use DBI qw(dbi_profile_merge_nodes); $time_in_dbi = dbi_profile_merge_nodes(my $totals=[], @$leaves);Merges profile data node. Given a reference to a destination array, and zero ormore references to profile data, merges the profile data into the destination array.For example: $time_in_dbi = dbi_profile_merge_nodes( my $totals=[], [ 10, 0.51, 0.11, 0.01, 0.22, 1023110000, 1023110010 ], [ 15, 0.42, 0.12, 0.02, 0.23, 1023110005, 1023110009 ], ); $totals will then contain [ 25, 0.93, 0.11, 0.01, 0.23, 1023110000, 1023110010 ]and $time_in_dbi will be 0.93;The second argument need not be just leaf nodes. If given a reference to a hashthen the hash is recursively searched for for leaf nodes and all those foundare merged.For example, to get the time spent 'inside' the DBI during an http request,your logging code run at the end of the request (i.e. mod_perl LogHandler)could use: my $time_in_dbi = 0; if (my $Profile = $dbh->{Profile}) { # if DBI profiling is enabled $time_in_dbi = dbi_profile_merge_nodes(my $total=[], $Profile->{Data}); $Profile->{Data} = {}; # reset the profile data }If profiling has been enabled then $time_in_dbi will hold the time spent insidethe DBI for that handle (and any other handles that share the same profile data)since the last request.Prior to DBI 1.56 the dbi_profile_merge_nodes() function was called dbi_profile_merge().That name still exists as an alias.=head1 CUSTOM DATA COLLECTION=head2 Using The Path Attribute XXX example to be added later using a selectall_arrayref call XXX nested inside a fetch loop where the first column of the XXX outer loop is bound to the profile Path using XXX bind_column(1, \${ $dbh->{Profile}->{Path}->[0] }) XXX so you end up with separate profiles for each loop XXX (patches welcome to add this to the docs :)=head2 Adding Your Own SamplesThe dbi_profile() function can be used to add extra sample datainto the profile data tree. For example: use DBI; use DBI::Profile (dbi_profile dbi_time); my $t1 = dbi_time(); # floating point high-resolution time ... execute code you want to profile here ... my $t2 = dbi_time(); dbi_profile($h, $statement, $method, $t1, $t2);The $h parameter is the handle the extra profile sample should beassociated with. The $statement parameter is the string to use wherethe Path specifies !Statement. If $statement is undefthen $h->{Statement} will be used. Similarly $method is the stringto use if the Path specifies !MethodName. There is nodefault value for $method.The $h->{Profile}{Path} attribute is processed by dbi_profile() inthe usual way.It is recommended that you keep these extra data samples separatefrom the DBI profile data samples by using values for $statementand $method that are distinct from any that are likely to appearin the profile data normally.=head1 SUBCLASSINGAlternate profile modules must subclass DBI::Profile to help ensurethey work with future versions of the DBI.=head1 CAVEATSApplications which generate many different statement strings(typically because they don't use placeholders) and profile with!Statement in the Path (the default) will consume memory
⌨️ 快捷键说明
复制代码
Ctrl + C
搜索代码
Ctrl + F
全屏模式
F11
切换主题
Ctrl + Shift + D
显示快捷键
?
增大字号
Ctrl + =
减小字号
Ctrl + -