o'ailly Measure Twice

Chapter 6 — Read the Logs Before Trusting the Plan

Draft status: author draft, gate-checked; human verification pending. The measured observations and the log excerpts described are the author’s own, on the apparatus named in the provenance page; the external claims resolve to the cited references.

The plan is a theory; the log is evidence

Every benchmark run begins with a plan — a theory about what the run will measure and how. The model is too big for the GPU, so quantize it. Throughput is low, so tune the batch size. The score dropped, so the last change must have hurt quality. A plan is a hypothesis about the world, and like any hypothesis it can be wrong, and when it is wrong it is usually wrong in a way the run’s own logs already record. The logs are the evidence; the plan is the story you told yourself before you looked at the evidence. Reading the logs before trusting the plan is the habit that separates hours of productive work from days of tuning a knob that was never connected to the problem.

This chapter is about a specific and humbling class of failure: the pathological number that no amount of legitimate tuning will move, because the number is not about what you think it is about. When you meet one — a throughput an order of magnitude too low, a score that will not budge no matter what flag you set, a memory footprint that grows when you tried to shrink it — the correct response is not another sweep of parameters. It is to stop, open the load log, and read it line by line until one line falsifies the plan. The line is almost always there.

A single line that killed a plan

The clearest example on my own record cost eight minutes instead of a day precisely because I read the log. The plan was routine: take a large model whose experts were already stored in a compact four-bit-ish floating format, and requantize them to a four-bit integer format to save space. The premise — the entire justification for the work — was that the target format was smaller than the source. I started the conversion, and while it ran I watched the load log, which reported, per tensor, the source format, the destination format, and the resulting size. One line settled it: a block that had been roughly ten-hundred-something mebibytes in the source format came out larger in the destination format, not smaller. The premise was false. Re-encoding weights that were already in a compact low-bit format onto a different grid of the same width does not shrink them; it can grow them, because you are paying new overhead to represent bits that were already efficiently packed. I killed the job eight minutes in.

Had I trusted the plan instead of the log, the job would have run to completion over hours, produced a larger file, and I would then have benchmarked that file, found it no better and bigger, and only then — maybe — gone looking for why. The log had the answer before the first tensor finished converting. The general principle it taught is worth stating flatly: requantizing weights sideways, from one format to another of the same bit-width, has no upside and a real downside, and you can see the downside in the size column of the load log within minutes. Quantize downward to shrink, deliberately, or ship the bits you have; never re-encode across at the same width and expect a win.

The number that no flag could move

The second example is the archetype of the pathological number. A large model was serving at roughly two tokens per second — not slow, but an order of magnitude too slow, the kind of number that says something is structurally wrong rather than merely unoptimized. The plan wrote itself: the model must be too big for the hardware, so the fixes are the usual throughput levers — batch size, thread count, a smaller quantization, cache settings. I tried several. None moved the number, and that failure was itself the clue, because when no legitimate tuning knob affects a number, the number is being set by something that is not a tuning knob.

The cause was one line in the load log. A particular component of the model — an indexer used by the attention mechanism — had been placed on the CPU rather than on a GPU, and every token was waiting on that CPU-bound step, throttling the entire pipeline down to its speed. No batch size could fix it because batching does not move a tensor from the CPU to the GPU. No quantization could fix it because the bottleneck was placement, not size. The two tokens per second was a faithful measurement — of the wrong thing. It was measuring how fast that one misplaced component could run on the CPU, and the model’s actual capability was irrelevant to it. The moment the placement was corrected, the number jumped to where the hardware said it should be.

The lesson generalizes into a diagnostic rule I now apply reflexively. When a number is pathological and every flag you try leaves it unchanged, stop tuning. A number that ignores all your knobs is not waiting for the right knob; it is being set by something outside the space of knobs you are turning — a placement, a fallback path, a silent error being swallowed and scored as a failure, a resource that is not where you assume it is. Reading the load log is how you find what that something is, and it is almost always faster than the sweep you were about to run.

Pathological numbers are usually the harness

Behind both stories is a single truth that is easy to state and hard to believe in the moment: when a benchmark number is wildly off, the fault is far more often in the measurement apparatus than in the model. Models fail gradually — a little less accurate, a little slower. Harnesses fail catastrophically and silently — a template that produces malformed prompts so every answer is wrong, a scorer that expects one answer format and receives another so every correct answer is marked incorrect, a timeout that turns slow-but-right responses into zeros, an error path that records exceptions as failing items. Each of these produces a dramatic, suspiciously round-looking bad number, and each is a bug in the harness that has nothing to do with the model’s ability.

I learned this rule the expensive way and then had it reinforced by a smaller incident during the very research that underlies this book. A framing experiment was returning zeros for some configurations, and the zeros were being averaged into the results as though the model had scored nothing. The model had not scored nothing; the harness was turning transport-level errors — a server returning an HTTP 500 under load — into a score of 0.0 and folding those into the mean. The “finding” that emerged from those runs was an artifact of the harness swallowing errors, and it had to be retracted once the cause was read out of the logs. A zero that means “the request failed” and a zero that means “the model answered wrong” are completely different facts, and a harness that conflates them will manufacture findings out of infrastructure hiccups. The logs distinguished them; the averaged score did not.

The standardized-harness projects exist in large part to reduce exactly this class of error, by giving everyone the same vetted templating, scoring, and answer-extraction rather than a hand-rolled script per lab, and the value of that shared, debugged apparatus is precisely that its silent failure modes have been found and fixed by many users [R3][R4]. Reference eval implementations make the same contribution, pinning the prompt formats and sampling settings that otherwise drift from lab to lab and quietly move scores [R18]. Using a well-worn harness does not free you from reading its logs, but it does mean the pathological number you are chasing is more likely to be a real property of your system and less likely to be a bug nobody else has hit.

The plausible wrong number is the dangerous one

The pathological number that no flag can move is, for all its frustration, a relatively kind failure, because its very wrongness announces that something is broken and demands investigation. The truly dangerous harness bug is the one that produces a plausible number — a score that is off by three or five points in a believable direction, consistent with a story you already expected, and therefore never questioned. A template that mangles one question type out of ten depresses a score by a few points that look exactly like ordinary model weakness. A scorer slightly too strict about formatting marks a fraction of correct answers wrong, and the resulting number is low but not alarmingly so. These do not trip any alarm because they do not look pathological; they look like results.

The defense against the plausible wrong number is to spot-check the trace even when nothing seems amiss. Pull a handful of items — some the harness scored correct, some it scored wrong — and read the prompt, the raw output, and the verdict together, by hand, as if you did not trust any of them. Reading the ones marked wrong is the higher-yield move, because a correct answer misparsed as wrong is the most common silent harness bug, and it is invisible in the aggregate score. This costs a few minutes and catches the errors that repetition and error bars are blind to, because a systematic mis-score is perfectly reproducible and produces a tight, confident interval around a wrong value. A number that survives a hand audit of its own traces has earned a trust that a number known only in aggregate has not, and the audit is cheapest exactly when you are least inclined to run it — when the result already agrees with what you hoped to find.

Reading a log with intent

Reading logs well is a skill, and it is not the same as scrolling through them. A log read with intent starts from the pathological number and works backward to the line that explains it, with a specific question in mind rather than a vague hope of noticing something. If throughput is wrong, the question is where is each part of the model running, and what is the slow step waiting on — and you read the placement and timing lines, ignoring everything else. If a score is impossibly low, the question is what does a single item’s full trace look like — and you pull one item’s prompt, the raw model output, and the scorer’s verdict, and you read all three together, because the bug is usually in the seam between them. If memory behaves wrongly, the question is what was actually allocated versus what I expected — and you read the size and allocation lines, comparing them against your mental model number by number.

The load log deserves special attention because it records the decisions the system made before the first token, and those decisions — precision, placement, fallback paths, which optional components loaded and which silently did not — set the ceiling on everything that follows. The numerical-reproducibility documentation for the underlying frameworks is candid that behavior depends on the exact configuration the run resolved into, including choices the framework makes for you [R5]; the load log is where those resolved choices are written down. A benchmarker who reads the load log before the results log knows what kind of run they are about to interpret, and is far less likely to attribute a harness artifact to the model.

What the load log should tell you

A load log earns its keep by answering, before the first token is generated, the questions whose wrong answers produce pathological scores. The most important is precision: what numeric format did each part of the model actually load in, as opposed to what you asked for? A cache silently loaded in a lower precision than intended, or a component that fell back to a format the engine could handle when it could not honor your request, will move quality in ways no results-log inspection alone will explain. I keep a standing wariness here from hard experience: one model’s output was corrupted specifically by storing its attention cache in a compressed integer format that the model could not tolerate, and the only clean signal was the load log confirming the cache precision the run had resolved into. The results looked like a model quality problem; the load log named it as a cache-format problem.

The next question is placement: which parts of the model ran on the accelerator and which fell to the CPU, and did anything spill to slower memory than you planned? Placement sets the throughput ceiling, and a single misplaced component — as the two-tokens-per-second story showed — can dominate everything. After placement comes the component inventory: did every optional piece the model needs actually load, or did one fail quietly and get replaced by a fallback that scores differently? A model missing a specialized head, or running with a generic attention path because its optimized one failed to initialize, will produce numbers that are internally consistent and externally meaningless. The load log is where that substitution is confessed, usually in a line that is easy to skim past because it reads like a status message rather than an alarm.

The final thing a load log should pin down is the exact build and configuration the run resolved into — the engine version, the flags as actually applied rather than as typed, and the seed. This is what makes a number reproducible and comparable, and its absence is what makes two of your own past runs incomparable. A results log tells you what happened; a load log tells you what kind of run it happened in, and only the two together let you interpret a number rather than merely record it.

When the log is silent, add instrumentation

Sometimes the log does not contain the line that would falsify the plan, and the temptation then is to fall back on tuning by feel. The better move is to make the apparatus say more. If you cannot tell from the log where the slow step is, add a timing probe around the candidates until one of them accounts for the missing time. If you cannot tell why a class of items scores zero, log the full prompt, the raw output, and the scorer’s decision for a handful of them, and read the three side by side — the error almost always lives in the seam where one hands off to the next, in a mismatched answer format or a stripped delimiter or a truncation. If you cannot tell whether a component loaded, make it announce itself. Instrumentation is cheaper than a sweep, because a sweep tests one hypothesis per run while a well-placed probe tests the whole space of “where did the time or the correctness go” in a single run.

This matters most for the failure mode that produces no error at all: the silent wrong answer. A run that crashes tells you it failed; a run that swallows an error, substitutes a default, and scores it as a legitimate result tells you nothing, and its number joins your records looking exactly like a real measurement. The HTTP-500-scored-as-zero incident was precisely this shape — an infrastructure failure wearing the costume of a model result — and it produced a published finding that had to be withdrawn. The defense is to make silence impossible: score a failed request as missing, never as zero; count and report the missing rate alongside every result; and treat any run with a non-trivial missing rate as a run about the infrastructure, not the model, until proven otherwise. A benchmark that cannot distinguish “wrong” from “never answered” is not measuring the model; it is measuring your uptime and calling it accuracy.

The discipline: suspect the apparatus first

The habit to build is an ordering of suspicion. When a number surprises you, suspect the apparatus before you suspect the model, and read the logs before you touch a flag. This inverts the natural instinct, which is to reach immediately for the tuning knob that would fix the number if the plan were correct — and the plan usually is the thing that is wrong. The ordering is not pessimism about your own competence; it is a calibrated response to the fact that harnesses fail loudly and often while models fail quietly and rarely, so a loud, dramatic number points at the harness by base rate alone.

There is a version of this discipline that a session-bound operator must build into its procedure, because it has no memory of yesterday’s log-reading to draw on. Every unattended run should emit enough of a load log — resolved precision, placement, component inventory, and a sample item trace — that a later session, starting cold, can reconstruct what kind of run produced a given number without rerunning it. The log is the operator’s memory of its own apparatus, and a number archived without its log is a number that can never be diagnosed, only re-measured from scratch. The mantis does not strike at a reflection; it reads the scene first. Read the log before you trust the plan, and most of the plans that would have wasted your day will falsify themselves in a single line.

1 / 1