fix: expose code agent trace phase timing (#1422)

This commit is contained in:
lyon
2026-06-18 19:15:55 +08:00
parent b12a74ecdc
commit e647be4ee6
2 changed files with 104 additions and 14 deletions
@@ -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<void>((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<void>((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) => {
+24 -14
View File
@@ -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) {