📄 profile.pm
字号:
package DBI::Profile;=head1 NAMEDBI::Profile - Performance profiling and benchmarking for the DBI=head1 SYNOPSISThe easiest way to enable DBI profiling is to set the DBI_PROFILEenvironment variable to 2 and then run your code as usual: DBI_PROFILE=2 prog.plThis will profile your program and then output a textual summarygrouped by query when the program exits. You can also enable profiling bysetting the Profile attribute of any DBI handle: $dbh->{Profile} = 2;Then the summary will be printed when the handle is destroyed.Many other values apart from are possible - see L<"ENABLING A PROFILE"> below.=head1 DESCRIPTIONThe DBI::Profile module provides a simple interface to collect andreport performance and benchmarking data from the DBI.For a more elaborate interface, suitable for larger programs, seeL<DBI::ProfileDumper|DBI::ProfileDumper> and L<dbiprof|dbiprof>.For Apache/mod_perl applications seeL<DBI::ProfileDumper::Apache|DBI::ProfileDumper::Apache>.=head1 OVERVIEWPerformance data collection for the DBI is built around severalconcepts which are important to understand clearly.=over 4=item Method DispatchEvery method call on a DBI handle passes through a single 'dispatch'function which manages all the common aspects of DBI method calls,such as handling the RaiseError attribute.=item Data CollectionIf profiling is enabled for a handle then the dispatch code takesa high-resolution timestamp soon after it is entered. Then, aftercalling the appropriate method and just before returning, it takesanother high-resolution timestamp and calls a function to recordthe information. That function is passed the two timestampsplus the DBI handle and the name of the method that was called.That data about a single DBI method call is called a I<profile sample>.=item Data FilteringIf the method call was invoked by the DBI or by a driver then the call isignored for profiling because the time spent will be accounted for by theoriginal 'outermost' call for your code.For example, the calls that the selectrow_arrayref() method makesto prepare() and execute() etc. are not counted individuallybecause the time spent in those methods is going to be allocatedto the selectrow_arrayref() method when it returns. If this was notdone then it would be very easy to double count time spent insidethe DBI.=item Data Storage TreeThe profile data is accumulated as 'leaves on a tree'. The 'path' through thebranches of the tree to a particular leaf is determined dynamically for each sample.This is a key feature of DBI profiliing.For each profiled method call the DBI walks along the Path and uses each valuein the Path to step into and grow the Data tree.For example, if the Path is [ 'foo', 'bar', 'baz' ]then the new profile sample data will be I<merged> into the tree at $h->{Profile}->{Data}->{foo}->{bar}->{baz}But it's not very useful to merge all the call data into one leaf node (exceptto get an overall 'time spent inside the DBI' total). It's more common to wantthe Path to include dynamic values such as the current statement text and/orthe name of the method called to show what the time spent inside the DBI was for.The Path can contain some 'magic cookie' values that are automatically replacedby corresponding dynamic values when they're used. These magic cookies alwaysstart with a punctuation character.For example a value of 'C<!MethodName>' in the Path causes the correspondingentry in the Data to be the name of the method that was called.For example, if the Path was: [ 'foo', '!MethodName', 'bar' ]and the selectall_arrayref() method was called, then the profile sample datafor that call will be merged into the tree at: $h->{Profile}->{Data}->{foo}->{selectall_arrayref}->{bar}=item Profile DataProfile data is stored at the 'leaves' of the tree as referencesto an array of numeric values. For example: [ 106, # 0: count of samples at this node 0.0312958955764771, # 1: total duration 0.000490069389343262, # 2: first duration 0.000176072120666504, # 3: shortest duration 0.00140702724456787, # 4: longest duration 1023115819.83019, # 5: time of first sample 1023115819.86576, # 6: time of last sample ]After the first sample, later samples always update elements 0, 1, and 6, andmay update 3 or 4 depending on the duration of the sampled call.=back=head1 ENABLING A PROFILEProfiling is enabled for a handle by assigning to the Profileattribute. For example: $h->{Profile} = DBI::Profile->new();The Profile attribute holds a blessed reference to a hash objectthat contains the profile data and attributes relating to it.The class the Profile object is blessed into is expected toprovide at least a DESTROY method which will dump the profile datato the DBI trace file handle (STDERR by default).All these examples have the same effect as each other: $h->{Profile} = 0; $h->{Profile} = "/DBI::Profile"; $h->{Profile} = DBI::Profile->new(); $h->{Profile} = {}; $h->{Profile} = { Path => [] };Similarly, these examples have the same effect as each other: $h->{Profile} = 6; $h->{Profile} = "6/DBI::Profile"; $h->{Profile} = "!Statement:!MethodName/DBI::Profile"; $h->{Profile} = { Path => [ '!Statement', '!MethodName' ] };If a non-blessed hash reference is given then the DBI::Profilemodule is automatically C<require>'d and the reference is blessedinto that class.If a string is given then it is processed like this: ($path, $module, $args) = split /\//, $string, 3 @path = split /:/, $path @args = split /:/, $args eval "require $module" if $module $module ||= "DBI::Profile" $module->new( Path => \@Path, @args )So the first value is used to select the Path to be used (see below).The second value, if present, is used as the name of a module whichwill be loaded and it's C<new> method called. If not present itdefaults to DBI::Profile. Any other values are passed as argumentsto the C<new> method. For example: "C<2/DBIx::OtherProfile/Foo:42>".Numbers can be used as a shorthand way to enable common Path values.The simplest way to explain how the values are interpreted is to show the code: push @Path, "DBI" if $path_elem & 0x01; push @Path, "!Statement" if $path_elem & 0x02; push @Path, "!MethodName" if $path_elem & 0x04; push @Path, "!MethodClass" if $path_elem & 0x08; push @Path, "!Caller2" if $path_elem & 0x10;So "2" is the same as "!Statement" and "6" (2+4) is the same as"!Statement:!Method". Those are the two most commonly used values. Using anegative number will reverse the path. Thus "-6" will group by method name thenstatement.The spliting and parsing of string values assigned to the Profileattribute may seem a little odd, but there's a good reason for it.Remember that attributes can be embedded in the Data Source Namestring which can be passed in to a script as a parameter. Forexample: dbi:DriverName(Profile=>2):dbname dbi:DriverName(Profile=>{Username}:!Statement/MyProfiler/Foo:42):dbnameAnd also, if the C<DBI_PROFILE> environment variable is set thenThe DBI arranges for every driver handle to share the same profileobject. When perl exits a single profile summary will be generatedthat reflects (as nearly as practical) the total use of the DBI bythe application.=head1 THE PROFILE OBJECTThe DBI core expects the Profile attribute value to be a hashreference and if the following values don't exist it will createthem as needed:=head2 DataA reference to a hash containing the collected profile data.=head2 PathThe Path value is a reference to an array. Each element controls thevalue to use at the corresponding level of the profile Data tree.If the value of Path is anything other than an array reference,it is treated as if it was: [ '!Statement' ]The elements of Path array can be one of the following types:=head3 Special ConstantB<!Statement>Use the current Statement text. Typically that's the value of the Statementattribute for the handle the method was called with. Some methods, likecommit() and rollback(), are unrelated to a particular statement. For thosemethods !Statement records an empty string.For statement handles this is always simply the string that wasgiven to prepare() when the handle was created. For database handlesthis is the statement that was last prepared or executed on thatdatabase handle. That can lead to a little 'fuzzyness' because, forexample, calls to the quote() method to build a new statement willtypically be associated with the previous statement. In practicethis isn't a significant issue and the dynamic Path mechanism canbe used to setup your own rules.B<!MethodName>Use the name of the DBI method that the profile sample relates to.B<!MethodClass>Use the fully qualified name of the DBI method, includingthe package, that the profile sample relates to. This shows youwhere the method was implemented. For example: 'DBD::_::db::selectrow_arrayref' => 0.022902s 'DBD::mysql::db::selectrow_arrayref' => 2.244521s / 99 = 0.022445s avg (first 0.022813s, min 0.022051s, max 0.028932s)The "DBD::_::db::selectrow_arrayref" shows that the driver hasinherited the selectrow_arrayref method provided by the DBI.But you'll note that there is only one call toDBD::_::db::selectrow_arrayref but another 99 toDBD::mysql::db::selectrow_arrayref. Currently the firstcall Pern't record the true location. That may change.B<!Caller>Use a string showing the filename and line number of the code calling the method.B<!Caller2>Use a string showing the filename and line number of the code calling themethod, as for !Caller, but also include filename and line number of the codethat called that. Calls from DBI:: and DBD:: packages are skipped.B<!File>Same as !Caller above except that only the filename is included, not the line number.B<!File2>Same as !Caller2 above except that only the filenames are included, not the line number.B<!Time>Use the current value of time(). Rarely used. See the more useful C<!Time~N> below.B<!Time~N>Where C<N> is an integer. Use the current value of time() but with reduced precision.The value used is determined in this way: int( time() / N ) * NThis is a useful way to segregate a profile into time slots. For example: [ '!Time~60', '!Statement' ]=head3 Code ReferenceThe subroutine is passed the handle it was called on and the DBI method name.The current Statement is in $_. The statement string should not be modified,so most subs start with C<local $_ = $_;>.The list of values it returns is used at that point in the Profile Path.The sub can 'veto' (reject) a profile sample by including a reference to undefin the returned list. That can be useful when you want to only profile
⌨️ 快捷键说明
复制代码
Ctrl + C
搜索代码
Ctrl + F
全屏模式
F11
切换主题
Ctrl + Shift + D
显示快捷键
?
增大字号
Ctrl + =
减小字号
Ctrl + -