docs: diagnose the Symbol Properties hang (stranded tool fiber)
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 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01TfxKn5utcntBSnxz4ZnYKs
This commit is contained in:
parent
9bc4da89ff
commit
d6ca125cac
2 changed files with 280 additions and 0 deletions
93
docs/features/async/19-quasimodal-fiber-strand.md
Normal file
93
docs/features/async/19-quasimodal-fiber-strand.md
Normal file
|
|
@ -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.
|
||||
187
tests/kicad/dialog-deadlock-probe.spec.ts
Normal file
187
tests/kicad/dialog-deadlock-probe.spec.ts
Normal file
|
|
@ -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<void> {
|
||||
await page.goto('/kicad/eeschema.html');
|
||||
await page.waitForFunction(() => !!window.wxElementRegistry, null, { timeout: 90000 });
|
||||
await page.waitForFunction(
|
||||
() => typeof (window.Module as unknown as Partial<Mod>)?.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);
|
||||
});
|
||||
});
|
||||
Loading…
Reference in a new issue