From e647be4ee6a18f915c4d3af9e1e597000028f89f Mon Sep 17 00:00:00 2001 From: lyon Date: Thu, 18 Jun 2026 19:15:55 +0800 Subject: [PATCH] fix: expose code agent trace phase timing (#1422) --- internal/cloud/backend-performance.test.ts | 80 ++++++++++++++++++++++ internal/cloud/server-code-agent-http.ts | 38 ++++++---- 2 files changed, 104 insertions(+), 14 deletions(-) diff --git a/internal/cloud/backend-performance.test.ts b/internal/cloud/backend-performance.test.ts index b94442f1..ac01b813 100644 --- a/internal/cloud/backend-performance.test.ts +++ b/internal/cloud/backend-performance.test.ts @@ -9,6 +9,7 @@ import { createBackendPerformanceStore, backendPerformanceRouteTemplate, withBac import { submitAgentRunChatTurn } from "./code-agent-agentrun-adapter.ts"; import { createCodeAgentTraceStore } from "./code-agent-trace-store.ts"; import { createCloudApiServer } from "./server.ts"; +import { createCodeAgentChatResultStore } from "./server-code-agent-http.ts"; test("backend performance store templates routes and appends Cloud API metrics to loopback metrics", async () => { assert.equal(backendPerformanceRouteTemplate("/v1/agent/traces/trc_secret_0123456789abcdef?full=1"), "/v1/agent/traces/:id"); @@ -37,6 +38,85 @@ test("backend performance store templates routes and appends Cloud API metrics t } }); +test("backend performance records Code Agent trace handler phases without high-cardinality labels", async () => { + const traceId = "trc_backend_phase_trace"; + const runId = "run_backend_phase"; + const commandId = "cmd_backend_phase"; + const traceStore = createCodeAgentTraceStore(); + const codeAgentChatResults = createCodeAgentChatResultStore(); + traceStore.append(traceId, { type: "message", role: "assistant", label: "assistant:start", sourceSeq: 1, commandId }); + traceStore.append(traceId, { type: "result", status: "completed", terminal: true, label: "result:completed", sourceSeq: 2, commandId }); + codeAgentChatResults.set(traceId, { + status: "completed", + conversationId: "cnv_backend_phase", + sessionId: "ses_backend_phase", + threadId: "thr_backend_phase", + ownerUserId: "usr_backend_phase", + updatedAt: "2026-06-18T00:00:00.000Z", + agentRun: { + adapter: "agentrun-v01", + runId, + commandId, + terminalStatus: "completed", + lastSeq: 2 + }, + finalResponse: { + text: "done", + traceId, + status: "completed", + updatedAt: "2026-06-18T00:00:00.000Z" + }, + traceSummary: { + source: "agentrun-command-result", + terminalStatus: "completed", + eventCount: 2, + updatedAt: "2026-06-18T00:00:00.000Z" + } + }); + const backendPerformanceStore = createBackendPerformanceStore({ env: { POD_NAMESPACE: "hwlab-v03", HWLAB_GITOPS_TARGET: "v03" } }); + const accessController = { + required: true, + async authenticate() { + return { ok: true, actor: { id: "usr_backend_phase", role: "user" }, session: { id: "web_backend_phase" } }; + }, + async getAgentSessionByTraceId(requestedTraceId: string) { + assert.equal(requestedTraceId, traceId); + return { + id: "ses_backend_phase", + sessionId: "ses_backend_phase", + projectId: "prj_hwpod_workbench", + ownerUserId: "usr_backend_phase", + ownerRole: "user", + session: {} + }; + } + }; + const server = createCloudApiServer({ backendPerformanceStore, traceStore, codeAgentChatResults, accessController, env: { POD_NAMESPACE: "hwlab-v03", HWLAB_GITOPS_TARGET: "v03" } }); + await new Promise((resolve) => server.listen(0, "127.0.0.1", resolve)); + try { + const address = server.address(); + assert.ok(address && typeof address === "object"); + const baseUrl = `http://127.0.0.1:${address.port}`; + const trace = await fetch(`${baseUrl}/v1/agent/traces/${traceId}?projectId=prj_hwpod_workbench&limit=1`); + assert.equal(trace.status, 200); + const serverTiming = trace.headers.get("server-timing") ?? ""; + assert.match(serverTiming, /trace-project-check;dur=/u); + assert.match(serverTiming, /trace-paginate;dur=/u); + assert.match(serverTiming, /total;dur=/u); + const payload = await trace.json(); + assert.equal(payload.range.returned, 1); + + const metrics = await fetch(`${baseUrl}/v1/web-performance/metrics`); + const text = await metrics.text(); + assert.equal(metrics.status, 200); + assert.match(text, /hwlab_cloud_api_request_phase_duration_seconds_count\{[^}]*route="\/v1\/agent\/traces\/:id"[^}]*phase="trace_project_check"[^}]*\} 1/u); + assert.match(text, /hwlab_cloud_api_request_phase_duration_seconds_count\{[^}]*route="\/v1\/agent\/traces\/:id"[^}]*phase="trace_paginate"[^}]*\} 1/u); + assert.doesNotMatch(text, /trc_backend_phase_trace|run_backend_phase|cmd_backend_phase|ses_backend_phase|cnv_backend_phase/u); + } finally { + await new Promise((resolve, reject) => server.close((error) => error ? reject(error) : resolve())); + } +}); + test("AgentRun adapter records upstream timing through backend performance context", async () => { const calls: Array<{ method?: string; path: string; body?: any }> = []; const agentRunServer = createHttpServer(async (request, response) => { diff --git a/internal/cloud/server-code-agent-http.ts b/internal/cloud/server-code-agent-http.ts index 0c080dca..01a7b217 100644 --- a/internal/cloud/server-code-agent-http.ts +++ b/internal/cloud/server-code-agent-http.ts @@ -1144,12 +1144,12 @@ export async function handleCodeAgentTurnHttp(request, response, url, options) { return; } const requestOptions = codeAgentRequestScopedOptions(options); - const projectMismatch = await traceProjectMismatchSnapshot(traceId, url, requestOptions, "turn"); + const projectMismatch = await measureCodeAgentHttpPhase(requestOptions, "turn_project_check", () => traceProjectMismatchSnapshot(traceId, url, requestOptions, "turn")); if (projectMismatch) { sendJson(response, projectMismatch.statusCode, projectMismatch.body); return; } - const resolved = await resolveCodeAgentTurnStatusSnapshot(traceId, requestOptions); + const resolved = await measureCodeAgentHttpPhase(requestOptions, "turn_resolve_status", () => resolveCodeAgentTurnStatusSnapshot(traceId, requestOptions)); sendJson(response, resolved.statusCode, resolved.body); } @@ -1164,7 +1164,7 @@ async function resolveCodeAgentTurnStatusSnapshot(traceId, options) { let turnRefreshSatisfiedByResultSync = false; if (adapterEnabled && (result?.agentRun?.runId || !result)) { try { - const synced = await syncAgentRunChatResult({ traceId, currentResult: result, options: refreshOptions, traceStore }); + const synced = await measureCodeAgentHttpPhase(options, "turn_result_sync", () => syncAgentRunChatResult({ traceId, currentResult: result, options: refreshOptions, traceStore })); result = synced.result ?? result; turnRefreshSatisfiedByResultSync = synced.eventsRefreshed === true || synced.resultSynced === true || synced.terminalRefreshSkipped === true; if (result && !canAccessOwnedResult(result, options.actor)) return forbiddenTurnSnapshot(traceId); @@ -1193,7 +1193,7 @@ async function resolveCodeAgentTurnStatusSnapshot(traceId, options) { let agentRunResult = result?.agentRun ? result : null; if (!agentRunResult && adapterEnabled) { try { - agentRunResult = await loadPersistedAgentRunResult(traceId, options); + agentRunResult = await measureCodeAgentHttpPhase(options, "turn_load_persisted_result", () => loadPersistedAgentRunResult(traceId, options)); } catch { agentRunResult = null; } @@ -1203,10 +1203,10 @@ async function resolveCodeAgentTurnStatusSnapshot(traceId, options) { let refreshError = null; if (agentRunResult?.agentRun && !turnRefreshSatisfiedByResultSync && !resultPollError) { try { - const refreshedTrace = await refreshAgentRunTrace({ traceId, result: agentRunResult, options: refreshOptions, traceStore }); + const refreshedTrace = await measureCodeAgentHttpPhase(options, "turn_trace_refresh", () => refreshAgentRunTrace({ traceId, result: agentRunResult, options: refreshOptions, traceStore })); agentRunResult = options.codeAgentChatResults?.get?.(traceId) ?? agentRunResult; if (traceNeedsCommandResultSync(agentRunResult, refreshedTrace)) { - const synced = await syncAgentRunChatResult({ traceId, currentResult: agentRunResult, options: refreshOptions, traceStore, appendResultEvent: false, refreshEvents: false, forceResultSync: true }); + const synced = await measureCodeAgentHttpPhase(options, "turn_force_result_sync", () => syncAgentRunChatResult({ traceId, currentResult: agentRunResult, options: refreshOptions, traceStore, appendResultEvent: false, refreshEvents: false, forceResultSync: true })); agentRunResult = synced.result ?? agentRunResult; } if (isTraceCommandTerminalStatus(agentRunResult?.status)) { @@ -1217,8 +1217,10 @@ async function resolveCodeAgentTurnStatusSnapshot(traceId, options) { } } - const snapshot = traceSnapshotWithTerminalEvidence(traceStore.snapshot(traceId), agentRunResult ?? result, traceId, refreshError); - const body = codeAgentTurnStatusPayload({ traceId, result: agentRunResult ?? result, snapshot, resultPollError, refreshError, options }); + const body = await measureCodeAgentHttpPhase(options, "turn_payload", () => { + const snapshot = traceSnapshotWithTerminalEvidence(traceStore.snapshot(traceId), agentRunResult ?? result, traceId, refreshError); + return codeAgentTurnStatusPayload({ traceId, result: agentRunResult ?? result, snapshot, resultPollError, refreshError, options }); + }); return { statusCode: body.ok ? 200 : 404, body }; } @@ -1245,6 +1247,11 @@ function codeAgentRequestScopedOptions(options = {}) { }; } +async function measureCodeAgentHttpPhase(options, phase, callback) { + const perf = options?.backendPerformance; + return perf && typeof perf.measure === "function" ? await perf.measure(phase, callback) : await callback(); +} + function forbiddenTurnSnapshot(traceId) { return { statusCode: 403, @@ -2524,7 +2531,7 @@ export async function handleCodeAgentTraceHttp(request, response, url, options) return; } const requestOptions = codeAgentRequestScopedOptions(options); - const projectMismatch = await traceProjectMismatchSnapshot(traceId, url, requestOptions, "trace"); + const projectMismatch = await measureCodeAgentHttpPhase(requestOptions, "trace_project_check", () => traceProjectMismatchSnapshot(traceId, url, requestOptions, "trace")); if (projectMismatch) { sendJson(response, projectMismatch.statusCode, projectMismatch.body); return; @@ -2540,7 +2547,7 @@ export async function handleCodeAgentTraceHttp(request, response, url, options) return; } - let agentRunResult = result?.agentRun ? result : await loadPersistedAgentRunResult(traceId, requestOptions); + let agentRunResult = result?.agentRun ? result : await measureCodeAgentHttpPhase(requestOptions, "trace_load_persisted_result", () => loadPersistedAgentRunResult(traceId, requestOptions)); let refreshError = null; if (agentRunResult && !canAccessOwnedResult(agentRunResult, requestOptions.actor)) { sendJson(response, 403, { @@ -2557,10 +2564,10 @@ export async function handleCodeAgentTraceHttp(request, response, url, options) const terminalSnapshotRefreshSatisfied = traceRefreshSatisfiedByTerminalSnapshot(agentRunResult, existingSnapshot); const snapshot = terminalSnapshotRefreshSatisfied ? existingSnapshot - : await refreshAgentRunTrace({ traceId, result: agentRunResult, options: requestOptions, traceStore }); + : await measureCodeAgentHttpPhase(requestOptions, "trace_trace_refresh", () => refreshAgentRunTrace({ traceId, result: agentRunResult, options: requestOptions, traceStore })); agentRunResult = requestOptions.codeAgentChatResults?.get?.(traceId) ?? agentRunResult; if (!terminalSnapshotRefreshSatisfied && traceNeedsCommandResultSync(agentRunResult, snapshot)) { - const synced = await syncAgentRunChatResult({ traceId, currentResult: agentRunResult, options: requestOptions, traceStore, appendResultEvent: false, refreshEvents: false, forceResultSync: true }); + const synced = await measureCodeAgentHttpPhase(requestOptions, "trace_result_sync", () => syncAgentRunChatResult({ traceId, currentResult: agentRunResult, options: requestOptions, traceStore, appendResultEvent: false, refreshEvents: false, forceResultSync: true })); agentRunResult = synced.result ?? agentRunResult; } if (isTraceCommandTerminalStatus(agentRunResult?.status)) { @@ -2576,8 +2583,11 @@ export async function handleCodeAgentTraceHttp(request, response, url, options) return; } - const snapshot = traceStore.snapshot(traceId); - sendJson(response, 200, paginateTraceSnapshot(traceSnapshotWithTerminalEvidence(snapshot, agentRunResult, traceId, refreshError), pageOptions)); + const body = await measureCodeAgentHttpPhase(requestOptions, "trace_paginate", () => { + const snapshot = traceStore.snapshot(traceId); + return paginateTraceSnapshot(traceSnapshotWithTerminalEvidence(snapshot, agentRunResult, traceId, refreshError), pageOptions); + }); + sendJson(response, 200, body); } function codeAgentTracePageOptions(url) {