From d6ca125cacd81b921071f894f7dee356e130f5c3 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Gerg=C5=91=20T=C3=B6rcsv=C3=A1ri?= Date: Wed, 5 Aug 2026 19:15:30 +0200 Subject: [PATCH] docs: diagnose the Symbol Properties hang (stranded tool fiber) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Reproduced live on the dev platform: the tool fiber running the quasi-modal parks mid-body, is quarantined by the stale-fiber guard, and its resume is REFUSED — so it never releases the dispatch guard. Interlock held forever => clicks deferred and never drained, timer delivery frozen; the titlebar X works because it is ungated. Includes the captured frozen state, what is ruled out (clicks do reach wx; no I/O in flight), and ranked fix directions. Regression vs pre-existing still undetermined — needs a real WX_SCHEDULER=0 build. Co-Authored-By: Claude Fable 5 Claude-Session: https://claude.ai/code/session_01TfxKn5utcntBSnxz4ZnYKs --- .../async/19-quasimodal-fiber-strand.md | 93 +++++++++ tests/kicad/dialog-deadlock-probe.spec.ts | 187 ++++++++++++++++++ 2 files changed, 280 insertions(+) create mode 100644 docs/features/async/19-quasimodal-fiber-strand.md create mode 100644 tests/kicad/dialog-deadlock-probe.spec.ts diff --git a/docs/features/async/19-quasimodal-fiber-strand.md b/docs/features/async/19-quasimodal-fiber-strand.md new file mode 100644 index 0000000..2cba165 --- /dev/null +++ b/docs/features/async/19-quasimodal-fiber-strand.md @@ -0,0 +1,93 @@ +# 19 — Symbol Properties dialog hangs: a stranded tool fiber (live investigation) + +> **Status: DIAGNOSED, NOT FIXED (2026-08-05).** Reproduced end-to-end in a real browser +> against the dev platform on the scheduler build. Regression-vs-pre-existing is **not yet +> determined** — see §5. Related: [`17`](17-mailbox-scheduler-plan.md) S4 (waits), +> [`16`](16-fiber-resume-guard.md) (the quarantine guard), the 8/4 three-UI-bugs triage +> (which blamed the interlock drain — that is the *symptom layer*, not the proximate cause). + +## 1. Repro (100%, ~40 s) + +Dev platform (`npm run dev`), editor at `:3048`, Arduino Leonardo schematic: + +1. Open the project URL, wait for load (~30 s). +2. Double-click the USB receptacle (J1) → **Symbol Properties** opens. +3. Click OK / Cancel / any control → **nothing happens**. Only the titlebar × closes it. + +## 2. Frozen state (captured live) + +``` +Fibers.__internallyParked = [607191040] // tool fiber, quarantined +Fibers.__parkSleepBuf = {607191040 → 607977472} +Asyncify.__pendingSleepContexts= [{buf 607977472, rootOwned:false, cleaned:false}, + {buf 205586432, rootOwned:true, cleaned:false}] +Asyncify.currData = 205586432, state = 0 +Fibers.__validSuspensions ∌ 607191040 // no resumable suspension +scheduler: mailbox=3 enqueued=655 delivered=652 // FROZEN (0 progress in 4 s) + waits=1 waitsBegun=1 waitsResolved=0 // the quasi-modal wait, unresolved +``` + +Console beacons, in order: + +``` +[wx-asyncify] overlapped-wake × 10 (benign: restore over null) +[wx-asyncify] aliased-wake-live: restoring currData=205586432 over 607977472 +[wx-asyncify] fiber-resume-refused: fiber=607191040 is asyncify-parked mid-body (sleep in flight) +``` + +## 3. What is NOT the cause + +- **Not clicks failing to reach wx.** The OK click produced exactly one + `wx_dom_event(domId 81, kind 1)` ccall; the button is enabled and hit-testable. + (Rules out the `WINDOW_DISABLER`/`IsEnabled()` hypothesis.) +- **Not slow I/O.** The last library network resource completed at t=5 s; the hang was + inspected at t=277 s with nothing in flight. The fiber's park is waiting on a promise + that will never settle — a **lost wake**, not pending work. +- **Not the mailbox/embind/wait bookkeeping.** `strayWrites=0`, `mutQ=0`, no deferred + wakes, no stranded messages beyond the 3 blocked by the interlock. + +## 4. Mechanism + +The tool fiber running the dialog parks mid-body (the quasi-modal wait). The stale-fiber +guard correctly marks it `__internallyParked` — its slice ended with a sleep in flight. +Its resume then arrives and is **refused** (`fiber-resume-refused`), because a quarantined +fiber has no valid suspension; the guard's contract is "the parked body completes via its +own wake." Here that wake *is* the refused resume, so nothing ever completes: + +- the fiber never resumes → the dispatch guard it holds is never released → +- `wxWasmDispatchParked()` stays true forever → `ProcessEvents` is Paint-only and + `wxWasmMailboxDeliver` bails → **every** subsequent click is deferred and never drained, + and timer delivery stops (the frozen 652). +- The × works because `wx_window_close` (`toplevel.cpp`) is ungated and synchronous. + +The 8/4 triage saw the *outer* ring of this (deferred clicks + a drain gated on the same +predicate) and proposed flushing the queue at depth 0 — that cannot help: the depth never +returns to 0 because the holder is stranded. + +## 5. Open: regression or pre-existing? + +Undetermined. The quarantine guard and the aliasing repair are pre-existing (ported +verbatim into the scheduler at S2), but S4 changed *how* a quasi-modal parks +(`wxWasmRunNestedLoop` pump → `wxWasmBeginWait`/`wxWasmYieldUntil`). Both shapes park the +fiber mid-body, so the quarantine interaction plausibly predates S4 — but that must be +proven, not assumed. **A hand-edited legacy glue is not a valid comparison** (attempted +2026-08-05: stripping the scheduler and re-injecting `handlesleep.js` into a C-lane build +booted to a fatal `TypeError: … reading 'mode'`). The differential needs a real +`WX_SCHEDULER=0` docker build of `kicad_editor`, same flow. + +## 6. Fix directions (ranked, none implemented) + +1. **Don't drop a refused resume — defer it.** When `__refuseFiber` fires for a fiber in + `__internallyParked`, record the pending resume and retry it when that fiber's park + resolves (`__parkSleepBuf` already maps fiber → its sleep buffer, and the sleep's + context leaving `__pendingSleepContexts` is the exact "now safe" signal). This is the + same drop→deliver flip the whole mailbox migration is built on, applied one layer down. + Caveat: doc 16 closed the *deferral family* for the root-hot case (a suspension broken + at write time). This is a different case — a healthy fiber quarantined mid-body — so the + closure does not automatically apply, but the round-6 evidence must be re-read first. +2. **Make a permanently-held interlock loud** (watchdog beacon after N seconds with a + parked holder). Diagnostic only, but it turns this class from "UI mysteriously dead" + into a one-line console verdict. +3. **Handler fibers** (the ledgered Design-B step): if parkable handlers own scheduler + contexts, "a parked chain holds the global interlock" stops being representable. This is + the structural cure and the S5 ledger's unlock for deleting the interlock entirely. diff --git a/tests/kicad/dialog-deadlock-probe.spec.ts b/tests/kicad/dialog-deadlock-probe.spec.ts new file mode 100644 index 0000000..70d2914 --- /dev/null +++ b/tests/kicad/dialog-deadlock-probe.spec.ts @@ -0,0 +1,187 @@ +import type { Page } from '@playwright/test'; +import { test, expect } from './fixtures'; + +/** + * PROBE (temporary, not a gate): the reported "Symbol Properties dialog is + * unresponsive to clicks, only the titlebar X closes it" bug. + * Triage 2026-08-04 blamed a dispatch-interlock self-deadlock; this spec exists + * to establish the ACTUAL mechanism empirically before any fix lands: + * + * A. clicks never reach wx → wx_dom_event early-returns + * (!IsEnabled — WINDOW_DISABLER makes + * IsEnabled() false through the parent + * chain), or no DOM element is hit; + * B. clicks reach wx but are DEFERRED → wxWasmDispatchParked() true and the + * drain is gated on the same predicate; + * C. clicks dispatch and work → the bug needs another ingredient. + * + * The probe instruments wx_dom_event traffic from JS and reports which. + */ + +const SCH = `(kicad_sch +\t(version 20231120) +\t(generator "eeschema") +\t(uuid "aaaa0000-0000-0000-0000-000000000001") +\t(paper "A4") +\t(lib_symbols +\t\t(symbol "Device:R" +\t\t\t(pin_numbers (hide yes)) +\t\t\t(pin_names (offset 0)) +\t\t\t(exclude_from_sim no) (in_bom yes) (on_board yes) +\t\t\t(property "Reference" "R" (at 2.032 0 90) (effects (font (size 1.27 1.27)))) +\t\t\t(property "Value" "R" (at 0 0 90) (effects (font (size 1.27 1.27)))) +\t\t\t(symbol "R_0_1" +\t\t\t\t(rectangle (start -1.016 -2.54) (end 1.016 2.54) +\t\t\t\t\t(stroke (width 0.254) (type default)) (fill (type none))) +\t\t\t) +\t\t\t(symbol "R_1_1" +\t\t\t\t(pin passive line (at 0 3.81 270) (length 1.27) +\t\t\t\t\t(name "~" (effects (font (size 1.27 1.27)))) +\t\t\t\t\t(number "1" (effects (font (size 1.27 1.27))))) +\t\t\t\t(pin passive line (at 0 -3.81 90) (length 1.27) +\t\t\t\t\t(name "~" (effects (font (size 1.27 1.27)))) +\t\t\t\t\t(number "2" (effects (font (size 1.27 1.27))))) +\t\t\t) +\t\t) +\t) +\t(symbol +\t\t(lib_id "Device:R") +\t\t(at 100 100 0) +\t\t(unit 1) +\t\t(exclude_from_sim no) (in_bom yes) (on_board yes) (dnp no) +\t\t(uuid "bbbb0000-0000-0000-0000-000000000002") +\t\t(property "Reference" "R1" (at 102 98 0) (effects (font (size 1.27 1.27)) (justify left))) +\t\t(property "Value" "10k" (at 102 101 0) (effects (font (size 1.27 1.27)) (justify left))) +\t\t(instances (project "probe" (path "/aaaa0000-0000-0000-0000-000000000001" (reference "R1") (unit 1)))) +\t) +)`; + +type Mod = { kicadOpenFile(p: string): unknown; kicadOpenFileBusy?: () => boolean }; +type FS = { mkdirTree(p: string): void; writeFile(p: string, d: string): void }; + +async function bootAndLoad(page: Page): Promise { + await page.goto('/kicad/eeschema.html'); + await page.waitForFunction(() => !!window.wxElementRegistry, null, { timeout: 90000 }); + await page.waitForFunction( + () => typeof (window.Module as unknown as Partial)?.kicadOpenFile === 'function', + null, + { timeout: 90000 }, + ); + await page.waitForFunction( + () => + !!window.wxElementRegistry && + window.wxElementRegistry.findAll({ visible: true }) + .some((e) => /Frame$/.test(e.typeName) || (e.name || '').endsWith('Frame')), + null, + { timeout: 90000 }, + ); + await page.evaluate((sch) => { + const w = window as unknown as { FS: FS; Module: Mod }; + const dir = '/home/kicad/documents'; + try { w.FS.mkdirTree(dir); } catch { /* exists */ } + w.FS.writeFile(`${dir}/probe.kicad_sch`, sch); + w.Module.kicadOpenFile(`${dir}/probe.kicad_sch`); + }, SCH); + await expect.poll(() => page.title(), { timeout: 60000 }).toMatch(/probe/i); + await page.waitForTimeout(2000); +} + +test.describe('PROBE: symbol-properties dialog responsiveness', () => { + test('double-click a symbol, then click OK — what happens to the click?', async ({ + page, + testLogger, + }) => { + test.setTimeout(180000); + await bootAndLoad(page); + + // Instrument the DOM-event bridge: record every wx_dom_event ccall and + // whether wx deferred it (interlock parked) at that moment. + await page.evaluate(() => { + const w = window as unknown as { + Module: { ccall: (...a: unknown[]) => unknown; _wxWasmDispatchDepthProbe?: () => number }; + __probe: { calls: { domId: number; kind: number }[] }; + }; + w.__probe = { calls: [] }; + const origCcall = w.Module.ccall.bind(w.Module); + w.Module.ccall = function (name: unknown, ...rest: unknown[]) { + if (name === 'wx_dom_event') { + const args = rest[2] as number[]; + w.__probe.calls.push({ domId: args[0], kind: args[1] }); + } + return origCcall(name, ...rest); + } as typeof w.Module.ccall; + }); + + // Open Symbol Properties WITHOUT pixel hit-testing: select the first item + // through the e2e lever, then use the "edit properties" hotkey (E). + const canvas = page.locator('#canvas'); + const box = (await canvas.boundingBox())!; + await page.mouse.click(box.x + 40, box.y + 40); // focus the canvas + const selected = await page.evaluate(() => { + const m = window.Module as unknown as { kicadCollabTestSelectFirst?: () => unknown }; + if (typeof m.kicadCollabTestSelectFirst !== 'function') return 'lever-missing'; + try { m.kicadCollabTestSelectFirst(); return 'ok'; } catch (e) { return String(e); } + }); + console.log(`[PROBE] select-first: ${selected}`); + await page.waitForTimeout(500); + await page.keyboard.press('e'); + + // A dialog should appear. Report what the registry sees either way. + const dialogInfo = await page + .waitForFunction( + () => { + const r = window.wxElementRegistry!; + const dlg = r.findAll({ visible: true }) + .filter((e) => /Dialog/.test(e.typeName)); + return dlg.length > 0 ? JSON.stringify(dlg.map((d) => ({ t: d.typeName, n: d.name }))) : null; + }, + null, + { timeout: 30000 }, + ) + .then((h) => h.jsonValue()) + .catch(() => null); + console.log(`[PROBE] dialogs after dblclick: ${dialogInfo ?? 'NONE'}`); + test.skip(!dialogInfo, 'no dialog opened — dblclick did not reach the edit tool'); + + // Find a clickable DOM button inside the dialog and click it. + const buttons = await page.evaluate(() => { + const els = Array.from(document.querySelectorAll('button')); + return els.map((b, i) => ({ + i, + text: (b.textContent || '').trim().slice(0, 24), + visible: !!(b.offsetWidth || b.offsetHeight), + enabled: !b.disabled, + domId: (b as HTMLElement).dataset.wxDomId ?? null, + })).filter((b) => b.visible); + }); + console.log(`[PROBE] visible DOM buttons: ${JSON.stringify(buttons.slice(0, 12))}`); + + const okIdx = buttons.findIndex((b) => /^OK$/i.test(b.text)); + console.log(`[PROBE] OK button index: ${okIdx}`); + if (okIdx >= 0) { + await page.evaluate((i) => { + const els = Array.from(document.querySelectorAll('button')).filter( + (b) => !!((b as HTMLElement).offsetWidth || (b as HTMLElement).offsetHeight), + ); + (els[i] as HTMLElement).click(); + }, okIdx); + } + await page.waitForTimeout(3000); + + const after = await page.evaluate(() => { + const r = window.wxElementRegistry!; + const dlgs = r.findAll({ visible: true }).filter((e) => /Dialog/.test(e.typeName)); + const p = (window as unknown as { __probe: { calls: unknown[] } }).__probe; + return { dialogsStillOpen: dlgs.length, domEventCalls: p.calls.length }; + }); + console.log( + `[PROBE] after OK click: dialogsStillOpen=${after.dialogsStillOpen} ` + + `wx_dom_event calls seen=${after.domEventCalls}`, + ); + const deferBeacons = testLogger.consoleLogs.filter((l) => /wx-dispatch|retry storm/.test(l)); + console.log(`[PROBE] interlock beacons: ${deferBeacons.length}`); + + // The probe always "passes"; its console output is the deliverable. + expect(true).toBe(true); + }); +});