Day 93 — 4.8 billion tokens, and the run that lied about its own speed

“are you sure we are ready for the pretrain now?”

The honest answer that morning was mostly — and the gap was the part that mattered.

The vocabulary was never the constraint

Doubling the vocab 16k → 32k moved books from 2.490 to 2.627 bytes/token. Five and a half percent, for double the embedding table. That should have been suspicious immediately.

The pre-tokenizer is \s+|\S+ — whitespace becomes its own piece, and BPE merges never cross a piece boundary. So a space can never join the word after it:

'The old house at the end'
 -> ['The', ' ', 'old', ' ', 'house', ' ', 'at', ' ', 'the', ' ', 'end']

48% of the token stream is a bare space.

The words were already single tokens. house, street, stood — one token each. The spaces were the waste, and no amount of vocabulary fixes that, because the cost is structural.

v2 attaches the leading whitespace to the following word, GPT-2 style. On 32 real Gutenberg books:

1.80× — and notice the vocab bump starts paying again once the waste is gone (+8.9% vs +4.4%).

Which pre-tokenizer a vocab used is now provenance: recorded in the json, read back on load, never inferred — applying the wrong one re-segments every word and turns weights into noise. It’s threaded through all four implementations that must agree byte-for-byte, with a parity test. A file with no pretok key predates v2 and is v1 by definition, so every existing checkpoint still loads.

The default deliberately stays v1. Flipping a global default silently re-tokenizes every vocab trained from that point on — and a distill test caught exactly that, a 300-vocab toy going from ANSWER: 2 to ANSWER: 111.

The corpus, finished

58,536 books    -> 21.2 GB cleaned
32k v2 vocab    -> 223 seconds
22.27 GB text   -> 4,800,093,525 tokens in 11.1 minutes
                   4.63 bytes/token, 58,536 EOT seams (exactly one per book)

0.4 → 13.7 tok/param for a 350M. Two days ago that model would have been more starved than the 30M that produced the babble in the first place.

Two features the run needed and didn’t have

Snapshots. --ckpt-every writes a rolling file — a rescue point, replaced every interval, which can only ever answer “where was I 20 minutes ago”. Over 56 hours that isn’t enough: if the model diverges at hour 40, the rolling file has already eaten the good state. --snapshot-every writes numbered permanent copies that are never overwritten. Five across one run is also a token-budget scaling curve for free — bench snapshot 1 against 3 against 5 and see whether the loss was still moving when the clock ran out.

Keeping the final optimizer state. Completion used to unlink() the checkpoint, leaving weights without Adam’s moments — so continuing later meant restarting the optimizer and eating a loss spike. Now kept as ckpt-final.pt. Verified by continuing a finished run to more steps, then again onto a different corpus.

The pre-flight earned its hour

Four things, each of which would have cost the run:

• Batch 16 was slower than batch 8 — 17,073 vs 25,009 tok/s at 16.5 of 17.1GB. Allocator thrash at the memory edge. Batch 4 collapsed to 2,940 on loader round-trips. 8×8 is the sweet spot and it isn’t obvious from either direction.
• Resume had never been tested at 336M, where the checkpoint is 3.76GB. Killed it mid-flight; it came back at step 81 with the optimizer state intact — loss continuous at 8.96, not a reset to 10.6.
• timeout /t fails under SSH (Input redirection is not supported), so the self-healing wrapper’s 60-second backoff never waited. Five retries in seven seconds.
• The launcher on the box had no shutdown block at all — I’d edited my local copy after pushing it. It would have run 56 hours and then just sat there.

Then the run lied about its own speed

Calibrate said 1.310 s/step. The real thing ran at 1.700 — 72 hours remaining against a 61-hour window.

Two wrong hypotheses first. Checkpoint writes: plausible, but a 3.76GB write at the measured disk speed is 16 seconds, not 195. Then a sequential disk test returned a reassuring 242 MB/s — which was itself misleading, because it measured the wrong thing.

train.bin was on a spinning 8TB drive. Sequential writes are fine on an HDD; our access pattern is random 512-token windows across 9.6GB, which is seek-bound. And calibrate only measures 30 steps — a working set small enough to stay in page cache, which is exactly why it disagreed.

The box had 95GB of RAM sitting unused.

HDD memmap     1.700 s/step   19,275 tok/s   72.1h
RAM resident   1.345 s/step   24,368 tok/s   55.5h

Running

336.39M params · 24 layers · 32k v2 vocab · EOT · bf16
step 0  loss 10.5577      (chance = ln 32768 = 10.397)
150,178 steps = 4.92B tokens = 14.6 tok/param, 1.03 epochs
24,368 tok/s · 11.3 of 17.1 GB · five snapshots ~12h apart
finishes ~Sunday 05:15, then powers itself off

Self-healing: relaunches on crash, resumes from the last checkpoint, and stops after five failures that write no checkpoint so a hard error can’t spin forever.

The AHA

A short benchmark and a long run are different measurements, and only the long one counts. Calibrate, the smoke test and the live run each reported a different speed for identical work. The gaps were page cache, allocator pressure, and a disk nobody had looked at — none of which a 30-step timing loop can see. The number worth trusting is the one that ran longest.