diff --git a/apps/web/src/components/SlowRpcRequestToastCoordinator.tsx b/apps/web/src/components/SlowRpcRequestToastCoordinator.tsx index 07711ca84b7..f5391c13aba 100644 --- a/apps/web/src/components/SlowRpcRequestToastCoordinator.tsx +++ b/apps/web/src/components/SlowRpcRequestToastCoordinator.tsx @@ -5,7 +5,10 @@ import { toastManager } from "./ui/toast"; function describeSlowRequests(requests: ReadonlyArray): string { const count = requests.length; - const thresholdSeconds = Math.round((requests[0]?.thresholdMs ?? 0) / 1000); + // Thresholds vary per method, so report the smallest one the batch has passed. + const thresholdSeconds = Math.round( + Math.min(...requests.map((request) => request.thresholdMs)) / 1000, + ); return `${count} request${count === 1 ? "" : "s"} waiting longer than ${thresholdSeconds}s.`; } diff --git a/apps/web/src/connection/platform.ts b/apps/web/src/connection/platform.ts index 56d25fa142e..c7652136f54 100644 --- a/apps/web/src/connection/platform.ts +++ b/apps/web/src/connection/platform.ts @@ -590,7 +590,7 @@ const rpcRequestObserverLayer = Layer.succeed( Effect.sync(() => { nextObservedRpcRequestId += 1; const requestId = `${environmentId}:${nextObservedRpcRequestId}`; - trackRpcRequestSent(requestId, `${method} · ${environmentId}`); + trackRpcRequestSent(requestId, method, `${method} · ${environmentId}`); return Effect.sync(() => { acknowledgeRpcRequest(requestId); }); diff --git a/apps/web/src/rpc/requestLatencyState.test.ts b/apps/web/src/rpc/requestLatencyState.test.ts index 504c93e1f78..e5b3144d252 100644 --- a/apps/web/src/rpc/requestLatencyState.test.ts +++ b/apps/web/src/rpc/requestLatencyState.test.ts @@ -6,6 +6,7 @@ import { getSlowRpcAckRequests, resetRequestLatencyStateForTests, trackRpcRequestSent, + LONG_RUNNING_RPC_ACK_THRESHOLD_MS, SLOW_RPC_ACK_THRESHOLD_MS, MAX_TRACKED_RPC_ACK_REQUESTS, } from "./requestLatencyState"; @@ -58,6 +59,32 @@ describe("requestLatencyState", () => { expect(getSlowRpcAckRequests()).toEqual([]); }); + it("keeps ignoring untracked methods when a display tag is supplied", () => { + trackRpcRequestSent( + "1", + WS_METHODS.previewAutomationConnect, + `${WS_METHODS.previewAutomationConnect} · env-1`, + ); + vi.advanceTimersByTime(SLOW_RPC_ACK_THRESHOLD_MS * 2); + + expect(getSlowRpcAckRequests()).toEqual([]); + }); + + it("gives provider updates a longer threshold before warning", () => { + trackRpcRequestSent("1", WS_METHODS.serverUpdateProvider, "server.updateProvider · env-1"); + vi.advanceTimersByTime(LONG_RUNNING_RPC_ACK_THRESHOLD_MS - 1); + expect(getSlowRpcAckRequests()).toEqual([]); + + vi.advanceTimersByTime(1); + expect(getSlowRpcAckRequests()).toMatchObject([ + { + requestId: "1", + tag: "server.updateProvider · env-1", + thresholdMs: LONG_RUNNING_RPC_ACK_THRESHOLD_MS, + }, + ]); + }); + it("evicts the oldest pending requests once the tracker reaches capacity", () => { for (let index = 0; index < MAX_TRACKED_RPC_ACK_REQUESTS + 1; index += 1) { trackRpcRequestSent(String(index), "server.getConfig"); diff --git a/apps/web/src/rpc/requestLatencyState.ts b/apps/web/src/rpc/requestLatencyState.ts index c30ffc88279..4736d3783c3 100644 --- a/apps/web/src/rpc/requestLatencyState.ts +++ b/apps/web/src/rpc/requestLatencyState.ts @@ -5,6 +5,12 @@ import { Atom } from "effect/unstable/reactivity"; import { appAtomRegistry } from "./atomRegistry"; export const SLOW_RPC_ACK_THRESHOLD_MS = 15_000; +/** + * Some requests are slow by design — they shell out to a package manager on the + * server and only respond once the install finishes. Warning about those after + * 15s is noise, so they get a much longer leash. + */ +export const LONG_RUNNING_RPC_ACK_THRESHOLD_MS = 120_000; export const MAX_TRACKED_RPC_ACK_REQUESTS = 256; let slowRpcAckThresholdMs = SLOW_RPC_ACK_THRESHOLD_MS; @@ -22,7 +28,12 @@ interface PendingRpcAckRequest { } const pendingRpcAckRequests = new Map(); -const untrackedRpcAckTags = new Set([WS_METHODS.previewAutomationConnect]); +const untrackedRpcAckMethods = new Set([WS_METHODS.previewAutomationConnect]); +const longRunningRpcAckMethods = new Set([ + WS_METHODS.serverUpdateProvider, + WS_METHODS.serverRefreshProviders, + WS_METHODS.serverUpdateServer, +]); const slowRpcAckRequestsAtom = Atom.make>([]).pipe( Atom.keepAlive, @@ -37,16 +48,27 @@ function getSlowRpcAckRequestsValue(): ReadonlyArray { return appAtomRegistry.get(slowRpcAckRequestsAtom); } -function shouldTrackRpcAck(tag: string): boolean { - return !tag.includes("subscribe") && !untrackedRpcAckTags.has(tag); +function shouldTrackRpcAck(method: string): boolean { + return !method.includes("subscribe") && !untrackedRpcAckMethods.has(method); +} + +function rpcAckThresholdMs(method: string): number { + return longRunningRpcAckMethods.has(method) + ? Math.max(slowRpcAckThresholdMs, LONG_RUNNING_RPC_ACK_THRESHOLD_MS) + : slowRpcAckThresholdMs; } export function getSlowRpcAckRequests(): ReadonlyArray { return getSlowRpcAckRequestsValue(); } -export function trackRpcRequestSent(requestId: string, tag: string): void { - if (!shouldTrackRpcAck(tag)) { +/** + * Starts the slow-request timer for one in-flight unary RPC. `method` is the + * bare WS method (used to decide whether and how long to wait); `tag` is the + * human-readable label shown in the toast, which defaults to the method. + */ +export function trackRpcRequestSent(requestId: string, method: string, tag = method): void { + if (!shouldTrackRpcAck(method)) { return; } @@ -54,17 +76,18 @@ export function trackRpcRequestSent(requestId: string, tag: string): void { evictOldestPendingRpcRequestIfNeeded(); const startedAtMs = Date.now(); + const thresholdMs = rpcAckThresholdMs(method); const request: SlowRpcAckRequest = { requestId, startedAt: new Date(startedAtMs).toISOString(), startedAtMs, tag, - thresholdMs: slowRpcAckThresholdMs, + thresholdMs, }; const timeoutId = setTimeout(() => { pendingRpcAckRequests.delete(requestId); appendSlowRpcAckRequest(request); - }, slowRpcAckThresholdMs); + }, thresholdMs); pendingRpcAckRequests.set(requestId, { request,