diff --git a/explorer.qmd b/explorer.qmd index 08d3e39..01ec6a3 100644 --- a/explorer.qmd +++ b/explorer.qmd @@ -4528,6 +4528,45 @@ 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 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(); + } + function refreshFacetCounts() { clearTimeout(facetCountsDebounce); const myReq = ++facetCountsReqId; @@ -5046,6 +5085,18 @@ 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(); + // 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(); @@ -5068,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()) { @@ -5180,6 +5234,14 @@ 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(); + // Inner finally guarantees a successor even if this throws — see the + // source handler and invalidateFacetCountsNow() (Codex review). + try { syncFacetNote(); writeQueryState(); refreshHeatmap(); @@ -5190,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 new file mode 100644 index 0000000..9568eaf --- /dev/null +++ b/tests/playwright/verify_preawait_invariant.py @@ -0,0 +1,127 @@ +#!/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]}") + + # 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 = 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] + 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)} (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)