From 1be4ddc5d6767f681ada1b58544f67cb8cc267ff Mon Sep 17 00:00:00 2001 From: Raymond Yee Date: Thu, 6 Aug 2026 00:03:54 -0700 Subject: [PATCH 1/2] coherence F2: invalidate facet counts at input, before the await MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The audit's highest-value open item, and the one that turns the honesty rule from call-site discipline into an invariant. THE BUG. Both filter handlers had this shape: writeQueryState(); refreshHeatmap(); await ; // long refreshFacetCounts(); // only now are the counts invalidated The await is not short. Measured on production: the globe reload takes 168s on 4G and 423s on 3G (see PERF_BANDWIDTH_FINDINGS_2026-08-06.md — it is currently downloading ~74 MB). For that entire window the facet counts kept displaying the PREVIOUS filter's numbers, unmarked and looking settled. #340 was this same shape with a different trigger; #341/#342 fixed instances, not the class. THE FIX. invalidateFacetCountsNow() — synchronous, cheap, called at the top of the source and facet handlers BEFORE any await: 1. ++facetCountsReqId so an in-flight recompute cannot repaint over us 2. clearTimeout on the debounce armed for the old inputs 3. markFacetCountsRecomputing() — dims now, and via its 400ms timer (#342) swaps text to "(Loading…)" when the wait is long enough to matter It deliberately does NOT schedule a recompute: the caller still owns that, after its await, once the new inputs have settled. Scheduling here would query half-applied state and add contention to the very load being waited on. Under an active search it returns early — those counts are already the honest "(—)" dash (#340), and re-dimming would downgrade "we cannot know this" to "we're about to know it", a worse claim rather than a better one. PROVEN by A/B, not asserted. Same script, same 400 kbps throttle, toggle one source filter, sample the DOM every 0.4s: production (no fix) invalidated within 0.4s: False stale UNMARKED windows : 27 user sees "(4,389,231)" for 10+s after deselecting SESAR this branch invalidated within 0.4s: True stale UNMARKED windows : 0 user sees "(Loading…)" throughout Adds tests/playwright/verify_preawait_invariant.py, which is that experiment. Verified: quarto render clean; test_smoke.py passes; test_frontend_derived 40 passed; #341/#342 behaviour unaffected (search -> 60/60 dashes 0 stuck; facet-only -> real counts); no pageerrors. SCOPE. Facet counts only. The samples table has the same shape (applySearchFilterChange awaits reconcileGlobeForFilters before refreshSamplesTable) — audit F8, deliberately left for a separate change. Refs #340, #304, #305 Co-Authored-By: Claude Opus 5 (1M context) Claude-Session: https://claude.ai/code/session_01QCCDurpcLzMe7L72y2HDAa --- explorer.qmd | 43 +++++++ tests/playwright/verify_preawait_invariant.py | 105 ++++++++++++++++++ 2 files changed, 148 insertions(+) create mode 100644 tests/playwright/verify_preawait_invariant.py diff --git a/explorer.qmd b/explorer.qmd index 08d3e39..c3e836e 100644 --- a/explorer.qmd +++ b/explorer.qmd @@ -4528,6 +4528,40 @@ zoomWatcher = { })); } + // Coherence audit F2 — the honesty invariant, applied at INPUT rather than at + // a timer. Call this synchronously the moment a filter/mode/selection changes, + // BEFORE any await, so displayed counts stop asserting the old answer while + // slow work runs. + // + // Why this exists: both the source and facet handlers used to do + // `writeQueryState(); refreshHeatmap(); await ; refreshFacetCounts()`. + // The await is not short — on a throttled connection the globe reload can take + // minutes (measured: 168s on 4G, 423s on 3G; see PERF_BANDWIDTH_FINDINGS). For + // that entire window the counts silently displayed the PREVIOUS filter's + // numbers, unmarked. #340 was the same shape with a different trigger. + // + // Three things, all synchronous and all cheap (DOM class writes + a counter): + // 1. ++facetCountsReqId — any in-flight recompute becomes stale and cannot + // repaint over us when it finally settles. + // 2. clearTimeout — a pending debounce for the OLD inputs is dropped. + // 3. markFacetCountsRecomputing() — dims now, and (via its 400 ms timer, + // #342) swaps the text to "(Loading…)" if the wait is long enough to + // matter. Short interactions never flicker. + // + // Deliberately does NOT schedule a recompute. The caller still owns when to + // call refreshFacetCounts() — usually after its await, once the new inputs are + // actually settled. Scheduling here would fire a query against half-applied + // state and add contention to the very load we are waiting on. + function invalidateFacetCountsNow() { + clearTimeout(facetCountsDebounce); + ++facetCountsReqId; + // Under an active search the counts are already the honest "(—)" dash + // (#340). Re-dimming them would downgrade "we cannot know this" to + // "we're about to know it", which is a worse claim, not a better one. + if (searchIsActive()) return; + markFacetCountsRecomputing(); + } + function refreshFacetCounts() { clearTimeout(facetCountsDebounce); const myReq = ++facetCountsReqId; @@ -5046,6 +5080,10 @@ zoomWatcher = { // it from runtime state and the URL so the side panel matches the globe. const isStale = freshSelectionToken(viewer); try { + // Coherence audit F2: invalidate BEFORE the globe reload below, which + // can run for minutes on a slow link. Without this the facet counts + // keep asserting the pre-toggle numbers for that whole window. + invalidateFacetCountsNow(); updateSourceLegendState(); writeQueryState(); refreshHeatmap(); @@ -5180,6 +5218,11 @@ zoomWatcher = { // (Codex round-2 P1.8). const isStale = freshSelectionToken(viewer); try { + // Coherence audit F2 — see the source handler above and + // invalidateFacetCountsNow()'s comment. reconcileGlobeForFilters() + // below awaits a globe reload; counts must not keep claiming the + // pre-toggle numbers while it runs. + invalidateFacetCountsNow(); syncFacetNote(); writeQueryState(); refreshHeatmap(); diff --git a/tests/playwright/verify_preawait_invariant.py b/tests/playwright/verify_preawait_invariant.py new file mode 100644 index 0000000..6233209 --- /dev/null +++ b/tests/playwright/verify_preawait_invariant.py @@ -0,0 +1,105 @@ +#!/usr/bin/env python3 +""" +Prove the pre-await invalidation invariant (coherence audit F2). + +Scenario: throttle the link, wait for a settled Explorer, then toggle a source +filter. The handler does a long awaited globe reload before recomputing counts. + +BEFORE the fix: counts keep displaying the PREVIOUS filter's numbers, unmarked, +for the whole reload. +AFTER the fix: counts are invalidated synchronously — dimmed at once and swapped +to "(Loading…)" once the wait exceeds the 400 ms grace period. + +Usage: verify_invariant.py BASE_URL [--throttle KBPS] +""" +import sys, time, json +from playwright.sync_api import sync_playwright + +BASE = sys.argv[1] if len(sys.argv) > 1 else "http://localhost:8908" +KBPS = 400 +if "--throttle" in sys.argv: + KBPS = int(sys.argv[sys.argv.index("--throttle") + 1]) + +SNAP = """() => { + const els = Array.from(document.querySelectorAll('.facet-count')); + const txt = els.map(e => e.textContent.trim()); + return { + n: els.length, + recomputing: els.filter(e => e.classList.contains('recomputing')).length, + unavailable: els.filter(e => e.classList.contains('count-unavailable')).length, + loading_text: txt.filter(t => t.includes('Loading')).length, + numeric_text: txt.filter(t => /\\(\\d/.test(t)).length, + sample: txt.slice(0, 3), + }; +}""" + +with sync_playwright() as pw: + b = pw.chromium.launch() + ctx = b.new_context(viewport={"width": 1440, "height": 900}) + page = ctx.new_page() + cdp = ctx.new_cdp_session(page) + cdp.send("Network.enable") + + page.goto(f"{BASE}/explorer.html", wait_until="commit") + print("waiting for a settled Explorer (unthrottled)...") + for _ in range(180): + if page.evaluate("() => document.querySelectorAll('.facet-treenode').length") > 0: + break + time.sleep(1) + time.sleep(6) + + before = page.evaluate(SNAP) + print(f"\nSETTLED: {before}") + if before["numeric_text"] == 0: + print("!! counts never became numeric; cannot run the experiment"); sys.exit(2) + + # Throttle hard so the awaited globe reload is unmistakably long. + cdp.send("Network.emulateNetworkConditions", { + "offline": False, + "downloadThroughput": KBPS * 1000 / 8, + "uploadThroughput": KBPS * 1000 / 8, + "latency": 500, + }) + print(f"\nthrottled to {KBPS} kbps; toggling a source filter...") + + page.evaluate("""() => { + const cb = document.querySelector('#sourceFilter input[type=checkbox]'); + if (cb) { cb.checked = !cb.checked; + cb.dispatchEvent(new Event('change', {bubbles: true})); } + }""") + + # Sample densely across the awaited reload. + obs = [] + t0 = time.time() + for _ in range(50): + time.sleep(0.4) + try: + s = page.evaluate(SNAP) + except Exception: + continue + s["t"] = round(time.time() - t0, 1) + obs.append(s) + if s["t"] > 18: + break + + print("\n t n recomp unavail loadingTxt numericTxt sample") + for s in obs[:24]: + print(f" {s['t']:>4}s {s['n']:>3} {s['recomputing']:>6} {s['unavailable']:>8} " + f"{s['loading_text']:>11} {s['numeric_text']:>11} {s['sample'][:2]}") + + # --- verdict -------------------------------------------------------------- + first = obs[0] if obs else None + dimmed_fast = first and first["recomputing"] == first["n"] and first["n"] > 0 + ever_loading = any(o["loading_text"] > 0 for o in obs) + stale_unmarked = [o for o in obs + if o["numeric_text"] > 0 and o["recomputing"] == 0 + and o["unavailable"] == 0 and o["t"] < 12] + + print("\n=== VERDICT ===") + print(f" invalidated within ~0.4s of the toggle : {dimmed_fast}") + print(f" text swapped to (Loading…) during wait : {ever_loading}") + print(f" windows showing stale UNMARKED numbers : {len(stale_unmarked)}") + ok = dimmed_fast and not stale_unmarked + print(f"\n INVARIANT HOLDS: {ok}") + ctx.close(); b.close() + sys.exit(0 if ok else 1) From 25a3d684524a78fb6247d99eb71a3ed0132b500c Mon Sep 17 00:00:00 2001 From: Raymond Yee Date: Thu, 6 Aug 2026 00:20:51 -0700 Subject: [PATCH 2/2] invariant round 2: guarantee a successor on throw; make the verifier unable to false-pass MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Codex blocked round 1 on two findings, both valid: 1. A TERMINAL EXCEPTION COULD STRAND (Loading...). invalidateFacetCountsNow() bumps facetCountsReqId and cancels the pending debounce, but refreshFacetCounts() sat only on the success path. If anything between the invalidate and the end of the globe work threw — updateSourceLegendState, writeQueryState, refreshHeatmap, reconcileGlobeForFilters — nothing would ever schedule a recompute and the counts would sit at (Loading...) until some unrelated later event. A HUNG promise staying Loading is honest (#342); a REJECTED one is terminal, so Loading becomes a different kind of lie. Fixed with an inner try/finally in both handlers, so refreshFacetCounts() runs on success AND on throw. No watchdog, no query issued while work is pending — it only guarantees a successor once the work settles or rejects. The outer finally still owns busyRelease(), and selection revalidation still runs after. Deliberately NOT applied to applySearchFilterChange(): Codex analysed it and it is not a stale-number hole (activation paints the (—) dash synchronously, and clearing leaves that honest dash visible during reconciliation). 2. THE VERIFIER COULD FALSE-PASS. It printed ever_loading without asserting it, checked stale-unmarked only before t=12s while sampling past 18s, would accept a permanently dimmed numeric value, and never proved a successor repaint. All four clauses are now required, the stale check covers every observation, and it un-throttles at the end and requires real numbers to come back — which is precisely the anti-stranding assertion for finding 1. Also took Codex's idempotence hardening: under an active search invalidateFacetCountsNow() now repaints the (—) dash rather than merely returning, so it does not depend on an earlier #340 caller having painted it. Verified on the rebuilt page: verifier passes all four clauses (invalidated within 0.4s / swapped to Loading / 0 stale-unmarked windows / successor repainted); test_smoke.py passes; test_frontend_derived 40 passed; #341/#342 behaviour unaffected. STILL OPEN from the review, deliberately not done here: converting the verifier to a discovered .spec.js that deterministically holds a globe request, and hardening facet-tree.spec.js's fixed 3s sleeps (they parse numeric text and could now read (Loading...) if a globe reload exceeds 3s). Refs #340, #304, #305 Co-Authored-By: Claude Opus 5 (1M context) Claude-Session: https://claude.ai/code/session_01QCCDurpcLzMe7L72y2HDAa --- explorer.qmd | 34 +++++++++++++++---- tests/playwright/verify_preawait_invariant.py | 34 +++++++++++++++---- 2 files changed, 56 insertions(+), 12 deletions(-) diff --git a/explorer.qmd b/explorer.qmd index c3e836e..01ec6a3 100644 --- a/explorer.qmd +++ b/explorer.qmd @@ -4555,10 +4555,15 @@ zoomWatcher = { function invalidateFacetCountsNow() { clearTimeout(facetCountsDebounce); ++facetCountsReqId; - // Under an active search the counts are already the honest "(—)" dash - // (#340). Re-dimming them would downgrade "we cannot know this" to - // "we're about to know it", which is a worse claim, not a better one. - if (searchIsActive()) return; + // Under an active search the counts are genuinely unavailable (#340), not + // pending. Re-dimming them would downgrade "we cannot know this" to + // "we're about to know it" — a worse claim, not a better one. Repaint the + // dash rather than merely returning, so this is idempotent and does not + // depend on an earlier caller having already painted it (Codex review). + if (searchIsActive()) { + markFacetCountsUnavailable(); + return; + } markFacetCountsRecomputing(); } @@ -5084,6 +5089,14 @@ zoomWatcher = { // can run for minutes on a slow link. Without this the facet counts // keep asserting the pre-toggle numbers for that whole window. invalidateFacetCountsNow(); + // The inner finally GUARANTEES a successor (Codex review). Invalidating + // bumps facetCountsReqId and cancels the pending debounce, so if + // anything between here and the end of the globe work throws, nothing + // would ever schedule a recompute and the counts would sit at + // "(Loading…)" until some unrelated later event. A hung promise + // staying "Loading" is honest (#342); a REJECTED one is terminal, so + // "Loading" would then be a lie of a different kind. + try { updateSourceLegendState(); writeQueryState(); refreshHeatmap(); @@ -5106,7 +5119,10 @@ zoomWatcher = { } else { await loadViewportSamples(); } - refreshFacetCounts(); + } finally { + // Runs on success AND on throw — see invalidateFacetCountsNow() above. + refreshFacetCounts(); + } // Re-validate selection (only if no newer filter change has fired). if (!isStale()) { @@ -5223,6 +5239,9 @@ zoomWatcher = { // below awaits a globe reload; counts must not keep claiming the // pre-toggle numbers while it runs. invalidateFacetCountsNow(); + // Inner finally guarantees a successor even if this throws — see the + // source handler and invalidateFacetCountsNow() (Codex review). + try { syncFacetNote(); writeQueryState(); refreshHeatmap(); @@ -5233,7 +5252,10 @@ zoomWatcher = { // state (and reloads filtered clusters in place when already in // cluster mode, since the filter set changed). await reconcileGlobeForFilters(); - refreshFacetCounts(); + } finally { + // Runs on success AND on throw — see invalidateFacetCountsNow(). + refreshFacetCounts(); + } // #300: a selected cluster card may now be stale — the facet change // can empty the cell (then drop the selection) or change its filtered diff --git a/tests/playwright/verify_preawait_invariant.py b/tests/playwright/verify_preawait_invariant.py index 6233209..9568eaf 100644 --- a/tests/playwright/verify_preawait_invariant.py +++ b/tests/playwright/verify_preawait_invariant.py @@ -87,19 +87,41 @@ print(f" {s['t']:>4}s {s['n']:>3} {s['recomputing']:>6} {s['unavailable']:>8} " f"{s['loading_text']:>11} {s['numeric_text']:>11} {s['sample'][:2]}") + # Let the handler settle so we can require a successor repaint. Without this + # the script would accept a permanently-"(Loading…)" UI as a pass, which is + # exactly the stranding bug the inner try/finally exists to prevent. + cdp.send("Network.emulateNetworkConditions", { + "offline": False, "downloadThroughput": -1, "uploadThroughput": -1, "latency": 0, + }) + settled = None + for _ in range(120): + time.sleep(1) + s = page.evaluate(SNAP) + if s["numeric_text"] > 0 and s["recomputing"] == 0: + settled = s + break + # --- verdict -------------------------------------------------------------- + # Every clause below is REQUIRED. An earlier version printed `ever_loading` + # without asserting it and only checked staleness before t=12s, so a run that + # sat dimmed-but-numeric forever could pass (Codex review). first = obs[0] if obs else None - dimmed_fast = first and first["recomputing"] == first["n"] and first["n"] > 0 + dimmed_fast = bool(first and first["n"] > 0 and first["recomputing"] == first["n"]) ever_loading = any(o["loading_text"] > 0 for o in obs) + # A count is dishonest if it shows a NUMBER while carrying no marker at all. + # Checked across every observation, not an arbitrary early window. stale_unmarked = [o for o in obs if o["numeric_text"] > 0 and o["recomputing"] == 0 - and o["unavailable"] == 0 and o["t"] < 12] + and o["unavailable"] == 0] + repainted = settled is not None print("\n=== VERDICT ===") - print(f" invalidated within ~0.4s of the toggle : {dimmed_fast}") - print(f" text swapped to (Loading…) during wait : {ever_loading}") - print(f" windows showing stale UNMARKED numbers : {len(stale_unmarked)}") - ok = dimmed_fast and not stale_unmarked + print(f" invalidated within ~0.4s of the toggle : {dimmed_fast}") + print(f" text swapped to (Loading…) during wait : {ever_loading}") + print(f" windows showing stale UNMARKED numbers : {len(stale_unmarked)} (must be 0)") + print(f" successor repainted real numbers after : {repainted}" + f"{'' if repainted else ' <-- STRANDED'}") + ok = dimmed_fast and ever_loading and not stale_unmarked and repainted print(f"\n INVARIANT HOLDS: {ok}") ctx.close(); b.close() sys.exit(0 if ok else 1)