Skip to content

Profiling asyncio Applications with py-spy

The loop-lag histogram says the service stalled for 400 ms twice a minute, debug mode is off in production, and nobody wants to redeploy with instrumentation just to find out why. Worse, when someone does run cProfile locally, the output is a wall of _run_once and select entries that says the program spent its time "in asyncio". The tool for this situation is a sampling profiler that attaches to a running process from the outside: py-spy reads the interpreter's memory to capture stacks without modifying or pausing the target for more than microseconds. This guide covers attaching it safely in containers, grabbing a stack dump from a stuck loop, recording a flame graph under real traffic, reading the asyncio frames correctly, and attributing time to individual coroutines.

Prerequisites

  • Python 3.11+ target process on Linux (macOS works with sudo; Windows works for dump and record).
  • py-spy installed on the host or in a debug sidecar: pip install py-spy. It does not need to be installed in the target's virtual environment.
  • Permission to ptrace the target process — covered in step 1.
  • Loop instrumentation basics from Event Loop Debugging & Instrumentation, ideally with event loop lag already measured in production so you know when the stalls happen.

Everything below profiles one process from the outside; nothing requires a code change or a restart of the service.

Which py-spy command for which symptom A decision on What is the loop doing with 3 outcomes. Which py-spy command for which symptom What is the loop doing? hung right now py-spy dump one stack, find the blocker slow during an incident py-spy top live view of hot functions slow on average py-spy record flame graph under traffic All three attach from outside the process — no restart, no code change.

1. Grant ptrace access without weakening the host

py-spy reads another process's memory with the same kernel facility debuggers use. Most container runtimes and hardened kernels block that by default, so the first attempt usually fails with Permission denied rather than a profile.

# Kubernetes: add the capability to a debug container that shares the pod's PID namespace
kubectl debug -it pod/api-7c9f --image=python:3.12-slim \
    --target=api --profile=general -- bash
# inside the debug container
pip install py-spy
py-spy dump --pid "$(pgrep -f 'uvicorn|gunicorn|python' | head -n1)"

# Plain Docker: grant the capability to the container you exec into
docker run --cap-add SYS_PTRACE ...

# Bare metal: check the Yama policy (1 = only parents may trace children)
cat /proc/sys/kernel/yama/ptrace_scope
sudo py-spy dump --pid 4242        # root bypasses scope 1 without changing it

Prefer an ephemeral debug container or sudo for one command over permanently lowering ptrace_scope on a production host; the capability is exactly what an attacker would want too.

Verify: py-spy dump --pid <pid> prints a Thread ... (active) header followed by Python frames. Error: Failed to find python version means you attached to a wrapper process (a shell, tini, or the gunicorn master) — pick the worker PID instead.

2. Dump the stack of a stuck loop

When the service is hung right now — health checks timing out, loop lag climbing without bound — a single stack dump is usually enough. The event loop runs on one thread, so whatever frame sits on top of that thread's stack is the code that is refusing to yield.

py-spy dump --pid 4242 --locals

Thread 4242 (active): "MainThread"
    recv_into (ssl.py:1307)
    read (ssl.py:1162)
    _safe_read (http/client.py:640)
    begin (http/client.py:331)
    getresponse (http/client.py:1428)
    urlopen (urllib/request.py:216)
    fetch_exchange_rates (pricing/rates.py:88)
        Arguments:
            currency: "EUR"
    quote (pricing/service.py:41)
    _run (asyncio/events.py:84)
    _run_once (asyncio/base_events.py:1936)
    run_forever (asyncio/base_events.py:608)

Read it from the bottom: the loop (run_forever → _run_once → Handle._run) resumed the quote coroutine, which called a synchronous urllib request that is now blocked in a TLS read. That is a blocking call on the loop thread, the same class of bug that asyncio debug mode reports as a slow callback.

Verify: take three dumps a second apart. If the top frames are identical each time, the loop is genuinely stuck in that call. If they differ, the loop is busy rather than blocked — move on to recording a profile.

3. Record a flame graph under real traffic

A busy loop that is slow on average needs a statistical picture. Record for long enough to cover several stalls, at a rate high enough to catch short callbacks, and keep idle frames out of the picture so waiting does not dominate the graph.

# 60 s at 250 Hz, speedscope output for interactive inspection
py-spy record --pid 4242 --rate 250 --duration 60 \
    --format speedscope --output api-profile.json

# Same capture as collapsed stacks, for scripting (step 5)
py-spy record --pid 4242 --rate 250 --duration 60 \
    --format raw --output api-profile.txt

# Include native frames when C extensions (orjson, asyncpg, uvloop) are suspects
py-spy record --pid 4242 --native --duration 30 --output native.svg

Leave --idle off for the first capture. Without it, py-spy drops samples where the thread is parked in epoll_wait, so every remaining sample is time the loop thread spent doing something. Add --idle later only if you need the busy-versus-idle ratio. Sampling at 250 Hz costs a few percent of one core in the py-spy process and nothing measurable in the target.

Verify: open api-profile.json at speedscope.app (it runs locally in the browser) and switch to the Left Heavy view. The total sample count should roughly equal rate × duration × active fraction; a count near zero means the process was idle for the whole capture, so record during a busier window.

Anatomy of one asyncio sample 4 stacked layers from Your code to Scheduler. Anatomy of one asyncio sample Your code parse_order() price_items() json.dumps Task step Task.__step coro.send(None) handler coroutine Callback dispatch Handle._run Context.run call_soon queue Scheduler _run_once run_forever Runner.run The bottom three layers appear in every sample; read the layer above Task.__step.

4. Read the asyncio frames correctly

Every stack in an asyncio profile shares the same base: the runner, run_forever, _run_once, and Handle._run. That base is always 100% wide and tells you nothing on its own. The information lives in what sits directly above Handle._run:

  • Task.__step then your coroutine — a task was resumed and ran until its next await. Wide frames here are CPU work between awaits on the loop thread.
  • _SelectorSocketTransport._read_ready then data_received — protocol callbacks processing incoming bytes; wide means parsing cost on the loop thread.
  • select / epoll.poll inside _run_once — only present with --idle; this is the loop waiting for I/O and is healthy.
  • _run_once self time — the scheduler's own bookkeeping. If this is a large share, you have too many tiny callbacks or timers, not slow code.

Because a coroutine only appears on the stack while it is actually executing, the flame graph measures on-CPU time between awaits, not how long the coroutine took end to end. A request handler that awaits a 2-second database query will look narrow, and that is correct: the loop was free during the query.

Verify: find your slowest known endpoint's handler in the graph. If it is narrow while its latency is high, the time is spent awaiting downstream calls — profile the dependency, not the handler. If it is wide, look at the widest child frames without an await between them.

5. Attribute samples to coroutines with a script

Flame graphs are good for exploration and poor for regression tracking. The collapsed raw output is one line per unique stack with a sample count, which makes it easy to summarise which of your functions sit directly above the scheduler.

import collections
import re
import sys

FRAME = re.compile(r"^(?P<func>.+?) \((?P<file>[^:]+):\d+\)$")
LOOP_FRAMES = {"_run_once", "run_forever", "_run", "run_until_complete", "run", "__step",
               "__step_run_and_handle_result"}


def first_app_frame(stack: str) -> str:
    """Return the first frame above the scheduler that belongs to application code."""
    frames = stack.split(";")[1:]                  # drop the leading process/thread label
    for frame in frames:
        m = FRAME.match(frame)
        if not m:
            continue
        if m["func"] in LOOP_FRAMES or "/asyncio/" in m["file"]:
            continue
        if "site-packages" in m["file"] or "/lib/python3" in m["file"]:
            continue
        return f'{m["func"]} ({m["file"]})'
    return "<scheduler / idle>"


def summarise(path: str, top: int = 15) -> None:
    counts: collections.Counter[str] = collections.Counter()
    total = 0
    for line in open(path):
        stack, _, n = line.rstrip().rpartition(" ")
        counts[first_app_frame(stack)] += int(n)
        total += int(n)
    for name, n in counts.most_common(top):
        print(f"{n / total:6.1%}  {name}")


if __name__ == "__main__":
    summarise(sys.argv[1])

Run it against the raw capture from step 3: python summarise.py api-profile.txt. Store the output alongside the release tag; comparing two releases' top-15 lists catches a new hot path long before it becomes an incident.

Verify: the percentages sum to roughly 100%, the <scheduler / idle> bucket is small when --idle was off, and the top entry matches the widest application frame you saw in speedscope. For per-coroutine wall time including awaits, use yappi with yappi.set_clock_type("wall"), which understands coroutine switches.

Sampling from outside versus tracing from inside 2 columns contrasting py-spy, yappi. Sampling from outside versus tracing from inside py-spy external sampling profiler attach to a live PID on-CPU time between awaits negligible target overhead no code change or restart yappi in-process tracing profiler start and stop in code wall time across awaits measurable overhead per-coroutine totals Use py-spy to find where the loop burns CPU; yappi to see where requests wait.

Verification

The profiling workflow is working when:

  • Attachment is repeatable: py-spy dump succeeds against the worker PID from the documented debug container or sudo command, without changing host security settings.
  • Stuck versus busy is distinguished: repeated dumps identify a single blocking frame when the loop is hung, and a varying top frame when it is merely busy.
  • Flame graphs exclude idle time by default, so the widest application frames represent on-loop CPU work between awaits.
  • Findings survive a fix: after moving the hot synchronous call off the loop (for example with asyncio.to_thread), the same capture shows that frame shrinking and the loop-lag histogram's tail dropping.
  • The summary is tracked: the script's top-N output is archived per release so regressions are visible as a diff.

Pitfalls & edge cases

  • Profiling the gunicorn or uvicorn master. The master process supervises workers and runs no request code. Its profile is empty and misleading; list children with pgrep -P <master> and profile a worker.
  • Short captures miss periodic stalls. A stall that happens every 30 seconds needs at least a two-minute capture to show up reliably. Line the capture window up with the loop-lag metric rather than recording at a random moment.
  • Native frames without symbols. --native against stripped C extensions produces hex addresses. Install debug symbols or accept that the Python frame just below the native block is the actionable one.
  • GIL contention from threads looks like loop work. If the service runs thread-pool executors, the loop thread may be waiting for the GIL. Record with --gil to keep only samples where a thread holds it, and compare against a capture without the flag.
  • Mistaking narrow frames for fast requests. Awaited time is invisible to on-CPU sampling by design. Latency problems caused by slow dependencies need tracing or pending-task inspection, not a flame graph.

Frequently Asked Questions

Is it safe to run py-spy against a production Python process?

Generally yes. py-spy samples by reading the target's memory from a separate process and does not inject code or hold the GIL, so overhead in the target is negligible at the default sampling rates. The real risk is operational: it needs ptrace permission, so grant that through a short-lived debug container or a single sudo command rather than permanently relaxing host security.

Why does my asyncio flame graph show everything under _run_once?

Every piece of code in an asyncio program runs as a callback dispatched by the event loop, so run_forever, _run_once and Handle._run form the base of every stack. Ignore that shared base and look at the frames directly above Handle._run, such as Task.__step followed by your coroutine, which show where the loop thread actually spent CPU time.

Why doesn't a slow awaited database query appear in the py-spy profile?

py-spy records what each thread is executing when it samples. While a coroutine awaits a query, it is suspended and not on any stack, and the loop thread is either running other callbacks or waiting in epoll. Without --idle those waiting samples are dropped. Use tracing, pending-task inspection or wall-clock profilers like yappi to measure awaited time.

What is the difference between py-spy dump, top and record?

dump prints the current stack of every thread once, which is ideal for a hung process. top shows a live, continuously updated view of the functions using the most time, useful for a quick look during an incident. record samples for a period and writes a flame graph, speedscope file or collapsed stacks for later analysis and comparison.