diff --git a/scripts/recovery_e2e.py b/scripts/recovery_e2e.py index 7ad87787..955d31e1 100644 --- a/scripts/recovery_e2e.py +++ b/scripts/recovery_e2e.py @@ -27,19 +27,21 @@ the page asserts the final DOM has the expected top-level tool rows, the task_agent card nests its sub-tool rows (NO child escaped to the top level), and the composer settles idle. Stamps ``RECOVERY-READY-STORM-``. -Scenario B (hide -> restart -> show): the page runs a turn, the runner -hides the tab (interactive.js closes the stream), restarts the node on the -SAME port (fresh empty ring, storage-seeded counter), then shows the tab; -the pane reconnects to the restarted node, the committed transcript stays -intact, and the composer settles idle. Stamps ``RECOVERY-READY-RESTART``. - -The specific ``replay_truncated`` envelope is NOT asserted at the browser -level here: it needs a browser cursor below the restarted node's seeded -counter, and Chrome's ``EventSource`` tracks that cursor internally only on -its native auto-reconnect (not on the close-on-hide reconnect, which opens -a fresh stream). The truncated -> lost_count -> /history-cursor rebuild is -proven deterministically at the server-contract level in Tier 1's -``test_restart_truncated_honesty`` / ``test_failed_resync_retries_via_truncation_record``. +Scenario B (hide mid-turn -> restart -> show): the runner hides the tab +the moment the first streamed line paints (freezing the pane's cursor at +a mid-turn event id — the MessageEvent ``lastEventId`` capture is what +makes that cursor real; the pre-2026-07 object-form read left it null and +this whole path unassertable), lets the turn and a follow-up text commit +while hidden, restarts the node on the SAME port (fresh empty ring, +storage-seeded counter), then shows the tab. The show-edge reconnect +presents the stale cursor, MUST draw ``replay_truncated`` (asserted: +trunc>=1), the truncated resync rebuilds from /history, and the turns +committed during the hide window MUST be present afterwards (asserted: +``healed`` — the 'turn disappeared' field symptom). Stamps +``RECOVERY-READY-RESTART-rows-trunc``. The exact ``lost_count`` +arithmetic and the failed-resync retry stay at the server-contract level +in Tier 1's ``test_restart_truncated_honesty`` / +``test_failed_resync_retries_via_truncation_record``. A NOTE ON THE BROWSER OVERFLOW (server-side poison): a real listener-queue poison needs the browser to STOP reading the socket so TCP backpressure @@ -81,6 +83,13 @@ from typing import Any sys.path.insert(0, str(Path(__file__).resolve().parent.parent)) +# Healed-gap sentinel for scenario B: injected as the scripted turn-2 text +# AND threaded to the page via ``?healed=`` (read into ``healedSentinel``), +# so the injected text and the DOM check share one definition. Must never +# collide with rendered command/output text — the bash command row paints +# its shell source verbatim, which contains the keyword ``done``. +HEALED_SENTINEL = "HEALED-e5b1" + # --------------------------------------------------------------------------- # The recovery page — served same-origin by the node at /recovery. # --------------------------------------------------------------------------- @@ -117,6 +126,9 @@ PAGE_HTML = r""" const wsId = q.get("ws_id"); const scenario = q.get("scenario") || "storm"; const expectRows = parseInt(q.get("rows") || "4", 10); + // Healed-gap sentinel, threaded from the runner (HEALED_SENTINEL) + // so the injected turn text and this check cannot drift apart. + const healedSentinel = q.get("healed") || ""; // REAL pane against THIS origin (base=""): real authFetch (cookie) and // real EventSource. The default host provides all SSE seams. @@ -212,24 +224,41 @@ PAGE_HTML = r""" return origHandle(ev); }; window.__verifyRestart = function () { - // Browser-level restart RECOVERY: after the node restarts on the - // same port, the pane reconnects (status bar not stuck - // disconnected), the committed transcript is intact, and the - // composer settles idle. (The specific ``replay_truncated`` - // envelope requires a browser cursor below the restarted node's - // seeded counter; Chrome's EventSource tracks that cursor - // internally only on its native auto-reconnect, so it is proven - // deterministically at the server-contract level in Tier 1's - // test_restart_truncated_honesty. ``__truncatedSeen`` is recorded - // here for the runs where it does fire.) + // Browser-level restart RECOVERY, full contract: the runner hid + // the tab MID-turn (cursor frozen below the commits that land + // while hidden), so the show-edge reconnect must present the + // stale cursor and draw ``replay_truncated`` (REQUIRED since the + // MessageEvent lastEventId capture fix — the pre-fix object-form + // read left manual reconnects cursorless and this envelope + // unreachable, which is why trunc used to report 0), the + // truncated resync must rebuild from /history, and the turns + // committed DURING the hide window must be present afterwards + // (``healed`` — the 'turn disappeared' field symptom). Composer + // idle, status bar not stuck disconnected. const c = domCounts(); const idle = !pane.busy; const disc = document.querySelector(".ws-sb-disconnected") !== null; - document.title = - c.topLevel >= 1 && idle && !disc - ? "RECOVERY-READY-RESTART-rows" + c.topLevel + "-trunc" + window.__truncatedSeen - : "RECOVERY-FAILED-RESTART-rows" + c.topLevel + - "-busy" + (pane.busy ? 1 : 0) + "-disc" + (disc ? 1 : 0); + // Sentinel must be collision-proof against everything else the + // transcript renders: the paced bash COMMAND row paints its + // shell text verbatim (buildConvCmd), which contains the + // keyword ``done`` — a plain-word sentinel is vacuously + // present whether or not the hidden-window turn survived. + // The value rides the ?healed= param (single source: + // HEALED_SENTINEL in the runner). + const healed = + healedSentinel !== "" && + (pane.messagesEl.textContent || "").includes(healedSentinel); + const ok = + c.topLevel >= 1 && + idle && + !disc && + healed && + window.__truncatedSeen >= 1; + document.title = ok + ? "RECOVERY-READY-RESTART-rows" + c.topLevel + "-trunc" + window.__truncatedSeen + : "RECOVERY-FAILED-RESTART-rows" + c.topLevel + + "-busy" + (pane.busy ? 1 : 0) + "-disc" + (disc ? 1 : 0) + + "-healed" + (healed ? 1 : 0) + "-trunc" + window.__truncatedSeen; }; } @@ -514,31 +543,54 @@ def run_restart(chrome: str) -> str: port = _free_port() node = _boot_node(port=port) - # A PACED turn so the tab can hide MID-turn (browser cursor below the - # committed counter) -> the post-restart reconnect draws truncated. + # A PACED turn so the tab can hide MID-turn: the browser cursor + # freezes at a mid-stream event id, the rest of turn 1 plus the + # turn-2 text commit while hidden, and the restarted node's seeded + # counter therefore sits ABOVE the frozen cursor -> the show-edge + # reconnect draws ``replay_truncated`` and must heal the gap. paced = parallel_bash_script({"r0": "for i in $(seq 1 40); do echo r-$i; sleep 0.05; done"}) - ws_id = node.create_workstream(paced, final_text_script("done"), name="browser-restart") + # The turn-2 text is the healed-gap sentinel — it must be a token + # that cannot appear in any rendered command/output (the bash + # command row contains the shell keyword ``done``, so the obvious + # word is vacuously present; see __verifyRestart). Single source: + # the same constant is injected as the scripted turn text AND + # threaded to the page via ?healed=, so the two sides cannot drift. + ws_id = node.create_workstream( + paced, final_text_script(HEALED_SENTINEL), name="browser-restart" + ) profile = Path(_scratch()) / "chrome-restart" proc, cdp_port = _launch_chrome(chrome, profile) cdp: CDP | None = None try: cdp = CDP(_page_ws_url(cdp_port)) - url = f"{node.base_url}/recovery?ws_id={ws_id}&scenario=restart" + url = f"{node.base_url}/recovery?ws_id={ws_id}&scenario=restart&healed={HEALED_SENTINEL}" _set_cookie_and_navigate(cdp, node.base_url, node.token, url) - node.wait_turn(ws_id, timeout=30) # the turn renders into the DOM - time.sleep(0.5) - # Hide the tab -> interactive.js closes the stream (close-on-hide). + # Hide as soon as the FIRST streamed line has painted (proof the + # pane holds a live mid-turn cursor) — NOT after wait_turn, which + # would leave the cursor at/above the committed counter and the + # reconnect on the lossless replay_ok path (trunc0). + deadline = time.monotonic() + 15 + while time.monotonic() < deadline: + painted = cdp.evaluate("document.querySelector('.tool-output-stream') !== null") + if painted: + break + time.sleep(0.2) + else: + raise AssertionError("restart scenario: first streamed line never painted") cdp.evaluate("window.__hide && window.__hide()") + # The turn (and the follow-up text) commits while the tab is hidden. + node.wait_turn(ws_id, timeout=30) # Restart the node on the SAME port (fresh empty ring, seeded counter). node.stop() node = _boot_node(port=port) node.open_workstream(ws_id) - # Show the tab -> the pane reconnects to the restarted node and recovers. - # The reconnect + any resync carries jitter, so settle before the verdict. + # Show the tab -> stale-cursor reconnect -> truncated -> jittered + # resync (0-10s) -> /history rebuild. Settle past the worst-case + # jitter before the verdict. cdp.evaluate("window.__show && window.__show()") - time.sleep(9.0) + time.sleep(12.0) cdp.evaluate("window.__verifyRestart && window.__verifyRestart()") - return _poll_title(cdp, 15) + return _poll_title(cdp, 20) finally: if cdp is not None: cdp.close() diff --git a/tests/test_app_js.py b/tests/test_app_js.py index 160d254e..037c58f6 100644 --- a/tests/test_app_js.py +++ b/tests/test_app_js.py @@ -1024,7 +1024,11 @@ def _slice_balanced_body(body: str, anchor: int) -> str | None: depth = 0 in_str: str | None = None start = i - while i < n and i - start < 8000: + # 12000: connectSSE reached ~7950 chars during the 2026-07 SSE + # recovery campaign (cursor-override + capture-rationale comments); + # the window exists to bound a runaway scan, not to cap legitimate + # method growth — keep it comfortably above the largest real body. + while i < n and i - start < 12000: ch = body[i] if in_str: if ch == "\\" and i + 1 < n: @@ -1996,14 +2000,81 @@ def test_coord_detects_server_restart_by_backwards_event_id() -> None: m = re.search(r"evtSource\.onmessage = function \(event\) \{(.*?)\n \};", body, re.S) assert m is not None, "onmessage handler not found" handler = m.group(1) - assert "Number(evtSource.lastEventId) < Number(lastEventId)" in handler + assert "Number(event.lastEventId) < Number(lastEventId)" in handler assert "!gapRefreshedAtOpen" in handler assert "refreshSidebarAfterGap();" in handler - check = handler.index("Number(evtSource.lastEventId) < Number(lastEventId)") - overwrite = handler.index("lastEventId = evtSource.lastEventId;") + check = handler.index("Number(event.lastEventId) < Number(lastEventId)") + overwrite = handler.index("lastEventId = event.lastEventId;") assert check < overwrite +def test_sse_cursor_captured_from_message_event_never_the_source_object() -> None: + """``lastEventId`` lives on the MessageEvent — EventSource exposes no + such property (WHATWG: url/withCredentials/readyState only), so an + object-form read like ``evtSource.lastEventId`` is undefined in every + real browser. All three clients shipped exactly that dead + conditional: the cursor never tracked live traffic, every MANUAL + reconnect (close-on-hide show edge, degraded retry, recover beat) + connected fresh, and turns committed during the gap silently never + painted — the 2026-07 'turn disappeared' field mechanism. Only a + real-browser harness could catch it (source-pattern tests pinned the + broken form as happily as the fixed one), so this tripwire at least + pins the corrected form and forbids the dead one by name. + + Guard shape is pinned too — the explicit ``!= null && !== ""`` form. + On a DOMString this is behaviorally identical to truthiness (the + valid id "0" is a truthy STRING; only "" and null/undefined are + falsy here), so the pin is for cross-site symmetry with the NUMERIC + cursor gates (``_lastEventId != null`` / ``data.cursor != null``), + where truthiness genuinely drops a valid 0 — one visual idiom for + every cursor guard keeps a future editor from "simplifying" the + numeric ones to match a terser string form. + + The GLOBAL stream (app.js) is the deliberate exception: its manual + reconnects are pinned CURSORLESS — the global ring's counter reboots + at 0 on restart (KNOWN GAP #881), so a stale cursor draws + ``replay_ok``-empty with no node_snapshot and the roster ghosts; + cursorless always draws the fresh snapshot. Revisit when #881 + lands. + + Comments are stripped before the scan (module-level, string-aware + stripper) so documentation may name the anti-pattern verbatim — the + tripwire forbids the dead CODE, not its description.""" + dead_form = re.compile(r"(?:this\.)?\w*[Ee]vtSource\.lastEventId") + for path, capture in ( + ( + _INTERACTIVE_JS, + r'if \(e\.lastEventId != null && e\.lastEventId !== ""\) \{\s*' + r"this\._lastEventId = e\.lastEventId;", + ), + ( + _COORD_JS, + r'if \(event\.lastEventId != null && event\.lastEventId !== ""\) \{', + ), + ): + body = path.read_text(encoding="utf-8") + code = _strip_js_comments(body) + hits = [m.group(0) for m in dead_form.finditer(code)] + assert not hits, ( + f"{path.name}: cursor read off the EventSource OBJECT {hits} — " + "that property does not exist; capture from the MessageEvent." + ) + assert re.search(capture, code), ( + f"{path.name}: MessageEvent cursor capture (with the " + '``!= null && !== ""`` guard) not found' + ) + app_code = _strip_js_comments(_APP_JS.read_text(encoding="utf-8")) + assert not dead_form.search(app_code), ( + "app.js: dead EventSource-object cursor read must not return" + ) + assert "lastEventId" not in app_code and "last_event_id" not in app_code, ( + "app.js global stream must stay CURSORLESS on manual reconnects " + "until #881's boot-epoch staleness signal lands — a stale cursor " + "on the reborn global ring draws replay_ok-empty with no " + "node_snapshot (ghost roster)." + ) + + def test_interactive_history_is_rest_first_not_sse() -> None: """PR A converged interactive onto coord's REST-first history model: first paint and post-rewind re-render fetch ``GET /history`` diff --git a/turnstone/console/static/coordinator/coordinator.js b/turnstone/console/static/coordinator/coordinator.js index 72fd45f6..f74f72eb 100644 --- a/turnstone/console/static/coordinator/coordinator.js +++ b/turnstone/console/static/coordinator/coordinator.js @@ -2648,7 +2648,15 @@ function createCoordinatorPane(root, wsId, opts) { // Capture lastEventId BEFORE JSON.parse so a malformed event // doesn't desync the manual-reconnect fallback from native // auto-reconnect. - if (evtSource && evtSource.lastEventId) { + // ``lastEventId`` lives on the MESSAGE EVENT — EventSource exposes + // no such property, so the pre-2026-07 read off the source OBJECT + // was a dead conditional: the cursor never tracked live traffic + // and the counter-reset detector below never fired in a real + // browser. ``!== ""``: no-id frames carry "" per spec. (A + // DOMString — the valid id "0" is truthy, so truthiness would + // behave identically; the explicit form matches interactive.js's + // canonical capture.) + if (event.lastEventId != null && event.lastEventId !== "") { // A live event id BELOW our saved cursor means the server's per-ws // event counter reset — a coordinator process restart with a fresh, // empty ring. The replay path can't flag that (a cursor at/above the @@ -2661,12 +2669,12 @@ function createCoordinatorPane(root, wsId, opts) { if ( lastEventId != null && !gapRefreshedAtOpen && - Number(evtSource.lastEventId) < Number(lastEventId) + Number(event.lastEventId) < Number(lastEventId) ) { refreshSidebarAfterGap(); gapRefreshedAtOpen = true; } - lastEventId = evtSource.lastEventId; + lastEventId = event.lastEventId; } let data = null; try { diff --git a/turnstone/shared_static/interactive.js b/turnstone/shared_static/interactive.js index efe9151d..7faa6d4c 100644 --- a/turnstone/shared_static/interactive.js +++ b/turnstone/shared_static/interactive.js @@ -1366,17 +1366,23 @@ class Pane { }; this.evtSource.onmessage = (e) => { - // Capture lastEventId BEFORE JSON.parse so a (rare) malformed - // event doesn't desync the manual-reconnect fallback from - // native auto-reconnect (which advances lastEventId regardless - // of whether we successfully process the data). Server's - // stamping contract: ``id:`` only on events sourced from the - // per-ws ring buffer — synthetic replay events (history / - // state_change / in_progress_snapshot) don't advance the - // counter, so reconnect resumes from the last BUFFERED id (or - // none on a truly-fresh connect that never received one). - if (this.evtSource && this.evtSource.lastEventId) { - this._lastEventId = this.evtSource.lastEventId; + // Capture lastEventId from the MESSAGE EVENT, before JSON.parse, + // so a malformed frame can't desync the manual-reconnect cursor + // from native auto-reconnect. Spec shape — do NOT revert to + // reading the property off the EventSource OBJECT: per WHATWG the + // id lives on MessageEvent only, so the pre-2026-07 object-form + // read was a dead conditional and every manual reconnect (show + // edge, degraded retry, recover beat) went cursorless, silently + // dropping turns committed during the gap. Guard: ``!= null && + // !== ""`` — no-id frames carry "" per spec. (lastEventId is a + // DOMString, so the valid id "0" — the error-surface snap_seq — + // is TRUTHY and plain truthiness would also accept it; the + // explicit form is for parity with the NUMERIC cursor gates + // below, where bare truthiness genuinely drops 0.) Stamping + // contract: ``id:`` rides only ring-buffered events; synthetic + // replay frames never advance it. + if (e.lastEventId != null && e.lastEventId !== "") { + this._lastEventId = e.lastEventId; } // Guarded parse + dispatch. onmessage is the pane's whole event // pipeline: an exception escaping it doesn't close the EventSource, so diff --git a/turnstone/ui/static/app.js b/turnstone/ui/static/app.js index ca625a7c..d718718b 100644 --- a/turnstone/ui/static/app.js +++ b/turnstone/ui/static/app.js @@ -16,13 +16,6 @@ let workstreams = {}; let currentWsId = null; let globalEvtSource = null; let globalRetryDelay = 1000; -// Saved high-water mark for the manual-reconnect path (the -// EventSource constructor can't set custom headers, so the -// browser-native ``Last-Event-ID`` header is unavailable on -// reconnect — we thread it via ``?last_event_id=N`` instead). Updated -// from ``globalEvtSource.lastEventId`` on every onmessage; native -// auto-reconnect uses the header directly on the same source object. -let globalLastEventId = null; let dashboardVisible = false; let _historyNavigation = false; let _lastHealth = null; @@ -1759,28 +1752,29 @@ function connectGlobalSSE() { globalEvtSource.close(); globalEvtSource = null; } - // Manual-reconnect path threads ``?last_event_id=N`` because the - // EventSource constructor can't set headers; native auto-reconnect - // on the same source uses the header directly. - let globalUrl = "/v1/api/events/global"; - if (globalLastEventId) { - globalUrl += "?last_event_id=" + encodeURIComponent(globalLastEventId); - } - globalEvtSource = new EventSource(globalUrl); + // Manual reconnects on the GLOBAL stream are DELIBERATELY cursorless + // (no ``?last_event_id=`` — do not add a MessageEvent lastEventId + // capture here like the per-ws streams'): the global ring cannot + // report truncation for a stale cursor after a node restart (its + // counter reboots at 0 — KNOWN GAP #881), so presenting one draws + // ``replay_ok``-empty with NO node_snapshot and the roster ghosts + // exactly when a full rebuild is most needed. Cursorless manual + // reconnects always draw the fresh node_snapshot — lossless for + // roster STATE (unlike per-ws append-only history, where the + // storage-seeded counter makes a stale cursor report ``truncated`` + // and the cursor is therefore safe to track). Native auto-reconnect + // keeps its browser-internal header either way. Revisit when #881's + // boot-epoch staleness signal lands. + globalEvtSource = new EventSource("/v1/api/events/global"); globalEvtSource.onopen = function () { globalRetryDelay = 1000; }; globalEvtSource.onmessage = function (e) { - // Capture lastEventId BEFORE JSON.parse (see Pane.connectSSE - // onmessage for full rationale). - if (globalEvtSource && globalEvtSource.lastEventId) { - globalLastEventId = globalEvtSource.lastEventId; - } - // Guarded parse: the cursor above has already advanced past this frame, - // so a parse failure is a permanently-lost roster mutation — resync the - // roster from REST instead of silently drifting (a dropped ws_created - // renders as a conversation that never appears; a dropped ws_closed as - // a ghost row forever). + // Guarded parse: native auto-reconnect's header cursor has already + // advanced past this frame, so a parse failure is a permanently-lost + // roster mutation — resync the roster from REST instead of silently + // drifting (a dropped ws_created renders as a conversation that + // never appears; a dropped ws_closed as a ghost row forever). let data = null; try { data = JSON.parse(e.data);