Ignore:
Timestamp:
Mar 19, 2014, 11:31:01 PM (11 years ago)
Author:
dmik
Message:

python: Merge vendor 2.7.6 to trunk.

Location:
python/trunk
Files:
2 edited

Legend:

Unmodified
Added
Removed

  • python/trunk

  • python/trunk/Doc/library/profile.rst

    r2 r391  
    1 
    21.. _profile:
    32
    … …  
    65********************
    76
    8 .. sectionauthor:: James Roskind
    9 
    10 
    11 .. index:: single: InfoSeek Corporation
    12 
    13 Copyright © 1994, by InfoSeek Corporation, all rights reserved.
    14 
    15 Written by James Roskind. [#]_
    16 
    17 Permission to use, copy, modify, and distribute this Python software and its
    18 associated documentation for any purpose (subject to the restriction in the
    19 following sentence) without fee is hereby granted, provided that the above
    20 copyright notice appears in all copies, and that both that copyright notice and
    21 this permission notice appear in supporting documentation, and that the name of
    22 InfoSeek not be used in advertising or publicity pertaining to distribution of
    23 the software without specific, written prior permission.  This permission is
    24 explicitly restricted to the copying and modification of the software to remain
    25 in Python, compiled Python, or other languages (such as C) wherein the modified
    26 or derived code is exclusively imported into a Python module.
    27 
    28 INFOSEEK CORPORATION DISCLAIMS ALL WARRANTIES WITH REGARD TO THIS SOFTWARE,
    29 INCLUDING ALL IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS. IN NO EVENT
    30 SHALL INFOSEEK CORPORATION BE LIABLE FOR ANY SPECIAL, INDIRECT OR CONSEQUENTIAL
    31 DAMAGES OR ANY DAMAGES WHATSOEVER RESULTING FROM LOSS OF USE, DATA OR PROFITS,
    32 WHETHER IN AN ACTION OF CONTRACT, NEGLIGENCE OR OTHER TORTIOUS ACTION, ARISING
    33 OUT OF OR IN CONNECTION WITH THE USE OR PERFORMANCE OF THIS SOFTWARE.
     7**Source code:** :source:`Lib/profile.py` and :source:`Lib/pstats.py`
     8
     9--------------
    3410
    3511.. _profiler-introduction:
    … …  
    4218   single: profiling, deterministic
    4319
    44 A :dfn:`profiler` is a program that describes the run time performance
    45 of a program, providing a variety of statistics.  This documentation
    46 describes the profiler functionality provided in the modules
    47 :mod:`cProfile`, :mod:`profile` and :mod:`pstats`.  This profiler
    48 provides :dfn:`deterministic profiling` of Python programs.  It also
    49 provides a series of report generation tools to allow users to rapidly
    50 examine the results of a profile operation.
    51 
    52 The Python standard library provides three different profilers:
    53 
    54 #. :mod:`cProfile` is recommended for most users; it's a C extension
    55    with reasonable overhead
    56    that makes it suitable for profiling long-running programs.
    57    Based on :mod:`lsprof`,
    58    contributed by Brett Rosen and Ted Czotter.
     20:mod:`cProfile` and :mod:`profile` provide :dfn:`deterministic profiling` of
     21Python programs. A :dfn:`profile` is a set of statistics that describes how
     22often and for how long various parts of the program executed. These statistics
     23can be formatted into reports via the :mod:`pstats` module.
     24
     25The Python standard library provides three different implementations of the same
     26profiling interface:
     27
     281. :mod:`cProfile` is recommended for most users; it's a C extension with
     29   reasonable overhead that makes it suitable for profiling long-running
     30   programs.  Based on :mod:`lsprof`, contributed by Brett Rosen and Ted
     31   Czotter.
    5932
    6033   .. versionadded:: 2.5
    6134
    62 #. :mod:`profile`, a pure Python module whose interface is imitated by
    63    :mod:`cProfile`.  Adds significant overhead to profiled programs.
    64    If you're trying to extend
    65    the profiler in some way, the task might be easier with this module.
    66    Copyright © 1994, by InfoSeek Corporation.
     352. :mod:`profile`, a pure Python module whose interface is imitated by
     36   :mod:`cProfile`, but which adds significant overhead to profiled programs.
     37   If you're trying to extend the profiler in some way, the task might be easier
     38   with this module.
    6739
    6840   .. versionchanged:: 2.4
    69       Now also reports the time spent in calls to built-in functions and methods.
    70 
    71 #. :mod:`hotshot` was an experimental C module that focused on minimizing
     41      Now also reports the time spent in calls to built-in functions
     42      and methods.
     43
     443. :mod:`hotshot` was an experimental C module that focused on minimizing
    7245   the overhead of profiling, at the expense of longer data
    7346   post-processing times.  It is no longer maintained and may be
    … …  
    8659usage.
    8760
     61.. note::
     62
     63   The profiler modules are designed to provide an execution profile for a given
     64   program, not for benchmarking purposes (for that, there is :mod:`timeit` for
     65   reasonably accurate results).  This particularly applies to benchmarking
     66   Python code against C code: the profilers introduce overhead for Python code,
     67   but not for C-level functions, and so the C code would seem faster than any
     68   Python one.
     69
    8870
    8971.. _profile-instant:
    … …  
    9678on an existing application.
    9779
    98 To profile an application with a main entry point of :func:`foo`, you would add
    99 the following to your module::
     80To profile a function that takes a single argument, you can do::
    10081
    10182   import cProfile
    102    cProfile.run('foo()')
     83   import re
     84   cProfile.run('re.compile("foo|bar")')
    10385
    10486(Use :mod:`profile` instead of :mod:`cProfile` if the latter is not available on
    10587your system.)
    10688
    107 The above action would cause :func:`foo` to be run, and a series of informative
    108 lines (the profile) to be printed.  The above approach is most useful when
    109 working with the interpreter.  If you would like to save the results of a
    110 profile into a file for later examination, you can supply a file name as the
    111 second argument to the :func:`run` function::
     89The above action would run :func:`re.compile` and print profile results like
     90the following::
     91
     92         197 function calls (192 primitive calls) in 0.002 seconds
     93
     94   Ordered by: standard name
     95
     96   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
     97        1    0.000    0.000    0.001    0.001 <string>:1(<module>)
     98        1    0.000    0.000    0.001    0.001 re.py:212(compile)
     99        1    0.000    0.000    0.001    0.001 re.py:268(_compile)
     100        1    0.000    0.000    0.000    0.000 sre_compile.py:172(_compile_charset)
     101        1    0.000    0.000    0.000    0.000 sre_compile.py:201(_optimize_charset)
     102        4    0.000    0.000    0.000    0.000 sre_compile.py:25(_identityfunction)
     103      3/1    0.000    0.000    0.000    0.000 sre_compile.py:33(_compile)
     104
     105The first line indicates that 197 calls were monitored.  Of those calls, 192
     106were :dfn:`primitive`, meaning that the call was not induced via recursion. The
     107next line: ``Ordered by: standard name``, indicates that the text string in the
     108far right column was used to sort the output. The column headings include:
     109
     110ncalls
     111   for the number of calls,
     112
     113tottime
     114    for the total time spent in the given function (and excluding time made in
     115    calls to sub-functions)
     116
     117percall
     118   is the quotient of ``tottime`` divided by ``ncalls``
     119
     120cumtime
     121   is the cumulative time spent in this and all subfunctions (from invocation
     122   till exit). This figure is accurate *even* for recursive functions.
     123
     124percall
     125   is the quotient of ``cumtime`` divided by primitive calls
     126
     127filename:lineno(function)
     128   provides the respective data of each function
     129
     130When there are two numbers in the first column (for example ``3/1``), it means
     131that the function recursed.  The second value is the number of primitive calls
     132and the former is the total number of calls.  Note that when the function does
     133not recurse, these two values are the same, and only the single figure is
     134printed.
     135
     136Instead of printing the output at the end of the profile run, you can save the
     137results to a file by specifying a filename to the :func:`run` function::
    112138
    113139   import cProfile
    114    cProfile.run('foo()', 'fooprof')
    115 
    116 The file :file:`cProfile.py` can also be invoked as a script to profile another
     140   import re
     141   cProfile.run('re.compile("foo|bar")', 'restats')
     142
     143The :class:`pstats.Stats` class reads profile results from a file and formats
     144them in various ways.
     145
     146The file :mod:`cProfile` can also be invoked as a script to profile another
    117147script.  For example::
    118148
    119    python -m cProfile myscript.py
    120 
    121 :file:`cProfile.py` accepts two optional arguments on the command line::
    122 
    123    cProfile.py [-o output_file] [-s sort_order]
    124 
    125 :option:`-s` only applies to standard output (:option:`-o` is not supplied).
    126 Look in the :class:`Stats` documentation for valid sort values.
    127 
    128 When you wish to review the profile, you should use the methods in the
    129 :mod:`pstats` module.  Typically you would load the statistics data as follows::
     149   python -m cProfile [-o output_file] [-s sort_order] myscript.py
     150
     151``-o`` writes the profile results to a file instead of to stdout
     152
     153``-s`` specifies one of the :func:`~pstats.Stats.sort_stats` sort values to sort
     154the output by. This only applies when ``-o`` is not supplied.
     155
     156The :mod:`pstats` module's :class:`~pstats.Stats` class has a variety of methods
     157for manipulating and printing the data saved into a profile results file::
    130158
    131159   import pstats
    132    p = pstats.Stats('fooprof')
    133 
    134 The class :class:`Stats` (the above code just created an instance of this class)
    135 has a variety of methods for manipulating and printing the data that was just
    136 read into ``p``.  When you ran :func:`cProfile.run` above, what was printed was
    137 the result of three method calls::
    138 
     160   p = pstats.Stats('restats')
    139161   p.strip_dirs().sort_stats(-1).print_stats()
    140162
    141 The first method removed the extraneous path from all the module names. The
    142 second method sorted all the entries according to the standard module/line/name
    143 string that is printed. The third method printed out all the statistics.  You
    144 might try the following sort calls:
    145 
    146 .. (this is to comply with the semantics of the old profiler).
    147 
    148 ::
     163The :meth:`~pstats.Stats.strip_dirs` method removed the extraneous path from all
     164the module names. The :meth:`~pstats.Stats.sort_stats` method sorted all the
     165entries according to the standard module/line/name string that is printed. The
     166:meth:`~pstats.Stats.print_stats` method printed out all the statistics.  You
     167might try the following sort calls::
    149168
    150169   p.sort_stats('name')
    … …  
    195214
    196215   p.print_callees()
    197    p.add('fooprof')
     216   p.add('restats')
    198217
    199218Invoked as a script, the :mod:`pstats` module is a statistics browser for
    200219reading and examining profile dumps.  It has a simple line-oriented interface
    201220(implemented using :mod:`cmd`) and interactive help.
     221
     222:mod:`profile` and :mod:`cProfile` Module Reference
     223=======================================================
     224
     225.. module:: cProfile
     226.. module:: profile
     227   :synopsis: Python source profiler.
     228
     229Both the :mod:`profile` and :mod:`cProfile` modules provide the following
     230functions:
     231
     232.. function:: run(command, filename=None, sort=-1)
     233
     234   This function takes a single argument that can be passed to the :func:`exec`
     235   function, and an optional file name.  In all cases this routine executes::
     236
     237      exec(command, __main__.__dict__, __main__.__dict__)
     238
     239   and gathers profiling statistics from the execution. If no file name is
     240   present, then this function automatically creates a :class:`~pstats.Stats`
     241   instance and prints a simple profiling report. If the sort value is specified
     242   it is passed to this :class:`~pstats.Stats` instance to control how the
     243   results are sorted.
     244
     245.. function:: runctx(command, globals, locals, filename=None)
     246
     247   This function is similar to :func:`run`, with added arguments to supply the
     248   globals and locals dictionaries for the *command* string. This routine
     249   executes::
     250
     251      exec(command, globals, locals)
     252
     253   and gathers profiling statistics as in the :func:`run` function above.
     254
     255.. class:: Profile(timer=None, timeunit=0.0, subcalls=True, builtins=True)
     256
     257   This class is normally only used if more precise control over profiling is
     258   needed than what the :func:`cProfile.run` function provides.
     259
     260   A custom timer can be supplied for measuring how long code takes to run via
     261   the *timer* argument. This must be a function that returns a single number
     262   representing the current time. If the number is an integer, the *timeunit*
     263   specifies a multiplier that specifies the duration of each unit of time. For
     264   example, if the timer returns times measured in thousands of seconds, the
     265   time unit would be ``.001``.
     266
     267   Directly using the :class:`Profile` class allows formatting profile results
     268   without writing the profile data to a file::
     269
     270      import cProfile, pstats, StringIO
     271      pr = cProfile.Profile()
     272      pr.enable()
     273      # ... do something ...
     274      pr.disable()
     275      s = StringIO.StringIO()
     276      sortby = 'cumulative'
     277      ps = pstats.Stats(pr, stream=s).sort_stats(sortby)
     278      ps.print_stats()
     279      print s.getvalue()
     280
     281   .. method:: enable()
     282
     283      Start collecting profiling data.
     284
     285   .. method:: disable()
     286
     287      Stop collecting profiling data.
     288
     289   .. method:: create_stats()
     290
     291      Stop collecting profiling data and record the results internally
     292      as the current profile.
     293
     294   .. method:: print_stats(sort=-1)
     295
     296      Create a :class:`~pstats.Stats` object based on the current
     297      profile and print the results to stdout.
     298
     299   .. method:: dump_stats(filename)
     300
     301      Write the results of the current profile to *filename*.
     302
     303   .. method:: run(cmd)
     304
     305      Profile the cmd via :func:`exec`.
     306
     307   .. method:: runctx(cmd, globals, locals)
     308
     309      Profile the cmd via :func:`exec` with the specified global and
     310      local environment.
     311
     312   .. method:: runcall(func, *args, **kwargs)
     313
     314      Profile ``func(*args, **kwargs)``
     315
     316.. _profile-stats:
     317
     318The :class:`Stats` Class
     319========================
     320
     321Analysis of the profiler data is done using the :class:`~pstats.Stats` class.
     322
     323.. module:: pstats
     324   :synopsis: Statistics object for use with the profiler.
     325
     326.. class:: Stats(*filenames or profile, stream=sys.stdout)
     327
     328   This class constructor creates an instance of a "statistics object" from a
     329   *filename* (or list of filenames) or from a :class:`Profile` instance. Output
     330   will be printed to the stream specified by *stream*.
     331
     332   The file selected by the above constructor must have been created by the
     333   corresponding version of :mod:`profile` or :mod:`cProfile`.  To be specific,
     334   there is *no* file compatibility guaranteed with future versions of this
     335   profiler, and there is no compatibility with files produced by other
     336   profilers.  If several files are provided, all the statistics for identical
     337   functions will be coalesced, so that an overall view of several processes can
     338   be considered in a single report.  If additional files need to be combined
     339   with data in an existing :class:`~pstats.Stats` object, the
     340   :meth:`~pstats.Stats.add` method can be used.
     341
     342   Instead of reading the profile data from a file, a :class:`cProfile.Profile`
     343   or :class:`profile.Profile` object can be used as the profile data source.
     344
     345   :class:`Stats` objects have the following methods:
     346
     347   .. method:: strip_dirs()
     348
     349      This method for the :class:`Stats` class removes all leading path
     350      information from file names.  It is very useful in reducing the size of
     351      the printout to fit within (close to) 80 columns.  This method modifies
     352      the object, and the stripped information is lost.  After performing a
     353      strip operation, the object is considered to have its entries in a
     354      "random" order, as it was just after object initialization and loading.
     355      If :meth:`~pstats.Stats.strip_dirs` causes two function names to be
     356      indistinguishable (they are on the same line of the same filename, and
     357      have the same function name), then the statistics for these two entries
     358      are accumulated into a single entry.
     359
     360
     361   .. method:: add(*filenames)
     362
     363      This method of the :class:`Stats` class accumulates additional profiling
     364      information into the current profiling object.  Its arguments should refer
     365      to filenames created by the corresponding version of :func:`profile.run`
     366      or :func:`cProfile.run`. Statistics for identically named (re: file, line,
     367      name) functions are automatically accumulated into single function
     368      statistics.
     369
     370
     371   .. method:: dump_stats(filename)
     372
     373      Save the data loaded into the :class:`Stats` object to a file named
     374      *filename*.  The file is created if it does not exist, and is overwritten
     375      if it already exists.  This is equivalent to the method of the same name
     376      on the :class:`profile.Profile` and :class:`cProfile.Profile` classes.
     377
     378   .. versionadded:: 2.3
     379
     380
     381   .. method:: sort_stats(*keys)
     382
     383      This method modifies the :class:`Stats` object by sorting it according to
     384      the supplied criteria.  The argument is typically a string identifying the
     385      basis of a sort (example: ``'time'`` or ``'name'``).
     386
     387      When more than one key is provided, then additional keys are used as
     388      secondary criteria when there is equality in all keys selected before
     389      them.  For example, ``sort_stats('name', 'file')`` will sort all the
     390      entries according to their function name, and resolve all ties (identical
     391      function names) by sorting by file name.
     392
     393      Abbreviations can be used for any key names, as long as the abbreviation
     394      is unambiguous.  The following are the keys currently defined:
     395
     396      +------------------+----------------------+
     397      | Valid Arg        | Meaning              |
     398      +==================+======================+
     399      | ``'calls'``      | call count           |
     400      +------------------+----------------------+
     401      | ``'cumulative'`` | cumulative time      |
     402      +------------------+----------------------+
     403      | ``'cumtime'``    | cumulative time      |
     404      +------------------+----------------------+
     405      | ``'file'``       | file name            |
     406      +------------------+----------------------+
     407      | ``'filename'``   | file name            |
     408      +------------------+----------------------+
     409      | ``'module'``     | file name            |
     410      +------------------+----------------------+
     411      | ``'ncalls'``     | call count           |
     412      +------------------+----------------------+
     413      | ``'pcalls'``     | primitive call count |
     414      +------------------+----------------------+
     415      | ``'line'``       | line number          |
     416      +------------------+----------------------+
     417      | ``'name'``       | function name        |
     418      +------------------+----------------------+
     419      | ``'nfl'``        | name/file/line       |
     420      +------------------+----------------------+
     421      | ``'stdname'``    | standard name        |
     422      +------------------+----------------------+
     423      | ``'time'``       | internal time        |
     424      +------------------+----------------------+
     425      | ``'tottime'``    | internal time        |
     426      +------------------+----------------------+
     427
     428      Note that all sorts on statistics are in descending order (placing most
     429      time consuming items first), where as name, file, and line number searches
     430      are in ascending order (alphabetical). The subtle distinction between
     431      ``'nfl'`` and ``'stdname'`` is that the standard name is a sort of the
     432      name as printed, which means that the embedded line numbers get compared
     433      in an odd way.  For example, lines 3, 20, and 40 would (if the file names
     434      were the same) appear in the string order 20, 3 and 40.  In contrast,
     435      ``'nfl'`` does a numeric compare of the line numbers.  In fact,
     436      ``sort_stats('nfl')`` is the same as ``sort_stats('name', 'file',
     437      'line')``.
     438
     439      For backward-compatibility reasons, the numeric arguments ``-1``, ``0``,
     440      ``1``, and ``2`` are permitted.  They are interpreted as ``'stdname'``,
     441      ``'calls'``, ``'time'``, and ``'cumulative'`` respectively.  If this old
     442      style format (numeric) is used, only one sort key (the numeric key) will
     443      be used, and additional arguments will be silently ignored.
     444
     445      .. For compatibility with the old profiler.
     446
     447
     448   .. method:: reverse_order()
     449
     450      This method for the :class:`Stats` class reverses the ordering of the
     451      basic list within the object.  Note that by default ascending vs
     452      descending order is properly selected based on the sort key of choice.
     453
     454      .. This method is provided primarily for compatibility with the old
     455         profiler.
     456
     457
     458   .. method:: print_stats(*restrictions)
     459
     460      This method for the :class:`Stats` class prints out a report as described
     461      in the :func:`profile.run` definition.
     462
     463      The order of the printing is based on the last
     464      :meth:`~pstats.Stats.sort_stats` operation done on the object (subject to
     465      caveats in :meth:`~pstats.Stats.add` and
     466      :meth:`~pstats.Stats.strip_dirs`).
     467
     468      The arguments provided (if any) can be used to limit the list down to the
     469      significant entries.  Initially, the list is taken to be the complete set
     470      of profiled functions.  Each restriction is either an integer (to select a
     471      count of lines), or a decimal fraction between 0.0 and 1.0 inclusive (to
     472      select a percentage of lines), or a regular expression (to pattern match
     473      the standard name that is printed.  If several restrictions are provided,
     474      then they are applied sequentially.  For example::
     475
     476         print_stats(.1, 'foo:')
     477
     478      would first limit the printing to first 10% of list, and then only print
     479      functions that were part of filename :file:`.\*foo:`.  In contrast, the
     480      command::
     481
     482         print_stats('foo:', .1)
     483
     484      would limit the list to all functions having file names :file:`.\*foo:`,
     485      and then proceed to only print the first 10% of them.
     486
     487
     488   .. method:: print_callers(*restrictions)
     489
     490      This method for the :class:`Stats` class prints a list of all functions
     491      that called each function in the profiled database.  The ordering is
     492      identical to that provided by :meth:`~pstats.Stats.print_stats`, and the
     493      definition of the restricting argument is also identical.  Each caller is
     494      reported on its own line.  The format differs slightly depending on the
     495      profiler that produced the stats:
     496
     497      * With :mod:`profile`, a number is shown in parentheses after each caller
     498        to show how many times this specific call was made.  For convenience, a
     499        second non-parenthesized number repeats the cumulative time spent in the
     500        function at the right.
     501
     502      * With :mod:`cProfile`, each caller is preceded by three numbers: the
     503        number of times this specific call was made, and the total and
     504        cumulative times spent in the current function while it was invoked by
     505        this specific caller.
     506
     507
     508   .. method:: print_callees(*restrictions)
     509
     510      This method for the :class:`Stats` class prints a list of all function
     511      that were called by the indicated function.  Aside from this reversal of
     512      direction of calls (re: called vs was called by), the arguments and
     513      ordering are identical to the :meth:`~pstats.Stats.print_callers` method.
    202514
    203515
    … …  
    235547
    236548
    237 Reference Manual -- :mod:`profile` and :mod:`cProfile`
    238 ======================================================
    239 
    240 .. module:: cProfile
    241    :synopsis: Python profiler
    242 
    243 
    244 The primary entry point for the profiler is the global function
    245 :func:`profile.run` (resp. :func:`cProfile.run`). It is typically used to create
    246 any profile information.  The reports are formatted and printed using methods of
    247 the class :class:`pstats.Stats`.  The following is a description of all of these
    248 standard entry points and functions.  For a more in-depth view of some of the
    249 code, consider reading the later section on Profiler Extensions, which includes
    250 discussion of how to derive "better" profilers from the classes presented, or
    251 reading the source code for these modules.
    252 
    253 
    254 .. function:: run(command[, filename])
    255 
    256    This function takes a single argument that can be passed to the
    257    :keyword:`exec` statement, and an optional file name.  In all cases this
    258    routine attempts to :keyword:`exec` its first argument, and gather profiling
    259    statistics from the execution. If no file name is present, then this function
    260    automatically prints a simple profiling report, sorted by the standard name
    261    string (file/line/function-name) that is presented in each line.  The
    262    following is a typical output from such a call::
    263 
    264             2706 function calls (2004 primitive calls) in 4.504 CPU seconds
    265 
    266       Ordered by: standard name
    267 
    268       ncalls  tottime  percall  cumtime  percall filename:lineno(function)
    269            2    0.006    0.003    0.953    0.477 pobject.py:75(save_objects)
    270         43/3    0.533    0.012    0.749    0.250 pobject.py:99(evaluate)
    271        ...
    272 
    273    The first line indicates that 2706 calls were monitored.  Of those calls, 2004
    274    were :dfn:`primitive`.  We define :dfn:`primitive` to mean that the call was not
    275    induced via recursion. The next line: ``Ordered by: standard name``, indicates
    276    that the text string in the far right column was used to sort the output. The
    277    column headings include:
    278 
    279    ncalls
    280       for the number of calls,
    281 
    282    tottime
    283       for the total time spent in the given function (and excluding time made in calls
    284       to sub-functions),
    285 
    286    percall
    287       is the quotient of ``tottime`` divided by ``ncalls``
    288 
    289    cumtime
    290       is the total time spent in this and all subfunctions (from invocation till
    291       exit). This figure is accurate *even* for recursive functions.
    292 
    293    percall
    294       is the quotient of ``cumtime`` divided by primitive calls
    295 
    296    filename:lineno(function)
    297       provides the respective data of each function
    298 
    299    When there are two numbers in the first column (for example, ``43/3``), then the
    300    latter is the number of primitive calls, and the former is the actual number of
    301    calls.  Note that when the function does not recurse, these two values are the
    302    same, and only the single figure is printed.
    303 
    304 
    305 .. function:: runctx(command, globals, locals[, filename])
    306 
    307    This function is similar to :func:`run`, with added arguments to supply the
    308    globals and locals dictionaries for the *command* string.
    309 
    310 Analysis of the profiler data is done using the :class:`Stats` class.
    311 
    312 .. note::
    313 
    314    The :class:`Stats` class is defined in the :mod:`pstats` module.
    315 
    316 
    317 .. module:: pstats
    318    :synopsis: Statistics object for use with the profiler.
    319 
    320 
    321 .. class:: Stats(filename[, stream=sys.stdout[, ...]])
    322 
    323    This class constructor creates an instance of a "statistics object" from a
    324    *filename* (or set of filenames).  :class:`Stats` objects are manipulated by
    325    methods, in order to print useful reports.  You may specify an alternate output
    326    stream by giving the keyword argument, ``stream``.
    327 
    328    The file selected by the above constructor must have been created by the
    329    corresponding version of :mod:`profile` or :mod:`cProfile`.  To be specific,
    330    there is *no* file compatibility guaranteed with future versions of this
    331    profiler, and there is no compatibility with files produced by other profilers.
    332    If several files are provided, all the statistics for identical functions will
    333    be coalesced, so that an overall view of several processes can be considered in
    334    a single report.  If additional files need to be combined with data in an
    335    existing :class:`Stats` object, the :meth:`add` method can be used.
    336 
    337    .. (such as the old system profiler).
    338 
    339    .. versionchanged:: 2.5
    340       The *stream* parameter was added.
    341 
    342 
    343 .. _profile-stats:
    344 
    345 The :class:`Stats` Class
    346 ------------------------
    347 
    348 :class:`Stats` objects have the following methods:
    349 
    350 
    351 .. method:: Stats.strip_dirs()
    352 
    353    This method for the :class:`Stats` class removes all leading path information
    354    from file names.  It is very useful in reducing the size of the printout to fit
    355    within (close to) 80 columns.  This method modifies the object, and the stripped
    356    information is lost.  After performing a strip operation, the object is
    357    considered to have its entries in a "random" order, as it was just after object
    358    initialization and loading.  If :meth:`strip_dirs` causes two function names to
    359    be indistinguishable (they are on the same line of the same filename, and have
    360    the same function name), then the statistics for these two entries are
    361    accumulated into a single entry.
    362 
    363 
    364 .. method:: Stats.add(filename[, ...])
    365 
    366    This method of the :class:`Stats` class accumulates additional profiling
    367    information into the current profiling object.  Its arguments should refer to
    368    filenames created by the corresponding version of :func:`profile.run` or
    369    :func:`cProfile.run`. Statistics for identically named (re: file, line, name)
    370    functions are automatically accumulated into single function statistics.
    371 
    372 
    373 .. method:: Stats.dump_stats(filename)
    374 
    375    Save the data loaded into the :class:`Stats` object to a file named *filename*.
    376    The file is created if it does not exist, and is overwritten if it already
    377    exists.  This is equivalent to the method of the same name on the
    378    :class:`profile.Profile` and :class:`cProfile.Profile` classes.
    379 
    380    .. versionadded:: 2.3
    381 
    382 
    383 .. method:: Stats.sort_stats(key[, ...])
    384 
    385    This method modifies the :class:`Stats` object by sorting it according to the
    386    supplied criteria.  The argument is typically a string identifying the basis of
    387    a sort (example: ``'time'`` or ``'name'``).
    388 
    389    When more than one key is provided, then additional keys are used as secondary
    390    criteria when there is equality in all keys selected before them.  For example,
    391    ``sort_stats('name', 'file')`` will sort all the entries according to their
    392    function name, and resolve all ties (identical function names) by sorting by
    393    file name.
    394 
    395    Abbreviations can be used for any key names, as long as the abbreviation is
    396    unambiguous.  The following are the keys currently defined:
    397 
    398    +------------------+----------------------+
    399    | Valid Arg        | Meaning              |
    400    +==================+======================+
    401    | ``'calls'``      | call count           |
    402    +------------------+----------------------+
    403    | ``'cumulative'`` | cumulative time      |
    404    +------------------+----------------------+
    405    | ``'file'``       | file name            |
    406    +------------------+----------------------+
    407    | ``'module'``     | file name            |
    408    +------------------+----------------------+
    409    | ``'pcalls'``     | primitive call count |
    410    +------------------+----------------------+
    411    | ``'line'``       | line number          |
    412    +------------------+----------------------+
    413    | ``'name'``       | function name        |
    414    +------------------+----------------------+
    415    | ``'nfl'``        | name/file/line       |
    416    +------------------+----------------------+
    417    | ``'stdname'``    | standard name        |
    418    +------------------+----------------------+
    419    | ``'time'``       | internal time        |
    420    +------------------+----------------------+
    421 
    422    Note that all sorts on statistics are in descending order (placing most time
    423    consuming items first), where as name, file, and line number searches are in
    424    ascending order (alphabetical). The subtle distinction between ``'nfl'`` and
    425    ``'stdname'`` is that the standard name is a sort of the name as printed, which
    426    means that the embedded line numbers get compared in an odd way.  For example,
    427    lines 3, 20, and 40 would (if the file names were the same) appear in the string
    428    order 20, 3 and 40.  In contrast, ``'nfl'`` does a numeric compare of the line
    429    numbers.  In fact, ``sort_stats('nfl')`` is the same as ``sort_stats('name',
    430    'file', 'line')``.
    431 
    432    For backward-compatibility reasons, the numeric arguments ``-1``, ``0``, ``1``,
    433    and ``2`` are permitted.  They are interpreted as ``'stdname'``, ``'calls'``,
    434    ``'time'``, and ``'cumulative'`` respectively.  If this old style format
    435    (numeric) is used, only one sort key (the numeric key) will be used, and
    436    additional arguments will be silently ignored.
    437 
    438    .. For compatibility with the old profiler,
    439 
    440 
    441 .. method:: Stats.reverse_order()
    442 
    443    This method for the :class:`Stats` class reverses the ordering of the basic list
    444    within the object.  Note that by default ascending vs descending order is
    445    properly selected based on the sort key of choice.
    446 
    447    .. This method is provided primarily for compatibility with the old profiler.
    448 
    449 
    450 .. method:: Stats.print_stats([restriction, ...])
    451 
    452    This method for the :class:`Stats` class prints out a report as described in the
    453    :func:`profile.run` definition.
    454 
    455    The order of the printing is based on the last :meth:`sort_stats` operation done
    456    on the object (subject to caveats in :meth:`add` and :meth:`strip_dirs`).
    457 
    458    The arguments provided (if any) can be used to limit the list down to the
    459    significant entries.  Initially, the list is taken to be the complete set of
    460    profiled functions.  Each restriction is either an integer (to select a count of
    461    lines), or a decimal fraction between 0.0 and 1.0 inclusive (to select a
    462    percentage of lines), or a regular expression (to pattern match the standard
    463    name that is printed; as of Python 1.5b1, this uses the Perl-style regular
    464    expression syntax defined by the :mod:`re` module).  If several restrictions are
    465    provided, then they are applied sequentially.  For example::
    466 
    467       print_stats(.1, 'foo:')
    468 
    469    would first limit the printing to first 10% of list, and then only print
    470    functions that were part of filename :file:`.\*foo:`.  In contrast, the
    471    command::
    472 
    473       print_stats('foo:', .1)
    474 
    475    would limit the list to all functions having file names :file:`.\*foo:`, and
    476    then proceed to only print the first 10% of them.
    477 
    478 
    479 .. method:: Stats.print_callers([restriction, ...])
    480 
    481    This method for the :class:`Stats` class prints a list of all functions that
    482    called each function in the profiled database.  The ordering is identical to
    483    that provided by :meth:`print_stats`, and the definition of the restricting
    484    argument is also identical.  Each caller is reported on its own line.  The
    485    format differs slightly depending on the profiler that produced the stats:
    486 
    487    * With :mod:`profile`, a number is shown in parentheses after each caller to
    488      show how many times this specific call was made.  For convenience, a second
    489      non-parenthesized number repeats the cumulative time spent in the function
    490      at the right.
    491 
    492    * With :mod:`cProfile`, each caller is preceded by three numbers: the number of
    493      times this specific call was made, and the total and cumulative times spent in
    494      the current function while it was invoked by this specific caller.
    495 
    496 
    497 .. method:: Stats.print_callees([restriction, ...])
    498 
    499    This method for the :class:`Stats` class prints a list of all function that were
    500    called by the indicated function.  Aside from this reversal of direction of
    501    calls (re: called vs was called by), the arguments and ordering are identical to
    502    the :meth:`print_callers` method.
    503 
    504 
    505 .. _profile-limits:
     549.. _profile-limitations:
    506550
    507551Limitations
    … …  
    546590socking away the results.  By default, the constant is 0. The following
    547591procedure can be used to obtain a better constant for a given platform (see
    548 discussion in section Limitations above). ::
     592:ref:`profile-limitations`). ::
    549593
    550594   import profile
    … …  
    556600and again under the profiler, measuring the time for both. It then computes the
    557601hidden overhead per profiler event, and returns that as a float.  For example,
    558 on an 800 MHz Pentium running Windows 2000, and using Python's time.clock() as
    559 the timer, the magical number is about 12.5e-6.
     602on a 1.8Ghz Intel Core i5 running Mac OS X, and using Python's time.clock() as
     603the timer, the magical number is about 4.04e-6.
    560604
    561605The object of this exercise is to get a fairly consistent result. If your
    … …  
    580624your results will "less often" show up as negative in profile statistics.
    581625
    582 
    583 .. _profiler-extensions:
    584 
    585 Extensions --- Deriving Better Profilers
    586 ========================================
    587 
    588 The :class:`Profile` class of both modules, :mod:`profile` and :mod:`cProfile`,
    589 were written so that derived classes could be developed to extend the profiler.
    590 The details are not described here, as doing this successfully requires an
    591 expert understanding of how the :class:`Profile` class works internally.  Study
    592 the source code of the module carefully if you want to pursue this.
    593 
    594 If all you want to do is change how current time is determined (for example, to
    595 force use of wall-clock time or elapsed process time), pass the timing function
    596 you want to the :class:`Profile` class constructor::
    597 
    598    pr = profile.Profile(your_time_func)
    599 
    600 The resulting profiler will then call :func:`your_time_func`.
     626.. _profile-timers:
     627
     628Using a custom timer
     629====================
     630
     631If you want to change how current time is determined (for example, to force use
     632of wall-clock time or elapsed process time), pass the timing function you want
     633to the :class:`Profile` class constructor::
     634
     635    pr = profile.Profile(your_time_func)
     636
     637The resulting profiler will then call ``your_time_func``. Depending on whether
     638you are using :class:`profile.Profile` or :class:`cProfile.Profile`,
     639``your_time_func``'s return value will be interpreted differently:
    601640
    602641:class:`profile.Profile`
    603    :func:`your_time_func` should return a single number, or a list of numbers whose
    604    sum is the current time (like what :func:`os.times` returns).  If the function
    605    returns a single time number, or the list of returned numbers has length 2, then
    606    you will get an especially fast version of the dispatch routine.
     642   ``your_time_func`` should return a single number, or a list of numbers whose
     643   sum is the current time (like what :func:`os.times` returns).  If the
     644   function returns a single time number, or the list of returned numbers has
     645   length 2, then you will get an especially fast version of the dispatch
     646   routine.
    607647
    608648   Be warned that you should calibrate the profiler class for the timer function
    609    that you choose.  For most machines, a timer that returns a lone integer value
    610    will provide the best results in terms of low overhead during profiling.
    611    (:func:`os.times` is *pretty* bad, as it returns a tuple of floating point
    612    values).  If you want to substitute a better timer in the cleanest fashion,
    613    derive a class and hardwire a replacement dispatch method that best handles your
    614    timer call, along with the appropriate calibration constant.
     649   that you choose (see :ref:`profile-calibration`).  For most machines, a timer
     650   that returns a lone integer value will provide the best results in terms of
     651   low overhead during profiling.  (:func:`os.times` is *pretty* bad, as it
     652   returns a tuple of floating point values).  If you want to substitute a
     653   better timer in the cleanest fashion, derive a class and hardwire a
     654   replacement dispatch method that best handles your timer call, along with the
     655   appropriate calibration constant.
    615656
    616657:class:`cProfile.Profile`
    617    :func:`your_time_func` should return a single number.  If it returns plain
    618    integers, you can also invoke the class constructor with a second argument
    619    specifying the real duration of one unit of time.  For example, if
    620    :func:`your_integer_time_func` returns times measured in thousands of seconds,
    621    you would constuct the :class:`Profile` instance as follows::
    622 
    623       pr = profile.Profile(your_integer_time_func, 0.001)
     658   ``your_time_func`` should return a single number.  If it returns integers,
     659   you can also invoke the class constructor with a second argument specifying
     660   the real duration of one unit of time.  For example, if
     661   ``your_integer_time_func`` returns times measured in thousands of seconds,
     662   you would construct the :class:`Profile` instance as follows::
     663
     664      pr = cProfile.Profile(your_integer_time_func, 0.001)
    624665
    625666   As the :mod:`cProfile.Profile` class cannot be calibrated, custom timer
    626    functions should be used with care and should be as fast as possible.  For the
    627    best results with a custom timer, it might be necessary to hard-code it in the C
    628    source of the internal :mod:`_lsprof` module.
     667   functions should be used with care and should be as fast as possible.  For
     668   the best results with a custom timer, it might be necessary to hard-code it
     669   in the C source of the internal :mod:`_lsprof` module.
     670
    629671
    630672.. rubric:: Footnotes
    631673
    632 .. [#] Updated and converted to LaTeX by Guido van Rossum. Further updated by Armin
    633    Rigo to integrate the documentation for the new :mod:`cProfile` module of Python
    634    2.5.
    635 
    636 .. [#] Prior to Python 2.2, it was necessary to edit the profiler source code to embed
    637    the bias as a literal number.  You still can, but that method is no longer
     674.. [#] Prior to Python 2.2, it was necessary to edit the profiler source code to
     675   embed the bias as a literal number.  You still can, but that method is no longer
    638676   described, because no longer needed.
    639 
Note: See TracChangeset for help on using the changeset viewer.