Logging a game so it can be debugged without you

The debugging loop on this project starts with someone playing the game, seeing that something is wrong, and saying so. That is the entire input. Everything downstream has to work from a sentence like "the ground has gone white", with no stack trace, no reproduction and no line number.

The ground really had gone white, for hours, and the only evidence anywhere was a line in the browser console that nothing was recording. The crash reporter could never have caught it, because it hooks the browser's global error handlers, and three.js reports a shader that failed to build by printing to the console and then carrying on.

That is the design brief for every piece of instrumentation here. The loop cannot start with Adam reading a stack trace, so it starts with a model reading instrumentation, which means the instrumentation has to produce something that can be acted on directly: structured, searchable, and complete enough to diagnose a failure without reproducing it. Logs written to be skimmed and logs written to be queried are not the same thing.

The failures that are logged, not raised#

JavaScript has two ways for something to go wrong, and the difference between them is the entire subject of this post. An error can be thrown, which unwinds the stack and, if nobody catches it, reaches one of the browser's two global handlers — window.onerror for ordinary errors and unhandledrejection for failed promises. Or it can simply be printed, with console.error, which is an ordinary function call that returns normally and tells nobody. A library that prints its failures has not failed as far as your program is concerned.

A crash reporter turns a thrown error into a database row. It hooks those two global handlers, takes explicit calls from places that catch errors themselves, and posts each one with the browser, the operating system, the graphics card and the game state attached. It is blind to the second category by construction.

What it structurally cannot see is anything a library decides merely to print. There are three such cases here, and all three produce a visibly broken game with no error anywhere.

• A shader that fails to build. Three.js prints it and keeps drawing, and the surface comes out white or black. That is precisely the failure behind the flat white map, which shipped once.
• A file that fails to load. An image, script or stylesheet fires its error on the element itself, and that error does not travel up to the window, so an ordinary listener never fires for a missing file.
• Anything a catch block prints and then swallows.

So a development-only module takes the printed half. It wraps the four console methods, adds an error listener registered in the capture phase, which is the only phase that sees a file that failed to load, and adds its own handler for rejected promises that nothing caught.

Three details in it are the difference between an instrument and a new source of bugs.

// Capture what is LOGGED, not just what is raised. Development builds only.
let inHook = false;
for (const method of ['log', 'info', 'warn', 'error']) {
  const original = console[method].bind(console);
  console[method] = (...args) => {
    original(...args);       // chain FIRST, so devtools looks the same either way
    if (inHook) return;      // re-entry guard: a logger that logs is a loop
    inHook = true;
    try {
      record(method, args.map(stringify).join(' '));
    } catch {
      /* a logger must never break its caller */
    } finally {
      inHook = false;
    }
  };
}
 
// The capture phase is the ONLY way to see a file that failed to load. An image,
// script or stylesheet error does not travel up to the window, so an ordinary
// listener never fires for a 404. That trailing `true` is what makes it fire.
window.addEventListener('error', (event) => {
  const el = event.target;
  if (el && el !== window && el.tagName) record('resource', `<${el.tagName}> failed`);
  else record('uncaught', event.message);
}, true);

Chain to the original before doing anything else, so the browser's own console panel behaves exactly as it did. Guard against re-entry, because anything you call inside the hook might itself log. And swallow everything, because a logger that can raise an error is worse than no logger at all.

Then run the check that tells you it was worth installing: break a material on purpose, by using one texture more than the device allows or by putting a typo in a shader. If the capture records it and your existing error reporting recorded nothing, that gap was already there, and the only detector you had was a white surface on the screen.

Designing for a reader that searches#

Reading a console by eye means skimming top to bottom and reacting to whatever looks alarming. A machine runs a query. Four decisions follow from that, and each shows up in the output format rather than in a convention I have to remember.

Shader failures get their own level rather than a tag. The levels are the four console ones plus shader, resource, uncaught and rejection. Six patterns catch the variants three.js prints across versions, including the bare driver line that sometimes arrives as its own separate message. Giving the highest-value signal its own level means it sorts above the ordinary noise instead of competing with it.

The tag carries the material that failed. The material's name is pulled out of the printed banner, so the tag becomes something like "shader, ground material" and the whole incident collapses to one search.

Repeats collapse into a count. A shader failure inside the drawing loop fires every frame. Without collapsing, one failure buries every other line within a couple of seconds and then overflows the 4,000-entry buffer entirely. Consecutive identical entries merge into a count plus a first and last time, and a test pins the behaviour: 120 identical messages produce one entry carrying a count of 120, and merging is consecutive-only, so a different message in between reopens the entry rather than hiding a recurrence.

The output is one JSON object per line, not a transcript. Entries land in a dated file that rotates at 8 MB and is never committed. An endpoint serves them back filtered by level, text, time or count, where the level "problems" expands to the five that matter. Both halves are absent from the shipped game, because an unauthenticated endpoint that writes to disk is a trivially abusable way to fill a hard drive.

Two constraints hold the rest up. Nothing in the capture path may raise an error, so every hook swallows. And a failed upload puts its batch back at the front of the queue, so a development server restarting mid-session loses nothing.

The instrument was wrong, not the system#

Every match load records how many bytes came over the network and how many came from cache, from every player, always. For a long stretch the cache figure sat at roughly zero. There is one obvious reading of that: browser caching is completely broken.

It was not. Assets carry a one-year cache lifetime on addresses that change whenever their contents change, and reloading the page is a disk read rather than a download. The zero came from the instrument. A response served from another domain that does not explicitly opt in to being timed has its recorded sizes zeroed, and Chrome zeroes the transferred size and the body size together. Look at the transferred size alone and a response served from disk cache and a response you are not permitted to measure are the same number.

The cached bytes were invisible to the very measurement built to count them, and the measurement reported that absence as a fact about caching.

What separates that from a real regression is a third state. The code that turns a browser timing entry into a row now sorts every entry three ways rather than two: bytes actually crossed the network, or no bytes crossed but the body size is known and it came from cache, or everything is zero, which means not permitted to measure. That third bucket is not a cache hit. It is a blindfold. A test pins all three and names the one that matters in its own assertion, a flag rides along when nothing in a whole load was measurable, and the report prints the unmeasurable count next to the cache figure with an instruction not to read a low number as a caching bug.

The portable form is a rule about instruments rather than about caching. Before you act on a number, count how many of its inputs were measurable at all. Any measurement with a permission gate in front of it has three outcomes, not two, and the third one silently reads as whichever of the other two happens to be zero. The web has several: timing data from another domain, reading pixels back from a canvas that has loaded a foreign image, a stack trace from a script served without the right header.

That was not the only counter that lied. The transfer statistics had been counting repeat fetches of the same address twice, which put rows of 1,611 MB and 4,155 MB into the table for single matches. The fix gave repeat downloads their own counter, because a wasted download is a real signal but not a size signal.

Counting bytes instead of running a stopwatch#

The companion decision is a tool that measures nothing at runtime at all. It works out how many bytes a match makes a player wait for by walking the built files and following the same rules the game follows, without loading, drawing or timing anything.

The reasoning is stated plainly wherever it is used: page load timing folds in network weather, cache warmth and whatever else the machine happened to be doing, and the effect being looked for is smaller than that noise on a good day. A count of bytes has no weather. It is a property of the build, identical on every machine.

What that bought is a distinction no stopwatch can draw. The same count can be run twice, once over what the project contains and once over what the content network actually serves.

Those two rows disagree by 121.0 MB. A saving that is real in the build and absent for players means something the game asks for is not where it should be, and every request for it silently falls back to the larger file. A timed load would have shown a slow loading screen and no reason for it. Preferring a measurement with a stated weakness over a plausible-looking number is the same discipline that got triangle count removed from the rendering budget.

Public writes, private reads#

Nine groups of endpoints collect something: crashes, console output, game logs, rendering and model debug output, performance sessions, load measurements, missing files and player feedback.

The write side of the shipped ones is public and unauthenticated, deliberately. A player whose game will not load cannot sign in first, and a crash report that requires a session is the one you never receive from the crashes that matter most. The read side is behind a secret in every case, and the pages that read them are not linked from anywhere public.

What replaces authentication on the write side is a budget. Crash reports allow twenty per address per five minutes. Load measurements allow thirty a minute and hash the address with a salt that rotates daily rather than storing it. The game spends less than either: fifty reports per session, a ten second window that suppresses duplicates keyed on type, category and the first hundred characters of the message, and a burst of more than five in one second pauses reporting for thirty seconds. Noise from browser extensions is dropped before it costs any of that budget. Missing files are aggregated per address per hour, expire after fourteen days, and are capped at fifty thousand rows.

What a debugging loop needs when the bug report is one sentence#

The three pieces here are the three any project needs once the bug report arrives from outside the code. Something that captures what is raised. Something that captures what is merely printed, because the most expensive failures in a browser 3D application are all in the second category. And something that measures a property of the build rather than a property of the afternoon, so a change can be judged without recreating the conditions it was found in.

The instrumentation is what turns "the ground has gone white" into something actionable, and its shape comes entirely from who is reading at each end. Adam looks at the game, a model looks at the logs, and the format in the middle exists so that neither has to do the other's job. The scripts that hold the individual pieces steady are the standalone files described in testing a game without a test framework, and the wider working practice this fits into is in directing a codebase you have never read.