morluto/rea

Fork 0

mirror of https://github.com/morluto/rea.git synced 2026-11-05 06:45:22 +00:00

[GH-ISSUE #7369] [Bug] Owned commands return success when their deadline expires during final cleanup #4377

New issue

Open

opened 2026-10-31 00:49:20 +00:00 by bsakaguchi · 0 comments

bsakaguchi commented

2026-10-31 00:49:20 +00:00

Owner

Originally created by @coygeek on GitHub (Oct 27, 2026).
Original GitHub issue: https://github.com/morluto/rea/issues/7369

Before submitting

I searched the open and closed issues for a related report.
I removed credentials, tokens, private paths, and sensitive target data.

Area

Process capture or runtime observation

Observed behavior

A focused production-owner test called runOwnedCommand with a 100 ms timeout, complete output and exit 0. Its injected cleanup began before expiry, waited for the actual command-deadline signal to abort, and returned successful cleanup. The command resolved successfully at 101 ms instead of throwing a timeout. This is an executed synthetic-launcher reproduction, not an external-provider or CLI/MCP timing reproduction.

Reproduction

Run from a checkout of 6749bd090d with Node 24.22.1. The three-case test was executed once: the deadline expectation failed; prompt-cleanup success and caller-cancellation controls passed. The temporary test filename below is a public-safe spelling of the file used.

export PATH="$(mise where node@24.22.1)/bin:$PATH"
WORK=$(mktemp -d)
mkdir -p "$WORK"/{home,config,data,cache,state,tmp}
export HOME="$WORK/home" XDG_CONFIG_HOME="$WORK/config" XDG_DATA_HOME="$WORK/data"
export XDG_CACHE_HOME="$WORK/cache" XDG_STATE_HOME="$WORK/state" TMPDIR="$WORK/tmp"
npm ci && npm run build:cached
cat > src/process/deadlineCleanup.test.ts <<'EOF'
import { EventEmitter } from "node:events";
import { PassThrough } from "node:stream";
import { expect, it } from "vitest";
import { runOwnedCommand } from "./OwnedCommand.js";

it.each(["deadline", "fast", "caller"] as const)("final cleanup: %s", async (mode) => {
  const child = Object.assign(new EventEmitter(), {
    stdout: new PassThrough(), stderr: new PassThrough(), stdin: null,
    exitCode: null as number | null, signalCode: null, kill: () => false,
  });
  const caller = new AbortController();
  const callerReason = { reason: "caller-control" };
  let cleanupStarted = false;
  let abortedAtEntry = false;
  let abortedAtReturn = false;
  const start = performance.now();
  const result = await runOwnedCommand(
    { command: "synthetic-command", arguments: [], runId: "deadline-cleanup" },
    { timeoutMs: mode === "deadline" ? 100 : 1000, diagnosticBytes: 1024 },
    { signal: caller.signal, launcher: async ({ signal }) => {
      setImmediate(() => {
        child.stdout.end("complete output"); child.stderr.end();
        child.exitCode = 0; child.emit("exit", 0, null); child.emit("close", 0, null);
      });
      return {
        process: child,
        ownership: { runId: "deadline-cleanup", leaderPid: 43210, processGroupId: 43210 },
        cleanup: async () => {
          cleanupStarted = true; abortedAtEntry = signal!.aborted;
          if (mode === "deadline") await new Promise<void>((resolve) => {
            if (signal!.aborted) resolve();
            else signal!.addEventListener("abort", () => resolve(), { once: true });
          });
          if (mode === "caller") caller.abort(callerReason);
          abortedAtReturn = signal!.aborted;
          return { cleaned: true as const, signaled: false };
        },
      };
    } },
  ).then((snapshot) => ({ outcome: "success", snapshot }), (error: unknown) => ({ outcome: "failure", error }));
  console.log(JSON.stringify({ mode, cleanupStarted, abortedAtEntry, abortedAtReturn, elapsedMs: Math.round(performance.now() - start), ...result }));
  expect(cleanupStarted).toBe(true);
  expect(abortedAtEntry).toBe(false);
  if (mode === "deadline") {
    expect(abortedAtReturn).toBe(true);
    expect(result).toMatchObject({ outcome: "failure", error: { reason: "timeout" } });
  } else if (mode === "fast") expect(result).toMatchObject({ outcome: "success" });
  else expect(result).toMatchObject({ outcome: "failure", error: { reason: "cancelled", cancellation: { reason: callerReason } } });
});
EOF
npx vitest run src/process/deadlineCleanup.test.ts
rm src/process/deadlineCleanup.test.ts

The verification checkout already had locked dependencies; its lockfile did not change when updating to this commit. I rebuilt it, but did not rerun npm ci. That installation command is fresh-checkout setup.

Expected behavior

Return an OwnedCommandFailure with reason "timeout" after cleanup finishes if the absolute command deadline expired during cleanup, retaining the completed output. Preserve prior physical failures and independent cleanup classification. src/process/OwnedCommand.ts:166 describes timeoutMs as a positive absolute deadline; docs/tool-design.md:181-184 requires a final signal check after awaited cleanup before returning success.

Impact and scope

P2: bounded wrong outcome classification at the shared command owner. The reproduced command reports success despite its deadline having fired. Source-derived reachability includes inspect_pcap_client: src/cli/pcapCommands.ts and src/server/registerPcapTools.ts register the operation; PcapAnalysisService admits its empty input; PcapProvider validates selected executable identity, runs --version with a 20,000 ms deadline, and calls PcapCommand, which forwards it to runOwnedCommand. Valid configured executables pass these guards. Natural provider frequency, public transport behavior and a practical workaround were not measured. No process leak, lost output or data loss was observed.

REA version

Exact node scripts/rea.mjs --version output: 6.8.0. Source commit: 6749bd090d.

Runtime and platform

Node v24.22.1; macOS 27.0.1; darwin arm64. Repository-locked Vitest reported v5.0.3.

Target and artifact context

Synthetic completed child with PassThrough stdout/stderr, output "complete output", exit 0 and a successful injected cleanup callback. No real subprocess, native provider, target device or external service.

Interface

Other

Earliest failure stage

Cleanup, cancellation, or lifecycle

Relevant output or evidence

Observed focused result: 1 failed, 2 passed. The failing timeout assertion received outcome "success", with these instrumentation fields:

{"mode":"deadline","cleanupStarted":true,"abortedAtEntry":false,"abortedAtReturn":true,"elapsedMs":101,"outcome":"success"}

The snapshot retained stdout "complete output", exitCode 0 and signal null. Prompt cleanup returned success; caller abort inside cleanup returned reason "cancelled" with the expected caller reason.

Analysis or suspected cause

Source-derived: OwnedCommand.ts checks deadline.interruption before await supervisor.stop() at line 454. After stop it consults that deadline only when a late stdin failure exists (lines 457-459); the ordinary successful path checks only callerSignal at lines 508-518. ProviderProcess.ts:715-731 awaits owned cleanup even after observed child exit, so expiry can occur in this interval.

Additional context

Related closed reports concern different failures: #4638 retains exact caller-cancellation provenance; #5292 preserves an earlier physical failure against later cancellation; #6111 handles caller cancellation in a later CLI cleanup owner. None reports successful runOwnedCommand cleanup dropping its own deadline. Introducing commit, first affected release and real-provider frequency: NOT_ENOUGH_INFO.

Originally created by @coygeek on GitHub (Oct 27, 2026). Original GitHub issue: https://github.com/morluto/rea/issues/7369 ## Before submitting - [x] I searched the open and closed issues for a related report. - [x] I removed credentials, tokens, private paths, and sensitive target data. ## Area Process capture or runtime observation ## Observed behavior A focused production-owner test called runOwnedCommand with a 100 ms timeout, complete output and exit 0. Its injected cleanup began before expiry, waited for the actual command-deadline signal to abort, and returned successful cleanup. The command resolved successfully at 101 ms instead of throwing a timeout. This is an executed synthetic-launcher reproduction, not an external-provider or CLI/MCP timing reproduction. ## Reproduction Run from a checkout of 6749bd090dc1b5a31ad60a8932e8fbad48f814e6 with Node 24.22.1. The three-case test was executed once: the deadline expectation failed; prompt-cleanup success and caller-cancellation controls passed. The temporary test filename below is a public-safe spelling of the file used. ```sh export PATH="$(mise where node@24.22.1)/bin:$PATH" WORK=$(mktemp -d) mkdir -p "$WORK"/{home,config,data,cache,state,tmp} export HOME="$WORK/home" XDG_CONFIG_HOME="$WORK/config" XDG_DATA_HOME="$WORK/data" export XDG_CACHE_HOME="$WORK/cache" XDG_STATE_HOME="$WORK/state" TMPDIR="$WORK/tmp" npm ci && npm run build:cached cat > src/process/deadlineCleanup.test.ts <<'EOF' import { EventEmitter } from "node:events"; import { PassThrough } from "node:stream"; import { expect, it } from "vitest"; import { runOwnedCommand } from "./OwnedCommand.js"; it.each(["deadline", "fast", "caller"] as const)("final cleanup: %s", async (mode) => { const child = Object.assign(new EventEmitter(), { stdout: new PassThrough(), stderr: new PassThrough(), stdin: null, exitCode: null as number | null, signalCode: null, kill: () => false, }); const caller = new AbortController(); const callerReason = { reason: "caller-control" }; let cleanupStarted = false; let abortedAtEntry = false; let abortedAtReturn = false; const start = performance.now(); const result = await runOwnedCommand( { command: "synthetic-command", arguments: [], runId: "deadline-cleanup" }, { timeoutMs: mode === "deadline" ? 100 : 1000, diagnosticBytes: 1024 }, { signal: caller.signal, launcher: async ({ signal }) => { setImmediate(() => { child.stdout.end("complete output"); child.stderr.end(); child.exitCode = 0; child.emit("exit", 0, null); child.emit("close", 0, null); }); return { process: child, ownership: { runId: "deadline-cleanup", leaderPid: 43210, processGroupId: 43210 }, cleanup: async () => { cleanupStarted = true; abortedAtEntry = signal!.aborted; if (mode === "deadline") await new Promise<void>((resolve) => { if (signal!.aborted) resolve(); else signal!.addEventListener("abort", () => resolve(), { once: true }); }); if (mode === "caller") caller.abort(callerReason); abortedAtReturn = signal!.aborted; return { cleaned: true as const, signaled: false }; }, }; } }, ).then((snapshot) => ({ outcome: "success", snapshot }), (error: unknown) => ({ outcome: "failure", error })); console.log(JSON.stringify({ mode, cleanupStarted, abortedAtEntry, abortedAtReturn, elapsedMs: Math.round(performance.now() - start), ...result })); expect(cleanupStarted).toBe(true); expect(abortedAtEntry).toBe(false); if (mode === "deadline") { expect(abortedAtReturn).toBe(true); expect(result).toMatchObject({ outcome: "failure", error: { reason: "timeout" } }); } else if (mode === "fast") expect(result).toMatchObject({ outcome: "success" }); else expect(result).toMatchObject({ outcome: "failure", error: { reason: "cancelled", cancellation: { reason: callerReason } } }); }); EOF npx vitest run src/process/deadlineCleanup.test.ts rm src/process/deadlineCleanup.test.ts ``` The verification checkout already had locked dependencies; its lockfile did not change when updating to this commit. I rebuilt it, but did not rerun npm ci. That installation command is fresh-checkout setup. ## Expected behavior Return an OwnedCommandFailure with reason "timeout" after cleanup finishes if the absolute command deadline expired during cleanup, retaining the completed output. Preserve prior physical failures and independent cleanup classification. src/process/OwnedCommand.ts:166 describes timeoutMs as a positive absolute deadline; docs/tool-design.md:181-184 requires a final signal check after awaited cleanup before returning success. ## Impact and scope P2: bounded wrong outcome classification at the shared command owner. The reproduced command reports success despite its deadline having fired. Source-derived reachability includes inspect_pcap_client: src/cli/pcapCommands.ts and src/server/registerPcapTools.ts register the operation; PcapAnalysisService admits its empty input; PcapProvider validates selected executable identity, runs --version with a 20,000 ms deadline, and calls PcapCommand, which forwards it to runOwnedCommand. Valid configured executables pass these guards. Natural provider frequency, public transport behavior and a practical workaround were not measured. No process leak, lost output or data loss was observed. ## REA version Exact node scripts/rea.mjs --version output: 6.8.0. Source commit: 6749bd090dc1b5a31ad60a8932e8fbad48f814e6. ## Runtime and platform Node v24.22.1; macOS 27.0.1; darwin arm64. Repository-locked Vitest reported v5.0.3. ## Target and artifact context Synthetic completed child with PassThrough stdout/stderr, output "complete output", exit 0 and a successful injected cleanup callback. No real subprocess, native provider, target device or external service. ## Interface Other ## Earliest failure stage Cleanup, cancellation, or lifecycle ## Relevant output or evidence Observed focused result: 1 failed, 2 passed. The failing timeout assertion received outcome "success", with these instrumentation fields: ```json {"mode":"deadline","cleanupStarted":true,"abortedAtEntry":false,"abortedAtReturn":true,"elapsedMs":101,"outcome":"success"} ``` The snapshot retained stdout "complete output", exitCode 0 and signal null. Prompt cleanup returned success; caller abort inside cleanup returned reason "cancelled" with the expected caller reason. ## Analysis or suspected cause Source-derived: OwnedCommand.ts checks deadline.interruption before await supervisor.stop() at line 454. After stop it consults that deadline only when a late stdin failure exists (lines 457-459); the ordinary successful path checks only callerSignal at lines 508-518. ProviderProcess.ts:715-731 awaits owned cleanup even after observed child exit, so expiry can occur in this interval. ## Additional context Related closed reports concern different failures: [#4638](https://github.com/morluto/rea/issues/4638) retains exact caller-cancellation provenance; [#5292](https://github.com/morluto/rea/issues/5292) preserves an earlier physical failure against later cancellation; [#6111](https://github.com/morluto/rea/issues/6111) handles caller cancellation in a later CLI cleanup owner. None reports successful runOwnedCommand cleanup dropping its own deadline. Introducing commit, first affected release and real-provider frequency: NOT_ENOUGH_INFO.

bsakaguchi referenced this issue

2026-10-31 01:12:54 +00:00

[PR #4428] [MERGED] fix(snapshot): count newly retained workflow bindings on import #6235

No milestone

No project

No assignees

1 participant

Notifications

Due date

The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set.

Reference

morluto/rea#4377

No description provided.

Rows
Columns