mirror of
https://github.com/paperclipai/paperclip.git
synced 2026-10-23 17:33:51 +02:00
## Thinking Path > - Paperclip is the open source app people use to manage AI agents for work. > - Native runs persist their results and workspace before they release execution. > - A task monitor must wait for that settlement before it starts the next run. > - The scheduler checked provider status but did not check unfinished finalization. > - A timer could dispatch too early, then its old finalizer could no longer find the consumed schedule. > - This pull request delays dispatch and reconciles prior delivery from server records. > - The task can continue without repeating the provider turn or removing a newer run's ownership. ## Linked Issues or Issue Description **What happened?** A native run saved a yielded monitor result while workspace finalization needed recovery. Its timer dispatched after the provider stopped. The follow-up failed because the earlier run still held workspace recovery. The old finalizer then retried `monitor_wait_authority_lost` indefinitely. **Expected behavior** Timer dispatch waits for native finalization. If an older timer already dispatched, the finalizer uses its saved scheduling receipt and admitted successor to settle the old result. It preserves current task state and ownership. **Steps to reproduce** 1. Schedule a task monitor from a native run and save a yielded result. 2. Leave native finalization retryable after the provider reaches a terminal state. 3. Let the monitor become due. Before this change, the scheduler consumes it. 4. Restore workspace persistence and retry the old finalizer. Before this change, the missing schedule leaves it retryable. **Paperclip version or commit** Reproduced against master `34be1b831bcaba070264ae8d214ceffe6a8f9eab`. **Deployment mode** Self-hosted server built from source, with PostgreSQL and the native runner. Related recent recovery work: #16962 and #16963. No duplicate repair found for this failure. ## What Changed - Scheduled and manual monitor dispatch wait for unfinished native finalization. If the monitor expires during workspace recovery, the accepted result can settle into the persisted schedule, and the scheduler then applies its existing expiry policy. New monitor-wait results still require an unexpired, unexhausted schedule. - A narrow reader joins the run's server-issued monitor receipt to its durable wake and admitted successor. - The finalizer and locked status commit verify that evidence and preserve current task ownership. They do not create another wake. - Monitor delivery participates in assessment identity, so recovery can replace a prior error decision without violating the decision ledger's uniqueness constraints. - PostgreSQL regressions cover saved-result replay, active successors, wrong task or agent, missing receipts, unadmitted wakes, ownership races, and failed workspace persistence. - The execution contract and verification maps describe the recovery boundary. ## Verification - Red: the saved monitor regression remained `retryable_failure` instead of `committed` on unpatched code. - Red: the scheduler admitted a wake while terminal-run finalization remained retryable. - Red/green: two PostgreSQL cases reproduce timeout during workspace recovery for scheduled and manual checks. Before the review repair, both remain `retryable_failure` with `monitor_wait_authority_lost`. Afterward, both commit, apply board escalation once, preserve the saved result, and enqueue zero provider wakes. New completion still rejects the expired schedule. - Typecheck: `pnpm -r typecheck` passed. - Build: `pnpm build` passed. - Maps: `node scripts/check-maps.mjs` passed. - Review: Greptile 5/5 and Ponytail Paperclip Review 5/5 on the current head, with no unresolved findings. Both reviews are static; execution evidence is recorded separately above and below. - Linux staging: the original repair passed 170 tests across monitor integration, scheduling, status arbitration, and workspace finalization. The expanded suite passes all 172 tests, including both new timeout regressions. - Live acceptance: deployed the original repair to the authorized Linux ARM64 self-hosted instance. The stranded saved result finalized automatically; the original task then completed through normal admission, with its final answer persisted after browser reload. The other original task was already complete and its external delivery was verified without repeating it. - The initial Mac regression run passed 68 tests, but three suites failed during embedded PostgreSQL startup. A subsequent focused run confirmed the host had exhausted its PostgreSQL semaphore allowance. Linux verification uses isolated databases; the local failure logs remain preserved. - The local full test suite is not claimed as passed. It is blocked by the same PostgreSQL startup limitation; full-suite CI passed on head `8bc29d1b7783446f397b858e558083570a96bb66` ([run](https://github.com/paperclipai/paperclip/actions/runs/39447913466)). ## Risks - A delivery match must not grant new execution authority. The lookup requires the original run's server receipt and a matching company, agent, task, wake, and admitted successor. The locked commit rejects old-run checkout ownership and permits no status effects. - Workspace persistence must succeed before settlement. Its existing failure path remains effective. - The scheduler waits while a native finalizer is unfinished. Workspace recovery must settle before dispatch; elapsed monitor limits transfer to the existing scheduler recovery policy instead of stranding the result. Neither settlement path renews a deadline or changes budget, approval, pause, or provider authority. - No schema, migration, credential, or provider configuration change. ## Model Used OpenAI Codex, based on GPT-6, with tool use and code execution. The exact backend model ID and context-window size are not exposed in this session. ## Checklist - [x] I have included a thinking path that traces from project context to this change - [x] I have specified the model used (with version and capability details) - [x] I have checked ROADMAP.md and confirmed this PR does not duplicate planned core work - [x] I have searched GitHub for duplicate or related PRs and linked them above - [x] I have either (a) linked existing issues with `Fixes: #` / `Closes #` / `Refs #` OR (b) described the issue in-PR following the relevant issue template - [x] I have not referenced internal/instance-local Paperclip issues or links (only public GitHub `#NNN` / `github.com/paperclipai/paperclip` URLs) - [x] My branch name describes the change (e.g. `docs/...`, `fix/...`) and contains no internal Paperclip ticket id or instance-derived details - [x] I have run tests locally and they pass - [x] I have added or updated tests where applicable - [x] I have updated relevant documentation to reflect my changes - [x] I have considered and documented any risks above - [x] All Paperclip CI gates are green - [x] Greptile is 5/5 with no open P2s, recommendations, or follow-ups - [x] I will address all Greptile and reviewer comments before requesting merge --------- Co-authored-by: Paperclip <noreply@paperclip.ing>
464 lines
29 KiB
TypeScript
464 lines
29 KiB
TypeScript
import { randomUUID } from "node:crypto";
|
|
import type { Db } from "@paperclipai/db";
|
|
import {
|
|
activityLog, agents, agentSessionGoalActions, agentTaskSessions, companies, createDb,
|
|
completionContracts, EMBEDDED_POSTGRES_TEST_TIMEOUT_MS, heartbeatRuns, issueComments, issues, nativeRunFinalizations, nativeRunResults,
|
|
} from "@paperclipai/db";
|
|
import { eq, sql } from "drizzle-orm";
|
|
import { afterAll, beforeAll, beforeEach, describe, expect, it, vi } from "vitest";
|
|
import { getEmbeddedPostgresTestSupport, startEmbeddedPostgresTestDatabase } from "../../__tests__/helpers/embedded-postgres.js";
|
|
import { conflict } from "../../errors.js";
|
|
import { createHeartbeatRunPreparation } from "./run-preparation.js";
|
|
import { createHeartbeatRunState } from "./run-state.js";
|
|
import { createHeartbeatScheduling, type HeartbeatSchedulingDependencies } from "./scheduling.js";
|
|
import { readIdleSleepSafety } from "../idle-sleep-safety.js";
|
|
import { PaperclipRunnerToolAuthority } from "../native-runtime/paperclip-runner-tool-authority.js";
|
|
import { finalizeNativeRun } from "../native-runtime/native-run-finalizer.js";
|
|
import { nativeCompletionFeedback } from "../native-runtime/native-completion-feedback.js";
|
|
import type { PrpStructuredRunResult } from "../../vendor/paperclip-runner/index.js";
|
|
|
|
vi.mock("../live-events.js", () => ({ publishLiveEvent: vi.fn() }));
|
|
|
|
type Run = typeof heartbeatRuns.$inferSelect;
|
|
const now = new Date("2026-10-09T12:00:00.000Z");
|
|
const dueAt = new Date(now.getTime() - 60_000);
|
|
const admitted = { id: "admitted-run" } as Run;
|
|
const timerPolicy = {
|
|
enabled: false, intervalSec: 60, wakeOnDemand: true, maxConcurrentRuns: 1,
|
|
skipTimerWhenNoActionableWork: false, maxDailyRuns: null, maxDailyCostCents: null,
|
|
};
|
|
|
|
function callbacks(db: Db) {
|
|
const state = createHeartbeatRunState(db);
|
|
const preparation = createHeartbeatRunPreparation(db);
|
|
return {
|
|
getAgent: state.getAgent,
|
|
getRun: state.getRun,
|
|
toAgentOrgRow: preparation.toAgentOrgRow,
|
|
groupAgentOrgRowsByCompany: preparation.groupAgentOrgRowsByCompany,
|
|
issuesSvc: {
|
|
listReviewAttention: vi.fn<HeartbeatSchedulingDependencies["issuesSvc"]["listReviewAttention"]>(async () => new Map()),
|
|
create: vi.fn<HeartbeatSchedulingDependencies["issuesSvc"]["create"]>(),
|
|
},
|
|
enqueueWakeup: vi.fn<HeartbeatSchedulingDependencies["enqueueWakeup"]>(async () => admitted),
|
|
scheduleBoundedRetryForRun: vi.fn<HeartbeatSchedulingDependencies["scheduleBoundedRetryForRun"]>(),
|
|
getSchedulingSuppression: vi.fn(async () => ({ suppressed: false })),
|
|
getWorktreeExecutionCutoff: vi.fn<HeartbeatSchedulingDependencies["getWorktreeExecutionCutoff"]>(async () => null),
|
|
parseHeartbeatPolicy: vi.fn<HeartbeatSchedulingDependencies["parseHeartbeatPolicy"]>(() => timerPolicy),
|
|
claimDueTimerHeartbeat: vi.fn<HeartbeatSchedulingDependencies["claimDueTimerHeartbeat"]>(async () => ({ wasFirstHeartbeat: true })),
|
|
} satisfies HeartbeatSchedulingDependencies;
|
|
}
|
|
|
|
describe("heartbeat scheduling module boundary", () => {
|
|
function guardedDatabase() {
|
|
const access = vi.fn(() => { throw new Error("Unexpected scheduling database access"); });
|
|
return { db: new Proxy({}, { get: access }) as Db, access };
|
|
}
|
|
|
|
it("constructs without querying, admitting work, or starting timers", () => {
|
|
const database = guardedDatabase();
|
|
const deps = callbacks(database.db);
|
|
createHeartbeatScheduling(database.db, deps);
|
|
expect(database.access).not.toHaveBeenCalled();
|
|
for (const callback of Object.values(deps)) if (vi.isMockFunction(callback)) expect(callback).not.toHaveBeenCalled();
|
|
});
|
|
|
|
it.each(["tickTimers", "recoverActiveSessionGoals", "recoverPendingSessionGoalActions"] as const)(
|
|
"honors suppression before %s reads or admits work", async (operation) => {
|
|
const database = guardedDatabase();
|
|
const deps = callbacks(database.db);
|
|
deps.getSchedulingSuppression.mockResolvedValue({ suppressed: true });
|
|
const result = await createHeartbeatScheduling(database.db, deps)[operation]();
|
|
expect(Object.values(result).every(value => value === 0)).toBe(true);
|
|
expect(database.access).not.toHaveBeenCalled();
|
|
expect(deps.enqueueWakeup).not.toHaveBeenCalled();
|
|
expect(deps.claimDueTimerHeartbeat).not.toHaveBeenCalled();
|
|
},
|
|
);
|
|
});
|
|
|
|
const postgres = await getEmbeddedPostgresTestSupport();
|
|
describe.skipIf(!postgres.supported)("heartbeat scheduling database boundary", () => {
|
|
let database: Awaited<ReturnType<typeof startEmbeddedPostgresTestDatabase>>;
|
|
let db: Db;
|
|
beforeAll(async () => {
|
|
database = await startEmbeddedPostgresTestDatabase("paperclip-heartbeat-scheduling-module");
|
|
db = createDb(database.connectionString);
|
|
}, EMBEDDED_POSTGRES_TEST_TIMEOUT_MS);
|
|
afterAll(async () => {
|
|
await db?.$client.end();
|
|
await database?.cleanup();
|
|
});
|
|
beforeEach(async () => {
|
|
await db.execute(sql`truncate table companies restart identity cascade`);
|
|
});
|
|
|
|
async function fixture() {
|
|
const [company] = await db.insert(companies).values({ name: "Scheduling", issuePrefix: "SCH" }).returning();
|
|
const [agent] = await db.insert(agents).values({ companyId: company.id, name: "Scheduled agent", adapterType: "paperclip_runner", createdAt: dueAt }).returning();
|
|
const [issue] = await db.insert(issues).values({
|
|
companyId: company.id, title: "Check deployment", status: "in_progress", assigneeAgentId: agent.id,
|
|
monitorNextCheckAt: dueAt, monitorAttemptCount: 0, createdAt: dueAt,
|
|
executionPolicy: { mode: "normal", commentRequired: true, stages: [], monitor: { nextCheckAt: dueAt.toISOString() } },
|
|
}).returning();
|
|
const deps = callbacks(db);
|
|
return { company, agent, issue, deps, scheduler: createHeartbeatScheduling(db, deps) };
|
|
}
|
|
async function readIssue(id: string) {
|
|
return db.select().from(issues).where(eq(issues.id, id)).then(rows => rows[0]!);
|
|
}
|
|
async function session(f: Awaited<ReturnType<typeof fixture>>, patch: Partial<typeof agentTaskSessions.$inferInsert> = {}) {
|
|
return db.insert(agentTaskSessions).values({
|
|
companyId: f.company.id, agentId: f.agent.id, adapterType: f.agent.adapterType, taskKey: f.issue.id,
|
|
goalDesiredState: "active", goalStatus: "active", goalRevision: 7, ...patch,
|
|
}).returning().then(rows => rows[0]!);
|
|
}
|
|
function enableTimer(deps: ReturnType<typeof callbacks>) {
|
|
deps.parseHeartbeatPolicy.mockReturnValue({ ...timerPolicy, enabled: true });
|
|
deps.parseHeartbeatPolicy.mockClear();
|
|
}
|
|
|
|
it("shares database monitor claims across scheduler instances", async () => {
|
|
const f = await fixture();
|
|
let release!: () => void;
|
|
let entered!: () => void;
|
|
const started = new Promise<void>(resolve => { entered = resolve; });
|
|
const hold = new Promise<void>(resolve => { release = resolve; });
|
|
f.deps.enqueueWakeup.mockImplementationOnce(async () => { entered(); await hold; return admitted; });
|
|
const first = f.scheduler.tickTimers(now);
|
|
try {
|
|
await started;
|
|
const second = createHeartbeatScheduling(db, f.deps);
|
|
expect(await second.tickTimers(now)).toEqual({ checked: 0, enqueued: 0, skipped: 0 });
|
|
await expect(second.triggerIssueMonitor(f.issue.id, { now })).rejects.toThrow("already in progress");
|
|
} finally {
|
|
release();
|
|
await first;
|
|
}
|
|
expect(f.deps.enqueueWakeup).toHaveBeenCalledTimes(1);
|
|
expect(await readIssue(f.issue.id)).toMatchObject({ monitorNextCheckAt: null, monitorAttemptCount: 1 });
|
|
});
|
|
|
|
it("restores the reported future deadline and claims monitor delivery exactly once", async () => {
|
|
const f = await fixture();
|
|
const at = new Date(now.getTime() + 600_000);
|
|
await db.update(issues).set({ monitorNextCheckAt: at,
|
|
executionPolicy: { monitor: { nextCheckAt: at.toISOString() } } }).where(eq(issues.id, f.issue.id));
|
|
const ownerId = randomUUID();
|
|
const hold = () => ({ ownerId, draining: true, activeRuns: 0, pendingWakes: 0,
|
|
startedAt: now, expiresAt: new Date(now.getTime() + 120_000) });
|
|
const report = await readIdleSleepSafety(db, hold, () => now.getTime(), ownerId,
|
|
async () => "none", undefined, undefined, true, true);
|
|
expect(report).toMatchObject({ version: 2, backgroundWork: "none", scheduledWake: {
|
|
kind: "routines_and_issue_monitors", nextWakeAt: at.toISOString() } });
|
|
expect(await f.scheduler.tickTimers(now)).toEqual({ checked: 0, enqueued: 0, skipped: 0 });
|
|
expect(f.deps.enqueueWakeup).not.toHaveBeenCalled();
|
|
const restored = createHeartbeatScheduling(db, f.deps);
|
|
const deadline = new Date(report.scheduledWake!.nextWakeAt);
|
|
await Promise.all([restored.tickTimers(deadline), f.scheduler.tickTimers(deadline)]);
|
|
expect(f.deps.enqueueWakeup).toHaveBeenCalledOnce();
|
|
expect(f.deps.enqueueWakeup).toHaveBeenCalledWith(f.agent.id, expect.objectContaining({ reason: "issue_monitor_due" }));
|
|
expect(await readIssue(f.issue.id)).toMatchObject({ monitorNextCheckAt: null, monitorAttemptCount: 1 });
|
|
});
|
|
|
|
it("preserves a replacement schedule written during wake admission", async () => {
|
|
const f = await fixture();
|
|
const replacement = new Date(now.getTime() + 60_000);
|
|
f.deps.enqueueWakeup.mockImplementationOnce(async () => {
|
|
await db.update(issues).set({ monitorNextCheckAt: replacement, monitorWakeRequestedAt: null }).where(eq(issues.id, f.issue.id));
|
|
return admitted;
|
|
});
|
|
expect(await f.scheduler.tickTimers(now)).toEqual({ checked: 1, enqueued: 0, skipped: 1 });
|
|
expect(await readIssue(f.issue.id)).toMatchObject({ monitorNextCheckAt: replacement, monitorAttemptCount: 0 });
|
|
});
|
|
|
|
it("retains a deferred monitor and releases its claim for a later tick", async () => {
|
|
const f = await fixture();
|
|
f.deps.enqueueWakeup.mockResolvedValueOnce(null);
|
|
expect(await f.scheduler.tickTimers(now)).toEqual({ checked: 1, enqueued: 0, skipped: 1 });
|
|
expect(await readIssue(f.issue.id)).toMatchObject({ monitorNextCheckAt: dueAt, monitorWakeRequestedAt: null, monitorAttemptCount: 0 });
|
|
expect(await f.scheduler.tickTimers(now)).toEqual({ checked: 1, enqueued: 1, skipped: 0 });
|
|
const calls = f.deps.enqueueWakeup.mock.calls;
|
|
expect(calls[0]![1]!.idempotencyKey).toBe(calls[1]![1]!.idempotencyKey);
|
|
expect(calls[0]![1]!.issueStateGuard).toMatchObject({
|
|
assigneeAgentId: f.agent.id, statuses: ["in_progress"], monitorNextCheckAt: dueAt.toISOString(), monitorWakeRequestedAt: now.toISOString(),
|
|
});
|
|
});
|
|
|
|
it("keeps manual error recovery distinct from scheduled client-error handling", async () => {
|
|
const f = await fixture();
|
|
f.deps.enqueueWakeup.mockRejectedValue(conflict("Agent is paused"));
|
|
await expect(f.scheduler.triggerIssueMonitor(f.issue.id, { now, actorType: "user", actorId: "board-user" })).rejects.toThrow("Agent is paused");
|
|
expect(await readIssue(f.issue.id)).toMatchObject({ monitorNextCheckAt: dueAt, monitorWakeRequestedAt: null });
|
|
expect(f.deps.enqueueWakeup).toHaveBeenLastCalledWith(f.agent.id, expect.objectContaining({
|
|
source: "on_demand", requestedByActorType: "user", requestedByActorId: "board-user",
|
|
}));
|
|
expect(await f.scheduler.tickTimers(now)).toEqual({ checked: 1, enqueued: 0, skipped: 1 });
|
|
expect(await readIssue(f.issue.id)).toMatchObject({ monitorNextCheckAt: null });
|
|
});
|
|
|
|
it("retains monitors after transient admission failures", async () => {
|
|
const f = await fixture();
|
|
f.deps.enqueueWakeup.mockRejectedValueOnce(new Error("Temporary admission failure"));
|
|
await f.scheduler.tickTimers(now);
|
|
expect(await readIssue(f.issue.id)).toMatchObject({ monitorNextCheckAt: dueAt, monitorWakeRequestedAt: null });
|
|
expect(await f.scheduler.tickTimers(now)).toEqual({ checked: 1, enqueued: 1, skipped: 0 });
|
|
});
|
|
|
|
it("records bounded dispatch failure diagnostics while retaining the schedule", async () => {
|
|
const f = await fixture();
|
|
f.deps.enqueueWakeup.mockRejectedValue(new Error("PRIVATE_PROVIDER_FAILURE"));
|
|
await f.scheduler.tickTimers(now);
|
|
await f.scheduler.tickTimers(new Date(now.getTime() + 30_000));
|
|
expect(await readIssue(f.issue.id)).toMatchObject({ monitorNextCheckAt: dueAt, monitorWakeRequestedAt: null, monitorAttemptCount: 0 });
|
|
const events = await db.select().from(activityLog).where(eq(activityLog.entityId, f.issue.id));
|
|
expect(events.filter(event => event.action === "issue.monitor_dispatch_failed")).toHaveLength(1);
|
|
expect(events[0]?.details).toMatchObject({ reason: "monitor_dispatch_failed", nextCheckAt: dueAt.toISOString(), attemptCount: 0 });
|
|
expect(JSON.stringify(events)).not.toContain("PRIVATE_PROVIDER_FAILURE");
|
|
});
|
|
|
|
it("repeats a persistent diagnostic after its bounded quiet window", async () => {
|
|
const f = await fixture();
|
|
f.deps.enqueueWakeup.mockResolvedValue(null);
|
|
await f.scheduler.tickTimers(now);
|
|
await f.scheduler.tickTimers(new Date(now.getTime() + 30_000));
|
|
expect(await db.select().from(activityLog).where(eq(activityLog.entityId, f.issue.id))).toHaveLength(1);
|
|
await db.update(activityLog).set({ createdAt: new Date(Date.now() - 6 * 60_000) }).where(eq(activityLog.entityId, f.issue.id));
|
|
await f.scheduler.tickTimers(new Date(now.getTime() + 60_000));
|
|
expect(await db.select().from(activityLog).where(eq(activityLog.entityId, f.issue.id))).toHaveLength(2);
|
|
expect(await readIssue(f.issue.id)).toMatchObject({ monitorNextCheckAt: dueAt, monitorAttemptCount: 0 });
|
|
});
|
|
|
|
it("does not copy an unrecognized blocker cause into monitor activity", async () => {
|
|
const f = await fixture();
|
|
f.deps.enqueueWakeup.mockImplementationOnce(async (_agentId, options) => {
|
|
options?.issueStateGuard?.onExecutionDeferred?.("PRIVATE_BLOCKER_CAUSE");
|
|
return null;
|
|
});
|
|
await f.scheduler.tickTimers(now);
|
|
const events = await db.select().from(activityLog).where(eq(activityLog.entityId, f.issue.id));
|
|
expect(events).toMatchObject([{ action: "issue.monitor_deferred", details: { reason: "execution_reconciliation_required" } }]);
|
|
expect(JSON.stringify(events)).not.toContain("PRIVATE_BLOCKER_CAUSE");
|
|
});
|
|
|
|
it("releases a monitor claim when diagnostic storage fails", async () => {
|
|
const f = await fixture();
|
|
await db.execute(sql`create function fail_monitor_diagnostic_test() returns trigger language plpgsql as $$
|
|
begin if new.action = 'issue.monitor_deferred' then raise exception 'Synthetic diagnostic storage failure'; end if; return new; end; $$`);
|
|
await db.execute(sql`create trigger fail_monitor_diagnostic_test before insert on activity_log
|
|
for each row execute function fail_monitor_diagnostic_test()`);
|
|
try {
|
|
f.deps.enqueueWakeup.mockResolvedValueOnce(null);
|
|
expect(await f.scheduler.tickTimers(now)).toEqual({ checked: 1, enqueued: 0, skipped: 1 });
|
|
expect(await readIssue(f.issue.id)).toMatchObject({ monitorNextCheckAt: dueAt, monitorWakeRequestedAt: null, monitorAttemptCount: 0 });
|
|
expect(await f.scheduler.tickTimers(now)).toEqual({ checked: 1, enqueued: 1, skipped: 0 });
|
|
} finally {
|
|
await db.execute(sql`drop trigger fail_monitor_diagnostic_test on activity_log`);
|
|
await db.execute(sql`drop function fail_monitor_diagnostic_test()`);
|
|
}
|
|
});
|
|
|
|
it("does not attach old dispatch diagnostics to a replacement monitor", async () => {
|
|
const f = await fixture();
|
|
const replacement = new Date(now.getTime() + 60_000);
|
|
f.deps.enqueueWakeup.mockImplementationOnce(async () => {
|
|
await db.update(issues).set({ monitorNextCheckAt: replacement, monitorWakeRequestedAt: null }).where(eq(issues.id, f.issue.id));
|
|
return null;
|
|
});
|
|
await f.scheduler.tickTimers(now);
|
|
expect(await readIssue(f.issue.id)).toMatchObject({ monitorNextCheckAt: replacement });
|
|
expect(await db.select().from(activityLog).where(eq(activityLog.entityId, f.issue.id))).toHaveLength(0);
|
|
});
|
|
|
|
it("leaves monitors alone while a native run owns the issue", async () => {
|
|
const f = await fixture();
|
|
const [run] = await db.insert(heartbeatRuns).values({ companyId: f.company.id, agentId: f.agent.id, nativeIssueId: f.issue.id, runtimeMode: "native", status: "running", contextSnapshot: { issueId: f.issue.id } }).returning();
|
|
expect(await f.scheduler.tickTimers(now)).toEqual({ checked: 0, enqueued: 0, skipped: 0 });
|
|
expect(f.deps.enqueueWakeup).not.toHaveBeenCalled();
|
|
await db.update(heartbeatRuns).set({ status: "succeeded" }).where(eq(heartbeatRuns.id, run!.id));
|
|
expect(await f.scheduler.tickTimers(now)).toEqual({ checked: 1, enqueued: 1, skipped: 0 });
|
|
});
|
|
|
|
it("keeps a due monitor until a terminal native run finishes finalization", async () => {
|
|
const f = await fixture();
|
|
const [run] = await db.insert(heartbeatRuns).values({
|
|
companyId: f.company.id, agentId: f.agent.id, nativeIssueId: f.issue.id,
|
|
runtimeMode: "native", status: "succeeded", contextSnapshot: { issueId: f.issue.id },
|
|
}).returning();
|
|
await db.insert(nativeRunFinalizations).values({
|
|
companyId: f.company.id, issueId: f.issue.id, runId: run!.id, phase: "retryable_failure",
|
|
});
|
|
expect(await f.scheduler.tickTimers(now)).toEqual({ checked: 0, enqueued: 0, skipped: 0 });
|
|
await expect(f.scheduler.triggerIssueMonitor(f.issue.id, { now })).rejects.toThrow("waiting for the previous run to settle");
|
|
expect(f.deps.enqueueWakeup).not.toHaveBeenCalled();
|
|
expect(await readIssue(f.issue.id)).toMatchObject({ monitorNextCheckAt: dueAt, monitorWakeRequestedAt: null });
|
|
await db.update(nativeRunFinalizations).set({ phase: "committed" }).where(eq(nativeRunFinalizations.runId, run!.id));
|
|
expect(await f.scheduler.tickTimers(now)).toEqual({ checked: 1, enqueued: 1, skipped: 0 });
|
|
expect(f.deps.enqueueWakeup).toHaveBeenCalledTimes(1);
|
|
});
|
|
|
|
it.each(["scheduled", "manual"] as const)("applies expired monitor recovery after workspace settlement without another turn (%s)", async (dispatch) => {
|
|
const f = await fixture();
|
|
const start = new Date();
|
|
const nextCheckAt = new Date(start.getTime() + 60_000).toISOString();
|
|
const timeoutAt = new Date(start.getTime() + 120_000).toISOString();
|
|
const [contract] = await db.insert(completionContracts).values({
|
|
companyId: f.company.id, issueId: f.issue.id, revision: 1,
|
|
schemaVersion: "paperclip.completion-contract.v1", policyVersion: "test",
|
|
risk: "standard", completionAuthority: "server_arbiter", incompleteCriteriaPolicy: "preserve_non_terminal",
|
|
contractJson: { revision: "test", criteria: [] }, canonicalSha256: randomUUID(),
|
|
createdByActorType: "system", createdByActorId: "test",
|
|
}).returning();
|
|
const [run] = await db.insert(heartbeatRuns).values({
|
|
companyId: f.company.id, agentId: f.agent.id, nativeIssueId: f.issue.id,
|
|
runtimeMode: "native", status: "running", completionContractId: contract!.id,
|
|
contextSnapshot: { issueId: f.issue.id },
|
|
}).returning();
|
|
await db.update(issues).set({ executionRunId: run!.id, checkoutRunId: run!.id }).where(eq(issues.id, f.issue.id));
|
|
const authority = new PaperclipRunnerToolAuthority(db, { companyId: f.company.id,
|
|
issueId: f.issue.id, agentId: f.agent.id, runId: run!.id });
|
|
await authority.execute({ tool: "set_task_monitor", callId: randomUUID(), arguments: {
|
|
idempotencyKey: "expires-during-workspace-save",
|
|
monitor: { nextCheckAt, timeoutAt, notes: "Check once saved", recoveryPolicy: "escalate_to_board" },
|
|
} });
|
|
const result: PrpStructuredRunResult = {
|
|
schema: "paperclip.run_result.v1", reportedWorkDisposition: "yielded", summary: "Wait for the check.",
|
|
completionClaim: { contractRevision: "test", objectiveSatisfied: false, criteria: [],
|
|
remainingWork: [{ description: "Check after saving", blocksCompletion: true }] },
|
|
continuation: { kind: "monitor", summary: "Wait for the saved check", idempotencyKey: "wait" },
|
|
evidence: [], verification: [], attentionRequests: [], artifacts: [],
|
|
};
|
|
await expect(nativeCompletionFeedback(db, run!.id, result)).resolves.toContain("issue_monitor_due");
|
|
const [saved] = await db.insert(nativeRunResults).values({
|
|
companyId: f.company.id, issueId: f.issue.id, runId: run!.id, completionContractId: contract!.id,
|
|
serverFingerprint: randomUUID(), canonicalSha256: randomUUID(), schemaStatus: "accepted",
|
|
resultJson: { result, terminal: { schema: "paperclip.prp.terminal.v1", runTerminalState: "succeeded",
|
|
turnTerminalState: "completed", reportedWorkDisposition: "yielded" } },
|
|
}).returning();
|
|
await db.update(heartbeatRuns).set({ status: "succeeded" }).where(eq(heartbeatRuns.id, run!.id));
|
|
await db.insert(nativeRunFinalizations).values({ companyId: f.company.id, issueId: f.issue.id,
|
|
runId: run!.id, phase: "result_persisted", resultId: saved!.id });
|
|
await finalizeNativeRun({ db, runId: run!.id, workspaceFinalizeStatus: "failed" });
|
|
const expiredAt = new Date(start.getTime() + 180_000);
|
|
vi.useFakeTimers({ toFake: ["Date"] });
|
|
vi.setSystemTime(expiredAt);
|
|
try {
|
|
await expect(nativeCompletionFeedback(db, run!.id, result)).rejects.toThrow("persisted, eligible monitor");
|
|
expect(await f.scheduler.tickTimers(expiredAt)).toEqual({ checked: 0, enqueued: 0, skipped: 0 });
|
|
await expect(f.scheduler.triggerIssueMonitor(f.issue.id, { now: expiredAt })).rejects.toThrow("waiting for the previous run to settle");
|
|
await finalizeNativeRun({ db, runId: run!.id, workspaceFinalizeStatus: "succeeded" });
|
|
expect((await db.select().from(nativeRunFinalizations).where(eq(nativeRunFinalizations.runId, run!.id)))[0])
|
|
.toMatchObject({ phase: "committed", failureCode: null });
|
|
expect(await readIssue(f.issue.id)).toMatchObject({ executionRunId: null, checkoutRunId: null,
|
|
monitorNextCheckAt: new Date(nextCheckAt) });
|
|
if (dispatch === "manual") await f.scheduler.triggerIssueMonitor(f.issue.id, { now: expiredAt });
|
|
else await f.scheduler.tickTimers(expiredAt);
|
|
expect(await readIssue(f.issue.id)).toMatchObject({ monitorNextCheckAt: null,
|
|
executionState: { monitor: { status: "cleared", clearReason: "timeout_exceeded" } } });
|
|
expect(await db.select().from(issueComments).where(eq(issueComments.issueId, f.issue.id))).toHaveLength(1);
|
|
await finalizeNativeRun({ db, runId: run!.id, workspaceFinalizeStatus: "succeeded" });
|
|
await f.scheduler.tickTimers(expiredAt);
|
|
expect(await db.select().from(issueComments).where(eq(issueComments.issueId, f.issue.id))).toHaveLength(1);
|
|
expect(f.deps.enqueueWakeup).not.toHaveBeenCalled();
|
|
expect((await db.select().from(nativeRunResults).where(eq(nativeRunResults.id, saved!.id)))[0]!.resultJson).toEqual(saved!.resultJson);
|
|
} finally {
|
|
vi.useRealTimers();
|
|
}
|
|
});
|
|
|
|
it("skips archived companies for both timers and monitors", async () => {
|
|
const f = await fixture();
|
|
enableTimer(f.deps);
|
|
await db.update(companies).set({ status: "archived" }).where(eq(companies.id, f.company.id));
|
|
expect(await f.scheduler.tickTimers(now)).toEqual({ checked: 0, enqueued: 0, skipped: 0 });
|
|
expect(f.deps.claimDueTimerHeartbeat).not.toHaveBeenCalled();
|
|
expect(f.deps.enqueueWakeup).not.toHaveBeenCalled();
|
|
expect(await readIssue(f.issue.id)).toMatchObject({ monitorNextCheckAt: dueAt });
|
|
});
|
|
|
|
it("combines timer and monitor counts and passes the timer claim receipt to admission", async () => {
|
|
const f = await fixture();
|
|
enableTimer(f.deps);
|
|
expect(await f.scheduler.tickTimers(now)).toEqual({ checked: 2, enqueued: 2, skipped: 0 });
|
|
expect(f.deps.claimDueTimerHeartbeat).toHaveBeenCalledWith(expect.objectContaining({ id: f.agent.id }), now, 60);
|
|
expect(f.deps.enqueueWakeup).toHaveBeenCalledWith(f.agent.id, expect.objectContaining({
|
|
source: "timer", reason: "heartbeat_timer", contextSnapshot: expect.objectContaining({ timerClaimWasFirstHeartbeat: true }),
|
|
}));
|
|
});
|
|
|
|
it("does not enqueue a timer after losing its due claim", async () => {
|
|
const f = await fixture();
|
|
enableTimer(f.deps);
|
|
await db.update(issues).set({ monitorNextCheckAt: null }).where(eq(issues.id, f.issue.id));
|
|
f.deps.claimDueTimerHeartbeat.mockResolvedValue(null);
|
|
expect(await f.scheduler.tickTimers(now)).toEqual({ checked: 1, enqueued: 0, skipped: 0 });
|
|
expect(f.deps.enqueueWakeup).not.toHaveBeenCalled();
|
|
});
|
|
|
|
it("enforces worktree cutoffs and agent invokability before timer claims", async () => {
|
|
const f = await fixture();
|
|
enableTimer(f.deps);
|
|
await db.update(issues).set({ monitorNextCheckAt: null }).where(eq(issues.id, f.issue.id));
|
|
f.deps.getWorktreeExecutionCutoff.mockResolvedValue(now);
|
|
await f.scheduler.tickTimers(now);
|
|
expect(f.deps.claimDueTimerHeartbeat).not.toHaveBeenCalled();
|
|
await db.update(issues).set({ createdAt: now }).where(eq(issues.id, f.issue.id));
|
|
await db.update(agents).set({ status: "paused" }).where(eq(agents.id, f.agent.id));
|
|
await f.scheduler.tickTimers(now);
|
|
expect(f.deps.claimDueTimerHeartbeat).not.toHaveBeenCalled();
|
|
await db.update(agents).set({ status: "idle" }).where(eq(agents.id, f.agent.id));
|
|
expect(await f.scheduler.tickTimers(now)).toEqual({ checked: 1, enqueued: 1, skipped: 0 });
|
|
});
|
|
|
|
it("recovers active goals with stable revision-based admission keys", async () => {
|
|
const f = await fixture();
|
|
const active = await session(f);
|
|
expect(await f.scheduler.recoverActiveSessionGoals()).toEqual({ scanned: 1, enqueued: 1 });
|
|
expect(f.deps.enqueueWakeup).toHaveBeenCalledWith(f.agent.id, expect.objectContaining({
|
|
idempotencyKey: `goal_recovery:${active.id}:7`, contextSnapshot: { issueId: f.issue.id, taskKey: f.issue.id, resumeSessionGoalHeartbeat: true, skipIssueComment: true },
|
|
}));
|
|
f.deps.enqueueWakeup.mockResolvedValueOnce(null);
|
|
expect(await f.scheduler.recoverActiveSessionGoals()).toEqual({ scanned: 1, enqueued: 0 });
|
|
expect(f.deps.enqueueWakeup.mock.calls[1]![1]!.idempotencyKey).toBe(f.deps.enqueueWakeup.mock.calls[0]![1]!.idempotencyKey);
|
|
await db.update(issues).set({ status: "done" }).where(eq(issues.id, f.issue.id));
|
|
expect(await f.scheduler.recoverActiveSessionGoals()).toEqual({ scanned: 0, enqueued: 0 });
|
|
});
|
|
|
|
it("excludes goals after reassignment or with a mismatched company binding", async () => {
|
|
const f = await fixture();
|
|
const [other] = await db.insert(companies).values({ name: "Other company", issuePrefix: "OTH" }).returning();
|
|
const active = await session(f, { companyId: other!.id });
|
|
expect(await f.scheduler.recoverActiveSessionGoals()).toEqual({ scanned: 0, enqueued: 0 });
|
|
await db.update(agentTaskSessions).set({ companyId: f.company.id }).where(eq(agentTaskSessions.id, active.id));
|
|
await db.update(issues).set({ assigneeAgentId: null }).where(eq(issues.id, f.issue.id));
|
|
expect(await f.scheduler.recoverActiveSessionGoals()).toEqual({ scanned: 0, enqueued: 0 });
|
|
expect(f.deps.enqueueWakeup).not.toHaveBeenCalled();
|
|
});
|
|
|
|
it.each(["queued", "scheduled_retry", "running"])("deduplicates a pending goal action against a %s run", async status => {
|
|
const f = await fixture();
|
|
const active = await session(f);
|
|
const requestId = randomUUID();
|
|
const [action] = await db.insert(agentSessionGoalActions).values({ companyId: f.company.id, sessionId: active.id, requestId, action: "pause", payloadJson: { requestId, action: "pause" } }).returning();
|
|
const [run] = await db.insert(heartbeatRuns).values({ companyId: f.company.id, agentId: f.agent.id, status, contextSnapshot: { goalControlRequestId: requestId } }).returning();
|
|
expect(await f.scheduler.recoverPendingSessionGoalActions()).toEqual({ scanned: 1, enqueued: 0, alreadyQueued: 1, invalid: 0 });
|
|
expect(f.deps.enqueueWakeup).not.toHaveBeenCalled();
|
|
await db.update(heartbeatRuns).set({ status: "succeeded" }).where(eq(heartbeatRuns.id, run!.id));
|
|
await db.update(issues).set({ status: "done" }).where(eq(issues.id, f.issue.id));
|
|
expect(await f.scheduler.recoverPendingSessionGoalActions()).toEqual({ scanned: 1, enqueued: 1, alreadyQueued: 0, invalid: 0 });
|
|
expect(f.deps.enqueueWakeup).toHaveBeenCalledWith(f.agent.id, expect.objectContaining({
|
|
idempotencyKey: `goal_control_recovery:${action!.id}`, contextSnapshot: expect.objectContaining({ resumeIntent: true, goalControlRequestId: requestId, runnerGoalControl: { requestId, action: "pause" } }),
|
|
}));
|
|
});
|
|
|
|
it("persists invalid goal actions as failures without wake admission", async () => {
|
|
const f = await fixture();
|
|
const active = await session(f);
|
|
const [action] = await db.insert(agentSessionGoalActions).values({ companyId: f.company.id, sessionId: active.id, requestId: "expected", action: "pause", payloadJson: { requestId: "different", action: "pause" } }).returning();
|
|
expect(await f.scheduler.recoverPendingSessionGoalActions()).toEqual({ scanned: 1, enqueued: 0, alreadyQueued: 0, invalid: 1 });
|
|
expect(f.deps.enqueueWakeup).not.toHaveBeenCalled();
|
|
const failed = await db.select().from(agentSessionGoalActions).where(eq(agentSessionGoalActions.id, action!.id));
|
|
expect(failed[0]).toMatchObject({ status: "failed", error: "session_goal_control_payload_invalid" });
|
|
});
|
|
});
|