diff --git a/packages/opencode/src/altimate/observability/trace-consumer.ts b/packages/opencode/src/altimate/observability/trace-consumer.ts index ae5ce06c46..fa852d0da5 100644 --- a/packages/opencode/src/altimate/observability/trace-consumer.ts +++ b/packages/opencode/src/altimate/observability/trace-consumer.ts @@ -388,6 +388,9 @@ export function subscribeTraceConsumer( (() => { const fetchFn = (async (fetchInput: RequestInfo | URL, init?: RequestInit) => { const request = new Request(fetchInput, init) + // Mark this as the in-process observability subscription so the client_connected telemetry + // hook in Server.createApp does not count it as a real external client attaching. + request.headers.set("x-altimate-trace-consumer", "1") const password = Flag.OPENCODE_SERVER_PASSWORD if (password) { const username = Flag.OPENCODE_SERVER_USERNAME ?? "opencode" diff --git a/packages/opencode/src/altimate/telemetry/index.ts b/packages/opencode/src/altimate/telemetry/index.ts index f350d9783c..5c16568c1b 100644 --- a/packages/opencode/src/altimate/telemetry/index.ts +++ b/packages/opencode/src/altimate/telemetry/index.ts @@ -674,11 +674,25 @@ export namespace Telemetry { session_id: string /** Top-level CLI command, e.g. "tui", "serve", "run". */ command: string + /** Same value as `command`, under the name dashboards query (Properties.surface). Shared + * with `client_connected`, which has no `command`, so the funnel joins on one key. */ + surface: string /** Wall time from process start until the command could serve its first request or frame. */ duration_ms: number /** True when this process emitted a non-upgrade first_launch, i.e. a brand-new machine. */ fresh_install: boolean } + | { + // First time a client attaches to a running server (once per process). Splits + // "backend launched but no client ever connected" from "connected but never sent a message". + type: "client_connected" + timestamp: number + session_id: string + /** Launching command/surface ("serve", "run", "tui"); IDE-funnel reads filter surface=="serve". */ + surface: string + /** Process uptime when the first client attached. */ + since_start_ms: number + } | { type: "event_loop_stall" timestamp: number @@ -2133,6 +2147,8 @@ export namespace Telemetry { const ANCHOR_EVENTS = new Set([ "first_launch", "startup_ready", + // Once per process, and a short-lived extension host may die before the 5 s flush interval. + "client_connected", "event_loop_stall", "altimate_base_registration", "session_start", @@ -2148,6 +2164,7 @@ export namespace Telemetry { let command = process.env[COMMAND_ENV] ?? "unknown" let freshInstall = false let startupReported = false + let clientConnectedReported = false let loopTimer: ReturnType | undefined let loopExpectedAt = 0 let loopStallsEmitted = 0 @@ -2172,11 +2189,25 @@ export namespace Telemetry { timestamp: Date.now(), session_id: sessionId, command, + surface: command, duration_ms: Math.round(performance.now()), fresh_install: freshInstall, }) } + /** Emit client_connected once per process; called from the server's event-stream routes. */ + export function clientConnected() { + if (clientConnectedReported) return + clientConnectedReported = true + Telemetry.track({ + type: "client_connected", + timestamp: Date.now(), + session_id: sessionId, + surface: command, + since_start_ms: Math.round(performance.now()), + }) + } + /** Pure lag check, exported for tests: the stall event when a tick is late by more than the threshold. */ export function loopStallFor( now: number, @@ -2252,6 +2283,7 @@ export namespace Telemetry { command = process.env[COMMAND_ENV] ?? "unknown" freshInstall = false startupReported = false + clientConnectedReported = false loopStallsEmitted = 0 loopExpectedAt = 0 } diff --git a/packages/opencode/src/server/server.ts b/packages/opencode/src/server/server.ts index e5ff81ec39..717a53d939 100644 --- a/packages/opencode/src/server/server.ts +++ b/packages/opencode/src/server/server.ts @@ -312,6 +312,23 @@ export namespace Server { // altimate_change end return basicAuth({ username, password })(c, next) }) + // altimate_change start — telemetry: a real external client attached to the event stream. + // Emit after next() and only on a 2xx, so a request that fails before the stream is + // established doesn't burn the once-per-process latch. Skip the in-process trace consumer + // (serve.ts subscribes to /event for observability via x-altimate-trace-consumer): it is not + // a real client and would otherwise trip the latch on every `serve` launch before the IDE + // attaches. + .use(async (c, next) => { + const isClientEventStream = + c.req.method === "GET" && + (c.req.path === "/event" || c.req.path === "/global/event") && + !c.req.header("x-altimate-trace-consumer") + await next() + if (isClientEventStream && c.res.ok) { + void import("../altimate/telemetry").then((m) => m.Telemetry.clientConnected()).catch(() => {}) + } + }) + // altimate_change end .use(async (c, next) => { const skipLogging = c.req.path === "/log" if (!skipLogging) { diff --git a/packages/opencode/test/altimate/telemetry/first-run-health.test.ts b/packages/opencode/test/altimate/telemetry/first-run-health.test.ts index aa91339a7d..c609540480 100644 --- a/packages/opencode/test/altimate/telemetry/first-run-health.test.ts +++ b/packages/opencode/test/altimate/telemetry/first-run-health.test.ts @@ -47,6 +47,45 @@ describe("first-run health telemetry", () => { } }) + test("startup_ready carries surface as a top-level property", () => { + const events: Telemetry.Event[] = [] + const spy = spyOn(Telemetry, "track").mockImplementation((event) => { + events.push(event) + }) + try { + Telemetry.startupReady("serve") + const event = events.find((e) => e.type === "startup_ready") as Extract< + Telemetry.Event, + { type: "startup_ready" } + > + expect(event.surface).toBe("serve") + } finally { + spy.mockRestore() + } + }) + + test("client_connected is emitted exactly once per process with surface", () => { + const events: Telemetry.Event[] = [] + const spy = spyOn(Telemetry, "track").mockImplementation((event) => { + events.push(event) + }) + try { + Telemetry.setCommand("serve") + Telemetry.clientConnected() + Telemetry.clientConnected() + Telemetry.clientConnected() + const connected = events.filter((e) => e.type === "client_connected") as Extract< + Telemetry.Event, + { type: "client_connected" } + >[] + expect(connected).toHaveLength(1) + expect(connected[0].surface).toBe("serve") + expect(connected[0].since_start_ms).toBeGreaterThan(0) + } finally { + spy.mockRestore() + } + }) + test("loopStallFor reports only lags beyond the threshold", () => { expect(Telemetry.loopStallFor(1_000, 900, 500, "main")).toBeUndefined() const stall = Telemetry.loopStallFor(2_000, 500, 1_000, "worker") diff --git a/packages/opencode/test/server/altimate-client-connected-wiring.test.ts b/packages/opencode/test/server/altimate-client-connected-wiring.test.ts new file mode 100644 index 0000000000..01d7d913de --- /dev/null +++ b/packages/opencode/test/server/altimate-client-connected-wiring.test.ts @@ -0,0 +1,97 @@ +// altimate_change — regression test for the server-side wiring that produces `client_connected`. +// +// The telemetry unit tests (test/altimate/telemetry/first-run-health.test.ts) prove the +// `Telemetry.clientConnected()` latch; this file proves the `.use` middleware in `Server.createApp` +// that calls it. Without it, deleting the middleware, changing the `/event` / `/global/event` path +// literals, dropping the `GET` guard, failing to skip the in-process trace consumer, or emitting on +// a non-2xx would all leave the suite green while breaking (or corrupting) the IDE-funnel signal. +// +// The middleware emits AFTER next() and only when the event route returned a 2xx, via +// `void import("../altimate/telemetry").then((m) => m.Telemetry.clientConnected())`. The call lands +// on a later microtask, so positive cases poll with a bounded timeout rather than sleeping a fixed +// amount. We spy on `Telemetry.clientConnected` itself so the assertion is purely about the +// middleware deciding to call it; the once-per-process latch lives inside that function and is +// covered elsewhere. +// +// Not exercised here: the "hook moved above basic-auth" case. Auth is a separate `basicAuth` +// middleware gated on `Flag.OPENCODE_SERVER_PASSWORD`, a module-level const frozen at load, and CI +// runs the package in one Bun process, so a password set at test time can't drive a 401. The order +// is enforced structurally: the hook is registered immediately after the basic-auth `.use`, and it +// now only counts a 2xx response, so an auth rejection (non-2xx) cannot trip it. +import { afterEach, beforeEach, describe, expect, spyOn, test } from "bun:test" +import { Server } from "../../src/server/server" +import { Telemetry } from "../../src/altimate/telemetry" +import { resetDatabase } from "./db" +import { disposeAllInstances, tmpdir } from "../fixture/fixture" + +async function cancelBody(response: Response) { + await response.body?.cancel().catch(() => {}) +} + +// The emit is async (dynamic import + .then). Poll for it instead of sleeping a fixed amount. +async function waitForCall(spy: { mock: { calls: unknown[] } }, timeoutMs = 1000): Promise { + const start = Date.now() + while (Date.now() - start < timeoutMs) { + if (spy.mock.calls.length > 0) return true + await new Promise((r) => setTimeout(r, 5)) + } + return false +} + +// A negative can't be proven instantly; give the microtask/import a real chance to fire first. +async function settle() { + await new Promise((r) => setTimeout(r, 50)) +} + +let spy: ReturnType> + +beforeEach(() => { + spy = spyOn(Telemetry, "clientConnected").mockImplementation(() => {}) +}) + +afterEach(async () => { + spy.mockRestore() + await disposeAllInstances() + await resetDatabase() +}) + +describe("client_connected server wiring", () => { + test("GET /global/event (2xx) invokes Telemetry.clientConnected", async () => { + const response = await Server.Default().request("/global/event") + expect(response.ok).toBe(true) + await cancelBody(response) + expect(await waitForCall(spy)).toBe(true) + }) + + test("GET /event (2xx, resolved instance) invokes Telemetry.clientConnected", async () => { + await using tmp = await tmpdir({ git: true, config: { formatter: false, lsp: false } }) + const response = await Server.Default().request("/event", { headers: { "x-opencode-directory": tmp.path } }) + expect(response.ok).toBe(true) + await cancelBody(response) + expect(await waitForCall(spy)).toBe(true) + }) + + test("the in-process trace consumer (x-altimate-trace-consumer) is NOT counted", async () => { + const response = await Server.Default().request("/global/event", { + headers: { "x-altimate-trace-consumer": "1" }, + }) + expect(response.ok).toBe(true) + await cancelBody(response) + await settle() + expect(spy).not.toHaveBeenCalled() + }) + + test("a non-event path does not invoke Telemetry.clientConnected", async () => { + const response = await Server.Default().request("/global/config") + await cancelBody(response) + await settle() + expect(spy).not.toHaveBeenCalled() + }) + + test("a non-GET request to /event does not invoke Telemetry.clientConnected", async () => { + const response = await Server.Default().request("/event", { method: "POST" }) + await cancelBody(response) + await settle() + expect(spy).not.toHaveBeenCalled() + }) +}) diff --git a/packages/opencode/test/skill/release-v0.11.1-adversarial.test.ts b/packages/opencode/test/skill/release-v0.11.1-adversarial.test.ts index f334161318..5a805bdb51 100644 --- a/packages/opencode/test/skill/release-v0.11.1-adversarial.test.ts +++ b/packages/opencode/test/skill/release-v0.11.1-adversarial.test.ts @@ -465,6 +465,7 @@ describe("track — anchor events before init", () => { timestamp: Date.now(), session_id: "pre-init", command: "run", + surface: "run", duration_ms: 1, fresh_install: false, }) diff --git a/packages/opencode/test/telemetry/config-opt-out.test.ts b/packages/opencode/test/telemetry/config-opt-out.test.ts index e797324931..35d0d9495d 100644 --- a/packages/opencode/test/telemetry/config-opt-out.test.ts +++ b/packages/opencode/test/telemetry/config-opt-out.test.ts @@ -109,6 +109,7 @@ describe("Telemetry.init() inside an Instance context — config.telemetry.disab timestamp: Date.now(), session_id: "config-opt-out-enabled", command: "test", + surface: "test", duration_ms: 1, fresh_install: false, })