Filter concepts by levelShowing all levels.

Django · Section 72

Django Performance Debugging

Level
advanced
Read
42 min
Concepts
4

Every investigation starts the same way: refuse to open a file until one duration has become four numbers. A request took 2,400 ms — how much was the database, how much was waiting on other services, how much was your own Python, and how much happened before the view was even reached? That last span is the one people forget. Every entry in `MIDDLEWARE` runs on every request in both directions, so a query in there is the most expensive query in the codebase, and its tell is a floor under every endpoint including a health check that does nothing. Percentiles need the same discipline: a p95 of two seconds can mean everything is uniformly slow or that a small tail is catastrophic, and those are unrelated investigations. Once the time has a location, the signatures take over. Database problems come in three shapes with three unrelated fixes — query count growing with row count is an N+1 that no index touches; connections growing with worker count is exhaustion, fixed upstream of the database; and a wait that grows with concurrency while the query stays constant is lock contention, whose tell is a perfect `EXPLAIN` plan beside a slow production number, because the lock wait is counted inside the statement. Only a query that is consistently slow on its own deserves a plan and an index. Memory is its own category because it does not degrade: exceeding a limit kills the process, dropping every in-flight request, so the failure is diagnosed backwards from a restart rather than forwards from an exception. Track rows fetched, objects held and bytes returned separately, and use `tracemalloc` to name the allocating lines. Finally, dependencies and tools. Redis latency hides inside whatever endpoint touched the cache, a slow external API concentrates in one span, and a worker backlog produces no slow request at all. Pick the tool by the question: Debug Toolbar locally, `cProfile` on a reproducible path, py-spy on a live worker you must not restart, an APM for patterns, and load testing to create the conditions that make the rest informative.

What is true here

  1. Turn one duration into four spans — including middleware — before reading any code.
  2. Database time and query count are different signals with opposite fixes.
  3. A healthy plan beside a slow production duration is evidence of contention, not of an index gap.
  4. Memory failures terminate rather than degrade; diagnose from restarts and name the lines with tracemalloc.
  5. Each tool answers one question — choose by where you are, not by habit.

What you will be able to do

  • Attribute a slow request to a layer before changing anything
  • Tell an N+1, connection exhaustion and lock contention apart from their signatures
  • Find the lines responsible for a process that keeps being killed
  • Pick between Debug Toolbar, cProfile, py-spy, an APM and a load test on purpose
From "it is slow" to a fix, without guessing which layer to open
yesnocount growscount lowonly underloador: nothing isslow, it dies

"The endpoint is slow"

one number — tells you nothing yet

Split into spans

middleware · db_ms · db_queries · external_ms · cpu_ms

Floor under every endpoint?

even /healthz is slow

Middleware

a query here is paid by every request you serve

db_ms dominates

count grows with rows → N+1

select_related / prefetch_related

few queries, always slow → plan

EXPLAIN, then an index

fast alone, slow under load → contention

shorten the holding transaction

external_ms dominates

Redis latency or a third-party call

Timeout, then move it out of the request

cpu_ms dominates

usually serialization

cProfile locally · py-spy in production

Process restarts, no exception

not slowness at all

tracemalloc → the allocating lines

.values() · .iterator() · stream

  • "The endpoint is slow" — one number — tells you nothing yet
    • leads to Split into spans
    • on error, leads to Process restarts, no exception (or: nothing is slow, it dies)
  • Split into spans — middleware · db_ms · db_queries · external_ms · cpu_ms
    • leads to Floor under every endpoint?
    • leads to external_ms dominates
    • leads to cpu_ms dominates
  • Floor under every endpoint? — even /healthz is slow
    • leads to Middleware (yes)
    • leads to db_ms dominates (no)
  • Middleware — a query here is paid by every request you serve
  • db_ms dominates
    • leads to count grows with rows → N+1 (count grows)
    • leads to few queries, always slow → plan (count low)
    • on error, leads to fast alone, slow under load → contention (only under load)
  • count grows with rows → N+1 — select_related / prefetch_related
  • few queries, always slow → plan — EXPLAIN, then an index
  • fast alone, slow under load → contention — shorten the holding transaction
  • external_ms dominates — Redis latency or a third-party call
    • leads to Timeout, then move it out of the request
  • Timeout, then move it out of the request
  • cpu_ms dominates — usually serialization
    • leads to cProfile locally · py-spy in production
  • cProfile locally · py-spy in production
  • Process restarts, no exception — not slowness at all
    • leads to tracemalloc → the allocating lines
  • tracemalloc → the allocating lines — .values() · .iterator() · stream

Locating the time

Four numbers before any file is opened — and the middleware span that explains a floor under every endpoint.

Locating the time in a slow request

coreadvanced

Start by splitting one number into four. A request takes 2,400 ms; how much of that was the database, how much was waiting on other services, how much was your own Python, and how much happened before your view was even called? Middleware is the part people forget: every entry in `MIDDLEWARE` runs on every request, in order, on the way in and on the way out — so one middleware doing a database lookup per request adds its cost to every endpoint, including the health check. Until the 2,400 is broken up, any fix is a guess.

Think of it as

A request is a stack of nested spans, and debugging is narrowing down which span holds the time. The outermost span is the whole request; inside it, middleware on the way in, the view, and middleware on the way out. Inside the view sit database time, outbound call time, and your own computation. The useful discipline is to refuse to look at code until you know which span is guilty, because the layers look identical from a single duration and lead to completely different files. Two subtleties are worth internalising. First, database time is not the sum of your view's queries alone — session middleware, authentication middleware and any custom middleware also query, and their cost is attributed to the request but lives outside the view. An endpoint that is "slow for no reason" with three trivial queries is often paying for a session read, a user lookup, and a feature-flag fetch before the view runs. Second, a percentile hides shape. A p95 of 2 s can mean every request takes about 2 s, or that 95% take 50 ms and a tail takes 30 s — and those are unrelated investigations. Always look at the distribution, and always attach the four numbers to individual slow requests, so that a bad one can be read directly instead of inferred from an aggregate.

python
MIDDLEWARE = [...]      # every entry runs on EVERY request, in and out
# cost here is multiplied by your total request rate, not by the endpoint's

What we're doing: Time each middleware and the view separately, so "the request is slow" becomes "this layer is slow".

observability/timing.pypython
class SpanTimingMiddleware:
    """Outermost entry in MIDDLEWARE: measures everything inside it."""

    def __init__(self, get_response):
        self.get_response = get_response

    def __call__(self, request):
        request._spans = {}
        start = time.monotonic()

        response = self.get_response(request)      # everything below runs here

        total_ms = (time.monotonic() - start) * 1000
        view_ms = request._spans.get("view", 0.0)

        log.info("request", extra={
            "path": request.path,
            "total_ms": round(total_ms, 1),
            "view_ms": round(view_ms, 1),
            "middleware_ms": round(total_ms - view_ms, 1),   # the forgotten span
            "db_ms": round(request._spans.get("db", 0.0), 1),
            "db_queries": request._spans.get("queries", 0),
            "external_ms": round(request._spans.get("external", 0.0), 1),
        })
        return response

    def process_view(self, request, view_func, view_args, view_kwargs):
        request._view_started = time.monotonic()
        return None
8
A dict on the request is the simplest span carrier. Anything deeper — a database wrapper, an HTTP client hook — writes into it, so the log line is assembled in one place.
11
Everything below this middleware in `MIDDLEWARE` happens inside this call, which is what makes an outermost middleware the right place to measure the whole request.
20
The number that finds the problem nobody looks for: total minus view time is everything the middleware stack spent. A session backend on a slow store shows up here and nowhere else.
22–23
Both database numbers, because they disagree usefully — high time with a high count is a different fix from high time with a low count.
27–29
`process_view` fires after routing and just before the view, giving a clean boundary between "the framework got here" and "your code ran".

Why this works: One log line per request turns a duration into a location. The middleware span in particular is invisible to view-level profiling, and it is the layer whose cost is paid by every endpoint you own.

Profiling the view when the time is in middleware

Wrong

python
# health check takes 300 ms; the view is one line
def healthz(request):
    return HttpResponse("ok")
# ...so the profiling starts inside the view, and finds nothing

Better

python
# measure the layer first
# total 300 ms · view 0.4 ms · middleware 299 ms
#   -> a custom middleware resolves the tenant with an uncached query,
#      on every request, including this one

What you see: Every endpoint has an unexplained floor — even a static response takes hundreds of milliseconds — and per-view optimisation never moves it, because no view is responsible.

Why: Middleware runs outside the view, so a profiler started inside the view cannot see it, and per-endpoint dashboards attribute its cost to whichever endpoint was called. The tell is the floor: a request that does nothing should be near zero, and when it is not, the cost is in the stack around it. This is also why middleware is the most expensive place to put a database query in the whole codebase — the cost is multiplied by your total request rate rather than by one endpoint's.

Where 2,400 ms actually went — the same request, broken into spans
  1. 0 ms

    Request accepted by the worker

    anything before this is server queueing, not your code

  2. 0–40 ms

    Middleware, inbound

    session read + user lookup + feature flags = 3 queries before the view

  3. 40–2,250 ms

    The view

    db 2,210 ms across 431 queries — the count says N+1, not a slow query

  4. 2,250–2,380 ms

    Serialization

    invisible in the SQL log; shows up as cpu_ms

  5. 2,380–2,400 ms

    Middleware, outbound

    compression, headers — runs on every response too

  6. after

    What a single duration told you

    nothing: the same 2,400 ms could have been any one of these spans

  1. 0 ms: Request accepted by the worker — anything before this is server queueing, not your code
  2. 0–40 ms: Middleware, inbound — session read + user lookup + feature flags = 3 queries before the view
  3. 40–2,250 ms: The view — db 2,210 ms across 431 queries — the count says N+1, not a slow query
  4. 2,250–2,380 ms: Serialization — invisible in the SQL log; shows up as cpu_ms
  5. 2,380–2,400 ms: Middleware, outbound — compression, headers — runs on every response too
  6. after: What a single duration told you — nothing: the same 2,400 ms could have been any one of these spans

Reading the four numbers

Reading the four numbers
PatternMeansGo to
`db_ms` high, `db_queries` highN+1 or per-row workthe view's loops and the serializer
`db_ms` high, `db_queries` lowone genuinely slow query`EXPLAIN`, indexes
`external_ms` higha third party inside your requesttimeouts, then move it to a task
`cpu_ms` highyour own computation`cProfile` on the view, or `py-spy` in production
all four low, total hightime before or after the viewmiddleware, or the WSGI/ASGI server queue

Together

python
# the last row is the one people miss: nothing in the view is slow,
# and the request still took 900 ms — look at MIDDLEWARE.

Remember: Refuse to open a file until one duration is four numbers: database, external, CPU and — the one people forget — middleware. Every entry in `MIDDLEWARE` runs on every request in both directions, so a query in there is the most expensive query in the codebase; the tell is a floor under every endpoint, including ones that do nothing. And always read p50 next to p95 and p99, because uniform slowness and a bad tail look identical in a single percentile and need opposite investigations.

See also: database symptoms n plus 1 connections and locks · dependencies and the tool for each symptom · the request response lifecycle

Advertisement

Database symptoms

N+1, connection exhaustion and lock contention have three signatures and three unrelated fixes.

N+1 queries, connection exhaustion, and lock contention

coreadvanced

Three database problems produce three different signatures. **N+1**: query count grows with row count, every query fast. **Connection exhaustion**: requests fail rather than slow down, with `too many clients already`, and it usually follows a scale-up. **Lock contention**: a small number of requests wait a long time on rows other requests hold, and the waiting is invisible in query duration until you look at what is blocking what. `EXPLAIN` answers a fourth question — why one query is slow — and it is the only one of the four that an index can fix.

Think of it as

Sort database symptoms by what grows. If the query *count* grows with the data, you have an N+1, and no index or bigger server changes anything — the fix is structural, loading the relation once instead of per row. If the number of *connections* grows with your worker count, you have exhaustion, and the fix is upstream of the database entirely: fewer workers, or a pooler, or a shorter connection lifetime. If the *wait* grows with concurrency while the work itself stays constant, you have contention: two transactions want the same rows, and the second is asleep until the first commits. Only the fourth case — one query, consistently slow, regardless of everything else — is the one where reading a plan and adding an index is the right move, and it is the case people reach for first because it is the most familiar. Lock contention deserves extra care because it is the one that hides. The query duration for the blocked statement includes the wait, so it looks like a slow query; but `EXPLAIN` on it will show a perfectly good plan, which sends people looking for a phantom index. The distinguishing question is whether the same statement is fast when run alone. If it is, nothing about the query is wrong — the problem is the transaction on the other side holding rows longer than it needs to, and the fix is almost always to shorten that transaction, not to speed up this one.

python
qs.explain()                 # the plan
qs.explain(analyze=True)     # PostgreSQL: actually runs it, reports real rows

What we're doing: Show the same endpoint failing three different ways, and the one-line difference between each diagnosis.

orders/views.pypython
# ---- 1. N+1: 1 + 2n queries, all of them fast --------------------------
def order_list(request):
    orders = Order.objects.filter(month=9)               # 1 query
    return render(request, "orders.html", {"orders": orders})
# orders.html: {{ order.customer.name }} {{ order.customer.region.name }}
#   -> 2 queries per row. db_ms 2210, db_queries 431.

def order_list(request):                                  # fixed
    orders = Order.objects.filter(month=9).select_related("customer__region")
    return render(request, "orders.html", {"orders": orders})
#   -> db_ms 24, db_queries 1


# ---- 2. Contention: fast alone, slow under load ------------------------
def settle_order(order_id):
    with transaction.atomic():
        order = Order.objects.select_for_update().get(pk=order_id)
        charge = payment_client.charge(order.total)       # 800 ms HTTP call
        order.charge_id = charge["id"]                    # ...while holding the lock
        order.save()

def settle_order(order_id):                               # fixed
    order = Order.objects.get(pk=order_id)
    charge = payment_client.charge(order.total)           # outside the transaction
    with transaction.atomic():
        locked = Order.objects.select_for_update().get(pk=order_id)
        locked.charge_id = charge["id"]                   # lock held for ~1 ms
        locked.save()


# ---- 3. Plan problem: one query, always slow ---------------------------
Order.objects.filter(customer__email__iexact="a@b.test").explain(analyze=True)
# Seq Scan on customers (actual time=0.03..618.9 rows=1 loops=1)
#   -> iexact cannot use a plain b-tree index on email; add a functional
#      index on UPPER(email), or store a normalised column.
5–6
The template is where this N+1 lives, which is why reading the view alone finds nothing. Any attribute traversal in a loop — template, serializer or Python — has the same effect.
17–19
The lock is taken, then an 800 ms network call happens while holding it. Every other request wanting this order waits the full 800 ms, and their query duration reports it as slow SQL.
23–28
The fix reorders rather than optimises: do the slow work first, take the lock only for the write. Lock held drops from the length of an HTTP call to the length of an UPDATE.
32–35
The genuine index case. `iexact` wraps the column in a function, so a plain index on `email` cannot be used — the plan says sequential scan, and that is the one symptom an index actually fixes.

Why this works: Three symptoms that all present as "the database is slow" have three unrelated causes, and each fix would do nothing for the other two — which is exactly why the diagnosis has to come before the change.

Holding a lock across a network call

Wrong

python
with transaction.atomic():
    order = Order.objects.select_for_update().get(pk=pk)
    charge = payment_client.charge(order.total)     # lock held for the whole call
    order.save()

Better

python
charge = payment_client.charge(order.total)         # slow part, no lock

with transaction.atomic():
    order = Order.objects.select_for_update().get(pk=pk)
    order.charge_id = charge["id"]
    order.save()

What you see: Latency on unrelated endpoints touching the same rows rises whenever the payment provider is slow — so a third party's bad day appears in your dashboards as a database problem.

Why: A transaction holds every lock it has taken until it commits, so the lock's lifetime is the whole `atomic()` block, not the statement that took it. Putting an HTTP call inside means the lock is held for however long that call takes — including a timeout. Everything else queues behind it, and because the wait is counted inside the blocked statement's duration, the symptom looks like slow SQL. Keep transactions short and free of anything whose duration you do not control; if the write must depend on the call, do the call first and take the lock afterwards.

Narrowing a database symptom in four checks

1. Does the query count grow with the data?

Run the same request against 10 rows and 100 rows. If the count moves, stop here — it is an N+1, and nothing else on this list applies.

2. Are requests failing, or merely slow?

Failures naming clients or connections mean exhaustion, which is a worker-count problem upstream of the database, not a query problem.

3. Is the query fast when it runs alone?

Same statement, same parameters, on an idle system. Fast alone and slow under load is contention — the wait is counted inside the query duration and looks exactly like slowness.

4. Only now, read the plan

A sequential scan over a large table, or a large gap between estimated and actual rows, is what an index or fresh statistics can fix. Reaching this step first is what wastes the afternoon.

  1. 1. Does the query count grow with the data? — Run the same request against 10 rows and 100 rows. If the count moves, stop here — it is an N+1, and nothing else on this list applies.
  2. 2. Are requests failing, or merely slow? — Failures naming clients or connections mean exhaustion, which is a worker-count problem upstream of the database, not a query problem.
  3. 3. Is the query fast when it runs alone? — Same statement, same parameters, on an idle system. Fast alone and slow under load is contention — the wait is counted inside the query duration and looks exactly like slowness.
  4. 4. Only now, read the plan — A sequential scan over a large table, or a large gap between estimated and actual rows, is what an index or fresh statistics can fix. Reaching this step first is what wastes the afternoon.

Four database symptoms, four different fixes

Four database symptoms, four different fixes
SignatureDiagnosisFixWhat does NOT help
count grows with rowsN+1`select_related` / `prefetch_related`indexes, a bigger database
`too many clients already`connection exhaustionfewer workers, pooler, `CONN_MAX_AGE`more workers
fast alone, slow under loadlock contentionshorten the holding transaction`EXPLAIN`, indexes
one query always slowplan or index problemread `EXPLAIN`, add an indexcaching around it

Together

python
print(Order.objects.filter(month=9).explain(analyze=True))
# Seq Scan on orders  (cost=0.00..48210.00 rows=5012 width=142)
#                     (actual time=0.02..812.4 rows=5012 loops=1)

Remember: Sort by what grows. Query count growing with rows is an N+1 that no index fixes. Connections growing with workers is exhaustion, fixed upstream of the database. Waiting that grows with concurrency while the query stays constant is lock contention — and its tell is a perfect `EXPLAIN` plan beside a slow production duration, because the wait is counted inside the statement. Only a query that is consistently slow on its own deserves the plan-and-index treatment. Keep `atomic()` blocks short and free of network calls: a lock lives until commit, not until the statement ends.

See also: locating the time in a slow request · worker multiplication and connection exhaustion · row level locking

Advertisement

Memory, payloads, and serialization

The category that kills rather than slows, and how to name the lines responsible.

High memory, huge payloads, and excessive serialization

coreadvanced

These three are usually the same incident seen from three angles. An endpoint loads every row, builds a model instance for each, serializes them all into one response, and the process runs out of memory. The distinguishing evidence is that memory problems do not show up as slow requests — the process is killed, and the requests that die are whichever ones happened to be in flight. `tracemalloc` is the standard library tool for finding which lines allocated the memory: start it, take a snapshot, compare it to a later one, and read the top allocating lines.

Think of it as

Track three numbers that people usually collapse into one: rows fetched, objects held, and bytes returned. They are different quantities with different fixes. Rows fetched is a database concern, capped by pagination or by `LIMIT`. Objects held is a process concern — `.values()` avoids model instantiation entirely, `.iterator()` avoids holding the whole result at once — and it is what determines whether the container survives. Bytes returned is a client concern, and it is the one that keeps being ignored because it does not hurt your server much: a 40 MB JSON response is slow to serialize, slow to transfer, and often unusable by the client anyway. The critical asymmetry is that memory does not degrade. CPU saturation makes everything slower; a database bottleneck makes everything queue; both give you time to notice. Exceeding a memory limit kills the process, which drops every concurrent request, empties in-process caches, and shows up in logs as a restart with no exception attached. That is why memory bugs are diagnosed backwards — from a restart rather than from an error — and why the useful defence is structural rather than reactive: cap the row count at the query, stream anything that can be large, and treat any response whose size depends on user data as an unbounded response until proven otherwise.

python
tracemalloc.start()
before = tracemalloc.take_snapshot()
...
for stat in tracemalloc.take_snapshot().compare_to(before, "lineno")[:10]:
    print(stat)

What we're doing: Find the allocating lines with `tracemalloc`, then remove the three costs the snapshot names.

reports/debug_memory.pypython
import tracemalloc


def profile_export(build):
    tracemalloc.start()
    before = tracemalloc.take_snapshot()

    build()

    after = tracemalloc.take_snapshot()
    for stat in after.compare_to(before, "lineno")[:5]:
        print(stat)
    tracemalloc.stop()


# reports/views.py:14: size=612 MiB (+612 MiB), count=1988431 (+1988431)
# reports/views.py:15: size=488 MiB (+488 MiB), count=1988431 (+1988431)
#   line 14 = list(Order.objects.all())          -> the model instances
#   line 15 = OrderSerializer(...).data          -> the serialized copy


def build_bounded():
    rows = (
        Order.objects
        .values("id", "total", "placed_at")        # no model instances at all
        .iterator(chunk_size=2000)                 # never the whole result set
    )
    for chunk in batched(rows, 2000):
        yield orjson.dumps(chunk)                  # bytes leave as they are made


# after: peak size ≈ one chunk, flat as the table grows
5–6
A snapshot before and after is the whole technique. `compare_to(..., "lineno")` reports the delta per source line, which is what turns "the process died" into a file and a line number.
9
Run only the suspect code between the snapshots. Wrapping the whole request instead buries the interesting allocations under framework noise.
16–20
Two lines, two copies of the same data: the model instances, then the serialized structure built from them. Both exist at once, which is why peak is roughly their sum.
25–27
`.values()` removes the first copy and `.iterator()` removes the "all at once" property. Neither changes the query; both change what the process holds.
29
Yielding bytes as they are produced removes the second copy. Peak memory becomes a function of chunk size rather than of table size.

Why this works: The snapshot names the lines rather than the endpoint, and the fix follows directly from what it names — one line was building instances, the other was building a full copy of the payload.

Leaving `tracemalloc` on in production to "catch it next time"

Wrong

python
# settings.py
import tracemalloc
tracemalloc.start(25)        # every worker, every request, 25 frames deep

Better

python
# one worker, deliberately, behind a flag — then off again
if os.environ.get("TRACEMALLOC") == "1":
    tracemalloc.start()

What you see: Latency rises across the fleet after the "diagnostic" ships, and memory use goes up as well — because the traces themselves are stored per allocation.

Why: `tracemalloc` hooks every allocation and stores a traceback for it, so both CPU and memory overhead scale with allocation rate. That is acceptable on one process you are actively investigating and not acceptable as a permanent setting. For always-on production insight, use a sampling profiler that attaches to a running process instead, and keep `tracemalloc` for the moment you have narrowed the problem to a specific code path.

The same export, before and after — where each megabyte went

Materialised

  • +Every row fetched, whatever the table size
  • +One `Order` instance per row, all fields
  • +The whole payload built in memory before the first byte is sent
  • +Peak memory ≈ instances + serialized payload, at once
  • +Failure mode: the container is killed, taking every other request

Streamed

  • Rows arrive in chunks; the database keeps the cursor
  • Dicts, not model instances
  • Bytes leave as they are produced
  • Peak memory ≈ one chunk, whatever the row count
  • Failure mode: none new — it is flat in the data size
  • Materialised
    • Every row fetched, whatever the table size
    • One `Order` instance per row, all fields
    • The whole payload built in memory before the first byte is sent
    • Peak memory ≈ instances + serialized payload, at once
    • Failure mode: the container is killed, taking every other request
  • Streamed
    • Rows arrive in chunks; the database keeps the cursor
    • Dicts, not model instances
    • Bytes leave as they are produced
    • Peak memory ≈ one chunk, whatever the row count
    • Failure mode: none new — it is flat in the data size

Three quantities, three fixes

Three quantities, three fixes
QuantityGrows withFix
rows fetchedthe filter you did not applypaginate; filter in the database
objects heldrows × fields per instance`.values()`, `.only()`, `.iterator()`
bytes returnedrows × serialized fieldspage the response, or export asynchronously
peak during serializationbuilding the whole payload before sending`StreamingHttpResponse`

Together

python
Order.objects.values("id", "total").iterator(chunk_size=2000)   # bounded
list(Order.objects.all())                                       # unbounded

Remember: Memory failures kill the process rather than slowing it, so the requests that die are rarely the guilty one — diagnose from restarts, not from exceptions. Track rows fetched, objects held and bytes returned as three separate numbers: `.values()` removes the instance copy, `.iterator()` removes the all-at-once property, and streaming removes the payload copy. Use `tracemalloc` to name the allocating lines, deliberately and on one process, then turn it off. And never treat a slice as a bound on cost — cap the response in bytes, or hand genuinely large exports to a background job.

See also: dependencies and the tool for each symptom · iterator batching and streaming responses · data migrations and work that must be resumable

Advertisement

Dependencies, and the tool for each question

Redis latency, worker backlog and slow third parties — then Debug Toolbar, cProfile, py-spy, APM and load testing.

Slow dependencies, and the right tool for each symptom

coreadvanced

Three dependencies commonly go slow and each has a distinct tell. **Redis latency**: everything that touches the cache gets slower at once, and cache reads start costing more than the database reads they were meant to replace. **Worker backlog**: nothing is slow at all — the queue depth grows, and users see stale results because their job has not run yet. **A slow external API**: time concentrates in one outbound call, and the fix is a timeout plus moving it out of the request. Then pick the tool by where you are: Debug Toolbar locally, `cProfile` for a reproducible path, py-spy for a live process you must not restart, and an APM for the fleet.

Think of it as

Every tool answers one question well and lies about the others, so choose by the question rather than by habit. "Which queries does this page run?" is Debug Toolbar, locally, with the SQL panel showing duplicates — and it is a development tool that must never be enabled in production, both for the overhead and because it exposes settings and SQL. "Which function in this reproducible path is expensive?" is `cProfile`, which counts every call and therefore distorts anything call-heavy, but is precise enough for a script or a management command. "What is this production process doing *right now*?" is py-spy, which reads another process's stack from outside — no code change, no restart, no import into your app — and it is the only one of the four that is safe to point at a wedged worker. "Where is time going across the fleet, over the last hour?" is an APM, which is the only tool that sees patterns rather than instances. Load testing sits apart from all four: it does not diagnose anything, it *creates* the conditions under which the others become informative. Contention, connection exhaustion and queue backlog are all invisible in a single request, and load testing is how you get them to happen somewhere you can watch. And keep one distinction sharp: benchmarking compares two implementations under controlled conditions, while profiling finds where time goes in one. Benchmarking the wrong function is a very tidy way to waste a day.

bash
python -m cProfile -s cumtime manage.py rebuild_report 2026-09 | head -30
py-spy dump --pid $(pgrep -f "gunicorn: worker" | head -1)

What we're doing: Instrument the three dependency spans, then reach for the tool the numbers point at.

observability/dependencies.pypython
@contextmanager
def span(request, name):
    started = time.monotonic()
    try:
        yield
    finally:
        elapsed = (time.monotonic() - started) * 1000
        request._spans[name] = request._spans.get(name, 0.0) + elapsed


def dashboard(request):
    with span(request, "cache"):
        summary = cache.get(f"summary:{request.user.id}")

    if summary is None:
        with span(request, "db"):
            summary = build_summary(request.user)

    with span(request, "external"):
        rates = fx_client.rates(timeout=(3.05, 5))   # always a timeout

    return render(request, "dashboard.html", {"summary": summary, "rates": rates})


# cache 412ms · db 18ms · external 30ms
#   -> the CACHE is slower than the database it protects.
#      Redis latency, or a value too large to be worth caching.

# queue_depth 40219 · oldest_job_age 1841s · request p95 60ms
#   -> nothing is "slow": the backlog is the incident, and no request metric shows it.
1–8
One context manager, one dict on the request. Every dependency gets its own named span, which is what makes the log line diagnostic rather than descriptive.
12–13
The cache call is timed separately from what it protects. Without this, Redis latency is invisible — it is attributed to whichever endpoint happened to call it.
20
A timeout on every outbound call, always. Without one the span can grow to minutes and the worker is held for the whole time.
25–27
The reading that surprises people: a cache slower than the database means the cache is now a cost. Either Redis is unwell, or the value is large enough that transferring it beats recomputing it.
29–30
The backlog case has no slow request anywhere. Queue depth and oldest-job age are separate signals, and a system without them is blind to this entire class of incident.

Why this works: Named spans turn three different dependency failures into three different log lines, and each line points at exactly one tool — which is the step that keeps an investigation from starting with a guess.

Enabling Django Debug Toolbar in production to "see what is slow"

Wrong

python
DEBUG = True                                    # to make the toolbar work
INTERNAL_IPS = ["0.0.0.0/0"]
INSTALLED_APPS += ["debug_toolbar"]

Better

bash
# attach to the running worker instead — no restart, no settings change
py-spy dump --pid 4242
py-spy record -o flame.svg --pid 4242 --duration 30

What you see: The site gets slower under the instrumentation, and the debug pages expose settings, SQL and stack traces to anyone who can reach them.

Why: The toolbar records every query and captures template and stack context for each request, which is real overhead on live traffic, and it requires `DEBUG` — which by itself turns on Django's full error pages, disables `ALLOWED_HOSTS` protections you were relying on, and makes the framework retain every query on the connection. It is a development tool by design. When the question genuinely is "what is production doing", a sampling profiler that attaches from outside answers it without changing settings, restarting workers, or exposing anything.

Choose by where you are and how wide the question is
cProfile
per-function costs on a path you can re-run; distorts call-heavy code
Django Debug Toolbar
queries, duplicates and templates for one page — development only
assertNumQueries
not a measurement: a regression gate that runs in CI forever
py-spy
attach to a running worker, no restart — the tool for a wedged process
APM traces
the only view that shows patterns across requests and services
load testing
creates the conditions — contention and backlog do not exist in one request
  • cProfile: local / reproducible, one line or function — per-function costs on a path you can re-run; distorts call-heavy code
  • Django Debug Toolbar: local / reproducible, between one line or function and the whole system — queries, duplicates and templates for one page — development only
  • assertNumQueries: local / reproducible, between one line or function and the whole system — not a measurement: a regression gate that runs in CI forever
  • py-spy: live production traffic, one line or function — attach to a running worker, no restart — the tool for a wedged process
  • APM traces: live production traffic, the whole system — the only view that shows patterns across requests and services
  • load testing: between local / reproducible and live production traffic, the whole system — creates the conditions — contention and backlog do not exist in one request

The tool for each question

The tool for each question
QuestionToolWhere it runsIts distortion
which queries does this page run?Django Debug Toolbarlocal onlyadds overhead; never enable in production
did the query count change?`assertNumQueries`CInone — it is an assertion, not a measurement
which function is expensive here?`cProfile`local / a scriptinflates call-heavy code
what is this process doing now?py-spyproduction, livesampling: rare frames may be missed
where does time go across the fleet?APMproduction, alwayssampled traces; per-request detail is thin
what happens under concurrency?load testingstagingreveals problems rather than explaining them

Together

bash
py-spy dump --pid 4242         # one stack trace, right now
py-spy top --pid 4242          # live, top functions
py-spy record -o flame.svg --pid 4242 --duration 30

Remember: Give every dependency its own span: Redis latency hides inside whatever endpoint called the cache, and a worker backlog produces no slow request at all — its signals are queue depth and job age. Pick the tool by the question and where you are: Debug Toolbar locally (never in production, since it needs `DEBUG`), `cProfile` on a reproducible path, py-spy on a live worker you must not restart, an APM for patterns across the fleet, and load testing to create the conditions the others need. Profile before benchmarking — a component's share of the total is the ceiling on any improvement to it.

See also: locating the time in a slow request · the signals worth measuring · task idempotency monitoring and recovery

Advertisement