Find Slow Functions with cProfile

Your import script got slower, and you don't know which function to blame. Timing every function by hand would take all day. A profiler watches your program run and reports where the time went. Python's built-in cProfile records every function call. Save this as report.py and run it:

import cProfile
import pstats


def parse_row(line: str) -> tuple[str, int]:
    name, qty = line.split(",")
    return name, int(qty)


def load(lines: list[str]) -> dict[str, int]:
    totals: dict[str, int] = {}
    for line in lines:
        name, qty = parse_row(line)
        totals[name] = totals.get(name, 0) + qty
    return totals


lines = [f"item{i % 50},{i % 7}" for i in range(200_000)]

profiler = cProfile.Profile()
profiler.enable()
totals = load(lines)
profiler.disable()

assert totals["item0"] == sum(i % 7 for i in range(0, 200_000, 50))
pstats.Stats(profiler).sort_stats("tottime").print_stats(5)

On a laptop with Python 3.15, it printed this, with the folder names cut:

         600002 function calls in 0.071 seconds

   Ordered by: internal time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.027    0.027    0.071    0.071 report.py:10(load)
   200000    0.024    0.000    0.034    0.000 report.py:5(parse_row)
   200000    0.010    0.000    0.010    0.000 {method 'split' of 'str' objects}
   200000    0.010    0.000    0.010    0.000 {method 'get' of 'dict' objects}
        1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}

Self time and cumulative time

Each row is one function, with times in seconds:

• ncalls is the number of calls.
• tottime is its self time, the time in the function's own lines.
• cumtime is its cumulative time, which also includes the functions it calls.
• The two percall columns divide tottime and cumtime by the calls.

load has a cumulative time of 0.071 seconds, the whole run, because it calls everything else. Its self time of 0.027 seconds is its own loop and dictionary update. parse_row ran 200,000 times, and its cumulative time includes 0.010 seconds inside str.split.

Sort by "tottime" to find the functions that do the work themselves. Sort by "cumulative" to follow the slow path down from the top. Don't add up the cumulative column, because load's 0.071 seconds already contains the 0.034 seconds of parse_row.

To profile a whole script without editing it, run python -m cProfile -s cumulative script.py. Use it on a script with no profiling code of its own. Only one profiler can run at a time, so running it on report.py raises ValueError.

Common mistakes

• Skipping a function with high cumulative time and low self time. A wrapper that does little itself can still be the place to fix. It may call an expensive helper more often than it needs to.
• Comparing timings taken under the profiler. cProfile adds work to every call it records. Without it, load took 0.020 seconds, not 0.071. Many small Python functions pay more of that extra cost than a few large ones, so the profiler can change which version looks faster. Use the profile to find the slow place. Then time your fix with perf_counter or timeit, with the profiler off.

Read a profile in code

The exercise reads the profile with Profile.getstats() instead of printing it. Each entry has inlinetime, the self time, and totaltime, the cumulative time. Its code field is a code object for a Python function and a string for a built-in such as str.split. Check its type before you read code.co_name.

Going further

The pstats documentation lists every sort key. Python 3.15 adds a profiling package, in which profiling.tracing is the new name for cProfile. import cProfile still works there. Python 3.15 also adds a sampling profiler, which the optional articles at the end of this track cover.