Debugging

The hardest bugs report nothing at all, and the usual response to one, reading the code again and changing lines hopefully, is the slowest method available.

Debugging is a procedure, not a talent. It is the same procedure every time, it is close to what an experimental science does, and its central move is that you never guess twice in a row without learning something in between. If you have arrived here directly, what is assumed is functions, arrays, objects and the fact that a stack trace names where a program stopped rather than where it went wrong.

Reproduce it before you touch anything

The first step is to make the bug happen on demand. Until you can produce it whenever you like, you cannot tell a fix from a coincidence, and most of the time people believe they have fixed something they have merely disturbed.

Reproducing means writing down the exact input, the exact steps, and the exact wrong output beside the expected one. "Sometimes the total is wrong" is not a reproduction. "totalFor(['2024-01-03']) returns 0 and should return 45" is, and half the time writing that sentence tells you the answer before you have run anything.

Intermittent bugs are the difficult case, and intermittency is itself a clue: it usually means the program depends on something other than its input. Time and dates, randomness, the order of concurrent operations, uninitialised or leftover state between runs, and data that varies with the environment are the usual suspects, in about that order. Look for a hidden input rather than a haunted machine.

One more thing to check before anything else, because it wastes more time than any other single cause: confirm the code being run is the code you are editing. A stale build, a cached file, an edit saved into another copy of the project, a server that was never restarted. Add a line that prints something absurd and check that it appears. If it does not, you have already found today's problem.

Cut it down

A bug in 500 lines is hard. The same bug in 5 lines is usually obvious. Minimising means removing everything not needed to produce the failure, and it is the highest value step in the whole procedure.

Work by deletion, and keep checking that the failure is still there after every cut. Remove the user interface and call the function directly. Replace the database with three rows typed into an array. Cut the input in half, and if it still fails, halve it again. Take out the code that formats the answer and look at the raw one. Each removal either preserves the failure, which means the deleted part was innocent, or destroys it, which means the deleted part was involved, and either outcome is information.

The end state is a handful of lines with fixed input that fails every time. That artifact is worth more than the fix: it is what you paste into a bug report, it is what tells you unambiguously when you are done, and in the next lesson it becomes a test that stops the bug returning.

Predict, then look

Here is where most people go wrong. The tempting move is to change something plausible and rerun. That is guessing, it teaches nothing when it fails, and it teaches almost nothing when it works, since you rarely learn which change mattered or why.

The method is a small experiment. State a hypothesis specific enough to predict an observation, then make the observation, then keep or discard the hypothesis. "Something is wrong with the sorting" predicts nothing. "sorted is in string order rather than numeric order, so sorted[0] will be 10 rather than 2" predicts a specific value on a specific line, and one print settles it.

Take a real case. median returns 3 for [1, 2, 3, 4], where 2.5 is expected:

function median(values) {
  const sorted = values.sort((a, b) => a - b);
  const mid = Math.floor(sorted.length / 2);
  return sorted[mid];
}

Hypothesis one: the sort is wrong. Prediction: printing sorted shows something other than [1, 2, 3, 4]. Observation: it shows [1, 2, 3, 4]. Discarded, and one candidate is gone for good.

Hypothesis two: the index is wrong. Prediction: mid is 2 for a four element array, and sorted[2] is 3. Observation: mid is 2. Kept, and now the question is sharp: what should the middle of an even length array be? There is no single middle element, and the median of an even sample is the mean of the two central values. The function has no case for it, so it silently returns the upper one, which is a plausible number and exactly why nobody noticed.

function median(values) {
  if (values.length === 0) return null;
  const sorted = [...values].sort((a, b) => a - b);
  const mid = Math.floor(sorted.length / 2);
  return sorted.length % 2 === 0 ? (sorted[mid - 1] + sorted[mid]) / 2 : sorted[mid];
}
console.log(median([1, 2, 3, 4]), median([1, 2, 3]));
// 2.5 2

Note the second fix that fell out on the way. The original called sort on the caller's array, which the references lesson showed mutates it, so every call to median silently reordered the data it was given. That is a second bug, in a function whose name promises to answer a question, and minimising is how such things surface.

Example. A function returns NaN for some inputs and correct numbers for others. Write two hypotheses that predict an observation.

The first: a value arriving from outside is a string that will not convert, so printing typeof for each element will show "string" for at least one, and Number() of it will be NaN. The second: an index one past the end is being read, so printing the loop bound and the array length together will show the bound is length with a <= test, and the last read will be undefined. Both are checkable with one print each, and each is either killed or kept outright. Compare that with "maybe the data is bad", which survives any observation and therefore tells you nothing.

Now you. A shopping basket total is correct on the first page load and doubles every time the page is refreshed. Write a hypothesis that predicts an observation, and say what you would print.

Print what you actually have

The humble print is still the most used debugging tool in the world, and it is used badly more often than not.

Print the value and its type when a type is in question: console.log("amount:", amount, typeof amount). The console shows "5" and 5 almost identically at a glance, and half of all coercion bugs are visible the moment the type is printed beside the value.

Label every print. Six bare numbers in a console tell you nothing about which line produced which. console.log("after filter:", rows.length) is readable a day later, and console.log({ mid, length: sorted.length }) prints names along with values automatically.

Print at the boundaries. The input as it arrives, the value at each hand-off between functions, the output as it leaves. Bugs live at the seams between pieces far more often than inside them, because that is where one person's assumption meets another's.

Beware one genuine trap. In browser consoles, logging an object logs a live reference, and expanding it later shows the object's state at the moment you expanded it rather than at the moment you logged it. An object that was correct when printed can appear wrong minutes afterwards. console.log(JSON.stringify(obj)) takes a snapshot and avoids the question entirely.

Two other console methods earn their keep. console.table(rows) prints an array of objects as a grid, which makes an odd row visible instantly. console.trace() prints a stack trace without throwing, which answers the question "who called this?" when a function is invoked from several places.

Halving the search space

When the failing region is still too large to read, stop reading and start bisecting. Binary search over the program: pick a point in the middle, check whether the data is already wrong there, and you have eliminated half of it. Checking means an assertion or a print of the value you can verify by hand.

The arithmetic is what makes it worth doing. Halving a 1000 line region takes $\lceil {\log }_{2}1000\rceil =10$ checks to reach a single line. Reading 1000 lines takes an hour and misses it. Ten checks of thirty seconds each is five minutes and cannot miss it, because each check is a fact rather than an opinion.

The same move works over history, and this is the one people forget. If the program worked last month and fails now, the bug is in one of the commits between, and git bisect performs the binary search for you: it checks out a commit halfway back, you say whether it is good or bad, and it repeats. Over 1000 commits that is 10 builds to find the exact one that broke it. Since a commit is usually small, that very often ends the investigation outright, and it works without understanding the code at all, which is why it is the first thing to reach for in an unfamiliar codebase.

It also works over data. If a file of 100,000 rows crashes the importer, run the first half, then a half of whichever half fails, and about 17 steps later you have the one row that does it.

Example. A pipeline reads a file, parses it, filters, joins to another table, aggregates and prints a wrong total. Where do you put the first check, and how many checks should it take to isolate the stage?

In the middle, after the filter, printing the row count and the sum of the raw amounts, both verifiable against the file by hand. Six stages need $\lceil {\log }_{2}6\rceil =3$ checks to isolate one, so checking after the third stage, then after the first or fifth, then one more, finds it. Checking each stage in order takes up to six, and starting at the end because that is where the symptom appeared is the most common and least useful choice.

Now you. A test suite passed at the release two weeks ago and fails today, with 512 commits in between. How many builds does git bisect need in the worst case, and what do you need before starting?

Assertions turn quiet wrongness into a loud stop

The previous lesson made the case for validating at the edges of a program. An assertion is the same idea used temporarily, inside, while hunting: a check of something you believe to be true, which stops the program at once if it is not.

function process(rows) {
  console.assert(Array.isArray(rows), "rows must be an array");
  const cleaned = rows.filter(r => r.amount > 0);
  console.assert(cleaned.length <= rows.length, "filter grew the array");
  ...
}

console.assert prints a message when the condition is false and carries on, which is fine for hunting. Where you want the program to stop, if (!cond) throw new Error(...) is the version to use, and it is what belongs in code that ships.

The point is where an assertion is placed. Put it on the invariant that would have to break for the bug to occur. If a total is coming out too high, assert that every amount is positive before the sum. If a list is coming out too short, assert its length after each stage. A failing assertion converts a logic error into a runtime error with a message and a line number, which is the single most valuable trade in debugging, and it is why assertions are worth adding as you go rather than only when stuck.

The debugger, and knowing when to stop

Every browser and every Node runtime ships a debugger that pauses execution and lets you inspect every value in scope. A breakpoint stops on a line; stepping moves one line at a time; a conditional breakpoint stops only when a condition holds, which is what you want when the failure is on the nine thousandth iteration. debugger; in the source is a breakpoint you can commit temporarily.

Prefer the debugger when there is a lot of state to look at, when you do not know the shape of the data, or when the failing call is buried in a library. Prefer prints when the run is fast, when you want a record of many iterations to compare, or when the bug appears only in an environment you cannot attach to. Neither is more professional than the other, whatever anybody says.

Two closing habits. Explaining the problem aloud, to a colleague or to an object on your desk, solves a startling proportion of bugs before the listener says anything, because narrating forces you to state the assumptions you have been skipping over. And when you have been stuck for an hour, stop. The reason is not mysticism: after an hour you are re-examining the same three hypotheses, and the bug is in the fourth, which you cannot see because you have already convinced yourself it is impossible.

Example. A function returns the wrong count and you suspect the filter. Write the assertion that settles it.

Assert what must be true of a filter's output rather than what you hope: console.assert(kept.length <= rows.length, "filter grew the array") catches a filter that is returning the wrong thing entirely, and console.assert(kept.every(r => r.active), "filter kept an inactive row") catches a predicate with the test inverted. The second is the one that finds a ! in the wrong place, and it states the specification of the filter in one line.

Now you. A running total ends up negative when every input is meant to be a positive amount. Where do you put an assertion, and what does it say?

Doing it again, and again

The method works. Its weakness is that it is manual, and it has to be repeated in full every time the bug comes back, which bugs do: someone refactors the function next month and reintroduces exactly the median case you fixed, and nothing anywhere notices.

The last step of a good debugging session is therefore to write the check down so the machine performs it. The minimised reproduction is already almost that. Turning it into a test that runs on demand, and building the rest of a program the same way, is the final lesson.