Debugging systematically

Most debugging is guessing, and it works often enough to pass for a method. It stops working on the failures that matter in AI systems: no exception, no stack trace, just an answer that is quietly wrong. This section is a procedure instead — reproduce it, form a hypothesis you could disprove, then halve the search space until one explanation is left standing. It covers reading someone else's stack trace, chasing intermittent failures, and the particular problem of debugging something that never errors.

The loop#

1. 1.Reproduce it reliably. Everything else is guesswork until you can.
2. 2.Form one hypothesis about the cause.
3. 3.Design the cheapest experiment that could prove it wrong.
4. 4.Run it. Update. Repeat.

The discipline is trying to falsify rather than confirm. Looking for evidence that supports your hypothesis will always find some, and you will fix the wrong thing.

One hypothesis at a time is the part people drop under pressure. Change three things and watch the symptom go away, and all you have learnt is that one of the three mattered; you now have to keep all three forever, because you do not know which. Change one and you learn something either way. If the symptom persists you have ruled a cause out, and ruling causes out is most of what debugging is.

Reproduce it first#

Everything after this step is cheap and everything before it is guesswork, so reproduction deserves more effort than it usually gets. A reproduction is not the bug report. It is a command you can run that fails, in under a minute, on your machine. Three things make one: the exact input, saved to a file rather than described; the exact versions, pinned, including the model, because a provider updating a default is invisible from your side; and the exact state, because a bug that only appears on a warm cache is a different bug from the one you are about to chase.

When you have it, write it down as a test that fails. It costs two minutes, it stops the reproduction quietly rotting, and it is the only evidence anyone will accept later that you actually fixed the thing.

Reading a stack trace#

Read it bottom upwards. The last line is the exception type and its message, and the message is usually precise about what went wrong. The lines above are the call path with the innermost frame last. The frame you want is the last one that is your own code, because the library beneath it is almost always doing exactly what it was asked to do.

import os, traceback

def load_config(raw):                 # library code, doing what it was asked
    return {k: v for k, v in (line.split("=") for line in raw.splitlines() if line)}

def read_settings(raw):               # yours
    return load_config(raw)

def start(raw):                       # yours
    return read_settings(raw)["model"]

try:
    start("model=haiku\nretries=3\nnote=written by an = sign")
except Exception:
    here = os.path.dirname(os.path.abspath(__file__)) + "/"
    print(traceback.format_exc().replace(here, ""))

# Traceback (most recent call last):
#   File "settings.py", line 13, in <module>
#     start("model=haiku\nretries=3\nnote=written by an = sign")
#     ~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
#   File "settings.py", line 10, in start
#     return read_settings(raw)["model"]
#            ~~~~~~~~~~~~~^^^^^
#   File "settings.py", line 7, in read_settings
#     return load_config(raw)
#   File "settings.py", line 4, in load_config
#     return {k: v for k, v in (line.split("=") for line in raw.splitlines() if line)}
#                      ^^^^
# ValueError: too many values to unpack (expected 2, got 3)

Work it from the bottom. The exception is a ValueError and the message says three values where two were expected, which is a complete description of the bug before you have looked at any code. The innermost frame is load_config, and it is where the fix goes: split on the first equals sign only. The two frames above it, both yours, are innocent — they passed the string along. And the input that triggered it is right there in the top frame: a value with an equals sign inside it. Reading the message carefully was faster than any debugger would have been.

Two habits follow. Read the whole message, numbers included, before scrolling anywhere. And when every frame is library code, you are almost certainly handing something the wrong shape, so find the last frame that is yours and print what it passed.

Halve the space#

Rather than inspecting from the start, test the midpoint. Is the data correct halfway through the pipeline? That one question eliminates half the system, and repeating it finds the cause in a handful of steps regardless of size.

parse -> chunk -> embed -> index -> retrieve -> rerank -> generate

Check the retrieved chunks first. Correct means the problem is
downstream, in generation. Wrong means it is upstream, and you
have removed four stages with one check.

Three things are worth halving and they are the same move applied to different axes: the pipeline, as above; the commit history, when it worked last week and does not now; and the input, when one document in forty thousand brings the run down. Each turns a linear search into a logarithmic one, which is the difference between an afternoon and ten minutes.

Bisecting the commit history#

git bisect does this for you. Its value is entirely in the logarithm: a thousand commits is ten tests rather than five hundred. What people get wrong is the test itself. Write a script that exits zero when the commit is good and non-zero when it is bad, check it by hand against the known-good and known-bad ends before starting, and then let bisect run unattended with git bisect run.

import math

commits = [f"c{i:03d}" for i in range(1000)]
BROKE_AT = 617                       # the answer, which you do not know

def test(i):
    """Stands in for git bisect run: true if this commit is good."""
    return i < BROKE_AT

lo, hi, steps = 0, len(commits) - 1, 0     # lo known good, hi known bad
assert test(lo) and not test(hi)
while hi - lo > 1:
    mid = (lo + hi) // 2
    steps += 1
    good = test(mid)
    print(f"  step {steps:>2}: {hi - lo:>4} commits left, testing {commits[mid]} -> "
          f"{'good' if good else 'bad'}")
    if good:
        lo = mid
    else:
        hi = mid

print(f"\nfirst bad commit: {commits[hi]}")
print(f"{steps} tests over {len(commits)} commits (log2 is {math.log2(len(commits)):.1f})")
print(f"reading them one at a time would have been up to {BROKE_AT + 1}")

#   step  1:  999 commits left, testing c499 -> good
#   step  2:  500 commits left, testing c749 -> bad
#   step  3:  250 commits left, testing c624 -> bad
#   step  4:  125 commits left, testing c561 -> good
#   step  5:   63 commits left, testing c592 -> good
#   step  6:   32 commits left, testing c608 -> good
#   step  7:   16 commits left, testing c616 -> good
#   step  8:    8 commits left, testing c620 -> bad
#   step  9:    4 commits left, testing c618 -> bad
#   step 10:    2 commits left, testing c617 -> bad
#
# first bad commit: c617
# 10 tests over 1000 commits (log2 is 10.0)
# reading them one at a time would have been up to 618

Bisecting the input#

The same halving works on data, and almost nobody does it. A batch of forty thousand documents fails somewhere. You do not need to know where; you need the smallest input that still fails. Halve it, keep the half that still fails, repeat, then take one item away at a time until nothing more can go. What you are left with is a test case.

calls = 0

def fails(rows):
    """The real check is running your pipeline. Here: a heading row with no
    text makes the chunker emit an empty chunk, which crashes embedding."""
    global calls
    calls += 1
    return any(r.startswith("## ") and r.strip() == "##" for r in rows)

def shrink(rows, fails):
    """Halve, keep the half that still fails, then drop one row at a time."""
    while len(rows) > 1:
        half = len(rows) // 2
        for candidate in (rows[:half], rows[half:]):
            if fails(candidate):
                rows = candidate
                break
        else:
            break
    changed = True
    while changed:
        changed = False
        for i in range(len(rows)):
            candidate = rows[:i] + rows[i + 1:]
            if fails(candidate):
                rows, changed = candidate, True
                break
    return rows

document = [f"line {i}" for i in range(400)]
document[137] = "## "
document[300] = "## also empty but not needed to reproduce"

print(f"input that fails: {len(document)} lines")
minimal = shrink(document, fails)
print(f"minimal input that still fails: {len(minimal)} lines -> {minimal}")
print(f"{calls} runs of the pipeline to get there")

# input that fails: 400 lines
# minimal input that still fails: 1 lines -> ['## ']
# 12 runs of the pipeline to get there

Four hundred lines down to one, and the one is a heading with nothing under it. The bug report changes from the ingest job crashes to a heading with no body produces an empty chunk, and that sentence contains its own fix.

When nothing errors#

AI systems fail by producing wrong output with no exception. The stack trace you would normally start from does not exist, so you need a different entry point.

• Read the rendered prompt. Not the template, the exact text that was sent. Most surprising behaviour is obvious once you see it.
• Check the retrieved context before blaming the model. The answer usually was not there.
• Compare a failing case against a similar passing one and find the difference.
• Check the model and its version. A provider changing a default is invisible from your side.
• Look at temperature. Intermittent failures with identical input are often sampling variance rather than a bug.

Systems you cannot reproduce by re-running#

A model call at a non-zero temperature, a race between two workers, a cache that expires after five minutes: none of these fail on demand. Running it again and watching it pass is the commonest way people convince themselves a bug is fixed, and the arithmetic says a clean run means very little.

import math, random

def runs_needed(p, confidence=0.95):
    """How many attempts before you have seen a p-probability failure at least once."""
    return math.ceil(math.log(1 - confidence) / math.log(1 - p))

print("failure rate   runs to see it once (95%)   runs to see it five times (expected)")
for p in (0.30, 0.10, 0.05, 0.02, 0.005):
    print(f"{p:>10.1%}   {runs_needed(p):>25}   {math.ceil(5/p):>36}")

random.seed(0)
p = 0.05
clean = sum(1 for _ in range(10_000) if all(random.random() > p for _ in range(3)))
print(f"\nA 5% failure passes three runs in a row {clean/10_000:.1%} of the time.")
print("Three clean runs is not evidence that you fixed it.")

# failure rate   runs to see it once (95%)   runs to see it five times (expected)
#      30.0%                           9                                     17
#      10.0%                          29                                     50
#       5.0%                          59                                    100
#       2.0%                         149                                    250
#       0.5%                         598                                   1000
#
# A 5% failure passes three runs in a row 85.4% of the time.
# Three clean runs is not evidence that you fixed it.

So the first move on an intermittent failure is not to hunt but to measure. Run it enough times to get a rate. A rate converts is it broken, which nobody can answer, into is it broken less often than before, which anybody can. Then remove one source of variance at a time: fix the seed, set temperature to zero, run a single worker, freeze the clock. If the failure survives all of that it was never variance. If it disappears, you have found the knob it hangs from.

The other half is capture. A system that fails one time in fifty cannot be debugged from a log line saying the answer was wrong. It can be debugged from the rendered prompt, the retrieved chunks, the model and version, the sampling settings and the request id, written down for every request an automated check flagged. Build that before you need it; you cannot go back and collect it for a failure that already happened.

Intermittent failures#

• Something concurrent: a race, a shared mutable object, an unbounded pool.
• Something time-dependent: a cache expiring, a token, a date boundary.
• Something external: rate limits, a slow dependency, another team deploying.
• Sampling: with a non-zero temperature, identical input genuinely produces different output.

What to skip#

Skip reading code looking for the bug. Reading finds the bugs you already suspect and walks past the one that is actually there, which is why the loop starts with reproduction rather than inspection. Skip the clever theory until the boring ones are gone: the wrong environment variable, the stale build, two copies of the file, a cache. And skip the second tool when the first one answered the question — a debugger session for something a log line already shows is a quarter of an hour you did not need to spend.