| .. _profiling-tracing: | |
| **************************************************** | |
| :mod:`!profiling.tracing` --- Deterministic profiler | |
| **************************************************** | |
| .. module:: profiling.tracing | |
| :synopsis: Deterministic tracing profiler for Python programs. | |
| .. module:: cProfile | |
| :synopsis: Alias for profiling.tracing (backward compatibility). | |
| :noindex: | |
| .. versionadded:: 3.15 | |
| **Source code:** :source:`Lib/profiling/tracing/` | |
| -------------- | |
| The :mod:`!profiling.tracing` module provides deterministic profiling of Python | |
| programs. It monitors every function call, function return, and exception event, | |
| recording precise timing for each. This approach provides exact call counts and | |
| complete visibility into program execution, making it ideal for development and | |
| testing scenarios. | |
| .. note:: | |
| This module is also available as ``cProfile`` for backward compatibility. | |
| The ``cProfile`` name will continue to work in all future Python versions. | |
| Use whichever import style suits your codebase:: | |
| # Preferred (new style) | |
| import profiling.tracing | |
| profiling.tracing.run('my_function()') | |
| # Also works (backward compatible) | |
| import cProfile | |
| cProfile.run('my_function()') | |
| What is deterministic profiling? | |
| ================================ | |
| :dfn:`Deterministic profiling` captures every function call, function return, | |
| and exception event during program execution. The profiler measures the precise | |
| time intervals between these events, providing exact statistics about how the | |
| program behaves. | |
| In contrast to :ref:`statistical profiling <profiling-sampling>`, which samples | |
| the call stack periodically to estimate where time is spent, deterministic | |
| profiling records every event. This means you get exact call counts rather than | |
| statistical approximations. The trade-off is that instrumenting every event | |
| introduces overhead that can slow down program execution. | |
| Python's interpreted nature makes deterministic profiling practical. The | |
| interpreter already dispatches events for function calls and returns, so the | |
| profiler can hook into this mechanism without requiring code modification. The | |
| overhead tends to be moderate relative to the inherent cost of interpretation, | |
| making deterministic profiling suitable for most development workflows. | |
| Deterministic profiling helps answer questions like: | |
| - How many times was this function called? | |
| - What is the complete call graph of my program? | |
| - Which functions are called by a particular function? | |
| - Are there unexpected function calls happening? | |
| Call count statistics can identify bugs (surprising counts) and inline | |
| expansion opportunities (high call counts). Internal time statistics reveal | |
| "hot loops" that warrant optimization. Cumulative time statistics help identify | |
| algorithmic inefficiencies. The handling of cumulative times in this profiler | |
| allows direct comparison of recursive and iterative implementations. | |
| .. _profiling-tracing-cli: | |
| Command-line interface | |
| ====================== | |
| .. program:: profiling.tracing | |
| The :mod:`!profiling.tracing` module can be invoked as a script to profile | |
| another script or module: | |
| .. code-block:: shell-session | |
| python -m profiling.tracing [-o output_file] [-s sort_order] (-m module | script.py) | |
| This runs the specified script or module under the profiler and prints the | |
| results to standard output (or saves them to a file). | |
| .. option:: -o <output_file> | |
| Write the profile results to a file instead of standard output. The output | |
| file can be read by the :mod:`pstats` module for later analysis. | |
| .. option:: -s <sort_order> | |
| Sort the output by the specified key. This accepts any of the sort keys | |
| recognized by :meth:`pstats.Stats.sort_stats`, such as ``cumulative``, | |
| ``time``, ``calls``, or ``name``. This option only applies when | |
| :option:`-o <profiling.tracing -o>` is not specified. | |
| .. option:: -m <module> | |
| Profile a module instead of a script. The module is located using the | |
| standard import mechanism. | |
| .. versionadded:: 3.7 | |
| The ``-m`` option for ``cProfile``. | |
| .. versionadded:: 3.8 | |
| The ``-m`` option for :mod:`profile`. | |
| Programmatic usage examples | |
| =========================== | |
| For more control over profiling, use the module's functions and classes | |
| directly. | |
| Basic profiling | |
| --------------- | |
| The simplest approach uses the :func:`!run` function:: | |
| import profiling.tracing | |
| profiling.tracing.run('my_function()') | |
| This profiles the given code string and prints a summary to standard output. | |
| To save results for later analysis:: | |
| profiling.tracing.run('my_function()', 'output.prof') | |
| Using the :class:`!Profile` class | |
| --------------------------------- | |
| The :class:`!Profile` class provides fine-grained control:: | |
| import profiling.tracing | |
| import pstats | |
| from io import StringIO | |
| pr = profiling.tracing.Profile() | |
| pr.enable() | |
| # ... code to profile ... | |
| pr.disable() | |
| # Print results | |
| s = StringIO() | |
| ps = pstats.Stats(pr, stream=s).sort_stats(pstats.SortKey.CUMULATIVE) | |
| ps.print_stats() | |
| print(s.getvalue()) | |
| The :class:`!Profile` class also works as a context manager:: | |
| import profiling.tracing | |
| with profiling.tracing.Profile() as pr: | |
| # ... code to profile ... | |
| pr.print_stats() | |
| Module reference | |
| ================ | |
| .. currentmodule:: profiling.tracing | |
| .. function:: run(command, filename=None, sort=-1) | |
| Profile execution of a command and print or save the results. | |
| This function executes the *command* string using :func:`exec` in the | |
| ``__main__`` module's namespace:: | |
| exec(command, __main__.__dict__, __main__.__dict__) | |
| If *filename* is not provided, the function creates a :class:`pstats.Stats` | |
| instance and prints a summary to standard output. If *filename* is | |
| provided, the raw profile data is saved to that file for later analysis | |
| with :mod:`pstats`. | |
| The *sort* argument specifies the sort order for printed output, accepting | |
| any value recognized by :meth:`pstats.Stats.sort_stats`. | |
| .. function:: runctx(command, globals, locals, filename=None, sort=-1) | |
| Profile execution of a command with explicit namespaces. | |
| Like :func:`run`, but executes the command with the specified *globals* | |
| and *locals* mappings instead of using the ``__main__`` module's namespace:: | |
| exec(command, globals, locals) | |
| .. class:: Profile(timer=None, timeunit=0.0, subcalls=True, builtins=True) | |
| A profiler object that collects execution statistics. | |
| The optional *timer* argument specifies a custom timing function. If not | |
| provided, the profiler uses a platform-appropriate default timer. When | |
| supplying a custom timer, it must return a single number representing the | |
| current time. If the timer returns integers, use *timeunit* to specify the | |
| duration of one time unit (for example, ``0.001`` for milliseconds). | |
| The *subcalls* argument controls whether the profiler tracks call | |
| relationships between functions. The *builtins* argument controls whether | |
| built-in functions are profiled. | |
| .. versionchanged:: 3.8 | |
| Added context manager support. | |
| .. method:: enable() | |
| Start collecting profiling data. | |
| .. method:: disable() | |
| Stop collecting profiling data. | |
| .. method:: create_stats() | |
| Stop collecting data and record the results internally as the current | |
| profile. | |
| .. method:: print_stats(sort=-1) | |
| Create a :class:`pstats.Stats` object from the current profile and print | |
| the results to standard output. | |
| The *sort* argument specifies the sorting order. It accepts a single | |
| key or a tuple of keys for multi-level sorting, using the same values | |
| as :meth:`pstats.Stats.sort_stats`. | |
| .. versionadded:: 3.13 | |
| Support for a tuple of sort keys. | |
| .. method:: dump_stats(filename) | |
| Write the current profile data to *filename*. The file can be read by | |
| :class:`pstats.Stats` for later analysis. | |
| .. method:: run(cmd) | |
| Profile the command string via :func:`exec`. | |
| .. method:: runctx(cmd, globals, locals) | |
| Profile the command string via :func:`exec` with the specified | |
| namespaces. | |
| .. method:: runcall(func, /, *args, **kwargs) | |
| Profile a function call. Returns whatever *func* returns:: | |
| result = pr.runcall(my_function, arg1, arg2, keyword=value) | |
| .. note:: | |
| Profiling requires that the profiled code returns normally. If the | |
| interpreter terminates (for example, via :func:`sys.exit`) during | |
| profiling, no results will be available. | |
| Using a custom timer | |
| ==================== | |
| The :class:`Profile` class accepts a custom timing function, allowing you to | |
| measure different aspects of execution such as wall-clock time or CPU time. | |
| Pass the timing function to the constructor:: | |
| pr = profiling.tracing.Profile(my_timer_function) | |
| The timer function must return a single number representing the current time. | |
| If it returns integers, also specify *timeunit* to indicate the duration of | |
| one unit:: | |
| # Timer returns time in milliseconds | |
| pr = profiling.tracing.Profile(my_ms_timer, 0.001) | |
| For best performance, the timer function should be as fast as possible. The | |
| profiler calls it frequently, so timer overhead directly affects profiling | |
| overhead. | |
| The :mod:`time` module provides several functions suitable for use as custom | |
| timers: | |
| - :func:`time.perf_counter` for high-resolution wall-clock time | |
| - :func:`time.process_time` for CPU time (excluding sleep) | |
| - :func:`time.monotonic` for monotonic clock time | |
| Limitations | |
| =========== | |
| Deterministic profiling has inherent limitations related to timing accuracy. | |
| The underlying timer typically has a resolution of about one millisecond. | |
| Measurements cannot be more accurate than this resolution. With enough | |
| measurements, timing errors tend to average out, but individual measurements | |
| may be imprecise. | |
| There is also latency between when an event occurs and when the profiler | |
| captures the timestamp. Similarly, there is latency after reading the | |
| timestamp before user code resumes. Functions called frequently accumulate | |
| this latency, which can make them appear slower than they actually are. This | |
| error is typically less than one clock tick per call but can become | |
| significant for functions called many times. | |
| The :mod:`!profiling.tracing` module (and its ``cProfile`` alias) is | |
| implemented as a C extension with low overhead, so these timing issues are | |
| less pronounced than with the deprecated pure Python :mod:`profile` module. | |
| .. seealso:: | |
| :mod:`profiling` | |
| Overview of Python profiling tools and guidance on choosing a profiler. | |
| :mod:`profiling.sampling` | |
| Statistical sampling profiler for production use. | |
| :mod:`pstats` | |
| Statistics analysis and formatting for profile data. | |
| :mod:`profile` | |
| Deprecated pure Python profiler (includes calibration documentation). |