diff --git a/packages/extension/src/sse_client.ts b/packages/extension/src/sse_client.ts index 3e885741..40255a3b 100644 --- a/packages/extension/src/sse_client.ts +++ b/packages/extension/src/sse_client.ts @@ -1,6 +1,7 @@ import * as http from "node:http"; import * as vscode from "vscode"; import type { StatusBarManager } from "./status_bar"; +import { SseLivenessTracker, type SseState } from "./sse_liveness"; // ============================================================================ // OpencodeEventClient — Channel 1 of the bidirectional plumbing. @@ -25,6 +26,9 @@ export interface SseClientOptions { * without it the fork 401s /event and the reconnect loop spins forever. * Never logged; the value exists only on the wire. */ authorization?: string; + /** Liveness states (L1, #638): fired on every transition. The status bar + * is driven automatically from this; this hook is for any other sink. */ + onSseState?: (from: SseState, to: SseState) => void; } export class OpencodeEventClient implements vscode.Disposable { @@ -34,17 +38,67 @@ export class OpencodeEventClient implements vscode.Disposable { private url?: URL; private reconnectTimer?: NodeJS.Timeout; private disposed = false; + private liveness?: SseLivenessTracker; constructor(private readonly opts: SseClientOptions) {} connect(serverUrl: URL): void { this.url = new URL("/event", serverUrl); this.opts.channel.appendLine(`[sse] connecting to ${this.url}`); + // Liveness (L1, #638): frames are the truth; the probe splits a quiet + // half-open stream from a dead server; every transition reaches the + // status bar and the caller's hook — "thinking" is never unbacked. + this.liveness?.dispose(); + this.liveness = new SseLivenessTracker({ + probe: () => this.probeServer(), + log: (line) => this.opts.channel.appendLine(line), + onStateChange: (from, to) => { + this.opts.onSseState?.(from, to); + this.opts.statusBar?.setSseState(to); + }, + onReconnectNeeded: () => { + // half-open: the server is alive but this stream will never speak + // again — tear it down; the reconnect loop reopens fresh + try { + this.req?.destroy(); + } catch { + /* noop */ + } + try { + this.res?.destroy(); + } catch { + /* noop */ + } + this.scheduleReconnect(); + }, + }); + this.liveness.start(); this.openOnce(); } + /** The stream's honest state — for callers and tests. */ + get sseState(): SseState { + return this.liveness?.getState() ?? "connecting"; + } + + /** A short-timeout GET on the server root with the same credential the + * stream uses — the STALE branch's dead-or-alive question. */ + private async probeServer(): Promise { + if (!this.url) return false; + try { + const r = await fetch(this.url.origin, { + signal: AbortSignal.timeout(2_000), + headers: this.opts.authorization ? { Authorization: this.opts.authorization } : undefined, + }); + return r.status > 0; + } catch { + return false; + } + } + dispose(): void { this.disposed = true; + this.liveness?.dispose(); if (this.reconnectTimer) clearTimeout(this.reconnectTimer); try { this.req?.destroy(); @@ -74,25 +128,30 @@ export class OpencodeEventClient implements vscode.Disposable { (res) => { this.res = res; if (res.statusCode !== 200) { + this.liveness?.noteDisconnected(); this.opts.channel.appendLine(`[sse] bad status ${res.statusCode}; will retry`); this.scheduleReconnect(); return; } this.opts.channel.appendLine(`[sse] connected`); + this.liveness?.noteConnected(); res.setEncoding("utf8"); res.on("data", (chunk: string) => this.onChunk(chunk)); res.on("end", () => { this.opts.channel.appendLine(`[sse] stream ended; will retry`); + this.liveness?.noteDisconnected(); this.scheduleReconnect(); }); res.on("error", (err) => { this.opts.channel.appendLine(`[sse] response error: ${err.message}`); + this.liveness?.noteDisconnected(); this.scheduleReconnect(); }); }, ); req.on("error", (err) => { this.opts.channel.appendLine(`[sse] req error: ${err.message}`); + this.liveness?.noteDisconnected(); this.scheduleReconnect(); }); req.end(); @@ -109,6 +168,9 @@ export class OpencodeEventClient implements vscode.Disposable { } private onChunk(chunk: string): void { + // ANY bytes = the stream is speaking (events or comment-only pings — + // the liveness signal the old client discarded, #638) + this.liveness?.noteFrame(); this.buf += chunk; // SSE events terminate on a blank line (\n\n). let sep: number; diff --git a/packages/extension/src/sse_liveness.ts b/packages/extension/src/sse_liveness.ts new file mode 100644 index 00000000..75278540 --- /dev/null +++ b/packages/extension/src/sse_liveness.ts @@ -0,0 +1,139 @@ +// Liveness state machine (L1, #638): evidence-backed states for the event +// stream, so "thinking" is never rendered without a live connection behind it. +// +// The truth hierarchy: frames are the primary signal (ANY SSE block — event +// or comment-only ping; opencode sends pings the old client discarded). No +// frames for stalenessMs → STALE. The STALE branch probes the server to split +// "alive but stream quiet" (a half-open TCP connection — tear it down and +// reconnect; never wait for TCP to notice) from "server gone" (DEAD). Every +// transition fires onStateChange with the evidence logged — the UI gets the +// truth, the output channel gets the why. +// +// Pure by injection: the probe, the clock, and the state-change sink are +// dependencies. The production caller is sse_client; T4a's serve-daemon tests +// reuse the same semantics. Tests use fake timers — zero real sleeps. + +export type SseState = "connecting" | "live" | "stale" | "dead"; + +export const DEFAULT_STALENESS_MS = 30_000; +export const DEFAULT_TICK_MS = 5_000; + +export interface SseLivenessOptions { + /** ms without a frame before the stream is STALE (default 30s). */ + stalenessMs?: number; + /** tick cadence for staleness checks (default 5s). */ + tickMs?: number; + /** Probe the server: resolve true = alive. Injected so the STALE branch + * can split stale-from-dead without this module owning fetch. */ + probe: () => Promise; + /** Fired on every state TRANSITION (never twice for the same state). */ + onStateChange?: (from: SseState, to: SseState) => void; + /** Fired once when the server proves alive but the stream stayed quiet — + * the half-open signal: the owner tears the connection down and + * reconnects rather than waiting for TCP to notice. */ + onReconnectNeeded?: () => void; + /** Diagnostics sink (the output channel); liveness never crashes the host. */ + log?: (line: string) => void; + /** Clock — injected; tests pass a controllable one, production wall clock. */ + now?: () => number; +} + +export class SseLivenessTracker { + private state: SseState = "connecting"; + private lastFrameAt: number | undefined; + private connectedAt: number | undefined; + private readonly stalenessMs: number; + private readonly tickMs: number; + private readonly probeFn: () => Promise; + private readonly onStateChange?: (from: SseState, to: SseState) => void; + private readonly onReconnectNeeded?: () => void; + private readonly log?: (line: string) => void; + private readonly now: () => number; + private timer: ReturnType | undefined; + private probing = false; + + constructor(opts: SseLivenessOptions) { + this.stalenessMs = opts.stalenessMs ?? DEFAULT_STALENESS_MS; + this.tickMs = opts.tickMs ?? DEFAULT_TICK_MS; + this.probeFn = opts.probe; + this.onStateChange = opts.onStateChange; + this.onReconnectNeeded = opts.onReconnectNeeded; + this.log = opts.log; + this.now = opts.now ?? Date.now; + } + + /** Start ticking. Idempotent. */ + start(): void { + if (this.timer !== undefined) return; + this.timer = setInterval(() => void this.tick(), this.tickMs); + } + + dispose(): void { + if (this.timer !== undefined) { + clearInterval(this.timer); + this.timer = undefined; + } + } + + getState(): SseState { + return this.state; + } + + /** The stream connected (2xx on the event request). */ + noteConnected(): void { + this.connectedAt = this.now(); + this.transition("live"); + } + + /** The stream ended/errored — a reconnect is in flight. */ + noteDisconnected(): void { + this.transition("connecting"); + } + + /** ANY block arrived — event or comment-only ping. The discarded-ping fix: + * this is the liveness signal. Frames recover STALE back to LIVE. */ + noteFrame(): void { + this.lastFrameAt = this.now(); + if (this.state === "stale") { + this.log?.("[liveness] frames returned — stream live again"); + } + // a speaking stream is live in every state — believe the frames + this.transition("live"); + } + + private transition(to: SseState): void { + if (this.state === to) return; + const from = this.state; + this.state = to; + this.log?.(`[liveness] ${from} → ${to}`); + this.onStateChange?.(from, to); + } + + private async tick(): Promise { + if (this.state !== "live" && this.state !== "stale") return; + const now = this.now(); + const last = this.lastFrameAt ?? this.connectedAt ?? now; + if (now - last < this.stalenessMs) return; + if (this.state === "live") { + this.transition("stale"); + } + if (this.probing) return; + this.probing = true; + let alive = false; + try { + alive = await this.probeFn(); + } catch { + alive = false; /* a throwing probe is a dead probe, never a crash */ + } finally { + this.probing = false; + } + // state may have moved on while the probe was in flight (frames returned) + if (this.state !== "stale") return; + if (!alive) { + this.transition("dead"); + return; + } + this.log?.("[liveness] server alive but stream quiet — half-open; reconnect"); + this.onReconnectNeeded?.(); + } +} diff --git a/packages/extension/src/status_bar.ts b/packages/extension/src/status_bar.ts index 74d0fed2..393adfee 100644 --- a/packages/extension/src/status_bar.ts +++ b/packages/extension/src/status_bar.ts @@ -1,19 +1,44 @@ import * as vscode from "vscode"; +import type { SseState } from "./sse_liveness"; // ============================================================================ -// StatusBarManager — minimal server-ready indicator. The live-solve indicator -// (iter/fidelity) is removed in #351 — the Work Column Run Inspector tab is -// now the sole surface for solve status. +// StatusBarManager — the honest server/stream indicator. The live-solve +// indicator (iter/fidelity) is removed in #351 — the Work Column Run +// Inspector tab is the sole surface for solve status. The stream states (L1, +// #638) are evidence-backed: "thinking" is only ever true while the event +// stream is LIVE; a stalled stream says so instead of pretending. // ============================================================================ -export function statusBarLabel(serverReady: boolean): { text: string; tooltip: string } { +export function statusBarLabel( + serverReady: boolean, + // default "live" preserves the historical ready-state label for callers + // that only know the server is ready; the manager always passes the real + // stream state (L1, #638) + sseState: SseState = "live", +): { text: string; tooltip: string } { if (!serverReady) return { text: "$(loading~spin) Amicode (booting)", tooltip: "Spawning opencode server…" }; - return { text: "$(comment-discussion) Amicode", tooltip: "Amicode — chat + Work Column inspectors" }; + switch (sseState) { + case "live": + return { text: "$(comment-discussion) Amicode", tooltip: "Amicode — chat + Work Column inspectors" }; + case "stale": + return { + text: "$(debug-disconnect) Amicode — stream stalled", + tooltip: "Event stream stalled — probing the harness, reconnecting if needed. A 'thinking' indicator is not truth right now.", + }; + case "dead": + return { + text: "$(error) Amicode — server unreachable", + tooltip: "Harness unreachable — reconnecting. Session state is preserved; work is not lost.", + }; + case "connecting": + return { text: "$(loading~spin) Amicode", tooltip: "Connecting to the harness event stream…" }; + } } export class StatusBarManager { private readonly item: vscode.StatusBarItem; private serverReady = false; + private sseState: SseState = "connecting"; constructor() { this.item = vscode.window.createStatusBarItem(vscode.StatusBarAlignment.Right, 100); @@ -27,12 +52,19 @@ export class StatusBarManager { this.render(); } + /** The stream's honest state (L1, #638) — driven by the SSE client's + * liveness transitions; boot states stay untouched. */ + setSseState(state: SseState): void { + this.sseState = state; + this.render(); + } + dispose(): void { this.item.dispose(); } private render(): void { - const { text, tooltip } = statusBarLabel(this.serverReady); + const { text, tooltip } = statusBarLabel(this.serverReady, this.sseState); this.item.text = text; this.item.tooltip = tooltip; } diff --git a/packages/extension/test/sse_liveness.test.ts b/packages/extension/test/sse_liveness.test.ts new file mode 100644 index 00000000..c2b3167c --- /dev/null +++ b/packages/extension/test/sse_liveness.test.ts @@ -0,0 +1,157 @@ +import { describe, it, expect, vi, beforeEach, afterEach } from "vitest"; +import { SseLivenessTracker, type SseState } from "../src/sse_liveness"; + +// The state machine's law (L1, #638): frames are truth; a quiet stream is +// STALE, not "thinking"; the probe splits dead from half-open; transitions +// fire exactly once. Fake timers — zero real sleeps. + +describe("SseLivenessTracker", () => { + beforeEach(() => { + vi.useFakeTimers(); + }); + afterEach(() => { + vi.useRealTimers(); + }); + + function rig(opts: { + probe?: () => Promise; + onReconnectNeeded?: () => void; + } = {}) { + const transitions: [SseState, SseState][] = []; + const probe = opts.probe ?? vi.fn().mockResolvedValue(true); + const onReconnectNeeded = opts.onReconnectNeeded ?? vi.fn(); + const tracker = new SseLivenessTracker({ + stalenessMs: 30_000, + tickMs: 5_000, + probe, + onReconnectNeeded, + onStateChange: (from, to) => transitions.push([from, to]), + log: () => {}, + }); + tracker.start(); + return { tracker, transitions, probe, onReconnectNeeded }; + } + + it("starts connecting; a connection makes it live", () => { + const { tracker } = rig(); + expect(tracker.getState()).toBe("connecting"); + tracker.noteConnected(); + expect(tracker.getState()).toBe("live"); + }); + + it("frames keep it live — the discarded-ping fix (comment-only blocks count)", () => { + const { tracker } = rig(); + tracker.noteConnected(); + // frames arriving every { + const { tracker, transitions } = rig(); + tracker.noteConnected(); + vi.advanceTimersByTime(35_000); + expect(tracker.getState()).toBe("stale"); + expect(transitions).toContainEqual(["live", "stale"]); + }); + + it("stale + dead probe → dead", async () => { + const { tracker } = rig({ probe: vi.fn().mockResolvedValue(false) }); + tracker.noteConnected(); + vi.advanceTimersByTime(35_000); + expect(tracker.getState()).toBe("stale"); + await vi.advanceTimersByTimeAsync(5_000); + expect(tracker.getState()).toBe("dead"); + }); + + it("stale + live server (half-open) → reconnect requested, once per tick", async () => { + const onReconnectNeeded = vi.fn(); + const { tracker } = rig({ onReconnectNeeded }); + tracker.noteConnected(); + // the staleness threshold lands on the 30s tick, which goes stale AND + // probes in the same pass (the faster dead/alive split by design) + vi.advanceTimersByTime(30_000); + expect(tracker.getState()).toBe("stale"); + // flush: probe #1 (the stale tick's own) + probe #2 (the next tick) + await vi.advanceTimersByTimeAsync(5_000); + expect(onReconnectNeeded).toHaveBeenCalledTimes(2); + // still stale, still quiet, still alive: asks again on the next tick + await vi.advanceTimersByTimeAsync(5_000); + expect(onReconnectNeeded).toHaveBeenCalledTimes(3); + }); + + it("frames while stale recover to live (and it says so)", async () => { + const { tracker, transitions } = rig(); + tracker.noteConnected(); + vi.advanceTimersByTime(35_000); + expect(tracker.getState()).toBe("stale"); + tracker.noteFrame(); + expect(tracker.getState()).toBe("live"); + expect(transitions).toContainEqual(["stale", "live"]); + }); + + it("a throwing probe is a dead probe, never a crash", async () => { + const { tracker } = rig({ probe: vi.fn().mockRejectedValue(new Error("probe blew up")) }); + tracker.noteConnected(); + vi.advanceTimersByTime(35_000); + await vi.advanceTimersByTimeAsync(5_000); + expect(tracker.getState()).toBe("dead"); + }); + + it("disconnect makes it connecting; a reconnect returns it to live", () => { + const { tracker } = rig(); + tracker.noteConnected(); + tracker.noteDisconnected(); + expect(tracker.getState()).toBe("connecting"); + tracker.noteConnected(); + expect(tracker.getState()).toBe("live"); + }); + + it("transitions never double-fire for the same state", () => { + const { tracker, transitions } = rig(); + tracker.noteConnected(); + tracker.noteConnected(); + tracker.noteFrame(); + expect(transitions.filter(([f, t]) => t === "live").length).toBe(1); + }); + + it("dead recovers through a reconnect: connecting → live", async () => { + const { tracker } = rig({ probe: vi.fn().mockResolvedValue(false) }); + tracker.noteConnected(); + vi.advanceTimersByTime(35_000); + await vi.advanceTimersByTimeAsync(5_000); + expect(tracker.getState()).toBe("dead"); + // the reconnect loop eventually succeeds + tracker.noteDisconnected(); + tracker.noteConnected(); + expect(tracker.getState()).toBe("live"); + }); + + it("frames arriving while the probe is in flight win over the probe", async () => { + let resolveProbe!: (v: boolean) => void; + const { tracker } = rig({ + probe: () => new Promise((res) => (resolveProbe = res)), + }); + tracker.noteConnected(); + vi.advanceTimersByTime(35_000); + expect(tracker.getState()).toBe("stale"); + const tickDone = vi.advanceTimersByTimeAsync(5_000); + // frames return mid-probe — the stream recovered; the probe result is moot + tracker.noteFrame(); + expect(tracker.getState()).toBe("live"); + resolveProbe(false); + await tickDone; + expect(tracker.getState()).toBe("live"); + }); + + it("dispose stops the ticks", () => { + const { tracker } = rig({ probe: vi.fn().mockResolvedValue(false) }); + tracker.noteConnected(); + tracker.dispose(); + vi.advanceTimersByTime(60_000); + expect(tracker.getState()).toBe("live"); // no ticks: no stale transition + }); +}); diff --git a/packages/extension/test/status_bar.test.ts b/packages/extension/test/status_bar.test.ts index b81e6f17..3435a36c 100644 --- a/packages/extension/test/status_bar.test.ts +++ b/packages/extension/test/status_bar.test.ts @@ -11,4 +11,26 @@ describe("statusBarLabel", () => { it("ready tooltip mentions chat + Work Column", () => { expect(statusBarLabel(true).tooltip).toMatch(/Work Column/i); }); + + // L1, #638 — honest stream states: "thinking" is never unbacked + it("live stream shows the normal Amicode state", () => { + expect(statusBarLabel(true, "live").text).toMatch(/Amicode$/); + }); + it("stalled stream says so, never 'thinking'", () => { + const s = statusBarLabel(true, "stale"); + expect(s.text).toMatch(/stream stalled/i); + expect(s.tooltip).toMatch(/reconnect/i); + }); + it("dead stream says unreachable and promises the work survives", () => { + const s = statusBarLabel(true, "dead"); + expect(s.text).toMatch(/unreachable/i); + expect(s.tooltip).toMatch(/not lost/i); + }); + it("connecting stream shows an honest spinner", () => { + expect(statusBarLabel(true, "connecting").tooltip).toMatch(/Connecting/i); + }); + it("stalled/dead states never override the booting label", () => { + expect(statusBarLabel(false, "stale").text).toMatch(/booting/i); + expect(statusBarLabel(false, "dead").text).toMatch(/booting/i); + }); });