Profiling and performance

What you'll learn

• Measure before optimizing, with timeit for snippets and cProfile for whole programs
• Read a profile and find the few functions that account for most of the time
• Apply the speedups that actually matter in Python: better data structures, fewer Python-level operations, caching, and moving work out of loops
• Know when to stop, and when the answer is a different tool

Concept

Every optimization starts with the same three words: measure it first. Intuition about what is slow is wrong often enough that acting on it wastes days. timeit answers "how long does this small piece take", running it many times and reporting the best of several rounds so noise is averaged out. cProfile answers "where does this whole program spend its time", recording every function call with how often it ran and how long it took, including the time spent in the functions it called.

A profile is a table. ncalls is how many times a function ran, tottime the time inside it excluding callees, cumtime the time including callees, and percall the averages. Sort by cumtime to see which high-level operations dominate, then by tottime to see which functions do the actual work. Almost always a handful of lines account for most of the time; that is where to look, and nowhere else. snakeviz and the pstats module let you browse a saved profile, and python -m cProfile -s cumtime script.py needs no code changes at all.

The fixes with the biggest payoff are the least clever. A quadratic loop becomes linear with a dictionary. A value computed inside a loop that never changes moves above it. A function called a million times with a hundred distinct inputs gets lru_cache. String building with += in a loop becomes one "".join. Python-level loops become built-ins, which loop in C. Only after those does micro-optimization of a hot inner loop, such as binding a method to a local name, earn its keep, and only with a profile pointing at it.

Knowing when to stop matters as much. The goal is a target, not a minimum: fast enough for the user, the batch window, the budget. Once the profile shows time spread thinly across many small functions, the remaining wins are structural: a compiled extension, a different algorithm, caching results across runs, or doing less work. Readability is a cost you pay on every future change, so keep the clear version unless the measured gain justifies the harder code, and leave a comment saying why.

Code

timeit on three ways to build a string. The numbers vary by machine; the ranking does not, and that ranking is what you act on.

# timeit_demo.py
import timeit

words = [f"word{i}" for i in range(2000)]


def plus_equals():
    out = ""
    for w in words:
        out += w + " "
    return out


def join_words():
    return " ".join(words) + " "


def list_then_join():
    parts = []
    for w in words:
        parts.append(w)
    return " ".join(parts) + " "


assert plus_equals() == join_words() == list_then_join()
results = {fn.__name__: min(timeit.repeat(fn, number=200, repeat=3)) for fn in (plus_equals, join_words, list_then_join)}
ranked = sorted(results, key=results.get)
print("fastest to slowest:", ranked)
print("join beats += by at least 2x:", results["plus_equals"] / results["join_words"] > 2)

fastest to slowest: ['join_words', 'list_then_join', 'plus_equals']
join beats += by at least 2x: True

cProfile on a small program with a hidden hot spot. The profile names it: nearly all the time is inside is_duplicate, which scans a list.

# profile_demo.py
import cProfile
import io
import pstats
import random


def is_duplicate(item, seen):
    return item in seen                 # O(n) scan: the hidden hot spot


def load(n):
    random.seed(1)
    return [random.randint(0, n) for _ in range(n)]


def count_unique(items):
    seen = []
    for item in items:
        if not is_duplicate(item, seen):
            seen.append(item)
    return len(seen)


profiler = cProfile.Profile()
profiler.enable()
unique = count_unique(load(6000))
profiler.disable()

stream = io.StringIO()
pstats.Stats(profiler, stream=stream).sort_stats("cumtime").print_stats(4)
lines = [ln for ln in stream.getvalue().splitlines() if "profile_demo" in ln]
print("unique:", unique)
for ln in lines:
    name = ln.split("(")[-1].rstrip(")")
    ncalls = ln.split()[0]
    print(f"{name:<14} ncalls={ncalls}")
hot = next(ln for ln in lines if "is_duplicate" in ln).split()
print("is_duplicate share of total time is large:", float(hot[3]) / float(lines[0].split()[3]) > 0.5)

unique: 3788
count_unique   ncalls=1
is_duplicate   ncalls=6000
load           ncalls=1
is_duplicate share of total time is large: True

The fix the profile pointed at, plus the two other cheap wins: a set for membership, work hoisted out of the loop, and lru_cache on a repeated pure computation. Each is measured against its slow version.

# fixes.py
import functools
import random
import timeit

random.seed(1)
items = [random.randint(0, 6000) for _ in range(6000)]


def unique_list():
    seen = []
    for item in items:
        if item not in seen:
            seen.append(item)
    return len(seen)


def unique_set():
    return len(set(items))


def hoist_slow(rows):
    return [row * len(str(sorted(items)[-1])) for row in rows]


def hoist_fast(rows):
    width = len(str(sorted(items)[-1]))          # computed once, not per row
    return [row * width for row in rows]


def slow_square(n):
    return sum(i * i for i in range(n))


cached_square = functools.lru_cache(maxsize=None)(slow_square)

assert unique_list() == unique_set()
t_list = timeit.timeit(unique_list, number=3)
t_set = timeit.timeit(unique_set, number=3)
print("set version at least 20x faster:", t_list / t_set > 20)

rows = list(range(300))
t_slow = timeit.timeit(lambda: hoist_slow(rows), number=3)
t_fast = timeit.timeit(lambda: hoist_fast(rows), number=3)
print("hoisting at least 10x faster:", t_slow / t_fast > 10)

t_first = timeit.timeit(lambda: cached_square(200_000), number=1)
t_again = timeit.timeit(lambda: cached_square(200_000), number=1)
print("cached call effectively free:", t_again < t_first / 100)

set version at least 20x faster: True
hoisting at least 10x faster: True
cached call effectively free: True

Built-ins over manual loops, and the one micro-optimization worth knowing for a hot inner loop. The gains are real but smaller; do these last, with a profile in hand.

# builtins_micro.py
import math
import timeit

numbers = list(range(200_000))


def manual_sum():
    total = 0
    for n in numbers:
        total += n
    return total


def builtin_sum():
    return sum(numbers)


def sqrt_attr():
    out = []
    for n in numbers[:50_000]:
        out.append(math.sqrt(n))
    return out


def sqrt_local():
    sqrt, append, out = math.sqrt, [].append, []
    append = out.append
    for n in numbers[:50_000]:
        append(sqrt(n))
    return out


assert manual_sum() == builtin_sum() and sqrt_attr() == sqrt_local()
print("sum() faster than a manual loop:", timeit.timeit(manual_sum, number=5) > timeit.timeit(builtin_sum, number=5))
print("local names faster than attribute lookups:", timeit.timeit(sqrt_attr, number=5) > timeit.timeit(sqrt_local, number=5))


def manual_double():
    out = []
    for n in numbers:
        out.append(n * 2)
    return out


print("comprehension faster than manual append:",
      timeit.timeit(lambda: [n * 2 for n in numbers], number=5) < timeit.timeit(manual_double, number=5))

sum() faster than a manual loop: True
local names faster than attribute lookups: True
comprehension faster than manual append: True

Try it yourself

Take the file organizer or the expense library from earlier and profile a run over a few thousand generated records with python -m cProfile -s cumtime. Identify the top three functions by cumulative time, pick the one you can improve, apply one change, and profile again, recording both timings in a comment. Then use timeit to compare two ways of writing one line from that code and keep whichever is clearer unless the faster one wins by more than 2x.

Common mistakes

• Optimizing without measuring. The slow part is rarely where you think; profile first, every time.
• Micro-optimizing a cold path. A 30% gain on a function that takes 1% of the time is nothing; sort by cumtime and start at the top.
• Sacrificing clarity for a small gain. Keep the readable version unless the measured improvement matters to a user, and document why the fast version exists.

What's next

• timeit measures snippets, cProfile measures programs; read cumtime to find the hot spot, then tottime for where the work is.
• The big wins are structural: the right data structure, work moved out of loops, caching, built-ins that loop in C.
• Fix one thing, re-measure, and stop at the target; a flat profile means the next step is a different algorithm or tool.

You can make code fast where it matters. Next you will look at where Python's time and memory actually go: the memory model, from names and objects to reference counting.