CPU Profiling Python Services

A profile answers one question precisely: while the process was executing, what was it executing. That is enormously useful when the process is busy and actively misleading when it is not, which is why the first step of every profiling session is confirming that CPU is the constraint at all. This guide covers attaching a profiler to a live service, choosing the sampling parameters, reading the output, and recognising the cases where the answer lies elsewhere. It is part of the Python profiling and performance observability section. The focused articles in this topic are Profiling a Live Python Process with py-spy, Reading Flame Graphs for Python Services and Using cProfile and pstats in Production.

Prerequisites

pip install "py-spy>=0.3.14,<0.5.0" \
            "yappi>=1.6.0,<2.0.0"

The attaching profiler needs permission to read another process's memory, which in a container usually means running it in the same process namespace with the appropriate capability.

# in Kubernetes, an ephemeral debug container sharing the target's namespace
kubectl debug -it checkout-7d9f8c5b6-xk2lm --image=python:3.12-slim \
  --target=app --profile=general

Concept and architecture

An attaching sampling profiler works by reading the target process's memory directly. It locates the interpreter's thread state structures, walks the frame chain for each thread, resolves the code objects to file names and function names, and writes the resulting stack. It does this on a timer, and the target is briefly paused for each read — microseconds, at a rate that makes the total overhead one or two percent.

Three consequences follow from that mechanism, and each shapes how the tool is used.

No code change and no restart. The target does not know it is being profiled. This is the property that matters most operationally, because the instance you want to measure is the one currently misbehaving, and restarting it to add instrumentation destroys the state you were trying to observe.

It sees every thread. The profiler walks all thread states, so a thread pool's workers, the batch span processor's export thread and the garbage collector's activity all appear. This is useful and it means the output needs filtering, because a thread that is idle in a select call contributes samples that are technically accurate and rarely interesting.

It cannot see application context. The profiler knows about frames, not about requests. A profile therefore describes the process as a whole, and attributing cost to an endpoint requires either that the endpoint's handler appears as a distinct frame — which it usually does — or that the profiler records the active span, which is the subject of linking profiles to traces with span context.

The alternative mechanism, deterministic profiling, hooks the interpreter's call and return events. It produces exact call counts, which sampling cannot, and its cost scales with call volume, which in a framework-heavy Python service is enormous. The two are complements: sampling for "where does the time go in production", deterministic for "how many times is this actually called" in a reproduction.

Step-by-step implementation

Step 1 — Establish that CPU is the constraint. Thirty seconds with a process-level metric answers this and prevents the most common wasted afternoon. A process pinned near its limit is worth profiling; one sitting at fifteen percent while requests are slow is waiting for something, and the profile will say so uninformatively.

# is the process busy at all?
kubectl top pod checkout-7d9f8c5b6-xk2lm --containers

Step 2 — Attach and record. A dump gives an instantaneous picture, useful for a process that appears stuck. A recording over a window gives the aggregate, which is what you want for a slow rather than stuck service.

# an immediate snapshot of every thread — for a process that looks hung
py-spy dump --pid 1

# a 60-second recording, producing a flame graph
py-spy record --pid 1 --duration 60 --rate 100 --output profile.svg

Step 3 — Take the wall-clock version as well. By default the recording counts only samples where the thread was on the CPU. Including idle threads changes what the profile describes from "where cycles went" to "where wall-clock time went", and the difference between the two is the amount of blocking.

# includes threads that are blocked, not just those executing
py-spy record --pid 1 --duration 60 --idle --output wallclock.svg

Step 4 — Read by width from the bottom up. The widest frame whose implementation you control is the one to act on. Frames below it are callers, usually framework code; frames above it are callees, usually the standard library. Depth carries no cost information at all.

Step 5 — Compare against a baseline. A frame that is eight percent of CPU means nothing in isolation. The same frame at three percent last month and eight percent now means a change landed, and that comparison is the single most useful thing a stored profile provides.

# keep a monthly baseline alongside the release it belongs to
py-spy record --pid 1 --duration 60 --format speedscope \
  --output "baselines/checkout-$(date +%Y%m)-$(cat /etc/release).json"

Configuration reference

Async and concurrency considerations

An asyncio service profiles differently from a threaded one, and the difference is not cosmetic.

Under threads, each worker has its own stack, so a profile shows the call chains naturally and the interpreter lock's effect appears as threads waiting to acquire rather than executing. Under asyncio there is one thread running an event loop, so every coroutine's frames appear under the loop's own frames, and the resulting flame graph is dominated by the loop machinery with the application's work fragmented beneath it. Reading it requires collapsing those frames, which most viewers can do, and knowing that the loop's own frames are not the cost.

The more important point is that a blocked event loop does not appear in an on-CPU profile at all. A coroutine performing a synchronous database call stops the entire loop, and the profile shows a process doing almost nothing — which is true and is the opposite of the conclusion most people draw. The wall-clock profile shows the blocking call occupying the loop thread, and pairing it with event loop lag turns a suspicion into a measurement. This is developed in diagnosing blocked event loops in production.

Under a prefork server, each worker is a separate process. A profile of the master process shows almost nothing, because the master accepts connections and supervises. Profiling means attaching to a worker, or following subprocesses, and the choice of which worker matters if load is unevenly distributed.

Production code examples

A wrapper that captures a profile automatically when a service's latency crosses a threshold, so the measurement happens while the problem is live:

# autoprofile.py — capture a profile when things are actually bad.
import os
import subprocess
import threading
import time

THRESHOLD_MS = float(os.environ.get("AUTOPROFILE_P99_MS", "800"))
COOLDOWN_S = 900
_last_capture = 0.0
_lock = threading.Lock()


def maybe_profile(current_p99_ms: float) -> None:
    """Called from the metrics scrape path; cheap when nothing is wrong."""
    global _last_capture
    if current_p99_ms < THRESHOLD_MS:
        return
    with _lock:
        if time.time() - _last_capture < COOLDOWN_S:
            return                       # 1. never profile in a tight loop
        _last_capture = time.time()

    out = f"/tmp/profiles/{int(time.time())}-p99-{int(current_p99_ms)}.json"
    # 2. Detached, so a slow profiler never delays the caller.
    subprocess.Popen([
        "py-spy", "record", "--pid", str(os.getpid()),
        "--duration", "30", "--rate", "100",
        "--format", "speedscope", "--output", out,
    ], start_new_session=True)

Expected Output: a profile file written during the incident rather than after it.

/tmp/profiles/1789012431-p99-1180.json
py-spy> Sampling process 100 times a second for 30 seconds
py-spy> Wrote speedscope file to '/tmp/profiles/1789012431-p99-1180.json'

A comparison between two stored profiles, which is how a regression is actually identified:

# compare.py — which frames grew between two folded-stack profiles?
import collections, sys

def load(path):
    counts = collections.Counter()
    for line in open(path):
        stack, _, count = line.rpartition(" ")
        counts[stack.split(";")[-1]] += int(count)
    return counts

old, new = load(sys.argv[1]), load(sys.argv[2])
old_total, new_total = sum(old.values()), sum(new.values())

rows = []
for frame in set(old) | set(new):
    before = old[frame] / old_total
    after = new[frame] / new_total
    rows.append((after - before, frame, before, after))

for delta, frame, before, after in sorted(rows, reverse=True)[:5]:
    print(f"{delta:+7.2%}  {before:6.2%} -> {after:6.2%}  {frame}")

Expected Output: one frame accounting for the regression, which is the usual shape.

 +5.10%   2.94% -> 8.04%  dateutil.py:parse
 +0.41%   1.02% -> 1.43%  serializers.py:to_representation
 -0.22%   3.11% -> 2.89%  psycopg.py:execute

Sampling versus deterministic, in practice

The two mechanisms answer different questions, and choosing between them is easier when the question is stated precisely.

Sampling answers "where does the time go". It gives a proportional picture of execution, accurate in aggregate, with a cost that does not depend on the program's behaviour. It cannot tell you how many times a function was called, because it never observes calls — only the fact that a function was executing at particular instants. A function called four thousand times when it should have been called four is invisible to it, unless the aggregate time happens to be large.

Deterministic profiling answers "what is called, and how often". It hooks the interpreter's call and return events and records every one. That makes call counts exact, which is precisely what identifies the four-thousand-calls problem, and it makes the cost proportional to the number of calls. In a Python service using an ORM and a web framework, a single request makes tens of thousands of calls, so the profiler's overhead is measured in multiples rather than percentages.

The practical arrangement is to use sampling in production to find where the time is, and deterministic profiling in a test or a reproduction to understand why. A frame that a production profile shows as unexpectedly wide is a candidate for a deterministic run against the same code path locally, where the call counts usually explain it immediately.

There is a middle option worth knowing about. yappi can run in a sampling mode and, unlike most profilers, understands threads and coroutines natively — it can attribute time per thread and per asyncio task rather than merging everything into the loop's stack. Where the question is "which coroutine is consuming the loop", that attribution is worth the in-process instrumentation it requires.

Turning a profile into a change

A profile identifies where time goes. Deciding what to do about it is a separate step, and four outcomes are far more common than "optimise this function".

The frame is in a library you cannot change. Common, and the actionable question is not the frame but the call volume reaching it. A wide frame in a date parsing library is usually a call site parsing the same value repeatedly, or parsing in a loop where the result could be hoisted. Read the frame below it.

The work should not happen at all. Serialising fields nobody reads, validating data that was already validated, re-computing a value that could be cached for the duration of a request. This is the most common real finding, and it is a design change rather than an optimisation.

The work should happen elsewhere. A CPU-bound operation on the event loop or inside a request handler that could be deferred to a worker. The profile shows the cost; the fix is architectural, and moving it changes latency without changing total CPU.

The profile is telling you about a dependency. A wide frame inside a database driver's result processing usually means too much data is being fetched, not that the driver is slow. The remedy is upstream in the query, and confirming it means looking at slow SQL queries in traces rather than at the profile.

The remaining case — a function of yours doing necessary work inefficiently — is real and is a minority of findings. Approaching every profile expecting that case is why so many profiling sessions end with a micro-optimisation that improves nothing measurable.

Getting permission to profile in production

The technical work above is straightforward; the obstacle in most organisations is access. A profiler needs to read another process's memory, which requires a capability most container runtimes drop by default, and the request to enable it tends to surface in the middle of an incident when nobody wants to discuss security posture.

Three things make it a solved problem rather than a recurring negotiation.

A debug container profile agreed in advance. Most platforms support attaching an ephemeral container to a running pod with an elevated profile. Agreeing which image, which capability and who may invoke it — before it is needed — turns a live argument into a command. The capability involved permits reading the memory of processes in the same namespace, which is a genuine privilege and a narrow one, and it is much easier to reason about when nobody is under pressure.

A profiling sidecar for the services that need it most. Where a service is profiled often enough that the ephemeral route is tedious, a sidecar with the capability and a small HTTP trigger removes the friction entirely. It costs a container and gives on-call a button rather than a procedure.

Continuous profiling, which removes the question. If profiles are collected constantly and stored, nobody needs to attach anything during an incident: the profile for the relevant minute already exists. This is the strongest argument for the approach in running continuous profiling for Python services, and it is an operational argument rather than a technical one — the data is the same, and the difference is whether obtaining it requires a decision at three in the morning.

The failure mode worth naming is the one where profiling is theoretically possible and practically never done, because each attempt requires a ticket. In that situation performance problems are diagnosed by guesswork, and the guesses are wrong in the direction of whatever the team last optimised.

Common mistakes

Profiling a process that is waiting. Error signature: a nearly empty flame graph and a conclusion that the profiler is broken. Root cause: the service is blocked, not busy. Remediation: check CPU utilisation first; use a wall-clock profile when it is low.

Profiling during startup. Error signature: a profile dominated by imports and module initialisation. Root cause: the first seconds of a Python process are not representative of anything. Remediation: profile a warm process under load.

Reading depth as cost. Error signature: an optimisation aimed at a deep call chain that changes nothing. Root cause: the vertical axis of a flame graph is call nesting. Remediation: rank by width, from the bottom.

Attaching to the master under a prefork server. Error signature: a profile showing only accept loops and supervision. Root cause: the work happens in worker processes. Remediation: attach to a worker, or follow subprocesses.

Profiling only when something is wrong. Error signature: a profile that cannot be interpreted because nobody knows what normal looks like. Root cause: no baseline captured while the service was healthy. Remediation: record one profile a month alongside its release, which costs a minute and makes every future profile a comparison.

Acting on a single profile. Error signature: an optimisation that does not improve the metric it was aimed at. Root cause: a thirty-second window that happened to be unrepresentative. Remediation: take two profiles at different times and act on what they agree about.

Frequently Asked Questions