diff --git a/README.md b/README.md index dcf5ca6..4d75b97 100644 --- a/README.md +++ b/README.md @@ -104,12 +104,23 @@ allowed. That interception covers the MV3 background service worker as well as the popup page, which it does not by default — `script/test-e2e` sets `PW_EXPERIMENTAL_SERVICE_WORKER_NETWORK_EVENTS=1` for it. Because that flag is -experimental, the harness does not take it on trust: at launch it fetches a -`.invalid` URL from inside the service worker that only the route handler can -answer, and aborts the entire suite if the answer does not come back. Escaping -traffic fails the run instead of disappearing. To see what is actually being -intercepted, run with `E2E_TRACE_NETWORK=1` and every routed request is printed, -tagged `[sw]` or `[page]`. +experimental, the harness does not take it on trust. At launch it waits for the +background worker's **own** startup request — the phishing blocklist fetch that +`src/background/index.js` issues unconditionally — to arrive in the route +handler, and aborts the entire suite if none does within 30 seconds +(`tests/e2e/harness.js`). The check is passive on purpose: a synthetic probe +fetched from inside the worker via `worker.evaluate()` was tried first and +rejected, because evaluating in an extension service worker that early kills the +worker outright, destroying the thing being measured. Observing traffic the +extension already generates perturbs nothing. Losing the race fails closed — the +suite refuses to run rather than passing quietly. + +As defence in depth, Chrome is also started with +`--host-resolver-rules=MAP * ~NOTFOUND`, so a request that ever did slip past +the route handler could not resolve a host at all. That only bounds the damage; +detecting escaping traffic remains the canary's job. To see what is actually +being intercepted, run with `E2E_TRACE_NETWORK=1` and every routed request is +printed, tagged `[sw]` or `[page]`. **Any uncaught page error or `console.error` fails the run.** That is the point: a `ReferenceError` from a used-but-not-imported identifier is invisible to diff --git a/tests/e2e/harness.js b/tests/e2e/harness.js index 24e3da6..0a55a97 100644 --- a/tests/e2e/harness.js +++ b/tests/e2e/harness.js @@ -39,23 +39,55 @@ function isAllowed(text) { return ALLOWED_ERRORS.some((a) => a.pattern.test(text)); } +// Collects every uncaught page error, console.error and unstubbed +// request, and hands each one to exactly one reporter. +// +// This deliberately has NO window API. It used to expose mark()/since() +// so a test could ask for "the errors since I started", and that shape +// produced a green run that proved nothing twice over: first the mark +// started after test 1, so everything recorded during launch was +// discarded, then the tail after the final test was never read at all. In +// both cases a record fell outside somebody's window and vanished, which +// is the precise failure this harness exists to prevent. +// +// So there is no window left to fall outside of. take() is the only +// reader and it always takes everything outstanding, so successive takes +// partition the entire record stream with no gaps. seal() closes the +// stream once the run is over and routes anything later straight to a +// callback rather than into a list nobody reads again. Attribution is +// therefore total by construction, and the runner turns every attributed +// record into a failure. class ErrorCollector { constructor() { this.entries = []; + this.taken = 0; + this.onLate = null; } record(kind, text) { const line = kind + ": " + String(text).split("\n")[0]; if (isAllowed(line)) return; + if (this.onLate) { + // Sealed: no test and no suite phase is left to attribute + // this to, so hand it over now instead of accumulating it + // where nothing will look. + this.onLate(line); + return; + } this.entries.push(line); } - mark() { - return this.entries.length; + // Everything recorded since the previous take(). Never yields a + // record twice and never skips one. + take() { + const out = this.entries.slice(this.taken); + this.taken = this.entries.length; + return out; } - since(mark) { - return this.entries.slice(mark); + // Close the stream: later records go to onLate instead of the list. + seal(onLate) { + this.onLate = onLate; } } @@ -89,8 +121,16 @@ async function serviceWorker(ctx) { } // How long to wait for the background worker's first outbound request. -// Measured at roughly 650ms after the route is installed; the margin is -// for a loaded machine, not for hope. +// +// The margin that actually decides whether this check is sound is not +// this timeout — it is whether the route handler is installed before the +// worker fetches. Measured over several runs: route installation +// completes 11-23ms after the context comes up, and the worker's +// blocklist fetch arrives 525-883ms after that, so the route wins by +// roughly 25-50x. This 30s figure is only slack for a loaded machine on +// top of that; losing the race fails the run rather than passing it +// quietly, which was verified by forcing a 3s delay before route +// installation. const WORKER_TRAFFIC_TIMEOUT_MS = 30000; // ctx.route() only sees service-worker requests when Playwright runs with @@ -115,19 +155,29 @@ async function assertWorkerTrafficIntercepted(stubs) { ); if (seen) return seen; + // State the observation, not a conclusion. This fires for at least + // two quite different causes and the harness cannot tell them apart + // from here, so guessing one of them in the message sends the reader + // the wrong way. throw new Error( - "no service-worker request reached the route handler within " + + "observed no service-worker request in the route handler within " + WORKER_TRAFFIC_TIMEOUT_MS + - "ms, so background worker traffic is escaping this harness and " + - "going to the real internet. Run the suite through " + - "script/test-e2e, which sets " + - "PW_EXPERIMENTAL_SERVICE_WORKER_NETWORK_EVENTS=1. If a " + - "Playwright upgrade dropped that flag, replace the mechanism or " + - "downgrade the isolation claims in tests/e2e/network.js and " + - "README.md — do not delete this check. If instead the " + - "background worker legitimately stopped making startup " + - "requests, this check needs a new anchor, because there is no " + - "longer any worker traffic to observe", + "ms. Under working interception the background worker's " + + "startup blocklist fetch (src/background/index.js) reaches the " + + "handler about half a second after the route is installed. " + + "Two causes are plausible and this check cannot distinguish " + + "them: (1) service-worker interception is not in effect, so " + + "that traffic went to the real internet unobserved — the suite " + + "must be run through script/test-e2e, which sets " + + "PW_EXPERIMENTAL_SERVICE_WORKER_NETWORK_EVENTS=1, and a " + + "Playwright upgrade may have dropped or renamed that flag; " + + "(2) no worker request was made in the first place — the route " + + "lost the startup race, or the worker no longer fetches at " + + "startup, in which case this check needs a new anchor because " + + "there is no longer any worker traffic to observe. Either way " + + "the fix is a replacement mechanism or an honest downgrade of " + + "the isolation claims in tests/e2e/network.js and README.md — " + + "not deleting this check", ); } diff --git a/tests/e2e/network.js b/tests/e2e/network.js index f5abf0e..413a45b 100644 --- a/tests/e2e/network.js +++ b/tests/e2e/network.js @@ -146,6 +146,33 @@ function handleRpc(route, postData, report) { return jsonResponse(route, Array.isArray(payload) ? replies : replies[0]); } +const TRACE_TRUE = ["1", "true", "yes", "on"]; +const TRACE_FALSE = ["", "0", "false", "no", "off"]; + +// Whether E2E_TRACE_NETWORK asks for the request trace. +// +// A set-but-unrecognised value is a hard error rather than a quiet +// "off": E2E_TRACE_NETWORK=true asking for a trace and getting silence +// is the operator being lied to about what the harness is doing, which +// is the whole failure mode this suite exists to eliminate. Refusing to +// guess costs one line and one obvious error message. +function traceEnabled(raw) { + if (raw === undefined || raw === null) return false; + const v = String(raw).trim().toLowerCase(); + if (TRACE_TRUE.includes(v)) return true; + if (TRACE_FALSE.includes(v)) return false; + throw new Error( + "E2E_TRACE_NETWORK is set to " + + JSON.stringify(String(raw)) + + ", which is not a recognised on/off value. Use one of " + + TRACE_TRUE.join(", ") + + " to enable the request trace, or one of " + + TRACE_FALSE.slice(1).join(", ") + + " to disable it. Refusing to guess: a diagnostic that silently " + + "does nothing is worse than one that is not there", + ); +} + /** * Route every http(s) request through local fixtures. * @@ -174,7 +201,7 @@ async function installNetworkStubs(ctx, opts) { // showing up with an [sw] tag is the proof that the worker really is // intercepted and that the raw.githubusercontent.com stub below is // live code rather than decoration. - const trace = process.env.E2E_TRACE_NETWORK === "1"; + const trace = traceEnabled(process.env.E2E_TRACE_NETWORK); // Regex rather than a glob so chrome-extension:// resource loads are // never touched — routing those would break the popup itself. diff --git a/tests/e2e/run.js b/tests/e2e/run.js index 8fc6a49..f20f0a9 100644 --- a/tests/e2e/run.js +++ b/tests/e2e/run.js @@ -20,6 +20,10 @@ const { STUB_TOKEN, STUB_TX_HASH } = require("./network"); const TEST_TIMEOUT_MS = 120000; +// How long to keep collecting after the final test returns; see the +// trailing drain in main(). +const TRAILING_WATCH_MS = 1500; + const tests = []; function test(name, fn) { @@ -152,13 +156,27 @@ async function main() { page: null, }; + // Attribution of collected errors is total. session.errors has no + // window API at all: take() always drains everything outstanding, so + // successive takes partition the whole stream, and the phases below + // cover the entire life of the run. Nothing the collector holds can + // go unread. + // + // launch .. end of test 1 -> test 1 (so the worker's startup + // fetches land on a test, not + // nowhere) + // end of test k .. end of k+1 -> test k+1 + // last test .. teardown -> the suite, via the trailing drain + // after the trailing drain -> seal(), which fails on the spot + // + // Two green-but-vacuous runs on this harness were the same shape: a + // record falling outside somebody's window and being dropped. First + // the mark started after test 1, discarding launch-time records; + // then the tail after the last test was never read. Patching a + // second boundary would have invited a third, so the window concept + // is gone rather than fixed. let failed = 0; let n = 0; - // Starts at zero rather than at the current mark on purpose: errors - // and escaping requests recorded during launch — before any test ran, - // which is when the background worker does its startup fetches — are - // attributed to the first test instead of being discarded. - let mark = 0; for (const t of tests) { n += 1; let failure = null; @@ -168,11 +186,10 @@ async function main() { failure = e.message; } - // Any uncaught page error or console.error fails the test that - // provoked it, whether or not its assertions passed. This is the - // mechanism that caught #150. - const newErrors = session.errors.since(mark); - mark = session.errors.mark(); + // Any uncaught page error, console.error or unstubbed request + // fails the test that provoked it, whether or not its assertions + // passed. This is the mechanism that caught #150. + const newErrors = session.errors.take(); if (!failure && newErrors.length > 0) { failure = "uncaught browser errors during this test"; } @@ -189,12 +206,58 @@ async function main() { } } + // Keep watching after the last test returns, before tearing the + // browser down. A request a test fires without awaiting is still in + // flight when its function resolves; measured here it reaches the + // route handler about 10ms later, but closing the context does not + // wait for it — with no window at all the request dies unobserved + // and the run goes green, which is exactly how escaping traffic + // stays invisible. + // + // A fixed bounded window rather than a quiescence poll on purpose: + // the collector being quiet is not evidence, because a request that + // has not been dispatched yet has recorded nothing to be quiet + // about. Playwright offers no "is anything in flight" question to + // ask either — the route handler is the only observation point — so + // a grace period is the mechanism available, and this one is ~150x + // the measured latency for 1.5s on a ~25s suite. + await new Promise((resolve) => setTimeout(resolve, TRAILING_WATCH_MS)); + await session.close(); + // The tail. These cannot be blamed on any single test, so they are + // reported against the suite rather than guessed at — but they are + // reported, and they fail the run. + const trailing = session.errors.take(); + + // From here the run is over and there is nothing left to attribute a + // record to, so stragglers fail immediately instead of piling up + // where nothing will read them. + let late = 0; + session.errors.seal((line) => { + late += 1; + console.log("# FAILED: browser error recorded after the run ended"); + console.log("# " + line); + process.exitCode = 1; + }); + console.log( - "# " + (tests.length - failed) + "/" + tests.length + " passed", + "# " + (tests.length - failed) + "/" + tests.length + " tests passed", ); - if (failed > 0) { + + if (trailing.length > 0) { + console.log( + "# " + + trailing.length + + " browser error(s) recorded after the last test finished, " + + "not attributable to any single test:", + ); + for (const line of trailing) { + console.log("# " + line); + } + } + + if (failed > 0 || trailing.length > 0 || late > 0) { console.log("# FAILED"); process.exitCode = 1; }