Compare commits

...
Author SHA1 Message Date
sneak 40d27b6f92 fix: a slow answer to an approval still reaches the site (closes #540)
check / check (push) Waiting to run
e2e / e2e-chrome (push) Waiting to run
e2e / e2e-firefox (push) Waiting to run
Chrome stopped the background worker about six minutes after a site's
request even with the approval window open, and the approval and the
site's waiting request went with it. The approval window now posts an
empty message on its approval port every 20 seconds while it is open;
each one is an event, which keeps the worker running.

tests/e2e/slowApproval.js, run by make test-e2e, leaves a transaction
and a signature approval open for seven minutes and requires the site
to receive both results. It drives Chromium over the DevTools pipe
without Playwright, because Playwright keeps DevTools attached to the
worker and Chrome then never stops it.

Model: opus-5-5
2026-10-14 10:08:11 +00:00
6 changed files with 560 additions and 4 deletions
+2 -2
View File
@@ -35,10 +35,10 @@ on: [push]
jobs:
e2e-chrome:
runs-on: ubuntu-latest
# Bounds the image build, a cold cache included, and both Chrome
# Bounds the image build, a cold cache included, and the three Chrome
# programs, so a hung browser frees the shared runner. README.md
# "In CI" has the measured times.
timeout-minutes: 20
timeout-minutes: 40
steps:
# actions/checkout v4.2.2, 2026-02-22
- uses: actions/checkout@11bd71901bbe5b1630ceea73d27597364c9af683
+32 -2
View File
@@ -527,6 +527,24 @@ one profile yields a single extension id, not two: Chrome does not load a second
copy of an id it already has. The assertions are annotated as observations, so a
Chrome that ever changes this fails the run instead of passing it.
Last, `make test-e2e` runs `tests/e2e/slowApproval.js`, which leaves a
transaction approval and a signature approval open for seven minutes, then
approves both and requires the site to receive the hash of the transaction the
stub node received and a signature that recovers to the address. Before the
approval window kept the background worker running, Chrome stopped it about six
minutes in and neither request was ever answered
([#540](https://git.eeqj.de/sneak/AutistMask/issues/540)). It is its own program
and does not use Playwright: Playwright keeps DevTools attached to the
background worker, and Chrome never stops a worker DevTools is attached to, so
no wait in the suite above can show the worker stopping. It starts Chromium
itself, speaks the DevTools protocol over `--remote-debugging-pipe`, and
attaches to pages only. Before raising the approvals it requires the worker to
stop on its own with nothing pending, so a run in which something else keeps the
worker running fails. The site is connected and the RPC endpoint set through the
extension's own screens, against the Firefox suite's loopback dApp page and stub
node (`tests/e2e/firefox/dapp.js`). Unlike the suite above, it does not fail on
page errors.
### Firefox (`make test-e2e-firefox`)
`make test-e2e-firefox` builds `dist/firefox/` and drives the **real popup in a
@@ -707,11 +725,13 @@ installing Firefox, geckodriver and their system libraries. Both scripts now
build their image with `--no-cache`, so every run pays the cold figure. Those
`e2e-chrome` runs predate the cases that wait in real time for a receipt to end
in error. `make test-e2e` took 3m51s locally with its image cached, so with the
image rebuilt every run, an `e2e-chrome` run comes to about seven minutes.
image rebuilt every run, an `e2e-chrome` run comes to about seven minutes. The
approvals left open for seven minutes (`tests/e2e/slowApproval.js`) add about
eight more, so about fifteen.
Each e2e job has a `timeout-minutes` cap, so a hung build or browser ends the
job instead of holding the shared runner: `e2e-firefox` 15 minutes and
`e2e-chrome` 20, each over two and a half times the job's slowest cold run. A
`e2e-chrome` 40, each over two and a half times the job's slowest cold run. A
job that reaches its cap has hung; read it as a hang, not as a slow run to
retry. The `check` job has no cap: `.gitea/workflows/check.yml` is the canonical
copy from `sneak/prompts`, kept byte-identical.
@@ -806,6 +826,16 @@ on the next event. Two consequences shape every recurring job in the background:
service worker at all — the one remaining user of it, `src/shared/ens.js`,
runs only in the popup and is marked as such.
Pending approvals are the exception: an approval waiting for the user, and the
site's request waiting on it, live only in the worker's memory, and only the
worker that received the request can answer it. Chrome stopped the worker about
six minutes after a site's request even with the approval window still open, and
the user's answer then reached nobody. So while an approval window is open it
posts an empty message on its approval port every 20 seconds, and each message
is an event that keeps the worker running: an approval stays answerable however
long the user takes. A worker that stops for another reason, a crash say, still
loses the approvals open in it.
The job also carries a freshness guard, and a guard must never be timed to the
alarm period it gates. The guard is measured from the moment the last run
finished, which is one run-duration after the alarm that started it, so a guard
+12
View File
@@ -97,6 +97,18 @@ main() {
-e HOME=/tmp \
"$(cat "$IIDFILE")" \
node tests/e2e/storagePartition.js
# Approvals left open for seven minutes, past the point where Chrome
# stopped the background worker before the approval window kept it
# running. Its own program, without Playwright: Playwright keeps DevTools
# attached to the worker, and Chrome never stops a worker DevTools is
# attached to. It reaches nothing but its own loopback server.
echo "Running the approvals left open for seven minutes..."
docker run --rm \
--ipc=host \
-e HOME=/tmp \
"$(cat "$IIDFILE")" \
node tests/e2e/slowApproval.js
}
main "$@"
+3
View File
@@ -649,6 +649,9 @@ runtime.onConnect.addListener((port) => {
pendingApprovals[id].portConnected = true;
}
port.onMessage.addListener((msg) => {
// The window also posts an empty message every 20 seconds while
// it is open, only so that Chrome keeps this worker, and the
// approval in it, running (src/popup/views/approval.js, show()).
if (!msg || msg.type !== "AUTISTMASK_APPROVAL_DECISION") return;
if (!isExtensionSender(port.sender)) return;
const approval = pendingApprovals[id];
+16
View File
@@ -784,6 +784,22 @@ async function show(id) {
approvalId = id;
approvalPort = runtimeApi().connect({ name: "approval:" + id });
// The approval this window answers, and the site's request waiting on it,
// exist only in the background worker's memory. Chrome stops that worker
// about six minutes after the site's request even while the user is still
// deciding, and the approval is lost with it. A message on this port is an
// event, and an event keeps the worker running, so one is sent every 20
// seconds for as long as this window is open. The background ignores it.
const port = approvalPort;
const timer = setInterval(() => {
try {
port.postMessage({});
} catch {
// The worker is gone anyway, and the port with it.
clearInterval(timer);
}
}, 20000);
let details = null;
try {
details = await sendMessage({ type: "AUTISTMASK_GET_APPROVAL", id });
+495
View File
@@ -0,0 +1,495 @@
// A transaction approval and a signature approval the user leaves open for
// seven minutes are still answered, and the site receives both results
// (https://git.eeqj.de/sneak/AutistMask/issues/540).
//
// Both approvals, and the site's requests waiting on them, live only in the
// background worker's memory. With nothing else going on, Chrome stopped that
// worker about six minutes after the site's request, while the window was
// still open, and the user's answer then reached nobody. The approval window
// now posts on its approval port every 20 seconds, which keeps the worker
// running (src/popup/views/approval.js, show()).
//
// A separate program from run.js, and not driven by Playwright: Playwright
// keeps DevTools attached to the background worker, and Chrome never stops a
// worker DevTools is attached to, so in run.js the worker outlives any wait
// and a wait there proves nothing. This program starts Chromium itself and
// speaks the DevTools protocol over the pipe Chromium opens for it
// (--remote-debugging-pipe), attaching to pages only, never to the worker.
// Before the approvals are raised it watches the worker stop on its own, so a
// run in which something else keeps the worker running cannot pass.
//
// The dApp page and the stub node are the Firefox suite's loopback ones
// (tests/e2e/firefox/dapp.js). The site is connected and the node chosen
// through the extension's own screens, so nothing is written to its storage
// from outside.
//
// Run through script/test-e2e, which builds the extension and the pinned
// container.
//
// node tests/e2e/slowApproval.js
"use strict";
const fs = require("fs");
const os = require("os");
const path = require("path");
const { spawn } = require("child_process");
const { chromium } = require("playwright-core");
const {
Transaction,
getAddress,
getBytes,
hexlify,
parseEther,
toQuantity,
toUtf8Bytes,
verifyMessage,
} = require("ethers");
const { PASSWORD } = require("./harness");
const { STUB_COUNTERPARTY } = require("./network");
const { startDappServer } = require("./firefox/dapp");
const DIST_CHROME = path.resolve(__dirname, "..", "..", "dist", "chrome");
// Chrome stopped the worker six minutes after the site's request when nothing
// kept it running, so the approvals are left open for longer than that.
const APPROVAL_WAIT_MS = 7 * 60 * 1000;
// With nothing pending, Chrome stops the worker 30 seconds after its last
// event; this is how long the program waits to see that.
const IDLE_STOP_TIMEOUT_MS = 90000;
const SIGN_HEX = hexlify(toUtf8Bytes("AutistMask e2e: a slow signature"));
const checks = [];
let failed = 0;
function check(name, cond, detail) {
checks.push(name);
if (cond) {
console.log("ok " + checks.length + " - " + name);
} else {
failed += 1;
console.log("not ok " + checks.length + " - " + name);
if (detail) console.log(" " + detail);
}
}
function sleep(ms) {
return new Promise((resolve) => setTimeout(resolve, ms));
}
// Poll `probe` until it returns something truthy, and return that.
async function until(what, probe, timeout = 30000) {
const deadline = Date.now() + timeout;
for (;;) {
const value = await probe().catch(() => null);
if (value) return value;
if (Date.now() > deadline) {
throw new Error(
"gave up after " + timeout + "ms waiting for " + what,
);
}
await sleep(250);
}
}
// The DevTools protocol over Chromium's pipe: commands go to its fd 3, and
// replies and events come back on its fd 4, each one JSON message ended by a
// NUL byte. Events are not used and are dropped. Returns send(method, params,
// sessionId), which resolves with the command's result.
function devtools(browser) {
const waiting = new Map();
let nextId = 1;
let pending = "";
const replies = browser.stdio[4];
replies.setEncoding("utf8");
replies.on("data", (chunk) => {
pending += chunk;
let end;
while ((end = pending.indexOf("\0")) !== -1) {
const message = JSON.parse(pending.slice(0, end));
pending = pending.slice(end + 1);
const caller = waiting.get(message.id);
if (!caller) continue;
waiting.delete(message.id);
if (message.error) {
caller.reject(
new Error(caller.method + ": " + message.error.message),
);
} else {
caller.resolve(message.result);
}
}
});
replies.on("close", () => {
for (const caller of waiting.values()) {
caller.reject(new Error("the browser exited"));
}
waiting.clear();
});
return (method, params = {}, sessionId) =>
new Promise((resolve, reject) => {
const id = nextId++;
waiting.set(id, { method, resolve, reject });
browser.stdio[3].write(
JSON.stringify({ id, method, params, sessionId }) + "\0",
);
});
}
// Attach to a page and return a function that evaluates an expression in it,
// awaiting a promise it returns, and resolves with the value.
async function attach(send, targetId) {
const { sessionId } = await send("Target.attachToTarget", {
targetId,
flatten: true,
});
return async (expression) => {
const r = await send(
"Runtime.evaluate",
{ expression, awaitPromise: true, returnByValue: true },
sessionId,
);
if (r.exceptionDetails) {
throw new Error(
"evaluating " +
expression.slice(0, 80) +
" threw: " +
JSON.stringify(r.exceptionDetails.exception || {}),
);
}
return r.result.value;
};
}
// Whether the page has loaded and shows the element with this id: the
// `hidden` class showView() keeps on every other view is on neither it nor
// anything around it.
function shows(id) {
return (
"document.readyState === 'complete' &&" +
" !!document.getElementById(" +
JSON.stringify(id) +
") && !document.getElementById(" +
JSON.stringify(id) +
").closest('.hidden')"
);
}
// Set an input's value and fire the input event typing would fire.
function typeInto(id, value) {
return (
"(() => { const el = document.getElementById(" +
JSON.stringify(id) +
"); el.value = " +
JSON.stringify(value) +
"; el.dispatchEvent(new Event('input', { bubbles: true })); })()"
);
}
function click(id) {
return "document.getElementById(" + JSON.stringify(id) + ").click()";
}
// The outcome of a request the dApp page started with __dapp.start(), or
// {settled: "pending"} if it has not settled within `timeout`.
function settled(key, timeout = 30000) {
return (
"Promise.race([window.__dapp.settle(" +
JSON.stringify(key) +
"), new Promise((r) => setTimeout(() => r({ settled: 'pending' }), " +
timeout +
"))])"
);
}
async function main() {
if (!fs.existsSync(path.join(DIST_CHROME, "manifest.json"))) {
console.error(
"slowApproval: no unpacked build at " +
DIST_CHROME +
" — run make build first",
);
process.exitCode = 1;
return;
}
const node = await startDappServer();
const profile = fs.mkdtempSync(
path.join(os.tmpdir(), "autistmask-slow-approval-"),
);
const browser = spawn(
chromium.executablePath(),
[
"--headless",
// The container runs unprivileged, as in harness.js.
"--no-sandbox",
"--remote-debugging-pipe",
"--user-data-dir=" + profile,
"--disable-extensions-except=" + DIST_CHROME,
"--load-extension=" + DIST_CHROME,
// Nothing but the loopback dApp page and stub node can be reached.
"--host-resolver-rules=MAP * ~NOTFOUND, EXCLUDE 127.0.0.1",
"about:blank",
],
{ stdio: ["ignore", "ignore", "ignore", "pipe", "pipe"] },
);
try {
const send = devtools(browser);
const targets = async () =>
(await send("Target.getTargets")).targetInfos;
const worker = await until("the background worker", async () =>
(await targets()).find(
(t) =>
t.type === "service_worker" &&
t.url.startsWith("chrome-extension://"),
),
);
// The extension id is the host of the worker's URL, as in harness.js.
const popupUrl =
"chrome-extension://" +
new URL(worker.url).host +
"/src/popup/index.html";
const workerRunning = async () =>
(await targets()).some((t) => t.url === worker.url);
const openPage = async (url) => {
const { targetId } = await send("Target.createTarget", { url });
return { targetId, evaluate: await attach(send, targetId) };
};
const approvalPages = async () =>
(await targets()).filter(
(t) => t.type === "page" && t.url.includes("?approval="),
);
// A wallet, through the popup's own screens, and the stub node as its
// RPC endpoint, through Settings.
const popup = await openPage(popupUrl);
await until("the welcome screen", () =>
popup.evaluate(shows("view-welcome")),
);
await popup.evaluate(click("btn-welcome-add"));
await until("the add wallet screen", () =>
popup.evaluate(shows("view-add-wallet")),
);
await popup.evaluate(click("btn-generate-phrase"));
await until("a generated recovery phrase", () =>
popup.evaluate(
"document.getElementById('wallet-mnemonic').value.trim()" +
".split(/\\s+/).length >= 12",
),
);
await popup.evaluate(typeInto("add-wallet-password", PASSWORD));
await popup.evaluate(typeInto("add-wallet-password-confirm", PASSWORD));
await popup.evaluate(click("btn-add-wallet-confirm"));
await until(
"the main screen",
() => popup.evaluate(shows("view-main")),
60000,
);
await popup.evaluate(click("btn-settings"));
await until("the settings screen", () =>
popup.evaluate(shows("view-settings")),
);
await popup.evaluate(typeInto("settings-rpc", node.rpcUrl));
await popup.evaluate(click("btn-save-rpc"));
await until("the stub node saved as the RPC endpoint", () =>
popup.evaluate(
"new Promise((resolve) => chrome.storage.local.get(" +
"'autistmask', (r) => resolve(r.autistmask.rpcUrl === " +
JSON.stringify(node.rpcUrl) +
")))",
),
);
await send("Target.closeTarget", { targetId: popup.targetId });
// The site, connected through the real prompt with "Remember", so
// the connection is stored rather than held by the worker.
const dapp = await openPage(node.url);
await until("the injected provider", () =>
dapp.evaluate("!!window.ethereum && !!window.__dapp"),
);
await dapp.evaluate(
"window.__dapp.start('accounts', 'eth_requestAccounts', [])",
);
const prompt = await until(
"the connection prompt",
async () => (await approvalPages())[0],
);
const inPrompt = await attach(send, prompt.targetId);
await until("the connection prompt's screen", () =>
inPrompt(shows("view-approve-site")),
);
await inPrompt(
"document.getElementById('approve-remember').checked = true",
);
// The prompt closes itself on the click.
await inPrompt(click("btn-approve")).catch(() => {});
const accounts = await dapp.evaluate(settled("accounts"));
if (accounts.settled !== "resolved") {
throw new Error(
"the site could not be connected: " + JSON.stringify(accounts),
);
}
const address = getAddress(accounts.result[0]);
console.log("# address " + address + ", site " + node.origin);
// The control: with nothing pending, the worker stops on its own.
// Were something else keeping it running, the wait below would
// prove nothing.
const idleStart = Date.now();
const stoppedWhenIdle = await until(
"the idle worker to stop",
async () => !(await workerRunning()),
IDLE_STOP_TIMEOUT_MS,
).catch(() => false);
check(
"with nothing pending, Chrome stops the background worker on its own",
stoppedWhenIdle,
"the worker was still running " +
IDLE_STOP_TIMEOUT_MS / 1000 +
"s after its last event, so something other than the " +
"approval windows is keeping it running",
);
console.log(
"# idle worker stopped after " +
Math.round((Date.now() - idleStart) / 1000) +
"s",
);
// A transaction approval and a signature approval, both open at once.
await dapp.evaluate(
"window.__dapp.start('tx', 'eth_sendTransaction', [" +
JSON.stringify({
from: address,
to: STUB_COUNTERPARTY,
value: toQuantity(parseEther("0.01")),
}) +
"])",
);
await until("the transaction approval window", async () =>
(await approvalPages()).length === 1 ? true : null,
);
await dapp.evaluate(
"window.__dapp.start('sign', 'personal_sign', [" +
JSON.stringify(SIGN_HEX) +
", " +
JSON.stringify(address) +
"])",
);
const windows = await until("both approval windows", async () => {
const pages = await approvalPages();
return pages.length === 2 ? pages : null;
});
let txWindow = null;
let signWindow = null;
for (const page of windows) {
const evaluate = await attach(send, page.targetId);
const view = await until("an approval screen", () =>
evaluate(
"(" +
shows("view-approve-tx") +
") ? 'tx' : (" +
shows("view-approve-sign") +
") ? 'sign' : null",
),
);
if (view === "tx") txWindow = evaluate;
if (view === "sign") signWindow = evaluate;
}
if (!txWindow || !signWindow) {
throw new Error("the two windows are not one of each kind");
}
// The user takes seven minutes. The worker is checked every two
// seconds, and the wait ends early if Chrome stops it.
const opened = Date.now();
let stoppedAfter = null;
while (Date.now() - opened < APPROVAL_WAIT_MS) {
if (!(await workerRunning())) {
stoppedAfter = Math.round((Date.now() - opened) / 1000);
break;
}
await sleep(2000);
}
check(
"the background worker keeps running while both approvals are open",
stoppedAfter === null,
"Chrome stopped the worker " +
stoppedAfter +
"s after the approvals opened",
);
await txWindow(typeInto("approve-tx-password", PASSWORD));
await txWindow(click("btn-approve-tx"));
await signWindow(typeInto("approve-sign-password", PASSWORD));
// The window closes itself once the signature is handed over.
await signWindow(click("btn-approve-sign")).catch(() => {});
const tx = await dapp.evaluate(settled("tx"));
const broadcast = node.broadcast.map((raw) => Transaction.from(raw));
check(
"the transaction approved after seven minutes reaches the site",
tx.settled === "resolved" &&
broadcast.length === 1 &&
tx.result === broadcast[0].hash &&
getAddress(broadcast[0].from) === address,
"the page got " +
JSON.stringify(tx) +
" and the node received " +
broadcast.length +
" transaction(s)",
);
const sign = await dapp.evaluate(settled("sign"));
check(
"the signature approved after seven minutes reaches the site",
sign.settled === "resolved" &&
getAddress(verifyMessage(getBytes(SIGN_HEX), sign.result)) ===
address,
"the page got " + JSON.stringify(sign),
);
} catch (e) {
failed += 1;
console.log("# ERROR: " + (e && e.stack ? e.stack : e));
} finally {
if (browser.exitCode === null && browser.signalCode === null) {
const exited = new Promise((resolve) =>
browser.once("exit", resolve),
);
browser.kill();
await exited;
}
await node.close();
// Chromium's helper processes can still be writing to the profile
// for a moment after the browser process itself has exited.
fs.rmSync(profile, { recursive: true, force: true, maxRetries: 5 });
}
console.log("1.." + checks.length);
if (checks.length === 0) {
console.log("# FAILED: this program asserted nothing");
process.exitCode = 1;
return;
}
console.log(
"# " +
(checks.length - failed) +
"/" +
checks.length +
" checks passed",
);
if (failed > 0) {
console.log("# FAILED");
process.exitCode = 1;
}
}
main().catch((e) => {
console.error("slowApproval: " + (e && e.stack ? e.stack : e));
process.exitCode = 1;
});