diff --git a/scripts/src/hwlab-node-impl.ts b/scripts/src/hwlab-node-impl.ts index f93bf5ac..3d38fb15 100644 --- a/scripts/src/hwlab-node-impl.ts +++ b/scripts/src/hwlab-node-impl.ts @@ -7622,6 +7622,7 @@ function renderWebObserveAnalyzeTable(value: Record): string { const consoleAlertSamples = Array.isArray(analysis?.consoleAlertSamples) ? analysis.consoleAlertSamples.map(record).filter((item): item is Record => item !== null).slice(0, 8) : []; const runnerErrors = Array.isArray(analysis?.runnerErrors) ? analysis.runnerErrors.map(record).filter((item): item is Record => item !== null).slice(-8) : []; const recentUpdateJumps = Array.isArray(analysis?.turnTimingRecentUpdateJumps) ? analysis.turnTimingRecentUpdateJumps.map(record).filter((item): item is Record => item !== null).slice(0, 8) : []; + const elapsedZeroResets = Array.isArray(analysis?.turnTimingElapsedZeroResets) ? analysis.turnTimingElapsedZeroResets.map(record).filter((item): item is Record => 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 { 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 { ]), "", "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 { "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), diff --git a/scripts/src/hwlab-node-web-observe-runner-source.ts b/scripts/src/hwlab-node-web-observe-runner-source.ts index e70242cc..a6dc028d 100644 --- a/scripts/src/hwlab-node-web-observe-runner-source.ts +++ b/scripts/src/hwlab-node-web-observe-runner-source.ts @@ -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) {