fix(server): settle routine status from committed work

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

server/src/__tests__/routine-execution-status-work.test.ts

@@ -0,0 +1,206 @@
+import { randomUUID } from "node:crypto";
+import { eq, sql } from "drizzle-orm";
+import { afterAll, afterEach, beforeAll, beforeEach, describe, expect, it, vi } from "vitest";
+import { agents, companies, createDb, heartbeatRuns, issues, pluginManagedResources, plugins, routineRuns, type Db } from "@paperclipai/db";
+import { getEmbeddedPostgresTestSupport, startEmbeddedPostgresTestDatabase } from "./helpers/embedded-postgres.js";
+import { resolveExternalTestDatabaseUrl } from "./helpers/external-test-database.js";
+import { createDeliveryWorkCoordinator } from "../services/delivery-work-coordinator.js";
+import { notifyRoutineExecutionStatus } from "../services/routine-execution-status-notifications.js";
+import { registerRoutineExecutionStatusWork } from "../services/routine-execution-status-work.js";
+import { routineExecutionStatusService } from "../services/routine-run-status.js";
+import { routineService } from "../services/routines.js";
+import { issueService } from "../services/issues.js";
+import { idleWorkSnapshot } from "../services/task-admission.js";
+import { createHeartbeatLifecycle, type HeartbeatLifecycleDependencies } from "../services/heartbeat/run-lifecycle.js";
+import { createHeartbeatRunState } from "../services/heartbeat/run-state.js";
+import { createHeartbeatRunPreparation } from "../services/heartbeat/run-preparation.js";
+
+const external = resolveExternalTestDatabaseUrl("PAPERCLIP_ROUTINE_STATUS_WORK_TEST_DATABASE_URL");
+const support = external ? { supported: true } : await getEmbeddedPostgresTestSupport();
+(support.supported ? describe : describe.skip)("routine execution status work with PostgreSQL", () => {
+  let db: Db, temporary: Awaited<ReturnType<typeof startEmbeddedPostgresTestDatabase>> | undefined;
+  let coordinator: ReturnType<typeof createDeliveryWorkCoordinator> | undefined;
+  let enabled = true, draining = false, standby = false;
+  const errors: unknown[] = [];
+  beforeAll(async () => {
+    if (!external) temporary = await startEmbeddedPostgresTestDatabase("routine-status-work-");
+    db = createDb(external ?? temporary!.connectionString, { maxConnections: 6 });
+  }, 60_000);
+  beforeEach(() => {
+    enabled = true; draining = false; standby = false; errors.length = 0;
+    vi.useFakeTimers({ toFake: ["Date", "setTimeout", "clearTimeout"], shouldAdvanceTime: true });
+  });
+  afterEach(async () => {
+    await coordinator?.stop(); coordinator = undefined;
+    vi.useRealTimers(); vi.restoreAllMocks();
+    await db.execute(sql`SET client_min_messages = warning; TRUNCATE companies CASCADE`);
+  });
+  afterAll(async () => { await db?.$client.end(); await temporary?.cleanup(); });
+  const canRun = () => enabled && !draining && !standby;
+  async function start(service = routineExecutionStatusService(db)) {
+    coordinator = createDeliveryWorkCoordinator({ owner: db, canRun, canReconcile: () => !standby,
+      onError: error => errors.push(error) });
+    const worker = registerRoutineExecutionStatusWork(coordinator, service, canRun);
+    await worker.ready;
+    return worker;
+  }
+  async function settled() { await vi.waitFor(() => expect(idleWorkSnapshot().active).toBe(0)); }
+  async function quiet() {
+    await settled();
+    const select = vi.spyOn(db, "select"), execute = vi.spyOn(db, "execute"), transaction = vi.spyOn(db, "transaction");
+    try {
+      await vi.advanceTimersByTimeAsync(20 * 60_000);
+      expect(select).not.toHaveBeenCalled(); expect(execute).not.toHaveBeenCalled(); expect(transaction).not.toHaveBeenCalled();
+    } finally { select.mockRestore(); execute.mockRestore(); transaction.mockRestore(); }
+  }
+  async function fixture() {
+    const companyId = randomUUID(), agentId = randomUUID();
+    await db.insert(companies).values({ id: companyId, name: "Routine status work", issuePrefix: `R${companyId.slice(0, 6)}`,
+      defaultResponsibleUserId: randomUUID(), requireBoardApprovalForNewAgents: false });
+    await db.insert(agents).values({ id: agentId, companyId, name: "Routine worker", status: "active", lifecycleState: "ready", adapterType: "codex_local" });
+    const service = routineService(db, { heartbeat: { wakeup: async () => null }, runtimeEnv: {} });
+    const routine = await service.create(companyId, { title: "Status projection", assigneeAgentId: agentId,
+      priority: "medium", status: "active", concurrencyPolicy: "always_enqueue", catchUpPolicy: "skip_missed" }, {});
+    return { companyId, agentId, routine, service };
+  }
+  async function dispatch(f: Awaited<ReturnType<typeof fixture>>) {
+    return f.service.runRoutine(f.routine.id, { source: "manual", idempotencyKey: randomUUID() });
+  }
+  async function saved(id: string) { return (await db.select().from(routineRuns).where(eq(routineRuns.id, id)))[0]; }
+  async function projected(id: string, status: string) {
+    await vi.waitFor(async () => expect((await saved(id)).status).toBe(status));
+    await settled();
+  }
+
+  it("settles empty startup, configured idle, healthy active and retained terminal history without recurring SQL", async () => {
+    await start(); await quiet();
+    const f = await fixture(); await quiet();
+    const run = await dispatch(f); await quiet();
+    await issueService(db).update(run.linkedIssueId!, { status: "done" });
+    await projected(run.id, "completed");
+    const before = await saved(run.id); await quiet();
+    expect(await saved(run.id)).toEqual(before); expect(errors).toEqual([]);
+  });
+  it.each(["done", "blocked", "cancelled"])("reactivates from the first ordinary %s transition and preserves input", async status => {
+    await start(); await quiet();
+    const f = await fixture(), run = await dispatch(f);
+    await issueService(db).update(run.linkedIssueId!, { status });
+    await projected(run.id, status === "done" ? "completed" : "failed");
+    expect((await saved(run.id)).completedAt).toBeInstanceOf(Date);
+    await quiet(); expect(errors).toEqual([]);
+    if (status !== "done") {
+      await issueService(db).update(run.linkedIssueId!, { status: "in_progress" });
+      await projected(run.id, "issue_created");
+      expect(await saved(run.id)).toMatchObject({ completedAt: null, failureReason: null });
+      await quiet();
+    }
+  });
+  it("reconstructs legacy terminal debt and reopened transient failures but leaves skipped and coalesced history unchanged", async () => {
+    const f = await fixture(), first = await dispatch(f), second = await dispatch(f);
+    await db.update(issues).set({ status: "done" }).where(eq(issues.id, first.linkedIssueId!));
+    await db.update(routineRuns).set({ status: "failed", failureReason: "Execution issue moved to blocked", completedAt: new Date() }).where(eq(routineRuns.id, second.id));
+    const terminal = await db.insert(routineRuns).values(["skipped", "coalesced"].map(status => ({ companyId: f.companyId,
+      routineId: f.routine.id, source: "manual", linkedIssueId: first.linkedIssueId, status, completedAt: new Date() }))).returning();
+    await start(); await projected(first.id, "completed"); await projected(second.id, "issue_created");
+    for (const row of terminal) expect(await saved(row.id)).toEqual(row);
+    await quiet(); expect(errors).toEqual([]);
+  });
+  it("settles the declared custom origin of a real plugin-managed dispatch and preserves other companies", async () => {
+    const f = await fixture(), other = await fixture();
+    const pluginKey = `routine-status-${randomUUID()}`, originId = `operation:${randomUUID()}`;
+    const [plugin] = await db.insert(plugins).values({ pluginKey, packageName: pluginKey, version: "0.1.0",
+      manifestJson: { id: pluginKey, apiVersion: 1, version: "0.1.0", displayName: "Routine test", description: "Routine test",
+        author: "Paperclip", categories: ["automation"], capabilities: ["routines.managed"], entrypoints: { worker: "./worker.js" } } }).returning();
+    await db.insert(pluginManagedResources).values({ companyId: f.companyId, pluginId: plugin.id, pluginKey,
+      resourceKind: "routine", resourceKey: "status", resourceId: f.routine.id, defaultsJson: { issueTemplate: { originId } } });
+    const run = await dispatch(f), otherRun = await dispatch(other);
+    expect((await db.select().from(issues).where(eq(issues.id, run.linkedIssueId!)))[0].originId).toBe(originId);
+    await start(); await quiet();
+    await issueService(db).update(run.linkedIssueId!, { status: "done" }); await projected(run.id, "completed");
+    const before = await saved(run.id);
+    await db.transaction(async tx => { await notifyRoutineExecutionStatus(tx, run.linkedIssueId!); await notifyRoutineExecutionStatus(tx, run.linkedIssueId!); });
+    await settled(); await quiet();
+    expect(await saved(run.id)).toEqual(before); expect((await saved(otherRun.id)).status).toBe("issue_created"); expect(errors).toEqual([]);
+  });
+  it("waits for the real outer transaction and forgets a rolled-back nested status write", async () => {
+    const f = await fixture(), run = await dispatch(f); await start(); await quiet();
+    let release!: () => void, entered!: () => void;
+    const gate = new Promise<void>(resolve => { release = resolve; });
+    const written = new Promise<void>(resolve => { entered = resolve; });
+    const writing = db.transaction(async tx => {
+      await issueService(db).update(run.linkedIssueId!, { status: "done" }, tx);
+      entered(); await gate;
+    });
+    try { await written; expect((await saved(run.id)).status).toBe("issue_created"); }
+    finally { release(); await writing; }
+    await projected(run.id, "completed"); await quiet();
+    const other = await dispatch(f);
+    await expect(db.transaction(async tx => {
+      await issueService(db).update(other.linkedIssueId!, { status: "cancelled" }, tx);
+      throw new Error("outer rollback");
+    })).rejects.toThrow("outer rollback");
+    await settled(); expect((await saved(other.id)).status).toBe("issue_created"); await quiet(); expect(errors).toEqual([]);
+  });
+  it("keeps the first write during drain and reconstructs on resume without passive SQL", async () => {
+    const f = await fixture(), run = await dispatch(f); await start(); await quiet();
+    draining = true;
+    await issueService(db).update(run.linkedIssueId!, { status: "cancelled" });
+    await settled(); await quiet(); expect((await saved(run.id)).status).toBe("issue_created");
+    draining = false; await vi.advanceTimersByTimeAsync(30_000); await projected(run.id, "failed");
+    await quiet(); expect(errors).toEqual([]);
+  });
+  it.each(["standby", "disabled"])("does no owner SQL while %s and reconstructs when enabled", async mode => {
+    const f = await fixture(), run = await dispatch(f);
+    await issueService(db).update(run.linkedIssueId!, { status: "done" });
+    if (mode === "standby") standby = true; else enabled = false;
+    await start(); await quiet(); expect((await saved(run.id)).status).toBe("issue_created");
+    standby = false; enabled = true; await vi.advanceTimersByTimeAsync(30_000);
+    await projected(run.id, "completed"); await quiet(); expect(errors).toEqual([]);
+  });
+  it("retries failed exact owners, retains the retry across drain and reconstructs after restart", async () => {
+    const f = await fixture(), run = await dispatch(f), service = routineExecutionStatusService(db);
+    const settle = vi.spyOn(service, "settle").mockRejectedValueOnce(new Error("projection unavailable"));
+    await start(service);
+    await issueService(db).update(run.linkedIssueId!, { status: "done" });
+    await vi.waitFor(() => expect(errors).toHaveLength(1));
+    expect((await saved(run.id)).status).toBe("issue_created");
+    await vi.advanceTimersByTimeAsync(29_000); expect(settle).toHaveBeenCalledTimes(1);
+    draining = true; await vi.advanceTimersByTimeAsync(60_000); await quiet();
+    draining = false; await vi.advanceTimersByTimeAsync(30_000); await projected(run.id, "completed"); await quiet();
+    await coordinator!.stop(); coordinator = undefined;
+    const other = await dispatch(f); await issueService(db).update(other.linkedIssueId!, { status: "blocked" });
+    await start(); await projected(other.id, "failed"); await quiet();
+  });
+  it("preserves notifications during a sweep, coalesces duplicate hints and never overlaps", async () => {
+    const f = await fixture(), first = await dispatch(f), second = await dispatch(f), service = routineExecutionStatusService(db);
+    let entered!: () => void, release!: () => void;
+    const enteredGate = new Promise<void>(resolve => { entered = resolve; });
+    const releaseGate = new Promise<void>(resolve => { release = resolve; });
+    const load = service.load;
+    vi.spyOn(service, "load").mockImplementationOnce(async issueId => { const rows = await load(issueId); entered(); await releaseGate; return rows; });
+    const starting = start(service); await enteredGate;
+    await issueService(db).update(second.linkedIssueId!, { status: "done" });
+    await db.transaction(async tx => { await notifyRoutineExecutionStatus(tx, second.linkedIssueId!); await notifyRoutineExecutionStatus(tx, second.linkedIssueId!); });
+    release(); await starting;
+    await projected(second.id, "completed"); expect((await saved(first.id)).status).toBe("issue_created");
+    await quiet(); expect(errors).toEqual([]);
+  });
+  it.each(["succeeded", "failed", "cancelled", "interrupted", "timed_out"])("uses real %s run lifecycle changes for activeIssue without an open-issue retry", async status => {
+    const f = await fixture(), run = await dispatch(f); await start();
+    const [execution] = await db.insert(heartbeatRuns).values({ companyId: f.companyId, agentId: f.agentId,
+      status: "running", contextSnapshot: { issueId: run.linkedIssueId } }).returning();
+    await db.update(issues).set({ executionRunId: execution.id }).where(eq(issues.id, run.linkedIssueId!));
+    expect((await f.service.getDetail(f.routine.id))?.activeIssue?.id).toBe(run.linkedIssueId);
+    const deps = {
+      ...createHeartbeatRunState(db), ...createHeartbeatRunPreparation(db),
+      issuesSvc: { addComment: vi.fn(), listReviewAttention: vi.fn() },
+      recovery: { escalateStrandedAssignedIssue: vi.fn() }, companySkills: { completeTestRunForIssue: vi.fn() },
+      budgets: { getInvocationBlock: vi.fn(async () => null) }, treeControlSvc: { getActivePauseHoldGate: vi.fn(async () => null) },
+      enqueueWakeup: vi.fn(), getCurrentUserRedactionOptions: vi.fn(async () => ({})),
+      getAgentInvokability: vi.fn(async () => ({ invokable: true })), emitTerminalAgentTaskRun: vi.fn(), budgetHooks: {},
+    } satisfies HeartbeatLifecycleDependencies;
+    await createHeartbeatLifecycle(db, deps).setRunStatusIfRunning(execution.id, status, { finishedAt: new Date() });
+    expect((await f.service.getDetail(f.routine.id))?.activeIssue).toBeNull();
+    expect((await saved(run.id)).status).toBe("issue_created"); await quiet(); expect(errors).toEqual([]);
+  });
+});

server/src/__tests__/routine-execution-status-worker.test.ts

@@ -0,0 +1,86 @@
+import { installDatabaseWorkSignals } from "../../../packages/db/src/work-signals.js";
+import { afterEach, beforeEach, expect, it, vi } from "vitest";
+import { createDeliveryWorkCoordinator } from "../services/delivery-work-coordinator.js";
+import { registerRoutineExecutionStatusWork } from "../services/routine-execution-status-work.js";
+
+let coordinator: ReturnType<typeof createDeliveryWorkCoordinator>;
+let canRun = true;
+const errors: unknown[] = [];
+const entry = { id: "run", companyId: "company", routineId: "routine", issueId: "issue" };
+beforeEach(() => {
+  vi.useFakeTimers(); canRun = true; errors.length = 0;
+  const owner = installDatabaseWorkSignals({ execute: vi.fn(async () => []) });
+  coordinator = createDeliveryWorkCoordinator({ owner, canRun: () => canRun, canReconcile: () => true,
+    onError: error => errors.push(error) });
+});
+afterEach(async () => { await coordinator.stop(); vi.useRealTimers(); });
+
+it("loads actual debt once and leaves no recurring owner work", async () => {
+  const service = { load: vi.fn(async () => []), settle: vi.fn(async () => true) };
+  await registerRoutineExecutionStatusWork(coordinator, service, () => canRun).ready;
+  expect(service.load).toHaveBeenCalledExactlyOnceWith(undefined);
+  expect(coordinator.nextWakeAt()).toBeNull();
+  await vi.advanceTimersByTimeAsync(20 * 60_000);
+  expect(service.load).toHaveBeenCalledOnce(); expect(service.settle).not.toHaveBeenCalled(); expect(errors).toEqual([]);
+});
+
+it("reconstructs only an invalidated issue and coalesces duplicate requests", async () => {
+  const service = { load: vi.fn(async (_issueId?: string) => [] as typeof entry[]), settle: vi.fn(async () => true) };
+  const worker = registerRoutineExecutionStatusWork(coordinator, service, () => canRun); await worker.ready;
+  service.load.mockResolvedValueOnce([entry]);
+  worker.invalidate("issue"); worker.invalidate("issue");
+  await vi.advanceTimersByTimeAsync(1000);
+  expect(service.load).toHaveBeenLastCalledWith("issue"); expect(service.load).toHaveBeenCalledTimes(2);
+  expect(service.settle).toHaveBeenCalledExactlyOnceWith(expect.objectContaining(entry));
+  expect(coordinator.nextWakeAt()).toBeNull(); expect(errors).toEqual([]);
+});
+
+it("retries only the failed owner at backoff and disarms after success", async () => {
+  const service = { load: vi.fn(async () => [entry]), settle: vi.fn(async () => true).mockRejectedValueOnce(new Error("locked")) };
+  await registerRoutineExecutionStatusWork(coordinator, service, () => canRun).ready;
+  expect(errors).toHaveLength(1);
+  const retryAt = coordinator.nextWakeAt(); expect(retryAt).toBe(Date.now() + 30_000);
+  await vi.advanceTimersByTimeAsync(29_999); expect(service.settle).toHaveBeenCalledOnce();
+  await vi.advanceTimersByTimeAsync(1); expect(service.settle).toHaveBeenCalledTimes(2);
+  expect(service.load).toHaveBeenCalledOnce(); expect(coordinator.nextWakeAt()).toBeNull();
+  await vi.advanceTimersByTimeAsync(20 * 60_000); expect(service.settle).toHaveBeenCalledTimes(2);
+});
+
+it("retains startup and first work during drain without passive owner calls", async () => {
+  canRun = false;
+  const service = { load: vi.fn(async () => [entry]), settle: vi.fn(async () => true) };
+  const worker = registerRoutineExecutionStatusWork(coordinator, service, () => canRun); await worker.ready;
+  worker.invalidate("issue");
+  await vi.advanceTimersByTimeAsync(20 * 60_000);
+  expect(service.load).not.toHaveBeenCalled(); expect(service.settle).not.toHaveBeenCalled();
+  canRun = true; await vi.advanceTimersByTimeAsync(30_000);
+  expect(service.settle).toHaveBeenCalledOnce(); expect(coordinator.nextWakeAt()).toBeNull(); expect(errors).toEqual([]);
+});
+
+it("keeps a failed owner across drain and retries after resume", async () => {
+  const service = { load: vi.fn(async () => [entry]), settle: vi.fn(async () => true).mockRejectedValueOnce(new Error("write failed")) };
+  await registerRoutineExecutionStatusWork(coordinator, service, () => canRun).ready;
+  canRun = false; await vi.advanceTimersByTimeAsync(20 * 60_000);
+  expect(service.settle).toHaveBeenCalledOnce(); expect(service.load).toHaveBeenCalledOnce();
+  canRun = true; await vi.advanceTimersByTimeAsync(30_000);
+  expect(service.settle).toHaveBeenCalledTimes(2); expect(coordinator.nextWakeAt()).toBeNull();
+});
+
+it("retains a notification that arrives while the startup reconstruction is in flight", async () => {
+  let release!: () => void;
+  const gate = new Promise<void>(resolve => { release = resolve; });
+  const service = { load: vi.fn(async (_issueId?: string) => [] as typeof entry[]), settle: vi.fn(async () => true) };
+  service.load.mockImplementationOnce(async () => { await gate; return []; });
+  const worker = registerRoutineExecutionStatusWork(coordinator, service, () => canRun);
+  await vi.waitFor(() => expect(service.load).toHaveBeenCalledOnce());
+  worker.invalidate("issue"); service.load.mockResolvedValueOnce([entry]); release(); await worker.ready;
+  await vi.advanceTimersByTimeAsync(1000);
+  expect(service.settle).toHaveBeenCalledOnce(); expect(coordinator.nextWakeAt()).toBeNull(); expect(errors).toEqual([]);
+});
+
+it("cancels retries and subscriptions at shutdown", async () => {
+  const service = { load: vi.fn(async () => [entry]), settle: vi.fn(async () => true).mockRejectedValue(new Error("offline")) };
+  const worker = registerRoutineExecutionStatusWork(coordinator, service, () => canRun); await worker.ready;
+  await worker.stop(); worker.invalidate("issue"); await vi.advanceTimersByTimeAsync(20 * 60_000);
+  expect(service.settle).toHaveBeenCalledOnce(); expect(coordinator.nextWakeAt()).toBeNull();
+});

server/src/__tests__/routine-status-reconciliation.test.ts

@@ -1,3 +1,4 @@
+import { resolveExternalTestDatabaseUrl } from "./helpers/external-test-database.js";
 import { randomUUID } from "node:crypto";
 import { eq, sql } from "drizzle-orm";
 import { afterAll, afterEach, beforeAll, describe, expect, it, vi } from "vitest";
@@ -5,11 +6,12 @@ import { companies, createDb, issues, routineRuns, routines } from "@paperclipai
 import { routineService } from "../services/routines.js";
 import { getEmbeddedPostgresTestSupport, startEmbeddedPostgresTestDatabase } from "./helpers/embedded-postgres.js";
 
-const support = await getEmbeddedPostgresTestSupport();
+const external = resolveExternalTestDatabaseUrl("PAPERCLIP_ROUTINE_STATUS_TEST_DATABASE_URL");
+const support = external ? { supported: true, reason: undefined } : await getEmbeddedPostgresTestSupport();
 if (!support.supported) console.warn(`Skipping routine status database tests: ${support.reason}`);
 (support.supported ? describe : describe.skip)("routine status reconciliation", () => {
   let db: ReturnType<typeof createDb>, database: Awaited<ReturnType<typeof startEmbeddedPostgresTestDatabase>>;
-  beforeAll(async () => { database = await startEmbeddedPostgresTestDatabase("routine-status-"); db = createDb(database.connectionString); }, 60_000);
+  beforeAll(async () => { if (!external) database = await startEmbeddedPostgresTestDatabase("routine-status-"); db = createDb(external ?? database.connectionString, { maxConnections: 6 }); }, 60_000);
   afterEach(async () => { vi.restoreAllMocks(); await db.execute(sql`SET client_min_messages = warning; TRUNCATE companies CASCADE`); });
   afterAll(async () => { await db?.$client.end(); await database?.cleanup(); });
   async function seed(status = "blocked") {