fix: harden workbench trace timeout observability

This commit is contained in:
lyon
2026-06-20 01:16:45 +08:00
parent faca69ec01
commit 8f9bdbd5fd
5 changed files with 185 additions and 46 deletions
+95 -37
View File
@@ -21,45 +21,49 @@ const DEFAULT_SESSION_LIST_LIMIT = 20;
const MAX_PAGE_LIMIT = 100;
const DEFAULT_WORKBENCH_SSE_HEARTBEAT_MS = 15000;
export async function handleWorkbenchReadModelHttp(request, response, url, options = {}) {
const perf = options.backendPerformance;
const auth = perf ? await perf.measure("workbench_auth", () => authenticateWorkbenchRead(request, response, options)) : await authenticateWorkbenchRead(request, response, options);
if (!auth) return;
try {
const perf = options.backendPerformance;
const auth = perf ? await perf.measure("workbench_auth", () => authenticateWorkbenchRead(request, response, options)) : await authenticateWorkbenchRead(request, response, options);
if (!auth) return;
if (url.pathname === "/v1/workbench/sessions") {
if (request.method !== "GET") return methodNotAllowed(response, "GET");
await (perf ? perf.measure("workbench_session_list", () => handleWorkbenchSessionList(response, url, options, auth.actor)) : handleWorkbenchSessionList(response, url, options, auth.actor));
return;
if (url.pathname === "/v1/workbench/sessions") {
if (request.method !== "GET") return methodNotAllowed(response, "GET");
await (perf ? perf.measure("workbench_session_list", () => handleWorkbenchSessionList(response, url, options, auth.actor)) : handleWorkbenchSessionList(response, url, options, auth.actor));
return;
}
const sessionMessagesMatch = url.pathname.match(/^\/v1\/workbench\/sessions\/([^/]+)\/messages$/u);
if (sessionMessagesMatch) {
if (request.method !== "GET") return methodNotAllowed(response, "GET");
await (perf ? perf.measure("workbench_message_page", () => handleWorkbenchMessagePage(response, url, options, auth.actor, decodeURIComponent(sessionMessagesMatch[1]))) : handleWorkbenchMessagePage(response, url, options, auth.actor, decodeURIComponent(sessionMessagesMatch[1])));
return;
}
const sessionMatch = url.pathname.match(/^\/v1\/workbench\/sessions\/([^/]+)$/u);
if (sessionMatch) {
if (request.method !== "GET") return methodNotAllowed(response, "GET");
await (perf ? perf.measure("workbench_session_detail", () => handleWorkbenchSessionDetail(response, options, auth.actor, decodeURIComponent(sessionMatch[1]))) : handleWorkbenchSessionDetail(response, options, auth.actor, decodeURIComponent(sessionMatch[1])));
return;
}
const turnMatch = url.pathname.match(/^\/v1\/workbench\/turns\/([^/]+)$/u);
if (turnMatch) {
if (request.method !== "GET") return methodNotAllowed(response, "GET");
await (perf ? perf.measure("workbench_turn_snapshot", () => handleWorkbenchTurnSnapshot(response, url, options, auth.actor, decodeURIComponent(turnMatch[1]))) : handleWorkbenchTurnSnapshot(response, url, options, auth.actor, decodeURIComponent(turnMatch[1])));
return;
}
const traceEventsMatch = url.pathname.match(/^\/v1\/workbench\/traces\/([^/]+)\/events$/u);
if (traceEventsMatch) {
if (request.method !== "GET") return methodNotAllowed(response, "GET");
await (perf ? perf.measure("workbench_trace_events", () => handleWorkbenchTraceEventPage(response, url, options, auth.actor, decodeURIComponent(traceEventsMatch[1]))) : handleWorkbenchTraceEventPage(response, url, options, auth.actor, decodeURIComponent(traceEventsMatch[1])));
return;
}
sendJson(response, 404, workbenchError("workbench_route_not_found", "Workbench read model route is not implemented.", { route: url.pathname }));
} catch (error) {
handleWorkbenchReadModelFailure(response, url, options, error);
}
const sessionMessagesMatch = url.pathname.match(/^\/v1\/workbench\/sessions\/([^/]+)\/messages$/u);
if (sessionMessagesMatch) {
if (request.method !== "GET") return methodNotAllowed(response, "GET");
await (perf ? perf.measure("workbench_message_page", () => handleWorkbenchMessagePage(response, url, options, auth.actor, decodeURIComponent(sessionMessagesMatch[1]))) : handleWorkbenchMessagePage(response, url, options, auth.actor, decodeURIComponent(sessionMessagesMatch[1])));
return;
}
const sessionMatch = url.pathname.match(/^\/v1\/workbench\/sessions\/([^/]+)$/u);
if (sessionMatch) {
if (request.method !== "GET") return methodNotAllowed(response, "GET");
await (perf ? perf.measure("workbench_session_detail", () => handleWorkbenchSessionDetail(response, options, auth.actor, decodeURIComponent(sessionMatch[1]))) : handleWorkbenchSessionDetail(response, options, auth.actor, decodeURIComponent(sessionMatch[1])));
return;
}
const turnMatch = url.pathname.match(/^\/v1\/workbench\/turns\/([^/]+)$/u);
if (turnMatch) {
if (request.method !== "GET") return methodNotAllowed(response, "GET");
await (perf ? perf.measure("workbench_turn_snapshot", () => handleWorkbenchTurnSnapshot(response, url, options, auth.actor, decodeURIComponent(turnMatch[1]))) : handleWorkbenchTurnSnapshot(response, url, options, auth.actor, decodeURIComponent(turnMatch[1])));
return;
}
const traceEventsMatch = url.pathname.match(/^\/v1\/workbench\/traces\/([^/]+)\/events$/u);
if (traceEventsMatch) {
if (request.method !== "GET") return methodNotAllowed(response, "GET");
await (perf ? perf.measure("workbench_trace_events", () => handleWorkbenchTraceEventPage(response, url, options, auth.actor, decodeURIComponent(traceEventsMatch[1]))) : handleWorkbenchTraceEventPage(response, url, options, auth.actor, decodeURIComponent(traceEventsMatch[1])));
return;
}
sendJson(response, 404, workbenchError("workbench_route_not_found", "Workbench read model route is not implemented.", { route: url.pathname }));
}
export async function handleWorkbenchRealtimeHttp(request, response, url, options = {}) {
@@ -1024,6 +1028,60 @@ function canActorReadOwner(ownerUserId, actor) {
return ownerUserId === actor.id;
}
function handleWorkbenchReadModelFailure(response, url, options = {}, error) {
const classified = classifyWorkbenchReadModelFailure(error);
const route = workbenchReadRouteTemplate(url?.pathname ?? "/v1/workbench");
logWorkbenchReadModelFailure(options.logger ?? console, {
event: "workbench_read_model_route_failed",
ok: false,
route,
statusCode: classified.statusCode,
errorCode: classified.code,
errorName: error?.name ?? "Error",
message: error instanceof Error ? error.message : String(error ?? "unknown"),
valuesRedacted: true
});
if (response.headersSent || response.destroyed) return;
sendJson(response, classified.statusCode, workbenchError(classified.code, classified.message, { route, errorName: error?.name ?? "Error" }));
}
function classifyWorkbenchReadModelFailure(error) {
const message = String(error?.message ?? error ?? "");
const code = String(error?.code ?? "").toLowerCase();
if (/timeout|connection terminated|terminating connection|econnreset|econnrefused|etimedout/iu.test(message) || /timeout|econnreset|econnrefused|etimedout/u.test(code)) {
return {
statusCode: 503,
code: "workbench_read_model_store_unavailable",
message: "Workbench read model store is temporarily unavailable."
};
}
return {
statusCode: 500,
code: "workbench_read_model_failed",
message: "Workbench read model failed."
};
}
function workbenchReadRouteTemplate(pathname) {
const path = String(pathname ?? "");
if (path === "/v1/workbench/sessions") return path;
if (/^\/v1\/workbench\/sessions\/[^/]+\/messages$/u.test(path)) return "/v1/workbench/sessions/:id/messages";
if (/^\/v1\/workbench\/sessions\/[^/]+$/u.test(path)) return "/v1/workbench/sessions/:id";
if (/^\/v1\/workbench\/turns\/[^/]+$/u.test(path)) return "/v1/workbench/turns/:id";
if (/^\/v1\/workbench\/traces\/[^/]+\/events$/u.test(path)) return "/v1/workbench/traces/:id/events";
return path || "/v1/workbench";
}
function logWorkbenchReadModelFailure(logger, payload) {
try {
const line = JSON.stringify(payload);
if (typeof logger?.error === "function") logger.error(line);
else if (typeof logger?.warn === "function") logger.warn(line);
} catch {
// Read-model failure logging must not affect response generation.
}
}
function methodNotAllowed(response, allowed) {
sendJson(response, 405, workbenchError("method_not_allowed", `Use ${allowed} for this Workbench read model route.`));
}
+48 -1
View File
@@ -5,7 +5,7 @@ import assert from "node:assert/strict";
import { test } from "bun:test";
import { createCloudApiServer } from "./server.ts";
import { createWebPerformanceStore, webPerformanceRouteTemplate } from "./web-performance.ts";
import { createWebPerformanceStore, emitWorkbenchUiOtelSpans, webPerformanceRouteTemplate } from "./web-performance.ts";
test("web performance store aggregates browser-perceived durations as Prometheus histograms", () => {
const store = createWebPerformanceStore({ env: { HWLAB_METRICS_NAMESPACE: "hwlab-v02", HWLAB_GITOPS_TARGET: "v02" } });
@@ -202,6 +202,53 @@ test("web performance store accepts Workbench UI lifecycle events without high-c
assert.doesNotMatch(text, /ses_secret|trc_secret|ui_secret|0123456789abcdef|sessionId|traceId|otelTraceId|prompt|api key/iu);
});
test("Workbench UI OTel spans include timeout activity diagnostics without raw trace ids", async () => {
const calls: any[] = [];
const originalFetch = globalThis.fetch;
globalThis.fetch = async (_url: string | URL | Request, init?: RequestInit) => {
calls.push(JSON.parse(String(init?.body ?? "{}")));
return new Response(null, { status: 200 });
};
try {
const result = await emitWorkbenchUiOtelSpans({
schemaVersion: "hwlab-web-performance-v2",
page: "/workbench/sessions/ses_secret",
events: [{
kind: "workbench_ui_event",
eventType: "api_request",
loadingScope: "api",
state: "request",
reason: "api_request",
route: "/v1/workbench/turns/trc_secret",
method: "GET",
status: 0,
outcome: "timeout",
valueMs: 8001,
uiTraceId: "ui_secret",
otelTraceId: "0123456789abcdef0123456789abcdef",
timeoutName: "workbench turn",
activityWaitingFor: "code-agent",
activityLastEventLabel: "realtime:heartbeat",
activityIdleMs: 13042,
traceId: "trc_secret"
}]
} as Record<string, unknown>, { OTEL_EXPORTER_OTLP_TRACES_ENDPOINT: "http://otel.example/v1/traces" });
assert.equal(result.submitted, 1);
assert.equal(calls.length, 1);
const span = calls[0].resourceSpans[0].scopeSpans[0].spans[0];
const attrs = Object.fromEntries(span.attributes.map((item: any) => [item.key, item.value.stringValue ?? Number(item.value.intValue) ?? item.value.boolValue]));
assert.equal(attrs["http.route"], "/v1/workbench/turns/:id");
assert.equal(attrs["workbench.ui.timeout_name"], "workbench turn");
assert.equal(attrs["workbench.ui.activity_waiting_for"], "code-agent");
assert.equal(attrs["workbench.ui.activity_last_event_label"], "realtime:heartbeat");
assert.equal(attrs["workbench.ui.activity_idle_ms"], 13042);
assert.doesNotMatch(JSON.stringify(calls[0]), /trc_secret|ses_secret|prompt|api key/iu);
} finally {
globalThis.fetch = originalFetch;
}
});
test("web performance store drops unsupported Workbench labels and counts series limit drops", () => {
const store = createWebPerformanceStore({ env: { HWLAB_METRICS_NAMESPACE: "hwlab-v03", HWLAB_GITOPS_TARGET: "v03" }, maxSeries: 1 });
const first = store.record({
+12
View File
@@ -112,6 +112,10 @@ interface WebPerformanceEvent {
startedAtEpochMs?: unknown;
endedAtEpochMs?: unknown;
errorName?: unknown;
timeoutName?: unknown;
activityWaitingFor?: unknown;
activityLastEventLabel?: unknown;
activityIdleMs?: unknown;
}
interface NormalizedPerformanceEvent {
@@ -664,6 +668,10 @@ function normalizeWorkbenchUiOtelSpan(rawEvent: unknown, payload: WebPerformance
const sessionHash = sanitizeOtelAttribute(input.sessionHash, 80);
const traceHash = sanitizeOtelAttribute(input.traceHash, 80);
const errorName = sanitizeOtelAttribute(input.errorName, 80);
const timeoutName = sanitizeOtelAttribute(input.timeoutName, 80);
const activityWaitingFor = sanitizeOtelAttribute(input.activityWaitingFor, 80);
const activityLastEventLabel = sanitizeOtelAttribute(input.activityLastEventLabel, 120);
const activityIdleMs = Math.min(Math.max(finiteNumber(input.activityIdleMs, NaN), 0), 3_600_000);
return {
name: ["workbench", eventType, scope, state].filter((part) => part && part !== "unknown").join("."),
uiTraceId,
@@ -686,6 +694,10 @@ function normalizeWorkbenchUiOtelSpan(rawEvent: unknown, payload: WebPerformance
"workbench.ui.session_hash": sessionHash,
"workbench.ui.trace_hash": traceHash,
"workbench.ui.error_name": errorName,
"workbench.ui.timeout_name": timeoutName,
"workbench.ui.activity_waiting_for": activityWaitingFor,
"workbench.ui.activity_last_event_label": activityLastEventLabel,
...(Number.isFinite(activityIdleMs) ? { "workbench.ui.activity_idle_ms": Math.trunc(activityIdleMs) } : {}),
"workbench.ui.values_printed": false,
"http.route": route,
"http.request.method": normalizeMethod(input.method),
+19 -6
View File
@@ -71,15 +71,28 @@ export async function fetchJson<T>(path: string, options: ApiRequestOptions = {}
});
const payload = await response.json().catch(() => null) as T | null;
recordApiTiming({ route: path, method: options.method, status: response.status, startedAt, outcome: response.ok ? "ok" : "http_error" });
recordWorkbenchApiRequest({ route: path, method: options.method, status: response.status, startedAtEpochMs: startedAt, endedAtEpochMs: Date.now(), outcome: response.ok ? "ok" : "http_error" });
recordWorkbenchApiRequest({ route: path, method: options.method, status: response.status, startedAtEpochMs: startedAt, endedAtEpochMs: Date.now(), outcome: response.ok ? "ok" : "http_error", timeoutName: options.timeoutName });
return { ok: response.ok, status: response.status, data: payload, error: response.ok ? null : errorMessage(payload, `HTTP ${response.status}`) };
} catch (error) {
const outcome = error instanceof DOMException && error.name === "AbortError" ? "timeout" : "network_error";
const activity = inactivityRef.current;
recordApiTiming({ route: path, method: options.method, status: 0, startedAt, outcome });
recordWorkbenchApiRequest({ route: path, method: options.method, status: 0, startedAtEpochMs: startedAt, endedAtEpochMs: Date.now(), outcome });
recordWorkbenchApiRequest({
route: path,
method: options.method,
status: 0,
startedAtEpochMs: startedAt,
endedAtEpochMs: Date.now(),
outcome,
timeoutName: options.timeoutName,
activityIdleMs: activity?.idleMs,
activityWaitingFor: activity?.waitingFor,
activityLastEventLabel: activity?.lastEventLabel,
errorName: error instanceof Error ? error.name : undefined
});
if (error instanceof DOMException && error.name === "AbortError") {
if (inactivityRef.current) {
const detail = inactivityRef.current;
if (activity) {
const detail = activity;
return { ok: false, status: 0, data: null, error: `${options.timeoutName ?? path} 超过 ${timeoutMs}ms 无新活动(idle ${Math.round(detail.idleMs / 1000)}swaitingFor=${detail.waitingFor ?? "unknown"}lastEventLabel=${detail.lastEventLabel ?? "none"}` };
}
return { ok: false, status: 0, data: null, error: `${options.timeoutName ?? path} 超时` };
@@ -96,11 +109,11 @@ export async function fetchText(path: string, options: ApiRequestOptions = {}):
const response = await fetch(path, { ...options, credentials: options.credentials ?? "same-origin" });
const text = await response.text();
recordApiTiming({ route: path, method: options.method, status: response.status, startedAt, outcome: response.ok ? "ok" : "http_error" });
recordWorkbenchApiRequest({ route: path, method: options.method, status: response.status, startedAtEpochMs: startedAt, endedAtEpochMs: Date.now(), outcome: response.ok ? "ok" : "http_error" });
recordWorkbenchApiRequest({ route: path, method: options.method, status: response.status, startedAtEpochMs: startedAt, endedAtEpochMs: Date.now(), outcome: response.ok ? "ok" : "http_error", timeoutName: options.timeoutName });
return { ok: response.ok, status: response.status, data: text, error: response.ok ? null : `HTTP ${response.status}` };
} catch (error) {
recordApiTiming({ route: path, method: options.method, status: 0, startedAt, outcome: "network_error" });
recordWorkbenchApiRequest({ route: path, method: options.method, status: 0, startedAtEpochMs: startedAt, endedAtEpochMs: Date.now(), outcome: "network_error" });
recordWorkbenchApiRequest({ route: path, method: options.method, status: 0, startedAtEpochMs: startedAt, endedAtEpochMs: Date.now(), outcome: "network_error", timeoutName: options.timeoutName, errorName: error instanceof Error ? error.name : undefined });
return { ok: false, status: 0, data: null, error: error instanceof Error ? error.message : String(error) };
}
}
@@ -4,7 +4,7 @@
import type { ChatMessage, TraceEvent } from "@/types";
type WorkbenchEventKind = "workbench_journey" | "workbench_event_phase" | "workbench_backend_event_visible" | "workbench_ui_event";
type WorkbenchOutcome = "ok" | "timeout" | "error" | "dropped" | "stale" | "partial" | "empty" | "network" | "unknown";
type WorkbenchOutcome = "ok" | "timeout" | "error" | "dropped" | "stale" | "partial" | "empty" | "network" | "denied" | "unknown";
type WorkbenchLoadingScope = "workbench" | "session_list" | "session_detail" | "api" | "sse" | "page";
type WorkbenchUiState = "enter" | "exit" | "request" | "connect" | "open" | "message" | "close" | "error" | "sample";
type WorkbenchUiReason = "hydrate" | "select_session" | "create_session" | "api_request" | "sse_connect" | "sse_open" | "sse_error" | "sse_close" | "pagehide" | "visibility_hidden" | "unknown";
@@ -41,6 +41,10 @@ interface WorkbenchPerformanceEvent {
startedAtEpochMs?: number;
endedAtEpochMs?: number;
errorName?: string;
timeoutName?: string;
activityWaitingFor?: string | null;
activityLastEventLabel?: string | null;
activityIdleMs?: number;
}
interface TraceEventTimingInput {
@@ -169,7 +173,7 @@ export function recordWorkbenchLoadingState(input: { scope: WorkbenchLoadingScop
enqueueWorkbenchUiEvent({ eventType: "loading_state", loadingScope: input.scope, state: "exit", reason: previous.reason, route: previous.route, valueMs, startedAtEpochMs: previous.startEpochMs, endedAtEpochMs: nowEpoch, sessionHash: previous.sessionHash, traceHash: previous.traceHash, outcome: "ok" });
}
export function recordWorkbenchApiRequest(input: { route: string; method?: string; status?: number; startedAtEpochMs: number; endedAtEpochMs?: number; outcome?: string | null }): void {
export function recordWorkbenchApiRequest(input: { route: string; method?: string; status?: number; startedAtEpochMs: number; endedAtEpochMs?: number; outcome?: string | null; timeoutName?: string | null; errorName?: string | null; activityWaitingFor?: string | null; activityLastEventLabel?: string | null; activityIdleMs?: number | null }): void {
if (!isWorkbenchPage()) return;
const route = safeText(input.route);
if (!route || route.startsWith("/v1/web-performance")) return;
@@ -185,6 +189,11 @@ export function recordWorkbenchApiRequest(input: { route: string; method?: strin
status: input.status,
statusClass: statusClass(input.status),
outcome: normalizeUiOutcome(input.outcome),
timeoutName: input.timeoutName ? safeText(input.timeoutName).slice(0, 80) : undefined,
errorName: input.errorName ? safeText(input.errorName).slice(0, 80) : undefined,
activityWaitingFor: input.activityWaitingFor ? safeText(input.activityWaitingFor).slice(0, 80) : undefined,
activityLastEventLabel: input.activityLastEventLabel ? safeText(input.activityLastEventLabel).slice(0, 120) : undefined,
activityIdleMs: Number.isFinite(input.activityIdleMs ?? NaN) ? Math.max(0, Math.round(Number(input.activityIdleMs))) : undefined,
valueMs: Math.max(0, endedAtEpochMs - input.startedAtEpochMs),
startedAtEpochMs: input.startedAtEpochMs,
endedAtEpochMs