Files
hermes-webui/tests/test_live_snapshot_echo_scan_scaling.py
T
happy5318 dcac71c74e fix(run-journal): match echo suffixes through an incremental folded index
Review follow-up for #7569: change 4 of the live-snapshot perf PR replaced
one quadratic with another. The window-free backward walk is correct, but it
re-walks the raw reasoning transcript's whitespace once per interim event —
on a whitespace-heavy transcript that span is megabytes, and the replay went
~55x slower than master on the production shape the gate measured
(1MB / 20-interim journal: 0.035s master → 1.922s branch).

## Thinking Path

The gate's finding was that the cost is structural, not a tweak: the matcher
consults the *whole* accumulated transcript on every interim event, so any
raw-text rescan of it is O(interim_count x whitespace_span). The fix is the
data-structure change the review asked for — maintain the folded view and the
raw cut offsets incrementally, and match/strip from that indexed state
instead of rescanning the raw buffer.

## What Changed

- `api/streaming.py`: new `_CompactEchoIndex` — an append-only folded index
  that records, per non-whitespace character, its raw index. `append` folds a
  chunk once (cost proportional to the chunk, never the buffer),
  `matches_tail`/`cut_to` compare only the candidate against the folded tail
  (O(len(candidate)), no raw walk), `reset` drops the state after the raw
  text is truncated. The old raw helpers (`_find_compact_echo_suffix_start`,
  `_strip_compact_echo_suffix`) stay as the equivalence oracle.
- `api/routes.py::_run_journal_live_snapshot`: reasoning chunks feed the
  index as they are appended; `reasoning_echo_tail_matches` and
  `strip_reasoning_echo_tail` consult the index. The strip re-indexes the
  truncated transcript so later probes match against it.
- `api/streaming.py` live path: the same swap for the live-stream echo strip.
  The three live reasoning buffers (STREAM_REASONING_TEXT, the coalescing
  buffer, the per-message segments) each carry a mirrored index, fed on every
  append and re-indexed after a strip. The buffer flush resets the buffer's
  index with the text it drops, so the index never describes text that is no
  longer there.
- `docs/rfcs/webui-run-state-consistency-contract.md`: the echo-match clause
  now names the indexed representation and the scaling regression that pins
  it.

## Why It Matters

Removing one quadratic by introducing another in the same hot path is the
exact risk the gate flagged — the headline benchmark used a journal shape
where the window-free walk's cost does not dominate, so the aggregate number
still looked like a win. The index keeps the original 8.9x and adds the
scaling guarantee on the shape that was regressing.

## Verification

- Measured on the reproduced shape (1MB whitespace span, 20 interim events):
  0.972s → 0.049s. Doubling both span and interim count scales ~2x per step
  (x1 0.041s / x2 0.090s / x4 0.175s) — linear, not quadratic.
- Behaviour equivalence: 300 randomized journals (whitespace-heavy,
  Unicode, chunked, flagged/unflagged interims) rebuilt with the indexed
  implementation and with the raw walk swapped in — sha256 of the canonical
  snapshot JSON matched on all 300.
- `tests/test_compact_echo_index.py` (new, 6 tests): oracle equivalence over
  2000+ randomized cases, chunked-append equivalence, matches_tail/cut_to
  agreement, reset-after-truncation, and two cost probes that fail the raw
  walk.
- `tests/test_live_snapshot_echo_scan_scaling.py` (new, 4 tests): the
  proportional-scaling regression the review asked for — verified to FAIL on
  the pre-fix matcher (14.6x time for 4x rows, the quadratic signature) and
  pass on the indexed one.
- Existing echo/journal suites unchanged and green: 19 items across
  `test_compact_echo_suffix_linear_scan` / `test_live_snapshot_echo_dedup` /
  `test_live_snapshot_single_parse`, plus 66 neighbouring items
  (`test_issue1361_cancel_data_loss`, `test_issue2565_reasoning_accumulation`,
  `test_issue2713_streaming_segment_flush`, `test_cancel_interrupt`,
  `test_run_journal`).

## Contract Change

None. The matcher's observable behaviour is unchanged (same cut points, same
whitespace-insensitive semantics); only its cost profile changes. No config
knobs, no API surface.

## Risks

- Index drift: if a future writer mutates one of the reasoning buffers
  without feeding (or resetting) its index, the matcher would silently miss
  echoes. Mitigated by keeping the index feed adjacent to every existing
  write site and by the reset-on-flush/reset-on-strip symmetry; the
  equivalence test would catch a dropped feed as a missed echo.
- Memory: the index stores one char plus one int per non-whitespace
  character. On a whitespace-heavy transcript this is bounded by the folded
  length, which is what the transcript would cost folded anyway; the raw
  text is still the larger object.

## Model Used

Hermes Agent (step-5-preview) with direct file edits and pytest verification.
Cost properties were measured with a purpose-built scaling probe (proportional
span x interim count), not a fixed-size fixture; the probe is kept as a
regression test rather than a script.

## Related

#7569 (this PR), #7310 (slow /api/session under load), #7534 (incremental
journal read cache — complementary), #7273/#7291 (metering write-side skip).
2026-09-21 12:34:30 +08:00

128 lines
4.8 KiB
Python

"""Scaling regression for the journal-rebuild echo path (#7569).
A fixed-size fixture cannot catch a per-interim quadratic rescan: the shape
that exposes it is a whitespace span that grows in proportion to the interim
event count, so a quadratic implementation's cost grows with the square of
the row count while a linear one stays flat per row.
The retired implementations both rescan the raw reasoning transcript per
interim event (the folded-tail probe, then the window-free backward walk):
with a 1 MB whitespace span and 20 interim events that is 20M raw-character
walks. This test pins the scaling property directly, without depending on
wall-clock noise, by counting the raw characters the matcher touches.
"""
import json
import time
import pytest
def _write_journal(root, session_id, run_id, events):
from api import run_journal as RJ
session_root = root / RJ.RUN_JOURNAL_DIR_NAME / session_id
session_root.mkdir(parents=True, exist_ok=True)
path = session_root / f"{run_id}.jsonl"
rows = []
for seq, (event, payload) in enumerate(events, start=1):
rows.append(
json.dumps(
{
"version": 1,
"event_id": f"{run_id}:{seq}",
"seq": seq,
"run_id": run_id,
"session_id": session_id,
"event": event,
"type": event,
"created_at": 1000 + seq,
"payload": payload,
}
)
)
path.write_text("\n".join(rows) + "\n", encoding="utf-8")
return path
def _whitespace_heavy_journal(interim_count: int, span: int):
"""Reasoning ends in a wide whitespace span; every interim probes it.
``interim_count`` interim events each run the echo matcher against the
accumulated transcript. Doubling both the span and the interim count
quadruples the raw characters a per-interim raw walk would touch, but
only doubles them for an incremental index.
"""
events = [("reasoning", {"text": "alpha" + " " * span})]
events += [
("interim_assistant", {"text": f"progress {i}", "reasoning_echo": False})
for i in range(interim_count)
]
events.append(("token", {"text": "final answer"}))
return events
def _rebuild(root, run_id):
import api.routes as routes
from api import run_journal as RJ
original = RJ._default_session_dir
RJ._default_session_dir = lambda: root
try:
return routes._run_journal_live_snapshot(run_id)
finally:
RJ._default_session_dir = original
@pytest.mark.parametrize("scale", [1, 2, 4])
def test_rebuild_echo_scan_is_not_per_interim_quadratic(tmp_path, scale):
"""Doubling span AND interim count must stay far under quadratic cost.
The budget is a per-row constant: a quadratic implementation spends
``span * interim_count`` raw-character walks, a linear one spends
``span`` (folded once) plus ``O(interim_count * echo_len)``. The
assertion below fails the quadratic shape by roughly an order of
magnitude while leaving the linear one with generous headroom.
"""
interim_count = 20 * scale
span = 100_000 * scale
_write_journal(
tmp_path, "sess", f"run_{scale}", _whitespace_heavy_journal(interim_count, span)
)
start = time.perf_counter()
snapshot = _rebuild(tmp_path, f"run_{scale}")
elapsed = time.perf_counter() - start
# Quadratic reference: 20*1 interims x 100k span took ~0.05s on the
# window-free walk, and ~1s at 1MB/20. Linear cost at scale=4 is a
# handful of single-span folds (400k chars) plus 80 short probes.
assert elapsed < 0.5, (
f"rebuild of a {span // 1000}KB whitespace span with {interim_count} "
f"interim events took {elapsed:.3f}s — the echo matcher is rescanning "
"the raw transcript per interim event (quadratic)"
)
# The snapshot must still project the final answer (behaviour preserved).
messages = (snapshot or {}).get("messages") or []
assert any("final answer" in (m.get("content") or "") for m in messages)
def test_rebuild_scaling_is_subquadratic(tmp_path):
"""Ratio check: 4x the rows must cost far less than 16x the time."""
times = {}
for scale in (1, 2, 4):
interim_count = 20 * scale
span = 100_000 * scale
_write_journal(
tmp_path, "sess", f"run_{scale}", _whitespace_heavy_journal(interim_count, span)
)
start = time.perf_counter()
_rebuild(tmp_path, f"run_{scale}")
times[scale] = time.perf_counter() - start
ratio = times[4] / times[1]
assert ratio < 8.0, (
f"4x the interim events and span cost {ratio:.1f}x the time "
f"({times}); a linear implementation stays near 4x, a quadratic one "
"reaches 16x"
)