Files
hyperframes/packages/cli/src/cli.lifecycle.test.ts
T
WaterrrForever bc6dbc7e21 fix(cli): stop dropping queued telemetry when process.exit races the final flush (#2970)
* fix(cli): stop dropping queued telemetry when process.exit races the final flush

Two exit-path defects introduced by the 0.7.65 process-lifecycle refactor:

1. The 'exit' handler returned early once finalizeCli had started, which
   also skipped the flushSync() fallback. When an agent-pipe EPIPE killed
   the process mid-flush (the NORMAL teardown under Claude Code / Codex),
   the still-queued render_complete was silently dropped — fleet delivery
   fell from ~90% (0.7.55-0.7.64) to ~35%. flushSync() is now
   unconditional: empty queue is a no-op, event uuids dedupe re-sends.

2. The EPIPE handlers set commandFailed unconditionally, so every piped
   successful render scored success:false in cli_command_result (fleet
   success rate collapsed 89% -> 5-25%). EPIPE now only marks failure
   when the pipe died before the render artifact was validated, matching
   the existing isRenderSucceeded() exemption on the uncaughtException
   path.

Regression tests cover both: flushSync-after-finalize, and EPIPE
before/after artifact validation.

* fix(cli): don't score a validated render as failed due to pre-artifact noise

Review follow-up: commandFailed can be set by noise that precedes artifact
validation — a stray unhandledRejection mid-render, or an EPIPE firing
before markRenderSucceeded on a run that still completes. Once the
artifact validates, that earlier noise must not flip the run's
cli_command_result to success:false. Genuine failures keep a non-zero
exit code and are still caught by the exitCode check.

Extracted commandSucceededForTelemetry() and applied it at both tracking
sites (finalizeCli and the exit handler), with a regression test.

* test(cli): pin the production-reachable producer of the stale-failure override

Review note: the pre-artifact-noise test drives the scenario with an
EPIPE, which only reaches 'render validates afterwards' because
process.exit is mocked — that sequence can't occur in production. Add a
test for the reachable producer: an unhandledRejection before validation
(the handler deliberately does not exit), followed by a validated render,
must score success:true at exit code 0. Verified red on the pre-override
cli.ts.
2026-08-04 02:02:55 +08:00

215 lines
7.5 KiB
TypeScript

import { afterEach, describe, expect, it, vi } from "vitest";
const originalArgv = [...process.argv];
const originalExitCode = process.exitCode;
afterEach(() => {
process.argv = [...originalArgv];
process.exitCode = originalExitCode;
vi.doUnmock("./commands/init.js");
vi.doUnmock("./telemetry/events.js");
vi.doUnmock("./telemetry/index.js");
vi.resetModules();
});
describe("CLI lifecycle", () => {
it("queues a command failure before finalizing telemetry", async () => {
let resolveEvents!: (events: {
trackCommandFailure: (command: string, error: unknown) => void;
}) => void;
const eventsModule = new Promise<{
trackCommandFailure: (command: string, error: unknown) => void;
}>((resolve) => {
resolveEvents = resolve;
});
let markEventsImportStarted!: () => void;
const eventsImportStarted = new Promise<void>((resolve) => {
markEventsImportStarted = resolve;
});
const order: string[] = [];
vi.doMock("./commands/init.js", () => ({
default: {
meta: { name: "init" },
args: { json: { type: "boolean" } },
run: vi.fn(),
},
}));
vi.doMock("./telemetry/index.js", () => ({
flush: async () => {
order.push("flush");
},
flushSync: vi.fn(),
incrementCommandCount: vi.fn(),
showTelemetryNotice: vi.fn(),
shouldTrack: () => false,
trackCliError: vi.fn(),
trackCommand: vi.fn(),
trackCommandResult: vi.fn(),
}));
vi.doMock("./telemetry/events.js", async () => {
markEventsImportStarted();
return eventsModule;
});
process.argv = ["node", "cli.ts", "init", "--bogus", "--json"];
const execution = import("./cli.js");
await eventsImportStarted;
expect(order).toEqual([]);
resolveEvents({
trackCommandFailure: () => {
order.push("cli_error");
},
});
await execution;
expect(order).toEqual(["cli_error", "flush"]);
});
it("hands queued events to flushSync even after finalizeCli has run", async () => {
const flushSync = vi.fn();
const trackCommandResult = vi.fn();
mockInitCommand(vi.fn());
mockTelemetry({ flushSync, trackCommandResult });
process.argv = ["node", "cli.ts", "init", "--json"];
await import("./cli.js");
// Command finished → finalizeCli ran and tracked the result once.
expect(trackCommandResult).toHaveBeenCalledTimes(1);
// The process.exit() that follows fires the 'exit' handler. It must not
// double-track, but it MUST still hand the queue to flushSync — this is
// the fallback that re-delivers a render_complete whose eager flush()
// was killed by an EPIPE process.exit(0) racing finalizeCli. Gating it
// behind `finalized` was the 0.7.65 render_complete regression.
process.emit("exit", 0);
expect(trackCommandResult).toHaveBeenCalledTimes(1);
expect(flushSync).toHaveBeenCalled();
});
it("keeps an EPIPE after a validated render scored as success", async () => {
const trackCommandResult = vi.fn();
const exitSpy = vi.spyOn(process, "exit").mockImplementation((() => undefined) as never);
try {
mockInitCommand(() => emitStreamEpipe());
mockTelemetry({ trackCommandResult });
const successState = await import("./utils/render-success-state.js");
successState.markRenderSucceeded();
process.argv = ["node", "cli.ts", "init", "--json"];
await import("./cli.js");
// The pipe closing after the artifact was validated is a normal agent
// teardown: exit 0, and the run must NOT be scored as a failure.
expect(exitSpy).toHaveBeenCalledWith(0);
expect(trackCommandResult).toHaveBeenCalledWith(expect.objectContaining({ success: true }));
successState._resetRenderSuccessForTests();
} finally {
exitSpy.mockRestore();
}
});
it("does not let pre-artifact noise doom a run whose render later validates", async () => {
const trackCommandResult = vi.fn();
const exitSpy = vi.spyOn(process, "exit").mockImplementation((() => undefined) as never);
try {
const successState = await import("./utils/render-success-state.js");
// Noise arrives BEFORE the artifact is validated (mid-render EPIPE /
// stray rejection shape), then the render completes and validates.
mockInitCommand(() => {
emitStreamEpipe();
successState.markRenderSucceeded();
});
mockTelemetry({ trackCommandResult });
process.argv = ["node", "cli.ts", "init", "--json"];
await import("./cli.js");
expect(trackCommandResult).toHaveBeenCalledWith(expect.objectContaining({ success: true }));
successState._resetRenderSuccessForTests();
} finally {
exitSpy.mockRestore();
}
});
it("does not let a pre-validation unhandledRejection doom a validated render", async () => {
// The production-reachable producer of the stale-failure override: the
// unhandledRejection handler deliberately does NOT exit, so a stray
// rejection mid-render sets commandFailed (and exitCode 1), the render
// then completes and validates, and finalizeCli writes exit code 0.
const trackCommandResult = vi.fn();
// Detach the test runner's own unhandledRejection listeners so the
// synthetic emit reaches only the CLI's handler, then restore them.
const priorListeners = process.listeners("unhandledRejection");
process.removeAllListeners("unhandledRejection");
try {
const successState = await import("./utils/render-success-state.js");
mockInitCommand(() => {
process.emit("unhandledRejection", new Error("stray teardown noise"), Promise.resolve());
successState.markRenderSucceeded();
});
mockTelemetry({ trackCommandResult });
process.argv = ["node", "cli.ts", "init", "--json"];
await import("./cli.js");
expect(trackCommandResult).toHaveBeenCalledWith(
expect.objectContaining({ success: true, exitCode: 0 }),
);
successState._resetRenderSuccessForTests();
} finally {
process.removeAllListeners("unhandledRejection");
for (const listener of priorListeners) process.on("unhandledRejection", listener);
}
});
it("still scores an EPIPE before the artifact is validated as a failure", async () => {
const trackCommandResult = vi.fn();
const exitSpy = vi.spyOn(process, "exit").mockImplementation((() => undefined) as never);
try {
mockInitCommand(() => emitStreamEpipe());
mockTelemetry({ trackCommandResult });
process.argv = ["node", "cli.ts", "init", "--json"];
await import("./cli.js");
expect(exitSpy).toHaveBeenCalledWith(0);
expect(trackCommandResult).toHaveBeenCalledWith(expect.objectContaining({ success: false }));
} finally {
exitSpy.mockRestore();
}
});
});
function mockInitCommand(run: () => void): void {
vi.doMock("./commands/init.js", () => ({
default: {
meta: { name: "init" },
args: { json: { type: "boolean" } },
run,
},
}));
}
function mockTelemetry(overrides: {
flushSync?: ReturnType<typeof vi.fn>;
trackCommandResult?: ReturnType<typeof vi.fn>;
}): void {
vi.doMock("./telemetry/index.js", () => ({
flush: vi.fn(async () => {}),
flushSync: overrides.flushSync ?? vi.fn(),
incrementCommandCount: vi.fn(),
showTelemetryNotice: vi.fn(),
shouldTrack: () => false,
trackCliError: vi.fn(),
trackCommand: vi.fn(),
trackCommandResult: overrides.trackCommandResult ?? vi.fn(),
}));
}
function emitStreamEpipe(): void {
process.stdout.emit("error", Object.assign(new Error("write EPIPE"), { code: "EPIPE" }));
}