A Django school timetable page runs 400 queries per request; how would you use CaptureQueriesContext and the emitted SQL to find which code fires them?

seniorshould knowfreq 47%

answer

capture one request, then group
works even with DEBUG off
same statement, different id
LIMIT 21 means a get()
map the fingerprint back to a template line

basics

~20 s

Wrap one request to the page in django.test.utils.CaptureQueriesContext, normalise each captured statement's literals, and count them; the fingerprint repeated hundreds of times names the table and filter, which leads straight to the attribute access in the view or template.

solid answer

~50 s

I reproduce the page inside a test with realistic data and wrap the client call in CaptureQueriesContext(connection) from django.test.utils. It forces the connection's debug cursor on, so it records even with DEBUG = False, and it holds back reset_queries so the request does not wipe its own log. Then I replace numbers and quoted strings with ? and count the fingerprints with Counter. On a 400-query page one or two shapes dominate, for example SELECT ... FROM school_teacher WHERE school_teacher.id = ? LIMIT 21 repeated per lesson. The LIMIT 21 is the signature of get(), which a lazy foreign-key access uses, and a repeated WHERE lesson.period_id = ? is a reverse manager called per row. The table and filter column tell me which relation, and a search for it in the template finds the loop.

I reproduce the page inside a test with realistic data and wrap the client call in `CaptureQueriesContext(connection)` from `django.test.utils`. It forces the connection's debug cursor on, so it records even with `DEBUG = False`, and it holds back `reset_queries` so the request does not wipe its own log. Then I replace numbers and quoted strings with `?` and count the fingerprints with `Counter`. On a 400-query page one or two shapes dominate, for example `SELECT ... FROM school_teacher WHERE school_teacher.id = ? LIMIT 21` repeated per lesson. The `LIMIT 21` is the signature of `get()`, which a lazy foreign-key access uses, and a repeated `WHERE lesson.period_id = ?` is a reverse manager called per row. The table and filter column tell me which relation, and a search for it in the template finds the loop.

code

python · 23 lines

python

import re
from collections import Counter

from django.db import connection
from django.test import TestCase
from django.test.utils import CaptureQueriesContext


def fingerprint(sql):
    sql = re.sub(r"'[^']*'", "?", sql)
    return re.sub(r"\b\d+\b", "?", sql)


class TimetableQueryAudit(TestCase):
    fixtures = ["timetable_full_week.json"]

    def test_print_query_fingerprints(self):
        with CaptureQueriesContext(connection) as ctx:
            self.client.get("/timetable/7b/")
        print(len(ctx), "queries")
        counts = Counter(fingerprint(q["sql"]) for q in ctx.captured_queries)
        for sql, n in counts.most_common(5):
            print(n, sql[:160])

go deeper

for a junior

Know that you can capture every query a page runs and that hundreds of near-identical statements with different ids point to a loop.

for a middle

Explain what CaptureQueriesContext switches on, why it works with DEBUG off, and how a repeated WHERE id = ? LIMIT 21 maps to a lazy foreign key.

for a senior

Walk the full diagnosis: realistic data, fingerprints, baseline subtraction, hidden emitters in str or properties, per-alias captures, and a before-and-after count at two data sizes.

for a principal

Turn the one-off diagnosis into something repeatable, such as a shared fingerprinting helper the team reaches for before anyone guesses at a fix.

The goal: from a number to a line of code

"The timetable page runs 400 queries" is a symptom. The fix belongs to whoever owns related-object loading; this question is about the diagnosis: turning the count into the exact attribute access that causes it, with Django's own tools and no guessing.

Step 1: capture exactly one request

CaptureQueriesContext lives in django.test.utils. It is the machinery underneath TestCase.assertNumQueries, and it is not covered by the reference documentation, but it is stable and widely used on its own. What it does on entry and exit matters:

Forces logging on. It sets the connection's force_debug_cursor to True, so statements are recorded even when DEBUG = False, which is the default under the test runner.
Excludes connection setup. It calls ensure_connection() before taking its starting mark, so initialisation queries are not counted.
Protects its own log. It disconnects reset_queries from request_started for the duration, so a test-client request inside the block does not clear the log it is filling.
Is sliceable. len(ctx), iteration, indexing and ctx.captured_queries all give you the statements run between entry and exit, as {'sql': ..., 'time': ...} dicts.

Use a test with a realistic fixture: one class, a full week, several teachers. A page with three lessons will not show an N+1 clearly.

Step 2: fingerprint and count

Raw logs are hard to read because every repeated statement has a different id in it. Normalise the literals and count:

python

import re
from collections import Counter

def fingerprint(sql):
    sql = re.sub(r"'[^']*'", "?", sql)
    return re.sub(r"\b\d+\b", "?", sql)

counts = Counter(fingerprint(q["sql"]) for q in ctx.captured_queries)
for sql, n in counts.most_common(5):
    print(n, sql[:160])

A healthy page shows a handful of fingerprints with count 1. An N+1 page shows one or two fingerprints with counts in the tens or hundreds.

Step 3: read the shape of the repeated statement

The fingerprint tells you which relation and in which direction:

Repeated shape	What usually emits it
`FROM school_teacher WHERE school_teacher.id = ? LIMIT 21`	Forward foreign key read per row, e.g. `lesson.teacher`
`FROM school_lesson WHERE school_lesson.period_id = ?`	Reverse manager per row, e.g. `period.lesson_set.all()`
`INNER JOIN school_lesson_groups ... WHERE ...lesson_id = ?`	Many-to-many manager per row
`SELECT COUNT(*) ... WHERE ...period_id = ?`	`.count()` on a related manager per row
`SELECT id, <one column> FROM school_lesson WHERE id = ?`	A deferred column reloaded per instance of the model itself

The LIMIT 21 is a strong clue that QuerySet.get() produced the statement: get() limits its query to 21 rows so it can report "more than 20" in MultipleObjectsReturned, and the lazy forward-relation descriptor loads through get(). When the table is the related model's (teacher) rather than the looped model's own, it is a foreign-key access.
The filter column (teacher.id, period_id) names the relation; the table names the model on the other side.
The count tells you the loop: 380 teacher lookups on a page with 380 lesson cells means one per cell.

Step 4: find the line

Search the view and its templates for the relation: {{ lesson.teacher.name }} inside {% for lesson in period.lessons %} is the typical culprit. Watch for hidden emitters too: a model method or __str__ that touches a relation, a template filter, a @property. If the log shows several fingerprints repeating in lockstep (teacher and room, each 380 times), the same loop has two lazy relations.

Also separate the baseline from the problem. Session and user lookups, a savepoint pair when ATOMIC_REQUESTS nests inside the test's transaction, and one query per real list are normal; subtract them before calling the rest waste.

Edges that bite

One alias only. The context captures the connection you pass; a project with a reporting database needs a second context on connections['reporting'].
One thread only. Django connections are per thread, so work done in another thread is not in the capture.
The 9,000 cap. The capture slices the connection's bounded log by length; if that log is already at its 9,000-entry cap when the block starts, the slice comes back empty. Keep capture blocks small and fresh.
Fixing is a separate step. Once the fingerprint names the relation, the remedy (select_related, prefetch_related, a 6.1 fetch mode) is chosen elsewhere; re-run the same capture afterwards to prove the count dropped and stays flat as data grows.

## The goal: from a number to a line of code "The timetable page runs 400 queries" is a symptom. The fix belongs to whoever owns related-object loading; this question is about the **diagnosis**: turning the count into the exact attribute access that causes it, with Django's own tools and no guessing. ## Step 1: capture exactly one request `CaptureQueriesContext` lives in `django.test.utils`. It is the machinery underneath `TestCase.assertNumQueries`, and it is not covered by the reference documentation, but it is stable and widely used on its own. What it does on entry and exit matters: - **Forces logging on.** It sets the connection's `force_debug_cursor` to `True`, so statements are recorded even when `DEBUG = False`, which is the default under the test runner. - **Excludes connection setup.** It calls `ensure_connection()` before taking its starting mark, so initialisation queries are not counted. - **Protects its own log.** It disconnects `reset_queries` from `request_started` for the duration, so a test-client request inside the block does not clear the log it is filling. - **Is sliceable.** `len(ctx)`, iteration, indexing and `ctx.captured_queries` all give you the statements run between entry and exit, as `{'sql': ..., 'time': ...}` dicts. Use a test with a realistic fixture: one class, a full week, several teachers. A page with three lessons will not show an N+1 clearly. ## Step 2: fingerprint and count Raw logs are hard to read because every repeated statement has a different id in it. Normalise the literals and count: ```python import re from collections import Counter def fingerprint(sql): sql = re.sub(r"'[^']*'", "?", sql) return re.sub(r"\b\d+\b", "?", sql) counts = Counter(fingerprint(q["sql"]) for q in ctx.captured_queries) for sql, n in counts.most_common(5): print(n, sql[:160]) ``` A healthy page shows a handful of fingerprints with count 1. An N+1 page shows one or two fingerprints with counts in the tens or hundreds. ## Step 3: read the shape of the repeated statement The fingerprint tells you which relation and in which direction: | Repeated shape | What usually emits it | |---|---| | `FROM school_teacher WHERE school_teacher.id = ? LIMIT 21` | Forward foreign key read per row, e.g. `lesson.teacher` | | `FROM school_lesson WHERE school_lesson.period_id = ?` | Reverse manager per row, e.g. `period.lesson_set.all()` | | `INNER JOIN school_lesson_groups ... WHERE ...lesson_id = ?` | Many-to-many manager per row | | `SELECT COUNT(*) ... WHERE ...period_id = ?` | `.count()` on a related manager per row | | `SELECT id, <one column> FROM school_lesson WHERE id = ?` | A deferred column reloaded per instance of the model itself | - The **`LIMIT 21`** is a strong clue that `QuerySet.get()` produced the statement: `get()` limits its query to 21 rows so it can report "more than 20" in `MultipleObjectsReturned`, and the lazy forward-relation descriptor loads through `get()`. When the table is the related model's (teacher) rather than the looped model's own, it is a foreign-key access. - The **filter column** (`teacher.id`, `period_id`) names the relation; the **table** names the model on the other side. - The **count** tells you the loop: 380 teacher lookups on a page with 380 lesson cells means one per cell. ## Step 4: find the line Search the view and its templates for the relation: `{{ lesson.teacher.name }}` inside `{% for lesson in period.lessons %}` is the typical culprit. Watch for hidden emitters too: a model method or `__str__` that touches a relation, a template filter, a `@property`. If the log shows several fingerprints repeating in lockstep (teacher and room, each 380 times), the same loop has two lazy relations. Also separate the **baseline** from the problem. Session and user lookups, a savepoint pair when `ATOMIC_REQUESTS` nests inside the test's transaction, and one query per real list are normal; subtract them before calling the rest waste. ## Edges that bite 1. **One alias only.** The context captures the connection you pass; a project with a reporting database needs a second context on `connections['reporting']`. 2. **One thread only.** Django connections are per thread, so work done in another thread is not in the capture. 3. **The 9,000 cap.** The capture slices the connection's bounded log by length; if that log is already at its 9,000-entry cap when the block starts, the slice comes back empty. Keep capture blocks small and fresh. 4. **Fixing is a separate step.** Once the fingerprint names the relation, the remedy (`select_related`, `prefetch_related`, a 6.1 fetch mode) is chosen elsewhere; re-run the same capture afterwards to prove the count dropped and stays flat as data grows.

Why does CaptureQueriesContext record queries under the test runner even though DEBUG is False there?
On entry it saves the connection's `force_debug_cursor` flag and sets it to `True`; the connection logs whenever that flag or `settings.DEBUG` is on. On exit it restores the previous value. That is also why `assertNumQueries` works in tests that run with `DEBUG = False`.
The capture shows 380 teacher lookups but the template never mentions teacher; where else could they come from?
Anything that touches the relation per row: a model `__str__` that returns `f"{self.subject} ({self.teacher})"`, a `@property` on `Lesson`, a custom template filter or tag, or a form field that renders choices. Search the Python side for `.teacher` as well as the templates, and check which fingerprints repeat in lockstep to narrow it down.
How do you prove the fix worked and will keep working?
Run the same capture after the change and compare fingerprints: the repeated shape should be gone and the total small. Then load twice as much timetable data and capture again. If the count stays the same, per-row statements are gone; if it grows with the data, something still loads lazily.

It is like reading a phone bill: the total says you spent too much, but sorting the calls by number shows one number dialled 380 times, and that number tells you who to go and ask.

saying these in an interview costs you the question

CaptureQueriesContext needs DEBUG = True to record anything
Raw query counts alone identify which relation is loading lazily
The capture includes queries on every database alias automatically
Session and user lookups in the log are part of the N+1
Testing with three lessons is enough to see the N+1

A Django school timetable page runs 400 queries per request; how would you use CaptureQueriesContext and the emitted SQL to find which code fires them?

§ answer

basics

solid answer

code

§ go deeper

▾level notes4 levels

▾deep dive~4 min

The goal: from a number to a line of code

Step 1: capture exactly one request

Step 2: fingerprint and count

Step 3: read the shape of the repeated statement

Step 4: find the line

Edges that bite

▾common follow-ups3 questions

▾analogy~20 s

▾red flags5 flags

The goal: from a number to a line of code

Step 1: capture exactly one request

Step 2: fingerprint and count

Step 3: read the shape of the repeated statement

Step 4: find the line

Edges that bite

answer

go deeper