diff --git a/CHANGELOG.md b/CHANGELOG.md index 41e6830..a309c20 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -5,6 +5,101 @@ All notable changes to this project are documented in this file. The format is based on [Keep a Changelog](https://keepachangelog.com/en/1.1.0/), and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0.html). +## [Unreleased] — 0.7.0 + +The handoff now knows whether anybody is on the other side, and the ending is +confirmed before the sandbox dies. + +Both halves close gaps this project had written down and lived with: the first +limitation in the README ("if the human silently closes the tab, the agent +can't tell") and the observation logged in every live approval round, where a +second viewer of the link saw nothing because the `ended` lost its race with +the kill. + +**No new outcome.** A human who walked away ends the handoff as `timeout`, the +value it has always had for "nobody answered". `HandoffOutcome` grew once +already, in 0.4.0, and every growth is a `switch` in somebody else's code that +quietly stops being exhaustive — while the decision a caller makes here is +unchanged: nobody answered, do not blindly retry the same step. What changed is +*why*, and why belongs in the wide event, which callers read rather than branch +on. [ADR 0009](docs/adr/0009-peer-presence-and-ended-ack.md) has the argument +and the rejected alternatives. + +### Added + +- **The relay reports the human's socket to the agent**: `{ "type": + "presence", "human": boolean }`, on every connect, replace and close of the + phone's socket, and once immediately after an agent connects, so a + reconnecting agent starts from the truth. It is the only signal there can be + — the relay answers the heartbeats itself, so a pong proves the relay is + alive and says nothing about the person. +- **`humanGoneGraceMs`, default 60 000 ms, accepted between 5 000 and + 2 147 483 647.** Once a human has been there and + their phone has been gone for the whole grace, the handoff ends instead of + waiting out `timeoutMs`. A phone that comes back inside the grace resets it, + which is what makes 60 s the right default: the preview proxy cuts an idle + WebSocket after exactly 60 s and the phone reconnects about a second later, + so a shorter grace would end healthy handoffs on the platform's own + housekeeping. A handoff nobody ever opened is deliberately untouched and + waits the full `timeoutMs` — an unscanned QR code is the ordinary wait, not + somebody leaving. +- **Three fields on the wide event**: `humanSeen: boolean` and `endedEarly: + boolean` (both **required** — additive for anyone who receives the event, one + edit for a TypeScript consumer that builds a `HandoffEvent` literal in a + test) and `humanLeftMs?: number`, the last time the phone disappeared, in ms + since the handoff started. `timeout` now has two shapes, and these tell them + apart: `endedEarly: true` is somebody who came and left; `humanSeen: false` + is a link that never reached anyone. Two different problems, two different + fixes. +- **The presence report carries what an absent agent missed**: `seen` (has a + human ever been here) and `sinceMs` (how old this news is), both optional so + an older relay still speaks the protocol. A whole visit can begin and end + while the agent's socket is down — the proxy's 60 s cut, a reconnect backoff + — and a bare current state cannot tell that apart from a link nobody ever + opened. The agent uses `sinceMs` to run the grace from the moment the human + actually left rather than from the moment it heard about it. +- **`{ "type": "ended_ack" }` from the relay**, sent once it has stored the + ending for whoever opens the link next. `sendFinal` waits up to 2 s for it + before `raiseHand` destroys the sandbox. Without it the ending was written to + a socket whose process was already being deleted — measurable in approval + mode, which tears down in milliseconds and has no `storageState` capture to + hold the door open. Against a relay that cannot answer, teardown proceeds + exactly as before. +- **`invalid_option`**, an eighth `HandraiseErrorCode`. Today it is a + `humanGoneGraceMs` outside 5 000–2 147 483 647 ms — below the floor the + phone's own reconnect would end handoffs, and above the ceiling a Node timer + collapses to one millisecond. Checked + before any sandbox exists, like the mode checks, and refused rather than + clamped: a caller who asks for a 10 ms grace has misunderstood the option, + and silently substituting a minute would hide that until a handoff ended on a + network blip in production. +- **A live e2e case for each half.** A scripted human opens the handoff and + closes the socket without answering — the run asserts the handoff ends on the + absence rather than on the wait, after the grace, with `endedEarly: true`. + For the ending, two assertions that used to be a log line: the answering + phone is told over the wire in both approval rounds, and a second holder of + the link who never answered — connected, watching, while a channel decides — + is told how it ended, 306 ms after the answer in the run these notes were + written from. Somebody who only *starts* opening the link after the answer is + measured and not asserted: the sandbox stops serving about a second later, + which is roughly what a fresh HTTPS and WebSocket handshake costs. + [ADR 0009](docs/adr/0009-peer-presence-and-ended-ack.md) says why that window + is not worth a live sandbox. + +### Changed + +- **`RelayMessage` has a third direction.** `RelayToAgent` joins `AgentToHuman` + and `HumanToAgent` in `src/relay/protocol.ts`; the relay is no longer only a + forwarder between two peers. The phone never receives either new message, and + the vocabulary test that keeps the relay's `MSG` constants and the protocol's + unions in step now spans all three. +- **`RelayConnectionStats` carries `endedAcked`** (internal to the package), + and `raiseHand` logs one `ended_ack` line with it and the wait it cost. +- **`HandoffResult.durationMs` is frozen at settlement**, the same number the + wide event has always carried. It used to be measured after teardown, so the + ending's receipt, the CDP detach and the relay's destruction were counted as + time the human took. Nobody waited for those. + ## [0.6.0] - 2026-09-02 QR passthrough, and typed errors on everything `raiseHand` throws. @@ -468,7 +563,7 @@ Initial release. Human-in-the-loop handoff for Solari cloud browsers. so two simultaneous handoffs is the plan-tier ceiling. - TypeScript/Node only. -[Unreleased]: https://github.com/Sy-D/handraise/compare/v0.3.0...HEAD +[Unreleased]: https://github.com/Sy-D/handraise/compare/v0.6.0...HEAD [0.6.0]: https://github.com/Sy-D/handraise/releases/tag/v0.6.0 [0.5.1]: https://github.com/Sy-D/handraise/releases/tag/v0.5.1 [0.5.0]: https://github.com/Sy-D/handraise/releases/tag/v0.5.0 diff --git a/README.md b/README.md index d117b70..64633ca 100644 --- a/README.md +++ b/README.md @@ -315,6 +315,7 @@ await raiseHand(page, { | `mode` | `"takeover"` \| `"approval"` | `"takeover"` | `takeover` hands the live browser over; `approval` shows one screenshot and asks for a yes or a no. | | `action` | `string` | *required in approval mode* | The exact step being decided, e.g. "Submit $12,430 vendor payment to Acme GmbH". A type error if `mode` is `"approval"` and it is missing. | | `timeoutMs` | `number` | 5 minutes | How long to wait for the human. | +| `humanGoneGraceMs` | `number` | 60s | How long to keep waiting after the human's phone disappears. A handoff nobody ever opened is unaffected and waits out `timeoutMs`. Range 5000–2147483647, and the floor is a floor rather than a safe value — the default is what covers a proxy cut plus the phone's reconnect. Raise it if the human is expected to leave the page: a locked screen can lose the socket. | | `webhookUrl` | `string` | — | Generic JSON POST when the link is ready. | | `onUrl` | `(url) => void` | — | Called with the handoff URL. | | `channels` | `HandoffChannel[]` | — | Where else to announce it. In approval mode a channel also gets the screenshot and can answer. See [Channels](#channels). | @@ -339,7 +340,7 @@ await raiseHand(page, { | `aborted` | takeover | The human looked and could not solve it. Do not retry the same step. | | `approved` | approval | Carry out the action. | | `denied` | approval | Do not carry out the action. | -| `timeout` | both | Nobody answered within `timeoutMs`. | +| `timeout` | both | Nobody answered — either `timeoutMs` ran out, or a human who was there closed the tab and stayed away for `humanGoneGraceMs`. The wide event's `endedEarly` and `humanSeen` say which. | | `disconnected` | both | The browser session died mid-handoff. | ### `scanQrLinks(png): ScannedLink[]` @@ -394,6 +395,7 @@ try { | `missing_api_key` | No `options.apiKey` and no `SOLARI_API_KEY`. | Set one; handraise needs it to create the relay sandbox. | | `invalid_mode` | `mode` is neither `"takeover"` nor `"approval"`. | Fix the call. TypeScript already refuses it; this is for JavaScript callers. | | `empty_action` | `mode: "approval"` without a non-empty `action`. | Name the step the human says yes or no to. | +| `invalid_option` | An option is present but unusable. Today: `humanGoneGraceMs` outside 5000–2147483647 ms (below that the phone's own reconnect ends handoffs; above it a Node timer collapses to 1 ms). | Fix the value. Refused rather than clamped, because a grace that is silently something else ends handoffs you did not expect to end. | | `browser_unusable` | The page is closed, or its browser has disconnected — checked before anything is created. | Open a new page or relaunch the session (restore `storageState` if you kept it) and retry. | | `relay_start_failed` | The relay sandbox could not be created or deployed. | Read `cause` — it is the Solari SDK's own error, redacted. Retry. Nothing is left behind unless you also see `relay_release_failed` (below). | | `concurrency_limit` | Your Solari account is at its concurrent session cap (429). | Free a session, or wait and retry. The one relay failure that is purely temporary. | @@ -413,7 +415,8 @@ tool, so every row here is measured rather than hoped for. | Failure | Outcome | |---|---| -| Human never shows | Clean `timeout`, relay destroyed | +| Human never shows | Clean `timeout` after `timeoutMs`, relay destroyed | +| Human opens it, then closes the tab | `timeout` one grace later, not five minutes later — the relay reports the phone's socket, and the event says `endedEarly: true` | | Browser session dies mid-handoff | `disconnected`, not an exception | | Relay WebSocket drops | 20s heartbeats, reconnect, last frame replayed | | Agent process killed | Sandbox lifecycle kill, no orphaned URL | @@ -529,9 +532,6 @@ with `isTrusted: true`. ## Limitations (v1) -- If the human silently closes the tab, the agent can't tell — it waits until - `timeoutMs`. (The relay answers heartbeats itself; peer presence is a v2 - protocol change.) - Solari's $20 plan allows 2 concurrent sandboxes; each active handoff uses one. Two simultaneous handoffs is the plan-tier ceiling. - An approval shows the page as it was when the agent asked. If the page @@ -548,7 +548,6 @@ with `isTrusted: true`. ## Contributing Small, focused PRs welcome. Good first issues: a Python port, a -`needHuman` tool export for more agent frameworks, wall-detection heuristics, -peer-presence in the relay protocol. +`needHuman` tool export for more agent frameworks, wall-detection heuristics. MIT diff --git a/docs/adr/0009-peer-presence-and-ended-ack.md b/docs/adr/0009-peer-presence-and-ended-ack.md new file mode 100644 index 0000000..b6ef127 --- /dev/null +++ b/docs/adr/0009-peer-presence-and-ended-ack.md @@ -0,0 +1,188 @@ +# 0009 — Peer presence, and a receipt for the ending + +- **Status:** accepted +- **Date:** 2026-09-02 + +## Context + +Two things the relay knew and never said. + +**1. The human closed the tab.** handraise's wait was a single number: +`timeoutMs`, five minutes by default. It ran whether the human was reading a +code off another device, had never scanned the QR code, or had looked at the +page and closed it. The agent could not tell those apart, and the reason is in +the transport: the relay answers `ping` itself and never forwards it +([ADR 0001](0001-websocket-live-view-transport.md)), so a pong proves the relay +is alive and says nothing about the person. The README listed this as the first +limitation of v1. + +The cost is not abstract. A Solari browser session dies about ten minutes after +creation and one measured session died at 319 s +([measurement 04](../measurements/04-browser-session-lifetime.md)). Sitting out +a five-minute wait for somebody who left after twenty seconds spends half of +that lifetime on nothing, and it spends it *after* the agent already knows the +handoff is not going to be answered — it just has no way to know it. + +**2. The ending lost a race with the kill.** `raiseHand` sends +`{ "type": "ended", … }` and then destroys the sandbox. The relay keeps that +message for whoever opens the link next, which is what the phone's terminal +overlay is built on. In the live e2e's approval rounds the second viewer of a +link regularly saw nothing: the answering phone shows its own ending locally, +so the bug was invisible from the one screen that was being watched. An +approval tears down in milliseconds — there is no `storageState` capture to +hold the door open, as there is after a takeover — and the `ended` was written +to a socket whose process was already being deleted. + +## Decision + +**The relay reports the human's socket, and acknowledges the ending.** Two new +messages, both relay→agent, in a new `RelayToAgent` union next to the two peer +unions in `src/relay/protocol.ts`: + +```jsonc +// on every connect/replace/close, and once right after an agent connects +{ "type": "presence", "human": true, "seen": true, "sinceMs": 0 } +{ "type": "ended_ack" } // once `ended` has been stored +``` + +**A three-state machine in the core**, `never_seen → present → gone`: + +- `never_seen` is the ordinary wait and is **not** shortened. A QR code nobody + scanned is a handoff nobody has been asked to answer yet, and the full + `timeoutMs` is the honest budget for it. +- `present → gone` starts a clock: `humanGoneGraceMs`, default **60 000 ms**, + accepted between 5 000 and 2 147 483 647 ms (`invalid_option` outside that). + The floor is five times the phone's reconnect because one times it was + measured failing: a 1 000 ms grace ended a healthy handoff on the first proxy + cut. The ceiling is Node's largest timer delay, above which it becomes 1 ms. +- A reconnect inside the grace cancels it. It does not shorten it, and a second + `presence: false` does not restart it. +- When the grace runs out, the handoff ends with the **existing** outcome + `timeout`, and the wide event carries `humanSeen`, `humanLeftMs` and + `endedEarly` so the two kinds of timeout are still distinguishable. + +**`sendFinal` waits up to 2 s for `ended_ack`** before `raiseHand` kills the +sandbox, **re-sending the ending on any reconnect inside that window**. +Without an ack it proceeds exactly as before, and `stats().endedAcked` records +which of the two happened. + +### What the report carries, and why it is not just a boolean + +A current state alone loses a whole class of visit. The agent's socket goes +down — the 60 s proxy cut, a reconnect backoff — and a human opens the link, +looks at it and closes it again before the agent is back. Both announcements +find no agent and are dropped, and what the reconnecting agent is then told, +`human: false`, is also exactly what a link nobody has ever opened says. The +handoff would wait out the full `timeoutMs` and the event would report that +nobody came. + +So the relay keeps the two facts that survive an outage — has a human ever been +here (`seen`), and how long the current state has held (`sinceMs`) — and sends +them with every report. Both are optional on the wire, so an older relay still +speaks this protocol and an agent that receives neither behaves exactly as it +did before they existed. The core leaves `never_seen` on `seen`, and runs both +the grace and `humanLeftMs` from when the human actually left rather than from +when it heard about it. `sinceMs` is clamped into `[0, handoff age]` first: it +is a relay-local delta, so there is no clock skew between machines to correct, +but a wall-clock step inside that sandbox would otherwise describe an absence +older than the handoff. + +**The report goes out before any buffered terminal answer.** The relay already +holds a `handback` or an `approve` given while the agent was away. An answer +settles the handoff, and a settled handoff refuses everything it learns +afterwards — so announced second, a visit that happened during the outage would +still be reported as a handoff nobody ever opened. Announced first, and a +backdated grace that is already expired could settle the handoff as `timeout` +in the same breath, losing a race to the answer one frame behind it. Hence a +floor of **250 ms** on a backdated grace: the relay writes both frames back to +back on one socket, measured 0 ms apart, and the floor tolerates 240 ms of +that gap — three orders of magnitude of margin for a race that is otherwise a +coin flip on which tick the second frame lands in. + +### Why the ending is re-sent, and not merely written once + +The two seconds `sendFinal` waits are justified by the connection coming back +inside them — so it has to carry the ending when it does. A socket that dies +between the local write and the relay's store would otherwise leave `lastEnded` +unset with the agent none the wiser: the phone stays on "Reconnecting…" and the +next viewer of the link is told nothing, which is the failure this ADR exists +to close. The ending is held for the duration of the wait and re-sent from +every reconnect until the ack lands. Sending it twice is safe by construction: +the relay's store is an assignment, it acks each copy, and a second ack outside +an active waiter resolves nothing. + +## Alternatives + +- **A new outcome, `abandoned`.** Rejected. The union grew once already, in + 0.4.0, and every growth is a `switch` somewhere in a caller's code that + silently stops being exhaustive — or worse, a default branch that treats a + new member as success. Nothing about the *decision* a caller makes changes + here: nobody answered, do not retry the same step blindly, report that you + are blocked. That is `timeout`. What changed is *why*, and why belongs in the + wide event, which is the field consumers read rather than branch on. +- **End the handoff the moment the socket drops.** Rejected on the measured + number that shapes this whole transport: the preview proxy cuts an idle + WebSocket after exactly 60 s (close 1006, + [measurement 01](../measurements/01-preview-transport.md)) and the phone + reconnects about a second later. Ending on the first `presence: false` would + end healthy handoffs on the platform's own housekeeping — a human holding a + phone, reading a code, doing nothing wrong. +- **Forward the heartbeats to the human instead.** Rejected. It would make the + phone's liveness the agent's problem to infer from timing, which is exactly + the guessing this ADR removes, and it would put a keep-alive on the critical + path of a socket the relay is already keeping warm. The relay has the `peers` + map; presence is a fact it can state, not a signal anyone should have to + measure. +- **Shorten the default `timeoutMs` instead.** Rejected: it punishes the human + who is genuinely working — reading an SMS, fetching a hardware key — to + detect the human who is not. +- **A grace as an internal constant.** Rejected: 60 s is right for a phone on a + proxy that cuts at 60 s, and wrong for an e2e that has to observe the + behaviour in a test, or for a deployment behind a different proxy. It is an + option with a floor, and the floor is where the judgement lives. +- **Fire-and-forget the ending, and let the relay outlive the handoff.** + Rejected: the relay sandbox is a paid, capped resource (two concurrent on the + measured plan) and leaving one alive to serve a page nobody may open trades a + slot for a maybe. Two seconds of waiting is cheaper than a leaked sandbox. + +## Consequences + +- **`HandoffEvent` gains three fields**: `humanSeen: boolean`, + `endedEarly: boolean` (both required) and `humanLeftMs?: number`. Additive + for anybody who receives the event; a TypeScript consumer that *builds* a + `HandoffEvent` literal in a test has to add the two required ones. +- **`timeout` now has two shapes.** `endedEarly: true` means somebody came and + left; `false` with `humanSeen: false` means nobody came at all. Alerting on + "handoffs nobody answered" should split on it — they are different problems + with different fixes (a link that never reached anyone, versus a page a + person could not finish). +- **A `presence` message is delivered on every agent reconnect.** It reports + the state, not a change, so a reconnecting agent that finds the human still + there cancels a grace it may have started while its own socket was down. +- **The relay's message set is no longer two peers only.** `RelayToAgent` is a + third direction, and the vocabulary test now spans three unions; the phone + never sees either message. Both test harnesses classify relay-originated + traffic off that union rather than off a hand-written list, so a third member + does not compile until they say what to do with it. +- **The relay keeps two more facts for the length of a handoff**, and neither + is about the page: whether a human has ever connected, and when that last + changed. They are the only state that survives an agent outage, and they are + scrubbed with the sandbox like everything else. +- **Everyone already holding the link is told; somebody who arrives after the + answer still may not be.** The ack fixes the part that was broken — the + ending is stored and relayed before anything is destroyed, and the live e2e + asserts it against a viewer who is watching when a channel answers and is + told 306 ms later. It does not make the link outlive the handoff: measured in + the same run, the preview URL stops serving about a second after an approval + is answered, and a fresh HTTPS plus WebSocket handshake from Germany to + us-west costs about as much again, so a viewer who starts opening the link + after the answer usually finds a 404. Serving them would mean keeping the + sandbox alive past the handoff, which spends a capped, paid slot on a page + nobody may open. The e2e measures that window rather than asserting it. +- **Teardown is up to 2 s slower in the worst case** — a relay that cannot + answer — and typically one round trip. In exchange the ending is stored + before the sandbox dies, which is what makes the terminal overlay reliable + for the second viewer of a link. +- **The first README limitation is gone.** The remaining one about a stale + approval screenshot is untouched: presence says the human is *there*, not + that what they are looking at is still true. diff --git a/docs/adr/README.md b/docs/adr/README.md index a7e0fd3..5f064e7 100644 --- a/docs/adr/README.md +++ b/docs/adr/README.md @@ -16,6 +16,7 @@ pre-publish security review — they document the history, they do not invent it | [0006](0006-approval-mode.md) | Approval mode: one screenshot, a hold on yes | accepted | Scope decision | | [0007](0007-channels.md) | Channels: an in-process hook, not a second WebSocket client | accepted | Scope decision | | [0008](0008-qr-passthrough.md) | QR passthrough: the agent reads the code, the phone gets the link | accepted | [Measurement 05](../measurements/05-qr.md) | +| [0009](0009-peer-presence-and-ended-ack.md) | Peer presence, and a receipt for the ending | accepted | Measurements [01](../measurements/01-preview-transport.md), [04](../measurements/04-browser-session-lifetime.md) | ## Format diff --git a/e2e/handoff.e2e.ts b/e2e/handoff.e2e.ts index 0a6c8e0..2e704f8 100644 --- a/e2e/handoff.e2e.ts +++ b/e2e/handoff.e2e.ts @@ -25,7 +25,7 @@ import { Solari } from "@solarisdk/browser" import type { Page } from "playwright-core" import type { HandoffEvent } from "../src/events" -import { raiseHand } from "../src/index" +import { type Logger, raiseHand } from "../src/index" import { previewPath, startTestApp } from "../test-app/deploy" import { msUntilNextStep, totp } from "../test-app/totp" import { openHandoffPage } from "./human-sim" @@ -44,6 +44,9 @@ declare global { const FAULT = process.env.HANDRAISE_E2E_FAULT ?? "" const VIEWPORT = { width: 1280, height: 800 } const TIMEOUT_CASE_MS = 8_000 +/** The presence case: a wait nobody would sit through, and a short grace. */ +const PRESENCE_TIMEOUT_MS = 90_000 +const PRESENCE_GRACE_MS = 5_000 const started = Date.now() const timings: Record = {} @@ -55,6 +58,82 @@ function log(event: string, detail: LogDetail = {}): void { console.log(JSON.stringify({ t: Date.now() - started, event, ...detail })) } +/** + * A logger that keeps the one line this file measures — the relay's receipt for + * the ending — and shouts about anything that went wrong. Everything else + * handraise says is already covered by the wide event. + */ +interface AckWatcher { + logger: Logger + /** The `ended_ack` lines handraise logged, as JSON. */ + lines: string[] +} + +function ackWatcher(): AckWatcher { + const lines: string[] = [] + return { + lines, + logger: { + debug: () => undefined, + info: (event, fields) => { + if (event === "ended_ack") lines.push(JSON.stringify(fields)) + }, + warn: (event, fields) => + console.error(JSON.stringify({ warn: event, fields })), + error: (event, fields) => + console.error(JSON.stringify({ error: event, fields })), + }, + } +} + +/** Whether the relay confirmed it had stored the ending before the kill. */ +function acked(lines: string[]): boolean { + return lines.some((line) => line.includes('"acked":true')) +} + +/** + * Open the link the way somebody who was not watching would, *after* the + * answer, and report what they are told about the ending. + * + * Measured, not asserted, and the comment at the call site says why: the relay + * holds the ending (that part is now guaranteed — the agent waits for the + * relay's receipt before it kills anything), but the sandbox it is held in is + * being destroyed, and opening a fresh HTTPS connection plus a WebSocket + * upgrade to us-west takes about as long as the teardown does. What this + * number says is how wide that remaining window is. + */ +async function lateViewerEnding( + humanUrl: string, + deadlineMs = 3_000, +): Promise { + const deadline = Date.now() + deadlineMs + let attempts = 0 + while (Date.now() < deadline) { + attempts += 1 + const openedAt = Date.now() + try { + const viewer = await openHandoffPage(humanUrl) + log("late_viewer_connected", { + attempt: attempts, + ms: Date.now() - openedAt, + }) + const until = Math.min(deadline, Date.now() + 2_000) + while (Date.now() < until && !viewer.ending()) await Bun.sleep(50) + const ending = viewer.ending() + await viewer.close() + if (ending) return ending + } catch (error) { + log("late_viewer_refused", { + attempt: attempts, + ms: Date.now() - openedAt, + error: String(error).slice(0, 80), + }) + await Bun.sleep(150) + } + } + return null +} + function check(condition: boolean, what: string): void { if (!condition) throw new Error(`ASSERTION FAILED: ${what}`) log("assertion_passed", { what }) @@ -358,12 +437,14 @@ try { const askedAt = Date.now() let approvalUrl = "" let event: HandoffEvent | undefined + const ack = ackWatcher() const asking = raiseHand(page, { mode: "approval", reason: "The agent may not move money without a human", action: APPROVAL_ACTION, qr: false, timeoutMs: 60_000, + logger: ack.logger, onUrl: (url) => { approvalUrl = url }, @@ -421,6 +502,13 @@ try { if (answer === "approve") await human.approve() else await human.deny() + // Somebody else opens the same link, right after the answer and while the + // sandbox is being torn down. Until 0.7.0 they saw a blank page: the + // `ended` lost its race with the kill, so the relay had nothing to replay. + // The agent now waits for the relay's receipt before it kills anything, + // which is what makes this an assertion instead of a log line. + const lateEnding = await lateViewerEnding(approvalUrl) + const result = await asking pending = null timings[`approval${answer}Ms`] = Date.now() - askedAt @@ -453,16 +541,23 @@ try { event?.framesSent === 1 + (event?.reconnects ?? 0), `the wide event counts one frame per connection (${event?.framesSent} frames, ${event?.reconnects} reconnects)`, ) - // Deliberately observed and not asserted. The ending is relayed while the - // relay sandbox is already being destroyed, and an approval tears down in - // milliseconds — there is no storageState capture to hold the door open, - // as there is in the takeover case above, which does assert it. A phone - // that answered does not depend on this message: it shows its own ending - // the moment the human taps. A second viewer of the link does, and that - // path is covered offline, where the relay is not being killed underneath - // it: relay.test.ts "a human who joins after the handoff ended sees the - // ending, not the frame" and the ui.spec terminal-overlay tests. log("phone_ending", { seen: human.ending() ?? "none", expected }) + check( + acked(ack.lines), + `the relay stored the ending and said so before the kill (${ack.lines.join(",") || "no ended_ack line"})`, + ) + // Was an observation until 0.7.0, for the reason the ack now removes: the + // ending was written to a socket whose sandbox was already being deleted, + // so whether it was ever relayed was a race. The phone that answered does + // not need it — it shows its own ending the moment the human taps — but + // every *other* holder of the link does, and this is the message they are + // all served from. + check( + human.ending() === expected, + `the answering phone was told over the wire that it ended as ${expected} (saw ${human.ending() ?? "nothing"})`, + ) + // Measured, not asserted. See lateViewerEnding. + log("late_viewer", { seen: lateEnding ?? "none", expected }) await human.close() const gone = await fetch(approvalUrl, { cache: "no-store" }) @@ -473,16 +568,33 @@ try { await askApproval("approve") await askApproval("deny") - // --- An approval answered by a channel, not by the phone --------------- + // --- An approval answered by a channel, while somebody watches the link - // // The path a Telegram or Slack adapter takes: handraise hands the channel - // the screenshot and an `answer()`, and nobody opens the link at all. The - // in-process channel here stands in for the adapter; what is under test is - // the core's side of it against the real relay. + // the screenshot and an `answer()`, and nobody has to open the link at all. + // The in-process channel here stands in for the adapter; what is under test + // is the core's side of it against the real relay. + // + // And the second half of what 0.7.0 fixes. Somebody else *is* holding the + // link — two people were sent it, which is the whole reason it is a URL — + // and they did not answer. Before the relay acknowledged the ending, that + // person watched the handoff be decided and were told nothing: the `ended` + // was written to a socket whose sandbox was already being destroyed. Here + // the viewer is connected before the answer and must be told how it ended. const channelAt = Date.now() let channelUrl = "" let channelEvent: HandoffEvent | undefined let channelShot = 0 + const channelAck = ackWatcher() + // The channel's `answer`, handed out when the adapter is notified and called + // once the watching viewer is on the link. + let handAnswer: (answer: (decision: "approve" | "deny") => boolean) => void = + () => undefined + const answerReady = new Promise<(decision: "approve" | "deny") => boolean>( + (resolve) => { + handAnswer = resolve + }, + ) const channelAnswered = raiseHand(page, { mode: "approval", reason: "The agent may not move money without a human", @@ -492,6 +604,7 @@ try { onUrl: (url) => { channelUrl = url }, + logger: channelAck.logger, onEvent: (raised) => { channelEvent = raised }, @@ -508,20 +621,49 @@ try { raised.url === channelUrl && channelUrl !== "", "the channel is handed the same link the phone would open", ) - check( - raised.answer("approve") === true, - "the channel's first answer settles the handoff", - ) - check( - raised.answer("deny") === false, - "a second answer from the channel is refused", - ) + handAnswer(raised.answer) }, }, ], }) pending = channelAnswered + + const answerFromChannel = await answerReady + // The bystander: they opened the link, they are looking at the screenshot, + // and they are not the one who decides. + const watcher = await openHandoffPage(channelUrl) + await watcher.waitForFrame() + const answeredAt = Date.now() + check( + answerFromChannel("approve") === true, + "the channel's first answer settles the handoff", + ) + check( + answerFromChannel("deny") === false, + "a second answer from the channel is refused", + ) + + const watcherDeadline = Date.now() + 15_000 + while (!watcher.ending() && Date.now() < watcherDeadline) await Bun.sleep(50) + timings.watcherToldMs = Date.now() - answeredAt + log("watcher_told", { + seen: watcher.ending() ?? "none", + ms: timings.watcherToldMs, + endedAck: channelAck.lines[0] ?? "none", + }) + check( + watcher.ending() === "approved", + `a second holder of the link who never answered is told it ended as approved (saw ${watcher.ending() ?? "nothing"})`, + ) + await watcher.close() + const channelResult = await channelAnswered + // After the handoff has returned, because that is when the line is written: + // the watcher above is told at the same moment the agent hears the receipt. + check( + acked(channelAck.lines), + `the relay stored the ending and said so before the kill (${channelAck.lines.join(",") || "no ended_ack line"})`, + ) pending = null timings.channelApprovalMs = Date.now() - channelAt log("channel_approval_done", { @@ -554,6 +696,116 @@ try { `the channel-answered relay is gone (${channelGone.status})`, ) + // --- The human who was there and went ---------------------------------- + // + // The gap this release closes. A human opens the handoff, looks at it, and + // closes the tab without answering — no handback, no abort, nothing on the + // wire. The relay is the only party that can see that socket go (it answers + // the heartbeats itself), so before 0.7.0 the agent sat out the whole + // `timeoutMs`: five minutes by default, against a browser session with a + // ten-minute life. + // A fresh paint first. A CDP screencast delivers a frame when the page + // composites one, and this page has been sitting still through three + // approvals — what is under test here is the socket, not the picture, but a + // handoff that never paints is a confusing way to prove it. + await page.goto(previewPath(app.url, "/qr"), { + waitUntil: "domcontentloaded", + timeout: 30_000, + }) + + const presenceAt = Date.now() + let presenceUrl = "" + let presenceEvent: HandoffEvent | undefined + const presenceAck = ackWatcher() + const abandoned = raiseHand(page, { + reason: "Aurora Bank is asking for a 2FA code", + qr: false, + timeoutMs: PRESENCE_TIMEOUT_MS, + humanGoneGraceMs: PRESENCE_GRACE_MS, + logger: presenceAck.logger, + onUrl: (url) => { + presenceUrl = url + }, + onEvent: (raised) => { + presenceEvent = raised + }, + }) + pending = abandoned + + while (presenceUrl === "") await Bun.sleep(50) + const leaver = await openHandoffPage(presenceUrl) + // The phone is *there*, which is the fact under test: the relay reports the + // socket, and the agent hears about it whether or not a frame has painted. + const shownDeadline = Date.now() + 30_000 + while (leaver.reason() === "" && Date.now() < shownDeadline) { + await Bun.sleep(100) + } + check( + leaver.reason() === "Aurora Bank is asking for a 2FA code", + `the phone is on the handoff (${leaver.reason() || "nothing shown"})`, + ) + log("presence_phone_open", { frames: leaver.frameCount() }) + const leftAt = Date.now() + await leaver.close() + + const abandonedResult = await abandoned + pending = null + timings.presenceCaseMs = Date.now() - presenceAt + timings.endedAfterLeaveMs = Date.now() - leftAt + log("presence_case", { + outcome: abandonedResult.outcome, + durationMs: abandonedResult.durationMs, + afterLeaveMs: timings.endedAfterLeaveMs, + humanSeen: presenceEvent?.humanSeen, + humanLeftMs: presenceEvent?.humanLeftMs, + endedEarly: presenceEvent?.endedEarly, + endedAck: presenceAck.lines[0] ?? "none", + ms: timings.presenceCaseMs, + }) + + check( + abandonedResult.outcome === "timeout", + `a human who walked away ends the handoff as timeout (${abandonedResult.outcome})`, + ) + check( + abandonedResult.durationMs < PRESENCE_TIMEOUT_MS / 2, + `it ended on the absence, not on the wait (${abandonedResult.durationMs}ms of ${PRESENCE_TIMEOUT_MS}ms)`, + ) + check( + timings.endedAfterLeaveMs >= PRESENCE_GRACE_MS, + `it waited the grace out first (${timings.endedAfterLeaveMs}ms of ${PRESENCE_GRACE_MS}ms)`, + ) + check( + timings.endedAfterLeaveMs < PRESENCE_GRACE_MS + 15_000, + `and it ended within the grace plus teardown (${timings.endedAfterLeaveMs}ms)`, + ) + check( + presenceEvent?.humanSeen === true, + "the wide event says a human was there", + ) + check( + abandonedResult.durationMs === presenceEvent?.durationMs, + `the result reports the time the human took, not the teardown after it (${abandonedResult.durationMs}ms vs ${presenceEvent?.durationMs}ms)`, + ) + check( + presenceEvent?.endedEarly === true, + "the wide event says the handoff ended early", + ) + check( + (presenceEvent?.humanLeftMs ?? -1) >= 0, + `the wide event says when they left (${presenceEvent?.humanLeftMs})`, + ) + check( + acked(presenceAck.lines), + `the relay acknowledged the ending before the kill (${presenceAck.lines.join(",") || "no ended_ack line"})`, + ) + const leaverGone = await fetch(presenceUrl, { cache: "no-store" }) + await leaverGone.text() + check( + leaverGone.status !== 200, + `its relay was destroyed too (${leaverGone.status})`, + ) + // --- The cheap second case: nobody comes ------------------------------- const timeoutAt = Date.now() let secondUrl = "" diff --git a/e2e/human-sim.ts b/e2e/human-sim.ts index 7a88603..9afc219 100644 --- a/e2e/human-sim.ts +++ b/e2e/human-sim.ts @@ -100,6 +100,11 @@ export async function openHandoffPage( await page.text() const socket = new WebSocket(humanWebSocketUrl(humanUrl)) + // A phone whose socket is reset — replaced by a second holder of the link, + // or left holding a sandbox that has just been destroyed — must not take the + // run down with it. `ws` throws an unhandled error event when nothing is + // listening, and there is nothing to do about it here: the page is gone. + socket.on("error", () => undefined) let frame: ReceivedFrame | null = null let firstFrameAt: number | null = null let frames = 0 diff --git a/e2e/ui.spec.ts b/e2e/ui.spec.ts index 10950ce..23fdb28 100644 --- a/e2e/ui.spec.ts +++ b/e2e/ui.spec.ts @@ -32,6 +32,7 @@ import type { FrameMeta, HumanToAgent, RelayMessage, + RelayToAgent, } from "../src/relay/protocol" import type { HandoffMode } from "../src/types" @@ -85,12 +86,26 @@ interface AgentClient { /** Put bytes on the wire that the protocol has no way to describe. */ sendRaw(text: string): void next(): Promise - /** Every message this socket has seen, in order. `next()` never consumes it, - * so a test can assert that something was sent *exactly once*. */ + /** Every message the *phone* has sent, in order. `next()` never consumes it, + * so a test can assert that something was sent *exactly once*. The relay's + * own messages — `presence`, `ended_ack` — are not the phone's and are not + * here: every test in this file is about what the page puts on the wire. */ received: RelayMessage[] close(): void } +/** + * What the relay says for itself, rather than forwarding from the phone. Keyed + * by the protocol union, so a third member does not compile until this harness + * knows whether to count it as something the page sent. + */ +const RELAY_ORIGINATED = new Set( + Object.keys({ + presence: true, + ended_ack: true, + } satisfies Record), +) + interface Box { x: number y: number @@ -176,6 +191,7 @@ async function connectAgent(port: number): Promise { socket.on("message", (raw: Buffer) => { const message = parseMessage(raw.toString("utf8")) + if (RELAY_ORIGINATED.has(message.type)) return received.push(message) const waiter = waiters.shift() if (waiter) waiter(message) diff --git a/src/core/handoff.test.ts b/src/core/handoff.test.ts index bc8c4e6..146111d 100644 --- a/src/core/handoff.test.ts +++ b/src/core/handoff.test.ts @@ -33,7 +33,7 @@ import type { RaiseHandOptions, StorageState, } from "../types" -import { raiseHand, runHandoff } from "./raise-hand" +import { raiseHand, runHandoff, watchPresence } from "./raise-hand" import type { ScreencastFrame } from "./screencast" const SERVER_PATH = fileURLToPath( @@ -97,6 +97,8 @@ function startRelayProcess(mode: HandoffMode = "takeover"): Promise { async function connectHuman(port: number): Promise<{ inbox: RelayMessage[] send(message: RelayMessage): void + /** Close the tab, the way a human who has given up does: no message first. */ + close(): void }> { const socket = new WebSocket(`ws://127.0.0.1:${port}/ws?role=human`) const inbox: RelayMessage[] = [] @@ -113,6 +115,7 @@ async function connectHuman(port: number): Promise<{ return { inbox, send: (message) => socket.send(JSON.stringify(message)), + close: () => socket.close(), } } @@ -368,6 +371,10 @@ test("a full handoff emits exactly one wide event with plausible fields", async expect(event.reconnects).toBe(0) expect(event.storageStateCaptured).toBe(true) expect(event.firstFrameMs ?? -1).toBeGreaterThanOrEqual(0) + // What the caller is handed is the time the human took, frozen at the same + // instant the event's is — not that plus the ack, the CDP detach and the + // socket close, which the caller never waited for. + expect(end.durationMs).toBe(event.durationMs) // No secret ever rides along in the wide event. expect(JSON.stringify(event)).not.toContain("pt_token") }) @@ -627,6 +634,549 @@ test("the approval screenshot is not re-published once the handoff is over", asy expect(relay.connections.length).toBeGreaterThan(1) }, 20000) +// --- 0.7.0: the human who was there and went ------------------------------ + +/** + * A takeover against the real relay, with the presence grace turned down to + * something a test can wait for. The wait itself stays long, because the whole + * point is that the handoff ends before it. + */ +function presenceHandoff( + port: number, + cdp: CDPSession, + graceMs: number, + timeoutMs: number, + events: HandoffEvent[], +): Promise<{ outcome: string }> { + return runHandoff({ + page: fakePage(cdp), + agentWsUrl: `ws://127.0.0.1:${port}/ws?role=agent`, + options: { + reason: "Aurora Bank is asking for a 2FA code", + humanGoneGraceMs: graceMs, + logger: noopLogger, + onEvent: (event) => events.push(event), + }, + timeoutMs, + url: "https://relay.example/?pt_token=x", + handoffId: "presence", + relayColdStartMs: 3, + logger: noopLogger, + }) +} + +test("a human who was there and then closed the tab ends the handoff early", async () => { + const port = await startRelayProcess() + const cdp = fakeCdp() + const events: HandoffEvent[] = [] + const human = await connectHuman(port) + + const startedAt = Date.now() + const handoff = presenceHandoff(port, cdp.cdp, 400, 30_000, events) + await until("the phone to see the reason", () => + human.inbox.some((message) => message.type === "state"), + ) + cdp.emitFrame(FRAME) + await until("the phone to see a frame", () => + human.inbox.some((message) => message.type === "frame"), + ) + + // No handback, no abort: the tab is simply gone, which before this release + // cost the agent the whole `timeoutMs`. + human.close() + const end = await handoff + const waited = Date.now() - startedAt + + // The existing outcome, deliberately: a handoff nobody finished is a + // timeout, whether the wait ran out or the human walked away from it. + expect(end.outcome).toBe("timeout") + expect(waited).toBeLessThan(10_000) + const event = events[0] + if (!event) throw new Error("no event") + expect(event.outcome).toBe("timeout") + expect(event.humanSeen).toBe(true) + expect(event.endedEarly).toBe(true) + expect(event.humanLeftMs ?? -1).toBeGreaterThanOrEqual(0) + expect(event.humanLeftMs ?? Infinity).toBeLessThanOrEqual(event.durationMs) +}, 20000) + +test("a phone that comes back inside the grace keeps the handoff alive", async () => { + const port = await startRelayProcess() + const cdp = fakeCdp() + const events: HandoffEvent[] = [] + const first = await connectHuman(port) + + const handoff = presenceHandoff(port, cdp.cdp, 1500, 30_000, events) + await until("the phone to see the reason", () => + first.inbox.some((message) => message.type === "state"), + ) + + // The 60 s proxy cut, and the phone's own reconnect a moment later. + first.close() + await Bun.sleep(300) + const second = await connectHuman(port) + await until("the phone to see the reason again", () => + second.inbox.some((message) => message.type === "state"), + ) + + // Well past the grace, had it not been reset by the reconnect. + await Bun.sleep(1800) + second.send({ type: "handback" }) + const end = await handoff + + expect(end.outcome).toBe("resolved") + const event = events[0] + if (!event) throw new Error("no event") + expect(event.humanSeen).toBe(true) + expect(event.endedEarly).toBe(false) +}, 20000) + +test("a handoff nobody ever opened waits the whole timeout", async () => { + const port = await startRelayProcess() + const cdp = fakeCdp() + const events: HandoffEvent[] = [] + + const startedAt = Date.now() + // A grace far shorter than the wait: a QR code nobody scanned must not be + // read as a human who left, or every unattended handoff would end at once. + const end = await presenceHandoff(port, cdp.cdp, 200, 1200, events) + const waited = Date.now() - startedAt + + expect(end.outcome).toBe("timeout") + expect(waited).toBeGreaterThanOrEqual(1200) + const event = events[0] + if (!event) throw new Error("no event") + expect(event.humanSeen).toBe(false) + expect(event.endedEarly).toBe(false) + expect(event.humanLeftMs).toBeUndefined() +}, 20000) + +test("a grace longer than what is left of the wait changes nothing", async () => { + const port = await startRelayProcess() + const cdp = fakeCdp() + const events: HandoffEvent[] = [] + const human = await connectHuman(port) + + const handoff = presenceHandoff(port, cdp.cdp, 30_000, 1200, events) + await until("the phone to see the reason", () => + human.inbox.some((message) => message.type === "state"), + ) + human.close() + + const end = await handoff + expect(end.outcome).toBe("timeout") + const event = events[0] + if (!event) throw new Error("no event") + // Seen and gone, but the wait ran out first, so this is an ordinary timeout. + expect(event.humanSeen).toBe(true) + expect(event.endedEarly).toBe(false) + expect(event.humanLeftMs ?? -1).toBeGreaterThanOrEqual(0) +}, 20000) + +test("an approval whose human walks away ends early too", async () => { + const port = await startRelayProcess("approval") + const cdp = fakeCdp() + const events: HandoffEvent[] = [] + const human = await connectHuman(port) + + const handoff = runHandoff({ + page: fakePage(cdp.cdp), + agentWsUrl: `ws://127.0.0.1:${port}/ws?role=agent`, + options: { + mode: "approval", + reason: "The agent may not move money without a human", + action: "Transfer EUR 12,430.00 to Acme GmbH", + humanGoneGraceMs: 400, + logger: noopLogger, + onEvent: (event) => events.push(event), + }, + timeoutMs: 30_000, + url: "https://relay.example/?pt_token=x", + handoffId: "presence-approval", + relayColdStartMs: 3, + logger: noopLogger, + }) + + await until("the phone to see the screenshot", () => + human.inbox.some((message) => message.type === "frame"), + ) + // Leaving a decision open is exactly as informative as leaving a browser + // open: nobody is coming back, and the agent should not wait five minutes. + human.close() + + const end = await handoff + expect(end.outcome).toBe("timeout") + const event = events[0] + if (!event) throw new Error("no event") + expect(event.mode).toBe("approval") + expect(event.endedEarly).toBe(true) + expect(event.humanSeen).toBe(true) +}, 20000) + +test("a watch that has been stopped records nothing and arms nothing", () => { + let gone = 0 + const watch = watchPresence(50, Date.now(), () => { + gone += 1 + }) + watch.saw(true, true, 0) + watch.stop() + // The ordinary teardown: the phone closes its socket the instant it renders + // the ending, the relay reports that, and the report arrives while the + // agent's own socket is still finishing its close handshake. It is not a + // departure from a handoff that is already over. + watch.saw(false, true, 0) + + expect(watch.leftMs()).toBeUndefined() + return Bun.sleep(150).then(() => { + expect(gone).toBe(0) + }) +}) + +test("a stopped watch leaves no timer holding the process open", async () => { + // The cost of the bug this pins was invisible from inside the process: the + // stale timer's callback did nothing, it just kept the event loop alive for + // the whole grace — a minute of hang at exit for a CLI agent, after + // `raiseHand` had already resolved. So the assertion is the exit itself. + const root = fileURLToPath(new URL("../../", import.meta.url)) + const probe = Bun.spawn( + [ + "bun", + "-e", + 'import { watchPresence } from "./src/core/raise-hand"; const w = watchPresence(60_000, Date.now(), () => undefined); w.saw(true, true, 0); w.stop(); w.saw(false, true, 0)', + ], + { cwd: root, stdout: "ignore", stderr: "ignore" }, + ) + const outcome = await Promise.race([ + probe.exited, + Bun.sleep(6000).then(() => "still running after 6s" as const), + ]) + probe.kill() + expect(outcome).toBe(0) +}, 15000) + +test("a human who leaves after answering never left", async () => { + const port = await startRelayProcess() + const cdp = fakeCdp() + const events: HandoffEvent[] = [] + const human = await connectHuman(port) + + const handoff = presenceHandoff(port, cdp.cdp, 60_000, 30_000, events) + await until("the phone to see the reason", () => + human.inbox.some((message) => message.type === "state"), + ) + human.send({ type: "handback" }) + // What a real phone does the moment it has answered. + human.close() + + const end = await handoff + expect(end.outcome).toBe("resolved") + const event = events[0] + if (!event) throw new Error("no event") + expect(event.humanSeen).toBe(true) + expect(event.endedEarly).toBe(false) + // Not a departure: it happened after the handoff was over, and reporting it + // would tell an alert that watches this field the opposite of the truth. + expect(event.humanLeftMs).toBeUndefined() +}, 20000) + +test("the ending is acknowledged by the relay before the sandbox could be killed", async () => { + const port = await startRelayProcess() + const cdp = fakeCdp() + const lines: string[] = [] + const recording: Logger = { + debug: () => undefined, + info: (event, fields) => lines.push(`${event} ${JSON.stringify(fields)}`), + warn: () => undefined, + error: () => undefined, + } + + const human = await connectHuman(port) + const handoff = runHandoff({ + page: fakePage(cdp.cdp), + agentWsUrl: `ws://127.0.0.1:${port}/ws?role=agent`, + options: { reason: "Aurora Bank is asking for a 2FA code" }, + timeoutMs: 10_000, + url: "https://relay.example/?pt_token=x", + handoffId: "ack", + relayColdStartMs: 3, + logger: recording, + }) + await until("the phone to see the reason", () => + human.inbox.some((message) => message.type === "state"), + ) + human.send({ type: "abort" }) + await handoff + + // The line the live e2e reads its timing off — and its `acked` field is the + // whole point: `false` there means the ending raced the kill exactly as it + // did before this release, which a test that only looks for the event name + // would call a pass. + const ack = lines.find((line) => line.startsWith("ended_ack ")) + expect(ack ?? "no ended_ack line").toContain('"acked":true') +}, 20000) + +/** Evict the handoff's agent socket the way a second agent process would. */ +async function forceAgentOutage(port: number): Promise { + const impostor = new WebSocket(`ws://127.0.0.1:${port}/ws?role=agent`) + await new Promise((resolve, reject) => { + impostor.once("open", () => resolve()) + impostor.once("error", reject) + }) + // Closing it leaves no agent at all, which is the state under test: the + // handoff's own socket is down and backing off. + impostor.close() +} + +test("a departure the agent only hears about later is counted from when it happened", () => { + let gone = 0 + // A handoff that started five seconds ago. + const watch = watchPresence(1_000, Date.now() - 5_000, () => { + gone += 1 + }) + // The relay's report to a reconnecting agent: nobody is here, somebody was, + // and that has been true for 800 ms. + watch.saw(false, true, 800) + + expect(watch.everSeen()).toBe(true) + expect(watch.leftMs() ?? -1).toBeGreaterThanOrEqual(4_100) + expect(watch.leftMs() ?? -1).toBeLessThanOrEqual(4_300) + // 200 ms of the grace are left, and the floor gives the reconnect a beat to + // deliver whatever else it is holding first. + return Bun.sleep(120) + .then(() => { + expect(gone).toBe(0) + return Bun.sleep(400) + }) + .then(() => { + expect(gone).toBe(1) + }) +}) + +test("a relay whose clock jumps cannot shorten the grace", async () => { + // `sinceMs` is a relay-local delta, so there is no cross-machine skew to + // worry about — but a wall-clock step inside the sandbox is still a number + // this side has no reason to trust. Staleness can never exceed the age of + // the handoff itself, and it is never negative. + let gone = 0 + const forward = watchPresence(2_000, Date.now(), () => { + gone += 1 + }) + forward.saw(true, true, 0) + // The clock jumped forward: the relay reports a departure six minutes ago, + // on a handoff that is milliseconds old. + forward.saw(false, true, 500_000) + expect(forward.leftMs() ?? -1).toBeGreaterThanOrEqual(0) + expect(forward.leftMs() ?? -1).toBeLessThan(200) + + // And backwards, which would otherwise write a departure in the future. + const backward = watchPresence(2_000, Date.now(), () => undefined) + backward.saw(true, true, 0) + backward.saw(false, true, -60_000) + expect(backward.leftMs() ?? -1).toBeGreaterThanOrEqual(0) + expect(backward.leftMs() ?? -1).toBeLessThan(200) + + // The full grace, not the 250 ms floor a backdated report is armed with. + await Bun.sleep(500) + expect(gone).toBe(0) + await Bun.sleep(1_800) + expect(gone).toBe(1) +}, 15000) + +test("a whole visit during an agent outage still counts, and the grace runs from the real departure", async () => { + const port = await startRelayProcess() + const cdp = fakeCdp() + const events: HandoffEvent[] = [] + + const startedAt = Date.now() + const handoff = presenceHandoff(port, cdp.cdp, 1500, 20_000, events) + await Bun.sleep(300) + await forceAgentOutage(port) + + // The human opens the link, sees a handoff nobody is driving, and closes it + // — all of it while the agent's socket is down and backing off. Both + // announcements find no agent; only the history the relay keeps survives. + const visitor = await connectHuman(port) + await Bun.sleep(80) + const leftAt = Date.now() + visitor.close() + + const end = await handoff + expect(end.outcome).toBe("timeout") + const event = events[0] + if (!event) throw new Error("no event") + expect(event.humanSeen).toBe(true) + expect(event.endedEarly).toBe(true) + // The grace ran from the departure, not from the reconnect that reported it. + expect(Date.now() - leftAt).toBeLessThan(4_000) + expect(event.humanLeftMs ?? -1).toBeGreaterThan(leftAt - startedAt - 400) + expect(event.humanLeftMs ?? -1).toBeLessThan(leftAt - startedAt + 400) +}, 30000) + +test("an answer given during an agent outage still resolves the handoff", async () => { + const port = await startRelayProcess() + const cdp = fakeCdp() + const events: HandoffEvent[] = [] + + // A grace shorter than the outage, so the departure the reconnecting agent + // hears about is already past it. The answer is one frame behind that + // report, and it must not lose a race to a timer. + const handoff = presenceHandoff(port, cdp.cdp, 400, 20_000, events) + await Bun.sleep(300) + await forceAgentOutage(port) + + const visitor = await connectHuman(port) + visitor.send({ type: "handback" }) + await Bun.sleep(50) + visitor.close() + + const end = await handoff + expect(end.outcome).toBe("resolved") + const event = events[0] + if (!event) throw new Error("no event") + expect(event.humanSeen).toBe(true) + expect(event.endedEarly).toBe(false) +}, 30000) + +test("input that arrives after the grace ended the handoff never reaches the page", async () => { + const port = await startRelayProcess() + const cdp = fakeCdp() + const events: HandoffEvent[] = [] + // A slow screenshot, so the QR scan below is still in flight when the grace + // settles the handoff: teardown waits for it, and that wait is the window in + // which a phone that comes back could still be routed to a live page. + const handoff = runHandoff({ + page: fakePage(cdp.cdp, 1500), + agentWsUrl: `ws://127.0.0.1:${port}/ws?role=agent`, + options: { + reason: "Aurora Bank is asking for a 2FA code", + humanGoneGraceMs: 300, + logger: noopLogger, + onEvent: (event) => events.push(event), + }, + timeoutMs: 30_000, + url: "https://relay.example/?pt_token=x", + handoffId: "late-input", + relayColdStartMs: 3, + logger: noopLogger, + }) + + const human = await connectHuman(port) + await until("the phone to see the reason", () => + human.inbox.some((message) => message.type === "state"), + ) + cdp.emitFrame(FRAME) + await until("the phone to see a frame", () => + human.inbox.some((message) => message.type === "frame"), + ) + human.send({ type: "tap", fx: 400, fy: 250 }) + await until("the tap to dispatch as a mouse event", () => + cdp.calls.includes("Input.dispatchMouseEvent"), + ) + const dispatches = (): number => + cdp.calls.filter((call) => call === "Input.dispatchMouseEvent").length + const before = dispatches() + + human.send({ type: "scanqr" }) + await Bun.sleep(100) + // Gone, and the grace ends the handoff while the scan is still in flight. + human.close() + await Bun.sleep(600) + + // Somebody opens the link again and taps at a page the agent has already + // moved on from. Before 0.7.0 the only guard here was "a terminal message + // arrived", and a grace timeout is not one. + const late = await connectHuman(port) + for (let i = 0; i < 5; i++) late.send({ type: "tap", fx: 100, fy: 100 }) + + const end = await handoff + expect(end.outcome).toBe("timeout") + expect(dispatches()).toBe(before) + expect(events[0]?.inputsApplied).toBe(1) +}, 30000) + +test("a grace that is not a usable number is refused before anything is created", async () => { + const asking = raiseHand(fakePage(fakeCdp().cdp), { + reason: "Aurora Bank is asking for a 2FA code", + // Below the floor: a grace this short would end a handoff on the gap + // between a proxy cut and the phone's own reconnect. + humanGoneGraceMs: 10, + baseUrl: CLOSED_PORT, + logger: noopLogger, + }) + + await expect(asking).rejects.toMatchObject({ + name: "HandraiseError", + code: "invalid_option", + }) + + const infinite = raiseHand(fakePage(fakeCdp().cdp), { + reason: "Aurora Bank is asking for a 2FA code", + humanGoneGraceMs: Number.POSITIVE_INFINITY, + baseUrl: CLOSED_PORT, + logger: noopLogger, + }) + await expect(infinite).rejects.toMatchObject({ + name: "HandraiseError", + code: "invalid_option", + }) + + // One past the largest delay a Node timer can hold. It is finite and far + // above the floor, and Node silently collapses it to 1 ms — a request for a + // three-week grace that ends the handoff on the first blink. + const overflowed = raiseHand(fakePage(fakeCdp().cdp), { + reason: "Aurora Bank is asking for a 2FA code", + humanGoneGraceMs: 2_147_483_648, + baseUrl: CLOSED_PORT, + logger: noopLogger, + }) + await expect(overflowed).rejects.toMatchObject({ + name: "HandraiseError", + code: "invalid_option", + }) + + // One below the floor. The floor is not a formality: measured against the + // real relay, a 1 000 ms grace ended a healthy handoff on the first 60 s + // proxy cut, because the phone's reconnect takes about a second. + const tooTight = raiseHand(fakePage(fakeCdp().cdp), { + reason: "Aurora Bank is asking for a 2FA code", + humanGoneGraceMs: 4_999, + baseUrl: CLOSED_PORT, + logger: noopLogger, + }) + await expect(tooTight).rejects.toMatchObject({ + name: "HandraiseError", + code: "invalid_option", + }) + + // And the floor itself: accepted, so the guard fails on the relay rather + // than on the option. + const atTheFloor = raiseHand(fakePage(fakeCdp().cdp), { + reason: "Aurora Bank is asking for a 2FA code", + humanGoneGraceMs: 5_000, + apiKey: "not-a-real-key", + baseUrl: CLOSED_PORT, + logger: noopLogger, + }) + await expect(atTheFloor).rejects.toMatchObject({ + name: "HandraiseError", + code: "relay_start_failed", + }) + + // And the last value that is still a timer: accepted, so the guard fails on + // the relay rather than on the option. + const largest = raiseHand(fakePage(fakeCdp().cdp), { + reason: "Aurora Bank is asking for a 2FA code", + humanGoneGraceMs: 2_147_483_647, + apiKey: "not-a-real-key", + baseUrl: CLOSED_PORT, + logger: noopLogger, + }) + await expect(largest).rejects.toMatchObject({ + name: "HandraiseError", + code: "relay_start_failed", + }) +}, 20000) + test("an approval with a blank action is refused before a relay is started", async () => { // The tool guards this for the model; the library has to guard it for every // caller, and here is the one place raiseHand may still throw — no URL @@ -1400,7 +1950,7 @@ test("settled resolves with the outcome when the phone answers", async () => { if (!raised) throw new Error("the channel was not notified") human.send({ type: "deny" }) - expect(await handoff).toEqual({ outcome: "denied" }) + expect(await handoff).toMatchObject({ outcome: "denied" }) // This is the whole point: the channel is told the phone answered, without // having been the one who was asked. expect(await raised.settled).toBe("denied") diff --git a/src/core/raise-hand.ts b/src/core/raise-hand.ts index cf74cbb..9ad2309 100644 --- a/src/core/raise-hand.ts +++ b/src/core/raise-hand.ts @@ -54,6 +54,53 @@ const DEFAULT_TIMEOUT_MS = 5 * 60_000 /** The relay must outlive the handoff, never the other way round. */ const RELAY_SLACK_MS = 5 * 60_000 +/** + * How long a handoff keeps waiting after the human's phone has disappeared. + * + * One minute, because of the number underneath it: the preview proxy cuts an + * idle WebSocket after exactly 60 s (docs/measurements/01-preview-transport.md) + * and the phone reconnects about a second later, so anything that ends a + * handoff on a shorter absence would end it on the platform's own housekeeping + * instead of on a human decision. See ADR 0009. + */ +const DEFAULT_HUMAN_GONE_GRACE_MS = 60_000 + +/** + * The floor under `humanGoneGraceMs`. + * + * Five seconds, and not the one second the reconnect nominally takes: measured + * against the real relay, a 1 000 ms grace ended a healthy handoff on the + * first 60 s proxy cut — the phone was back a second later, and a second was + * exactly the budget. The floor has to clear the reconnect it exists to + * survive, with room for a slow one, so it is five times it. + */ +const MIN_HUMAN_GONE_GRACE_MS = 5_000 + +/** + * The largest delay a Node timer holds. One millisecond more and it fires + * immediately (the value is truncated to a signed 32-bit integer), so a + * caller asking for a three-week grace would get one that ends the handoff on + * the first blink. Refused rather than silently honoured as 1 ms. + */ +const MAX_TIMER_DELAY_MS = 2_147_483_647 + +/** + * The shortest grace a *backdated* absence is ever armed with. + * + * A reconnecting agent is told the presence state first and handed whatever + * the relay buffered for it second — the handback the human gave while the + * socket was down, typically. Those are separate frames and therefore possibly + * separate ticks, so an absence that is already past its grace must not settle + * in the same breath as the reconnect: the answer would lose a race with a + * timer, and a handoff somebody answered would be reported as a timeout. + * + * Only reached when the news is stale; a live departure always has the whole + * grace ahead of it. Measured rather than guessed: the relay writes the + * presence report and the buffered answer back to back on one socket, and the + * gap between them is 0 ms; the floor tolerates 240 ms of it. + */ +const BACKDATED_GRACE_FLOOR_MS = 250 + /** * Cap on the `storageState()` capture. It is a CDP round trip, and the Solari * browser session may die in the very same instant the human hands back, which @@ -147,8 +194,123 @@ function isBrowserGone(error: Error): boolean { return error.message.includes("Browser closed") } +/** + * Whether a human is on the other end, as a three-state fact. + * + * `never_seen` is a link nobody has opened, and it is deliberately not the + * same as `gone`: an unscanned QR code is the ordinary wait, and ending it + * early would turn every unattended handoff into an instant timeout. Only the + * step from `present` to `gone` starts a clock. + */ +type Presence = "never_seen" | "present" | "gone" + +/** The presence state machine of one handoff. */ +interface PresenceWatch { + /** + * Feed it the relay's `presence` message: the current state, whether a human + * was ever there, and how old that news is. + */ + saw(human: boolean, seen: boolean, sinceMs: number): void + /** Whether a human was ever connected. */ + everSeen(): boolean + /** When the human last disappeared, in ms since the handoff started. */ + leftMs(): number | undefined + /** + * Stop watching: clear any pending grace, and ignore every later report. + * Idempotent, and called on every teardown path. + */ + stop(): void +} + +/** + * Watch the human's socket and call `onGone` once they have been away for the + * whole grace. + * + * A reconnect cancels the pending call rather than shortening it: the 60 s + * proxy cut is a departure and a return about a second apart, and treating it + * as anything else would end healthy handoffs. The clock is not restarted + * either when a second `presence: false` arrives — a reconnecting *agent* is + * told the state afresh, and that report says nothing new about the human. + * + * After `stop()` nothing is recorded and nothing is armed. That is not + * tidiness: the phone closes its socket the moment it renders the ending, so + * the last report of almost every handoff is a departure that arrives while + * the agent's own socket is still closing. Acting on it armed a grace-long + * timer nobody would ever clear — the process hung for a minute after + * `raiseHand` had resolved — and recorded a `humanLeftMs` for a human who was + * there to the end. + */ +export function watchPresence( + graceMs: number, + startedAt: number, + onGone: () => void, +): PresenceWatch { + let presence: Presence = "never_seen" + let everSeen = false + let leftMs: number | undefined + let timer: ReturnType | null = null + let stopped = false + + const clear = (): void => { + if (timer) clearTimeout(timer) + timer = null + } + + return { + saw(human, seen, sinceMs) { + if (stopped) return + if (seen) everSeen = true + if (human) { + everSeen = true + presence = "present" + clear() + return + } + // A departure only means something after an arrival — but the arrival + // does not have to be one this agent saw. A whole visit can begin and + // end while the agent's socket is down, and the relay reports that as + // "nobody here, somebody was, this long ago". + if (!everSeen) return + // Only the first report starts the clock. A reconnecting agent is told + // the state afresh, and that says nothing new about the human. + if (presence === "gone") return + presence = "gone" + // When it happened, not when we heard: `sinceMs` is how stale the news + // is, and both the timestamp and what is left of the grace are measured + // from the departure itself. + // + // Clamped to the age of the handoff first. The number is a relay-local + // delta, so there is no clock skew between two machines to correct — but + // a wall-clock step inside that sandbox would otherwise report an + // absence older than the handoff, which arms the floor and ends a + // handoff with a human possibly still on it. Nothing that happened + // before this handoff started is news about it. + const elapsed = Date.now() - startedAt + const staleness = Math.min(Math.max(0, sinceMs), elapsed) + leftMs = elapsed - staleness + timer = setTimeout( + onGone, + Math.max(BACKDATED_GRACE_FLOOR_MS, graceMs - staleness), + ) + }, + everSeen: () => everSeen, + leftMs: () => leftMs, + stop() { + stopped = true + clear() + }, + } +} + interface HandoffEnd { outcome: HandoffOutcome + /** + * How long the human had, frozen at settlement — the same number the wide + * event carries. Teardown happens after it: the ending's receipt, the CDP + * detach, the socket close. None of that is time anybody waited for a human, + * and before this was returned the caller's `durationMs` included it. + */ + durationMs: number storageState?: StorageState } @@ -326,6 +488,23 @@ export async function runHandoff(run: HandoffRun): Promise { const timer = setTimeout(() => settle("timeout"), timeoutMs) + /** + * The human who was there and went. Ends the handoff with the outcome a + * handoff nobody finished has always had — `timeout` — because that is what + * happened: nobody answered. `endedEarly` is how the wide event tells the + * two apart, and it is why no seventh outcome was added (ADR 0009). + */ + let endedEarly = false + const presence = watchPresence( + run.options.humanGoneGraceMs ?? DEFAULT_HUMAN_GONE_GRACE_MS, + startedAt, + () => { + if (over) return + endedEarly = true + settle("timeout") + }, + ) + let pump: FramePump | null = null let cdp: CDPSession | null = null let input: ReturnType | null = null @@ -366,11 +545,13 @@ export async function runHandoff(run: HandoffRun): Promise { const refreshFocus = (): void => { // One probe at a time. A fast typist would otherwise queue a CDP round // trip per keystroke, all of them answering the same question. - if (probing || terminal) return + if (probing || terminal || over) return probing = true void probeFocus(page) .then((focus) => { - if (terminal) return + // A probe is a CDP round trip, so the handoff can settle while one is + // in flight; nothing about the page may go on the wire after that. + if (terminal || over) return const json = JSON.stringify(focus) if (json === lastFocusJson) return lastFocusJson = json @@ -444,6 +625,13 @@ export async function runHandoff(run: HandoffRun): Promise { } const onHuman = (message: HumanToAgent): void => { + // Nothing the human sends means anything once this is over, and one of + // them would still do something: the relay goes on routing until the agent + // socket closes, and teardown can wait seconds — on a QR scan in flight, + // on the ending's receipt — with a live input path behind it. The `answer` + // that ends a handoff is refused here too; `answerHandoff` refused it + // anyway, and "first answer wins" is the relay's rule as well. + if (over) return const ending = endingFor(mode, message.type) if (ending) { answerHandoff(ending, "relay") @@ -497,6 +685,14 @@ export async function runHandoff(run: HandoffRun): Promise { const connection = connectRelay({ url: agentWsUrl, onMessage: onHuman, + // The relay's own report, and the only way to learn that a tab was closed: + // it answers the heartbeats itself, so silence on this socket says nothing + // about the person. Not after the handoff has settled: the phone closes + // its socket as soon as it is told how this ended, and that is not a human + // walking away from anything. + onPresence: (human, seen, sinceMs) => { + if (!over) presence.saw(human, seen, sinceMs) + }, // The relay replays the last state to a late joiner, but re-sending on // every reconnect costs one small message and covers the case where the // relay restarted underneath us. @@ -615,6 +811,7 @@ export async function runHandoff(run: HandoffRun): Promise { announceSettled(finalOutcome) clearTimeout(timer) + presence.stop() browser?.off("disconnected", onGone) page.off("close", onGone) // Let a scan that was in flight when the handoff settled finish reporting @@ -625,8 +822,16 @@ export async function runHandoff(run: HandoffRun): Promise { await scanner.close() await pump?.stop() // The ending must reach the phone, so wait briefly for a reconnect if the - // socket is momentarily down rather than dropping it like a stale frame. + // socket is momentarily down rather than dropping it like a stale frame — + // and then for the relay's receipt, because the caller destroys the sandbox + // next and a written ending that was never stored is one a second viewer of + // the link will never see. + const endingAt = Date.now() await connection.sendFinal(endedMessage(finalOutcome)) + logger.info("ended_ack", { + acked: connection.stats().endedAcked, + ms: Date.now() - endingAt, + }) await connection.close() await cdp?.detach().catch(() => undefined) @@ -647,9 +852,13 @@ export async function runHandoff(run: HandoffRun): Promise { qrScans, qrHits, reconnects: connection.stats().reconnects, + humanSeen: presence.everSeen(), + endedEarly, storageStateCaptured: storageState !== undefined, } if (firstFrameMs !== undefined) event.firstFrameMs = firstFrameMs + const humanLeftMs = presence.leftMs() + if (humanLeftMs !== undefined) event.humanLeftMs = humanLeftMs // Only an answer has a source. A timeout, a dead session or a handback is // not "answered via" anything, so the field stays absent there. if ( @@ -662,8 +871,8 @@ export async function runHandoff(run: HandoffRun): Promise { if (firstError !== undefined) event.error = firstError emitHandoffEvent(options, logger, event) - if (storageState === undefined) return { outcome: finalOutcome } - return { outcome: finalOutcome, storageState } + if (storageState === undefined) return { outcome: finalOutcome, durationMs } + return { outcome: finalOutcome, durationMs, storageState } } /** The two modes, as a runtime value. */ @@ -703,6 +912,30 @@ function checkedMode(options: RaiseHandOptions): HandoffMode { return mode as HandoffMode } +/** + * Check the presence grace, and return it. + * + * Validated here rather than clamped: a caller who asks for a 10 ms grace has + * misunderstood what the option does, and silently substituting a minute would + * hide that until a handoff ended on a network blip in production. Like the + * mode checks, it runs before any sandbox exists, so nothing is taken back. + */ +function checkedGrace(options: RaiseHandOptions): number { + const grace = options.humanGoneGraceMs + if (grace === undefined) return DEFAULT_HUMAN_GONE_GRACE_MS + if ( + !Number.isFinite(grace) || + grace < MIN_HUMAN_GONE_GRACE_MS || + grace > MAX_TIMER_DELAY_MS + ) { + throw new HandraiseError( + "invalid_option", + `handraise: humanGoneGraceMs must be a number between ${MIN_HUMAN_GONE_GRACE_MS} and ${MAX_TIMER_DELAY_MS} ms (got ${String(grace)}). It is how long a handoff keeps waiting after the human's phone disappears: below the floor it would end handoffs on the reconnect that follows the proxy's 60 s cut, and above the ceiling a Node timer collapses to one millisecond, which ends them at once.`, + ) + } + return grace +} + /** * Refuse a dead page before a sandbox is created. * @@ -757,6 +990,10 @@ export async function raiseHand( ): Promise { const logger = safeLogger(options.logger ?? quietLogger) const mode = checkedMode(options) + // Checked here and read in `runHandoff`, which takes it off the same options + // object: this is the guard, not the plumbing, and it belongs with the other + // two in the one place a `raiseHand` call may still be refused. + checkedGrace(options) const apiKey = options.apiKey ?? process.env.SOLARI_API_KEY if (!apiKey) { throw new HandraiseError( @@ -780,9 +1017,8 @@ export async function raiseHand( ) const startedAt = Date.now() - let endedAt = startedAt let webhook: Promise = Promise.resolve() - let end: HandoffEnd = { outcome: "disconnected" } + let end: HandoffEnd = { outcome: "disconnected", durationMs: 0 } try { try { @@ -832,12 +1068,11 @@ export async function raiseHand( }) } catch (error) { // runHandoff does not throw, so this only fires on an unexpected fault; the - // handoff event is emitted inside runHandoff, on every ordinary path. + // handoff event is emitted inside runHandoff, on every ordinary path. There + // is no settlement to report a duration from, so this path measures its own. logger.error("handoff_failed", { error: String(error) }) + end = { outcome: end.outcome, durationMs: Date.now() - startedAt } } finally { - // Captured before teardown: durationMs is the time the human had, not the - // time the sandbox took to shut down afterwards. - endedAt = Date.now() await webhook await relay.kill().catch((error) => { logger.error("relay_release_failed", { error: String(error) }) @@ -846,7 +1081,9 @@ export async function raiseHand( const result: HandoffResult = { outcome: end.outcome, - durationMs: endedAt - startedAt, + // The handoff's own measurement, not this function's: `endedAt` is taken + // after the relay teardown, which is nobody's waiting time. + durationMs: end.durationMs, url: relay.humanUrl, } if (end.storageState) result.storageState = end.storageState diff --git a/src/core/socket.test.ts b/src/core/socket.test.ts index cc1333d..a9c0f8a 100644 --- a/src/core/socket.test.ts +++ b/src/core/socket.test.ts @@ -18,12 +18,19 @@ import WebSocket, { WebSocketServer } from "ws" import type { HumanToAgent, RelayMessage } from "../relay/protocol" import type { HandoffMode } from "../types" -import { connectRelay, type RelayConnection } from "./socket" +import { + CLOSE_GRACE_MS, + connectRelay, + ENDED_ACK_TIMEOUT_MS, + type RelayConnection, +} from "./socket" const SERVER_PATH = fileURLToPath( new URL("../relay/guest/server.js", import.meta.url), ) const START_TIMEOUT_MS = 5000 +/** Long enough for one local round trip through the real relay process. */ +const MESSAGE_WAIT_MS = 2000 const META = { deviceWidth: 1280, @@ -96,6 +103,8 @@ interface FakeRelay { /** One entry per accepted connection. */ sockets: WebSocket[] send(message: RelayMessage): void + /** Take the whole relay away, so a reconnect has nothing to find. */ + stop(): Promise } /** A bare WebSocket server: no relay semantics, full control over the socket. */ @@ -132,6 +141,11 @@ async function startFakeRelay(): Promise { send(message) { sockets.at(-1)?.send(JSON.stringify(message)) }, + stop: () => + new Promise((resolve) => { + for (const socket of sockets) socket.terminate() + server.close(() => resolve()) + }), } } @@ -318,6 +332,220 @@ test("sendFinal waits for a reconnect before giving up on the ending", async () ) }) +test("presence from the real relay is reported, and only presence", async () => { + const relay = await startRelayProcess() + const presence: boolean[] = [] + const human: HumanToAgent[] = [] + const connection = track( + connectRelay({ + url: `ws://127.0.0.1:${relay.port}/ws?role=agent`, + onMessage: (message) => human.push(message), + onPresence: (there) => presence.push(there), + }), + ) + await until("the agent socket to open", () => connection.isOpen()) + // Nobody has opened the link yet, and that is what the relay says first. + await until("the empty relay to report itself", () => presence.length === 1) + expect(presence).toEqual([false]) + + const phone = await rawPeer(relay.port, "human") + await until("the arrival", () => presence.length === 2) + phone.socket.close() + await until("the departure", () => presence.length === 3) + + expect(presence).toEqual([false, true, false]) + // Presence is the relay's own message, not the human's: it must never reach + // the handoff as if a person had sent it. + expect(human).toEqual([]) +}) + +test("sendFinal waits for the relay to acknowledge the ending", async () => { + const relay = await startRelayProcess() + const connection = track( + connectRelay({ + url: `ws://127.0.0.1:${relay.port}/ws?role=agent`, + onMessage: () => undefined, + }), + ) + await until("the agent socket to open", () => connection.isOpen()) + + await connection.sendFinal({ type: "ended", outcome: "approved" }) + + // The ack is what makes the next line safe to assert without polling: the + // relay has stored the ending before `sendFinal` resolved, so a phone that + // opens the link now is told how it ended. + expect(connection.stats().endedAcked).toBe(true) + const late = await rawPeer(relay.port, "human") + await until( + "the late phone to be told", + () => late.inbox.length > 0, + MESSAGE_WAIT_MS, + ) + expect(late.inbox).toEqual([{ type: "ended", outcome: "approved" }]) +}) + +test("a relay that never acknowledges the ending costs two seconds, not the handoff", async () => { + // An older relay, or one whose socket died between the write and the ack. + // The ending still went out; the agent must not hang on the receipt. + const fake = await startFakeRelay() + const connection = track( + connectRelay({ + url: `ws://127.0.0.1:${fake.port}/ws?role=agent`, + onMessage: () => undefined, + heartbeatMs: 60_000, + }), + ) + await until("the socket to open", () => connection.isOpen()) + + const startedAt = Date.now() + await connection.sendFinal({ type: "ended", outcome: "timeout" }) + const waited = Date.now() - startedAt + + expect(fake.received).toEqual([{ type: "ended", outcome: "timeout" }]) + expect(connection.stats().endedAcked).toBe(false) + expect(waited).toBeGreaterThanOrEqual(ENDED_ACK_TIMEOUT_MS - 50) + expect(waited).toBeLessThan(ENDED_ACK_TIMEOUT_MS + 1500) +}, 10000) + +test("a relay that is gone costs the close grace, and not an ack on top of it", async () => { + // The `disconnected` path: the sandbox died under the handoff, so the ending + // cannot be written at all. Waiting for a receipt for a message that was + // never sent doubled the teardown of the one handoff whose caller is already + // having a bad time. + const fake = await startFakeRelay() + const connection = track( + connectRelay({ + url: `ws://127.0.0.1:${fake.port}/ws?role=agent`, + onMessage: () => undefined, + heartbeatMs: 60_000, + }), + ) + await until("the socket to open", () => connection.isOpen()) + await fake.stop() + await until("the socket to go down", () => !connection.isOpen()) + + const startedAt = Date.now() + await connection.sendFinal({ type: "ended", outcome: "disconnected" }) + const waited = Date.now() - startedAt + + expect(connection.stats().endedAcked).toBe(false) + expect(waited).toBeLessThan(CLOSE_GRACE_MS + 500) +}, 15000) + +test("an acknowledgement that lands before sendFinal is waiting still counts", async () => { + // A relay on a fast link can store the ending and answer before the local + // send callback has even resumed the caller. The receipt was armed after + // that callback, so the answer fell into a gap: teardown then waited its + // full two seconds and reported the ending as unacknowledged — while the + // relay had it. This relay acks exactly once, so a second `ended` cannot + // paper over the gap. + const fake = await startFakeRelay() + const connection = track( + connectRelay({ + url: `ws://127.0.0.1:${fake.port}/ws?role=agent`, + onMessage: () => undefined, + heartbeatMs: 60_000, + }), + ) + await until("the socket to open", () => connection.isOpen()) + const relaySocket = fake.sockets[0] + if (!relaySocket) throw new Error("the fake relay accepted no socket") + let acks = 0 + relaySocket.on("message", () => { + if (acks > 0) return + acks += 1 + relaySocket.send(JSON.stringify({ type: "ended_ack" })) + }) + + await connection.send({ type: "ended", outcome: "approved" }) + await until("the relay to answer", () => acks === 1) + await Bun.sleep(100) + + const startedAt = Date.now() + await connection.sendFinal({ type: "ended", outcome: "approved" }) + const waited = Date.now() - startedAt + + expect(connection.stats().endedAcked).toBe(true) + expect(waited).toBeLessThan(500) +}, 15000) + +/** + * A relay that dies under the first ending and answers on the next connection. + * + * The failure this stands in for is the one the two-second ack budget exists + * for: the write succeeds locally, the socket dies before the bytes are + * stored, and the connection comes back inside the window. A relay that simply + * never acks — the other fake here — does not exercise it, because there the + * ending really did arrive. + */ +interface FlakyRelay { + port: number + /** Endings this relay actually stored (i.e. did not die under). */ + stored(): number + stop(): Promise +} + +async function startFlakyRelay(): Promise { + const server = new WebSocketServer({ port: 0, host: "127.0.0.1" }) + const sockets: WebSocket[] = [] + let connections = 0 + let stored = 0 + + server.on("connection", (socket: WebSocket) => { + sockets.push(socket) + connections += 1 + const dies = connections === 1 + socket.on("message", (data: Buffer) => { + if (parse(data.toString()).type !== "ended") return + if (dies) { + socket.terminate() + return + } + stored += 1 + socket.send(JSON.stringify({ type: "ended_ack" })) + }) + }) + await new Promise((resolve) => + server.once("listening", () => resolve()), + ) + const stop = (): Promise => + new Promise((resolve) => { + for (const socket of sockets) socket.terminate() + server.close(() => resolve()) + }) + cleanups.push(stop) + + const address = server.address() + // SAFETY: as `startFakeRelay` — a listening TCP server, so `address()` is an + // AddressInfo and not the string a unix socket would give. + return { port: (address as AddressInfo).port, stored: () => stored, stop } +} + +test("an ending whose socket dies under it is re-sent on the reconnect", async () => { + const relay = await startFlakyRelay() + const connection = track( + connectRelay({ + url: `ws://127.0.0.1:${relay.port}/ws?role=agent`, + onMessage: () => undefined, + heartbeatMs: 60_000, + }), + ) + await until("the socket to open", () => connection.isOpen()) + + const startedAt = Date.now() + await connection.sendFinal({ type: "ended", outcome: "resolved" }) + const waited = Date.now() - startedAt + + // The whole justification for waiting two seconds is that the connection + // reconnects inside them. It has to carry the ending when it does, or the + // relay stores nothing, the phone stays on "Reconnecting…", and the next + // viewer of the link is told nothing — the exact failure this release + // exists to close. + expect(relay.stored()).toBe(1) + expect(connection.stats().endedAcked).toBe(true) + expect(waited).toBeLessThan(ENDED_ACK_TIMEOUT_MS + 500) +}, 15000) + test("close() ends the handoff and stops reconnecting", async () => { const fake = await startFakeRelay() let opens = 0 diff --git a/src/core/socket.ts b/src/core/socket.ts index 9c75f93..106c404 100644 --- a/src/core/socket.ts +++ b/src/core/socket.ts @@ -10,8 +10,9 @@ * valid for an hour, so a dropped socket is recovered with backoff for as * long as the handoff is running. * 3. The relay answers `ping` itself and does not forward it. A pong proves - * the relay is alive; it proves nothing about the human. There is no signal - * for "the human closed the tab" — the timeout is the honest answer. + * the relay is alive; it proves nothing about the human. The relay says + * that in its own words instead — `presence`, reported here as `onPresence` + * — because it is the only party that can see the phone's socket. */ import WebSocket from "ws" @@ -25,7 +26,23 @@ import { const MAX_BACKOFF_MS = 8_000 const BASE_BACKOFF_MS = 500 -const CLOSE_GRACE_MS = 2_000 +/** + * How long a terminal message waits for a reconnect, and how long `close()` + * waits for the close handshake. Exported for the tests that pin what a relay + * which is gone for good costs. + */ +export const CLOSE_GRACE_MS = 2_000 + +/** + * How long `sendFinal` waits for `ended_ack` before it stops caring. + * + * The sandbox is destroyed within a second or so of this call, and the ack is + * the only proof that the ending was stored rather than merely written to a + * socket that died with the process. Two seconds is the same grace the write + * itself gets: long enough for a round trip to us-west and a reconnect, short + * enough that a relay which cannot answer never becomes the caller's problem. + */ +export const ENDED_ACK_TIMEOUT_MS = 2_000 export interface RelayConnectionOptions { /** `wss://…/ws?role=agent&pt_token=…`, exactly as `startRelay()` returned it. */ @@ -34,6 +51,18 @@ export interface RelayConnectionOptions { onMessage: (message: HumanToAgent) => void /** Called on every successful connect, including reconnects. */ onOpen?: () => void + /** + * Called with what the relay knows about the human: whether one is connected + * now, whether one ever was, and how old that news is in ms. Once shortly + * after every connect, and then on every change. The relay is the only party + * that can see the phone's socket — it answers the heartbeats itself — so + * this is the sole signal that a tab was closed. + * + * `seen` and `sinceMs` are normalised here: a relay too old to send them + * reports the current state as everything it knows, which is what this + * callback did before they existed. + */ + onPresence?: (human: boolean, seen: boolean, sinceMs: number) => void /** Heartbeat period. Defaults to the protocol's 20 s. */ heartbeatMs?: number } @@ -47,9 +76,14 @@ export interface RelayConnection { send(message: AgentToHuman | Heartbeat): Promise /** * Send a terminal message (the `ended` frame), waiting up to the close grace - * period for a reconnect to finish if the socket is momentarily down. The - * human's phone hangs on "Reconnecting…" forever if this is dropped, so it is - * worth the short wait that `send` deliberately refuses for stale frames. + * period for a reconnect to finish if the socket is momentarily down, and + * then up to `ENDED_ACK_TIMEOUT_MS` for the relay's `ended_ack` — re-sending + * the ending on any reconnect inside that window, because a socket that dies + * between the write and the relay's store is exactly what the wait is for. The human's + * phone hangs on "Reconnecting…" forever if this is dropped, so it is worth + * the short wait that `send` deliberately refuses for stale frames — and the + * caller destroys the sandbox next, so "written" is not the same as + * "stored". `stats().endedAcked` says which of the two happened. */ sendFinal(message: AgentToHuman): Promise isOpen(): boolean @@ -66,6 +100,13 @@ export interface RelayConnectionStats { * second one connects; both are recovered here, and both count. */ reconnects: number + /** + * Whether the relay confirmed it had stored the ending before `sendFinal` + * gave up on it. False until `sendFinal` is called, and false afterwards + * against a relay too old to answer — in which case the ending was still + * sent, it is only its survival past the sandbox that is unproven. + */ + endedAcked: boolean } function toText(data: WebSocket.RawData): string { @@ -99,6 +140,29 @@ export function connectRelay(options: RelayConnectionOptions): RelayConnection { let opens = 0 let heartbeat: ReturnType | null = null let reconnect: ReturnType | null = null + // Set while `sendFinal` is waiting for the receipt, and called by the + // `ended_ack` branch of `handle`. Null at every other moment, so a stray ack + // — a relay that answers twice, a reconnect that replays one — resolves + // nothing but is still latched below. + let acknowledgeEnded: (() => void) | null = null + // The latch. Set the moment an ack arrives, waiter or no waiter: on a fast + // link the relay can store the ending and answer before the local send + // callback has resumed `sendFinal`, and an ack that fell into that gap used + // to be thrown away — teardown then waited its full two seconds and called + // an ending the relay was holding unacknowledged. + let endedAcked = false + // The ending, while `sendFinal` is waiting for its receipt. A socket can die + // between the local write and the relay's store, and this connection then + // reconnects inside the ack window — which is the whole justification for + // waiting. The reconnect carries the ending again. + // + // Sending it twice is expected and safe: the relay's store is an assignment + // (`lastEnded = payload`) and it acks each copy, while a second ack outside + // an active waiter resolves nothing. A socket that was already down when + // `sendFinal` was called takes both routes — the delivery poll and this + // re-send — so the phone can be told the same ending twice, which is the + // ending it is already showing. + let pendingEnding: AgentToHuman | null = null const send = (message: AgentToHuman | Heartbeat): Promise => new Promise((resolve) => { @@ -110,12 +174,13 @@ export function connectRelay(options: RelayConnectionOptions): RelayConnection { live.send(JSON.stringify(message), () => resolve()) }) - const sendFinal = (message: AgentToHuman): Promise => - new Promise((resolve) => { + /** Write `message`, waiting out a reconnect. Resolves true if it went out. */ + const deliverFinal = (message: AgentToHuman): Promise => + new Promise((resolve) => { const trySend = (): boolean => { const live = socket if (!live || live.readyState !== WebSocket.OPEN) return false - live.send(JSON.stringify(message), () => resolve()) + live.send(JSON.stringify(message), () => resolve(true)) return true } if (trySend()) return @@ -124,7 +189,7 @@ export function connectRelay(options: RelayConnectionOptions): RelayConnection { // cleanup is never blocked. const giveUp = setTimeout(() => { clearInterval(poll) - resolve() + resolve(false) }, CLOSE_GRACE_MS) const poll = setInterval(() => { if (trySend()) { @@ -134,11 +199,57 @@ export function connectRelay(options: RelayConnectionOptions): RelayConnection { }, 25) }) + /** Wait for `ended_ack`, or for the ack deadline, whichever comes first. */ + const waitForAck = (): Promise => + new Promise((resolve) => { + if (endedAcked) { + resolve() + return + } + const giveUp = setTimeout(() => { + acknowledgeEnded = null + resolve() + }, ENDED_ACK_TIMEOUT_MS) + acknowledgeEnded = () => { + clearTimeout(giveUp) + acknowledgeEnded = null + resolve() + } + }) + + const sendFinal = async (message: AgentToHuman): Promise => { + // Held for the reconnect handler above, for as long as this is waiting. + pendingEnding = message + // No receipt for a message that was never written. The relay is gone — + // that is the `disconnected` path — and two more seconds of waiting for it + // to say so is teardown the caller pays for nothing. + if (await deliverFinal(message)) await waitForAck() + pendingEnding = null + } + const handle = (message: RelayMessage): void => { switch (message.type) { case "ping": void send({ type: "pong" }) return + case "presence": + // The relay's own report, not a human message — and dropped once the + // handoff is shutting down, for the same reason a human message is: + // the phone closes its socket the instant it renders the ending, so + // the last thing this connection hears is a departure from a handoff + // that is already over. The core refuses it too (`watchPresence.stop`). + if (!shuttingDown) { + options.onPresence?.( + message.human, + message.seen ?? message.human, + message.sinceMs ?? 0, + ) + } + return + case "ended_ack": + endedAcked = true + acknowledgeEnded?.() + return case "tap": case "char": case "key": @@ -168,6 +279,9 @@ export function connectRelay(options: RelayConnectionOptions): RelayConnection { attempt = 0 opens += 1 options.onOpen?.() + // Last, so the ending is the final thing this socket carries. + const ending = pendingEnding + if (ending && !endedAcked) live.send(JSON.stringify(ending)) }) live.on("message", (data: WebSocket.RawData) => { const message = parse(toText(data)) @@ -191,7 +305,7 @@ export function connectRelay(options: RelayConnectionOptions): RelayConnection { send, sendFinal, isOpen: () => socket?.readyState === WebSocket.OPEN, - stats: () => ({ reconnects: Math.max(0, opens - 1) }), + stats: () => ({ reconnects: Math.max(0, opens - 1), endedAcked }), close() { shuttingDown = true if (heartbeat) clearInterval(heartbeat) diff --git a/src/errors.test.ts b/src/errors.test.ts index 0f3fe69..f7a8ca9 100644 --- a/src/errors.test.ts +++ b/src/errors.test.ts @@ -23,6 +23,8 @@ const COVERED_BY = { invalid_mode: "handoff.test.ts — an unknown mode is refused", empty_action: "handoff.test.ts and tool.test.ts — a blank approval action is refused", + invalid_option: + "handoff.test.ts — a humanGoneGraceMs below the floor, and an infinite one", browser_unusable: "handoff.test.ts — a closed or orphaned page is refused", relay_start_failed: "deploy.test.ts — an unreachable gateway", concurrency_limit: "deploy.test.ts — a gateway at its session cap", diff --git a/src/errors.ts b/src/errors.ts index d63aee9..017485c 100644 --- a/src/errors.ts +++ b/src/errors.ts @@ -26,6 +26,8 @@ * - `missing_api_key` — no `options.apiKey` and no `SOLARI_API_KEY`. * - `invalid_mode` — `mode` was neither `"takeover"` nor `"approval"`. * - `empty_action` — `mode: "approval"` without a non-empty `action`. + * - `invalid_option` — an option was present but unusable, which today means + * a `humanGoneGraceMs` outside 5000–2147483647 ms. * - `browser_unusable` — the page is closed, or its browser has disconnected. * Checked before anything is created, from local state only: a Solari * session that has died server-side while the CDP socket is still up looks @@ -45,6 +47,7 @@ export type HandraiseErrorCode = | "missing_api_key" | "invalid_mode" | "empty_action" + | "invalid_option" | "browser_unusable" | "relay_start_failed" | "concurrency_limit" diff --git a/src/events.ts b/src/events.ts index 870ebd0..a4b6d02 100644 --- a/src/events.ts +++ b/src/events.ts @@ -60,6 +60,31 @@ export interface HandoffEvent { qrHits: number /** Agent-socket reconnects during the handoff (the 60 s idle cut, drops). */ reconnects: number + /** + * Whether a human was ever connected to the relay. False is the QR code + * nobody scanned — the difference between "nobody came" and "somebody came + * and could not finish", which no other field in this event can tell apart. + */ + humanSeen: boolean + /** + * When the human's phone last disappeared while the handoff was running, in + * ms since it started — whether or not the phone came back. + * + * A reconnect overwrites it, so it is the last departure and not the first, + * and a `resolved` handoff can carry one: the socket dropped at the 60 s + * proxy cut, came back a second later, and the human handed back. It is + * absent on a handoff nobody opened and on one whose phone never dropped, + * and a departure after the handoff has ended is not recorded at all. + * `endedEarly` is the field that says the human was gone at the end. + */ + humanLeftMs?: number + /** + * Whether the handoff ended because the human was gone for the whole + * `humanGoneGraceMs`, rather than because `timeoutMs` ran out. The outcome + * is `timeout` either way; this is the field that says which of the two + * happened, and `timeoutMs - durationMs` is what it saved. + */ + endedEarly: boolean /** Whether cookies + localStorage were captured after a handback. */ storageStateCaptured: boolean /** diff --git a/src/relay/guest-source.ts b/src/relay/guest-source.ts index a978734..9a3ae56 100644 --- a/src/relay/guest-source.ts +++ b/src/relay/guest-source.ts @@ -24,8 +24,11 @@ export const GUEST_SERVER_JS = `/** * Routing contract (src/relay/protocol.ts): everything an agent sends goes to * the human and vice versa, byte for byte. The exceptions are answering * \`{"type":"ping"}\` with \`{"type":"pong"}\`, keeping the last \`frame\`/\`state\` so - * a human who joins late sees something instantly, and the mode: this process - * is started as a takeover relay or an approval relay and routes only the human + * a human who joins late sees something instantly, the two things this process + * says on its own behalf to the agent — \`presence\`, because only this side can + * see the phone's socket, and \`ended_ack\`, because the agent destroys the + * sandbox as soon as it has sent the ending — and the mode: this process is + * started as a takeover relay or an approval relay and routes only the human * messages that mode has. A hidden button is not a restriction — the human's * socket is reachable from any HTTP client. */ @@ -74,6 +77,9 @@ const MSG = { ABORT: "abort", APPROVE: "approve", DENY: "deny", + // relay -> agent, on the relay's own behalf + PRESENCE: "presence", + ENDED_ACK: "ended_ack", // either direction PING: "ping", PONG: "pong", @@ -172,6 +178,9 @@ const CLOSE_GRACE_MS = 1000 const PONG = JSON.stringify({ type: MSG.PONG }) +/** The receipt for \`ended\`, sent once this process has stored it. */ +const ENDED_ACK = JSON.stringify({ type: MSG.ENDED_ACK }) + /** role -> peer. At most one connection per role; a new one replaces the old. */ const peers = new Map() @@ -209,6 +218,65 @@ let humanEnded = false /** When the relay last forwarded a \`scanqr\`. See SCAN_INTERVAL_MS. */ let lastScanAt = 0 +/** + * The \`human\` value the current agent has been told, or null when it has been + * told nothing yet — a fresh agent socket, which must hear the state whatever + * it is. + * + * This relay answers the heartbeats itself, so the agent cannot tell a phone + * that was closed from a phone whose owner is reading a code off another + * device. Only this process knows, and it is the one fact worth volunteering. + */ +let announcedHuman = null + +/** + * The presence history an absent agent missed, which is all of it that matters: + * whether a human was ever here, and when the state last changed. + * + * A bare current state is not enough. An agent's socket can be down for + * seconds — the proxy's 60 s cut, a reconnect backoff — and a human can open + * the link, read the page and close it inside that gap. Both announcements + * find no agent and are dropped, and "nobody is here" is also what a link + * nobody ever opened says. These two fields are the difference. + */ +let humanEverSeen = false +let humanStateSince = Date.now() +/** The last state these two were computed against. */ +let lastHumanState = false + +/** + * Tell the agent what is known about the human, when that has changed. + * + * Called on every connect, replace and close of the human socket, and once + * right after an agent connects. Deduplicated against the last value sent, so + * a stale socket finishing its close does not report a departure that already + * happened — but never suppressed for a new agent, whose \`announcedHuman\` is + * null, and whose report therefore carries the history above. + * + * The bookkeeping happens before the agent is looked up, because the case this + * exists for is the one where there is no agent to tell. + */ +function announcePresence() { + const human = peers.has("human") + if (human !== lastHumanState) { + lastHumanState = human + humanStateSince = Date.now() + if (human) humanEverSeen = true + } + const agent = peers.get("agent") + if (!agent || human === announcedHuman) return + announcedHuman = human + sendText( + agent, + JSON.stringify({ + type: MSG.PRESENCE, + human, + seen: humanEverSeen, + sinceMs: Date.now() - humanStateSince, + }), + ) +} + /** * Forget everything that shows the remote page. Not the ending, which a late * human still has to be told, and not a human answer still waiting for its @@ -345,7 +413,10 @@ function closePeer(peer, reason) { // what keeps the human muted: the handback they are about to send has to // be read, held, and given to whichever agent connects next. resumeHuman() - } + // Whatever the last agent was told about the human is not something the + // next one heard. It is told the state on connect, from scratch. + announcedHuman = null + } else announcePresence() // Detach the reader so a replaced client that ignores the close frame can no // longer feed route(); a lingering listener is how a peer keeps injecting. if (peer.read) peer.socket.removeListener("data", peer.read) @@ -384,13 +455,17 @@ function messageType(payload) { } /** Keep what a human who joins late has to be shown, and drop what they must not. */ -function rememberFromAgent(type, payload) { +function rememberFromAgent(peer, type, payload) { if (type === MSG.ENDED) { // Terminal: keep the ending for a late human, drop everything that could // show the logged-in page to whoever opens the link next. lastEnded = payload forgetPage() pendingForAgent = null + // The receipt, sent after the store and not before it: the agent destroys + // this sandbox seconds later, and what it is waiting to hear is that + // whoever opens the link next will be told how the handoff ended. + sendText(peer, ENDED_ACK) return } // The agent goes on sending until it learns it has been answered — it @@ -467,7 +542,7 @@ function route(peer, payload, opcode) { sendText(peer, PONG) return } - if (peer.role === "agent") rememberFromAgent(type, payload) + if (peer.role === "agent") rememberFromAgent(peer, type, payload) else if (!acceptFromHuman(type, payload)) return // Newest frame wins: drop a frame bound for a backpressured receiver rather // than queue it in memory. Control and terminal messages are never dropped. @@ -660,6 +735,16 @@ server.on("upgrade", (req, socket, head) => { } } + // Whether there is a human on the other side, and what this socket missed. + // For a new agent that is the current state plus the history; for a new phone + // it is the change the agent has been waiting for. + // + // Before the buffered answer below, and that order is load-bearing: the + // answer settles the handoff, and a settled handoff refuses everything it + // learns afterwards. Announced second, a visit that happened during the + // outage would be reported as a handoff nobody ever opened. + announcePresence() + // A reconnecting agent that missed the human's handback/abort while it was // away gets it now, so the handoff resolves instead of falsely timing out. if (role === "agent" && pendingForAgent) { diff --git a/src/relay/guest/server.js b/src/relay/guest/server.js index f42323b..7a5979b 100644 --- a/src/relay/guest/server.js +++ b/src/relay/guest/server.js @@ -15,8 +15,11 @@ * Routing contract (src/relay/protocol.ts): everything an agent sends goes to * the human and vice versa, byte for byte. The exceptions are answering * `{"type":"ping"}` with `{"type":"pong"}`, keeping the last `frame`/`state` so - * a human who joins late sees something instantly, and the mode: this process - * is started as a takeover relay or an approval relay and routes only the human + * a human who joins late sees something instantly, the two things this process + * says on its own behalf to the agent — `presence`, because only this side can + * see the phone's socket, and `ended_ack`, because the agent destroys the + * sandbox as soon as it has sent the ending — and the mode: this process is + * started as a takeover relay or an approval relay and routes only the human * messages that mode has. A hidden button is not a restriction — the human's * socket is reachable from any HTTP client. */ @@ -65,6 +68,9 @@ const MSG = { ABORT: "abort", APPROVE: "approve", DENY: "deny", + // relay -> agent, on the relay's own behalf + PRESENCE: "presence", + ENDED_ACK: "ended_ack", // either direction PING: "ping", PONG: "pong", @@ -163,6 +169,9 @@ const CLOSE_GRACE_MS = 1000 const PONG = JSON.stringify({ type: MSG.PONG }) +/** The receipt for `ended`, sent once this process has stored it. */ +const ENDED_ACK = JSON.stringify({ type: MSG.ENDED_ACK }) + /** role -> peer. At most one connection per role; a new one replaces the old. */ const peers = new Map() @@ -200,6 +209,65 @@ let humanEnded = false /** When the relay last forwarded a `scanqr`. See SCAN_INTERVAL_MS. */ let lastScanAt = 0 +/** + * The `human` value the current agent has been told, or null when it has been + * told nothing yet — a fresh agent socket, which must hear the state whatever + * it is. + * + * This relay answers the heartbeats itself, so the agent cannot tell a phone + * that was closed from a phone whose owner is reading a code off another + * device. Only this process knows, and it is the one fact worth volunteering. + */ +let announcedHuman = null + +/** + * The presence history an absent agent missed, which is all of it that matters: + * whether a human was ever here, and when the state last changed. + * + * A bare current state is not enough. An agent's socket can be down for + * seconds — the proxy's 60 s cut, a reconnect backoff — and a human can open + * the link, read the page and close it inside that gap. Both announcements + * find no agent and are dropped, and "nobody is here" is also what a link + * nobody ever opened says. These two fields are the difference. + */ +let humanEverSeen = false +let humanStateSince = Date.now() +/** The last state these two were computed against. */ +let lastHumanState = false + +/** + * Tell the agent what is known about the human, when that has changed. + * + * Called on every connect, replace and close of the human socket, and once + * right after an agent connects. Deduplicated against the last value sent, so + * a stale socket finishing its close does not report a departure that already + * happened — but never suppressed for a new agent, whose `announcedHuman` is + * null, and whose report therefore carries the history above. + * + * The bookkeeping happens before the agent is looked up, because the case this + * exists for is the one where there is no agent to tell. + */ +function announcePresence() { + const human = peers.has("human") + if (human !== lastHumanState) { + lastHumanState = human + humanStateSince = Date.now() + if (human) humanEverSeen = true + } + const agent = peers.get("agent") + if (!agent || human === announcedHuman) return + announcedHuman = human + sendText( + agent, + JSON.stringify({ + type: MSG.PRESENCE, + human, + seen: humanEverSeen, + sinceMs: Date.now() - humanStateSince, + }), + ) +} + /** * Forget everything that shows the remote page. Not the ending, which a late * human still has to be told, and not a human answer still waiting for its @@ -336,7 +404,10 @@ function closePeer(peer, reason) { // what keeps the human muted: the handback they are about to send has to // be read, held, and given to whichever agent connects next. resumeHuman() - } + // Whatever the last agent was told about the human is not something the + // next one heard. It is told the state on connect, from scratch. + announcedHuman = null + } else announcePresence() // Detach the reader so a replaced client that ignores the close frame can no // longer feed route(); a lingering listener is how a peer keeps injecting. if (peer.read) peer.socket.removeListener("data", peer.read) @@ -375,13 +446,17 @@ function messageType(payload) { } /** Keep what a human who joins late has to be shown, and drop what they must not. */ -function rememberFromAgent(type, payload) { +function rememberFromAgent(peer, type, payload) { if (type === MSG.ENDED) { // Terminal: keep the ending for a late human, drop everything that could // show the logged-in page to whoever opens the link next. lastEnded = payload forgetPage() pendingForAgent = null + // The receipt, sent after the store and not before it: the agent destroys + // this sandbox seconds later, and what it is waiting to hear is that + // whoever opens the link next will be told how the handoff ended. + sendText(peer, ENDED_ACK) return } // The agent goes on sending until it learns it has been answered — it @@ -458,7 +533,7 @@ function route(peer, payload, opcode) { sendText(peer, PONG) return } - if (peer.role === "agent") rememberFromAgent(type, payload) + if (peer.role === "agent") rememberFromAgent(peer, type, payload) else if (!acceptFromHuman(type, payload)) return // Newest frame wins: drop a frame bound for a backpressured receiver rather // than queue it in memory. Control and terminal messages are never dropped. @@ -651,6 +726,16 @@ server.on("upgrade", (req, socket, head) => { } } + // Whether there is a human on the other side, and what this socket missed. + // For a new agent that is the current state plus the history; for a new phone + // it is the change the agent has been waiting for. + // + // Before the buffered answer below, and that order is load-bearing: the + // answer settles the handoff, and a settled handoff refuses everything it + // learns afterwards. Announced second, a visit that happened during the + // outage would be reported as a handoff nobody ever opened. + announcePresence() + // A reconnecting agent that missed the human's handback/abort while it was // away gets it now, so the handoff resolves instead of falsely timing out. if (role === "agent" && pendingForAgent) { diff --git a/src/relay/protocol.ts b/src/relay/protocol.ts index a4d1c3d..f189301 100644 --- a/src/relay/protocol.ts +++ b/src/relay/protocol.ts @@ -127,6 +127,48 @@ export type HumanToAgent = | { type: "approve" } | { type: "deny" } +/** + * The two things the relay says on its own behalf, to the agent only. + * + * Everything else on this wire is forwarded verbatim between two peers who + * cannot see each other. These are the exceptions, and both exist because the + * relay knows something neither peer can find out for itself. + * + * `presence` is the human's socket, reported as a fact rather than inferred + * from silence: the relay answers the heartbeats itself, so a phone whose tab + * was closed looks exactly like a phone whose owner is reading a code off + * another device. Sent on every connect, replace and close of the human + * socket, and once immediately after an agent connects so a reconnecting agent + * starts from the truth instead of from its last guess. + * + * `ended_ack` is the receipt for `ended`: the relay has stored the ending and + * will hand it to whoever opens the link next. The agent kills the sandbox + * seconds later, and before this existed the ending and the kill were a race + * that a second viewer of the link regularly lost. + */ +export type RelayToAgent = + | { + type: "presence" + /** Whether a human socket is connected to the relay right now. */ + human: boolean + /** + * Whether one ever was. Optional so an older relay still speaks this + * protocol; absent means "this relay cannot say", and the agent falls + * back to `human`. It exists because a whole visit can begin and end + * while the agent's own socket is down, and a bare current state cannot + * carry an absence that started and finished in that gap. + */ + seen?: boolean + /** + * How long the relay has been in this state, in ms. Zero on a live + * change; on the report a reconnecting agent gets, it is how stale the + * news is — which is what lets the agent run the grace from when the + * human actually left rather than from when it heard about it. + */ + sinceMs?: number + } + | { type: "ended_ack" } + /** * Either side may ping; the receiver answers pong. Required: the preview * proxy kills WebSockets after exactly 60s of silence (close 1006, see @@ -135,7 +177,11 @@ export type HumanToAgent = */ export type Heartbeat = { type: "ping" } | { type: "pong" } -export type RelayMessage = AgentToHuman | HumanToAgent | Heartbeat +export type RelayMessage = + | AgentToHuman + | HumanToAgent + | RelayToAgent + | Heartbeat export const HEARTBEAT_INTERVAL_MS = 20_000 export const RELAY_PORT = 3000 diff --git a/src/relay/relay.test.ts b/src/relay/relay.test.ts index 956ce11..d22332f 100644 --- a/src/relay/relay.test.ts +++ b/src/relay/relay.test.ts @@ -24,6 +24,7 @@ import { type HumanToAgent, RELAY_PORT, type RelayMessage, + type RelayToAgent, } from "./protocol" const SERVER_PATH = fileURLToPath(new URL("./guest/server.js", import.meta.url)) @@ -49,11 +50,69 @@ interface Relay { interface Client { send(message: RelayMessage): void + /** The next message the relay *routed* here from the other peer. */ next(): Promise + /** + * The next message the relay sent on its own behalf — `presence` and + * `ended_ack`, which no peer wrote. Kept in a second queue so a test about + * routing reads routed traffic only, and a test about presence cannot pass + * on a forwarded message that happened to look right. + */ + fromRelay(): Promise + /** Every message type this socket has seen, in the order it arrived. */ + order: string[] closed: Promise socket: WebSocket } +/** + * What the relay says for itself; everything else on the wire was forwarded. + * + * Keyed by `RelayToAgent` rather than spelled out, for the reason `WIRE_NAMES` + * below is a mapped type: a third member of that union would otherwise be + * classified as peer traffic here, and would fail some unrelated test with a + * confusing message instead of this one. + */ +const RELAY_ORIGINATED = new Set( + Object.keys({ + presence: true, + ended_ack: true, + } satisfies Record), +) + +interface Mailbox { + deliver(message: RelayMessage): void + next(what: string): Promise +} + +/** A queue of received messages with a waiter for the next one. */ +function mailbox(): Mailbox { + const queued: RelayMessage[] = [] + const waiters: ((message: RelayMessage) => void)[] = [] + return { + deliver(message) { + const waiter = waiters.shift() + if (waiter) waiter(message) + else queued.push(message) + }, + next(what) { + const ready = queued.shift() + if (ready) return Promise.resolve(ready) + return new Promise((resolve, reject) => { + const receive = (message: RelayMessage): void => { + clearTimeout(timer) + resolve(message) + } + const timer = setTimeout(() => { + waiters.splice(waiters.indexOf(receive), 1) + reject(new Error(`no ${what} within ${MESSAGE_TIMEOUT_MS}ms`)) + }, MESSAGE_TIMEOUT_MS) + waiters.push(receive) + }) + }, + } +} + function parse(raw: string): RelayMessage { // SAFETY: every payload in this file is a RelayMessage produced by this file, // and the relay forwards bytes verbatim, so what comes back has that shape. @@ -104,14 +163,15 @@ function startRelayProcess( async function connect(port: number, role: "agent" | "human"): Promise { const socket = new WebSocket(`ws://127.0.0.1:${port}/ws?role=${role}`) - const inbox: RelayMessage[] = [] - const waiters: ((message: RelayMessage) => void)[] = [] + const routed = mailbox() + const own = mailbox() + const order: string[] = [] socket.on("message", (raw: Buffer) => { const message = parse(raw.toString("utf8")) - const waiter = waiters.shift() - if (waiter) waiter(message) - else inbox.push(message) + order.push(message.type) + if (RELAY_ORIGINATED.has(message.type)) own.deliver(message) + else routed.deliver(message) }) const closed = new Promise((resolve) => { @@ -129,25 +189,9 @@ async function connect(port: number, role: "agent" | "human"): Promise { send(message) { socket.send(JSON.stringify(message)) }, - next() { - const queued = inbox.shift() - if (queued) return Promise.resolve(queued) - return new Promise((resolve, reject) => { - const receive = (message: RelayMessage): void => { - clearTimeout(timer) - resolve(message) - } - const timer = setTimeout(() => { - waiters.splice(waiters.indexOf(receive), 1) - reject( - new Error( - `no message for role=${role} within ${MESSAGE_TIMEOUT_MS}ms`, - ), - ) - }, MESSAGE_TIMEOUT_MS) - waiters.push(receive) - }) - }, + next: () => routed.next(`message for role=${role}`), + fromRelay: () => own.next(`relay message for role=${role}`), + order, } } @@ -416,10 +460,16 @@ const WIRE_NAMES = { abort: "ABORT", approve: "APPROVE", deny: "DENY", + presence: "PRESENCE", + ended_ack: "ENDED_ACK", ping: "PING", pong: "PONG", } satisfies { - [K in AgentToHuman["type"] | HumanToAgent["type"] | Heartbeat["type"]]: string + [K in + | AgentToHuman["type"] + | HumanToAgent["type"] + | RelayToAgent["type"] + | Heartbeat["type"]]: string } /** The relay's own `MSG` object, read back out of the source that defines it. */ @@ -506,6 +556,195 @@ test("a cross-origin upgrade is refused, a same-origin one is not", async () => same.socket.destroy() }) +// --- 0.7.0: peer presence, and a receipt for the ending -------------------- + +test("the agent is told when the human arrives and when they leave", async () => { + const agent = await connect(relay.port, "agent") + // Nobody has scanned the code yet, and the agent is told exactly that: the + // first presence is the current state, not the first change. + expect(await agent.fromRelay()).toMatchObject({ + type: "presence", + human: false, + }) + + const human = await connect(relay.port, "human") + expect(await agent.fromRelay()).toMatchObject({ + type: "presence", + human: true, + }) + + human.socket.close() + expect(await agent.fromRelay()).toMatchObject({ + type: "presence", + human: false, + }) +}) + +test("an agent that connects while the human is there is told so at once", async () => { + const human = await connect(relay.port, "human") + // The human scanned the QR code before the agent's socket was up, which is + // the ordinary race on a fast phone. + const agent = await connect(relay.port, "agent") + expect(await agent.fromRelay()).toMatchObject({ + type: "presence", + human: true, + }) + + // And a reconnecting agent — the 60 s proxy cut — starts from the truth + // rather than from what it believed before the cut. + agent.socket.close() + await waitForLog(relay, "peer closed", { role: "agent" }) + const second = await connect(relay.port, "agent") + expect(await second.fromRelay()).toMatchObject({ + type: "presence", + human: true, + }) + human.socket.close() + expect(await second.fromRelay()).toMatchObject({ + type: "presence", + human: false, + }) +}) + +test("a phone replaced by a second one is a leave and a join, not silence", async () => { + const agent = await connect(relay.port, "agent") + expect(await agent.fromRelay()).toMatchObject({ + type: "presence", + human: false, + }) + const first = await connect(relay.port, "human") + expect(await agent.fromRelay()).toMatchObject({ + type: "presence", + human: true, + }) + + // A second holder of the link opens it; the relay keeps one human socket, so + // the first is closed. The agent must not be left believing nobody is there. + await connect(relay.port, "human") + expect(await first.closed).toBeGreaterThan(0) + expect(await agent.fromRelay()).toMatchObject({ + type: "presence", + human: false, + }) + expect(await agent.fromRelay()).toMatchObject({ + type: "presence", + human: true, + }) +}) + +test("presence is for the agent only and is never sent to the phone", async () => { + const agent = await connect(relay.port, "agent") + const human = await connect(relay.port, "human") + expect(await agent.fromRelay()).toMatchObject({ + type: "presence", + human: false, + }) + + agent.send({ type: "state", reason: "the first thing the phone hears" }) + expect(await human.next()).toEqual({ + type: "state", + reason: "the first thing the phone hears", + }) +}) + +test("the relay acknowledges the ending once it has stored it", async () => { + const agent = await connect(relay.port, "agent") + expect(await agent.fromRelay()).toMatchObject({ + type: "presence", + human: false, + }) + const human = await connect(relay.port, "human") + expect(await agent.fromRelay()).toMatchObject({ + type: "presence", + human: true, + }) + + agent.send({ type: "ended", outcome: "approved" }) + expect(await agent.fromRelay()).toEqual({ type: "ended_ack" }) + + // The ack means stored, not merely received: the next visitor of the link is + // told how it ended, which is the whole reason the agent waits for it. + human.socket.close() + const late = await connect(relay.port, "human") + expect(await late.next()).toEqual({ type: "ended", outcome: "approved" }) +}) + +test("an agent that reconnects before sending the ending is acknowledged too", async () => { + const first = await connect(relay.port, "agent") + first.socket.close() + await waitForLog(relay, "peer closed", { role: "agent" }) + + const second = await connect(relay.port, "agent") + expect(await second.fromRelay()).toMatchObject({ + type: "presence", + human: false, + }) + second.send({ type: "ended", outcome: "timeout" }) + expect(await second.fromRelay()).toEqual({ type: "ended_ack" }) +}) + +test("a whole visit that happened while the agent was away is still reported", async () => { + const first = await connect(relay.port, "agent") + expect(await first.fromRelay()).toEqual({ + type: "presence", + human: false, + seen: false, + sinceMs: expect.any(Number), + }) + first.socket.close() + await waitForLog(relay, "peer closed", { role: "agent" }) + + // The whole visit happens with nobody listening: a human opens the link, + // looks at a dead handoff and closes it again. A bare current state cannot + // carry this — both announcements are dropped, and "nobody is here" is what + // an unopened link says too. + const human = await connect(relay.port, "human") + human.socket.close() + await waitForLog(relay, "peer closed", { role: "human" }) + await Bun.sleep(300) + + const second = await connect(relay.port, "agent") + const report = await second.fromRelay() + expect(report).toMatchObject({ type: "presence", human: false, seen: true }) + // And how stale the news is, so the agent can run its grace from when the + // human actually left rather than from when it heard about it. + const sinceMs = report.type === "presence" ? (report.sinceMs ?? -1) : -1 + expect(sinceMs).toBeGreaterThanOrEqual(250) + expect(sinceMs).toBeLessThan(5_000) +}) + +test("the reconnecting agent hears the presence before the answer it was holding", async () => { + const first = await connect(relay.port, "agent") + await first.fromRelay() + first.socket.close() + await waitForLog(relay, "peer closed", { role: "agent" }) + + const human = await connect(relay.port, "human") + human.send({ type: "handback" }) + await Bun.sleep(50) + human.socket.close() + await waitForLog(relay, "peer closed", { role: "human" }) + + const second = await connect(relay.port, "agent") + expect(await second.next()).toEqual({ type: "handback" }) + // Order, not just arrival: the answer settles the handoff, and everything + // the agent learns after that is refused. If the presence came second, the + // event would report a handoff nobody ever opened. + expect(second.order).toEqual(["presence", "handback"]) +}) + +test("a live presence change is fresh news, not stale", async () => { + const agent = await connect(relay.port, "agent") + await agent.fromRelay() + await connect(relay.port, "human") + const arrival = await agent.fromRelay() + + expect(arrival).toMatchObject({ type: "presence", human: true, seen: true }) + const sinceMs = arrival.type === "presence" ? (arrival.sinceMs ?? -1) : -1 + expect(sinceMs).toBeGreaterThanOrEqual(0) + expect(sinceMs).toBeLessThan(250) +}) + // --- B1: a terminal human message survives an agent reconnect -------------- test("a handback reaches an agent that reconnects after the human sent it", async () => { diff --git a/src/types.ts b/src/types.ts index 3cc4909..d80e69c 100644 --- a/src/types.ts +++ b/src/types.ts @@ -39,6 +39,34 @@ export interface HandoffOptions { * wait is more likely to end in `disconnected` than in `resolved`. */ timeoutMs?: number + /** + * How long to keep waiting after the human's phone disappears, in ms. + * Default: 60 seconds. + * + * The relay reports whether a human is connected (it answers the heartbeats + * itself, so nobody else can tell). Once one has been there and their socket + * is gone for this long, the handoff ends as `timeout` rather than waiting + * out `timeoutMs` for somebody who has closed the tab. A phone that comes + * back inside the grace resets it, which is what makes the 60 s default + * safe: the preview proxy cuts an idle socket every 60 s and the phone + * reconnects in about a second. + * + * A handoff nobody ever opened is not affected — that is the ordinary wait, + * and it runs for the full `timeoutMs`. + * + * The accepted range is 5 000 to 2 147 483 647 ms. The floor is a floor and + * not a recommendation: a grace of one second — which is what the phone's + * reconnect takes — was measured ending a healthy handoff on the first proxy + * cut. Anything below the default is for tests, and for humans you expect to + * answer in seconds. + * + * Raise it when the human is expected to leave the page: a screen that locks + * or a tab that is backgrounded long enough can lose the socket without the + * reconnect firing, and reading an SMS or fetching a hardware key on the + * same phone is exactly that. Sixty seconds covers the proxy's own cut, not + * a person putting their phone in their pocket. + */ + humanGoneGraceMs?: number /** Print a scannable QR code for the handoff URL to the terminal. Default: true. */ qr?: boolean /**