PROF: DISK-CLASS — per-load cold/warm disk instrumentation

[monotophic]

PROF: DISK-CLASS — per-load cold/warm disk instrumentation

Authored by Fable 5 in Claude Code, analysis in partnership with @monotophic.

Re-derived onto the #391 split (this revision)

This branch (e7/disk-class-instr-rebased) re-derives the original
e7/disk-class-instr @ de6dd6d (base caa49f7) onto origin/dev @ 61004dc,
after PR #391 split c/glm.c into c/colibri.c + quant.h/sample.h/
kv_persist.h/telemetry.h/grammar.h. Semantic equivalence, not a copy: same
events, same accounting, re-sited onto the new tree.

• Placement: unchanged — everything stays in c/colibri.c. telemetry.h
  (new in refactor: split glm.c → colibri.c + 4 header modules (−18%) #391) is the dashboard/stats module (HWINFO/TIERS/EMAP/HITS
  protocol lines + usage persistence); prof_report(), expert_load_impl(),
  moe(), g_prof_io and g_edisk_ns all stayed in colibri.c after the
  split, so DISK-CLASS's aggregation and printing follow them there.
• Read path: feat(prefetch): async expert prefetcher v4 -- 94.3% cache hit rate, 2.8x speedup, zero RAM overhead #362 (prefetcher-v3, 22509fc) turned out to be testbed-only
  scope per its own merge message ("glm.c untouched") — confirmed zero
  c/glm.c changes in that merge's diff (only c/olmoe.c + tooling). The
  seven expert_load() call sites this patch touches are structurally
  identical to the pre-split tree; DISK-CLASS still counts demand loads only.
• One real drift, unrelated to feat(prefetch): async expert prefetcher v4 -- 94.3% cache hit rate, 2.8x speedup, zero RAM overhead #362: [Bug]: Metal — the LFRU recency clock freezes at prefill end; REPIN's tie-breaker runs on stale scores during decode #417 (cfcc742) fixed the exact
  "Metal pre-routed FASE A never bumps the real elast/eaccess_clock"
  defect this feature's comments used to describe as a documented,
  deliberately-unfixed upstream issue — the real clock now ticks in FASE A
  too. The private elast_dc/eaccess_clock_dc clock is kept anyway (its
  job was never only to route around that freeze — it also snapshots
  pre-bump state so a call's own routing bump can't contaminate its own
  classification, and keeping DISK-CLASS's bookkeeping fully separate from
  stock elast state is what makes "byte-identical with PROF=0" provable
  by construction). Code comments referencing the old defect are updated to
  point at the fix instead of describing a bug that no longer exists.
• File references below updated from glm.c to colibri.c where applicable.

What this adds

One new PROF=1 line that splits every routing-driven demand expert load into cold
(not recently routed) vs warm (recently routed — plausibly still in the page cache)
and reports, per class and per profile window:

[PROF] DISK-CLASS (recency split): cold N x GG.GG GB @ T.TT GB/s-thread, wall WW.Ws @ A.AA GB/s-wall, avg-conc C.C (direct n/N) | warm ... | disk-busy S.Ss (P% of window)

Read the header literally: cold/warm is a RECENCY classification, not measured
page-cache residency. When we checked this heuristic against ground truth
(mincore() residency probing, separate experiment), the two disagreed on 41% of
classified loads. The split is stable and meaningful as a lens — the per-class
byte/time/concurrency numbers are exact regardless of the labels' semantics — but no
consumer should treat "warm" as "guaranteed cached" (which is also why this PR ships no
policy on top of it; see below). The (recency split) tag in the line itself is there
so a log reader can't miss this.

• loads / bytes per class (weights + scales, same convention as the expert I/O line);
• GB/s-thread — bytes / thread-seconds: the per-read service rate, on whichever
  thread ran the read (PIPE workers, OMP loaders);
• wall / GB/s-wall — a per-class busy-wall tracker (an in-flight counter whose
  0→1 transition stamps a start and whose 1→0 transition accumulates the interval) and
  bytes / busy-wall: the aggregate rate the disk actually delivered while at least one
  load of the class was in flight;
• avg-conc — thread-seconds / busy-wall: mean overlap depth of the class;
• direct n/N — how many of the class's loads were actually served by the uncached
  twin fd (under DIRECT=0 this reads 0/N for both classes and confirms the split is
  a pure page-cache-locality signal, not an fd artifact; under DIRECT=1 it shows what
  blanket direct is doing to each class);
• disk-busy — combined busy-wall (either class in flight) as a share of the profile
  window: the disk's demand-read duty cycle.

Zero behavior change: the fd choice is untouched, the line prints only under PROF=1
and only when classified loads exist, and with PROF off the instrumentation compiles
to a handful of untaken branches (verified by line-by-line inspection of every new
branch's gate in this revision — see Testing below; the original branch additionally
verified this empirically against a no-model baseline on caa49f7).

Why two rate units (the hard-won part)

Thread-second rates and wall-aggregate rates answer different questions, and using
one where the other is needed produces confidently wrong conclusions — we did it, which
is why the units are now in the field names. A class of N slow reads that overlap can
deliver more aggregate bandwidth than N fast reads that serialize; per-thread service
rates cannot see that. In our first measurement run the thread-second numbers appeared
to refute a hypothesis that the wall-aggregate numbers then confirmed was about
concurrency structure, not per-read speed. GB/s-thread tells you what one read costs;
GB/s-wall tells you what the disk is actually delivering; avg-conc is the bridge
(their ratio). All three are printed so no reader has to re-learn this the hard way.

Why measure this at all (motivation numbers, our logs)

On our reference setup (GLM-5.2 int4 on an M5 Max, macOS 26.5, model streamed from
NVMe), a 256-token decode window classified as: cold ~1062 GB (~71% of the 1491 GB
classified) at 14.2–14.5 GB/s-wall over a 73–75 s busy-wall at avg-conc ~3.3, with the
disk idle ~39% of the window (logs: our overnight R1 bracket runs, 2026-07-19). That one line characterizes decode as
near-serial — a cold-read phase at the disk's practical concurrency ceiling followed by
a compute phase with the disk parked — which is the load-bearing fact for any I/O
overlap or prefetch work on MoE streaming engines. Getting it previously required
DTrace-level tooling; now it is one PROF=1 run.

The classifier, and why it ships without a policy

Cold/warm is decided by a private per-expert recency clock (elast_dc,
eaccess_clock_dc), ticked at routing time in both FASE A paths, with a pre-bump
snapshot (elast_pre, guarded once-per-call by a touched[] bitmap) so prefill's giant
first-touch burst cannot classify itself warm off its own routing bump — a trap that
otherwise silently inverts the labels exactly where they matter most.

Two honest disclosures:

1. Why a private clock: at the time this was first written, the engine's real
   recency state (elast/eaccess_clock) was never bumped on the Metal pre-routed
   decode path — an upstream defect (Metal-decode LRU/repin recency ran on
   prefill-frozen scores). That defect has since been reported and fixed upstream
   ([Bug]: Metal — the LFRU recency clock freezes at prefill end; REPIN's tie-breaker runs on stale scores during decode #417, cfcc742 — FASE A now bumps the real clock too), so the private clock is no
   longer the only way to get correct per-mode recency. It is kept anyway: it also
   snapshots pre-bump state so a call's own routing bump can't contaminate its own
   classification (a separate concern from the freeze bug), and keeping DISK-CLASS's
   bookkeeping fully decoupled from stock elast state is what makes "PROF=0 is
   byte-identical" provable by construction rather than by argument against a shared,
   evolving array.
2. Why measurement WITHOUT policy: we also built and measured an fd-choice policy on
   top of this classifier (cold → uncached fd). It is not in this PR because the
   premise was refuted on our hardware — cold buffered reads were not the
   bottleneck — and because the recency heuristic itself, checked against page-cache
   ground truth (mincore() residency probing in a separate experiment), disagreed on
   41% of classified loads. A 41%-wrong signal is a fine lens (both units above are
   exact regardless — the split just has to be stable and meaningful, and cold-vs-warm
   recency is) but a poor steering wheel. The instrumentation earned its keep across
   ~15 measurement batteries; the policy did not survive one. Shipping the lens, not
   the wheel.

Durability map

• Durable (expected to hold anywhere): the instrumentation itself — per-class
  counters, the busy-wall/concurrency tracker and its pairing discipline (every
  dc_wall_enter paired on every exit path, including the non-fatal pread-failure
  unwinds), the two-unit reporting convention, the private-clock/pre-bump-snapshot
  classification scheme, the demand-only scoping (speculative/pin/repin loads pass
  demand=0 and are never classified — they don't run through the current call's
  routing, so the snapshot doesn't describe them).
• Current-state calibration (marked CURRENT-STATE CALIBRATION in the code, with
  coordinates): the default recency window COLI_DISKCLASS_WINDOW = topk*n_layers*8
  (~the last 8 tokens' worth of routing). Measured 2026-07 on macOS 26.5, M5 Max
  128 GB, engine base caa49f7 (the number itself was not re-measured for this
  re-derivation — it is a hardware/model measurement, not a code-base one, and stays
  valid regardless of which commit the instrumentation now sits on top of), GLM-5.2
  int4 (topk=8, n_layers=78), where it splits the classes cleanly (decode cold share
  ~71% of classified bytes). Other models/disks/page-cache regimes may want a different
  window; COLI_DISKCLASS_WINDOW overrides it, and the DISK-CLASS line itself is the
  tuning instrument.

Interface

• PROF=1 — enables classification + the line (no new env var needed for the common
  case).
• COLI_DISKCLASS_WINDOW=<ticks> — optional: recency window override, in ticks of the
  private clock (one tick per selected (position, expert) at routing). (Historical
  note for anyone cross-reading our measurement campaign's logs: those runs used this
  knob under its pre-upstream name COLI_DIRECT_HEAT; same semantics, renamed here to
  drop the collision with the unrelated DIRECT fd policy.)

Testing (this revision, re-derived onto 61004dc)

• make glm METAL=0 and make glm METAL=1: both clean under -Wall -Wextra, zero
  warnings — matches a from-scratch stock 61004dc build (also built for comparison,
  also zero warnings).
• make test-c: all C test binaries pass, 0 failures (includes tests/test_kv_alloc,
  tests/test_dsa_select, etc. — several link colibri.c directly).
• make test-python: 77 tests, OK.
• make metal-test: all 15 Metal kernel cases pass (Metal kernel-level tests;
  unrelated to this patch's code paths, run for general confidence). tests/test_backend_metal.mm
  is byte-identical to the caa49f7-era file (verified by hash), so this is not a
  rebase-induced change from the original branch's testing note — the case count
  is a property of unchanged test source.
• Byte-identical-with-PROF=0 claim verified by line-by-line code inspection in
  this revision (every new branch traced back to a dc_on/need_classify/
  dc_needed() gate, all of which reduce to g_prof, default 0) — not by an executed
  no-model smoke run, since this pass is instrumentation-only and does not execute the
  engine against a model. The original branch additionally verified this empirically
  (no-model smoke, output byte-identical to base caa49f7 for bare/PROF=1/
  COLI_DISKCLASS_WINDOW/DIRECT=1 invocations); an equivalent on-box empirical
  verification decode against 61004dc is expected to be run separately before merge.
• Busy-wall pairing and union/gap arithmetic were verified with a synthetic-timestamp
  replica during the original branch's development (overlap, cross-class union, gap
  exclusion, leaked-counter check) — unchanged by this re-derivation.
• MTP/speculative-decode disclosure: the private DISK-CLASS clock
  (elast_dc/eaccess_clock_dc) ticks at the same call sites and the same rate as
  the real recency clock (elast/eaccess_clock) by construction — same loop
  iterations in both FASE A paths, one tick per selected (position, expert) — so
  MTP/speculative-decode tick patterns are mirrored exactly between the two clocks
  and there is no MTP-specific divergence channel between them. This is a
  by-construction property reviewed in code audit (the tick call sites are visibly
  paired in moe()), not an empirically tested claim — no MTP decode run was
  executed to confirm it at runtime.

On-box verification decode (2026-07-19, M5 Max 128 GB, macOS 26.5, base 61004dc)

This completes the empirical check the Testing section above deferred to a separate
run. Branch 1f00142, METAL=1, GLM-5.2 int4, cap 16, ngen 32:

• PROF=1: the DISK-CLASS line prints with physically consistent values:
  cold 7366 x 139.33 GB @ 4.30 GB/s-thread, wall 9.0s @ 15.51 GB/s-wall, avg-conc 3.6 | warm 2837 x 53.66 GB @ 11.17 GB/s-thread, wall 2.9s @ 18.54 GB/s-wall, avg-conc 1.7 | disk-busy 9.1s (58% of window) — in line with the caa49f7-era measurements
  (cold ~4.0–4.3 GB/s-thread; ~61% duty cycle).
• Gate-off, same binary: zero DISK-CLASS output; generated prose byte-identical
  to the PROF=1 run (md5 after excising instrumentation/status lines).
• Usage-file snapshot/restore md5-verified around both runs.

🤖 Generated with Claude Code