fix(web-probe): report trace order and card timing mismatches (#746)

Co-authored-by: Codex <codex@noreply.local>
This commit is contained in:
Lyon
2026-06-23 18:26:44 +08:00
committed by GitHub
parent da1e9ca4fa
commit 5a64905054
@@ -1577,9 +1577,25 @@ async function sampleOnePage(targetPage, { reason, groupSeq, pageRole, targetPag
}
return trim(clone.textContent || "", 1200);
};
const numericAttr = (element, names) => {
for (const name of names) {
const raw = element.getAttribute(name);
const value = Number(raw);
if (Number.isFinite(value)) return value;
}
return null;
};
const textAttr = (element, names) => {
for (const name of names) {
const raw = element.getAttribute(name);
if (raw && String(raw).trim()) return String(raw).trim();
}
return null;
};
const summarize = (selector, limit) => Array.from(document.querySelectorAll(selector)).filter(visible).slice(-limit).map((element, index) => {
const rect = element.getBoundingClientRect();
const owner = element.closest('article.message-card, .message-card[data-message-id], article[data-message-id], [data-trace-id]');
const timeElement = element.matches("time,[datetime]") ? element : element.querySelector("time,[datetime]");
return {
index,
tag: element.tagName.toLowerCase(),
@@ -1590,6 +1606,12 @@ async function sampleOnePage(targetPage, { reason, groupSeq, pageRole, targetPag
messageId: element.getAttribute("data-message-id") || owner?.getAttribute("data-message-id") || element.getAttribute("id") || null,
traceId: element.getAttribute("data-trace-id") || owner?.getAttribute("data-trace-id") || null,
turnId: element.getAttribute("data-turn-id") || owner?.getAttribute("data-turn-id") || null,
projectedSeq: numericAttr(element, ["data-projected-seq", "data-projectedseq", "data-seq", "data-sequence", "aria-posinset"]),
sourceSeq: numericAttr(element, ["data-source-seq", "data-sourceseq", "data-source-event-seq"]),
eventSeq: numericAttr(element, ["data-event-seq", "data-eventseq"]),
eventTimestamp: textAttr(element, ["data-event-ts", "data-event-time", "data-timestamp", "datetime"]) || (timeElement ? textAttr(timeElement, ["datetime", "data-event-ts", "data-event-time", "data-timestamp"]) : null),
eventTimeText: timeElement ? trim(timeElement.textContent || "", 80) : null,
eventKind: textAttr(element, ["data-event-kind", "data-kind", "data-label", "data-status"]) || element.getAttribute("aria-label") || null,
text: textHashInput(element),
rect: { x: Math.round(rect.x), y: Math.round(rect.y), width: Math.round(rect.width), height: Math.round(rect.height) },
};
@@ -2266,6 +2288,63 @@ console.log(JSON.stringify({
pagePerformancePartialApi: recentWindow.pagePerformance.sameOriginApiByPath.filter((item) => item.isLongLivedStream !== true && Number(item.partialOverBudgetCount ?? item.partialOverFiveSecondCount ?? 0) > 0).slice(0, 5).map((item) => ({ path: item.path, route: item.route, sampleCount: item.sampleCount, completeTimingSampleCount: item.completeTimingSampleCount, partialTimingSampleCount: item.partialTimingSampleCount, partialOverBudgetCount: item.partialOverBudgetCount, budgetMs: item.partialBudgetMs, partialOverFiveSecondCount: item.partialOverFiveSecondCount, partialSamples: item.partialSamples })),
pagePerformanceSseStreams: recentWindow.pagePerformance.sameOriginApiByPath.filter((item) => item.isLongLivedStream === true).slice(0, 5).map((item) => ({ path: item.path, route: item.route, sampleCount: item.sampleCount, streamOpenSampleCount: item.streamOpenSampleCount, streamOpenP95Ms: item.streamOpenP95Ms, streamOpenMaxMs: item.streamOpenMaxMs, streamOpenOverBudgetCount: item.streamOpenOverBudgetCount, streamOpenBudgetMs: item.streamOpenBudgetMs, streamOpenOverFiveSecondCount: item.streamOpenOverFiveSecondCount, streamLifetimeOverFiveSecondCount: item.streamLifetimeOverFiveSecondCount, slowSamples: item.slowSamples })),
findings: prioritizeFindings(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) })),
traceOrderAnomalies: (recentWindow.sampleMetrics?.traceOrder?.orderAnomalies || []).slice(0, 8).map((item) => ({
sampleSeq: item.sampleSeq ?? null,
sampleIndex: item.sampleIndex ?? null,
timestamp: item.timestamp ?? null,
pageRole: item.pageRole ?? null,
traceId: item.traceId ?? null,
reasons: item.reasons ?? [],
previousRowIndex: item.previousRowIndex ?? null,
currentRowIndex: item.currentRowIndex ?? null,
previousTotalSeconds: item.previousTotalSeconds ?? null,
currentTotalSeconds: item.currentTotalSeconds ?? null,
previousProjectedSeq: item.previousProjectedSeq ?? null,
currentProjectedSeq: item.currentProjectedSeq ?? null,
previousSourceSeq: item.previousSourceSeq ?? null,
currentSourceSeq: item.currentSourceSeq ?? null,
previousEventSeq: item.previousEventSeq ?? null,
currentEventSeq: item.currentEventSeq ?? null,
previousPreview: String(item.previousPreview || "").slice(0, 120),
currentPreview: String(item.currentPreview || "").slice(0, 120),
})),
traceCompletionNotLast: (recentWindow.sampleMetrics?.traceOrder?.completionNotLast || []).slice(0, 8).map((item) => ({
sampleSeq: item.sampleSeq ?? null,
sampleIndex: item.sampleIndex ?? null,
timestamp: item.timestamp ?? null,
pageRole: item.pageRole ?? null,
traceId: item.traceId ?? null,
completionRowIndex: item.completionRowIndex ?? null,
laterRowIndex: item.laterRowIndex ?? null,
completionTotalSeconds: item.completionTotalSeconds ?? null,
laterTotalSeconds: item.laterTotalSeconds ?? null,
completionProjectedSeq: item.completionProjectedSeq ?? null,
laterProjectedSeq: item.laterProjectedSeq ?? null,
completionPreview: String(item.completionPreview || "").slice(0, 120),
laterPreview: String(item.laterPreview || "").slice(0, 120),
})),
roundCompletionElapsedMismatches: (recentWindow.sampleMetrics?.codeAgentCardTiming?.roundCompletion?.elapsedMismatches || []).slice(0, 8).map((item) => ({
seq: item.seq ?? null,
ts: item.ts ?? null,
pageRole: item.pageRole ?? null,
promptIndex: item.promptIndex ?? null,
traceId: item.traceId ?? null,
completionElapsedSeconds: item.completionElapsedSeconds ?? null,
cardTotalElapsedSeconds: item.cardTotalElapsedSeconds ?? null,
deltaSeconds: item.deltaSeconds ?? null,
toleranceSeconds: item.toleranceSeconds ?? null,
})),
codeAgentCardDurationUnderreported: (recentWindow.sampleMetrics?.codeAgentCardTiming?.durationUnderreported || []).slice(0, 8).map((item) => ({
sampleIndex: item.sampleIndex ?? null,
timestamp: item.timestamp ?? null,
pageRole: item.pageRole ?? null,
traceId: item.traceId ?? null,
cardTotalElapsedSeconds: item.cardTotalElapsedSeconds ?? null,
expectedElapsedSeconds: item.expectedElapsedSeconds ?? null,
deltaSeconds: item.deltaSeconds ?? null,
evidenceKind: item.evidenceKind ?? null,
evidencePreview: String(item.evidencePreview || "").slice(0, 120),
})),
valuesRedacted: true,
}));
@@ -2482,6 +2561,12 @@ function compactDomItem(item) {
messageId: item.messageId ?? null,
traceId: item.traceId ?? null,
turnId: item.turnId ?? null,
projectedSeq: Number.isFinite(Number(item.projectedSeq)) ? Number(item.projectedSeq) : null,
sourceSeq: Number.isFinite(Number(item.sourceSeq)) ? Number(item.sourceSeq) : null,
eventSeq: Number.isFinite(Number(item.eventSeq)) ? Number(item.eventSeq) : null,
eventTimestamp: item.eventTimestamp ?? null,
eventTimeText: item.eventTimeText ?? null,
eventKind: item.eventKind ?? null,
durationText: item.durationText ?? null,
activityText: item.activityText ?? null,
className: item.className ?? null,
@@ -4526,7 +4611,8 @@ function buildTraceOrderMetrics(samples, timeline) {
const normalized = {
...row,
sampleIndex,
timestamp: sample.timestamp || sample.collectedAt || sample.time || null,
sampleSeq: sample.seq ?? null,
timestamp: sample.ts || sample.timestamp || sample.collectedAt || sample.time || null,
pageRole: row.pageRole || sample.pageRole || sample.role || sample.contextRole || null,
pageId: row.pageId || sample.pageId || sample.contextId || null,
sessionId: row.sessionId || sample.sessionId || sample.workbenchSessionId || null,
@@ -4557,9 +4643,13 @@ function buildTraceOrderMetrics(samples, timeline) {
const diff = previous.clockSeconds - row.clockSeconds;
if (diff > slackSeconds && diff < 43200) reasons.push('clock-decreased');
}
if (Number.isFinite(previous.timestampMs) && Number.isFinite(row.timestampMs) && row.timestampMs + slackSeconds * 1000 < previous.timestampMs) {
reasons.push('timestamp-decreased');
}
if (reasons.length) {
orderAnomalies.push({
sampleIndex: row.sampleIndex,
sampleSeq: row.sampleSeq,
timestamp: row.timestamp,
pageRole: row.pageRole,
pageId: row.pageId,
@@ -4572,8 +4662,14 @@ function buildTraceOrderMetrics(samples, timeline) {
currentTotalSeconds: row.totalSeconds,
previousProjectedSeq: previous.projectedSeq,
currentProjectedSeq: row.projectedSeq,
previousSourceSeq: previous.sourceSeq,
currentSourceSeq: row.sourceSeq,
previousEventSeq: previous.eventSeq,
currentEventSeq: row.eventSeq,
previousClockSeconds: previous.clockSeconds,
currentClockSeconds: row.clockSeconds,
previousTimestampMs: previous.timestampMs,
currentTimestampMs: row.timestampMs,
previousPreview: previous.preview,
currentPreview: row.preview,
});
@@ -4591,6 +4687,7 @@ function buildTraceOrderMetrics(samples, timeline) {
if (later) {
completionNotLast.push({
sampleIndex: row.sampleIndex,
sampleSeq: row.sampleSeq,
timestamp: row.timestamp,
pageRole: row.pageRole,
pageId: row.pageId,
@@ -4600,6 +4697,12 @@ function buildTraceOrderMetrics(samples, timeline) {
laterRowIndex: later.rowIndex,
completionTotalSeconds: row.totalSeconds,
laterTotalSeconds: later.totalSeconds,
completionProjectedSeq: row.projectedSeq,
laterProjectedSeq: later.projectedSeq,
completionSourceSeq: row.sourceSeq,
laterSourceSeq: later.sourceSeq,
completionEventSeq: row.eventSeq,
laterEventSeq: later.eventSeq,
completionPreview: row.preview,
laterPreview: later.preview,
});
@@ -4691,6 +4794,12 @@ function traceTimingRowsForSample(sample, timelineItem) {
pageId: item.pageId || item.contextId || candidate.meta?.pageId || null,
sessionId: item.sessionId || item.workbenchSessionId || candidate.meta?.sessionId || null,
traceId: item.traceId || item.trace_id || candidate.meta?.traceId || null,
projectedSeq: item.projectedSeq ?? item.projected_seq ?? item.projectedSequence ?? null,
sourceSeq: item.sourceSeq ?? item.source_seq ?? item.sourceSequence ?? null,
eventSeq: item.eventSeq ?? item.event_seq ?? item.sequence ?? null,
eventTimestamp: item.eventTimestamp ?? item.event_ts ?? item.timestamp ?? item.ts ?? null,
eventTimeText: item.eventTimeText ?? item.timeText ?? null,
eventKind: item.eventKind ?? item.kind ?? item.status ?? null,
});
});
}
@@ -4722,6 +4831,10 @@ function extractTraceRowsFromText(text, source, baseIndex, meta = {}) {
function normalizeTraceTimingRow(text, source, rowIndex, meta = {}) {
const preview = compactOneLine(text).slice(0, 240);
const projectedSeq = firstFiniteNumber(meta.projectedSeq, parseTraceRowProjectedSeq(preview));
const sourceSeq = firstFiniteNumber(meta.sourceSeq);
const eventSeq = firstFiniteNumber(meta.eventSeq);
const timestampMs = parseTraceRowTimestampMs(meta.eventTimestamp || meta.eventTimeText || preview);
return {
source,
rowIndex,
@@ -4730,10 +4843,16 @@ function normalizeTraceTimingRow(text, source, rowIndex, meta = {}) {
pageId: meta.pageId || null,
sessionId: meta.sessionId || null,
traceId: meta.traceId || parseTraceRowTraceId(preview),
clockSeconds: parseTraceRowClockSeconds(preview),
clockSeconds: parseTraceRowClockSeconds(preview) ?? parseTraceRowClockSeconds(meta.eventTimeText || ""),
timestampMs,
totalSeconds: parseTraceRowTotalSeconds(preview),
projectedSeq: parseTraceRowProjectedSeq(preview),
isCompletion: /轮次完成|turn\s+completed|completed\s+turn/i.test(preview),
projectedSeq,
sourceSeq,
eventSeq,
eventTimestamp: meta.eventTimestamp || null,
eventTimeText: meta.eventTimeText || null,
eventKind: meta.eventKind || null,
isCompletion: /轮次完成|turn\s+completed|completed\s+turn|terminal[_: -]?status|backend[_: -]?turn[_: -]?finished/i.test([preview, meta.eventKind || ""].join(" ")),
};
}
@@ -4829,6 +4948,21 @@ function parseTraceRowProjectedSeq(text) {
return match ? Number(match[1]) : null;
}
function parseTraceRowTimestampMs(value) {
const text = String(value || '').trim();
if (!text) return null;
const parsed = Date.parse(text);
return Number.isFinite(parsed) ? parsed : null;
}
function firstFiniteNumber(...values) {
for (const value of values) {
const numeric = Number(value);
if (Number.isFinite(numeric)) return numeric;
}
return null;
}
function parseTraceRowTraceId(text) {
const match = String(text || '').match(/\b(?:trace_id=|traceId[:=]?\s*)(trc_[a-z0-9_-]+|[a-f0-9]{16,})\b/i);
return match ? match[1] : null;
@@ -5083,10 +5217,13 @@ function buildRoundCompletionMetrics(samples, timeline, turnTiming) {
function roundCompletionEventsForSample(sample, timelineItem) {
const rows = [];
for (const item of Array.isArray(sample?.traceRows) ? sample.traceRows : []) {
const text = String(item?.text || item?.textPreview || "");
if (!//iu.test(text)) continue;
const elapsedValues = parseTotalElapsedSeconds(text).filter(Number.isFinite);
for (const item of traceTimingRowsForSample(sample, timelineItem)) {
const text = String(item?.preview || item?.text || item?.textPreview || "");
if (!item?.isCompletion && !//iu.test(text)) continue;
const elapsedValues = [
Number(item?.totalSeconds),
...parseTotalElapsedSeconds(text).filter(Number.isFinite)
].filter(Number.isFinite);
const attributed = inferRoundCompletionCard(sample, text);
rows.push({
...ref(sample),
@@ -5094,7 +5231,7 @@ function roundCompletionEventsForSample(sample, timelineItem) {
traceId: item?.traceId ?? firstTraceId([text]) ?? attributed?.traceId ?? null,
messageId: item?.messageId ?? attributed?.messageId ?? null,
attributed: Boolean(item?.traceId || item?.messageId || attributed?.traceId || attributed?.messageId),
traceRowIndex: item?.index ?? null,
traceRowIndex: item?.rowIndex ?? item?.index ?? null,
elapsedSeconds: elapsedValues.length > 0 ? Math.max(...elapsedValues) : null,
textHash: item?.textHash ?? sha256(text),
preview: limitText(text, 180),
@@ -5120,9 +5257,15 @@ function inferRoundCompletionCard(sample, text) {
}
function cardMetricItemsForCompletion(sample, timelineItem, event) {
if (!event.traceId && !event.messageId) return [];
return turnMetricItems(sample, timelineItem)
const metrics = turnMetricItems(sample, timelineItem)
.filter((item) => item.promptIndex === event.promptIndex)
.filter((item) => item.pageRole === event.pageRole || !event.pageRole)
.filter((item) => item.pageId === event.pageId || !event.pageId);
if (!event.traceId && !event.messageId) {
const withElapsed = metrics.filter((item) => Number.isFinite(Number(item.totalElapsedSeconds)));
return withElapsed.length === 1 ? withElapsed : [];
}
return metrics
.filter((item) => !event.traceId || !item.traceId || item.traceId === event.traceId)
.filter((item) => !event.messageId || !item.messageId || item.messageId === event.messageId)
.sort((left, right) => {
@@ -5135,7 +5278,7 @@ function cardMetricItemsForCompletion(sample, timelineItem, event) {
}
function hasFinalResponseAfterCompletion(samples, timeline, event) {
if (!event.traceId && !event.messageId) return true;
if (!event.traceId && !event.messageId && !event.promptIndex) return true;
const eventTsMs = Date.parse(String(event.ts || ""));
for (let index = 0; index < (Array.isArray(samples) ? samples : []).length; index += 1) {
const sample = samples[index];