From 727d41f43222e209a0d23b042a72549a12673514 Mon Sep 17 00:00:00 2001 From: Michael Ramos Date: Tue, 27 Oct 2026 14:20:08 -0400 Subject: [PATCH 1/5] DIAG (temporary, to be reverted): trace notify_reach in the shared-events e2e The notify_reach test (inbox-shared-events.spec.ts) fails on CI with windows 2 after its 17 s hold, and does not reproduce on macOS or in a Linux container. This commit only collects evidence from GitHub's runner: the Inbox traces each window change (PLANNOTATOR_E2E_WINDOWS_TRACE, set by the shared-events world only), the test records each tab's requests and the count over time into the proof artifact, and the workflow runs the file 8 times before the full proof. It is reverted before review. --- .github/workflows/inbox-e2e.yml | 5 ++ packages/server/inbox-windows.ts | 17 +++++- tests/e2e/inbox-shared-events-world.ts | 2 + tests/e2e/inbox-shared-events.spec.ts | 81 ++++++++++++++++++++++++-- 4 files changed, 99 insertions(+), 6 deletions(-) diff --git a/.github/workflows/inbox-e2e.yml b/.github/workflows/inbox-e2e.yml index 1abad11fec..10bab248aa 100644 --- a/.github/workflows/inbox-e2e.yml +++ b/.github/workflows/inbox-e2e.yml @@ -158,6 +158,11 @@ jobs: bun build apps/hook/server/index.ts --compile --no-compile-autoload-bunfig --define '__CLI_VERSION__="0.0.0-dev"' --outfile .local/plannotator + # DIAG (temporary): the shared-events file alone, repeated, before the full proof. + - name: DIAG shared events repeated + continue-on-error: true + run: bunx playwright test -c tests/e2e/playwright.config.ts inbox-shared-events.spec.ts --project chromium --repeat-each 8 + - name: Run the Inbox window proof run: bun run test:e2e:inbox diff --git a/packages/server/inbox-windows.ts b/packages/server/inbox-windows.ts index 353d3126c5..5473d3288c 100644 --- a/packages/server/inbox-windows.ts +++ b/packages/server/inbox-windows.ts @@ -124,6 +124,13 @@ export function createInboxWindows(options: { graceMs?: number; now?: () => numb allowed_origins: [...new Set(allowed.map((w) => w.origin).filter((o): o is string => o !== null))].sort(), }; }; + // DIAG (temporary): every change, with the ids that count after it. + const trace = process.env.PLANNOTATOR_E2E_WINDOWS_TRACE + ? (op: string, id: string, extra: Record = {}) => { + const r = windows.get(id); + console.error(`[windows] ${JSON.stringify({ t: Date.now(), op, id: id.slice(0, 8), ...extra, rec: r ? { streams: r.streams, servedBy: r.servedBy?.slice(0, 8) ?? null, gone: r.gone, ended: r.streamEndedAt } : null, counted: [...windows].filter(([, w]) => isOpen(w)).map(([k]) => k.slice(0, 8)) })}`); + } + : () => {}; const scheduleDrop = (id: string, record: WindowRecord) => { if (record.drop) clearTimeout(record.drop); record.drop = setTimeout(() => { @@ -135,6 +142,7 @@ export function createInboxWindows(options: { graceMs?: number; now?: () => numb return; } windows.delete(id); + trace("drop", id); changed(); }, graceMs); (record.drop as { unref?: () => void }).unref?.(); @@ -163,6 +171,7 @@ export function createInboxWindows(options: { graceMs?: number; now?: () => numb clearTimeout(record.drop); record.drop = null; } + trace("connect", id); changed(); let closed = false; return () => { @@ -180,6 +189,7 @@ export function createInboxWindows(options: { graceMs?: number; now?: () => numb (expiry as { unref?: () => void }).unref?.(); expiries.add(expiry); } + trace("disconnect", id); changed(); }; }, @@ -193,14 +203,19 @@ export function createInboxWindows(options: { graceMs?: number; now?: () => numb // A report before the stream (or after it closed) is kept for the grace only // (a follower's, for as long as its leader is known: see scheduleDrop). if (record.streams === 0) scheduleDrop(id, record); + trace("report", id); changed(); }, leave(id) { const record = windows.get(id); - if (!record || record.gone) return; + if (!record || record.gone) { + trace("leave-ignored", id); + return; + } record.gone = true; // Kept for the grace, so followers it served still count until they report their new leader. if (record.streams === 0) scheduleDrop(id, record); + trace("leave", id); changed(); }, reach(enabled) { diff --git a/tests/e2e/inbox-shared-events-world.ts b/tests/e2e/inbox-shared-events-world.ts index 2a6754011e..6a4a3e4266 100644 --- a/tests/e2e/inbox-shared-events-world.ts +++ b/tests/e2e/inbox-shared-events-world.ts @@ -141,6 +141,8 @@ export async function newWorld(browser: Browser, options: { binary?: string; noL PLANNOTATOR_INBOX_CONNECT: '0', PLANNOTATOR_UPDATE_CHECK: '0', PLANNOTATOR_INBOX_PHONES: '0', + // DIAG (temporary): the server traces every window change to inbox.log. + PLANNOTATOR_E2E_WINDOWS_TRACE: '1', }; const chosen = options.binary ?? binary; const context = await browser.newContext({ viewport: { width: 1100, height: 760 }, colorScheme: 'light' }); diff --git a/tests/e2e/inbox-shared-events.spec.ts b/tests/e2e/inbox-shared-events.spec.ts index faa5e56edd..7e8138c6e7 100644 --- a/tests/e2e/inbox-shared-events.spec.ts +++ b/tests/e2e/inbox-shared-events.spec.ts @@ -36,7 +36,7 @@ */ import { expect, test, type Browser, type Page } from '@playwright/test'; -import { mkdirSync, writeFileSync } from 'node:fs'; +import { mkdirSync, readFileSync, writeFileSync } from 'node:fs'; import { join } from 'node:path'; import { removeInboxScratch, stopScratchInbox } from './inbox-scratch'; import { @@ -75,6 +75,13 @@ test.afterAll(async () => { for (const world of worlds) await closeWorld(world); } finally { writeFileSync(join(proofDir, 'results-chromium.json'), `${JSON.stringify(results, null, 2)}\n`); + // DIAG (temporary): each world's window trace. + worlds.forEach((world, i) => { + try { + const lines = readFileSync(join(world.dataDir, 'inbox', 'inbox.log'), 'utf8').split('\n').filter((l) => l.includes('[windows]')); + writeFileSync(join(proofDir, `windows-${process.pid}-${Date.now()}-${i}.log`), `${lines.join('\n')}\n`); + } catch {} + }); await removeInboxScratch(); } }); @@ -367,34 +374,93 @@ test('notifications once and the sound once across the tabs; a follower in front test('notify_reach follows the tabs: open, a follower closes, a follower crashes, the leader closes', async ({ browser }) => { const w = await world(browser); + // DIAG (temporary): what each tab asked the server, and the count over time. + const t0 = Date.now(); + const diag: string[] = []; + const label = new Map(); + const tag = (p: unknown) => label.get(p as object) ?? '?'; + w.context.on('request', (req) => { + const u = req.url(); + if (!u.includes('/api/inbox/window') && !u.includes('/api/inbox/events')) return; + let who = '?'; + try { + who = tag(req.frame().page()); + } catch { + who = 'noframe'; + } + diag.push(`${Date.now() - t0} ${who} ${req.method()} ${u.replace(w.url, '/')} ${req.postData() ?? ''}`); + }); await seed(w); - for (let i = 0; i < 4; i++) await openTab(w); + for (let i = 0; i < 4; i++) { + const { page } = await openTab(w); + label.set(page, `T${i}`); + } + for (const p of w.pages) diag.push(`${tag(p)} id=${(await logOf(p)).find((e) => e.type === 'subscribe')?.window}`); + let polling = true; + let lastCount = -1; + const poller = (async () => { + while (polling) { + try { + const n = (await health(w)).notify_reach.windows; + if (n !== lastCount) diag.push(`${Date.now() - t0} windows=${n}`); + lastCount = n; + } catch {} + await new Promise((d) => setTimeout(d, 50)); + } + })(); + const pagesSeen = [...w.pages]; + const dump = async (name: string) => { + polling = false; + await poller; + const logs: Record = {}; + for (const p of pagesSeen) logs[tag(p)] = await Promise.race([logOf(p), new Promise((d) => setTimeout(() => d('timeout'), 2000))]).catch((e) => String(e)); + let server: string[] = []; + try { + server = readFileSync(join(w.dataDir, 'inbox', 'inbox.log'), 'utf8').split('\n').filter((l) => l.includes('[windows]')).map((l) => { + const j = JSON.parse(l.slice(l.indexOf('{'))); + return `${j.t - t0} ${j.op} ${j.id} ${JSON.stringify(j.rec)} counted=${j.counted.join(',')}`; + }); + } catch (e) { + server = [String(e)]; + } + writeFileSync(join(proofDir, `diag-reach-${name}-${process.pid}-${Date.now()}.json`), JSON.stringify({ diag, logs, server }, null, 1)); + }; const windows = async () => (await health(w)).notify_reach; + const timeline: Record = {}; + let dumped = false; + try { await expect.poll(async () => (await windows()).windows).toBe(4); expect((await windows()).allowed).toBe(4); - const timeline: Record = {}; let [leader] = await leaders(w.pages); const followers = w.pages.filter((p) => p !== leader); // A follower closes: its pagehide beacon (or the leader, which sees its lock go). + diag.push(`${Date.now() - t0} closing follower ${tag(followers[0])}`); await followers[0]!.close(); forget(w, followers[0]!); timeline.followerClosedMs = (await waitFor(windows, (r) => r.windows === 3)).ms; // A follower crashes: no pagehide; the leader sees its lock released. const cdp = await w.context.newCDPSession(followers[1]!); - void cdp.send('Page.crash').catch(() => {}); + diag.push(`${Date.now() - t0} crashing ${tag(followers[1])}`); + void cdp.send('Page.crash').catch((e) => diag.push(`crash error ${e}`)); forget(w, followers[1]!); timeline.followerCrashedMs = (await waitFor(windows, (r) => r.windows === 2)).ms; // The leader closes: it stops counting at once, its follower stays counted under the new leader. [leader] = await leaders(w.pages); + diag.push(`${Date.now() - t0} closing leader ${tag(leader)}`); await leader!.close(); forget(w, leader!); timeline.leaderClosedMs = (await waitFor(windows, (r) => r.windows === 1)).ms; // And it holds there (never drops to 0 while one tab is open). + diag.push(`${Date.now() - t0} hold start`); await new Promise((done) => setTimeout(done, 17_000)); - expect((await windows()).windows).toBe(1); + const held = (await windows()).windows; + diag.push(`timeline ${JSON.stringify(timeline)}`); + dumped = true; + await dump(held === 1 ? 'ok' : 'FAIL'); + expect(held).toBe(1); expect(await streams(w)).toBe(1); // A new tab joins. await openTab(w); @@ -402,6 +468,11 @@ test('notify_reach follows the tabs: open, a follower closes, a follower crashes // A crashed tab is seen when the browser frees its lock: at once on macOS, about 3 s later on GitHub's Linux runners. for (const [step, ms] of Object.entries(timeline)) expect(ms).toBeLessThan(step === 'followerCrashedMs' ? 8000 : 3000); results.reach = timeline; + } catch (e) { + diag.push(`threw ${String(e).slice(0, 300)} timeline ${JSON.stringify(timeline)}`); + if (!dumped) await dump('THROW').catch(() => {}); + throw e; + } }); test('an Inbox restart: every tab reconnects through one stream and keeps getting every record once', async ({ browser }) => { From 8aaedd0d5070e2dbd86dcba7e65e78d5d6c83ae9 Mon Sep 17 00:00:00 2001 From: Michael Ramos Date: Tue, 27 Oct 2026 15:50:43 -0400 Subject: [PATCH 2/5] fix(inbox): a tab that said gone at pagehide reports nothing more A closing tab still runs for a moment after pagehide. When it led, the next leader's announcement and its relayed hello reached it there, and each sent a window report (served_by the next leader). That report clears `gone`; landing after the other tab's lock-watch `gone`, it left a closed tab counted for as long as the next leader's stream stayed open. This is the notify_reach e2e "Expected 1, Received 2" after the leader closes. Now the tab reports nothing from pagehide until a pageshow brings it back. Co-Authored-By: Claude --- packages/inbox/sharedEvents.test.ts | 24 ++++++++++++++++++++++++ packages/inbox/sharedEvents.ts | 19 +++++++++++++++++-- 2 files changed, 41 insertions(+), 2 deletions(-) diff --git a/packages/inbox/sharedEvents.test.ts b/packages/inbox/sharedEvents.test.ts index 3b2c4d82f1..1a32234953 100644 --- a/packages/inbox/sharedEvents.test.ts +++ b/packages/inbox/sharedEvents.test.ts @@ -526,6 +526,27 @@ test('the leader tells the server when a follower is gone: a crash (its lock fre expect(w.gone.some((g) => g.by === a.id && g.window === a.win.id)).toBe(false); }); +test('a leader still running after its pagehide reports nothing more: the next leader\'s announcement and hello do not count it again', async () => { + // The page is not gone the moment pagehide fires: its scripts can still hear the next leader. A report + // then (served_by the next leader) could reach the server after every `gone` and count a closed tab. + const w = world(); + const a = w.open(); + await settle(); + const b = w.open(); + await settle(10); + expect(w.leader()).toBe(a.id); + const connects = a.connects; + const hide = new Event('pagehide'); + Object.defineProperty(hide, 'persisted', { value: false }); + a.win2.dispatchEvent(hide); + w.server.write(2); + await settle(16); + expect(w.leader()).toBe(b.id); + expect(w.gone).toContainEqual({ by: a.id, window: a.win.id, unloading: true }); + expect(a.connects).toBe(connects); + w.kill(a); +}); + test('a frozen leader steps down so another leads; it queues again when it resumes, as a follower', async () => { const w = world(); const a = w.open(); @@ -578,12 +599,15 @@ test('the back/forward cache: pagehide (persisted) steps down and says gone; pag await settle(); const b = w.open(); await settle(8); + const hidden = a.connects; const hide = new Event('pagehide'); Object.defineProperty(hide, 'persisted', { value: true }); a.win2.dispatchEvent(hide); await settle(10); expect(w.leader()).toBe(b.id); expect(w.gone).toContainEqual({ by: a.id, window: a.win.id, unloading: true }); + // Going into the cache, it heard B lead but did not report: it counts again only at pageshow. + expect(a.connects).toBe(hidden); const connects = a.connects; const show = new Event('pageshow'); Object.defineProperty(show, 'persisted', { value: true }); diff --git a/packages/inbox/sharedEvents.ts b/packages/inbox/sharedEvents.ts index 657a143f1f..c17c083b4d 100644 --- a/packages/inbox/sharedEvents.ts +++ b/packages/inbox/sharedEvents.ts @@ -291,6 +291,19 @@ export function subscribeSharedInboxEvents( let stopped = false; /** Frozen, or in the back/forward cache: not a candidate, not the leader. */ let suspended = false; + /** + * Said `gone` at pagehide: until a pageshow brings it back, this tab reports + * nothing. Its scripts can still hear the next leader before the page goes, + * and a report then could reach the server after every `gone` and count a + * closed tab for good. + */ + let departed = false; + const tabHandlers: InboxEventHandlers = { + ...handlers, + onConnect: () => { + if (!departed) handlers.onConnect?.(); + }, + }; let closeStream: (() => void) | null = null; let releaseLeader: (() => void) | null = null; let queued: AbortController | null = null; @@ -356,7 +369,7 @@ export function subscribeSharedInboxEvents( lastSeq = seq; trace({ type: 'record', seq, via }); } - env.dispatch(frame, handlers); + env.dispatch(frame, tabHandlers); }; const clearRetry = () => { @@ -421,7 +434,7 @@ export function subscribeSharedInboxEvents( leader = id; if (id !== null && id !== win.id && !stopped) { void catchUp(); - handlers.onConnect?.(); + tabHandlers.onConnect?.(); } return true; }; @@ -631,12 +644,14 @@ export function subscribeSharedInboxEvents( const onResume = () => wake(); const onPageHide = (event: Event) => { // Leaving for good, or for the back/forward cache: either way this tab stops counting now. + departed = true; env.sendGone(win.id, true); if ((event as PageTransitionEvent).persisted) suspend(); else stepDown(); }; const onPageShow = (event: Event) => { if (!(event as PageTransitionEvent).persisted) return; + departed = false; wake(); // The server heard `gone` at pagehide: count this tab again. handlers.onConnect?.(); From b7c2a8be68470a5f78b3d170317a7cc0976d2c12 Mon Sep 17 00:00:00 2001 From: Michael Ramos Date: Tue, 27 Oct 2026 15:50:44 -0400 Subject: [PATCH 3/5] Revert "DIAG (temporary, to be reverted): trace notify_reach in the shared-events e2e" This reverts commit 727d41f43222e209a0d23b042a72549a12673514. --- .github/workflows/inbox-e2e.yml | 5 -- packages/server/inbox-windows.ts | 17 +----- tests/e2e/inbox-shared-events-world.ts | 2 - tests/e2e/inbox-shared-events.spec.ts | 81 ++------------------------ 4 files changed, 6 insertions(+), 99 deletions(-) diff --git a/.github/workflows/inbox-e2e.yml b/.github/workflows/inbox-e2e.yml index 10bab248aa..1abad11fec 100644 --- a/.github/workflows/inbox-e2e.yml +++ b/.github/workflows/inbox-e2e.yml @@ -158,11 +158,6 @@ jobs: bun build apps/hook/server/index.ts --compile --no-compile-autoload-bunfig --define '__CLI_VERSION__="0.0.0-dev"' --outfile .local/plannotator - # DIAG (temporary): the shared-events file alone, repeated, before the full proof. - - name: DIAG shared events repeated - continue-on-error: true - run: bunx playwright test -c tests/e2e/playwright.config.ts inbox-shared-events.spec.ts --project chromium --repeat-each 8 - - name: Run the Inbox window proof run: bun run test:e2e:inbox diff --git a/packages/server/inbox-windows.ts b/packages/server/inbox-windows.ts index 5473d3288c..353d3126c5 100644 --- a/packages/server/inbox-windows.ts +++ b/packages/server/inbox-windows.ts @@ -124,13 +124,6 @@ export function createInboxWindows(options: { graceMs?: number; now?: () => numb allowed_origins: [...new Set(allowed.map((w) => w.origin).filter((o): o is string => o !== null))].sort(), }; }; - // DIAG (temporary): every change, with the ids that count after it. - const trace = process.env.PLANNOTATOR_E2E_WINDOWS_TRACE - ? (op: string, id: string, extra: Record = {}) => { - const r = windows.get(id); - console.error(`[windows] ${JSON.stringify({ t: Date.now(), op, id: id.slice(0, 8), ...extra, rec: r ? { streams: r.streams, servedBy: r.servedBy?.slice(0, 8) ?? null, gone: r.gone, ended: r.streamEndedAt } : null, counted: [...windows].filter(([, w]) => isOpen(w)).map(([k]) => k.slice(0, 8)) })}`); - } - : () => {}; const scheduleDrop = (id: string, record: WindowRecord) => { if (record.drop) clearTimeout(record.drop); record.drop = setTimeout(() => { @@ -142,7 +135,6 @@ export function createInboxWindows(options: { graceMs?: number; now?: () => numb return; } windows.delete(id); - trace("drop", id); changed(); }, graceMs); (record.drop as { unref?: () => void }).unref?.(); @@ -171,7 +163,6 @@ export function createInboxWindows(options: { graceMs?: number; now?: () => numb clearTimeout(record.drop); record.drop = null; } - trace("connect", id); changed(); let closed = false; return () => { @@ -189,7 +180,6 @@ export function createInboxWindows(options: { graceMs?: number; now?: () => numb (expiry as { unref?: () => void }).unref?.(); expiries.add(expiry); } - trace("disconnect", id); changed(); }; }, @@ -203,19 +193,14 @@ export function createInboxWindows(options: { graceMs?: number; now?: () => numb // A report before the stream (or after it closed) is kept for the grace only // (a follower's, for as long as its leader is known: see scheduleDrop). if (record.streams === 0) scheduleDrop(id, record); - trace("report", id); changed(); }, leave(id) { const record = windows.get(id); - if (!record || record.gone) { - trace("leave-ignored", id); - return; - } + if (!record || record.gone) return; record.gone = true; // Kept for the grace, so followers it served still count until they report their new leader. if (record.streams === 0) scheduleDrop(id, record); - trace("leave", id); changed(); }, reach(enabled) { diff --git a/tests/e2e/inbox-shared-events-world.ts b/tests/e2e/inbox-shared-events-world.ts index 6a4a3e4266..2a6754011e 100644 --- a/tests/e2e/inbox-shared-events-world.ts +++ b/tests/e2e/inbox-shared-events-world.ts @@ -141,8 +141,6 @@ export async function newWorld(browser: Browser, options: { binary?: string; noL PLANNOTATOR_INBOX_CONNECT: '0', PLANNOTATOR_UPDATE_CHECK: '0', PLANNOTATOR_INBOX_PHONES: '0', - // DIAG (temporary): the server traces every window change to inbox.log. - PLANNOTATOR_E2E_WINDOWS_TRACE: '1', }; const chosen = options.binary ?? binary; const context = await browser.newContext({ viewport: { width: 1100, height: 760 }, colorScheme: 'light' }); diff --git a/tests/e2e/inbox-shared-events.spec.ts b/tests/e2e/inbox-shared-events.spec.ts index 7e8138c6e7..faa5e56edd 100644 --- a/tests/e2e/inbox-shared-events.spec.ts +++ b/tests/e2e/inbox-shared-events.spec.ts @@ -36,7 +36,7 @@ */ import { expect, test, type Browser, type Page } from '@playwright/test'; -import { mkdirSync, readFileSync, writeFileSync } from 'node:fs'; +import { mkdirSync, writeFileSync } from 'node:fs'; import { join } from 'node:path'; import { removeInboxScratch, stopScratchInbox } from './inbox-scratch'; import { @@ -75,13 +75,6 @@ test.afterAll(async () => { for (const world of worlds) await closeWorld(world); } finally { writeFileSync(join(proofDir, 'results-chromium.json'), `${JSON.stringify(results, null, 2)}\n`); - // DIAG (temporary): each world's window trace. - worlds.forEach((world, i) => { - try { - const lines = readFileSync(join(world.dataDir, 'inbox', 'inbox.log'), 'utf8').split('\n').filter((l) => l.includes('[windows]')); - writeFileSync(join(proofDir, `windows-${process.pid}-${Date.now()}-${i}.log`), `${lines.join('\n')}\n`); - } catch {} - }); await removeInboxScratch(); } }); @@ -374,93 +367,34 @@ test('notifications once and the sound once across the tabs; a follower in front test('notify_reach follows the tabs: open, a follower closes, a follower crashes, the leader closes', async ({ browser }) => { const w = await world(browser); - // DIAG (temporary): what each tab asked the server, and the count over time. - const t0 = Date.now(); - const diag: string[] = []; - const label = new Map(); - const tag = (p: unknown) => label.get(p as object) ?? '?'; - w.context.on('request', (req) => { - const u = req.url(); - if (!u.includes('/api/inbox/window') && !u.includes('/api/inbox/events')) return; - let who = '?'; - try { - who = tag(req.frame().page()); - } catch { - who = 'noframe'; - } - diag.push(`${Date.now() - t0} ${who} ${req.method()} ${u.replace(w.url, '/')} ${req.postData() ?? ''}`); - }); await seed(w); - for (let i = 0; i < 4; i++) { - const { page } = await openTab(w); - label.set(page, `T${i}`); - } - for (const p of w.pages) diag.push(`${tag(p)} id=${(await logOf(p)).find((e) => e.type === 'subscribe')?.window}`); - let polling = true; - let lastCount = -1; - const poller = (async () => { - while (polling) { - try { - const n = (await health(w)).notify_reach.windows; - if (n !== lastCount) diag.push(`${Date.now() - t0} windows=${n}`); - lastCount = n; - } catch {} - await new Promise((d) => setTimeout(d, 50)); - } - })(); - const pagesSeen = [...w.pages]; - const dump = async (name: string) => { - polling = false; - await poller; - const logs: Record = {}; - for (const p of pagesSeen) logs[tag(p)] = await Promise.race([logOf(p), new Promise((d) => setTimeout(() => d('timeout'), 2000))]).catch((e) => String(e)); - let server: string[] = []; - try { - server = readFileSync(join(w.dataDir, 'inbox', 'inbox.log'), 'utf8').split('\n').filter((l) => l.includes('[windows]')).map((l) => { - const j = JSON.parse(l.slice(l.indexOf('{'))); - return `${j.t - t0} ${j.op} ${j.id} ${JSON.stringify(j.rec)} counted=${j.counted.join(',')}`; - }); - } catch (e) { - server = [String(e)]; - } - writeFileSync(join(proofDir, `diag-reach-${name}-${process.pid}-${Date.now()}.json`), JSON.stringify({ diag, logs, server }, null, 1)); - }; + for (let i = 0; i < 4; i++) await openTab(w); const windows = async () => (await health(w)).notify_reach; - const timeline: Record = {}; - let dumped = false; - try { await expect.poll(async () => (await windows()).windows).toBe(4); expect((await windows()).allowed).toBe(4); + const timeline: Record = {}; let [leader] = await leaders(w.pages); const followers = w.pages.filter((p) => p !== leader); // A follower closes: its pagehide beacon (or the leader, which sees its lock go). - diag.push(`${Date.now() - t0} closing follower ${tag(followers[0])}`); await followers[0]!.close(); forget(w, followers[0]!); timeline.followerClosedMs = (await waitFor(windows, (r) => r.windows === 3)).ms; // A follower crashes: no pagehide; the leader sees its lock released. const cdp = await w.context.newCDPSession(followers[1]!); - diag.push(`${Date.now() - t0} crashing ${tag(followers[1])}`); - void cdp.send('Page.crash').catch((e) => diag.push(`crash error ${e}`)); + void cdp.send('Page.crash').catch(() => {}); forget(w, followers[1]!); timeline.followerCrashedMs = (await waitFor(windows, (r) => r.windows === 2)).ms; // The leader closes: it stops counting at once, its follower stays counted under the new leader. [leader] = await leaders(w.pages); - diag.push(`${Date.now() - t0} closing leader ${tag(leader)}`); await leader!.close(); forget(w, leader!); timeline.leaderClosedMs = (await waitFor(windows, (r) => r.windows === 1)).ms; // And it holds there (never drops to 0 while one tab is open). - diag.push(`${Date.now() - t0} hold start`); await new Promise((done) => setTimeout(done, 17_000)); - const held = (await windows()).windows; - diag.push(`timeline ${JSON.stringify(timeline)}`); - dumped = true; - await dump(held === 1 ? 'ok' : 'FAIL'); - expect(held).toBe(1); + expect((await windows()).windows).toBe(1); expect(await streams(w)).toBe(1); // A new tab joins. await openTab(w); @@ -468,11 +402,6 @@ test('notify_reach follows the tabs: open, a follower closes, a follower crashes // A crashed tab is seen when the browser frees its lock: at once on macOS, about 3 s later on GitHub's Linux runners. for (const [step, ms] of Object.entries(timeline)) expect(ms).toBeLessThan(step === 'followerCrashedMs' ? 8000 : 3000); results.reach = timeline; - } catch (e) { - diag.push(`threw ${String(e).slice(0, 300)} timeline ${JSON.stringify(timeline)}`); - if (!dumped) await dump('THROW').catch(() => {}); - throw e; - } }); test('an Inbox restart: every tab reconnects through one stream and keeps getting every record once', async ({ browser }) => { From f4268a921818139a982a2a4c8b65e5c602aa9c35 Mon Sep 17 00:00:00 2001 From: Michael Ramos Date: Tue, 27 Oct 2026 15:52:32 -0400 Subject: [PATCH 4/5] docs(inbox): a tab reports nothing between pagehide and pageshow Co-Authored-By: Claude --- docs/agent-guides/inbox-notifications-and-agents.md | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/docs/agent-guides/inbox-notifications-and-agents.md b/docs/agent-guides/inbox-notifications-and-agents.md index 79018ecc56..66c65ad6b5 100644 --- a/docs/agent-guides/inbox-notifications-and-agents.md +++ b/docs/agent-guides/inbox-notifications-and-agents.md @@ -37,7 +37,7 @@ - **No record missed or twice.** Each tab drops a record whose seq it already passed (its subscribe cursor, its list read's, counts as passed). A new leader opens its stream after the highest seq IT has seen. A tab that learns of a new leader (a handover, or its own join) first fetches what it may lack, `GET /api/inbox/events?cursor=&once=1` (the hello and the replay, then the response ends; not counted as a stream), holding the leader's frames until then, so a tab that slept or whose list read was older than the new leader's start loses nothing. A catch-up that fails (the Inbox restarting) keeps holding: the frames that arrive meanwhile wait (past 5,000 the oldest records go, which the catch-up fetches again), and it is tried again on a timer (1 s, doubling to 30 s) and at the next `hello`, from the same seq, so the gap is never skipped. A replay holds each record's latest line only (`changesSince`), exactly as an EventSource reconnect always did. `prepareInboxEvents()` opens the channel before the first list read, so a frame passed on between that read and the subscription is kept. - **Handover.** Close, reload, navigation and a crash free the leader's lock; the next tab in the lock's queue leads (measured 1 to 8 ms after the old leader went, 217 ms in the simulated freeze). `freeze` and a `pagehide` into the back/forward cache step down and leave the queue; `resume` / `pageshow` (persisted) join again, as a follower, with a catch-up. A frozen tab is never a candidate. - **A leader that stops without freezing** (a debugger, a long script in an attached HTML page's frame, which shares the tab's main thread, a phone's browser suspending a background tab) keeps its lock and passes nothing on. So every follower asks: `ping` on the channel every 3 s while the person can see it (`LEADER_PING_EVERY_MS`; at once when it becomes visible or gets focus), every 15 s while hidden (`LEADER_HIDDEN_PING_EVERY_MS`: a notification may still be owed); the leader answers `pong` from its message handler, so the answer proves its main thread runs, and any frame or announcement from a leader counts as an answer. No answer in 2 s (`LEADER_PONG_TIMEOUT_MS`): the follower takes the lock (`navigator.locks.request(..., { steal: true })`) and leads, opening its stream from its own last seq. The old leader learns it when it runs again (its lock request rejects): it closes its stream, steps down, joins, queues again and catches up, as a follower. Until then the server holds two streams (the stopped one and the new); records the two pass on are told apart by seq. A follower takes a leader only from its announcement (or, knowing none, from a frame), so the old leader's last frames never take the tabs back. Measured: Chromium with the leader held by the debugger for 8 s, the tab in front had the stream 3.4 s in, its longest gap without a record 3.2 s, two streams at most, every tab every record once; WebKit with a looping script in an attached page, 3.8 s and 3.7 s. A leader busy for more than 2 s for an ordinary reason is taken over the same way; nothing is lost. -- **Presence (`notify_reach`).** A follower holds no stream, so its `POST /api/inbox/window` reports `served_by` (the leader's window id, `inboxEventsServedBy()`), again whenever its leader changes and on every relayed `hello` (an Inbox restart); the server counts it while that leader holds its own stream, or held one less than the 15 s grace ago (a handover). Only a leader's own stream counts, never one link further: two tabs naming each other are never counted. Each tab holds the Web Lock `plannotator-inbox-window:` for its life; the leader queues for each follower's (on its `join`), and when the browser grants it the tab is gone (closed or crashed): the leader posts `{ window, gone: true }`. A tab also sends that itself at `pagehide` (a beacon). A gone tab stops counting at once; the followers it served keep counting through the grace. Worst case (the whole browser killed): followers stop counting 15 s after the leader's stream drops (one grace, and the pages hear it then). +- **Presence (`notify_reach`).** A follower holds no stream, so its `POST /api/inbox/window` reports `served_by` (the leader's window id, `inboxEventsServedBy()`), again whenever its leader changes and on every relayed `hello` (an Inbox restart); the server counts it while that leader holds its own stream, or held one less than the 15 s grace ago (a handover). Only a leader's own stream counts, never one link further: two tabs naming each other are never counted. Each tab holds the Web Lock `plannotator-inbox-window:` for its life; the leader queues for each follower's (on its `join`), and when the browser grants it the tab is gone (closed or crashed): the leader posts `{ window, gone: true }`. A tab also sends that itself at `pagehide` (a beacon), and from then until a `pageshow` brings it back it reports nothing: a closing leader still hears the next leader for a moment, and a report then could land after every `gone` and count a closed tab. A gone tab stops counting at once; the followers it served keep counting through the grace. Worst case (the whole browser killed): followers stop counting 15 s after the leader's stream drops (one grace, and the pages hear it then). - **Health** carries `event_streams` (additive): the event streams open now, windows' and the phone door's. - **Another site** is refused on `GET /api/inbox/events` (`Sec-Fetch-Site` cross-site or same-site, or an Origin naming another server: `403 cross_origin`), as on the other read routes; the window, the tailnet page (same-origin), the phone's door and agents (no fetch metadata) are answered. - **With every tab hidden**, a stalled leader is taken over in about 16 s (the next hidden check, up to 15 s, plus the 2 s wait), longer where the browser throttles a hidden tab's timers (Chrome: at most once a minute in a tab hidden for more than 5 minutes; Safari suspends background tabs). From f6929de521e1c763425a462537566ce727cfaadf Mon Sep 17 00:00:00 2001 From: Michael Ramos Date: Tue, 27 Oct 2026 16:16:11 -0400 Subject: [PATCH 5/5] test(inbox): a tab back from the bfcache reports again on later leader changes Guards the pageshow line that clears the post-pagehide silence; the header comment now names that silence. Co-Authored-By: Claude --- packages/inbox/sharedEvents.test.ts | 6 ++++++ packages/inbox/sharedEvents.ts | 3 ++- 2 files changed, 8 insertions(+), 1 deletion(-) diff --git a/packages/inbox/sharedEvents.test.ts b/packages/inbox/sharedEvents.test.ts index 1a32234953..d9b4577bdc 100644 --- a/packages/inbox/sharedEvents.test.ts +++ b/packages/inbox/sharedEvents.test.ts @@ -617,6 +617,12 @@ test('the back/forward cache: pagehide (persisted) steps down and says gone; pag expect(a.connects).toBeGreaterThan(connects); expectAll(a, 0, 2); expect(w.server.streams.size).toBe(1); + // Back from the cache it is live: its later reports (a leader change, a hello) go out again. + const restored = a.connects; + w.kill(b); + await settle(16); + expect(w.leader()).toBe(a.id); + expect(a.connects).toBeGreaterThan(restored); }); test('a sleeping follower behind a new leader that started past it fetches the lines between, once, in order', async () => { diff --git a/packages/inbox/sharedEvents.ts b/packages/inbox/sharedEvents.ts index c17c083b4d..43a69c2310 100644 --- a/packages/inbox/sharedEvents.ts +++ b/packages/inbox/sharedEvents.ts @@ -26,7 +26,8 @@ * holds a lock of its own (`WINDOW_LOCK_PREFIX` + its id) for its life; the * leader queues for each follower's lock, which the browser grants when that * tab is gone (closed or crashed), and tells the server (`gone`). A tab also - * says so itself at pagehide (a beacon). + * says so itself at pagehide (a beacon), and reports nothing more until a + * pageshow brings it back from the back/forward cache. * * Where Web Locks or BroadcastChannel is missing (an older browser, an * insecure context) `subscribeInboxEvents` opens this tab's own stream, as