From fe4a0025a89927c317b9f1435026c1dd0ea77723 Mon Sep 17 00:00:00 2001 From: hack-cli-tests Date: Thu, 8 Oct 2026 22:27:37 -0400 Subject: [PATCH] test: report native job restart substages --- ...native-compose-adoption-job-diagnostics.ts | 122 ++++++++++++++ .../native-compose-adoption-job-worktrees.ts | 63 ++++--- ...e-compose-adoption-job-diagnostics.test.ts | 155 ++++++++++++++++++ 3 files changed, 320 insertions(+), 20 deletions(-) create mode 100644 tests/e2e/scenarios/native-compose-adoption-job-diagnostics.ts create mode 100644 tests/native-compose-adoption-job-diagnostics.test.ts diff --git a/tests/e2e/scenarios/native-compose-adoption-job-diagnostics.ts b/tests/e2e/scenarios/native-compose-adoption-job-diagnostics.ts new file mode 100644 index 000000000..10ba128d0 --- /dev/null +++ b/tests/e2e/scenarios/native-compose-adoption-job-diagnostics.ts @@ -0,0 +1,122 @@ +import { isRecord } from "../../../src/lib/guards.ts"; +import type { CliResult } from "../harness.ts"; + +const STAGES = [ + "prior-state", + "cli-result", + "fresh-state", + "fresh-exit", + "pending-clear", + "sql-ready", + "sql-counts", + "sibling-isolation", +] as const; +type Stage = (typeof STAGES)[number]; +const CODES = [ + "E_CONFIG_INVALID", + "E_LIFECYCLE_FAILED", + "E_STATE", + "E_NATIVE_COMPOSE_ADOPTION", + "E_NATIVE_COMPOSE_OWNERSHIP", + "E_NATIVE_COMPOSE_PROBE", + "E_NATIVE_COMPOSE_PROBE_TIMEOUT", +] as const; +const MAX_REPLY_BYTES = 64 * 1024; + +function isStage(value: unknown): value is Stage { + return STAGES.some((stage) => stage === value); +} + +function cliCode(stdout: string): string { + if (Buffer.byteLength(stdout) > MAX_REPLY_BYTES) { + return "unavailable"; + } + try { + const value: unknown = JSON.parse(stdout); + if (!isRecord(value)) { + return "unavailable"; + } + if (value.ok === true) { + return "none"; + } + if (value.ok === false && isRecord(value.error)) { + const error = value.error; + return CODES.find((code) => code === error.code) ?? "unavailable"; + } + } catch { + // A diagnostic cannot replace the original command outcome. + } + return "unavailable"; +} + +/** + * Record only closed start/restart substages and allowlisted CLI codes. No reply + * values, paths, argv, identifiers, arbitrary errors or elapsed-budget claims are + * emitted. Logging failure never replaces the original result or thrown error. + */ +export function createCompletedJobFixtureStartDiagnostics(opts: { + readonly log: (message: string) => void; + readonly operation: unknown; + readonly scope: unknown; +}) { + const log = opts.log; + const operation = + opts.operation === "up" || opts.operation === "restart" + ? opts.operation + : "unavailable"; + const scope = + opts.scope === "alpha" || opts.scope === "beta" + ? opts.scope + : "unavailable"; + const prefix = `start-operation=${operation} worktree=${scope}`; + const emit = (message: string) => { + try { + log(`${prefix} ${message}`); + } catch { + // Diagnostics cannot skip cleanup or replace its original refusal. + } + }; + return Object.freeze({ + step: async ( + stage: unknown, + action: () => T | Promise + ): Promise => { + if (!isStage(stage)) { + return await action(); + } + emit(`stage=${stage} status=begin`); + try { + const value = await action(); + emit(`stage=${stage} status=end`); + return value; + } catch (error) { + emit(`stage=${stage} status=failed`); + throw error; + } + }, + cliOutcome: ( + result: Pick + ) => { + try { + const exit = exitClass(result.exitCode); + const timeout = result.timedOut ? "yes" : "no"; + emit( + `stage=cli-result exit=${exit} timed-out=${timeout} code=${cliCode(result.stdout)}` + ); + } catch { + emit( + "stage=cli-result exit=unavailable timed-out=unavailable code=unavailable" + ); + } + }, + }); +} + +function exitClass(value: unknown): "zero" | "nonzero" | "unavailable" { + if (value === 0) { + return "zero"; + } + return typeof value === "number" && Number.isSafeInteger(value) + ? "nonzero" + : "unavailable"; +} diff --git a/tests/e2e/scenarios/native-compose-adoption-job-worktrees.ts b/tests/e2e/scenarios/native-compose-adoption-job-worktrees.ts index e3bc6ce68..0a70476d8 100644 --- a/tests/e2e/scenarios/native-compose-adoption-job-worktrees.ts +++ b/tests/e2e/scenarios/native-compose-adoption-job-worktrees.ts @@ -16,6 +16,7 @@ import { type Scenario, type ScenarioContext, } from "../harness.ts"; +import { createCompletedJobFixtureStartDiagnostics } from "./native-compose-adoption-job-diagnostics.ts"; import { completedJobFixtureSources } from "./native-compose-adoption-job-inputs.ts"; import { createAdoptionFixtureProbe, @@ -752,30 +753,48 @@ function runtime(input: Awaited>) { expected: readonly number[], restart = false ) => { - const previous = await state(instance, "seed"); - requireValue(typeof previous.startedAt === "string"); - successful( - await cli( + const diagnostics = createCompletedJobFixtureStartDiagnostics({ + log: ctx.log, + operation: restart ? "restart" : "up", + scope: instance === input.first ? "alpha" : "beta", + }); + const previous = await diagnostics.step("prior-state", async () => { + const value = await state(instance, "seed"); + requireValue(typeof value.startedAt === "string"); + return value; + }); + await diagnostics.step("cli-result", async () => { + const result = await cli( instance, restart ? ["restart", "--json"] : ["up", "--detach", "--json"] - ) + ); + diagnostics.cliOutcome(result); + successful(result); + }); + const current = await diagnostics.step("fresh-state", () => + state(instance, "seed") ); - const current = await state(instance, "seed"); - if (typeof previous.startedAt !== "string") { - refused(); - } - completedJobFixtureFreshExit({ - id: id(instance, "seed"), - priorStartedAt: previous.startedAt, - observed: current, + await diagnostics.step("fresh-exit", () => { + if (typeof previous.startedAt !== "string") { + refused(); + } + completedJobFixtureFreshExit({ + id: id(instance, "seed"), + priorStartedAt: previous.startedAt, + observed: current, + }); }); - await pending(instance, null); - await waitSql( - instance, - "SELECT count(*) FROM app_starts", - String(expected.length) + await diagnostics.step("pending-clear", () => pending(instance, null)); + await diagnostics.step("sql-ready", () => + waitSql( + instance, + "SELECT count(*) FROM app_starts", + String(expected.length) + ) + ); + await diagnostics.step("sql-counts", () => + counts(instance, attempts, expected) ); - await counts(instance, attempts, expected); }; const control = async ( instance: Instance, @@ -1397,7 +1416,11 @@ export const nativeComposeAdoptionJobWorktreesScenario: Scenario = { await h.freshUp(first, 3, [1, 2, 3]); phases.mark("alpha-restart-4"); await h.freshUp(first, 4, [1, 2, 3, 4], true); - await h.counts(second, 1, [1]); + await createCompletedJobFixtureStartDiagnostics({ + log: ctx.log, + operation: "restart", + scope: "alpha", + }).step("sibling-isolation", () => h.counts(second, 1, [1])); phases.mark("alpha-nonzero-job-5"); await h.control(first, "fail"); await stop(h, first); diff --git a/tests/native-compose-adoption-job-diagnostics.test.ts b/tests/native-compose-adoption-job-diagnostics.test.ts new file mode 100644 index 000000000..419d7f1b3 --- /dev/null +++ b/tests/native-compose-adoption-job-diagnostics.test.ts @@ -0,0 +1,155 @@ +import { expect, test } from "bun:test"; +import { createCompletedJobFixtureStartDiagnostics } from "./e2e/scenarios/native-compose-adoption-job-diagnostics.ts"; + +function diagnostics(messages: string[]) { + return createCompletedJobFixtureStartDiagnostics({ + operation: "restart", + scope: "alpha", + log: (message) => messages.push(message), + }); +} + +test("completed-job start diagnostics distinguish CLI refusal from a later oracle", async () => { + for (const failureStage of ["cli-result", "fresh-exit"] as const) { + const messages: string[] = []; + const diagnostic = diagnostics(messages); + const original = new Error("private-original-refusal-canary"); + const calls: string[] = []; + let observed: unknown; + try { + for (const stage of [ + "cli-result", + "fresh-exit", + "pending-clear", + ] as const) { + await diagnostic.step(stage, () => { + calls.push(stage); + if (stage === failureStage) { + throw original; + } + }); + } + } catch (error) { + observed = error; + } + expect(observed).toBe(original); + expect(calls).toEqual( + failureStage === "cli-result" + ? ["cli-result"] + : ["cli-result", "fresh-exit"] + ); + expect(messages.at(-1)).toBe( + `start-operation=restart worktree=alpha stage=${failureStage} status=failed` + ); + expect(messages.join("\n")).not.toContain("canary"); + expect(messages.join("\n")).not.toContain("pending-clear"); + } +}); + +test("completed-job start diagnostics preserve success order and callback results", async () => { + const messages: string[] = []; + const diagnostic = diagnostics(messages); + const value = { privateValue: "private-result-canary" }; + for (const stage of [ + "prior-state", + "cli-result", + "fresh-state", + "fresh-exit", + "pending-clear", + "sql-ready", + "sql-counts", + "sibling-isolation", + ]) { + expect(await diagnostic.step(stage, () => value)).toBe(value); + expect(messages.slice(-2)).toEqual([ + `start-operation=restart worktree=alpha stage=${stage} status=begin`, + `start-operation=restart worktree=alpha stage=${stage} status=end`, + ]); + } + expect(messages).toHaveLength(16); + expect(messages.join("\n")).not.toContain("private-result-canary"); +}); + +test("completed-job start diagnostics omit reply values and unknown codes or labels", async () => { + const messages: string[] = []; + const diagnostic = diagnostics(messages); + for (const code of ["E_CONFIG_INVALID", "private-code-canary"]) { + diagnostic.cliOutcome({ + exitCode: 17, + timedOut: false, + stdout: JSON.stringify({ + ok: false, + error: { code, message: "private-message-canary" }, + env: "private-env-canary", + argv: ["private-argv-canary"], + }), + }); + } + diagnostic.cliOutcome({ + exitCode: 0, + timedOut: false, + stdout: "private-malformed-canary", + }); + diagnostic.cliOutcome({ + exitCode: 17, + timedOut: true, + stdout: "private-oversized-canary".repeat(10_000), + }); + const unknown = createCompletedJobFixtureStartDiagnostics({ + operation: "private-operation-canary", + scope: "private-scope-canary", + log: (message) => messages.push(message), + }); + let calls = 0; + expect(await unknown.step("private-stage-canary", () => ++calls)).toBe(1); + await unknown.step("fresh-exit", () => ++calls); + expect(calls).toBe(2); + expect(messages[0]).toContain("code=E_CONFIG_INVALID"); + expect(messages[1]).toContain("code=unavailable"); + expect(messages[3]).toContain("timed-out=yes code=unavailable"); + expect(messages.at(-1)).toBe( + "start-operation=unavailable worktree=unavailable stage=fresh-exit status=end" + ); + expect(messages.join("\n")).not.toContain("canary"); +}); + +test("completed-job start diagnostics cannot replace an outcome when the logger throws", async () => { + const diagnostic = createCompletedJobFixtureStartDiagnostics({ + operation: "up", + scope: "beta", + log: () => { + throw new Error("private-logger-canary"); + }, + }); + const original = new Error("private-original-canary"); + expect(await diagnostic.step("prior-state", () => 42)).toBe(42); + let observed: unknown; + try { + await diagnostic.step("cli-result", () => { + diagnostic.cliOutcome({ + exitCode: 17, + timedOut: false, + stdout: "private-reply-canary", + }); + throw original; + }); + } catch (error) { + observed = error; + } + expect(observed).toBe(original); +}); + +test("completed-job CLI diagnostics treat an unreadable reply as unavailable", () => { + const messages: string[] = []; + const diagnostic = diagnostics(messages); + const result = { exitCode: 1, timedOut: false, stdout: "" }; + Object.defineProperty(result, "stdout", { + get: () => { + throw new Error("private-unreadable-reply-canary"); + }, + }); + expect(() => diagnostic.cliOutcome(result)).not.toThrow(); + expect(messages).toEqual([ + "start-operation=restart worktree=alpha stage=cli-result exit=unavailable timed-out=unavailable code=unavailable", + ]); +});