fix(harness): restore the close-routing guard PR #61 dropped, on a faked clock
Adversarial review of PR #61 found one real coverage loss, and it is the defect class that PR's own body names: an assertion that survives the deletion of the thing it was about. `shell.spec.js` lost "a socket that opened and then dropped reads as disconnected, and stays that way" and both MutationObserver negative assertions. Reverting PR #21's routing half in `web/app.js` — the socket `error` and `close` arms calling `setShell` instead of `fail` — left the node suite 26/26 and Playwright 13/13 green. `shell.test.js` cannot cover it, and why is the whole boundary argument: "a loud failure DISARMS the watchdog" tests `createShell` in isolation and cannot see whether `app.js` ROUTES the close event through `fail()`. That routing is the half gotcha 48 says keeps getting lost; this was the third time, after two earlier mis-confirmations that simulated the `opened` flag and not the routing. Both tests are back under their original names, so the two `####` headings in context/test-evidence/clients.md name live tests again. They cost ~75ms each rather than ~9s, because `page.clock` fakes the PAGE's timers: the page, the socket, the listeners and the `setTimeout` call are all real and only the passage of time is simulated. That is not a weakening, and the injections are the proof in both directions — if `runFor` did not advance the page's timers, a broken routing could not surface the watchdog's message and they would pass: - both arms reverted to `setShell` -> "…and stays that way" fails - close arm only -> "…and stays that way" fails - close arm drops the `opened` flag -> "…the watchdog stays out of it" fails Three injections, three outcomes, none of them the unit test. The helper guards its own premise, because it turned out not to: `runFor` without `clock.install()` does nothing AND throws nothing, so a test that forgot the install asserted "the watchdog never spoke" against a watchdog that never ran — 6/6 green. `outlastTheWatchdog` now requires the page's own `Date.now()` to have moved, and that omission fails by name. Also: `render_surface.test.js` matched `model.<field>` over source INCLUDING comments, so un-painting a field and mentioning it in a comment passed — demonstrated against the pre-fix version, then fixed and re-demonstrated. And the PR's speed claim is corrected where it is documented. The eleven deleted per-widget tests cost 3.3s between them against 3.4s for the three contract tests replacing them: they were free. Essentially all of 36.9s -> 15.5s was two real-timer waits, one of them this guard. The wait was the cost, not the test. Filed, not fixed: improvise-igxp (the help overlay's rows are asserted as present, never as content — inherited verbatim from the test contract.spec.js replaced) and improvise-4ktt (the js job's bundle-freedom is a shell-glob convention, not a gate). The `####`-vs-`###` blind spot in --check-evidence, which is why the dangling heading survived the gate, is a comment on improvise-r0qa. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
This commit is contained in:
+28
-6
@@ -1189,9 +1189,20 @@ it about", and the browser half has four:
|
|||||||
|---|---|---|
|
|---|---|---|
|
||||||
| `RenderModel` → DOM | every field the render model projects reaches an element | `web/tests/render_surface.test.js` (statically) **and** `harness/tests/contract.spec.js` (on the screen) |
|
| `RenderModel` → DOM | every field the render model projects reaches an element | `web/tests/render_surface.test.js` (statically) **and** `harness/tests/contract.spec.js` (on the screen) |
|
||||||
| JS → wasm | the calls the page makes exist, with the arity the bundle declares, and their answers are painted | `web/tests/bundle/wasm_surface.test.js` (the surface) **and** `contract.spec.js`'s pointer test (the wiring) |
|
| JS → wasm | the calls the page makes exist, with the arity the bundle declares, and their answers are painted | `web/tests/bundle/wasm_surface.test.js` (the surface) **and** `contract.spec.js`'s pointer test (the wiring) |
|
||||||
| page → peer | the handshake goes out first, a frame is answered whole, and a failure is named | `harness/tests/shell.spec.js`, `harness/tests/drill.spec.js` |
|
| page → peer | the handshake goes out first, a frame is answered whole, a failure is named, **and the page routes each failure through the call that disarms the watchdog** | `harness/tests/shell.spec.js`, `harness/tests/drill.spec.js` |
|
||||||
| worker → OPFS | `storage_contract`, run against a real `OpfsFs` | `harness/tests/opfs.spec.js` |
|
| worker → OPFS | `storage_contract`, run against a real `OpfsFs` | `harness/tests/opfs.spec.js` |
|
||||||
|
|
||||||
|
**A unit test of a rule does not test the wiring that reaches it**, and the
|
||||||
|
sharpest case in this file is the watchdog. `shell.test.js` proves that
|
||||||
|
`createShell.fail()` disarms rather than pre-empts; it cannot prove that
|
||||||
|
`app.js`'s socket `close` and `error` listeners call `fail()` rather than
|
||||||
|
`setShell()`. That routing is PR #21's other half, the one gotcha 48 says keeps
|
||||||
|
getting lost — and PR #61 lost it a third time by keeping the unit test and
|
||||||
|
dropping the browser assertion, with 26/26 and 13/13 green. Restored, and the
|
||||||
|
rule generalises: **when a unit test replaces a boundary test, ask which of the
|
||||||
|
two the regression would have been in.** Here it is the routing, so the guard
|
||||||
|
stays in Playwright.
|
||||||
|
|
||||||
Everything **between** those seams is `node --test web/tests`, and it may assume
|
Everything **between** those seams is `node --test web/tests`, and it may assume
|
||||||
the boundary holds rather than re-establishing it: transport selection from
|
the boundary holds rather than re-establishing it: transport selection from
|
||||||
`?ws=`, the two facts `#status` composes, the watchdog's arm and disarm, the
|
`?ws=`, the two facts `#status` composes, the watchdog's arm and disarm, the
|
||||||
@@ -1242,12 +1253,23 @@ Measured on one machine at `1af51c9` versus this branch, both on a private
|
|||||||
| suite | tests | execution | whole job |
|
| suite | tests | execution | whole job |
|
||||||
|---|---|---|---|
|
|---|---|---|---|
|
||||||
| Playwright, before | 29 (+3 skipped) | 36.9s | ~4m30s in CI |
|
| Playwright, before | 29 (+3 skipped) | 36.9s | ~4m30s in CI |
|
||||||
| Playwright, after | 16 (+3 skipped) | 15.7s | ~4m30s in CI |
|
| Playwright, after | 18 (+3 skipped) | ~16s | ~4m30s in CI |
|
||||||
| `node --test web/tests` | 26 | 0.11s | seconds |
|
| `node --test web/tests` | 26 | 0.12s | seconds |
|
||||||
|
|
||||||
**Cutting Playwright tests barely moves the CI number**, because roughly four
|
**Where that saving actually came from is worth stating, because the obvious
|
||||||
minutes of that job is three `wasm-pack` builds, `npm ci` and a browser
|
answer is wrong.** The eleven per-widget tests that were deleted cost **3.3
|
||||||
download — not test execution. The feedback-time win is the `js` job, which
|
seconds between them** — restored verbatim and re-measured — against 3.4s for
|
||||||
|
the three contract tests that replace them. They were free. Essentially all of
|
||||||
|
36.9s → 15.5s was two `shell.spec.js` tests that **waited out the 8s watchdog in
|
||||||
|
real time**, and one of those two was the routing guard this section now
|
||||||
|
explains should never have gone. So the deletion of the eleven bought shape, not
|
||||||
|
speed; the speed came from a deletion that cost coverage. Both are now back, at
|
||||||
|
~75ms each, because `page.clock` fakes the page's timers — which is the honest
|
||||||
|
version of the trade: *the wait was the cost, not the test.*
|
||||||
|
|
||||||
|
**Cutting Playwright tests barely moves the CI number** in any case, because
|
||||||
|
roughly four minutes of that job is three `wasm-pack` builds, `npm ci` and a
|
||||||
|
browser download — not test execution. The feedback-time win is the `js` job, which
|
||||||
needs **no Rust toolchain and no wasm bundle at all**, and that is a constraint
|
needs **no Rust toolchain and no wasm bundle at all**, and that is a constraint
|
||||||
rather than an accident: the moment a `web/tests/*.test.js` file needs
|
rather than an accident: the moment a `web/tests/*.test.js` file needs
|
||||||
`web/pkg/`, it inherits the four-minute build and the argument for it
|
`web/pkg/`, it inherits the four-minute build and the argument for it
|
||||||
|
|||||||
@@ -538,8 +538,9 @@ handshake with a frame the client cannot fold — so this exercises the real
|
|||||||
|
|
||||||
improvise-hwpi: without an `error` listener, a connection that never opened left
|
improvise-hwpi: without an `error` listener, a connection that never opened left
|
||||||
`#status` blank, and "the server is not running" read exactly like "still
|
`#status` blank, and "the server is not running" read exactly like "still
|
||||||
connecting". The watchdog half is asserted on the same page load rather than in
|
connecting". The watchdog half is asserted on the same page load, and since
|
||||||
its own test, because it needs the same nine-second wait. It holds for a reason
|
PR #61's follow-up it costs no wall clock at all: `page.clock` fakes the PAGE's
|
||||||
|
timers, so `runFor(10s)` advances the watchdog without the test sleeping. It holds for a reason
|
||||||
its own comment does not lead you to expect: `armWatchdog` runs only after
|
its own comment does not lead you to expect: `armWatchdog` runs only after
|
||||||
`transport.ready` resolves, which happens on `open` — so on a socket that never
|
`transport.ready` resolves, which happens on `open` — so on a socket that never
|
||||||
opened the watchdog is never armed at all.
|
opened the watchdog is never armed at all.
|
||||||
@@ -550,7 +551,8 @@ The other arm, which must keep working when the first is fixed: a socket that
|
|||||||
really did open and then dropped IS a disconnect, and saying so is the whole
|
really did open and then dropped IS a disconnect, and saying so is the whole
|
||||||
reason `close` cannot simply be suppressed.
|
reason `close` cannot simply be suppressed.
|
||||||
|
|
||||||
**It runs past `HANDSHAKE_TIMEOUT_MS` on purpose.** On this arm the watchdog IS
|
**It runs past `HANDSHAKE_TIMEOUT_MS` on purpose** — through `page.clock`, not
|
||||||
|
through a real wait. On this arm the watchdog IS
|
||||||
armed — `armWatchdog` runs after `transport.ready` resolves, i.e. on `open` — so
|
armed — `armWatchdog` runs after `transport.ready` resolves, i.e. on `open` — so
|
||||||
"disconnected" is written while a timer is pending, and the only reason it
|
"disconnected" is written while a timer is pending, and the only reason it
|
||||||
survives is that `close` goes through `setShellFailure`, which clears it. That
|
survives is that `close` goes through `setShellFailure`, which clears it. That
|
||||||
@@ -566,6 +568,35 @@ assertion rather than another paragraph — proved discriminating by making
|
|||||||
`setShellFailure` skip its `clearTimeout`, which makes it fail. Same rule as
|
`setShellFailure` skip its `clearTimeout`, which makes it fail. Same rule as
|
||||||
`doctrine(an_injected_fault_must_be_the_fault_you_named)`, one level up.
|
`doctrine(an_injected_fault_must_be_the_fault_you_named)`, one level up.
|
||||||
|
|
||||||
|
**And it was lost a third time, by the PR that was arguing about exactly this.**
|
||||||
|
PR #61 split the browser tests into boundary contracts (Playwright) and unit
|
||||||
|
tests (`node --test`), and merged these two tests into one that kept only the
|
||||||
|
last-value assertions. `shell.test.js`'s "a loud failure DISARMS the watchdog"
|
||||||
|
covers `createShell` in isolation and **cannot see whether `app.js` routes the
|
||||||
|
close event through `fail()` rather than `setShell()`** — which is the half
|
||||||
|
PR #21 fixed and the half that keeps getting lost. Reverting both socket arms
|
||||||
|
to `setShell` left the node suite 26/26 and Playwright 13/13 green. Restored
|
||||||
|
under their original names, and re-proved with that exact revert: the two-arm
|
||||||
|
revert and the close-arm-only revert each fail "…and stays that way", and
|
||||||
|
dropping the `opened` flag fails "…the watchdog stays out of it". **Three
|
||||||
|
injections, three different tests, none of them the unit test.**
|
||||||
|
|
||||||
|
**And the helper guards its own premise.** `page.clock.runFor` on a page where
|
||||||
|
`clock.install()` was never called does **nothing and throws nothing**, so a test
|
||||||
|
that forgot the install would assert "the watchdog never spoke" against a
|
||||||
|
watchdog never given the chance — vacuous, and green. `outlastTheWatchdog` reads
|
||||||
|
`Date.now()` inside the page either side of the jump and requires it to have
|
||||||
|
moved. Demonstrated both ways: with the install removed the suite passed 6/6,
|
||||||
|
and with the guard in place the same omission fails by name.
|
||||||
|
|
||||||
|
**The faked clock is what makes the restoration cheap without weakening it**,
|
||||||
|
and the injections are the proof of that too: if `page.clock.runFor` did not
|
||||||
|
really advance the page's timers, a broken routing could not surface the
|
||||||
|
watchdog's message and those injections would have passed. They failed. The
|
||||||
|
test keeps the real page, the real socket, the real listeners and the real
|
||||||
|
`setTimeout` call — only the *passage of time* is simulated, and 9 seconds of
|
||||||
|
wall clock became 75 milliseconds.
|
||||||
|
|
||||||
**The measurement that could not become a CI guard.** Both of the above were once
|
**The measurement that could not become a CI guard.** Both of the above were once
|
||||||
asserted as `test.fail` expected-failures and **had to be removed**: neither
|
asserted as `test.fail` expected-failures and **had to be removed**: neither
|
||||||
reproduced on the GitHub runner, where `close` does not follow `error` within the
|
reproduced on the GitHub runner, where `close` does not follow `error` within the
|
||||||
@@ -1164,6 +1195,11 @@ Every test below was proved able to fail by patching the code it names,
|
|||||||
checking the patch was on disk, running the suite and reading the failure —
|
checking the patch was on disk, running the suite and reading the failure —
|
||||||
never by the absence of an error. Thirteen injections, thirteen failures:
|
never by the absence of an error. Thirteen injections, thirteen failures:
|
||||||
|
|
||||||
|
**What `shell.test.js` cannot reach, and the PR found out the hard way:** it
|
||||||
|
tests `createShell` in isolation, so it sees the watchdog RULE and never the
|
||||||
|
`app.js` wiring that calls it. That distinction is now written into
|
||||||
|
`context/code/clients.md` and guarded in `shell.spec.js`.
|
||||||
|
|
||||||
**`shell.test.js`** — `socketUrl` stops upgrading `ws://` on an https page;
|
**`shell.test.js`** — `socketUrl` stops upgrading `ws://` on an https page;
|
||||||
`composeStatus` returns the model fact alone (which fails five tests, because
|
`composeStatus` returns the model fact alone (which fails five tests, because
|
||||||
the watchdog's messages are shell facts and vanish with it); `fail()` stops
|
the watchdog's messages are shell facts and vanish with it); `fail()` stops
|
||||||
|
|||||||
@@ -11,10 +11,38 @@ const status = (page) => page.locator("#status");
|
|||||||
/// the harness's OWN server, so it follows the port the config chose.
|
/// the harness's OWN server, so it follows the port the config chose.
|
||||||
const NO_WEBSOCKET_HERE = `127.0.0.1:${process.env.IMPROVISE_HARNESS_PORT ?? "8099"}`;
|
const NO_WEBSOCKET_HERE = `127.0.0.1:${process.env.IMPROVISE_HARNESS_PORT ?? "8099"}`;
|
||||||
|
|
||||||
/// `web/app.js`'s own HANDSHAKE_TIMEOUT_MS. One test has to outlast it, and a
|
/// `web/app.js`'s own HANDSHAKE_TIMEOUT_MS. Three tests have to outlast it, and
|
||||||
/// number that silently disagreed with the page would pass for the wrong reason.
|
/// a number that silently disagreed with the page would pass for the wrong reason.
|
||||||
const HANDSHAKE_TIMEOUT_MS = 8_000;
|
const HANDSHAKE_TIMEOUT_MS = 8_000;
|
||||||
|
|
||||||
|
/// Record every distinct #status the page shows, not just the last one: the
|
||||||
|
/// properties below are about a message being REPLACED, which a final read
|
||||||
|
/// cannot see. Installed before the page's own script runs.
|
||||||
|
function logStatus() {
|
||||||
|
window.__statusLog = [];
|
||||||
|
new MutationObserver(() => {
|
||||||
|
const text = document.getElementById("status")?.textContent ?? "";
|
||||||
|
if (text && window.__statusLog.at(-1) !== text) window.__statusLog.push(text);
|
||||||
|
}).observe(document, { childList: true, subtree: true, characterData: true });
|
||||||
|
}
|
||||||
|
|
||||||
|
const json = (v) => JSON.stringify(v);
|
||||||
|
|
||||||
|
/// Walk past the watchdog without waiting for it. `page.clock` fakes the
|
||||||
|
/// page's own timers, so the 8s is the PAGE's and the wall clock is not.
|
||||||
|
async function outlastTheWatchdog(page) {
|
||||||
|
const jump = HANDSHAKE_TIMEOUT_MS + 2_000;
|
||||||
|
const before = await page.evaluate(() => Date.now());
|
||||||
|
await page.clock.runFor(jump);
|
||||||
|
// `runFor` without `clock.install()` does NOTHING and throws nothing, so a
|
||||||
|
// test that forgot it would assert "the watchdog never spoke" vacuously.
|
||||||
|
const after = await page.evaluate(() => Date.now());
|
||||||
|
expect(
|
||||||
|
after - before,
|
||||||
|
"page.clock.install() was not called: the page's timers never advanced",
|
||||||
|
).toBeGreaterThanOrEqual(jump);
|
||||||
|
}
|
||||||
|
|
||||||
test.describe("the shell reports what its peer is doing", () => {
|
test.describe("the shell reports what its peer is doing", () => {
|
||||||
// improvise-hwpi. The fault is injected at the *peer*, not in the page, so
|
// improvise-hwpi. The fault is injected at the *peer*, not in the page, so
|
||||||
// this exercises the real `on_frame` and the real catch.
|
// this exercises the real `on_frame` and the real catch.
|
||||||
@@ -26,15 +54,30 @@ test.describe("the shell reports what its peer is doing", () => {
|
|||||||
await expect(status(page)).toContainText("bad frame", { timeout: 15_000 });
|
await expect(status(page)).toContainText("bad frame", { timeout: 15_000 });
|
||||||
});
|
});
|
||||||
|
|
||||||
// A socket that never opened did not "disconnect" (improvise-taxx): nothing
|
// improvise-hwpi, plus the half `shell.test.js` cannot reach: that app.js
|
||||||
// on the close event can discriminate, so the page records `opened` itself.
|
// ROUTES this arm through `shell.fail`, which disarms the watchdog.
|
||||||
// That it then STAYS is the watchdog's disarming, which is Node's now.
|
test("a peer that cannot be reached is named, and the watchdog stays out of it", async ({
|
||||||
test("a peer that cannot be reached is named, and one that dropped is not confused with it", async ({
|
|
||||||
page,
|
page,
|
||||||
}) => {
|
}) => {
|
||||||
|
await page.clock.install();
|
||||||
|
await page.addInitScript(logStatus);
|
||||||
await page.goto(`/app/index.html?ws=${NO_WEBSOCKET_HERE}`);
|
await page.goto(`/app/index.html?ws=${NO_WEBSOCKET_HERE}`);
|
||||||
await expect(status(page)).toContainText("cannot reach", { timeout: 15_000 });
|
await expect(status(page)).toContainText("cannot reach", { timeout: 15_000 });
|
||||||
|
await outlastTheWatchdog(page);
|
||||||
|
|
||||||
|
const log = await page.evaluate(() => window.__statusLog);
|
||||||
|
expect(log.some((t) => t.includes("sent no document")), `#status said: ${json(log)}`).toBe(
|
||||||
|
false,
|
||||||
|
);
|
||||||
|
});
|
||||||
|
|
||||||
|
// The arm PR #21 fixed and that gotcha 48 says keeps getting lost: a socket
|
||||||
|
// that never opened did not "disconnect", and the one that did STAYS so.
|
||||||
|
test("a socket that opened and then dropped reads as disconnected, and stays that way", async ({
|
||||||
|
page,
|
||||||
|
}) => {
|
||||||
|
await page.clock.install();
|
||||||
|
await page.addInitScript(logStatus);
|
||||||
// Closes on the page's first frame, so "it opened first" is true by
|
// Closes on the page's first frame, so "it opened first" is true by
|
||||||
// construction rather than by timer.
|
// construction rather than by timer.
|
||||||
await page.routeWebSocket("ws://127.0.0.1:8790/", (ws) => {
|
await page.routeWebSocket("ws://127.0.0.1:8790/", (ws) => {
|
||||||
@@ -43,6 +86,16 @@ test.describe("the shell reports what its peer is doing", () => {
|
|||||||
await page.goto("/app/index.html?ws=127.0.0.1:8790");
|
await page.goto("/app/index.html?ws=127.0.0.1:8790");
|
||||||
await expect(status(page)).toContainText("connected", { timeout: 15_000 });
|
await expect(status(page)).toContainText("connected", { timeout: 15_000 });
|
||||||
await expect(status(page)).toContainText("disconnected", { timeout: 15_000 });
|
await expect(status(page)).toContainText("disconnected", { timeout: 15_000 });
|
||||||
|
|
||||||
|
// Past the watchdog it was armed against: the routing, not the rule, is
|
||||||
|
// what this can see and `shell.test.js` cannot.
|
||||||
|
await outlastTheWatchdog(page);
|
||||||
|
await expect(status(page)).toContainText("disconnected");
|
||||||
|
|
||||||
|
const log = await page.evaluate(() => window.__statusLog);
|
||||||
|
expect(log.some((t) => t.includes("sent no document")), `#status said: ${json(log)}`).toBe(
|
||||||
|
false,
|
||||||
|
);
|
||||||
});
|
});
|
||||||
|
|
||||||
// The one assertion that needs the real timer: that the watchdog is ARMED
|
// The one assertion that needs the real timer: that the watchdog is ARMED
|
||||||
|
|||||||
@@ -8,6 +8,13 @@ import { fileURLToPath } from "node:url";
|
|||||||
|
|
||||||
const read = (rel) => readFileSync(fileURLToPath(new URL(rel, import.meta.url)), "utf8");
|
const read = (rel) => readFileSync(fileURLToPath(new URL(rel, import.meta.url)), "utf8");
|
||||||
|
|
||||||
|
/// Comments name model fields routinely, so a field mentioned only in one
|
||||||
|
/// would read as painted. Strip them before asking what the code touches.
|
||||||
|
const code = (rel) =>
|
||||||
|
read(rel)
|
||||||
|
.replace(/\/\*[\s\S]*?\*\//g, " ")
|
||||||
|
.replace(/(^|[^:"'`])\/\/.*$/gm, "$1");
|
||||||
|
|
||||||
/// Fields the page deliberately does not read, each with the reason. A field
|
/// Fields the page deliberately does not read, each with the reason. A field
|
||||||
/// belongs here only with an argument; the list is the debt, written down.
|
/// belongs here only with an argument; the list is the debt, written down.
|
||||||
// improvise-z754 put the title bar's facts in one shared cache and taught
|
// improvise-z754 put the title bar's facts in one shared cache and taught
|
||||||
@@ -32,7 +39,7 @@ function renderModelFields() {
|
|||||||
|
|
||||||
test("every field the render model projects is painted, or named as debt", () => {
|
test("every field the render model projects is painted, or named as debt", () => {
|
||||||
// Both halves of the page: `app.js` paints, `shell.js` plans the grid.
|
// Both halves of the page: `app.js` paints, `shell.js` plans the grid.
|
||||||
const page = read("../app.js") + read("../shell.js");
|
const page = code("../app.js") + code("../shell.js");
|
||||||
const unpainted = renderModelFields().filter((field) => !page.includes(`model.${field}`));
|
const unpainted = renderModelFields().filter((field) => !page.includes(`model.${field}`));
|
||||||
assert.deepEqual(
|
assert.deepEqual(
|
||||||
unpainted.sort(),
|
unpainted.sort(),
|
||||||
|
|||||||
Reference in New Issue
Block a user