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()

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.