0.1.53

The 30s grace timer that bounds K8s Job condition propagation lag was
armed by streamPodLogs's onFirstStreamExit callback the moment
streamPodLogsOnce returned for the first time.  A transient K8s log-API
disconnect mid-run also returns from streamPodLogsOnce — so the grace
timer fired 30s later regardless of whether streamPodLogs had already
reconnected and the container was still producing output.

Nancy / Privileged Escalation reproduced this on long Opus-4-6 runs:
the prod paperclip pod was stable, the cancel-poll guard was already
narrowed in 0.1.51, but every long run truncated with claude_truncated
+ "container terminated state not yet observable (pod phase=Running)"
because the run was being abandoned mid-output.

Replace the boolean onFirstStreamExit signal with a streamActivity ref
carrying lastActiveAt + streamHasExited.  streamPodLogs refreshes
lastActiveAt every time a streamPodLogsOnce attempt returns non-empty
output, so reconnects that resume real output keep the grace clock
reset.  The grace timer fires only once the stream has exited at least
once AND no chunk has arrived for the full grace window — which
preserves the original FAR-23 behaviour (container truly exited but
Job condition lags) while ending the false-truncation of healthy
streams.  Adds a regression test that asserts a stream drop + reconnect
+ deferred Job completion does not surface as truncated.

Co-Authored-By: Paperclip <noreply@paperclip.ing>

package-lock.json

@@ -1,12 +1,12 @@
 {
   "name": "paperclip-adapter-claude-k8s",
-  "version": "0.1.49",
+  "version": "0.1.53",
   "lockfileVersion": 3,
   "requires": true,
   "packages": {
     "": {
       "name": "paperclip-adapter-claude-k8s",
-      "version": "0.1.49",
+      "version": "0.1.53",
       "license": "MIT",
       "dependencies": {
         "@kubernetes/client-node": "^1.0.0",

package.json

@@ -1,6 +1,6 @@
 {
   "name": "paperclip-adapter-claude-k8s",
-  "version": "0.1.49",
+  "version": "0.1.53",
   "description": "Paperclip adapter plugin that runs Claude Code agents as Kubernetes Jobs",
   "license": "MIT",
   "repository": {

src/server/execute.test.ts

@@ -1512,6 +1512,54 @@ describe("execute: log-stream-exit grace period (FAR-23)", () => {
     // (grace did not fire, real completion arrived)
     expect(result.errorMessage).toBeNull();
   });
+
+  it("does NOT fire grace when stream drops mid-output and reconnects with more output (FAR-107)", async () => {
+    // Reproduces Nancy / Privileged Escalation symptom: the K8s log API drops
+    // the streaming connection mid-run; streamPodLogs reconnects and the
+    // container is still producing.  Before the fix, the grace timer was
+    // armed on first stream exit and fired 30s later regardless of whether
+    // output had resumed, surfacing claude_truncated even though the pod was
+    // still phase=Running.
+    let attemptIndex = 0;
+    mockLogFn.mockImplementation(
+      async (_ns: string, _pod: string, _ctr: string, writable: import("node:stream").Writable) => {
+        if (attemptIndex === 0) {
+          // Stream a partial init line then "drop" the connection without a
+          // result event — this is the transient API disconnect.
+          writable.write(JSON.stringify({ type: "system", subtype: "init", model: "claude-sonnet-4-6", session_id: "sess_test123" }) + "\n");
+          attemptIndex++;
+          return;
+        }
+        // Reconnect produces the rest of the stream including the result event.
+        writable.write(CLAUDE_HAPPY_OUTPUT);
+      },
+    );
+    // Job condition arrives only after the reconnect produces output, well
+    // beyond the 30s grace window; the old code would have grace-fired at
+    // ~30s and treated the run as truncated.
+    let readJobCalls = 0;
+    mockBatchReadJob.mockImplementation(async () => {
+      readJobCalls++;
+      // Stay non-terminal until the reconnect has had time to run and the
+      // grace window has fully elapsed since the FIRST disconnect.
+      if (readJobCalls < 25) return { status: { conditions: [] } };
+      return { status: { conditions: [{ type: "Complete", status: "True" }] } };
+    });
+
+    const executePromise = execute(makeCtx());
+    // t=3000: first reconnect sleep fires → second streamPodLogsOnce attempt
+    await vi.advanceTimersByTimeAsync(3_100);
+    // Drive past the old (buggy) 30s grace boundary without firing real completion
+    await vi.advanceTimersByTimeAsync(35_000);
+    // Then let the Job's Complete condition land
+    await vi.advanceTimersByTimeAsync(20_000);
+    const result = await executePromise;
+
+    // Run completed normally — grace must not have falsely truncated it.
+    expect(result.exitCode).toBe(0);
+    expect(result.errorCode).toBeUndefined();
+    expect(result.sessionId).toBe("sess_test123");
+  }, 80_000);
 });
 
 // ─── execute: concurrency guard — multiple orphan sorting ────────────────────
@@ -1561,16 +1609,24 @@ describe("shouldAbortForCancellation", () => {
     expect(shouldAbortForCancellation("cancelled")).toBe(true);
   });
 
-  it("returns true when status is 'failed'", () => {
-    expect(shouldAbortForCancellation("failed")).toBe(true);
+  it("returns true when status is 'cancelling'", () => {
+    expect(shouldAbortForCancellation("cancelling")).toBe(true);
   });
 
-  it("returns true when status is 'completed'", () => {
-    expect(shouldAbortForCancellation("completed")).toBe(true);
+  // FAR-107: terminal-but-not-cancelled statuses MUST NOT trigger Job deletion.
+  // The previous "anything but running" guard caused k8s_job_deleted_externally
+  // false positives for in-flight runs whenever the API briefly reported a
+  // transient/stale status.
+  it("returns false for non-cancellation terminal statuses (FAR-107)", () => {
+    expect(shouldAbortForCancellation("succeeded")).toBe(false);
+    expect(shouldAbortForCancellation("failed")).toBe(false);
+    expect(shouldAbortForCancellation("completed")).toBe(false);
   });
 
-  it("returns true for any non-running non-empty string", () => {
-    expect(shouldAbortForCancellation("unknown")).toBe(true);
+  it("returns false for unknown statuses (FAR-107)", () => {
+    expect(shouldAbortForCancellation("unknown")).toBe(false);
+    expect(shouldAbortForCancellation("queued")).toBe(false);
+    expect(shouldAbortForCancellation("pending")).toBe(false);
   });
 });
 
@@ -1771,7 +1827,7 @@ describe("execute: SIGTERM handler best-effort cleanup", () => {
     vi.useRealTimers();
   });
 
-  it("deletes the active Job when SIGTERM fires during execution", async () => {
+  it("does NOT delete active Jobs on SIGTERM — leaves them for orphan reattach (FAR-107)", async () => {
     // Mock process.kill to prevent the test process from actually being killed.
     const killSpy = vi.spyOn(process, "kill").mockImplementation(() => true);
 
@@ -1782,17 +1838,19 @@ describe("execute: SIGTERM handler best-effort cleanup", () => {
     // Flush microtasks through the async setup chain: getSelfPodInfo, listJobs,
     // readSkillEntries, prepareBundle, createJob, onLog, activeJobs.add(), and
     // ensureSigtermHandler() all complete before the try block enters streaming.
-    // 30 rounds is more than enough for the ~7 sequential await points.
     for (let i = 0; i < 30; i++) await Promise.resolve();
 
-    // Emit SIGTERM — the process.once handler fires synchronously and kicks off
-    // async cleanup (deleteNamespacedJob). The mock resolves immediately.
+    // Reset deleteJob spy after setup so we can detect any SIGTERM-driven calls.
+    mockBatchDeleteJob.mockClear();
+
+    // Emit SIGTERM — the handler must re-raise to the default handler without
+    // touching the K8s Job.  Deleting the Job here would surface as
+    // k8s_job_deleted_externally in the in-flight run (FAR-107).
     process.emit("SIGTERM");
 
-    // Flush microtasks for deleteJob to resolve and the .then(process.kill) to run.
     for (let i = 0; i < 10; i++) await Promise.resolve();
 
-    expect(mockBatchDeleteJob).toHaveBeenCalled();
+    expect(mockBatchDeleteJob).not.toHaveBeenCalled();
     expect(killSpy).toHaveBeenCalledWith(process.pid, "SIGTERM");
 
     killSpy.mockRestore();

src/server/execute.ts

@@ -58,30 +58,20 @@ function ensureSigtermHandler(): void {
   if (sigtermHandlerRegistered) return;
   sigtermHandlerRegistered = true;
   process.once("SIGTERM", () => {
-    const jobs = [...activeJobs];
-    void Promise.allSettled(
-      jobs.map(async (ref) => {
-        try {
-          const batchApi = getBatchApi(ref.kubeconfigPath);
-          await batchApi.deleteNamespacedJob({
-            name: ref.jobName,
-            namespace: ref.namespace,
-            body: { propagationPolicy: "Background" },
-          });
-        } catch { /* best-effort */ }
-        if (ref.promptSecretName && ref.promptSecretNamespace) {
-          try {
-            const coreApi = getCoreApi(ref.kubeconfigPath);
-            await coreApi.deleteNamespacedSecret({
-              name: ref.promptSecretName,
-              namespace: ref.promptSecretNamespace,
-            });
-          } catch { /* best-effort */ }
-        }
-      }),
-    ).then(() => {
-      process.kill(process.pid, "SIGTERM");
-    });
+    // Do NOT delete active K8s Jobs on SIGTERM (FAR-107).  Paperclip itself
+    // receives SIGTERM during rolling deploys, evictions, scale-down, etc.
+    // Deleting the Jobs we own there causes the in-flight heartbeat to surface
+    // a false-positive `k8s_job_deleted_externally` error and tears down work
+    // the user expected to keep running.
+    //
+    // The correct behaviour with `reattachOrphanedJobs=true` (default) is to
+    // leave the Jobs alive: the next paperclip process discovers them via the
+    // orphan-classification path and reattaches their log streams.  When
+    // `reattachOrphanedJobs=false` the operator explicitly opted into manual
+    // cleanup and should not have us auto-deleting either.  The owning Job's
+    // ownerReference (FAR-15) keeps the prompt Secret tied to the Job, so
+    // both survive together and TTL cleans them up after natural completion.
+    process.kill(process.pid, "SIGTERM");
   });
 }
 
@@ -100,13 +90,23 @@ export function isK8s404(err: unknown): boolean {
 }
 
 /**
- * Returns true when the heartbeat-run status indicates the run is no longer
- * active and the K8s Job should be cancelled.
+ * Returns true when the heartbeat-run status indicates the run was explicitly
+ * cancelled and the K8s Job must be torn down.
+ *
+ * Only `cancelled` / `cancelling` qualify.  Treating any non-`running` status
+ * as cancellation (the previous behaviour) produced spurious
+ * k8s_job_deleted_externally errors for in-flight runs whenever the API
+ * briefly reported a transient or stale status — Nancy's runs at
+ * Privileged Escalation hit this without anyone actually cancelling them
+ * (FAR-107).  Other terminal statuses (`succeeded`/`failed`/`completed`)
+ * are unreachable in practice while the adapter is still executing
+ * (the adapter's own return is what flips them) and even if observed,
+ * they do not warrant our deleting a Job that may still be doing work.
  * Exported for unit tests.
  */
 export function shouldAbortForCancellation(runStatus: string | undefined): boolean {
   if (!runStatus) return false;
-  return runStatus !== "running";
+  return runStatus === "cancelled" || runStatus === "cancelling";
 }
 
 /**
@@ -481,10 +481,18 @@ export async function streamPodLogsOnce(
  * Capped at MAX_LOG_RECONNECT_ATTEMPTS to prevent infinite reconnect
  * loops during sustained API partitions.
  *
- * onFirstStreamExit is called the first time streamPodLogsOnce returns
- * (container has exited or stream disconnected). Used by execute() to
- * start the LOG_EXIT_COMPLETION_GRACE_MS grace timer (FAR-23) without
- * waiting for all reconnects to exhaust.
+ * `activity` tracks stream liveness so execute()'s grace timer can
+ * distinguish a transient K8s log-API reconnect from a real container
+ * exit (FAR-107).  Two signals:
+ *  - `streamHasExited` becomes true on the first return from
+ *    streamPodLogsOnce.  Until then we are still in the warm-up window
+ *    and waitForJobCompletion is the authoritative signal — grace must
+ *    not fire.
+ *  - `lastActiveAt` advances every time a streamPodLogsOnce attempt
+ *    returns non-empty output (the container is still producing).
+ *    The grace timer fires only once GRACE_MS have passed since the
+ *    last chunk, so output that resumes after a transient drop keeps
+ *    the run alive.
  */
 async function streamPodLogs(
   namespace: string,
@@ -493,7 +501,7 @@ async function streamPodLogs(
   kubeconfigPath?: string,
   stopSignal?: { stopped: boolean },
   dedup?: LogLineDedupFilter,
-  onFirstStreamExit?: () => void,
+  activity?: { lastActiveAt: number; streamHasExited: boolean },
 ): Promise<string> {
   const allChunks: string[] = [];
   let attempt = 0;
@@ -524,14 +532,15 @@ async function streamPodLogs(
 
     const preStreamTs = Math.floor(Date.now() / 1000);
     const result = await streamPodLogsOnce(namespace, podName, onLog, kubeconfigPath, sinceSeconds, dedup, stopSignal);
-    // Signal first stream exit immediately so the grace-period timer in
-    // execute() can start without waiting for all reconnects to complete.
-    if (attempt === 0) onFirstStreamExit?.();
+    if (activity) activity.streamHasExited = true;
     if (result) {
       allChunks.push(result);
       // Update last-received timestamp to now (the stream just ended,
       // so any log lines in `result` were received up to this moment).
       lastLogReceivedAt = Math.floor(Date.now() / 1000);
+      // Refresh stream liveness so the grace timer in execute() does not
+      // fire while output is still flowing through reconnects (FAR-107).
+      if (activity) activity.lastActiveAt = Date.now();
     } else if (attempt === 0) {
       // First attempt returned nothing — update timestamp so reconnect
       // window stays reasonable.
@@ -650,30 +659,82 @@ export interface PodTerminatedState {
   signal: number | null;
 }
 
-async function getPodTerminatedState(
+/**
+ * Result of a pod-state lookup.  `state` is the terminated state when available;
+ * `phase` and `podMissing` give the caller enough context to render an honest
+ * truncation-cause message instead of guessing "likely deleted" (FAR-107).
+ */
+export interface PodLookupResult {
+  state: PodTerminatedState | null;
+  phase: string | null;
+  podMissing: boolean;
+}
+
+async function lookupPodState(
   namespace: string,
   jobName: string,
   kubeconfigPath?: string,
-): Promise<PodTerminatedState | null> {
+): Promise<PodLookupResult> {
   const coreApi = getCoreApi(kubeconfigPath);
   const podList = await coreApi.listNamespacedPod({
     namespace,
     labelSelector: `job-name=${jobName}`,
   });
   const pod = podList.items[0];
-  if (!pod) return null;
+  if (!pod) return { state: null, phase: null, podMissing: true };
 
+  const phase = pod.status?.phase ?? null;
   const containerStatus = pod.status?.containerStatuses?.find((s) => s.name === "claude");
   const terminated = containerStatus?.state?.terminated;
-  if (!terminated) return null;
+  if (!terminated) return { state: null, phase, podMissing: false };
   return {
-    exitCode: terminated.exitCode ?? null,
-    reason: terminated.reason ?? null,
-    message: (terminated.message ?? "").trim() || null,
-    signal: terminated.signal ?? null,
+    state: {
+      exitCode: terminated.exitCode ?? null,
+      reason: terminated.reason ?? null,
+      message: (terminated.message ?? "").trim() || null,
+      signal: terminated.signal ?? null,
+    },
+    phase,
+    podMissing: false,
   };
 }
 
+/**
+ * Read the claude container's terminated state, retrying briefly when the pod
+ * exists in a terminal phase but kubelet has not yet propagated the
+ * containerStatuses[].state.terminated field.  Without this retry, fast
+ * truncated-stream exits surface as "pod state unavailable" (FAR-107) and
+ * mask the real exit code / OOMKilled / SIGTERM cause.
+ */
+async function getPodLookupWithRetry(
+  namespace: string,
+  jobName: string,
+  kubeconfigPath?: string,
+  attempts = 4,
+  delayMs = 500,
+): Promise<PodLookupResult> {
+  let last: PodLookupResult = { state: null, phase: null, podMissing: true };
+  for (let i = 0; i < attempts; i++) {
+    last = await lookupPodState(namespace, jobName, kubeconfigPath);
+    if (last.state) return last;
+    if (last.podMissing) return last;
+    // Pod exists but no terminated state.  If it is in a terminal phase the
+    // containerStatuses update is in flight — wait briefly and retry.  If it
+    // is still Running/Pending, retrying is unlikely to help, so bail.
+    if (last.phase !== "Succeeded" && last.phase !== "Failed") return last;
+    if (i < attempts - 1) await new Promise((r) => setTimeout(r, delayMs));
+  }
+  return last;
+}
+
+async function getPodTerminatedState(
+  namespace: string,
+  jobName: string,
+  kubeconfigPath?: string,
+): Promise<PodTerminatedState | null> {
+  return (await lookupPodState(namespace, jobName, kubeconfigPath)).state;
+}
+
 /**
  * Format a human-readable explanation for a truncated run, including the
  * pod's claude-container terminated state when available. Exit code 137
@@ -682,9 +743,17 @@ async function getPodTerminatedState(
  */
 export function describeTruncationCause(
   state: PodTerminatedState | null,
+  lookup?: PodLookupResult,
 ): string {
   if (!state) {
-    return "pod state unavailable — likely deleted before exit could be read";
+    if (lookup?.podMissing) {
+      return "pod is gone — Job pod was removed (eviction, preemption, or external delete) before exit could be read";
+    }
+    if (lookup && !lookup.podMissing) {
+      const phaseHint = lookup.phase ? `pod phase=${lookup.phase}` : "pod present";
+      return `container terminated state not yet observable (${phaseHint}) — kubelet status update did not land within retry window; exit cause unknown`;
+    }
+    return "pod state unavailable — exit cause unknown";
   }
   const parts: string[] = [];
   if (state.exitCode !== null) {
@@ -1280,17 +1349,16 @@ export async function execute(ctx: AdapterExecutionContext): Promise<AdapterExec
       return onLog(stream, chunk);
     };
 
-    // Track when the log stream first exits so the grace-period can fire
-    // if the K8s Job condition lags behind container exit (FAR-23).
-    // Set via onFirstStreamExit callback (called after attempt=0 returns)
-    // rather than in .then() of streamPodLogs, which would create a
-    // deadlock: streamPodLogs only resolves after stopSignal is set, but
-    // stopSignal is set by the grace timer which needs logExitTime to be
-    // non-null.
-    let logExitTime: number | null = null;
+    // Track stream liveness so the grace timer below only fires when output
+    // has actually stopped — not on a transient K8s log-API reconnect that
+    // streamPodLogs heals on its own (FAR-107).
+    const streamActivity: { lastActiveAt: number; streamHasExited: boolean } = {
+      lastActiveAt: Date.now(),
+      streamHasExited: false,
+    };
     const trackedLogStream = streamPodLogs(
       namespace, podName, wrappedOnLog, kubeconfigPath, logStopSignal, logDedup,
-      () => { logExitTime = Date.now(); },
+      streamActivity,
     );
 
     // completionWithGrace races waitForJobCompletion against a grace timer
@@ -1320,7 +1388,17 @@ export async function execute(ctx: AdapterExecutionContext): Promise<AdapterExec
       };
       waitForJobCompletion(namespace, jobName, completionTimeoutMs, kubeconfigPath, jobObserver).then(settleOk).catch(settleErr);
       gracePoller = setInterval(() => {
-        if (logExitTime !== null && Date.now() - logExitTime >= LOG_EXIT_COMPLETION_GRACE_MS) {
+        // Only consider grace once the stream has exited at least once.
+        // Until then we are still in the warm-up window and
+        // waitForJobCompletion is the authoritative signal.  Once the
+        // stream has exited, fire only after GRACE_MS of inactivity
+        // measured against the last received chunk — output that resumes
+        // through a reconnect resets the clock so transient drops do not
+        // truncate live runs (FAR-107).
+        if (
+          streamActivity.streamHasExited &&
+          Date.now() - streamActivity.lastActiveAt >= LOG_EXIT_COMPLETION_GRACE_MS
+        ) {
           // Stop the grace poller immediately so we don't double-fire while the
           // verification read below is in flight.
           if (gracePoller) { clearInterval(gracePoller); gracePoller = null; }
@@ -1554,7 +1632,23 @@ export async function execute(ctx: AdapterExecutionContext): Promise<AdapterExec
       };
     }
     if (parsedStream.truncatedMidStream) {
-      const cause = describeTruncationCause(podTerminatedState);
+      // Re-query pod state with retry — the initial single-shot read can lose
+      // to kubelet propagation lag and surface a useless "pod state unavailable"
+      // message that hides the real exit cause (OOMKilled, SIGTERM, etc).  The
+      // retry distinguishes pod-genuinely-gone from terminated-state-lag and
+      // gives the operator the actual exit code/reason where possible (FAR-107).
+      let lookup: PodLookupResult | undefined;
+      let refreshedState = podTerminatedState;
+      try {
+        lookup = await getPodLookupWithRetry(namespace, jobName, kubeconfigPath);
+        refreshedState = lookup.state;
+        if (refreshedState && refreshedState.exitCode !== null) {
+          exitCode = refreshedState.exitCode;
+        }
+      } catch (err) {
+        await onLog("stderr", `[paperclip] truncation diagnostic: pod re-query failed (${err instanceof Error ? err.message : String(err)})\n`).catch(() => {});
+      }
+      const cause = describeTruncationCause(refreshedState, lookup);
       const modelHint = parsedStream.model ? ` (model: ${parsedStream.model})` : "";
       return {
         exitCode,