Python cProfile example: find slow functions and read pstats

Select a timestamp to watch that moment on YouTube.

1. 00:00

   A script feels slow. Which function is responsible? cProfile can collect call counts and timing for a representative run. We will use a tiny wrapper and inner function to learn the columns, then show how recursion changes call counts. The exact seconds on your computer will differ, so the exercise checks stable structural facts rather than comparing arbitrary millisecond values. Keep a specific workload question in mind before opening a profile report. A Python cProfile example should answer a concrete question: which functions consume time during a reproducible workload? cProfile is in the standard library.

2. 00:41

   Run `python -m cProfile -s cumulative script.py` from a local terminal to profile an entire script, or create cProfile.Profile() and call runcall for a specific function. The result records function calls and timings. This lesson uses tiny deterministic workloads for the browser exercise, so it checks the call-count structure rather than claiming a stable millisecond benchmark. A profiler is useful when you can name a workload whose speed matters. Choose a representative input and run the same operation under cProfile. From a terminal, `python -m cProfile -s cumulative script.py` prints a sorted whole-script report.

3. 01:23

   Inside Python, Profile.runcall focuses on one function. Tiny examples are good for learning the API, but their timing columns cannot justify a production optimization. The first profile sorts by total self time. That can be useful, but if our question is which high-level path dominates, a wrapper may look deceptively cheap because most work is in its subcall. This is a diagnostic choice, not an exception. Read the column label before deciding what the numbers mean. A top row sorted by one metric does not automatically identify the algorithm to change. We need to compare inclusive and exclusive time.

4. 02:05

   In a profile report, `ncalls` counts all calls and may show a total/primitive form for recursion. `tottime` excludes time in subcalls, while `cumtime` includes them. Sorting by cumulative time helps find higher-level functions that dominate a program. Sorting by total time highlights work done inside a function itself. The top row is not automatically the root cause; inspect what that function calls and whether the workload represents the real application. A profile is measurement evidence, not a replacement for a clear performance question. This guide starts with one function and verifies that it appears in pstats.

5. 02:46

   We avoid asserting a number of milliseconds because operating system scheduling and runtime state change measurements. The exercise still uses the real cProfile module, so the structure of the report is authentic. For your own program, profile a workload large enough that repeated runs reveal a stable pattern. The diagnosis profiles a recursive countdown and prints the primitive and total call counts. One top-level invocation triggers four calls: values three, two, one, and zero. A report may display a total/primitive form for such a function. This is a stable fact that a task checker can verify.

6. 03:27

   It does not say anything useful about speed because four tiny calls are too fast to benchmark reliably. Understanding call structure helps interpret the larger timing report later. The programmatic API uses `profile.runcall(function, argument)` and `pstats.Stats(profile).sort_stats(SortKey.CUMULATIVE).print_stats(10)`. For stable tests, the code accesses the `stats` mapping and reads its call counters. In a real investigation, print the human- readable report and compare a representative input before and after a change. Avoid profiling only one tiny input and extrapolating to a million rows: algorithm

7. 04:08

   growth can be more important than one measured duration. The report's `tottime` is time spent in a function excluding its subcalls. `cumtime` includes subcalls and is often useful for locating high-level slow paths. `ncalls` counts invocations; a recursive function can show total and primitive counts. Use `sort_stats(SortKey.CUMULATIVE)` to order by inclusive cost, and compare with `SortKey.TIME` when you need to locate self time. Now sort by SortKey.CUMULATIVE. This includes time spent in subcalls, so the wrapper row can reflect the work it initiated. Compare with tottime, which excludes callees.

8. 04:50

   For a real script, run python -m cProfile -s cumulative your_script.py in a local terminal or write the report to a profile file for pstats. Profile a workload that resembles actual use; tiny synthetic input can conceal a costly growth pattern. The practical task counts calls to a named function, including recursive calls, without asserting any elapsed time. The sample recursive function is run once at the outer level but appears multiple times in `ncalls`. The final examples compare a direct call and recursion, then show how to sort a report. When you are ready to profile your own script, run it locally with realistic data

9. 05:32

   and keep the profile separate from a timeit microbenchmark. For an end-to-end workflow, first locate the slow path, then write a correctness test, change one implementation detail, and profile again under the same conditions. The pstats stats mapping is also available programmatically, but the human-readable report is easier to inspect during a performance investigation. Here we read the second tuple element to test total calls deterministically. A high call count does not prove a problem: a cheap function may be called many times, while a single expensive call may dominate time. Interpret the columns together.

10. 06:13

    The final run implements a count_calls helper and confirms four recursive invocations. On your own program, after locating a slow path, write a correctness test before changing it and profile both versions with the same input. If one function appears frequently but takes almost no time, it may not be the best target. If a wrapper has high cumulative time but low self time, inspect its callees. Pair these observations with algorithm reasoning rather than treating one profile snapshot as universal truth. Recursion demonstrates why a single top- level call can appear many times in the report.

11. 06:53

    A countdown from three invokes the same function at three, two, one, and zero: four total calls. Counting those calls provides a stable task assertion. The actual elapsed time for four calls is too small and variable to teach a reliable optimization conclusion. After locating a suspicious path in your own program, preserve correctness tests before changing the implementation. Re-profile with the same input and compare the same columns. If input size changes, a difference may come from workload rather than code. Pair a profile with algorithm reasoning and a benchmark only when you have a specific hypothesis about why one path is slow.