diff --git a/scripts/src/hwlab-node-help.ts b/scripts/src/hwlab-node-help.ts index 80ad1433..75945f5e 100644 --- a/scripts/src/hwlab-node-help.ts +++ b/scripts/src/hwlab-node-help.ts @@ -87,6 +87,7 @@ export function hwlabNodeWebProbeHelp(): Record { "observe start registers a local UniDesk-side observer id under .state/web-observe/index.json; after start, prefer observe status|command|stop|collect|analyze instead of repeating --node/--lane/--state-dir.", "observe command actions are explicit user/control actions and are appended to control.jsonl; use --type newSession/selectProvider/sendPrompt/goto/screenshot/mark/stop and keep prompt text out of issue comments by citing textHash/textBytes.", "observe analyze is offline-only: it reads artifact JSONL and writes analysis/report.md plus analysis/report.json without accessing Workbench APIs or driving the browser.", + "observe analyze scans every sampled DOM point, extracts Workbench timing text such as 总耗时/total and 最近 N 秒/分前, writes sampleMetrics.timeline, and flags backwards/frozen/stale/diagnostic timing anomalies instead of relying on status tail output.", "Use recordStep(name, data) or fetchApiMatrix(paths) to keep structured partial evidence when a later step fails.", "Use reloadStable(), gotoCurrentStable(), or safeReload() for bounded retries around page reload/current-URL navigation jitter such as ERR_NETWORK_CHANGED.", "Playwright page.evaluate accepts one serializable argument; use page.evaluate(({ a, b }) => ..., { a, b }) or safeEvaluate(fn, { a, b }).", diff --git a/scripts/src/hwlab-node-web-observe-runner-source.ts b/scripts/src/hwlab-node-web-observe-runner-source.ts index 6fbae4ab..ccdb05ec 100644 --- a/scripts/src/hwlab-node-web-observe-runner-source.ts +++ b/scripts/src/hwlab-node-web-observe-runner-source.ts @@ -663,8 +663,9 @@ const manifest = await readJson(path.join(stateDir, "manifest.json")); const heartbeat = await readJson(path.join(stateDir, "heartbeat.json")); await mkdir(analysisDir, { recursive: true, mode: 0o700 }); -const findings = buildFindings(samples, control, network, errors); const transitions = buildTransitions(samples); +const sampleMetrics = buildSampleMetrics(samples, control); +const findings = buildFindings(samples, control, network, errors, sampleMetrics); const commandTimeline = control.filter((item) => item.phase === "completed" || item.phase === "failed").map((item) => ({ ts: item.ts, phase: item.phase, commandId: item.commandId, type: item.type, input: item.input, afterUrl: item.afterUrl })); const report = { ok: findings.filter((item) => item.severity === "red").length === 0, @@ -676,6 +677,7 @@ const report = { counts: { samples: samples.length, control: control.length, network: network.length, errors: errors.length, artifacts: artifacts.length }, commandTimeline, transitions, + sampleMetrics, findings, artifactSummary: await artifactSummary(artifacts), safety: { offlineOnly: true, browserDriven: false, apiFetch: false, valuesRedacted: true }, @@ -683,7 +685,7 @@ const report = { await writeFile(reportJsonPath, JSON.stringify(report, null, 2) + "\n", { mode: 0o600 }); await writeFile(reportMdPath, renderMarkdown(report), { mode: 0o600 }); const [jsonMeta, mdMeta] = await Promise.all([fileMeta(reportJsonPath), fileMeta(reportMdPath)]); -console.log(JSON.stringify({ ok: true, command: "web-probe-observe analyze", stateDir, reportJsonPath, reportJsonSha256: jsonMeta.sha256, reportMdPath, reportMdSha256: mdMeta.sha256, counts: report.counts, findings: findings.slice(0, 20), valuesRedacted: true }, null, 2)); +console.log(JSON.stringify({ ok: true, command: "web-probe-observe analyze", stateDir, reportJsonPath, reportJsonSha256: jsonMeta.sha256, reportMdPath, reportMdSha256: mdMeta.sha256, counts: report.counts, sampleMetrics: sampleMetrics.summary, findings: findings.slice(0, 20), valuesRedacted: true }, null, 2)); async function readJson(file) { try { return JSON.parse(await readFile(file, "utf8")); } catch { return null; } @@ -698,7 +700,7 @@ async function readJsonl(file) { } catch { return []; } } -function buildFindings(samples, control, network, errors) { +function buildFindings(samples, control, network, errors, sampleMetrics) { const findings = []; const commandTimes = control.filter((item) => item.phase === "completed" || item.phase === "started").map((item) => Date.parse(item.ts)).filter(Number.isFinite); const routeSessions = new Set(samples.map((item) => item.routeSessionId).filter(Boolean)); @@ -728,11 +730,164 @@ function buildFindings(samples, control, network, errors) { 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 naturalApi = network.filter((item) => item.observerInitiated === false && item.type === "response" && /\/v1\/|\/auth\//u.test(String(item.url || ""))); findings.push({ id: "natural-api-dom-lag-baseline", severity: "info", summary: "natural API responses and DOM samples are available for manual lag correlation", naturalApiResponses: naturalApi.length, sampleCount: samples.length }); + for (const finding of sampleMetricFindings(sampleMetrics)) findings.push(finding); if (errors.length > 0) findings.push({ id: "browser-console-or-page-errors", severity: "amber", summary: "pageerror/runner errors were captured", count: errors.length, first: errors.slice(0, 5) }); if (samples.length === 0) findings.push({ id: "no-samples", severity: "red", summary: "observer produced no samples" }); return findings; } +function buildSampleMetrics(samples, control) { + const promptTimes = control.filter((item) => item.type === "sendPrompt" && item.phase === "completed").map((item) => Date.parse(item.ts)).filter(Number.isFinite).sort((a, b) => a - b); + const timeline = samples.map((sample) => { + const texts = sampleTexts(sample); + const tsMs = Date.parse(sample.ts); + const promptIndex = Number.isFinite(tsMs) ? latestPromptIndex(promptTimes, tsMs) : 0; + const totalElapsedValues = texts.flatMap(parseTotalElapsedSeconds).filter(Number.isFinite); + const recentUpdateValues = texts.flatMap(parseRecentUpdateSeconds).filter(Number.isFinite); + const diagnosticTexts = texts.filter((text) => /Failed to fetch|realtime-gap|durable projection store|turn 超过|无法连接|projection-resume|503|timeout|error/iu.test(text)).slice(0, 5); + const terminalTexts = texts.filter((text) => /轮次完成|轮次失败|轮次取消|已记录|已完成第\d+轮|final response|turn completed|turn failed|turn canceled|terminal result/iu.test(text)).slice(0, 5); + return { + seq: sample.seq ?? null, + ts: sample.ts ?? null, + routeSessionId: sample.routeSessionId ?? null, + activeSessionId: sample.activeSessionId ?? null, + promptIndex, + messageCount: Array.isArray(sample.messages) ? sample.messages.length : 0, + traceRowCount: Array.isArray(sample.traceRows) ? sample.traceRows.length : 0, + totalElapsedSeconds: totalElapsedValues.length > 0 ? Math.max(...totalElapsedValues) : null, + recentUpdateSeconds: recentUpdateValues.length > 0 ? Math.max(...recentUpdateValues) : null, + terminalSeen: terminalTexts.length > 0, + diagnosticSeen: diagnosticTexts.length > 0, + diagnosticTextHashes: diagnosticTexts.map(sha256).slice(0, 5), + textDigest: digestSample(sample) + }; + }); + const withTotal = timeline.filter((item) => item.totalElapsedSeconds !== null).length; + const withRecent = timeline.filter((item) => item.recentUpdateSeconds !== null).length; + const diagnostics = timeline.filter((item) => item.diagnosticSeen).length; + return { + summary: { + sampleCount: timeline.length, + withTotalElapsed: withTotal, + withRecentUpdate: withRecent, + diagnostics, + promptSegments: Math.max(0, promptTimes.length) + }, + timeline + }; +} + +function sampleMetricFindings(sampleMetrics) { + const findings = []; + const timeline = Array.isArray(sampleMetrics?.timeline) ? sampleMetrics.timeline : []; + const elapsedBackwards = []; + const recentBackwardsWithoutDigestChange = []; + const staleRunning = []; + const diagnosticSamples = []; + const terminalDiagnostic = []; + const freezeWindows = []; + let freezeStart = null; + let previous = null; + for (const item of timeline) { + if (item.diagnosticSeen) diagnosticSamples.push(metricRef(item)); + if (item.terminalSeen && item.diagnosticSeen) terminalDiagnostic.push(metricRef(item)); + if ( + previous + && item.promptIndex === previous.promptIndex + && item.totalElapsedSeconds !== null + && previous.totalElapsedSeconds !== null + && item.totalElapsedSeconds + 3 < previous.totalElapsedSeconds + ) { + elapsedBackwards.push({ from: metricRef(previous), to: metricRef(item), deltaSeconds: item.totalElapsedSeconds - previous.totalElapsedSeconds }); + } + if ( + previous + && item.promptIndex === previous.promptIndex + && item.recentUpdateSeconds !== null + && previous.recentUpdateSeconds !== null + && item.recentUpdateSeconds + 5 < previous.recentUpdateSeconds + && item.textDigest === previous.textDigest + ) { + recentBackwardsWithoutDigestChange.push({ from: metricRef(previous), to: metricRef(item), deltaSeconds: item.recentUpdateSeconds - previous.recentUpdateSeconds }); + } + if (!item.terminalSeen && item.recentUpdateSeconds !== null && item.recentUpdateSeconds >= 45) staleRunning.push(metricRef(item)); + const elapsedFrozen = previous && item.promptIndex === previous.promptIndex && !item.terminalSeen && !previous.terminalSeen && item.totalElapsedSeconds !== null && previous.totalElapsedSeconds !== null && Math.abs(item.totalElapsedSeconds - previous.totalElapsedSeconds) <= 1 && item.textDigest === previous.textDigest; + if (elapsedFrozen) { + if (!freezeStart) freezeStart = previous; + } else if (freezeStart && previous) { + if ((previous.seq ?? 0) - (freezeStart.seq ?? 0) >= 3) freezeWindows.push({ from: metricRef(freezeStart), to: metricRef(previous) }); + freezeStart = null; + } + previous = item; + } + if (freezeStart && previous && (previous.seq ?? 0) - (freezeStart.seq ?? 0) >= 3) freezeWindows.push({ from: metricRef(freezeStart), to: metricRef(previous) }); + if (elapsedBackwards.length > 0) findings.push({ id: "sample-total-elapsed-backward", severity: "red", summary: "sampled total elapsed time moved backwards within the same prompt segment", count: elapsedBackwards.length, samples: elapsedBackwards.slice(0, 20) }); + if (freezeWindows.length > 0) findings.push({ id: "sample-total-elapsed-frozen-while-running", severity: "amber", summary: "sampled total elapsed time froze across repeated non-terminal samples", count: freezeWindows.length, windows: freezeWindows.slice(0, 20) }); + if (recentBackwardsWithoutDigestChange.length > 0) findings.push({ id: "sample-recent-update-backward-without-visible-change", severity: "amber", summary: "sampled recent-update age moved backwards while visible digest stayed the same", count: recentBackwardsWithoutDigestChange.length, samples: recentBackwardsWithoutDigestChange.slice(0, 20) }); + if (staleRunning.length > 0) findings.push({ id: "sample-recent-update-stale-while-nonterminal", severity: "amber", summary: "recent-update age exceeded threshold while no terminal state was sampled", count: staleRunning.length, samples: staleRunning.slice(0, 20) }); + if (diagnosticSamples.length > 0) findings.push({ id: "sample-diagnostic-banner-visible", severity: "amber", summary: "diagnostic/error banners were visible in sampled message or trace text", count: diagnosticSamples.length, samples: diagnosticSamples.slice(0, 20) }); + if (terminalDiagnostic.length > 0) findings.push({ id: "sample-terminal-with-diagnostic-visible", severity: "red", summary: "terminal/completed text and diagnostic/error text were visible in the same sampled state", count: terminalDiagnostic.length, samples: terminalDiagnostic.slice(0, 20) }); + return findings; +} + +function sampleTexts(sample) { + const rows = []; + for (const group of [sample?.messages, sample?.traceRows]) { + if (!Array.isArray(group)) continue; + for (const item of group) { + const text = String(item?.textPreview || ""); + if (text.trim()) rows.push(text); + } + } + return rows; +} + +function parseTotalElapsedSeconds(text) { + const values = []; + for (const match of String(text || "").matchAll(/总耗时\s*[=:：]?\s*(\d{1,2}):(\d{2}):(\d{2})/giu)) { + values.push(Number(match[1]) * 3600 + Number(match[2]) * 60 + Number(match[3])); + } + for (const match of String(text || "").matchAll(/总耗时\s*[=:：]?\s*(\d{1,2}):(\d{2})(?!:)/giu)) { + values.push(Number(match[1]) * 60 + Number(match[2])); + } + return values; +} + +function parseRecentUpdateSeconds(text) { + const values = []; + for (const match of String(text || "").matchAll(/最近\s*(?:(\d+)\s*天)?\s*(?:(\d+)\s*小时)?\s*(?:(\d+)\s*分)?\s*(?:(\d+)\s*秒)?\s*前/giu)) { + const days = Number(match[1] || 0); + const hours = Number(match[2] || 0); + const minutes = Number(match[3] || 0); + const seconds = Number(match[4] || 0); + values.push(days * 86400 + hours * 3600 + minutes * 60 + seconds); + } + return values; +} + +function latestPromptIndex(promptTimes, tsMs) { + let index = 0; + for (let i = 0; i < promptTimes.length; i += 1) { + if (promptTimes[i] <= tsMs) index = i + 1; + else break; + } + return index; +} + +function metricRef(item) { + return { + seq: item.seq ?? null, + ts: item.ts ?? null, + promptIndex: item.promptIndex ?? null, + routeSessionId: item.routeSessionId ?? null, + activeSessionId: item.activeSessionId ?? null, + totalElapsedSeconds: item.totalElapsedSeconds ?? null, + recentUpdateSeconds: item.recentUpdateSeconds ?? null, + terminalSeen: Boolean(item.terminalSeen), + diagnosticSeen: Boolean(item.diagnosticSeen) + }; +} + function buildTransitions(samples) { const rows = []; let last = null; @@ -752,7 +907,8 @@ function detectFinalFlicker(samples) { for (const sample of samples) { const messageText = Array.isArray(sample.messages) ? sample.messages.map((item) => item.textPreview || "").join("\n") : ""; const nonEmpty = messageText.trim().length > 0; - if (nonEmpty && !/temporarily|timeout|无法连接|暂时|error|failed|超时/iu.test(messageText)) lastNonEmpty = { sample, messageText }; + const finalLike = /轮次完成|已记录|已完成第\d+轮|final response|terminal result/iu.test(messageText); + if (nonEmpty && finalLike && !/temporarily|timeout|无法连接|暂时|error|failed|超时/iu.test(messageText)) lastNonEmpty = { sample, messageText }; if (lastNonEmpty && nonEmpty && /temporarily|timeout|无法连接|暂时|error|failed|超时/iu.test(messageText)) flickers.push({ from: ref(lastNonEmpty.sample), to: ref(sample) }); if (lastNonEmpty && !nonEmpty) flickers.push({ from: ref(lastNonEmpty.sample), to: ref(sample), reason: "text-disappeared" }); } @@ -806,6 +962,10 @@ function renderMarkdown(report) { const findingLines = report.findings.length === 0 ? "- 无红灯项。" : report.findings.map((item) => "- " + item.severity + ": " + item.id + " - " + item.summary).join("\n"); const commandLines = report.commandTimeline.length === 0 ? "- 无控制命令。" : report.commandTimeline.map((item) => "- " + item.ts + " " + item.phase + " " + item.type + " " + item.commandId + " " + (item.afterUrl || "")).join("\n"); const transitionLines = report.transitions.length === 0 ? "- 无状态变化。" : report.transitions.slice(0, 80).map((item) => "- #" + item.seq + " " + item.ts + " messages=" + item.messageCount + " traceRows=" + item.traceRowCount + " route=" + (item.routeSessionId || "-") + " active=" + (item.activeSessionId || "-")).join("\n"); + const metricSummary = report.sampleMetrics?.summary || {}; + const metricLines = Array.isArray(report.sampleMetrics?.timeline) && report.sampleMetrics.timeline.length > 0 + ? report.sampleMetrics.timeline.slice(0, 120).map((item) => "- #" + item.seq + " " + item.ts + " prompt=" + item.promptIndex + " totalElapsedSeconds=" + (item.totalElapsedSeconds ?? "-") + " recentUpdateSeconds=" + (item.recentUpdateSeconds ?? "-") + " terminal=" + item.terminalSeen + " diagnostic=" + item.diagnosticSeen).join("\n") + : "- 无采样指标。"; return "# web-probe observe analysis\n\n" + "- stateDir: " + report.stateDir + "\n" + "- generatedAt: " + report.generatedAt + "\n" @@ -814,6 +974,13 @@ function renderMarkdown(report) { + "- network: " + report.counts.network + "\n" + "- errors: " + report.counts.errors + "\n\n" + "## Findings\n\n" + findingLines + "\n\n" + + "## Sample metrics\n\n" + + "- sampleCount: " + (metricSummary.sampleCount ?? 0) + "\n" + + "- withTotalElapsed: " + (metricSummary.withTotalElapsed ?? 0) + "\n" + + "- withRecentUpdate: " + (metricSummary.withRecentUpdate ?? 0) + "\n" + + "- diagnostics: " + (metricSummary.diagnostics ?? 0) + "\n" + + "- promptSegments: " + (metricSummary.promptSegments ?? 0) + "\n\n" + + metricLines + "\n\n" + "## Command timeline\n\n" + commandLines + "\n\n" + "## State transitions\n\n" + transitionLines + "\n"; }