diff --git a/cloud/browser-probe.ts b/cloud/browser-probe.ts new file mode 100644 index 000000000..f9ecabc78 --- /dev/null +++ b/cloud/browser-probe.ts @@ -0,0 +1,11 @@ +// Opt-in timings for the local browser latency probe. Never log input text or credentials. +export function probeTiming(phase: string, detail: Record) { + if (process.env.BOPS_BROWSER_PROBE === "1") + console.log(`[browser-probe] ${JSON.stringify({ phase, at: performance.timeOrigin + performance.now(), ...detail })}`); +} + +export function probeInput(phase: string, method: unknown, params: unknown) { + if (process.env.BOPS_BROWSER_PROBE !== "1" || method !== "Input.dispatchMouseEvent" || !params || typeof params !== "object") return; + const p = params as Record; + probeTiming(phase, { type: p.type, x: p.x, y: p.y, deltaY: p.deltaY }); +} diff --git a/cloud/browser.ts b/cloud/browser.ts index 600903630..6173e8205 100644 --- a/cloud/browser.ts +++ b/cloud/browser.ts @@ -1,11 +1,15 @@ -import type { IncomingMessage, ServerResponse } from "node:http"; +import { STATUS_CODES, type IncomingMessage, type ServerResponse } from "node:http"; +import type { Duplex } from "node:stream"; import { WebSocket, WebSocketServer, type RawData } from "ws"; -import { bearer, type CloudUser } from "./auth.ts"; +import { bearer, userForKey, type CloudUser } from "./auth.ts"; import { HttpError, readJson, refuseUpgrade, sendJson, type Route, type Upgrade } from "./http.ts"; import { botsOn } from "./computer-scope.ts"; +import { onStateWritten } from "./live.ts"; import { levelOf, permits, type MemberAccess } from "./member-access.ts"; import { ROLE_MS, trackMemberStream, viewerOf, watchable } from "./members.ts"; import { + BROWSER_INPUT_HEADER, + BROWSER_INPUT_PATH, BROWSER_NEEDS_COMPUTER, BROWSER_NEEDS_WRITE, BROWSER_SHARED_COMPUTER, @@ -14,6 +18,8 @@ import { type BrowserAct, type BrowserActivity, type BrowserEvent, + type BrowserInputAct, + type BrowserInputReply, type BrowserPerson, type BrowserToRunner, type RunnerToBrowser, @@ -21,6 +27,7 @@ import { import { loadState } from "./state.ts"; import { computerFor } from "./turns.ts"; import { computerUseOf, list, viewerAccess, wsOfBot } from "./ws-slice.ts"; +import { probeInput, probeTiming } from "./browser-probe.ts"; /** * The bot's browser (protocol.ts "The bot's browser"): Bops Cloud between the runner on a bot's computer, which captures @@ -33,7 +40,8 @@ import { computerUseOf, list, viewerAccess, wsOfBot } from "./ws-slice.ts"; * the owner, or someone the owner gave Write on that bot AND Use its computer (mayUseBrowser: the check a member's chat * turn on the computer goes by, turns.ts memberStill), and Write on every other bot that works on that computer (they * share its screens), as orgo-web and the owner's state say it now; looked at again - * every ROLE_MS while it's open, and ended at once by orgo-web's notice that their access changed (members.ts). With + * every ROLE_MS while it's open, at each write of the owner's state (a level, a bot hidden or moved to another computer: + * recheck), and ended at once by orgo-web's notice that their access changed (members.ts). With * `&only=activity` it hears only what the bot is doing with its browser and whether its computer is there, and isn't * watching: the runner captures nothing for it (a Watch chip's, components/app/bops-app.tsx). * - **What a bot is doing** with its browser (BrowserActivity), as its runner last said: kept in memory while that @@ -41,6 +49,12 @@ import { computerUseOf, list, viewerAccess, wsOfBot } from "./ws-slice.ts"; * - **Acting**: POST /v1/browser/act takes control, hands it back, or sends one CDP input, checked the same way each time. * The runner holds who has control (one person at a time) and refuses any input but theirs, and any method outside * BROWSER_METHODS. + * - **Acting on one socket**: WS /v1/browser/input?bot=[&project=] (protocol.ts BROWSER_INPUT_PATH) + * carries one viewer's acts in order, each checked as a POST's is (actOf, sendAct), without asking the owner's state for + * each: who may is asked at the upgrade, every ROLE_MS while it's open and at each write of the owner's state, and + * orgo-web's notice ends it at once, as a watch stream. A pointer's moves go about 60 a second there, which a POST each + * (a database read each) couldn't carry. Pinged every KEEPALIVE_MS: one that hasn't answered by the next goes (a Mac + * that changed networks leaves it open with nobody there). */ const BOT_ID = /^[A-Za-z0-9_-]{1,80}$/; @@ -51,6 +65,11 @@ const MAX_FRAME = 8 * 1024 * 1024; const KEEPALIVE_MS = 15_000; /** The most bots one runner message is for. */ const MAX_BOTS = 50; +/** The most one act may be, on the socket as in a POST's body. */ +const MAX_ACT = 64 * 1024; +/** An input socket's end: they may no longer use the bot's browser, or its computer or account changed. */ +const INPUT_REFUSED = 4403; +const INPUT_MOVED = 4409; /** `quiet`: an activity-only stream (`?only=activity`): not watching, so never in `watching`, and only told activity and the computer. */ type Viewer = { person: BrowserPerson; desktop: string; res: ServerResponse; end: () => void; quiet: boolean }; @@ -62,28 +81,59 @@ const runners = new Map(); const viewers = new Map>(); /** By "\n": what the bot is doing with its browser, as the runner of that computer last said. */ const doing = new Map(); +/** Each input socket open now, as its end. */ +const inputs = new Set<() => void>(); +/** By account: each watch stream and input socket open now, as its look at who may with the owner's state as just written. */ +const rechecks = new Map) => void>>(); const runnerKey = (account: string, desktop: string) => `${account}\n${desktop}`; const botKey = (account: string, bot: string) => `${account}\n${bot}`; let ownerState = async (account: string) => ((await loadState(account))?.state ?? {}) as Record; let every = ROLE_MS; +let pingEvery = KEEPALIVE_MS; /** Every socket and stream ends (the cloud stopping): each runner and viewer reconnects to the next start. */ export function closeBrowser() { for (const set of viewers.values()) for (const v of [...set]) v.end(); + for (const end of [...inputs]) end(); for (const r of runners.values()) r.ws.terminate(); runners.clear(); viewers.clear(); doing.clear(); + rechecks.clear(); } -/** Tests: the owner's state as given, and how often an open stream is checked again. */ -export function resetBrowser(o: { state?: (account: string) => Promise>; every?: number } = {}) { +/** Tests: the owner's state as given, how often an open stream is checked again, and how often an input socket is pinged. */ +export function resetBrowser(o: { state?: (account: string) => Promise>; every?: number; ping?: number } = {}) { ownerState = o.state ?? (async (account) => ((await loadState(account))?.state ?? {}) as Record); every = o.every ?? ROLE_MS; + pingEvery = o.ping ?? KEEPALIVE_MS; closeBrowser(); } +/** + * The owner's state was just written (live.ts stateWritten): each watch stream and input socket of that account asks + * again who may, from the blob as written (no database read; orgo-web's answer as kept). A Member set to Read or hidden + * on the bot, or the bot moved to another computer or onto one with bots they don't have, stops at once rather than at + * the next ROLE_MS look: orgo-web sends no notice for what lives only in the owner's state. + */ +function recheck(account: string, blob: Record) { + for (const f of [...(rechecks.get(account) ?? [])]) f(blob); +} +onStateWritten(recheck); + +/** Keep `f` as one of `account`'s looks at each write of its state (recheck); gives back its undoing. */ +function onWrite(account: string, f: (blob: Record) => void): () => void { + let set = rechecks.get(account); + if (!set) rechecks.set(account, (set = new Set())); + set.add(f); + return () => { + const s = rechecks.get(account); + s?.delete(f); + if (s && !s.size) rechecks.delete(account); + }; +} + /* ---------------- Who may ---------------- */ /** `owner`: the caller owns the bot (their own, or the workspace's owner), so their take goes over a member's control. */ @@ -97,7 +147,13 @@ export type BrowserAccess = { account: string; person: BrowserPerson; desktop: s * at Read, or of another workspace there (a main bot on the free computer) keeps it the owner's. 404 for a workspace or a * bot they don't see (never saying whether it exists), 403 with the words for what they lack, 409 when the bot has no computer. */ -export async function mayUseBrowser(user: CloudUser, key: string, projectId: string | null, botId: string, opts: { fresh?: boolean } = {}): Promise { +export async function mayUseBrowser( + user: CloudUser, + key: string, + projectId: string | null, + botId: string, + opts: { fresh?: boolean; written?: { account: string; blob: Record } } = {}, +): Promise { if (!BOT_ID.test(botId)) throw new HttpError(400, "bot must be a bot's id"); const person: BrowserPerson = { id: user.id, name: (user.name || user.email || "Someone").slice(0, 80) }; let account = user.id; @@ -105,12 +161,14 @@ export async function mayUseBrowser(user: CloudUser, key: string, projectId: str let blob: Record; // Someone other than the owner: their workspace and what they have of its bots, for the computer's other bots below. let theirs: { ws: string; access: MemberAccess } | null = null; - if (projectId === null) blob = await ownerState(account); + // `written`: the owner's state just written (recheck), used only when it's this account's. + const stateOf = async (of: string) => (opts.written?.account === of ? opts.written.blob : ownerState(of)); + if (projectId === null) blob = await stateOf(account); else { if (!PROJECT_ID.test(projectId)) throw new HttpError(400, "project must be an Orgo workspace id"); const { access, target } = await watchable(user, key, projectId, opts); account = target.account; - blob = await ownerState(account); + blob = await stateOf(account); const ws = list(blob.workspaces).find((w) => w.id === target.ws) ?? null; const bot = list(blob.bots).find((b) => b.id === botId); if (!ws || !bot || wsOfBot(bot) !== target.ws) throw new HttpError(404, "No such bot"); @@ -139,6 +197,17 @@ const nameOf = (blob: Record, botId: string) => { return typeof n === "string" && n.trim() ? n.trim().slice(0, 80) : "The bot"; }; +/** + * Asked again for a watch stream or input socket that's open: the key itself first, as each POST's is (userForKey, kept + * as long: one Orgo turns down now, or someone else's, is a 401 within HIT_MS and ROLE_MS, though no notice comes for an + * owner's own bot), then who may now (mayUseBrowser). Orgo or the database out of reach: a 5xx, which keeps it open. + */ +async function stillMay(user: CloudUser, key: string, projectId: string | null, botId: string): Promise { + const who = await userForKey(key); + if (!who || who.id !== user.id) throw new HttpError(401, "Sign in with Orgo again to see the bot's browser.", { code: "signed_out" }); + return mayUseBrowser(user, key, projectId, botId, { fresh: true }); +} + /* ---------------- Viewers ---------------- */ /** What a runner says its bot is doing with its browser, checked; null for anything else. A sign-in's page: http or https only. */ @@ -161,9 +230,9 @@ function watching(account: string, bot: string, desktop: string): BrowserPerson[ return [...out.values()]; } -/** Tell the bot's runner who watches it now. */ -function sayWatching(account: string, bot: string, desktop: string) { - sendRunner(runners.get(runnerKey(account, desktop)), { t: "watch", bot, viewers: watching(account, bot, desktop) }); +/** Tell the bot's runner who watches it now; `joined`: a stream just opened (its runner catches it up). */ +function sayWatching(account: string, bot: string, desktop: string, joined = false) { + sendRunner(runners.get(runnerKey(account, desktop)), { t: "watch", bot, viewers: watching(account, bot, desktop), ...(joined ? { joined: true as const } : {}) }); } function sendRunner(r: Runner | undefined, m: BrowserToRunner) { @@ -199,6 +268,7 @@ const watchRoute: Route = { clearInterval(beat); clearInterval(look); untrack(); + unwrite(); const s = viewers.get(k); s?.delete(v); if (s && !s.size) viewers.delete(k); @@ -210,23 +280,26 @@ const watchRoute: Route = { event(res, { t: "computer", connected: runners.has(runnerKey(a.account, a.desktop)) }); const now = doing.get(k); if (now?.desktop === a.desktop) event(res, { t: "activity", ...now.activity }); - if (!quiet) sayWatching(a.account, bot, a.desktop); + if (!quiet) sayWatching(a.account, bot, a.desktop, true); const beat = setInterval(() => res.write(": still\n\n"), KEEPALIVE_MS); beat.unref?.(); - // Asked afresh while it's open: someone out of the workspace, or without Write or Use its computer now, stops watching. - const look = setInterval(() => { - void mayUseBrowser(user!, key, project, bot, { fresh: true }) + // Asked afresh while it's open: a key turned down, someone out of the workspace, or without Write or Use its computer + // now, stops watching. + const judge = (asked: Promise) => + void asked .then((now) => { if (now.account !== a.account || now.desktop !== a.desktop) v.end(); }) .catch((e) => { - if (e instanceof HttpError && e.status < 500) { + if (e instanceof HttpError && e.status < 500 && !over) { event(res, { t: "refused", why: e.message, code: String(e.extra?.code ?? `http_${e.status}`) }); v.end(); } }); - }, every); + const look = setInterval(() => judge(stillMay(user!, key, project, bot)), every); look.unref?.(); + // And at each write of the owner's state, from it (recheck). + const unwrite = onWrite(a.account, (blob) => !over && judge(mayUseBrowser(user!, key, project, bot, { written: { account: a.account, blob } }))); // orgo-web's notice that their access to the workspace changed ends it at once (members.ts membersChanged). const untrack = project ? trackMemberStream(user!.id, project, () => v.end()) : () => {}; req.on("close", v.end); @@ -237,26 +310,123 @@ const watchRoute: Route = { /* ---------------- Acting ---------------- */ +type Act = BrowserInputAct["act"]; + +/** An act's name, checked: take, release or input. */ +function actOf(v: unknown): Act { + if (v !== "take" && v !== "release" && v !== "input") throw new HttpError(400, "act must be take, release or input"); + return v; +} + +/** One act of someone who may use `bot`'s browser (`a`), sent to the runner of its computer now; what it refuses, thrown. */ +function sendAct(a: BrowserAccess, bot: string, act: Act, body: Partial) { + const r = runners.get(runnerKey(a.account, a.desktop)); + if (!r) throw new HttpError(409, `${a.botName}'s computer isn't connected right now.`, { code: "browser_offline" }); + if (act === "input") { + if (!isBrowserMethod(body.method)) throw new HttpError(400, "The browser tab can't do that."); + sendRunner(r, { t: "input", bot, who: a.person, method: body.method, params: body.params ?? {} }); + } else if (act === "take") sendRunner(r, { t: "take", bot, who: a.person, ...(a.owner ? { over: true as const } : {}) }); + else sendRunner(r, { t: "release", bot, who: a.person }); +} + const actRoute: Route = { method: "POST", path: "/v1/browser/act", auth: "user", handle: async (req, res, { user }) => { - const body = await readJson>(req, 64 * 1024); - if (body.act !== "take" && body.act !== "release" && body.act !== "input") throw new HttpError(400, "act must be take, release or input"); + const body = await readJson>(req, MAX_ACT); + probeInput("cloud_got", body.method, body.params); + const act = actOf(body.act); const project = typeof body.project === "string" && body.project ? body.project : null; - const a = await mayUseBrowser(user!, bearer(req), project, typeof body.bot === "string" ? body.bot : ""); - const r = runners.get(runnerKey(a.account, a.desktop)); - if (!r) throw new HttpError(409, `${a.botName}'s computer isn't connected right now.`, { code: "browser_offline" }); - if (body.act === "input") { - if (!isBrowserMethod(body.method)) throw new HttpError(400, "The browser tab can't do that."); - sendRunner(r, { t: "input", bot: body.bot!, who: a.person, method: body.method, params: body.params ?? {} }); - } else if (body.act === "take") sendRunner(r, { t: "take", bot: body.bot!, who: a.person, ...(a.owner ? { over: true as const } : {}) }); - else sendRunner(r, { t: "release", bot: body.bot!, who: a.person }); + const bot = typeof body.bot === "string" ? body.bot : ""; + sendAct(await mayUseBrowser(user!, bearer(req), project, bot), bot, act, body); sendJson(res, 202, { ok: true }); }, }; +const inputWss = new WebSocketServer({ noServer: true, clientTracking: false, maxPayload: MAX_ACT, perMessageDeflate: false }); + +/** What didn't go, told on the socket it came on (nothing for what did). */ +const replyInput = (ws: WebSocket, e: HttpError) => { + if (ws.readyState !== WebSocket.OPEN) return; + const m: BrowserInputReply = { t: "error", code: String(e.extra?.code ?? `http_${e.status}`), why: e.message }; + ws.send(JSON.stringify(m)); +}; + +/** + * WS /v1/browser/input: asked as the watch stream is (mayUseBrowser; a refusal is the upgrade's status), then each message + * one act, checked and sent on in the order it came. Asked afresh every ROLE_MS (stillMay: the key too) and at each write + * of the owner's state (recheck), and ended at once by orgo-web's notice that their access changed; ended too when the + * bot's computer or account isn't the one it was. + */ +async function openInput(req: IncomingMessage, socket: Duplex, head: Buffer, user: CloudUser, url: URL) { + const bot = url.searchParams.get("bot") ?? ""; + const project = url.searchParams.get("project"); + const key = bearer(req); + let a = await mayUseBrowser(user, key, project, bot); + // Gone while that was asked: never a socket. + if (socket.destroyed) return; + inputWss.handleUpgrade(req, socket, head, (ws) => { + let over = false; + const end = (code: number, why: string) => { + if (over) return; + over = true; + inputs.delete(stop); + clearInterval(look); + clearInterval(ping); + untrack(); + unwrite(); + if (ws.readyState === WebSocket.OPEN) ws.close(code, why); + else ws.terminate(); + }; + const stop = () => end(1001, "Bops Cloud is restarting"); + inputs.add(stop); + const judge = (asked: Promise) => + void asked + .then((now) => { + if (over) return; + if (now.account !== a.account || now.desktop !== a.desktop) end(INPUT_MOVED, "The bot's computer changed"); + else a = now; + }) + .catch((e) => { + // Orgo or the database out of reach (5xx): kept as it is, as a watch stream is. + if (e instanceof HttpError && e.status < 500) end(INPUT_REFUSED, e.status === 401 ? "Sign in again" : "No longer allowed"); + }); + const look = setInterval(() => judge(stillMay(user, key, project, bot)), every); + look.unref?.(); + // At each write of the owner's state too, from it (recheck): a level or a bot's computer, which no notice says. + const unwrite = onWrite(a.account, (blob) => !over && judge(mayUseBrowser(user, key, project, bot, { written: { account: a.account, blob } }))); + const untrack = project ? trackMemberStream(user.id, project, () => end(INPUT_REFUSED, "Access changed")) : () => {}; + // Pinged: one that hasn't answered (a pong, or any act) since the last ping is gone without a close (a Mac that + // changed networks), and would otherwise be kept, and looked at, for good. Ended without a close to wait for. + let heard = true; + ws.on("pong", () => (heard = true)); + const ping = setInterval(() => { + if (!heard) return void ws.terminate(); + heard = false; + ws.ping(); + }, pingEvery); + ping.unref?.(); + ws.on("message", (data: RawData, binary: boolean) => { + if (over) return; + heard = true; + let m: unknown = null; + try { + if (!binary) m = JSON.parse(String(data)); + } catch {} + const body = (m && typeof m === "object" ? m : {}) as Partial; + probeInput("cloud_got", body.method, body.params); + try { + sendAct(a, bot, actOf(body.act), body); + } catch (e) { + if (e instanceof HttpError) replyInput(ws, e); + } + }); + ws.on("close", () => end(1000, "")); + ws.on("error", () => ws.terminate()); + }); +} + /* ---------------- The runner ---------------- */ const wss = new WebSocketServer({ noServer: true, clientTracking: false, maxPayload: MAX_FRAME }); @@ -283,7 +453,10 @@ function fromRunner(r: Runner, m: RunnerToBrowser) { if (activity) event(v.res, { t: "activity", ...activity }); if (v.quiet) continue; if (m.t === "frame") { - if (!v.res.writableNeedDrain && typeof m.data === "string") event(v.res, { t: "frame", data: m.data, meta: m.meta }); + if (!v.res.writableNeedDrain && typeof m.data === "string") { + probeTiming("cloud_frame", { timestamp: m.meta?.timestamp, bytes: Buffer.byteLength(m.data, "base64") }); + event(v.res, { t: "frame", data: m.data, meta: m.meta }); + } } else if (m.t === "page") event(v.res, { t: "page", url: String(m.url ?? ""), title: String(m.title ?? ""), back: typeof m.back === "number" ? m.back : null }); else if (m.t === "tabs") event(v.res, { t: "tabs", ...tabsOf(m) }); else if (m.t === "control") event(v.res, { t: "control", by: m.by ?? null, you: !!m.by && m.by.id === v.person.id }); @@ -343,4 +516,18 @@ export const upgrades: Upgrade[] = [ wss.handleUpgrade(req, socket, head, (ws) => attach(user, ws)); }, }, + { + // A person's own key only: a computer is refused before this (server.ts computerCheck). + path: BROWSER_INPUT_PATH, + handle: (req, socket, head, { user, url }) => { + // Node takes its own error handler off an upgrading socket: one dropping mid-handshake mustn't take the process down. + socket.on("error", () => socket.destroy()); + openInput(req, socket, head, user, url).catch((e: unknown) => { + const status = e instanceof HttpError ? e.status : 500; + if (!(e instanceof HttpError)) console.error(`[browser] input socket: ${(e as Error)?.message ?? e}`); + // Marked as this route's: a 404 without the mark is a Bops Cloud from before it. + if (!socket.destroyed) refuseUpgrade(socket, status, STATUS_CODES[status] ?? "Error", { [BROWSER_INPUT_HEADER]: "1" }); + }); + }, + }, ]; diff --git a/cloud/http.ts b/cloud/http.ts index bdd883012..a38b5e6e3 100644 --- a/cloud/http.ts +++ b/cloud/http.ts @@ -71,8 +71,9 @@ export class HttpError extends Error { } } -/** Refuse a WebSocket upgrade with an HTTP status. */ -export function refuseUpgrade(socket: Duplex, status: number, message: string) { - socket.write(`HTTP/1.1 ${status} ${message}\r\nConnection: close\r\nContent-Length: 0\r\n\r\n`); +/** Refuse a WebSocket upgrade with an HTTP status (and `headers`: names and values of letters, digits and dashes). */ +export function refuseUpgrade(socket: Duplex, status: number, message: string, headers: Record = {}) { + const extra = Object.entries(headers).map(([k, v]) => `${k}: ${v}\r\n`).join(""); + socket.write(`HTTP/1.1 ${status} ${message}\r\nConnection: close\r\n${extra}Content-Length: 0\r\n\r\n`); socket.destroy(); } diff --git a/cloud/live.ts b/cloud/live.ts index aa16ddb36..2d01194b1 100644 --- a/cloud/live.ts +++ b/cloud/live.ts @@ -555,6 +555,17 @@ function chatsOf(blob: Record): Map { return chats; } +/** + * What else hears of each write of an account's state, with the blob as written, before anything below: the bot's + * browser asks again who may use it (browser.ts), as a per-bot level or a bot's computer lives only in the owner's + * state and orgo-web sends no notice for it. Kept here, not imported, so nothing that writes the state imports browser.ts. + */ +const writeHooks = new Set<(account: string, blob: Record) => void>(); +export function onStateWritten(f: (account: string, blob: Record) => void): () => void { + writeHooks.add(f); + return () => void writeHooks.delete(f); +} + /** * The user's state was written (`by` the device that wrote it): every watched workspace whose part of it * changed hears "state", with the fingerprint of what it shows (sliceHash, and each member's stream its @@ -564,6 +575,13 @@ function chatsOf(blob: Record): Map { */ export function stateWritten(account: string, blob: Record, by: string | null, h: LiveHub = hub) { h.written++; + for (const f of writeHooks) { + try { + f(account, blob); + } catch (e) { + console.warn(`[live] after a state write: ${(e as Error)?.message ?? e}`); + } + } const watched = h.watched(account); if (!watched.length) return void h.seen.delete(account); const prev = h.seen.get(account); diff --git a/cloud/protocol.ts b/cloud/protocol.ts index 1430c8a4a..052ad2cb5 100644 --- a/cloud/protocol.ts +++ b/cloud/protocol.ts @@ -1279,11 +1279,13 @@ export type BrowserActivity = { step: "browsing" | "idle"; waiting: boolean; sig /** * What Bops Cloud tells a runner on its socket (WS /v1/browser/runner): who watches each of its bots' browsers now - * ("watch", the whole list each time; empty: nobody), and what a viewer asked ("take", "release", "input"). A take + * ("watch", the whole list each time; empty: nobody; `joined`: a stream just opened, maybe for someone already watching + * on another Mac or window, who sees the page at once as someone new does), and what a viewer asked ("take", "release", + * "input"). A take * by the owner (`over`) takes control from a member who has it; a member's never takes it from anyone. */ export type BrowserToRunner = - | { t: "watch"; bot: string; viewers: BrowserPerson[] } + | { t: "watch"; bot: string; viewers: BrowserPerson[]; joined?: true } | { t: "take"; bot: string; who: BrowserPerson; over?: true } | { t: "release"; bot: string; who: BrowserPerson } | { t: "input"; bot: string; who: BrowserPerson; method: string; params: unknown }; @@ -1319,6 +1321,20 @@ export type BrowserEvent = /** POST /v1/browser/act: take control, hand it back, or (in control) one CDP input. `project`: a shared workspace's Orgo id; none for the caller's own bots. */ export type BrowserAct = { bot: string; project?: string; act: "take" | "release" | "input"; method?: string; params?: unknown }; +/** + * WS /v1/browser/input?bot=[&project=]: the acts of one viewer's Bops for one bot, in order, on one + * socket (lib/server/browser-view.ts), each message a BrowserAct without `bot` and `project` (the address says them), at + * most 64 KiB. Checked as the watch stream is: at the upgrade (refused with mayUseBrowser's status), every ROLE_MS while + * open and at each write of the owner's state, and ended by orgo-web's notice; each act checked as POST /v1/browser/act + * checks it, then sent to the runner of that computer at that moment. Bops Cloud answers only what didn't go + * (BrowserInputReply), and pings it; each end pings the other, and one that doesn't answer by the next ping is taken for + * gone. Its refusals of the upgrade carry BROWSER_INPUT_HEADER, so a 404 without it is a Bops Cloud from before this socket. + */ +export const BROWSER_INPUT_PATH = "/v1/browser/input"; +export const BROWSER_INPUT_HEADER = "x-bops-browser-input"; +export type BrowserInputAct = Omit; +export type BrowserInputReply = { t: "error"; code: string; why: string }; + /** Why Bops Cloud won't let someone watch a bot's browser (403, with the words to show them). */ export const BROWSER_NEEDS_WRITE = "browser_needs_write"; export const BROWSER_NEEDS_COMPUTER = "browser_needs_computer"; diff --git a/cloud/test/edge-browser.test.ts b/cloud/test/edge-browser.test.ts index 491a36382..2734bccfb 100644 --- a/cloud/test/edge-browser.test.ts +++ b/cloud/test/edge-browser.test.ts @@ -5,9 +5,9 @@ import { WebSocket } from "ws"; import { clearAuthCache } from "../auth.ts"; import { resetBrowser, runnerConnected, viewersOf } from "../browser.ts"; import { closeDb } from "../db.ts"; -import { resetMembers } from "../members.ts"; +import { membersChanged, resetMembers } from "../members.ts"; import { BROWSER_NEEDS_COMPUTER, BROWSER_NEEDS_WRITE, BROWSER_SHARED_COMPUTER, type BrowserToRunner, type RunnerToBrowser } from "../protocol.ts"; -import { listen, newUserId, prepareDb, startCloud, until, type Listening } from "./edge-fakes.ts"; +import { dropUsers, listen, newUserId, prepareDb, startCloud, until, type Listening } from "./edge-fakes.ts"; /** * The bot's browser in Bops Cloud (browser.ts): who may watch a bot's browser and take control of it. The owner, and a @@ -32,6 +32,8 @@ const PROJECT = "22222222-3333-4444-5555-666666666666"; const DESKTOP = "0f0e0d0c-0b0a-4908-8706-050403020100"; const keyOf = (id: string) => `key-${id}`; const COMPUTER_KEY = `computer-${owner}`; +/** Keys orgo-web turns down now (revoked after they signed in). */ +const revoked = new Set(); before(async () => { await prepareDb(); @@ -51,6 +53,7 @@ before(async () => { const json = (status: number, body: unknown) => res.writeHead(status, { "content-type": "application/json" }).end(JSON.stringify(body)); const key = /^Bearer (.+)$/.exec(req.headers.authorization ?? "")?.[1] ?? ""; if (req.url === "/api/user/profile") { + if (revoked.has(key)) return json(401, { error: "This key was revoked" }); if (key === COMPUTER_KEY) return json(200, { id: owner, api_key: { scope: "computer", computer_id: DESKTOP } }); const id = /^key-(.+)$/.exec(key)?.[1]; return id ? json(200, { id, email: `${id}@example.com`, full_name: id.split("-")[1] }) : json(401, { error: "no" }); @@ -96,6 +99,7 @@ after(async () => { resetBrowser(); await cloud.close(); await orgo.close(); + await dropUsers([owner]); await closeDb(); }); @@ -179,6 +183,28 @@ test("the owner and a member with Write and Use its computer watch the bot's bro r.close(); }); +test("a second stream of someone already watching (another Mac or window) tells the runner one joined, so it catches them up", async () => { + const r = await runner(); + const first = await watch(owner, null); + const second = { close: () => {} }; + try { + await until(() => r.got.some((m) => m.t === "watch" && m.viewers.length === 1), "the runner to hear the owner"); + r.got.length = 0; + Object.assign(second, await watch(owner, null)); + const w = await until(() => r.got.findLast((m) => m.t === "watch"), "the runner to hear of the second stream"); + assert.ok(w.t === "watch" && w.joined === true && w.viewers.length === 1, JSON.stringify(w)); + first.close(); + const left = await until(() => r.got.findLast((m) => m.t === "watch" && m !== w), "the runner to hear one left"); + assert.ok(left.t === "watch" && !left.joined && left.viewers.length === 1, "one leaving: no one joined, the owner still watches"); + } finally { + first.close(); + second.close(); + await until(() => viewersOf(owner, "max") === 0, "both streams to end"); + r.close(); + await until(() => !runnerConnected(owner, DESKTOP), "the runner to go"); + } +}); + test("a member without Use its computer, a member at Read, one who doesn't see the bot and an outsider are refused, saying why", async () => { const no = await watch(noComputer); assert.equal(no.status, 403); @@ -325,3 +351,217 @@ test("only a computer opens the runner's socket", async () => { }); assert.equal(status, 403, "the owner's own key isn't a computer"); }); + +/** + * A viewer's input socket (WS /v1/browser/input): the upgrade's status and whether Bops Cloud marked a refusal as this + * route's (a plain 404 is a Bops Cloud from before it); open, what Bops Cloud says on it and how it closed. The address + * and the mark are the wire's, spelled out here. + */ +async function inputSocket(key: string, query = `bot=max&project=${PROJECT}`, opts: { autoPong?: boolean } = {}) { + const ws = new WebSocket(`${cloud.url.replace("http", "ws")}/v1/browser/input?${query}`, { headers: { Authorization: `Bearer ${key}` }, ...opts }); + const said: { t: string; code?: string; why?: string }[] = []; + let closed: number | null = null; + ws.on("message", (d) => said.push(JSON.parse(String(d)))); + ws.on("close", (code) => (closed = code)); + ws.on("error", () => {}); + const upgrade = await new Promise<{ status: number; marked: boolean }>((ok) => { + ws.on("unexpected-response", (req, res) => { + ok({ status: res.statusCode ?? 0, marked: res.headers["x-bops-browser-input"] === "1" }); + req.destroy(); + }); + ws.on("open", () => ok({ status: 101, marked: false })); + }); + return { ...upgrade, said, closed: () => closed, send: (m: unknown) => ws.send(typeof m === "string" ? m : JSON.stringify(m)), close: () => ws.close() }; +} + +test("one input socket: each act reaches the runner in order as who sent it; what a POST would refuse is refused on it, in words", async () => { + const r = await runner(); + const s = await inputSocket(keyOf(writer)); + assert.equal(s.status, 101, "a member with Write and Use its computer opens it"); + const who = { id: writer, name: "writer" }; + const moves = Array.from({ length: 20 }, (_, x) => ({ type: "mouseMoved", x, y: 5, button: "none", clickCount: 0, modifiers: 0 })); + s.send({ act: "take" }); + for (const params of moves) s.send({ act: "input", method: "Input.dispatchMouseEvent", params }); + s.send({ act: "input", method: "Runtime.evaluate", params: { expression: "document.cookie" } }); + s.send({ act: "input", method: "Input.insertText", params: { text: "hi" } }); + s.send({ act: "steal" }); + s.send("not json"); + s.send({ act: "release" }); + const acts = await until(() => { + const a = r.got.filter((m) => m.t !== "watch"); + return a.length >= 23 && a; + }, "the acts"); + assert.deepEqual(acts, [ + { t: "take", bot: "max", who }, + ...moves.map((params) => ({ t: "input", bot: "max", who, method: "Input.dispatchMouseEvent", params })), + { t: "input", bot: "max", who, method: "Input.insertText", params: { text: "hi" } }, + { t: "release", bot: "max", who }, + ], "in the order sent; a method outside BROWSER_METHODS never reaches the runner"); + await until(() => s.said.length === 3, "the refusals"); + assert.deepEqual(s.said, [ + { t: "error", code: "http_400", why: "The browser tab can't do that." }, + { t: "error", code: "http_400", why: "act must be take, release or input" }, + { t: "error", code: "http_400", why: "act must be take, release or input" }, + ]); + // No runner now: said on the socket in Bops Cloud's words, and nothing sent. + r.close(); + await until(() => !runnerConnected(owner, DESKTOP), "the runner to go"); + s.send({ act: "input", method: "Input.insertText", params: { text: "x" } }); + assert.deepEqual(await until(() => s.said[3], "the offline answer"), { t: "error", code: "browser_offline", why: "Max's computer isn't connected right now." }); + // More than 64 KiB in one act: the socket ends, as a POST that big is refused. + s.send({ act: "input", method: "Input.insertText", params: { text: "x".repeat(70 * 1024) } }); + assert.equal(await until(() => s.closed(), "the socket to end"), 1009); +}); + +test("only someone who may use the bot's browser opens its input socket: refused at the upgrade with the watch stream's status, marked as this route's", async () => { + for (const [who, status] of [[noComputer, 403], [reader, 403], [hidden, 404], [outsider, 404]] as const) { + const s = await inputSocket(keyOf(who)); + assert.deepEqual({ status: s.status, marked: s.marked }, { status, marked: true }, `${who}`); + } + const shared = await inputSocket(keyOf(hidden), `bot=dana&project=${PROJECT}`); + assert.deepEqual({ status: shared.status, marked: shared.marked }, { status: 403, marked: true }, "nor through a bot that shares its computer"); + const own = await inputSocket(keyOf(outsider), "bot=max"); + assert.deepEqual({ status: own.status, marked: own.marked }, { status: 404, marked: true }, "nor their own account's bot of that id"); + assert.equal((await inputSocket(COMPUTER_KEY)).status, 403, "a computer's key isn't a person"); + const before = await new Promise<{ status: number; marked: boolean }>((ok) => { + const ws = new WebSocket(`${cloud.url.replace("http", "ws")}/v1/browser/elsewhere?bot=max`, { headers: { Authorization: `Bearer ${keyOf(owner)}` } }); + ws.on("error", () => {}); + ws.on("unexpected-response", (req, res) => (ok({ status: res.statusCode ?? 0, marked: !!res.headers["x-bops-browser-input"] }), req.destroy())); + }); + assert.deepEqual(before, { status: 404, marked: false }, "a path Bops Cloud doesn't have: a plain 404, as one from before the socket says"); +}); + +test("an open input socket ends at once on orgo-web's notice, and when the owner takes away Write (asked again every ROLE_MS)", async () => { + let now: typeof state = state; + resetBrowser({ state: async (account) => (account === owner ? now : {}), every: 50 }); + const s = await inputSocket(keyOf(writer)); + assert.equal(s.status, 101); + membersChanged(PROJECT, writer); + assert.equal(await until(() => s.closed(), "the notice to end it", 1000), 4403); + const t = await inputSocket(keyOf(writer)); + assert.equal(t.status, 101, "asked afresh, they still may"); + const ws = state.workspaces[0]; + now = { ...state, workspaces: [{ ...ws, memberAccess: { ...ws.memberAccess, [`${writer}@example.com`]: { others: "none", bots: { max: "read", dana: "write" }, computer: "use", at } } }] }; + assert.equal(await until(() => t.closed(), "the next look to end it", 2000), 4403); +}); + +test("an open input socket ends once orgo-web turns its key down, at the next look, though no notice comes for an owner's own bot", async () => { + resetBrowser({ state: async (account) => (account === owner ? state : {}), every: 50 }); + const r = await runner(); + const s = await inputSocket(keyOf(owner), "bot=max"); + try { + assert.equal(s.status, 101); + s.send({ act: "input", method: "Input.insertText", params: { text: "a" } }); + await until(() => r.got.some((m) => m.t === "input"), "the act before"); + // Revoked: orgo-web turns the key down, and what was kept of its sign-in has run out (as HIT_MS passing). + revoked.add(keyOf(owner)); + clearAuthCache(); + assert.equal(await until(() => s.closed(), "the next look to end it", 2000), 4403); + s.send({ act: "input", method: "Input.insertText", params: { text: "b" } }); + await new Promise((ok) => setTimeout(ok, 150)); + assert.equal(r.got.filter((m) => m.t === "input").length, 1, "nothing after it reaches the runner"); + assert.equal((await inputSocket(keyOf(owner), "bot=max")).status, 401, "nor does a new socket on that key"); + } finally { + revoked.delete(keyOf(owner)); + clearAuthCache(); + r.close(); + await until(() => !runnerConnected(owner, DESKTOP), "the runner to go"); + } +}); + +test("an open watch stream ends once orgo-web turns its key down, at the next look, though no notice comes for an owner's own bot", async () => { + resetBrowser({ state: async (account) => (account === owner ? state : {}), every: 50 }); + const v = await watch(owner, null); + try { + assert.equal(v.status, 200); + await until(() => viewersOf(owner, "max") === 1, "watching"); + // Revoked: orgo-web turns the key down, and what was kept of its sign-in has run out (as HIT_MS passing). + revoked.add(keyOf(owner)); + clearAuthCache(); + await until(() => viewersOf(owner, "max") === 0, "the next look to end it", 2000); + // It says why, in place of the page (read as it comes: the stream can end here before its last event is read). + await until(() => v.events.some((e) => e.t === "refused" && e.code === "signed_out"), "the stream to say why", 1000); + assert.equal((await watch(owner, null)).status, 401, "nor does a new stream on that key"); + } finally { + revoked.delete(keyOf(owner)); + clearAuthCache(); + v.close(); + } +}); + +/** The owner's Mac writes their state through PUT /v1/state, over what it read last (`base`); gives back the version. */ +async function ownerWrites(base: number, blob: Record): Promise { + const headers = { Authorization: `Bearer ${keyOf(owner)}`, "x-bops-user": owner, "x-bops-protocol": "2", "x-bops-device": "mac-o", "content-type": "application/json" }; + const res = await fetch(`${cloud.url}/v1/state`, { method: "PUT", headers, body: JSON.stringify({ base, state: blob }) }); + assert.equal(res.status, 200, await res.clone().text()); + return ((await res.json()) as { version: number }).version; +} +const head = async () => ((await (await fetch(`${cloud.url}/v1/state/head`, { headers: { Authorization: `Bearer ${keyOf(owner)}`, "x-bops-user": owner, "x-bops-protocol": "2" } })).json()) as { version: number }).version; +/** The owner's state with the member's levels on its bots as given (and Use its computer, as before). */ +const writerGets = (bots: Record) => { + const ws = state.workspaces[0]; + return { ...state, workspaces: [{ ...ws, memberAccess: { ...ws.memberAccess, [`${writer}@example.com`]: { others: "none", bots, computer: "use", at } } }] }; +}; + +test("the owner setting a member to Read on the bot, written through the state route, ends their input socket and watch stream at once, not at the next look", async () => { + // Looked at again only every ROLE_MS (a minute): what ends them here is the write itself. + const version = await ownerWrites(await head(), state); + const s = await inputSocket(keyOf(writer)); + const v = await watch(writer); + try { + assert.equal(s.status, 101); + assert.equal(v.status, 200); + await until(() => viewersOf(owner, "max") === 1, "watching"); + // A write that changes nothing of theirs leaves them be. + await ownerWrites(version, { ...state, owner: { name: "Olive" } }); + await new Promise((ok) => setTimeout(ok, 150)); + assert.equal(s.closed(), null, "nothing of theirs changed: still open"); + assert.equal(viewersOf(owner, "max"), 1); + await ownerWrites(version + 1, writerGets({ max: "read", dana: "write" })); + assert.equal(await until(() => s.closed(), "the write to end the socket", 1000), 4403); + await until(() => viewersOf(owner, "max") === 0, "the write to end the stream", 1000); + const why = await until(() => v.events.find((e) => e.t === "refused"), "the stream to say why", 1000); + assert.equal(why.code, BROWSER_NEEDS_WRITE, "the stream says why, in place of the page"); + } finally { + s.close(); + v.close(); + } +}); + +test("a bot moved to another computer ends the owner's input socket at once; a bot they don't have moved onto its computer ends a member's", async () => { + const OTHER = "0a0b0c0d-0e0f-4011-8213-141516171819"; + let version = await ownerWrites(await head(), state); + const mine = await inputSocket(keyOf(owner), "bot=max"); + const theirs = await inputSocket(keyOf(writer)); + try { + assert.equal(mine.status, 101); + assert.equal(theirs.status, 101); + // Zed, a bot the member doesn't have, now works on Max's computer: its screens are Zed's too. + const zed = { id: "zed", name: "Zed", workspaceId: "ws_acme", computerId: DESKTOP, computerStatus: "ready" }; + version = await ownerWrites(version, { ...state, bots: [...state.bots, zed] }); + assert.equal(await until(() => theirs.closed(), "the write to end the member's socket", 1000), 4403); + assert.equal(mine.closed(), null, "the owner has every bot: still open"); + // Max moved to another computer: acts would reach the old one's runner, whose screens another bot may hold now. + await ownerWrites(version, { ...state, bots: state.bots.map((b) => (b.id === "max" ? { ...b, computerId: OTHER } : b)) }); + assert.equal(await until(() => mine.closed(), "the write to end the owner's socket", 1000), 4409); + } finally { + mine.close(); + theirs.close(); + } +}); + +test("an input socket that stops answering pings ends (a Mac gone without a close); one that answers stays", async () => { + resetBrowser({ state: async (account) => (account === owner ? state : {}), ping: 40 }); + const gone = await inputSocket(keyOf(owner), "bot=max", { autoPong: false }); + const here = await inputSocket(keyOf(owner), "bot=max"); + try { + assert.equal(gone.status, 101); + assert.equal(here.status, 101); + assert.equal(await until(() => gone.closed(), "the silent one to end", 1000), 1006, "ended without a close to wait for"); + await new Promise((ok) => setTimeout(ok, 200)); + assert.equal(here.closed(), null, "five pings answered: still open"); + } finally { + gone.close(); + here.close(); + } +}); diff --git a/components/app/bot-browser.tsx b/components/app/bot-browser.tsx index 2e8225c4e..5f1bef47b 100644 --- a/components/app/bot-browser.tsx +++ b/components/app/bot-browser.tsx @@ -72,8 +72,28 @@ const mods = (e: { altKey: boolean; ctrlKey: boolean; metaKey: boolean; shiftKey /** Keys that aren't text, as Chrome's key codes. Enter carries its "\r" so a form submits. */ const KEY_CODES: Record = { Enter: 13, Backspace: 8, Tab: 9, Escape: 27, ArrowLeft: 37, ArrowUp: 38, ArrowRight: 39, ArrowDown: 40, Delete: 46, Home: 36, End: 35, PageUp: 33, PageDown: 34 }; const BUTTON = ["left", "middle", "right"] as const; -/** Moves and scrolls go at most this often: the last move always (where the pointer stopped), scrolls added up. */ -const MOVE_MS = 50; +/** + * Moves and scrolls go at most this often (about 60 a second): the last move always (where the pointer stopped), scrolls + * added up. Inputs reach Bops Cloud on one socket now (lib/server/browser-view.ts), and a move still waiting is replaced + * by the next (act), so this many never queue up, even by POST to a Bops Cloud from before the socket. + */ +const MOVE_MS = 16; + +type ActBody = { act: "take" | "release" | "input"; method?: BrowserMethod; params?: unknown }; +/** An act waiting to be sent, for the bot and workspace it was made in; `sent` settles once Bops answered it. */ +type Queued = { body: ActBody; bot: string; project: string; sent: Promise; done: () => void }; +type Wheel = { x: number; y: number; deltaX: number; deltaY: number }; +/** A move or a scroll: one still waiting is replaced by a later one of its kind. Anything else is never replaced. */ +const laterWins = (b: ActBody): "move" | "wheel" | null => { + const type = b.act === "input" && b.method === "Input.dispatchMouseEvent" ? (b.params as { type?: string } | undefined)?.type : null; + return type === "mouseMoved" ? "move" : type === "mouseWheel" ? "wheel" : null; +}; +/** Two scrolls as one: where the later one is, by both their distances. */ +const addWheel = (was: unknown, next: unknown) => { + const a = was as Wheel; + const b = next as Wheel; + return { ...b, deltaX: a.deltaX + b.deltaX, deltaY: a.deltaY + b.deltaY }; +}; /** * `project`: the shared workspace the window shows (its Orgo id; none: the user's own), sent with the stream and every @@ -128,7 +148,10 @@ export function BotBrowser({ bot, project = "", hidden = false, inset = false }: [], ); const surface = useRef(null); - const sending = useRef(Promise.resolve()); + // Acts not sent yet, oldest first, and whether one is on its way (they go one at a time, in order). + const queue = useRef([]); + const sending = useRef(false); + const probePending = useRef(0); const lastMove = useRef(0); const held = useRef<{ move?: Record; wheel?: { x: number; y: number; deltaX: number; deltaY: number }; timer?: ReturnType }>({}); const meta = useRef(null); @@ -222,15 +245,58 @@ export function BotBrowser({ bot, project = "", hidden = false, inset = false }: return () => clearTimeout(t); }, [note]); - /** One act, after the ones before it (typing stays in order). */ - const act = (body: { act: "take" | "release" | "input"; method?: BrowserMethod; params?: unknown }) => { - const run = sending.current.then(async () => { - const res = await fetch("/api/browser", { method: "POST", headers: { "content-type": "application/json" }, body: JSON.stringify({ bot: bot.id, ...(project ? { project } : {}), ...body }) }).catch(() => null); - if (!res) return setNote("Couldn't reach Bops. Try again."); - if (!res.ok) setNote(((await res.json().catch(() => ({}))) as { error?: string }).error ?? "That didn't go through."); - }); - sending.current = run.catch(() => {}); - return run; + /** Opt-in latency probe (docs/BROWSER-SPEED.md): a mouse act's queued, sent and settled times. Silent otherwise. */ + const timing = (q: Queued, phase: "queued" | "sent" | "settled") => { + if (process.env.BOPS_BROWSER_PROBE !== "1" || q.body.method !== "Input.dispatchMouseEvent") return; + if (phase === "queued") probePending.current++; + const p = q.body.params as { type?: string; x?: number; y?: number } | undefined; + window.dispatchEvent(new CustomEvent("bops-browser-probe", { detail: { phase, at: performance.timeOrigin + performance.now(), depth: probePending.current - 1, type: p?.type, x: p?.x, y: p?.y } })); + if (phase === "settled") probePending.current--; + }; + /** The acts waiting, sent one at a time in order, each when the one before it is answered. */ + const pump = async () => { + if (sending.current) return; + sending.current = true; + try { + for (let q; (q = queue.current.shift()); ) { + timing(q, "sent"); + try { + const res = await fetch("/api/browser", { method: "POST", headers: { "content-type": "application/json" }, body: JSON.stringify({ bot: q.bot, ...(q.project ? { project: q.project } : {}), ...q.body }) }).catch(() => null); + if (!res) setNote("Couldn't reach Bops. Try again."); + else if (!res.ok) setNote(((await res.json().catch(() => ({}))) as { error?: string }).error ?? "That didn't go through."); + } finally { + timing(q, "settled"); + q.done(); + } + } + } finally { + sending.current = false; + } + }; + /** + * One act, after the ones before it: presses, releases, keys and pages in order, never dropped. A move or a scroll still + * waiting, with only moves and scrolls after it, is replaced by the newer one of its kind (latest wins; scrolls added + * up), so at most one of each waits there and moving never queues up ahead of a press. + */ + const act = (body: ActBody): Promise => { + const kind = laterWins(body); + let i = queue.current.length - 1; + if (kind) while (i >= 0 && laterWins(queue.current[i].body) && laterWins(queue.current[i].body) !== kind) i--; + const was = i >= 0 ? queue.current[i] : null; + const same = kind && was && laterWins(was.body) === kind && was.bot === bot.id && was.project === project ? was : null; + if (same) { + timing(same, "settled"); + same.body = kind === "wheel" ? { ...body, params: addWheel(same.body.params, body.params) } : body; + timing(same, "queued"); + return same.sent; + } + let done = () => {}; + const sent = new Promise((r) => (done = r)); + const q: Queued = { body, bot: bot.id, project, sent, done }; + timing(q, "queued"); + queue.current.push(q); + void pump(); + return sent; }; const input = (method: BrowserMethod, params: unknown) => (control.you ? void act({ act: "input", method, params }) : undefined); @@ -250,6 +316,8 @@ export function BotBrowser({ bot, project = "", hidden = false, inset = false }: if (!p) return; const params = { type, ...p, button: type === "mouseMoved" ? (e.buttons & 1 ? "left" : "none") : (BUTTON[e.button] ?? "left"), clickCount: type === "mouseMoved" ? 0 : Math.min(3, e.detail || 1), modifiers: mods(e) }; if (type === "mouseMoved") return often({ move: params }); + // Their own press rings at once where they pressed, rather than once the page's answer comes back. + if (type === "mousePressed") feed.ring(p); // A press or release lands after the move held back for it, where the pointer is. flushHeld(); input("Input.dispatchMouseEvent", params); diff --git a/components/app/browser-cursor.tsx b/components/app/browser-cursor.tsx index 7fc7cc1c6..6f075ba3b 100644 --- a/components/app/browser-cursor.tsx +++ b/components/app/browser-cursor.tsx @@ -13,23 +13,33 @@ import { Mascot } from "./mascot"; * with its face and name, a person's with their initials and first name. It travels like a hand (lib/cursor-path.ts), * arrives before it presses (a press that comes first hurries the rest of the way), dips and rings once where it * pressed, and fades after resting a while. The viewer's own pointer is never drawn twice: their own events don't come - * here (`you`). + * here (`you`). Their own press on the page rings at once where they pressed (CursorFeed.ring, from bot-browser.tsx), + * rather than once the page's answer comes back; nothing of it reaches the page. * * Reduced motion: the cursor is simply there, with no arc and no dip; the ring where it pressed still shows (it's what * happened, not decoration), held still. */ type PointerEvent = Extract; -/** The stream's pointer events, handed on as they come (bot-browser.tsx): a cursor moves at each without a render. */ -export type CursorFeed = { on: (fn: (e: PointerEvent) => void) => () => void; emit: (e: PointerEvent) => void }; +/** + * The stream's pointer events, handed on as they come (bot-browser.tsx): a cursor moves at each without a render. `ring`: + * the viewer's own press on the page, at its CSS pixels, shown at once. + */ +export type CursorFeed = { on: (fn: (e: PointerEvent) => void) => () => void; emit: (e: PointerEvent) => void; onRing: (fn: (p: Point) => void) => () => void; ring: (p: Point) => void }; export function cursorFeed(): CursorFeed { const fns = new Set<(e: PointerEvent) => void>(); + const rings = new Set<(p: Point) => void>(); return { on: (fn) => { fns.add(fn); return () => void fns.delete(fn); }, emit: (e) => fns.forEach((f) => f(e)), + onRing: (fn) => { + rings.add(fn); + return () => void rings.delete(fn); + }, + ring: (p) => rings.forEach((f) => f(p)), }; } @@ -70,15 +80,19 @@ export function BrowserCursors({ bot, feed, page, driver, idle = false }: { bot: if (now) fade(); else c.rest = setTimeout(fade, REST_MS); }; + /** A ring where something pressed, for RING_MS. */ + const ringAt = (p: Point) => { + const id = performance.now() + Math.random(); + setRings((r) => [...r, { id, x: p.x, y: p.y }]); + setTimeout(() => setRings((r) => r.filter((x) => x.id !== id)), RING_MS); + }; const press = (key: string, p: Point) => { const el = els.current.get(key); if (el && !reducedMotion()) { el.setAttribute("data-pressed", ""); setTimeout(() => el.removeAttribute("data-pressed"), DIP_MS); } - const id = performance.now() + Math.random(); - setRings((r) => [...r, { id, ...p }]); - setTimeout(() => setRings((r) => r.filter((x) => x.id !== id)), RING_MS); + ringAt(p); }; /** Each cursor where its travel has it now; a press that was waiting for it, once it's there. Again next frame while any moves. */ const place = () => { @@ -124,12 +138,15 @@ export function BrowserCursors({ bot, feed, page, driver, idle = false }: { bot: rest(key); if (!frame.current) frame.current = requestAnimationFrame(place); }); + // The viewer's own press: its ring at once, where they pressed (no cursor of theirs: their own pointer is there). + const offRing = feed.onRing(ringAt); // The frame shown at another size: each cursor stays over the same point of the page. const ro = typeof ResizeObserver === "function" ? new ResizeObserver(() => !frame.current && (frame.current = requestAnimationFrame(place))) : null; if (layer.current) ro?.observe(layer.current); const all = cursors.current; return () => { off(); + offRing(); ro?.disconnect(); cancelAnimationFrame(frame.current); frame.current = 0; diff --git a/docs/BROWSER-SPEED.md b/docs/BROWSER-SPEED.md new file mode 100644 index 000000000..b41e0de5e --- /dev/null +++ b/docs/BROWSER-SPEED.md @@ -0,0 +1,22 @@ +# Browser latency probe + +The real viewer, local Next server, Bops Cloud and input/capture pipeline are exercised through the two-person stack. A loopback proxy delays data independently in each direction. Each new upstream TCP connection also pays one modeled round trip. Each incoming app connection has its own upstream keep-alive agent, preserving connection lifetime and avoiding reuse across unrelated app sockets. Connection open/ready/close and each act's reused/new connection status are timestamped. HTTP streams and WebSocket upgrades both work. The local stack has no TLS: real HTTPS adds one more round trip per new connection than measured here. The orchestrator's supplied remote connect timings are context, not measurements made by this probe. + +Only the hidden viewer queue and Cloud/runner boundaries need opt-in instrumentation (`BOPS_BROWSER_PROBE=1`), silent by default. It logs mouse geometry and frame metadata, never typed text or credentials. The viewer probe observes EventSource, reuses the app's bitmap decode and samples actual canvas pixels in requestAnimationFrame. Colour matching uses expected RGB within 35 levels. No second screencast or decoder runs on the measured viewer. + +Acceptance and proof: + +- `scripts/verify browser-speed`: regression checks, Node syntax, `npx tsc --noEmit` and touched-file ESLint. Tests include the saved real CPU counterexample, click release attribution, missing-hop rejection, cleanup failures, real streaming and cold/warm connection tests. +- `node scripts/probe-browser-speed.mjs --link-ms 0 --out .scratch/probe-0` (repeat with 35): opens the owner's Browser tab and takes control through the UI; 30 rest clicks at least 600 ms apart, 15 clicks after two seconds moving, 30 hovers, 10 clicks after six seconds idle, and five seconds scrolling. Idle clicks use down/up at the existing pointer position, without an extra mouse move warming the connection. Raw JSON and n/median/p90 summaries include all hops and per-scenario counts of acts opening connections. +- Several people at once: add `--driver sam --watchers 2` (sam drives as a Member of the owner's shared workspace while two of the owner's windows watch; `--driver owner --watchers 1` the other way round). Each watcher is its own stream; the summary adds `watcher__to_photon_ms` (from the driver's input to the watcher's first paint of it), `watcher__behind_driver_ms` and `watcher_scroll_fps`. Watchers run on the same Mac, so they share its CPU with the driver. +- `node scripts/probe-computer-side.mjs --out .scratch/computer-probe`: Node 22+ and Chrome, no Playwright required; an owned headless Chrome/profile only, relay screencast settings, 30 CDP clicks and five seconds scrolling. Actual dispatch-to-JPEG and page-handler-to-JPEG timings lead its summary. +- Commit before measuring and change no tracked code during a run. Run 0 ms, 35 ms, then the standalone reference serially. +- Stop the stack and compare the listener list with the pre-run inventory. Cleanup saves raw observations before teardown and attempts every resource close even when evidence copying or stop fails. + +CPU is reported, never a gate. Sampling uses each process's own cumulative `ps time`, excluding reaped-child aggregation. Each interval sums nonnegative deltas only for PIDs present in both snapshots and records appearing/exiting PID counts. This slightly undercounts helpers' work at process boundaries. Sampling failures are saved as CPU warnings and cannot discard latency results. Counters have 10 ms precision on this Mac. Relay CPU is the stack parent process, including fixture servers and the delay proxy, excluding its children. Scenario summaries include queue drain; FPS and bandwidth use exactly five one-second scroll buckets. + +All ordinary observations use epoch milliseconds from Node/browser performance clocks on this Mac. Click causal hops follow the release that fires `click`; queue depth comes from the physical press. Input-to-release-send includes queued moves, the press round trip and any new connection setup on that press. Proxy data-ready/socket-write timestamps separate outgoing propagation from connection setup/agent wait. Per-input joins are bounded by input and first paint, and identify the same changed source frame. Missing latency observations fail; missing CPU does not. + +Chrome metadata caveat: [Chromium's implementation](https://chromium.googlesource.com/chromium/src/+/refs/heads/main/content/browser/devtools/protocol/page_handler.cc) uses expected display time for `metadata.timestamp` (`ScreencastFrameTimestamp`), which may follow JPEG delivery. Keep signed metadata deltas, and use actual encoded-frame callback timing for draw/encode and transport durations. Socket creation/reuse follows the [Node HTTP Agent API](https://nodejs.org/api/http.html#agentcreateconnectionoptions-callback). + +Scope: local fixtures, `next dev`, no physical display measurement, production, real Orgo computer, paid model calls, transport fix, new npm dependencies, installed Bops changes, push, PR or deploy. Two required link conditions only; the optional runner-delay condition is deferred to stay within the one authorized campaign. The probe stops a stack it starts and refuses a mismatched reused stack. Revert the probe commits to remove the tooling; timing logs remain off unless explicitly enabled. diff --git a/docs/FEATURES.md b/docs/FEATURES.md new file mode 100644 index 000000000..353b72909 --- /dev/null +++ b/docs/FEATURES.md @@ -0,0 +1,7 @@ +# Feature checks + +| Feature | How to reach it | Expected result | Files | Verify | +|---|---|---|---|---| +| Browser latency measurement | `node scripts/probe-browser-speed.mjs --link-ms 0 --out .scratch/probe-0` (repeat with 35) | 85 colour changes including ten clicks after six seconds idle, five seconds scrolling, raw JSON and hop/connection summaries, cleanup | `scripts/browser-speed/`, `scripts/probe-browser-speed.mjs`, `docs/BROWSER-SPEED.md` | `scripts/verify browser-speed`, then the command in this row | +| Computer draw and encode measurement | `node scripts/probe-computer-side.mjs --out .scratch/computer-probe` | 30 clicks, five seconds scrolling, owned Chrome stopped | `scripts/probe-computer-side.mjs` | Same static gate, then this row's command | +| Browser tab input on one socket | Owner's Bops, the bot's browser tab, Take over, then move, click, scroll and type on the page (`npm run two-person`) | Inputs reach the page in order; moves and scrolls waiting are replaced by the newest (scrolls summed); presses, keys and pages never dropped; an older Bops Cloud (plain 404 on WS /v1/browser/input) gets every act by POST | `cloud/browser.ts`, `lib/server/browser-view.ts`, `components/app/bot-browser.tsx` | `scripts/verify browser-input`, then `node scripts/test-browser-tab-e2e.mjs` and the latency probe row | diff --git a/lib/browser-relay.ts b/lib/browser-relay.ts index fcbd1b9c9..2b4cb6dd7 100644 --- a/lib/browser-relay.ts +++ b/lib/browser-relay.ts @@ -1,4 +1,5 @@ import WebSocket from "ws"; +import { probeInput, probeTiming } from "@/cloud/browser-probe"; import { isBrowserMethod, POINTER_KINDS, type BrowserActivity, type BrowserFrameMeta, type BrowserPerson, type BrowserPointer, type BrowserTab, type BrowserToRunner, type RunnerToBrowser } from "@/cloud/protocol"; /** @@ -31,7 +32,7 @@ import { isBrowserMethod, POINTER_KINDS, type BrowserActivity, type BrowserFrame * or reach, and each goes to the viewers labelled with who drove it: the person in control, else the bot. So the bot's * cursor shows however it moves (xdotool on the screen, Playwright over CDP), and so does a person's. Never kept. * - * It imports only `ws` and the protocol, so plain Node runs it (the stand-in) as well as the Next server. + * Its dependencies are `ws`, the protocol and optional safe timing logs; plain Node runs it as well as Next. */ export { BOPS_DEVICE_HEADER as DEVICE_HEADER } from "@/cloud/protocol"; @@ -391,6 +392,7 @@ class Screen { void cdp.send("Page.screencastFrameAck", { sessionId: p.sessionId }).catch(() => {}); if (this.cdp !== cdp) return; const frame = { data: String(p.data ?? ""), meta: p.metadata as BrowserFrameMeta }; + probeTiming("source_frame", { timestamp: frame.meta.timestamp, bytes: Buffer.byteLength(frame.data, "base64") }); this.last.frame = frame; if (this.watchers().length && this.relay.send({ t: "frame", bots: this.watchers(), ...frame }, true)) this.framesSent++; }); @@ -675,7 +677,7 @@ class RelayCore { private heard(m: BrowserToRunner) { if (!m || typeof m !== "object" || typeof m.bot !== "string") return; - if (m.t === "watch") return this.watch(m.bot, Array.isArray(m.viewers) ? m.viewers : []); + if (m.t === "watch") return this.watch(m.bot, Array.isArray(m.viewers) ? m.viewers : [], m.joined === true); const sc = this.screenOf(m.bot); if (!sc) return m.who && this.refuse(m.bot, m.who.id, "Its browser isn't open right now."); if (m.t === "take") { @@ -689,6 +691,7 @@ class RelayCore { return; } if (m.t === "input") { + probeInput("runner_got", m.method, m.params); if (!isBrowserMethod(m.method)) return this.refuse(m.bot, m.who.id, "The browser tab can't do that."); if (sc.controller?.who.id !== m.who.id) return this.refuse(m.bot, m.who.id, "Take over first."); const params = cleanInput(m.method, m.params); @@ -698,7 +701,7 @@ class RelayCore { } /** Who watches a bot's browser now: its screen captured while anyone does; a person in control who left hands it back. */ - private watch(bot: string, viewers: BrowserPerson[]) { + private watch(bot: string, viewers: BrowserPerson[], joined: boolean) { const had = this.screenOf(bot); const want = viewers.length ? this.screen(this.botScreen.get(bot) ?? this.o.screenFor(bot) ?? this.o.screens()[0]?.display ?? -1) : null; if (had && had !== want) { @@ -713,8 +716,9 @@ class RelayCore { this.botScreen.set(bot, want.display); want.watch(); if (want.controller && !want.watchedBy(want.controller.who.id)) want.setController(null); - // Someone new: they see the screen at once, not at its next paint. - if (viewers.some((v) => !before.some((b) => b.id === v.id))) want.catchUp([bot]); + // Someone new, or a stream just opened (someone already watching, on another Mac or window): they see the screen at + // once, not at its next paint. + if (joined || viewers.some((v) => !before.some((b) => b.id === v.id))) want.catchUp([bot]); } status() { diff --git a/lib/server/browser-view.ts b/lib/server/browser-view.ts index e11b73396..d20a4088b 100644 --- a/lib/server/browser-view.ts +++ b/lib/server/browser-view.ts @@ -1,5 +1,6 @@ import "server-only"; -import { BOPS_DEVICE_HEADER, type BrowserAct } from "@/cloud/protocol"; +import WebSocket from "ws"; +import { BOPS_DEVICE_HEADER, BROWSER_INPUT_HEADER, BROWSER_INPUT_PATH, isBrowserMethod, type BrowserAct, type BrowserInputAct, type BrowserInputReply } from "@/cloud/protocol"; import { appHeaders } from "./app-version"; import { cloudOn, cloudUrl } from "./cloud"; import { orgoKey } from "./orgo-auth"; @@ -12,14 +13,22 @@ import { stateUser } from "./store"; * stream of it (cloud/browser.ts), asked for on the signed-in user's own key, for a bot of the workspace open now: the * user's own, or the one shared with them (by its Orgo id). Bops Cloud decides who may; this only passes it on. Nothing * of it is kept: frames go straight through to the window. + * + * Inputs go to Bops Cloud on one socket per bot and workspace (WS /v1/browser/input), in order, each answered as soon as + * it's on its way rather than after a round trip to Bops Cloud and a database read there. A Bops Cloud from before that + * socket (its upgrade a plain 404) gets every act by POST, as before, for ten minutes (timing.noSocketMs); then it's asked + * again, as it may have been updated since. The socket is pinged: one a network change left dead without a close goes, + * and the next act opens another. */ -/** Where to ask, as whom: null when this Bops isn't signed in on Bops Cloud. */ -function asWhom(): { headers: Record; project: string | null } | null { +type Who = { id: string; url: string; headers: Record; project: string | null }; + +/** Where to ask, as whom: null when this Bops isn't signed in on Bops Cloud. `id`: the person and key it's asked as. */ +function asWhom(): Who | null { const user = stateUser(); const key = orgoKey(); if (!cloudOn() || !user || !key) return null; - return { headers: { Authorization: `Bearer ${key}`, [BOPS_DEVICE_HEADER]: deviceIdFor(user), ...appHeaders() }, project: sharedProjectId() }; + return { id: `${user}\n${key}`, url: cloudUrl(), headers: { Authorization: `Bearer ${key}`, [BOPS_DEVICE_HEADER]: deviceIdFor(user), ...appHeaders() }, project: sharedProjectId() }; } const SSE = { "content-type": "text/event-stream", "cache-control": "no-store", "x-accel-buffering": "no" }; @@ -47,7 +56,7 @@ export async function watchBrowser(bot: string, project: string, signal: AbortSi if (!who) return refused("Sign in with Orgo to see the bot's browser.", "signed_out"); if (!sameWorkspace(who, project)) return refused(MOVED, "workspace_changed"); const q = new URLSearchParams({ bot, ...(who.project ? { project: who.project } : {}), ...(quiet ? { only: "activity" } : {}) }); - const res = await fetch(`${cloudUrl()}/v1/browser/watch?${q}`, { headers: { ...who.headers, accept: "text/event-stream" }, cache: "no-store", signal }).catch(() => null); + const res = await fetch(`${who.url}/v1/browser/watch?${q}`, { headers: { ...who.headers, accept: "text/event-stream" }, cache: "no-store", signal }).catch(() => null); if (!res) return refused("Couldn't reach Bops Cloud. Check your internet connection.", "unreachable", true); if (!res.ok || !res.body) { const body = (await res.json().catch(() => ({}))) as { error?: string; code?: string }; @@ -57,12 +66,21 @@ export async function watchBrowser(bot: string, project: string, signal: AbortSi return new Response(res.body, { headers: SSE }); } +type Answer = { status: number; body: unknown }; +const SENT: Answer = { status: 202, body: { ok: true } }; + /** POST: take control, hand it back, or one input, as Bops Cloud answers it. `project`: as watchBrowser's. */ -export async function actBrowser(act: Omit, project: string): Promise<{ status: number; body: unknown }> { +export async function actBrowser(act: Omit, project: string): Promise { const who = asWhom(); if (!who) return { status: 409, body: { error: "Sign in with Orgo first." } }; if (!sameWorkspace(who, project)) return { status: 409, body: { error: MOVED, code: "workspace_changed" } }; - const res = await fetch(`${cloudUrl()}/v1/browser/act`, { + // Take, hand back and a method outside BROWSER_METHODS go by POST: their refusals come back in Bops Cloud's words. + return act.act === "input" && isBrowserMethod(act.method) && !(Date.now() < (noSocketUntil.get(who.url) ?? 0)) ? viaSocket(who, act) : post(who, act); +} + +/** One act by POST /v1/browser/act, as Bops Cloud answers it. */ +async function post(who: Who, act: Omit): Promise { + const res = await fetch(`${who.url}/v1/browser/act`, { method: "POST", headers: { ...who.headers, "content-type": "application/json" }, body: JSON.stringify({ ...act, ...(who.project ? { project: who.project } : {}) }), @@ -72,3 +90,110 @@ export async function actBrowser(act: Omit, project: stri if (!res) return { status: 502, body: { error: "Couldn't reach Bops Cloud." } }; return { status: res.status, body: await res.json().catch(() => ({})) }; } + +/* ---------------- One socket per bot ---------------- */ + +/** + * `idleMs`: a socket with no act for this long closes; the next act opens another. `pingMs`: how often an open one is + * pinged; one that hasn't answered by the next ping is gone (a network change can leave it so, taking acts into nothing + * without a close), and the next act opens another. `noSocketMs`: how long a Bops Cloud from before the socket gets acts + * by POST before it's asked again. + */ +const timing = { idleMs: 60_000, pingMs: 5_000, noSocketMs: 10 * 60_000 }; +/** The most one act may be on the socket (Bops Cloud's limit); a bigger one goes by POST, which refuses it in words. */ +const MAX_ACT = 64 * 1024; + +type Waiting = { who: Who; act: Omit; done: (a: Answer) => void }; +/** + * `waiting`: acts that came while it opens, sent in order once it has. `said`: an act Bops Cloud said didn't go (its + * computer isn't connected): the next goes by POST, so the window hears it in Bops Cloud's words. + */ +type Pipe = { ws: WebSocket; who: Who; waiting: Waiting[]; said: boolean; idle?: ReturnType; beat?: ReturnType }; + +/** By "\n\n\n". */ +const pipes = new Map(); +/** By Bops Cloud's address: one with no input socket (a plain 404) gets every act by POST until then. */ +const noSocketUntil = new Map(); + +function viaSocket(who: Who, act: Omit): Promise { + const msg = JSON.stringify({ act: act.act, method: act.method, params: act.params } satisfies BrowserInputAct); + if (Buffer.byteLength(msg) > MAX_ACT) return post(who, act); + const id = `${who.id}\n${who.url}\n${who.project ?? ""}\n${act.bot}`; + let p = pipes.get(id); + if (p && p.ws.readyState > WebSocket.OPEN) { + gone(id, p); + p = undefined; + } + if (p?.said) { + p.said = false; + return post(who, act); + } + const pipe = p ?? openPipe(id, who, act.bot); + rest(id, pipe); + return new Promise((done) => { + if (pipe.ws.readyState === WebSocket.OPEN) send(pipe, { who, act, done }, msg); + else pipe.waiting.push({ who, act, done }); + }); +} + +/** On its way: answered once the socket took it; a socket that failed sends it by POST instead. */ +function send(p: Pipe, w: Waiting, msg = JSON.stringify({ act: w.act.act, method: w.act.method, params: w.act.params })) { + p.ws.send(msg, (e) => (e ? void post(w.who, w.act).then(w.done) : w.done(SENT))); +} + +function openPipe(id: string, who: Who, bot: string): Pipe { + const q = new URLSearchParams({ bot, ...(who.project ? { project: who.project } : {}) }); + const ws = new WebSocket(`${who.url.replace(/^http/, "ws")}${BROWSER_INPUT_PATH}?${q}`, { headers: who.headers, handshakeTimeout: 10_000, perMessageDeflate: false, maxPayload: MAX_ACT }); + const p: Pipe = { ws, who, waiting: [], said: false }; + pipes.set(id, p); + ws.once("open", () => { + for (const w of p.waiting.splice(0)) send(p, w); + // No answer since the last ping: gone, though nothing said so. + let heard = true; + ws.on("pong", () => (heard = true)); + p.beat = setInterval(() => { + if (!heard) return gone(id, p); + heard = false; + ws.ping(); + }, timing.pingMs); + p.beat.unref?.(); + }); + ws.once("unexpected-response", (req, res) => { + // A Bops Cloud from before this socket: by POST for a while. Any other refusal: these by POST, which say why in words. + if (res.statusCode === 404 && !res.headers[BROWSER_INPUT_HEADER]) noSocketUntil.set(who.url, Date.now() + timing.noSocketMs); + req.destroy(); + gone(id, p); + }); + ws.on("message", (data, binary) => { + if (binary) return; + try { + if ((JSON.parse(String(data)) as BrowserInputReply).t === "error") p.said = true; + } catch {} + }); + ws.on("error", () => gone(id, p)); + ws.on("close", () => gone(id, p)); + return p; +} + +/** Closed after timing.idleMs without an act. */ +function rest(id: string, p: Pipe) { + if (p.idle) clearTimeout(p.idle); + p.idle = setTimeout(() => { + p.ws.close(1000); + gone(id, p); + }, timing.idleMs); + p.idle.unref?.(); +} + +/** The socket is gone (or going): forgotten, and acts still waiting for it go by POST, in order. */ +function gone(id: string, p: Pipe) { + if (pipes.get(id) === p) pipes.delete(id); + if (p.idle) clearTimeout(p.idle); + if (p.beat) clearInterval(p.beat); + const waiting = p.waiting.splice(0); + if (p.ws.readyState < WebSocket.CLOSING) p.ws.terminate(); + void waiting.reduce((chain, w) => chain.then(() => post(w.who, w.act).then(w.done)), Promise.resolve()); +} + +/** Tests: how long a socket rests, how often it's pinged, and how long an older Bops Cloud gets acts by POST. */ +export const browserViewForTests = { timing }; diff --git a/next.config.ts b/next.config.ts index c6cad3745..d2873c968 100644 --- a/next.config.ts +++ b/next.config.ts @@ -6,7 +6,7 @@ import type { NextConfig } from "next"; const { version } = JSON.parse(readFileSync(join(process.cwd(), "package.json"), "utf8")) as { version: string }; const nextConfig: NextConfig = { - env: { BOPS_APP_VERSION: version }, + env: { BOPS_APP_VERSION: version, BOPS_BROWSER_PROBE: process.env.BOPS_BROWSER_PROBE === "1" ? "1" : "" }, // A second app from this folder at once (the local two-person stack, scripts/dev-two-person.mjs) builds into a // folder of its own, as next dev locks its own. Unset, as everywhere else, it's Next's .next. ...(process.env.BOPS_NEXT_DIST_DIR ? { distDir: process.env.BOPS_NEXT_DIST_DIR } : {}), diff --git a/scripts/browser-speed/common.mjs b/scripts/browser-speed/common.mjs new file mode 100644 index 000000000..cab30617d --- /dev/null +++ b/scripts/browser-speed/common.mjs @@ -0,0 +1,219 @@ +import { spawn, spawnSync } from "node:child_process"; +import { existsSync, mkdirSync, readFileSync, rmSync } from "node:fs"; +import { createServer } from "node:http"; +import { join, resolve } from "node:path"; +import { now } from "./link.mjs"; +import { endGroup } from '../fixtures/cleanup.mjs'; +export { now }; +export const sleep = (ms) => new Promise((r) => setTimeout(r, ms)); +export async function cleanupSteps(save, steps) { + const errors = []; + for (const step of [save, ...steps, save]) + try { + await step(); + } + catch (e) { + errors.push(e); + } + if (errors.length) + throw new AggregateError(errors, 'Probe cleanup failed; observations saved when writable'); +} +export function cpuSeconds(value) { + const [days, clock] = value.includes('-') ? value.split('-') : ['0', value]; + const parts = clock.split(':').map(Number); + const seconds = parts.reduce((sum, n) => sum * 60 + n, 0) + Number(days) * 86400; + if (!Number.isFinite(seconds)) + throw new Error(`Invalid ps CPU time: ${value}`); + return seconds; +} +export function cpuIntervals(samples) { + const result = []; + for (let i = 1; i < samples.length; i++) { + const a = samples[i - 1], b = samples[i]; + const seconds = (b.at - a.at) / 1000; + if (a.scenario !== b.scenario || seconds < .05) + continue; + const before = a.chromeTimes ?? {}, after = b.chromeTimes ?? {}; + const shared = Object.keys(after).filter(pid => pid in before); + // CPU is informational: omit work from appearing/exiting PIDs and clamp counter resets. + // This slightly undercounts; retain churn so the report can say exactly where it happened. + const ticks = shared.reduce((sum, pid) => sum + Math.max(0, Math.round(after[pid] * 100) - Math.round(before[pid] * 100)), 0); + const chrome = Number.isFinite(ticks) ? ticks / seconds : null; + const relayTicks = Math.max(0, Math.round(b.relaySeconds * 100) - Math.round(a.relaySeconds * 100)); + const relay = Number.isFinite(relayTicks) ? relayTicks / seconds : null; + result.push({ scenario: b.scenario, chrome, relay, seconds, appearedPids: Object.keys(after).filter(pid => !(pid in before)).length, exitedPids: Object.keys(before).filter(pid => !(pid in after)).length }); + } + return result; +} +export async function until(check, what, ms = 15000) { + const end = now() + ms; + while (now() < end) { + const v = await check(); + if (v) + return v; + await sleep(20); + } + throw new Error(`Timed out: ${what}`); +} +export function stats(values) { + if (values.some((v) => !Number.isFinite(v))) + throw new Error("Non-finite observation"); + const a = [...values].sort((x, y) => x - y); + const percentile = (p) => a.length ? a[Math.max(0, Math.ceil(a.length * p) - 1)] : null; + return { n: a.length, median: a.length ? (a[Math.floor((a.length - 1) / 2)] + a[Math.floor(a.length / 2)]) / 2 : null, p90: percentile(.9) }; +} +export function hopTimings(t) { + const hops = { input_to_send: t.sent - t.input, send_to_cloud: t.cloud - t.sent, cloud_to_runner: t.runner - t.cloud, runner_to_page: t.handled - t.runner, page_to_frame: t.frame - t.handled, frame_to_cloud: t.forwarded - t.frame, cloud_to_viewer: t.received - t.forwarded, viewer_to_paint: t.painted - t.received, page_to_encoded_frame: t.sourceReceived - t.handled, encoded_frame_to_cloud: t.forwarded - t.sourceReceived }; + for (const [hop, ms] of Object.entries(hops)) { + if (!Number.isFinite(ms)) + throw new Error(`${hop}: missing observation`); + // Chrome reports expected display time, not encode completion. These two deltas are signed by design. + if (!['page_to_frame', 'frame_to_cloud'].includes(hop) && ms < -2) + throw new Error(`${hop} clock/order violation ${ms}`); + } + return hops; +} +export function args(argv) { + const out = {}; + for (let i = 0; i < argv.length; i += 2) { + if (!['--link-ms', '--out', '--driver', '--watchers'].includes(argv[i]) || !argv[i + 1]) + throw new Error("Usage: --link-ms <0|35> --out [--driver owner|sam] [--watchers <0-3>]"); + out[argv[i].slice(2)] = argv[i + 1]; + } + if (!out.out) + throw new Error("--out is required"); + if (out['link-ms'] !== undefined && !['0', '35'].includes(out['link-ms'])) + throw new Error("--link-ms must be 0 or 35"); + // Who drives the bot's browser (sam: a Member of the shared workspace, by its Orgo id), and how many others watch it + // at once: the other person first, then more tabs of either, each its own stream. + out.driver ??= 'owner'; + if (!['owner', 'sam'].includes(out.driver)) + throw new Error("--driver must be owner or sam"); + out.watchers = Number(out.watchers ?? 0); + if (!Number.isInteger(out.watchers) || out.watchers < 0 || out.watchers > 3) + throw new Error("--watchers must be 0 to 3"); + out.out = resolve(out.out); + mkdirSync(out.out, { recursive: true }); + return out; +} +export async function testSite() { + const html = readFileSync(new URL('./page.html', import.meta.url)); + const server = createServer((req, res) => res.writeHead(200, { 'content-type': 'text/html', 'cache-control': 'no-store' }).end(html)); + await new Promise((r) => server.listen(0, '127.0.0.1', r)); + return { url: `http://127.0.0.1:${server.address().port}`, close: () => new Promise((r) => { server.closeAllConnections(); server.close(r); }) }; +} +export class CDP { + constructor(url) { + this.ws = new WebSocket(url); + this.id = 0; + this.pending = new Map(); + this.handlers = new Map(); + this.open = new Promise((ok, no) => { this.ws.addEventListener('open', ok, { once: true }); this.ws.addEventListener('error', no, { once: true }); }); + this.ws.addEventListener('message', (e) => { + const m = JSON.parse(e.data); + if (m.id) { + const p = this.pending.get(m.id); + if (p) { + clearTimeout(p.timer); + this.pending.delete(m.id); + if (m.error) + p.no(new Error(m.error.message)); + else + p.ok(m.result); + } + } + else + for (const fn of this.handlers.get(m.method) ?? []) + fn(m.params); + }); + } + on(event, fn) { this.handlers.set(event, [...(this.handlers.get(event) ?? []), fn]); } + async send(method, params = {}) { + await this.open; + const id = ++this.id; + return new Promise((ok, no) => { + const timer = setTimeout(() => { this.pending.delete(id); no(new Error(`CDP timeout: ${method}`)); }, 15000); + this.pending.set(id, { ok, no, timer }); + this.ws.send(JSON.stringify({ id, method, params })); + }); + } + async eval(expression) { + const r = await this.send('Runtime.evaluate', { expression, returnByValue: true, awaitPromise: true }); + if (r.exceptionDetails) + throw new Error(JSON.stringify(r.exceptionDetails)); + return r.result.value; + } + close() { + this.ws.close(); + for (const p of this.pending.values()) { + clearTimeout(p.timer); + p.no(new Error('CDP closed')); + } + this.pending.clear(); + } +} +export async function connectPage(port) { + const tabs = await (await fetch(`http://127.0.0.1:${port}/json/list`)).json(); + const tab = tabs.find((t) => t.type === 'page' && !t.url.startsWith('devtools:')); + if (!tab) + throw new Error('No page on owned DevTools port'); + const cdp = new CDP(tab.webSocketDebuggerUrl); + await cdp.open; + return cdp; +} +export async function ownChrome(out, url) { + const profile = join(out, 'chrome-profile'); + if (existsSync(profile)) + throw new Error(`Owned profile already exists: ${profile}`); + const choices = process.platform === 'darwin' ? ['/Applications/Google Chrome.app/Contents/MacOS/Google Chrome'] : process.platform === 'win32' ? [join(process.env.PROGRAMFILES ?? 'C:\\Program Files', 'Google/Chrome/Application/chrome.exe')] : ['google-chrome-stable', 'google-chrome', 'chromium', 'chromium-browser']; + const binary = process.env.CHROME || choices.find((p) => p.includes('/') ? existsSync(p) : spawnSync('which', [p], { stdio: 'ignore' }).status === 0); + if (!binary) + throw new Error('Chrome not found; set CHROME to its executable'); + mkdirSync(profile); + const chrome = spawn(binary, ['--headless=new', '--remote-debugging-address=127.0.0.1', '--remote-debugging-port=0', `--user-data-dir=${profile}`, '--no-first-run', '--no-default-browser-check', '--disable-background-networking', '--use-mock-keychain', '--password-store=basic', '--window-size=1280,800', url], { stdio: 'ignore', detached: process.platform !== 'win32' }); + let launchError; + chrome.once('error', e => { launchError = e; }); + const stop = async () => { + if (chrome.pid) { + chrome.kill('SIGTERM'); + await until(() => chrome.exitCode !== null || chrome.signalCode !== null, 'owned Chrome exit', 5000).catch(() => chrome.kill('SIGKILL')); + if (process.platform === 'win32') + spawnSync('taskkill', ['/PID', String(chrome.pid), '/T', '/F'], { stdio: 'ignore' }); + else if (!await endGroup(chrome.pid)) + throw new Error('Owned Chrome helpers did not exit'); + } + rmSync(profile, { recursive: true, force: true, maxRetries: 5, retryDelay: 100 }); + }; + try { + const port = await until(() => { + if (launchError) + throw launchError; + try { + return Number(readFileSync(join(profile, 'DevToolsActivePort'), 'utf8').split('\n')[0]); + } + catch { + return null; + } + }, 'owned Chrome DevTools'); + return { pid: chrome.pid, port, stop }; + } + catch (e) { + await stop(); + throw e; + } +} +export function cpuTree(rootPid) { + const r = spawnSync('ps', ['-axo', 'pid=,ppid=,time='], { encoding: 'utf8' }); + if (r.status !== 0) + throw new Error('ps sampling failed'); + const rows = r.stdout.trim().split('\n').map(l => { const [pid, ppid, time] = l.trim().split(/\s+/); return [Number(pid), Number(ppid), cpuSeconds(time)]; }); + const ids = new Set([rootPid]); + let size; + do { + size = ids.size; + for (const [pid, ppid] of rows) + if (ids.has(ppid)) + ids.add(pid); + } while (size !== ids.size); + return { at: now(), times: Object.fromEntries(rows.filter(([pid]) => ids.has(pid)).map(([pid, , time]) => [pid, time])), pids: [...ids] }; +} diff --git a/scripts/browser-speed/link.mjs b/scripts/browser-speed/link.mjs new file mode 100644 index 000000000..ff0a702e3 --- /dev/null +++ b/scripts/browser-speed/link.mjs @@ -0,0 +1,261 @@ +import { Agent, createServer, request } from "node:http"; +import { appendFileSync } from "node:fs"; +import { connect } from 'node:net'; +export const now = () => performance.timeOrigin + performance.now(); +/** + * Acts on the browser input socket (WS /v1/browser/input), read from the client's raw frames: each complete text frame + * of JSON. Only its act, method, mouse type and position, as for a POST act; never its text. + */ +function actFrames(nextId) { + let buf = Buffer.alloc(0); + return (chunk) => { + buf = buf.length ? Buffer.concat([buf, chunk]) : chunk; + const found = []; + while (buf.length >= 2) { + const fin = buf[0] & 0x80, opcode = buf[0] & 0x0f, masked = buf[1] & 0x80; + let length = buf[1] & 0x7f, at = 2; + if (length === 126) { + if (buf.length < 4) + break; + length = buf.readUInt16BE(2); + at = 4; + } + else if (length === 127) { + if (buf.length < 10) + break; + length = Number(buf.readBigUInt64BE(2)); + at = 10; + } + const mask = masked ? buf.subarray(at, at + 4) : null; + if (masked) + at += 4; + if (buf.length < at + length) + break; + const payload = Buffer.from(buf.subarray(at, at + length)); + buf = buf.subarray(at + length); + if (mask) + for (let i = 0; i < payload.length; i++) + payload[i] ^= mask[i & 3]; + if (!fin || opcode !== 1) + continue; + try { + const m = JSON.parse(payload.toString()); + const p = m.params ?? {}; + found.push({ actId: nextId(), act: m.act, method: m.method, type: p.type, x: p.x, y: p.y, transport: 'websocket' }); + } + catch { } + } + return found; + }; +} +/** A fixed propagation delay, not a bandwidth cap or a serial sleep per chunk. */ +export async function startLink(target, delayMs, logFile) { + const sockets = new Set(); + const upstreams = new Set(); + const timers = new Set(); + const agents = new Set(), paired = new WeakMap(), info = new WeakMap(); + let nextConnection = 0, nextAct = 0; + const log = (phase, detail) => logFile && appendFileSync(logFile, JSON.stringify({ phase, at: now(), ...detail }) + "\n"); + const later = (fn, ms = delayMs) => { + const timer = setTimeout(() => { timers.delete(timer); fn(); }, ms); + timers.add(timer); + }; + const openConnection = (options, downstreamId, transport, callback) => { + const connectionId = ++nextConnection, startAt = now(); + log('connection_open', { direction: 'upstream', connectionId, downstreamId, transport, setupDelayMs: 2 * delayMs }); + later(() => { + const socket = connect(options); + sockets.add(socket); + const metadata = { connectionId, downstreamId, startAt }; + info.set(socket, metadata); + let settled = false; + socket.once('error', error => { if (!settled) { + settled = true; + callback(error); + } }); + socket.once('connect', () => { + if (settled) + return; + settled = true; + metadata.readyAt = now(); + log('connection_ready', { direction: 'upstream', connectionId, downstreamId, transport, setupMs: metadata.readyAt - startAt }); + callback(null, socket); + }); + socket.once('close', () => { sockets.delete(socket); log('connection_close', { direction: 'upstream', connectionId, downstreamId, transport }); }); + }, 2 * delayMs); + }; + const upstream = new URL(target); + const server = createServer(async (req, res) => { + // Only a path on the one Bops Cloud this stands in front of: an absolute or "//" address would name another host. + if (!req.url.startsWith('/') || req.url.startsWith('//')) { + res.writeHead(400).end(); + return; + } + const chunks = []; + for await (const chunk of req) + chunks.push(chunk); + const body = Buffer.concat(chunks); + let act; + if (req.url === "/v1/browser/act") { + let parsed; + try { + parsed = JSON.parse(body.toString()); + } + catch { + parsed = {}; + } + const p = parsed.params ?? {}; + act = { actId: ++nextAct, act: parsed.act, method: parsed.method, type: p.type, x: p.x, y: p.y }; + log("proxy_act_in", act); + } + later(() => { + if (res.destroyed) + return; + if (act) + log("proxy_act_ready", act); + const up = request({ protocol: upstream.protocol, hostname: upstream.hostname, port: upstream.port, path: req.url, agent: paired.get(req.socket).agent, method: req.method, headers: { ...req.headers, host: upstream.host } }, (reply) => { + let pending = ""; + if (act) + log("proxy_reply_in", { status: reply.statusCode }); + later(() => { + if (!res.destroyed) + res.writeHead(reply.statusCode, reply.headers); + }); + reply.on("data", (chunk) => { + const events = []; + // Parse only event boundaries for timings, forward original bytes without re-encoding. + if (req.url.startsWith("/v1/browser/watch")) { + pending += chunk.toString(); + let end; + while ((end = pending.indexOf("\n\n")) >= 0) { + const event = pending.slice(0, end); + pending = pending.slice(end + 2); + const data = /^data: (.+)$/m.exec(event); + if (data) { + let m; + try { + m = JSON.parse(data[1]); + } + catch { + continue; + } + const event = { t: m.t, timestamp: m.meta?.timestamp }; + events.push(event); + log("proxy_sse_in", event); + } + } + } + later(() => { + if (res.destroyed) + return; + res.write(chunk); + for (const event of events) + log('proxy_sse_out', event); + log("proxy_chunk_out", { path: req.url.split("?")[0], bytes: chunk.length }); + }); + }); + reply.on("end", () => later(() => { + if (!res.destroyed) + res.end(); + })); + reply.on("error", () => res.destroy()); + }); + up.once('socket', socket => { + if (act) { + const connection = info.get(socket); + log('proxy_act_connection', { ...act, ...connection, newConnection: !up.reusedSocket, setupMs: up.reusedSocket ? 0 : connection.readyAt - connection.startAt }); + } + }); + up.once('finish', () => { if (act) + log('proxy_act_out', act); }); + upstreams.add(up); + up.once("close", () => upstreams.delete(up)); + up.on("error", () => { + if (!res.destroyed) + res.destroy(); + }); + res.once("close", () => up.destroy()); + up.end(body); + }); + }); + // Preserve all app Cloud tunnels, including future browser WebSocket transports. Delay raw bytes in both + // directions independently, so several chunks in flight do not pay a serial delay per chunk. + server.on('upgrade', (req, socket, head) => { + const destination = new URL(target); + const downstreamId = paired.get(socket).connectionId; + let up; + // The input socket's acts, logged as POST acts are: in on arrival, ready and out as they're written upstream. + const read = req.url.startsWith('/v1/browser/input') ? actFrames(() => ++nextAct) : () => []; + const arrived = (data) => { + const acts = read(data); + for (const act of acts) + log('proxy_act_in', act); + return acts; + }; + const writeLater = (to, data, acts = [], newConnection = false) => later(() => { + if (to.destroyed) + return; + const connection = info.get(to); + for (const act of acts) { + log('proxy_act_ready', act); + log('proxy_act_connection', { ...act, ...connection, newConnection, setupMs: newConnection ? connection.readyAt - connection.startAt : 0 }); + } + to.write(data); + for (const act of acts) + log('proxy_act_out', act); + }); + const headers = { ...req.headers, host: destination.host }; + const requestHead = `${req.method} ${req.url} HTTP/${req.httpVersion}\r\n` + Object.entries(headers).map(([k, v]) => `${k}: ${v}\r\n`).join('') + '\r\n'; + const pending = [{ data: Buffer.concat([Buffer.from(requestHead), head]), acts: arrived(head) }]; + openConnection({ port: Number(destination.port), host: destination.hostname }, downstreamId, 'websocket', (error, connected) => { + if (error || socket.destroyed) { + connected?.destroy(); + socket.destroy(); + return; + } + up = connected; + for (const { data, acts } of pending) + writeLater(up, data, acts, true); + pending.length = 0; + up.on('data', data => writeLater(socket, data)); + up.on('end', () => later(() => socket.end())); + up.on('error', () => socket.destroy()); + up.on('close', () => later(() => socket.destroy())); + }); + socket.on('data', data => { + const acts = arrived(data); + if (up) + writeLater(up, data, acts); + else + pending.push({ data, acts }); + }); + socket.on('end', () => later(() => up?.end())); + socket.on('error', () => up?.destroy()); + socket.on('close', () => up?.destroy()); + }); + server.on("connection", (s) => { + const connectionId = ++nextConnection; + log('connection_open', { direction: 'downstream', connectionId, transport: 'tcp' }); + const agent = new Agent({ keepAlive: true, maxSockets: 1 }); + agents.add(agent); + agent.createConnection = (options, callback) => { openConnection(options, connectionId, 'http', callback); return undefined; }; + paired.set(s, { connectionId, agent }); + sockets.add(s); + s.once('close', () => { sockets.delete(s); agent.destroy(); agents.delete(agent); log('connection_close', { direction: 'downstream', connectionId, transport: 'tcp' }); }); + }); + await new Promise((resolve) => server.listen(0, "127.0.0.1", resolve)); + return { + server, url: `http://127.0.0.1:${server.address().port}`, + close: async () => { + for (const timer of timers) + clearTimeout(timer); + for (const agent of agents) + agent.destroy(); + for (const up of upstreams) + up.destroy(); + for (const s of sockets) + s.destroy(); + await new Promise((resolve) => server.close(resolve)); + }, + }; +} diff --git a/scripts/browser-speed/page.html b/scripts/browser-speed/page.html new file mode 100644 index 000000000..d74bdc22a --- /dev/null +++ b/scripts/browser-speed/page.html @@ -0,0 +1,15 @@ +Browser speed probe +
Click target
Hover target
+ diff --git a/scripts/browser-speed/summarize.mjs b/scripts/browser-speed/summarize.mjs new file mode 100644 index 000000000..6f511062a --- /dev/null +++ b/scripts/browser-speed/summarize.mjs @@ -0,0 +1,122 @@ +import assert from 'node:assert/strict'; +import { stats, hopTimings, cpuIntervals } from './common.mjs'; +import { colourValue } from './viewer.mjs'; +export function attributeSample(s, viewer, pageEvents, logs, links) { + const near = (a, b) => Math.abs(a - b) < 2; + const within = at => at >= s.start - 2 && at <= s.paint.at + 2; + const type = s.kind === 'click' ? 'mouseReleased' : 'mouseMoved'; + const x = s.kind === 'click' ? 200 : 700; + const queued = viewer.inputs.find(e => e.phase === 'queued' && e.type === type && near(e.x, x) && near(e.y, 200) && within(e.at)); + assert.ok(queued, `${s.scenario}: queued observation`); + const sent = viewer.inputs.find(e => e.phase === 'sent' && e.type === type && near(e.x, x) && near(e.y, 200) && e.at >= queued.at && within(e.at)); + assert.ok(sent, `${s.scenario}: sent observation`); + const cloud = logs.find(e => e.phase === 'cloud_got' && e.type === type && near(e.x, x) && near(e.y, 200) && e.at >= sent.at - 2 && within(e.at)); + const runner = logs.find(e => e.phase === 'runner_got' && e.type === type && near(e.x, x) && near(e.y, 200) && e.at >= cloud?.at && within(e.at)); + const handled = pageEvents.find(e => e.kind === s.kind && e.value === s.value && e.at >= runner?.at - 2 && within(e.at)); + assert.ok(cloud && runner && handled, `${s.scenario}: Cloud, runner and page observations`); + const decoded = viewer.decoded.find(f => logs.some(e => e.phase === 'source_frame' && e.timestamp === f.timestamp && e.at >= handled.at && within(e.at)) && colourValue(f.colours[s.kind === 'click' ? 0 : 1], s.kind) === s.value); + const received = viewer.received.find(f => f.timestamp === decoded?.timestamp && within(f.at)); + const produced = logs.find(e => e.phase === 'source_frame' && e.timestamp === decoded?.timestamp && within(e.at)); + const forwarded = logs.find(e => e.phase === 'cloud_frame' && e.timestamp === decoded?.timestamp && within(e.at)); + assert.ok(decoded && received && produced && forwarded, `${s.scenario}: first changed frame observations`); + const dom = viewer.dom.find(e => e.type === (s.kind === 'click' ? 'mousedown' : 'mousemove') && within(e.at)); + assert.ok(dom, `${s.scenario}: real viewer input`); + const times = { input: dom.at, queued: queued.at, sent: sent.at, cloud: cloud.at, runner: runner.at, handled: handled.at, frame: decoded.timestamp * 1000, sourceReceived: produced.at, forwarded: forwarded.at, received: received.at, painted: s.paint.at }; + s.times = times; + const press = s.kind === 'click' ? viewer.inputs.find(e => e.phase === 'queued' && e.type === 'mousePressed' && near(e.x, x) && near(e.y, 200) && within(e.at)) : queued; + assert.ok(press, 'press queue observation'); + s.queueDepth = press.depth; + assert.equal(s.paint.timestamp, decoded.timestamp, 'painted frame must be the first changed source frame'); + const proxyIn = links.find(e => e.phase === 'proxy_act_in' && e.type === type && near(e.x, x) && near(e.y, 200) && e.at >= sent.at - 2 && within(e.at)); + const proxyOut = links.find(e => e.phase === 'proxy_act_out' && e.type === type && near(e.x, x) && near(e.y, 200) && e.at >= proxyIn?.at && within(e.at)); + const proxyReady = links.find(e => e.phase === 'proxy_act_ready' && e.actId === proxyIn?.actId && within(e.at)); + const connection = links.find(e => e.phase === 'proxy_act_connection' && e.actId === proxyIn?.actId && within(e.at)); + const frameIn = links.find(e => e.phase === 'proxy_sse_in' && e.timestamp === decoded.timestamp && within(e.at)); + const frameOut = links.find(e => e.phase === 'proxy_sse_out' && e.timestamp === decoded.timestamp && within(e.at)); + assert.ok(proxyIn && proxyReady && proxyOut && connection && frameIn && frameOut, 'proxy hop observations'); + Object.assign(times, { proxyIn: proxyIn.at, proxyReady: proxyReady.at, proxyOut: proxyOut.at, frameIn: frameIn.at, frameOut: frameOut.at }); + s.connection = { connectionId: connection.connectionId, newConnection: connection.newConnection, setupMs: connection.setupMs }; + if (s.kind === 'click') { + const pressConnection = links.find(e => e.phase === 'proxy_act_connection' && e.type === 'mousePressed' && near(e.x, x) && near(e.y, 200) && within(e.at)); + assert.ok(pressConnection, 'press connection observation'); + s.pressConnection = { connectionId: pressConnection.connectionId, newConnection: pressConnection.newConnection, setupMs: pressConnection.setupMs }; + } + s.hops = { ...hopTimings(times), send_to_local_forward: times.proxyIn - times.sent, outbound_delay: times.proxyReady - times.proxyIn, connection_setup_and_write: times.proxyOut - times.proxyReady, proxy_to_cloud: times.cloud - times.proxyOut, cloud_to_proxy: times.frameIn - times.forwarded, inbound_delay: times.frameOut - times.frameIn, proxy_to_viewer: times.received - times.frameOut }; + for (const [key, ms] of Object.entries(s.hops)) + if (!['page_to_frame', 'frame_to_cloud'].includes(key)) + assert.ok(ms >= -2, `${key}: reversed boundary ${ms}`); + s.total = times.painted - times.input; + s.queueWait = times.sent - times.queued; + return s; +} +export function summarize(raw, logs, links = []) { + const delay = raw.linkMs; + raw.timings = logs.filter(l => l.at >= raw.measurementStart && l.at <= raw.measurementEnd); + for (const s of raw.samples) + attributeSample(s, raw.viewer, raw.page.events, logs, links); + const summary = { linkMs: delay, metrics: {}, hops: {}, byScenario: {}, caveats: ["Local two-person apps use next dev; not production or a real Orgo computer.", "Canvas photon is first requestAnimationFrame pixel observation; physical display and network jitter are not measured.", "CPU sums clamped per-PID time deltas only for PIDs present in both samples. Appearing/exiting helpers cause a slight undercount; churn is recorded. CPU is informational and cannot gate latency. Relay process includes fixture servers and proxy.", "New upstream TCP connections pay one extra modeled RTT in addition to data propagation; local HTTP has no TLS. The real HTTPS leg pays one more RTT for TLS per new connection than measured.", "Two pixels are read from each reused decoded bitmap; measurement overhead is included.", "Chrome metadata.timestamp is expected display time, which can follow actual JPEG delivery. Metadata deltas are signed, not transit durations. Actual page_to_encoded_frame and encoded_frame_to_cloud use the runner's frame callback. See Chromium page_handler.cc ScreencastFrameTimestamp."] }; + for (const scenario of ['rest', 'moving', 'hover', 'idle']) { + const samples = raw.samples.filter(s => s.scenario === scenario); + assert.equal(samples.length, scenario === 'moving' ? 15 : scenario === 'idle' ? 10 : 30); + summary.metrics[`${scenario}_to_photon_ms`] = stats(samples.map(s => s.total)); + summary.metrics[`${scenario}_queue_depth`] = stats(samples.map(s => s.queueDepth)); + summary.metrics[`${scenario}_queue_wait_ms`] = stats(samples.map(s => s.queueWait)); + if (scenario !== 'hover') + summary.metrics[`${scenario}_press_connection_setup_ms`] = stats(samples.map(s => s.pressConnection.setupMs)); + summary.byScenario[scenario] = Object.fromEntries(Object.keys(samples[0].hops).map(h => [h, stats(samples.map(s => s.hops[h]))])); + } + for (const sample of raw.samples.filter(s => s.scenario === 'idle')) { + assert.ok(sample.idle?.waitedMs >= 6000, 'six-second idle wait'); + assert.ok(!links.some(e => e.phase === 'proxy_act_in' && e.at > sample.idle.start && e.at < sample.start - 2), 'idle must not send an act before the click'); + } + for (const hop of Object.keys(raw.samples[0].hops)) + summary.hops[hop] = stats(raw.samples.map(s => s.hops[hop])); + const inScroll = (t) => t >= raw.scroll.start && t < raw.scroll.end; + const sourceFrames = raw.timings.filter(f => f.phase === 'source_frame' && inScroll(f.at)); + const viewerFrames = raw.viewer.painted.filter(f => inScroll(f.at)); + const receivedFrames = raw.viewer.received.filter(f => inScroll(f.at)); + const bins = (rows, time, value) => Array.from({ length: 5 }, (_, i) => rows.filter(r => time(r) >= raw.scroll.start + i * 1000 && time(r) < raw.scroll.start + (i + 1) * 1000).reduce((sum, r) => sum + value(r), 0)); + summary.metrics.source_scroll_fps = stats(bins(sourceFrames, f => f.at, () => 1)); + summary.metrics.viewer_scroll_fps = stats(bins(viewerFrames, f => f.at, () => 1)); + summary.metrics.jpeg_bytes_per_second = stats(bins(receivedFrames, f => f.at, f => f.bytes)); + summary.metrics.sse_json_bytes_per_second = stats(bins(receivedFrames, f => f.at, f => f.wireBytes)); + summary.metrics.jpeg_bytes_per_frame = stats(receivedFrames.map(f => f.bytes)); + raw.cpuIntervals = cpuIntervals(raw.cpu); + summary.metrics.chrome_cpu_percent = stats(raw.cpuIntervals.map(c => c.chrome).filter(Number.isFinite)); + summary.metrics.relay_cpu_percent = stats(raw.cpuIntervals.map(c => c.relay).filter(Number.isFinite)); + summary.cpu = { nonBlocking: true, samplingErrors: raw.cpuErrors ?? [], appearedPids: raw.cpuIntervals.reduce((n, c) => n + c.appearedPids, 0), exitedPids: raw.cpuIntervals.reduce((n, c) => n + c.exitedPids, 0), byScenario: {} }; + for (const scenario of ['rest', 'moving', 'hover', 'idle', 'scroll']) { + const rows = raw.cpuIntervals.filter(c => c.scenario === scenario); + summary.metrics[`chrome_${scenario}_cpu_percent`] = stats(rows.map(c => c.chrome).filter(Number.isFinite)); + summary.metrics[`relay_${scenario}_cpu_percent`] = stats(rows.map(c => c.relay).filter(Number.isFinite)); + summary.cpu.byScenario[scenario] = { intervals: rows.length, appearedPids: rows.reduce((n, c) => n + c.appearedPids, 0), exitedPids: rows.reduce((n, c) => n + c.exitedPids, 0) }; + } + summary.connections = {}; + for (const window of raw.scenarios ?? []) { + const acts = links.filter(e => e.phase === 'proxy_act_connection' && e.at >= window.start && e.at <= window.end); + const opens = links.filter(e => e.phase === 'connection_open' && e.at >= window.start && e.at <= window.end); + summary.connections[window.name] = { acts: acts.length, actsOpeningConnection: acts.filter(e => e.newConnection).length, actsReusingConnection: acts.filter(e => !e.newConnection).length, downstreamConnections: opens.filter(e => e.direction === 'downstream').length, upstreamConnections: opens.filter(e => e.direction === 'upstream').length }; + } + summary.connections.idlePressesOpeningConnection = raw.samples.filter(s => s.scenario === 'idle' && s.pressConnection?.newConnection).length; + const from = raw.samples[0].start, to = raw.samples.at(-1).paint.at; + const produced = new Set(logs.filter(l => l.phase === 'source_frame' && l.at >= from && l.at <= to).map(f => f.timestamp)); + const received = new Set(raw.viewer.received.map(f => f.timestamp)); + summary.integrity = { unreceivedSourceFrames: [...produced].filter(t => !received.has(t)).length, clock: raw.clock }; + assert.equal(summary.integrity.unreceivedSourceFrames, 0, 'Source colour attribution requires every source frame during input scenarios'); + // Others watching while the driver drives: when each first painted the change, from the driver's own input, and how + // long after the driver's window it was; and each one's frames a second while scrolling. + summary.driver = raw.driver ?? 'owner'; + summary.watchers = (raw.watchers ?? []).map(w => w.who); + if (summary.watchers.length) { + for (const scenario of ['rest', 'moving', 'hover', 'idle']) { + const seen = raw.samples.filter(s => s.scenario === scenario).flatMap(s => s.watchers.map(w => ({ total: w.at - s.times.input, behind: w.at - s.paint.at }))); + assert.equal(seen.length, raw.samples.filter(s => s.scenario === scenario).length * summary.watchers.length, `${scenario}: every watcher saw every change`); + summary.metrics[`watcher_${scenario}_to_photon_ms`] = stats(seen.map(w => w.total)); + summary.metrics[`watcher_${scenario}_behind_driver_ms`] = stats(seen.map(w => w.behind)); + } + summary.metrics.watcher_scroll_fps = stats(raw.watchers.flatMap(w => bins(w.painted.filter(f => inScroll(f.at)), f => f.at, () => 1))); + summary.caveats.push("Watchers are pages on this same Mac (one headless Chrome), so they share its CPU with the driver; in real use each is on its own Mac. Per-hop splits are the driver's; a watcher's figures are its first paint of the change."); + } + assert.ok(sourceFrames.length > 0 && viewerFrames.length > 0 && receivedFrames.length > 0, 'non-empty scrolling observations'); + return summary; +} diff --git a/scripts/browser-speed/viewer.mjs b/scripts/browser-speed/viewer.mjs new file mode 100644 index 000000000..38d13d621 --- /dev/null +++ b/scripts/browser-speed/viewer.mjs @@ -0,0 +1,75 @@ +// Injected into the viewer before the app boots. Measures the real EventSource, decoder and canvas. +export function installViewerProbe() { + const clock = () => performance.timeOrigin + performance.now(); + const state = window.__speed = { inputs: [], dom: [], received: [], decoded: [], painted: [], pending: 0 }; + window.addEventListener('bops-browser-probe', ({ detail }) => { + state.inputs.push(detail); + if (detail.phase === 'queued') + state.pending++; + if (detail.phase === 'settled') + state.pending--; + }); + for (const type of ['mousedown', 'mousemove']) + document.addEventListener(type, e => { + if (e.target.closest?.('[data-bot-browser]')) + state.dom.push({ type, at: performance.timeOrigin + e.timeStamp, x: e.clientX, y: e.clientY }); + }, true); + let incoming = null; + const EventSourceOriginal = window.EventSource; + window.EventSource = class extends EventSourceOriginal { + constructor(...args) { + super(...args); + this.addEventListener('frame', (e) => { + const m = JSON.parse(e.data); + incoming = { at: clock(), timestamp: m.meta.timestamp, bytes: m.data.length * 3 / 4 - (m.data.endsWith('==') ? 2 : m.data.endsWith('=') ? 1 : 0), wireBytes: new TextEncoder().encode(e.data).length, meta: m.meta }; + state.received.push(incoming); + }); + } + }; + const bitmaps = new WeakMap(); + const sampleCanvas = document.createElement('canvas'); + sampleCanvas.width = 2; + sampleCanvas.height = 1; + const sample = sampleCanvas.getContext('2d', { willReadFrequently: true }); + const draw = CanvasRenderingContext2D.prototype.drawImage; + const colours = (context, width, height, meta) => { + const points = [[200, 200], [700, 200]]; + return points.map(([x, y]) => [...context.getImageData(Math.floor(x * width / meta.deviceWidth), Math.floor(y * height / meta.deviceHeight), 1, 1).data].slice(0, 3)); + }; + const create = window.createImageBitmap.bind(window); + window.createImageBitmap = async (...args) => { + const frame = incoming; + const b = await create(...args); + if (frame) { + bitmaps.set(b, frame); + // Two one-pixel samples; reuse the app's decode, never start another capture or decoder. + [[200, 200], [700, 200]].forEach(([x, y], i) => draw.call(sample, b, x * b.width / frame.meta.deviceWidth, y * b.height / frame.meta.deviceHeight, 1, 1, i, 0, 1, 1)); + const p = sample.getImageData(0, 0, 2, 1).data; + state.decoded.push({ at: clock(), timestamp: frame.timestamp, colours: [[...p.slice(0, 3)], [...p.slice(4, 7)]] }); + } + return b; + }; + let latest = null, seen = null; + CanvasRenderingContext2D.prototype.drawImage = function (...args) { + const result = draw.apply(this, args); + if (this.canvas.closest?.('[data-bot-browser]') && bitmaps.has(args[0])) + latest = { frame: bitmaps.get(args[0]), canvas: this.canvas, drawnAt: clock() }; + return result; + }; + const tick = () => { + if (latest && latest.frame.timestamp !== seen) { + const { frame, canvas, drawnAt } = latest; + if (canvas.width && canvas.height) { + state.painted.push({ at: clock(), drawnAt, timestamp: frame.timestamp, colours: colours(canvas.getContext('2d', { willReadFrequently: true }), canvas.width, canvas.height, frame.meta) }); + seen = frame.timestamp; + } + } + requestAnimationFrame(tick); + }; + requestAnimationFrame(tick); +} +export const PALETTE = { click: [[40, 80, 220], [220, 40, 40]], hover: [[220, 180, 40], [40, 180, 70]] }; +export const colourValue = (rgb, kind) => { + const value = PALETTE[kind].findIndex(expected => expected.every((channel, i) => Math.abs(rgb[i] - channel) <= 35)); + return value < 0 ? null : value; +}; diff --git a/scripts/dev-two-person.mjs b/scripts/dev-two-person.mjs index 4ca709954..d1262dbd3 100644 --- a/scripts/dev-two-person.mjs +++ b/scripts/dev-two-person.mjs @@ -285,7 +285,7 @@ function scriptedModel(b) { function cleanEnv() { const env = {}; for (const [k, v] of Object.entries(process.env)) if (!/^(BOPS|OPENAI|AGENTPHONE|AGENTMAIL|HONCHO|COMPOSIO|TYPESAFE|TWILIO|ORGO|POSTHOG|SENTRY|ANTHROPIC|NEXT_PUBLIC)_/.test(k)) env[k] = v; - return { ...env, NEXT_TELEMETRY_DISABLED: "1", BOPS_TELEMETRY: "0", DO_NOT_TRACK: "1" }; + return { ...env, NEXT_TELEMETRY_DISABLED: "1", BOPS_TELEMETRY: "0", DO_NOT_TRACK: "1", ...(process.env.BOPS_BROWSER_PROBE === "1" ? { BOPS_BROWSER_PROBE: "1" } : {}) }; } /** macOS's `security`, with a folder for a Keychain (as scripts/test-delete-messages-cloud.mjs). */ @@ -521,6 +521,21 @@ async function serve() { }); await waitFor("Bops Cloud", () => cloud.output().includes(`listening on 127.0.0.1:${ports.cloud}`), 60_000); + // Probe only: delay the app-to-Cloud link, leaving the runner's link untouched. + if (process.env.TWO_PERSON_BROWSER_LINK_MS !== undefined) { + const delay = Number(process.env.TWO_PERSON_BROWSER_LINK_MS); + if (![0, 35].includes(delay)) throw new Error("TWO_PERSON_BROWSER_LINK_MS must be 0 or 35"); + const { startLink } = await import("./browser-speed/link.mjs"); + const logFile = join(HERE, "link.jsonl"); + writeFileSync(logFile, ""); + const proxy = await startLink(urls.cloud, delay, logFile); + servers.push(proxy.server); + urls.browserProxy = proxy.url; + ports.browserProxy = Number(new URL(proxy.url).port); + state.probe = { delay, timing: process.env.BOPS_BROWSER_PROBE === "1", logFile }; + save(); + } + /* The owner's state, before either app starts: the bot on the stand-in computer, and sam's access. */ const pg = require("pg"); const db = new pg.Client({ connectionString: DB }); @@ -605,7 +620,7 @@ async function serve() { HOME: home, PATH: `${bin}:${process.env.PATH}`, BOPS_TEST_KEYCHAIN: keychain, - BOPS_CLOUD_URL: urls.cloud, + BOPS_CLOUD_URL: urls.browserProxy ?? urls.cloud, BOPS_ORGO_ORIGIN: ORGO, ...(dist ? { BOPS_NEXT_DIST_DIR: dist } : {}), }, diff --git a/scripts/fixtures/browser-speed-cpu-counterexample.json b/scripts/fixtures/browser-speed-cpu-counterexample.json new file mode 100644 index 000000000..988694bfe --- /dev/null +++ b/scripts/fixtures/browser-speed-cpu-counterexample.json @@ -0,0 +1,66 @@ +{ + "i": 23, + "scenario": "rest", + "elapsedMs": 984.711181640625, + "chromeCentiseconds": -8, + "before": { + "at": 1794014594026.2554, + "scenario": "rest", + "chromeTimes": { + "91728": 1.44, + "91734": 0.31, + "91735": 0.3, + "91736": 0.03, + "91739": 0.1, + "91742": 0.17, + "91743": 0.05, + "91745": 0.05, + "91747": 0.05, + "91930": 0.04, + "92672": 0.01, + "92675": 0.01 + }, + "chromePids": [ + 91728, + 91734, + 91735, + 91736, + 91739, + 91742, + 91743, + 91745, + 91747, + 91930, + 92672, + 92675 + ], + "relaySeconds": 0.99 + }, + "after": { + "at": 1794014595010.9666, + "scenario": "rest", + "chromeTimes": { + "91728": 1.49, + "91734": 0.31, + "91735": 0.31, + "91736": 0.03, + "91739": 0.1, + "91742": 0.18, + "91930": 0.04, + "92672": 0.01, + "92675": 0.01 + }, + "chromePids": [ + 91728, + 91734, + 91735, + 91736, + 91739, + 91742, + 91930, + 92672, + 92675 + ], + "relaySeconds": 1.01 + } +} diff --git a/scripts/probe-browser-speed.mjs b/scripts/probe-browser-speed.mjs new file mode 100644 index 000000000..d761faf3d --- /dev/null +++ b/scripts/probe-browser-speed.mjs @@ -0,0 +1,261 @@ +// Outside-in baseline. The only implementation-specific observation is the opt-in hidden queue counter. +import assert from 'node:assert/strict'; +import { spawn, spawnSync } from 'node:child_process'; +import { copyFileSync, readFileSync, writeFileSync } from 'node:fs'; +import { join } from 'node:path'; +import { chromium } from 'playwright'; +import { BOT, PROJECT } from './fixtures/two-person.mjs'; +import { args, cleanupSteps, connectPage, cpuSeconds, cpuTree, now, sleep, testSite, until } from './browser-speed/common.mjs'; +import { installViewerProbe, PALETTE } from './browser-speed/viewer.mjs'; +import { summarize } from './browser-speed/summarize.mjs'; +const root = new URL('..', import.meta.url).pathname.replace(/\/$/, ''); +const options = args(process.argv.slice(2)); +if (options['link-ms'] === undefined) + throw new Error('--link-ms is required'); +const delay = Number(options['link-ms']); +const out = options.out; +const statePath = join(root, '.scratch/two-person/stack.json'); +function running() { + try { + const s = JSON.parse(readFileSync(statePath, 'utf8')); + process.kill(s.pid, 0); + return s.ready ? s : null; + } + catch { + return null; + } +} +async function stackCommand(command, env = process.env) { + const child = spawn(process.execPath, ['scripts/dev-two-person.mjs', command], { cwd: root, env, stdio: 'inherit' }); + const code = await new Promise((resolve, reject) => { child.once('error', reject); child.once('exit', resolve); }); + if (code !== 0) + throw new Error(`two-person ${command} exited ${code}`); +} +const raw = { version: 2, linkMs: delay, startedAt: now(), samples: [], cpu: [], cpuErrors: [], scenarios: [], scroll: null, clock: [], errors: [] }; +let started = false, stack, browser, context, page, source, site, cpuTimer; +/** Others watching the bot's browser while the driver drives it, each its own page and stream. */ +const watchers = []; +const write = (name, value) => writeFileSync(join(out, name), JSON.stringify(value, null, 2)); +let cleanupPromise; +function cleanup() { return cleanupPromise ??= performCleanup(); } +async function performCleanup() { + clearInterval(cpuTimer); + if (page && !page.isClosed()) + raw.viewer = await page.evaluate(() => window.__speed).catch(() => null); + // A watcher's frames, as when it got and painted each (not its pixels: the samples say when it showed the change). + for (const w of watchers) + w.speed = await w.page.evaluate(() => ({ received: window.__speed.received.map(f => ({ at: f.at, timestamp: f.timestamp, bytes: f.bytes })), painted: window.__speed.painted.map(f => ({ at: f.at, timestamp: f.timestamp })) })).catch(() => null); + raw.watchers = watchers.map(w => ({ who: w.who, ...w.speed })); + if (source) + raw.page = await source.eval('window.__probe').catch(() => null); + raw.endedAt = now(); + await cleanupSteps(() => write('raw.json', raw), [ + () => { + if (stack) + copyFileSync(join(root, '.scratch/two-person/stack.log'), join(out, 'stack.log')); + }, + () => { + if (stack?.probe?.logFile) + copyFileSync(stack.probe.logFile, join(out, 'link.jsonl')); + }, + () => source?.close(), ...watchers.map(w => () => w.context.close()), () => context?.close(), () => browser?.close(), () => site?.close(), + () => started ? stackCommand('stop') : undefined, + ]); +} +for (const signal of ['SIGINT', 'SIGTERM']) + process.once(signal, () => { raw.errors.push(signal); void cleanup().finally(() => process.exit(1)); }); +try { + raw.revision = spawnSync('git', ['rev-parse', 'HEAD'], { cwd: root, encoding: 'utf8' }).stdout.trim(); + stack = running(); + if (stack && (!stack.probe?.timing || stack.probe.delay !== delay)) + throw new Error('Existing stack has a different probe configuration; stop it explicitly before this run.'); + if (!stack) { + started = true; + await stackCommand('start', { ...process.env, BOPS_BROWSER_PROBE: '1', TWO_PERSON_BROWSER_LINK_MS: String(delay) }); + stack = running(); + } + assert.ok(stack?.probe?.timing, 'timing-enabled local stack'); + raw.stack = { ports: stack.ports, urls: stack.urls, pid: stack.pid, probe: stack.probe }; + site = await testSite(); + source = await connectPage(stack.ports.chrome); + await source.send('Page.navigate', { url: site.url }); + await until(() => source.eval('!!window.__probe'), 'source test page'); + const proc = spawnSync('ps', ['-o', 'pid=,comm=', '-p', stack.children.join(',')], { encoding: 'utf8' }); + const chromePid = Number(proc.stdout.split('\n').find(l => l.includes('Google Chrome'))?.trim().split(/\s+/)[0]); + if (!chromePid) + raw.cpuErrors.push({ at: now(), scenario: 'setup', error: 'Stand-in Chrome PID not observed; CPU unavailable' }); + browser = await chromium.launch({ channel: 'chrome', headless: true }); + raw.versions = { node: process.version, source: (await source.send('Browser.getVersion')).product, viewer: browser.version(), platform: process.platform }; + // One person's Bops showing the bot's browser: the owner's, or sam's in the owner's shared workspace (as a Member). + async function openViewer(who) { + const ctx = await browser.newContext({ viewport: { width: 1440, height: 900 }, deviceScaleFactor: 1 }); + await ctx.route(/^(?!(https?|wss?):\/\/127\.0\.0\.1[:/])(?!data:)(?!blob:)/, r => r.abort()); + await ctx.addInitScript(installViewerProbe); + const p = await ctx.newPage(); + await p.goto(stack.urls[who], { waitUntil: 'load' }); + if (who === 'sam') { + const opened = await p.evaluate((id) => fetch('/api/workspaces/shared', { method: 'POST', headers: { 'content-type': 'application/json' }, body: JSON.stringify({ open: id }) }).then(r => r.status), PROJECT.id); + assert.equal(opened, 200, 'sam opens the shared workspace'); + await p.reload({ waitUntil: 'load' }); + } + // The browser's tab, unless it's in front already (a Member's only tab is): a press on the open tab would close it. + const tab = p.locator(`div.group\\/tab[title="${BOT.name}'s browser"]`); + await tab.waitFor({ timeout: 30000 }); + if (!(await tab.evaluate(t => t.classList.contains('bg-white')))) + await tab.click(); + await p.locator('[data-bot-browser] canvas[data-drawn]').waitFor({ timeout: 30000 }); + return { who, context: ctx, page: p }; + } + raw.driver = options.driver; + ({ context, page } = await openViewer(options.driver)); + const other = options.driver === 'owner' ? 'sam' : 'owner'; + for (let i = 0; i < options.watchers; i++) + watchers.push(await openViewer(other)); + await page.getByRole('button', { name: 'Take over', exact: true }).click(); + await page.getByRole('button', { name: 'Hand back', exact: true }).waitFor(); + await until(() => page.evaluate(() => window.__speed.painted.length), 'observed canvas paint'); + const drained = () => until(() => page.evaluate(() => window.__speed.pending === 0), 'viewer queue drained', 30000); + const point = async (x, y) => page.locator('[data-bot-browser] canvas').evaluate((c, { x, y }) => { + const r = c.getBoundingClientRect(); + const m = window.__speed.received.at(-1).meta; + return { x: r.left + x * r.width / m.deviceWidth, y: r.top + y * r.height / m.deviceHeight }; + }, { x, y }); + const move = async (x, y) => { const p = await point(x, y); await page.mouse.move(p.x, p.y); }; + const paintedOn = (p, kind, value, start, latest = false) => until(() => p.evaluate(({ kind, start, latest, expected }) => { + const index = kind === 'click' ? 0 : 1; + const matches = p => p && p.at >= start && expected.every((channel, i) => Math.abs(p.colours[index][i] - channel) <= 35); + return latest ? (matches(window.__speed.painted.at(-1)) && window.__speed.painted.at(-1)) : window.__speed.painted.find(matches); + }, { kind, start, latest, expected: PALETTE[kind][value] }), `${kind} colour at viewer`, 30000); + const painted = (...a) => paintedOn(page, ...a); + // When each watcher first painted the change the driver made (their first frame of it after `start`). + const seenBy = (kind, value, start) => Promise.all(watchers.map(async (w) => ({ who: w.who, at: (await paintedOn(w.page, kind, value, start)).at }))); + // Warm route compilation, then exclude it from the measurement interval. + await move(200, 200); + await drained(); + await sleep(500); + for (const [name, readClock] of [['viewer', () => page.evaluate(() => performance.timeOrigin + performance.now())], ['source', () => source.eval('performance.timeOrigin+performance.now()')]]) { + for (let i = 0; i < 5; i++) { + const a = now(); + const theirs = await readClock(); + const b = now(); + raw.clock.push({ name, at: theirs, offsetMs: theirs - (a + b) / 2, uncertaintyMs: (b - a) / 2 }); + } + } + let scenario = 'rest'; + const sampleCPU = () => { + try { + if (!chromePid) + throw new Error('Stand-in Chrome PID unavailable'); + const chrome = cpuTree(chromePid); + const r = spawnSync('ps', ['-p', String(stack.pid), '-o', 'time='], { encoding: 'utf8' }); + if (r.status !== 0) + throw new Error('relay ps failed'); + raw.cpu.push({ at: now(), scenario, chromeTimes: chrome.times, chromePids: chrome.pids, relaySeconds: cpuSeconds(r.stdout.trim()) }); + } + catch (error) { + raw.cpuErrors.push({ at: now(), scenario, error: String(error.message ?? error) }); + } + }; + sampleCPU(); + cpuTimer = setInterval(sampleCPU, 1000); + raw.measurementStart = now(); + raw.scenarios.push({ name: 'rest', start: raw.measurementStart }); + const nextScenario = name => { sampleCPU(); raw.scenarios.at(-1).end = now(); scenario = name; raw.scenarios.push({ name, start: now() }); sampleCPU(); }; + let clickValue = await source.eval('window.__probe.click'); + async function clickSample(scenario, moving, idleMs = 0) { + await drained(); + await move(200, 200); + await drained(); + await sleep(150); + if (moving) { + const end = now() + 2000; + while (now() < end) { + const t = now(); + await move(200 + 100 * Math.sin(t / 60), 200 + 70 * Math.cos(t / 80)); + await sleep(8); + } + await move(200, 200); + } + let idle; + if (idleMs) { + const start = now(); + // A timer can end a fraction of a millisecond early by this clock: wait out the rest. + while (now() - start < idleMs) + await sleep(Math.max(1, idleMs - (now() - start))); + idle = { start, end: now(), waitedMs: now() - start }; + } + const start = now(); + // The pointer is already in place. Avoid Playwright click's extra mouse move warming an idle connection. + await page.mouse.down(); + await page.mouse.up(); + clickValue ^= 1; + const paint = await painted('click', clickValue, start); + raw.samples.push({ scenario, kind: 'click', value: clickValue, start, paint, watchers: await seenBy('click', clickValue, start), ...(idle ? { idle } : {}) }); + await sleep(Math.max(0, 650 - (now() - start))); + } + console.log(`link ${delay} ms: 30 rest clicks`); + for (let i = 0; i < 30; i++) + await clickSample('rest', false); + console.log(`link ${delay} ms: 15 clicks after two seconds moving`); + nextScenario('moving'); + for (let i = 0; i < 15; i++) + await clickSample('moving', true); + console.log(`link ${delay} ms: 30 hovers`); + nextScenario('hover'); + for (let i = 0; i < 30; i++) { + await move(1000, 400); + await drained(); + await painted('hover', 0, 0, true); + await sleep(100); + const start = now(); + await move(700, 200); + const paint = await painted('hover', 1, start); + raw.samples.push({ scenario: 'hover', kind: 'hover', value: 1, start, paint, watchers: await seenBy('hover', 1, start) }); + await drained(); + await sleep(150); + } + console.log(`link ${delay} ms: 10 clicks after six seconds idle`); + nextScenario('idle'); + for (let i = 0; i < 10; i++) + await clickSample('idle', false, 6000); + await move(1000, 500); + await drained(); + await sleep(200); + console.log(`link ${delay} ms: five seconds scrolling`); + nextScenario('scroll'); + const scrollStart = now(); + while (now() - scrollStart < 5000) { + await page.mouse.wheel(0, 80); + await sleep(16); + } + raw.scroll = { start: scrollStart, end: scrollStart + 5000 }; + await drained(); + await sleep(300); + sampleCPU(); + raw.scenarios.at(-1).end = now(); + raw.measurementEnd = now(); + await page.screenshot({ path: join(out, 'viewer.png') }); +} +catch (e) { + raw.errors.push(e.stack ?? String(e)); + throw e; +} +finally { + await cleanup(); +} +try { + const logs = readFileSync(join(out, 'stack.log'), 'utf8').split('\n').flatMap(l => { + const m = /\[browser-probe\] (\{.*\})/.exec(l); + return m ? [JSON.parse(m[1])] : []; + }); + const links = readFileSync(join(out, 'link.jsonl'), 'utf8').trim().split('\n').filter(Boolean).map(l => JSON.parse(l)); + const summary = summarize(raw, logs, links); + write('raw.json', raw); + write('summary.json', summary); + console.log(JSON.stringify(summary, null, 2)); +} +catch (e) { + raw.errors.push(e.stack ?? String(e)); + write('raw.json', raw); + throw e; +} diff --git a/scripts/probe-computer-side.mjs b/scripts/probe-computer-side.mjs new file mode 100644 index 000000000..9bea19bca --- /dev/null +++ b/scripts/probe-computer-side.mjs @@ -0,0 +1,74 @@ +// Node >=22 and Chrome; no Playwright needed. Only the Chrome/profile started here is stopped. +import { writeFileSync } from 'node:fs'; +import { join } from 'node:path'; +import { pathToFileURL } from 'node:url'; +import { args, connectPage, now, ownChrome, sleep, stats, testSite, until } from './browser-speed/common.mjs'; +export async function computerProbe(out) { + const site = await testSite(); + let chrome, cdp; + const images = new Map(); + const raw = { frames: [], clicks: [], scroll: null, settings: { format: 'jpeg', quality: 60, maxWidth: 1280, maxHeight: 1280, everyNthFrame: 1 } }; + try { + chrome = await ownChrome(out, site.url); + cdp = await connectPage(chrome.port); + await until(() => cdp.eval('!!window.__probe'), 'test page'); + cdp.on('Page.screencastFrame', (f) => { + void cdp.send('Page.screencastFrameAck', { sessionId: f.sessionId }).catch(() => { }); + raw.frames.push({ at: now(), timestamp: f.metadata.timestamp, bytes: Buffer.from(f.data, 'base64').length }); + images.set(f.metadata.timestamp, f.data); + }); + await cdp.send('Page.startScreencast', raw.settings); + await until(() => raw.frames.length, 'first screencast frame'); + await sleep(500); + for (let i = 0; i < 30; i++) { + const start = now(); + const before = raw.frames.length; + await cdp.send('Input.dispatchMouseEvent', { type: 'mousePressed', x: 200, y: 200, button: 'left', clickCount: 1 }); + await cdp.send('Input.dispatchMouseEvent', { type: 'mouseReleased', x: 200, y: 200, button: 'left', clickCount: 1 }); + const event = await until(async () => { const es = await cdp.eval('window.__probe.events'); return es.find(e => e.kind === 'click' && e.at >= start); }, 'computer click handled'); + const frame = await until(async () => { + for (const f of raw.frames.slice(before).filter(f => f.at >= event.at)) { + if (f.colour === undefined) { + f.colour = await cdp.eval(`(async()=>{const b=await createImageBitmap(await (await fetch('data:image/jpeg;base64,${images.get(f.timestamp)}')).blob());const c=new OffscreenCanvas(1,1);const x=c.getContext('2d');x.drawImage(b,200,200,1,1,0,0,1,1);b.close();const p=x.getImageData(0,0,1,1).data;return [[40,80,220],[220,40,40]].findIndex(rgb=>rgb.every((n,i)=>Math.abs(p[i]-n)<=35));})()`); + } + if (f.colour === event.value) + return f; + } + }, 'first frame with changed click colour'); + raw.clicks.push({ start, handled: event.at, frame: frame.timestamp * 1000, received: frame.at }); + await sleep(Math.max(0, 600 - (now() - start))); + } + const start = now(); + while (now() - start < 5000) { + await cdp.send('Input.dispatchMouseEvent', { type: 'mouseWheel', x: 1000, y: 500, deltaY: 80, deltaX: 0 }); + await sleep(16); + } + const end = now(); + await sleep(250); + const frames = raw.frames.filter(f => f.at >= start && f.at < end); + raw.scroll = { start, end, frames: frames.length, bytes: frames.reduce((s, f) => s + f.bytes, 0) }; + const perSecond = Array.from({ length: 5 }, (_, i) => frames.filter(f => f.at >= start + i * 1000 && f.at < start + (i + 1) * 1000)); + assertCounts(raw); + const summary = { dispatch_to_encoded_frame_ms: stats(raw.clicks.map(c => c.received - c.start)), page_to_encoded_frame_ms: stats(raw.clicks.map(c => c.received - c.handled)), dispatch_to_frame_ms: stats(raw.clicks.map(c => c.frame - c.start)), page_to_frame_ms: stats(raw.clicks.map(c => c.frame - c.handled)), scroll_fps: stats(perSecond.map(f => f.length)), scroll_bytes_per_second: stats(perSecond.map(fs => fs.reduce((s, f) => s + f.bytes, 0))), scroll_bytes_per_frame: stats(frames.map(f => f.bytes)), caveat: 'First JPEG verified to contain the changed colour; offscreen pixel sampling is used for click attribution. metadata.timestamp is expected display time, not encode completion; dispatch_to_encoded_frame_ms measures actual JPEG delivery. No physical display measurement. Owned Chrome only.' }; + writeFileSync(join(out, 'raw.json'), JSON.stringify(raw, null, 2)); + writeFileSync(join(out, 'summary.json'), JSON.stringify(summary, null, 2)); + return summary; + } + finally { + if (cdp) { + await cdp.send('Page.stopScreencast').catch(() => { }); + cdp.close(); + } + if (chrome) + await chrome.stop(); + await site.close(); + } +} +function assertCounts(raw) { + if (raw.clicks.length !== 30 || !raw.scroll.frames) + throw new Error('Incomplete computer-side observations'); +} +if (process.argv[1] && import.meta.url === pathToFileURL(process.argv[1]).href) { + const options = args(process.argv.slice(2)); + console.log(JSON.stringify(await computerProbe(options.out), null, 2)); +} diff --git a/scripts/test-browser-probe.mjs b/scripts/test-browser-probe.mjs new file mode 100644 index 000000000..c7d782309 --- /dev/null +++ b/scripts/test-browser-probe.mjs @@ -0,0 +1,261 @@ +import assert from "node:assert/strict"; +import { spawnSync } from "node:child_process"; +import { mkdirSync, readFileSync, writeFileSync } from 'node:fs'; +import { Agent, request } from 'node:http'; +import { test } from "node:test"; +import { createServer } from "node:http"; +import { args, cleanupSteps, cpuIntervals, cpuSeconds, hopTimings, stats } from "./browser-speed/common.mjs"; +import { now, startLink } from "./browser-speed/link.mjs"; +import { attributeSample } from './browser-speed/summarize.mjs'; +import { colourValue } from './browser-speed/viewer.mjs'; +import WebSocket, { WebSocketServer } from 'ws'; +test("timing logs are silent by default and never include typed text", () => { + const code = `import { probeInput } from './cloud/browser-probe.ts'; + probeInput('test', 'Input.dispatchMouseEvent', {type:'mousePressed',x:12,y:34,text:'PRIVATE'}); + probeInput('test', 'Input.insertText', {text:'PRIVATE'});`; + const run = (enabled) => spawnSync(process.execPath, ["--input-type=module", "-e", code], { + cwd: process.cwd(), encoding: "utf8", env: { ...process.env, BOPS_BROWSER_PROBE: enabled }, + }); + const off = run(""); + assert.equal(off.status, 0, off.stderr); + assert.equal(off.stdout + off.stderr, ""); + const on = run("1"); + assert.equal(on.status, 0, on.stderr); + assert.match(on.stdout + on.stderr, /mousePressed/); + assert.doesNotMatch(on.stdout + on.stderr, /PRIVATE|insertText/); +}); +test("summaries retain sample counts and reject missing numeric observations", () => { + assert.deepEqual(stats([100, 4, 7, 1]), { n: 4, median: 5.5, p90: 100 }); + assert.deepEqual(stats([]), { n: 0, median: null, p90: null }); + assert.throws(() => stats([1, NaN]), /Non-finite/); + assert.throws(() => args(['--link-ms', '36', '--out', '.scratch/probe-test']), /0 or 35/); +}); +test("proxy adds both one-way delays and streams the first event before upstream end", async () => { + let got, finish; + const gate = new Promise(r => { finish = r; }); + const upstream = createServer(async (req, res) => { + got = now(); + res.writeHead(200, { 'content-type': 'text/event-stream' }); + res.write('event: test\ndata: {"t":"test"}\n\n'); + await gate; + res.end('event: last\ndata: {"t":"last"}\n\n'); + }); + await new Promise(r => upstream.listen(0, '127.0.0.1', r)); + const proxy = await startLink(`http://127.0.0.1:${upstream.address().port}`, 35); + try { + const start = now(); + const res = await fetch(`${proxy.url}/v1/browser/watch`); + const first = await res.body.getReader().read(); + assert.ok(got - start >= 30, `upstream received after ${got - start}ms`); + assert.ok(now() - got >= 30, `downstream delay ${now() - got}ms`); + assert.match(new TextDecoder().decode(first.value), /event: test/); + assert.equal(res.status, 200); + } + finally { + finish(); + await proxy.close(); + upstream.closeAllConnections(); + await new Promise(r => upstream.close(r)); + } +}); +test("the delay proxy only forwards a path to its own upstream, never to a host the request names", async () => { + let upstreamHits = 0, elsewhereHits = 0; + const upstream = createServer((req, res) => { upstreamHits++; res.end('ok'); }); + const elsewhere = createServer((req, res) => { elsewhereHits++; res.end('elsewhere'); }); + await new Promise(r => upstream.listen(0, '127.0.0.1', r)); + await new Promise(r => elsewhere.listen(0, '127.0.0.1', r)); + const proxy = await startLink(`http://127.0.0.1:${upstream.address().port}`, 0); + const ask = (path) => new Promise((ok, no) => { + const r = request({ host: '127.0.0.1', port: new URL(proxy.url).port, path, agent: false }, (res) => { res.resume(); res.on('end', () => ok(res.statusCode)); }); + r.on('error', no); + r.end(); + }); + try { + const other = `127.0.0.1:${elsewhere.address().port}`; + assert.equal(await ask(`http://${other}/v1/browser/watch`), 400, "an absolute address is refused"); + assert.equal(await ask(`//${other}/v1/browser/watch`), 400, "a scheme-relative one too"); + assert.equal(elsewhereHits, 0, "nothing reached the other host"); + assert.equal(await ask('/v1/health?x=1'), 200, "a path goes to the upstream"); + assert.equal(upstreamHits, 1); + } + finally { + await proxy.close(); + for (const s of [upstream, elsewhere]) { + s.closeAllConnections(); + await new Promise(r => s.close(r)); + } + } +}); +test("Chrome expected-display metadata can be later than the encoded frame; preserve signed deltas", () => { + const times = { input: 0, sent: 1, cloud: 2, runner: 3, handled: 4, frame: 20, sourceReceived: 10, forwarded: 11, received: 12, painted: 14 }; + const hops = hopTimings(times); + assert.equal(hops.frame_to_cloud, -9); + assert.equal(hops.page_to_encoded_frame, 6); + assert.equal(hops.encoded_frame_to_cloud, 1); + assert.throws(() => hopTimings({ ...times, forwarded: 5 }), /encoded_frame_to_cloud/); +}); +test('click attribution follows release, retains press queue depth, and cannot borrow a later sample', () => { + const sample = { kind: 'click', value: 1, start: 100, paint: { at: 250, timestamp: .2 } }; + const input = (phase, type, at, depth = 0) => ({ phase, type, at, x: 200, y: 200, depth }); + const viewer = { inputs: [input('queued', 'mousePressed', 101, 5), input('sent', 'mousePressed', 120), input('queued', 'mouseReleased', 102, 6), input('sent', 'mouseReleased', 180)], dom: [{ type: 'mousedown', at: 100 }], decoded: [{ timestamp: .2, colours: [[220, 40, 40], [220, 180, 40]] }], received: [{ timestamp: .2, at: 210 }] }; + const logs = [input('cloud_got', 'mousePressed', 130), input('runner_got', 'mousePressed', 140), input('cloud_got', 'mouseReleased', 190), input('runner_got', 'mouseReleased', 191), { phase: 'source_frame', timestamp: .2, at: 200.5 }, { phase: 'cloud_frame', timestamp: .2, at: 201 }]; + const links = [{ ...input('proxy_act_in', 'mouseReleased', 185), actId: 1 }, { ...input('proxy_act_ready', 'mouseReleased', 187), actId: 1 }, { ...input('proxy_act_connection', 'mouseReleased', 188), actId: 1, connectionId: 4, newConnection: false, setupMs: 0 }, { ...input('proxy_act_out', 'mouseReleased', 189), actId: 1 }, { ...input('proxy_act_connection', 'mousePressed', 125), actId: 0, connectionId: 4, newConnection: false, setupMs: 0 }, { phase: 'proxy_sse_in', timestamp: .2, at: 202 }, { phase: 'proxy_sse_out', timestamp: .2, at: 205 }]; + const events = [{ kind: 'click', value: 1, at: 195 }]; + const result = attributeSample(structuredClone(sample), viewer, events, logs, links); + assert.equal(result.times.sent, 180); + assert.equal(result.hops.runner_to_page, 4); + assert.equal(result.queueDepth, 5); + assert.equal(result.queueWait, 78); + assert.equal(result.hops.outbound_delay, 2); + assert.equal(result.hops.connection_setup_and_write, 2); + const missing = logs.filter(e => !(e.phase === 'cloud_got' && e.type === 'mouseReleased')); + missing.push(input('cloud_got', 'mouseReleased', 300)); + assert.throws(() => attributeSample(structuredClone(sample), viewer, events, missing, links), /observation/); + assert.throws(() => attributeSample({ ...sample, paint: { at: 250, timestamp: .21 } }, viewer, events, logs, links), /painted frame/); +}); +test('WebSocket traffic survives the same propagation delay', { timeout: 5000 }, async () => { + const upstream = createServer(); + const wss = new WebSocketServer({ server: upstream }); + wss.on('connection', ws => ws.on('message', (m) => ws.send(m))); + await new Promise(r => upstream.listen(0, '127.0.0.1', r)); + const proxy = await startLink(`http://127.0.0.1:${upstream.address().port}`, 35); + const ws = new WebSocket(proxy.url.replace('http:', 'ws:') + '/v1/connect', { handshakeTimeout: 1000 }); + try { + await new Promise((ok, no) => { ws.once('open', ok); ws.once('error', no); }); + const sent = now(); + ws.send('hello'); + const message = await new Promise((ok, no) => { ws.once('message', ok); ws.once('error', no); }); + assert.equal(String(message), 'hello'); + assert.ok(now() - sent >= 60); + } + finally { + ws.terminate(); + await proxy.close(); + for (const s of wss.clients) + s.terminate(); + await new Promise(r => wss.close(r)); + await new Promise(r => upstream.close(r)); + } +}); +test('cleanup saves observations and runs every teardown even when evidence copying and stop fail', async () => { + const calls = []; + await assert.rejects(cleanupSteps(() => calls.push('save'), [ + () => { calls.push('copy'); throw new Error('copy failed'); }, + () => { calls.push('stop'); throw new Error('stop failed'); }, + () => calls.push('close'), + ]), AggregateError); + assert.deepEqual(calls, ['save', 'copy', 'stop', 'close', 'save']); +}); +test('CPU uses cumulative time deltas per scenario rather than smoothed ps percentages', () => { + assert.equal(cpuSeconds('01:30.50'), 90.5); + assert.equal(cpuSeconds('1-02:03:04'), 93784); + const a = { at: 1000, scenario: 'scroll', chromeTimes: { 1: 2 }, relaySeconds: 1 }; + const b = { at: 2000, scenario: 'scroll', chromeTimes: { 1: 2.5 }, relaySeconds: 1.25 }; + assert.deepEqual(cpuIntervals([a, b]), [{ scenario: 'scroll', chrome: 50, relay: 25, seconds: 1, appearedPids: 0, exitedPids: 0 }]); + assert.equal(colourValue([255, 255, 255], 'click'), null); +}); +test('CPU reports churn and only surviving-PID deltas when a helper exits', () => { + const start = { at: 1000, scenario: 'scroll', chromeTimes: { 1: 2, 2: 1 }, relaySeconds: 1 }; + const end = { at: 2000, scenario: 'scroll', chromeTimes: { 1: 2.5 }, relaySeconds: 1.25 }; + assert.deepEqual(cpuIntervals([start, end]), [{ scenario: 'scroll', chrome: 50, relay: 25, seconds: 1, appearedPids: 0, exitedPids: 1 }]); +}); +test('the saved real CPU counterexample reports surviving-PID work and churn without gating latency', () => { + const fixture = JSON.parse(readFileSync(new URL('./fixtures/browser-speed-cpu-counterexample.json', import.meta.url), 'utf8')); + const [interval] = cpuIntervals([fixture.before, fixture.after]); + assert.ok(Math.abs(interval.chrome - 7 / ((fixture.after.at - fixture.before.at) / 1000)) < 1e-9); + assert.equal(interval.appearedPids, 0); + assert.equal(interval.exitedPids, 3); + const [reset] = cpuIntervals([{ at: 0, scenario: 'rest', chromeTimes: { 1: 2 }, relaySeconds: 2 }, { at: 1000, scenario: 'rest', chromeTimes: { 1: 1 }, relaySeconds: 1 }]); + assert.equal(reset.chrome, 0); + assert.equal(reset.relay, 0); +}); +test('cold HTTP connections pay one extra RTT while warm acts reuse the paired connection', { timeout: 5000 }, async () => { + mkdirSync('.scratch', { recursive: true }); + const logFile = '.scratch/probe-connection-test.jsonl'; + writeFileSync(logFile, ''); + const upstream = createServer(async (req, res) => { for await (const chunk of req) + void chunk; res.end('ok'); }); + await new Promise(r => upstream.listen(0, '127.0.0.1', r)); + const proxy = await startLink(`http://127.0.0.1:${upstream.address().port}`, 35, logFile); + const firstAgent = new Agent({ keepAlive: true, maxSockets: 1 }); + const secondAgent = new Agent({ keepAlive: true, maxSockets: 1 }); + const act = agent => new Promise((ok, no) => { + const req = request(proxy.url + '/v1/browser/act', { agent, method: 'POST', headers: { 'content-type': 'application/json' } }, res => { res.resume(); res.once('end', ok); }); + req.once('error', no); + req.end(JSON.stringify({ act: 'input', method: 'Input.dispatchMouseEvent', params: { type: 'mousePressed', x: 200, y: 200 } })); + }); + try { + await act(firstAgent); + await new Promise(r => setTimeout(r, 15)); + await act(firstAgent); + firstAgent.destroy(); + await act(secondAgent); + const logs = readFileSync(logFile, 'utf8').trim().split('\n').map(l => JSON.parse(l)); + const acts = logs.filter(e => e.phase === 'proxy_act_connection'); + assert.deepEqual(acts.map(e => e.newConnection), [true, false, true]); + assert.equal(acts[0].connectionId, acts[1].connectionId); + assert.notEqual(acts[0].connectionId, acts[2].connectionId); + const opens = logs.filter(e => e.phase === 'connection_open' && e.direction === 'upstream' && e.transport === 'http'); + assert.equal(opens.length, 2); + for (const open of opens) { + const ready = logs.find(e => e.phase === 'connection_ready' && e.connectionId === open.connectionId); + assert.ok(ready.at - open.at >= 65); + } + for (const act of acts) { + const input = logs.find(e => e.phase === 'proxy_act_in' && e.actId === act.actId); + const ready = logs.find(e => e.phase === 'proxy_act_ready' && e.actId === act.actId); + assert.ok(ready.at - input.at >= 30); + } + } + finally { + firstAgent.destroy(); + secondAgent.destroy(); + await proxy.close(); + upstream.closeAllConnections(); + await new Promise(r => upstream.close(r)); + } +}); +test('acts on the browser input socket are logged as POST acts are, in order, without their text', { timeout: 5000 }, async () => { + mkdirSync('.scratch', { recursive: true }); + const logFile = '.scratch/probe-input-socket-test.jsonl'; + writeFileSync(logFile, ''); + const upstream = createServer(); + const wss = new WebSocketServer({ server: upstream }); + const got = []; + wss.on('connection', ws => ws.on('message', (m) => got.push(JSON.parse(String(m))))); + await new Promise(r => upstream.listen(0, '127.0.0.1', r)); + const proxy = await startLink(`http://127.0.0.1:${upstream.address().port}`, 35, logFile); + const ws = new WebSocket(proxy.url.replace('http:', 'ws:') + '/v1/browser/input?bot=b', { handshakeTimeout: 1000, perMessageDeflate: false }); + try { + await new Promise((ok, no) => { ws.once('open', ok); ws.once('error', no); }); + const moves = Array.from({ length: 5 }, (_, i) => ({ act: 'input', method: 'Input.dispatchMouseEvent', params: { type: 'mouseMoved', x: 10 + i, y: 20 } })); + for (const m of moves) + ws.send(JSON.stringify(m)); + ws.send(JSON.stringify({ act: 'input', method: 'Input.insertText', params: { text: 'secret-typed-words' } })); + // A frame over 125 bytes (a 16-bit length). + ws.send(JSON.stringify({ act: 'input', method: 'Input.dispatchMouseEvent', params: { type: 'mousePressed', x: 200, y: 200, pad: 'x'.repeat(300) } })); + await new Promise((ok) => { const t = setInterval(() => got.length === 7 && (clearInterval(t), ok()), 5); }); + await new Promise(r => setTimeout(r, 10)); + const text = readFileSync(logFile, 'utf8'); + assert.ok(!text.includes('secret-typed-words'), 'typed text never logged'); + const logs = text.trim().split('\n').map(l => JSON.parse(l)); + const ins = logs.filter(e => e.phase === 'proxy_act_in'); + assert.deepEqual(ins.map(e => [e.type ?? e.method, e.x]), [...moves.map(m => ['mouseMoved', m.params.x]), ['Input.insertText', undefined], ['mousePressed', 200]]); + for (const act of ins) { + const ready = logs.find(e => e.phase === 'proxy_act_ready' && e.actId === act.actId); + const out = logs.find(e => e.phase === 'proxy_act_out' && e.actId === act.actId); + const connection = logs.find(e => e.phase === 'proxy_act_connection' && e.actId === act.actId); + assert.ok(ready.at - act.at >= 30, 'pays the outbound delay'); + assert.ok(out.at >= ready.at); + assert.equal(connection.newConnection, false, 'sent on the open socket'); + } + } + finally { + ws.terminate(); + await proxy.close(); + for (const s of wss.clients) + s.terminate(); + await new Promise(r => wss.close(r)); + await new Promise(r => upstream.close(r)); + } +}); diff --git a/scripts/test-browser-relay.mjs b/scripts/test-browser-relay.mjs index 5ac296bea..078db49ae 100644 --- a/scripts/test-browser-relay.mjs +++ b/scripts/test-browser-relay.mjs @@ -371,6 +371,16 @@ try { say({ t: "watch", bot: "boppy", viewers: [sam, tess] }); }); + await test("a stream that just opened for someone already watching (another Mac or window) sees the page at once too", async () => { + await sleep(300); + got.length = 0; + say({ t: "watch", bot: "boppy", viewers: [sam, tess] }); + await sleep(500); + assert.equal(got.filter((g) => g.m.t === "control").length, 0, "the same people and no stream new: nothing to catch up"); + say({ t: "watch", bot: "boppy", viewers: [sam, tess], joined: true }); + await until(() => got.some((g) => g.m.t === "page") && got.some((g) => g.m.t === "control"), "the page and who has control, for the new stream", 3000); + }); + await test("a bot step waits while someone has control, and goes on when they hand it back", async () => { let ran = false; const step = relay.whenFree(100).then(() => (ran = true)); diff --git a/scripts/test-browser-tab-e2e.mjs b/scripts/test-browser-tab-e2e.mjs index 7c4ad98b4..42b06d84d 100644 --- a/scripts/test-browser-tab-e2e.mjs +++ b/scripts/test-browser-tab-e2e.mjs @@ -5,9 +5,9 @@ // 1. The owner opens the bot's browser from a new tab; the bot goes to a page with a fresh word; within 2 s the owner's // tab shows its address, and its frame matches a direct CDP screenshot of the bot's page (and not the page before). // 2. Sam sees the same in place of the owner's computer. -// 4. Sam takes over (the owner sees "Sam has control"), clicks the page's button and types in its field, and the page -// reacts; a bot step on that screen waits meanwhile and runs once sam hands back. A CDP method outside the allowlist -// is refused. +// 4. Sam takes over (the owner sees "Sam has control"), clicks the page's button (sam's own press rings at once where +// sam pressed, within 400 ms) and types in its field, and the page reacts; a bot step on that screen waits +// meanwhile and runs once sam hands back. A CDP method outside the allowlist is refused. // 7. Without control the address bar is read-only; in control, sam types an address and the page goes there. // 5. Sam signs in to the test site's sign-in page with the fixture's made-up account, hands back, and a bot step reads // the signed-in page: it prints the name it read. @@ -921,7 +921,23 @@ try { await sleep(1500); assert.equal(stepDone, null, "the bot's step waits while sam has control"); await beat(1000); - await clickOnFrame(sam.page, "#press"); + // Sam's own press rings at once where sam pressed, on sam's frame, without waiting for the page's answer (the + // page's own pointer event for it is sam's, so it never draws one). + const pressAt = await onFrame(sam.page, ...(await centre("#press"))); + await sam.page.mouse.move(pressAt.x, pressAt.y); + const pressed = Date.now(); + await sam.page.mouse.down(); + const ring = await until( + () => sam.page.evaluate(() => { + const r = document.querySelector("[data-bot-browser] [data-browser-cursors] [data-cursor-ring]")?.getBoundingClientRect(); + return r && { x: r.left + r.width / 2, y: r.top + r.height / 2 }; + }), + "sam's own press to ring", + 400, + ); + console.log(` sam's own press rang ${Date.now() - pressed} ms after it, ${Math.hypot(ring.x - pressAt.x, ring.y - pressAt.y).toFixed(1)} px from it`); + await sam.page.mouse.up(); + assert.ok(Math.hypot(ring.x - pressAt.x, ring.y - pressAt.y) < 3, "the ring is where sam pressed"); await until(async () => (await onPage("document.getElementById('press').textContent")) === "Pressed by a person", "the page's button to react"); await beat(1000); await clickOnFrame(sam.page, "#note"); diff --git a/scripts/test-browser-view.mjs b/scripts/test-browser-view.mjs new file mode 100644 index 000000000..6875e7b0b --- /dev/null +++ b/scripts/test-browser-view.mjs @@ -0,0 +1,208 @@ +// Tests for how this Bops sends a person's inputs on the bot's browser to Bops Cloud (lib/server/browser-view.ts +// actBrowser), against a fake Bops Cloud on localhost: +// +// - Inputs go on one socket per bot (WS /v1/browser/input), in order, signed in as the person with this Mac's device; +// each is answered as soon as it's on its way, and ones that come while it opens wait and go in order. Take goes by POST. +// - Bops Cloud saying an act didn't go (its computer isn't connected): the next goes by POST, so its words come back. +// - Bops Cloud closing the socket: the next act opens another. +// - A refusal marked as the socket route's (403): that act goes by POST, which answers in words; the next tries again. +// - A Bops Cloud from before the socket (a plain 404): every act by POST for a while, without asking again; then asked +// again (it may have been updated since). Another Bops Cloud isn't held to it. +// - A socket that stops answering pings (a network change can leave it dead without a close) goes, and the next act +// opens another; one that answers stays. +// Usage: node scripts/test-browser-view.mjs +import assert from "node:assert/strict"; +import { createServer } from "node:http"; +import { registerHooks } from "node:module"; +import { pathToFileURL } from "node:url"; +import { WebSocketServer } from "ws"; + +const root = new URL("..", import.meta.url).pathname.replace(/\/$/, ""); +// The signed-in person and where Bops Cloud is: stand-ins for what the app's server reads from its store and Keychain. +const STUBS = { + "server-only": "export {}", + "./app-version": "export const appHeaders = () => ({ 'x-bops-app-version': 'test' });", + "./cloud": "export const cloudOn = () => true; export const cloudUrl = () => globalThis.__cloudUrl;", + "./orgo-auth": "export const orgoKey = () => 'key-u1';", + "./persist-cloud": "export const deviceIdFor = (u) => `device-${u}`;", + "./shared": "export const sharedProjectId = () => null;", + "./store": "export const stateUser = () => 'u1';", +}; +registerHooks({ + resolve(specifier, context, next) { + if (STUBS[specifier] !== undefined && (specifier === "server-only" || context.parentURL?.includes("/lib/server/browser-view.ts"))) + return { url: `data:text/javascript,${encodeURIComponent(STUBS[specifier])}`, shortCircuit: true }; + if (specifier.startsWith("@/")) return next(pathToFileURL(`${root}/${specifier.slice(2)}.ts`).href, context); + return next(specifier, context); + }, +}); +/** A fresh copy of the module (its sockets and "by POST for a while" are per process), with its timing as given. */ +const fresh = async (n, timing = {}) => { + const v = await import(`${root}/lib/server/browser-view.ts?${n}`); + Object.assign(v.browserViewForTests?.timing ?? {}, timing); + return v; +}; + +let passed = 0; +const test = async (name, f) => { + await f(); + passed++; + console.log(`ok - ${name}`); +}; +async function until(check, what, ms = 5000) { + for (const end = Date.now() + ms; Date.now() < end; await new Promise((r) => setTimeout(r, 10))) { + const v = await check(); + if (v) return v; + } + assert.fail(`timed out waiting for ${what}`); +} + +/** + * A fake Bops Cloud: `upgrade` is "accept", 404 (a plain one: from before the socket) or 403 (marked as the route's), read + * at each upgrade. `pong: false`: its sockets never answer a ping (a connection a network change left dead). + */ +async function fakeCloud(o) { + const c = { posts: [], said: [], upgrades: 0, sockets: [], asked: [] }; + const server = createServer(async (req, res) => { + let body = ""; + for await (const chunk of req) body += chunk; + c.posts.push(JSON.parse(body)); + res.writeHead(o.postStatus ?? 202, { "content-type": "application/json" }).end(JSON.stringify(o.postStatus ? { error: "In Bops Cloud's words." } : { ok: true })); + }); + const wss = new WebSocketServer({ noServer: true, autoPong: o.pong !== false }); + server.on("upgrade", (req, socket, head) => { + c.upgrades++; + c.asked.push({ url: req.url, auth: req.headers.authorization, device: req.headers["x-bops-device"] }); + if (o.upgrade === 404) return socket.end("HTTP/1.1 404 Not Found\r\nConnection: close\r\nContent-Length: 0\r\n\r\n"); + if (o.upgrade === 403) return socket.end("HTTP/1.1 403 Forbidden\r\nConnection: close\r\nx-bops-browser-input: 1\r\nContent-Length: 0\r\n\r\n"); + wss.handleUpgrade(req, socket, head, (ws) => { + c.sockets.push(ws); + ws.on("message", (m) => c.said.push(JSON.parse(String(m)))); + ws.on("close", () => (ws.ended = true)); + }); + }); + await new Promise((r) => server.listen(0, "127.0.0.1", r)); + c.url = globalThis.__cloudUrl = `http://127.0.0.1:${server.address().port}`; + c.close = async () => { + for (const ws of wss.clients) ws.terminate(); + server.closeAllConnections(); + await new Promise((r) => server.close(r)); + }; + return c; +} +const move = (x) => ({ bot: "b", act: "input", method: "Input.dispatchMouseEvent", params: { type: "mouseMoved", x, y: 1 } }); + +await test("inputs go on one socket in order, each answered once on its way; take by POST; an act Bops Cloud said didn't go makes the next a POST; a closed socket is opened again", async () => { + const v = await fresh(1); + const c = await fakeCloud({ upgrade: "accept" }); + try { + // 30 at once: the first opens the socket, the rest wait for it, and all go in order. + const answers = await Promise.all(Array.from({ length: 30 }, (_, x) => v.actBrowser(move(x), ""))); + assert.ok(answers.every((a) => a.status === 202), JSON.stringify(answers[0])); + await until(() => c.said.length === 30, "the 30 on the socket"); + assert.deepEqual(c.said.map((m) => m.params.x), Array.from({ length: 30 }, (_, x) => x)); + assert.deepEqual(c.said[0], { act: "input", method: "Input.dispatchMouseEvent", params: { type: "mouseMoved", x: 0, y: 1 } }); + assert.equal(c.upgrades, 1, "one socket"); + assert.deepEqual(c.asked[0], { url: "/v1/browser/input?bot=b", auth: "Bearer key-u1", device: "device-u1" }); + assert.equal(c.posts.length, 0, "no input by POST"); + assert.equal((await v.actBrowser({ bot: "b", act: "take" }, "")).status, 202); + assert.deepEqual(c.posts, [{ bot: "b", act: "take" }], "take by POST"); + // Bops Cloud says one didn't go: the next is a POST (its answer has the words), the one after the socket again. + c.sockets[0].send(JSON.stringify({ t: "error", code: "browser_offline", why: "B's computer isn't connected right now." })); + await new Promise((r) => setTimeout(r, 50)); + await v.actBrowser(move(100), ""); + assert.deepEqual(c.posts.at(-1), move(100)); + await v.actBrowser(move(101), ""); + await until(() => c.said.at(-1)?.params.x === 101, "the next on the socket"); + // Closed by Bops Cloud (their access changed): the next act opens another, which Bops Cloud asks about afresh. + c.sockets[0].close(4403, "Access changed"); + await new Promise((r) => setTimeout(r, 50)); + assert.equal((await v.actBrowser(move(102), "")).status, 202); + await until(() => c.said.at(-1)?.params.x === 102, "the act on the new socket"); + assert.equal(c.upgrades, 2); + // Another workspace than the one open here: refused before anything is sent, as before. + assert.equal((await v.actBrowser(move(103), "p-other")).body.code, "workspace_changed"); + // A method outside BROWSER_METHODS: by POST, so Bops Cloud's refusal comes back in its words; never on the socket. + const said = c.said.length; + await v.actBrowser({ bot: "b", act: "input", method: "Runtime.evaluate", params: { expression: "1" } }, ""); + assert.equal(c.posts.at(-1).method, "Runtime.evaluate"); + assert.equal(c.said.length, said); + } finally { + await c.close(); + } +}); + +await test("a refusal marked as the socket's (403): that act by POST, answered in Bops Cloud's words; the next asks for the socket again", async () => { + const v = await fresh(2); + const c = await fakeCloud({ upgrade: 403, postStatus: 403 }); + try { + const a = await v.actBrowser(move(1), ""); + assert.deepEqual(a, { status: 403, body: { error: "In Bops Cloud's words." } }); + assert.deepEqual(c.posts, [move(1)]); + await v.actBrowser(move(2), ""); + assert.equal(c.upgrades, 2, "asked again: access can come back"); + assert.equal(c.posts.length, 2); + } finally { + await c.close(); + } +}); + +await test("a Bops Cloud from before the socket (a plain 404): every act by POST for a while, without asking again; then asked again; another Bops Cloud isn't held to it", async () => { + const v = await fresh(3, { noSocketMs: 300 }); + const o = { upgrade: 404 }; + const c = await fakeCloud(o); + let other; + try { + const waiting = await Promise.all([1, 2, 3].map((x) => v.actBrowser(move(x), ""))); + assert.ok(waiting.every((a) => a.status === 202)); + assert.deepEqual(c.posts.map((p) => p.params.x), [1, 2, 3], "the ones waiting for the socket, by POST in order"); + for (const x of [4, 5]) assert.equal((await v.actBrowser(move(x), "")).status, 202); + assert.equal(c.upgrades, 1, "not asked again for a while"); + assert.deepEqual(c.posts.map((p) => p.params.x), [1, 2, 3, 4, 5]); + // Another Bops Cloud (signed in to elsewhere) is asked for its own socket. + other = await fakeCloud({ upgrade: "accept" }); + assert.equal((await v.actBrowser(move(6), "")).status, 202); + await until(() => other.said.length === 1, "the act on the other Bops Cloud's socket"); + assert.equal(other.posts.length, 0); + // Bops Cloud updated since: once the while is up, the next act asks again and goes on the socket. + globalThis.__cloudUrl = c.url; + o.upgrade = "accept"; + await new Promise((r) => setTimeout(r, 350)); + assert.equal((await v.actBrowser(move(7), "")).status, 202); + await until(() => c.said.length === 1, "the act on the socket"); + assert.equal(c.upgrades, 2, "asked again"); + assert.deepEqual(c.posts.map((p) => p.params.x), [1, 2, 3, 4, 5], "nothing more by POST"); + } finally { + await c.close(); + await other?.close(); + } +}); + +await test("a socket that stops answering pings goes, and the next act opens another; one that answers stays", async () => { + const v = await fresh(4, { pingMs: 40 }); + const here = await fakeCloud({ upgrade: "accept" }); + try { + await v.actBrowser(move(1), ""); + await until(() => here.said.length === 1, "the act on the socket"); + await new Promise((r) => setTimeout(r, 250)); + assert.equal((await v.actBrowser(move(2), "")).status, 202); + await until(() => here.said.length === 2, "the next on the same socket"); + assert.equal(here.upgrades, 1, "pings answered: one socket"); + } finally { + await here.close(); + } + const dead = await fakeCloud({ upgrade: "accept", pong: false }); + try { + await v.actBrowser(move(3), ""); + await until(() => dead.said.length === 1, "the act on the socket"); + await until(() => dead.sockets[0].ended, "the socket that never answers to go", 1000); + assert.equal((await v.actBrowser(move(4), "")).status, 202); + await until(() => dead.said.length === 2, "the next act on a new socket"); + assert.equal(dead.upgrades, 2, "another socket"); + assert.equal(dead.posts.length, 0); + } finally { + await dead.close(); + } +}); + +console.log(`${passed} passed`); diff --git a/scripts/verify b/scripts/verify new file mode 100755 index 000000000..4326f2bff --- /dev/null +++ b/scripts/verify @@ -0,0 +1,28 @@ +#!/usr/bin/env node +import { spawnSync } from 'node:child_process'; +const feature = process.argv[2] ?? 'browser-speed'; +if (feature === '--list') { + console.log('browser-speed\nbrowser-input'); + process.exit(0); +} +if (feature !== 'browser-speed' && feature !== 'browser-input') + throw new Error('Use scripts/verify browser-speed or browser-input; see docs/FEATURES.md'); +// The browser tab's input socket: the app server's sending (fake Bops Cloud), Bops Cloud's checks (needs the test database, cloud/test/edge-fakes.ts), types and lint. +const steps = feature === 'browser-input' ? [ + [process.execPath, ['scripts/test-browser-view.mjs']], + [process.execPath, ['--test', 'cloud/test/core-browser.test.ts', 'cloud/test/edge-browser.test.ts']], + ['npx', ['tsc', '--noEmit']], + ['npx', ['tsc', '--noEmit', '-p', 'cloud']], + ['npx', ['eslint', 'cloud/browser.ts', 'cloud/http.ts', 'cloud/live.ts', 'cloud/protocol.ts', 'cloud/test/edge-browser.test.ts', 'lib/server/browser-view.ts', 'scripts/test-browser-view.mjs', 'components/app/bot-browser.tsx', 'components/app/browser-cursor.tsx', 'scripts/browser-speed/link.mjs', 'scripts/test-browser-probe.mjs']], +] : [ + [process.execPath, ['--test', 'scripts/test-browser-probe.mjs']], + [process.execPath, ['--check', 'scripts/verify']], + ['npx', ['tsc', '--noEmit']], + ['npx', ['eslint', 'scripts/browser-speed', 'scripts/probe-browser-speed.mjs', 'scripts/probe-computer-side.mjs', 'scripts/dev-two-person.mjs', 'scripts/test-browser-probe.mjs', 'cloud/browser-probe.ts', 'cloud/browser.ts', 'lib/browser-relay.ts', 'components/app/bot-browser.tsx', 'next.config.ts']], +]; +for (const [cmd, args] of steps) { + const r = spawnSync(cmd, args, { stdio: 'inherit' }); + if (r.status !== 0) + process.exit(r.status ?? 1); + console.log(`PASS ${cmd} ${args.join(' ')}`); +}