From 593401e94869e4df70de90a56d92519184436859 Mon Sep 17 00:00:00 2001 From: RoboClaw Date: Sun, 27 Sep 2026 07:15:55 -0700 Subject: [PATCH] fix(ci): expose bounded Docker survivor failure metadata (#159659) * fix(ci): expose bounded Docker survivor failure metadata Keep diagnostic artifacts and outcomes unchanged. Publish only redacted phase, exit and signal coordinates plus scheduler status and timeout flags as check annotations. Hosted review and CI remain pending; local dependency admission was unavailable. Co-authored-by: RomneyDa <6581799+RomneyDa@users.noreply.github.com> * fix(ci): retain survivor metadata beyond clipped failure tails Use a bounded host metadata pipe within the existing scheduler process owner. Validate the three fields and emit only after process-group and log cleanup. Preserve artifact bytes and all lane outcomes. Fix the publisher consistent-return lint defect. Co-authored-by: RomneyDa <6581799+RomneyDa@users.noreply.github.com> * fix(ci): use typed Docker timeout flags directly Remove two unnecessary boolean comparisons without changing annotation output or failure handling. Co-authored-by: RomneyDa <6581799+RomneyDa@users.noreply.github.com> --------- Co-authored-by: RomneyDa <6581799+RomneyDa@users.noreply.github.com> --- .../e2e/lib/upgrade-survivor/diagnostics.mjs | 8 +- scripts/test-docker-all.mts | 71 +++++++++++++- scripts/upgrade-survivor-diagnostics.mjs | 20 +++- test/scripts/docker-all-harness.test.ts | 75 +++++++++++++++ test/scripts/docker-all-scheduler.test.ts | 43 +++++++++ ...ade-survivor-migration-diagnostics.test.ts | 96 ++++++++++++++++++- 6 files changed, 307 insertions(+), 6 deletions(-) diff --git a/scripts/e2e/lib/upgrade-survivor/diagnostics.mjs b/scripts/e2e/lib/upgrade-survivor/diagnostics.mjs index 14866fdaa874..be6ddb7b7e30 100644 --- a/scripts/e2e/lib/upgrade-survivor/diagnostics.mjs +++ b/scripts/e2e/lib/upgrade-survivor/diagnostics.mjs @@ -1831,7 +1831,7 @@ export function publishDiagnostics( publishedSuccessSummary(artifactRoot, sanitize), publicLimit, ); - return; + return undefined; } if (outcome !== "failed") { throw new Error(); @@ -2018,6 +2018,12 @@ export function publishDiagnostics( "Upgrade survivor diagnostics: some inputs omitted; see failure.json omissions.\n", ); } + // Return only published failure coordinates; logs and configuration stay in the artifact. + return { + phase: sanitize(report.phase, "phase"), + exitStatus: report.exitStatus, + signal: report.signal, + }; } if (import.meta.main) { diff --git a/scripts/test-docker-all.mts b/scripts/test-docker-all.mts index 95d5cafddf20..606765e55c14 100644 --- a/scripts/test-docker-all.mts +++ b/scripts/test-docker-all.mts @@ -8,6 +8,7 @@ import { randomUUID } from "node:crypto"; import fs from "node:fs"; import { mkdir, open, readFile } from "node:fs/promises"; import path from "node:path"; +import { Readable } from "node:stream"; import { finished } from "node:stream/promises"; import { fileURLToPath } from "node:url"; import { coerceErrorMessage } from "@openclaw/normalization-core/error-coercion"; @@ -110,6 +111,7 @@ type ShellCommandOptions = { env: NodeJS.ProcessEnv; label: string; logFile?: string; + captureUpgradeFailure?: boolean; noOutputTimeoutMs?: number; timeoutKillGraceMs?: number; timeoutMs?: number; @@ -920,6 +922,7 @@ export function runShellCommand({ env, label, logFile, + captureUpgradeFailure = false, timeoutMs, noOutputTimeoutMs, timeoutKillGraceMs = SHELL_TIMEOUT_KILL_GRACE_MS, @@ -934,13 +937,32 @@ export function runShellCommand({ timeoutKillGraceMs, SHELL_TIMEOUT_KILL_GRACE_MS, ); - const pipeOutput = Boolean(logFile || resolvedNoOutputTimeoutMs); + const pipeOutput = Boolean(logFile || resolvedNoOutputTimeoutMs || captureUpgradeFailure); const child = spawn("bash", ["-c", command], { cwd: ROOT_DIR, detached: process.platform !== "win32", - env, - stdio: pipeOutput ? ["ignore", "pipe", "pipe"] : "inherit", + env: captureUpgradeFailure ? { ...env, OPENCLAW_DOCKER_FAILURE_METADATA_FD: "3" } : env, + stdio: captureUpgradeFailure + ? ["ignore", "pipe", "pipe", "pipe"] + : pipeOutput + ? ["ignore", "pipe", "pipe"] + : "inherit", }); + // Host publication has a private pipe, never parsed from candidate stdout or + // stderr. Drain it through child close; emit only after process and log cleanup. + let failureMetadata: Buffer | undefined = Buffer.alloc(0); + const metadataPipe = captureUpgradeFailure ? child.stdio[3] : undefined; + if (metadataPipe instanceof Readable) { + metadataPipe.on("data", (chunk: Buffer) => { + failureMetadata = + failureMetadata && failureMetadata.length + chunk.length <= 1024 + ? Buffer.concat([failureMetadata, chunk]) + : undefined; + }); + metadataPipe.on("error", () => { + failureMetadata = undefined; + }); + } activeChildren.set(child, resolvedTimeoutKillGraceMs); let timedOut = false; let noOutputTimedOut = false; @@ -1075,6 +1097,9 @@ export function runShellCommand({ cause: errors[0], }); } + if (exitCode !== 0 && env.GITHUB_ACTIONS === "true") { + printUpgradeFailureMetadata(failureMetadata); + } resolve({ signal, status: exitCode, @@ -1534,6 +1559,8 @@ async function runLane( env, label: name, logFile, + captureUpgradeFailure: + env.GITHUB_ACTIONS === "true" && lane.stateScenario === "upgrade-survivor", timeoutMs, noOutputTimeoutMs, }); @@ -1773,9 +1800,47 @@ export async function tailFile(file: string, lines: number, maxBytes = LOG_TAIL_ return tail.trimEnd(); } +function printUpgradeFailureMetadata(bytes: Buffer | undefined) { + if (!bytes?.length) { + return; + } + let failure: unknown; + try { + failure = JSON.parse(bytes.toString("utf8")); + } catch { + return; + } + if ( + !isRecord(failure) || + Object.keys(failure).length !== 3 || + typeof failure.phase !== "string" || + !/^[a-z0-9-]{1,80}$/u.test(failure.phase) || + typeof failure.exitStatus !== "number" || + !Number.isInteger(failure.exitStatus) || + failure.exitStatus < 0 || + failure.exitStatus > 255 || + (failure.signal !== null && + failure.signal !== "SIGHUP" && + failure.signal !== "SIGINT" && + failure.signal !== "SIGTERM") + ) { + return; + } + console.error( + `::error title=Upgrade survivor failure::phase=${failure.phase}; exitStatus=${failure.exitStatus}; signal=${failure.signal ?? "none"}`, + ); +} + async function printFailureSummary(failures: LaneResult[], tailLines: number) { console.error(`ERROR: ${failures.length} Docker lane(s) failed.`); for (const failure of failures) { + // Keep commands, paths, and captured output out of check annotations. + if (process.env.GITHUB_ACTIONS === "true") { + const status = Number.isInteger(failure.status) ? failure.status : "unknown"; + console.error( + `::error title=Docker lane failure::status=${status}; timedOut=${failure.timedOut}; noOutputTimedOut=${failure.noOutputTimedOut}`, + ); + } console.error(`---- ${failure.name} failed (status=${failure.status}): ${failure.logFile}`); const tail = await tailFile(failure.logFile, tailLines); if (tail) { diff --git a/scripts/upgrade-survivor-diagnostics.mjs b/scripts/upgrade-survivor-diagnostics.mjs index 0c0ab14d1589..fe154ca3a95e 100644 --- a/scripts/upgrade-survivor-diagnostics.mjs +++ b/scripts/upgrade-survivor-diagnostics.mjs @@ -1,5 +1,6 @@ // Host-only entrypoint: this file and app source are never mounted into the // package-under-test container. Keep the capture module dependency-light. +import { writeSync } from "node:fs"; import { publishDiagnostics } from "./e2e/lib/upgrade-survivor/diagnostics.mjs"; try { @@ -9,7 +10,24 @@ try { } // The wrapper registers this harness's scripts/tsx.mjs before loading source. const { redactSensitiveText } = await import("../src/logging/redact.ts"); - publishDiagnostics(artifactRoot, destination, redactSensitiveText, outcome); + const failure = publishDiagnostics(artifactRoot, destination, redactSensitiveText, outcome); + // Use the host scheduler pipe, which is not forwarded into the container. + // Wrapper cleanup and bounded log tails cannot clip this published receipt. + if (failure && process.env.OPENCLAW_DOCKER_FAILURE_METADATA_FD === "3") { + try { + writeSync(3, `${JSON.stringify(failure)}\n`); + } catch { + process.stderr.write("Upgrade survivor failure metadata unavailable.\n"); + } + } else if (process.env.GITHUB_ACTIONS === "true" && failure) { + const phase = failure.phase + .replaceAll("%", "%25") + .replaceAll("\r", "%0D") + .replaceAll("\n", "%0A"); + process.stderr.write( + `::error title=Upgrade survivor failure::phase=${phase}; exitStatus=${failure.exitStatus}; signal=${failure.signal ?? "none"}\n`, + ); + } } catch { process.stderr.write("Upgrade survivor diagnostics missing: safe host publication failed.\n"); process.exitCode = 1; diff --git a/test/scripts/docker-all-harness.test.ts b/test/scripts/docker-all-harness.test.ts index 4b3b2c4f78d4..eabe5356b0e8 100644 --- a/test/scripts/docker-all-harness.test.ts +++ b/test/scripts/docker-all-harness.test.ts @@ -1311,6 +1311,74 @@ describe("Docker scheduler trusted harness execution", () => { }, ); + posixIt("retains host-published survivor metadata after cleanup with a one-line tail", () => { + const fixture = setupFixture("split"); + const catalog = path.join(fixture.harness, "scripts/lib/docker-e2e-scenarios.mts"); + writeFileSync( + catalog, + readFileSync(catalog, "utf8") + + '\nmainLanes.find(lane => lane.name === "gateway-concurrency").stateScenario = "upgrade-survivor";\n', + ); + const artifacts = path.join(fixture.root, "private"); + mkdirSync(path.join(artifacts, "diagnostics"), { recursive: true }); + writeFileSync( + path.join(artifacts, "diagnostics/raw.json"), + JSON.stringify({ + phase: "recovery-update-restart", + exitStatus: 7, + signal: null, + logs: { "update.err": "PRIVATE_LOG_BYTES" }, + environment: { TOKEN: "PRIVATE_ENV_BYTES" }, + }), + ); + const published = path.join(fixture.root, "public"); + const cleaned = path.join(fixture.root, "cleanup-complete"); + writeFileSync( + path.join(fixture.harness, "scripts/e2e/gateway-concurrency-docker.sh"), + [ + "#!/usr/bin/env bash", + "set -euo pipefail", + "cleanup() { printf settled > " + + quote(cleaned) + + '; printf "[upgrade-survivor] FAILED (exit 7)\\n" >&2; }', + "trap cleanup EXIT", + [ + quote(process.execPath), + "--import", + quote(path.resolve("scripts/tsx.mjs")), + quote(path.resolve("scripts/upgrade-survivor-diagnostics.mjs")), + "publish", + quote(artifacts), + quote(published), + ].join(" "), + "exit 7", + "", + ].join("\n"), + ); + const { result, logDir } = runFixture(fixture, "split", ["gateway-concurrency"], { + env: { GITHUB_ACTIONS: "true", OPENCLAW_DOCKER_ALL_FAILURE_TAIL_LINES: "1" }, + }); + expect(result.status, result.stdout + result.stderr).toBe(1); + expect(readFileSync(cleaned, "utf8")).toBe("settled"); + expect(readFileSync(path.join(logDir, "gateway-concurrency.log"), "utf8")).toContain( + "[upgrade-survivor] FAILED (exit 7)", + ); + const annotations = result.stderr.split("\n").filter((line) => line.startsWith("::error")); + expect(annotations).toEqual([ + "::error title=Upgrade survivor failure::phase=recovery-update-restart; exitStatus=7; signal=none", + "::error title=Docker lane failure::status=7; timedOut=false; noOutputTimedOut=false", + ]); + expect(annotations.join("")).not.toContain("PRIVATE"); + expect(annotations.join("")).not.toContain(fixture.root); + const summary = JSON.parse(readFileSync(path.join(logDir, "summary.json"), "utf8")); + expect(summary).toMatchObject({ + status: "failed", + cleanup: { joined: true }, + lanes: [{ status: 7 }], + }); + expect(summary.lanes[0]).not.toHaveProperty("failureMetadata"); + }); + posixIt.each(["timeout", "deterministic failure", "rate limited", "ECONNRESET"])( "fails on the first lane outcome: %s", (failure) => { @@ -1350,6 +1418,7 @@ if (${JSON.stringify(failure)} === "timeout") { ["live-models", "gateway-concurrency"], { env: { + GITHUB_ACTIONS: "true", OPENCLAW_DOCKER_ALL_FAIL_FAST: "0", OPENCLAW_DOCKER_ALL_PARALLELISM: "1", }, @@ -1362,6 +1431,12 @@ if (${JSON.stringify(failure)} === "timeout") { expect(live.attempts).toHaveLength(1); expect(live.status).not.toBe(0); expect(live.timedOut).toBe(failure === "timeout"); + const annotations = result.stderr.split("\n").filter((line) => line.startsWith("::error")); + expect(annotations).toEqual([ + `::error title=Docker lane failure::status=${live.status}; timedOut=${failure === "timeout"}; noOutputTimedOut=false`, + ]); + expect(annotations.join("")).not.toContain(command); + expect(annotations.join("")).not.toContain(fixture.root); expect( summary.lanes.find((lane: { name: string }) => lane.name === "gateway-concurrency").status, ).toBe(0); diff --git a/test/scripts/docker-all-scheduler.test.ts b/test/scripts/docker-all-scheduler.test.ts index f53f047ba4d9..0406bdc57463 100644 --- a/test/scripts/docker-all-scheduler.test.ts +++ b/test/scripts/docker-all-scheduler.test.ts @@ -1221,6 +1221,49 @@ postgres Created } }); + posixIt.each(["extra field", "oversized", "two receipts", "injected phase"])( + "never promotes logs or invalid %s metadata into an annotation", + async (kind) => { + const root = tempDirs.make("docker-failure-metadata-"); + const logFile = path.join(root, "lane.log"); + const metadata = { phase: "update-candidate", exitStatus: 7, signal: null }; + const valid = JSON.stringify(metadata); + const payload = + kind === "oversized" + ? "x".repeat(1025) + : kind === "two receipts" + ? valid + valid + : JSON.stringify( + kind === "extra field" + ? { ...metadata, secret: "PRIVATE_ENV_BYTES" } + : { ...metadata, phase: "update\n::error::PRIVATE_LOG_BYTES" }, + ); + const program = [ + "const fs = require('node:fs');", + "console.error(" + JSON.stringify(valid) + ");", + "fs.writeSync(3," + JSON.stringify(payload) + ");", + "process.exitCode = 7;", + ].join("\n"); + const entry = path.join(root, "metadata.cjs"); + writeFileSync(entry, program); + const error = vi.spyOn(console, "error").mockImplementation(() => {}); + try { + const result = await runShellCommand({ + command: JSON.stringify(process.execPath) + " " + JSON.stringify(entry), + env: { ...process.env, GITHUB_ACTIONS: "true" }, + label: "metadata", + logFile, + captureUpgradeFailure: true, + }); + expect(result).toMatchObject({ status: 7, timedOut: false, noOutputTimedOut: false }); + expect(error.mock.calls.some(([text]) => String(text).startsWith("::error"))).toBe(false); + expect(readFileSync(logFile, "utf8")).toContain(valid); + } finally { + error.mockRestore(); + } + }, + ); + posixIt("clamps oversized shell command timers before scheduling", async () => { const result = await runShellCommand({ command: `exec ${JSON.stringify(process.execPath)} -e ${JSON.stringify( diff --git a/test/scripts/upgrade-survivor-migration-diagnostics.test.ts b/test/scripts/upgrade-survivor-migration-diagnostics.test.ts index 2cc36a3637d8..3824dbbcefa7 100644 --- a/test/scripts/upgrade-survivor-migration-diagnostics.test.ts +++ b/test/scripts/upgrade-survivor-migration-diagnostics.test.ts @@ -4,12 +4,17 @@ import fs from "node:fs"; import path from "node:path"; import { DatabaseSync } from "node:sqlite"; import { pathToFileURL } from "node:url"; -import { afterEach, expect, it } from "vitest"; +import { afterEach, expect, it, vi } from "vitest"; import { publishDiagnostics } from "../../scripts/e2e/lib/upgrade-survivor/diagnostics.mjs"; import { redactSensitiveText } from "../../src/logging/redact.js"; import { resolveTestNodeExecPath } from "../../src/test-utils/node-process.js"; import { useAutoCleanupTempDirTracker } from "../helpers/temp-dir.js"; +afterEach(() => { + vi.restoreAllMocks(); + vi.unstubAllEnvs(); +}); + const dirs = useAutoCleanupTempDirTracker(afterEach); const node = resolveTestNodeExecPath(); const observer = path.resolve("scripts/e2e/lib/upgrade-survivor/diagnostics.mjs"); @@ -79,6 +84,92 @@ function capture(f: ReturnType, outcome: "failed" | "passed" = " return JSON.parse(text); } +it("returns only redacted failure coordinates after safe publication", () => { + const f = fixture(); + vi.stubEnv("GITHUB_ACTIONS", "true"); + const stderr = vi.spyOn(process.stderr, "write").mockReturnValue(true); + const raw = { + phase: "update-candidate", + exitStatus: 143, + signal: "SIGTERM", + logs: { "update.err": `${secret} ${privateBody} ::error::private-log` }, + command: privateBody, + environment: { TOKEN: secret }, + }; + write(path.join(f.artifacts, "diagnostics/raw.json"), raw); + const output = path.join(f.root, "public"); + const redact = (text: string) => + text === raw.phase ? "safe%phase\r\n::error::not-another-command" : redactSensitiveText(text); + const failure = publishDiagnostics(f.artifacts, output, redact); + expect(failure).toEqual({ + phase: "safe%phase\r\n::error::not-another-command", + exitStatus: 143, + signal: "SIGTERM", + }); + expect(JSON.stringify(failure)).not.toContain(secret); + expect(JSON.stringify(failure)).not.toContain(privateBody); + expect(stderr.mock.calls.some(([text]) => String(text).startsWith("::error"))).toBe(false); + expect(JSON.parse(fs.readFileSync(path.join(output, "failure.json"), "utf8"))).toMatchObject({ + phase: raw.phase, + exitStatus: 143, + signal: "SIGTERM", + }); +}); + +it("does not annotate local runs, invalid snapshots, or failed publication", () => { + const f = fixture(); + const stderr = vi.spyOn(process.stderr, "write").mockReturnValue(true); + const rawPath = path.join(f.artifacts, "diagnostics/raw.json"); + const raw = { phase: "update-candidate", exitStatus: 1, signal: null }; + write(rawPath, raw); + vi.stubEnv("GITHUB_ACTIONS", "false"); + publishDiagnostics(f.artifacts, path.join(f.root, "local"), redactSensitiveText); + vi.stubEnv("GITHUB_ACTIONS", "true"); + write(rawPath, { ...raw, phase: "update\n::error::injected" }); + expect(() => + publishDiagnostics(f.artifacts, path.join(f.root, "invalid"), redactSensitiveText), + ).toThrow(); + write(rawPath, raw); + const blocked = path.join(f.root, "blocked"); + fs.writeFileSync(blocked, "not a directory"); + expect(() => publishDiagnostics(f.artifacts, blocked, redactSensitiveText)).toThrow(); + expect(stderr.mock.calls.some(([text]) => String(text).startsWith("::error"))).toBe(false); +}); + +it("emits the published failure metadata through the host CLI without changing its exit status", () => { + const f = fixture(); + write(path.join(f.artifacts, "diagnostics/raw.json"), { + phase: "recovery-update-restart", + exitStatus: 1, + signal: null, + logs: { "update.err": `${secret} ${privateBody}` }, + }); + const destination = path.join(f.root, "public"); + const result = spawnSync( + node, + [ + "--import", + path.resolve("scripts/tsx.mjs"), + path.resolve("scripts/upgrade-survivor-diagnostics.mjs"), + "publish", + f.artifacts, + destination, + ], + { env: { ...f.env, GITHUB_ACTIONS: "true" }, encoding: "utf8", timeout: 10_000 }, + ); + expect(result.status, result.stderr).toBe(0); + expect(result.stderr.split("\n").filter((line) => line.startsWith("::error"))).toEqual([ + "::error title=Upgrade survivor failure::phase=recovery-update-restart; exitStatus=1; signal=none", + ]); + expect(result.stderr).not.toContain(secret); + expect(result.stderr).not.toContain(privateBody); + const control = path.join(f.root, "unannotated-publication"); + publishDiagnostics(f.artifacts, control, redactSensitiveText); + expect(fs.readFileSync(path.join(destination, "failure.json"), "utf8")).toBe( + fs.readFileSync(path.join(control, "failure.json"), "utf8"), + ); +}); + function pluginPolicyReceipt() { return { baselineVersion: "2026.9.2", @@ -113,11 +204,14 @@ function policySuccessSummary(pluginPolicy: unknown) { it("preserves historical success receipts without adopting policy sidecars", () => { const f = fixture(); + vi.stubEnv("GITHUB_ACTIONS", "true"); + const stderr = vi.spyOn(process.stderr, "write").mockReturnValue(true); write(path.join(f.artifacts, "summary.json"), policySuccessSummary(undefined)); write(path.join(f.artifacts, "webhooks-only-policy/result.json"), { privateBody }); const report = capture(f, "passed"); expect(report).not.toHaveProperty("pluginPolicy"); expect(report.logs).not.toHaveProperty("webhooks-only-policy/result.json"); + expect(stderr.mock.calls.some(([text]) => String(text).startsWith("::error"))).toBe(false); }); it("requires policy evidence when a successful receipt records the completed probe", () => {