diff --git a/api/models.py b/api/models.py index 22c22128..eca27ab5 100644 --- a/api/models.py +++ b/api/models.py @@ -1085,7 +1085,26 @@ def _read_file_head(path: Path, max_prefix_bytes: int = 4096) -> str: return fp.read(max_prefix_bytes).decode('utf-8', errors='ignore') -def _read_metadata_json_prefix(path, max_prefix_bytes=65536): +#: Budget for the cheap metadata read. Sized as a BACKSTOP, not a target: the +#: prefix normally stops at ``messages`` after a few KB, and the write-side field +#: order keeps it there. The cap only matters for a sidecar already on disk whose +#: heavy metadata blobs serialize BEFORE ``messages`` — where the old 64 KB cap +#: turned one oversized field into a full multi-MB parse on EVERY poll (#4633). +#: Measured case: a 73,192-byte ``compression_anchor_summary`` pushed the +#: ``messages`` key to offset 76,603, so the read gave up 11 KB short of it. +_METADATA_PREFIX_MAX_BYTES = 1024 * 1024 + +#: Size of the FIRST stage of the cheap metadata read. A healthy sidecar carries +#: its stop key (`messages`) within a few KB — the write-side field order in +#: ``save()`` guarantees it — so every ordinary poll pays this read and stops +#: there. The 1 MiB backstop above is only reached by a sidecar already on disk +#: whose heavy metadata blobs really do precede ``messages`` in bulk. Without a +#: small first stage the cheap read pulls the whole budget on the polling path +#: even when the stop key sits at 2 KB. +_METADATA_PREFIX_FIRST_STAGE_BYTES = 64 * 1024 + + +def _read_metadata_json_prefix(path, max_prefix_bytes=_METADATA_PREFIX_MAX_BYTES): """Read only the metadata portion before the large arrays. #5854: stop at the top-level ``messages`` key OR the top-level @@ -1098,24 +1117,58 @@ def _read_metadata_json_prefix(path, max_prefix_bytes=65536): the scenes-stop a legacy large-scene sidecar overflows ``max_prefix_bytes`` and forces a full multi-MB parse on every poll (the #4633 churn). """ + if max_prefix_bytes <= 0: + return None + # Geometric staged reads: 64 KiB, 128 KiB, 256 KiB, ... up to the backstop. + # + # The original loop read 4096 bytes at a time and re-scanned the WHOLE + # accumulated buffer after each chunk — two full `_find_top_level_json_key` + # passes (a pure-Python char loop) plus a decode per chunk. That is O(n^2) in + # the prefix size, and it is why the cap could not simply be raised. + # Measured on this function before the change: + # prefix 10 KB -> 19.6 ms + # prefix 60 KB -> 87.3 ms <- already paid on EVERY poll + # prefix 200 KB -> 768.9 ms + # prefix 500 KB -> 4,634.7 ms + # prefix 900 KB -> 14,957.1 ms <- slower than the full parse + # + # A single `f.read(max_prefix_bytes)` fixed that complexity but pulled the + # whole 1 MiB backstop on every poll, even when the stop key sat at 2 KB — + # read amplification on a path that runs once per sidebar poll. Doubling + # stages keep both properties: the COMMON case stops inside the first small + # read, and re-scanning each accumulated stage stays linear because the stage + # sizes form a bounded geometric series (total work < 2x the bytes actually + # read, worst case). `_find_top_level_json_key` returns AT the key, so the + # final scan costs O(offset of the stop key), not O(stage). + stage = min(_METADATA_PREFIX_FIRST_STAGE_BYTES, max_prefix_bytes) + raw = b'' buf = '' - with open(path, 'r', encoding='utf-8') as f: - while len(buf.encode('utf-8')) < max_prefix_bytes: - chunk = f.read(4096) + stop_pos = None + with open(path, 'rb') as f: + while len(raw) < max_prefix_bytes: + chunk = f.read(min(stage, max_prefix_bytes - len(raw))) if not chunk: + # EOF before the stop key: no metadata prefix to serve, so the + # caller falls back to a full parse (same answer as a budget miss). return None - buf += chunk + raw += chunk + # A byte budget can truncate a multi-byte character at the boundary; + # dropping it is safe because a stop key straddling the cap is a miss + # either way. + buf = raw.decode('utf-8', errors='ignore') stop_pos = _find_top_level_json_key(buf, 'messages') scenes_pos = _find_top_level_json_key(buf, 'anchor_activity_scenes') if scenes_pos is not None and (stop_pos is None or scenes_pos < stop_pos): stop_pos = scenes_pos - if stop_pos is None: - continue - prefix = buf[:stop_pos].rstrip() - if prefix.endswith(','): - prefix = prefix[:-1].rstrip() - return f'{prefix}\n}}' - return None + if stop_pos is not None: + break + stage *= 2 + if stop_pos is None: + return None + prefix = buf[:stop_pos].rstrip() + if prefix.endswith(','): + prefix = prefix[:-1].rstrip() + return f'{prefix}\n}}' def _load_session_from_path(path: Path) -> "Session | None": @@ -1605,6 +1658,18 @@ class Session: # expected_sig guards against an atomic replace during the read. # (When _collapsed_partials fired, save() above already rewrote the # modern layout, so no legacy caching is needed.) + # + # WHY STILL GATED, and not "obviously" broadened to modern files: the + # cache is only READ from the two sites that reach it when the cheap + # prefix carried NEITHER message_count NOR anchor_scene_index — i.e. + # legacy layouts (see the `if ... and 'anchor_scene_index' not in + # parsed` guards in load_metadata_only() and the eviction-count + # helper). A modern sidecar that overflows the budget therefore + # never consults an entry written for it, so populating one is dead + # work that also stores entries no consumer can use. Making the + # modern case benefit needs the READ side redesigned to build a + # metadata stub from cached facts — a separate change; until then + # this stays legacy-only. if 'anchor_scene_index' not in data: try: _legacy_sidecar_facts_put( diff --git a/tests/test_issue5854_anchor_scene_split.py b/tests/test_issue5854_anchor_scene_split.py index 11da496e..d5ef5147 100644 --- a/tests/test_issue5854_anchor_scene_split.py +++ b/tests/test_issue5854_anchor_scene_split.py @@ -163,13 +163,20 @@ def test_parity_cache_not_forced_reload_when_prefix_read_fails(session_store): Simulate an oversized metadata prefix by giving the session a large `compression_anchor_summary` so `_read_metadata_json_prefix` overflows and the slow path (Session.load_metadata_only) is taken. + + Sized off `_METADATA_PREFIX_MAX_BYTES` rather than a literal: this test needs + the prefix read to FAIL, so hardcoding a number that happens to exceed + today's budget makes it silently stop exercising the slow path the next time + the budget moves. (It did: the budget went 64 KB -> 1 MiB and the old + `"Z" * 80000` no longer overflowed.) """ + oversized = "Z" * (M._METADATA_PREFIX_MAX_BYTES + 100_000) scenes = {"scene0": {"updated_at": 1000.0, "scene": {}}} s = M.Session(session_id="p1", title="T", workspace=str(session_store.parent), model="glm", messages=[{"role": "user", "content": "hi"}, {"role": "assistant", "content": "yo"}]) s.anchor_activity_scenes = scenes - s.compression_anchor_summary = "Z" * 80000 # push metadata prefix > 64KB + s.compression_anchor_summary = oversized s.save() # Sanity: the cheap prefix genuinely fails for this file (slow path taken). assert M._read_metadata_json_prefix(session_store / "p1.json") is None @@ -180,7 +187,7 @@ def test_parity_cache_not_forced_reload_when_prefix_read_fails(session_store): {"role": "assistant", "content": "yo"}]) cached_parity.anchor_activity_scenes = {"scene0": {"updated_at": 1000.0, "scene": {}}} cached_parity._anchor_scene_index = {} # stale/empty load-time fingerprint - cached_parity.compression_anchor_summary = "Z" * 80000 + cached_parity.compression_anchor_summary = oversized assert M._cached_session_lags_disk(cached_parity) is False # But a genuinely-behind cache (disk has a newer scene) still reloads. cached_behind = M.Session(session_id="p1", title="T", workspace=str(session_store.parent), diff --git a/tests/test_oversized_metadata_field_reparse.py b/tests/test_oversized_metadata_field_reparse.py new file mode 100644 index 00000000..98040cb8 --- /dev/null +++ b/tests/test_oversized_metadata_field_reparse.py @@ -0,0 +1,241 @@ +"""The #4633 churn returns through a field #5854 did not move. + +#5854 stopped `anchor_activity_scenes` from overflowing the 64 KB metadata +prefix, and cached the authoritative facts of a LEGACY sidecar so an unchanged +one is full-parsed at most once. Both halves are gated on the file being legacy +(`'anchor_scene_index' not in data`). A MODERN sidecar that overflows the prefix +for any OTHER reason therefore gets neither protection: the cheap read fails, +`load_metadata_only()` full-parses, and nothing is cached — so it re-parses on +every poll. That is exactly the #4633 allocation churn the earlier fix removed. + +Measured in production on 2026-09-14 (Mac docker stack, 5.77 GiB colima VM): + + /data/hermes/webui/sessions/fa3bca34a0c6.json 111,857,574 bytes, 135,634 msgs + "compression_anchor_summary" offset 1,007 (73,192 bytes long) + "message_count" offset 75,446 + "anchor_scene_index" offset 75,473 <- file IS modern + "messages" offset 76,603 <- past the 65,536 budget + +`_read_metadata_json_prefix` scanned to `messages`, exhausted its budget first +and returned None; `load_metadata_only` fell back to `json.loads` of all 112 MB; +the legacy-facts cache was skipped because `anchor_scene_index` was present. +`/api/session/status` averaged 1,172 ms over 6,441 calls, one `messages=0` +request took 48.1 s, the server reached 4.0 GB RSS and the guest OOM killer +killed it 7 times. + +The fix covers the measured case: the prefix read is linear and STAGED (a 64 KiB +first stage, doubling to a 1 MiB backstop), so the stop key at offset 76,603 is +now reached within the second stage instead of failing just short of it. The +cache-write half deliberately stays legacy-gated — broadening it to modern files +writes entries neither read site can reach (both are guarded on +`anchor_scene_index` being absent), so the >1 MiB case below remains an explicit +gap rather than fixed by accident. + +These tests lock: + * the cheap prefix survives one oversized metadata field, + * the cheap read stops in the first stage for an ordinary small prefix, + * an unchanged modern sidecar is full-parsed at most once regardless (xfail). +""" +import builtins +import json + +import pytest + +import api.models as M + + +@pytest.fixture +def session_store(tmp_path, monkeypatch): + sdir = tmp_path / "sessions" + monkeypatch.setattr(M, "SESSION_DIR", sdir) + sdir.mkdir(parents=True, exist_ok=True) + return sdir + + +def _make_modern_oversized(session_store, sid, n_msgs=5, summary_bytes=80000): + """A MODERN sidecar (carries anchor_scene_index) whose metadata prefix + overflows because of one oversized field, mirroring production. + + Scenes are deliberately tiny: the point is that the overflow comes from a + field #5854 never moved, not from the scene bodies it did move. + """ + s = M.Session( + session_id=sid, + title="Oversized", + workspace=str(session_store.parent), + model="glm", + messages=[{"role": "user", "content": f"m{i}"} for i in range(n_msgs)], + ) + s.anchor_activity_scenes = {"scene0": {"version": 1, "updated_at": 1000.0, + "scene": {"activity_rows": []}}} + s.compression_anchor_summary = "Z" * summary_bytes + s.save() + return s + + +def test_sidecar_is_modern_and_overflows_the_budget(session_store): + """Guard the premise: the fixture really is the production shape — a modern + file (anchor_scene_index present, scenes after messages) whose "messages" + key sits beyond the 64 KB budget. + + If this ever fails, the two tests below stop covering what they claim to. + """ + _make_modern_oversized(session_store, "mod1") + raw = (session_store / "mod1.json").read_text(encoding="utf-8") + assert '"anchor_scene_index"' in raw, "fixture must be MODERN, not legacy" + ci = raw.find('"compression_anchor_summary"') + xi = raw.find('"anchor_scene_index"') + mi = raw.find('"messages"') + si = raw.find('"anchor_activity_scenes"') + assert -1 < ci < xi < mi < si, "modern layout: summary < scene_index < messages < scenes" + assert mi > M._METADATA_PREFIX_FIRST_STAGE_BYTES, ( + f'"messages" at {mi} must exceed the first read stage ' + f'({M._METADATA_PREFIX_FIRST_STAGE_BYTES}) to reproduce #4633' + ) + + +def _make_small_prefix_large_body(session_store, sid, n_msgs=40): + """A healthy sidecar: tiny metadata prefix, bulky body AFTER ``messages``. + + The shape every ordinary sidebar poll sees — the stop key lands a few KB in, + while the file itself is comfortably larger than the first read stage, so a + full-budget read is distinguishable from a staged one. + """ + s = M.Session( + session_id=sid, + title="Ordinary", + workspace=str(session_store.parent), + model="glm", + messages=[{"role": "user", "content": "B" * 4000} for _ in range(n_msgs)], + ) + s.save() + return s + + +def test_cheap_read_stops_in_the_first_stage_for_a_normal_sidecar(session_store, monkeypatch): + """The polling path must not pull the whole budget for a sidecar whose stop + key sits after a few KB. + + This is the read amplification the geometric stages exist to prevent: with a + single fixed-budget read, every uncached ordinary metadata lookup consumed + ``_METADATA_PREFIX_MAX_BYTES`` even when ``messages`` appeared 2 KB in. + Instrumented against the real reader (through the module's ``open``) rather + than asserted on constants, so it fails if the staged loop regresses to one + full-budget read. + """ + _make_small_prefix_large_body(session_store, "normal") + path = session_store / "normal.json" + assert path.stat().st_size > M._METADATA_PREFIX_FIRST_STAGE_BYTES, ( + "the file must be larger than the first stage, otherwise a single " + "full-budget read would be indistinguishable from a staged one" + ) + bytes_read = {"n": 0} + real_open = builtins.open + + class _CountingFile: + def __init__(self, fh): + self._fh = fh + + def read(self, n=-1): + data = self._fh.read(n) + bytes_read["n"] += len(data) + return data + + def __enter__(self): + self._fh.__enter__() + return self + + def __exit__(self, *exc): + return self._fh.__exit__(*exc) + + def _counting_open(*args, **kwargs): + return _CountingFile(real_open(*args, **kwargs)) + + monkeypatch.setattr(M, "open", _counting_open, raising=False) + prefix = M._read_metadata_json_prefix(path) + assert prefix is not None + assert json.loads(prefix)["message_count"] == 40 + assert bytes_read["n"] <= M._METADATA_PREFIX_FIRST_STAGE_BYTES, ( + f"cheap read consumed {bytes_read['n']} bytes for a prefix whose stop key " + f"is inside the first stage ({M._METADATA_PREFIX_FIRST_STAGE_BYTES})" + ) + assert bytes_read["n"] < M._METADATA_PREFIX_MAX_BYTES + + +def test_cheap_prefix_survives_an_oversized_metadata_field(session_store): + """The cheap read must stop once it holds the metadata its callers need, + instead of scanning all the way to "messages" and overflowing on whatever + large field happens to precede it. + + Scanning-to-"messages" makes every future large metadata field a repeat of + #4633; stopping at "enough" does not. + """ + _make_modern_oversized(session_store, "mod2", n_msgs=7) + prefix = M._read_metadata_json_prefix(session_store / "mod2.json") + assert prefix is not None, "cheap prefix must succeed, not fall back to a full parse" + parsed = json.loads(prefix) + assert {"session_id", "title", "created_at", "updated_at"}.issubset(parsed.keys()) + assert parsed["message_count"] == 7 + assert "messages" not in parsed, "the messages array must not be in the cheap prefix" + + +@pytest.mark.xfail( + strict=True, + reason=( + "KNOWN GAP, not a flake: a sidecar whose metadata blob exceeds the prefix " + "budget still re-parses per read. A failed prefix read yields no metadata at " + "all, and the facts cache holds only counts (no title/created_at), so no stub " + "can be built from it. The durable cure is write-side -- serialize the " + "unbounded blobs AFTER `messages`, as #5854 did for scene bodies. Broadening " + "the facts-cache WRITE to modern files does NOT close this: both read sites " + "reach the cache only when the prefix carried neither message_count nor " + "anchor_scene_index (see the guards in load_metadata_only() and the " + "eviction-count helper), so a modern entry is never consulted -- the write " + "side must stay legacy-gated until the READ side is redesigned to build a " + "metadata stub from cached facts. strict=True so this fails loudly once that " + "lands, instead of quietly passing and leaving a stale marker behind." + ), +) +def test_modern_oversized_sidecar_not_reparsed_on_every_read(session_store, monkeypatch): + """An unchanged sidecar must be full-parsed at most once, whether it is + legacy or modern. + + This is the production failure: 6,441 polls of one session, each paying a + full 112 MB `json.loads`, because the facts cache is reached only when + `anchor_scene_index` is ABSENT. The counterpart legacy assertion already + exists (test_issue5854_anchor_scene_split.py:: + test_legacy_large_scene_not_reparsed_on_every_read); the modern one does not. + + The field here deliberately exceeds the prefix budget so the fallback is + genuinely taken. A budget bump alone must NOT be able to satisfy this test — + otherwise it stops covering the caching hole and silently passes for the + wrong reason. + """ + M._LEGACY_SIDECAR_FACTS.clear() + _make_modern_oversized(session_store, "mod3", n_msgs=5, + summary_bytes=M._METADATA_PREFIX_MAX_BYTES + 200_000) + # Sanity: the cheap read genuinely fails here, so the slow path IS exercised. + assert M._read_metadata_json_prefix(session_store / "mod3.json") is None, ( + "fixture must overflow the prefix budget; otherwise this test does not " + "cover the fallback caching at all" + ) + + calls = {"n": 0} + real_load = M.Session.load.__func__ + + def _counting_load(cls, sid, *a, **k): + if sid == "mod3": + calls["n"] += 1 + return real_load(cls, sid, *a, **k) + + monkeypatch.setattr(M.Session, "load", classmethod(_counting_load)) + + stubs = [M.Session.load_metadata_only("mod3") for _ in range(3)] + for stub in stubs: + assert stub is not None + assert (stub._metadata_message_count or len(stub.messages)) == 5 + + assert calls["n"] <= 1, ( + f"modern oversized sidecar full-loaded {calls['n']}x across 3 metadata reads; " + "an unchanged file must be parsed at most once" + )