DBI::Profile man page on IRIX

Man page or keyword search:  
man Server   31559 pages
apropos Keyword Search (all sections)
Output format
IRIX logo
[printable version]

DBI::Profile(3)	      User Contributed Perl Documentation      DBI::Profile(3)

NAME
       DBI::Profile - Performance profiling and benchmarking for the DBI

SYNOPSIS
       The easiest way to enable DBI profiling is to set the DBI_PROFILE envi‐
       ronment variable to 2 and then run your code as usual:

	 DBI_PROFILE=2 prog.pl

       This will profile your program and then output a textual summary
       grouped by query.  You can also enable profiling by setting the Profile
       attribute of any DBI handle:

	 $dbh->{Profile} = 2;

       Other values are possible - see the section on "ENABLING A PROFILE"
       below.

DESCRIPTION
       DBI::Profile is new and experimental and subject to change.

       The DBI::Profile module provides a simple interface to collect and
       report performance and benchmarking data from the DBI.

       For a more elaborate interface, suitable for larger programs, see
       DBI::ProfileDumper and dbiprof.	For Apache/mod_perl applications see
       DBI::ProfileDumper::Apache.

OVERVIEW
       Performance data collection for the DBI is built around several con‐
       cepts which are important to understand clearly.

       Method Dispatch
	   Every method call on a DBI handle passes through a single 'dis‐
	   patch' function which manages all the common aspects of DBI method
	   calls, such as handling the RaiseError attribute.

       Data Collection
	   If profiling is enabled for a handle then the dispatch code takes a
	   high-resolution timestamp soon after it is entered. Then, after
	   calling the appropriate method and just before returning, it takes
	   another high-resolution timestamp and calls a function to record
	   the information.  That function is passed the two timestamps plus
	   the DBI handle and the name of the method that was called.  That
	   information about a single DBI method call is called the profile
	   sample data.

       Data Filtering
	   If the method call was invoked by the DBI or by a driver then the
	   call is currently ignored for profiling because the time spent will
	   be accounted for by the original 'outermost' call.

	   For example, the calls that the selectrow_arrayref() method makes
	   to prepare() and execute() etc. are not counted individually
	   because the time spent in those methods is going to be allocated to
	   the selectrow_arrayref() method when it returns. If this was not
	   done then it would be very easy to double count time spent inside
	   the DBI.

	   In future releases it may be possible to alter this behaviour.

       Data Storage Tree
	   The profile data is stored as 'leaves on a tree'. The 'path'
	   through the branches of the tree to the particular leaf that will
	   store the profile sample data for a profiled call is determined
	   dynamically.	 This is a powerful feature.

	   For example, if the Path is

	     [ 'foo', 'bar', 'baz' ]

	   then the new profile sample data will be merged into the tree at

	     $h->{Profile}->{Data}->{foo}->{bar}->{baz}

	   It wouldn't be very useful to merge all the call data into one leaf
	   node (except to get an overall 'time spent inside the DBI' total).
	   It's more common to want the Path to include the current statement
	   text and/or the 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 automati‐
	   cally replaced by corresponding dynamic values when they're used.
	   For example DBIprofile_Statement (exported by DBI::profile) is
	   automatically replaced by value of the "Statement" attribute of the
	   handle. For example, is the Path was:

	     [ 'foo', DBIprofile_Statement, 'bar' ]

	   and the value of $h->{Statement} was:

	     SELECT * FROM tablename

	   then the profile data will be merged into the tree at:

	     $h->{Profile}->{Data}->{foo}->{SELECT * FROM tablename}->{bar}

	   The default Path is just "[ DBIprofile_Statement ]" and so by
	   default the profile data is aggregated per distinct Statement
	   string.

	   For statement handles this is always simply the string that was
	   given to prepare() when the handle was created.  For database han‐
	   dles this is the statement that was last prepared or executed on
	   that database handle. That can lead to a little 'fuzzyness'
	   because, for example, calls to the quote() method to build a new
	   statement will typically be associated with the previous statement.
	   In practice this isn't a significant issue and the dynamic Path
	   mechanism can be used to setup your own rules.

       Profile Data
	   Profile data is stored at the 'leaves' of the tree as references to
	   an array of numeric values. For example:

	       [
		 106,			 # count
		 0.0312958955764771,	 # total duration
		 0.000490069389343262,	 # first duration
		 0.000176072120666504,	 # shortest duration
		 0.00140702724456787,	 # longest duration
		 1023115819.83019,	 # time of first event
		 1023115819.86576,	 # time of last event
	       ]

ENABLING A PROFILE
       Profiling is enabled for a handle by assigning to the Profile
       attribute. For example:

	 $h->{Profile} = DBI::Profile->new();

       The Profile attribute holds a blessed reference to a hash object that
       contains the profile data and attributes relating to it.	 The class the
       Profile object is blessed into is expected to provide at least a
       DESTROY method which will dump the profile data to the DBI trace file
       handle (STDERR by default).

       All these examples have the same effect as the first:

	 $h->{Profile} = {};
	 $h->{Profile} = "DBI::Profile";
	 $h->{Profile} = "2/DBI::Profile";
	 $h->{Profile} = 2;

       If a non-blessed hash reference is given then the DBI::Profile module
       is automatically "require"'d and the reference is blessed into that
       class.

       If a string is given then it is split on '"/"' characters and 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 which will be loaded
       and it's "new" method called. If not present it defaults to DBI::Pro‐
       file. Any other values are passed as arguments to the "new" method. For
       example: ""2/DBIx::OtherProfile/Foo/42"".

       Various common sequences for Path can be selected by simply assigning
       an integer value to Profile. The simplest way to explain how the values
       are interpreted is to show the code:

	   push @Path, "DBI"			   if $path & 0x01;
	   push @Path, DBIprofile_Statement	   if $path & 0x02;
	   push @Path, DBIprofile_MethodName	   if $path & 0x04;
	   push @Path, DBIprofile_MethodClass	   if $path & 0x08;

       So using the value ""1"" causes all profile data to be merged into a
       single leaf of the tree. That's useful when you just want a total.

       Using ""2"" causes profile sample data to be merged grouped by the cor‐
       responding Statement text. This is the most frequently used.

       Using ""4"" causes profile sample data to be merged grouped by the
       method name ('FETCH', 'prepare' etc.). Using ""8"" is similar but gives
       the fully qualified 'glob name' of the method called. For example:
       '*DBD::Driver::db::prepare', '*DBD::_::st::fetchrow_hashref'.

       The values can be added together to create deeper paths. The most use‐
       ful being 6 (statement then method name) or 10 (statement then method
       name with class).  Using a negative number will reverse the path. Thus
       -6 will group by method name then statement.

       The spliting and parsing of string values assigned to the Profile
       attribute may seem a little odd, but there's a good reason for it.
       Remember that attributes can be embedded in the Data Source Name string
       which can be passed in to a script as a parameter. For example:

	   dbi:DriverName(RaiseError=>1,Profile=>2):dbname

       And also, if the "DBI_PROFILE" environment variable is set then The DBI
       arranges for every driver handle to share the same profile object. When
       perl exits a single profile summary will be generated that reflects (as
       nearly as practical) the total use of the DBI by the application.

THE PROFILE OBJECT
       The DBI core expects the Profile attribute value to be a hash reference
       and if the following values don't exist it will create them as needed:

       Data

       A reference to a hash containing the collected profile data.

       Path

       The Path value is used to control where the profile for a method call
       will be merged into the collected profile data.	Whenever profile data
       is to be stored the current value for Path is used.

       The value can be one of:

       Array Reference
	   Each element of the array defines an element of the path to use to
	   store the profile data into the "Data" hash.

       Undefined value (the default)
	   Treated the same as "[ $DBI::Profile::DBIprofile_Statement ]".

       Subroutine Reference NOT YET IMPLEMENTED
	   The subroutine is passed the DBI method name and the handle it was
	   called on.  It should return a list of values to uses as the path.
	   If it returns an empty list then the method call is not profiled.

       The following 'magic cookie' values can be included in the Path and
       will be

       DBIprofile_Statement
	   Replaced with the current value of the Statement attribute for the
	   handle the method was called with. If that value is undefined then
	   an empty string is used.

       DBIprofile_MethodName
	   Replaced with the name of the DBI method that the profile sample
	   relates to.

       DBIprofile_MethodClass
	   Replaced with the fully qualified name of the DBI method, including
	   the package, that the profile sample relates to. This shows you
	   where 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 has
	   inherited the selectrow_arrayref method provided by the DBI.

	   But you'll note that there is only one call to DBD::_::db::selec‐
	   trow_arrayref but another 99 to DBD::mysql::db::selectrow_arrayref.
	   That's because after the first call Perl has cached the method to
	   speed up method calls.  You may also see some names begin with an
	   asterix ('"*"').  Both of these effects are subject to change in
	   later releases.

       Other magic cookie values may be added in the future.

REPORTING
       Report Format

       The current profile data can be formatted and output using

	   print $h->{Profile}->format;

       To discard the profile data and start collecting fresh data you can do:

	   $h->{Profile}->{Data} = undef;

       The default results format looks like this:

	 DBI::Profile: 0.001015s (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 of the
       total number of method calls and the name of the script being run, 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 variable is
       used) then the percentage of time the process spent inside the DBI is
       also shown.

       In the example above the paths in the tree are only one level deep and
       use the Statement text as the value (that's the default behaviour).

       The merged profile data at the 'leaves' of the tree are presented as
       total time spent, count, average time spent (which is simply total time
       divided by the count), then the time spent on the first call, the time
       spent on the fastest call, and finally the time spent on the slowest
       call.

       The 'avg', 'first', 'min' and 'max' times are not particularly useful
       when the profile data path only contains the statement text.  Here's an
       extract of a more detailed example using both statement text 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 the 108 calls
       to fetchrow_hashref() become rather more interesting.  Also the data
       for FETCH just shows a time value because it was only called once.

       Currently the profile data is output sorted by branch names. That may
       change in a later version so the leaf nodes are sorted by total time
       per leaf node.

       Report Destination

       The default method of reporting is for the DESTROY method of the Pro‐
       file object to format the results and write them using:

	   DBI->trace_msg($results, 0);	 # see $ON_DESTROY_DUMP below

       to write them to the DBI trace() filehandle (which defaults to STDERR).
       To direct the DBI trace filehandle to write to a file without enabling
       tracing the trace() method can be called with a trace level of 0. For
       example:

	   DBI->trace(0, $filename);

       The same effect can be achieved without changing the code by setting
       the "DBI_TRACE" environment variable to "0=filename".

       The $DBI::Profile::ON_DESTROY_DUMP variable holds a code ref that'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 also be
       useful as a simple way to disable dumping results.

CHILD HANDLES
       Child handles inherit a reference to the Profile attribute value of
       their parent.  So if profiling is enabled for a database handle then by
       default the statement handles created from it all contribute to the
       same merged profile data tree.

CUSTOM DATA COLLECTION
       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 :)

       Adding Your Own Samples

       The dbi_profile() function can be used to add extra sample data into
       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 be asso‐
       ciated with. The $statement parameter is the string to use where the
       Path specifies DBIprofile_Statement. If $statement is undef then
       $h->{Statement} will be used. Similarly $method is the string to use if
       the Path specifies DBIprofile_MethodName. There is no default value for
       $method.

       The $h->{Profile}{Path} attribute is processed by dbi_profile() in the
       usual way.

       It is recommended that you keep these extra data samples separate from
       the DBI profile data samples by using values for $statement and $method
       that are distinct from any that are likely to appear in the profile
       data normally.

SUBCLASSING
       Alternate profile modules must subclass DBI::Profile to help ensure
       they work with future versions of the DBI.

CAVEATS
       Applications which generate many different statement strings (typically
       because they don't use placeholders) and profile with DBIprofile_State‐
       ment in the Path (the default) will consume memory in the Profile Data
       structure for each statement.

       If a method throws an exception itself (not via RaiseError) then it
       won't be counted in the profile.

       If a HandleError subroutine throws an exception (rather than returning
       0 and letting RaiseError do it) then the method call won't be counted
       in the profile.

       Time spent in DESTROY is added to the profile of the parent handle.

       Time spent in DBI->*() methods is not counted. The time spent in the
       driver connect method, $drh->connect(), when it's called by DBI->con‐
       nect is counted if the DBI_PROFILE environment variable is set.

       Time spent fetching tied variables, $DBI::errstr, is counted.

       DBI::PurePerl does not support profiling (though it could in theory).

       A few platforms don't support the gettimeofday() high resolution time
       function used by the DBI (and available via the dbi_time() function).
       In which case you'll get integer resolution time which is mostly use‐
       less.

       On Windows platforms the dbi_time() function is limited to millisecond
       resolution. Which isn't sufficiently fine for our needs, but still much
       better than integer resolution. This limited resolution means that fast
       method calls will often register as taking 0 time. And timings in gen‐
       eral will have much more 'jitter' depending on where within the 'cur‐
       rent millisecond' the start and and timing was taken.

       This documentation could be more clear. Probably needs to be reordered
       to start with several examples and build from there.  Trying to explain
       the concepts first seems painful and to lead to just as many forward
       references.  (Patches welcome!)

3rd Berkeley Distribution	  perl v5.6.1		       DBI::Profile(3)
[top]

List of man pages available for IRIX

Copyright (c) for man pages and the logo by the respective OS vendor.

For those who want to learn more, the polarhome community provides shell access and support.

[legal] [privacy] [GNU] [policy] [cookies] [netiquette] [sponsors] [FAQ]
Tweet
Polarhome, production since 1999.
Member of Polarhome portal.
Based on Fawad Halim's script.
....................................................................
Vote for polarhome
Free Shell Accounts :: the biggest list on the net