From c3a37305dfce900ae63e1645d1f7dfdb73c9e3f3 Mon Sep 17 00:00:00 2001 From: austinpower1258 Date: Tue, 29 Sep 2026 17:11:26 -0700 Subject: [PATCH 01/15] test: prove cold Freestyle warm-up is single-flight --- web/tests/freestyle-request-timing.test.ts | 20 ++++++++++++++++++++ 1 file changed, 20 insertions(+) diff --git a/web/tests/freestyle-request-timing.test.ts b/web/tests/freestyle-request-timing.test.ts index f9e8259e8181..f482b01bb710 100644 --- a/web/tests/freestyle-request-timing.test.ts +++ b/web/tests/freestyle-request-timing.test.ts @@ -1,7 +1,27 @@ import { describe, expect, test } from "bun:test"; +import { preconnectFreestyle } from "../services/vms/drivers/freestyle"; import { freestyleRequestFetch, type FreestyleRequestTiming } from "../services/vms/drivers/freestyleRequestTiming"; describe("Freestyle enrollment request timings", () => { + test("coalesces concurrent cold connection warm-ups", async () => { + let release!: () => void; + const gate = new Promise(resolve => { release = resolve; }); + let calls = 0; + const fetch = (async () => { + calls += 1; + await gate; + return new Response(null, { status: 204 }); + }) as typeof globalThis.fetch; + + const first = preconnectFreestyle({ baseUrl: "https://provider.example.test", fetch }); + const second = preconnectFreestyle({ baseUrl: "https://provider.example.test", fetch }); + expect(second).toBe(first); + expect(calls).toBe(1); + + release(); + await Promise.all([first, second]); + }); + test.each(["workflow", "init", "request"])("forwards %s cancellation alongside the provider timeout", async (source) => { const controller = new AbortController(); const reason = new DOMException("synthetic cancellation", "AbortError"); From 75eb3ff40ab256bacd8b491cf5bc65056f5aaa87 Mon Sep 17 00:00:00 2001 From: austinpower1258 Date: Tue, 29 Sep 2026 17:16:24 -0700 Subject: [PATCH 02/15] fix: keep Cloud VM create connections warm Await one shared provider and database warm-up before create admission, reuse the per-process Freestyle client, and expose admission and provider initialization timings so an idle invocation cannot race its first paid request. Co-authored-by: Lawrence Chen <54008264+lawrencecchen@users.noreply.github.com> --- web/app/api/vm/route.ts | 33 +++++++++- web/db/client.ts | 5 +- web/services/vms/drivers/freestyle.ts | 90 ++++++++++++++++++++++----- web/services/vms/timings.ts | 2 + web/tests/vm-timings.test.ts | 4 +- 5 files changed, 114 insertions(+), 20 deletions(-) diff --git a/web/app/api/vm/route.ts b/web/app/api/vm/route.ts index 03ef13fbfd1a..b8644aa3290a 100644 --- a/web/app/api/vm/route.ts +++ b/web/app/api/vm/route.ts @@ -92,8 +92,14 @@ import { getGoVmUsage, GO_SAVED_VM_LIMIT } from "../../../services/vms/goUsage"; // stuck-provisioning alert. The plan allows more (app/v1/responses/route.ts // uses 1800). export const maxDuration = 600; +const VM_CREATE_ADMISSION_BUDGET_MS = 200; export async function GET(request: Request): Promise { + // List traffic is the natural idle-path signal from the Cloud sidebar. Keep + // the provider and database connections ready before the next create rather + // than making the first paid mutation pay their cold handshake. + void preconnectFreestyle(); + void preconnectCloudDb(); return withAuthedVmApiRoute( request, "/api/vm", @@ -235,8 +241,9 @@ export async function GET(request: Request): Promise { export async function POST(request: Request): Promise { // Warm the Freestyle and database connections while the caller is being verified. - preconnectFreestyle(); - preconnectCloudDb(); + const warmupStartedAt = performance.now(); + const freestyleWarmup = preconnectFreestyle(); + const databaseWarmup = preconnectCloudDb(); return withAuthedVmApiRoute( request, "/api/vm", @@ -245,7 +252,21 @@ export async function POST(request: Request): Promise { async ({ user: initialUser, span, authDurationMs, routeStartedAtMs, setResponseFinalizer }) => { const timing = new VmTimingRecorder(span, "create", { startedAt: routeStartedAtMs }); timing.record("auth", authDurationMs); + let admissionRecorded = false; + let admissionStartedAt = performance.now(); + const recordAdmission = () => { + if (admissionRecorded) return; + admissionRecorded = true; + const durationMs = performance.now() - admissionStartedAt; + timing.record("admission", durationMs); + setSpanAttributes(span, { + "cmux.vm.admission_ms": Math.round(durationMs * 100) / 100, + "cmux.vm.admission_budget_ms": VM_CREATE_ADMISSION_BUDGET_MS, + "cmux.vm.admission_within_budget": durationMs <= VM_CREATE_ADMISSION_BUDGET_MS, + }); + }; setResponseFinalizer((response) => { + recordAdmission(); timing.finish({ status: response.status }); // Per-stage timings travel with the response too, so a client or a // smoke run sees where a create spent its time without Axiom. @@ -257,6 +278,13 @@ export async function POST(request: Request): Promise { captureVmProvisionOutcome({ userId: initialUser.id, operation: "create", response, span }); }); + await Promise.all([freestyleWarmup, databaseWarmup]); + timing.record("connection_init", performance.now() - warmupStartedAt); + // Admission starts after connection readiness. Its budget therefore + // describes request validation and durable create admission, without + // hiding the separate cold connection phase above. + admissionStartedAt = performance.now(); + const parsed = await parseCreateRequest(request, span, timing); if (!parsed.ok) return parsed.response; const { candidate, body, idempotencyKey } = parsed; @@ -293,6 +321,7 @@ export async function POST(request: Request): Promise { "cmux.vm.image_size": imageSelection.size?.name ?? "size-less", "cmux.idempotency_key_set": !!idempotencyKey, }); + recordAdmission(); // Wire the machine to coderouter inside the workflow: the route token // is bound to the VM row id, so provisioning runs after the row exists diff --git a/web/db/client.ts b/web/db/client.ts index b0bf9747b4b5..088746cf2e67 100644 --- a/web/db/client.ts +++ b/web/db/client.ts @@ -300,12 +300,13 @@ function coalesceWarm(run: () => Promise): () => Promise { * first success a no-op for the life of the process, so calling it ahead of * auth cannot amplify an unauthenticated burst beyond one pooled connection. */ -export function preconnectCloudDb(): void { +export function preconnectCloudDb(): Promise { try { cloudDb(); - void globalForDb.__cmuxCloudDb?.warm().catch(() => undefined); + return globalForDb.__cmuxCloudDb?.warm().catch(() => undefined) ?? Promise.resolve(); } catch { // No database configured (tests, offline builds): the first query reports it. + return Promise.resolve(); } } diff --git a/web/services/vms/drivers/freestyle.ts b/web/services/vms/drivers/freestyle.ts index 2fa49898ba54..1957d63fe8a1 100644 --- a/web/services/vms/drivers/freestyle.ts +++ b/web/services/vms/drivers/freestyle.ts @@ -184,6 +184,36 @@ export type FreestyleProviderDependencies = { readonly client: (timeoutMs?: number) => Freestyle; }; +export type FreestylePreconnectOptions = { + readonly baseUrl?: string; + readonly fetch?: typeof fetch; + readonly timeoutMs?: number; +}; + +type FreestyleWarmupState = { promise?: Promise }; + +const freestyleWarmupStates = new WeakMap(); + +const globalForFreestyle = globalThis as typeof globalThis & { + __cmuxFreestyleClients?: Map; +}; + +function warmupStateFor(fetchImpl: typeof fetch): FreestyleWarmupState { + const key = fetchImpl as unknown as object; + const existing = freestyleWarmupStates.get(key); + if (existing) return existing; + const state: FreestyleWarmupState = {}; + freestyleWarmupStates.set(key, state); + return state; +} + +async function warmFreestyleConnection(options: Required): Promise { + await options.fetch(`${options.baseUrl}/`, { + method: "HEAD", + signal: AbortSignal.timeout(options.timeoutMs), + }); +} + /** * FREESTYLE_API_URL stays as an operator escape hatch (a staging edge); unset, * the SDK's own default — the public api.freestyle.sh — is used. The @@ -194,15 +224,35 @@ export type FreestyleProviderDependencies = { * first Freestyle call of a function invocation paid about 130 ms of DNS, TCP, * and TLS in production (vpc.get: 150 ms from pdx1, 12 ms warm); a route fires * this while it is still verifying the caller so the real call finds the - * connection in undici's pool. Best effort, never awaited for correctness. + * connection in undici's pool. Concurrent route requests share one in-flight + * warm-up, and a failed probe is best-effort so provider errors remain typed. */ -export function preconnectFreestyle(): void { - const baseUrl = process.env.FREESTYLE_API_URL?.trim() || "https://api.freestyle.sh"; - fetch(`${baseUrl}/`, { method: "HEAD", signal: AbortSignal.timeout(3_000) }).catch(() => undefined); +export function preconnectFreestyle(options: FreestylePreconnectOptions = {}): Promise { + const baseUrl = options.baseUrl?.trim() || process.env.FREESTYLE_API_URL?.trim() || "https://api.freestyle.sh"; + const fetchImpl = options.fetch ?? fetch; + const timeoutMs = options.timeoutMs ?? 3_000; + const state = warmupStateFor(fetchImpl); + if (state.promise) return state.promise; + const promise = warmFreestyleConnection({ baseUrl, fetch: fetchImpl, timeoutMs }).catch(() => undefined); + const settled = promise.finally(() => { + if (state.promise === settled) state.promise = undefined; + }); + state.promise = settled; + return settled; } /** Exported for the publication provider, which shares this account-wide client. */ export function freestyleClient(timeoutMs = DEFAULT_TIMEOUT_MS): Freestyle { + const baseUrl = process.env.FREESTYLE_API_URL?.trim() || undefined; + const apiKey = process.env.FREESTYLE_API_KEY?.trim(); + const stackAccessToken = process.env.FREESTYLE_STACK_ACCESS_TOKEN?.trim(); + const teamId = process.env.FREESTYLE_TEAM_ID?.trim(); + const credentialKind = apiKey ? "api-key" : stackAccessToken && teamId ? "stack" : "missing"; + const cacheKey = `${baseUrl ?? "https://api.freestyle.sh"}|${credentialKind}|${timeoutMs}`; + const clients = globalForFreestyle.__cmuxFreestyleClients ??= new Map(); + const cached = clients.get(cacheKey); + if (cached) return cached; + const longFetch = freestyleRequestFetch({ timeoutMs, record: process.env.NODE_ENV === "development" ? (event) => { @@ -212,18 +262,19 @@ export function freestyleClient(timeoutMs = DEFAULT_TIMEOUT_MS): Freestyle { })); } : undefined, }); - const baseUrl = process.env.FREESTYLE_API_URL?.trim() || undefined; - const apiKey = process.env.FREESTYLE_API_KEY?.trim(); - if (apiKey) return new Freestyle({ apiKey, baseUrl, fetch: longFetch }); - const stackAccessToken = process.env.FREESTYLE_STACK_ACCESS_TOKEN?.trim(); - const teamId = process.env.FREESTYLE_TEAM_ID?.trim(); - if (stackAccessToken && teamId) { - return new Freestyle({ stackAccessToken, teamId, baseUrl, fetch: longFetch }); + const client = apiKey + ? new Freestyle({ apiKey, baseUrl, fetch: longFetch }) + : stackAccessToken && teamId + ? new Freestyle({ stackAccessToken, teamId, baseUrl, fetch: longFetch }) + : null; + if (!client) { + throw new ProviderError( + "freestyle", + "freestyle requires FREESTYLE_API_KEY (or FREESTYLE_STACK_ACCESS_TOKEN + FREESTYLE_TEAM_ID)", + ); } - throw new ProviderError( - "freestyle", - "freestyle requires FREESTYLE_API_KEY (or FREESTYLE_STACK_ACCESS_TOKEN + FREESTYLE_TEAM_ID)", - ); + clients.set(cacheKey, client); + return client; } /** @@ -955,8 +1006,12 @@ export class FreestyleProvider implements VMProvider { }, async (span) => { try { + const clientStartedAt = performance.now(); const fs = this.deps.client(CREATE_TIMEOUT_MS); + const clientInitMs = Math.round((performance.now() - clientStartedAt) * 100) / 100; + setSpanAttributes(span, { "cmux.vm.provider.client_init_ms": clientInitMs }); const networkId = options.network?.id; + const providerStartedAt = performance.now(); const { vm, vmId, data } = await fs.vms.create({ snapshotId: image, displayName: "cmux Cloud VM", @@ -971,9 +1026,14 @@ export class FreestyleProvider implements VMProvider { ...(networkId ? { vpcs: [{ vpcId: networkId, ipv4: true, ipv6: true }] } : {}), ...(tlsRules ? { tls: { rules: tlsRules } } : {}), }); + const providerMs = Math.round((performance.now() - providerStartedAt) * 100) / 100; setSpanAttributes(span, { "cmux.vm.id": vmId, "cmux.vm.network.private": !!networkId, + // The SDK resolves only after the provider response has been + // decoded, so this is both API provisioning and machine-id receipt. + "cmux.vm.provider.api_provision_ms": providerMs, + "cmux.vm.provider.machine_id_receipt_ms": providerMs, }); try { // Validate the provider-assigned VPC address without issuing the diff --git a/web/services/vms/timings.ts b/web/services/vms/timings.ts index 40ba0e4936fd..537e4c5990c2 100644 --- a/web/services/vms/timings.ts +++ b/web/services/vms/timings.ts @@ -3,7 +3,9 @@ import * as Effect from "effect/Effect"; export type VmTimingStage = | "auth" + | "connection_init" | "request_parse" + | "admission" | "entitlements" | "begin_create" | "begin_base_open" diff --git a/web/tests/vm-timings.test.ts b/web/tests/vm-timings.test.ts index 4ef4a9427cf7..d763823ba99d 100644 --- a/web/tests/vm-timings.test.ts +++ b/web/tests/vm-timings.test.ts @@ -30,9 +30,11 @@ describe("VM timing helpers", () => { const span = { setAttribute: (key: string, value: unknown) => attributes.push({ key, value }) } as unknown as Span; const recorder = new VmTimingRecorder(span, "create", { debugTimings: false }); recorder.record("auth", 12.345); + recorder.record("connection_init", 8); + recorder.record("admission", 20); recorder.record("provider_create", 250); recorder.record("provider_create", 50); - expect(recorder.serverTimingHeader()).toBe("auth;dur=12.35, provider_create;dur=300"); + expect(recorder.serverTimingHeader()).toBe("auth;dur=12.35, connection_init;dur=8, admission;dur=20, provider_create;dur=300"); expect(attributes.some((attribute) => attribute.key === "cmux.vm.timing.provider_create_started_at_ms")).toBe(true); expect(attributes.some((attribute) => attribute.key === "cmux.vm.timing.provider_create_ended_at_ms")).toBe(true); }); From 242620d09530ea381634861d8d604f386f01476e Mon Sep 17 00:00:00 2001 From: austinpower1258 Date: Tue, 29 Sep 2026 17:26:01 -0700 Subject: [PATCH 03/15] test: allow protected Vercel benchmark targets --- web/scripts/cloud-vm/bench-vm-startup.mjs | 12 +++++++++++- 1 file changed, 11 insertions(+), 1 deletion(-) diff --git a/web/scripts/cloud-vm/bench-vm-startup.mjs b/web/scripts/cloud-vm/bench-vm-startup.mjs index 68e25745a091..fb2df557007a 100644 --- a/web/scripts/cloud-vm/bench-vm-startup.mjs +++ b/web/scripts/cloud-vm/bench-vm-startup.mjs @@ -739,7 +739,17 @@ async function mintSessionHeaders(expiresInMillis) { const session = await withTimeout(user.createSession({ expiresInMillis, isImpersonation: true }), STACK_TIMEOUT_MS, "Stack createSession"); const tokens = await withTimeout(session.getTokens(), STACK_TIMEOUT_MS, "Stack getTokens"); if (!tokens.accessToken || !tokens.refreshToken) throw new Error("Stack did not return bench session tokens"); - return { authorization: `Bearer ${tokens.accessToken}`, "x-stack-refresh-token": tokens.refreshToken }; + // Vercel SSO-protected unaliased deployments accept this header when the + // operator supplies the project-scoped automation bypass secret. Keep it + // scoped to a non-canonical target and never include it in reports/logs. + const canonicalHost = new URL(project.url).host; + const targetHost = new URL(targetUrl).host; + const bypassSecret = targetHost !== canonicalHost ? process.env.VERCEL_AUTOMATION_BYPASS_SECRET?.trim() : undefined; + return { + authorization: `Bearer ${tokens.accessToken}`, + "x-stack-refresh-token": tokens.refreshToken, + ...(bypassSecret ? { "x-vercel-protection-bypass": bypassSecret } : {}), + }; } /** Everything teardown learned, so the report can say what really happened. */ From caffdf0a1f10a57ebbadfe006568bade6a5288fb Mon Sep 17 00:00:00 2001 From: austinpower1258 Date: Tue, 29 Sep 2026 17:33:52 -0700 Subject: [PATCH 04/15] test: trace durable Cloud VM row readiness --- web/app/api/vm/route.ts | 1 + web/scripts/cloud-vm/bench-vm-startup.mjs | 41 +++++++++++++++++++++-- web/services/vms/drivers/freestyle.ts | 2 ++ 3 files changed, 41 insertions(+), 3 deletions(-) diff --git a/web/app/api/vm/route.ts b/web/app/api/vm/route.ts index b8644aa3290a..9a3160220685 100644 --- a/web/app/api/vm/route.ts +++ b/web/app/api/vm/route.ts @@ -254,6 +254,7 @@ export async function POST(request: Request): Promise { timing.record("auth", authDurationMs); let admissionRecorded = false; let admissionStartedAt = performance.now(); + /** Records validation/admission even when the request exits before provisioning. */ const recordAdmission = () => { if (admissionRecorded) return; admissionRecorded = true; diff --git a/web/scripts/cloud-vm/bench-vm-startup.mjs b/web/scripts/cloud-vm/bench-vm-startup.mjs index fb2df557007a..0363535a7e30 100644 --- a/web/scripts/cloud-vm/bench-vm-startup.mjs +++ b/web/scripts/cloud-vm/bench-vm-startup.mjs @@ -48,6 +48,10 @@ const REQUEST_TIMEOUT_MS = 330_000; const CREATE_TIMEOUT_MS = 630_000; // Bounds when a new attach attempt may start; it never cuts a request short. const ATTACH_BUDGET_MS = 180_000; +// The durable row should become visible immediately after the create response; +// keep this separate from provider/daemon readiness so a lagging list index is +// visible instead of being folded into attach time. +const ROW_READY_BUDGET_MS = 60_000; const requireFromWeb = createRequire(path.join(webDir, "package.json")); const { StackServerApp } = await import(pathToFileURL(requireFromWeb.resolve("@hexclave/js")).href); @@ -266,6 +270,35 @@ async function attachUntilReady(vmId, stage) { } } +/** Polls the authoritative VM list until the newly created durable row is visible. */ +async function rowUntilVisible(vmId) { + const startedAt = performance.now(); + const attempts = []; + for (;;) { + const elapsed = performance.now() - startedAt; + if (elapsed >= ROW_READY_BUDGET_MS || interrupted) { + throw new Error(`VM row for ${vmId} did not become visible within ${ROW_READY_BUDGET_MS} ms (${attempts.length} attempts)`); + } + const response = await fetchTimed(`${targetUrl}/api/vm`, { headers: authHeaders }); + const body = json(response.text); + attempts.push({ status: response.status, ms: response.ms }); + if (response.status === 200) { + const row = (body.vms ?? []).find((entry) => entry?.id === vmId); + if (row) { + return { + rowReadyMs: elapsedMs(startedAt), + rowReadyStatus: row.status ?? null, + rowReadyAttempts: attempts, + }; + } + } else if (response.status >= 500) { + throw new Error(`VM row list failed while waiting for ${vmId}: ${response.status} ${response.text.slice(0, 300)}`); + } + const remainingMs = ROW_READY_BUDGET_MS - (performance.now() - startedAt); + await sleep(Math.min(remainingMs, 250)); + } +} + /** Time from the first probe until the edge alias answers with an HTTP status (any status proves injection). */ async function edgeReady(vmId) { const startedAt = performance.now(); @@ -328,12 +361,14 @@ async function runTrial(trial) { trial.vmId = vmId; trial.imageVersion = created.imageVersion ?? null; trial.size = created.size?.name ?? null; + Object.assign(trial, await rowUntilVisible(vmId)); Object.assign(trial, await attachUntilReady(vmId, "attach")); // Create plus the attach-endpoint's own time: the route and lease exist, // but the link, the terminal and the shell prompt come after this point - // (bench-private-link.ts measures those), so this is attach readiness, - // not a usable terminal. + // (bench-private-link.ts measures those). Trusted-carrier attach is the + // first usable machine boundary; rowReadyMs is the durable fleet-row boundary. trial.createToAttachReadyMs = trial.createMs + trial.attachMs; + trial.createToRowReadyMs = trial.createMs + trial.rowReadyMs; Object.assign(trial, await attachUntilReady(vmId, "warmAttach")); if (!skipExec) { const exec = await fetchTimed(vmUrl(vmId, "/exec"), { @@ -888,7 +923,7 @@ function emitReport({ results, listMs, startedAt, runError, cleanup }) { totalMs: startedAt === null ? null : elapsedMs(startedAt), succeeded: ok.length, failed: results.length - ok.length, - stages: summarizeFields(measured, ["createMs", "attachMs", "createToAttachReadyMs", "warmAttachMs", "execMs", "edgeReadyMs", "pauseMs", "resumeAttachMs", "destroyMs"]), + stages: summarizeFields(measured, ["createMs", "rowReadyMs", "createToRowReadyMs", "attachMs", "createToAttachReadyMs", "warmAttachMs", "execMs", "edgeReadyMs", "pauseMs", "resumeAttachMs", "destroyMs"]), attachAttempts: summarizeFields(measured.map((trial) => ({ attempts: trial.attachAttempts?.length })), ["attempts"]).attempts, createServerTiming: summarizeStages(measured.map((trial) => trial.createStages)), results, diff --git a/web/services/vms/drivers/freestyle.ts b/web/services/vms/drivers/freestyle.ts index 1957d63fe8a1..3efb85f23183 100644 --- a/web/services/vms/drivers/freestyle.ts +++ b/web/services/vms/drivers/freestyle.ts @@ -198,6 +198,7 @@ const globalForFreestyle = globalThis as typeof globalThis & { __cmuxFreestyleClients?: Map; }; +/** Returns the single-flight state associated with one fetch implementation. */ function warmupStateFor(fetchImpl: typeof fetch): FreestyleWarmupState { const key = fetchImpl as unknown as object; const existing = freestyleWarmupStates.get(key); @@ -207,6 +208,7 @@ function warmupStateFor(fetchImpl: typeof fetch): FreestyleWarmupState { return state; } +/** Performs the bounded same-origin probe that establishes the provider connection pool. */ async function warmFreestyleConnection(options: Required): Promise { await options.fetch(`${options.baseUrl}/`, { method: "HEAD", From c2efa626461fd55db5985d88f64a4f9996a97bba Mon Sep 17 00:00:00 2001 From: austinpower1258 Date: Tue, 29 Sep 2026 17:40:00 -0700 Subject: [PATCH 05/15] fix: keep connection timing separate from auth --- web/app/api/vm/route.ts | 6 ++++-- 1 file changed, 4 insertions(+), 2 deletions(-) diff --git a/web/app/api/vm/route.ts b/web/app/api/vm/route.ts index 9a3160220685..33fab86d9cbf 100644 --- a/web/app/api/vm/route.ts +++ b/web/app/api/vm/route.ts @@ -244,6 +244,9 @@ export async function POST(request: Request): Promise { const warmupStartedAt = performance.now(); const freestyleWarmup = preconnectFreestyle(); const databaseWarmup = preconnectCloudDb(); + const connectionInitDuration = Promise.all([freestyleWarmup, databaseWarmup]).then( + () => performance.now() - warmupStartedAt, + ); return withAuthedVmApiRoute( request, "/api/vm", @@ -279,8 +282,7 @@ export async function POST(request: Request): Promise { captureVmProvisionOutcome({ userId: initialUser.id, operation: "create", response, span }); }); - await Promise.all([freestyleWarmup, databaseWarmup]); - timing.record("connection_init", performance.now() - warmupStartedAt); + timing.record("connection_init", await connectionInitDuration); // Admission starts after connection readiness. Its budget therefore // describes request validation and durable create admission, without // hiding the separate cold connection phase above. From 8e4c979fb69b26d470c2b06f034733f0c5f3c857 Mon Sep 17 00:00:00 2001 From: austinpower1258 Date: Tue, 29 Sep 2026 17:59:29 -0700 Subject: [PATCH 06/15] fix: make Cloud warm-up and readiness evidence truthful --- web/app/api/vm/route.ts | 24 ++++++++------ web/scripts/cloud-vm/bench-vm-startup.mjs | 38 ++++++++++++++-------- web/services/vms/drivers/freestyle.ts | 28 +++++++++------- web/tests/freestyle-request-timing.test.ts | 24 +++++++++----- 4 files changed, 71 insertions(+), 43 deletions(-) diff --git a/web/app/api/vm/route.ts b/web/app/api/vm/route.ts index 33fab86d9cbf..01c947040c6d 100644 --- a/web/app/api/vm/route.ts +++ b/web/app/api/vm/route.ts @@ -95,17 +95,17 @@ export const maxDuration = 600; const VM_CREATE_ADMISSION_BUDGET_MS = 200; export async function GET(request: Request): Promise { - // List traffic is the natural idle-path signal from the Cloud sidebar. Keep - // the provider and database connections ready before the next create rather - // than making the first paid mutation pay their cold handshake. - void preconnectFreestyle(); - void preconnectCloudDb(); return withAuthedVmApiRoute( request, "/api/vm", { "cmux.vm.operation": "list" }, "/api/vm GET failed", async ({ user, span }) => { + // List traffic is the natural idle-path signal from the Cloud sidebar. + // Start warming only after auth so an unauthenticated poll cannot open a + // provider socket or database pool on every fresh function instance. + void preconnectCloudDb(); + runAfterResponse(() => preconnectFreestyle()); let billingTeamId: string | null = null; let listEntitlements: ReturnType | null = null; const requestedBillingTeamId = requestedVmTeamIdFromRequest(request); @@ -244,7 +244,11 @@ export async function POST(request: Request): Promise { const warmupStartedAt = performance.now(); const freestyleWarmup = preconnectFreestyle(); const databaseWarmup = preconnectCloudDb(); - const connectionInitDuration = Promise.all([freestyleWarmup, databaseWarmup]).then( + // Database warming is an optimization only: its driver may wait on a + // provider-controlled connect deadline, so it must never delay validation or + // turn an authenticated create into an unbounded database health check. + void databaseWarmup; + const connectionInitDuration = freestyleWarmup.then( () => performance.now() - warmupStartedAt, ); return withAuthedVmApiRoute( @@ -257,7 +261,7 @@ export async function POST(request: Request): Promise { timing.record("auth", authDurationMs); let admissionRecorded = false; let admissionStartedAt = performance.now(); - /** Records validation/admission even when the request exits before provisioning. */ + /** Records request validation even when it exits before provisioning. */ const recordAdmission = () => { if (admissionRecorded) return; admissionRecorded = true; @@ -283,9 +287,9 @@ export async function POST(request: Request): Promise { }); timing.record("connection_init", await connectionInitDuration); - // Admission starts after connection readiness. Its budget therefore - // describes request validation and durable create admission, without - // hiding the separate cold connection phase above. + // Admission starts after connection readiness. Its budget describes only + // request validation; the durable begin_create phase is recorded inside + // the workflow and remains a separate authoritative boundary. admissionStartedAt = performance.now(); const parsed = await parseCreateRequest(request, span, timing); diff --git a/web/scripts/cloud-vm/bench-vm-startup.mjs b/web/scripts/cloud-vm/bench-vm-startup.mjs index 0363535a7e30..2e0a50315a64 100644 --- a/web/scripts/cloud-vm/bench-vm-startup.mjs +++ b/web/scripts/cloud-vm/bench-vm-startup.mjs @@ -15,13 +15,14 @@ import { pathToFileURL } from "node:url"; import { elapsedMs, formatSummary, ownerNetworkSlug, parseServerTiming, pollBoundedFetch, providerCredentialsFromEnv, summarizeFields, summarizeStages } from "./benchStats.mjs"; import { loadTargetEnv, optionValue, parseWebDirAndTarget, requireEnvKeys, runVercel } from "./projects.mjs"; -const usage = "Usage: bench-vm-startup.mjs [web-dir] [--trials N] [--concurrency K] [--url https://preview.example] [--allow-preview] [--allow-any-url] [--skip-pause] [--skip-exec] [--edge-check] [--edge-alias ] [--label ] [--out ]"; +const usage = "Usage: bench-vm-startup.mjs [web-dir] [--trials N] [--concurrency K] [--url https://preview.example] [--allow-preview] [--allow-any-url] [--skip-initial-list] [--skip-pause] [--skip-exec] [--edge-check] [--edge-alias ] [--label ] [--out ]"; const { webDir, target, project, rest } = parseWebDirAndTarget(process.argv.slice(2), usage); const trials = positiveInteger(optionValue(rest, "--trials") ?? "3", "--trials"); const concurrency = Math.min(positiveInteger(optionValue(rest, "--concurrency") ?? "1", "--concurrency"), trials); const targetUrl = resolveTargetUrl(project, rest); const skipPause = rest.includes("--skip-pause"); const skipExec = rest.includes("--skip-exec"); +const skipInitialList = rest.includes("--skip-initial-list"); // Full-feature readiness: poll the model-plane edge alias from inside the // guest until the coderouter reflection route answers, so the report can // separate "terminal usable" from "agents can reach their credentials". The @@ -279,12 +280,20 @@ async function rowUntilVisible(vmId) { if (elapsed >= ROW_READY_BUDGET_MS || interrupted) { throw new Error(`VM row for ${vmId} did not become visible within ${ROW_READY_BUDGET_MS} ms (${attempts.length} attempts)`); } - const response = await fetchTimed(`${targetUrl}/api/vm`, { headers: authHeaders }); + const remainingMs = ROW_READY_BUDGET_MS - (performance.now() - startedAt); + const response = await fetchTimed( + `${targetUrl}/api/vm`, + { headers: authHeaders }, + Math.min(REQUEST_TIMEOUT_MS, remainingMs), + ); const body = json(response.text); attempts.push({ status: response.status, ms: response.ms }); if (response.status === 200) { const row = (body.vms ?? []).find((entry) => entry?.id === vmId); - if (row) { + if (row?.status === "failed") { + throw new Error(`VM row for ${vmId} became failed while waiting for readiness`); + } + if (row?.status === "running") { return { rowReadyMs: elapsedMs(startedAt), rowReadyStatus: row.status ?? null, @@ -294,7 +303,6 @@ async function rowUntilVisible(vmId) { } else if (response.status >= 500) { throw new Error(`VM row list failed while waiting for ${vmId}: ${response.status} ${response.text.slice(0, 300)}`); } - const remainingMs = ROW_READY_BUDGET_MS - (performance.now() - startedAt); await sleep(Math.min(remainingMs, 250)); } } @@ -330,6 +338,7 @@ async function runTrial(trial) { const { index } = trial; const idempotencyKey = `bench-${suffix}-${index}`; const createRequestedAt = Date.now(); + const createStartedAt = performance.now(); let create; try { create = await fetchTimed(`${targetUrl}/api/vm`, { @@ -346,6 +355,7 @@ async function runTrial(trial) { trial.createMs = create.ms; trial.createStatus = create.status; trial.createTraceId = create.headers.get("x-cmux-trace-id"); + trial.createVercelId = create.headers.get("x-vercel-id"); trial.createStages = parseServerTiming(create.headers.get("server-timing")); if (create.status >= 500) { // A 5xx (a gateway or function timeout above all) can end the invocation @@ -363,13 +373,13 @@ async function runTrial(trial) { trial.size = created.size?.name ?? null; Object.assign(trial, await rowUntilVisible(vmId)); Object.assign(trial, await attachUntilReady(vmId, "attach")); - // Create plus the attach-endpoint's own time: the route and lease exist, - // but the link, the terminal and the shell prompt come after this point - // (bench-private-link.ts measures those). Trusted-carrier attach is the - // first usable machine boundary; rowReadyMs is the durable fleet-row boundary. - trial.createToAttachReadyMs = trial.createMs + trial.attachMs; - trial.createToRowReadyMs = trial.createMs + trial.rowReadyMs; + // Row polling is serialized before endpoint issuance. Use one monotonic + // origin so the totals include both phases; endpoint issuance is not a + // terminal-ready claim (bench-private-link.ts measures the real prompt). + trial.createToRowReadyMs = elapsedMs(createStartedAt); + trial.createToAttachReadyMs = undefined; Object.assign(trial, await attachUntilReady(vmId, "warmAttach")); + trial.createToAttachReadyMs = elapsedMs(createStartedAt); if (!skipExec) { const exec = await fetchTimed(vmUrl(vmId, "/exec"), { method: "POST", @@ -960,9 +970,11 @@ try { const sessionMs = Math.min(24 * 60 * 60 * 1000, 30 * 60 * 1000 + Math.ceil(trials / concurrency) * trialWorstMs); authHeaders = await mintSessionHeaders(sessionMs); - const list = await fetchTimed(`${targetUrl}/api/vm`, { headers: authHeaders }); - if (list.status !== 200) throw new Error(`authenticated GET /api/vm expected 200, got ${list.status}: ${list.text.slice(0, 200)}`); - listMs = list.ms; + if (!skipInitialList) { + const list = await fetchTimed(`${targetUrl}/api/vm`, { headers: authHeaders }); + if (list.status !== 200) throw new Error(`authenticated GET /api/vm expected 200, got ${list.status}: ${list.text.slice(0, 200)}`); + listMs = list.ms; + } startedAt = performance.now(); results = await runBatches(); diff --git a/web/services/vms/drivers/freestyle.ts b/web/services/vms/drivers/freestyle.ts index 3efb85f23183..d37abeb51006 100644 --- a/web/services/vms/drivers/freestyle.ts +++ b/web/services/vms/drivers/freestyle.ts @@ -190,21 +190,23 @@ export type FreestylePreconnectOptions = { readonly timeoutMs?: number; }; -type FreestyleWarmupState = { promise?: Promise }; +type FreestyleWarmupState = { promise?: Promise; succeeded?: boolean }; -const freestyleWarmupStates = new WeakMap(); +const freestyleWarmupStates = new WeakMap>(); const globalForFreestyle = globalThis as typeof globalThis & { __cmuxFreestyleClients?: Map; }; -/** Returns the single-flight state associated with one fetch implementation. */ -function warmupStateFor(fetchImpl: typeof fetch): FreestyleWarmupState { +/** Returns the sticky single-flight state for one fetch implementation and origin. */ +function warmupStateFor(fetchImpl: typeof fetch, baseUrl: string): FreestyleWarmupState { const key = fetchImpl as unknown as object; - const existing = freestyleWarmupStates.get(key); + const states = freestyleWarmupStates.get(key) ?? new Map(); + const existing = states.get(baseUrl); if (existing) return existing; const state: FreestyleWarmupState = {}; - freestyleWarmupStates.set(key, state); + states.set(baseUrl, state); + freestyleWarmupStates.set(key, states); return state; } @@ -233,9 +235,12 @@ export function preconnectFreestyle(options: FreestylePreconnectOptions = {}): P const baseUrl = options.baseUrl?.trim() || process.env.FREESTYLE_API_URL?.trim() || "https://api.freestyle.sh"; const fetchImpl = options.fetch ?? fetch; const timeoutMs = options.timeoutMs ?? 3_000; - const state = warmupStateFor(fetchImpl); + const state = warmupStateFor(fetchImpl, baseUrl); + if (state.succeeded) return Promise.resolve(); if (state.promise) return state.promise; - const promise = warmFreestyleConnection({ baseUrl, fetch: fetchImpl, timeoutMs }).catch(() => undefined); + const promise = warmFreestyleConnection({ baseUrl, fetch: fetchImpl, timeoutMs }) + .then(() => { state.succeeded = true; }) + .catch(() => { state.succeeded = false; }); const settled = promise.finally(() => { if (state.promise === settled) state.promise = undefined; }); @@ -1032,10 +1037,11 @@ export class FreestyleProvider implements VMProvider { setSpanAttributes(span, { "cmux.vm.id": vmId, "cmux.vm.network.private": !!networkId, - // The SDK resolves only after the provider response has been - // decoded, so this is both API provisioning and machine-id receipt. "cmux.vm.provider.api_provision_ms": providerMs, - "cmux.vm.provider.machine_id_receipt_ms": providerMs, + // `vms.create` resolves only after the SDK has decoded the id; + // retain its wall-clock receipt as an explicit correlation point. + "cmux.vm.provider.machine_id_received": true, + "cmux.vm.provider.machine_id_received_at_ms": Date.now(), }); try { // Validate the provider-assigned VPC address without issuing the diff --git a/web/tests/freestyle-request-timing.test.ts b/web/tests/freestyle-request-timing.test.ts index f482b01bb710..214fd0eeb8c4 100644 --- a/web/tests/freestyle-request-timing.test.ts +++ b/web/tests/freestyle-request-timing.test.ts @@ -3,23 +3,29 @@ import { preconnectFreestyle } from "../services/vms/drivers/freestyle"; import { freestyleRequestFetch, type FreestyleRequestTiming } from "../services/vms/drivers/freestyleRequestTiming"; describe("Freestyle enrollment request timings", () => { - test("coalesces concurrent cold connection warm-ups", async () => { + test("coalesces concurrent production connection warm-ups and keeps success sticky", async () => { + const originalFetch = globalThis.fetch; let release!: () => void; const gate = new Promise(resolve => { release = resolve; }); let calls = 0; - const fetch = (async () => { + globalThis.fetch = (async () => { calls += 1; await gate; return new Response(null, { status: 204 }); }) as typeof globalThis.fetch; + try { + const first = preconnectFreestyle(); + const second = preconnectFreestyle(); + expect(second).toBe(first); + expect(calls).toBe(1); - const first = preconnectFreestyle({ baseUrl: "https://provider.example.test", fetch }); - const second = preconnectFreestyle({ baseUrl: "https://provider.example.test", fetch }); - expect(second).toBe(first); - expect(calls).toBe(1); - - release(); - await Promise.all([first, second]); + release(); + await Promise.all([first, second]); + await preconnectFreestyle(); + expect(calls).toBe(1); + } finally { + globalThis.fetch = originalFetch; + } }); test.each(["workflow", "init", "request"])("forwards %s cancellation alongside the provider timeout", async (source) => { From 863fa8f078b597cd6537510eed991065b4e62e59 Mon Sep 17 00:00:00 2001 From: austinpower1258 Date: Tue, 29 Sep 2026 18:02:52 -0700 Subject: [PATCH 07/15] fix: bound Cloud row readiness benchmark --- web/scripts/cloud-vm/bench-vm-startup.mjs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/web/scripts/cloud-vm/bench-vm-startup.mjs b/web/scripts/cloud-vm/bench-vm-startup.mjs index 2e0a50315a64..7f73d87e2a61 100644 --- a/web/scripts/cloud-vm/bench-vm-startup.mjs +++ b/web/scripts/cloud-vm/bench-vm-startup.mjs @@ -966,7 +966,7 @@ try { // request), exec, pause and destroy requests and the edge probe, in // ceil(trials / concurrency) rounds; capped at a day. Cleanup mints its // own fresh session, so it does not depend on this one. - const trialWorstMs = CREATE_TIMEOUT_MS + 3 * (ATTACH_BUDGET_MS + REQUEST_TIMEOUT_MS) + 3 * REQUEST_TIMEOUT_MS + EDGE_BUDGET_MS + REQUEST_TIMEOUT_MS; + const trialWorstMs = CREATE_TIMEOUT_MS + ROW_READY_BUDGET_MS + 3 * (ATTACH_BUDGET_MS + REQUEST_TIMEOUT_MS) + 3 * REQUEST_TIMEOUT_MS + EDGE_BUDGET_MS + REQUEST_TIMEOUT_MS; const sessionMs = Math.min(24 * 60 * 60 * 1000, 30 * 60 * 1000 + Math.ceil(trials / concurrency) * trialWorstMs); authHeaders = await mintSessionHeaders(sessionMs); From e6d78cea697e75d406f3bd67455cf3dedc40fee6 Mon Sep 17 00:00:00 2001 From: austinpower1258 Date: Tue, 29 Sep 2026 18:05:23 -0700 Subject: [PATCH 08/15] fix: expire provider warm-up reuse after idle --- web/services/vms/drivers/freestyle.ts | 14 ++++++++++---- 1 file changed, 10 insertions(+), 4 deletions(-) diff --git a/web/services/vms/drivers/freestyle.ts b/web/services/vms/drivers/freestyle.ts index d37abeb51006..59c40a2efd77 100644 --- a/web/services/vms/drivers/freestyle.ts +++ b/web/services/vms/drivers/freestyle.ts @@ -190,9 +190,12 @@ export type FreestylePreconnectOptions = { readonly timeoutMs?: number; }; -type FreestyleWarmupState = { promise?: Promise; succeeded?: boolean }; +type FreestyleWarmupState = { promise?: Promise; succeeded?: boolean; succeededAtMs?: number }; const freestyleWarmupStates = new WeakMap>(); +// Keep a successful probe only for the provider's normal idle-pool window; +// after a longer suspension the next Cloud request probes again. +const FREESTYLE_WARMUP_REUSE_MS = 30_000; const globalForFreestyle = globalThis as typeof globalThis & { __cmuxFreestyleClients?: Map; @@ -236,11 +239,14 @@ export function preconnectFreestyle(options: FreestylePreconnectOptions = {}): P const fetchImpl = options.fetch ?? fetch; const timeoutMs = options.timeoutMs ?? 3_000; const state = warmupStateFor(fetchImpl, baseUrl); - if (state.succeeded) return Promise.resolve(); + if (state.succeeded && state.succeededAtMs !== undefined && Date.now() - state.succeededAtMs < FREESTYLE_WARMUP_REUSE_MS) { + return Promise.resolve(); + } + state.succeeded = undefined; if (state.promise) return state.promise; const promise = warmFreestyleConnection({ baseUrl, fetch: fetchImpl, timeoutMs }) - .then(() => { state.succeeded = true; }) - .catch(() => { state.succeeded = false; }); + .then(() => { state.succeeded = true; state.succeededAtMs = Date.now(); }) + .catch(() => { state.succeeded = false; state.succeededAtMs = undefined; }); const settled = promise.finally(() => { if (state.promise === settled) state.promise = undefined; }); From 2a4cb03059bdc0cd5ea834952d3f2bf920109b2d Mon Sep 17 00:00:00 2001 From: austinpower1258 Date: Tue, 29 Sep 2026 18:15:10 -0700 Subject: [PATCH 09/15] fix: bound provider cache and pin idle regression --- web/scripts/cloud-vm/bench-vm-startup.mjs | 5 ++--- web/services/vms/drivers/freestyle.ts | 15 ++++++++++++--- web/tests/freestyle-request-timing.test.ts | 14 ++++++++++++++ 3 files changed, 28 insertions(+), 6 deletions(-) diff --git a/web/scripts/cloud-vm/bench-vm-startup.mjs b/web/scripts/cloud-vm/bench-vm-startup.mjs index 7f73d87e2a61..ef776e48e59c 100644 --- a/web/scripts/cloud-vm/bench-vm-startup.mjs +++ b/web/scripts/cloud-vm/bench-vm-startup.mjs @@ -372,14 +372,13 @@ async function runTrial(trial) { trial.imageVersion = created.imageVersion ?? null; trial.size = created.size?.name ?? null; Object.assign(trial, await rowUntilVisible(vmId)); + trial.createToRowReadyMs = elapsedMs(createStartedAt); Object.assign(trial, await attachUntilReady(vmId, "attach")); // Row polling is serialized before endpoint issuance. Use one monotonic // origin so the totals include both phases; endpoint issuance is not a // terminal-ready claim (bench-private-link.ts measures the real prompt). - trial.createToRowReadyMs = elapsedMs(createStartedAt); - trial.createToAttachReadyMs = undefined; - Object.assign(trial, await attachUntilReady(vmId, "warmAttach")); trial.createToAttachReadyMs = elapsedMs(createStartedAt); + Object.assign(trial, await attachUntilReady(vmId, "warmAttach")); if (!skipExec) { const exec = await fetchTimed(vmUrl(vmId, "/exec"), { method: "POST", diff --git a/web/services/vms/drivers/freestyle.ts b/web/services/vms/drivers/freestyle.ts index 59c40a2efd77..0840ebd2457b 100644 --- a/web/services/vms/drivers/freestyle.ts +++ b/web/services/vms/drivers/freestyle.ts @@ -188,6 +188,7 @@ export type FreestylePreconnectOptions = { readonly baseUrl?: string; readonly fetch?: typeof fetch; readonly timeoutMs?: number; + readonly now?: () => number; }; type FreestyleWarmupState = { promise?: Promise; succeeded?: boolean; succeededAtMs?: number }; @@ -196,6 +197,7 @@ const freestyleWarmupStates = new WeakMap; @@ -214,7 +216,7 @@ function warmupStateFor(fetchImpl: typeof fetch, baseUrl: string): FreestyleWarm } /** Performs the bounded same-origin probe that establishes the provider connection pool. */ -async function warmFreestyleConnection(options: Required): Promise { +async function warmFreestyleConnection(options: Required>): Promise { await options.fetch(`${options.baseUrl}/`, { method: "HEAD", signal: AbortSignal.timeout(options.timeoutMs), @@ -238,14 +240,15 @@ export function preconnectFreestyle(options: FreestylePreconnectOptions = {}): P const baseUrl = options.baseUrl?.trim() || process.env.FREESTYLE_API_URL?.trim() || "https://api.freestyle.sh"; const fetchImpl = options.fetch ?? fetch; const timeoutMs = options.timeoutMs ?? 3_000; + const now = options.now ?? Date.now; const state = warmupStateFor(fetchImpl, baseUrl); - if (state.succeeded && state.succeededAtMs !== undefined && Date.now() - state.succeededAtMs < FREESTYLE_WARMUP_REUSE_MS) { + if (state.succeeded && state.succeededAtMs !== undefined && now() - state.succeededAtMs < FREESTYLE_WARMUP_REUSE_MS) { return Promise.resolve(); } state.succeeded = undefined; if (state.promise) return state.promise; const promise = warmFreestyleConnection({ baseUrl, fetch: fetchImpl, timeoutMs }) - .then(() => { state.succeeded = true; state.succeededAtMs = Date.now(); }) + .then(() => { state.succeeded = true; state.succeededAtMs = now(); }) .catch(() => { state.succeeded = false; state.succeededAtMs = undefined; }); const settled = promise.finally(() => { if (state.promise === settled) state.promise = undefined; @@ -286,6 +289,12 @@ export function freestyleClient(timeoutMs = DEFAULT_TIMEOUT_MS): Freestyle { "freestyle requires FREESTYLE_API_KEY (or FREESTYLE_STACK_ACCESS_TOKEN + FREESTYLE_TEAM_ID)", ); } + // Exec accepts a caller-selected timeout; bound the account-wide wrapper + // cache so arbitrary timeout values cannot retain clients indefinitely. + if (clients.size >= FREESTYLE_CLIENT_CACHE_LIMIT) { + const oldest = clients.keys().next().value; + if (oldest !== undefined) clients.delete(oldest); + } clients.set(cacheKey, client); return client; } diff --git a/web/tests/freestyle-request-timing.test.ts b/web/tests/freestyle-request-timing.test.ts index 214fd0eeb8c4..d6f81103429b 100644 --- a/web/tests/freestyle-request-timing.test.ts +++ b/web/tests/freestyle-request-timing.test.ts @@ -28,6 +28,20 @@ describe("Freestyle enrollment request timings", () => { } }); + test("re-probes after the idle-pool reuse window", async () => { + let now = 0; + let calls = 0; + const fetch = (async () => { + calls += 1; + return new Response(null, { status: 204 }); + }) as typeof globalThis.fetch; + const options = { baseUrl: "https://provider-idle.example.test", fetch, now: () => now }; + await preconnectFreestyle(options); + now = 30_001; + await preconnectFreestyle(options); + expect(calls).toBe(2); + }); + test.each(["workflow", "init", "request"])("forwards %s cancellation alongside the provider timeout", async (source) => { const controller = new AbortController(); const reason = new DOMException("synthetic cancellation", "AbortError"); From 395c5a5e179c58c98c9ac63995e8d80ac1c52630 Mon Sep 17 00:00:00 2001 From: austinpower1258 Date: Tue, 29 Sep 2026 18:25:21 -0700 Subject: [PATCH 10/15] test: pin provider warm-up clock --- web/tests/freestyle-request-timing.test.ts | 3 +++ 1 file changed, 3 insertions(+) diff --git a/web/tests/freestyle-request-timing.test.ts b/web/tests/freestyle-request-timing.test.ts index d6f81103429b..1e4be0d6e5f7 100644 --- a/web/tests/freestyle-request-timing.test.ts +++ b/web/tests/freestyle-request-timing.test.ts @@ -5,6 +5,7 @@ import { freestyleRequestFetch, type FreestyleRequestTiming } from "../services/ describe("Freestyle enrollment request timings", () => { test("coalesces concurrent production connection warm-ups and keeps success sticky", async () => { const originalFetch = globalThis.fetch; + const originalNow = Date.now; let release!: () => void; const gate = new Promise(resolve => { release = resolve; }); let calls = 0; @@ -13,6 +14,7 @@ describe("Freestyle enrollment request timings", () => { await gate; return new Response(null, { status: 204 }); }) as typeof globalThis.fetch; + Date.now = () => 0; try { const first = preconnectFreestyle(); const second = preconnectFreestyle(); @@ -25,6 +27,7 @@ describe("Freestyle enrollment request timings", () => { expect(calls).toBe(1); } finally { globalThis.fetch = originalFetch; + Date.now = originalNow; } }); From 5c134467f2d21f34643a8d46c319ac0bba10b00c Mon Sep 17 00:00:00 2001 From: austinpower1258 Date: Tue, 29 Sep 2026 18:49:48 -0700 Subject: [PATCH 11/15] fix: preserve Cloud phase boundary timestamps --- web/app/api/vm/route.ts | 5 +++-- web/scripts/cloud-vm/bench-vm-startup.mjs | 8 ++++---- web/services/vms/drivers/freestyle.ts | 7 ++++--- web/services/vms/timings.ts | 6 +++--- web/tests/freestyle-request-timing.test.ts | 2 +- web/tests/vm-timings.test.ts | 9 +++++++++ 6 files changed, 24 insertions(+), 13 deletions(-) diff --git a/web/app/api/vm/route.ts b/web/app/api/vm/route.ts index 01c947040c6d..7b448697ca25 100644 --- a/web/app/api/vm/route.ts +++ b/web/app/api/vm/route.ts @@ -249,7 +249,7 @@ export async function POST(request: Request): Promise { // turn an authenticated create into an unbounded database health check. void databaseWarmup; const connectionInitDuration = freestyleWarmup.then( - () => performance.now() - warmupStartedAt, + () => ({ durationMs: performance.now() - warmupStartedAt, endedAtMs: Date.now() }), ); return withAuthedVmApiRoute( request, @@ -286,7 +286,8 @@ export async function POST(request: Request): Promise { captureVmProvisionOutcome({ userId: initialUser.id, operation: "create", response, span }); }); - timing.record("connection_init", await connectionInitDuration); + const connectionInit = await connectionInitDuration; + timing.record("connection_init", connectionInit.durationMs, { endedAtMs: connectionInit.endedAtMs }); // Admission starts after connection readiness. Its budget describes only // request validation; the durable begin_create phase is recorded inside // the workflow and remains a separate authoritative boundary. diff --git a/web/scripts/cloud-vm/bench-vm-startup.mjs b/web/scripts/cloud-vm/bench-vm-startup.mjs index ef776e48e59c..ac1faddd3739 100644 --- a/web/scripts/cloud-vm/bench-vm-startup.mjs +++ b/web/scripts/cloud-vm/bench-vm-startup.mjs @@ -228,7 +228,7 @@ function json(text) { const vmUrl = (vmId, tail = "") => `${targetUrl}/api/vm/${encodeURIComponent(vmId)}${tail}`; -/** Attach until the daemon answers; a 502 with `retryable` is the documented not-ready contract. */ +/** Request endpoint metadata until the attach contract is issued; this does not dial the daemon. */ async function attachUntilReady(vmId, stage) { const startedAt = performance.now(); const attempts = []; @@ -373,11 +373,11 @@ async function runTrial(trial) { trial.size = created.size?.name ?? null; Object.assign(trial, await rowUntilVisible(vmId)); trial.createToRowReadyMs = elapsedMs(createStartedAt); - Object.assign(trial, await attachUntilReady(vmId, "attach")); + Object.assign(trial, await attachUntilReady(vmId, "attachEndpoint")); // Row polling is serialized before endpoint issuance. Use one monotonic // origin so the totals include both phases; endpoint issuance is not a // terminal-ready claim (bench-private-link.ts measures the real prompt). - trial.createToAttachReadyMs = elapsedMs(createStartedAt); + trial.createToAttachEndpointMs = elapsedMs(createStartedAt); Object.assign(trial, await attachUntilReady(vmId, "warmAttach")); if (!skipExec) { const exec = await fetchTimed(vmUrl(vmId, "/exec"), { @@ -932,7 +932,7 @@ function emitReport({ results, listMs, startedAt, runError, cleanup }) { totalMs: startedAt === null ? null : elapsedMs(startedAt), succeeded: ok.length, failed: results.length - ok.length, - stages: summarizeFields(measured, ["createMs", "rowReadyMs", "createToRowReadyMs", "attachMs", "createToAttachReadyMs", "warmAttachMs", "execMs", "edgeReadyMs", "pauseMs", "resumeAttachMs", "destroyMs"]), + stages: summarizeFields(measured, ["createMs", "rowReadyMs", "createToRowReadyMs", "attachEndpointMs", "createToAttachEndpointMs", "warmAttachMs", "execMs", "edgeReadyMs", "pauseMs", "resumeAttachMs", "destroyMs"]), attachAttempts: summarizeFields(measured.map((trial) => ({ attempts: trial.attachAttempts?.length })), ["attempts"]).attempts, createServerTiming: summarizeStages(measured.map((trial) => trial.createStages)), results, diff --git a/web/services/vms/drivers/freestyle.ts b/web/services/vms/drivers/freestyle.ts index 0840ebd2457b..0fb95f3bc6c7 100644 --- a/web/services/vms/drivers/freestyle.ts +++ b/web/services/vms/drivers/freestyle.ts @@ -194,9 +194,10 @@ export type FreestylePreconnectOptions = { type FreestyleWarmupState = { promise?: Promise; succeeded?: boolean; succeededAtMs?: number }; const freestyleWarmupStates = new WeakMap>(); -// Keep a successful probe only for the provider's normal idle-pool window; -// after a longer suspension the next Cloud request probes again. -const FREESTYLE_WARMUP_REUSE_MS = 30_000; +// Undici's default global-fetch idle pool expires around four seconds. Keep a +// successful probe for less than that, so an idle Cloud path probes again +// before the next provider call rather than trusting a closed socket. +const FREESTYLE_WARMUP_REUSE_MS = 3_000; const FREESTYLE_CLIENT_CACHE_LIMIT = 8; const globalForFreestyle = globalThis as typeof globalThis & { diff --git a/web/services/vms/timings.ts b/web/services/vms/timings.ts index 537e4c5990c2..d574a7f6c203 100644 --- a/web/services/vms/timings.ts +++ b/web/services/vms/timings.ts @@ -22,7 +22,7 @@ export type VmTimingStage = | "total"; export type VmTimingSink = { - readonly record: (stage: VmTimingStage, durationMs: number) => void; + readonly record: (stage: VmTimingStage, durationMs: number, options?: { readonly endedAtMs?: number }) => void; }; export class VmTimingRecorder implements VmTimingSink { @@ -41,11 +41,11 @@ export class VmTimingRecorder implements VmTimingSink { this.debugTimings = options.debugTimings ?? process.env.CMUX_VM_DEBUG_TIMINGS === "1"; } - record(stage: VmTimingStage, durationMs: number): void { + record(stage: VmTimingStage, durationMs: number, options: { readonly endedAtMs?: number } = {}): void { const duration = roundedMs(durationMs); // Keep wall-clock boundaries alongside monotonic durations so an operator // can line up a slow create with provider logs and request IDs in Axiom. - const endedAtMs = Date.now(); + const endedAtMs = options.endedAtMs ?? Date.now(); const startedAtMs = endedAtMs - Math.max(0, Math.round(duration)); const startKey = `cmux.vm.timing.${stage}_started_at_ms`; const endKey = `cmux.vm.timing.${stage}_ended_at_ms`; diff --git a/web/tests/freestyle-request-timing.test.ts b/web/tests/freestyle-request-timing.test.ts index 1e4be0d6e5f7..7425f74790b6 100644 --- a/web/tests/freestyle-request-timing.test.ts +++ b/web/tests/freestyle-request-timing.test.ts @@ -40,7 +40,7 @@ describe("Freestyle enrollment request timings", () => { }) as typeof globalThis.fetch; const options = { baseUrl: "https://provider-idle.example.test", fetch, now: () => now }; await preconnectFreestyle(options); - now = 30_001; + now = 3_001; await preconnectFreestyle(options); expect(calls).toBe(2); }); diff --git a/web/tests/vm-timings.test.ts b/web/tests/vm-timings.test.ts index d763823ba99d..e3b1ff6d2bc1 100644 --- a/web/tests/vm-timings.test.ts +++ b/web/tests/vm-timings.test.ts @@ -56,4 +56,13 @@ describe("VM timing helpers", () => { expect(attributes.filter((attribute) => attribute.key === "cmux.vm.timing.total_ms")).toHaveLength(1); expect(attributes.filter((attribute) => attribute.key === "cmux.vm.timing.total_count")).toHaveLength(1); }); + + test("accepts the phase end timestamp when work settles before its caller records it", () => { + const attributes: Array<{ key: string; value: unknown }> = []; + const span = { setAttribute: (key: string, value: unknown) => attributes.push({ key, value }) } as unknown as Span; + const recorder = new VmTimingRecorder(span, "create", { debugTimings: false }); + recorder.record("connection_init", 20, { endedAtMs: 1_500 }); + expect(attributes.find((attribute) => attribute.key === "cmux.vm.timing.connection_init_ended_at_ms")?.value).toBe(1_500); + expect(attributes.find((attribute) => attribute.key === "cmux.vm.timing.connection_init_started_at_ms")?.value).toBe(1_480); + }); }); From 505b959b37aaad363cbfcee0404e9b2a41c10852 Mon Sep 17 00:00:00 2001 From: austinpower1258 Date: Tue, 29 Sep 2026 18:59:03 -0700 Subject: [PATCH 12/15] fix: clamp warm-up age after clock rollback --- web/services/vms/drivers/freestyle.ts | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/web/services/vms/drivers/freestyle.ts b/web/services/vms/drivers/freestyle.ts index 0fb95f3bc6c7..9f5e791adaba 100644 --- a/web/services/vms/drivers/freestyle.ts +++ b/web/services/vms/drivers/freestyle.ts @@ -243,7 +243,8 @@ export function preconnectFreestyle(options: FreestylePreconnectOptions = {}): P const timeoutMs = options.timeoutMs ?? 3_000; const now = options.now ?? Date.now; const state = warmupStateFor(fetchImpl, baseUrl); - if (state.succeeded && state.succeededAtMs !== undefined && now() - state.succeededAtMs < FREESTYLE_WARMUP_REUSE_MS) { + const warmupAgeMs = state.succeededAtMs === undefined ? undefined : Math.max(0, now() - state.succeededAtMs); + if (state.succeeded && warmupAgeMs !== undefined && warmupAgeMs < FREESTYLE_WARMUP_REUSE_MS) { return Promise.resolve(); } state.succeeded = undefined; From c305d66916fed016e27ca859cfc87f553b687bfe Mon Sep 17 00:00:00 2001 From: austinpower1258 Date: Tue, 29 Sep 2026 22:03:45 -0700 Subject: [PATCH 13/15] test: use authoritative Cloud VM row readiness --- web/scripts/cloud-vm/bench-vm-startup.mjs | 64 ++++++++++------------- web/tests/vm-route-auth.test.ts | 5 ++ 2 files changed, 33 insertions(+), 36 deletions(-) diff --git a/web/scripts/cloud-vm/bench-vm-startup.mjs b/web/scripts/cloud-vm/bench-vm-startup.mjs index ac1faddd3739..28264d8c2658 100644 --- a/web/scripts/cloud-vm/bench-vm-startup.mjs +++ b/web/scripts/cloud-vm/bench-vm-startup.mjs @@ -271,40 +271,32 @@ async function attachUntilReady(vmId, stage) { } } -/** Polls the authoritative VM list until the newly created durable row is visible. */ -async function rowUntilVisible(vmId) { +/** Reads the authoritative VM row after create; the detail endpoint is the completion signal. */ +async function readAuthoritativeRow(vmId) { const startedAt = performance.now(); - const attempts = []; - for (;;) { - const elapsed = performance.now() - startedAt; - if (elapsed >= ROW_READY_BUDGET_MS || interrupted) { - throw new Error(`VM row for ${vmId} did not become visible within ${ROW_READY_BUDGET_MS} ms (${attempts.length} attempts)`); - } - const remainingMs = ROW_READY_BUDGET_MS - (performance.now() - startedAt); - const response = await fetchTimed( - `${targetUrl}/api/vm`, - { headers: authHeaders }, - Math.min(REQUEST_TIMEOUT_MS, remainingMs), - ); - const body = json(response.text); - attempts.push({ status: response.status, ms: response.ms }); - if (response.status === 200) { - const row = (body.vms ?? []).find((entry) => entry?.id === vmId); - if (row?.status === "failed") { - throw new Error(`VM row for ${vmId} became failed while waiting for readiness`); - } - if (row?.status === "running") { - return { - rowReadyMs: elapsedMs(startedAt), - rowReadyStatus: row.status ?? null, - rowReadyAttempts: attempts, - }; - } - } else if (response.status >= 500) { - throw new Error(`VM row list failed while waiting for ${vmId}: ${response.status} ${response.text.slice(0, 300)}`); - } - await sleep(Math.min(remainingMs, 250)); + if (interrupted) throw new Error(`VM row for ${vmId} was interrupted before readiness`); + const response = await fetchTimed( + vmUrl(vmId), + { headers: authHeaders }, + Math.min(REQUEST_TIMEOUT_MS, ROW_READY_BUDGET_MS), + ); + const body = json(response.text); + const attempt = { status: response.status, ms: response.ms }; + if (response.status !== 200) { + throw new Error(`VM row for ${vmId} was not readable after create: ${response.status} ${response.text.slice(0, 300)}`); + } + if (body.status === "failed") { + throw new Error(`VM row for ${vmId} became failed while waiting for readiness`); + } + if (body.id !== vmId || body.status !== "running") { + throw new Error(`VM row for ${vmId} was not running after create: ${response.text.slice(0, 300)}`); } + return { + rowReadyMs: elapsedMs(startedAt), + rowReadyStatus: body.status, + rowReadyAttempts: [attempt], + rowReadySource: "detail", + }; } /** Time from the first probe until the edge alias answers with an HTTP status (any status proves injection). */ @@ -371,12 +363,12 @@ async function runTrial(trial) { trial.vmId = vmId; trial.imageVersion = created.imageVersion ?? null; trial.size = created.size?.name ?? null; - Object.assign(trial, await rowUntilVisible(vmId)); + Object.assign(trial, await readAuthoritativeRow(vmId)); trial.createToRowReadyMs = elapsedMs(createStartedAt); Object.assign(trial, await attachUntilReady(vmId, "attachEndpoint")); - // Row polling is serialized before endpoint issuance. Use one monotonic - // origin so the totals include both phases; endpoint issuance is not a - // terminal-ready claim (bench-private-link.ts measures the real prompt). + // The authoritative row read is serialized before endpoint issuance. Use + // one monotonic origin so totals include both phases; endpoint issuance is + // not a terminal-ready claim (bench-private-link.ts measures the prompt). trial.createToAttachEndpointMs = elapsedMs(createStartedAt); Object.assign(trial, await attachUntilReady(vmId, "warmAttach")); if (!skipExec) { diff --git a/web/tests/vm-route-auth.test.ts b/web/tests/vm-route-auth.test.ts index dd1923f9752d..6af61c33304d 100644 --- a/web/tests/vm-route-auth.test.ts +++ b/web/tests/vm-route-auth.test.ts @@ -74,6 +74,7 @@ const VM_ENV_KEYS = [ const originalEnv = Object.fromEntries( VM_ENV_KEYS.map((key) => [key, process.env[key]]), ) as Record<(typeof VM_ENV_KEYS)[number], string | undefined>; +const originalFetch = globalThis.fetch; // Capture the real implementations BY VALUE before mocking. bun's // mock.module can mutate an already-loaded module namespace in place, so a @@ -247,11 +248,15 @@ const { VmPublicationProviderError } = await import( beforeAll(() => { useWorkflowStubs = true; useStubDb = true; + // POST /api/vm now awaits the provider connection probe. Keep this route + // suite deterministic and local while still exercising that await. + globalThis.fetch = (async () => new Response(null, { status: 204 })) as typeof globalThis.fetch; }); afterAll(() => { useWorkflowStubs = false; useStubDb = false; + globalThis.fetch = originalFetch; }); beforeEach(() => { From b28eb75ef4c760177cf8934961ee2cf416a8fb6e Mon Sep 17 00:00:00 2001 From: Austin Wang <38676809+austinywang@users.noreply.github.com> Date: Fri, 2 Oct 2026 03:28:40 -0700 Subject: [PATCH 14/15] fix(cloud): authenticate before provider warm-up --- web/app/api/vm/route.ts | 18 ++++++++++-------- 1 file changed, 10 insertions(+), 8 deletions(-) diff --git a/web/app/api/vm/route.ts b/web/app/api/vm/route.ts index 7b448697ca25..231f4ac7fc57 100644 --- a/web/app/api/vm/route.ts +++ b/web/app/api/vm/route.ts @@ -240,17 +240,10 @@ export async function GET(request: Request): Promise { } export async function POST(request: Request): Promise { - // Warm the Freestyle and database connections while the caller is being verified. - const warmupStartedAt = performance.now(); - const freestyleWarmup = preconnectFreestyle(); - const databaseWarmup = preconnectCloudDb(); // Database warming is an optimization only: its driver may wait on a // provider-controlled connect deadline, so it must never delay validation or // turn an authenticated create into an unbounded database health check. - void databaseWarmup; - const connectionInitDuration = freestyleWarmup.then( - () => ({ durationMs: performance.now() - warmupStartedAt, endedAtMs: Date.now() }), - ); + void preconnectCloudDb(); return withAuthedVmApiRoute( request, "/api/vm", @@ -259,6 +252,15 @@ export async function POST(request: Request): Promise { async ({ user: initialUser, span, authDurationMs, routeStartedAtMs, setResponseFinalizer }) => { const timing = new VmTimingRecorder(span, "create", { startedAt: routeStartedAtMs }); timing.record("auth", authDurationMs); + // Start the provider probe only after authentication. It is shared by + // concurrent creates, so the first authenticated request pays the cold + // connection once and unauthenticated traffic cannot consume provider + // capacity. The await below is bounded by the probe's own timeout. + const warmupStartedAt = performance.now(); + const freestyleWarmup = preconnectFreestyle(); + const connectionInitDuration = freestyleWarmup.then( + () => ({ durationMs: performance.now() - warmupStartedAt, endedAtMs: Date.now() }), + ); let admissionRecorded = false; let admissionStartedAt = performance.now(); /** Records request validation even when it exits before provisioning. */ From cb698ea7618042899555fad3e00bfae58b23f23c Mon Sep 17 00:00:00 2001 From: Austin Wang <38676809+austinywang@users.noreply.github.com> Date: Fri, 2 Oct 2026 03:42:08 -0700 Subject: [PATCH 15/15] fix(cloud): scope warm-up to selected provider --- web/app/api/vm/route.ts | 19 ++++++++++++------- web/scripts/cloud-vm/bench-vm-startup.mjs | 2 +- 2 files changed, 13 insertions(+), 8 deletions(-) diff --git a/web/app/api/vm/route.ts b/web/app/api/vm/route.ts index 231f4ac7fc57..53c0e3449fa7 100644 --- a/web/app/api/vm/route.ts +++ b/web/app/api/vm/route.ts @@ -288,13 +288,6 @@ export async function POST(request: Request): Promise { captureVmProvisionOutcome({ userId: initialUser.id, operation: "create", response, span }); }); - const connectionInit = await connectionInitDuration; - timing.record("connection_init", connectionInit.durationMs, { endedAtMs: connectionInit.endedAtMs }); - // Admission starts after connection readiness. Its budget describes only - // request validation; the durable begin_create phase is recorded inside - // the workflow and remains a separate authoritative boundary. - admissionStartedAt = performance.now(); - const parsed = await parseCreateRequest(request, span, timing); if (!parsed.ok) return parsed.response; const { candidate, body, idempotencyKey } = parsed; @@ -331,6 +324,18 @@ export async function POST(request: Request): Promise { "cmux.vm.image_size": imageSelection.size?.name ?? "size-less", "cmux.idempotency_key_set": !!idempotencyKey, }); + + // Only Freestyle creation needs this probe. Other providers must not + // wait behind an unrelated connection check, while the Freestyle path + // still overlaps the probe with authentication and request parsing. + if (provider === "freestyle") { + const connectionInit = await connectionInitDuration; + timing.record("connection_init", connectionInit.durationMs, { endedAtMs: connectionInit.endedAtMs }); + } + // Admission starts after provider-specific connection readiness. Its + // budget describes only request validation; the durable begin_create + // phase is recorded inside the workflow and remains authoritative. + admissionStartedAt = performance.now(); recordAdmission(); // Wire the machine to coderouter inside the workflow: the route token diff --git a/web/scripts/cloud-vm/bench-vm-startup.mjs b/web/scripts/cloud-vm/bench-vm-startup.mjs index 28264d8c2658..3da3adf00a97 100644 --- a/web/scripts/cloud-vm/bench-vm-startup.mjs +++ b/web/scripts/cloud-vm/bench-vm-startup.mjs @@ -925,7 +925,7 @@ function emitReport({ results, listMs, startedAt, runError, cleanup }) { succeeded: ok.length, failed: results.length - ok.length, stages: summarizeFields(measured, ["createMs", "rowReadyMs", "createToRowReadyMs", "attachEndpointMs", "createToAttachEndpointMs", "warmAttachMs", "execMs", "edgeReadyMs", "pauseMs", "resumeAttachMs", "destroyMs"]), - attachAttempts: summarizeFields(measured.map((trial) => ({ attempts: trial.attachAttempts?.length })), ["attempts"]).attempts, + attachAttempts: summarizeFields(measured.map((trial) => ({ attempts: trial.attachEndpointAttempts?.length })), ["attempts"]).attempts, createServerTiming: summarizeStages(measured.map((trial) => trial.createStages)), results, };