fix(web-probe): report elapsed zero-reset timing anomalies (#645)

Co-authored-by: Codex <codex@noreply.local>
This commit is contained in:
Lyon
2026-06-22 10:34:50 +08:00
committed by GitHub
parent 1780cb8980
commit 77b467a72b
2 changed files with 54 additions and 8 deletions
+15 -1
View File
@@ -7622,6 +7622,7 @@ function renderWebObserveAnalyzeTable(value: Record<string, unknown>): string {
const consoleAlertSamples = Array.isArray(analysis?.consoleAlertSamples) ? analysis.consoleAlertSamples.map(record).filter((item): item is Record<string, unknown> => item !== null).slice(0, 8) : [];
const runnerErrors = Array.isArray(analysis?.runnerErrors) ? analysis.runnerErrors.map(record).filter((item): item is Record<string, unknown> => item !== null).slice(-8) : [];
const recentUpdateJumps = Array.isArray(analysis?.turnTimingRecentUpdateJumps) ? analysis.turnTimingRecentUpdateJumps.map(record).filter((item): item is Record<string, unknown> => item !== null).slice(0, 8) : [];
const elapsedZeroResets = Array.isArray(analysis?.turnTimingElapsedZeroResets) ? analysis.turnTimingElapsedZeroResets.map(record).filter((item): item is Record<string, unknown> => item !== null).slice(0, 8) : [];
const domDiagnosticRows = domDiagnostics.length > 0
? domDiagnostics.map((item) => [
webObserveText(item.count),
@@ -7671,6 +7672,15 @@ function renderWebObserveAnalyzeTable(value: Record<string, unknown>): string {
webObserveText(item.allowedIncreaseSeconds),
webObserveShort(webObserveText(item.traceId), 24),
]);
const elapsedZeroResetRows = elapsedZeroResets.map((item) => [
webObserveShort(webObserveText(item.columnLabel), 14),
webObserveText(item.promptIndex),
webObserveText(item.fromSeq),
webObserveText(item.toSeq),
`${webObserveText(item.fromValue)}->${webObserveText(item.toValue)}`,
webObserveText(item.delta),
webObserveShort(webObserveText(item.traceId), 24),
]);
const httpErrorRows = httpErrorGroups.map((item) => [
webObserveText(item.count),
webObserveText(item.method),
@@ -7736,12 +7746,13 @@ function renderWebObserveAnalyzeTable(value: Record<string, unknown>): string {
]),
"",
"Turn timing:",
webObserveTable(["ROUNDS", "TURNS", "ROWS", "NON_MONO", "ELAPSED_DEC", "TERMINAL_GROWTH", "RECENT_JUMP", "MAX_RECENT_STEP"], [[
webObserveTable(["ROUNDS", "TURNS", "ROWS", "NON_MONO", "ELAPSED_DEC", "ZERO_RESET", "TERMINAL_GROWTH", "RECENT_JUMP", "MAX_RECENT_STEP"], [[
webObserveText(roundCount),
webObserveText(turnColumnCount),
webObserveText(sampleMetrics?.turnTimingRows),
webObserveText(sampleMetrics?.turnTimingNonMonotonicCount),
webObserveText(sampleMetrics?.turnTimingTotalElapsedDecreaseCount),
webObserveText(sampleMetrics?.turnTimingTotalElapsedZeroResetCount ?? elapsedZeroResets.length),
webObserveText(sampleMetrics?.turnTimingTerminalElapsedGrowthCount),
webObserveText(sampleMetrics?.turnTimingRecentUpdateJumpCount ?? sampleMetrics?.turnTimingRecentUpdateSawtoothJumpCount),
webObserveText(sampleMetrics?.turnTimingRecentUpdateMaxIncreaseSeconds),
@@ -7771,6 +7782,9 @@ function renderWebObserveAnalyzeTable(value: Record<string, unknown>): string {
"Recent update jumps:",
webObserveTable(["TURN", "PROMPT", "FROM_SEQ", "TO_SEQ", "VALUE", "DELTA", "SAMPLE_S", "ALLOWED", "TRACE"], recentUpdateJumpRows.length > 0 ? recentUpdateJumpRows : [["-", "-", "-", "-", "-", "-", "-", "-", "-"]]),
"",
"Total elapsed zero resets:",
webObserveTable(["TURN", "PROMPT", "FROM_SEQ", "TO_SEQ", "VALUE", "DELTA", "TRACE"], elapsedZeroResetRows.length > 0 ? elapsedZeroResetRows : [["-", "-", "-", "-", "-", "-", "-"]]),
"",
"Runtime alerts:",
webObserveTable(["HTTP_ERR", "REQUEST_FAILED", "DOM_DIAG", "CONSOLE_ALERT", "PROMPT_SEGMENTS", "PROMPT_NETWORK"], [[
webObserveText(runtimeAlerts?.httpErrorCount),
@@ -1308,7 +1308,7 @@ console.log(JSON.stringify({
readIssues: jsonlReadIssues.slice(0, 3).map((item) => ({ file: item.file, line: item.line ?? null, error: String(item.error ?? "").slice(0, 160) })),
sampleMetrics: {
...recentWindow.sampleMetrics.summary,
rounds: recentWindow.sampleMetrics.rounds.slice(-8).map((item) => ({ promptIndex: item.promptIndex, promptTextHash: item.promptTextHash, sampleCount: item.sampleCount, firstSeq: item.firstSeq, lastSeq: item.lastSeq, lastTotalElapsedSeconds: item.lastTotalElapsedSeconds, lastRecentUpdateSeconds: item.lastRecentUpdateSeconds, diagnosticSamples: item.diagnosticSamples, terminalSamples: item.terminalSamples, finalTextSamples: item.finalTextSamples, turnTimingRecentUpdateJumpCount: item.turnTimingRecentUpdateJumpCount, turnTimingRecentUpdateMaxIncreaseSeconds: item.turnTimingRecentUpdateMaxIncreaseSeconds })),
rounds: recentWindow.sampleMetrics.rounds.slice(-8).map((item) => ({ promptIndex: item.promptIndex, promptTextHash: item.promptTextHash, sampleCount: item.sampleCount, firstSeq: item.firstSeq, lastSeq: item.lastSeq, lastTotalElapsedSeconds: item.lastTotalElapsedSeconds, lastRecentUpdateSeconds: item.lastRecentUpdateSeconds, diagnosticSamples: item.diagnosticSamples, terminalSamples: item.terminalSamples, finalTextSamples: item.finalTextSamples, turnTimingTotalElapsedZeroResetCount: item.turnTimingTotalElapsedZeroResetCount, turnTimingRecentUpdateJumpCount: item.turnTimingRecentUpdateJumpCount, turnTimingRecentUpdateMaxIncreaseSeconds: item.turnTimingRecentUpdateMaxIncreaseSeconds })),
turnColumns: recentWindow.sampleMetrics.turnColumns.slice(-12).map((item) => ({ label: item.label, source: item.source, promptIndex: item.promptIndex, lastPromptIndex: item.lastPromptIndex, firstSeq: item.firstSeq, lastSeq: item.lastSeq, traceId: item.traceId, messageId: item.messageId })),
},
pageProvenance: recentWindow.pageProvenance.summary,
@@ -1392,6 +1392,19 @@ console.log(JSON.stringify({
allowedIncreaseSeconds: item.allowedIncreaseSeconds ?? null,
excessiveIncreaseSeconds: item.excessiveIncreaseSeconds ?? null,
})),
turnTimingElapsedZeroResets: recentWindow.sampleMetrics.turnTimingElapsedZeroResets.slice(0, 8).map((item) => ({
columnLabel: item.columnLabel ?? item.columnId ?? null,
promptIndex: item.promptIndex ?? null,
traceId: item.traceId ?? null,
fromSeq: item.fromSeq ?? null,
toSeq: item.toSeq ?? null,
fromTs: item.fromTs ?? null,
toTs: item.toTs ?? null,
fromValue: item.fromValue ?? null,
toValue: item.toValue ?? null,
delta: item.delta ?? null,
anomaly: item.anomaly ?? null,
})),
pagePerformanceSlowApi: recentWindow.pagePerformance.sameOriginApiByPath.filter((item) => item.overFiveSecondCount > 0).slice(0, 5).map((item) => ({ path: item.path, route: item.route, sampleCount: item.sampleCount, p95Ms: item.p95Ms, maxMs: item.maxMs, overFiveSecondCount: item.overFiveSecondCount })),
findings: recentWindow.findings.slice(0, 8).map((item) => ({ kind: item.id ?? item.kind ?? item.code, severity: item.severity, count: item.count ?? item.sampleCount ?? null, summary: String(item.summary ?? item.message ?? "").slice(0, 180) })),
valuesRedacted: true,
@@ -1560,6 +1573,8 @@ function buildFindings(samples, control, network, errors, sampleMetrics, promptN
if (traceSeen && !traceTerminal) findings.push({ id: "trace-without-terminal", severity: "amber", summary: "trace rows were visible but no terminal status was sampled", firstTraceSample: ref(samples.find((item) => Array.isArray(item.traceRows) && item.traceRows.length > 0)) });
const promptFailures = Array.isArray(promptNetwork?.rounds) ? promptNetwork.rounds.filter((item) => item.chatPostOk === false) : [];
if (promptFailures.length > 0) findings.push({ id: "prompt-chat-submit-failed", severity: "red", summary: "sendPrompt command had no successful /v1/agent/chat POST response in the sampling window", count: promptFailures.length, rounds: promptFailures.slice(0, 10) });
const elapsedZeroResets = Array.isArray(sampleMetrics?.turnTimingElapsedZeroResets) ? sampleMetrics.turnTimingElapsedZeroResets : [];
if (elapsedZeroResets.length > 0) findings.push({ id: "turn-timing-total-elapsed-zero-reset", severity: "red", summary: "Code Agent total elapsed jumped from a non-zero value back to 0 seconds", count: elapsedZeroResets.length, samples: elapsedZeroResets.slice(0, 20) });
const recentUpdateSawtoothJumps = Array.isArray(sampleMetrics?.turnTimingRecentUpdateSawtoothJumps)
? sampleMetrics.turnTimingRecentUpdateSawtoothJumps
: Array.isArray(sampleMetrics?.turnTimingNonMonotonic)
@@ -1600,7 +1615,7 @@ function buildRecentAnalysisWindow({ samples, control, network, consoleEvents, e
const sampleMetrics = buildSampleMetrics(windowSamples, control);
const pageProvenance = buildPageProvenanceReport(windowSamples, windowControl, manifest);
const pagePerformance = buildPagePerformanceReport(windowSamples, manifest);
const promptNetwork = buildPromptNetworkReport(control, windowNetwork);
const promptNetwork = buildPromptNetworkReport(windowControl, windowNetwork);
const runtimeAlerts = buildRuntimeAlerts(windowSamples, control, windowNetwork, windowConsole, windowErrors);
const findings = buildFindings(windowSamples, control, windowNetwork, windowErrors, sampleMetrics, promptNetwork, runtimeAlerts, pagePerformance, pageProvenance);
return {
@@ -2507,6 +2522,7 @@ function buildSampleMetrics(samples, control) {
const turnTiming = buildTurnTimingTable(samples, timeline);
const turnCells = turnTiming.rows.flatMap((row) => Object.values(row.cells || {}));
const turnTimingNonMonotonic = Array.isArray(turnTiming.nonMonotonic) ? turnTiming.nonMonotonic : [];
const turnTimingElapsedZeroResets = Array.isArray(turnTiming.elapsedZeroResets) ? turnTiming.elapsedZeroResets : [];
const turnTimingRecentUpdateSawtoothJumps = turnTimingNonMonotonic.filter((item) => item.metric === "recentUpdateSeconds" && item.anomaly === "jump");
const turnTimingTerminalElapsedGrowth = Array.isArray(turnTiming.terminalElapsedGrowth) ? turnTiming.terminalElapsedGrowth : [];
const turnTimingRecentUpdateResets = Array.isArray(turnTiming.recentUpdateResets) ? turnTiming.recentUpdateResets : [];
@@ -2530,6 +2546,7 @@ function buildSampleMetrics(samples, control) {
const diagnostics = timeline.filter((item) => item.diagnosticSeen).length;
const rounds = buildRoundMetricSummaries(timeline, promptCommands, {
nonMonotonic: turnTimingNonMonotonic,
elapsedZeroResets: turnTimingElapsedZeroResets,
terminalElapsedGrowth: turnTimingTerminalElapsedGrowth,
recentUpdateResets: turnTimingRecentUpdateResets,
recentUpdateSteps: turnTimingRecentUpdateSteps
@@ -2549,6 +2566,7 @@ function buildSampleMetrics(samples, control) {
turnCellsWithRecentUpdate: turnCells.filter((item) => item.recentUpdateSeconds !== null).length,
turnTimingNonMonotonicCount: turnTimingNonMonotonic.length,
turnTimingTotalElapsedDecreaseCount: turnTimingNonMonotonic.filter((item) => item.metric === "totalElapsedSeconds").length,
turnTimingTotalElapsedZeroResetCount: turnTimingElapsedZeroResets.length,
turnTimingTerminalElapsedGrowthCount: turnTimingTerminalElapsedGrowth.length,
turnTimingTerminalElapsedGrowthMaxSeconds: turnTimingTerminalElapsedGrowthDeltas.length > 0 ? Math.max(...turnTimingTerminalElapsedGrowthDeltas) : 0,
turnTimingRecentUpdateJumpCount: recentUpdateJumpCount,
@@ -2566,6 +2584,7 @@ function buildSampleMetrics(samples, control) {
turnColumns: turnTiming.columns,
turnTimingTable: turnTiming.rows,
turnTimingNonMonotonic,
turnTimingElapsedZeroResets,
turnTimingTerminalElapsedGrowth,
turnTimingRecentUpdateSawtoothJumps,
turnTimingRecentUpdateSteps,
@@ -2635,6 +2654,7 @@ function buildTurnTimingTable(samples, timeline) {
columns,
rows,
nonMonotonic: timingEvents.anomalies,
elapsedZeroResets: timingEvents.elapsedZeroResets,
terminalElapsedGrowth: timingEvents.terminalElapsedGrowth,
recentUpdateResets: timingEvents.recentUpdateResets,
recentUpdateSteps: timingEvents.recentUpdateSteps
@@ -2643,6 +2663,7 @@ function buildTurnTimingTable(samples, timeline) {
function detectTurnTimingNonMonotonic(columns, rows) {
const anomalies = [];
const elapsedZeroResets = [];
const terminalElapsedGrowth = [];
const recentUpdateResets = [];
const recentUpdateSteps = [];
@@ -2658,11 +2679,13 @@ function detectTurnTimingNonMonotonic(columns, rows) {
const current = Number(value);
const previous = previousByMetric.get(metric);
if (previous && metric === "totalElapsedSeconds" && current < previous.value) {
anomalies.push({
const anomaly = previous.value > 0 && current === 0 ? "zero-reset" : "decrease";
const event = {
columnId: column.id,
columnLabel: column.label,
metric,
anomaly: "decrease",
anomaly,
expectedPattern: anomaly === "zero-reset" ? "total-elapsed-should-not-return-to-zero" : "total-elapsed-monotonic",
fromSeq: previous.seq,
fromTs: previous.ts,
fromValue: previous.value,
@@ -2675,7 +2698,9 @@ function detectTurnTimingNonMonotonic(columns, rows) {
promptIndex: cell.promptIndex ?? row.promptIndex ?? null,
source: cell.source ?? column.source ?? null,
valuesRedacted: true
});
};
anomalies.push(event);
if (anomaly === "zero-reset") elapsedZeroResets.push(event);
}
if (metric === "totalElapsedSeconds" && isTerminalTurnStatus(cell.status)) {
if (previousTerminalTotal && current > previousTerminalTotal.value) {
@@ -2781,7 +2806,7 @@ function detectTurnTimingNonMonotonic(columns, rows) {
}
}
}
return { anomalies, terminalElapsedGrowth, recentUpdateResets, recentUpdateSteps };
return { anomalies, elapsedZeroResets, terminalElapsedGrowth, recentUpdateResets, recentUpdateSteps };
}
function isTerminalTurnStatus(value) {
@@ -2888,6 +2913,7 @@ function firstTraceId(texts) {
function buildRoundMetricSummaries(timeline, promptCommands, timing = {}) {
const rounds = [];
const nonMonotonic = Array.isArray(timing.nonMonotonic) ? timing.nonMonotonic : [];
const elapsedZeroResets = Array.isArray(timing.elapsedZeroResets) ? timing.elapsedZeroResets : [];
const terminalElapsedGrowth = Array.isArray(timing.terminalElapsedGrowth) ? timing.terminalElapsedGrowth : [];
const recentUpdateResets = Array.isArray(timing.recentUpdateResets) ? timing.recentUpdateResets : [];
const recentUpdateSteps = Array.isArray(timing.recentUpdateSteps) ? timing.recentUpdateSteps : [];
@@ -2897,6 +2923,7 @@ function buildRoundMetricSummaries(timeline, promptCommands, timing = {}) {
const totalElapsed = items.map((item) => item.totalElapsedSeconds).filter((value) => value !== null);
const recentUpdate = items.map((item) => item.recentUpdateSeconds).filter((value) => value !== null);
const timingAnomalies = nonMonotonic.filter((item) => item.promptIndex === promptIndex);
const timingZeroResets = elapsedZeroResets.filter((item) => item.promptIndex === promptIndex);
const timingTerminalGrowth = terminalElapsedGrowth.filter((item) => item.promptIndex === promptIndex);
const timingResets = recentUpdateResets.filter((item) => item.promptIndex === promptIndex);
const timingSteps = recentUpdateSteps.filter((item) => item.promptIndex === promptIndex);
@@ -2925,6 +2952,7 @@ function buildRoundMetricSummaries(timeline, promptCommands, timing = {}) {
finalTextSamples: items.filter((item) => item.finalResultTextSeen).length,
turnTimingNonMonotonicCount: timingAnomalies.length,
turnTimingTotalElapsedDecreaseCount: timingAnomalies.filter((item) => item.metric === "totalElapsedSeconds").length,
turnTimingTotalElapsedZeroResetCount: timingZeroResets.length,
turnTimingTerminalElapsedGrowthCount: timingTerminalGrowth.length,
turnTimingTerminalElapsedGrowthMaxSeconds: terminalGrowthDeltas.length > 0 ? Math.max(...terminalGrowthDeltas) : 0,
turnTimingRecentUpdateJumpCount: timingAnomalies.filter((item) => item.metric === "recentUpdateSeconds" && item.anomaly === "jump").length,
@@ -3101,6 +3129,10 @@ function renderTurnTimingTable(sampleMetrics) {
const terminalGrowthLines = terminalGrowth.length > 0
? terminalGrowth.slice(0, 80).map((item) => "- " + (item.columnLabel || item.columnId || "-") + " terminal totalElapsed growth " + (item.fromValue ?? "-") + " -> " + (item.toValue ?? "-") + " delta=" + (item.delta ?? "-") + " status " + (item.fromStatus || "-") + " -> " + (item.toStatus || "-") + " seq " + (item.fromSeq ?? "-") + " -> " + (item.toSeq ?? "-") + " ts " + (item.fromTs || "-") + " -> " + (item.toTs || "-") + " traceId=" + (item.traceId || "-")).join("\n")
: "- 未观察到 terminal 后总耗时增长。";
const elapsedZeroResets = Array.isArray(sampleMetrics?.turnTimingElapsedZeroResets) ? sampleMetrics.turnTimingElapsedZeroResets : [];
const elapsedZeroResetLines = elapsedZeroResets.length > 0
? elapsedZeroResets.slice(0, 80).map((item) => "- " + (item.columnLabel || item.columnId || "-") + " totalElapsed zero-reset " + (item.fromValue ?? "-") + " -> " + (item.toValue ?? "-") + " delta=" + (item.delta ?? "-") + " seq " + (item.fromSeq ?? "-") + " -> " + (item.toSeq ?? "-") + " ts " + (item.fromTs || "-") + " -> " + (item.toTs || "-") + " traceId=" + (item.traceId || "-")).join("\n")
: "- 未观察到总耗时从非零跳回 0 秒。";
const sawtoothJumps = Array.isArray(sampleMetrics?.turnTimingRecentUpdateSawtoothJumps)
? sampleMetrics.turnTimingRecentUpdateSawtoothJumps
: nonMonotonic.filter((item) => item.metric === "recentUpdateSeconds" && item.anomaly === "jump");
@@ -3119,7 +3151,7 @@ function renderTurnTimingTable(sampleMetrics) {
const resetLines = recentUpdateResets.length > 0
? recentUpdateResets.slice(0, 80).map((item) => "- " + (item.columnLabel || item.columnId || "-") + " reset " + (item.fromValue ?? "-") + " -> " + (item.toValue ?? "-") + " delta=" + (item.delta ?? "-") + " sampleDelta=" + (item.sampleDeltaSeconds ?? "-") + " seq " + (item.fromSeq ?? "-") + " -> " + (item.toSeq ?? "-") + " ts " + (item.fromTs || "-") + " -> " + (item.toTs || "-") + " traceId=" + (item.traceId || "-")).join("\n")
: "- 未观察到最近更新归零/回落。";
return lines.join("\n") + "\n\n列说明:\n" + columnLines + "\n\n异常事件(仅报表暴露,不做下游 repair;最近更新按三角波模型检测异常跳增):\n" + nonMonotonicLines + "\n\nTerminal 后总耗时增长事件(终态 turn 的总耗时应 sealed,不应继续增长):\n" + terminalGrowthLines + "\n\n最近更新 sawtooth jump 事件(预期每秒增长约 1,遇到新活动归零;例如 1 秒 -> 1 分 4 秒应被列入这里):\n" + sawtoothJumpLines + "\n\n最近更新相邻采样 step(按 delta 降序;用于人工识别一秒跳几十秒/一分钟的瞬态):\n" + stepLines + "\n\n最近更新 reset 事件(预期三角波归零,不计为异常):\n" + resetLines;
return lines.join("\n") + "\n\n列说明:\n" + columnLines + "\n\n异常事件(仅报表暴露,不做下游 repair;最近更新按三角波模型检测异常跳增):\n" + nonMonotonicLines + "\n\nTerminal 后总耗时增长事件(终态 turn 的总耗时应 sealed,不应继续增长):\n" + terminalGrowthLines + "\n\n总耗时归零跳变事件(例如已显示真实耗时后又变成 0 秒):\n" + elapsedZeroResetLines + "\n\n最近更新 sawtooth jump 事件(预期每秒增长约 1,遇到新活动归零;例如 1 秒 -> 1 分 4 秒应被列入这里):\n" + sawtoothJumpLines + "\n\n最近更新相邻采样 step(按 delta 降序;用于人工识别一秒跳几十秒/一分钟的瞬态):\n" + stepLines + "\n\n最近更新 reset 事件(预期三角波归零,不计为异常):\n" + resetLines;
}
function formatMetricCell(value) {