A repeatable debugging method: reproduce, isolate with git bisect, fix the cause

Most debugging time is not spent fixing bugs. It is spent not knowing where the bug is: reading code that turns out to be fine, adding print statements in the wrong service, trying a fix that makes the symptom go away for a day. The engineers we admire most are not faster at guessing. They follow a method that turns a vague symptom into a single line of code with as little guessing as possible.

This post describes the six-step method our team uses for any bug that survives the first fifteen minutes, and walks through one real case: a reporting endpoint that went from two seconds to forty between two releases. If you adopt only one step, make it step 4: when you have a good version and a bad version, let git bisect find the change for you.

Step 1: Reproduce it reliably

A bug you cannot reproduce on demand is a bug you cannot prove fixed. Before reading any code, write down the shortest sequence that triggers it, and make it runnable.

Our case started as a support ticket: "the monthly export times out for our account". The account had about 18,000 invoices. Production showed the endpoint at a p95 of 41 seconds after the v3.9.0 release, against 2.1 seconds before. We restored an anonymised copy of that account into a local database and wrote a script that hit the endpoint once and printed the timing:

#!/usr/bin/env bash
# scripts/repro-export.sh
set -euo pipefail
curl -s -o /dev/null -w '%{http_code} %{time_total}\n' \
  -H "Authorization: Bearer $LOCAL_TEST_TOKEN" \
  "http://localhost:8000/api/reports/monthly-export?account=acct_demo_18k&month=2024-08"

200 39.84

If a bug is intermittent, the reproduction is "run it 200 times and count failures". That is still a reproduction, as long as the failure rate is stable enough to tell good from bad.

Step 2: Observe before you theorise

Collect facts the system already gives you before forming a theory. For a slowdown that means profiles and query counts; for a crash, the full stack trace and the inputs; for wrong data, the exact rows involved.

We enabled Django's database query logging around one request and counted:

# quick measurement in a Django shell
from django.db import connection, reset_queries
from django.test.utils import CaptureQueriesContext
from reports.export import build_monthly_export

with CaptureQueriesContext(connection) as ctx:
    build_monthly_export(account_id="acct_demo_18k", month="2024-08")
print(len(ctx.captured_queries))

36214

Thirty-six thousand queries for one export: roughly two per invoice. That observation did not tell us which change caused it, but it ruled out a whole class of theories (network, CPU, a slow PDF library) in one measurement.

Step 3: Form hypotheses you can falsify

Write hypotheses down, each with a quick test that could prove it wrong. Ours:

The third row confirmed the kind of bug but not where. v3.8.0 to v3.9.0 contained 143 commits from six people, several touching the reports and billing models. Reading them all would take hours. This is exactly the situation bisection is built for.

Step 4: Isolate the change with git bisect

git bisect performs a binary search over history. You mark one commit bad and one good, and it checks out the midpoint for you to test; each answer halves the range. For 143 commits that is at most eight steps. With git bisect run, a script answers each step automatically. The script's exit code is the verdict:

Our test script measured query count rather than wall time, because query count is deterministic while timings are noisy:

#!/usr/bin/env bash
# scripts/bisect-export.sh
set -uo pipefail

# Install deps and migrate; if this commit cannot build, tell bisect to skip it.
pip install -q -r requirements.txt >/dev/null 2>&1 || exit 125
python manage.py migrate --noinput >/dev/null 2>&1 || exit 125

count=$(python manage.py shell -c "
from django.db import connection
from django.test.utils import CaptureQueriesContext
from reports.export import build_monthly_export
with CaptureQueriesContext(connection) as ctx:
    build_monthly_export(account_id='acct_demo_18k', month='2024-08')
print(len(ctx.captured_queries))
" 2>/dev/null | tail -n 1) || exit 125

echo "queries=$count"
[ "$count" -lt 100 ]   # good if under 100 queries, bad otherwise

Then the session itself:

git bisect start v3.9.0 v3.8.0
git bisect run ./scripts/bisect-export.sh

Bisecting: 71 revisions left to test after this (roughly 6 steps)
running './scripts/bisect-export.sh'
queries=4
Bisecting: 35 revisions left to test after this (roughly 5 steps)
running './scripts/bisect-export.sh'
queries=36214
...
e41c9a7d2b is the first bad commit
commit e41c9a7d2b
Author: (redacted)
    Show customer display name in export, refactor row builder
 reports/export.py | 22 ++++++++++++----------
bisect found first bad commit

Eight builds, about six minutes, no code reading. We saved the log for the incident notes and returned to the branch we started on:

git bisect log > /tmp/bisect-export.log
git bisect reset

Two practical notes. Bisecting needs a test that is stable on old commits, so keep the script outside the repository or in a path the old commits do not touch. And if a commit range is known to be broken for unrelated reasons, git bisect skip (or exit code 125) keeps the search going around it.

Step 5: Fix the cause, not the symptom

The first bad commit refactored the export row builder and added the customer's display name, which lives on a related Customer model. The original query used select_related("customer"); the refactor built a new queryset without it and accessed invoice.customer.display_name in a loop. The "two queries per invoice" came from the customer and its billing address.

 def export_rows(account_id, month):
-    invoices = Invoice.objects.filter(account_id=account_id, period=month)
+    invoices = (
+        Invoice.objects.filter(account_id=account_id, period=month)
+        .select_related("customer", "customer__billing_address")
+        .order_by("number")
+    )
     for inv in invoices:
         yield [inv.number, inv.customer.display_name, inv.customer.billing_address.country, inv.total]

Fixing the cause also meant asking why review missed it. The diff looked harmless because the expensive attribute access was a line away from the queryset definition. That led to the guard in step 6 rather than a reminder to "be careful with ORMs".

Tempting symptom fixes we rejected: raising the endpoint timeout, caching the export for an hour, and moving it to a background job. All three would have hidden an N+1 that also slowed two other pages using the same row builder.

Step 6: Lock it in with a test

The bug is not done until a test fails on the bad commit and passes on the fix. Query count is the thing that regressed, so that is what we assert:

from django.test import TestCase
from reports.export import export_rows
from reports.tests.factories import make_invoices

class ExportQueryCountTest(TestCase):
    def test_export_query_count_is_constant(self):
        account = make_invoices(count=50)
        with self.assertNumQueries(1):
            rows = list(export_rows(account.id, "2024-08"))
        self.assertEqual(len(rows), 50)

We checked out e41c9a7d2b, confirmed this test failed there with 101 queries, then confirmed it passed on the fix. After the hotfix release, the endpoint's p95 dropped back to 1.9 seconds.

When the method is hard to apply

• No known good version. Build one: a minimal input that works, then grow it toward the failing input. That is bisection over data instead of history.
• Cannot reproduce locally. Move observation to where the bug lives: structured logs with request IDs, feature-flagged extra logging, a production profiler sample.
• Bisect lands on a merge commit or a huge squash. Use git bisect start --first-parent to find the guilty merge on the main line first, then bisect inside the merged branch, or split a squashed change into smaller commits on a scratch branch and bisect those.
• Flaky verdicts. Make the script repeat the test several times and only call a commit bad when failures exceed a threshold.

Common mistakes

Key takeaways

• Start every hard bug with a runnable, reliable reproduction.
• Measure first; a single observation can rule out whole families of theories.
• Write falsifiable hypotheses and test them cheaply.
• With a good and a bad version, automate the search with git bisect run, using exit code 125 for untestable commits.
• Fix the mechanism, ask why it slipped through, and add a test that fails on the bad commit.

References

• Git documentation: git-bisect — https://git-scm.com/docs/git-bisect
• Django documentation: assertNumQueries — https://docs.djangoproject.com/en/5.1/topics/testing/tools/#django.test.TransactionTestCase.assertNumQueries
• Django documentation: select_related — https://docs.djangoproject.com/en/5.1/ref/models/querysets/#select-related
• Simon Tatham: How to Report Bugs Effectively — https://www.chiark.greenend.org.uk/~sgtatham/bugs.html