Migration¶

Migrating fromprofile toprofiling.tracing is straightforward.The APIs are compatible:

# Old (deprecated)importprofileprofile.run('my_function()')# New (recommended)importprofiling.tracingprofiling.tracing.run('my_function()')

For most code, replacingimportprofile withimportprofiling.tracing(and usingprofiling.tracing instead ofprofile throughout) providesa straightforward migration path.

profile andprofiling.tracing module reference¶

Both theprofile andprofiling.tracing modules provide thefollowing functions:

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 theprofiling.tracing.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:

importprofiling.tracingimportpstatsimportiofrompstatsimportSortKeypr=profiling.tracing.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 inprofiling.tracing, not in the deprecatedprofilemodule; seeContext Manager Types):

importprofiling.tracingwithprofiling.tracing.Profile()aspr:# ... do something ...pr.print_stats()

Changed in version 3.8:Added context manager support.

enable()¶

Start collecting profiling data. Only inprofiling.tracing.

disable()¶

Stop collecting profiling data. Only inprofiling.tracing.

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 inpstats.Stats.sort_stats().

Added in version 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.

Differences fromprofiling.tracing¶

Theprofile module differs fromprofiling.tracing in severalways:

Higher overhead. The pure Python implementation is significantly slowerthan the C implementation, making it unsuitable for profiling long-runningprograms or performance-sensitive code.

Calibration support. Theprofile module supports calibration tocompensate for profiling overhead. This is not needed inprofiling.tracingbecause the C implementation has negligible overhead.

Custom timers. Both modules support custom timers, butprofileaccepts timer functions that return tuples (likeos.times()), whileprofiling.tracing requires a function returning a single number.

Subclassing. The pure Python implementation is easier to subclass andextend for custom profiling behavior.

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 isprovided by theprofiling.sampling module) periodically samples theeffective instruction pointer, and deduces where time is being spent. Thelatter technique traditionally involves less overhead (as the code does notneed to be instrumented), but provides only relative indications of where timeis 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.

Limitations¶

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 with the deprecatedprofile module thanwith the lower-overheadprofiling.tracing. For this reason,profile provides a means of calibrating itself for a given platform sothat this error can be probabilistically (on the average) removed. After theprofiler is calibrated, it will be more accurate (in a least square sense), butit will sometimes produce negative numbers (when call counts are exceptionallylow, and the gods of probability work against you :-). ) Donot be alarmedby negative numbers in the profile. They shouldonly appear if you havecalibrated your profiler, and the results are actually better than withoutcalibration.

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

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 orprofiling.tracing.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 (seeCalibration). 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.

profiling.tracing.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=profiling.tracing.Profile(your_integer_time_func,0.001)

As theprofiling.tracing.Profile class cannot be calibrated, customtimer functions should be used with care and should be as fast as possible.For the best results with a custom timer, it might be necessary to hard-codeit in 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().