diff --git a/docs/features/async/15-timer-park-repro.md b/docs/features/async/15-timer-park-repro.md index 0d4199c..cf45ad8 100644 --- a/docs/features/async/15-timer-park-repro.md +++ b/docs/features/async/15-timer-park-repro.md @@ -119,7 +119,37 @@ The lever + spec stay as the regression gate for the fix regardless: they deterministically create and verify the concurrent-park window that all three shipped fixes were blind to. -## Candidate real fix (only after a red) +## Round 3 — v0.1.20 PROD crash decoded (2026-07-31 late, log console-export-2026-7-31_22-33-27.log) + +The crash reproduced in prod with the diagnostics live, and they discriminate +cleanly: ZERO `concurrent-park`, ZERO `aliased-wake-live` (this spec's +collision class is NOT the prod mechanism — the two green rounds were a true +negative), exactly one benign `overlapped-wake … over null` 2 ms after +`open:settled`, traps 218 ms later. Decoding the trap stack against the +shipped runtime source: + +**Root cause: a KiCad coroutine is Resume()d while its body is +asyncify-parked inside handleSleep.** libcontext-on-emscripten-fibers and +handleSleep are two independent suspension protocols sharing one context: a +fiber suspended by `fiber_swap` has valid rewind data at `fiber+20`; a fiber +whose body parked via handleSleep does NOT (its live state is in the sleep's +allocateData buffer, invisible to the fiber machinery — and to TOOL_MANAGER). +Resume → `fiber_swap` into it → `finishContextSwitch` rewinds the STALE +`fiber+20` → rewind-path mismatch → "unreachable executed"; every subsequent +entry (the GAL timer's async_call cascade among them) reads poisoned asyncify +state → "index out of bounds". Impossible on native (no parking without +yielding), unreachable in this spec (warm fibers never park internally), and +untouched by all three shipped fixes. + +Next: a `kicadTestSetFiberPark(ms)`-style lever (coroutine body that +`emscripten_sleep()`s + a Resume poked mid-park) as spec cycle 5 — expected +deterministically RED with exactly the prod signature — then the fix: track +"asyncify park in flight" per fiber and defer Resume/swap-into until the +park completes (wasm layer; `kicadCollabFiberBusy` from drift-trio #10b is +the precedent). + +## Candidate real fix for the timer half (superseded by round 3 for the prod +crash, still sound hygiene) Deliver timer notifies from the main-loop chain: the JS timer callback only marks the timer due and wakes the yield; the loop dispatches due timers after diff --git a/docs/features/async/16-fiber-resume-guard.md b/docs/features/async/16-fiber-resume-guard.md new file mode 100644 index 0000000..baa6b64 --- /dev/null +++ b/docs/features/async/16-fiber-resume-guard.md @@ -0,0 +1,85 @@ +# 16 — Fiber resume guard (the production board-load trap, fixed) + +Status: 2026-07-31 · red/green e2e `tests/kicad/fiber-resume-park.spec.ts` · +lineage: 14 (open-settle gate), 15 (timer-park lever + the v0.1.20 decode), +drift-trio #10b (fiber buffers, ghost beacons). + +## The bug + +`RuntimeError: index out of bounds` / `unreachable executed` on prod board +loads (editor.pcbjam.com, v0.1.12 → v0.1.20), runtime permanently poisoned +afterwards. Survived three shipped fixes aimed at other reentrancy holes +(open-settle gate, dispatch interlock, busy-guard-holds-interlock). + +**Root cause — two suspension protocols share one context.** KiCad coroutines +(TOOL_MANAGER tool loops, collab fiber bodies) run on emscripten fibers via +the libcontext wasm port. A coroutine suspended by a real yield +(`jump_fcontext` → `emscripten_fiber_swap`) has valid rewind state in its +fiber struct. A coroutine whose body is asyncify-parked inside `handleSleep` +(lib-bridge wait, `emscripten_sleep`, any EM_ASYNC_JS below a tool handler) +is suspended in a way the fiber machinery — and TOOL_MANAGER — cannot see: +its live state sits in the sleep's buffer, and the fiber struct still holds +the stale data of its LAST real yield. Natively this state cannot exist (a +coroutine cannot be suspended without yielding), so no upstream code guards +it. + +When the next event arrives during such a park, TOOL_MANAGER `Resume()`s the +"waiting" tool → `finishContextSwitch` rewinds the STALE fiber suspension → +binaryen's rewind-path mismatch `unreachable`, or replayed frames clobber the +parked body's stack; the sleep's wake then rewinds into wreckage. Every later +Asyncify entry (the GAL refresh timer's `emscripten_async_call` cascade was +the usual first victim, which is why the symbolization kept pointing at +timers) reads poisoned state → `index out of bounds`. + +Trigger window in prod: right after `open:settled`, presync/realtime lib +churn + first-paint activity dispatch events while tool bodies still park in +lib waits. Fast loads crash too — the window needs only one event during one +park. + +## The evidence chain + +1. v0.1.20 shipped rate-limited `[wx-asyncify]` reporting in the handlesleep + shim + the `[wx-timer]`/`[wx-dispatch]` channels. The crashing prod log + (console-export-2026-7-31_22-33-27.log) showed NO concurrent-park, NO + retry storms, NO depth erasure — every competing hypothesis ruled out on a + live crash — and one `overlapped-wake … over null` 2 ms after settle: a + fiber fingerprint (`finishContextSwitch`/`fiber_swap` are the only + mid-flight sources of a null `currData`). +2. The trap-2 stack decoded mechanically against the shipped runtime: + `maybeStopUnwind → Fibers.trampoline → finishContextSwitch → doRewind → + unreachable` — a fiber swap-in rewinding stale data at the tail of an + unwind. +3. The lever (`wasm/bindings/fiber_park.h`, `kicadTestFiberPark*`) stages the + state machine deterministically: Call + yield (valid suspension) → + legitimate resume → body parks in `emscripten_sleep` → **Resume during the + park**. RED on the unguarded runtime: fiber-buffer/sleep-buffer + cross-restores (`aliased-wake-live` 103710720 ⇄ 406683648), a + `jump-ghost` beacon, and the parked body zombified (its wake lost — in + prod, the next timer/tool entry turns this into the loud trap). + +## The fix + +`kicad/thirdparty/libcontext/libcontext.cpp` (wasm port only): +`wasm_fcontext::swap_suspended` — true only between a real `fiber_swap` +suspension and the next swap-in (set at both swap sites; fresh contexts start +true, the entry-point path needs no rewind). `jump_fcontext` REFUSES a target +whose flag is false — returns 0, the null-`INVOCATION_ARGS` contract the +jump-ghost path already established, with a rate-limited +`[collab-fcontext] jump-refused` beacon. The refused dispatch is dropped; the +parked body completes via its own wake, suspends properly, and the next +dispatch lands normally. + +Why refuse rather than wait: a waiting guard (park the resumer until the +target suspends) deadlocks against the yield-back path — the target's yield +needs to swap into the very context that is busy waiting. + +## Verification + +- `fiber-resume-park.spec.ts` red on unguarded build (phase-3 poll dies), + green with the guard: mid-park poke refused + logged, body completes its + park, second yield reached, post-yield resume works, no trap signatures, + model walk functional afterwards. +- `timer-park-repro.spec.ts`, `collab-load-fuzz.spec.ts`, `load-pcb.spec.ts` + stay green (guard must not refuse valid suspensions). +- Prod validation: watch for `jump-refused` beacons in the next crash-free + Leonardo load — each one is a would-have-been crash. diff --git a/kicad b/kicad index ca1dde0..f0ce20e 160000 --- a/kicad +++ b/kicad @@ -1 +1 @@ -Subproject commit ca1dde0e5ffdd9fa32062d816c59a301d1d0fc6c +Subproject commit f0ce20ef645059c7c8443626d6aa2b94a32e80cf diff --git a/tests/kicad/fiber-resume-park.spec.ts b/tests/kicad/fiber-resume-park.spec.ts new file mode 100644 index 0000000..eda5a5f --- /dev/null +++ b/tests/kicad/fiber-resume-park.spec.ts @@ -0,0 +1,143 @@ +import type { Page } from "@playwright/test"; +import { test, expect } from "./fixtures"; + +/** + * Resume-into-asyncify-parked-coroutine repro — the DECODED production + * board-load trap (docs/features/async/15-timer-park-repro.md round 3). + * + * A coroutine suspended by a real yield has valid rewind data in its fiber + * struct; one whose body is asyncify-parked inside handleSleep does NOT. + * TOOL_MANAGER cannot tell the difference, so an event arriving during the + * park Resume()s it → the swap rewinds the STALE suspension → + * finishContextSwitch → doRewind → "unreachable executed", and the runtime is + * poisoned ("index out of bounds" from every later entry). The + * kicadTestFiberPark* levers (wasm/bindings/fiber_park.h) stage exactly that + * state machine: + * + * start(parkMs) Call + first KiYield — valid suspension primed (phase 1) + * prime() legitimate Resume; body parks in emscripten_sleep (phase 2) + * poke() Resume DURING the park — the fatal prod operation + * + * This spec asserts the HEALTHY contract: the mid-park poke must be refused + * (null-INVOCATION_ARGS ghost contract), the body must complete its park and + * yield again undisturbed, a post-yield poke must resume it for real, and no + * trap signature may appear anywhere. On a runtime without the libcontext + * guard this is deterministically RED with the prod signature. + */ + +const TRAP_SIGNATURE = + /Aborted\(|index out of bounds|unreachable executed|indirect call signature|null function or function signature|memory access out of bounds/; + +type Mod = { + kicadTestFiberParkStart(parkMs: number): boolean; + kicadTestFiberParkPrime(): boolean; + kicadTestFiberParkPoke(): boolean; + kicadTestFiberParkState(): string; + kicadCollabSnapshotItems(): string; +}; + +interface ParkState { + phase: number; + pokes: number; + parkMs: number; + running: boolean; +} + +async function bootHarness(page: Page): Promise { + await page.goto("/kicad/pcbnew-collab.html"); + await expect(page.locator("#canvas")).toBeVisible({ timeout: 90000 }); + await page.waitForFunction(() => !!window.wxElementRegistry, null, { timeout: 90000 }); + await page.waitForFunction( + () => { + const m = (window as unknown as { Module?: Partial }).Module; + return ( + typeof m?.kicadTestFiberParkStart === "function" && + typeof m?.kicadCollabSnapshotItems === "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 }, + ); +} + +function parkState(page: Page): Promise { + return page.evaluate(() => + JSON.parse((window.Module as unknown as Mod).kicadTestFiberParkState()), + ); +} + +test.describe("Resume() into an asyncify-parked coroutine (libcontext guard)", () => { + test("mid-park resume is refused; the parked body completes undisturbed", async ({ + page, + testLogger, + }) => { + test.setTimeout(240000); + await bootHarness(page); + + // Phase 1: prime a real suspension (Call + first KiYield). NOTE: embind + // return values are asyncify unwind PLACEHOLDERS for anything that + // crosses a fiber swap (the real return lands in the discarded ghost + // rewind) — every assertion here is on polled state, never on returns. + await page.evaluate(() => { + (window.Module as unknown as Mod).kicadTestFiberParkStart(2000); + }); + await expect + .poll(async () => (await parkState(page)).phase, { timeout: 10000, intervals: [50] }) + .toBe(1); + + // Phase 2: legitimate resume; the body enters its 2s asyncify park. + await page.evaluate(() => { + (window.Module as unknown as Mod).kicadTestFiberParkPrime(); + }); + await expect + .poll(async () => (await parkState(page)).phase, { timeout: 10000, intervals: [50] }) + .toBe(2); + + // THE PROD OPERATION: resume while the body is parked. On an unguarded + // runtime this rewinds the stale fiber suspension and traps right here + // (the page's uncaught "unreachable executed"); with the guard it is a + // clean no-op refusal. + await page.evaluate(() => { + (window.Module as unknown as Mod).kicadTestFiberParkPoke(); + }); + const afterPoke = await parkState(page); + console.log(`[TEST] mid-park poke: ${JSON.stringify(afterPoke)}`); + expect(afterPoke.pokes, "poke reached the coroutine layer").toBe(1); + expect(afterPoke.phase, "refused poke left the parked body undisturbed").toBe(2); + + // The park must complete on its own wake and yield again (phase 3) — + // if the poke corrupted the fiber, the wake rewind dies instead. + await expect + .poll(async () => (await parkState(page)).phase, { timeout: 15000, intervals: [100] }) + .toBe(3); + + // A post-yield poke is a LEGITIMATE resume and must work (the guard must + // not refuse valid suspensions): body runs to completion. + await page.evaluate(() => { + (window.Module as unknown as Mod).kicadTestFiberParkPoke(); + }); + await expect + .poll(async () => (await parkState(page)).phase, { timeout: 10000, intervals: [100] }) + .toBe(4); + + // Runtime integrity: a model walk still works and no trap signature + // appeared anywhere in the console. + const snapshot = await page.evaluate(() => + (window.Module as unknown as Mod).kicadCollabSnapshotItems(), + ); + expect(typeof snapshot, "snapshot entry still functional").toBe("string"); + const trapLines = [...testLogger.consoleLogs, ...testLogger.errors].filter((l) => + TRAP_SIGNATURE.test(l), + ); + expect(trapLines, "no wasm trap signature anywhere in the run").toEqual([]); + }); +}); diff --git a/wasm/bindings/fiber_park.h b/wasm/bindings/fiber_park.h new file mode 100644 index 0000000..3edbc31 --- /dev/null +++ b/wasm/bindings/fiber_park.h @@ -0,0 +1,127 @@ +/* + * Test-only repro lever for the DECODED production board-load trap + * (docs/features/async/15-timer-park-repro.md round 3, 2026-07-31): + * resuming a KiCad coroutine while its body is asyncify-parked inside + * handleSleep. + * + * Two suspension protocols share one context on wasm. A coroutine suspended + * by a real yield (fiber_swap) has valid rewind data in its fiber struct; a + * coroutine whose body parked via handleSleep (lib-bridge wait, + * emscripten_sleep) does NOT — its live state is in the sleep's buffer, + * invisible to the fiber machinery and to TOOL_MANAGER. Resume() then swaps + * into the STALE fiber data: finishContextSwitch → doRewind → "unreachable + * executed", and every later entry reads poisoned Asyncify state ("index out + * of bounds"). Impossible natively — a coroutine cannot be suspended without + * yielding. + * + * The lever stages the prod state machine exactly: + * start(parkMs): Call() a coroutine that immediately KiYield()s — this + * writes VALID suspension data once and clears the fresh-entry path, the + * state every long-lived tool loop is in. + * prime(): Resume() it legitimately — the body then emscripten_sleep()s + * (the internal park; prime's Resume ghost-returns per the epoch + * machinery) and afterwards KiYield()s again. + * poke(): Resume() DURING the sleep — the fatal prod operation. Unfixed + * runtime: rewinds the stale suspension → the exact prod trap. Fixed + * runtime: the jump is refused (null INVOCATION_ARGS, same contract as + * jump-ghost) and the body completes undisturbed; a later poke() after + * the second KiYield resumes it for real. + * + * Production is inert: nothing runs unless start() is called. + */ +#pragma once + +#include +#include + +#include +#include + +namespace pcbjam_fiber_park +{ + +struct State +{ + // 0 idle · 1 yielded-once (primed suspension) · 2 in the sleep park · + // 3 woke, yielded again · 4 resumed past second yield · 5 body returned + int phase = 0; + int parkMs = 0; + int pokes = 0; +}; + +inline State& state() +{ + static State s_state; + return s_state; +} + +inline COROUTINE*& co() +{ + static COROUTINE* s_co = nullptr; + return s_co; +} + +inline int fiberBody( int ) +{ + state().phase = 1; + co()->KiYield(); + + state().phase = 2; + if( state().parkMs > 0 ) + emscripten_sleep( state().parkMs ); + + state().phase = 3; + co()->KiYield(); + + state().phase = 4; + return 0; +} + +/** Call() + first KiYield: coroutine now has VALID fiber suspension data. */ +inline bool start( int aParkMs ) +{ + if( co() && co()->Running() ) + return false; // one in flight; the spec drives one cycle at a time + + delete co(); + state() = State(); + state().parkMs = aParkMs; + co() = new COROUTINE( fiberBody ); + co()->Call( 0 ); + return state().phase == 1; +} + +/** Legitimate Resume into the primed yield; the body then parks. Ghost-returns. */ +inline bool prime() +{ + if( !co() ) + return false; + + return co()->Resume(); +} + +/** + * Resume() regardless of the body's suspension state — what TOOL_MANAGER does + * on the next event, unaware the body is asyncify-parked. Counted so the spec + * can correlate pokes with phases. + */ +inline bool poke() +{ + if( !co() ) + return false; + + ++state().pokes; + return co()->Resume(); +} + +inline std::string stateJson() +{ + char buf[112]; + snprintf( buf, sizeof( buf ), + "{\"phase\":%d,\"pokes\":%d,\"parkMs\":%d,\"running\":%s}", + state().phase, state().pokes, state().parkMs, + ( co() && co()->Running() ) ? "true" : "false" ); + return buf; +} + +} // namespace pcbjam_fiber_park diff --git a/wasm/bindings/kicad_editor_embind.cpp b/wasm/bindings/kicad_editor_embind.cpp index c5ad4ee..cd6a1c1 100644 --- a/wasm/bindings/kicad_editor_embind.cpp +++ b/wasm/bindings/kicad_editor_embind.cpp @@ -42,6 +42,7 @@ #include "pcbjam_libs_reload.h" #include "open_gate.h" #include "timer_park.h" +#include "fiber_park.h" using namespace emscripten; @@ -188,6 +189,28 @@ static std::string kicadTestTimerParkState() return pcbjam_timer_park::stateJson(); } +// Test-only (fiber-resume-park repro, fiber_park.h): Resume() into an +// asyncify-parked coroutine — the decoded prod board-load trap. +static bool kicadTestFiberParkStart( int aParkMs ) +{ + return pcbjam_fiber_park::start( aParkMs ); +} + +static bool kicadTestFiberParkPrime() +{ + return pcbjam_fiber_park::prime(); +} + +static bool kicadTestFiberParkPoke() +{ + return pcbjam_fiber_park::poke(); +} + +static std::string kicadTestFiberParkState() +{ + return pcbjam_fiber_park::stateJson(); +} + // Canvas-only chrome toggle (features/mobile): hide/show every AUI pane // except the central draw canvas, plus the menubar and status bar, so the GAL @@ -544,6 +567,10 @@ EMSCRIPTEN_BINDINGS(kicad_editor) { function("kicadTestSetOpenPark", &kicadTestSetOpenPark); function("kicadTestArmTimerPark", &kicadTestArmTimerPark); function("kicadTestTimerParkState", &kicadTestTimerParkState); + function("kicadTestFiberParkStart", &kicadTestFiberParkStart); + function("kicadTestFiberParkPrime", &kicadTestFiberParkPrime); + function("kicadTestFiberParkPoke", &kicadTestFiberParkPoke); + function("kicadTestFiberParkState", &kicadTestFiberParkState); // Canvas-only mobile mode (features/mobile). function("kicadSetChrome", &kicadSetChrome); diff --git a/wasm/bindings/pcbnew_embind.cpp b/wasm/bindings/pcbnew_embind.cpp index abf30c1..34ee94f 100644 --- a/wasm/bindings/pcbnew_embind.cpp +++ b/wasm/bindings/pcbnew_embind.cpp @@ -54,6 +54,7 @@ #include "collab_presence_core.h" #include "open_gate.h" #include "timer_park.h" +#include "fiber_park.h" #include "collab_presence_style.h" #include "pcbjam_theme.h" #include "pcbjam_libs_reload.h" @@ -137,6 +138,28 @@ std::string kicadTestTimerParkState() return pcbjam_timer_park::stateJson(); } +// Test-only (fiber-resume-park repro, fiber_park.h): Resume() into an +// asyncify-parked coroutine — the decoded prod board-load trap. +bool kicadTestFiberParkStart( int aParkMs ) +{ + return pcbjam_fiber_park::start( aParkMs ); +} + +bool kicadTestFiberParkPrime() +{ + return pcbjam_fiber_park::prime(); +} + +bool kicadTestFiberParkPoke() +{ + return pcbjam_fiber_park::poke(); +} + +std::string kicadTestFiberParkState() +{ + return pcbjam_fiber_park::stateJson(); +} + // Read-only viewer lock (read-only-viewer): flips the process-global // PCBJAM_READ_ONLY flag consumed by TOOL_MANAGER (view-only action allowlist) // and the selection tools (nothing selectable), and mirrors it onto the @@ -2401,6 +2424,10 @@ EMSCRIPTEN_BINDINGS(pcbnew) { function("kicadTestSetOpenPark", &kicadTestSetOpenPark); function("kicadTestArmTimerPark", &kicadTestArmTimerPark); function("kicadTestTimerParkState", &kicadTestTimerParkState); + function("kicadTestFiberParkStart", &kicadTestFiberParkStart); + function("kicadTestFiberParkPrime", &kicadTestFiberParkPrime); + function("kicadTestFiberParkPoke", &kicadTestFiberParkPoke); + function("kicadTestFiberParkState", &kicadTestFiberParkState); function("kicadCollabFiberBusy", &kicadCollabFiberBusyProbe); // Read-only viewer lock (read-only-viewer). function("kicadSetReadOnly", &kicadSetReadOnly);