[v0.9.0] SSD complete-checkpoint stage blocks TTFT 18s on warm 128GB M5 Max (RAM prefix off)

Summary

Provider 0.9.0 on a 128 GB M5 Max. Models already warm. TTFT jumped from <1000 ms to 18304 ms on a live request.

This is the read-side of #865. Donate writes hitch the box; a “cache hit” then stages a ~1 GB encrypted complete checkpoint from SSD before token 1. Resident RAM prefix cache is default-off, so a hit is not a RAM lookup.

Docs already admit the scheduler will still attempt the longest SSD checkpoint even when restore costs more than cold prefill (cache-aware-routing.md: no prefill-time comparison that bypasses an expensive hit). That showed up here as an 18 s first-token wait, not a slightly worse TTFT.

Environment

Same host as #865.

Weights were not reloaded (loaded-models.json mtime still 18:11; process elapsed ~2.5 h). This is not a cold start.

Actual

Operator-observed TTFT: 18304 ms (was <1000 ms on comparable warm requests).

On-disk complete checkpoints under ~/Library/Caches/darkbloom/kv3/ (one model dir 0f93c2b77540, ~1.9 GB):

20:23:25  1071.40 MB  e0….dbk3
20:23:25   215.46 MB  02….dbk3
20:32:06   114.75 MB
20:32:10   165.10 MB
20:32:14   215.46 MB
20:32:14   265.81 MB

provider.log still only logs WeightHasher. No stage-ms, no donation outcome, no TTFT. First operator signal is the 18 s wait.

Related: #865 disk-writes diagnostic at 20:09 (SSDHybridCheckpointStore.write → write(2)). Same consume pipeline.

Expected

On a warm 128 GB M5 Max:

1. A prefix-cache “hit” must not take 18 s to first token.
2. If the only stored prefix is a ~1 GB SSD complete checkpoint, skip it (or cap stage time) and cold-prefill. Sub-1 s was already happening without restore.
3. Do not prefer longest checkpoint when full_external_stage_ms blows past avoidable prefill. The cost model already computes restore_penalty; the provider still executes the expensive hit anyway (SSDHybridCheckpointStore.stage).
4. Log stage bytes, stage ms, donation outcome, and whether the attempt was SSD vs cold — in provider.log, not only coordinator gauges.

Why this is the restore path

• Resident L1 requires DARKBLOOM_PREFIX_CACHE_MEMORY=1. Unset → no RAM bank between requests.
• SSD L2 defaults on for these two Qwen ids (PrefixCachePolicy.isEnabled).
• Cache routing is on in production (10% cohort, 3-artifact allowlist includes this Qwen pair). A participating request can be sent back to the holder that just donated.
• Stage is SSDHybridCheckpointStore+Read.swift (stage): authenticate + decrypt + import into paged KV before decode. That sits in front of TTFT.
• gpu_memory_cache_gb dropping to 0 after the slow window is consistent with a large native import / cache flush, not with a 35B weight reload.

Ask

• Bound or skip SSD complete-checkpoint stage when estimated stage ms > remaining prefill ms (or > a hard TTFT budget, e.g. 1 s).
• Keep restore off the Interactive decode path; Utility QoS / async, fail open to cold prefill.
• Emit stage-ms and outcome locally so 18 s TTFTs are attributable without Console.app.

See also #865 (write-side hitch on the same store).

Start with SSDHybridCheckpointStore+Read.swift, especially stage, and trace how PrefixCachePolicy.isEnabled and restore_penalty lead to a staged checkpoint before decode. Read cache-aware-routing.md and inspect the provider logging path. Done means expensive SSD restores no longer block the Interactive path, cold-prefill fallback is observable, and stage bytes, timing, and outcome appear in provider.log.