diff --git a/docs/cli/update/status-and-history.md b/docs/cli/update/status-and-history.md index 1c79fda7de6b..46514bfc11e0 100644 --- a/docs/cli/update/status-and-history.md +++ b/docs/cli/update/status-and-history.md @@ -323,6 +323,16 @@ diagnostic failures remain warnings, while refused config writes and incomplete required migrations remain errors. Historical runs cannot recover facts that their updater never recorded. +If a candidate check exits by signal, its failed step retains `termination`, +`signal`, and a redacted `stderrTail` (up to 80 lines, 512 characters per line, +and 8,192 characters total, reserving the fatal header when present). The report names the check, including **Checking +data migrations** for Doctor, and shows the native diagnostics ahead of adjacent +plugin warnings. The terminal and local Markdown report retain the excerpt; +the short status report can truncate it. JSON history keeps the bounded excerpt, +and reviewed public reports retain the termination class and recognized signal. This capture +requires the updated updater; a candidate cannot restore diagnostics that an +older installed driver discarded. + Current updaters record their process identities and refresh the ledger every 30 seconds during long build, install, and finalization phases. Those writes pause whenever a Doctor child is repairing state: finalization pauses them diff --git a/docs/reference/database-schemas/agent-schema-history.md b/docs/reference/database-schemas/agent-schema-history.md index a1e61713f2d2..20a0c11f8727 100644 --- a/docs/reference/database-schemas/agent-schema-history.md +++ b/docs/reference/database-schemas/agent-schema-history.md @@ -114,13 +114,15 @@ existing rebuild claims, cursors, active-path rows, and canonical-validation pending rows are preserved. The unpublished compressed schema-22 draft is not a supported predecessor. -The admitted migration converts one transcript record at a time, verifies each -compressed frame against its original bytes, preserves row identities and -timestamps, and commits table replacements with both schema markers. Unknown -columns or dependencies that a rebuild would discard cause a refusal. Earlier -supported schemas run their prerequisite migrations first. Conversion needs -temporary space for old and replacement tables, journal/WAL activity, and the -verified backup. Freed pages are reusable; a smaller payload does not by itself +The admitted migration converts one transcript record or memory vector at a time, +verifies each compressed transcript frame against its original bytes, preserves +row identities and timestamps, and commits table replacements with both schema +markers. Memory validation and conversion return from SQLite after each row so +large legacy embedding caches do not accumulate their JSON strings in the +JavaScript heap. Unknown columns or dependencies that a rebuild would discard +cause a refusal. Earlier supported schemas run their prerequisite migrations +first. Conversion needs temporary space for old and replacement tables, +journal/WAL activity, and the verified backup. Freed pages are reusable; a smaller payload does not by itself shrink the database file. Existing maintenance owns physical reclamation. Stop all writers and take a verified WAL-aware backup before upgrading. Supported diff --git a/packages/gateway-protocol/src/schema/update-runs.ts b/packages/gateway-protocol/src/schema/update-runs.ts index c0baf70b1d47..b9a9e2b1c858 100644 --- a/packages/gateway-protocol/src/schema/update-runs.ts +++ b/packages/gateway-protocol/src/schema/update-runs.ts @@ -129,6 +129,9 @@ export const UpdateRunRecordSchema = closedObject({ startedAtMs: Type.Optional(timestamp), endedAtMs: Type.Optional(timestamp), exitCode: Type.Optional(Type.Union([Type.Integer(), Type.Null()])), + termination: Type.Optional(Type.Enum(["exit", "timeout", "no-output-timeout", "signal"])), + signal: Type.Optional(Type.Union([Type.String({ maxLength: 32 }), Type.Null()])), + stderrTail: Type.Optional(Type.String({ maxLength: 8192 })), detail: Type.Optional(text), failureFacts: Type.Optional( Type.Array( diff --git a/packages/memory-host-sdk/src/host/memory-schema-storage-migration.test.ts b/packages/memory-host-sdk/src/host/memory-schema-storage-migration.test.ts index c1686b846e5c..cdc9bf786ee8 100644 --- a/packages/memory-host-sdk/src/host/memory-schema-storage-migration.test.ts +++ b/packages/memory-host-sdk/src/host/memory-schema-storage-migration.test.ts @@ -1,5 +1,8 @@ +import { spawnSync } from "node:child_process"; import { DatabaseSync } from "node:sqlite"; -import { describe, expect, it, onTestFinished, vi } from "vitest"; +import { fileURLToPath } from "node:url"; +import { afterEach, describe, expect, it, onTestFinished, vi } from "vitest"; +import { useAutoCleanupTempDirTracker } from "../../../../test/helpers/temp-dir.js"; import { decodeMemoryEmbedding, encodeMemoryEmbedding } from "./embedding-vector.js"; import { buildMemoryEmbeddingCacheSchema, @@ -7,6 +10,8 @@ import { } from "./memory-schema-base.js"; import { migrateMemoryIndexStorage } from "./memory-schema-storage-migration.js"; +const tempDirs = useAutoCleanupTempDirTracker(afterEach); + function legacyDatabase(): DatabaseSync { const db = new DatabaseSync(":memory:"); onTestFinished(() => db.close()); @@ -64,6 +69,75 @@ function snapshot(db: DatabaseSync) { } describe("memory storage migration", () => { + it("converts legacy vectors larger than the child heap while preserving 64-bit storage identities", () => { + const stateDir = tempDirs.make("memory-storage-heap-"); + const args = [ + "--max-old-space-size=96", + "--import", + fileURLToPath(new URL("../../../../scripts/tsx.mjs", import.meta.url)), + "--input-type=module", + "--eval", + ` + import { DatabaseSync } from 'node:sqlite'; + import { migrateMemoryIndexStorage } from ${JSON.stringify(new URL("./memory-schema-storage-migration.ts", import.meta.url).href)}; + const embedding = JSON.stringify(Array.from({ length: 3072 }, (_, index) => (index + 0.1234567890123456) / 9000)); + const results = []; + for (const kind of ['cache', 'chunks']) { + const db = new DatabaseSync(':memory:'); + const table = kind === 'cache' ? 'memory_embedding_cache' : 'memory_index_chunks'; + db.exec(kind === 'cache' ? + \`CREATE TABLE memory_embedding_cache ( + provider TEXT NOT NULL, model TEXT NOT NULL, provider_key TEXT NOT NULL, + hash TEXT NOT NULL, embedding TEXT NOT NULL, dims INTEGER, updated_at INTEGER NOT NULL, + PRIMARY KEY (provider, model, provider_key, hash) + ) STRICT;\` : + \`CREATE TABLE memory_index_meta (key TEXT PRIMARY KEY, value TEXT NOT NULL) STRICT; + CREATE TABLE memory_index_sources ( + path TEXT NOT NULL, source TEXT NOT NULL, hash TEXT NOT NULL, UNIQUE (path, source) + ) STRICT; + CREATE TABLE memory_index_chunks ( + id TEXT PRIMARY KEY, path TEXT NOT NULL, source TEXT NOT NULL DEFAULT 'memory', + start_line INTEGER NOT NULL, end_line INTEGER NOT NULL, hash TEXT NOT NULL, + model TEXT NOT NULL, text TEXT NOT NULL, embedding TEXT NOT NULL, updated_at INTEGER NOT NULL + ) STRICT;\`); + const insert = db.prepare(kind === 'cache' ? + "INSERT INTO memory_embedding_cache(rowid, provider, model, provider_key, hash, embedding, dims, updated_at) VALUES (?, 'provider', 'model', 'key', ?, ?, 3072, 123)" : + "INSERT INTO memory_index_chunks(rowid, id, path, source, start_line, end_line, hash, model, text, embedding, updated_at) VALUES (?, ?, 'memory/a.md', 'memory', 1, 2, 'h', 'model', CAST(X'80' AS TEXT), ?, 123)"); + insert.setReadBigInts(true); + for (let index = 0; index < 3000; index++) { + insert.run(9007199254740993n + BigInt(index), String(index), embedding); + } + migrateMemoryIndexStorage(db); + results.push(db.prepare(\`SELECT count(*) AS rows, sum(length(embedding)) AS bytes, + CAST(min(rowid) AS TEXT) AS first, CAST(max(rowid) AS TEXT) AS last + FROM \${table}\`).get()); + if (kind === 'chunks') { + results.push(db.prepare('SELECT DISTINCT hex(text) AS textBytes FROM memory_index_chunks').get()); + } + db.close(); + } + console.log(JSON.stringify(results)); + `, + ]; + const command = process.platform === "win32" ? process.execPath : "/bin/sh"; + const childArgs = + process.platform === "win32" + ? args + : ["-c", 'ulimit -c 0; exec "$@"', "memory-migration", process.execPath, ...args]; + const result = spawnSync(command, childArgs, { + env: { ...process.env, OPENCLAW_STATE_DIR: stateDir }, + encoding: "utf8", + }); + expect(result.status, result.error?.message ?? result.stderr).toBe(0); + const expected = { + rows: 3000, + bytes: 73_728_000, + first: "9007199254740993", + last: "9007199254743992", + }; + expect(JSON.parse(result.stdout)).toEqual([expected, expected, { textBytes: "80" }]); + }); + it("converts vectors without providers and preserves identity, provenance, cache age, and FTS maintenance", () => { const db = legacyDatabase(); migrateMemoryIndexStorage(db); diff --git a/packages/memory-host-sdk/src/host/memory-schema-storage-migration.ts b/packages/memory-host-sdk/src/host/memory-schema-storage-migration.ts index 25bf0f14f6df..4865b4e2872d 100644 --- a/packages/memory-host-sdk/src/host/memory-schema-storage-migration.ts +++ b/packages/memory-host-sdk/src/host/memory-schema-storage-migration.ts @@ -198,14 +198,58 @@ function storageShapes(db: DatabaseSync, cacheTable: string) { } function assertBinaryEmbeddings(db: DatabaseSync, table: string): void { - if ( - db - .prepare( - `SELECT 1 FROM ${table} WHERE openclaw_memory_embedding_blob_valid(embedding) = 0 LIMIT 1`, - ) - .get() - ) { - throw new Error(`Memory storage migration found invalid binary embeddings in ${table}`); + const rows = db.prepare( + `SELECT openclaw_memory_embedding_blob_valid(embedding) AS valid FROM ${table}`, + ); + for (const row of rows.iterate()) { + if (row.valid === 0) { + throw new Error(`Memory storage migration found invalid binary embeddings in ${table}`); + } + } +} + +function copyMemoryStorageRows(db: DatabaseSync, table: string, sql: string): void { + const rows = db.prepare(`SELECT rowid AS storage_rowid FROM ${table}`); + rows.setReadBigInts(true); + const copy = db.prepare(sql); + copy.setReadBigInts(true); + // node:sqlite retains UDF argument handles until its native call returns. + // Copy one row per call, keeping other persisted fields inside SQLite. + for (const row of rows.iterate()) { + if (typeof row.storage_rowid !== "bigint") { + throw new Error("Invalid memory storage identity during migration"); + } + copy.run(row.storage_rowid); + } +} + +function markInvalidMemoryEmbeddings(db: DatabaseSync, sql: string): void { + const rows = db.prepare(sql); + rows.setReadBigInts(true); + const dirtySource = db.prepare(` + UPDATE main.memory_index_sources SET hash = '' + WHERE (path, source) IN ( + SELECT path, source FROM main.memory_index_chunks WHERE rowid = ? + )`); + dirtySource.setReadBigInts(true); + let invalid = false; + // Project validity instead of filtering on the UDF: each native step must + // return even when every embedding is valid. + for (const row of rows.iterate()) { + if (row.valid === 0) { + if (typeof row.storage_rowid !== "bigint") { + throw new Error("Invalid memory storage identity during migration"); + } + dirtySource.run(row.storage_rowid); + invalid = true; + } + } + if (invalid) { + db.exec(` + INSERT INTO main.memory_index_meta (key, value) + VALUES ('memory_vector_rebuild_v1', '1') + ON CONFLICT(key) DO UPDATE SET value = excluded.value; + `); } } @@ -272,19 +316,16 @@ export function markInvalidImportedMemoryEmbeddings(db: DatabaseSync, schema: st if (!/^[A-Za-z_][A-Za-z0-9_]*$/u.test(schema)) { throw new Error("Invalid legacy memory schema identifier"); } - const invalidChunks = ` - SELECT chunk.path, chunk.source + markInvalidMemoryEmbeddings( + db, + ` + SELECT chunk.rowid AS storage_rowid, + openclaw_memory_embedding_json_valid(legacy.embedding) AS valid FROM ${schema}.chunks AS legacy JOIN main.memory_index_chunks AS chunk ON chunk.id = legacy.id - WHERE openclaw_memory_embedding_json_valid(legacy.embedding) = 0 - AND length(chunk.embedding) = 0`; - db.exec(` - UPDATE main.memory_index_sources SET hash = '' - WHERE (path, source) IN (${invalidChunks}); - INSERT INTO main.memory_index_meta (key, value) - SELECT 'memory_vector_rebuild_v1', '1' WHERE EXISTS (${invalidChunks}) - ON CONFLICT(key) DO UPDATE SET value = excluded.value; - `); + WHERE length(chunk.embedding) = 0 + `, + ); } function columns(db: DatabaseSync, table: string): Map { @@ -341,20 +382,14 @@ export function migrateMemoryIndexStorage( ensureMemoryRecallMetadataSchema(db); // Keep text and provenance searchable, but never invent a vector from // malformed legacy JSON. Source sync owns regeneration of these rows. - db.exec(` - UPDATE memory_index_sources SET hash = '' - WHERE (path, source) IN ( - SELECT path, source FROM memory_index_chunks - WHERE openclaw_memory_embedding_json_valid(embedding) = 0 - ); - INSERT INTO memory_index_meta (key, value) - SELECT 'memory_vector_rebuild_v1', '1' - WHERE EXISTS ( - SELECT 1 FROM memory_index_chunks - WHERE openclaw_memory_embedding_json_valid(embedding) = 0 - ) - ON CONFLICT(key) DO UPDATE SET value = excluded.value; - `); + markInvalidMemoryEmbeddings( + db, + ` + SELECT rowid AS storage_rowid, + openclaw_memory_embedding_json_valid(embedding) AS valid + FROM memory_index_chunks + `, + ); dropMemoryChunkFtsTriggers(db); db.exec( MEMORY_INDEX_CHUNKS_SCHEMA_SQL.replace( @@ -362,13 +397,19 @@ export function migrateMemoryIndexStorage( "CREATE TABLE", ).replace("memory_index_chunks", "memory_index_chunks_storage_migration"), ); - db.exec(` + copyMemoryStorageRows( + db, + "memory_index_chunks", + ` INSERT INTO memory_index_chunks_storage_migration ( chunk_rowid, id, path, source, start_line, end_line, hash, model, text, embedding, updated_at ) SELECT rowid, id, path, source, start_line, end_line, hash, model, text, openclaw_memory_embedding_from_json(embedding), updated_at - FROM memory_index_chunks; + FROM memory_index_chunks WHERE rowid = ? + `, + ); + db.exec(` DROP TABLE memory_index_chunks; ALTER TABLE memory_index_chunks_storage_migration RENAME TO memory_index_chunks; `); @@ -394,11 +435,17 @@ export function migrateMemoryIndexStorage( ); // Empty vectors retain a cache miss for malformed entries. Provider // identity, age, and rowid eviction order survive the conversion. - db.exec(` + copyMemoryStorageRows( + db, + cacheTable, + ` INSERT INTO ${replacement} (rowid, provider, model, provider_key, hash, embedding, dims, updated_at) SELECT rowid, provider, model, provider_key, hash, openclaw_memory_embedding_from_json(embedding), dims, updated_at - FROM ${cacheTable}; + FROM ${cacheTable} WHERE rowid = ? + `, + ); + db.exec(` DROP TABLE ${cacheTable}; ALTER TABLE ${replacement} RENAME TO ${cacheTable}; `); diff --git a/src/cli/update-cli/progress.ts b/src/cli/update-cli/progress.ts index 08f9f3d285f2..2c6cdb9db29d 100644 --- a/src/cli/update-cli/progress.ts +++ b/src/cli/update-cli/progress.ts @@ -262,7 +262,10 @@ function printStep(step: Omit): void { ? [step.stdoutTail, step.stderrTail] : updateStepDiagnostics(step).tails; for (const output of tails) { - for (const line of (output ?? "").trimEnd().split("\n").slice(-10)) { + for (const line of (output ?? "") + .trimEnd() + .split("\n") + .slice(step.termination === "signal" ? -80 : -10)) { if (line.trim()) { defaultRuntime.log(` ${color(line)}`); } diff --git a/src/infra/update-candidate-canary-process.ts b/src/infra/update-candidate-canary-process.ts index 2cafcb61220e..341ff88d0c40 100644 --- a/src/infra/update-candidate-canary-process.ts +++ b/src/infra/update-candidate-canary-process.ts @@ -31,6 +31,9 @@ export function launchCanary(params: { }); let stdout = ""; let lastStderrLine: string | undefined; + const stderrLines: string[] = []; + let fatalHeader: string | undefined; + const stderrTail = () => (fatalHeader ? [fatalHeader, ...stderrLines] : stderrLines).join("\n"); let cliReason: string | undefined; const captureStderr = (line: string) => { if (!line.trim() || line.startsWith(UPDATE_CANARY_PROGRESS_PREFIX)) { @@ -42,6 +45,16 @@ export function launchCanary(params: { Number.MAX_SAFE_INTEGER, ); lastStderrLine = sliceUtf16Safe(safe, -200); + if (safe.startsWith("FATAL ERROR:")) { + // A long native stack must not evict the fatal cause with earlier warnings. + fatalHeader = sliceUtf16Safe(safe, 0, 512); + stderrLines.length = 0; + } else { + stderrLines.push(sliceUtf16Safe(safe, 0, 512)); + } + while (stderrLines.length > (fatalHeader ? 79 : 80) || stderrTail().length > 8192) { + stderrLines.shift(); + } // The CLI prints a generic heading before its actual failure reason. if (line.startsWith("[openclaw] Reason: ")) { cliReason = sliceUtf16Safe(safe.replace(/^\[openclaw\] Reason: /u, ""), -200); @@ -138,7 +151,8 @@ export function launchCanary(params: { hasExited: () => exited, processExited: () => processExited, stdout: () => stdout, - stderrDiagnostic: () => cliReason ?? lastStderrLine, + stderrDiagnostic: () => fatalHeader ?? cliReason ?? lastStderrLine, + stderrTail, outputExceeded: () => outputExceeded, }; } diff --git a/src/infra/update-candidate-canary.exit.process.test.ts b/src/infra/update-candidate-canary.exit.process.test.ts index 52b96daa62ad..cd6ec44d7b9d 100644 --- a/src/infra/update-candidate-canary.exit.process.test.ts +++ b/src/infra/update-candidate-canary.exit.process.test.ts @@ -2,17 +2,30 @@ import fs from "node:fs/promises"; import path from "node:path"; import { afterEach, expect, it, vi } from "vitest"; import { useAutoCleanupTempDirTracker } from "../../test/helpers/temp-dir.js"; +import { closeOpenClawStateDatabaseForTest } from "../state/openclaw-state-db.js"; import { tryListenOnPort } from "./ports-probe.js"; import { validateUpdateCandidateCanary } from "./update-candidate-canary.js"; +import { renderSteps } from "./update-candidate-canary.test-support.js"; import * as rehearsals from "./update-candidate-rehearsal.js"; +import { writeUpdateRunReportArtifact } from "./update-failure-report-artifact.js"; +import { prepareUpdateFailureReport } from "./update-failure-report-prepare.js"; import { buildUpdateRehearsalPathEnv } from "./update-rehearsal-paths.js"; +import { + createUpdateRun, + finishUpdateRun, + getUpdateRun, + recordUpdateRunStep, +} from "./update-run-ledger.js"; import { renderUpdateRunReport, updateRunReportInputFromResult } from "./update-run-report.js"; +import { updateRunStepsFromResultStep } from "./update-run-step.js"; const dirs = useAutoCleanupTempDirTracker(afterEach); afterEach(() => vi.restoreAllMocks()); +afterEach(() => closeOpenClawStateDatabaseForTest()); it.each([ "doctor", + "doctor-signal", "lint", "policy", "missing", @@ -37,11 +50,23 @@ it.each([ path.join(root, "dist", "index.js"), `import { createServer } from "node:http"; import { spawn } from "node:child_process"; +import { writeFileSync } from "node:fs"; const mode = ${JSON.stringify(mode)}; const args = process.argv.slice(2); if (args.includes("--fix")) { + if (mode === "doctor-signal") { + writeFileSync(process.env.OPENCLAW_UPDATE_POST_INSTALL_DOCTOR_RESULT_PATH, JSON.stringify({ + status: "error", failureFacts: [{check: "plugins", code: "doctor-failed", message: "Plugin repair deferred"}], + })); + console.error(Array.from({length: 60}, (_, index) => "earlier warning " + index).join("\\n")); + console.error("FATAL ERROR: synthetic native failure token=synthetic-secret"); + console.error(Array.from({length: 60}, (_, index) => index + ": node::sqlite::DatabaseSync::Exec(v8::FunctionCallbackInfo const&) [openclaw]").join("\\n")); + console.log("adjacent stdout warning\\n".repeat(60)); + process.stderr.write("last native frame", () => process.kill(process.pid, "SIGTERM")); + } else { console.error("└ Doctor complete."); if (mode === "doctor") setInterval(() => {}, 1000); + } } else if (args.includes("--lint")) { if (mode !== "missing") console.log(JSON.stringify({ ok: mode !== "failed" && mode !== "policy", checksRun: 1, @@ -86,12 +111,73 @@ if (args.includes("--fix")) { cleanupDirectories: [], cleanup: async () => {}, }); + const options = { env: { OPENCLAW_STATE_DIR: path.join(root, "ledger") } }; + const run = mode === "doctor-signal" ? createUpdateRun({ trigger: "cli" }, options) : undefined; const result = await validateUpdateCandidateCanary({ root, config: {}, stateDir, timeoutMs: 2_000, + onStep: run + ? (step) => { + for (const receipt of updateRunStepsFromResultStep(step)) { + recordUpdateRunStep(run.runId, receipt, options); + } + } + : undefined, }); + if (run) { + for (let index = 0; index < 24; index++) { + recordUpdateRunStep( + run.runId, + { step: `finalize:fixture-${index}`, status: "completed", detail: "detail ".repeat(140) }, + options, + ); + } + finishUpdateRun(run.runId, { status: "failed", reason: "doctor-failed" }, options); + closeOpenClawStateDatabaseForTest(); + const saved = getUpdateRun(run.runId, options)!; + const crash = saved.steps.find((step) => step.step === "candidate-doctor")!; + expect(result).toMatchObject({ status: "error", phase: "doctor" }); + expect(crash).toMatchObject({ exitCode: null, termination: "signal", signal: "SIGTERM" }); + expect(crash.failureFacts?.[0]).toMatchObject({ check: "doctor", code: "signal" }); + expect(crash.detail).toContain("Checking data migrations"); + expect(crash.stderrTail).toContain("FATAL ERROR: synthetic native failure"); + expect(crash.stderrTail).toContain("0: node::sqlite::DatabaseSync::Exec"); + expect(crash.stderrTail).toContain("last native frame"); + expect(crash.stderrTail?.split("\n").length).toBeLessThanOrEqual(80); + expect(crash.stderrTail!.length).toBeLessThanOrEqual(8192); + expect(crash.stderrTail!.length).toBeGreaterThan(4096); + expect(crash.stderrTail).not.toContain("adjacent stdout"); + expect(JSON.stringify(saved)).not.toContain("synthetic-secret"); + const report = renderUpdateRunReport(saved); + expect(report.markdown).toContain("SIGTERM"); + expect(report.markdown).toContain("Checking data migrations"); + expect(report.markdown).toContain("FATAL ERROR: synthetic native failure"); + expect(report.lines.join("\n")).toContain("last native frame"); + const terminal = renderSteps(result.steps); + expect(terminal).toContain("SIGTERM"); + expect(terminal).toContain("FATAL ERROR: synthetic native failure"); + expect(terminal).toContain("last native frame"); + const failure = { ...result, mode: "npm" as const, root, runId: run.runId }; + const artifact = await writeUpdateRunReportArtifact({ + result: failure, + report, + readRun: () => saved, + env: options.env, + }); + const markdown = await fs.readFile(artifact, "utf8"); + expect(markdown).toContain("FATAL ERROR: synthetic native failure"); + expect(markdown).toContain("last native frame"); + expect(markdown).not.toContain("synthetic-secret"); + const publicReport = await prepareUpdateFailureReport( + { attemptId: run.runId, result: { ...failure, steps: [] }, recordedRun: saved }, + options, + ); + expect(publicReport.body).toContain("termination signal (SIGTERM)"); + expect(publicReport.body).toContain("candidate-doctor"); + return; + } const failedExit = mode === "failed-exit" || mode === "signalled-exit"; const step = result.steps.find((candidate) => failedExit ? candidate.name === "candidate-doctor-lint" : candidate.termination === "timeout", @@ -104,7 +190,9 @@ if (args.includes("--fix")) { expect(result, report).toMatchObject({ status: "error", phase: "lint" }); expect(step.exitCode).toBe(mode === "failed-exit" ? 7 : null); expect(step.signal).toBe(mode === "signalled-exit" ? "SIGTERM" : null); - expect(step.failureFacts).toMatchObject([{ check: "lint", code: "doctor-failed" }]); + expect(step.failureFacts).toMatchObject([ + { check: "lint", code: mode === "signalled-exit" ? "signal" : "doctor-failed" }, + ]); expect(step.advisory).toBeUndefined(); expect(step.warnings).not.toContainEqual(expect.stringContaining("exit phase")); } else if (mode === "missing" || mode === "failed") { diff --git a/src/infra/update-candidate-canary.lint.test.ts b/src/infra/update-candidate-canary.lint.test.ts index 2ff6592a0be0..3c249b3c1d12 100644 --- a/src/infra/update-candidate-canary.lint.test.ts +++ b/src/infra/update-candidate-canary.lint.test.ts @@ -363,7 +363,9 @@ describe("update candidate Doctor lint", () => { expect(renderSteps([step])).toContain( physical.outputLimitExceeded && physical.exitCode === 0 ? "Update health check output exceeded the inspection limit" - : "Update health check failed", + : physical.signal + ? `terminated by ${physical.signal}` + : "Update health check failed", ); expect(renderUpdateRunReport(updateRunReportInputFromResult(failure)).markdown).toContain( "Failed: candidate-doctor-lint", diff --git a/src/infra/update-candidate-canary.ts b/src/infra/update-candidate-canary.ts index af91d231b48e..533a83070f93 100644 --- a/src/infra/update-candidate-canary.ts +++ b/src/infra/update-candidate-canary.ts @@ -45,6 +45,7 @@ import { type UpdatePostInstallDoctorResult, } from "./update-doctor-result.js"; import { + createUpdateCanaryFailureFacts, createUpdateFailureFact, parseConfigFailureFacts, type UpdateFailureFact, @@ -344,6 +345,7 @@ export async function validateUpdateCandidateCanary( }, }); let code: number | null = null; + let signal: NodeJS.Signals | null = null; let doctorAdvisory: UpdateStepResult["advisory"]; let doctorReceipt: UpdatePostInstallDoctorResult | null = null; const pluginFailures: UpdateFailureFact[] = []; @@ -356,6 +358,7 @@ export async function validateUpdateCandidateCanary( // Freeze the winning outcome before teardown can make a killed child // emit a successful close event. code = outcome.status === "completed" ? outcome.value : 1; + signal = outcome.status === "completed" ? running.child.signalCode : null; timedOut = outcome.status === "deadline"; if (timedOut) { const elapsed = Date.now() - stepStartedAt; @@ -384,7 +387,7 @@ export async function validateUpdateCandidateCanary( doctorResultPath, doctorResultOptions, ); - if (doctorReceipt?.status === "error") { + if (doctorReceipt?.status === "error" && !signal) { code = 1; } doctorConfigChanges = doctorReceipt?.configChanges ?? []; @@ -419,6 +422,7 @@ export async function validateUpdateCandidateCanary( durationMs: Date.now() - stepStartedAt, exitCode: running.child.exitCode, signal: running.child.signalCode, + stderrTail: signal ? running.stderrTail() : undefined, killed: running.child.killed, termination: timedOut ? "timeout" : running.child.signalCode ? "signal" : "exit", outputLimitExceeded: running.outputExceeded(), @@ -501,7 +505,11 @@ export async function validateUpdateCandidateCanary( cwd: params.root, durationMs: Date.now() - stepStartedAt, exitCode: timedOut ? null : code, - ...(timedOut ? { termination: "timeout" as const } : {}), + ...(timedOut + ? { termination: "timeout" as const } + : signal + ? { termination: "signal" as const, signal, stderrTail: running.stderrTail() } + : {}), }; if (doctorAdvisory) { step.advisory = doctorAdvisory; @@ -528,25 +536,17 @@ export async function validateUpdateCandidateCanary( if (!findings?.length && phase === "config" && !running.outputExceeded()) { findings = parseConfigFailureFacts(running.stdout(), env); } - step.failureFacts = findings?.length - ? findings - : [ - createUpdateFailureFact( - { - check: phase, - code: - timedOut && !exitWarning - ? "candidate-checks-timeout" - : phase === "doctor" || phase === "lint" - ? "doctor-failed" - : `candidate-${phase}-failed`, - message: timedOut - ? failureMessage - : (running.stderrDiagnostic() ?? failureMessage), - }, - env, - ), - ]; + step.failureFacts = createUpdateCanaryFailureFacts({ + phase, + name: command.name, + signal, + timedOut, + exitWarning, + failureMessage, + diagnostic: running.stderrDiagnostic(), + findings, + env, + }); } steps.push(step); if (code !== 0 && !doctorAdvisory) { @@ -687,7 +687,7 @@ export async function validateUpdateCandidateCanary( failed.failureFacts.some( (fact) => failureLine === `${displayPhase}: ${fact.message} (${durationMs}ms)`, ); - failed.stderrTail = stepLogTail.slice(0, repeatsFact ? -1 : undefined).join("\n"); + failed.stderrTail ??= stepLogTail.slice(0, repeatsFact ? -1 : undefined).join("\n"); try { await receipts.onStep?.(failed); } catch (recordingError) { diff --git a/src/infra/update-failure-facts.ts b/src/infra/update-failure-facts.ts index 5cf54c2bed44..2e5b4717725c 100644 --- a/src/infra/update-failure-facts.ts +++ b/src/infra/update-failure-facts.ts @@ -213,6 +213,51 @@ export function normalizeUpdateFailureFacts( return facts.slice(0, 5).map((fact) => createUpdateFailureFact(fact, env)); } +export function createUpdateCanaryFailureFacts(params: { + phase: string; + name: string; + signal: NodeJS.Signals | null; + timedOut: boolean; + exitWarning?: string; + failureMessage: string; + diagnostic?: string; + findings?: UpdateFailureFact[]; + env: NodeJS.ProcessEnv; +}): UpdateFailureFact[] { + const { phase, signal, timedOut, exitWarning, failureMessage, diagnostic, findings, env } = + params; + if (signal) { + return [ + createUpdateFailureFact( + { + check: phase, + code: "signal", + message: `${phase === "doctor" ? "Checking data migrations" : params.name}: terminated by ${signal}`, + }, + env, + ), + ...(findings ?? []).slice(0, 4), + ]; + } + return findings?.length + ? findings + : [ + createUpdateFailureFact( + { + check: phase, + code: + timedOut && !exitWarning + ? "candidate-checks-timeout" + : phase === "doctor" || phase === "lint" + ? "doctor-failed" + : `candidate-${phase}-failed`, + message: timedOut ? failureMessage : (diagnostic ?? failureMessage), + }, + env, + ), + ]; +} + /** Config validation issues are more specific than the CLI's failure envelope. */ export function parseConfigFailureFacts( stdout: string, diff --git a/src/infra/update-failure-report-artifact.ts b/src/infra/update-failure-report-artifact.ts index b1e2feb0004c..9912ae0f2117 100644 --- a/src/infra/update-failure-report-artifact.ts +++ b/src/infra/update-failure-report-artifact.ts @@ -23,9 +23,25 @@ import { renderUpdateRunReport, type UpdateRunReport, } from "./update-run-report.js"; +import { updateRunStepsFromResultStep } from "./update-run-step.js"; import type { UpdateRunResult } from "./update-runner-types.js"; const DOCTOR_LINT_REPORT_SECTION = "\n## Complete Doctor lint findings ("; +const NATIVE_FAILURE_REPORT_SECTION = "\n## Native process diagnostics\n"; + +function nativeFailureDiagnostics(steps: UpdateRunRecord["steps"]): string { + const diagnostics = steps.flatMap((step) => + step.status === "failed" && step.termination === "signal" && step.stderrTail + ? [ + `Check: ${step.step}; termination: signal; signal: ${step.signal ?? "unknown"}\n\n${step.stderrTail + .split("\n") + .map((line) => ` ${line}`) + .join("\n")}`, + ] + : [], + ); + return diagnostics.length ? `${NATIVE_FAILURE_REPORT_SECTION}\n${diagnostics.join("\n\n")}` : ""; +} async function withUpdateReportWrite(outputPath: string, write: () => Promise): Promise { await fs.mkdir(path.dirname(outputPath), { recursive: true, mode: 0o700 }); @@ -68,11 +84,14 @@ export async function refreshUpdateRunReportArtifact( // Preserve the artifact writer's appendix while refreshing only its summary. const appendixStart = previous.indexOf(DOCTOR_LINT_REPORT_SECTION); const appendix = appendixStart < 0 ? "" : `\n${previous.slice(appendixStart)}`; + const native = appendix.includes(NATIVE_FAILURE_REPORT_SECTION) + ? "" + : nativeFailureDiagnostics(run.steps); const report = renderUpdateRunReport(run, { mode: run.target.kind }); await writeTextAtomic( outputPath, redactSupportString( - `${report.markdown}${appendix}`, + `${report.markdown}${appendix}${native}`, { env, stateDir }, { maxLength: Number.MAX_SAFE_INTEGER }, ), @@ -174,10 +193,14 @@ export async function writeUpdateRunReportArtifact(params: { ) : undefined; const findings = params.result.steps.flatMap((step) => step.doctorLintFindings ?? []); + const native = nativeFailureDiagnostics( + run?.steps ?? params.result.steps.flatMap(updateRunStepsFromResultStep), + ); const body = [ report.markdown, `${DOCTOR_LINT_REPORT_SECTION}${findings.length})\n`, ...findings.map((finding) => `- ${formatUpdateDoctorLintFinding(finding, env)}`), + ...(native ? [native] : []), failurePath ? `\nBounded diagnostic JSON: ${path.relative(directory, failurePath)}` : "", ].join("\n"); await writeTextAtomic( diff --git a/src/infra/update-failure-report-prepare.ts b/src/infra/update-failure-report-prepare.ts index ea3159a87061..6f61aeb26d5e 100644 --- a/src/infra/update-failure-report-prepare.ts +++ b/src/infra/update-failure-report-prepare.ts @@ -1,5 +1,6 @@ /** Sanitizes and prepares one explicitly reviewed update-failure report. */ import { isIP } from "node:net"; +import { constants } from "node:os"; import path from "node:path"; import { valid as validSemver } from "semver"; import { resolveStateDir } from "../config/paths.js"; @@ -129,7 +130,7 @@ function sanitizeFactIdentifier(value: string, context: UpdateFailureReportConte type ReportedFailedStep = Pick< UpdateStepResult, "name" | "exitCode" | "termination" | "failureFacts" | "stderrTail" -> & { detail?: string }; +> & { detail?: string; signal?: string | null }; function resolveFailedSteps(input: UpdateFailureReportInput): ReportedFailedStep[] { const direct = new Map(input.result.steps.map((step) => [updateRunStepKey(step.name), step])); @@ -154,6 +155,9 @@ function resolveFailedSteps(input: UpdateFailureReportInput): ReportedFailedStep exitCode: step.exitCode ?? null, failureFacts: step.failureFacts, detail: step.detail, + termination: step.termination, + signal: step.signal, + stderrTail: step.stderrTail, }, ] : []; @@ -279,7 +283,11 @@ async function renderBoundedDiagnostics( } for (const step of selectUpdateFailureReportSteps(steps)) { const phase = sanitizeFactIdentifier(step.name, context); - const termination = step.termination ? `, termination ${step.termination}` : ""; + const signal = + step.signal && Object.hasOwn(constants.signals, step.signal) ? step.signal : null; + const termination = step.termination + ? `, termination ${step.termination}${signal ? ` (${signal})` : ""}` + : ""; const message = [ ...(step.failureFacts ?? []).flatMap((fact) => [fact.message, fact.code]), step.detail, diff --git a/src/infra/update-run-codec.ts b/src/infra/update-run-codec.ts index 364ef8905b3b..488eee9e0078 100644 --- a/src/infra/update-run-codec.ts +++ b/src/infra/update-run-codec.ts @@ -96,7 +96,9 @@ export function isRetainedStep(item: unknown): boolean { return ( isRecord(item) && typeof item.step === "string" && - (item.step.startsWith("finalize:") || RETAINED_STEP_NAMES.some((name) => name === item.step)) + (item.termination === "signal" || + item.step.startsWith("finalize:") || + RETAINED_STEP_NAMES.some((name) => name === item.step)) ); } @@ -117,6 +119,7 @@ function boundedJson( // Recovery details are the durable backup receipt, not optional diagnostics. const compacted = value.map((item) => isRecord(item) && + item.termination !== "signal" && item.step !== "task-delivery-recovery" && item.step !== "diagnostic:database snapshot" && item.step !== "diagnostic:database migration writes" && @@ -126,9 +129,23 @@ function boundedJson( : item, ); if (JSON.stringify(compacted) === json) { - throw new Error("Update run retained step metadata exceeds its byte limit"); + // Native output is diagnostic, never a reason to refuse a recovery receipt. + const item = value.findLast( + (entry): entry is Record & { stderrTail: string } => + isRecord(entry) && + typeof entry.stderrTail === "string" && + entry.stderrTail.length > 0, + ); + if (!item) { + throw new Error("Update run retained step metadata exceeds its byte limit"); + } + value = value.with(value.indexOf(item), { + ...item, + stderrTail: truncateUtf16Safe(item.stderrTail, Math.floor(item.stderrTail.length / 2)), + }); + } else { + value = compacted; } - value = compacted; } } else if (isRecord(value)) { const object = value; @@ -259,12 +276,12 @@ export function encodeRun(input: UpdateRunRecord, options: UpdateRunLedgerOption : {}), })), }, - (value) => { + (value, key) => { let text = redactSensitiveText(value, { mode: "tools" }); for (const [pattern, replacement] of redactPaths) { text = text.replace(pattern, () => replacement); } - return truncateUtf16Safe(text, UPDATE_RUN_TEXT_LIMIT); + return truncateUtf16Safe(text, key === "stderrTail" ? 8192 : UPDATE_RUN_TEXT_LIMIT); }, ), ); diff --git a/src/infra/update-run-record.ts b/src/infra/update-run-record.ts index 72ed1831357b..fb53af2e45e8 100644 --- a/src/infra/update-run-record.ts +++ b/src/infra/update-run-record.ts @@ -53,7 +53,7 @@ export function updateStepDiagnostics( export function summarizeUpdateStepFailure( step: Pick< UpdateStepResult, - "name" | "exitCode" | "termination" | "stdoutTail" | "stderrTail" | "failureFacts" + "name" | "exitCode" | "termination" | "signal" | "stdoutTail" | "stderrTail" | "failureFacts" >, ): string { const diagnostics = updateStepDiagnostics(step); @@ -86,7 +86,12 @@ export function summarizeUpdateStepFailure( return [truncateUtf16Safe(causeOnly, 120 - outcome.length - 2), outcome].join("; "); }); return truncateUtf16Safe( - [step.termination ?? `Exit code: ${step.exitCode ?? "unknown"}`, ...excerpts] + [ + step.termination === "signal" + ? `signal: ${step.signal ?? "unknown"}` + : (step.termination ?? `Exit code: ${step.exitCode ?? "unknown"}`), + ...excerpts, + ] .filter(Boolean) .join("; "), 300, diff --git a/src/infra/update-run-report.ts b/src/infra/update-run-report.ts index 77564645dbfe..418049d628e9 100644 --- a/src/infra/update-run-report.ts +++ b/src/infra/update-run-report.ts @@ -333,6 +333,9 @@ export function renderUpdateRunReport( )) { const failure = `Failed: ${step.step}${step.detail ? ` — ${step.detail}` : ""}`; lines.push(bounded(failure, 300)); + if (step.termination === "signal" && step.stderrTail) { + lines.push(`Stderr (${step.signal ?? "unknown signal"}):\n${step.stderrTail}`); + } lines.push( ...(step.failureFacts ?? []).slice(0, 5).map((fact) => formatUpdateFailureFact({ diff --git a/src/infra/update-run-schema.ts b/src/infra/update-run-schema.ts index 50ee14e1b8e4..1a7e27878640 100644 --- a/src/infra/update-run-schema.ts +++ b/src/infra/update-run-schema.ts @@ -188,6 +188,9 @@ const UpdateRunStepSchema = z.object({ startedAtMs: timestamp.optional(), endedAtMs: timestamp.optional(), exitCode: z.number().int().nullable().optional(), + termination: z.enum(["exit", "timeout", "no-output-timeout", "signal"]).optional(), + signal: z.string().max(32).nullable().optional(), + stderrTail: z.string().max(8192).optional(), detail: text.optional(), failureFacts: z.array(UpdateFailureFactSchema).max(5).optional(), configChange: z diff --git a/src/infra/update-run-step.ts b/src/infra/update-run-step.ts index ae453b02b787..87f098de9587 100644 --- a/src/infra/update-run-step.ts +++ b/src/infra/update-run-step.ts @@ -90,6 +90,12 @@ export function updateRunStepsFromResultStep(step: ResultStep): UpdateRunStep[] step: text(step.name), status: failed ? "failed" : "completed", exitCode: step.exitCode, + termination: step.termination, + signal: step.signal, + stderrTail: + failed && step.termination === "signal" && step.stderrTail + ? truncateUtf16Safe(step.stderrTail, 8192) + : undefined, // A completed retry replaces diagnostics from the previous attempt with the same ID. failureFacts: step.failureFacts?.length && !step.advisory ? step.failureFacts.slice(0, 5) : undefined,