5.5. Profiling CPU
A profile is a set of statistics that describes how often and for how long various parts of the program executed
The profiler modules are designed to provide an execution profile for a given program, not for benchmarking purposes (for that, there is timeit for reasonably accurate results). This particularly applies to benchmarking Python code against C code: the profilers introduce overhead for Python code, but not for C-level functions, and so the C code would seem faster than any Python one.
https://docs.python.org/3.15/whatsnew/3.15.html#tachyon-high-frequency-statistical-sampling-profiler
cProfile (CPython built-in) is a deterministic profiler that provides a detailed report of the time spent in each function, including the number of calls and the cumulative time spent in each function and its sub-functions.
profiling.samplingprofiling.tracingPyCharm IDE
5.5.1. Tracing vs Sampling Profilers
Tracing profilers record every function call and return, which can be very slow and produce large amounts of data.
Sampling profilers take periodic samples of the program's state, which is less intrusive and produces smaller amounts of data.
https://docs.python.org/dev/whatsnew/3.14.html#pep-768-safe-external-debugger-interface-for-cpython
https://docs.python.org/dev/howto/perf_profiling.html#perf-profiling
https://docs.python.org/dev/library/sys.monitoring.html#module-sys.monitoring
https://creators.spotify.com/pod/profile/corepy/episodes/The-Megahertz-e35ffoi
https://docs.python.org/3.15/whatsnew/3.15.html#tachyon-high-frequency-statistical-sampling-profiler
https://www.youtube.com/results?search_query=pablo+galindo+salgado
5.5.2. Built-in Profilers
python -m profile myfile.py(deprecated)python -m cProfile myfile.py(will be renamed topython -m profiling.sampling myfile.pyin Python 3.15)python -m profiling.sampling myfile.py(Since Python 3.15)python -m profiling.tracing myfile.py(Since Python 3.15)
5.5.3. PyCharm Profiler
PyCharm Profiler is a built-in profiler in PyCharm IDE.
python -m pip install yappi
5.5.4. profile
Python's built-in profiler
Written in Python
Only for educational purposes
5.5.5. cProfile
Python's built-in profiler
Written in C
Name |
Description |
|---|---|
ncalls |
for the number of calls |
tottime |
for the total time spent in the given function (and excluding time made in calls to sub-functions) |
percall |
is the quotient of tottime divided by ncalls |
cumtime |
is the cumulative time spent in this and all subfunctions (from invocation till exit) |
percall |
is the quotient of cumtime divided by primitive calls |
filename:lineno(function) |
provides the respective data of each function |
Name |
Description |
|---|---|
calls |
call count |
cumulative |
cumulative time |
cumtime |
cumulative time |
file |
file name |
filename |
file name |
module |
file name |
ncalls |
call count |
pcalls |
primitive call count |
line |
line number |
name |
function name |
nfl |
name/file/line |
stdname |
standard name |
time |
internal time |
tottime |
internal time |
$ python -m cProfile [-o output_file] [-s sort_order] FILE.py
$ python -m cProfile myfile.py
$ python -m cProfile -s cumtime passwd.py
955 function calls (948 primitive calls) in 0.002 seconds
Ordered by: cumulative time
ncalls tottime percall cumtime percall filename:lineno(function)
2/1 0.000 0.000 0.002 0.002 {built-in method builtins.exec}
1 0.000 0.000 0.002 0.002 passwd.py:1(<module>)
2/1 0.000 0.000 0.002 0.002 <frozen importlib._bootstrap>:1349(_find_and_load)
2/1 0.000 0.000 0.001 0.001 <frozen importlib._bootstrap>:1304(_find_and_load_unlocked)
2/1 0.000 0.000 0.001 0.001 <frozen importlib._bootstrap>:911(_load_unlocked)
1 0.000 0.000 0.001 0.001 <frozen importlib._bootstrap_external>:1020(exec_module)
5/2 0.000 0.000 0.001 0.001 <frozen importlib._bootstrap>:480(_call_with_frames_removed)
1 0.000 0.000 0.001 0.001 datetime.py:1(<module>)
2 0.000 0.000 0.001 0.001 <frozen importlib._bootstrap>:806(module_from_spec)
1 0.000 0.000 0.001 0.001 <frozen importlib._bootstrap_external>:1318(create_module)
1 0.001 0.001 0.001 0.001 {built-in method _imp.create_dynamic}
1 0.000 0.000 0.000 0.000 passwd.py:857(main)
4 0.000 0.000 0.000 0.000 passwd.py:528(read)
4 0.000 0.000 0.000 0.000 {method 'read' of '_io.TextIOWrapper' objects}
2 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap>:1240(_find_spec)
7 0.000 0.000 0.000 0.000 {built-in method _io.open}
2 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap_external>:1551(find_spec)
2 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap_external>:1522(_get_spec)
8 0.000 0.000 0.000 0.000 {method '__exit__' of '_io._IOBase' objects}
7 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap_external>:1624(find_spec)
1 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap_external>:1093(get_code)
1 0.000 0.000 0.000 0.000 passwd.py:738(asshadow)
1 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap_external>:1326(exec_module)
1 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap_external>:1214(get_data)
1 0.000 0.000 0.000 0.000 {built-in method _imp.exec_dynamic}
4 0.000 0.000 0.000 0.000 passwd.py:544(asrecords)
9 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap_external>:1500(_path_importer_cache)
2 0.000 0.000 0.000 0.000 {built-in method posix.getcwd}
10 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap_external>:145(_path_stat)
1 0.000 0.000 0.000 0.000 {built-in method _io.open_code}
2 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap>:416(__enter__)
10 0.000 0.000 0.000 0.000 {built-in method posix.stat}
32 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap_external>:131(_path_join)
2 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap>:304(acquire)
2 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap>:733(_init_module_attrs)
1 0.000 0.000 0.000 0.000 passwd.py:636(aspasswd)
74 0.000 0.000 0.000 0.000 passwd.py:479(asint)
2 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap_external>:164(_path_isfile)
2 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap_external>:1619(_get_spec)
2 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap_external>:155(_path_is_mode_type)
22 0.000 0.000 0.000 0.000 passwd.py:491(asdate)
3 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap>:632(cached)
1 0.000 0.000 0.000 0.000 passwd.py:699(asgroups)
2 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap_external>:513(cache_from_source)
59 0.000 0.000 0.000 0.000 {method 'split' of 'str' objects}
2 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap_external>:642(_get_cached)
11 0.000 0.000 0.000 0.000 passwd.py:600(aspassword)
2 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap>:162(__enter__)
1 0.000 0.000 0.000 0.000 {method 'disable' of '_lsprof.Profiler' objects}
1 0.000 0.000 0.000 0.000 passwd.py:561(asmembers)
2 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap>:426(_get_module_lock)
2 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap>:124(setdefault)
2 0.000 0.000 0.000 0.000 __init__.py:101(find_spec)
2 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap_external>:833(spec_from_file_location)
66 0.000 0.000 0.000 0.000 {method 'rstrip' of 'str' objects}
1 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap_external>:782(_compile_bytecode)
2 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap>:420(__exit__)
4 0.000 0.000 0.000 0.000 <frozen codecs>:322(decode)
34 0.000 0.000 0.000 0.000 {method 'join' of 'str' objects}
82 0.000 0.000 0.000 0.000 passwd.py:463(asstr)
2 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap>:372(release)
2 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap_external>:137(_path_split)
1 0.000 0.000 0.000 0.000 passwd.py:586(asaccounts)
38 0.000 0.000 0.000 0.000 {method 'get' of 'dict' objects}
1 0.000 0.000 0.000 0.000 {built-in method marshal.loads}
1 0.000 0.000 0.000 0.000 {method 'read' of '_io.BufferedReader' objects}
47 0.000 0.000 0.000 0.000 {method 'startswith' of 'str' objects}
4 0.000 0.000 0.000 0.000 {method 'splitlines' of 'str' objects}
38 0.000 0.000 0.000 0.000 {method 'append' of 'list' objects}
41 0.000 0.000 0.000 0.000 {method 'isspace' of 'str' objects}
2 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap>:74(__new__)
1 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap_external>:697(_classify_pyc)
36 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap>:491(_verbose_message)
10 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap>:1226(__exit__)
2 0.000 0.000 0.000 0.000 {built-in method builtins.max}
3 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap_external>:89(_unpack_uint32)
10 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap>:1222(__enter__)
1 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap_external>:1233(path_stats)
8 0.000 0.000 0.000 0.000 passwd.py:514(aslist)
2 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap>:1128(find_spec)
14 0.000 0.000 0.000 0.000 {built-in method builtins.getattr}
2 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap>:82(remove)
4 0.000 0.000 0.000 0.000 <frozen codecs>:312(__init__)
2 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap>:232(__init__)
2 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap>:445(cb)
13 0.000 0.000 0.000 0.000 {method 'rpartition' of 'str' objects}
4 0.000 0.000 0.000 0.000 {built-in method _codecs.utf_8_decode}
1 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap_external>:730(_validate_timestamp_pyc)
2 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap_external>:190(_path_abspath)
2 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap>:982(find_spec)
4 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap_external>:139(<genexpr>)
14 0.000 0.000 0.000 0.000 {built-in method _imp.acquire_lock}
2 0.000 0.000 0.000 0.000 {built-in method builtins.locals}
2 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap>:79(__init__)
2 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap>:173(__exit__)
14 0.000 0.000 0.000 0.000 {built-in method _imp.release_lock}
11 0.000 0.000 0.000 0.000 {built-in method builtins.isinstance}
2 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap_external>:185(_path_isabs)
2 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap>:645(parent)
7 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap_external>:67(_relax_case)
10 0.000 0.000 0.000 0.000 {built-in method builtins.len}
2 0.000 0.000 0.000 0.000 {method 'format' of 'str' objects}
1 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap_external>:674(_check_name_wrapper)
2 0.000 0.000 0.000 0.000 {built-in method _imp.is_builtin}
3 0.000 0.000 0.000 0.000 {method 'write' of '_io.TextIOWrapper' objects}
1 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap>:48(_new_module)
2 0.000 0.000 0.000 0.000 {built-in method _imp.find_frozen}
4 0.000 0.000 0.000 0.000 {built-in method builtins.hasattr}
4 0.000 0.000 0.000 0.000 {method '__exit__' of '_thread.RLock' objects}
3 0.000 0.000 0.000 0.000 <frozen codecs>:189(__init__)
2 0.000 0.000 0.000 0.000 {method 'remove' of 'list' objects}
3 0.000 0.000 0.000 0.000 {method 'endswith' of 'str' objects}
2 0.000 0.000 0.000 0.000 {method 'pop' of 'dict' objects}
4 0.000 0.000 0.000 0.000 {built-in method _thread.get_ident}
2 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap>:599(__init__)
3 0.000 0.000 0.000 0.000 {built-in method from_bytes}
2 0.000 0.000 0.000 0.000 {built-in method __new__ of type object at 0x103c87cf0}
4 0.000 0.000 0.000 0.000 {built-in method posix.fspath}
2 0.000 0.000 0.000 0.000 {method 'rfind' of 'str' objects}
2 0.000 0.000 0.000 0.000 _virtualenv.py:52(find_spec)
4 0.000 0.000 0.000 0.000 <frozen codecs>:263(__init__)
2 0.000 0.000 0.000 0.000 {method 'pop' of 'list' objects}
2 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap>:653(has_location)
2 0.000 0.000 0.000 0.000 {built-in method _thread.allocate_lock}
2 0.000 0.000 0.000 0.000 {built-in method _weakref._remove_dead_weakref}
2 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap>:158(__init__)
2 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap>:412(__init__)
2 0.000 0.000 0.000 0.000 __init__.py:108(<lambda>)
1 0.000 0.000 0.000 0.000 {built-in method _imp._fix_co_filename}
1 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap_external>:1184(__init__)
1 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap_external>:1307(__init__)
1 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap_external>:1209(get_filename)
1 0.000 0.000 0.000 0.000 <frozen importlib._bootstrap_external>:1017(create_module)
>>> #
... import cProfile
...
... cProfile.run('import re; re.compile("foo|bar")')
216 function calls (209 primitive calls) in 0.000 seconds
Ordered by: standard name
ncalls tottime percall cumtime percall filename:lineno(function)
1 0.000 0.000 0.000 0.000 <string>:1(<module>)
2 0.000 0.000 0.000 0.000 enum.py:284(__call__)
2 0.000 0.000 0.000 0.000 enum.py:526(__new__)
1 0.000 0.000 0.000 0.000 enum.py:836(__and__)
1 0.000 0.000 0.000 0.000 pydev_import_hook.py:16(do_import)
1 0.000 0.000 0.000 0.000 re.py:232(compile)
1 0.000 0.000 0.000 0.000 re.py:271(_compile)
1 0.000 0.000 0.000 0.000 sre_compile.py:249(_compile_charset)
1 0.000 0.000 0.000 0.000 sre_compile.py:276(_optimize_charset)
2 0.000 0.000 0.000 0.000 sre_compile.py:453(_get_iscased)
1 0.000 0.000 0.000 0.000 sre_compile.py:461(_get_literal_prefix)
1 0.000 0.000 0.000 0.000 sre_compile.py:492(_get_charset_prefix)
1 0.000 0.000 0.000 0.000 sre_compile.py:536(_compile_info)
2 0.000 0.000 0.000 0.000 sre_compile.py:595(isstring)
1 0.000 0.000 0.000 0.000 sre_compile.py:598(_code)
3/1 0.000 0.000 0.000 0.000 sre_compile.py:71(_compile)
1 0.000 0.000 0.000 0.000 sre_compile.py:759(compile)
3 0.000 0.000 0.000 0.000 sre_parse.py:111(__init__)
7 0.000 0.000 0.000 0.000 sre_parse.py:160(__len__)
18 0.000 0.000 0.000 0.000 sre_parse.py:164(__getitem__)
7 0.000 0.000 0.000 0.000 sre_parse.py:172(append)
3/1 0.000 0.000 0.000 0.000 sre_parse.py:174(getwidth)
1 0.000 0.000 0.000 0.000 sre_parse.py:224(__init__)
8 0.000 0.000 0.000 0.000 sre_parse.py:233(__next)
2 0.000 0.000 0.000 0.000 sre_parse.py:249(match)
6 0.000 0.000 0.000 0.000 sre_parse.py:254(get)
1 0.000 0.000 0.000 0.000 sre_parse.py:286(tell)
1 0.000 0.000 0.000 0.000 sre_parse.py:417(_parse_sub)
2 0.000 0.000 0.000 0.000 sre_parse.py:475(_parse)
1 0.000 0.000 0.000 0.000 sre_parse.py:76(__init__)
2 0.000 0.000 0.000 0.000 sre_parse.py:81(groups)
1 0.000 0.000 0.000 0.000 sre_parse.py:903(fix_flags)
1 0.000 0.000 0.000 0.000 sre_parse.py:919(parse)
1 0.000 0.000 0.000 0.000 {built-in method _sre.compile}
1 0.000 0.000 0.000 0.000 {built-in method builtins.__import__}
1 0.000 0.000 0.000 0.000 {built-in method builtins.exec}
25 0.000 0.000 0.000 0.000 {built-in method builtins.isinstance}
29/26 0.000 0.000 0.000 0.000 {built-in method builtins.len}
2 0.000 0.000 0.000 0.000 {built-in method builtins.max}
9 0.000 0.000 0.000 0.000 {built-in method builtins.min}
6 0.000 0.000 0.000 0.000 {built-in method builtins.ord}
48 0.000 0.000 0.000 0.000 {method 'append' of 'list' objects}
1 0.000 0.000 0.000 0.000 {method 'disable' of '_lsprof.Profiler' objects}
5 0.000 0.000 0.000 0.000 {method 'find' of 'bytearray' objects}
1 0.000 0.000 0.000 0.000 {method 'items' of 'dict' objects}
5.5.6. perf
A powerful Python profiler that can be used to profile Python code and C extensions.
Linux and macOS only.
$ PYTHONPERFSUPPORT=1 perf record -F 9999 -g -o perf.data python my_script.py
$ perf report -g -i perf.data
$ perf record -F 9999 -g -o perf.data python -X perf my_script.py
$ perf report -g -i perf.data
or:
import sys
sys.activate_stack_trampoline("perf")
do_profiled_stuff()
sys.deactivate_stack_trampoline()
non_profiled_stuff()
then:
$ perf record -F 9999 -g -o perf.data python ./example.py
$ perf report -g -i perf.data
or with JIT:
$ perf record -F 9999 -g -k 1 --call-graph dwarf -o perf.data python -Xperf_jit my_script.py
$ perf inject -i perf.data --jit --output perf.jit.data
$ perf report -g -i perf.jit.data
or with JIT:
$ PYTHON_PERF_JIT_SUPPORT=1 perf record -F 9999 -g --call-graph dwarf -o perf.data python my_script.py
$ perf inject -i perf.data --jit --output perf.jit.data
$ perf report -g -i perf.jit.data
5.5.7. Samply
Command-line sampling profiler for macOS, Linux, and Windows
Samply is a sampling profiler for Python that can be used to profile Python code and C extensions.
It is designed to be fast and efficient, making it suitable for profiling large applications.
$ python -m pip install samply
$ python -m samply record PYTHONPERFSUPPORT=1 python my_script.py
5.5.8. Yappi
Yappi is a high-performance statistical profiler for Python. It is well-suited for profiling multi-threaded applications and handling partial loads of a program.
pip install yappipython -m yappi myfile.pyyappi.set_clock_type("cpu")# Useset_clock_type("wall")for wall timeyappi.start()yappi.get_func_stats().print_all()yappi.get_thread_stats().print_all()
$ python -m pip install yappi
$ python -m yappi myfile.py
>>> #
... import yappi
...
... def a():
... for _ in range(1_000): # do something CPU heavy
... pass
...
... yappi.set_clock_type("cpu") # Use set_clock_type("wall") for wall time
... yappi.start()
... a()
...
... yappi.get_func_stats().print_all()
... yappi.get_thread_stats().print_all()
Clock type: CPU
Ordered by: totaltime, desc
name ncall tsub ttot tavg doc.py:5 a 1 0.117907 0.117907 0.117907
name id tid ttot scnt _MainThread 0 139867147315008 0.118297 1
>>> #
... import yappi
... import time
... import threading
...
... _NTHREAD = 3
...
...
... def _work(n):
... time.sleep(n * 0.1)
...
...
... yappi.start()
...
... threads = []
... # generate _NTHREAD threads
... for i in range(_NTHREAD):
... t = threading.Thread(target=_work, args=(i + 1, ))
... t.start()
... threads.append(t)
... # wait all threads to finish
... for t in threads:
... t.join()
...
... yappi.stop()
...
... # retrieve thread stats by their thread id (given by yappi)
... threads = yappi.get_thread_stats()
... for thread in threads:
... print("Function stats for (%s) (%d)" % (thread.name, thread.id)
... ) # it is the Thread.__class__.__name__
... yappi.get_func_stats(ctx_id=thread.id).print_all()
Function stats for (Thread) (3)
name ncall tsub ttot tavg ..hon3.7/threading.py:859 Thread.run 1 0.000017 0.000062 0.000062 doc3.py:8 _work 1 0.000012 0.000045 0.000045
Function stats for (Thread) (2)
name ncall tsub ttot tavg ..hon3.7/threading.py:859 Thread.run 1 0.000017 0.000065 0.000065 doc3.py:8 _work 1 0.000010 0.000048 0.000048
Function stats for (Thread) (1)
name ncall tsub ttot tavg ..hon3.7/threading.py:859 Thread.run 1 0.000010 0.000043 0.000043 doc3.py:8 _work 1 0.000006 0.000033 0.000033
Async application:
>>> #
... import asyncio
... import yappi
...
... async def foo():
... await asyncio.sleep(1.0)
... await baz()
... await asyncio.sleep(0.5)
...
... async def bar():
... await asyncio.sleep(2.0)
...
... async def baz():
... await asyncio.sleep(1.0)
...
...
... yappi.set_clock_type("WALL")
...
... with yappi.run():
... asyncio.run(foo())
... asyncio.run(bar())
...
... yappi.get_func_stats().print_all()
Clock type: WALL
Ordered by: totaltime, desc
name ncall tsub ttot tavg doc4.py:5 foo 1 0.000030 2.503808 2.503808 doc4.py:11 bar 1 0.000012 2.002492 2.002492 doc4.py:15 baz 1 0.000013 1.001397 1.001397
5.5.9. Line Profiler
$ python -m pip install line_profiler
$ python -m kernprof -l myfile.py
$ python -m line_profiler -rmt myfile.py.lprof