diff --git a/scripts/src/hwlab-node-web-observe-analyzer-source.ts b/scripts/src/hwlab-node-web-observe-analyzer-source.ts index 8e6a24cd..dc017183 100644 --- a/scripts/src/hwlab-node-web-observe-analyzer-source.ts +++ b/scripts/src/hwlab-node-web-observe-analyzer-source.ts @@ -1386,7 +1386,7 @@ function buildFindings(samples, control, network, errors, sampleMetrics, promptN if (recentUpdateSawtoothJumps.length > 0) findings.push({ id: "turn-timing-recent-update-sawtooth-jump", severity: "amber", summary: "最近更新 value jumped faster than sample interval; expected sawtooth increase-or-reset", count: recentUpdateSawtoothJumps.length, samples: recentUpdateSawtoothJumps.slice(0, 20) }); const severeTimeoutRounds = Array.isArray(sampleMetrics?.rounds) ? sampleMetrics.rounds.filter((item) => Number(item.maxTotalElapsedSeconds) > alertThresholds.turnElapsedSevereTimeoutSeconds) : []; const severeTimeoutSamples = Array.isArray(sampleMetrics?.timeline) ? sampleMetrics.timeline.filter((item) => Number(item.totalElapsedSeconds) > alertThresholds.turnElapsedSevereTimeoutSeconds) : []; - if (severeTimeoutRounds.length > 0 || severeTimeoutSamples.length > 0) findings.push({ id: "turn-elapsed-severe-timeout", severity: "red", summary: "turn total elapsed exceeded YAML-configured severe timeout; investigate Workbench/AgentRun progress instead of treating the turn as healthy", thresholdSeconds: alertThresholds.turnElapsedSevereTimeoutSeconds, count: Math.max(severeTimeoutRounds.length, severeTimeoutSamples.length), rounds: severeTimeoutRounds.slice(0, 20), samples: severeTimeoutSamples.slice(0, 20) }); + if (severeTimeoutRounds.length > 0 || severeTimeoutSamples.length > 0) findings.push({ id: "turn-elapsed-severe-timeout", severity: "amber", summary: "turn total elapsed exceeded the YAML-configured elapsed alert threshold; timing is a non-blocking alert unless the turn fails to complete or breaks multi-round continuity", thresholdSeconds: alertThresholds.turnElapsedSevereTimeoutSeconds, count: Math.max(severeTimeoutRounds.length, severeTimeoutSamples.length), rounds: severeTimeoutRounds.slice(0, 20), samples: severeTimeoutSamples.slice(0, 20) }); const loadingSummary = sampleMetrics?.loading?.summary || {}; const visibleLoadingSlowSeconds = alertThresholds.visibleLoadingSlowMs / 1000; if (Number(loadingSummary.longestContinuousSeconds ?? 0) > visibleLoadingSlowSeconds) findings.push({ id: "page-loading-visible-over-budget", severity: "red", summary: "visible 加载中 stayed on screen longer than configured YAML budget; fix real loading latency instead of revealing incomplete content early", count: loadingSummary.overBudgetSegmentCount ?? loadingSummary.overFiveSecondSegmentCount ?? 1, longestContinuousSeconds: loadingSummary.longestContinuousSeconds, budgetSeconds: visibleLoadingSlowSeconds, segments: sampleMetrics.loading.segments.slice(0, 20), owners: sampleMetrics.loading.owners.slice(0, 20) }); diff --git a/scripts/src/hwlab-node-web-observe-runner-source.ts b/scripts/src/hwlab-node-web-observe-runner-source.ts index 089cfedc..d5d91984 100644 --- a/scripts/src/hwlab-node-web-observe-runner-source.ts +++ b/scripts/src/hwlab-node-web-observe-runner-source.ts @@ -1166,11 +1166,17 @@ async function sendPrompt(text, options = {}) { ].join(", ")).last(); await submit.waitFor({ state: "visible", timeout: 15000 }); if (options.expectedAction) { - await page.waitForFunction(({ selector, expected }) => { - const element = document.querySelector(selector); - return element?.getAttribute("data-action") === expected || element?.getAttribute("disabled") !== null; - }, { selector: primarySubmitSelector, expected: options.expectedAction }, { timeout: 1000 }).catch(() => null); - const composer = await composerButtonState(submit); + const actionWaitMs = Number.isFinite(Number(options.expectedActionWaitMs)) + ? Math.max(1000, Math.trunc(Number(options.expectedActionWaitMs))) + : options.expectedAction === "turn" ? 180000 : 1000; + const actionDeadline = Date.now() + actionWaitMs; + let composer = null; + while (Date.now() <= actionDeadline) { + composer = await composerButtonState(submit); + if (composer.action === options.expectedAction && composer.disabled !== true) break; + await page.waitForTimeout(250); + } + composer = composer || await composerButtonState(submit); if (composer.action !== options.expectedAction || composer.disabled === true) { await clearComposerEditor(editor).catch(() => {}); const sideEffect = await waitForPromptSideEffect(beforeEvidence, 200).catch(() => promptSideEffectSnapshot()); @@ -1190,6 +1196,7 @@ async function sendPrompt(text, options = {}) { responseObserved: false, sideEffectObserved: sideEffectHasAuthoritativePromptSubmission(sideEffect), sideEffect, + actionWaitMs, expectedAction: options.expectedAction, actualAction: composer.action, valuesRedacted: true diff --git a/scripts/src/hwlab-node-web-sentinel-cicd.ts b/scripts/src/hwlab-node-web-sentinel-cicd.ts index 9ad0f5e2..090c837c 100644 --- a/scripts/src/hwlab-node-web-sentinel-cicd.ts +++ b/scripts/src/hwlab-node-web-sentinel-cicd.ts @@ -543,9 +543,9 @@ function runSentinelImageBuildConfirmed(state: SentinelCicdState, options: Extra publish, elapsedMs, warnings: [ - ...sentinelElapsedWarnings(elapsedMs), - ...sentinelElapsedWarnings(record(sourceMirrorSync).elapsedMs), - ...sentinelElapsedWarnings(record(publish).elapsedMs), + ...sentinelElapsedWarnings(elapsedMs, "sentinel confirmed operation", numberAt(state.cicd, "targetValidation.maxSeconds")), + ...sentinelElapsedWarnings(record(sourceMirrorSync).elapsedMs, "sentinel source mirror sync", numberAt(state.cicd, "targetValidation.maxSeconds")), + ...sentinelElapsedWarnings(record(publish).elapsedMs, "sentinel publish", numberAt(state.cicd, "targetValidation.maxSeconds")), ], blocker: ok ? null @@ -647,10 +647,10 @@ function runSentinelControlPlaneConfirmed(state: SentinelCicdState, options: Ext targetValidation, elapsedMs, warnings: Array.from(new Set([ - ...sentinelElapsedWarnings(elapsedMs), - ...sentinelElapsedWarnings(record(sourceMirrorSync).elapsedMs), - ...sentinelElapsedWarnings(record(publish).elapsedMs), - ...sentinelElapsedWarnings(record(flush).result === undefined ? null : record(record(flush).result).durationMs), + ...sentinelElapsedWarnings(elapsedMs, "sentinel confirmed operation", numberAt(state.cicd, "targetValidation.maxSeconds")), + ...sentinelElapsedWarnings(record(sourceMirrorSync).elapsedMs, "sentinel source mirror sync", numberAt(state.cicd, "targetValidation.maxSeconds")), + ...sentinelElapsedWarnings(record(publish).elapsedMs, "sentinel publish", numberAt(state.cicd, "targetValidation.maxSeconds")), + ...sentinelElapsedWarnings(record(flush).result === undefined ? null : record(record(flush).result).durationMs, "sentinel git-mirror flush", numberAt(state.cicd, "targetValidation.maxSeconds")), ...(Array.isArray(record(targetValidation).warnings) ? record(targetValidation).warnings.map(text) : []), ...(targetValidationBlocked ? ["targetValidation is blocked; top-level STATUS only covers sentinel control-plane rollout. HWLAB business recovery remains pending; rerun quick verify after internal DB switch completes, without public fallback or a second execution path."] : []), ])), @@ -869,6 +869,8 @@ function runSentinelSourceMirrorSyncJob(state: SentinelCicdState, timeoutSeconds } const startedAt = Date.now(); const timeoutMs = Math.max(30_000, Math.min(timeoutSeconds * 1000, 900_000)); + const warningBudgetMs = Math.max(1, Math.trunc(numberAt(state.cicd, "targetValidation.maxSeconds"))) * 1000; + let slowWarningSent = false; let polls = 0; let lastProbe: Record = {}; while (Date.now() - startedAt < timeoutMs) { @@ -895,7 +897,10 @@ function runSentinelSourceMirrorSyncJob(state: SentinelCicdState, timeoutSeconds if (probe.failed === true) { return { ok: false, phase: "job-failed", jobName, payload: Object.keys(payload).length === 0 ? { ok: false, status: "failed", valuesRedacted: true } : payload, polls, elapsedMs: Date.now() - startedAt, probe: lastProbe, valuesRedacted: true }; } - if (Date.now() - startedAt > 120_000) sentinelProgressEvent("sentinel.source-mirror.warning", { warning: "source mirror sync exceeded 120s; investigate env-reuse/git mirror/source build path", jobName, elapsedMs: Date.now() - startedAt, node: state.spec.nodeId, lane: state.spec.lane }); + if (!slowWarningSent && Date.now() - startedAt > warningBudgetMs) { + slowWarningSent = true; + sentinelProgressEvent("sentinel.source-mirror.warning", { warning: `source mirror sync exceeded configured ${Math.round(warningBudgetMs / 1000)}s timing budget; non-blocking timing alert`, jobName, elapsedMs: Date.now() - startedAt, node: state.spec.nodeId, lane: state.spec.lane }); + } runCommand(["sleep", "5"], repoRoot, { timeoutMs: 6_000 }); } return { ok: false, phase: "job-timeout", jobName, payload: { ok: false, status: "timeout", valuesRedacted: true }, polls, elapsedMs: Date.now() - startedAt, probe: lastProbe, valuesRedacted: true }; @@ -1107,6 +1112,8 @@ function runSentinelPublishJob(state: SentinelCicdState, publishGitops: boolean, sentinelProgressEvent("sentinel.publish.progress", { phase: "create-job", status: "succeeded", jobName, publishGitops, node: state.spec.nodeId, lane: state.spec.lane }); const startedAt = Date.now(); const timeoutMs = Math.max(30_000, Math.min(timeoutSeconds * 1000, 900_000)); + const warningBudgetMs = Math.max(1, Math.trunc(numberAt(state.cicd, "targetValidation.maxSeconds"))) * 1000; + let slowWarningSent = false; let polls = 0; let lastProbe: Record = {}; while (Date.now() - startedAt < timeoutMs) { @@ -1134,7 +1141,10 @@ function runSentinelPublishJob(state: SentinelCicdState, publishGitops: boolean, if (probe.failed === true) { return { ok: false, phase: "job-failed", jobName, payload: Object.keys(payload).length === 0 ? { ok: false, status: "failed", valuesRedacted: true } : payload, polls, elapsedMs: Date.now() - startedAt, probe: lastProbe, valuesRedacted: true }; } - if (Date.now() - startedAt > 120_000) sentinelProgressEvent("sentinel.publish.warning", { warning: "remote job exceeded 120s; investigate env-reuse/git mirror/source build path", jobName, elapsedMs: Date.now() - startedAt, node: state.spec.nodeId, lane: state.spec.lane }); + if (!slowWarningSent && Date.now() - startedAt > warningBudgetMs) { + slowWarningSent = true; + sentinelProgressEvent("sentinel.publish.warning", { warning: `remote publish job exceeded configured ${Math.round(warningBudgetMs / 1000)}s timing budget; non-blocking timing alert`, jobName, elapsedMs: Date.now() - startedAt, node: state.spec.nodeId, lane: state.spec.lane }); + } runCommand(["sleep", "5"], repoRoot, { timeoutMs: 6_000 }); } return { ok: false, phase: "job-timeout", jobName, payload: { ok: false, status: "timeout", valuesRedacted: true }, polls, elapsedMs: Date.now() - startedAt, probe: lastProbe, valuesRedacted: true }; @@ -1350,10 +1360,11 @@ function sentinelPayloadFromLogs(logsTail: string): Record { return {}; } -function sentinelElapsedWarnings(value: unknown, subject = "sentinel confirmed operation"): string[] { +function sentinelElapsedWarnings(value: unknown, subject = "sentinel confirmed operation", budgetSeconds = 120): string[] { const elapsedMs = typeof value === "number" && Number.isFinite(value) ? value : null; - if (elapsedMs === null || elapsedMs <= 120_000) return []; - return [`${subject} exceeded 120s (${Math.round(elapsedMs / 1000)}s); treat this as a severe timeout and investigate env-reuse/git mirror/source build path plus the current wait stage before retrying.`]; + const budgetMs = Math.max(1, Math.trunc(budgetSeconds)) * 1000; + if (elapsedMs === null || elapsedMs <= budgetMs) return []; + return [`${subject} exceeded configured ${Math.round(budgetMs / 1000)}s timing budget (${Math.round(elapsedMs / 1000)}s); non-blocking timing alert, investigate wait-stage latency without treating timing alone as HWLAB business blockage.`]; } function targetValidationElapsedWarnings(value: unknown, subject: string, budgetSeconds: number): string[] { @@ -1818,7 +1829,10 @@ function finalizeQuickVerifyFailure(state: SentinelCicdState, input: { findings, screenshot: record(artifactSummary).screenshot, publicOrigin: stringAt(state.publicExposure, "publicBaseUrl"), - warnings: mergeWarnings(Array.isArray(input.warnings) ? input.warnings : [], sentinelElapsedWarnings(input.elapsedMs ?? null, "quick verify confirm-wait")), + warnings: mergeWarnings( + Array.isArray(input.warnings) ? input.warnings : [], + targetValidationElapsedWarnings(input.elapsedMs ?? null, "quick verify confirm-wait", numberAt(state.cicd, "targetValidation.maxSeconds")), + ), valuesRedacted: true, }; } @@ -2296,6 +2310,7 @@ function quickVerifyPromptWaitScript(stateDir: string, promptIndex: number, time " }", "};", "const readDone = (id) => id ? readJson(path.join('commands', 'done', `${id}.json`)) : null;", + "const readFailed = (id) => id ? readJson(path.join('commands', 'failed', `${id}.json`)) : null;", "function sessionIdFromUrl(value) { const match = String(value || '').match(/\\/workbench\\/sessions\\/(ses_[A-Za-z0-9_-]+)/u); return match ? match[1] : null; }", "function commandSessionId(item) { const done = readDone(item?.commandId); return item?.sessionId || item?.detail?.sessionId || item?.input?.sessionId || item?.result?.sessionId || done?.result?.sessionId || done?.result?.observer?.sessionId || sessionIdFromUrl(item?.afterUrl) || sessionIdFromUrl(item?.detail?.afterUrl) || sessionIdFromUrl(done?.result?.afterUrl) || null; }", "function firstTraceId(value) { const match = String(value || '').match(/\\btrc_[A-Za-z0-9_-]+\\b/u); return match ? match[0] : null; }", @@ -2332,8 +2347,13 @@ function quickVerifyPromptWaitScript(stateDir: string, promptIndex: number, time " const prompts = promptCommands(control);", " const prompt = prompts[promptIndex - 1] || null;", " if (!prompt) return { ok: true, round: promptIndex, status: null, traceId: null, finalResponseEmpty: true, lastSeq: null, lastTs: null, valuesRedacted: true };", + " const done = readDone(prompt.commandId);", + " const failed = readFailed(prompt.commandId);", + " if (failed) return { ok: false, failure: 'observe-command-sendPrompt-failed', round: promptIndex, status: 'command-failed', commandId: prompt.commandId || null, traceId: null, finalResponseEmpty: true, commandFailure: short(failed.error?.message || failed.failure || failed.status || 'command failed'), valuesRedacted: true };", + " const promptTraceId = commandTraceId(prompt);", + " if (!done || !promptTraceId) return { ok: true, round: promptIndex, status: 'command-pending', commandId: prompt.commandId || null, traceId: null, finalResponseEmpty: true, commandPhase: prompt.phase || null, valuesRedacted: true };", " const segment = segmentFor(samples, prompts, promptIndex - 1);", - " const traceId = chooseTraceId(segment, prompt);", + " const traceId = promptTraceId || chooseTraceId(segment, prompt);", " const status = statusFor(segment, traceId);", " const sampleForTrace = traceId ? segment.filter((sample) => traceIdsFromSamples([sample]).includes(traceId)).slice(-1)[0] || null : null;", " const lastSample = sampleForTrace || segment.slice(-1)[0] || null;",