Instant User's Manual¶
This section is provided for users that "don't want to read the manual." It
provides a very brief overview, and allows a user to rapidly perform profiling
on an existing application.
To profile a function that takes a single argument, you can do:
import cProfile
import re
cProfile.run('re.compile("foo|bar")')
(Use profile instead of cProfile if the latter is not available on
your system.)
The above action would run re.compile() and print profile results like
the following:
214 function calls (207 primitive calls) in 0.002 seconds
Ordered by: cumulative time
ncalls tottime percall cumtime percall filename:lineno(function)
1 0.000 0.000 0.002 0.002 {built-in method builtins.exec}
1 0.000 0.000 0.001 0.001
1 0.000 0.000 0.001 0.001 __init__.py:250(compile)
1 0.000 0.000 0.001 0.001 __init__.py:289(_compile)
1 0.000 0.000 0.000 0.000 _compiler.py:759(compile)
1 0.000 0.000 0.000 0.000 _parser.py:937(parse)
1 0.000 0.000 0.000 0.000 _compiler.py:598(_code)
1 0.000 0.000 0.000 0.000 _parser.py:435(_parse_sub)
The first line indicates that 214 calls were monitored. Of those calls, 207
were primitive, meaning that the call was not induced via recursion. The
next line: Ordered by: cumulative time indicates the output is sorted
by the cumtime values. The column headings include:
ncallsfor the number of calls.
tottimefor the total time spent in the given function (and excluding time made in
calls to sub-functions)
percallis the quotient of tottime divided by ncalls
cumtimeis the cumulative time spent in this and all subfunctions (from invocation
till exit). This figure is accurate even for recursive functions.
percallis the quotient of cumtime divided by primitive calls
filename:lineno(function)provides the respective data of each function
When there are two numbers in the first column (for example 3/1), it means
that the function recursed. The second value is the number of primitive calls
and the former is the total number of calls. Note that when the function does
not recurse, these two values are the same, and only the single figure is
printed.
Instead of printing the output at the end of the profile run, you can save the
results to a file by specifying a filename to the run() function:
import cProfile
import re
cProfile.run('re.compile("foo|bar")', 'restats')
The pstats.Stats class reads profile results from a file and formats
them in various ways.
The files cProfile and profile can also be invoked as a script to
profile another script. For example:
python -m cProfile [-o output_file] [-s sort_order] (-m module | myscript.py)
-o
Writes the profile results to a file instead of to stdout.
-s
Specifies one of the sort_stats() sort values
to sort the output by.
This only applies when -o is not supplied.
-m
Specifies that a module is being profiled instead of a script.
Added in version 3.7: Added the -m option to cProfile.
Added in version 3.8: Added the -m option to profile.
The pstats module's Stats class has a variety of methods
for manipulating and printing the data saved into a profile results file:
import pstats
from pstats import SortKey
p = pstats.Stats('restats')
p.strip_dirs().sort_stats(-1).print_stats()
The strip_dirs() method removed the extraneous path from all
the module names. The sort_stats() method sorted all the
entries according to the standard module/line/name string that is printed. The
print_stats() method printed out all the statistics. You
might try the following sort calls:
p.sort_stats(SortKey.NAME)
p.print_stats()
The first call will actually sort the list by function name, and the second call
will print out the statistics. The following are some interesting calls to
experiment with:
p.sort_stats(SortKey.CUMULATIVE).print_stats(10)
This sorts the profile by cumulative time in a function, and then only prints
the ten most significant lines. If you want to understand what algorithms are
taking time, the above line is what you would use.
If you were looking to see what functions were looping a lot, and taking a lot
of time, you would do:
p.sort_stats(SortKey.TIME).print_stats(10)
to sort according to time spent within each function, and then print the
statistics for the top ten functions.
You might also try:
p.sort_stats(SortKey.FILENAME).print_stats('__init__')
This will sort all the statistics by file name, and then print out statistics
for only the class init methods (since they are spelled with __init__ in
them). As one final example, you could try:
p.sort_stats(SortKey.TIME, SortKey.CUMULATIVE).print_stats(.5, 'init')
This line sorts statistics with a primary key of time, and a secondary key of
cumulative time, and then prints out some of the statistics. To be specific, the
list is first culled down to 50% (re: .5) of its original size, then only
lines containing init are maintained, and that sub-sub-list is printed.
If you wondered what functions called the above functions, you could now (p
is still sorted according to the last criteria) do:
p.print_callers(.5, 'init')
and you would get a list of callers for each of the listed functions.
If you want more functionality, you're going to have to read the manual, or
guess what the following functions do:
p.print_callees()
p.add('restats')
Invoked as a script, the pstats module is a statistics browser for
reading and examining profile dumps. It has a simple line-oriented interface
(implemented using cmd) and interactive help.