diff --git a/src/client/link-tunnel.ts b/src/client/link-tunnel.ts index 40165273c95..e4c2e46f22a 100644 --- a/src/client/link-tunnel.ts +++ b/src/client/link-tunnel.ts @@ -23,6 +23,7 @@ import { import { isLinkPort } from "../link/ports"; import { inspectIpv4LoopbackListener, type LoopbackOwnerLookupResult } from "../server/port-reclaim"; import type { LinkDiagnosticSink } from "../link/diagnostics"; +import { createTunnelHistoryBook, exitCause, type TunnelCause } from "../link/tunnel-history"; import { isLinkConnection, readClientConnectionState } from "./state"; import { clientLinkStatePath, readClientLinkState, type ClientLinkState } from "./link-state"; import type { LinkTunnelGate, LinkAdmissionResult } from "./link-relay"; @@ -167,6 +168,8 @@ export interface ClientTunnelPidfile { } const STOP_TIMEOUT_MS = 5_000; +/** A Child supervises one tunnel; its history needs one fixed key, never the link id. */ +const CHILD_TUNNEL_HISTORY_KEY = "child"; const REAP_POLL_MS = 100; const TIMER_MS = 1_000; /** Consecutive unreadable reads before the supervisor acts on them. */ @@ -607,6 +610,20 @@ export function createClientLinkSupervisor(deps: ClientLinkSupervisorDeps = {}): /** Minted on every transition into connected from the process-wide sequence (relay-auth.ts). */ let connection: string | undefined; let state: TunnelState = IDLE; + /** + * Child tunnel transitions go to the same bounded diagnostics file as the Home's, with the same + * fixed causes (#7297). The port is remembered past stop, which clears the live port first. + */ + let lastTunnelPort: number | undefined; + // The record is built at the transition but delivered after the current synchronous step, so a + // sink that re-enters the supervisor (stop, status) never runs in the middle of a transition. + const transitionSink = deps.diagnostic; + const history = createTunnelHistoryBook({ + diagnostic: transitionSink + ? record => queueMicrotask(() => { try { transitionSink(record); } catch { /* best effort */ } }) + : undefined, + tunnelPort: () => lastTunnelPort, + }); let linkId: string | null = null; let failure: ClientLinkSupervisorStatus | undefined; let tickFlight: Promise | undefined; @@ -689,9 +706,12 @@ export function createClientLinkSupervisor(deps: ClientLinkSupervisorDeps = {}): for (const settle of [...waiters]) settle(ready); }; - const setState = (next: TunnelState): void => { + const setState = (next: TunnelState, cause: TunnelCause | null = null): void => { + const before = state; if (next.kind === "connected" && state.kind !== "connected") connection = nextLinkConnectionGeneration(); state = next; + // Records only a real change and swallows sink errors; diagnostics never steer the lifecycle. + history.observe(CHILD_TUNNEL_HISTORY_KEY, before, next, cause, now()); settleWaiters(); }; @@ -750,7 +770,7 @@ export function createClientLinkSupervisor(deps: ClientLinkSupervisorDeps = {}): }; const onExit = (stderrClass: StderrClass): void => { - setState(reduceTunnel(state, { type: "exit", now: now(), stderrClass }, random, policy)); + setState(reduceTunnel(state, { type: "exit", now: now(), stderrClass }, random, policy), exitCause(stderrClass)); }; const spawn = (sidecar: ClientLinkState): void => { @@ -766,13 +786,16 @@ export function createClientLinkSupervisor(deps: ClientLinkSupervisorDeps = {}): }, deps); } catch { // A due retry that cannot start counts as a failed retry, so the backoff keeps its step. - setState(failedSpawnTunnel(state, "forward", timestamp, policy)); + lastTunnelPort = sidecar.tunnelPort; + setState(failedSpawnTunnel(state, "forward", timestamp, policy), "spawn_failed"); deps.warn?.("client link tunnel could not be started"); return; } invalidateOwnerProof(); linkId = sidecar.linkId; tunnelPort = sidecar.tunnelPort; + lastTunnelPort = sidecar.tunnelPort; + history.spawned(CHILD_TUNNEL_HISTORY_KEY); probe = null; probeFailures = 0; nextProbeAt = timestamp; @@ -871,6 +894,7 @@ export function createClientLinkSupervisor(deps: ClientLinkSupervisorDeps = {}): invalidateOwnerProof(); linkId = afterReap.sidecar.linkId; tunnelPort = afterReap.sidecar.tunnelPort; + lastTunnelPort = afterReap.sidecar.tunnelPort; nextProbeAt = now(); setState({ kind: "connecting", since: now() }); return; @@ -919,7 +943,8 @@ export function createClientLinkSupervisor(deps: ClientLinkSupervisorDeps = {}): probe = null; setState(IDLE); } - setState(reduceTunnel(state, { type: "tick", now: now() }, random, policy)); + // A tick changes state only when the outage limit fails the link, so its cause is the timeout. + setState(reduceTunnel(state, { type: "tick", now: now() }, random, policy), "timeout"); // An adopted tunnel is never killed. Failed identity or socket-owner proof keeps it // unprobed and unable to promote, even when the process stays alive after a timeout. if (state.kind === "failed" && !state.inFlight && adopted !== null) setState({ ...state, inFlight: true }); diff --git a/structure/remote-link.md b/structure/remote-link.md index bfd7574e84e..8d385629650 100644 --- a/structure/remote-link.md +++ b/structure/remote-link.md @@ -104,7 +104,7 @@ The `diagnostics.ts` module in `src/link/` owns best-effort local evidence in `< `owner_lookup` records only refused ownership checks; routine successful checks are silent. `owner_lookup.elapsedMs` measures the owner lookup itself. For `auth_timeout`, `relay_retry` and `relay_failure` report the actual transport-attempt duration in `elapsedMs` (normally about five seconds). A `relay_recovered` event with outcome `recovered` is emitted only after a retry receives an upstream response with `upstream.ok` (HTTP 2xx); it does not prove the streamed body completed. Rate limiting makes request-ID correlation sampled evidence, not a guaranteed trace of every failed request. -The Home writes `tunnel_transition` records into its own `/link/diagnostics.jsonl` through the same sink, wired in `src/server/index/optional-listeners.ts`: `previousState`, `state`, the cause as `outcome` (the history's causes, or `connected`, `spawned` and `stopped` when nothing failed), `attempt`, the link's `tunnelPort` and, when a retry is scheduled, `retryAfterMs`. The supervisor's `stop()` drains the sink for at most one second. The one-per-second limit per event/outcome applies across links. +The Home writes `tunnel_transition` records into its own `/link/diagnostics.jsonl` through the same sink, wired in `src/server/index/optional-listeners.ts`: `previousState`, `state`, the cause as `outcome` (the history's causes, or `connected`, `spawned` and `stopped` when nothing failed), `attempt`, the link's `tunnelPort` and, when a retry is scheduled, `retryAfterMs`. The supervisor's `stop()` drains the sink for at most one second. The one-per-second limit per event/outcome applies across links. The Child records its own `-L` tunnel the same way (#7297): `src/client/link-tunnel.ts` feeds every state change through a `createTunnelHistoryBook` keyed by one fixed key, with `spawn_failed` for a spawn that cannot start and the classified ssh stderr cause for an exit; the port is remembered past stop. Records carry the same fixed fields only, never argv, stderr, alias or link id, and reach the sink in a microtask after the transition, so a sink that re-enters the supervisor cannot interrupt one (`tests/clients/client-link-tunnel.test.ts`). `src/client/link-relay.ts` shares one preflight recovery attempt per request between an owner-lookup `deadline` and the typed `LinkRelayAuthTimeoutError` from `src/client/link-relay-transport.ts`. Only expiry of the credential-free authentication deadline before data dispatch produces that type; arbitrary aborts, authentication failures and transport errors do not qualify. Recovery obtains fresh owner proof where required and opens a fresh physical socket, authenticating it before sending any link credential or body. It never caches owner approval, bypasses security, restarts SSH or OpenCodex, or replays a dispatched body. The owner-lookup and authentication deadlines remain two and five seconds respectively, per attempt. Existing reconnect holding remains separate. diff --git a/tests/clients/client-link-tunnel.test.ts b/tests/clients/client-link-tunnel.test.ts index 4ccbf37c0cc..db7c4fa3833 100644 --- a/tests/clients/client-link-tunnel.test.ts +++ b/tests/clients/client-link-tunnel.test.ts @@ -1,4 +1,4 @@ -import { expect, test } from "bun:test"; +import { describe, expect, test } from "bun:test"; import { existsSync, mkdirSync, readFileSync, renameSync, statSync, writeFileSync, mkdtempSync, rmSync } from "node:fs"; import { tmpdir } from "node:os"; import { join } from "node:path"; @@ -17,6 +17,8 @@ import type { ClientLinkState } from "../../src/client/link-state"; import type { SshChild, SshRunner } from "../../src/link/ssh-runner"; import { buildTunnelArgv } from "../../src/link/ssh-argv"; import { relayLinkDataRequest } from "../../src/client/link-relay"; +import type { LinkDiagnosticRecord } from "../../src/link/diagnostics"; +import { FAILED_AFTER_MS } from "../../src/link/tunnel-state"; function deferred() { let resolve!: (value: T) => void; @@ -1327,7 +1329,8 @@ test("a stop triggered by failure diagnostics leaves admission closed", async () let stopping: Promise | undefined; const h = supervisorHarness({ inspectLoopbackListener: async () => ({ kind: result, elapsedMs: 1 }), - diagnostic: () => { stopping = h.supervisor.stop(); }, + // Tunnel transitions reach the same sink (#7297); this case is about the owner-lookup refusal. + diagnostic: record => { if (record.event === "owner_lookup") stopping = h.supervisor.stop(); }, }); try { await h.start(); @@ -1389,3 +1392,86 @@ test("a supervisor rebuilt by a restart rollback in the same process never repea expect(seen[1]).toEqual(expect.any(String)); expect(seen[1]).not.toBe(seen[0]); }); + +describe("Child tunnel transitions in the diagnostics file (#7297)", () => { + const ALLOWED = new Set(["event", "outcome", "state", "previousState", "attempt", "tunnelPort", "retryAfterMs"]); + const transitions = (records: LinkDiagnosticRecord[]) => records.filter(record => record.event === "tunnel_transition"); + + test("spawn, connect, a classified exit and stop each leave one fixed-cause record", async () => { + const records: LinkDiagnosticRecord[] = []; + const h = supervisorHarness({ diagnostic: record => { records.push(record); } }); + try { + await h.start(); + expect(h.state()).toBe("connecting"); + await h.step(); + expect(h.state()).toBe("connected"); + h.ssh.live()[0]!.exit(255, HOST_KEY_CHANGED); + await h.settle(); + } finally { await h.close(); } + const seen = transitions(records); + expect(seen.map(record => [record.previousState, record.state, record.outcome])).toEqual([ + ["idle", "connecting", "spawned"], + ["connecting", "connected", "connected"], + [seen[2]!.previousState, seen[2]!.state, "hostkey"], + [seen[3]!.previousState, "idle", "stopped"], + ]); + expect(seen[2]!.previousState).toBe("connected"); + expect(seen[0]!.attempt).toBe(1); + expect(seen[1]!.attempt).toBe(0); + // The port survives stop, which clears the live port before the transition is recorded. + for (const record of seen) expect(record.tunnelPort).toBe(sidecar().tunnelPort); + // Fixed metadata only: no argv, stderr, alias or link id ever reaches the sink. + for (const record of seen) for (const key of Object.keys(record)) expect(ALLOWED.has(key)).toBe(true); + }); + + test("a link that stays down past the outage limit records timeout", async () => { + // ssh stays up but the keyed probe never succeeds (the Home is down): the tick that fails the + // link at FAILED_AFTER_MS must say timeout, as the Home does, not fall back to spawned. + const records: LinkDiagnosticRecord[] = []; + const h = supervisorHarness({ diagnostic: record => { records.push(record); } }); + h.view.readyz = "refused"; + try { + await h.start(); + expect(h.state()).toBe("connecting"); + await h.step(FAILED_AFTER_MS); + expect(h.state()).toBe("failed"); + } finally { await h.close(); } + expect(transitions(records).find(record => record.state === "failed")).toMatchObject({ + outcome: "timeout", previousState: "connecting", state: "failed", + }); + }); + + test("a spawn that cannot start records spawn_failed", async () => { + const records: LinkDiagnosticRecord[] = []; + const h = supervisorHarness({ + diagnostic: record => { records.push(record); }, + runner: { async run() { return { code: 0, stdout: "", stderr: "" }; }, spawnTunnel() { throw new Error("ssh missing"); } }, + warn: () => {}, + }); + try { await h.start(); } finally { await h.close(); } + expect(transitions(records)[0]).toMatchObject({ outcome: "spawn_failed", previousState: "idle", state: "failed" }); + }); + + test("a sink that stops the supervisor on a transition never interrupts that transition", async () => { + let stopping: Promise | undefined; + const h = supervisorHarness({ + diagnostic: record => { if (record.event === "tunnel_transition" && record.outcome === "spawned") stopping = h.supervisor.stop(); }, + }); + try { + await h.start(); + expect(stopping).toBeDefined(); + await stopping; + expect(h.state()).toBe("idle"); + expect(h.ssh.live()).toEqual([]); + } finally { await stopping; await h.close(); } + }); + + test("a throwing sink never changes the tunnel lifecycle", async () => { + const h = supervisorHarness({ diagnostic: () => { throw new Error("disk full"); } }); + try { + await h.start(); + await h.step(); + expect(h.state()).toBe("connected"); + } finally { await h.close(); } + }); +});