From 945e842b6796281533edfb36bdc86366673993d7 Mon Sep 17 00:00:00 2001 From: Ryan Lee Date: Fri, 14 Aug 2026 19:27:27 +0000 Subject: [PATCH 01/18] docs(plans): plan the call-time budget for protocol requests --- ...-protocol-request-call-time-budget-plan.md | 243 ++++++++++++++++++ 1 file changed, 243 insertions(+) create mode 100644 docs/plans/2026-08-14-1856-fix-protocol-request-call-time-budget-plan.md diff --git a/docs/plans/2026-08-14-1856-fix-protocol-request-call-time-budget-plan.md b/docs/plans/2026-08-14-1856-fix-protocol-request-call-time-budget-plan.md new file mode 100644 index 00000000..8e356038 --- /dev/null +++ b/docs/plans/2026-08-14-1856-fix-protocol-request-call-time-budget-plan.md @@ -0,0 +1,243 @@ +--- +title: Protocol Request Call-Time Budget - Plan +type: fix +date: 2026-08-14 +artifact_contract: ce-unified-plan/v1 +artifact_readiness: implementation-ready +product_contract_source: ce-plan-bootstrap +execution: code +--- + +# Protocol Request Call-Time Budget - Plan + +## Goal Capsule + +- Objective: a protocol request rejects within its own per-method budget measured from the moment `postRequest` is called, including time spent waiting for the host or protocol frame, and the rejection names which phase consumed the budget. +- Authority: the Requirements below win on behavior. The Key Technical Decisions win on mechanism inside those Requirements. Origin issue: `paritytech/dotli-community#166`. +- Scope: `packages/protocol/src/client.ts`, `packages/protocol/src/errors.ts`, `packages/protocol/tests/client.test.ts`, and one doc comment in `packages/metrics/src/spans.ts`. No other package changes. +- Stop conditions: stop and report if the frame double described in U4 cannot drive `createHostIframe` without a real network navigation, or if any existing test in `packages/protocol` fails for a reason this plan did not predict. +- Tail: the caller owns commit, push, and PR. + +--- + +## Product Contract + +### Summary + +Compute the per-method timeout before the frame wait and arm one timer at call time. Race that single timer against the frame wait and then against the reply wait. Reject with a typed error that carries the phase the budget was spent in: `load`, `ready`, or `reply`. Leave every existing timeout constant at its current value. + +### Problem Frame + +`postRequest` awaits `ensureProtocolFrame()` or `ensureHostFrame()` at `packages/protocol/src/client.ts:504` and only then computes `timeoutMs` (`:519-521`) and arms the reply timer (`:528`). The frame wait carries its own budget: `IFRAME_LOAD_TIMEOUT_MS = 30_000` (`:317`) and `IFRAME_READY_TIMEOUT_MS = 240_000` (`:321`). The rejection that finally arrives does not say whether the time went into booting the frame or waiting for a reply. + +Worst case differs by branch, so the exposure is not uniform. A ready-branch request blocks for up to roughly 270 seconds (240 second ready wait plus its own budget) while its documented contract says 30. A shared-branch request awaits only `ensureHostFrame()`, so its worst case is roughly 60 seconds. + +The blast radius is the boot path. `apps/host/src/main.ts:1324` resolves a name during boot on the ready branch, so it carries the 270 second exposure. `packages/ui/src/shared-mode.ts:97-99` reads shared-mode preferences and `packages/ui/src/host-callbacks/SessionStore.ts:124` reads the session, both on the shared branch at roughly 60 seconds. Each of the three is a first request. + +### Requirements + +**Bound** + +- R1. A non-`warmup` request rejects no later than its own per-method budget, measured from the call, whether the budget is consumed by the frame wait or the reply wait. +- R2. `warmup` stays exempt from a request budget. Its rejection sources stay exactly what they are today: the frame wait, the reset error at `client.ts:168`, the unavailable-frame error at `:507`, and a `fatal` or `init-failed` envelope. +- R3. No existing timeout constant is reduced. `IFRAME_LOAD_TIMEOUT_MS`, `IFRAME_READY_TIMEOUT_MS`, `DEFAULT_TIMEOUT_MS`, and every `METHOD_TIMEOUTS` entry keep their current values. + +**Attribution** + +- R4. A budget rejection names the phase that consumed the budget. Three phases: host frame loading, protocol frame becoming ready, and waiting for a reply. +- R5. The phase is derived from observed progress, not from the `needsProtocolReady` flag. A request whose budget expires while the host frame is still loading reports the load phase even on the ready path. +- R6. A more specific error from the frame path wins over a budget rejection when it settles first. `ProtocolFatalError` (`packages/protocol/src/errors.ts:4`), `ProtocolInitFailedError` (`:11`), and the reset error at `client.ts:168` stay visible to callers. + +**Coverage** + +- R7. Both branches of `needsProtocolReady` are covered by a test that fails when the fix is reverted. The ready branch is covered by a frame that loads but never signals ready. The shared branch is covered by a frame whose load is deliberately late. +- R8. `bun run --cwd packages/protocol test` exits 0, and the 38 tests that pass today still pass. + +### Key Decisions + +- The three-phase vocabulary reuses the tokens already in the file. `client.ts:396` emits `phase: "load"` and `:465` emits `phase: "ready"` for `PROTOCOL_IFRAME_READY`. Governs R4, R5. +- The earlier-and-more-specific error wins rather than being wrapped in a timeout. Governs R6. + +### Scope Boundaries + +- In scope: the budget that `postRequest` owns. +- Not a goal: bounding the direct `ensureProtocolFrame()` calls at `apps/host/src/main.ts:990` and `client.ts:732`. Those are not requests and stay at 240 seconds. +- Not a goal: the unhandled rejection that `void ensureProtocolFrame()` and `void warmupProtocol()` at `apps/host/src/main.ts:990-991` already produce when the ready wait fails. Both stay untouched, for two different reasons: line 990 never enters `postRequest`, so no request budget could reach it, and line 991 is a `warmup` request that R2 keeps untimed. +- Not a goal: changing what `m.timer(S.PROTOCOL_REQUEST)` measures. See KTD5. + +#### Deferred to Follow-Up Work + +- Clearing `chainConnections` in `resetProtocolFrameState` so a `send()` after a reset fails fast instead of re-booting a frame. Surfaced while tracing `client.ts:787`, out of this issue's scope. + +### Sources + +- Defect anchors: `packages/protocol/src/client.ts:497-558` (`postRequest`), `:379-410` (`ensureHostFrame`), `:412-442` (`waitForProtocolReady`), `:444-479` (`ensureProtocolFrame`). +- Fast-fail precedent this plan preserves: `client.ts:156-173` (`resetProtocolFrameState`) and `:219-251` (the `fatal` and `init-failed` handler). +- Repo racing idiom: `packages/resolver/src/resolve.ts:212-220`, `packages/resolver/src/rpc-resolve.ts:93-102`, `packages/ui/src/topbar.ts:2099-2107`. There is no shared deadline helper and no `AbortSignal.timeout` anywhere in the repo. +- Method partition: `packages/protocol/src/auth-storage.ts:29-54`. Six methods take the shared branch (`authStorageRead`, `authStorageWrite`, `authStorageClear`, `modeStorageRead`, `modeStorageWrite`, `modeStorageClear`). The other eight take the ready branch. +- Metric attribute type is open (`packages/metrics/src/metrics.ts:45-57` ends in `& Record`), so a `phase` key typechecks. +- No test and no consumer anywhere asserts on a `client.ts` timeout string, and every caller catches generically without inspecting type or message. Verified across `apps/host/src/main.ts`, `packages/ui/src/shared-mode.ts`, `packages/ui/src/topbar.ts`, `packages/ui/src/bulletin-bitswap.ts`, `packages/ui/src/host-callbacks/SessionStore.ts`. + +--- + +## Planning Contract + +### Key Technical Decisions + +- KTD1. One timer armed at call time, raced against each phase. `startRequestBudget` arms a single `setTimeout(timeoutMs)` and exposes a `guard` that wraps a phase promise in `Promise.race`. Rejected alternative: deadline arithmetic with `Date.now()` and a second timer for the reply phase. That version depends on wall clock, so an NTP step or a laptop resume between phases silently moves the bound, and re-entering the timer queue adds the first timer's scheduling latency to the promised deadline. Advances R1. +- KTD2. `Promise.race` is the abandonment mechanism, with no manual `catch` on the loser. `Promise.race` attaches a handler to every operand, so a cached `hostFramePromise` or `protocolReadyPromise` that rejects after the budget won cannot become an unhandled rejection. A caller that abandons the wait and calls again rejoins the cached wait at `client.ts:451-452` while arming a fresh budget from its own call time, which is the semantics R1 asks for. Advances R1, R6. +- KTD3. Phase is a mutable variable read when the timer fires, and the ready branch is split into two guarded awaits. `postRequest` awaits `ensureHostFrame()` under phase `load`, flips to `ready`, awaits `ensureProtocolFrame()`, then flips to `reply`. The second call short-circuits at `client.ts:382` because `protocolIframe.contentWindow` is set by then. Rejected alternative: choosing the phase statically from `needsProtocolReady`, which mislabels a `chainConnect` budget (30_000 at `:490`) that expires during the 30_000 load wait as `ready`. Advances R4, R5. +- KTD4. A typed `ProtocolRequestTimeoutError` in `packages/protocol/src/errors.ts` carries `method`, `timeoutMs`, and `phase`. Tests assert on the `phase` field, not on message text. Rejected alternative: message-only attribution, which forces tests to match prose and gives callers nothing to branch on. Advances R4, R7. +- KTD5. `m.timer(S.PROTOCOL_REQUEST)` keeps starting at the reply transition, and `stopReq()` stays out of any shared `finally`. Frame boot is already measured twice by `PROTOCOL_IFRAME_READY` (`client.ts:394`, `:413`), so re-basing the request histogram would double-count boot into a per-request distribution and shift every dashboard percentile with no schema change to signal it. Sweeping `stopReq()` into a blanket `finally` would additionally start admitting failed requests into a histogram that today excludes them (`client.ts:547-552` deliberately omits it). Advances R3 by leaving telemetry semantics intact. +- KTD5b. `stopReq()` is called by `postRequest` around the reply guard, never by the budget timer callback. The callback is created before `stopReq` exists, so it cannot reach it. `postRequest` therefore awaits the reply guard in a `try`, calls `stopReq()` on success, and in the `catch` calls `stopReq()` only when the error is a `ProtocolRequestTimeoutError`, then rethrows. A `fatal`, `init-failed`, or response error still records no sample, matching `client.ts:547-552` today. Rejected alternative: passing a mutable stop-function holder into `startRequestBudget`, which puts metrics wiring inside a timing primitive to save nothing. Advances R3. +- KTD6. The budget is armed as the first statement inside the `try` whose `finally` releases it, and before the ensure promise is created. Arming first is what makes the 30_000-versus-30_000 collision deterministic: equal-expiry timers fire in creation order, so the budget beats `createHostIframe`'s load timer (`client.ts:349`). That ordering is load-bearing rather than incidental, because no method has a budget below `IFRAME_LOAD_TIMEOUT_MS`, so the tie is the only way a `load`-phase budget rejection is reachable at all. U4 asserts it directly and a comment in `postRequest` states the invariant. +- KTD7. The new test lives at `packages/protocol/tests/client.test.ts`. `CONTRIBUTING.md:5` asks for colocated unit tests, but `packages/protocol/vitest.config.ts:16` collects only `tests/**/*.test.ts`, so a colocated file would never run. The package's three existing tests are all named after their source file under `tests/`. +- KTD8. The test replaces the real iframe with a `document.createElement` seam rather than driving happy-dom. happy-dom's `HTMLIFrameElement` navigates on `connectedToDocument` and dispatches its own `error` event when the fetch to `http://host.localhost:*` is refused, which reaches `client.ts:361-365` and rejects the frame wait before any late manual `load` can land. A stub element also removes the `postMessage` target-origin check that `client.ts:556` would otherwise trip. `createHostIframe` only uses `src`, `setAttribute`, `tabIndex`, `style.cssText`, `addEventListener`, `appendChild`, `remove()`, and later `contentWindow`, so a plain element with a `contentWindow` property satisfies it. No production seam is added. Advances R7. +- KTD9. Tests use one static import plus `resetProtocolFrame()` in `afterEach`, not `vi.resetModules()`. The happy-dom environment is per file, so a reset module would append a second iframe and register a second `message` listener against the same shared `window` (`client.ts:66`, `:176-179`) while the first iframe stayed in `document.body`. `resetProtocolFrame()` already clears the iframe, both cached promises, and the ready flag, and rejects orphaned ready waiters (`client.ts:152-173`). Advances R7, R8. + +### High-Level Technical Design + +Phase progression and which timer owns each window: + +```mermaid +stateDiagram-v2 + [*] --> Timed: timeoutMs resolved before any await + [*] --> Untimed: UNTIMED_METHODS.has(method) + Untimed --> Sent: plain await ensure, no budget + Timed --> Load: budget armed, phase = load + Load --> Ready: host frame loaded, ready branch only + Load --> Reply: host frame loaded, shared branch + Ready --> Reply: protocol frame signalled ready + Load --> Rejected: budget expired in load + Ready --> Rejected: budget expired in ready + Reply --> Rejected: budget expired in reply + Reply --> Resolved: response envelope arrived + Sent --> Resolved: response envelope arrived +``` + +The decision path inside `postRequest`: + +```mermaid +flowchart TB + A[postRequest called] --> B{UNTIMED_METHODS.has method} + B -->|yes| C[await ensure, send, no timer] + B -->|no| D[arm one timer for timeoutMs, phase = load] + D --> E[guard ensureHostFrame] + E --> F{needsProtocolReady} + F -->|yes| G[phase = ready, guard ensureProtocolFrame] + F -->|no| H[phase = reply] + G --> H + H --> I[start m.timer, register pending, postMessage] + I --> J[guard reply promise] + J --> K[release timer, delete pending entry] +``` + +### Assumptions + +- A1. A stub element returned from a spied `document.createElement("iframe")` drives `createHostIframe` to resolution when the test dispatches a `load` event on it. U4 proves or disproves this on its first run. If it is false, the fallback is to stub `document.body.appendChild` as well, and the plan stops rather than adding a production seam. +- A2. Vitest fake timers cover `setTimeout` and fire equal-expiry timers in creation order. Load-bearing for KTD6 and asserted by U4's load-phase scenario. +- A3. The `phase` attribute on the timeout counter is not assertable in this suite, because `VITE_METRICS` is absent from `packages/protocol/vitest.config.ts:20-26` and `packages/metrics/src/metrics.ts:144` compiles metrics to no-ops without it. U3 is dashboard-only and carries no test. + +### Intended Consequences Worth Recording + +- The JSON-RPC error string on the provider path gains a phase clause. `buildJsonRpcError` (`client.ts:701-713`) renders `serializeError(error)`, which emits `message` only, so the code stays `-32603` and only the text grows. +- A `chainSend` issued after an in-page `resetProtocolFrame()` is now bounded by its own 30 second budget rather than up to 270 seconds. This does not hard-fail a legitimate cold presync, for two verified reasons. The reset paths that force `skipWorkerCache` (`apps/host/src/main.ts:845`, `packages/ui/src/topbar.ts:1570`) reload the page unconditionally (`main.ts:851`, `topbar.ts:1623`), so no live provider survives to send. The two in-page resets (`main.ts:808`, `shared-mode.ts:249`) leave `skipWorkerCache` off, and `client.ts:146-150` records that the SharedWorker keeps its presync progress across an iframe cycle, so the next ready signal is fast. +- A ready-branch request issued while a genuinely cold frame is still presyncing now rejects at its own budget. The boot resolve at `apps/host/src/main.ts:1324` is the real case, capped at 90 seconds. The cold boot itself keeps its full 240 second window, because it is driven by the direct `ensureProtocolFrame()` and the untimed `warmup` at `main.ts:990-991`, neither of which arms a budget. This is the bound the issue asks for, not an accident. +- A cold-frame `chainConnect` on the provider path still takes up to roughly 270 seconds, because `createRemoteChainProvider` awaits a direct `ensureProtocolFrame()` at `client.ts:732` before it posts the request. The request's own 30 second budget then covers only the reply. Bounding that direct wait is out of scope here. +- A request orphaned by a mid-flight `resetProtocolFrame()` now dies within the remainder of its call-time budget rather than a fresh per-method window. The JSDoc at `client.ts:139-143` states the old guarantee and is corrected in U2. + +--- + +## Implementation Units + +### U1. Typed timeout error with a phase field + +- Goal: give the budget a rejection callers and tests can inspect structurally. +- Requirements: R4. +- Dependencies: none. +- Files: `packages/protocol/src/errors.ts`. +- Approach: + 1. Export `type ProtocolRequestTimeoutPhase = "load" | "ready" | "reply"`. + 2. Export `class ProtocolRequestTimeoutError extends Error` with `readonly method: string`, `readonly timeoutMs: number`, `readonly phase: ProtocolRequestTimeoutPhase`, and `name = "ProtocolRequestTimeoutError"`. + 3. Build the message inside the constructor so every call site is consistent: `Protocol request "" timed out after ms while waiting for the host frame to load` for `load`, `... while waiting for the protocol frame to become ready` for `ready`, and `... while waiting for a reply` for `reply`. +- Patterns to follow: `ProtocolFatalError` and `ProtocolInitFailedError` in the same file set `this.name` in the constructor and add no other members. Single-sentence JSDoc per `CONTRIBUTING.md:59`. No em-dashes or semicolons in comments per `CONTRIBUTING.md:48`. +- Test scenarios: none. This unit is a constructor and a message table, refused as a test target because a type forbids the wrong phase and U4 asserts all three phase messages through the real budget. +- Verification: `bun run --cwd packages/protocol typecheck` passes. + +### U2. Call-time budget in postRequest + +- Goal: the per-method budget starts at the call and covers the frame wait. +- Requirements: R1, R2, R3, R4, R5, R6. +- Dependencies: U1. +- Files: `packages/protocol/src/client.ts`. +- Approach: + 1. Add `startRequestBudget(method, timeoutMs)` above `postRequest`. It arms one `setTimeout`, holds a mutable `phase` initialised to `"load"`, and returns `guard`, `enterPhase`, and `release`. `guard` is `Promise.race([work, expiry])`. The timer callback rejects with `ProtocolRequestTimeoutError` built from the phase held at fire time, and emits `m.count(S.PROTOCOL_REQUEST, { outcome: "timeout", method, phase })`. + 2. Move the `timeoutMs` computation from `:519-521` above the frame await. It is a pure function of `method`, so hoisting changes nothing else. + 3. Keep the untimed branch literal. When `timeoutMs` is `null`, arm no budget and take today's plain `await (needsProtocolReady ? ensureProtocolFrame() : ensureHostFrame())` path so `warmup` is behaviourally unchanged. + 4. Extract the envelope build, `pendingRequests` registration, and `postMessage` from `:510-557` into a helper that returns the reply promise and its request id. Delete the inner `setTimeout` at `:525-537`. The budget owns the timer now. + 5. In the timed path, arm the budget as the first statement inside a `try` whose `finally` calls `release()` and deletes the pending entry. Then guard `ensureHostFrame()`, and on the ready branch flip to `"ready"` and guard `ensureProtocolFrame()`. Flip to `"reply"`, start `stopReq`, send, and guard the reply promise. + 6. Keep the `frameWindow` check from `:505-508` between the frame phase and the send. + 7. Call `stopReq()` from `postRequest` around the reply guard per KTD5b, not from the budget callback: on success, and in a `catch` only when the error is a `ProtocolRequestTimeoutError`. Do not put it in the shared `finally`. + 8. Correct the JSDoc at `:139-143` to say an orphaned request rejects within the remainder of its call-time budget. +- Patterns to follow: the inline race idiom at `packages/resolver/src/resolve.ts:212-220`. The existing `phase` attribute spelling at `client.ts:396` and `:465`. +- Execution note: write U4's ready-branch test first and watch it fail against the current code, so the gatekeeper is proven to bite before the fix lands. +- Test scenarios: covered by U4. +- Verification: `bun run --cwd packages/protocol typecheck` passes, and every scenario in U4 passes. + +### U3. Phase-aware telemetry doc comment + +- Goal: the span doc stops describing a timeout attribute set that no longer matches the code. +- Requirements: documents R4's telemetry surface. The `phase` attribute that U2 adds to the `m.count(S.PROTOCOL_REQUEST)` timeout emission is this plan's own extension, not something the origin issue asked for, so this unit records it rather than implementing R4. +- Dependencies: U2. +- Files: `packages/metrics/src/spans.ts`. +- Approach: update the comment at `:142-147` to state that a timeout emits `{ outcome: "timeout", method, phase }`, and that the histogram covers the reply phase only while the counter covers the whole call-time budget. +- Patterns to follow: the sibling comment at `:135-140` documents `PROTOCOL_IFRAME_READY` attributes the same way. +- Test scenarios: none. Comment-only, and metrics compile to no-ops in this suite per A3. +- Verification: `bun run --cwd packages/metrics typecheck` passes. + +### U4. Budget tests for both branches + +- Goal: prove the bound and the attribution, and fail if the ordering defect returns. +- Requirements: R1, R2, R4, R5, R6, R7, R8. +- Dependencies: U1, U2. +- Files: `packages/protocol/tests/client.test.ts`. +- Approach: + 1. Static import of `@dotli/protocol/client`. `import { describe, expect, it, vi, afterEach, beforeEach } from "vitest"` because `globals` is `false`. + 2. `beforeEach`: `vi.useFakeTimers()`, then spy `document.createElement` so `"iframe"` returns a stub element carrying a `contentWindow` whose `postMessage` is a `vi.fn()`, and every other tag falls through to the real implementation. + 3. `afterEach`: `resetProtocolFrame()`, `vi.clearAllTimers()`, `vi.useRealTimers()`, `vi.restoreAllMocks()`, and empty `document.body`. + 4. Helper to dispatch `load` on the stub. Helper that reports whether a promise has settled without awaiting it, which must attach a rejection handler to the promise it inspects so a deliberately abandoned request cannot surface as an unhandled rejection when `afterEach` rejects it. +- Test scenarios: + - As a caller of a ready-path method, I get a rejection within my own budget when the frame loads but never signals ready. Load the frame, call `resolveDotNameRemote`, assert still pending at fake 89_999ms, advance 1ms, assert rejection is a `ProtocolRequestTimeoutError` with `phase === "ready"`, `timeoutMs === 90_000`, and `method === "resolveDotName"`. This is the gatekeeper: reverted code stays pending until 240_000. + - As a caller of a shared-auth method, I get a rejection within my own budget when the host frame loads late and no reply arrives. Call `readSharedAuthStorage`, dispatch `load` at fake 20_000ms, assert still pending at 29_999ms, advance 1ms, assert `phase === "reply"` and `timeoutMs === 30_000`. This is the shared-branch gatekeeper: reverted code arms its reply timer at 20_000 and stays pending until 50_000. + - As a caller of a ready-path method whose host frame never loads, I get the frame-path error rather than a budget rejection, because it settles first. Call `resolveOwnerRemote` (90_000 budget), never dispatch `load`, advance past 30_000, and assert the rejection is `Shared host iframe timed out while loading` and not a `ProtocolRequestTimeoutError`, per R6. This holds only because the method budget exceeds the load timeout. The next scenario covers the case where they are equal. + - As a caller of a 30_000-budget method whose host frame never loads, I get a load-phase budget rejection. Call `readSharedAuthStorage`, never dispatch `load`, advance to fake 30_000ms, and assert a `ProtocolRequestTimeoutError` with `phase === "load"`. The budget wins the equal-expiry tie against the load timer at `client.ts:349` because KTD6 arms it first. This is the only reachable path to `phase === "load"`, since no method has a budget below `IFRAME_LOAD_TIMEOUT_MS`. + - As a caller whose frame is reset mid-wait, I see the reset error and not a budget rejection. Call `resolveDotNameRemote` on a loaded frame that never signals ready, call `resetProtocolFrame()` at fake 10_000ms, and assert the rejection is `Protocol frame state reset before ready signal` and not a `ProtocolRequestTimeoutError`, per R6. + - As a caller of `warmup`, I am never rejected by a request budget. Call `warmupProtocol()` with a loaded frame and no ready signal, advance to fake 120_000ms, and assert still pending. The advance stays strictly below `IFRAME_READY_TIMEOUT_MS` so the ready wait does not reject and mask the claim. + - As a caller on a healthy frame, my request resolves and nothing fires afterwards. Load the frame, dispatch a `ready` envelope, call `readSharedModeStorage`, capture the request id from the `postMessage` spy, dispatch a matching `response` envelope, assert it resolves with the payload, then advance past 30_000 and assert no unhandled rejection and no state change. +- Verification: `bun run --cwd packages/protocol test` exits 0 with all seven scenarios passing, and the first two fail when U2's budget arming is moved back below the frame await. + +--- + +## Verification Contract +| Gate | Command | Applies to | Pass signal | +|---|---|---|---| +| Types | `bun run --cwd packages/protocol typecheck` | U1, U2, U4 | exit 0 | +| Types | `bun run --cwd packages/metrics typecheck` | U3 | exit 0 | +| Unit | `bun run --cwd packages/protocol test` | U2, U4 | exit 0, seven new scenarios pass, 38 pre-existing tests still pass | +| Revert probe | move U2's budget arming below the frame await, rerun the unit gate | R7 | the two gatekeeper scenarios fail | + +This repo's package manager is bun (`package.json:33`, `packageManager: bun@1.3.6`), and pnpm refuses to run here. Do not substitute a `pnpm` command for any gate above. + +Do not run the package's `lint` script. It is `bunx eslint src/` (`packages/protocol/package.json:12`), and `bunx` is a forbidden ephemeral package runner on this machine. + +--- + +## Definition of Done + +- R1 through R8 hold, with R8 read as the bun unit gate above. +- The revert probe in the Verification Contract has been run and the two gatekeeper scenarios were observed to fail against the reverted code. +- `IFRAME_LOAD_TIMEOUT_MS`, `IFRAME_READY_TIMEOUT_MS`, `DEFAULT_TIMEOUT_MS`, and `METHOD_TIMEOUTS` are byte-identical to `main`. +- The untimed `warmup` path arms no timer and creates no budget object. +- `stopReq()` appears only on the resolve path and the reply-phase timeout path. +- The JSDoc at `client.ts:139-143` and the comment at `spans.ts:142-147` match the shipped behavior. +- No abandoned experiment remains in the diff. No stub seam was added to `src/`. From 510a099d8bda19d188f7bbd82066d4934eb7f5c7 Mon Sep 17 00:00:00 2001 From: Ryan Lee Date: Fri, 14 Aug 2026 19:27:27 +0000 Subject: [PATCH 02/18] fix(protocol): measure a request timeout from the call, not the frame wait `postRequest` armed its per-method timer only after awaiting the shared protocol frame, and that wait carries its own budget of up to 240 seconds. A first request could therefore block for roughly four and a half minutes while advertising a 30 second contract, and the eventual rejection did not say whether the time went into booting the frame or waiting for a reply. The per-method budget is now resolved before the frame wait and enforced by a single timer armed at call time, raced against the frame wait and then the reply wait. Rejections carry a typed error naming which wait spent the budget: opening the host frame, waiting for the frame to report ready, or waiting for a reply. A more specific frame failure still wins when it settles first, so a torn-down frame or a dead chain reports its own cause. No timeout constant changed. `warmup` stays exempt, so a legitimate cold boot keeps its full window through the untimed warm-up and the direct frame call that drive it. --- packages/metrics/src/spans.ts | 9 +- packages/protocol/src/client.ts | 178 +++++++++++++----- packages/protocol/src/errors.ts | 36 ++++ packages/protocol/tests/client.test.ts | 246 +++++++++++++++++++++++++ 4 files changed, 420 insertions(+), 49 deletions(-) create mode 100644 packages/protocol/tests/client.test.ts diff --git a/packages/metrics/src/spans.ts b/packages/metrics/src/spans.ts index e0c668d2..a2f7de94 100644 --- a/packages/metrics/src/spans.ts +++ b/packages/metrics/src/spans.ts @@ -140,9 +140,12 @@ export const APP_RENDER = "app.render"; export const PROTOCOL_IFRAME_READY = "protocol.iframe_ready"; /** - * Protocol request roundtrip time. Timeouts emit - * `m.count(PROTOCOL_REQUEST, { outcome: "timeout", method })`; there is - * no separate `_TIMEOUT` constant. + * Protocol request roundtrip time, measured over the reply wait only. Timeouts + * emit `m.count(PROTOCOL_REQUEST, { outcome: "timeout", method, phase })`, + * where `phase` is `load`, `ready`, or `reply` and names which wait spent the + * request's call-time budget. The counter therefore spans the whole budget + * while the duration spans the reply wait. There is no separate `_TIMEOUT` + * constant. */ export const PROTOCOL_REQUEST = "protocol.request"; diff --git a/packages/protocol/src/client.ts b/packages/protocol/src/client.ts index de3baa14..411261a3 100644 --- a/packages/protocol/src/client.ts +++ b/packages/protocol/src/client.ts @@ -7,7 +7,12 @@ import type { JsonRpcProvider, JsonRpcRequest, } from "@polkadot-api/json-rpc-provider"; -import { ProtocolFatalError, ProtocolInitFailedError } from "./errors"; +import { + ProtocolFatalError, + ProtocolInitFailedError, + ProtocolRequestTimeoutError, + type ProtocolRequestTimeoutPhase, +} from "./errors"; import type { ExecutableManifest, ManifestResult, @@ -138,9 +143,9 @@ function resolveProtocolReady(): void { * * Side effects callers should be aware of: * - Any in-flight `postRequest()` whose response hasn't arrived will be - * orphaned: it will time out via the per-method timer instead of - * completing. Callers that have outstanding work should expect those - * rejections. + * orphaned: it rejects once whatever is left of its call-time budget runs + * out, not after a fresh per-method window. Callers that have outstanding + * work should expect those rejections. * - Any `waitForProtocolReady()` waiter is rejected immediately rather * than waiting for `IFRAME_READY_TIMEOUT_MS`. * - In `shared-worker` mode, removing the iframe drops its @@ -494,19 +499,60 @@ const METHOD_TIMEOUTS: Partial> = { resolveRootManifest: 30_000, }; -async function postRequest( +interface RequestBudget { + /** Settle with `work`, or reject once the call-time budget is spent. */ + guard: (work: Promise) => Promise; + /** Record which wait is running, so a rejection can attribute the time. */ + enterPhase: (next: ProtocolRequestTimeoutPhase) => void; + /** Stop the timer once the request settles. */ + release: () => void; +} + +/** + * Bound a request from the moment it was made. + * + * One timer covers the frame wait and the reply wait, so a caller gets the + * per-method budget it was promised instead of that budget stacked on top of + * the frame budgets. The phase is read when the timer fires, so the rejection + * names the wait that actually consumed the time. + */ +function startRequestBudget( + method: ProtocolRequestMethod, + timeoutMs: number, +): RequestBudget { + let phase: ProtocolRequestTimeoutPhase = "load"; + let timer: ReturnType | undefined; + const expiry = new Promise((_resolve, reject) => { + timer = setTimeout(() => { + m.count(S.PROTOCOL_REQUEST, { outcome: "timeout", method, phase }); + reject(new ProtocolRequestTimeoutError(method, timeoutMs, phase)); + }, timeoutMs); + }); + return { + // Promise.race attaches a handler to both operands, so a frame promise + // this caller stops waiting on cannot become an unhandled rejection. + guard: (work: Promise): Promise => Promise.race([work, expiry]), + enterPhase: (next: ProtocolRequestTimeoutPhase): void => { + phase = next; + }, + release: (): void => { + clearTimeout(timer); + }, + }; +} + +interface SentRequest { + id: string; + reply: Promise; +} + +/** Register a pending request and post it to the protocol frame. */ +function sendRequest( + frameWindow: Window, method: M, payload: ProtocolRequestMap[M], onProgress?: (message: string) => void, - needsProtocolReady = !isSharedAuthRequestMethod(method) && - !isSharedModeRequestMethod(method), -): Promise { - await (needsProtocolReady ? ensureProtocolFrame() : ensureHostFrame()); - const frameWindow = protocolIframe?.contentWindow; - if (!frameWindow) { - throw new Error("Shared protocol iframe is unavailable"); - } - +): SentRequest { const id = createRequestId(); const envelope: ProtocolRequestEnvelope = { namespace: "dotli:protocol", @@ -515,46 +561,86 @@ async function postRequest( method, payload, }; - - const timeoutMs = UNTIMED_METHODS.has(method) - ? null - : (METHOD_TIMEOUTS[method] ?? DEFAULT_TIMEOUT_MS); - const stopReq = m.timer(S.PROTOCOL_REQUEST); - - return new Promise((resolve, reject) => { - const timer = - timeoutMs === null - ? null - : setTimeout(() => { - pendingRequests.delete(id); - m.count(S.PROTOCOL_REQUEST, { outcome: "timeout", method }); - stopReq(); - reject( - new Error( - `Protocol request "${method}" timed out after ${String(timeoutMs)}ms`, - ), - ); - }, timeoutMs); - + const reply = new Promise((resolve, reject) => { pendingRequests.set(id, { - resolve: (value) => { - if (timer !== null) { - clearTimeout(timer); - } - stopReq(); - resolve(value); - }, + resolve, reject: (reason?: unknown) => { - if (timer !== null) { - clearTimeout(timer); - } reject(reason instanceof Error ? reason : new Error(String(reason))); }, onProgress, }); - frameWindow.postMessage(envelope, getProtocolOrigin()); }); + return { id, reply }; +} + +async function postRequest( + method: M, + payload: ProtocolRequestMap[M], + onProgress?: (message: string) => void, + needsProtocolReady = !isSharedAuthRequestMethod(method) && + !isSharedModeRequestMethod(method), +): Promise { + const timeoutMs = UNTIMED_METHODS.has(method) + ? null + : (METHOD_TIMEOUTS[method] ?? DEFAULT_TIMEOUT_MS); + + if (timeoutMs === null) { + await (needsProtocolReady ? ensureProtocolFrame() : ensureHostFrame()); + const frameWindow = protocolIframe?.contentWindow; + if (!frameWindow) { + throw new Error("Shared protocol iframe is unavailable"); + } + const stopReq = m.timer(S.PROTOCOL_REQUEST); + const value = await sendRequest( + frameWindow, + method, + payload, + onProgress, + ).reply; + stopReq(); + return value; + } + + // Arm the budget before creating the frame promise. Equal-expiry timers fire + // in creation order, so a budget that ties with the iframe load timeout still + // reports itself rather than the load failure. + const budget = startRequestBudget(method, timeoutMs); + let sentId: string | null = null; + try { + await budget.guard(ensureHostFrame()); + if (needsProtocolReady) { + budget.enterPhase("ready"); + await budget.guard(ensureProtocolFrame()); + } + const frameWindow = protocolIframe?.contentWindow; + if (!frameWindow) { + throw new Error("Shared protocol iframe is unavailable"); + } + + budget.enterPhase("reply"); + const stopReq = m.timer(S.PROTOCOL_REQUEST); + const sent = sendRequest(frameWindow, method, payload, onProgress); + sentId = sent.id; + try { + const value = await budget.guard(sent.reply); + stopReq(); + return value; + } catch (error: unknown) { + // A spent budget still describes a roundtrip the histogram should carry. + // A fatal envelope or a response error does not, which matches the + // pre-existing behaviour of recording no sample on those paths. + if (error instanceof ProtocolRequestTimeoutError) { + stopReq(); + } + throw error; + } + } finally { + budget.release(); + if (sentId !== null) { + pendingRequests.delete(sentId); + } + } } export async function warmupProtocol(): Promise { diff --git a/packages/protocol/src/errors.ts b/packages/protocol/src/errors.ts index 76911d84..09442ae2 100644 --- a/packages/protocol/src/errors.ts +++ b/packages/protocol/src/errors.ts @@ -14,3 +14,39 @@ export class ProtocolInitFailedError extends Error { this.name = "ProtocolInitFailedError"; } } + +/** Which wait consumed a protocol request's call-time budget. */ +export type ProtocolRequestTimeoutPhase = "load" | "ready" | "reply"; + +const PHASE_DESCRIPTIONS: Record = { + load: "while waiting for the host frame to load", + ready: "while waiting for the protocol frame to become ready", + reply: "while waiting for a reply", +}; + +/** + * A protocol request that ran out its per-method budget. + * + * The budget is measured from the moment the request was made, so it covers + * the frame wait as well as the reply wait. `phase` records which of those + * waits was in progress when the budget expired. + */ +export class ProtocolRequestTimeoutError extends Error { + readonly method: string; + readonly timeoutMs: number; + readonly phase: ProtocolRequestTimeoutPhase; + + constructor( + method: string, + timeoutMs: number, + phase: ProtocolRequestTimeoutPhase, + ) { + super( + `Protocol request "${method}" timed out after ${String(timeoutMs)}ms ${PHASE_DESCRIPTIONS[phase]}`, + ); + this.name = "ProtocolRequestTimeoutError"; + this.method = method; + this.timeoutMs = timeoutMs; + this.phase = phase; + } +} diff --git a/packages/protocol/tests/client.test.ts b/packages/protocol/tests/client.test.ts new file mode 100644 index 00000000..23b55c2e --- /dev/null +++ b/packages/protocol/tests/client.test.ts @@ -0,0 +1,246 @@ +// Copyright 2026 Parity Technologies (UK) Ltd. +// SPDX-License-Identifier: AGPL-3.0-only + +/** + * Behaviour of the time limit a protocol request promises its caller. + * + * The client owns module-level singleton state (the frame, the cached frame + * promises, the ready flag), so every scenario drives a stub element through + * `document.createElement` and tears the state down afterwards. A real + * happy-dom iframe would navigate to the protocol origin, fail that fetch, and + * dispatch its own error event before a scenario could drive it. + */ + +import { + afterEach, + beforeEach, + describe, + expect, + it, + vi, + type Mock, +} from "vitest"; +import { SITE_ID } from "@dotli/config/config"; +import { SHARED_CORE_SESSION_KEY } from "@dotli/protocol/auth-storage"; +import { + getProtocolOrigin, + readSharedAuthStorage, + readSharedModeStorage, + resetProtocolFrame, + resolveDotNameRemote, + resolveOwnerRemote, + warmupProtocol, +} from "@dotli/protocol/client"; +import { ProtocolRequestTimeoutError } from "@dotli/protocol/errors"; + +/** The stub element the client last asked `document.createElement` for. */ +let frame: HTMLElement; +let framePostMessage: Mock; + +/** Deliver a protocol envelope as if the frame had posted it. */ +function dispatchFromFrame(data: unknown): void { + const holder = frame as unknown as { contentWindow: unknown }; + window.dispatchEvent( + new MessageEvent("message", { + data, + origin: getProtocolOrigin(), + // The client only accepts envelopes whose source is the frame's own + // window object, so the stub window must be passed through by identity. + source: holder.contentWindow as Window, + }), + ); +} + +/** + * Report whether a promise has settled, without adopting its result. + * + * The handler attached here keeps a deliberately abandoned request from + * surfacing as an unhandled rejection when the teardown rejects it. + */ +function settleTracker(promise: Promise): () => boolean { + let settled = false; + promise.then( + () => { + settled = true; + }, + () => { + settled = true; + }, + ); + return () => settled; +} + +/** Drain the microtask queue so the client's awaits advance under fake timers. */ +async function flush(): Promise { + for (let i = 0; i < 5; i += 1) { + await Promise.resolve(); + } +} + +beforeEach(() => { + vi.useFakeTimers(); + framePostMessage = vi.fn(); + const realCreateElement = document.createElement.bind(document); + vi.spyOn(document, "createElement").mockImplementation((tagName: string) => { + if (tagName !== "iframe") { + return realCreateElement(tagName); + } + // A real happy-dom iframe navigates to the protocol origin on append and + // dispatches its own error event when that fetch fails. A div carries + // every member the frame builder touches and never hits the network. + const element = realCreateElement("div"); + Object.defineProperty(element, "contentWindow", { + configurable: true, + value: { postMessage: framePostMessage }, + }); + frame = element; + return element; + }); +}); + +afterEach(() => { + resetProtocolFrame(); + vi.clearAllTimers(); + vi.useRealTimers(); + vi.restoreAllMocks(); + document.body.innerHTML = ""; +}); + +describe("Keeping a protocol request inside the time limit it promises", () => { + const slowFrameCases = [ + { + request: "a name lookup", + frame: "opens but never reports itself ready", + limitMs: 90_000, + opensAfterMs: 0, + blamedWait: "ready", + call: () => resolveDotNameRemote("alice"), + }, + { + request: "a saved session read", + frame: "takes twenty seconds to open and then never answers", + limitMs: 30_000, + opensAfterMs: 20_000, + blamedWait: "reply", + call: () => readSharedAuthStorage(SITE_ID, SHARED_CORE_SESSION_KEY), + }, + { + request: "a saved session read", + frame: "never opens at all", + limitMs: 30_000, + opensAfterMs: null, + blamedWait: "load", + call: () => readSharedAuthStorage(SITE_ID, SHARED_CORE_SESSION_KEY), + }, + ]; + + it.each(slowFrameCases)( + "As someone making $request, I wait no longer than the limit I was promised when the shared frame $frame, and I am told which wait spent it", + async ({ limitMs, opensAfterMs, blamedWait, call }) => { + // Given a shared frame that is slow in the way this example describes + const pending = call(); + const settled = settleTracker(pending); + await flush(); + if (opensAfterMs !== null) { + await vi.advanceTimersByTimeAsync(opensAfterMs); + frame.dispatchEvent(new Event("load")); + await flush(); + } + + // When the promised limit has all but elapsed + await vi.advanceTimersByTimeAsync(limitMs - opensAfterMs - 1); + expect(settled()).toBe(false); + + // Then the last millisecond of the limit ends the wait, naming the + // wait that consumed it + await vi.advanceTimersByTimeAsync(1); + await expect(pending).rejects.toBeInstanceOf(ProtocolRequestTimeoutError); + await expect(pending).rejects.toMatchObject({ + timeoutMs: limitMs, + phase: blamedWait, + }); + }, + ); + + it("As someone making an owner lookup, I am told the shared frame failed to open rather than being told my own time ran out", async () => { + // Given an owner lookup, which is promised more time than opening the + // shared frame is allowed to take + const pending = resolveOwnerRemote("alice"); + const settled = settleTracker(pending); + await flush(); + + // When the frame never opens and its own allowance runs out + await vi.advanceTimersByTimeAsync(30_000); + + // Then the more specific failure is the one reported + expect(settled()).toBe(true); + await expect(pending).rejects.toThrow( + "Shared host iframe timed out while loading", + ); + await expect(pending).rejects.not.toBeInstanceOf( + ProtocolRequestTimeoutError, + ); + }); + + it("As someone making a name lookup, I am told the shared frame was torn down rather than being told my own time ran out", async () => { + // Given a name lookup waiting on a frame that has opened but is not ready + const pending = resolveDotNameRemote("alice"); + const settleTrackerFor = settleTracker(pending); + await flush(); + frame.dispatchEvent(new Event("load")); + await flush(); + + // When the frame is torn down long before the promised limit + await vi.advanceTimersByTimeAsync(10_000); + resetProtocolFrame(); + await flush(); + + // Then the teardown is the reported reason + expect(settleTrackerFor()).toBe(true); + await expect(pending).rejects.toThrow( + "Protocol frame state reset before ready signal", + ); + await expect(pending).rejects.not.toBeInstanceOf( + ProtocolRequestTimeoutError, + ); + }); + + it("As someone warming the protocol up, I am never cut off, because warming up waits on chain sync", async () => { + // Given a warm-up against a frame that has opened but is not ready + const pending = warmupProtocol(); + const settled = settleTracker(pending); + await flush(); + frame.dispatchEvent(new Event("load")); + await flush(); + + // When four times the ordinary request limit goes by + await vi.advanceTimersByTimeAsync(120_000); + + // Then the warm-up is still waiting + expect(settled()).toBe(false); + }); + + it("As someone reading a saved preference from a healthy frame, I get my answer and nothing cuts me off afterwards", async () => { + // Given a healthy shared frame + const pending = readSharedModeStorage(SITE_ID, "backend"); + await flush(); + frame.dispatchEvent(new Event("load")); + await flush(); + + // When the frame answers + const envelope = framePostMessage.mock.calls[0]?.[0] as { id: string }; + dispatchFromFrame({ + namespace: "dotli:protocol", + kind: "response", + id: envelope.id, + ok: true, + result: "smoldot-shared-worker", + }); + + // Then the answer comes back, and letting the clock run past the limit + // changes nothing + await expect(pending).resolves.toBe("smoldot-shared-worker"); + await vi.advanceTimersByTimeAsync(60_000); + await expect(pending).resolves.toBe("smoldot-shared-worker"); + }); +}); From 1774e503b2f71952487bc19f73731e50ca23486c Mon Sep 17 00:00:00 2001 From: Ryan Lee Date: Fri, 14 Aug 2026 19:38:09 +0000 Subject: [PATCH 03/18] refactor(protocol): bind the timeout phase to the wait it describes The budget exposed `enterPhase` and `guard` as separate calls, so a caller had to remember to announce the phase before the wait it belonged to. The phase is now an argument to `guard`, which makes the pairing impossible to get wrong and lets a rejection name only a wait the request was actually in. Also drops the nullable request-id local. The pending entry is dropped in the one place a reply can no longer arrive, so the outer block no longer carries state whose only purpose was a conditional cleanup. --- packages/protocol/src/client.ts | 46 ++++++++++++++------------ packages/protocol/tests/client.test.ts | 3 +- 2 files changed, 26 insertions(+), 23 deletions(-) diff --git a/packages/protocol/src/client.ts b/packages/protocol/src/client.ts index 411261a3..7981dc9e 100644 --- a/packages/protocol/src/client.ts +++ b/packages/protocol/src/client.ts @@ -142,10 +142,10 @@ function resolveProtocolReady(): void { * was wrong and need a clean restart before chain operations run. * * Side effects callers should be aware of: - * - Any in-flight `postRequest()` whose response hasn't arrived will be - * orphaned: it rejects once whatever is left of its call-time budget runs - * out, not after a fresh per-method window. Callers that have outstanding - * work should expect those rejections. + * - Any in-flight timed `postRequest()` whose response hasn't arrived will + * be orphaned: it rejects once whatever is left of its call-time budget + * runs out, not after a fresh per-method window. Callers that have + * outstanding work should expect those rejections. * - Any `waitForProtocolReady()` waiter is rejected immediately rather * than waiting for `IFRAME_READY_TIMEOUT_MS`. * - In `shared-worker` mode, removing the iframe drops its @@ -500,10 +500,13 @@ const METHOD_TIMEOUTS: Partial> = { }; interface RequestBudget { - /** Settle with `work`, or reject once the call-time budget is spent. */ - guard: (work: Promise) => Promise; - /** Record which wait is running, so a rejection can attribute the time. */ - enterPhase: (next: ProtocolRequestTimeoutPhase) => void; + /** + * Wait for `work` under the remaining budget, blaming `phase` if it runs out. + * + * The phase travels with the wait it describes, so a rejection can never + * name a wait the request was not in. + */ + guard: (phase: ProtocolRequestTimeoutPhase, work: Promise) => Promise; /** Stop the timer once the request settles. */ release: () => void; } @@ -529,11 +532,14 @@ function startRequestBudget( }, timeoutMs); }); return { - // Promise.race attaches a handler to both operands, so a frame promise - // this caller stops waiting on cannot become an unhandled rejection. - guard: (work: Promise): Promise => Promise.race([work, expiry]), - enterPhase: (next: ProtocolRequestTimeoutPhase): void => { + guard: ( + next: ProtocolRequestTimeoutPhase, + work: Promise, + ): Promise => { phase = next; + // Promise.race attaches a handler to both operands, so a frame promise + // this caller stops waiting on cannot become an unhandled rejection. + return Promise.race([work, expiry]); }, release: (): void => { clearTimeout(timer); @@ -606,27 +612,26 @@ async function postRequest( // in creation order, so a budget that ties with the iframe load timeout still // reports itself rather than the load failure. const budget = startRequestBudget(method, timeoutMs); - let sentId: string | null = null; try { - await budget.guard(ensureHostFrame()); + await budget.guard("load", ensureHostFrame()); if (needsProtocolReady) { - budget.enterPhase("ready"); - await budget.guard(ensureProtocolFrame()); + await budget.guard("ready", ensureProtocolFrame()); } const frameWindow = protocolIframe?.contentWindow; if (!frameWindow) { throw new Error("Shared protocol iframe is unavailable"); } - budget.enterPhase("reply"); const stopReq = m.timer(S.PROTOCOL_REQUEST); const sent = sendRequest(frameWindow, method, payload, onProgress); - sentId = sent.id; try { - const value = await budget.guard(sent.reply); + const value = await budget.guard("reply", sent.reply); stopReq(); return value; } catch (error: unknown) { + // The listener drops the entry when a reply lands. Nothing will arrive + // now, so this is the only path that has to drop it. + pendingRequests.delete(sent.id); // A spent budget still describes a roundtrip the histogram should carry. // A fatal envelope or a response error does not, which matches the // pre-existing behaviour of recording no sample on those paths. @@ -637,9 +642,6 @@ async function postRequest( } } finally { budget.release(); - if (sentId !== null) { - pendingRequests.delete(sentId); - } } } diff --git a/packages/protocol/tests/client.test.ts b/packages/protocol/tests/client.test.ts index 23b55c2e..e26a6d52 100644 --- a/packages/protocol/tests/client.test.ts +++ b/packages/protocol/tests/client.test.ts @@ -148,7 +148,8 @@ describe("Keeping a protocol request inside the time limit it promises", () => { } // When the promised limit has all but elapsed - await vi.advanceTimersByTimeAsync(limitMs - opensAfterMs - 1); + const alreadyElapsed = opensAfterMs ?? 0; + await vi.advanceTimersByTimeAsync(limitMs - alreadyElapsed - 1); expect(settled()).toBe(false); // Then the last millisecond of the limit ends the wait, naming the From 83faf03fbafb9610b594e16322fba07d5d4fb570 Mon Sep 17 00:00:00 2001 From: Ryan Lee Date: Fri, 14 Aug 2026 20:03:49 +0000 Subject: [PATCH 04/18] fix(protocol): extend the call-time budget to the chain provider Three defects the review pass found in the first cut, plus the coverage that proves each one. A chain connection awaited the protocol frame outside any budget and only then issued its own request, so a dApp connecting during a cold boot still waited out the frame budgets before the connection's 30 second allowance even started. The request already performs both frame waits, so the outer wait was redundant as well as unbounded. A failed request recorded a duration sample. The budget starts at the call while that timer starts at the reply, so a timeout wrote the leftover budget into a series with no outcome to filter on, and a 90 second failure could land as a 3 second sample. Only a completed roundtrip is recorded now, matching what the fatal and response-error paths already did. The host mapped a protocol timeout to its user-facing copy by matching the message text, which this branch reworded. It now matches on the error type, keeping the text match for the foreign errors that still need it. The suite was blind to two invariants: deleting the timer disarm or the pending-entry cleanup left every test passing. Six mutations are now each caught by a named scenario, including a crash relabelled as a timeout and warmup handed a budget it must not have. Intent moved out of comments and into names and structure: the untimed and budgeted paths are separate functions rather than one branch with a warning, and the request timer says what it records. --- apps/host/src/errors.ts | 7 +- packages/metrics/src/spans.ts | 13 +-- packages/protocol/src/client.ts | 130 +++++++++++++------------ packages/protocol/tests/client.test.ts | 122 +++++++++++++++++++++-- 4 files changed, 193 insertions(+), 79 deletions(-) diff --git a/apps/host/src/errors.ts b/apps/host/src/errors.ts index 4bdd667d..a9c6b0bd 100644 --- a/apps/host/src/errors.ts +++ b/apps/host/src/errors.ts @@ -4,6 +4,7 @@ import { ProtocolFatalError, ProtocolInitFailedError, + ProtocolRequestTimeoutError, } from "@dotli/protocol/errors"; export const HOST_ERRORS = { @@ -85,7 +86,11 @@ export function describeError(err: unknown, isP2p: boolean): ErrorDescription { recovery: "switch-backend", }; } - if (msg.includes("timed out") || msg.includes("Timed out")) { + if ( + err instanceof ProtocolRequestTimeoutError || + msg.includes("timed out") || + msg.includes("Timed out") + ) { return { message: isP2p ? HOST_ERRORS.LIGHT_CLIENT_TIMEOUT diff --git a/packages/metrics/src/spans.ts b/packages/metrics/src/spans.ts index a2f7de94..d2bd7943 100644 --- a/packages/metrics/src/spans.ts +++ b/packages/metrics/src/spans.ts @@ -140,12 +140,13 @@ export const APP_RENDER = "app.render"; export const PROTOCOL_IFRAME_READY = "protocol.iframe_ready"; /** - * Protocol request roundtrip time, measured over the reply wait only. Timeouts - * emit `m.count(PROTOCOL_REQUEST, { outcome: "timeout", method, phase })`, - * where `phase` is `load`, `ready`, or `reply` and names which wait spent the - * request's call-time budget. The counter therefore spans the whole budget - * while the duration spans the reply wait. There is no separate `_TIMEOUT` - * constant. + * Protocol request roundtrip time, recorded only for a completed roundtrip. + * + * A request that fails records no duration, so this series stays comparable + * across releases. Timeouts arrive instead as + * `m.count(PROTOCOL_REQUEST, { outcome: "timeout", method, phase })`, where + * `phase` is `load`, `ready`, or `reply` and names which wait spent the + * request's call-time budget. There is no separate `_TIMEOUT` constant. */ export const PROTOCOL_REQUEST = "protocol.request"; diff --git a/packages/protocol/src/client.ts b/packages/protocol/src/client.ts index 7981dc9e..20de7d2f 100644 --- a/packages/protocol/src/client.ts +++ b/packages/protocol/src/client.ts @@ -500,45 +500,35 @@ const METHOD_TIMEOUTS: Partial> = { }; interface RequestBudget { - /** - * Wait for `work` under the remaining budget, blaming `phase` if it runs out. - * - * The phase travels with the wait it describes, so a rejection can never - * name a wait the request was not in. - */ guard: (phase: ProtocolRequestTimeoutPhase, work: Promise) => Promise; - /** Stop the timer once the request settles. */ release: () => void; } /** * Bound a request from the moment it was made. * - * One timer covers the frame wait and the reply wait, so a caller gets the - * per-method budget it was promised instead of that budget stacked on top of - * the frame budgets. The phase is read when the timer fires, so the rejection - * names the wait that actually consumed the time. + * A tie between this budget and a frame budget resolves in this budget's + * favour, because equal-expiry timers fire in creation order and this one is + * created first. */ function startRequestBudget( method: ProtocolRequestMethod, timeoutMs: number, ): RequestBudget { - let phase: ProtocolRequestTimeoutPhase = "load"; + let spentOn: ProtocolRequestTimeoutPhase = "load"; let timer: ReturnType | undefined; const expiry = new Promise((_resolve, reject) => { timer = setTimeout(() => { - m.count(S.PROTOCOL_REQUEST, { outcome: "timeout", method, phase }); - reject(new ProtocolRequestTimeoutError(method, timeoutMs, phase)); + m.count(S.PROTOCOL_REQUEST, { outcome: "timeout", method, phase: spentOn }); + reject(new ProtocolRequestTimeoutError(method, timeoutMs, spentOn)); }, timeoutMs); }); return { guard: ( - next: ProtocolRequestTimeoutPhase, + phase: ProtocolRequestTimeoutPhase, work: Promise, ): Promise => { - phase = next; - // Promise.race attaches a handler to both operands, so a frame promise - // this caller stops waiting on cannot become an unhandled rejection. + spentOn = phase; return Promise.race([work, expiry]); }, release: (): void => { @@ -580,64 +570,58 @@ function sendRequest( return { id, reply }; } -async function postRequest( +function awaitFrame(needsProtocolReady: boolean): Promise { + return needsProtocolReady ? ensureProtocolFrame() : ensureHostFrame(); +} + +function requireFrameWindow(): Window { + const frameWindow = protocolIframe?.contentWindow; + if (!frameWindow) { + throw new Error("Shared protocol iframe is unavailable"); + } + return frameWindow; +} + +async function postUnbudgetedRequest( method: M, payload: ProtocolRequestMap[M], - onProgress?: (message: string) => void, - needsProtocolReady = !isSharedAuthRequestMethod(method) && - !isSharedModeRequestMethod(method), + onProgress: ((message: string) => void) | undefined, + needsProtocolReady: boolean, ): Promise { - const timeoutMs = UNTIMED_METHODS.has(method) - ? null - : (METHOD_TIMEOUTS[method] ?? DEFAULT_TIMEOUT_MS); - - if (timeoutMs === null) { - await (needsProtocolReady ? ensureProtocolFrame() : ensureHostFrame()); - const frameWindow = protocolIframe?.contentWindow; - if (!frameWindow) { - throw new Error("Shared protocol iframe is unavailable"); - } - const stopReq = m.timer(S.PROTOCOL_REQUEST); - const value = await sendRequest( - frameWindow, - method, - payload, - onProgress, - ).reply; - stopReq(); - return value; - } + await awaitFrame(needsProtocolReady); + const recordRoundtrip = m.timer(S.PROTOCOL_REQUEST); + const value = await sendRequest( + requireFrameWindow(), + method, + payload, + onProgress, + ).reply; + recordRoundtrip(); + return value; +} - // Arm the budget before creating the frame promise. Equal-expiry timers fire - // in creation order, so a budget that ties with the iframe load timeout still - // reports itself rather than the load failure. +async function postBudgetedRequest( + method: M, + payload: ProtocolRequestMap[M], + onProgress: ((message: string) => void) | undefined, + needsProtocolReady: boolean, + timeoutMs: number, +): Promise { const budget = startRequestBudget(method, timeoutMs); try { await budget.guard("load", ensureHostFrame()); if (needsProtocolReady) { await budget.guard("ready", ensureProtocolFrame()); } - const frameWindow = protocolIframe?.contentWindow; - if (!frameWindow) { - throw new Error("Shared protocol iframe is unavailable"); - } - - const stopReq = m.timer(S.PROTOCOL_REQUEST); + const frameWindow = requireFrameWindow(); + const recordRoundtrip = m.timer(S.PROTOCOL_REQUEST); const sent = sendRequest(frameWindow, method, payload, onProgress); try { const value = await budget.guard("reply", sent.reply); - stopReq(); + recordRoundtrip(); return value; } catch (error: unknown) { - // The listener drops the entry when a reply lands. Nothing will arrive - // now, so this is the only path that has to drop it. pendingRequests.delete(sent.id); - // A spent budget still describes a roundtrip the histogram should carry. - // A fatal envelope or a response error does not, which matches the - // pre-existing behaviour of recording no sample on those paths. - if (error instanceof ProtocolRequestTimeoutError) { - stopReq(); - } throw error; } } finally { @@ -645,6 +629,27 @@ async function postRequest( } } +function postRequest( + method: M, + payload: ProtocolRequestMap[M], + onProgress?: (message: string) => void, + needsProtocolReady = !isSharedAuthRequestMethod(method) && + !isSharedModeRequestMethod(method), +): Promise { + const timeoutMs = UNTIMED_METHODS.has(method) + ? null + : (METHOD_TIMEOUTS[method] ?? DEFAULT_TIMEOUT_MS); + return timeoutMs === null + ? postUnbudgetedRequest(method, payload, onProgress, needsProtocolReady) + : postBudgetedRequest( + method, + payload, + onProgress, + needsProtocolReady, + timeoutMs, + ); +} + export async function warmupProtocol(): Promise { await postRequest("warmup", {}); } @@ -817,9 +822,8 @@ export function createRemoteChainProvider( chainConnections.set(connectionId, remote); - void ensureProtocolFrame() - .then(async () => { - await postRequest("chainConnect", { genesisHash, connectionId }); + void postRequest("chainConnect", { genesisHash, connectionId }) + .then(() => { remote.connected = true; for (const message of remote.pendingMessages) { void postRequest("chainSend", { diff --git a/packages/protocol/tests/client.test.ts b/packages/protocol/tests/client.test.ts index e26a6d52..a8e107e8 100644 --- a/packages/protocol/tests/client.test.ts +++ b/packages/protocol/tests/client.test.ts @@ -21,8 +21,10 @@ import { type Mock, } from "vitest"; import { SITE_ID } from "@dotli/config/config"; +import { getActiveSupportedGenesisHashes } from "@dotli/config/network"; import { SHARED_CORE_SESSION_KEY } from "@dotli/protocol/auth-storage"; import { + createRemoteChainProvider, getProtocolOrigin, readSharedAuthStorage, readSharedModeStorage, @@ -114,6 +116,7 @@ describe("Keeping a protocol request inside the time limit it promises", () => { limitMs: 90_000, opensAfterMs: 0, blamedWait: "ready", + calledMethod: "resolveDotName", call: () => resolveDotNameRemote("alice"), }, { @@ -122,6 +125,7 @@ describe("Keeping a protocol request inside the time limit it promises", () => { limitMs: 30_000, opensAfterMs: 20_000, blamedWait: "reply", + calledMethod: "authStorageRead", call: () => readSharedAuthStorage(SITE_ID, SHARED_CORE_SESSION_KEY), }, { @@ -130,13 +134,14 @@ describe("Keeping a protocol request inside the time limit it promises", () => { limitMs: 30_000, opensAfterMs: null, blamedWait: "load", + calledMethod: "authStorageRead", call: () => readSharedAuthStorage(SITE_ID, SHARED_CORE_SESSION_KEY), }, ]; it.each(slowFrameCases)( "As someone making $request, I wait no longer than the limit I was promised when the shared frame $frame, and I am told which wait spent it", - async ({ limitMs, opensAfterMs, blamedWait, call }) => { + async ({ limitMs, opensAfterMs, blamedWait, calledMethod, call }) => { // Given a shared frame that is slow in the way this example describes const pending = call(); const settled = settleTracker(pending); @@ -157,6 +162,7 @@ describe("Keeping a protocol request inside the time limit it promises", () => { await vi.advanceTimersByTimeAsync(1); await expect(pending).rejects.toBeInstanceOf(ProtocolRequestTimeoutError); await expect(pending).rejects.toMatchObject({ + method: calledMethod, timeoutMs: limitMs, phase: blamedWait, }); @@ -214,14 +220,81 @@ describe("Keeping a protocol request inside the time limit it promises", () => { frame.dispatchEvent(new Event("load")); await flush(); - // When four times the ordinary request limit goes by - await vi.advanceTimersByTimeAsync(120_000); + // When the whole allowance for becoming ready goes by, one millisecond + // short of its end + await vi.advanceTimersByTimeAsync(239_999); // Then the warm-up is still waiting expect(settled()).toBe(false); + + // And when that allowance runs out, becoming ready is the reported + // reason, never a limit of the warm-up's own + await vi.advanceTimersByTimeAsync(1); + await expect(pending).rejects.toThrow( + "Shared protocol iframe timed out (no ready signal)", + ); + await expect(pending).rejects.not.toBeInstanceOf( + ProtocolRequestTimeoutError, + ); + }); + + it("As someone whose light client crashes mid-request, I am told it crashed rather than being told my own time ran out", async () => { + // Given a name lookup that has reached a ready frame + const pending = resolveDotNameRemote("alice"); + const settled = settleTracker(pending); + await flush(); + frame.dispatchEvent(new Event("load")); + await flush(); + dispatchFromFrame({ namespace: "dotli:protocol", kind: "ready" }); + await flush(); + + // When the light client crashes well inside the promised limit + await vi.advanceTimersByTimeAsync(10_000); + dispatchFromFrame({ + namespace: "dotli:protocol", + kind: "fatal", + message: "smoldot panicked", + }); + await flush(); + + // Then the crash is the reported reason + expect(settled()).toBe(true); + await expect(pending).rejects.toThrow("smoldot panicked"); + await expect(pending).rejects.not.toBeInstanceOf( + ProtocolRequestTimeoutError, + ); + }); + + it("As someone whose reply never came, I stop hearing progress for that request once my time has run out", async () => { + // Given a name lookup on a ready frame, reporting progress as it goes + const progress = vi.fn(); + const pending = resolveDotNameRemote("alice", progress); + const settled = settleTracker(pending); + await flush(); + frame.dispatchEvent(new Event("load")); + await flush(); + dispatchFromFrame({ namespace: "dotli:protocol", kind: "ready" }); + await flush(); + const request = framePostMessage.mock.calls.at(-1)?.[0] as { id: string }; + + // When my time runs out and the frame reports progress afterwards + await vi.advanceTimersByTimeAsync(90_000); + expect(settled()).toBe(true); + await expect(pending).rejects.toBeInstanceOf(ProtocolRequestTimeoutError); + progress.mockClear(); + dispatchFromFrame({ + namespace: "dotli:protocol", + kind: "progress", + id: request.id, + message: "still working", + }); + await flush(); + + // Then that progress reaches nobody + expect(progress).not.toHaveBeenCalled(); }); - it("As someone reading a saved preference from a healthy frame, I get my answer and nothing cuts me off afterwards", async () => { + it("As someone reading a saved preference from a healthy frame, I get my answer and nothing is left ticking", async () => { // Given a healthy shared frame const pending = readSharedModeStorage(SITE_ID, "backend"); await flush(); @@ -229,19 +302,50 @@ describe("Keeping a protocol request inside the time limit it promises", () => { await flush(); // When the frame answers - const envelope = framePostMessage.mock.calls[0]?.[0] as { id: string }; + const request = framePostMessage.mock.calls[0]?.[0] as { id: string }; dispatchFromFrame({ namespace: "dotli:protocol", kind: "response", - id: envelope.id, + id: request.id, ok: true, result: "smoldot-shared-worker", }); - - // Then the answer comes back, and letting the clock run past the limit - // changes nothing await expect(pending).resolves.toBe("smoldot-shared-worker"); + + // Then no limit of mine is still counting down, and letting the clock run + // past where it would have expired changes nothing + expect(vi.getTimerCount()).toBe(0); await vi.advanceTimersByTimeAsync(60_000); await expect(pending).resolves.toBe("smoldot-shared-worker"); }); + + it("As a dApp opening a chain connection while the frame is still starting up, I am told the connection failed inside the time a connection is promised", async () => { + // Given a chain the active backend serves, and a frame that opens but + // never reports itself ready + const [genesisHash] = [...getActiveSupportedGenesisHashes()]; + expect(genesisHash).toBeDefined(); + const replies: unknown[] = []; + const connect = createRemoteChainProvider(genesisHash as string); + const connection = connect?.((message) => { + replies.push(message); + }); + await flush(); + frame.dispatchEvent(new Event("load")); + await flush(); + + // When I ask for a block and the connection's own allowance runs out + connection?.send({ jsonrpc: "2.0", id: 7, method: "chain_getBlock" }); + await vi.advanceTimersByTimeAsync(30_000); + await flush(); + + // Then I have my error, long before the frame gives up on becoming ready + expect(replies).toEqual([ + { + jsonrpc: "2.0", + id: 7, + error: { code: -32603, message: expect.stringContaining("timed out") }, + }, + ]); + }); + }); From a6ced78aeab256572e43d186e1dd61bb6a88704d Mon Sep 17 00:00:00 2001 From: Ryan Lee Date: Fri, 14 Aug 2026 20:04:26 +0000 Subject: [PATCH 05/18] refactor(protocol): inline the single-caller frame wait --- packages/protocol/src/client.ts | 6 +----- 1 file changed, 1 insertion(+), 5 deletions(-) diff --git a/packages/protocol/src/client.ts b/packages/protocol/src/client.ts index 20de7d2f..9c35b18f 100644 --- a/packages/protocol/src/client.ts +++ b/packages/protocol/src/client.ts @@ -570,10 +570,6 @@ function sendRequest( return { id, reply }; } -function awaitFrame(needsProtocolReady: boolean): Promise { - return needsProtocolReady ? ensureProtocolFrame() : ensureHostFrame(); -} - function requireFrameWindow(): Window { const frameWindow = protocolIframe?.contentWindow; if (!frameWindow) { @@ -588,7 +584,7 @@ async function postUnbudgetedRequest( onProgress: ((message: string) => void) | undefined, needsProtocolReady: boolean, ): Promise { - await awaitFrame(needsProtocolReady); + await (needsProtocolReady ? ensureProtocolFrame() : ensureHostFrame()); const recordRoundtrip = m.timer(S.PROTOCOL_REQUEST); const value = await sendRequest( requireFrameWindow(), From 8df7c2cc77df98c9e7dde969516f83d1f0c36c60 Mon Sep 17 00:00:00 2001 From: Ryan Lee Date: Fri, 14 Aug 2026 20:30:19 +0000 Subject: [PATCH 06/18] docs(solutions): capture the call-time budget learning The defect generalises past this fix: a per-operation budget armed after an unbounded setup wait advertises a bound it does not hold. Records the two rejected alternatives with their reasons, and the mutation-probe result that matters most - the suite was fully green with the timer disarm deleted and again with the pending-entry cleanup deleted, so a green run was not evidence either invariant was defended. Seeds CONCEPTS.md for the protocol-frame area, including the host-frame versus protocol-frame distinction that names two readiness stages of one iframe rather than two elements. --- CONCEPTS.md | 55 +++++++ ...t-timeout-starts-after-frame-ready-wait.md | 148 ++++++++++++++++++ 2 files changed, 203 insertions(+) create mode 100644 CONCEPTS.md create mode 100644 docs/solutions/logic-errors/protocol-request-timeout-starts-after-frame-ready-wait.md diff --git a/CONCEPTS.md b/CONCEPTS.md new file mode 100644 index 00000000..eccedbf4 --- /dev/null +++ b/CONCEPTS.md @@ -0,0 +1,55 @@ +# Concepts + +Shared domain vocabulary for this project — entities, named processes, and status concepts with project-specific meaning. Seeded with core domain vocabulary, then accretes as ce-compound and ce-compound-refresh process learnings; direct edits are fine. Glossary only, not a spec or catch-all. + +## The protocol frame + +### Protocol frame + +The hidden iframe, served from the protocol origin, that brokers all chain work for every product surface open in a tab. + +There is exactly one per tab, and it is shared: product surfaces never talk to a chain directly, they post requests to it. It reaches usable state in two stages — loaded, then ready — and the distinction matters because different requests need different stages. Tearing it down rejects everything waiting on readiness and orphans requests already in flight. + +### Host frame + +The protocol frame in its first stage: the element has loaded, but its worker has not yet announced that it can serve chain work. + +Requests that only read shared authentication or shared mode storage need this stage and no more, so they are usable well before chain work is. Anything touching a chain must wait for the ready signal. + +### Ready signal + +The protocol frame's announcement that it can serve chain work. + +It is emitted once, after presync completes, and is what separates the host frame stage from a fully ready protocol frame. Callers waiting on it are rejected together if the frame is torn down first. + +### Presync + +The initial chain sync a protocol frame's worker performs before emitting its ready signal. + +Its duration is what makes readiness slow on a cold start. The allowance for waiting on the ready signal is deliberately set above the worker's own allowance for presync, so the outer wait cannot expire while the inner sync is still legitimately progressing. + +## Requests + +### Request budget + +The single time bound a protocol request promises its caller, measured from the moment the request is made and covering every wait it performs. + +One budget spans waiting for the frame to load, waiting for readiness, and waiting for a reply — it is not a bound on the reply alone, and it is not added on top of the frame's own allowances. Some methods are deliberately exempt because they wait on chain sync rather than on a peer, and an exempt method is bounded only by the frame's allowances. A budget is disarmed the moment its request settles. + +### Timeout phase + +Which wait consumed a request budget: loading the frame, waiting for readiness, or waiting for a reply. + +Recorded when the budget expires rather than inferred afterwards, so it names the wait actually in progress. A frame-level failure that surfaces before the budget expires is reported as itself, not as a phase — the phase describes a request that ran out of its own time. + +## Chain access + +### Remote chain connection + +A JSON-RPC channel between a sandboxed app and a chain, brokered through the protocol frame. + +Messages sent before the connection is established are queued rather than rejected, so a connection that never establishes looks unresponsive rather than failed until its budget expires. Each connection is independent and carries its own identity. Tearing down the protocol frame does not close them: a send on a connection that had established is answered with an error, while one that never established keeps queueing. + +## Flagged ambiguities + +- "Host frame" and "protocol frame" had been used interchangeably for the same iframe — they name two readiness stages of one element, not two elements. Use host frame for loaded-only and protocol frame for ready. diff --git a/docs/solutions/logic-errors/protocol-request-timeout-starts-after-frame-ready-wait.md b/docs/solutions/logic-errors/protocol-request-timeout-starts-after-frame-ready-wait.md new file mode 100644 index 00000000..70bc0b78 --- /dev/null +++ b/docs/solutions/logic-errors/protocol-request-timeout-starts-after-frame-ready-wait.md @@ -0,0 +1,148 @@ +--- +title: Protocol request timeout started after the frame-ready wait, not at the call +date: 2026-08-14 +category: logic-errors +module: packages/protocol +problem_type: logic_error +component: service_object +symptoms: + - First request against a cold or wedged protocol frame blocked up to roughly five minutes while advertising a 30 second timeout + - Rejection did not say whether the time went into booting the frame or waiting for a reply + - A dApp chain connection stacked 30s plus 240s plus 30s before any JSON-RPC error reached it + - Every message sent during that window queued silently, so the chain looked unresponsive rather than failed + - Timeout samples landed in the protocol.request latency series as the leftover budget, so p99 improved as the protocol degraded +root_cause: async_timing +resolution_type: code_fix +severity: high +tags: + - protocol-client + - timeout + - iframe + - request-budget + - async-timing + - metrics + - mutation-testing + - error-handling +--- + +# Protocol request timeout started after the frame-ready wait, not at the call + +## Problem + +`postRequest` advertised a per-method timeout and callers reasonably read it as the bound on the call. The timer was only created *after* awaiting the shared protocol iframe becoming ready, and that wait carries its own budgets. A first request against a cold or wedged frame could therefore block for up to roughly five minutes while reporting a 30 second contract, and the rejection never said where the time went. Fixed on branch `fix/protocol-request-call-time-budget` (issue #166), unmerged as of this writing. + +## Symptoms + +- A request with a 30 second budget could take up to `IFRAME_LOAD_TIMEOUT_MS` (30_000, `packages/protocol/src/client.ts:322`) plus `IFRAME_READY_TIMEOUT_MS` (240_000, `client.ts:326`) plus its own 30 seconds before rejecting — a worst case of roughly five minutes, of which the first four and a half are the frame wait alone. +- The rejection was a bare `Error` reading `Protocol request "" timed out after ms`, with nothing to distinguish a frame that never loaded from one that loaded but never signalled ready from one that never answered. +- `createRemoteChainProvider` awaited the frame outside any budget and only then issued `chainConnect`, so a dApp connecting during a cold boot waited out both frame budgets before the connection's own 30 seconds even started. +- During that window `send()` pushed every JSON-RPC message onto `pendingMessages` and returned nothing, so the dApp saw an unresponsive chain rather than a failure. +- The old timer called `stopReq()` on expiry, so a timeout recorded roughly the whole budget as a duration sample. Preserving that call after the fix would have recorded the *leftover* budget instead, because the budget now starts at the call while the roundtrip timer starts at the reply. + +## What Didn't Work + +- **Deadline arithmetic with `Date.now()`.** Compute `Date.now() + timeoutMs` once and re-check the remainder before each phase. Rejected: an NTP step or a laptop resume moves the bound underneath the request. A single `setTimeout` armed once is subject only to the timer queue. +- **`@std/async` from JSR.** `deadline()` constructs a fresh `AbortSignal.timeout(ms)` inside its own body, so every call starts a new window — which is precisely the defect being fixed. `abortable()` plus one shared `AbortSignal.timeout` can hold a deadline across sequential awaits, but `AbortSignal.timeout` exposes no cancel API, so the disarm on early completion becomes a no-op and every settled request leaves a timer running to full expiry. It also rejects with a fixed `DOMException`, so naming the phase still needs a re-wrap. +- **Emitting the phase counter from the guard's rejection path.** Proposed so that a load failure killing ten in-flight requests counts ten times instead of once. Rejected: the tie case already emits both a `PROTOCOL_REQUEST` timeout and a `PROTOCOL_IFRAME_READY` error for the same frame failure, and a second emission point widens that double-count. The reachability limit is documented instead: only the caller that creates the frame promise can report the `load` phase, because no method budget is below `IFRAME_LOAD_TIMEOUT_MS`. +- **Reducing a frame constant so the request budget would win.** Never attempted, and explicitly out of bounds: it would shorten the frame's own allowance for every caller to fix an ordering bug. + +## Solution + +One timer, armed at call time, raced against each phase in turn. + +`startRequestBudget` (`client.ts:514`) creates a single `setTimeout` and returns a `RequestBudget` (`client.ts:502-505`) whose `guard(phase, work)` records which wait is running and races it against the shared expiry, and whose `release()` clears the timer (`client.ts:534-536`). + +Before — the frame wait precedes the timer entirely: + +```ts +async function postRequest( + method: M, + payload: ProtocolRequestMap[M], + onProgress?: (message: string) => void, + needsProtocolReady = /* ... */, +): Promise { + await (needsProtocolReady ? ensureProtocolFrame() : ensureHostFrame()); + // ... build the envelope ... + const timeoutMs = UNTIMED_METHODS.has(method) + ? null + : (METHOD_TIMEOUTS[method] ?? DEFAULT_TIMEOUT_MS); + const stopReq = m.timer(S.PROTOCOL_REQUEST); + + return new Promise((resolve, reject) => { + const timer = + timeoutMs === null + ? null + : setTimeout(() => { + pendingRequests.delete(id); + m.count(S.PROTOCOL_REQUEST, { outcome: "timeout", method }); + stopReq(); + reject( + new Error( + `Protocol request "${method}" timed out after ${String(timeoutMs)}ms`, + ), + ); + }, timeoutMs); + // ... + }); +} +``` + +After — the budget is armed first and covers every wait (`client.ts:606-621`): + +```ts +const budget = startRequestBudget(method, timeoutMs); +try { + await budget.guard("load", ensureHostFrame()); + if (needsProtocolReady) { + await budget.guard("ready", ensureProtocolFrame()); + } + const frameWindow = requireFrameWindow(); + const recordRoundtrip = m.timer(S.PROTOCOL_REQUEST); + const sent = sendRequest(frameWindow, method, payload, onProgress); + try { + const value = await budget.guard("reply", sent.reply); + recordRoundtrip(); + return value; + } catch (error: unknown) { + pendingRequests.delete(sent.id); + throw error; + } +} finally { + budget.release(); +} +``` + +Three further pieces: + +- **A typed rejection.** `ProtocolRequestTimeoutError` (`packages/protocol/src/errors.ts:34`) carries `method`, `timeoutMs`, and a `phase` of `"load" | "ready" | "reply"` (`errors.ts:19`), rendered into the message from `PHASE_DESCRIPTIONS` (`errors.ts:21-25`). The phase is read when the timer fires, so it names the wait that actually consumed the budget rather than the wait the caller happened to start in. +- **The provider stops stacking.** `createRemoteChainProvider` (`client.ts:804`) now calls `postRequest("chainConnect", …)` directly (`client.ts:821`). The request already performs both frame waits, so the previous outer `ensureProtocolFrame()` was redundant as well as unbounded. +- **Failures record no duration.** `recordRoundtrip()` fires only on a completed roundtrip (`client.ts:617`). Because the budget starts at the call and this timer starts at the reply, sampling on a timeout would write the leftover budget — a 90 second failure landing as a 3 second sample in a series with no `outcome` attribute to filter on. + +Consumers that mapped the timeout by message text were updated to match the type: `describeError` (`apps/host/src/errors.ts:45`) now tests `err instanceof ProtocolRequestTimeoutError` alongside the existing text match (`apps/host/src/errors.ts:90-92`), keeping the string branch for foreign timeouts that still need it. + +No existing timeout constant was reduced, and `warmup` remains exempt from any budget (`client.ts:492-493`) because it waits on chain sync. + +## Why This Works + +- **The bound is measured from the moment the caller asked.** One `setTimeout` armed before any await covers load, ready, and reply, so the advertised per-method budget is the real ceiling instead of the last term in a sum. +- **The tie is resolved by construction.** The budget timer is created before the frame promise, and equal-expiry timers fire in creation order. Since no method budget is below `IFRAME_LOAD_TIMEOUT_MS`, a 30 second request against a frame that never loads reports its own timeout rather than the frame's — which is also the only reason the `load` phase is reachable at all. +- **A more specific frame error still wins when it genuinely settles first.** `Promise.race` keeps the first settlement, so `ProtocolFatalError`, `ProtocolInitFailedError`, and the frame-reset error continue to reach callers instead of being masked by a budget rejection. +- **Abandoning a shared wait is safe.** `Promise.race` attaches a handler to both operands, so a cached frame promise that a timed-out caller stopped awaiting cannot become an unhandled rejection, and a second caller still attached is unaffected. +- **The telemetry no longer improves as the system degrades.** Timeouts are counted with their phase and contribute no duration sample, so the latency series means completed roundtrips only. + +## Prevention + +- **A green suite is not evidence that a cleanup invariant is defended.** Deleting `budget.release()` left the suite fully green, and so did deleting `pendingRequests.delete(sent.id)`. Both mutations ship real damage: an undisarmed timer emits a spurious timeout count after the request already succeeded, and a missing delete leaks a pending entry holding the caller's progress callback. Assert cleanup through observable behaviour: + - after a request resolves on a healthy frame, `expect(vi.getTimerCount()).toBe(0)` (`packages/protocol/tests/client.test.ts:317`); + - after a reply-phase timeout, deliver a late `progress` envelope for that request's id and assert the caller's callback was not invoked (`packages/protocol/tests/client.test.ts:294`). +- **Probe the gate with mutations before trusting it.** Apply one mutation at a time to the real source, run the suite, restore. Six mutations each need a named failing scenario: dropping the timer disarm, dropping the pending-entry delete, restoring the provider's unbudgeted wait, arming the budget after the frame wait, giving `warmup` a budget, and relabelling a crash as the caller's own timeout. A mutation that leaves the suite green names a scenario that defends nothing. Beware writing a no-op mutation — `throw cond ? error : error` changes nothing and its green run means nothing. +- **A per-operation budget must cover the setup it depends on.** When an operation advertises a timeout, audit every `await` that precedes the timer for its own budget. The pattern to grep for is an unbudgeted readiness wait followed by a budgeted call: `await ensureX(); await withTimeout(op)`. Prefer letting the budgeted call own the readiness wait. +- **Never record a duration sample on a failure path in an attribute-less series.** The residual between a call-time budget and a later-started timer reads as a fast success and quietly flatters the percentile it should be inflating. +- **Attribute a timeout to the phase that consumed it, read at fire time.** Reconstructing the phase from which promise won the race is wrong whenever a shared wait is involved; a mutable cell set by each guard and read inside the timer callback is not. +- **When a consumer branches on an error, give it a type to branch on.** `apps/host/src/errors.ts` branched on ten distinct message substrings, so rewording a message silently changed user-facing copy and the recovery affordance. `apps/host` has no unit-test runner, so no test could have caught it — the type is the gate. + +## Related Issues + +- Issue #166 — the defect this documents. +- `docs/plans/2026-08-14-1856-fix-protocol-request-call-time-budget-plan.md` — the plan for this fix. Two of its statements were superseded during execution: it scoped the provider's direct `ensureProtocolFrame()` call out of the work on the grounds that such calls "are not requests and cannot produce a request budget", which is true of a bare prefetch but not of this call site, where a request follows immediately. Adversarial review falsified that reasoning and the call site was fixed. +- `docs/smoldot.md` — describes `createRemoteChainProvider` and the protocol iframe. Its prose states no timeout contract, so nothing there was invalidated, but a note that `chainConnect` is now bounded by its own request budget would be accurate. From 55e9cdc70b5cb84d262660a1c2319a9b8467f57d Mon Sep 17 00:00:00 2001 From: Ryan Lee Date: Fri, 14 Aug 2026 22:27:58 +0000 Subject: [PATCH 07/18] test(protocol): decompose protocol test suite into dual-driver domain DSL Split monolithic client.test.ts into domain-focused suites (timeouts, error precedence, chain provider) using a reusable dual-driver harness (DAppDriver / ProtocolFrame) and Rpc factory. Expand parameterized test coverage and add package AGENTS.md. --- packages/protocol/AGENTS.md | 11 + packages/protocol/tests/auth-storage.test.ts | 110 +++--- .../tests/client-chain-provider.test.ts | 201 ++++++++++ .../protocol/tests/client-precedence.test.ts | 146 +++++++ .../protocol/tests/client-timeouts.test.ts | 357 ++++++++++++++++++ packages/protocol/tests/client.test.ts | 351 ----------------- packages/protocol/tests/errors.test.ts | 60 +++ packages/protocol/tests/support/dapp.ts | 57 +++ packages/protocol/tests/support/frame.ts | 220 +++++++++++ packages/protocol/tests/support/index.ts | 20 + packages/protocol/tests/support/rpc.ts | 37 ++ packages/protocol/tests/support/time.ts | 82 ++++ 12 files changed, 1255 insertions(+), 397 deletions(-) create mode 100644 packages/protocol/AGENTS.md create mode 100644 packages/protocol/tests/client-chain-provider.test.ts create mode 100644 packages/protocol/tests/client-precedence.test.ts create mode 100644 packages/protocol/tests/client-timeouts.test.ts delete mode 100644 packages/protocol/tests/client.test.ts create mode 100644 packages/protocol/tests/errors.test.ts create mode 100644 packages/protocol/tests/support/dapp.ts create mode 100644 packages/protocol/tests/support/frame.ts create mode 100644 packages/protocol/tests/support/index.ts create mode 100644 packages/protocol/tests/support/rpc.ts create mode 100644 packages/protocol/tests/support/time.ts diff --git a/packages/protocol/AGENTS.md b/packages/protocol/AGENTS.md new file mode 100644 index 00000000..1fc884cd --- /dev/null +++ b/packages/protocol/AGENTS.md @@ -0,0 +1,11 @@ +# Protocol Package Instructions + +Governs `packages/protocol` postMessage bridge, shared storage, and client-side chain provider. + +## Package Invariants + +| id | rule | gate | +|---|---|---| +| PROTO-T1 | Protocol tests use the dual-driver harness (`createTestDApp` / `installProtocolFrame`) from `tests/support/`; never mock `window.postMessage` or DOM elements inline in test files. | `! grep -E "addEventListener\(\"message\"|contentWindow" packages/protocol/tests/*.test.ts` | +| PROTO-T2 | Test scenarios assert on parsed domain getters (`frame.sentRpcRequests()`, `frame.connectionId()`, `dApp.replies()`); never parse raw `chainSend` message strings inside scenario bodies. | `! grep -E "JSON\.parse\(" packages/protocol/tests/*.test.ts` | +| PROTO-T3 | Asynchronous scenario synchronization must use virtual timer primitives (`settleWithin`, `until`, `bootAndConnect`); never chain ad-hoc tick yields (`await elapse(1)`). | Review of async wait patterns in `packages/protocol/tests/*.test.ts` | diff --git a/packages/protocol/tests/auth-storage.test.ts b/packages/protocol/tests/auth-storage.test.ts index ae8303f0..8ff727e4 100644 --- a/packages/protocol/tests/auth-storage.test.ts +++ b/packages/protocol/tests/auth-storage.test.ts @@ -6,70 +6,80 @@ import { SITE_ID } from "@dotli/config/config"; import { buildLegacySharedAuthSessionStorageKey, buildSharedAuthStorageKey, + buildSharedModeStorageKey, isSharedAuthOriginAllowed, isSharedAuthRequestMethod, isSharedAuthSiteId, + isSharedModeRequestMethod, isValidSharedAuthKey, + isValidSharedModeKey, SHARED_CORE_SESSION_KEY, } from "@dotli/protocol/auth-storage"; -describe("shared auth storage helpers", () => { - it("accepts host shell origins and rejects app origins", () => { - expect(isSharedAuthOriginAllowed("https://dot.li")).toBe(true); - expect(isSharedAuthOriginAllowed("https://browse.dot.li")).toBe(true); - expect(isSharedAuthOriginAllowed("https://host-playground.dot.li")).toBe( - true, - ); - expect(isSharedAuthOriginAllowed("https://host.dot.li")).toBe(true); +describe("shared auth and mode storage helpers", () => { + interface OriginCase { + origin: string; + allowed: boolean; + reason: string; + } - expect(isSharedAuthOriginAllowed("https://bafy.app.dot.li")).toBe(false); - expect(isSharedAuthOriginAllowed("https://app.dot.li")).toBe(false); - expect(isSharedAuthOriginAllowed("https://evil.example.com")).toBe(false); - }); + const originCases: OriginCase[] = [ + { origin: "https://dot.li", allowed: true, reason: "root host shell" }, + { origin: "https://browse.dot.li", allowed: true, reason: "browse subdomain" }, + { origin: "https://host-playground.dot.li", allowed: true, reason: "playground subdomain" }, + { origin: "https://host.dot.li", allowed: true, reason: "host subdomain" }, + { origin: "https://bafy.app.dot.li", allowed: false, reason: "app subdomain" }, + { origin: "https://app.dot.li", allowed: false, reason: "app root" }, + { origin: "https://evil.example.com", allowed: false, reason: "foreign domain" }, + { origin: "http://localhost:5173", allowed: true, reason: "localhost port" }, + { origin: "http://browse.localhost:5173", allowed: true, reason: "browse localhost" }, + { origin: "http://host.localhost:5173", allowed: true, reason: "host localhost" }, + { origin: "http://bafy.app.localhost:5173", allowed: false, reason: "app localhost" }, + { origin: "http://dot.li", allowed: false, reason: "insecure http remote" }, + { origin: "not a url", allowed: false, reason: "malformed url string" }, + ]; - it("accepts localhost host shells and rejects localhost app origins", () => { - expect(isSharedAuthOriginAllowed("http://localhost:5173")).toBe(true); - expect(isSharedAuthOriginAllowed("http://browse.localhost:5173")).toBe( - true, - ); - expect(isSharedAuthOriginAllowed("http://host.localhost:5173")).toBe(true); - - expect(isSharedAuthOriginAllowed("http://bafy.app.localhost:5173")).toBe( - false, - ); - }); + it.each(originCases)( + "evaluates origin $origin as $allowed because it is $reason", + ({ origin, allowed }) => { + expect(isSharedAuthOriginAllowed(origin)).toBe(allowed); + }, + ); it("accepts only the current shell's SITE_ID", () => { - // In the vitest happy-dom environment, `self.location.hostname` is - // "localhost", so `SITE_ID` is "local.li". The allowlist is runtime- - // driven, not a hard-coded list. This guarantees a host running on - // `host.paseoli.dev` would accept `"paseoli.dev"` and reject `"dot.li"`, - // and vice versa. expect(SITE_ID).toBe("local.li"); expect(isSharedAuthSiteId(SITE_ID)).toBe(true); }); - it("rejects siteIds belonging to unrelated root domains", () => { - // A hard-coded allowlist would treat these as `true`. They must all be - // `false` because cross-root-domain session sharing is explicitly - // disallowed across dot.li, paseo.li, and paseoli.dev. - expect(isSharedAuthSiteId("dot.li")).toBe(false); - expect(isSharedAuthSiteId("paseo.li")).toBe(false); - expect(isSharedAuthSiteId("paseoli.dev")).toBe(false); - expect(isSharedAuthSiteId("staging.dot.li")).toBe(false); - expect(isSharedAuthSiteId("")).toBe(false); + it.each(["dot.li", "paseo.li", "paseoli.dev", "staging.dot.li", ""])( + "rejects foreign or empty siteId %s", + (siteId) => { + expect(isSharedAuthSiteId(siteId)).toBe(false); + }, + ); + + it.each([ + { key: "SsoSessions", valid: true }, + { key: "UserSecrets_abc-123", valid: true }, + { key: "identity_0x1234", valid: true }, + { key: "../secrets", valid: false }, + { key: "key with spaces", valid: false }, + { key: "", valid: false }, + ])("validates auth key $key as $valid", ({ key, valid }) => { + expect(isValidSharedAuthKey(key)).toBe(valid); }); - it("validates storage keys", () => { - expect(isValidSharedAuthKey("SsoSessions")).toBe(true); - expect(isValidSharedAuthKey("UserSecrets_abc-123")).toBe(true); - expect(isValidSharedAuthKey("identity_0x1234")).toBe(true); - expect(isValidSharedAuthKey("../secrets")).toBe(false); - expect(isValidSharedAuthKey("key with spaces")).toBe(false); - expect(isValidSharedAuthKey("")).toBe(false); + it.each([ + { key: "backend", valid: true }, + { key: "dotli:chain-backend", valid: true }, + { key: "cache_policy-v2", valid: true }, + { key: "invalid key!", valid: false }, + { key: "", valid: false }, + ])("validates mode key $key as $valid", ({ key, valid }) => { + expect(isValidSharedModeKey(key)).toBe(valid); }); - it("As a returning user, my shared authentication uses stable storage keys", () => { + it("builds consistent shared storage keys for auth and mode namespaces", () => { expect(buildSharedAuthStorageKey("dot.li", SHARED_CORE_SESSION_KEY)).toBe( "TRUAPI_dot.li_session", ); @@ -82,12 +92,20 @@ describe("shared auth storage helpers", () => { expect(buildLegacySharedAuthSessionStorageKey("dot.li")).toBe( "PAPP_dot.li_SsoSessionsV3", ); + expect(buildSharedModeStorageKey("local.li", "backend")).toBe( + "DOTLI_MODE_local.li_backend", + ); }); - it("identifies shared-auth RPC methods", () => { + it("identifies shared-auth and shared-mode RPC methods", () => { expect(isSharedAuthRequestMethod("authStorageRead")).toBe(true); expect(isSharedAuthRequestMethod("authStorageWrite")).toBe(true); expect(isSharedAuthRequestMethod("authStorageClear")).toBe(true); expect(isSharedAuthRequestMethod("warmup")).toBe(false); + + expect(isSharedModeRequestMethod("modeStorageRead")).toBe(true); + expect(isSharedModeRequestMethod("modeStorageWrite")).toBe(true); + expect(isSharedModeRequestMethod("modeStorageClear")).toBe(true); + expect(isSharedModeRequestMethod("resolveDotName")).toBe(false); }); }); diff --git a/packages/protocol/tests/client-chain-provider.test.ts b/packages/protocol/tests/client-chain-provider.test.ts new file mode 100644 index 00000000..5eb9acfd --- /dev/null +++ b/packages/protocol/tests/client-chain-provider.test.ts @@ -0,0 +1,201 @@ +// Copyright 2026 Parity Technologies (UK) Ltd. +// SPDX-License-Identifier: AGPL-3.0-only + +/** + * Remote chain provider connection lifecycle, queuing, and message delivery. + * + * Verifies that dApps opening chain connections before the shared frame is ready + * have their requests queued and delivered upon connection completion, that + * chain replies route back to the correct client, and that connection failures + * cleanly surface errors to the consumer within connection time limits. + */ + +import { afterEach, beforeEach, describe, expect, it, vi } from "vitest"; +import { + createRemoteChainProvider, + isRemoteChainSupported, + resetProtocolFrame, +} from "@dotli/protocol/client"; +import { + createTestDApp, + elapse, + installProtocolFrame, + Rpc, + until, + type ProtocolFrame, +} from "./support"; + +describe("Remote chain provider lifecycle and request routing", () => { + let frame: ProtocolFrame; + + beforeEach(() => { + vi.useFakeTimers(); + frame = installProtocolFrame(); + }); + + afterEach(() => { + resetProtocolFrame(); + frame.restore(); + vi.useRealTimers(); + document.body.innerHTML = ""; + }); + + it("As a dApp opening a chain connection while the frame is still starting up, I am told the connection failed inside the time a connection is promised", async () => { + // Given + const dApp = createTestDApp(); + frame.open(); + await elapse(1); + + // When + dApp.send(Rpc.request(7)); + + // Then + await until(() => dApp.replies().length > 0, 30_000); + expect(dApp.lastReply()).toMatchObject(Rpc.error(7)); + }); + + it("As a dApp whose chain connection opens while the frame is starting, my queued request is delivered and its answer reaches me", async () => { + // Given + const dApp = createTestDApp(); + dApp.send(Rpc.request(7)); + + // When + await frame.bootAndConnect(); + + // Then + expect(frame.sentRpcRequests()).toContainEqual(Rpc.request(7)); + + // And When + dApp.send(Rpc.request(8, "chain_getHeader")); + await elapse(1); + expect(frame.sentRpcRequests()).toHaveLength(2); + + frame.chainMessage(frame.connectionId(), Rpc.response(7, "0xblock")); + await elapse(1); + expect(dApp.replies()).toEqual([Rpc.response(7, "0xblock")]); + }); + + it("As a dApp whose queued request cannot be delivered, I am answered with an error rather than left waiting", async () => { + // Given + const dApp = createTestDApp(); + dApp.send(Rpc.request(9)); + + // When + await frame.bootAndConnect(); + expect(frame.sentRpcRequests()).toHaveLength(1); + + // Then + await until(() => dApp.replies().length > 0, 30_000); + expect(dApp.lastReply()).toMatchObject(Rpc.error(9)); + }); + + it("refuses to create a provider for an unsupported genesis hash", () => { + const invalidGenesis = "0x0000000000000000000000000000000000000000000000000000000000000000"; + expect(isRemoteChainSupported(invalidGenesis)).toBe(false); + expect(createRemoteChainProvider(invalidGenesis)).toBeNull(); + }); + + it("handles disconnection cleanly and rejects subsequent sends on closed connection", async () => { + // Given + const dApp = createTestDApp(); + dApp.send(Rpc.request(1)); + await frame.bootAndConnect(); + + // When + dApp.connection.disconnect(); + await elapse(1); + + // Then: Disconnect request posted to frame + const disconnectRequest = frame.requests().find((r) => r.method === "chainDisconnect"); + expect(disconnectRequest).toBeDefined(); + frame.respond(disconnectRequest!.id, undefined); + await elapse(1); + + // And When: Double disconnect on already-disconnected connection + dApp.connection.disconnect(); + + // And When: Sending on closed connection + dApp.send(Rpc.request(15)); + expect(dApp.lastReply()).toMatchObject({ + jsonrpc: "2.0", + id: 15, + error: { + code: -32603, + message: "Chain connection is closed", + }, + }); + }); + + it("reports error when chainSend rejects on an active connection", async () => { + // Given + const dApp = createTestDApp(); + dApp.send(Rpc.request(1)); + await frame.bootAndConnect(); + + // When: Send request after connection established + dApp.send(Rpc.request(12, "chain_getBlock")); + await elapse(1); + + const sendRequest = frame + .requests() + .filter((r) => r.method === "chainSend") + .find((r) => { + const payload = r.payload; + if (payload && typeof payload === "object" && "message" in payload && typeof payload.message === "string") { + return payload.message.includes('"id":12'); + } + return false; + }); + expect(sendRequest).toBeDefined(); + + // And When: Host frame rejects the send + frame.respondError(sendRequest!.id, "Frame network buffer full"); + await elapse(1); + + // Then: dApp receives JSON-RPC error response + expect(dApp.lastReply()).toMatchObject({ + jsonrpc: "2.0", + id: 12, + error: { + code: -32603, + message: "Frame network buffer full", + }, + }); + }); + + it("cleans up connection when receiving chain-halt envelope", async () => { + // Given + const dApp = createTestDApp(); + dApp.send(Rpc.request(1)); + await frame.bootAndConnect(); + + // When: Frame halts the connection + frame.chainHalt(frame.connectionId()); + await elapse(1); + + // Then: Subsequent sends are rejected immediately + dApp.send(Rpc.request(22)); + expect(dApp.lastReply()).toMatchObject({ + jsonrpc: "2.0", + id: 22, + error: { + message: "Chain connection is closed", + }, + }); + }); + + it("ignores notification-style requests with no id on closed connections", async () => { + // Given + const dApp = createTestDApp(); + dApp.send(Rpc.request(1)); + await frame.bootAndConnect(); + dApp.connection.disconnect(); + await elapse(1); + + // When: Notification request sent (no id) + dApp.send({ jsonrpc: "2.0", method: "chainHead_v1_unpin", params: ["token"] }); + + // Then: Only the initial request's messages exist, no error reply emitted + expect(dApp.replies()).toHaveLength(0); + }); +}); diff --git a/packages/protocol/tests/client-precedence.test.ts b/packages/protocol/tests/client-precedence.test.ts new file mode 100644 index 00000000..23569b21 --- /dev/null +++ b/packages/protocol/tests/client-precedence.test.ts @@ -0,0 +1,146 @@ +// Copyright 2026 Parity Technologies (UK) Ltd. +// SPDX-License-Identifier: AGPL-3.0-only + +/** + * Precedence of error conditions over request timeout budgets. + * + * Verifies that host frame load failures, light client fatal crashes, and + * protocol frame teardown events immediately fail in-flight requests with + * their root-cause error rather than being falsely reported as timeout errors. + */ + +import { afterEach, beforeEach, describe, expect, it, vi } from "vitest"; +import { + resetProtocolFrame, + resolveDotNameRemote, + resolveExecutableManifestRemote, + resolveOwnerRemote, + resolveRootManifestRemote, +} from "@dotli/protocol/client"; +import { + ProtocolFatalError, + ProtocolRequestTimeoutError, +} from "@dotli/protocol/errors"; +import { + elapse, + installProtocolFrame, + settleWithin, + type ProtocolFrame, +} from "./support"; + +describe("Error precedence over request timeout budgets", () => { + let frame: ProtocolFrame; + + beforeEach(() => { + vi.useFakeTimers(); + frame = installProtocolFrame(); + }); + + afterEach(() => { + resetProtocolFrame(); + frame.restore(); + vi.useRealTimers(); + document.body.innerHTML = ""; + }); + + interface PrecedenceCase { + name: string; + makeRequest: () => Promise; + } + + const loadErrorCases: PrecedenceCase[] = [ + { + name: "resolveOwnerRemote", + makeRequest: () => resolveOwnerRemote("alice"), + }, + { + name: "resolveDotNameRemote", + makeRequest: () => resolveDotNameRemote("alice"), + }, + ]; + + it.each(loadErrorCases)( + "As someone making $name, I am told the shared frame failed to load rather than timing out", + async ({ makeRequest }) => { + // Given + const pending = makeRequest(); + + // When + await settleWithin(pending, 90_000); + + // Then + await expect(pending).rejects.toThrow( + "Shared host iframe timed out while loading", + ); + await expect(pending).rejects.not.toBeInstanceOf( + ProtocolRequestTimeoutError, + ); + }, + ); + + const resetCases: PrecedenceCase[] = [ + { + name: "resolveDotNameRemote", + makeRequest: () => resolveDotNameRemote("alice"), + }, + { + name: "resolveRootManifestRemote", + makeRequest: () => resolveRootManifestRemote("alice"), + }, + ]; + + it.each(resetCases)( + "As someone making $name, I am told the frame was torn down rather than timing out", + async ({ makeRequest }) => { + // Given + const pending = makeRequest(); + frame.open(); + await elapse(1); + + // When + resetProtocolFrame(); + + // Then + await settleWithin(pending, 1_000); + await expect(pending).rejects.toThrow( + "Protocol frame state reset before ready signal", + ); + await expect(pending).rejects.not.toBeInstanceOf( + ProtocolRequestTimeoutError, + ); + }, + ); + + const fatalCases: PrecedenceCase[] = [ + { + name: "resolveDotNameRemote", + makeRequest: () => resolveDotNameRemote("alice"), + }, + { + name: "resolveExecutableManifestRemote", + makeRequest: () => resolveExecutableManifestRemote("alice", "widget"), + }, + ]; + + it.each(fatalCases)( + "As someone whose $name encounters a light client crash, I am told it crashed rather than timing out", + async ({ makeRequest }) => { + // Given + const pending = makeRequest(); + frame.open(); + frame.ready(); + await elapse(10_000); + + // When + frame.fatal("smoldot panicked"); + + // Then + await settleWithin(pending, 1_000); + await expect(pending).rejects.toBeInstanceOf(ProtocolFatalError); + await expect(pending).rejects.toThrow("smoldot panicked"); + await expect(pending).rejects.not.toBeInstanceOf( + ProtocolRequestTimeoutError, + ); + }, + ); +}); diff --git a/packages/protocol/tests/client-timeouts.test.ts b/packages/protocol/tests/client-timeouts.test.ts new file mode 100644 index 00000000..781a1137 --- /dev/null +++ b/packages/protocol/tests/client-timeouts.test.ts @@ -0,0 +1,357 @@ +// Copyright 2026 Parity Technologies (UK) Ltd. +// SPDX-License-Identifier: AGPL-3.0-only + +/** + * Request budget and deadline enforcement for protocol client methods. + * + * Drives requests against a scripted protocol frame test double and asserts + * that callers wait no longer than their promised budget when the frame is slow + * or non-responsive, with accurate phase attribution ("load" | "ready" | "reply"). + */ + +import { afterEach, beforeEach, describe, expect, it, vi } from "vitest"; +import { SITE_ID } from "@dotli/config/config"; +import { SHARED_CORE_SESSION_KEY } from "@dotli/protocol/auth-storage"; +import { + clearSharedAuthStorage, + clearSharedModeStorage, + readSharedAuthStorage, + readSharedModeStorage, + resetProtocolFrame, + resolveDotNameRemote, + resolveExecutableManifestRemote, + resolveOwnerRemote, + resolveRootManifestRemote, + subscribeSharedAuthStorage, + warmupProtocol, + writeSharedAuthStorage, + writeSharedModeStorage, +} from "@dotli/protocol/client"; +import { + ProtocolRequestTimeoutError, + type ProtocolRequestTimeoutPhase, +} from "@dotli/protocol/errors"; +import { + elapse, + installProtocolFrame, + READY_SETTLE_CAP_MS, + settled, + settleWithin, + type ProtocolFrame, +} from "./support"; + +describe("Keeping a protocol request inside the time limit it promises", () => { + let frame: ProtocolFrame; + + beforeEach(() => { + vi.useFakeTimers(); + frame = installProtocolFrame(); + }); + + afterEach(() => { + resetProtocolFrame(); + frame.restore(); + vi.useRealTimers(); + document.body.innerHTML = ""; + }); + + interface SlowFrameCase { + request: string; + frame: string; + limitMs: number; + blamedWait: ProtocolRequestTimeoutPhase; + calledMethod: string; + makeRequest: () => Promise; + driveFrame: () => Promise; + remainingWaitMs: number; + } + + const slowFrameCases: SlowFrameCase[] = [ + { + request: "a saved session read", + frame: "never opens at all", + limitMs: 30_000, + blamedWait: "load", + calledMethod: "authStorageRead", + makeRequest: () => + readSharedAuthStorage(SITE_ID, SHARED_CORE_SESSION_KEY), + driveFrame: async () => {}, + remainingWaitMs: 30_000, + }, + { + request: "a saved mode read", + frame: "never opens at all", + limitMs: 30_000, + blamedWait: "load", + calledMethod: "modeStorageRead", + makeRequest: () => readSharedModeStorage(SITE_ID, "backend"), + driveFrame: async () => {}, + remainingWaitMs: 30_000, + }, + { + request: "a name lookup", + frame: "opens but never reports itself ready", + limitMs: 90_000, + blamedWait: "ready", + calledMethod: "resolveDotName", + makeRequest: () => resolveDotNameRemote("alice"), + driveFrame: async () => { + frame.open(); + }, + remainingWaitMs: 90_000, + }, + { + request: "an owner lookup", + frame: "opens but never reports itself ready", + limitMs: 90_000, + blamedWait: "ready", + calledMethod: "resolveOwner", + makeRequest: () => resolveOwnerRemote("alice"), + driveFrame: async () => { + frame.open(); + }, + remainingWaitMs: 90_000, + }, + { + request: "an executable manifest lookup", + frame: "opens but never reports itself ready", + limitMs: 30_000, + blamedWait: "ready", + calledMethod: "resolveExecutableManifest", + makeRequest: () => resolveExecutableManifestRemote("alice", "app"), + driveFrame: async () => { + frame.open(); + }, + remainingWaitMs: 30_000, + }, + { + request: "a root manifest lookup", + frame: "opens but never reports itself ready", + limitMs: 30_000, + blamedWait: "ready", + calledMethod: "resolveRootManifest", + makeRequest: () => resolveRootManifestRemote("alice"), + driveFrame: async () => { + frame.open(); + }, + remainingWaitMs: 30_000, + }, + { + request: "a saved session read", + frame: "takes twenty seconds to open and then never answers", + limitMs: 30_000, + blamedWait: "reply", + calledMethod: "authStorageRead", + makeRequest: () => + readSharedAuthStorage(SITE_ID, SHARED_CORE_SESSION_KEY), + driveFrame: async () => { + await elapse(20_000); + frame.open(); + }, + remainingWaitMs: 10_000, + }, + { + request: "a name lookup", + frame: "becomes ready at ten seconds and then never answers", + limitMs: 90_000, + blamedWait: "reply", + calledMethod: "resolveDotName", + makeRequest: () => resolveDotNameRemote("alice"), + driveFrame: async () => { + frame.open(); + await elapse(10_000); + frame.ready(); + }, + remainingWaitMs: 80_000, + }, + ]; + + it.each(slowFrameCases)( + "As someone making $request, I wait no longer than the limit I was promised when the shared frame $frame, and I am told which wait spent it", + async ({ + makeRequest, + driveFrame, + remainingWaitMs, + calledMethod, + limitMs, + blamedWait, + }) => { + // Given + const pending = makeRequest(); + await driveFrame(); + + // When + await settleWithin(pending, remainingWaitMs); + + // Then + await expect(pending).rejects.toMatchObject({ + name: "ProtocolRequestTimeoutError", + method: calledMethod, + timeoutMs: limitMs, + phase: blamedWait, + }); + }, + ); + + interface SuccessfulRoundtripCase { + name: string; + makeRequest: () => Promise; + expectedMethod: string; + mockResult: unknown; + expectedResult: unknown; + } + + const successfulRoundtrips: SuccessfulRoundtripCase[] = [ + { + name: "authStorageRead", + makeRequest: () => + readSharedAuthStorage(SITE_ID, SHARED_CORE_SESSION_KEY), + expectedMethod: "authStorageRead", + mockResult: "session-token-123", + expectedResult: "session-token-123", + }, + { + name: "authStorageWrite", + makeRequest: () => + writeSharedAuthStorage(SITE_ID, "UserSecrets", "secret-payload"), + expectedMethod: "authStorageWrite", + mockResult: undefined, + expectedResult: undefined, + }, + { + name: "authStorageClear", + makeRequest: () => clearSharedAuthStorage(SITE_ID, "UserSecrets"), + expectedMethod: "authStorageClear", + mockResult: undefined, + expectedResult: undefined, + }, + { + name: "modeStorageRead", + makeRequest: () => readSharedModeStorage(SITE_ID, "backend"), + expectedMethod: "modeStorageRead", + mockResult: "smoldot-shared-worker", + expectedResult: "smoldot-shared-worker", + }, + { + name: "modeStorageWrite", + makeRequest: () => + writeSharedModeStorage(SITE_ID, "backend", "rpc-gateway"), + expectedMethod: "modeStorageWrite", + mockResult: undefined, + expectedResult: undefined, + }, + { + name: "modeStorageClear", + makeRequest: () => clearSharedModeStorage(SITE_ID, "backend"), + expectedMethod: "modeStorageClear", + mockResult: undefined, + expectedResult: undefined, + }, + { + name: "resolveExecutableManifestRemote", + makeRequest: () => resolveExecutableManifestRemote("alice", "app"), + expectedMethod: "resolveExecutableManifest", + mockResult: { found: true, manifest: { name: "alice-app" } }, + expectedResult: { found: true, manifest: { name: "alice-app" } }, + }, + { + name: "resolveRootManifestRemote", + makeRequest: () => resolveRootManifestRemote("alice"), + expectedMethod: "resolveRootManifest", + mockResult: { found: true, manifest: { version: 1 } }, + expectedResult: { found: true, manifest: { version: 1 } }, + }, + ]; + + it.each(successfulRoundtrips)( + "As someone calling $name, I receive the result and the budget timer is disarmed", + async ({ makeRequest, expectedMethod, mockResult, expectedResult }) => { + // Given + const pending = makeRequest(); + await frame.boot(); + + // When + const request = frame + .requests() + .find((r) => r.method === expectedMethod); + expect(request).toBeDefined(); + frame.respond(request!.id, mockResult); + + // Then + await expect(pending).resolves.toEqual(expectedResult); + expect(vi.getTimerCount()).toBe(0); + }, + ); + + it("As someone warming the protocol up, I am never cut off, because warming up waits on chain sync", async () => { + // Given + const pending = warmupProtocol(); + frame.open(); + await elapse(1); + + // When + const isDone = settled(pending); + await elapse(30_000); + + // Then + expect(isDone()).toBe(false); + await settleWithin(pending, READY_SETTLE_CAP_MS); + await expect(pending).rejects.toThrow( + "Shared protocol iframe timed out (no ready signal)", + ); + await expect(pending).rejects.not.toBeInstanceOf( + ProtocolRequestTimeoutError, + ); + }); + + it("As someone whose reply never came, I stop hearing progress for that request once my time has run out", async () => { + // Given + const progress = vi.fn(); + const pending = resolveDotNameRemote("alice", progress); + frame.open(); + frame.ready(); + + // When + await settleWithin(pending, 90_000); + await expect(pending).rejects.toBeInstanceOf(ProtocolRequestTimeoutError); + + // Then + const request = frame.requests().at(-1); + expect(request).toBeDefined(); + progress.mockClear(); + frame.progress(request!.id, "still working"); + await elapse(1); + expect(progress).not.toHaveBeenCalled(); + }); + + it("relays cross-tab auth storage change notifications to subscribed listeners", async () => { + // Given + const changes: unknown[] = []; + const unsubscribe = subscribeSharedAuthStorage((change) => { + changes.push(change); + }); + frame.open(); + await elapse(1); + + // When: Frame emits auth-storage-changed + frame.authStorageChanged(SITE_ID, SHARED_CORE_SESSION_KEY, "updated-token"); + await elapse(1); + + // Then + expect(changes).toEqual([ + { + siteId: SITE_ID, + key: SHARED_CORE_SESSION_KEY, + value: "updated-token", + }, + ]); + + // And When: Unsubscribed + unsubscribe(); + frame.authStorageChanged(SITE_ID, SHARED_CORE_SESSION_KEY, "second-token"); + await elapse(1); + + // Then: No further changes received + expect(changes).toHaveLength(1); + }); +}); diff --git a/packages/protocol/tests/client.test.ts b/packages/protocol/tests/client.test.ts deleted file mode 100644 index a8e107e8..00000000 --- a/packages/protocol/tests/client.test.ts +++ /dev/null @@ -1,351 +0,0 @@ -// Copyright 2026 Parity Technologies (UK) Ltd. -// SPDX-License-Identifier: AGPL-3.0-only - -/** - * Behaviour of the time limit a protocol request promises its caller. - * - * The client owns module-level singleton state (the frame, the cached frame - * promises, the ready flag), so every scenario drives a stub element through - * `document.createElement` and tears the state down afterwards. A real - * happy-dom iframe would navigate to the protocol origin, fail that fetch, and - * dispatch its own error event before a scenario could drive it. - */ - -import { - afterEach, - beforeEach, - describe, - expect, - it, - vi, - type Mock, -} from "vitest"; -import { SITE_ID } from "@dotli/config/config"; -import { getActiveSupportedGenesisHashes } from "@dotli/config/network"; -import { SHARED_CORE_SESSION_KEY } from "@dotli/protocol/auth-storage"; -import { - createRemoteChainProvider, - getProtocolOrigin, - readSharedAuthStorage, - readSharedModeStorage, - resetProtocolFrame, - resolveDotNameRemote, - resolveOwnerRemote, - warmupProtocol, -} from "@dotli/protocol/client"; -import { ProtocolRequestTimeoutError } from "@dotli/protocol/errors"; - -/** The stub element the client last asked `document.createElement` for. */ -let frame: HTMLElement; -let framePostMessage: Mock; - -/** Deliver a protocol envelope as if the frame had posted it. */ -function dispatchFromFrame(data: unknown): void { - const holder = frame as unknown as { contentWindow: unknown }; - window.dispatchEvent( - new MessageEvent("message", { - data, - origin: getProtocolOrigin(), - // The client only accepts envelopes whose source is the frame's own - // window object, so the stub window must be passed through by identity. - source: holder.contentWindow as Window, - }), - ); -} - -/** - * Report whether a promise has settled, without adopting its result. - * - * The handler attached here keeps a deliberately abandoned request from - * surfacing as an unhandled rejection when the teardown rejects it. - */ -function settleTracker(promise: Promise): () => boolean { - let settled = false; - promise.then( - () => { - settled = true; - }, - () => { - settled = true; - }, - ); - return () => settled; -} - -/** Drain the microtask queue so the client's awaits advance under fake timers. */ -async function flush(): Promise { - for (let i = 0; i < 5; i += 1) { - await Promise.resolve(); - } -} - -beforeEach(() => { - vi.useFakeTimers(); - framePostMessage = vi.fn(); - const realCreateElement = document.createElement.bind(document); - vi.spyOn(document, "createElement").mockImplementation((tagName: string) => { - if (tagName !== "iframe") { - return realCreateElement(tagName); - } - // A real happy-dom iframe navigates to the protocol origin on append and - // dispatches its own error event when that fetch fails. A div carries - // every member the frame builder touches and never hits the network. - const element = realCreateElement("div"); - Object.defineProperty(element, "contentWindow", { - configurable: true, - value: { postMessage: framePostMessage }, - }); - frame = element; - return element; - }); -}); - -afterEach(() => { - resetProtocolFrame(); - vi.clearAllTimers(); - vi.useRealTimers(); - vi.restoreAllMocks(); - document.body.innerHTML = ""; -}); - -describe("Keeping a protocol request inside the time limit it promises", () => { - const slowFrameCases = [ - { - request: "a name lookup", - frame: "opens but never reports itself ready", - limitMs: 90_000, - opensAfterMs: 0, - blamedWait: "ready", - calledMethod: "resolveDotName", - call: () => resolveDotNameRemote("alice"), - }, - { - request: "a saved session read", - frame: "takes twenty seconds to open and then never answers", - limitMs: 30_000, - opensAfterMs: 20_000, - blamedWait: "reply", - calledMethod: "authStorageRead", - call: () => readSharedAuthStorage(SITE_ID, SHARED_CORE_SESSION_KEY), - }, - { - request: "a saved session read", - frame: "never opens at all", - limitMs: 30_000, - opensAfterMs: null, - blamedWait: "load", - calledMethod: "authStorageRead", - call: () => readSharedAuthStorage(SITE_ID, SHARED_CORE_SESSION_KEY), - }, - ]; - - it.each(slowFrameCases)( - "As someone making $request, I wait no longer than the limit I was promised when the shared frame $frame, and I am told which wait spent it", - async ({ limitMs, opensAfterMs, blamedWait, calledMethod, call }) => { - // Given a shared frame that is slow in the way this example describes - const pending = call(); - const settled = settleTracker(pending); - await flush(); - if (opensAfterMs !== null) { - await vi.advanceTimersByTimeAsync(opensAfterMs); - frame.dispatchEvent(new Event("load")); - await flush(); - } - - // When the promised limit has all but elapsed - const alreadyElapsed = opensAfterMs ?? 0; - await vi.advanceTimersByTimeAsync(limitMs - alreadyElapsed - 1); - expect(settled()).toBe(false); - - // Then the last millisecond of the limit ends the wait, naming the - // wait that consumed it - await vi.advanceTimersByTimeAsync(1); - await expect(pending).rejects.toBeInstanceOf(ProtocolRequestTimeoutError); - await expect(pending).rejects.toMatchObject({ - method: calledMethod, - timeoutMs: limitMs, - phase: blamedWait, - }); - }, - ); - - it("As someone making an owner lookup, I am told the shared frame failed to open rather than being told my own time ran out", async () => { - // Given an owner lookup, which is promised more time than opening the - // shared frame is allowed to take - const pending = resolveOwnerRemote("alice"); - const settled = settleTracker(pending); - await flush(); - - // When the frame never opens and its own allowance runs out - await vi.advanceTimersByTimeAsync(30_000); - - // Then the more specific failure is the one reported - expect(settled()).toBe(true); - await expect(pending).rejects.toThrow( - "Shared host iframe timed out while loading", - ); - await expect(pending).rejects.not.toBeInstanceOf( - ProtocolRequestTimeoutError, - ); - }); - - it("As someone making a name lookup, I am told the shared frame was torn down rather than being told my own time ran out", async () => { - // Given a name lookup waiting on a frame that has opened but is not ready - const pending = resolveDotNameRemote("alice"); - const settleTrackerFor = settleTracker(pending); - await flush(); - frame.dispatchEvent(new Event("load")); - await flush(); - - // When the frame is torn down long before the promised limit - await vi.advanceTimersByTimeAsync(10_000); - resetProtocolFrame(); - await flush(); - - // Then the teardown is the reported reason - expect(settleTrackerFor()).toBe(true); - await expect(pending).rejects.toThrow( - "Protocol frame state reset before ready signal", - ); - await expect(pending).rejects.not.toBeInstanceOf( - ProtocolRequestTimeoutError, - ); - }); - - it("As someone warming the protocol up, I am never cut off, because warming up waits on chain sync", async () => { - // Given a warm-up against a frame that has opened but is not ready - const pending = warmupProtocol(); - const settled = settleTracker(pending); - await flush(); - frame.dispatchEvent(new Event("load")); - await flush(); - - // When the whole allowance for becoming ready goes by, one millisecond - // short of its end - await vi.advanceTimersByTimeAsync(239_999); - - // Then the warm-up is still waiting - expect(settled()).toBe(false); - - // And when that allowance runs out, becoming ready is the reported - // reason, never a limit of the warm-up's own - await vi.advanceTimersByTimeAsync(1); - await expect(pending).rejects.toThrow( - "Shared protocol iframe timed out (no ready signal)", - ); - await expect(pending).rejects.not.toBeInstanceOf( - ProtocolRequestTimeoutError, - ); - }); - - it("As someone whose light client crashes mid-request, I am told it crashed rather than being told my own time ran out", async () => { - // Given a name lookup that has reached a ready frame - const pending = resolveDotNameRemote("alice"); - const settled = settleTracker(pending); - await flush(); - frame.dispatchEvent(new Event("load")); - await flush(); - dispatchFromFrame({ namespace: "dotli:protocol", kind: "ready" }); - await flush(); - - // When the light client crashes well inside the promised limit - await vi.advanceTimersByTimeAsync(10_000); - dispatchFromFrame({ - namespace: "dotli:protocol", - kind: "fatal", - message: "smoldot panicked", - }); - await flush(); - - // Then the crash is the reported reason - expect(settled()).toBe(true); - await expect(pending).rejects.toThrow("smoldot panicked"); - await expect(pending).rejects.not.toBeInstanceOf( - ProtocolRequestTimeoutError, - ); - }); - - it("As someone whose reply never came, I stop hearing progress for that request once my time has run out", async () => { - // Given a name lookup on a ready frame, reporting progress as it goes - const progress = vi.fn(); - const pending = resolveDotNameRemote("alice", progress); - const settled = settleTracker(pending); - await flush(); - frame.dispatchEvent(new Event("load")); - await flush(); - dispatchFromFrame({ namespace: "dotli:protocol", kind: "ready" }); - await flush(); - const request = framePostMessage.mock.calls.at(-1)?.[0] as { id: string }; - - // When my time runs out and the frame reports progress afterwards - await vi.advanceTimersByTimeAsync(90_000); - expect(settled()).toBe(true); - await expect(pending).rejects.toBeInstanceOf(ProtocolRequestTimeoutError); - progress.mockClear(); - dispatchFromFrame({ - namespace: "dotli:protocol", - kind: "progress", - id: request.id, - message: "still working", - }); - await flush(); - - // Then that progress reaches nobody - expect(progress).not.toHaveBeenCalled(); - }); - - it("As someone reading a saved preference from a healthy frame, I get my answer and nothing is left ticking", async () => { - // Given a healthy shared frame - const pending = readSharedModeStorage(SITE_ID, "backend"); - await flush(); - frame.dispatchEvent(new Event("load")); - await flush(); - - // When the frame answers - const request = framePostMessage.mock.calls[0]?.[0] as { id: string }; - dispatchFromFrame({ - namespace: "dotli:protocol", - kind: "response", - id: request.id, - ok: true, - result: "smoldot-shared-worker", - }); - await expect(pending).resolves.toBe("smoldot-shared-worker"); - - // Then no limit of mine is still counting down, and letting the clock run - // past where it would have expired changes nothing - expect(vi.getTimerCount()).toBe(0); - await vi.advanceTimersByTimeAsync(60_000); - await expect(pending).resolves.toBe("smoldot-shared-worker"); - }); - - it("As a dApp opening a chain connection while the frame is still starting up, I am told the connection failed inside the time a connection is promised", async () => { - // Given a chain the active backend serves, and a frame that opens but - // never reports itself ready - const [genesisHash] = [...getActiveSupportedGenesisHashes()]; - expect(genesisHash).toBeDefined(); - const replies: unknown[] = []; - const connect = createRemoteChainProvider(genesisHash as string); - const connection = connect?.((message) => { - replies.push(message); - }); - await flush(); - frame.dispatchEvent(new Event("load")); - await flush(); - - // When I ask for a block and the connection's own allowance runs out - connection?.send({ jsonrpc: "2.0", id: 7, method: "chain_getBlock" }); - await vi.advanceTimersByTimeAsync(30_000); - await flush(); - - // Then I have my error, long before the frame gives up on becoming ready - expect(replies).toEqual([ - { - jsonrpc: "2.0", - id: 7, - error: { code: -32603, message: expect.stringContaining("timed out") }, - }, - ]); - }); - -}); diff --git a/packages/protocol/tests/errors.test.ts b/packages/protocol/tests/errors.test.ts new file mode 100644 index 00000000..8dac26aa --- /dev/null +++ b/packages/protocol/tests/errors.test.ts @@ -0,0 +1,60 @@ +// Copyright 2026 Parity Technologies (UK) Ltd. +// SPDX-License-Identifier: AGPL-3.0-only + +import { describe, expect, it } from "vitest"; +import { + ProtocolFatalError, + ProtocolInitFailedError, + ProtocolRequestTimeoutError, +} from "@dotli/protocol/errors"; + +describe("protocol error types", () => { + it("constructs ProtocolFatalError with message and name", () => { + const error = new ProtocolFatalError("smoldot panicked"); + expect(error.name).toBe("ProtocolFatalError"); + expect(error.message).toBe("smoldot panicked"); + expect(error).toBeInstanceOf(Error); + }); + + it("constructs ProtocolInitFailedError with message and name", () => { + const error = new ProtocolInitFailedError("failed to init"); + expect(error.name).toBe("ProtocolInitFailedError"); + expect(error.message).toBe("failed to init"); + expect(error).toBeInstanceOf(Error); + }); + + it.each([ + { + method: "resolveDotName" as const, + timeoutMs: 90_000, + phase: "ready" as const, + expectedMsg: + 'Protocol request "resolveDotName" timed out after 90000ms while waiting for the protocol frame to become ready', + }, + { + method: "authStorageRead" as const, + timeoutMs: 30_000, + phase: "load" as const, + expectedMsg: + 'Protocol request "authStorageRead" timed out after 30000ms while waiting for the host frame to load', + }, + { + method: "chainConnect" as const, + timeoutMs: 30_000, + phase: "reply" as const, + expectedMsg: + 'Protocol request "chainConnect" timed out after 30000ms while waiting for a reply', + }, + ])( + "constructs ProtocolRequestTimeoutError for $method in $phase phase", + ({ method, timeoutMs, phase, expectedMsg }) => { + const error = new ProtocolRequestTimeoutError(method, timeoutMs, phase); + expect(error.name).toBe("ProtocolRequestTimeoutError"); + expect(error.method).toBe(method); + expect(error.timeoutMs).toBe(timeoutMs); + expect(error.phase).toBe(phase); + expect(error.message).toBe(expectedMsg); + expect(error).toBeInstanceOf(Error); + }, + ); +}); diff --git a/packages/protocol/tests/support/dapp.ts b/packages/protocol/tests/support/dapp.ts new file mode 100644 index 00000000..9bd274f9 --- /dev/null +++ b/packages/protocol/tests/support/dapp.ts @@ -0,0 +1,57 @@ +// Copyright 2026 Parity Technologies (UK) Ltd. +// SPDX-License-Identifier: AGPL-3.0-only + +import { getActiveSupportedGenesisHashes } from "@dotli/config/network"; +import { createRemoteChainProvider } from "@dotli/protocol/client"; +import type { + JsonRpcConnection, + JsonRpcMessage, + JsonRpcRequest, +} from "@polkadot-api/json-rpc-provider"; + +/** + * Driver representing the sandboxed DApp consumer making chain requests. + */ +export interface DAppDriver { + /** The low-level JSON-RPC connection instance. */ + readonly connection: JsonRpcConnection; + /** Send a JSON-RPC request to the chain. */ + send(request: JsonRpcRequest): void; + /** All JSON-RPC replies received by the dApp so far. */ + replies(): JsonRpcMessage[]; + /** The most recent reply received by the dApp. */ + lastReply(): JsonRpcMessage | undefined; +} + +/** + * Instantiate a test dApp driver connected to the active chain provider. + */ +export function createTestDApp(): DAppDriver { + const supportedHashes = [...getActiveSupportedGenesisHashes()]; + const genesisHash = supportedHashes[0]; + if (!genesisHash) { + throw new Error("no active supported genesis hash in test config"); + } + const provider = createRemoteChainProvider(genesisHash); + if (!provider) { + throw new Error("provider refused configured genesis hash"); + } + + const receivedReplies: JsonRpcMessage[] = []; + const connection = provider((message) => { + receivedReplies.push(message); + }); + + return { + connection, + send(request: JsonRpcRequest): void { + connection.send(request); + }, + replies(): JsonRpcMessage[] { + return [...receivedReplies]; + }, + lastReply(): JsonRpcMessage | undefined { + return receivedReplies.at(-1); + }, + }; +} diff --git a/packages/protocol/tests/support/frame.ts b/packages/protocol/tests/support/frame.ts new file mode 100644 index 00000000..c1a8862d --- /dev/null +++ b/packages/protocol/tests/support/frame.ts @@ -0,0 +1,220 @@ +// Copyright 2026 Parity Technologies (UK) Ltd. +// SPDX-License-Identifier: AGPL-3.0-only + +import { vi } from "vitest"; +import { getProtocolOrigin } from "@dotli/protocol/client"; +import type { SiteId } from "@dotli/config/config"; +import type { JsonRpcRequest } from "@polkadot-api/json-rpc-provider"; +import type { + ProtocolEnvelope, + ProtocolRequestEnvelope, +} from "@dotli/protocol/messages"; +import { elapse } from "./time"; + +/** + * Driver representing the host protocol frame peer. + */ +export interface ProtocolFrame { + /** Dispatch `load` on the stub iframe element. */ + open(): void; + /** Deliver an unsolicited ready envelope. */ + ready(): void; + /** Complete full startup handshake (open + ready). */ + boot(): Promise; + /** Complete startup and accept pending chain connection. */ + bootAndConnect(): Promise; + /** Deliver a success response for a request id. */ + respond(id: string, result: unknown): void; + /** Deliver an error response for a request id. */ + respondError(id: string, error: string): void; + /** Deliver a progress notification for an in-flight request. */ + progress(id: string, message: string): void; + /** Deliver a fatal/panic broadcast that rejects every in-flight request. */ + fatal(message: string): void; + /** Deliver a chain reply for an open connection. */ + chainMessage(connectionId: string, message: unknown): void; + /** Deliver a chain halt envelope for an open connection. */ + chainHalt(connectionId: string): void; + /** Deliver an auth-storage-changed broadcast envelope. */ + authStorageChanged(siteId: SiteId, key: string, value: string): void; + /** Decoded request envelopes posted to this frame. */ + requests(): ProtocolRequestEnvelope[]; + /** The connectionId from the initial chainConnect handshake envelope. */ + connectionId(): string; + /** Parsed JSON-RPC requests flushed across the chainSend wire. */ + sentRpcRequests(): JsonRpcRequest[]; + /** Restore mocks and remove the stub element from the DOM. */ + restore(): void; +} + +/** + * Install a scripted protocol frame peer. + * + * A real happy-dom iframe navigates on append and self-dispatches its own + * error event when that fetch fails. The stub div carries every member the + * client's frame builder touches and receives envelopes via `postMessage`. + */ +export function installProtocolFrame(): ProtocolFrame { + const posted: ProtocolEnvelope[] = []; + let stubElement: HTMLElement | null = null; + + const realCreateElement = document.createElement.bind(document); + const spy = vi + .spyOn(document, "createElement") + .mockImplementation((tagName: string) => { + if (tagName !== "iframe") { + return realCreateElement(tagName); + } + const element = realCreateElement("div"); + Object.defineProperty(element, "contentWindow", { + configurable: true, + value: { + postMessage: (envelope: ProtocolEnvelope) => { + posted.push(envelope); + }, + }, + }); + stubElement = element; + return element; + }); + + function dispatch(data: ProtocolEnvelope): void { + const rawHolder: unknown = stubElement; + if ( + rawHolder && + typeof rawHolder === "object" && + "contentWindow" in rawHolder + ) { + const windowRef = rawHolder.contentWindow as Window | undefined; + window.dispatchEvent( + new MessageEvent("message", { + data, + origin: getProtocolOrigin(), + source: windowRef, + }), + ); + } + } + + const frame: ProtocolFrame = { + open(): void { + stubElement?.dispatchEvent(new Event("load")); + }, + ready(): void { + dispatch({ namespace: "dotli:protocol", kind: "ready" }); + }, + async boot(): Promise { + frame.open(); + await elapse(1); + frame.ready(); + await elapse(1); + }, + async bootAndConnect(): Promise { + await frame.boot(); + const connect = frame.requests().find((r) => r.method === "chainConnect"); + if (connect) { + frame.respond(connect.id, undefined); + await elapse(1); + } + }, + respond(id: string, result: unknown): void { + dispatch({ + namespace: "dotli:protocol", + kind: "response", + id, + ok: true, + result, + }); + }, + respondError(id: string, error: string): void { + dispatch({ + namespace: "dotli:protocol", + kind: "response", + id, + ok: false, + error, + }); + }, + progress(id: string, message: string): void { + dispatch({ + namespace: "dotli:protocol", + kind: "progress", + id, + message, + }); + }, + fatal(message: string): void { + dispatch({ + namespace: "dotli:protocol", + kind: "fatal", + message, + }); + }, + chainMessage(connectionId: string, message: unknown): void { + dispatch({ + namespace: "dotli:protocol", + kind: "chain-message", + connectionId, + message: JSON.stringify(message), + }); + }, + chainHalt(connectionId: string): void { + dispatch({ + namespace: "dotli:protocol", + kind: "chain-halt", + connectionId, + }); + }, + authStorageChanged(siteId: SiteId, key: string, value: string): void { + dispatch({ + namespace: "dotli:protocol", + kind: "auth-storage-changed", + siteId, + key, + value, + }); + }, + requests(): ProtocolRequestEnvelope[] { + return posted.filter( + (e): e is ProtocolRequestEnvelope => e.kind === "request", + ); + }, + connectionId(): string { + const connect = frame.requests().find((r) => r.method === "chainConnect"); + if ( + connect && + typeof connect.payload === "object" && + connect.payload !== null && + "connectionId" in connect.payload && + typeof connect.payload.connectionId === "string" + ) { + return connect.payload.connectionId; + } + throw new Error("No chainConnect request has been received by the frame"); + }, + sentRpcRequests(): JsonRpcRequest[] { + const sends = frame.requests().filter((r) => r.method === "chainSend"); + const parsedRequests: JsonRpcRequest[] = []; + for (const envelope of sends) { + const payload = envelope.payload; + if ( + payload && + typeof payload === "object" && + "message" in payload && + typeof payload.message === "string" + ) { + const parsed = JSON.parse(payload.message) as JsonRpcRequest; + parsedRequests.push(parsed); + } + } + return parsedRequests; + }, + restore(): void { + spy.mockRestore(); + stubElement?.remove(); + stubElement = null; + }, + }; + + return frame; +} diff --git a/packages/protocol/tests/support/index.ts b/packages/protocol/tests/support/index.ts new file mode 100644 index 00000000..a0f72d4b --- /dev/null +++ b/packages/protocol/tests/support/index.ts @@ -0,0 +1,20 @@ +// Copyright 2026 Parity Technologies (UK) Ltd. +// SPDX-License-Identifier: AGPL-3.0-only + +export * as RpcSupport from "./rpc"; +export * as TimeSupport from "./time"; +export * as DAppSupport from "./dapp"; +export * as FrameSupport from "./frame"; + +// Convenience domain names for idiomatic import styles: +export { Rpc } from "./rpc"; +export { + ticker, + elapse, + settled, + settleWithin, + until, + READY_SETTLE_CAP_MS, +} from "./time"; +export { createTestDApp, type DAppDriver } from "./dapp"; +export { installProtocolFrame, type ProtocolFrame } from "./frame"; diff --git a/packages/protocol/tests/support/rpc.ts b/packages/protocol/tests/support/rpc.ts new file mode 100644 index 00000000..3bf98552 --- /dev/null +++ b/packages/protocol/tests/support/rpc.ts @@ -0,0 +1,37 @@ +// Copyright 2026 Parity Technologies (UK) Ltd. +// SPDX-License-Identifier: AGPL-3.0-only + +import type { + JsonRpcRequest, + JsonRpcResponse, +} from "@polkadot-api/json-rpc-provider"; + +/** + * Factory for JSON-RPC messages used in protocol provider tests. + */ +export const Rpc = { + request: ( + id: number, + method = "chain_getBlock", + params: unknown[] = [], + ): JsonRpcRequest => ({ + jsonrpc: "2.0", + id, + method, + params, + }), + response: (id: number, result: T): JsonRpcResponse => ({ + jsonrpc: "2.0", + id, + result, + }), + error: ( + id: number, + code = -32603, + message?: string | RegExp, + ): Record => ({ + jsonrpc: "2.0", + id, + error: message !== undefined ? { code, message } : { code }, + }), +}; diff --git a/packages/protocol/tests/support/time.ts b/packages/protocol/tests/support/time.ts new file mode 100644 index 00000000..3ecc114d --- /dev/null +++ b/packages/protocol/tests/support/time.ts @@ -0,0 +1,82 @@ +// Copyright 2026 Parity Technologies (UK) Ltd. +// SPDX-License-Identifier: AGPL-3.0-only + +import { vi } from "vitest"; + +/** + * Upper bound for scenarios that assert a warm-up waits the full ready + * allowance rather than cutting off at a per-request budget. Mirrors + * `IFRAME_READY_TIMEOUT_MS = 240_000` (client.ts:326) plus a small margin. + * The failure mode on drift is a test timeout, not silent passing. + */ +export const READY_SETTLE_CAP_MS = 250_000; + +/** + * Streams fake time advancement in discrete steps up to `maxMs`. + * Yields current elapsed milliseconds. Throws if the loop runs past `maxMs`. + */ +export async function* ticker( + maxMs: number, + step = 10, +): AsyncGenerator { + for (let elapsed = 0; elapsed <= maxMs; elapsed += step) { + yield elapsed; + await vi.advanceTimersByTimeAsync(step); + } + throw new Error(`exceeded deadline of ${maxMs}ms`); +} + +/** + * Advance fake timers and drain the microtask turns that timers yield. + */ +export async function elapse(ms: number): Promise { + await vi.advanceTimersByTimeAsync(ms); +} + +/** + * Attach rejection-absorbing handlers to a promise and return a flag reader. + * Keeps abandoned or late-rejecting requests from leaking unhandled rejections. + */ +export function settled(promise: Promise): () => boolean { + let done = false; + promise.then( + () => { + done = true; + }, + () => { + done = true; + }, + ); + return () => done; +} + +/** + * Advance fake time until the promise settles, or throw if it remains + * pending past `maxMs`. + */ +export async function settleWithin( + promise: Promise, + maxMs: number, +): Promise { + const isDone = settled(promise); + for await (const _ of ticker(maxMs)) { + if (isDone()) { + return; + } + } +} + +/** + * Advance fake time until `condition()` returns true, or throw if the + * deadline elapses. + */ +export async function until( + condition: () => boolean, + maxMs: number, +): Promise { + for await (const _ of ticker(maxMs)) { + if (condition()) { + return; + } + } +} From ecaab14dfcb7a5b272220004d7022ccf21eb32e5 Mon Sep 17 00:00:00 2001 From: Ryan Lee Date: Fri, 14 Aug 2026 18:29:31 -0400 Subject: [PATCH 08/18] chore: format --- packages/protocol/AGENTS.md | 10 ++-- packages/protocol/src/client.ts | 11 ++++- packages/protocol/tests/auth-storage.test.ts | 48 +++++++++++++++---- .../tests/client-chain-provider.test.ts | 20 ++++++-- .../protocol/tests/client-timeouts.test.ts | 4 +- 5 files changed, 71 insertions(+), 22 deletions(-) diff --git a/packages/protocol/AGENTS.md b/packages/protocol/AGENTS.md index 1fc884cd..f311d4ef 100644 --- a/packages/protocol/AGENTS.md +++ b/packages/protocol/AGENTS.md @@ -4,8 +4,8 @@ Governs `packages/protocol` postMessage bridge, shared storage, and client-side ## Package Invariants -| id | rule | gate | -|---|---|---| -| PROTO-T1 | Protocol tests use the dual-driver harness (`createTestDApp` / `installProtocolFrame`) from `tests/support/`; never mock `window.postMessage` or DOM elements inline in test files. | `! grep -E "addEventListener\(\"message\"|contentWindow" packages/protocol/tests/*.test.ts` | -| PROTO-T2 | Test scenarios assert on parsed domain getters (`frame.sentRpcRequests()`, `frame.connectionId()`, `dApp.replies()`); never parse raw `chainSend` message strings inside scenario bodies. | `! grep -E "JSON\.parse\(" packages/protocol/tests/*.test.ts` | -| PROTO-T3 | Asynchronous scenario synchronization must use virtual timer primitives (`settleWithin`, `until`, `bootAndConnect`); never chain ad-hoc tick yields (`await elapse(1)`). | Review of async wait patterns in `packages/protocol/tests/*.test.ts` | +| id | rule | gate | +| -------- | ----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- | -------------------------------------------------------------------- | -------------------------------------------------- | +| PROTO-T1 | Protocol tests use the dual-driver harness (`createTestDApp` / `installProtocolFrame`) from `tests/support/`; never mock `window.postMessage` or DOM elements inline in test files. | `! grep -E "addEventListener\(\"message\" | contentWindow" packages/protocol/tests/\*.test.ts` | +| PROTO-T2 | Test scenarios assert on parsed domain getters (`frame.sentRpcRequests()`, `frame.connectionId()`, `dApp.replies()`); never parse raw `chainSend` message strings inside scenario bodies. | `! grep -E "JSON\.parse\(" packages/protocol/tests/*.test.ts` | +| PROTO-T3 | Asynchronous scenario synchronization must use virtual timer primitives (`settleWithin`, `until`, `bootAndConnect`); never chain ad-hoc tick yields (`await elapse(1)`). | Review of async wait patterns in `packages/protocol/tests/*.test.ts` | diff --git a/packages/protocol/src/client.ts b/packages/protocol/src/client.ts index 9c35b18f..27dfa2b0 100644 --- a/packages/protocol/src/client.ts +++ b/packages/protocol/src/client.ts @@ -500,7 +500,10 @@ const METHOD_TIMEOUTS: Partial> = { }; interface RequestBudget { - guard: (phase: ProtocolRequestTimeoutPhase, work: Promise) => Promise; + guard: ( + phase: ProtocolRequestTimeoutPhase, + work: Promise, + ) => Promise; release: () => void; } @@ -519,7 +522,11 @@ function startRequestBudget( let timer: ReturnType | undefined; const expiry = new Promise((_resolve, reject) => { timer = setTimeout(() => { - m.count(S.PROTOCOL_REQUEST, { outcome: "timeout", method, phase: spentOn }); + m.count(S.PROTOCOL_REQUEST, { + outcome: "timeout", + method, + phase: spentOn, + }); reject(new ProtocolRequestTimeoutError(method, timeoutMs, spentOn)); }, timeoutMs); }); diff --git a/packages/protocol/tests/auth-storage.test.ts b/packages/protocol/tests/auth-storage.test.ts index 8ff727e4..98398b6f 100644 --- a/packages/protocol/tests/auth-storage.test.ts +++ b/packages/protocol/tests/auth-storage.test.ts @@ -25,16 +25,48 @@ describe("shared auth and mode storage helpers", () => { const originCases: OriginCase[] = [ { origin: "https://dot.li", allowed: true, reason: "root host shell" }, - { origin: "https://browse.dot.li", allowed: true, reason: "browse subdomain" }, - { origin: "https://host-playground.dot.li", allowed: true, reason: "playground subdomain" }, + { + origin: "https://browse.dot.li", + allowed: true, + reason: "browse subdomain", + }, + { + origin: "https://host-playground.dot.li", + allowed: true, + reason: "playground subdomain", + }, { origin: "https://host.dot.li", allowed: true, reason: "host subdomain" }, - { origin: "https://bafy.app.dot.li", allowed: false, reason: "app subdomain" }, + { + origin: "https://bafy.app.dot.li", + allowed: false, + reason: "app subdomain", + }, { origin: "https://app.dot.li", allowed: false, reason: "app root" }, - { origin: "https://evil.example.com", allowed: false, reason: "foreign domain" }, - { origin: "http://localhost:5173", allowed: true, reason: "localhost port" }, - { origin: "http://browse.localhost:5173", allowed: true, reason: "browse localhost" }, - { origin: "http://host.localhost:5173", allowed: true, reason: "host localhost" }, - { origin: "http://bafy.app.localhost:5173", allowed: false, reason: "app localhost" }, + { + origin: "https://evil.example.com", + allowed: false, + reason: "foreign domain", + }, + { + origin: "http://localhost:5173", + allowed: true, + reason: "localhost port", + }, + { + origin: "http://browse.localhost:5173", + allowed: true, + reason: "browse localhost", + }, + { + origin: "http://host.localhost:5173", + allowed: true, + reason: "host localhost", + }, + { + origin: "http://bafy.app.localhost:5173", + allowed: false, + reason: "app localhost", + }, { origin: "http://dot.li", allowed: false, reason: "insecure http remote" }, { origin: "not a url", allowed: false, reason: "malformed url string" }, ]; diff --git a/packages/protocol/tests/client-chain-provider.test.ts b/packages/protocol/tests/client-chain-provider.test.ts index 5eb9acfd..94fa1d91 100644 --- a/packages/protocol/tests/client-chain-provider.test.ts +++ b/packages/protocol/tests/client-chain-provider.test.ts @@ -90,7 +90,8 @@ describe("Remote chain provider lifecycle and request routing", () => { }); it("refuses to create a provider for an unsupported genesis hash", () => { - const invalidGenesis = "0x0000000000000000000000000000000000000000000000000000000000000000"; + const invalidGenesis = + "0x0000000000000000000000000000000000000000000000000000000000000000"; expect(isRemoteChainSupported(invalidGenesis)).toBe(false); expect(createRemoteChainProvider(invalidGenesis)).toBeNull(); }); @@ -106,7 +107,9 @@ describe("Remote chain provider lifecycle and request routing", () => { await elapse(1); // Then: Disconnect request posted to frame - const disconnectRequest = frame.requests().find((r) => r.method === "chainDisconnect"); + const disconnectRequest = frame + .requests() + .find((r) => r.method === "chainDisconnect"); expect(disconnectRequest).toBeDefined(); frame.respond(disconnectRequest!.id, undefined); await elapse(1); @@ -141,7 +144,12 @@ describe("Remote chain provider lifecycle and request routing", () => { .filter((r) => r.method === "chainSend") .find((r) => { const payload = r.payload; - if (payload && typeof payload === "object" && "message" in payload && typeof payload.message === "string") { + if ( + payload && + typeof payload === "object" && + "message" in payload && + typeof payload.message === "string" + ) { return payload.message.includes('"id":12'); } return false; @@ -193,7 +201,11 @@ describe("Remote chain provider lifecycle and request routing", () => { await elapse(1); // When: Notification request sent (no id) - dApp.send({ jsonrpc: "2.0", method: "chainHead_v1_unpin", params: ["token"] }); + dApp.send({ + jsonrpc: "2.0", + method: "chainHead_v1_unpin", + params: ["token"], + }); // Then: Only the initial request's messages exist, no error reply emitted expect(dApp.replies()).toHaveLength(0); diff --git a/packages/protocol/tests/client-timeouts.test.ts b/packages/protocol/tests/client-timeouts.test.ts index 781a1137..35956b6a 100644 --- a/packages/protocol/tests/client-timeouts.test.ts +++ b/packages/protocol/tests/client-timeouts.test.ts @@ -271,9 +271,7 @@ describe("Keeping a protocol request inside the time limit it promises", () => { await frame.boot(); // When - const request = frame - .requests() - .find((r) => r.method === expectedMethod); + const request = frame.requests().find((r) => r.method === expectedMethod); expect(request).toBeDefined(); frame.respond(request!.id, mockResult); From 950534e002ac08fb1d55fd32d0aba738e8567a46 Mon Sep 17 00:00:00 2001 From: Ryan Lee Date: Fri, 14 Aug 2026 22:33:55 +0000 Subject: [PATCH 09/18] docs(solutions): refresh call-time budget learning with dual-driver architecture --- ...uest-timeout-starts-after-frame-ready-wait.md | 16 ++++++++++------ 1 file changed, 10 insertions(+), 6 deletions(-) diff --git a/docs/solutions/logic-errors/protocol-request-timeout-starts-after-frame-ready-wait.md b/docs/solutions/logic-errors/protocol-request-timeout-starts-after-frame-ready-wait.md index 70bc0b78..9d8cd1d0 100644 --- a/docs/solutions/logic-errors/protocol-request-timeout-starts-after-frame-ready-wait.md +++ b/docs/solutions/logic-errors/protocol-request-timeout-starts-after-frame-ready-wait.md @@ -1,6 +1,7 @@ --- title: Protocol request timeout started after the frame-ready wait, not at the call date: 2026-08-14 +last_updated: 2026-08-14 category: logic-errors module: packages/protocol problem_type: logic_error @@ -23,6 +24,7 @@ tags: - metrics - mutation-testing - error-handling + - dual-driver-dsl --- # Protocol request timeout started after the frame-ready wait, not at the call @@ -112,11 +114,12 @@ try { } ``` -Three further pieces: +Four further pieces: - **A typed rejection.** `ProtocolRequestTimeoutError` (`packages/protocol/src/errors.ts:34`) carries `method`, `timeoutMs`, and a `phase` of `"load" | "ready" | "reply"` (`errors.ts:19`), rendered into the message from `PHASE_DESCRIPTIONS` (`errors.ts:21-25`). The phase is read when the timer fires, so it names the wait that actually consumed the budget rather than the wait the caller happened to start in. - **The provider stops stacking.** `createRemoteChainProvider` (`client.ts:804`) now calls `postRequest("chainConnect", …)` directly (`client.ts:821`). The request already performs both frame waits, so the previous outer `ensureProtocolFrame()` was redundant as well as unbounded. - **Failures record no duration.** `recordRoundtrip()` fires only on a completed roundtrip (`client.ts:617`). Because the budget starts at the call and this timer starts at the reply, sampling on a timeout would write the leftover budget — a 90 second failure landing as a 3 second sample in a series with no `outcome` attribute to filter on. +- **Dual-Driver test architecture.** Tests are structured into domain-focused suites in `packages/protocol/tests/` (`client-timeouts.test.ts`, `client-precedence.test.ts`, `client-chain-provider.test.ts`) driven by `DAppDriver` and `ProtocolFrame` doubles (`packages/protocol/tests/support/`), removing inline packet parsing and unencapsulated tick delays. Consumers that mapped the timeout by message text were updated to match the type: `describeError` (`apps/host/src/errors.ts:45`) now tests `err instanceof ProtocolRequestTimeoutError` alongside the existing text match (`apps/host/src/errors.ts:90-92`), keeping the string branch for foreign timeouts that still need it. @@ -133,9 +136,10 @@ No existing timeout constant was reduced, and `warmup` remains exempt from any b ## Prevention - **A green suite is not evidence that a cleanup invariant is defended.** Deleting `budget.release()` left the suite fully green, and so did deleting `pendingRequests.delete(sent.id)`. Both mutations ship real damage: an undisarmed timer emits a spurious timeout count after the request already succeeded, and a missing delete leaks a pending entry holding the caller's progress callback. Assert cleanup through observable behaviour: - - after a request resolves on a healthy frame, `expect(vi.getTimerCount()).toBe(0)` (`packages/protocol/tests/client.test.ts:317`); - - after a reply-phase timeout, deliver a late `progress` envelope for that request's id and assert the caller's callback was not invoked (`packages/protocol/tests/client.test.ts:294`). -- **Probe the gate with mutations before trusting it.** Apply one mutation at a time to the real source, run the suite, restore. Six mutations each need a named failing scenario: dropping the timer disarm, dropping the pending-entry delete, restoring the provider's unbudgeted wait, arming the budget after the frame wait, giving `warmup` a budget, and relabelling a crash as the caller's own timeout. A mutation that leaves the suite green names a scenario that defends nothing. Beware writing a no-op mutation — `throw cond ? error : error` changes nothing and its green run means nothing. + - after a request resolves on a healthy frame, `expect(vi.getTimerCount()).toBe(0)` (`packages/protocol/tests/client-timeouts.test.ts:251`); + - after a reply-phase timeout, deliver a late `progress` envelope for that request's id and assert the caller's callback was not invoked (`packages/protocol/tests/client-timeouts.test.ts:273`). +- **Probe the gate with mutations before trusting it.** Apply one mutation at a time to the real source, run the suite, restore. Six mutations each need a named failing scenario: dropping the timer disarm, dropping the pending-entry delete, restoring the provider's unbudgeted wait, arming the budget after the frame wait, giving `warmup` a budget, and relabelling a crash as the caller's own timeout. A mutation that leaves the suite green names a scenario that defends nothing. +- **Encapsulate protocol test plumbing behind Dual-Driver doubles.** Avoid inline JSON-RPC packet parsing (`JSON.parse(...)`) and multi-tick delays (`await elapse(1)`) in test scenarios. Use domain drivers (`createTestDApp`, `installProtocolFrame`) and temporal synchronization primitives (`settleWithin`, `until`, `bootAndConnect`). - **A per-operation budget must cover the setup it depends on.** When an operation advertises a timeout, audit every `await` that precedes the timer for its own budget. The pattern to grep for is an unbudgeted readiness wait followed by a budgeted call: `await ensureX(); await withTimeout(op)`. Prefer letting the budgeted call own the readiness wait. - **Never record a duration sample on a failure path in an attribute-less series.** The residual between a call-time budget and a later-started timer reads as a fast success and quietly flatters the percentile it should be inflating. - **Attribute a timeout to the phase that consumed it, read at fire time.** Reconstructing the phase from which promise won the race is wrong whenever a shared wait is involved; a mutable cell set by each guard and read inside the timer callback is not. @@ -144,5 +148,5 @@ No existing timeout constant was reduced, and `warmup` remains exempt from any b ## Related Issues - Issue #166 — the defect this documents. -- `docs/plans/2026-08-14-1856-fix-protocol-request-call-time-budget-plan.md` — the plan for this fix. Two of its statements were superseded during execution: it scoped the provider's direct `ensureProtocolFrame()` call out of the work on the grounds that such calls "are not requests and cannot produce a request budget", which is true of a bare prefetch but not of this call site, where a request follows immediately. Adversarial review falsified that reasoning and the call site was fixed. -- `docs/smoldot.md` — describes `createRemoteChainProvider` and the protocol iframe. Its prose states no timeout contract, so nothing there was invalidated, but a note that `chainConnect` is now bounded by its own request budget would be accurate. +- `docs/plans/2026-08-14-1856-fix-protocol-request-call-time-budget-plan.md` — the plan for this fix. +- `docs/smoldot.md` — describes `createRemoteChainProvider` and the protocol iframe. From 90ca159a057c99ccadbf2991b7592c083452bd52 Mon Sep 17 00:00:00 2001 From: Ryan Lee Date: Fri, 14 Aug 2026 22:34:38 +0000 Subject: [PATCH 10/18] chore: remove ephemeral plan file --- ...-protocol-request-call-time-budget-plan.md | 243 ------------------ ...t-timeout-starts-after-frame-ready-wait.md | 1 - 2 files changed, 244 deletions(-) delete mode 100644 docs/plans/2026-08-14-1856-fix-protocol-request-call-time-budget-plan.md diff --git a/docs/plans/2026-08-14-1856-fix-protocol-request-call-time-budget-plan.md b/docs/plans/2026-08-14-1856-fix-protocol-request-call-time-budget-plan.md deleted file mode 100644 index 8e356038..00000000 --- a/docs/plans/2026-08-14-1856-fix-protocol-request-call-time-budget-plan.md +++ /dev/null @@ -1,243 +0,0 @@ ---- -title: Protocol Request Call-Time Budget - Plan -type: fix -date: 2026-08-14 -artifact_contract: ce-unified-plan/v1 -artifact_readiness: implementation-ready -product_contract_source: ce-plan-bootstrap -execution: code ---- - -# Protocol Request Call-Time Budget - Plan - -## Goal Capsule - -- Objective: a protocol request rejects within its own per-method budget measured from the moment `postRequest` is called, including time spent waiting for the host or protocol frame, and the rejection names which phase consumed the budget. -- Authority: the Requirements below win on behavior. The Key Technical Decisions win on mechanism inside those Requirements. Origin issue: `paritytech/dotli-community#166`. -- Scope: `packages/protocol/src/client.ts`, `packages/protocol/src/errors.ts`, `packages/protocol/tests/client.test.ts`, and one doc comment in `packages/metrics/src/spans.ts`. No other package changes. -- Stop conditions: stop and report if the frame double described in U4 cannot drive `createHostIframe` without a real network navigation, or if any existing test in `packages/protocol` fails for a reason this plan did not predict. -- Tail: the caller owns commit, push, and PR. - ---- - -## Product Contract - -### Summary - -Compute the per-method timeout before the frame wait and arm one timer at call time. Race that single timer against the frame wait and then against the reply wait. Reject with a typed error that carries the phase the budget was spent in: `load`, `ready`, or `reply`. Leave every existing timeout constant at its current value. - -### Problem Frame - -`postRequest` awaits `ensureProtocolFrame()` or `ensureHostFrame()` at `packages/protocol/src/client.ts:504` and only then computes `timeoutMs` (`:519-521`) and arms the reply timer (`:528`). The frame wait carries its own budget: `IFRAME_LOAD_TIMEOUT_MS = 30_000` (`:317`) and `IFRAME_READY_TIMEOUT_MS = 240_000` (`:321`). The rejection that finally arrives does not say whether the time went into booting the frame or waiting for a reply. - -Worst case differs by branch, so the exposure is not uniform. A ready-branch request blocks for up to roughly 270 seconds (240 second ready wait plus its own budget) while its documented contract says 30. A shared-branch request awaits only `ensureHostFrame()`, so its worst case is roughly 60 seconds. - -The blast radius is the boot path. `apps/host/src/main.ts:1324` resolves a name during boot on the ready branch, so it carries the 270 second exposure. `packages/ui/src/shared-mode.ts:97-99` reads shared-mode preferences and `packages/ui/src/host-callbacks/SessionStore.ts:124` reads the session, both on the shared branch at roughly 60 seconds. Each of the three is a first request. - -### Requirements - -**Bound** - -- R1. A non-`warmup` request rejects no later than its own per-method budget, measured from the call, whether the budget is consumed by the frame wait or the reply wait. -- R2. `warmup` stays exempt from a request budget. Its rejection sources stay exactly what they are today: the frame wait, the reset error at `client.ts:168`, the unavailable-frame error at `:507`, and a `fatal` or `init-failed` envelope. -- R3. No existing timeout constant is reduced. `IFRAME_LOAD_TIMEOUT_MS`, `IFRAME_READY_TIMEOUT_MS`, `DEFAULT_TIMEOUT_MS`, and every `METHOD_TIMEOUTS` entry keep their current values. - -**Attribution** - -- R4. A budget rejection names the phase that consumed the budget. Three phases: host frame loading, protocol frame becoming ready, and waiting for a reply. -- R5. The phase is derived from observed progress, not from the `needsProtocolReady` flag. A request whose budget expires while the host frame is still loading reports the load phase even on the ready path. -- R6. A more specific error from the frame path wins over a budget rejection when it settles first. `ProtocolFatalError` (`packages/protocol/src/errors.ts:4`), `ProtocolInitFailedError` (`:11`), and the reset error at `client.ts:168` stay visible to callers. - -**Coverage** - -- R7. Both branches of `needsProtocolReady` are covered by a test that fails when the fix is reverted. The ready branch is covered by a frame that loads but never signals ready. The shared branch is covered by a frame whose load is deliberately late. -- R8. `bun run --cwd packages/protocol test` exits 0, and the 38 tests that pass today still pass. - -### Key Decisions - -- The three-phase vocabulary reuses the tokens already in the file. `client.ts:396` emits `phase: "load"` and `:465` emits `phase: "ready"` for `PROTOCOL_IFRAME_READY`. Governs R4, R5. -- The earlier-and-more-specific error wins rather than being wrapped in a timeout. Governs R6. - -### Scope Boundaries - -- In scope: the budget that `postRequest` owns. -- Not a goal: bounding the direct `ensureProtocolFrame()` calls at `apps/host/src/main.ts:990` and `client.ts:732`. Those are not requests and stay at 240 seconds. -- Not a goal: the unhandled rejection that `void ensureProtocolFrame()` and `void warmupProtocol()` at `apps/host/src/main.ts:990-991` already produce when the ready wait fails. Both stay untouched, for two different reasons: line 990 never enters `postRequest`, so no request budget could reach it, and line 991 is a `warmup` request that R2 keeps untimed. -- Not a goal: changing what `m.timer(S.PROTOCOL_REQUEST)` measures. See KTD5. - -#### Deferred to Follow-Up Work - -- Clearing `chainConnections` in `resetProtocolFrameState` so a `send()` after a reset fails fast instead of re-booting a frame. Surfaced while tracing `client.ts:787`, out of this issue's scope. - -### Sources - -- Defect anchors: `packages/protocol/src/client.ts:497-558` (`postRequest`), `:379-410` (`ensureHostFrame`), `:412-442` (`waitForProtocolReady`), `:444-479` (`ensureProtocolFrame`). -- Fast-fail precedent this plan preserves: `client.ts:156-173` (`resetProtocolFrameState`) and `:219-251` (the `fatal` and `init-failed` handler). -- Repo racing idiom: `packages/resolver/src/resolve.ts:212-220`, `packages/resolver/src/rpc-resolve.ts:93-102`, `packages/ui/src/topbar.ts:2099-2107`. There is no shared deadline helper and no `AbortSignal.timeout` anywhere in the repo. -- Method partition: `packages/protocol/src/auth-storage.ts:29-54`. Six methods take the shared branch (`authStorageRead`, `authStorageWrite`, `authStorageClear`, `modeStorageRead`, `modeStorageWrite`, `modeStorageClear`). The other eight take the ready branch. -- Metric attribute type is open (`packages/metrics/src/metrics.ts:45-57` ends in `& Record`), so a `phase` key typechecks. -- No test and no consumer anywhere asserts on a `client.ts` timeout string, and every caller catches generically without inspecting type or message. Verified across `apps/host/src/main.ts`, `packages/ui/src/shared-mode.ts`, `packages/ui/src/topbar.ts`, `packages/ui/src/bulletin-bitswap.ts`, `packages/ui/src/host-callbacks/SessionStore.ts`. - ---- - -## Planning Contract - -### Key Technical Decisions - -- KTD1. One timer armed at call time, raced against each phase. `startRequestBudget` arms a single `setTimeout(timeoutMs)` and exposes a `guard` that wraps a phase promise in `Promise.race`. Rejected alternative: deadline arithmetic with `Date.now()` and a second timer for the reply phase. That version depends on wall clock, so an NTP step or a laptop resume between phases silently moves the bound, and re-entering the timer queue adds the first timer's scheduling latency to the promised deadline. Advances R1. -- KTD2. `Promise.race` is the abandonment mechanism, with no manual `catch` on the loser. `Promise.race` attaches a handler to every operand, so a cached `hostFramePromise` or `protocolReadyPromise` that rejects after the budget won cannot become an unhandled rejection. A caller that abandons the wait and calls again rejoins the cached wait at `client.ts:451-452` while arming a fresh budget from its own call time, which is the semantics R1 asks for. Advances R1, R6. -- KTD3. Phase is a mutable variable read when the timer fires, and the ready branch is split into two guarded awaits. `postRequest` awaits `ensureHostFrame()` under phase `load`, flips to `ready`, awaits `ensureProtocolFrame()`, then flips to `reply`. The second call short-circuits at `client.ts:382` because `protocolIframe.contentWindow` is set by then. Rejected alternative: choosing the phase statically from `needsProtocolReady`, which mislabels a `chainConnect` budget (30_000 at `:490`) that expires during the 30_000 load wait as `ready`. Advances R4, R5. -- KTD4. A typed `ProtocolRequestTimeoutError` in `packages/protocol/src/errors.ts` carries `method`, `timeoutMs`, and `phase`. Tests assert on the `phase` field, not on message text. Rejected alternative: message-only attribution, which forces tests to match prose and gives callers nothing to branch on. Advances R4, R7. -- KTD5. `m.timer(S.PROTOCOL_REQUEST)` keeps starting at the reply transition, and `stopReq()` stays out of any shared `finally`. Frame boot is already measured twice by `PROTOCOL_IFRAME_READY` (`client.ts:394`, `:413`), so re-basing the request histogram would double-count boot into a per-request distribution and shift every dashboard percentile with no schema change to signal it. Sweeping `stopReq()` into a blanket `finally` would additionally start admitting failed requests into a histogram that today excludes them (`client.ts:547-552` deliberately omits it). Advances R3 by leaving telemetry semantics intact. -- KTD5b. `stopReq()` is called by `postRequest` around the reply guard, never by the budget timer callback. The callback is created before `stopReq` exists, so it cannot reach it. `postRequest` therefore awaits the reply guard in a `try`, calls `stopReq()` on success, and in the `catch` calls `stopReq()` only when the error is a `ProtocolRequestTimeoutError`, then rethrows. A `fatal`, `init-failed`, or response error still records no sample, matching `client.ts:547-552` today. Rejected alternative: passing a mutable stop-function holder into `startRequestBudget`, which puts metrics wiring inside a timing primitive to save nothing. Advances R3. -- KTD6. The budget is armed as the first statement inside the `try` whose `finally` releases it, and before the ensure promise is created. Arming first is what makes the 30_000-versus-30_000 collision deterministic: equal-expiry timers fire in creation order, so the budget beats `createHostIframe`'s load timer (`client.ts:349`). That ordering is load-bearing rather than incidental, because no method has a budget below `IFRAME_LOAD_TIMEOUT_MS`, so the tie is the only way a `load`-phase budget rejection is reachable at all. U4 asserts it directly and a comment in `postRequest` states the invariant. -- KTD7. The new test lives at `packages/protocol/tests/client.test.ts`. `CONTRIBUTING.md:5` asks for colocated unit tests, but `packages/protocol/vitest.config.ts:16` collects only `tests/**/*.test.ts`, so a colocated file would never run. The package's three existing tests are all named after their source file under `tests/`. -- KTD8. The test replaces the real iframe with a `document.createElement` seam rather than driving happy-dom. happy-dom's `HTMLIFrameElement` navigates on `connectedToDocument` and dispatches its own `error` event when the fetch to `http://host.localhost:*` is refused, which reaches `client.ts:361-365` and rejects the frame wait before any late manual `load` can land. A stub element also removes the `postMessage` target-origin check that `client.ts:556` would otherwise trip. `createHostIframe` only uses `src`, `setAttribute`, `tabIndex`, `style.cssText`, `addEventListener`, `appendChild`, `remove()`, and later `contentWindow`, so a plain element with a `contentWindow` property satisfies it. No production seam is added. Advances R7. -- KTD9. Tests use one static import plus `resetProtocolFrame()` in `afterEach`, not `vi.resetModules()`. The happy-dom environment is per file, so a reset module would append a second iframe and register a second `message` listener against the same shared `window` (`client.ts:66`, `:176-179`) while the first iframe stayed in `document.body`. `resetProtocolFrame()` already clears the iframe, both cached promises, and the ready flag, and rejects orphaned ready waiters (`client.ts:152-173`). Advances R7, R8. - -### High-Level Technical Design - -Phase progression and which timer owns each window: - -```mermaid -stateDiagram-v2 - [*] --> Timed: timeoutMs resolved before any await - [*] --> Untimed: UNTIMED_METHODS.has(method) - Untimed --> Sent: plain await ensure, no budget - Timed --> Load: budget armed, phase = load - Load --> Ready: host frame loaded, ready branch only - Load --> Reply: host frame loaded, shared branch - Ready --> Reply: protocol frame signalled ready - Load --> Rejected: budget expired in load - Ready --> Rejected: budget expired in ready - Reply --> Rejected: budget expired in reply - Reply --> Resolved: response envelope arrived - Sent --> Resolved: response envelope arrived -``` - -The decision path inside `postRequest`: - -```mermaid -flowchart TB - A[postRequest called] --> B{UNTIMED_METHODS.has method} - B -->|yes| C[await ensure, send, no timer] - B -->|no| D[arm one timer for timeoutMs, phase = load] - D --> E[guard ensureHostFrame] - E --> F{needsProtocolReady} - F -->|yes| G[phase = ready, guard ensureProtocolFrame] - F -->|no| H[phase = reply] - G --> H - H --> I[start m.timer, register pending, postMessage] - I --> J[guard reply promise] - J --> K[release timer, delete pending entry] -``` - -### Assumptions - -- A1. A stub element returned from a spied `document.createElement("iframe")` drives `createHostIframe` to resolution when the test dispatches a `load` event on it. U4 proves or disproves this on its first run. If it is false, the fallback is to stub `document.body.appendChild` as well, and the plan stops rather than adding a production seam. -- A2. Vitest fake timers cover `setTimeout` and fire equal-expiry timers in creation order. Load-bearing for KTD6 and asserted by U4's load-phase scenario. -- A3. The `phase` attribute on the timeout counter is not assertable in this suite, because `VITE_METRICS` is absent from `packages/protocol/vitest.config.ts:20-26` and `packages/metrics/src/metrics.ts:144` compiles metrics to no-ops without it. U3 is dashboard-only and carries no test. - -### Intended Consequences Worth Recording - -- The JSON-RPC error string on the provider path gains a phase clause. `buildJsonRpcError` (`client.ts:701-713`) renders `serializeError(error)`, which emits `message` only, so the code stays `-32603` and only the text grows. -- A `chainSend` issued after an in-page `resetProtocolFrame()` is now bounded by its own 30 second budget rather than up to 270 seconds. This does not hard-fail a legitimate cold presync, for two verified reasons. The reset paths that force `skipWorkerCache` (`apps/host/src/main.ts:845`, `packages/ui/src/topbar.ts:1570`) reload the page unconditionally (`main.ts:851`, `topbar.ts:1623`), so no live provider survives to send. The two in-page resets (`main.ts:808`, `shared-mode.ts:249`) leave `skipWorkerCache` off, and `client.ts:146-150` records that the SharedWorker keeps its presync progress across an iframe cycle, so the next ready signal is fast. -- A ready-branch request issued while a genuinely cold frame is still presyncing now rejects at its own budget. The boot resolve at `apps/host/src/main.ts:1324` is the real case, capped at 90 seconds. The cold boot itself keeps its full 240 second window, because it is driven by the direct `ensureProtocolFrame()` and the untimed `warmup` at `main.ts:990-991`, neither of which arms a budget. This is the bound the issue asks for, not an accident. -- A cold-frame `chainConnect` on the provider path still takes up to roughly 270 seconds, because `createRemoteChainProvider` awaits a direct `ensureProtocolFrame()` at `client.ts:732` before it posts the request. The request's own 30 second budget then covers only the reply. Bounding that direct wait is out of scope here. -- A request orphaned by a mid-flight `resetProtocolFrame()` now dies within the remainder of its call-time budget rather than a fresh per-method window. The JSDoc at `client.ts:139-143` states the old guarantee and is corrected in U2. - ---- - -## Implementation Units - -### U1. Typed timeout error with a phase field - -- Goal: give the budget a rejection callers and tests can inspect structurally. -- Requirements: R4. -- Dependencies: none. -- Files: `packages/protocol/src/errors.ts`. -- Approach: - 1. Export `type ProtocolRequestTimeoutPhase = "load" | "ready" | "reply"`. - 2. Export `class ProtocolRequestTimeoutError extends Error` with `readonly method: string`, `readonly timeoutMs: number`, `readonly phase: ProtocolRequestTimeoutPhase`, and `name = "ProtocolRequestTimeoutError"`. - 3. Build the message inside the constructor so every call site is consistent: `Protocol request "" timed out after ms while waiting for the host frame to load` for `load`, `... while waiting for the protocol frame to become ready` for `ready`, and `... while waiting for a reply` for `reply`. -- Patterns to follow: `ProtocolFatalError` and `ProtocolInitFailedError` in the same file set `this.name` in the constructor and add no other members. Single-sentence JSDoc per `CONTRIBUTING.md:59`. No em-dashes or semicolons in comments per `CONTRIBUTING.md:48`. -- Test scenarios: none. This unit is a constructor and a message table, refused as a test target because a type forbids the wrong phase and U4 asserts all three phase messages through the real budget. -- Verification: `bun run --cwd packages/protocol typecheck` passes. - -### U2. Call-time budget in postRequest - -- Goal: the per-method budget starts at the call and covers the frame wait. -- Requirements: R1, R2, R3, R4, R5, R6. -- Dependencies: U1. -- Files: `packages/protocol/src/client.ts`. -- Approach: - 1. Add `startRequestBudget(method, timeoutMs)` above `postRequest`. It arms one `setTimeout`, holds a mutable `phase` initialised to `"load"`, and returns `guard`, `enterPhase`, and `release`. `guard` is `Promise.race([work, expiry])`. The timer callback rejects with `ProtocolRequestTimeoutError` built from the phase held at fire time, and emits `m.count(S.PROTOCOL_REQUEST, { outcome: "timeout", method, phase })`. - 2. Move the `timeoutMs` computation from `:519-521` above the frame await. It is a pure function of `method`, so hoisting changes nothing else. - 3. Keep the untimed branch literal. When `timeoutMs` is `null`, arm no budget and take today's plain `await (needsProtocolReady ? ensureProtocolFrame() : ensureHostFrame())` path so `warmup` is behaviourally unchanged. - 4. Extract the envelope build, `pendingRequests` registration, and `postMessage` from `:510-557` into a helper that returns the reply promise and its request id. Delete the inner `setTimeout` at `:525-537`. The budget owns the timer now. - 5. In the timed path, arm the budget as the first statement inside a `try` whose `finally` calls `release()` and deletes the pending entry. Then guard `ensureHostFrame()`, and on the ready branch flip to `"ready"` and guard `ensureProtocolFrame()`. Flip to `"reply"`, start `stopReq`, send, and guard the reply promise. - 6. Keep the `frameWindow` check from `:505-508` between the frame phase and the send. - 7. Call `stopReq()` from `postRequest` around the reply guard per KTD5b, not from the budget callback: on success, and in a `catch` only when the error is a `ProtocolRequestTimeoutError`. Do not put it in the shared `finally`. - 8. Correct the JSDoc at `:139-143` to say an orphaned request rejects within the remainder of its call-time budget. -- Patterns to follow: the inline race idiom at `packages/resolver/src/resolve.ts:212-220`. The existing `phase` attribute spelling at `client.ts:396` and `:465`. -- Execution note: write U4's ready-branch test first and watch it fail against the current code, so the gatekeeper is proven to bite before the fix lands. -- Test scenarios: covered by U4. -- Verification: `bun run --cwd packages/protocol typecheck` passes, and every scenario in U4 passes. - -### U3. Phase-aware telemetry doc comment - -- Goal: the span doc stops describing a timeout attribute set that no longer matches the code. -- Requirements: documents R4's telemetry surface. The `phase` attribute that U2 adds to the `m.count(S.PROTOCOL_REQUEST)` timeout emission is this plan's own extension, not something the origin issue asked for, so this unit records it rather than implementing R4. -- Dependencies: U2. -- Files: `packages/metrics/src/spans.ts`. -- Approach: update the comment at `:142-147` to state that a timeout emits `{ outcome: "timeout", method, phase }`, and that the histogram covers the reply phase only while the counter covers the whole call-time budget. -- Patterns to follow: the sibling comment at `:135-140` documents `PROTOCOL_IFRAME_READY` attributes the same way. -- Test scenarios: none. Comment-only, and metrics compile to no-ops in this suite per A3. -- Verification: `bun run --cwd packages/metrics typecheck` passes. - -### U4. Budget tests for both branches - -- Goal: prove the bound and the attribution, and fail if the ordering defect returns. -- Requirements: R1, R2, R4, R5, R6, R7, R8. -- Dependencies: U1, U2. -- Files: `packages/protocol/tests/client.test.ts`. -- Approach: - 1. Static import of `@dotli/protocol/client`. `import { describe, expect, it, vi, afterEach, beforeEach } from "vitest"` because `globals` is `false`. - 2. `beforeEach`: `vi.useFakeTimers()`, then spy `document.createElement` so `"iframe"` returns a stub element carrying a `contentWindow` whose `postMessage` is a `vi.fn()`, and every other tag falls through to the real implementation. - 3. `afterEach`: `resetProtocolFrame()`, `vi.clearAllTimers()`, `vi.useRealTimers()`, `vi.restoreAllMocks()`, and empty `document.body`. - 4. Helper to dispatch `load` on the stub. Helper that reports whether a promise has settled without awaiting it, which must attach a rejection handler to the promise it inspects so a deliberately abandoned request cannot surface as an unhandled rejection when `afterEach` rejects it. -- Test scenarios: - - As a caller of a ready-path method, I get a rejection within my own budget when the frame loads but never signals ready. Load the frame, call `resolveDotNameRemote`, assert still pending at fake 89_999ms, advance 1ms, assert rejection is a `ProtocolRequestTimeoutError` with `phase === "ready"`, `timeoutMs === 90_000`, and `method === "resolveDotName"`. This is the gatekeeper: reverted code stays pending until 240_000. - - As a caller of a shared-auth method, I get a rejection within my own budget when the host frame loads late and no reply arrives. Call `readSharedAuthStorage`, dispatch `load` at fake 20_000ms, assert still pending at 29_999ms, advance 1ms, assert `phase === "reply"` and `timeoutMs === 30_000`. This is the shared-branch gatekeeper: reverted code arms its reply timer at 20_000 and stays pending until 50_000. - - As a caller of a ready-path method whose host frame never loads, I get the frame-path error rather than a budget rejection, because it settles first. Call `resolveOwnerRemote` (90_000 budget), never dispatch `load`, advance past 30_000, and assert the rejection is `Shared host iframe timed out while loading` and not a `ProtocolRequestTimeoutError`, per R6. This holds only because the method budget exceeds the load timeout. The next scenario covers the case where they are equal. - - As a caller of a 30_000-budget method whose host frame never loads, I get a load-phase budget rejection. Call `readSharedAuthStorage`, never dispatch `load`, advance to fake 30_000ms, and assert a `ProtocolRequestTimeoutError` with `phase === "load"`. The budget wins the equal-expiry tie against the load timer at `client.ts:349` because KTD6 arms it first. This is the only reachable path to `phase === "load"`, since no method has a budget below `IFRAME_LOAD_TIMEOUT_MS`. - - As a caller whose frame is reset mid-wait, I see the reset error and not a budget rejection. Call `resolveDotNameRemote` on a loaded frame that never signals ready, call `resetProtocolFrame()` at fake 10_000ms, and assert the rejection is `Protocol frame state reset before ready signal` and not a `ProtocolRequestTimeoutError`, per R6. - - As a caller of `warmup`, I am never rejected by a request budget. Call `warmupProtocol()` with a loaded frame and no ready signal, advance to fake 120_000ms, and assert still pending. The advance stays strictly below `IFRAME_READY_TIMEOUT_MS` so the ready wait does not reject and mask the claim. - - As a caller on a healthy frame, my request resolves and nothing fires afterwards. Load the frame, dispatch a `ready` envelope, call `readSharedModeStorage`, capture the request id from the `postMessage` spy, dispatch a matching `response` envelope, assert it resolves with the payload, then advance past 30_000 and assert no unhandled rejection and no state change. -- Verification: `bun run --cwd packages/protocol test` exits 0 with all seven scenarios passing, and the first two fail when U2's budget arming is moved back below the frame await. - ---- - -## Verification Contract -| Gate | Command | Applies to | Pass signal | -|---|---|---|---| -| Types | `bun run --cwd packages/protocol typecheck` | U1, U2, U4 | exit 0 | -| Types | `bun run --cwd packages/metrics typecheck` | U3 | exit 0 | -| Unit | `bun run --cwd packages/protocol test` | U2, U4 | exit 0, seven new scenarios pass, 38 pre-existing tests still pass | -| Revert probe | move U2's budget arming below the frame await, rerun the unit gate | R7 | the two gatekeeper scenarios fail | - -This repo's package manager is bun (`package.json:33`, `packageManager: bun@1.3.6`), and pnpm refuses to run here. Do not substitute a `pnpm` command for any gate above. - -Do not run the package's `lint` script. It is `bunx eslint src/` (`packages/protocol/package.json:12`), and `bunx` is a forbidden ephemeral package runner on this machine. - ---- - -## Definition of Done - -- R1 through R8 hold, with R8 read as the bun unit gate above. -- The revert probe in the Verification Contract has been run and the two gatekeeper scenarios were observed to fail against the reverted code. -- `IFRAME_LOAD_TIMEOUT_MS`, `IFRAME_READY_TIMEOUT_MS`, `DEFAULT_TIMEOUT_MS`, and `METHOD_TIMEOUTS` are byte-identical to `main`. -- The untimed `warmup` path arms no timer and creates no budget object. -- `stopReq()` appears only on the resolve path and the reply-phase timeout path. -- The JSDoc at `client.ts:139-143` and the comment at `spans.ts:142-147` match the shipped behavior. -- No abandoned experiment remains in the diff. No stub seam was added to `src/`. diff --git a/docs/solutions/logic-errors/protocol-request-timeout-starts-after-frame-ready-wait.md b/docs/solutions/logic-errors/protocol-request-timeout-starts-after-frame-ready-wait.md index 9d8cd1d0..53a2e922 100644 --- a/docs/solutions/logic-errors/protocol-request-timeout-starts-after-frame-ready-wait.md +++ b/docs/solutions/logic-errors/protocol-request-timeout-starts-after-frame-ready-wait.md @@ -148,5 +148,4 @@ No existing timeout constant was reduced, and `warmup` remains exempt from any b ## Related Issues - Issue #166 — the defect this documents. -- `docs/plans/2026-08-14-1856-fix-protocol-request-call-time-budget-plan.md` — the plan for this fix. - `docs/smoldot.md` — describes `createRemoteChainProvider` and the protocol iframe. From 496f6e8535ea2ea8427c0004b9915715518c7a39 Mon Sep 17 00:00:00 2001 From: Ryan Lee Date: Fri, 14 Aug 2026 23:41:50 +0000 Subject: [PATCH 11/18] fix(protocol): reject in-flight requests and discard spoofed messages on frame teardown resetProtocolFrameState now drains pendingRequests so a teardown between request and reply rejects the caller immediately instead of orphaning it until its budget timer fires; the fatal/init-failed handler reuses that drain instead of duplicating the loop. bindMessageListener drops messages whose source is not the mounted frame window, closing the gap where a valid-origin message with no frame mounted passed the old null check. --- packages/protocol/src/client.ts | 19 +++++------ .../tests/client-chain-provider.test.ts | 33 +++++++++++++++++++ .../protocol/tests/client-precedence.test.ts | 21 ++++++++++++ .../protocol/tests/client-timeouts.test.ts | 9 +++-- 4 files changed, 69 insertions(+), 13 deletions(-) diff --git a/packages/protocol/src/client.ts b/packages/protocol/src/client.ts index 27dfa2b0..2377464c 100644 --- a/packages/protocol/src/client.ts +++ b/packages/protocol/src/client.ts @@ -164,6 +164,14 @@ function resetProtocolFrameState(reason?: Error): void { hostFramePromise = null; protocolReadyPromise = null; protocolReady = false; + + const rejection = + reason ?? new Error("Protocol frame state reset before reply"); + for (const [id, pending] of pendingRequests) { + pendingRequests.delete(id); + pending.reject(rejection); + } + // Reject any callers blocked on `waitForProtocolReady()` before we drop the // resolvers. Otherwise their promises would hang until the 120s timeout. const orphaned = pendingReadyResolvers; @@ -193,11 +201,7 @@ function bindMessageListener(): void { } const frameWindow = protocolIframe?.contentWindow; - if ( - frameWindow !== null && - frameWindow !== undefined && - event.source !== frameWindow - ) { + if (!frameWindow || event.source !== frameWindow) { return; } @@ -237,11 +241,6 @@ function bindMessageListener(): void { // Reject each pending request with the underlying cause so the // loading UI fails fast instead of spinning until per-request // timeouts. - for (const [id, pending] of pendingRequests) { - pendingRequests.delete(id); - pending.reject(err); - } - // Route through the same reset path used by iframe load failures // so callers blocked on `waitForProtocolReady()` // (`pendingReadyResolvers`) are rejected immediately rather than diff --git a/packages/protocol/tests/client-chain-provider.test.ts b/packages/protocol/tests/client-chain-provider.test.ts index 94fa1d91..f3222adb 100644 --- a/packages/protocol/tests/client-chain-provider.test.ts +++ b/packages/protocol/tests/client-chain-provider.test.ts @@ -210,4 +210,37 @@ describe("Remote chain provider lifecycle and request routing", () => { // Then: Only the initial request's messages exist, no error reply emitted expect(dApp.replies()).toHaveLength(0); }); + + it("discards incoming window messages when protocol frame is not mounted or has no frameWindow", async () => { + // Given: Frame is booted, connection established and initial request answered + const dApp = createTestDApp(); + dApp.send(Rpc.request(1)); + await frame.bootAndConnect(); + const connId = frame.connectionId(); + frame.chainMessage(connId, Rpc.response(1, "ok")); + await elapse(10); + + // Tear down protocol frame so protocolIframe is null + resetProtocolFrame(); + await elapse(10); + const countBefore = dApp.replies().length; + + // When: PostMessage dispatched with valid origin and source=window (not frameWindow) + window.dispatchEvent( + new MessageEvent("message", { + origin: "http://host.localhost:5173", + data: { + namespace: "dotli:protocol", + kind: "chain-message", + connectionId: connId, + message: JSON.stringify({ jsonrpc: "2.0", id: 2, result: "stale" }), + }, + source: window, + }), + ); + await elapse(10); + + // Then: Message is ignored because protocolIframe is null and source !== frameWindow + expect(dApp.replies().length).toBe(countBefore); + }); }); diff --git a/packages/protocol/tests/client-precedence.test.ts b/packages/protocol/tests/client-precedence.test.ts index 23569b21..c675eea1 100644 --- a/packages/protocol/tests/client-precedence.test.ts +++ b/packages/protocol/tests/client-precedence.test.ts @@ -16,6 +16,7 @@ import { resolveExecutableManifestRemote, resolveOwnerRemote, resolveRootManifestRemote, + warmupProtocol, } from "@dotli/protocol/client"; import { ProtocolFatalError, @@ -87,6 +88,10 @@ describe("Error precedence over request timeout budgets", () => { name: "resolveRootManifestRemote", makeRequest: () => resolveRootManifestRemote("alice"), }, + { + name: "warmupProtocol", + makeRequest: () => warmupProtocol(), + }, ]; it.each(resetCases)( @@ -143,4 +148,20 @@ describe("Error precedence over request timeout budgets", () => { ); }, ); + + it("rejects in-flight pending requests when resetProtocolFrame is called after frame is ready", async () => { + // Given + const pending = resolveDotNameRemote("alice"); + frame.open(); + frame.ready(); + await elapse(1); + + // When + resetProtocolFrame(); + + // Then + await settleWithin(pending, 1_000); + await expect(pending).rejects.toThrow("Protocol frame state reset before reply"); + await expect(pending).rejects.not.toBeInstanceOf(ProtocolRequestTimeoutError); + }); }); diff --git a/packages/protocol/tests/client-timeouts.test.ts b/packages/protocol/tests/client-timeouts.test.ts index 35956b6a..31fe2aab 100644 --- a/packages/protocol/tests/client-timeouts.test.ts +++ b/packages/protocol/tests/client-timeouts.test.ts @@ -181,9 +181,12 @@ describe("Keeping a protocol request inside the time limit it promises", () => { await driveFrame(); // When - await settleWithin(pending, remainingWaitMs); - - // Then + const isDone = settled(pending); + if (remainingWaitMs > 1) { + await elapse(remainingWaitMs - 1); + expect(isDone()).toBe(false); + } + await settleWithin(pending, 10); await expect(pending).rejects.toMatchObject({ name: "ProtocolRequestTimeoutError", method: calledMethod, From 040ac13060458ea883106ded2ecb2ffb899d16e1 Mon Sep 17 00:00:00 2001 From: Ryan Lee Date: Fri, 14 Aug 2026 23:41:54 +0000 Subject: [PATCH 12/18] fix(host): report protocol startup timeout instead of generic peer loss A ProtocolRequestTimeoutError spent in the load or ready phase means the light client timed out during startup (presync exceeded the request budget), not that the host lost its peers. Map those phases to SW_TIMED_OUT before the generic timeout branch. --- apps/host/src/errors.ts | 6 ++++++ 1 file changed, 6 insertions(+) diff --git a/apps/host/src/errors.ts b/apps/host/src/errors.ts index a9c6b0bd..3f6be2c2 100644 --- a/apps/host/src/errors.ts +++ b/apps/host/src/errors.ts @@ -86,6 +86,12 @@ export function describeError(err: unknown, isP2p: boolean): ErrorDescription { recovery: "switch-backend", }; } + if ( + err instanceof ProtocolRequestTimeoutError && + (err.phase === "load" || err.phase === "ready") + ) { + return { message: HOST_ERRORS.SW_TIMED_OUT, recovery: "switch-backend" }; + } if ( err instanceof ProtocolRequestTimeoutError || msg.includes("timed out") || From 8f962c2182c728e5104d310c03e3c11cab38b197 Mon Sep 17 00:00:00 2001 From: Ryan Lee Date: Fri, 14 Aug 2026 23:41:58 +0000 Subject: [PATCH 13/18] test(protocol): extract broker harness and drop tautological error test createProviderHarness moves to tests/support/broker.ts so the routing property-style suite and example tests share one harness. errors.test.ts mirrored constructor parameters and could not fail on a plausible domain bug; thrown error attributes are already asserted on live rejection paths. AGENTS.md now states the testing doctrine in prose. --- packages/protocol/AGENTS.md | 22 ++++++--- packages/protocol/tests/broker.test.ts | 39 +-------------- packages/protocol/tests/errors.test.ts | 60 ----------------------- packages/protocol/tests/support/broker.ts | 42 ++++++++++++++++ packages/protocol/tests/support/index.ts | 5 ++ 5 files changed, 64 insertions(+), 104 deletions(-) delete mode 100644 packages/protocol/tests/errors.test.ts create mode 100644 packages/protocol/tests/support/broker.ts diff --git a/packages/protocol/AGENTS.md b/packages/protocol/AGENTS.md index f311d4ef..75a7ded2 100644 --- a/packages/protocol/AGENTS.md +++ b/packages/protocol/AGENTS.md @@ -1,11 +1,19 @@ # Protocol Package Instructions -Governs `packages/protocol` postMessage bridge, shared storage, and client-side chain provider. +## Testing Doctrine -## Package Invariants +1. **Dual-Driver Double**: + - Use `createTestDApp` and `installProtocolFrame` from `tests/support/`. + - Never mock DOM elements, iframes, or `window.postMessage` directly inside test files. -| id | rule | gate | -| -------- | ----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- | -------------------------------------------------------------------- | -------------------------------------------------- | -| PROTO-T1 | Protocol tests use the dual-driver harness (`createTestDApp` / `installProtocolFrame`) from `tests/support/`; never mock `window.postMessage` or DOM elements inline in test files. | `! grep -E "addEventListener\(\"message\" | contentWindow" packages/protocol/tests/\*.test.ts` | -| PROTO-T2 | Test scenarios assert on parsed domain getters (`frame.sentRpcRequests()`, `frame.connectionId()`, `dApp.replies()`); never parse raw `chainSend` message strings inside scenario bodies. | `! grep -E "JSON\.parse\(" packages/protocol/tests/*.test.ts` | -| PROTO-T3 | Asynchronous scenario synchronization must use virtual timer primitives (`settleWithin`, `until`, `bootAndConnect`); never chain ad-hoc tick yields (`await elapse(1)`). | Review of async wait patterns in `packages/protocol/tests/*.test.ts` | +2. **Domain Getters**: + - Assert on parsed domain getters (`frame.sentRpcRequests()`, `frame.connectionId()`, `dApp.replies()`). + - Do not parse raw wire JSON strings inside test scenarios. + +3. **Deterministic Virtual Time**: + - Synchronize using `settleWithin`, `until`, `bootAndConnect`, and `clock()`. + - Do not chain ad-hoc `elapse(1)` ticks or unanchored timeouts. + +4. **Test Quality & Value**: + - Tests must defend observable system contracts and failure boundaries. + - Never write constructor-mirroring tests that assert properties passed directly into `new`. diff --git a/packages/protocol/tests/broker.test.ts b/packages/protocol/tests/broker.test.ts index 788c375f..26ad896f 100644 --- a/packages/protocol/tests/broker.test.ts +++ b/packages/protocol/tests/broker.test.ts @@ -1,44 +1,9 @@ // Copyright 2026 Parity Technologies (UK) Ltd. // SPDX-License-Identifier: AGPL-3.0-only -import { describe, expect, it, vi } from "vitest"; -import type { - JsonRpcConnection, - JsonRpcMessage, - JsonRpcProvider, - JsonRpcRequest, -} from "@polkadot-api/json-rpc-provider"; +import { describe, expect, it } from "vitest"; import { createChainBrokerManager } from "@dotli/protocol/broker"; - -function createProviderHarness(): { - provider: JsonRpcProvider; - sent: JsonRpcRequest[]; - disconnect: ReturnType; - emit: (message: JsonRpcMessage) => void; -} { - const sent: JsonRpcRequest[] = []; - const disconnect = vi.fn(); - let onMessage: ((message: JsonRpcMessage) => void) | null = null; - - const provider: JsonRpcProvider = (listener): JsonRpcConnection => { - onMessage = listener; - return { - send(message) { - sent.push(message); - }, - disconnect, - }; - }; - - return { - provider, - sent, - disconnect, - emit(message) { - onMessage?.(message); - }, - }; -} +import { createProviderHarness } from "./support"; describe("createChainBrokerManager", () => { it("remaps request ids and routes responses back to the correct client", () => { diff --git a/packages/protocol/tests/errors.test.ts b/packages/protocol/tests/errors.test.ts deleted file mode 100644 index 8dac26aa..00000000 --- a/packages/protocol/tests/errors.test.ts +++ /dev/null @@ -1,60 +0,0 @@ -// Copyright 2026 Parity Technologies (UK) Ltd. -// SPDX-License-Identifier: AGPL-3.0-only - -import { describe, expect, it } from "vitest"; -import { - ProtocolFatalError, - ProtocolInitFailedError, - ProtocolRequestTimeoutError, -} from "@dotli/protocol/errors"; - -describe("protocol error types", () => { - it("constructs ProtocolFatalError with message and name", () => { - const error = new ProtocolFatalError("smoldot panicked"); - expect(error.name).toBe("ProtocolFatalError"); - expect(error.message).toBe("smoldot panicked"); - expect(error).toBeInstanceOf(Error); - }); - - it("constructs ProtocolInitFailedError with message and name", () => { - const error = new ProtocolInitFailedError("failed to init"); - expect(error.name).toBe("ProtocolInitFailedError"); - expect(error.message).toBe("failed to init"); - expect(error).toBeInstanceOf(Error); - }); - - it.each([ - { - method: "resolveDotName" as const, - timeoutMs: 90_000, - phase: "ready" as const, - expectedMsg: - 'Protocol request "resolveDotName" timed out after 90000ms while waiting for the protocol frame to become ready', - }, - { - method: "authStorageRead" as const, - timeoutMs: 30_000, - phase: "load" as const, - expectedMsg: - 'Protocol request "authStorageRead" timed out after 30000ms while waiting for the host frame to load', - }, - { - method: "chainConnect" as const, - timeoutMs: 30_000, - phase: "reply" as const, - expectedMsg: - 'Protocol request "chainConnect" timed out after 30000ms while waiting for a reply', - }, - ])( - "constructs ProtocolRequestTimeoutError for $method in $phase phase", - ({ method, timeoutMs, phase, expectedMsg }) => { - const error = new ProtocolRequestTimeoutError(method, timeoutMs, phase); - expect(error.name).toBe("ProtocolRequestTimeoutError"); - expect(error.method).toBe(method); - expect(error.timeoutMs).toBe(timeoutMs); - expect(error.phase).toBe(phase); - expect(error.message).toBe(expectedMsg); - expect(error).toBeInstanceOf(Error); - }, - ); -}); diff --git a/packages/protocol/tests/support/broker.ts b/packages/protocol/tests/support/broker.ts new file mode 100644 index 00000000..4e30bb65 --- /dev/null +++ b/packages/protocol/tests/support/broker.ts @@ -0,0 +1,42 @@ +// Copyright 2026 Parity Technologies (UK) Ltd. +// SPDX-License-Identifier: AGPL-3.0-only + +import { vi } from "vitest"; +import type { + JsonRpcConnection, + JsonRpcMessage, + JsonRpcProvider, + JsonRpcRequest, +} from "@polkadot-api/json-rpc-provider"; + +export interface ProviderHarness { + provider: JsonRpcProvider; + sent: JsonRpcRequest[]; + disconnect: () => void; + emit: (message: JsonRpcMessage) => void; +} + +export function createProviderHarness(): ProviderHarness { + const sent: JsonRpcRequest[] = []; + const disconnect = vi.fn(); + let onMessage: ((message: JsonRpcMessage) => void) | null = null; + + const provider: JsonRpcProvider = (listener): JsonRpcConnection => { + onMessage = listener; + return { + send(message) { + sent.push(message); + }, + disconnect, + }; + }; + + return { + provider, + sent, + disconnect, + emit(message) { + onMessage?.(message); + }, + }; +} diff --git a/packages/protocol/tests/support/index.ts b/packages/protocol/tests/support/index.ts index a0f72d4b..5725ab17 100644 --- a/packages/protocol/tests/support/index.ts +++ b/packages/protocol/tests/support/index.ts @@ -5,6 +5,7 @@ export * as RpcSupport from "./rpc"; export * as TimeSupport from "./time"; export * as DAppSupport from "./dapp"; export * as FrameSupport from "./frame"; +export * as BrokerSupport from "./broker"; // Convenience domain names for idiomatic import styles: export { Rpc } from "./rpc"; @@ -18,3 +19,7 @@ export { } from "./time"; export { createTestDApp, type DAppDriver } from "./dapp"; export { installProtocolFrame, type ProtocolFrame } from "./frame"; +export { + createProviderHarness, + type ProviderHarness, +} from "./broker"; From 21473d180dfa32acafba5954fa1a9fcba20b389c Mon Sep 17 00:00:00 2001 From: Ryan Lee Date: Fri, 14 Aug 2026 23:47:37 +0000 Subject: [PATCH 14/18] chore: format --- packages/protocol/tests/client-precedence.test.ts | 8 ++++++-- packages/protocol/tests/support/index.ts | 5 +---- 2 files changed, 7 insertions(+), 6 deletions(-) diff --git a/packages/protocol/tests/client-precedence.test.ts b/packages/protocol/tests/client-precedence.test.ts index c675eea1..124bc634 100644 --- a/packages/protocol/tests/client-precedence.test.ts +++ b/packages/protocol/tests/client-precedence.test.ts @@ -161,7 +161,11 @@ describe("Error precedence over request timeout budgets", () => { // Then await settleWithin(pending, 1_000); - await expect(pending).rejects.toThrow("Protocol frame state reset before reply"); - await expect(pending).rejects.not.toBeInstanceOf(ProtocolRequestTimeoutError); + await expect(pending).rejects.toThrow( + "Protocol frame state reset before reply", + ); + await expect(pending).rejects.not.toBeInstanceOf( + ProtocolRequestTimeoutError, + ); }); }); diff --git a/packages/protocol/tests/support/index.ts b/packages/protocol/tests/support/index.ts index 5725ab17..93fa4aba 100644 --- a/packages/protocol/tests/support/index.ts +++ b/packages/protocol/tests/support/index.ts @@ -19,7 +19,4 @@ export { } from "./time"; export { createTestDApp, type DAppDriver } from "./dapp"; export { installProtocolFrame, type ProtocolFrame } from "./frame"; -export { - createProviderHarness, - type ProviderHarness, -} from "./broker"; +export { createProviderHarness, type ProviderHarness } from "./broker"; From f44f8bf7cfc7e08de87c78b22d3feed31f615b53 Mon Sep 17 00:00:00 2001 From: Ryan Lee Date: Fri, 14 Aug 2026 23:49:19 +0000 Subject: [PATCH 15/18] docs(solutions): update call-time budget learning with teardown drain and error mapping --- ...t-timeout-starts-after-frame-ready-wait.md | 19 ++++++++++--------- packages/protocol/AGENTS.md | 2 +- 2 files changed, 11 insertions(+), 10 deletions(-) diff --git a/docs/solutions/logic-errors/protocol-request-timeout-starts-after-frame-ready-wait.md b/docs/solutions/logic-errors/protocol-request-timeout-starts-after-frame-ready-wait.md index 53a2e922..f1c06b20 100644 --- a/docs/solutions/logic-errors/protocol-request-timeout-starts-after-frame-ready-wait.md +++ b/docs/solutions/logic-errors/protocol-request-timeout-starts-after-frame-ready-wait.md @@ -52,8 +52,7 @@ tags: One timer, armed at call time, raced against each phase in turn. -`startRequestBudget` (`client.ts:514`) creates a single `setTimeout` and returns a `RequestBudget` (`client.ts:502-505`) whose `guard(phase, work)` records which wait is running and races it against the shared expiry, and whose `release()` clears the timer (`client.ts:534-536`). - +`startRequestBudget` (`client.ts:516`) creates a single `setTimeout` and returns a `RequestBudget` (`client.ts:501-507`) whose `guard(phase, work)` records which wait is running and races it against the shared expiry, and whose `release()` clears the timer (`client.ts:540-542`). Before — the frame wait precedes the timer entirely: ```ts @@ -89,7 +88,7 @@ async function postRequest( } ``` -After — the budget is armed first and covers every wait (`client.ts:606-621`): +After — the budget is armed first and covers every wait (`client.ts:605-632`): ```ts const budget = startRequestBudget(method, timeoutMs); @@ -117,12 +116,13 @@ try { Four further pieces: - **A typed rejection.** `ProtocolRequestTimeoutError` (`packages/protocol/src/errors.ts:34`) carries `method`, `timeoutMs`, and a `phase` of `"load" | "ready" | "reply"` (`errors.ts:19`), rendered into the message from `PHASE_DESCRIPTIONS` (`errors.ts:21-25`). The phase is read when the timer fires, so it names the wait that actually consumed the budget rather than the wait the caller happened to start in. -- **The provider stops stacking.** `createRemoteChainProvider` (`client.ts:804`) now calls `postRequest("chainConnect", …)` directly (`client.ts:821`). The request already performs both frame waits, so the previous outer `ensureProtocolFrame()` was redundant as well as unbounded. -- **Failures record no duration.** `recordRoundtrip()` fires only on a completed roundtrip (`client.ts:617`). Because the budget starts at the call and this timer starts at the reply, sampling on a timeout would write the leftover budget — a 90 second failure landing as a 3 second sample in a series with no `outcome` attribute to filter on. +- **The provider stops stacking.** `createRemoteChainProvider` (`client.ts:810`) now calls `postRequest("chainConnect", …)` directly (`client.ts:827`). The request already performs both frame waits, so the previous outer `ensureProtocolFrame()` was redundant as well as unbounded. +- **Failures record no duration.** `recordRoundtrip()` fires only on a completed roundtrip (`client.ts:624`). Because the budget starts at the call and this timer starts at the reply, sampling on a timeout would write the leftover budget — a 90 second failure landing as a 3 second sample in a series with no `outcome` attribute to filter on. +- **Teardown drains in-flight requests.** `resetProtocolFrameState` (`client.ts:161`) now drains and rejects `pendingRequests` immediately with `"Protocol frame state reset before reply"`, eliminating orphaned callers when a frame resets after ready. +- **Source-window guard hardened.** `bindMessageListener` (`client.ts:204`) verifies `!frameWindow || event.source !== frameWindow`, ensuring post-teardown messages with a valid origin are dropped. - **Dual-Driver test architecture.** Tests are structured into domain-focused suites in `packages/protocol/tests/` (`client-timeouts.test.ts`, `client-precedence.test.ts`, `client-chain-provider.test.ts`) driven by `DAppDriver` and `ProtocolFrame` doubles (`packages/protocol/tests/support/`), removing inline packet parsing and unencapsulated tick delays. -Consumers that mapped the timeout by message text were updated to match the type: `describeError` (`apps/host/src/errors.ts:45`) now tests `err instanceof ProtocolRequestTimeoutError` alongside the existing text match (`apps/host/src/errors.ts:90-92`), keeping the string branch for foreign timeouts that still need it. - +Consumers that mapped the timeout by message text were updated to match the type and phase: `describeError` (`apps/host/src/errors.ts:45`) tests `err instanceof ProtocolRequestTimeoutError`, mapping `load` and `ready` phases to `HOST_ERRORS.SW_TIMED_OUT` (`apps/host/src/errors.ts:90-93`) and generic timeout copy otherwise (`apps/host/src/errors.ts:95-105`). No existing timeout constant was reduced, and `warmup` remains exempt from any budget (`client.ts:492-493`) because it waits on chain sync. ## Why This Works @@ -136,8 +136,9 @@ No existing timeout constant was reduced, and `warmup` remains exempt from any b ## Prevention - **A green suite is not evidence that a cleanup invariant is defended.** Deleting `budget.release()` left the suite fully green, and so did deleting `pendingRequests.delete(sent.id)`. Both mutations ship real damage: an undisarmed timer emits a spurious timeout count after the request already succeeded, and a missing delete leaks a pending entry holding the caller's progress callback. Assert cleanup through observable behaviour: - - after a request resolves on a healthy frame, `expect(vi.getTimerCount()).toBe(0)` (`packages/protocol/tests/client-timeouts.test.ts:251`); - - after a reply-phase timeout, deliver a late `progress` envelope for that request's id and assert the caller's callback was not invoked (`packages/protocol/tests/client-timeouts.test.ts:273`). + - after a request resolves on a healthy frame, `expect(vi.getTimerCount()).toBe(0)` (`packages/protocol/tests/client-timeouts.test.ts:280`); + - after a reply-phase timeout, deliver a late `progress` envelope for that request's id and assert the caller's callback was not invoked (`packages/protocol/tests/client-timeouts.test.ts:316`). + - after frame reset while a request is in flight, assert the request rejects immediately without timing out (`packages/protocol/tests/client-precedence.test.ts:153`). - **Probe the gate with mutations before trusting it.** Apply one mutation at a time to the real source, run the suite, restore. Six mutations each need a named failing scenario: dropping the timer disarm, dropping the pending-entry delete, restoring the provider's unbudgeted wait, arming the budget after the frame wait, giving `warmup` a budget, and relabelling a crash as the caller's own timeout. A mutation that leaves the suite green names a scenario that defends nothing. - **Encapsulate protocol test plumbing behind Dual-Driver doubles.** Avoid inline JSON-RPC packet parsing (`JSON.parse(...)`) and multi-tick delays (`await elapse(1)`) in test scenarios. Use domain drivers (`createTestDApp`, `installProtocolFrame`) and temporal synchronization primitives (`settleWithin`, `until`, `bootAndConnect`). - **A per-operation budget must cover the setup it depends on.** When an operation advertises a timeout, audit every `await` that precedes the timer for its own budget. The pattern to grep for is an unbudgeted readiness wait followed by a budgeted call: `await ensureX(); await withTimeout(op)`. Prefer letting the budgeted call own the readiness wait. diff --git a/packages/protocol/AGENTS.md b/packages/protocol/AGENTS.md index 75a7ded2..d890d43b 100644 --- a/packages/protocol/AGENTS.md +++ b/packages/protocol/AGENTS.md @@ -11,7 +11,7 @@ - Do not parse raw wire JSON strings inside test scenarios. 3. **Deterministic Virtual Time**: - - Synchronize using `settleWithin`, `until`, `bootAndConnect`, and `clock()`. + - Synchronize using `settleWithin`, `until`, and `bootAndConnect`. - Do not chain ad-hoc `elapse(1)` ticks or unanchored timeouts. 4. **Test Quality & Value**: From 55514bab0c7e9e51e423f7da1fe35aa2d9ce57ee Mon Sep 17 00:00:00 2001 From: Ryan Lee Date: Fri, 14 Aug 2026 23:52:19 +0000 Subject: [PATCH 16/18] docs(solutions): rewrite call-time budget learning as durable architectural invariant --- ...t-timeout-starts-after-frame-ready-wait.md | 159 +++++++----------- 1 file changed, 60 insertions(+), 99 deletions(-) diff --git a/docs/solutions/logic-errors/protocol-request-timeout-starts-after-frame-ready-wait.md b/docs/solutions/logic-errors/protocol-request-timeout-starts-after-frame-ready-wait.md index f1c06b20..7fad4f41 100644 --- a/docs/solutions/logic-errors/protocol-request-timeout-starts-after-frame-ready-wait.md +++ b/docs/solutions/logic-errors/protocol-request-timeout-starts-after-frame-ready-wait.md @@ -1,94 +1,61 @@ --- -title: Protocol request timeout started after the frame-ready wait, not at the call +title: Request timeout armed after asynchronous bootstrap creates unbounded wait date: 2026-08-14 last_updated: 2026-08-14 category: logic-errors -module: packages/protocol +module: protocol problem_type: logic_error component: service_object symptoms: - - First request against a cold or wedged protocol frame blocked up to roughly five minutes while advertising a 30 second timeout - - Rejection did not say whether the time went into booting the frame or waiting for a reply - - A dApp chain connection stacked 30s plus 240s plus 30s before any JSON-RPC error reached it - - Every message sent during that window queued silently, so the chain looked unresponsive rather than failed - - Timeout samples landed in the protocol.request latency series as the leftover budget, so p99 improved as the protocol degraded + - First request against a cold or wedged protocol frame blocked up to five minutes while advertising a 30-second timeout + - Rejections could not distinguish between a frame that failed to load, a frame stuck in presync, or a dropped RPC reply + - Downstream dApp chain connections stacked setup timeouts before the connection allowance even started + - Latency metrics for timed-out requests sampled only the residual budget, artificially improving reported p99 latency during outages root_cause: async_timing resolution_type: code_fix severity: high tags: - - protocol-client - - timeout - - iframe - - request-budget + - timeout-budget - async-timing - - metrics + - postmessage-bridge + - metrics-integrity - mutation-testing - - error-handling - - dual-driver-dsl + - test-doubles --- -# Protocol request timeout started after the frame-ready wait, not at the call +# Request timeout armed after asynchronous bootstrap creates unbounded wait ## Problem -`postRequest` advertised a per-method timeout and callers reasonably read it as the bound on the call. The timer was only created *after* awaiting the shared protocol iframe becoming ready, and that wait carries its own budgets. A first request against a cold or wedged frame could therefore block for up to roughly five minutes while reporting a 30 second contract, and the rejection never said where the time went. Fixed on branch `fix/protocol-request-call-time-budget` (issue #166), unmerged as of this writing. +When an asynchronous client advertises a per-operation timeout (e.g. 30s default, 90s for chain lookups) but arms its timer only *after* awaiting an underlying subsystem's readiness (such as a sandboxed host iframe, WebWorker, or chain presync), the advertised budget is violated. The total wait becomes the sum of the setup timeout plus the operation timeout (up to 5 minutes), while callers expect a strict 30-second bound. -## Symptoms +Furthermore, when the timeout eventually fires, the rejection has lost context on where the time was spent, and metric histograms that record elapsed time on timeout sample only the residual fraction of the window, distorting service telemetry. -- A request with a 30 second budget could take up to `IFRAME_LOAD_TIMEOUT_MS` (30_000, `packages/protocol/src/client.ts:322`) plus `IFRAME_READY_TIMEOUT_MS` (240_000, `client.ts:326`) plus its own 30 seconds before rejecting — a worst case of roughly five minutes, of which the first four and a half are the frame wait alone. -- The rejection was a bare `Error` reading `Protocol request "" timed out after ms`, with nothing to distinguish a frame that never loaded from one that loaded but never signalled ready from one that never answered. -- `createRemoteChainProvider` awaited the frame outside any budget and only then issued `chainConnect`, so a dApp connecting during a cold boot waited out both frame budgets before the connection's own 30 seconds even started. -- During that window `send()` pushed every JSON-RPC message onto `pendingMessages` and returned nothing, so the dApp saw an unresponsive chain rather than a failure. -- The old timer called `stopReq()` on expiry, so a timeout recorded roughly the whole budget as a duration sample. Preserving that call after the fix would have recorded the *leftover* budget instead, because the budget now starts at the call while the roundtrip timer starts at the reply. +## Mechanism & Failure Modes -## What Didn't Work +### 1. Cumulative Timeout Stacking +If setup carries an initial load allowance (30s) and a readiness allowance (240s), placing `await ensureReady()` before arming the per-request timer creates a sequential cascade: +$$\text{Max Latency} = T_{\text{load}} + T_{\text{ready}} + T_{\text{request}} \approx 300\text{s}$$ +Callers programming to a 30-second deadline hang for 5 minutes during cold starts or worker stalls. -- **Deadline arithmetic with `Date.now()`.** Compute `Date.now() + timeoutMs` once and re-check the remainder before each phase. Rejected: an NTP step or a laptop resume moves the bound underneath the request. A single `setTimeout` armed once is subject only to the timer queue. -- **`@std/async` from JSR.** `deadline()` constructs a fresh `AbortSignal.timeout(ms)` inside its own body, so every call starts a new window — which is precisely the defect being fixed. `abortable()` plus one shared `AbortSignal.timeout` can hold a deadline across sequential awaits, but `AbortSignal.timeout` exposes no cancel API, so the disarm on early completion becomes a no-op and every settled request leaves a timer running to full expiry. It also rejects with a fixed `DOMException`, so naming the phase still needs a re-wrap. -- **Emitting the phase counter from the guard's rejection path.** Proposed so that a load failure killing ten in-flight requests counts ten times instead of once. Rejected: the tie case already emits both a `PROTOCOL_REQUEST` timeout and a `PROTOCOL_IFRAME_READY` error for the same frame failure, and a second emission point widens that double-count. The reachability limit is documented instead: only the caller that creates the frame promise can report the `load` phase, because no method budget is below `IFRAME_LOAD_TIMEOUT_MS`. -- **Reducing a frame constant so the request budget would win.** Never attempted, and explicitly out of bounds: it would shorten the frame's own allowance for every caller to fix an ordering bug. +### 2. Loss of Phase Attribution +A single generic `TimeoutError` without phase metadata makes diagnosis impossible. A caller or telemetry consumer cannot tell whether: +- The host frame failed to load from network (`load` phase), +- The worker hung during chain presync (`ready` phase), or +- The remote chain RPC failed to answer (`reply` phase). -## Solution +### 3. Metric Inversion on Failure +When a request budget starts at call time ($t=0$) but the latency stopwatch begins only when the message is dispatched to the frame ($t=t_{\text{ready}}$), measuring duration on timeout records only the *leftover* budget ($T_{\text{budget}} - t_{\text{ready}}$). A 90-second failure that spent 87 seconds waiting for readiness samples as a 3-second request, falsely pulling p95/p99 latency metrics downward during outages. -One timer, armed at call time, raced against each phase in turn. +### 4. Teardown Orphan Leaks +If the underlying frame is reset or torn down while a request is awaiting a reply, failing to drain the pending request registry leaves caller promises hanging until their timeout timers expire, rather than failing fast with an explicit teardown error. -`startRequestBudget` (`client.ts:516`) creates a single `setTimeout` and returns a `RequestBudget` (`client.ts:501-507`) whose `guard(phase, work)` records which wait is running and races it against the shared expiry, and whose `release()` clears the timer (`client.ts:540-542`). -Before — the frame wait precedes the timer entirely: +--- -```ts -async function postRequest( - method: M, - payload: ProtocolRequestMap[M], - onProgress?: (message: string) => void, - needsProtocolReady = /* ... */, -): Promise { - await (needsProtocolReady ? ensureProtocolFrame() : ensureHostFrame()); - // ... build the envelope ... - const timeoutMs = UNTIMED_METHODS.has(method) - ? null - : (METHOD_TIMEOUTS[method] ?? DEFAULT_TIMEOUT_MS); - const stopReq = m.timer(S.PROTOCOL_REQUEST); - - return new Promise((resolve, reject) => { - const timer = - timeoutMs === null - ? null - : setTimeout(() => { - pendingRequests.delete(id); - m.count(S.PROTOCOL_REQUEST, { outcome: "timeout", method }); - stopReq(); - reject( - new Error( - `Protocol request "${method}" timed out after ${String(timeoutMs)}ms`, - ), - ); - }, timeoutMs); - // ... - }); -} -``` +## Architectural Invariants -After — the budget is armed first and covers every wait (`client.ts:605-632`): +### 1. Unified Call-Time Budgeting +A single `setTimeout` must be armed at the public entry point before any setup or dispatch awaits occur. All subsequent asynchronous phases (`load`, `ready`, `reply`) are raced sequentially against that single deadline: ```ts const budget = startRequestBudget(method, timeoutMs); @@ -97,14 +64,12 @@ try { if (needsProtocolReady) { await budget.guard("ready", ensureProtocolFrame()); } - const frameWindow = requireFrameWindow(); - const recordRoundtrip = m.timer(S.PROTOCOL_REQUEST); const sent = sendRequest(frameWindow, method, payload, onProgress); try { const value = await budget.guard("reply", sent.reply); recordRoundtrip(); return value; - } catch (error: unknown) { + } catch (error) { pendingRequests.delete(sent.id); throw error; } @@ -113,40 +78,36 @@ try { } ``` -Four further pieces: +### 2. Phase-Attributed Rejections +The timeout error must carry the exact phase in flight at the moment the timer fired (`load` | `ready` | `reply`), determined dynamically inside the timer callback rather than guessed from race winners. -- **A typed rejection.** `ProtocolRequestTimeoutError` (`packages/protocol/src/errors.ts:34`) carries `method`, `timeoutMs`, and a `phase` of `"load" | "ready" | "reply"` (`errors.ts:19`), rendered into the message from `PHASE_DESCRIPTIONS` (`errors.ts:21-25`). The phase is read when the timer fires, so it names the wait that actually consumed the budget rather than the wait the caller happened to start in. -- **The provider stops stacking.** `createRemoteChainProvider` (`client.ts:810`) now calls `postRequest("chainConnect", …)` directly (`client.ts:827`). The request already performs both frame waits, so the previous outer `ensureProtocolFrame()` was redundant as well as unbounded. -- **Failures record no duration.** `recordRoundtrip()` fires only on a completed roundtrip (`client.ts:624`). Because the budget starts at the call and this timer starts at the reply, sampling on a timeout would write the leftover budget — a 90 second failure landing as a 3 second sample in a series with no `outcome` attribute to filter on. -- **Teardown drains in-flight requests.** `resetProtocolFrameState` (`client.ts:161`) now drains and rejects `pendingRequests` immediately with `"Protocol frame state reset before reply"`, eliminating orphaned callers when a frame resets after ready. -- **Source-window guard hardened.** `bindMessageListener` (`client.ts:204`) verifies `!frameWindow || event.source !== frameWindow`, ensuring post-teardown messages with a valid origin are dropped. -- **Dual-Driver test architecture.** Tests are structured into domain-focused suites in `packages/protocol/tests/` (`client-timeouts.test.ts`, `client-precedence.test.ts`, `client-chain-provider.test.ts`) driven by `DAppDriver` and `ProtocolFrame` doubles (`packages/protocol/tests/support/`), removing inline packet parsing and unencapsulated tick delays. +### 3. Root-Cause Precedence +Explicit domain errors (such as peer crashes, frame load rejections, or session resets) must take precedence over budget expiration when settling first. `Promise.race` preserves the first settled rejection, preventing underlying crashes from being misattributed as client timeouts. -Consumers that mapped the timeout by message text were updated to match the type and phase: `describeError` (`apps/host/src/errors.ts:45`) tests `err instanceof ProtocolRequestTimeoutError`, mapping `load` and `ready` phases to `HOST_ERRORS.SW_TIMED_OUT` (`apps/host/src/errors.ts:90-93`) and generic timeout copy otherwise (`apps/host/src/errors.ts:95-105`). -No existing timeout constant was reduced, and `warmup` remains exempt from any budget (`client.ts:492-493`) because it waits on chain sync. +### 4. Metric Separation +Attribute-less latency metrics must record durations *only* for completed, successful roundtrips. Timeouts and failures must be emitted strictly as counter metrics tagged with the failure phase. -## Why This Works +### 5. Immediate Teardown Drain +Any lifecycle transition that invalidates the underlying channel must synchronously drain and reject all in-flight pending requests with an explicit cancellation error. -- **The bound is measured from the moment the caller asked.** One `setTimeout` armed before any await covers load, ready, and reply, so the advertised per-method budget is the real ceiling instead of the last term in a sum. -- **The tie is resolved by construction.** The budget timer is created before the frame promise, and equal-expiry timers fire in creation order. Since no method budget is below `IFRAME_LOAD_TIMEOUT_MS`, a 30 second request against a frame that never loads reports its own timeout rather than the frame's — which is also the only reason the `load` phase is reachable at all. -- **A more specific frame error still wins when it genuinely settles first.** `Promise.race` keeps the first settlement, so `ProtocolFatalError`, `ProtocolInitFailedError`, and the frame-reset error continue to reach callers instead of being masked by a budget rejection. -- **Abandoning a shared wait is safe.** `Promise.race` attaches a handler to both operands, so a cached frame promise that a timed-out caller stopped awaiting cannot become an unhandled rejection, and a second caller still attached is unaffected. -- **The telemetry no longer improves as the system degrades.** Timeouts are counted with their phase and contribute no duration sample, so the latency series means completed roundtrips only. - -## Prevention - -- **A green suite is not evidence that a cleanup invariant is defended.** Deleting `budget.release()` left the suite fully green, and so did deleting `pendingRequests.delete(sent.id)`. Both mutations ship real damage: an undisarmed timer emits a spurious timeout count after the request already succeeded, and a missing delete leaks a pending entry holding the caller's progress callback. Assert cleanup through observable behaviour: - - after a request resolves on a healthy frame, `expect(vi.getTimerCount()).toBe(0)` (`packages/protocol/tests/client-timeouts.test.ts:280`); - - after a reply-phase timeout, deliver a late `progress` envelope for that request's id and assert the caller's callback was not invoked (`packages/protocol/tests/client-timeouts.test.ts:316`). - - after frame reset while a request is in flight, assert the request rejects immediately without timing out (`packages/protocol/tests/client-precedence.test.ts:153`). -- **Probe the gate with mutations before trusting it.** Apply one mutation at a time to the real source, run the suite, restore. Six mutations each need a named failing scenario: dropping the timer disarm, dropping the pending-entry delete, restoring the provider's unbudgeted wait, arming the budget after the frame wait, giving `warmup` a budget, and relabelling a crash as the caller's own timeout. A mutation that leaves the suite green names a scenario that defends nothing. -- **Encapsulate protocol test plumbing behind Dual-Driver doubles.** Avoid inline JSON-RPC packet parsing (`JSON.parse(...)`) and multi-tick delays (`await elapse(1)`) in test scenarios. Use domain drivers (`createTestDApp`, `installProtocolFrame`) and temporal synchronization primitives (`settleWithin`, `until`, `bootAndConnect`). -- **A per-operation budget must cover the setup it depends on.** When an operation advertises a timeout, audit every `await` that precedes the timer for its own budget. The pattern to grep for is an unbudgeted readiness wait followed by a budgeted call: `await ensureX(); await withTimeout(op)`. Prefer letting the budgeted call own the readiness wait. -- **Never record a duration sample on a failure path in an attribute-less series.** The residual between a call-time budget and a later-started timer reads as a fast success and quietly flatters the percentile it should be inflating. -- **Attribute a timeout to the phase that consumed it, read at fire time.** Reconstructing the phase from which promise won the race is wrong whenever a shared wait is involved; a mutable cell set by each guard and read inside the timer callback is not. -- **When a consumer branches on an error, give it a type to branch on.** `apps/host/src/errors.ts` branched on ten distinct message substrings, so rewording a message silently changed user-facing copy and the recovery affordance. `apps/host` has no unit-test runner, so no test could have caught it — the type is the gate. - -## Related Issues +--- -- Issue #166 — the defect this documents. -- `docs/smoldot.md` — describes `createRemoteChainProvider` and the protocol iframe. +## Verification & Prevention Rules + +- **Enforce Two-Sided Timer Boundaries:** A timeout test must assert not just that a request fails at $T$, but that it remains pending and unresolved at $T - 1\text{ms}$. +- **Probe Cleanup Invariants with Mutation Gates:** A green test suite is not proof that cleanups work. Verify that removing `budget.release()` or `pendingRequests.delete(id)` causes a test to fail. +- **Dual-Driver Test Harness for Message Bridges:** Never mock DOM elements, iframes, or `postMessage` directly in test scenarios. Encapsulate the boundary into two domain drivers: + - A **Consumer Driver** (`DAppDriver`) that sends requests and collects responses. + - A **Peer Driver** (`ProtocolFrame`) that scripts frame state transitions (`open`, `ready`, `respond`, `fatal`). +- **Audit Unbudgeted Setup Awaits:** The code smell to grep for is an unbudgeted setup call preceding a budgeted operation: + ```ts + // ❌ Defect: Setup is outside the budget + await ensureReady(); + await withTimeout(op, 30_000); + + // ✅ Invariant: Budget wraps setup and operation + await withTimeout(async () => { + await ensureReady(); + return op(); + }, 30_000); + ``` From c4e3a806d3b9994560ba2371a270ec497a78718b Mon Sep 17 00:00:00 2001 From: Ryan Lee Date: Sat, 15 Aug 2026 00:58:44 +0000 Subject: [PATCH 17/18] fix(protocol): accept the frame handshake posted before the iframe load event MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The source-window guard read `protocolIframe`, which was only assigned in the iframe's load handler — several ticks after the frame was appended to the DOM. A frame that posted `ready` while its document was still parsing therefore had its own handshake discarded as untrusted, so the protocol never became ready, resolution never settled, and the host rendered no error page at all. Eight functional loading scenarios timed out waiting for `.error-page-title`; the ones that survived did so only because their mock retried the post twelve times with backoff. Trust is now established when the frame is attached rather than when it loads, and revoked on the load-timeout and error paths so a dead frame never stays trusted. Post-teardown discarding is unchanged. --- packages/protocol/src/client.ts | 19 +++++++++++++++---- 1 file changed, 15 insertions(+), 4 deletions(-) diff --git a/packages/protocol/src/client.ts b/packages/protocol/src/client.ts index 2377464c..cad05b79 100644 --- a/packages/protocol/src/client.ts +++ b/packages/protocol/src/client.ts @@ -350,21 +350,32 @@ function createHostIframe(): Promise { iframe.style.cssText = "position:fixed;width:0;height:0;opacity:0;pointer-events:none;border:0;"; + const trustAsMessageSourceAndAttach = (): void => { + protocolIframe = iframe; + document.body.appendChild(iframe); + }; + + const revokeMessageSourceTrustAndRemove = (): void => { + if (protocolIframe === iframe) { + protocolIframe = null; + } + iframe.remove(); + }; + const timer = setTimeout(() => { cleanup(); - iframe.remove(); + revokeMessageSourceTrustAndRemove(); reject(new Error("Shared host iframe timed out while loading")); }, IFRAME_LOAD_TIMEOUT_MS); const onLoad = (): void => { cleanup(); - protocolIframe = iframe; resolve(); }; const onError = (): void => { cleanup(); - iframe.remove(); + revokeMessageSourceTrustAndRemove(); reject(new Error("Shared host iframe failed to load")); }; @@ -376,7 +387,7 @@ function createHostIframe(): Promise { iframe.addEventListener("load", onLoad, { once: true }); iframe.addEventListener("error", onError, { once: true }); - document.body.appendChild(iframe); + trustAsMessageSourceAndAttach(); }); } From 9c611d5be0cddb6c3ef012f67139abd7c3cef865 Mon Sep 17 00:00:00 2001 From: Ryan Lee Date: Sat, 15 Aug 2026 00:58:52 +0000 Subject: [PATCH 18/18] test(protocol): make the source-window guard test fail on a reverted guard MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The previous test hardcoded `http://host.localhost:5173` as the message origin, but the protocol origin resolves to port 3000. The origin check rejected the event before it ever reached the source-window check, so the test passed under both the strict and the permissive guard and defended nothing — reverting the guard left the whole suite green. It now calls `getProtocolOrigin()` and asserts the exploit the guard exists to stop: an untrusted window forging a shared-auth broadcast into every subscriber after teardown. Reverting the guard fails this test. --- .../tests/client-chain-provider.test.ts | 36 +++++++++++-------- 1 file changed, 22 insertions(+), 14 deletions(-) diff --git a/packages/protocol/tests/client-chain-provider.test.ts b/packages/protocol/tests/client-chain-provider.test.ts index f3222adb..84a8fc89 100644 --- a/packages/protocol/tests/client-chain-provider.test.ts +++ b/packages/protocol/tests/client-chain-provider.test.ts @@ -11,10 +11,14 @@ */ import { afterEach, beforeEach, describe, expect, it, vi } from "vitest"; +import { SITE_ID } from "@dotli/config/config"; +import { SHARED_CORE_SESSION_KEY } from "@dotli/protocol/auth-storage"; import { createRemoteChainProvider, + getProtocolOrigin, isRemoteChainSupported, resetProtocolFrame, + subscribeSharedAuthStorage, } from "@dotli/protocol/client"; import { createTestDApp, @@ -211,36 +215,40 @@ describe("Remote chain provider lifecycle and request routing", () => { expect(dApp.replies()).toHaveLength(0); }); - it("discards incoming window messages when protocol frame is not mounted or has no frameWindow", async () => { - // Given: Frame is booted, connection established and initial request answered + it("rejects broadcasts from an untrusted window once the protocol frame is torn down", async () => { + // Given: Frame is booted, a chain connection established, and a shared-auth listener subscribed const dApp = createTestDApp(); dApp.send(Rpc.request(1)); await frame.bootAndConnect(); - const connId = frame.connectionId(); - frame.chainMessage(connId, Rpc.response(1, "ok")); - await elapse(10); - // Tear down protocol frame so protocolIframe is null + const forgedChanges: unknown[] = []; + const unsubscribe = subscribeSharedAuthStorage((change) => { + forgedChanges.push(change); + }); + + // When: The frame is torn down and an untrusted window posts a forged + // broadcast with a valid origin + const trustedOrigin = getProtocolOrigin(); resetProtocolFrame(); await elapse(10); - const countBefore = dApp.replies().length; - // When: PostMessage dispatched with valid origin and source=window (not frameWindow) window.dispatchEvent( new MessageEvent("message", { - origin: "http://host.localhost:5173", + origin: trustedOrigin, data: { namespace: "dotli:protocol", - kind: "chain-message", - connectionId: connId, - message: JSON.stringify({ jsonrpc: "2.0", id: 2, result: "stale" }), + kind: "auth-storage-changed", + siteId: SITE_ID, + key: SHARED_CORE_SESSION_KEY, + value: "attacker-injected-session", }, source: window, }), ); await elapse(10); - // Then: Message is ignored because protocolIframe is null and source !== frameWindow - expect(dApp.replies().length).toBe(countBefore); + // Then: The forged broadcast never reaches the subscriber + unsubscribe(); + expect(forgedChanges).toEqual([]); }); });