分析器簡介¶

cProfile andprofile providedeterministic profiling ofPython programs. Aprofile is a set of statistics that describes howoften and for how long various parts of the program executed. These statisticscan be formatted into reports via thepstats module.

The Python standard library provides two different implementations of the sameprofiling interface:

1. cProfile is recommended for most users; it's a C extension withreasonable overhead that makes it suitable for profiling long-runningprograms. Based onlsprof, contributed by Brett Rosen and TedCzotter.

2. profile, a pure Python module whose interface is imitated bycProfile, but which adds significant overhead to profiled programs.If you're trying to extend the profiler in some way, the task might be easierwith this module. Originally designed and written by Jim Roskind.

Instant User's Manual¶

This section is provided for users that "don't want to read the manual." Itprovides a very brief overview, and allows a user to rapidly perform profilingon an existing application.

To profile a function that takes a single argument, you can do:

importcProfileimportrecProfile.run('re.compile("foo|bar")')

(Useprofile instead ofcProfile if the latter is not available onyour system.)

The above action would runre.compile() and print profile results likethe following:

214functioncalls(207primitivecalls)in0.002secondsOrderedby:cumulativetimencallstottimepercallcumtimepercallfilename:lineno(function)10.0000.0000.0020.002{built-inmethodbuiltins.exec}10.0000.0000.0010.001<string>:1(<module>)10.0000.0000.0010.001__init__.py:250(compile)10.0000.0000.0010.001__init__.py:289(_compile)10.0000.0000.0000.000_compiler.py:759(compile)10.0000.0000.0000.000_parser.py:937(parse)10.0000.0000.0000.000_compiler.py:598(_code)10.0000.0000.0000.000_parser.py:435(_parse_sub)

The first line indicates that 214 calls were monitored. Of those calls, 207wereprimitive, meaning that the call was not induced via recursion. Thenext line:Orderedby:cumulativetime indicates the output is sortedby thecumtime values. The column headings include:

ncalls

for the number of calls.

tottime

for the total time spent in the given function (and excluding time made incalls to sub-functions)

percall

is the quotient oftottime divided byncalls

cumtime

is the cumulative time spent in this and all subfunctions (from invocationtill exit). This figure is accurateeven for recursive functions.

percall

is the quotient ofcumtime divided by primitive calls

filename:lineno(function)

provides the respective data of each function

When there are two numbers in the first column (for example3/1), it meansthat the function recursed. The second value is the number of primitive callsand the former is the total number of calls. Note that when the function doesnot recurse, these two values are the same, and only the single figure isprinted.

Instead of printing the output at the end of the profile run, you can save theresults to a file by specifying a filename to therun() function:

importcProfileimportrecProfile.run('re.compile("foo|bar")','restats')

Thepstats.Stats class reads profile results from a file and formatsthem in various ways.

The filescProfile andprofile can also be invoked as a script toprofile another script. For example:

python-mcProfile[-ooutput_file][-ssort_order](-mmodule|myscript.py)

-o<output_file>¶

Writes the profile results to a file instead of to stdout.

-s<sort_order>¶

Specifies one of thesort_stats() sort valuesto sort the output by.This only applies when-o is not supplied.

-m<module>¶

Specifies that a module is being profiled instead of a script.

在 3.7 版被加入:新增-m 選項到cProfile。

在 3.8 版被加入:新增-m 選項到profile。

Thepstats module'sStats class has a variety of methodsfor manipulating and printing the data saved into a profile results file:

importpstatsfrompstatsimportSortKeyp=pstats.Stats('restats')p.strip_dirs().sort_stats(-1).print_stats()

Thestrip_dirs() method removed the extraneous path from allthe module names. Thesort_stats() method sorted all theentries according to the standard module/line/name string that is printed. Theprint_stats() method printed out all the statistics. Youmight 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 callwill print out the statistics. The following are some interesting calls toexperiment with:

p.sort_stats(SortKey.CUMULATIVE).print_stats(10)

This sorts the profile by cumulative time in a function, and then only printsthe ten most significant lines. If you want to understand what algorithms aretaking time, the above line is what you would use.

If you were looking to see what functions were looping a lot, and taking a lotof time, you would do:

p.sort_stats(SortKey.TIME).print_stats(10)

to sort according to time spent within each function, and then print thestatistics 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 statisticsfor only the class init methods (since they are spelled with__init__ inthem). 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 ofcumulative time, and then prints out some of the statistics. To be specific, thelist is first culled down to 50% (re:.5) of its original size, then onlylines containinginit are maintained, and that sub-sub-list is printed.

If you wondered what functions called the above functions, you could now (pis 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, orguess what the following functions do:

p.print_callees()p.add('restats')

Invoked as a script, thepstats module is a statistics browser forreading and examining profile dumps. It has a simple line-oriented interface(implemented usingcmd) and interactive help.

profile 與cProfile 模組參考文件¶

Both theprofile andcProfile modules provide the followingfunctions:

profile.run(command,filename=None,sort=-1)¶

This function takes a single argument that can be passed to theexec()function, and an optional file name. In all cases this routine executes:

exec(command,__main__.__dict__,__main__.__dict__)

and gathers profiling statistics from the execution. If no file name ispresent, then this function automatically creates aStatsinstance and prints a simple profiling report. If the sort value is specified,it is passed to thisStats instance to control how theresults are sorted.

profile.runctx(command,globals,locals,filename=None,sort=-1)¶

This function is similar torun(), with added arguments to supply theglobals and locals mappings for thecommand string. This routineexecutes:

exec(command,globals,locals)

and gathers profiling statistics as in therun() function above.

classprofile.Profile(timer=None,timeunit=0.0,subcalls=True,builtins=True)¶

This class is normally only used if more precise control over profiling isneeded than what thecProfile.run() function provides.

A custom timer can be supplied for measuring how long code takes to run viathetimer argument. This must be a function that returns a single numberrepresenting the current time. If the number is an integer, thetimeunitspecifies a multiplier that specifies the duration of each unit of time. Forexample, if the timer returns times measured in thousands of seconds, thetime unit would be.001.

Directly using theProfile class allows formatting profile resultswithout writing the profile data to a file:

importcProfile,pstats,iofrompstatsimportSortKeypr=cProfile.Profile()pr.enable()# ... do something ...pr.disable()s=io.StringIO()sortby=SortKey.CUMULATIVEps=pstats.Stats(pr,stream=s).sort_stats(sortby)ps.print_stats()print(s.getvalue())

TheProfile class can also be used as a context manager (supportedonly incProfile module. see情境管理器型別):

importcProfilewithcProfile.Profile()aspr:# ... do something ...pr.print_stats()

在 3.8 版的變更:新增情境管理器的支援。

enable()¶

Start collecting profiling data. Only incProfile.

disable()¶

Stop collecting profiling data. Only incProfile.

create_stats()¶

Stop collecting profiling data and record the results internallyas the current profile.

print_stats(sort=-1)¶

Create aStats object based on the currentprofile and print the results to stdout.

Thesort parameter specifies the sorting order of the displayedstatistics. It accepts a single key or a tuple of keys to enablemulti-level sorting, as inStats.sort_stats.

在 3.13 版被加入:print_stats() now accepts a tuple of keys.

dump_stats(filename)¶

Write the results of the current profile tofilename.

run(cmd)¶

Profile the cmd viaexec().

runctx(cmd,globals,locals)¶

Profile the cmd viaexec() with the specified global andlocal environment.

runcall(func,/,*args,**kwargs)¶

Profilefunc(*args,**kwargs)

Note that profiling will only work if the called command/function actuallyreturns. If the interpreter is terminated (e.g. via asys.exit() callduring the called command/function execution) no profiling results will beprinted.

Stats 類別¶

Analysis of the profiler data is done using theStats class.

classpstats.Stats(*filenamesorprofile,stream=sys.stdout)¶

This class constructor creates an instance of a "statistics object" from afilename (or list of filenames) or from aProfile instance. Outputwill be printed to the stream specified bystream.

The file selected by the above constructor must have been created by thecorresponding version ofprofile orcProfile. To be specific,there isno file compatibility guaranteed with future versions of thisprofiler, and there is no compatibility with files produced by otherprofilers, or the same profiler run on a different operating system. Ifseveral files are provided, all the statistics for identical functions willbe coalesced, so that an overall view of several processes can be consideredin a single report. If additional files need to be combined with data in anexistingStats object, theadd() methodcan be used.

Instead of reading the profile data from a file, acProfile.Profileorprofile.Profile object can be used as the profile data source.

Stats 物件有以下方法：

strip_dirs()¶

This method for theStats class removes all leading pathinformation from file names. It is very useful in reducing the size ofthe printout to fit within (close to) 80 columns. This method modifiesthe object, and the stripped information is lost. After performing astrip operation, the object is considered to have its entries in a"random" order, as it was just after object initialization and loading.Ifstrip_dirs() causes two function names to beindistinguishable (they are on the same line of the same filename, andhave the same function name), then the statistics for these two entriesare accumulated into a single entry.

add(*filenames)¶

This method of theStats class accumulates additional profilinginformation into the current profiling object. Its arguments should referto filenames created by the corresponding version ofprofile.run()orcProfile.run(). Statistics for identically named (re: file, line,name) functions are automatically accumulated into single functionstatistics.

dump_stats(filename)¶

Save the data loaded into theStats object to a file namedfilename. The file is created if it does not exist, and is overwrittenif it already exists. This is equivalent to the method of the same nameon theprofile.Profile andcProfile.Profile classes.

sort_stats(*keys)¶

This method modifies theStats object by sorting it according tothe supplied criteria. The argument can be either a string or a SortKeyenum identifying the basis of a sort (example:'time','name',SortKey.TIME orSortKey.NAME). The SortKey enums argument haveadvantage over the string argument in that it is more robust and lesserror prone.

When more than one key is provided, then additional keys are used assecondary criteria when there is equality in all keys selected beforethem. For example,sort_stats(SortKey.NAME,SortKey.FILE) will sortall the entries according to their function name, and resolve all ties(identical function names) by sorting by file name.

For the string argument, abbreviations can be used for any key names, aslong as the abbreviation is unambiguous.

The following are the valid string and SortKey:

Valid String Arg	Valid enum Arg	含義
'calls'	SortKey.CALLS	call count
'cumulative'	SortKey.CUMULATIVE	cumulative time
'cumtime'	N/A	cumulative time
'file'	N/A	file name（檔案名稱）
'filename'	SortKey.FILENAME	file name（檔案名稱）
'module'	N/A	file name（檔案名稱）
'ncalls'	N/A	call count
'pcalls'	SortKey.PCALLS	primitive call count
'line'	SortKey.LINE	列號
'name'	SortKey.NAME	function name
'nfl'	SortKey.NFL	name/file/line
'stdname'	SortKey.STDNAME	standard name
'time'	SortKey.TIME	internal time
'tottime'	N/A	internal time

Note that all sorts on statistics are in descending order (placing mosttime consuming items first), where as name, file, and line number searchesare in ascending order (alphabetical). The subtle distinction betweenSortKey.NFL andSortKey.STDNAME is that the standard name is asort of the name as printed, which means that the embedded line numbersget compared in an odd way. For example, lines 3, 20, and 40 would (ifthe file names were the same) appear in the string order 20, 3 and 40.In contrast,SortKey.NFL does a numeric compare of the line numbers.In fact,sort_stats(SortKey.NFL) is the same assort_stats(SortKey.NAME,SortKey.FILENAME,SortKey.LINE).

For backward-compatibility reasons, the numeric arguments-1,0,1, and2 are permitted. They are interpreted as'stdname','calls','time', and'cumulative' respectively. If this oldstyle format (numeric) is used, only one sort key (the numeric key) willbe used, and additional arguments will be silently ignored.

在 3.7 版被加入:Added the SortKey enum.

reverse_order()¶

This method for theStats class reverses the ordering of thebasic list within the object. Note that by default ascending vsdescending order is properly selected based on the sort key of choice.

print_stats(*restrictions)¶

This method for theStats class prints out a report as describedin theprofile.run() definition.

The order of the printing is based on the lastsort_stats() operation done on the object (subject tocaveats inadd() andstrip_dirs()).

The arguments provided (if any) can be used to limit the list down to thesignificant entries. Initially, the list is taken to be the complete setof profiled functions. Each restriction is either an integer (to select acount of lines), or a decimal fraction between 0.0 and 1.0 inclusive (toselect a percentage of lines), or a string that will interpreted as aregular expression (to pattern match the standard name that is printed).If several restrictions are provided, then they are applied sequentially.For example:

print_stats(.1,'foo:')

would first limit the printing to first 10% of list, and then only printfunctions that were part of filename.*foo:. In contrast, thecommand:

print_stats('foo:',.1)

would limit the list to all functions having file names.*foo:,and then proceed to only print the first 10% of them.

print_callers(*restrictions)¶

This method for theStats class prints a list of all functionsthat called each function in the profiled database. The ordering isidentical to that provided byprint_stats(), and thedefinition of the restricting argument is also identical. Each caller isreported on its own line. The format differs slightly depending on theprofiler that produced the stats:

• Withprofile, a number is shown in parentheses after each callerto show how many times this specific call was made. For convenience, asecond non-parenthesized number repeats the cumulative time spent in thefunction at the right.

• WithcProfile, each caller is preceded by three numbers: thenumber of times this specific call was made, and the total andcumulative times spent in the current function while it was invoked bythis specific caller.

print_callees(*restrictions)¶

This method for theStats class prints a list of all functionthat were called by the indicated function. Aside from this reversal ofdirection of calls (re: called vs was called by), the arguments andordering are identical to theprint_callers() method.

get_stats_profile()¶

This method returns an instance of StatsProfile, which contains a mappingof function names to instances of FunctionProfile. Each FunctionProfileinstance holds information related to the function's profile such as howlong the function took to run, how many times it was called, etc...

在 3.9 版被加入:Added the following dataclasses: StatsProfile, FunctionProfile.Added the following function: get_stats_profile.

What Is Deterministic Profiling?¶

Deterministic profiling is meant to reflect the fact that allfunctioncall,function return, andexception events are monitored, and precisetimings are made for the intervals between these events (during which time theuser's code is executing). In contrast,statistical profiling (which isnot done by this module) randomly samples the effective instruction pointer, anddeduces where time is being spent. The latter technique traditionally involvesless overhead (as the code does not need to be instrumented), but provides onlyrelative indications of where time is being spent.

In Python, since there is an interpreter active during execution, the presenceof instrumented code is not required in order to do deterministic profiling.Python automatically provides ahook (optional callback) for each event.In addition, the interpreted nature of Python tends to add so much overhead toexecution, that deterministic profiling tends to only add small processingoverhead in typical applications. The result is that deterministic profiling isnot that expensive, yet provides extensive run time statistics about theexecution of a Python program.

Call count statistics can be used to identify bugs in code (surprising counts),and to identify possible inline-expansion points (high call counts). Internaltime statistics can be used to identify "hot loops" that should be carefullyoptimized. Cumulative time statistics should be used to identify high levelerrors in the selection of algorithms. Note that the unusual handling ofcumulative times in this profiler allows statistics for recursiveimplementations of algorithms to be directly compared to iterativeimplementations.

限制¶

One limitation has to do with accuracy of timing information. There is afundamental problem with deterministic profilers involving accuracy. The mostobvious restriction is that the underlying "clock" is only ticking at a rate(typically) of about .001 seconds. Hence no measurements will be more accuratethan the underlying clock. If enough measurements are taken, then the "error"will tend to average out. Unfortunately, removing this first error induces asecond source of error.

The second problem is that it "takes a while" from when an event is dispatcheduntil the profiler's call to get the time actuallygets the state of theclock. Similarly, there is a certain lag when exiting the profiler eventhandler from the time that the clock's value was obtained (and then squirreledaway), until the user's code is once again executing. As a result, functionsthat are called many times, or call many functions, will typically accumulatethis error. The error that accumulates in this fashion is typically less thanthe accuracy of the clock (less than one clock tick), but itcan accumulateand become very significant.

The problem is more important withprofile than with the lower-overheadcProfile. For this reason,profile provides a means ofcalibrating itself for a given platform so that this error can beprobabilistically (on the average) removed. After the profiler is calibrated, itwill be more accurate (in a least square sense), but it will sometimes producenegative numbers (when call counts are exceptionally low, and the gods ofprobability work against you :-). ) Donot be alarmed by negative numbers inthe profile. They shouldonly appear if you have calibrated your profiler,and the results are actually better than without calibration.

校正¶

The profiler of theprofile module subtracts a constant from each eventhandling time to compensate for the overhead of calling the time function, andsocking away the results. By default, the constant is 0. The followingprocedure can be used to obtain a better constant for a given platform (see限制).

importprofilepr=profile.Profile()foriinrange(5):print(pr.calibrate(10000))

The method executes the number of Python calls given by the argument, directlyand again under the profiler, measuring the time for both. It then computes thehidden overhead per profiler event, and returns that as a float. For example,on a 1.8Ghz Intel Core i5 running macOS, and using Python's time.process_time() asthe timer, the magical number is about 4.04e-6.

The object of this exercise is to get a fairly consistent result. If yourcomputer isvery fast, or your timer function has poor resolution, you mighthave to pass 100000, or even 1000000, to get consistent results.

When you have a consistent answer, there are three ways you can use it:

importprofile# 1. Apply computed bias to all Profile instances created hereafter.profile.Profile.bias=your_computed_bias# 2. Apply computed bias to a specific Profile instance.pr=profile.Profile()pr.bias=your_computed_bias# 3. Specify computed bias in instance constructor.pr=profile.Profile(bias=your_computed_bias)

If you have a choice, you are better off choosing a smaller constant, and thenyour results will "less often" show up as negative in profile statistics.

Using a custom timer¶

If you want to change how current time is determined (for example, to force useof wall-clock time or elapsed process time), pass the timing function you wantto theProfile class constructor:

pr=profile.Profile(your_time_func)

The resulting profiler will then callyour_time_func. Depending on whetheryou are usingprofile.Profile orcProfile.Profile,your_time_func's return value will be interpreted differently:

profile.Profile

your_time_func should return a single number, or a list of numbers whosesum is the current time (like whatos.times() returns). If thefunction returns a single time number, or the list of returned numbers haslength 2, then you will get an especially fast version of the dispatchroutine.

Be warned that you should calibrate the profiler class for the timer functionthat you choose (see校正). For most machines, a timerthat returns a lone integer value will provide the best results in terms oflow overhead during profiling. (os.times() ispretty bad, as itreturns a tuple of floating-point values). If you want to substitute abetter timer in the cleanest fashion, derive a class and hardwire areplacement dispatch method that best handles your timer call, along with theappropriate calibration constant.

cProfile.Profile

your_time_func should return a single number. If it returns integers,you can also invoke the class constructor with a second argument specifyingthe real duration of one unit of time. For example, ifyour_integer_time_func returns times measured in thousands of seconds,you would construct theProfile instance as follows:

pr=cProfile.Profile(your_integer_time_func,0.001)

As thecProfile.Profile class cannot be calibrated, custom timerfunctions should be used with care and should be as fast as possible. Forthe best results with a custom timer, it might be necessary to hard-code itin the C source of the internal_lsprof module.

Python 3.3 adds several new functions intime that can be used to makeprecise measurements of process or wall-clock time. For example, seetime.perf_counter().