29Performance & profiling — measure before you cut

In Chapter 28 we made the program correct — the tests went green and the numbers came out right. This chapter makes it fast. I want to go slow here, because there's a trap that catches almost everyone. Your intuition about where a program spends its time is not a little off. It is reliably wrong, and it's wrong for a reason you can name. The source text tells you what your code does. It says nothing about what any of it costs. a + b can be one machine ADD or a heap allocation, and x in seen can be one probe or a million compares. The letters look identical. So here's the plan. First we prove your gut is a liar. Then we install real instruments between your mental model and the machine: timeit to time one snippet honestly, and cProfile to watch the whole program run and hand back a ranked list of suspects. Then we learn to read what they say. The whole way through, we keep asking the one thing that matters — where is the time truly going, and how would you ever know without measuring? By the end you'll carry a discipline you can run on any slow program: measure first, fix only the one thing the measurement flagged, then measure again. There's no magic in performance work. It's just the machine doing what it does, once you stop guessing and actually look.

01Measure first — your intuition is wrong

Let's start with the mistake every one of us makes, because you have to feel it before the fix means anything. You closed Chapter 28 with a program that works — the numbers are right, the tests are green — but it is slow. So you do what everyone does. You read the code, your pulse rises at a particular line, and a voice says there: that triple-nested loop is the murderer. You spend an afternoon rewriting it into something clever. You run the program, and the stopwatch reads exactly what it read before. Not a little better. Identical. That loop was two percent of the runtime. The real cost was a config file being re-read and re-parsed on every iteration — a line so plain your eye slid right over it. You optimised the innocent and left the guilty untouched. And you paid for it with new complexity and a fresh chance at a bug.

So what you actually need is not a technique. It is a way to stop guessing. To earn that, you have to see why guessing fails so consistently. It does not fail at random. It fails systematically, and a systematic error is one you can correct for. Here is the root cause, from the metal up. A CPU issues billions of instructions per second, and the cost of an operation is nowhere in its written form. Watch two lines that read as perfect equals:

# Two lines. They look equally cheap. They are not.
total = a + b                 # small ints: one C-level ADD, a few nanoseconds
found = key in seen        # seen is a list of 1,000,000: up to a million compares

Nothing in the second line looks expensive. There is no loop in the source. The loop is inside the in operator, hidden in C, invisible to your eye. This is the pattern behind every performance surprise: the real time-eaters are the operations with no syntactic weight. A helper called ten million times. An accidental O(n²) crouched behind x in some_list. A generator that quietly re-does its work each pass. An I/O wait where the core sits idle for milliseconds while a disk or a socket answers. None of these announce themselves in the text. Thinking hard about the text cannot find them, because thinking hard cannot see call counts or wait states.

There is a second reason reading fails, and it is subtler: cost is non-local. The line that looks expensive is usually not where the time is spent. The time is spent inside the functions that line calls, three and four levels down. total = summarize(data) is one short line. If summarize calls normalize which calls a square-root-heavy routine n² times, the cost lives at the bottom of a call chain you cannot see from the top. You could stare at summarize(data) for an hour and learn nothing.

So we stop reasoning about the schematic and start measuring the running circuit. A profiler is an instrument, exactly like a multimeter clipped onto a live board. It does not argue about what should happen; it reports what does. This reframes the whole activity. The profile is ground truth. Your opinion about the slow part is a hypothesis — legitimate, but worthless until a measurement confirms it. And the shape of all performance work is one loop: measure → find the hot path → fix only the hot path → measure again. Everything else in this chapter is filling in that loop with real tools.

One last piece of vocabulary, because it splits every performance problem cleanly in two. Latency is the time for one operation; throughput is operations per second. They are not reciprocals once work runs in parallel, so name which one you care about. More important is the split between wall-clock time and CPU time. Wall-clock time is what the user actually feels — a real clock on the wall, which includes I/O and every other program on the machine. CPU time is the cycles your code truly burned. When those two numbers agree, your program is CPU-bound: it is computing, and to go faster it must compute less. When wall-clock time towers over CPU time, your program is waiting — for a disk, a network, a lock — and no amount of cleverer arithmetic will help. The fix for each is completely different, and telling them apart is the first diagnosis you will make on any slow program.

You know now to measure instead of guess. But your first attempt to measure — wrapping two snippets in a stopwatch — is about to betray you, because a single timing is almost pure noise. Next: how timeit subtracts the machine's chaos and hands you the one number that is really your code's. →

02timeit controls the noise

You have two ways to write the same function and you want to know which is faster. Reasonable. So you reach for the obvious tool: wrap each in a clock and diff the times.

import time
t0 = time.time(); build_a(); print(time.time() - t0)   # 0.0181
t0 = time.time(); build_b(); print(time.time() - t0)   # 0.0092  → B wins!

A wins. You run it again, and B wins. Again, and A wins by three times. The numbers are garbage, and you are one Enter away from making a permanent code decision on a coin flip. What you need is honest comparison: a way to tell which implementation is truly better that survives the fact that your machine is doing a thousand other things while it measures.

To fix this you have to see, from the metal up, why a single timing is meaningless. Your snippet does not run alone. The OS scheduler can preempt your process mid-measurement: another program grabs the core, your clock keeps ticking, and you are charged for someone else's work. The CPU also changes its own clock frequency under you — turbo boost when it is cool, thermal throttling when it is hot — so the same instructions take different real time minute to minute. The first run has cold caches and untrained branch predictors; the second is warm and faster for reasons that have nothing to do with your code. And Python's own garbage collector can fire in the middle of your snippet and bill its pause to you. Then one more problem on top: a fast snippet may finish in nanoseconds, far below the resolution of a naive clock, so a single call measures the clock's own graininess, not your code.

Now look at exactly what timeit does about each of these, because every design choice answers one of the problems above. First, it runs the snippet a chosen number of times in a tight compiled loop and divides. So nanosecond operations are multiplied up into a span the clock can actually resolve, and the per-call overhead is amortised away. Second, it uses time.perf_counter, the highest-resolution monotonic clock available: it never runs backward and is immune to the wall clock being nudged by NTP mid-measurement. Third — and this is the part people miss — it disables the garbage collector for the duration, so a gc pause cannot pollute the number. Fourth, it repeats the whole trial several times (repeat) and hands you a list, and you report the minimum, never the mean.

import timeit

# setup runs ONCE per trial and is NOT timed — build the input here
setup = "data = list(range(10_000))"

loop  = # the thing we actually want to measure
loop  = "total = []\nfor x in data: total.append(x*x)"
comp  = "total = [x*x for x in data]"

best_loop = min(timeit.repeat(loop, setup, number=1000, repeat=5))
best_comp = min(timeit.repeat(comp, setup, number=1000, repeat=5))
print(best_loop, best_comp)   # comprehension wins, and it wins every run

Two details in that code are the whole craft. The setup / stmt split is not decoration. setup runs once per trial and is not timed, so you build your input there and measure only the operation. Fold the input construction into the timed statement and you are secretly timing list(range(...)) too — the same operation, but a different and dishonest verdict. Beware the compiler as well: timeit('2 ** 20') reports a time near zero because 2 ** 20 is a constant expression folded at compile time into the literal 1048576. You measured nothing. To force real work, the operand must be unknown to the compiler: pull x from setup and time x ** 20.

timeit tells you which of two snippets is faster — but not which snippet to test. In a five-thousand-line program you have no idea where to point it. Next: an instrument that watches the whole program run and hands you a ranked list of suspects. →

03A profiler attributes time to functions

timeit is a scalpel, and a scalpel is useless until you know where to cut. In a real program — thousands of lines, hundreds of functions — the question is not "which of these two is faster" but "which of these hundred is the problem." You need triage: something that watches the entire program run and returns a ranked list. Here are your functions, here is how many times each was called, here is how much time each ate. That instrument is a profiler, and CPython ships one built from a mechanism you already met in Chapter 25.

Recall the trace hook. CPython lets you register a callback that the interpreter invokes as your program runs. There are two flavours. The trace hook fires on every line. The profile hook, installed via sys.setprofile, fires only on function call and return events — far fewer events, far less overhead. cProfile installs such a hook written in C (the _lsprof module), so the per-event cost is small. The logic is simple and worth holding in your head. On a call event it pushes a frame record onto a stack and stamps a timer. On the matching return it stamps the timer again and folds the elapsed span into that function's running ledger. Do that for every call in the program and you have, per function, three numbers that answer everything.

import cProfile, pstats

cProfile.run("main()", "out.prof")          # or: python -m cProfile -s cumtime prog.py
stats = pstats.Stats("out.prof")
stats.sort_stats("cumulative").print_stats(10)  # top 10 by inclusive time

The three numbers are these. ncalls — how many times the function was entered. tottime — time spent inside the function itself, excluding everything it called ("self time"). And cumtime — total time from entry to return, including every callee ("inclusive time"). The distinction between the last two is not a detail. It is the entire skill of profile-reading, so hold it hard. A function with huge cumtime but tiny tottime is a conductor: it barely works itself, it just calls other expensive things, so chase its children. A function with tottime ≈ cumtime is a hot leaf: this is where cycles actually burn, and this is where you fix. Read the table sorted by cumtime to find the expensive subtree, then re-sort by tottime to find the leaf that is truly hot inside it.

Now the honest caveats, because an instrument that lies to you is worse than none. First, cProfile perturbs what it measures — the observer effect. Its hook samples a clock on every call, so for a trivial function called ten million times the hook's own overhead swamps its real cost. The profiler will over-blame tiny hot functions. This is why there are two families. Deterministic profilers like cProfile see every call exactly, but they slow the program roughly 2–5× and mis-charge micro-functions. Sampling profilers like py-spy take the opposite bet: they interrupt the program at a fixed frequency — say a thousand times a second — and record where it "usually is," attributing time statistically with near-zero overhead and no per-call distortion. For a tight CPU loop of tiny calls, reach for a sampler. For understanding call structure, reach for cProfile.

The second caveat is the one that catches everyone, and it ties straight back to Section 1. cProfile measures the Python call structure: it fires on calls and returns. It does not fire while your program sits inside a socket read or a disk wait, because no Python function is being called during that wait. So an I/O-bound program produces a profile that blames almost nothing. Every function looks cheap, the totals are tiny, and yet the program took three real seconds. An empty profile is itself the diagnosis. It means your time went to waiting, not computing, and you should be reading wall-clock time, not a call profiler. The instrument that finds nothing has told you exactly where to look.

The profiler has named your hot function. Now the amateur and the professional part ways. The amateur shaves the inner loop; the professional asks a deeper question — is this slow because each step is expensive, or because there are too many steps? The answer decides everything. →

04Algorithmic beats constant-factor

The profiler flagged your hot function and you did the obvious thing. You rewrote its inner loop to be cleverer, hoisted a method into a local variable, unrolled it a little. You got fifteen percent. You felt good. Then the input doubled — a normal Tuesday for real data — and the function was slower than when you started. Something you did not touch scaled against you and ate your fifteen percent alive. What you need now is to understand why some optimisations evaporate the instant the data grows while others compound. And how to tell which kind of situation you are in before you spend a day fixing the wrong thing.

Here is the idea the entire chapter has been walking toward. A running time is, roughly, c × f(n). The constant factor c is how expensive each unit of work is — the thing micro-optimisation shrinks. The growth function f(n) is how the number of units scales with the input size, and that is set entirely by your algorithm. Micro-optimising changes c: it slides the whole curve down uniformly, but it never changes the curve's shape. Choosing a better algorithm changes f(n) itself: it bends the curve. Slide versus bend. That is the difference between a junior's afternoon and a senior's five-minute rewrite, and at scale it is not close.

# O(n²): 'in' on a list scans element by element, every time
def has_dup_list(items):
    seen = []
    for x in items:
        if x in seen: return True   # up to n compares, done n times → n²
        seen.append(x)
    return False

# O(n): a set membership test is one hash-and-probe (from the hash-table mechanism)
def has_dup_set(items):
    seen = set()
    for x in items:
        if x in seen: return True   # one probe, done n times → n
        seen.add(x)
    return False

The two functions differ by one word — [] became set() — and that word changes f(n) from n² to n, because a list must scan while a set does a single hash-and-probe. At n = 100 nobody notices. At n = 1,000,000 it is the difference between instant and never, and the arithmetic makes it visceral. O(n²) at a million is 10¹² operations. Even at a billion operations per second, that is about a thousand seconds, or seventeen minutes. O(n) is a million operations, about a millisecond. No constant factor in the universe closes that gap. Make the quadratic inner loop a hundred times faster and you move a thousand seconds to ten seconds, while the linear version still sits at a millisecond. You cannot micro-optimise your way across a change in curve. That is the punchline of the whole chapter.

So stock your head with the curves you will actually meet, in order of how they scale. O(1) — hash lookup, dict access, the dream. O(log n) — binary search, a balanced tree, where doubling n adds one step. O(n) — a single scan. O(n log n) — a good sort, the ceiling for comparison sorting. O(n²) — the nested scan, the all-pairs comparison, the accidental disaster. And O(2ⁿ) — naive recursion over subsets, the fib-without-memoisation explosion that dies at n = 40. Almost every real optimisation is one of a small handful of moves that step you down this ladder. Replace a scan with a hash lookup. Replace all-pairs with sort-then-scan. Replace recomputation with memoisation of overlapping subproblems. And above all, pick the data structure whose cheap operation is the one you do most — a set for membership, a dict for lookup, a heap for "smallest so far," a deque for both ends. The right structure is not a tidiness choice. It is the choice of which curve you live on.

You picked the optimal algorithm and the Big-O is as good as it gets — and two programs with the same O(n) still differ by tenfold. The algorithm cannot explain that gap. The layer below it can: where your data lives in memory, and how the CPU waits for it. →

05Memory, allocation, and the cache

You did everything right. The algorithm is optimal, the Big-O is O(n), there is no wasted work in the operation count — and one program is ten times faster than the other. The fast one stores its numbers in a packed array of raw floats; the slow one stores them in an ordinary Python list. Same n, same arithmetic, same complexity class. The algorithm cannot explain a tenfold gap, because the gap does not live in the algorithm. It lives one layer down, in the physics the algorithm sits on. The CPU spends most of its life not computing but waiting for memory, and where your data lives decides how long it waits.

Start with the hardware truth, because it is stark. Reading a value already in a CPU register costs about one cycle. From L1 cache, ~4 cycles. L2, ~12. L3, ~40. From main RAM, ~200+ cycles. A cache miss can cost fifty to a hundred times a hit. The CPU fights this with two tricks you must design around. First, it never fetches one byte; it fetches a cache line of 64 bytes at once, so if the next value you need is right beside the last, it is already there, free. Second, it prefetches: when it sees you walking memory sequentially, it fetches ahead of you. The consequence is enormous. Contiguous, sequential access is vastly faster than chasing pointers to scattered addresses, even for the identical number of elements.

Now the Python-specific reality, and this is where the volume's thread comes home. A Python list of integers is not a block of integers. It is a contiguous array of pointers, and each pointer aims at a separate, heap-allocated PyObject — a little box holding a refcount, a type pointer, and the actual value — that can live anywhere in memory. Iterating the list means pointer-chasing: read a pointer, jump to a random address, almost certainly miss the cache, unbox the object, repeat. Contrast an array.array('d', ...) or a NumPy array, which stores raw C doubles packed end to end. One 64-byte cache line delivers eight of them at once, the prefetcher sees the straight-line pattern and runs ahead, and every value is already unboxed. Same eight numbers, but eight misses versus one fetch.

import array, timeit

py_list = list(range(1_000_000))          # array of pointers → scattered PyObjects
packed  = array.array('q', range(1_000_000)) # contiguous raw 64-bit ints

# identical operation, identical O(n) — only the memory layout differs
print(min(timeit.repeat(lambda: sum(py_list), number=100)))
print(min(timeit.repeat(lambda: sum(packed),  number=100)))  # faster — the prefetcher can see it coming

There is a second cost centre hiding in Python's object model: allocation and refcount churn. Every time Python creates an object it calls the allocator — pymalloc hands out small blocks from pre-carved pools and arenas — and every assignment or function argument bumps a refcount up, then later down. Py_INCREF and Py_DECREF are not free bookkeeping. They are real memory writes, and writing to a shared object's refcount even invalidates that cache line across every core that holds it. A loop that creates a million short-lived temporary objects pays allocation, then refcount traffic, then deallocation for each one — that is churn — even though it computes nothing extra. This is why s += piece in a loop is a quiet O(n²) allocation disaster (a new string object every pass), while collecting pieces into a list and calling ''.join(pieces) once allocates the result a single time.

Hence the concrete levers, each one a move against a real cost you can now name. Prefer contiguous homogeneous storage for large numeric data. Reuse buffers instead of reallocating. Use generators to stream instead of materialising a huge intermediate list all at once. And add __slots__ to a class you make millions of, which drops the per-instance __dict__ for smaller objects, tighter packing, and less allocation. Now tie it back to measurement, because this is the sting: these effects are invisible in the source and largely invisible to cProfile's function-level view. The profiler points at a loop that is "slow for no reason," and the reason is the memory beneath it. The tools that confirm it are timeit comparisons and memory instruments — tracemalloc, sys.getsizeof — not the call profiler.

You can now find the hot path, choose the right curve, and lay the data out for the cache. One question remains — the one that decides whether any of it is worth doing. You made a function 4× faster and the program barely moved. Amdahl's Law explains exactly why, and turns your profile into a budget. →

06Optimize the hot path, then remeasure

You found the hot function, you fixed it, it is now four times faster — and the whole program got six percent faster. It feels like a swindle. Meanwhile a colleague spent the same afternoon and got 3× on the total. Same effort, wildly different payoff. The difference was not skill; it was which part they chose to fix. What you need now is to know, before you spend the day, whether an optimisation is worth doing at all. And to accept that performance work is never one-and-done, because the moment you fix the top of the list a different function becomes the new bottleneck.

The law that governs all of this is Amdahl's Law, and it is simple enough to keep in your head. Say a portion p of the total runtime is the part you speed up, and you make that part s times faster. The overall speedup is then:

def speedup(p, s):
    # p = fraction of runtime you optimized; s = how many times faster you made it
    return 1 / ((1 - p) + p / s)

print(speedup(0.08, 4))    # 1.06  → your 4x fix on an 8% slice: +6% total
print(speedup(0.70, 2))    # 1.54  → a mere 2x on the 70% slice beats it easily
print(speedup(0.05, 10_000)) # 1.052 → infinite speed on a 5% slice caps at ~5%

Three consequences fall straight out, and together they are the lesson. First, the ceiling. Let s → ∞, meaning you make the optimised part infinitely fast, and the best you can ever reach is 1 / (1 − p). A function that is 5% of runtime caps your total improvement at about 5.3%, no matter how brilliant the rewrite. Optimising cold code is money left on the table, and optimising the 5% part is nearly pointless even done perfectly. Second, it explains your swindle exactly: with p = 0.08 and s = 4, the total speedup is 1 / (0.92 + 0.02) ≈ 1.06. The fix worked. The part was just too small to matter. Third — and this is what turns theory into a tool — it tells you where to spend effort before you spend it. A modest 2× on the function that is 70% of runtime crushes a heroic 100× on the 3% function. Read this way, the profile is not just a list of suspects. It is a budget: each row's cumtime is the maximum payoff any fix to it can ever return.

Now the part people skip, and it is why performance work is a loop and not a task: the bottleneck moves. Say function A was 70% and you cut it in half. It is now a much smaller slice, and function B, which was a quiet 15%, is suddenly the tallest bar in a completely reshaped profile. Your first-round intuition is now worthless, because it was built against a distribution that no longer exists. This is why re-measure is mandatory, not optional: after every fix you must re-profile against the new reality, because the target physically relocated. Measure → find the hot path → fix only the hot path → measure again → repeat until the remaining wins cannot beat their cost.

And that closes both the chapter and the volume. Correctness first — the whole of Volumes 1 and 2. Then measure. Then fix the one thing the measurement flagged. Then measure again. Not the guesser's leap — the engineer's loop. →