From 1780cb8980ab2a52e8949bdf5fe2dcda1cdd6300 Mon Sep 17 00:00:00 2001 From: Lyon <88232613+pikasTech@users.noreply.github.com> Date: Mon, 22 Jun 2026 09:59:40 +0800 Subject: [PATCH] fix(web-probe): expose slow API samples in observe analysis (#644) Co-authored-by: Codex --- scripts/src/hwlab-node-impl.ts | 35 ++++++++-- .../hwlab-node-web-observe-runner-source.ts | 66 ++++++++++++++++++- scripts/src/platform-infra-observability.ts | 63 ++++++++++++++---- 3 files changed, 143 insertions(+), 21 deletions(-) diff --git a/scripts/src/hwlab-node-impl.ts b/scripts/src/hwlab-node-impl.ts index 458a8773..f93bf5ac 100644 --- a/scripts/src/hwlab-node-impl.ts +++ b/scripts/src/hwlab-node-impl.ts @@ -7487,10 +7487,12 @@ function runNodeWebProbeObserveAnalyze(options: NodeWebProbeObserveOptions, spec "const stdoutJson = readJson(stdoutPath);", "const reportJson = readJson(reportJsonPath);", "const source = (stdoutJson && stdoutJson.ok !== false ? stdoutJson : null) || reportJson || stdoutJson || null;", + "const fullSource = reportJson || source;", "const objectOrNull = (value) => value && typeof value === 'object' && !Array.isArray(value) ? value : null;", "const slimRound = (item) => { const v = objectOrNull(item) || {}; return { promptIndex: v.promptIndex ?? null, sampleCount: v.sampleCount ?? null, lastTotalElapsedSeconds: v.lastTotalElapsedSeconds ?? null, lastRecentUpdateSeconds: v.lastRecentUpdateSeconds ?? null, diagnosticSamples: v.diagnosticSamples ?? null, terminalSamples: v.terminalSamples ?? null, promptTextHash: clip(v.promptTextHash, 80) }; };", "const slimTurnColumn = (item) => { const v = objectOrNull(item) || {}; return { label: clip(v.label, 24), promptIndex: v.promptIndex ?? null, lastPromptIndex: v.lastPromptIndex ?? null, traceId: clip(v.traceId, 48), firstSeq: v.firstSeq ?? null, lastSeq: v.lastSeq ?? null, source: clip(v.source, 48) }; };", - "const slimSlowApi = (item) => { const v = objectOrNull(item) || {}; return { path: clip(v.path ?? v.route, 96), route: clip(v.route ?? v.path, 96), sampleCount: v.sampleCount ?? null, p95Ms: v.p95Ms ?? v.p95 ?? null, maxMs: v.maxMs ?? v.max ?? null, overFiveSecondCount: v.overFiveSecondCount ?? null }; };", + "const slimSlowSample = (item) => { const v = objectOrNull(item) || {}; return { ts: v.ts ?? null, seq: v.seq ?? null, path: clip(v.path ?? v.rawPath, 96), initiatorType: clip(v.initiatorType, 24), durationMs: v.durationMs ?? null, requestToResponseStartMs: v.requestToResponseStartMs ?? v.streamOpenMs ?? null, responseTransferMs: v.responseTransferMs ?? null, nextHopProtocol: clip(v.nextHopProtocol, 24) }; };", + "const slimSlowApi = (item) => { const v = objectOrNull(item) || {}; return { path: clip(v.path ?? v.route, 96), route: clip(v.route ?? v.path, 96), sampleCount: v.sampleCount ?? null, p95Ms: v.p95Ms ?? v.p95 ?? null, maxMs: v.maxMs ?? v.max ?? null, overFiveSecondCount: v.overFiveSecondCount ?? null, slowSamples: Array.isArray(v.slowSamples) ? v.slowSamples.slice(0, 3).map(slimSlowSample) : [] }; };", "const slimFinding = (item) => { const v = objectOrNull(item) || {}; return { kind: clip(v.kind ?? v.code, 48), code: clip(v.code ?? v.kind, 48), severity: clip(v.severity ?? v.level, 24), level: clip(v.level ?? v.severity, 24), count: v.count ?? v.sampleCount ?? null, sampleCount: v.sampleCount ?? v.count ?? null, summary: clip(v.summary ?? v.message, 180), message: clip(v.message ?? v.summary, 180) }; };", "const slimDomGroup = (item) => { const v = objectOrNull(item) || {}; return { count: v.count ?? null, firstAt: v.firstAt ?? null, lastAt: v.lastAt ?? null, text: clip(v.text ?? v.preview, 180) }; };", "const slimNetworkGroup = (item) => { const v = objectOrNull(item) || {}; return { count: v.count ?? null, method: clip(v.method, 12), status: v.status ?? null, path: clip(v.path, 96), firstAt: v.firstAt ?? null, lastAt: v.lastAt ?? null, promptIndexes: Array.isArray(v.promptIndexes) ? v.promptIndexes.slice(0, 6) : [], failureKinds: Array.isArray(v.failureKinds) ? v.failureKinds.slice(0, 4).map((x) => clip(x, 48)) : [] }; };", @@ -7516,7 +7518,11 @@ function runNodeWebProbeObserveAnalyze(options: NodeWebProbeObserveOptions, spec "const srcRuntimeAlerts = objectOrNull(source?.runtimeAlerts);", "const runtimeAlerts = srcRuntimeAlerts ? { httpErrorCount: srcRuntimeAlerts.httpErrorCount ?? null, requestFailedCount: srcRuntimeAlerts.requestFailedCount ?? null, domDiagnosticSampleCount: srcRuntimeAlerts.domDiagnosticSampleCount ?? null, consoleAlertCount: srcRuntimeAlerts.consoleAlertCount ?? null } : null;", "const srcPagePerformance = objectOrNull(source?.pagePerformance);", - "const pagePerformance = srcPagePerformance ? { sameOriginApiPaths: srcPagePerformance.sameOriginApiPaths ?? null, slowPathCount: srcPagePerformance.slowPathCount ?? null, slowSampleCount: srcPagePerformance.slowSampleCount ?? null, worstP95Ms: srcPagePerformance.worstP95Ms ?? null } : null;", + "const srcPagePerformanceSummary = objectOrNull(srcPagePerformance?.summary);", + "const pagePerformance = srcPagePerformance ? { sameOriginApiPaths: srcPagePerformance.sameOriginApiPaths ?? srcPagePerformanceSummary?.sameOriginApiPathCount ?? null, slowPathCount: srcPagePerformance.slowPathCount ?? srcPagePerformanceSummary?.slowPathCount ?? null, slowSampleCount: srcPagePerformance.slowSampleCount ?? srcPagePerformanceSummary?.slowSampleCount ?? null, worstP95Ms: srcPagePerformance.worstP95Ms ?? srcPagePerformanceSummary?.worstP95Ms ?? null } : null;", + "const fullRecentWindow = objectOrNull(fullSource?.windows?.recent);", + "const fullPagePerformance = objectOrNull(fullRecentWindow?.pagePerformance) || objectOrNull(fullSource?.pagePerformance);", + "const sourceSlowApi = Array.isArray(source?.pagePerformanceSlowApi) && source.pagePerformanceSlowApi.some((item) => Array.isArray(item?.slowSamples) && item.slowSamples.length > 0) ? source.pagePerformanceSlowApi : (Array.isArray(fullPagePerformance?.sameOriginApiByPath) ? fullPagePerformance.sameOriginApiByPath.filter((item) => Number(item?.overFiveSecondCount ?? 0) > 0) : []);", "const srcPromptNetwork = objectOrNull(source?.promptNetwork);", "const promptNetwork = srcPromptNetwork ? { promptSegments: srcPromptNetwork.promptSegments ?? null } : null;", "const compact = source ? {", @@ -7528,11 +7534,11 @@ function runNodeWebProbeObserveAnalyze(options: NodeWebProbeObserveOptions, spec " runtimeAlerts,", " pagePerformance,", " promptNetwork,", - " pagePerformanceSlowApi: takeHead(source.pagePerformanceSlowApi, 5).map(slimSlowApi),", - " findings: takeHead(source.findings, 8).map(slimFinding),", - " httpErrorGroups: takeHead(source.httpErrorGroups, 8).map(slimNetworkGroup),", - " requestFailedGroups: takeHead(source.requestFailedGroups, 8).map(slimNetworkGroup),", - " domDiagnosticGroups: takeHead(source.domDiagnosticGroups, 5).map(slimDomGroup),", + " pagePerformanceSlowApi: takeHead(sourceSlowApi, 4).map(slimSlowApi),", + " findings: takeHead(source.findings, 6).map(slimFinding),", + " httpErrorGroups: takeHead(source.httpErrorGroups, 4).map(slimNetworkGroup),", + " requestFailedGroups: takeHead(source.requestFailedGroups, 5).map(slimNetworkGroup),", + " domDiagnosticGroups: takeHead(source.domDiagnosticGroups, 3).map(slimDomGroup),", " domDiagnosticSamples: takeHead(source.domDiagnosticSamples, 5).map(slimDomSample),", " consoleAlertGroups: takeHead(source.consoleAlertGroups, 5).map(slimConsoleGroup),", " consoleAlertSamples: takeHead(source.consoleAlertSamples, 5).map(slimConsoleSample),", @@ -7799,6 +7805,21 @@ function renderWebObserveAnalyzeTable(value: Record): string { webObserveText(item.overFiveSecondCount), ]) : [["-", "-", "-", "-", "-"]]), "", + "Slow API samples (>5s):", + webObserveTable(["TS", "SEQ", "PATH", "DURATION", "REQ_WAIT", "RESP_XFER", "INIT", "PROTO"], (() => { + const rows = slowApis.flatMap((item) => (Array.isArray(item.slowSamples) ? item.slowSamples : []).map((sample) => ({ ...sample, path: sample.path ?? item.path ?? item.route }))).slice(0, 8).map((sample) => [ + webObserveShort(webObserveText(sample.ts), 24), + webObserveText(sample.seq), + webObserveShort(webObserveText(sample.path), 44), + webObserveText(sample.durationMs), + webObserveText(sample.requestToResponseStartMs ?? sample.streamOpenMs), + webObserveText(sample.responseTransferMs), + webObserveShort(webObserveText(sample.initiatorType), 12), + webObserveShort(webObserveText(sample.nextHopProtocol), 12), + ]); + return rows.length > 0 ? rows : [["-", "-", "-", "-", "-", "-", "-", "-"]]; + })()), + "", "DOM diagnostics:", webObserveTable(domDiagnostics.length > 0 ? ["COUNT", "FIRST", "LAST", "TEXT"] : ["SEQ", "TS", "META", "TEXT"], domDiagnosticRows.length > 0 ? domDiagnosticRows : [["-", "-", "-", "-"]]), "", diff --git a/scripts/src/hwlab-node-web-observe-runner-source.ts b/scripts/src/hwlab-node-web-observe-runner-source.ts index 3c203b97..e70242cc 100644 --- a/scripts/src/hwlab-node-web-observe-runner-source.ts +++ b/scripts/src/hwlab-node-web-observe-runner-source.ts @@ -1488,7 +1488,23 @@ function compactPerformanceItems(items) { name: item?.name ?? null, initiatorType: item?.initiatorType ?? null, startTime: item?.startTime ?? null, - duration: item?.duration ?? null + duration: item?.duration ?? null, + workerStart: item?.workerStart ?? null, + redirectStart: item?.redirectStart ?? null, + redirectEnd: item?.redirectEnd ?? null, + fetchStart: item?.fetchStart ?? null, + domainLookupStart: item?.domainLookupStart ?? null, + domainLookupEnd: item?.domainLookupEnd ?? null, + connectStart: item?.connectStart ?? null, + connectEnd: item?.connectEnd ?? null, + secureConnectionStart: item?.secureConnectionStart ?? null, + requestStart: item?.requestStart ?? null, + responseStart: item?.responseStart ?? null, + responseEnd: item?.responseEnd ?? null, + transferSize: item?.transferSize ?? null, + encodedBodySize: item?.encodedBodySize ?? null, + decodedBodySize: item?.decodedBodySize ?? null, + nextHopProtocol: item?.nextHopProtocol ?? null })); } @@ -1707,10 +1723,12 @@ function buildPagePerformanceReport(samples, manifest) { lastSeq: sample.seq ?? null, initiatorTypes: [], pageAssetFingerprints: [], + slowSamples: [], valuesRedacted: true }; group.sampleCount += 1; group.durationsMs.push(durationMs); + let overBudget = false; if (isLongLivedStream) { if (durationMs > 5000) group.streamLifetimeOverFiveSecondCount += 1; if (streamOpenMs !== null) { @@ -1718,11 +1736,14 @@ function buildPagePerformanceReport(samples, manifest) { if (streamOpenMs > 5000) { group.streamOpenOverFiveSecondCount += 1; group.overFiveSecondCount += 1; + overBudget = true; } } } else if (durationMs > 5000) { group.overFiveSecondCount += 1; + overBudget = true; } + if (overBudget && group.slowSamples.length < 80) group.slowSamples.push(compactPagePerformanceSlowSample({ sample, entry, normalizedPath, rawPath: parsed.path, durationMs, streamOpenMs })); group.lastAt = sample.ts ?? null; group.lastSeq = sample.seq ?? null; if (parsed.path && !group.rawPathSamples.includes(parsed.path)) group.rawPathSamples.push(parsed.path); @@ -1761,6 +1782,10 @@ function buildPagePerformanceReport(samples, manifest) { initiatorTypes: group.initiatorTypes, rawPathSamples: group.rawPathSamples.slice(0, 8), pageAssetFingerprints: group.pageAssetFingerprints.slice(0, 8), + slowSamples: group.slowSamples + .slice() + .sort((a, b) => Number(b.durationMs ?? 0) - Number(a.durationMs ?? 0)) + .slice(0, 12), valuesRedacted: true }; }).sort((a, b) => (b.overFiveSecondCount - a.overFiveSecondCount) || (Number(b.p95Ms ?? 0) - Number(a.p95Ms ?? 0)) || a.path.localeCompare(b.path)); @@ -1786,6 +1811,45 @@ function buildPagePerformanceReport(samples, manifest) { }; } +function compactPagePerformanceSlowSample({ sample, entry, normalizedPath, rawPath, durationMs, streamOpenMs }) { + return { + ts: sample?.ts ?? null, + seq: sample?.seq ?? null, + path: normalizedPath ?? null, + rawPath: rawPath ?? null, + initiatorType: entry?.initiatorType ?? null, + durationMs: roundFinite(durationMs), + startTimeMs: roundFinite(entry?.startTime), + fetchStartMs: roundFinite(entry?.fetchStart), + requestStartMs: roundFinite(entry?.requestStart), + responseStartMs: roundFinite(entry?.responseStart), + responseEndMs: roundFinite(entry?.responseEnd), + streamOpenMs: roundFinite(streamOpenMs), + dnsMs: phaseDeltaMs(entry, "domainLookupEnd", "domainLookupStart"), + tcpMs: phaseDeltaMs(entry, "connectEnd", "connectStart"), + tlsStartMs: roundFinite(entry?.secureConnectionStart), + requestToResponseStartMs: phaseDeltaMs(entry, "responseStart", "requestStart"), + responseTransferMs: phaseDeltaMs(entry, "responseEnd", "responseStart"), + transferSize: Number.isFinite(Number(entry?.transferSize)) ? Number(entry.transferSize) : null, + encodedBodySize: Number.isFinite(Number(entry?.encodedBodySize)) ? Number(entry.encodedBodySize) : null, + decodedBodySize: Number.isFinite(Number(entry?.decodedBodySize)) ? Number(entry.decodedBodySize) : null, + nextHopProtocol: entry?.nextHopProtocol ?? null, + valuesRedacted: true + }; +} + +function phaseDeltaMs(entry, endKey, startKey) { + const end = Number(entry?.[endKey]); + const start = Number(entry?.[startKey]); + if (!Number.isFinite(end) || !Number.isFinite(start) || end <= 0 || start < 0 || end < start) return null; + return Math.round(end - start); +} + +function roundFinite(value) { + const numeric = Number(value); + return Number.isFinite(numeric) ? Math.round(numeric) : null; +} + function classifyApiPerformanceRoute(normalizedPath, entry = {}) { if (normalizedPath === "/v1/workbench/events") return "same-origin-api-stream"; if (String(entry?.initiatorType ?? "").toLowerCase() === "eventsource") return "same-origin-api-stream"; diff --git a/scripts/src/platform-infra-observability.ts b/scripts/src/platform-infra-observability.ts index eaf73ad8..3d0aadc8 100644 --- a/scripts/src/platform-infra-observability.ts +++ b/scripts/src/platform-infra-observability.ts @@ -139,6 +139,7 @@ interface SearchOptions extends CommonOptions { limit: number; candidateLimit: number; lookbackMinutes: number; + endAt: string | null; } interface DiagnoseCodeAgentOptions extends CommonOptions { @@ -273,6 +274,7 @@ function parseSearchOptions(args: string[]): SearchOptions { let limit = 20; let candidateLimit = 80; let lookbackMinutes = 360; + let endAt: string | null = null; for (let index = 0; index < args.length; index += 1) { const arg = args[index]; if (arg === "--grep") { @@ -319,6 +321,13 @@ function parseSearchOptions(args: string[]): SearchOptions { if (!Number.isInteger(parsed) || parsed < 1 || parsed > 10080) throw new Error(`${arg} must be an integer from 1 to 10080`); lookbackMinutes = parsed; index += 1; + } else if (arg === "--end-at") { + const value = args[index + 1]; + if (value === undefined || value.startsWith("--")) throw new Error("--end-at requires an ISO timestamp value"); + const parsed = Date.parse(value); + if (!Number.isFinite(parsed)) throw new Error("--end-at must be an ISO timestamp parseable by Date.parse"); + endAt = new Date(parsed).toISOString(); + index += 1; } else { commonArgs.push(arg); if (arg === "--target") { @@ -328,7 +337,7 @@ function parseSearchOptions(args: string[]): SearchOptions { } } if (grep === null && query === null && path === null && status === null) throw new Error("observability search requires --grep , --query , --path , or --status "); - return { ...parseCommonOptions(commonArgs), grep, query, path, status, limit, candidateLimit, lookbackMinutes }; + return { ...parseCommonOptions(commonArgs), grep, query, path, status, limit, candidateLimit, lookbackMinutes, endAt }; } function parseDiagnoseCodeAgentOptions(args: string[]): DiagnoseCodeAgentOptions { @@ -687,7 +696,9 @@ async function search(config: UniDeskConfig, options: SearchOptions): Promise; }): RenderedCliResult { const traces = asArray(input.result.traces).map((item) => asPlainRecord(item) ?? {}); - const rows = traces.slice(0, 12).map((trace) => [ - shortenMiddle(textValue(trace.traceId), 20), - searchTraceStatus(trace), - numberValue(trace.spanCount), - numberValue(trace.errorSpanCount), - numberValue(trace.matchedSpanCount), - joinValues(trace.services, 46), - ]); + const requestedLimit = numberFromUnknown(input.options.limit); + const rowLimit = Math.max(1, Math.min(Number.isFinite(requestedLimit) ? Math.round(requestedLimit) : 12, 40)); + const rows = traces.slice(0, rowLimit).map((trace) => { + const meta = asPlainRecord(trace.meta) ?? {}; + return [ + shortenMiddle(textValue(trace.traceId), 32), + shortenEnd(textValue(trace.startAt ?? isoFromUnixNano(meta.startTimeUnixNano)), 20), + numberValue(trace.durationMs ?? meta.durationMs), + searchTraceStatus(trace), + numberValue(trace.spanCount), + numberValue(trace.errorSpanCount), + numberValue(trace.matchedSpanCount), + joinValues(trace.services, 38), + ]; + }); const lines = [ `platform-infra observability search (${input.ok ? "ok" : "not-ok"})`, "", - formatTable(["TRACE", "STATUS", "SPANS", "ERR", "MATCH", "SERVICES"], rows.length > 0 ? rows : [["-", "no-match", "-", "-", "-", "-"]]), + formatTable(["TRACE", "START", "DUR_MS", "STATUS", "SPANS", "ERR", "MATCH", "SERVICES"], rows.length > 0 ? rows : [["-", "-", "-", "no-match", "-", "-", "-", "-"]]), "", "Summary:", ` target=${input.target.id} backend=${textValue(input.query.backend)} service=${textValue(input.query.service)}`, ` grep=${textValue(input.query.grep)} path=${textValue(input.query.pathFilter)} status=${textValue(input.query.statusFilter)} tempoQuery=${shortenMiddle(textValue(input.query.tempoQuery), 80)}`, - ` mode=${textValue(input.query.mode)} businessTraceId=${textValue(input.query.businessTraceId)} lookbackMinutes=${textValue(input.query.lookbackMinutes)} requestedLookbackMinutes=${textValue(input.query.requestedLookbackMinutes)}`, + ` mode=${textValue(input.query.mode)} businessTraceId=${textValue(input.query.businessTraceId)} lookbackMinutes=${textValue(input.query.lookbackMinutes)} requestedLookbackMinutes=${textValue(input.query.requestedLookbackMinutes)} endAt=${textValue(input.query.endAt)}`, ` candidateLimit=${textValue(input.query.candidateLimit)} limit=${textValue(input.query.limit)}`, ` candidates=${textValue(input.result.candidateTraceCount)} scanned=${textValue(input.result.scannedTraceCount)} matched=${textValue(input.result.matchedTraceCount)} stopped=${textValue(input.result.scanStopped)}`, ]; @@ -1090,6 +1109,7 @@ function buildSearchCommand(target: ObservabilityTarget, options: SearchOptions, if (options.query !== null) parts.push("--query", options.query); if (options.path !== null) parts.push("--path", options.path); if (options.status !== null) parts.push("--status", String(options.status)); + if (options.endAt !== null) parts.push("--end-at", options.endAt); parts.push("--lookback-minutes", String(options.lookbackMinutes), "--candidate-limit", String(options.candidateLimit), "--limit", String(options.limit)); if (full) parts.push("--full"); return parts.map(cliArg).join(" "); @@ -1138,6 +1158,19 @@ function numberFromUnknown(value: unknown): number { return Number.NaN; } +function isoFromUnixNano(value: unknown): string { + if (value === null || value === undefined || value === "") return "-"; + try { + const text = String(value); + if (!/^\d+$/u.test(text)) return "-"; + const millis = Number(BigInt(text) / 1000000n); + if (!Number.isFinite(millis) || millis <= 0) return "-"; + return new Date(millis).toISOString().replace(/\.000Z$/u, "Z"); + } catch { + return "-"; + } +} + function joinValues(value: unknown, maxLength: number): string { const joined = asArray(value).map(textValue).filter((item) => item !== "-").join(","); return shortenEnd(joined.length > 0 ? joined : textValue(value), maxLength); @@ -1188,11 +1221,15 @@ function compactSearchResult(value: unknown): Record { function compactSearchTrace(value: unknown): Record { const trace = asPlainRecord(value) ?? {}; + const meta = compactMetaRecord(trace.meta); + const startTimeUnixNano = trace.startTimeUnixNano ?? meta?.startTimeUnixNano ?? null; return { traceId: trace.traceId ?? null, + startAt: isoFromUnixNano(startTimeUnixNano), + durationMs: trace.durationMs ?? meta?.durationMs ?? null, traceCommand: trace.traceCommand ?? null, grepCommand: trace.grepCommand ?? null, - meta: compactMetaRecord(trace.meta), + meta, queryOk: trace.queryOk ?? null, parseOk: trace.parseOk ?? null, rawMatched: trace.rawMatched ?? null,