diff --git a/packages/jimmy/src/cron/__tests__/runner.test.ts b/packages/jimmy/src/cron/__tests__/runner.test.ts index 9b001e6b9..ecc62ab5f 100644 --- a/packages/jimmy/src/cron/__tests__/runner.test.ts +++ b/packages/jimmy/src/cron/__tests__/runner.test.ts @@ -340,3 +340,134 @@ describe("runCronJob — session ended in error without route() throwing", () => expect(opsAlert).not.toHaveBeenCalled(); }); }); + +describe("runCronJob — session killed by the wall-clock timeout", () => { + // Regression for the Aug-2026 steward finding: sessions.maxDurationMinutes + // killed the engine, the manager flattened the kill to status:"idle" + + // lastError:null, and the runner logged {"status":"success","error":null} + // with no delivery and no alert. 75 runs across ~20 jobs went dark that way — + // including the system-steward audit itself, which failed 2/2 months while + // its run history read "success" both times. + beforeEach(async () => { + const { opsAlert } = await import("../../shared/ops-alert.js"); + const { appendRunLog } = await import("../jobs.js"); + const { getSession } = await import("../../sessions/registry.js"); + (opsAlert as any).mockReset().mockResolvedValue(undefined); + (appendRunLog as any).mockClear(); + (getSession as any).mockReset().mockReturnValue(undefined); + }); + + const timedOutSession = (overrides = {}) => ({ + status: "interrupted", + lastError: "Interrupted: session timeout (45m)", + totalTurns: 137, + ...overrides, + }); + + it("logs status 'session_timeout' carrying the reason, not 'success'", async () => { + const { appendRunLog } = await import("../jobs.js"); + const { getSession } = await import("../../sessions/registry.js"); + (getSession as any).mockReturnValue(timedOutSession()); + + const sessionManager = makeMockSessionManager(0); + const connectors = new Map([["slack", makeMockConnector()]]); + + await runCronJob(makeJob(), sessionManager, makeConfig(), connectors); + + expect(appendRunLog).toHaveBeenCalledWith( + "test-job", + expect.objectContaining({ + status: "session_timeout", + error: "Interrupted: session timeout (45m)", + actualTurns: 137, + }), + ); + }); + + it("fires an ops-alert naming the timeout", async () => { + const { opsAlert } = await import("../../shared/ops-alert.js"); + const { getSession } = await import("../../sessions/registry.js"); + (getSession as any).mockReturnValue(timedOutSession()); + + const sessionManager = makeMockSessionManager(0); + const connectors = new Map([["slack", makeMockConnector()]]); + + await runCronJob(makeJob(), sessionManager, makeConfig(), connectors); + + expect(opsAlert).toHaveBeenCalledTimes(1); + const msg = (opsAlert as any).mock.calls[0][0]; + expect(msg).toContain("FAILED"); + expect(msg).toMatch(/wall-clock/i); + }); + + it("warns about partial writes when the job is flagged sideEffects", async () => { + const { opsAlert } = await import("../../shared/ops-alert.js"); + const { getSession } = await import("../../sessions/registry.js"); + (getSession as any).mockReturnValue(timedOutSession()); + + const sessionManager = makeMockSessionManager(0); + const connectors = new Map([["slack", makeMockConnector()]]); + + await runCronJob( + makeJob({ sessionBudget: { sideEffects: true } }), + sessionManager, + makeConfig(), + connectors, + ); + + expect((opsAlert as any).mock.calls[0][0]).toContain("partial external writes"); + }); + + it("does NOT also fire the latency alert (single alert, no 🐢 on top)", async () => { + const { opsAlert } = await import("../../shared/ops-alert.js"); + const { getSession } = await import("../../sessions/registry.js"); + (getSession as any).mockReturnValue(timedOutSession()); + + const connector = makeMockConnector(); + const connectors = new Map([["slack", connector]]); + // 200ms run against a 100ms threshold would normally trip the latency alert + const sessionManager = makeMockSessionManager(200); + + await runCronJob(makeJob(), sessionManager, makeConfig({ alertThresholdMs: 100 }), connectors); + + expect(opsAlert).toHaveBeenCalledTimes(1); + expect(connector.sendMessage).not.toHaveBeenCalled(); + }); + + it("catches the engine-never-started timeout shape too", async () => { + const { appendRunLog } = await import("../jobs.js"); + const { getSession } = await import("../../sessions/registry.js"); + (getSession as any).mockReturnValue( + timedOutSession({ lastError: "Interrupted: session timeout (45m) — engine never started" }), + ); + + const sessionManager = makeMockSessionManager(0); + const connectors = new Map([["slack", makeMockConnector()]]); + + await runCronJob(makeJob(), sessionManager, makeConfig(), connectors); + + expect(appendRunLog).toHaveBeenCalledWith( + "test-job", + expect.objectContaining({ status: "session_timeout" }), + ); + }); + + it("does NOT classify a benign user interrupt as a timeout", async () => { + const { appendRunLog } = await import("../jobs.js"); + const { opsAlert } = await import("../../shared/ops-alert.js"); + const { getSession } = await import("../../sessions/registry.js"); + // "Interrupted by user" / "new message received" stay silent successes + (getSession as any).mockReturnValue({ status: "idle", lastError: null, totalTurns: 4 }); + + const sessionManager = makeMockSessionManager(0); + const connectors = new Map([["slack", makeMockConnector()]]); + + await runCronJob(makeJob(), sessionManager, makeConfig(), connectors); + + expect(appendRunLog).toHaveBeenCalledWith( + "test-job", + expect.objectContaining({ status: "success" }), + ); + expect(opsAlert).not.toHaveBeenCalled(); + }); +}); diff --git a/packages/jimmy/src/cron/runner.ts b/packages/jimmy/src/cron/runner.ts index 14f7e2e97..eaae335d3 100644 --- a/packages/jimmy/src/cron/runner.ts +++ b/packages/jimmy/src/cron/runner.ts @@ -7,6 +7,7 @@ import { CronConnector } from "../connectors/cron/index.js"; import type { SessionManager } from "../sessions/manager.js"; import { resolveJobBudget, SESSION_BUDGET_STOP_PREFIX } from "../sessions/budget.js"; import { getSession } from "../sessions/registry.js"; +import { SESSION_TIMEOUT_PREFIX } from "../shared/timeout.js"; import { opsAlert } from "../shared/ops-alert.js"; import { runPrecheck } from "./precheck.js"; @@ -174,19 +175,36 @@ export async function runCronJob( // Jun-2026 silent cron outage (a moved Claude binary ENOENT'd ~400 fires, // every one logged "completed in 16ms"). Treat a non-budget session error as // a cron failure: record it and fire an ops-alert. - const sessionErrored = !budgetStopped && finalSession?.status === "error"; + // A session killed by the wall-clock cap (sessions.maxDurationMinutes) is + // ALSO not a success: the manager used to flatten it to status:"idle" with a + // null lastError, so it landed here as "success"/no-alert — 75 runs across + // ~20 jobs went dark that way, including this steward's own monthly audit + // failing 2/2 months while run-history read "success". The manager now + // preserves status:"interrupted" + the SESSION_TIMEOUT_PREFIX sentinel; + // classify it as a distinct failure so the reason survives into the run-log. + const timedOut = !budgetStopped && !!finalSession?.lastError?.startsWith(SESSION_TIMEOUT_PREFIX); + const sessionErrored = !budgetStopped && !timedOut && finalSession?.status === "error"; appendRunLog(job.id, { timestamp: startedAt, sessionKey, sessionId: routeResult?.sessionId ?? null, - status: budgetStopped ? "session_budget_stop" : sessionErrored ? "error" : "success", + status: budgetStopped + ? "session_budget_stop" + : timedOut + ? "session_timeout" + : sessionErrored + ? "error" + : "success", durationMs, error: budgetStopped ? finalSession?.lastError ?? null - : sessionErrored - ? finalSession?.lastError ?? "session ended in error" - : null, + : timedOut + ? finalSession?.lastError ?? "session hit the wall-clock timeout" + : sessionErrored + ? finalSession?.lastError ?? "session ended in error" + : null, ...(budgetStopped ? { maxTurns: budget.maxTurns, actualTurns: finalSession?.totalTurns ?? null } : {}), + ...(timedOut ? { actualTurns: finalSession?.totalTurns ?? null } : {}), ...catchUpFields, resultPreview: null, }); @@ -196,7 +214,19 @@ export async function runCronJob( `after ~${finalSession?.totalTurns ?? "?"} turns. This job is flagged sideEffects:true — check for partial external writes.`, ).catch(() => {}); } - if (sessionErrored) { + if (timedOut) { + logger.error( + `Cron job "${job.name}" (${job.id}) hit the session wall-clock timeout after ${durationMs}ms: ${finalSession?.lastError ?? "(no message)"}`, + ); + await opsAlert( + `Cron "${job.name}" (${job.id}) FAILED — killed by the session wall-clock cap after ` + + `${(durationMs / 60_000).toFixed(1)}min (~${finalSession?.totalTurns ?? "?"} turns). No reply was delivered. ` + + `${finalSession?.lastError?.slice(0, 200) ?? ""}` + + (budget.sideEffects + ? " This job is flagged sideEffects:true — check for partial external writes." + : " Raise sessions.maxDurationMinutes or trim the job's scope."), + ).catch(() => {}); + } else if (sessionErrored) { logger.error( `Cron job "${job.name}" (${job.id}) session ended in error in ${durationMs}ms: ${finalSession?.lastError ?? "(no message)"}`, ); @@ -208,9 +238,11 @@ export async function runCronJob( logger.info(`Cron job "${job.name}" ${budgetStopped ? "stopped at turn budget" : "completed"} in ${durationMs}ms`); } - // Latency alert: warn if job exceeded threshold + // Latency alert: warn if job exceeded threshold. Skipped on a timeout — a + // wall-clock kill always blows past the latency threshold, and the failure + // alert above already carries the duration; a 🐢 on top is pure noise. const thresholdMs = config.cron?.alertThresholdMs; - if (thresholdMs && durationMs > thresholdMs) { + if (thresholdMs && durationMs > thresholdMs && !timedOut) { const alertConnector = config.cron?.alertConnector; const alertChannel = config.cron?.alertChannel; if (alertConnector && alertChannel) { diff --git a/packages/jimmy/src/gateway/api.ts b/packages/jimmy/src/gateway/api.ts index a45e8261b..6ce03495c 100644 --- a/packages/jimmy/src/gateway/api.ts +++ b/packages/jimmy/src/gateway/api.ts @@ -6,7 +6,7 @@ import path from "node:path"; import yaml from "js-yaml"; import type { CronJob, Engine, IncomingMessage, JinnConfig, Session, Target } from "../shared/types.js"; import { isInterruptibleEngine } from "../shared/types.js"; -import { startSessionTimeout } from "../shared/timeout.js"; +import { startSessionTimeout, SESSION_TIMEOUT_PREFIX } from "../shared/timeout.js"; import type { SessionManager } from "../sessions/manager.js"; import { buildContext } from "../sessions/context.js"; import { @@ -2541,6 +2541,9 @@ async function runWebSession( } const wasInterrupted = result.error?.startsWith("Interrupted"); + // Same carve-out as SessionManager.runSession: a wall-clock timeout kill is + // not a benign interrupt and must not be flattened to a clean idle row. + const timedOut = !!result.error?.startsWith(SESSION_TIMEOUT_PREFIX); const rateLimit = !wasInterrupted ? detectRateLimit(result) : { limited: false as const }; if (rateLimit.limited) { @@ -2835,9 +2838,9 @@ async function runWebSession( const completedSession = updateSession(currentSession.id, { ...(result.sessionId?.trim() ? { engineSessionId: result.sessionId } : {}), - status: wasInterrupted ? "idle" : (result.error ? "error" : "idle"), + status: timedOut ? "interrupted" : wasInterrupted ? "idle" : (result.error ? "error" : "idle"), lastActivity: new Date().toISOString(), - lastError: wasInterrupted ? null : (result.error ?? null), + lastError: timedOut ? (result.error ?? null) : (wasInterrupted ? null : (result.error ?? null)), }); if (result.cost || result.numTurns) { try { diff --git a/packages/jimmy/src/sessions/manager.ts b/packages/jimmy/src/sessions/manager.ts index a1f151622..2de84b481 100644 --- a/packages/jimmy/src/sessions/manager.ts +++ b/packages/jimmy/src/sessions/manager.ts @@ -10,7 +10,7 @@ import type { Target, } from "../shared/types.js"; import { modelFor } from "../shared/types.js"; -import { startSessionTimeout } from "../shared/timeout.js"; +import { startSessionTimeout, sessionTimeoutReason, SESSION_TIMEOUT_PREFIX } from "../shared/timeout.js"; import { accumulateSessionCost, logSessionCost, @@ -378,7 +378,9 @@ export class SessionManager { source: session.source, onForceInterrupt: () => updateSession(session.id, { status: "interrupted", - lastError: `Session timeout (${timeoutMinutes}m) — engine never started`, + // Same sentinel prefix as the live-engine kill, so the cron runner + // classifies both timeout shapes identically. + lastError: `${sessionTimeoutReason(Number(timeoutMinutes))} — engine never started`, }), }); @@ -505,6 +507,11 @@ export class SessionManager { } const wasInterrupted = result.error?.startsWith("Interrupted"); + // A wall-clock timeout kill is NOT a benign interrupt. "Interrupted by + // user"/"new message received" are expected and must stay silent, but the + // maxDurationMinutes kill means the task died mid-flight — it has to + // survive into the session row so the cron runner can classify the run. + const timedOut = !!result.error?.startsWith(SESSION_TIMEOUT_PREFIX); // Dead session detection: if the engine session ID is stale (expired/invalid), // clear cached engine sessions from transportMeta so the next attempt starts fresh. @@ -935,7 +942,7 @@ export class SessionManager { } const updatedSession = updateSession(session.id, { ...(result.sessionId?.trim() ? { engineSessionId: result.sessionId } : {}), - status: wasInterrupted ? "idle" : (result.error ? "error" : "idle"), + status: timedOut ? "interrupted" : wasInterrupted ? "idle" : (result.error ? "error" : "idle"), replyContext: msg.replyContext, messageId: msg.messageId ?? null, transportMeta: (() => { @@ -946,10 +953,10 @@ export class SessionManager { return merged as any; })(), lastActivity: new Date().toISOString(), - lastError: wasInterrupted ? null : (result.error ?? null), + lastError: timedOut ? (result.error ?? null) : (wasInterrupted ? null : (result.error ?? null)), }); if (updatedSession) { - notifyParentSession(updatedSession, { result: result.result, error: wasInterrupted ? null : (result.error ?? null), cost: result.cost, durationMs: result.durationMs }, { alwaysNotify: employee?.alwaysNotify }); + notifyParentSession(updatedSession, { result: result.result, error: (timedOut || !wasInterrupted) ? (result.error ?? null) : null, cost: result.cost, durationMs: result.durationMs }, { alwaysNotify: employee?.alwaysNotify }); } logger.info( diff --git a/packages/jimmy/src/shared/timeout.ts b/packages/jimmy/src/shared/timeout.ts index b19218c80..d3d0423a3 100644 --- a/packages/jimmy/src/shared/timeout.ts +++ b/packages/jimmy/src/shared/timeout.ts @@ -2,6 +2,19 @@ import type { Engine } from "./types.js"; import { isInterruptibleEngine } from "./types.js"; import { logger } from "./logger.js"; +/** Sentinel prefix for the kill reason written when the wall-clock cap fires. + * Still begins with "Interrupted" so the engines' retry-skip and the session + * manager's `startsWith("Interrupted")` idiom keep working, but is specific + * enough that both the manager and the cron runner can tell a TIMEOUT kill + * apart from a benign user interrupt ("Interrupted by user", "Interrupted: + * new message received"). Mirrors SESSION_BUDGET_STOP_PREFIX. */ +export const SESSION_TIMEOUT_PREFIX = "Interrupted: session timeout"; + +/** The exact kill reason for a wall-clock timeout at `minutes`. */ +export function sessionTimeoutReason(minutes: number): string { + return `${SESSION_TIMEOUT_PREFIX} (${minutes}m)`; +} + /** * Start a session timeout that kills the engine after `timeoutMinutes`. * Returns the timer handle (for clearTimeout in finally), or undefined if no timeout was set. @@ -31,7 +44,7 @@ export function startSessionTimeout( return setTimeout(() => { const wasAlive = engine.isAlive(sessionId); logger.info(`Session ${label} exceeded ${capped}m timeout — killing engine`); - engine.kill(sessionId, `Interrupted: session timeout (${capped}m)`); + engine.kill(sessionId, sessionTimeoutReason(capped)); if (!wasAlive) { logger.warn(`Session ${label} has no live engine process — marking interrupted`); opts?.onForceInterrupt?.();