Finding the Slow Part of Your Python Code With cProfile

When Python code is slow, don't guess which part is slow. Measure it. Guesses are often wrong, and a wrong guess means an afternoon spent speeding up a part that took 2% of the time. cProfile is built into Python and tells you in one run where the time actually goes.

Is it slow enough to bother?

Check first. If a script runs once a month and takes 40 seconds, profiling it is probably a waste of your time. If it runs every few minutes, blocks a person waiting for it, or gets slower every week as the data grows, it's worth it.

A slow script

This builds a small report: it finds which order IDs in a list of 40,000 have already been paid, and makes a summary text.

import random


def load_orders(count):
    random.seed(count)
    return [f"ORD-{random.randint(1, 200_000):06d}" for _ in range(count)]


def find_paid(orders, paid_ids):
    return [order for order in orders if order in paid_ids]


def build_summary(paid):
    text = ""
    for order in paid:
        text += order + "\n"
    return text


def main():
    orders = load_orders(40_000)
    paid_ids = load_orders(20_000)
    paid = find_paid(orders, paid_ids)
    summary = build_summary(paid)
    print(len(paid), "paid orders,", len(summary), "characters")


if __name__ == "__main__":
    main()

import time

import report

start = time.perf_counter()
report.main()
print(f"took {time.perf_counter() - start:.2f}s")

python timeit_report.py

3833 paid orders, 42163 characters
took 5.63s

The time line comes from timeit_report.py, a small wrapper that imports the script and times main(). Your time will be different, but it will be seconds, not milliseconds. Before reading on, guess which function is the slow one. The string building with += in a loop is the usual suspect.

Run cProfile

python -m cProfile -s cumulative report.py

3833 paid orders, 42163 characters
         499694 function calls (499671 primitive calls) in 5.259 seconds

   Ordered by: cumulative time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
      3/1    0.000    0.000    5.259    5.259 {built-in method builtins.exec}
        1    0.001    0.001    5.259    5.259 report.py:1(<module>)
        1    0.000    0.000    5.257    5.257 report.py:20(main)
        1    5.113    5.113    5.113    5.113 report.py:9(find_paid)
        2    0.030    0.015    0.143    0.072 report.py:4(load_orders)
    60000    0.017    0.000    0.113    0.000 random.py:336(randint)
    60000    0.041    0.000    0.097    0.000 random.py:295(randrange)
    60000    0.026    0.000    0.040    0.000 random.py:245(_randbelow_with_getrandbits)
   180000    0.015    0.000    0.015    0.000 {built-in method _operator.index}
...
        1    0.001    0.001    0.001    0.001 report.py:13(build_summary)

This runs the whole script under the profiler and prints a table sorted by cumulative time. Your numbers will differ. The shape won't.

How to read the table

The columns that matter:

• ncalls: how many times the function was called.
• tottime: time spent inside the function itself, not counting functions it called.
• cumtime: time including everything it called.

Read it like this:

1. **Sort by cumulative first,** like above. The top rows are your entry points, like main, and they always have a big cumtime, because everything happens inside them. Go down until you find the first function of yours that's doing real work. Here it's find_paid.
2. **Then look at tottime** to see where the time is really spent. find_paid has almost all of it in its own tottime, so the slow code is inside it, not in something it calls.
3. Ignore anything that's tiny. build_summary, the one most people suspect, is near the bottom with a millisecond or two. I cut the rows in between. Making it faster would save nothing you'd notice.

So the guess was wrong. The problem is order in paid_ids. paid_ids is a list, and in on a list checks every item, one by one. 40,000 orders times up to 20,000 checks each is hundreds of millions of comparisons.

Only the rows you need

The full table can be hundreds of lines. Save the profile to a file and print the top few with pstats:

python -m cProfile -o report.prof report.py

import pstats

stats = pstats.Stats("report.prof")
stats.strip_dirs().sort_stats("tottime").print_stats(5)

Tue Oct 13 12:49:09 2026    report.prof

         499694 function calls (499671 primitive calls) in 5.313 seconds

   Ordered by: internal time
   List reduced from 129 to 5 due to restriction <5>

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    5.156    5.156    5.156    5.156 report.py:9(find_paid)
    60000    0.045    0.000    0.105    0.000 random.py:295(randrange)
        2    0.031    0.015    0.154    0.077 report.py:4(load_orders)
    60000    0.028    0.000    0.044    0.000 random.py:245(_randbelow_with_getrandbits)
    60000    0.018    0.000    0.124    0.000 random.py:336(randint)

sort_stats("tottime") puts the function that does the actual work at the top. print_stats(5) keeps the top five.

Fix the slow part, then measure again

A set checks membership in about the same time no matter how big it is. One line changes:

import random


def load_orders(count):
    random.seed(count)
    return [f"ORD-{random.randint(1, 200_000):06d}" for _ in range(count)]


def find_paid(orders, paid_ids):
    paid_set = set(paid_ids)
    return [order for order in orders if order in paid_set]


def build_summary(paid):
    text = ""
    for order in paid:
        text += order + "\n"
    return text


def main():
    orders = load_orders(40_000)
    paid_ids = load_orders(20_000)
    paid = find_paid(orders, paid_ids)
    summary = build_summary(paid)
    print(len(paid), "paid orders,", len(summary), "characters")


if __name__ == "__main__":
    main()

3833 paid orders, 42163 characters
took 0.04s

Same result, a tiny fraction of the time. And build_summary still uses +=. It could be "\n".join(paid) + "\n", which is cleaner. But the profile says it isn't the problem, so it's a style fix, not a speed fix.

Profiling only part of a program

For a web app or a long program, profile just the part you care about:

import cProfile
import pstats

import report

orders = report.load_orders(40_000)
paid_ids = report.load_orders(20_000)

with cProfile.Profile() as profiler:
    report.find_paid(orders, paid_ids)

pstats.Stats(profiler).strip_dirs().sort_stats("tottime").print_stats(3)

         3 function calls in 0.005 seconds

   Ordered by: internal time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.005    0.005    0.005    0.005 report.py:9(find_paid)
        1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}
        1    0.000    0.000    0.000    0.000 cProfile.py:121(__exit__)

The with block (Python 3.8 and up) profiles only the code inside it. This ran on the fixed version, so find_paid now takes milliseconds.

Common mistakes

• Optimizing before profiling. You fix the wrong thing.
• **Reading only cumtime.** main always looks slow. Look for the function with a big tottime.
• Profiling with tiny test data. A list check that's fast for 100 items is slow for 40,000. Profile with realistic sizes.
• Not measuring again after the fix. Maybe it didn't help.

What happens if you skip measuring

You rewrite the part that looks slow, build_summary here, and test it. It's still slow, because that wasn't the problem. Then you start adding caching, threads or a new library to code that needed a one-line change.

Which part of your slowest script would you guess is the slow one, and are you willing to check before you change it?