From b29ede08351feed6c09494e82584dcfdd7fb9907 Mon Sep 17 00:00:00 2001 From: Lyon <88232613+pikasTech@users.noreply.github.com> Date: Tue, 23 Jun 2026 20:15:10 +0800 Subject: [PATCH] fix(web-probe): report code agent duration mismatches (#749) Co-authored-by: Codex --- .../hwlab-node-web-observe-runner-source.ts | 92 ++++++++++++++++++- 1 file changed, 89 insertions(+), 3 deletions(-) diff --git a/scripts/src/hwlab-node-web-observe-runner-source.ts b/scripts/src/hwlab-node-web-observe-runner-source.ts index 1e851d9b..ea4d2054 100644 --- a/scripts/src/hwlab-node-web-observe-runner-source.ts +++ b/scripts/src/hwlab-node-web-observe-runner-source.ts @@ -2345,6 +2345,20 @@ console.log(JSON.stringify({ evidenceKind: item.evidenceKind ?? null, evidencePreview: String(item.evidencePreview || "").slice(0, 120), })), + codeAgentCardDurationMismatches: (recentWindow.sampleMetrics?.codeAgentCardTiming?.durationMismatches || []).slice(0, 8).map((item) => ({ + sampleIndex: item.sampleIndex ?? null, + timestamp: item.timestamp ?? null, + pageRole: item.pageRole ?? null, + traceId: item.traceId ?? null, + direction: item.direction ?? null, + cardTotalElapsedSeconds: item.cardTotalElapsedSeconds ?? null, + expectedElapsedSeconds: item.expectedElapsedSeconds ?? null, + signedDeltaSeconds: item.signedDeltaSeconds ?? null, + deltaSeconds: item.deltaSeconds ?? null, + evidenceKind: item.evidenceKind ?? null, + exactEvidence: item.exactEvidence === true, + evidencePreview: String(item.evidencePreview || "").slice(0, 120), + })), valuesRedacted: true, })); @@ -2707,6 +2721,15 @@ function buildFindings(samples, control, network, errors, sampleMetrics, promptN samples: (cardTiming.durationUnderreported || []).slice(0, 20), }); } + if (Number(cardTimingSummary.durationMismatchCount ?? 0) > 0) { + findings.push({ + id: "code-agent-card-duration-mismatch", + severity: "red", + summary: "completed Code Agent card total elapsed does not match sealed completion/final-response timing evidence", + count: cardTimingSummary.durationMismatchCount, + samples: (cardTiming.durationMismatches || []).slice(0, 20), + }); + } const traceOrder = sampleMetrics?.traceOrder || {}; const traceOrderSummary = traceOrder.summary || {}; if (Number(traceOrderSummary.orderAnomalyCount ?? 0) > 0) { @@ -3895,9 +3918,12 @@ function buildSampleMetrics(samples, control) { const traceOrder = buildTraceOrderMetrics(samples, timeline); const codeAgentCardTiming = buildCodeAgentCardTimingMetrics(samples, timeline, turnTiming); const codeAgentCardDurationUnderreported = buildCodeAgentCardDurationUnderreportedMetrics(samples, timeline); + const codeAgentCardDurationMismatches = buildCodeAgentCardDurationMismatchMetrics(samples, timeline); if (codeAgentCardTiming && codeAgentCardTiming.summary) { codeAgentCardTiming.summary.durationUnderreportedCount = codeAgentCardDurationUnderreported.length; + codeAgentCardTiming.summary.durationMismatchCount = codeAgentCardDurationMismatches.length; codeAgentCardTiming.durationUnderreported = codeAgentCardDurationUnderreported; + codeAgentCardTiming.durationMismatches = codeAgentCardDurationMismatches; } const turnCells = turnTiming.rows.flatMap((row) => Object.values(row.cells || {})); const turnTimingNonMonotonic = Array.isArray(turnTiming.nonMonotonic) ? turnTiming.nonMonotonic : []; @@ -3984,6 +4010,7 @@ function buildSampleMetrics(samples, control) { roundCompletionFinalResponseMissingCount: codeAgentCardTiming.summary.roundCompletionFinalResponseMissingCount, roundCompletionPostTimingChangeCount: codeAgentCardTiming.summary.roundCompletionPostTimingChangeCount, codeAgentCardDurationUnderreportedCount: codeAgentCardTiming.summary.durationUnderreportedCount, + codeAgentCardDurationMismatchCount: codeAgentCardTiming.summary.durationMismatchCount, traceRowCount: traceOrder.summary.traceRowCount, traceRowOrderAnomalyCount: traceOrder.summary.orderAnomalyCount, traceRowCompletionNotLastCount: traceOrder.summary.completionNotLastCount, @@ -4767,6 +4794,58 @@ function buildCodeAgentCardDurationUnderreportedMetrics(samples, timeline) { return findings.slice(0, 100); } +function buildCodeAgentCardDurationMismatchMetrics(samples, timeline) { + const findings = []; + const slackSeconds = Math.max(5, Number(alertThresholds?.turnTimingSampleSlackSeconds || 0)); + for (let sampleIndex = 0; sampleIndex < samples.length; sampleIndex += 1) { + const sample = samples[sampleIndex] || {}; + const cards = codeAgentCardsForSample(sample); + if (!cards.length) continue; + const traceRows = traceTimingRowsForSample(sample, timeline[sampleIndex] || {}); + const terminalCards = cards.filter((card) => isCodeAgentCardTerminal(card)); + const sampleText = sampleVisibleText(sample, timeline[sampleIndex] || {}); + for (const card of terminalCards) { + const cardText = codeAgentCardText(card); + const parsedCardSeconds = parseTotalElapsedSeconds(cardText).filter(Number.isFinite); + const cardSeconds = Number.isFinite(Number(card.totalElapsedSeconds)) ? Number(card.totalElapsedSeconds) : parsedCardSeconds.length > 0 ? Math.max(...parsedCardSeconds) : NaN; + if (!Number.isFinite(cardSeconds)) continue; + const traceMatched = traceRows.filter((row) => traceRowMatchesCard(row, card, terminalCards.length)); + const traceEvidence = maxTraceDurationEvidence(traceMatched); + const textEvidence = maxSelfReportedDurationEvidence([card.text, card.preview, card.finalResponseText, card.runningRecordText, terminalCards.length === 1 ? sampleText : ''].filter(Boolean).join('\n')); + const evidences = [traceEvidence, textEvidence].filter((item) => item && Number.isFinite(item.seconds)); + if (!evidences.length) continue; + const strongest = evidences.sort((a, b) => b.seconds - a.seconds)[0]; + const exactEvidence = strongest.exact === true || strongest.kind === 'trace-completion-total' || strongest.kind === 'final-response-duration'; + const tolerance = Math.max(slackSeconds, Math.ceil(strongest.seconds * 0.05)); + const signedDelta = Number((cardSeconds - strongest.seconds).toFixed(3)); + const absoluteDelta = Math.abs(signedDelta); + const underreported = strongest.seconds > cardSeconds + tolerance; + const overreported = exactEvidence && cardSeconds > strongest.seconds + tolerance; + if (!underreported && !overreported) continue; + findings.push({ + sampleIndex, + timestamp: sample.timestamp || sample.collectedAt || sample.time || sample.ts || null, + pageRole: card.pageRole || sample.pageRole || sample.role || sample.contextRole || null, + pageId: card.pageId || sample.pageId || sample.contextId || null, + sessionId: card.sessionId || sample.sessionId || sample.workbenchSessionId || null, + traceId: card.traceId || strongest.traceId || null, + status: card.status || card.state || card.phase || null, + direction: underreported ? 'underreported' : 'overreported', + cardTotalElapsedSeconds: cardSeconds, + expectedElapsedSeconds: strongest.seconds, + signedDeltaSeconds: signedDelta, + deltaSeconds: Number(absoluteDelta.toFixed(3)), + toleranceSeconds: tolerance, + evidenceKind: strongest.kind, + exactEvidence, + evidencePreview: strongest.preview, + cardPreview: card.preview || compactOneLine(cardText || ''), + }); + } + } + return findings.slice(0, 100); +} + function traceTimingRowsForSample(sample, timelineItem) { const rows = []; const seen = new Set(); @@ -4989,13 +5068,14 @@ function maxTraceDurationEvidence(rows) { if (finiteTotals.length) { const maxTotal = Math.max(...finiteTotals); const source = rows.find((row) => Number(row.totalSeconds) === maxTotal); - evidences.push({ kind: 'trace-total', seconds: maxTotal, traceId: source?.traceId || null, preview: source?.preview || '' }); + const exact = source?.isCompletion === true; + evidences.push({ kind: exact ? 'trace-completion-total' : 'trace-total', seconds: maxTotal, traceId: source?.traceId || null, preview: source?.preview || '', exact }); } if (finiteClocks.length >= 2) { const minClock = Math.min(...finiteClocks); const maxClock = Math.max(...finiteClocks); const span = maxClock - minClock; - if (span >= 0 && span < 43200) evidences.push({ kind: 'trace-clock-span', seconds: span, traceId: null, preview: 'visible trace row clock span' }); + if (span >= 0 && span < 43200) evidences.push({ kind: 'trace-clock-span', seconds: span, traceId: null, preview: 'visible trace row clock span', exact: false }); } if (!evidences.length) return null; evidences.sort((a, b) => b.seconds - a.seconds); @@ -5015,7 +5095,7 @@ function maxSelfReportedDurationEvidence(text) { const seconds = parseSelfReportedRoundDurationSeconds(candidateText); if (!Number.isFinite(seconds)) continue; if (!best || seconds > best.seconds) { - best = { kind: 'final-response-duration', seconds, preview: compactOneLine(candidateText).slice(0, 240) }; + best = { kind: 'final-response-duration', seconds, preview: compactOneLine(candidateText).slice(0, 240), exact: true }; } } return best; @@ -6125,6 +6205,9 @@ function renderMarkdown(report) { const durationUnderreportedLines = Array.isArray(codeAgentCardTiming.durationUnderreported) && codeAgentCardTiming.durationUnderreported.length > 0 ? codeAgentCardTiming.durationUnderreported.slice(0, 80).map((item) => "- sample=" + (item.sampleIndex ?? "-") + " " + (item.timestamp || "-") + " role=" + (item.pageRole || "-") + " status=" + (item.status || "-") + " traceId=" + (item.traceId || "-") + " card=" + (item.cardTotalElapsedSeconds ?? "-") + "s expected=" + (item.expectedElapsedSeconds ?? "-") + "s delta=" + (item.deltaSeconds ?? "-") + "s evidence=" + (item.evidenceKind || "-") + " preview=" + escapeMarkdownCell(item.evidencePreview || item.cardPreview || "")).join("\n") : "- 未观察到 Code Agent 卡片耗时低于 trace/final-response 证据。"; + const durationMismatchLines = Array.isArray(codeAgentCardTiming.durationMismatches) && codeAgentCardTiming.durationMismatches.length > 0 + ? codeAgentCardTiming.durationMismatches.slice(0, 80).map((item) => "- sample=" + (item.sampleIndex ?? "-") + " " + (item.timestamp || "-") + " role=" + (item.pageRole || "-") + " status=" + (item.status || "-") + " traceId=" + (item.traceId || "-") + " direction=" + (item.direction || "-") + " card=" + (item.cardTotalElapsedSeconds ?? "-") + "s expected=" + (item.expectedElapsedSeconds ?? "-") + "s signedDelta=" + (item.signedDeltaSeconds ?? "-") + "s delta=" + (item.deltaSeconds ?? "-") + "s tolerance=" + (item.toleranceSeconds ?? "-") + "s evidence=" + (item.evidenceKind || "-") + " exact=" + String(item.exactEvidence === true) + " preview=" + escapeMarkdownCell(item.evidencePreview || item.cardPreview || "")).join("\n") + : "- 未观察到 Code Agent 卡片耗时与 completion/final-response 封口证据不一致。"; const traceOrderAnomalyLines = Array.isArray(traceOrder.orderAnomalies) && traceOrder.orderAnomalies.length > 0 ? traceOrder.orderAnomalies.slice(0, 80).map((item) => "- sample=" + (item.sampleIndex ?? "-") + " " + (item.timestamp || "-") + " role=" + (item.pageRole || "-") + " traceId=" + (item.traceId || "-") + " rows=" + (item.previousRowIndex ?? "-") + "->" + (item.currentRowIndex ?? "-") + " reasons=" + (Array.isArray(item.reasons) ? item.reasons.join(",") : "-") + " total=" + (item.previousTotalSeconds ?? "-") + "->" + (item.currentTotalSeconds ?? "-") + " clock=" + (item.previousClockSeconds ?? "-") + "->" + (item.currentClockSeconds ?? "-") + " preview=" + escapeMarkdownCell((item.previousPreview || "") + " / " + (item.currentPreview || ""))).join("\n") : "- 未观察到可见 trace 行顺序非单调。"; @@ -6207,6 +6290,7 @@ function renderMarkdown(report) { + "- codeAgentCardMissingElapsedCount: " + (metricSummary.codeAgentCardMissingElapsedCount ?? 0) + "\n" + "- codeAgentCardMissingRecentUpdateCount: " + (metricSummary.codeAgentCardMissingRecentUpdateCount ?? 0) + "\n" + "- codeAgentCardDurationUnderreportedCount: " + (metricSummary.codeAgentCardDurationUnderreportedCount ?? 0) + "\n" + + "- codeAgentCardDurationMismatchCount: " + (metricSummary.codeAgentCardDurationMismatchCount ?? 0) + "\n" + "- traceRowCount: " + (metricSummary.traceRowCount ?? 0) + "\n" + "- traceRowOrderAnomalyCount: " + (metricSummary.traceRowOrderAnomalyCount ?? 0) + "\n" + "- traceRowCompletionNotLastCount: " + (metricSummary.traceRowCompletionNotLastCount ?? 0) + "\n" @@ -6222,10 +6306,12 @@ function renderMarkdown(report) { + "- missingElapsedCount: " + (codeAgentCardTimingSummary.missingElapsedCount ?? 0) + "\n" + "- missingRecentUpdateCount: " + (codeAgentCardTimingSummary.missingRecentUpdateCount ?? 0) + "\n" + "- durationUnderreportedCount: " + (codeAgentCardTimingSummary.durationUnderreportedCount ?? 0) + "\n" + + "- durationMismatchCount: " + (codeAgentCardTimingSummary.durationMismatchCount ?? 0) + "\n" + "- policy: Code Agent 卡片无论终态/非终态都必须显示耗时；非终态必须显示最近更新。该 analyzer 只报告采样到的页面表现，不做下游 repair。\n\n" + "#### Missing elapsed samples\n\n" + cardMissingElapsedLines + "\n\n" + "#### Missing recent update samples\n\n" + cardMissingRecentLines + "\n\n" + "#### Duration underreported samples\n\n" + durationUnderreportedLines + "\n\n" + + "#### Duration mismatch samples\n\n" + durationMismatchLines + "\n\n" + "### Trace row visual order\n\n" + "- traceRowCount: " + (traceOrderSummary.traceRowCount ?? 0) + "\n" + "- orderAnomalyCount: " + (traceOrderSummary.orderAnomalyCount ?? 0) + "\n"