Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Original file line number Diff line number Diff line change
Expand Up @@ -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"
Expand Down
32 changes: 32 additions & 0 deletions packages/opencode/src/altimate/telemetry/index.ts
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand Down Expand Up @@ -2133,6 +2147,8 @@ export namespace Telemetry {
const ANCHOR_EVENTS = new Set<Event["type"]>([
"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",
Expand All @@ -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<typeof setInterval> | undefined
let loopExpectedAt = 0
let loopStallsEmitted = 0
Expand All @@ -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() {
Comment thread
anandgupta42 marked this conversation as resolved.
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,
Expand Down Expand Up @@ -2252,6 +2283,7 @@ export namespace Telemetry {
command = process.env[COMMAND_ENV] ?? "unknown"
freshInstall = false
startupReported = false
clientConnectedReported = false
loopStallsEmitted = 0
loopExpectedAt = 0
}
Expand Down
17 changes: 17 additions & 0 deletions packages/opencode/src/server/server.ts
Original file line number Diff line number Diff line change
Expand Up @@ -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(() => {})
Comment thread
anandgupta42 marked this conversation as resolved.
}
})
// altimate_change end
.use(async (c, next) => {
const skipLogging = c.req.path === "/log"
if (!skipLogging) {
Expand Down
39 changes: 39 additions & 0 deletions packages/opencode/test/altimate/telemetry/first-run-health.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -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")
Expand Down
Original file line number Diff line number Diff line change
@@ -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.
Comment thread
anandgupta42 marked this conversation as resolved.
//
// 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<boolean> {
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<typeof spyOn<typeof Telemetry, "clientConnected">>

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()
})
})
Original file line number Diff line number Diff line change
Expand Up @@ -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,
})
Expand Down
1 change: 1 addition & 0 deletions packages/opencode/test/telemetry/config-opt-out.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -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,
})
Expand Down
Loading