Files
PaperClipAI/server/src/shutdown.test.ts
T
DottaandPaperclip 96727b3cfe fix(server): schedule plugin jobs from saved deadlines (#17518)
## Thinking Path

> - Paperclip manages agents and plugin work.
> - Plugins can declare cron jobs with saved deadlines.
> - The existing scheduler queries for due jobs every 30 seconds, even
when none exist.
> - Empty queries keep an otherwise idle database active.
> - This PR uses the shared scheduler and committed job changes to
discover work.
> - Existing job and run rows preserve deadlines and execution history.

## Linked Issues or Issue Description

**What happened?**
The plugin scheduler on the base of this stack runs empty periodic SQL.
Its registration path also advances overdue timestamps. An empty
replacement manifest can leave removed schedules active.

**Expected behavior**
No recurring SQL when no eligible jobs exist. Configured jobs wait for
their saved deadline. Changes reactivate scheduling after commit. Work
remains protected through drain and shutdown.

**Steps to reproduce**
Start the plugin scheduler with no jobs. After startup, observe queries
during a three-minute idle window. The new PostgreSQL regression failed
on the baseline and passes with this change.

**Paperclip version or commit**
Stacked on #17510 at `4d15c08428`. Deployment: source checkout, local
PostgreSQL, controlled plugin RPC. Related: #7905 covers empty-manifest
sync; this migration requires that behavior on both activation paths.
#11571 proposes company-scoped jobs; this PR preserves the existing
instance-scoped job contract.

## What Changed

- Install the concurrency test barrier before due job notifications can
dispatch.

- Make dispatch the sole reservation owner and preserve retained or
concurrently committed results when unregistering a plugin.

- Replace the private interval with the existing shared deadline worker.
- Signal job definition and run changes inside their owning
transactions. No new tables.
- Wake from plugin registration and worker status events. Retain
explicit scheduler wakes received during drain.
- Preserve overdue work and initialize only missing or changed
schedules.
- Recheck claims under a job-row lock. Keep plugin calls outside
transactions and refill capacity on completion.
- Commit completion and schedule advancement together. Retry failed
persistence without repeating the plugin side effect.
- Track admitted calls through shutdown and synchronize empty manifests.

## Verification

This PR now targets master after #17510 merged as
`4e27a82a4265c01f3ab4f05aaecc010a0026de75`. The normal landed-parent
merge preserves the entire verified `df78ca3b5e` tree byte for byte;
only final publication docs change afterwards. The PR still differs in
its original seventeen paths and has no database schema or migration
change.

Primary test revision: `36be0bd73363680d7666d94ff5f1dd28b27f4235`, on
parent `ba80060407`. Final integration of parent `51668b8240` preserves
all plugin/runtime/shutdown sources from that proof and passes all 63
cases in complete plugin, approval-seeding and scoped-deadline suites at
`56ce7c1d2a`, plus server types/build. Only six parent seeding/doc files
changed; this is not a rerun of all eleven suites. Only the original
seventeen plugin-scheduling paths differ from that parent; all other
tracked files, including migration history, match it.

- **247 cases pass in eleven complete suites:** plugin scheduler,
shutdown, warm standby, plugin environment-driver readiness, delivery
coordinator, both retention workers, approval seeding, decision expiry,
scoped deadlines and startup. Server typecheck and production build
pass.
- The new real PostgreSQL lock test failed before the repair: shutdown
remained pending while the completion update waited for a held run row.
After repair, shutdown reports the statement timeout while the lock
remains held; retry after release commits the saved result with exactly
one plugin invocation. All 34 scheduler cases pass.
- Existing regressions preserve real committed schedule changes, saved
deadlines, manual/scheduled reservation, retained success and failure
results during unregister, completion/unregister lock order, independent
progress, rollback/outer commit, quiet configured states, drain/resume
and shutdown cleanup.
- The parent's complete seeding/producer run passed 522 cases at its
stated revision. Earlier duplicate reservations, overwritten retained
results, hourly-clock fixture failures and combined-stack CI/setup
failures remain recorded in `doc/idle-plugin-jobs.md`, its dated audit
and the stack ledger; they are not erased or recounted as this
candidate's tests.
- The completion timeout is transaction-local and defaults to thirty
seconds per PostgreSQL statement. It does not bound every
shutdown/network operation or make plugin side effects safe to replay.
No full local repository-suite or deployed host-sleep claim is made.

Commands: server Vitest for the eleven suites above; server
typecheck/build. Fresh exact-head CI, Greptile and Ponytail reviews
remain required before merge.

## Risks

- This uses process-local notifications. Independent SQL writers and
other replicas need their own wake integration.
- A run left unresolved after process loss is not automatically
replayed: the external effect may have occurred. Existing
lifecycle/operator reconciliation must resolve it. Live-process
settlement failures retry without replay.
- Job definitions remain instance-scoped. This PR does not implement
company-scoped job dispatch.
- Cloud's plugin sleep blockers remain. Internal deadlines do not add
durable external wake coverage or prove deployed sleep.
- The shared deadline helper now retains direct lifecycle wakes through
drain; existing coordinator and decision deadline consumers are tested.

## Model Used

OpenAI Codex, GPT-6-based agent, with repository tools, code execution,
and GitHub access. The exact serving model version 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
- [ ] All Paperclip CI gates are green
- [ ] 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>
2026-10-27 21:07:10 -05:00

550 lines
19 KiB
TypeScript

import { EventEmitter } from "node:events";
import { describe, expect, it, vi } from "vitest";
import {
closeHttpListenerForShutdown,
coordinateHeartbeatSchedulerShutdown,
drainRunExecutionFinalizersForShutdown,
finalizeServerShutdown,
finishServiceShutdown,
loadWithoutCoordinatedShutdownSignalHooks,
} from "./shutdown.js";
function deferred<T = void>() {
let resolve!: (value: T) => void;
let reject!: (reason?: unknown) => void;
const promise = new Promise<T>((res, rej) => {
resolve = res;
reject = rej;
});
return { promise, resolve, reject };
}
function stubLogger() {
return { info: vi.fn(), error: vi.fn() };
}
describe("finalizeServerShutdown", () => {
it("awaits the setup-token cleanup before the database stop and the process exit", async () => {
const order: string[] = [];
// The held promise models the setup-token session cancellation and its
// sandbox lease release. The teardown must not continue while it is pending.
const release = deferred();
const shutdownAppServices = vi.fn(async () => {
order.push("appServices:start");
await release.promise;
order.push("appServices:settled");
});
const closeHttpListener = vi.fn(async () => {
order.push("listener:close");
});
const closeDatabase = vi.fn(async () => {
order.push("database:close");
});
const stopEmbeddedPostgres = vi.fn(async () => {
order.push("postgres:stop");
});
const shutdownInstrumentation = vi.fn(async () => {
order.push("instrumentation:flush");
});
const shutdownSentry = vi.fn(async () => {
order.push("sentry:flush");
});
let exited = false;
const finalize = finalizeServerShutdown({
signal: "SIGTERM",
shutdownAppServices,
closeHttpListener,
closeDatabase,
stopEmbeddedPostgres,
shutdownInstrumentation,
shutdownSentry,
log: stubLogger(),
}).then(() => {
// This models the caller's `process.exit(0)` continuation.
exited = true;
order.push("exit");
});
// The cleanup is in flight. The database stop, the instrumentation flush,
// and the process exit continuation must all wait for it to settle.
await vi.waitFor(() => expect(shutdownAppServices).toHaveBeenCalledOnce());
// The listener already closed: requests are drained while every service
// is still available, and nothing after this point can be reached.
expect(closeHttpListener).toHaveBeenCalledOnce();
expect(closeDatabase).not.toHaveBeenCalled();
expect(stopEmbeddedPostgres).not.toHaveBeenCalled();
expect(shutdownInstrumentation).not.toHaveBeenCalled();
expect(exited).toBe(false);
release.resolve();
await finalize;
expect(exited).toBe(true);
expect(order).toEqual([
"listener:close",
"appServices:start",
"appServices:settled",
"database:close",
"postgres:stop",
"instrumentation:flush",
"sentry:flush",
"exit",
]);
});
it("keeps the teardown durable and still exits when the setup-token release fails", async () => {
const order: string[] = [];
// The held promise rejects, which models a lease release that failed. The
// reaper owns the durable retry, so the teardown must log the failure and
// continue rather than swallow it or block the exit.
const release = deferred();
const releaseError = new Error("lease release failed");
const shutdownAppServices = vi.fn(async () => {
await release.promise;
});
const stopEmbeddedPostgres = vi.fn(async () => {
order.push("postgres:stop");
});
const shutdownInstrumentation = vi.fn(async () => {
order.push("instrumentation:flush");
});
const shutdownSentry = vi.fn(async () => undefined);
const log = stubLogger();
let exited = false;
const finalize = finalizeServerShutdown({
signal: "SIGTERM",
shutdownAppServices,
stopEmbeddedPostgres,
shutdownInstrumentation,
shutdownSentry,
log,
}).then(() => {
exited = true;
});
await vi.waitFor(() => expect(shutdownAppServices).toHaveBeenCalledOnce());
expect(stopEmbeddedPostgres).not.toHaveBeenCalled();
expect(exited).toBe(false);
release.reject(releaseError);
await finalize;
// The teardown surfaced the failure in the log, then finished the ordered
// teardown and reached the exit continuation.
expect(log.error).toHaveBeenCalledWith(
expect.objectContaining({ err: releaseError, signal: "SIGTERM" }),
expect.any(String),
);
expect(order).toEqual(["postgres:stop", "instrumentation:flush"]);
expect(exited).toBe(true);
});
it("logs a failed database close and still stops the provider and exits", async () => {
const order: string[] = [];
const closeError = new Error("pool end timed out");
const closeDatabase = vi.fn(async () => {
order.push("database:close");
throw closeError;
});
const stopEmbeddedPostgres = vi.fn(async () => {
order.push("postgres:stop");
});
const log = stubLogger();
await finalizeServerShutdown({
signal: "SIGTERM",
shutdownAppServices: vi.fn(async () => undefined),
closeDatabase,
stopEmbeddedPostgres,
shutdownInstrumentation: vi.fn(async () => undefined),
shutdownSentry: vi.fn(async () => undefined),
log,
});
expect(order).toEqual(["database:close", "postgres:stop"]);
expect(log.error).toHaveBeenCalledWith(
expect.objectContaining({ err: closeError, signal: "SIGTERM" }),
"Database client shutdown failed",
);
});
it("waits for pending run-failure reports before the database stop and the Sentry flush", async () => {
const order: string[] = [];
const release = deferred();
const drainPendingRunFailureReports = vi.fn(async () => {
order.push("runFailureReports:start");
await release.promise;
order.push("runFailureReports:settled");
});
const closeDatabase = vi.fn(async () => {
order.push("database:close");
});
const shutdownSentry = vi.fn(async () => {
order.push("sentry:flush");
});
const finalize = finalizeServerShutdown({
signal: "SIGTERM",
shutdownAppServices: vi.fn(async () => undefined),
drainPendingRunFailureReports,
closeDatabase,
stopEmbeddedPostgres: null,
shutdownInstrumentation: vi.fn(async () => undefined),
shutdownSentry,
log: stubLogger(),
});
await vi.waitFor(() => expect(drainPendingRunFailureReports).toHaveBeenCalledOnce());
expect(closeDatabase).not.toHaveBeenCalled();
expect(shutdownSentry).not.toHaveBeenCalled();
release.resolve();
await finalize;
expect(order).toEqual([
"runFailureReports:start",
"runFailureReports:settled",
"database:close",
"sentry:flush",
]);
});
it("logs a failed run-failure report drain and still stops the database and exits", async () => {
const drainError = new Error("drain failed");
const drainPendingRunFailureReports = vi.fn(async () => {
throw drainError;
});
const closeDatabase = vi.fn(async () => undefined);
const log = stubLogger();
await finalizeServerShutdown({
signal: "SIGTERM",
shutdownAppServices: vi.fn(async () => undefined),
drainPendingRunFailureReports,
closeDatabase,
stopEmbeddedPostgres: null,
shutdownInstrumentation: vi.fn(async () => undefined),
shutdownSentry: vi.fn(async () => undefined),
log,
});
expect(closeDatabase).toHaveBeenCalledOnce();
expect(log.error).toHaveBeenCalledWith(
expect.objectContaining({ err: drainError, signal: "SIGTERM" }),
"run-failure report drain failed",
);
});
it("skips the database stop when no embedded PostgreSQL runs in this process", async () => {
const shutdownAppServices = vi.fn(async () => undefined);
const shutdownInstrumentation = vi.fn(async () => undefined);
const shutdownSentry = vi.fn(async () => undefined);
const log = stubLogger();
await finalizeServerShutdown({
signal: "SIGINT",
shutdownAppServices,
stopEmbeddedPostgres: null,
shutdownInstrumentation,
shutdownSentry,
log,
});
expect(shutdownAppServices).toHaveBeenCalledOnce();
expect(shutdownInstrumentation).toHaveBeenCalledOnce();
expect(log.info).not.toHaveBeenCalled();
});
});
describe("closeHttpListenerForShutdown", () => {
function fakeServer(input: { listening: boolean; closeDelayMs?: number | null }) {
const closeIdleConnections = vi.fn();
const closeAllConnections = vi.fn();
const close = vi.fn((callback?: (err?: Error) => void) => {
if (input.closeDelayMs === null) return;
setTimeout(() => callback?.(), input.closeDelayMs ?? 0);
});
return { listening: input.listening, close, closeIdleConnections, closeAllConnections };
}
it("stops accepting, closes idle keep-alive sockets, and resolves once the listener closed", async () => {
const server = fakeServer({ listening: true, closeDelayMs: 0 });
await expect(
closeHttpListenerForShutdown({ server, signal: "SIGTERM", timeoutMs: 1_000, log: stubLogger() }),
).resolves.toBe("closed");
expect(server.close).toHaveBeenCalledOnce();
expect(server.closeIdleConnections).toHaveBeenCalledOnce();
expect(server.closeAllConnections).not.toHaveBeenCalled();
});
it("closes the remaining connections when the drain outlives the grace period", async () => {
vi.useFakeTimers();
try {
const server = fakeServer({ listening: true, closeDelayMs: null });
const log = stubLogger();
const pending = closeHttpListenerForShutdown({ server, signal: "SIGINT", timeoutMs: 250, log });
await vi.advanceTimersByTimeAsync(250);
await expect(pending).resolves.toBe("timed_out");
expect(server.closeAllConnections).toHaveBeenCalledOnce();
expect(log.info).toHaveBeenCalledWith(
expect.objectContaining({ timeoutMs: 250 }),
expect.stringContaining("timed out"),
);
} finally {
vi.useRealTimers();
}
});
it("does nothing when the listener was never bound", async () => {
const server = fakeServer({ listening: false });
await expect(
closeHttpListenerForShutdown({ server, signal: "SIGTERM", log: stubLogger() }),
).resolves.toBe("not_listening");
expect(server.close).not.toHaveBeenCalled();
});
});
describe("drainRunExecutionFinalizersForShutdown", () => {
it("awaits bounded execution finalizers", async () => {
const release = deferred();
const drain = vi.fn(() => release.promise);
const pending = drainRunExecutionFinalizersForShutdown({
signal: "SIGTERM",
drain,
timeoutMs: 1_000,
log: stubLogger(),
});
await vi.waitFor(() => expect(drain).toHaveBeenCalledOnce());
release.resolve();
await expect(pending).resolves.toBe("drained");
});
it("returns after the bounded timeout when an adopted run remains active", async () => {
vi.useFakeTimers();
try {
const log = stubLogger();
const pending = drainRunExecutionFinalizersForShutdown({
signal: "SIGINT",
drain: () => new Promise<void>(() => undefined),
timeoutMs: 250,
log,
});
await vi.advanceTimersByTimeAsync(250);
await expect(pending).resolves.toBe("timed_out");
expect(log.info).toHaveBeenCalledWith(
expect.objectContaining({ timeoutMs: 250 }),
expect.stringContaining("timed out"),
);
} finally {
vi.useRealTimers();
}
});
});
describe("loadWithoutCoordinatedShutdownSignalHooks", () => {
it("removes the eager signal handlers from the real embedded-postgres import", async () => {
const before = {
SIGINT: process.rawListeners("SIGINT"),
SIGTERM: process.rawListeners("SIGTERM"),
};
const moduleName = "embedded-postgres";
await loadWithoutCoordinatedShutdownSignalHooks(() => import(moduleName));
expect(process.rawListeners("SIGINT")).toEqual(before.SIGINT);
expect(process.rawListeners("SIGTERM")).toEqual(before.SIGTERM);
});
it("keeps the database available for a marker-backed SIGTERM snapshot", async () => {
const signalTarget = new EventEmitter();
const preexistingSignalListener = vi.fn();
signalTarget.on("SIGTERM", preexistingSignalListener);
let databaseAvailable = true;
const embeddedPostgresExitHook = vi.fn(() => {
databaseAvailable = false;
});
await loadWithoutCoordinatedShutdownSignalHooks(
async () => {
signalTarget.on("SIGINT", embeddedPostgresExitHook);
signalTarget.on("SIGTERM", embeddedPostgresExitHook);
return { default: class EmbeddedPostgres {} };
},
signalTarget,
);
let shutdown: Promise<unknown> | null = null;
let snapshotCaptured = false;
signalTarget.once("SIGTERM", () => {
shutdown = coordinateHeartbeatSchedulerShutdown({
signal: "SIGTERM",
prepareHotRestartShutdown: async () => {
// This models the real failure path: a valid intent exists, and the
// snapshot must query embedded PostgreSQL after SIGTERM is delivered.
expect(databaseAvailable).toBe(true);
snapshotCaptured = true;
return { mode: "hot_restart" as const, skipDrain: true };
},
waitForHeartbeatSchedulerIdle: vi.fn(async () => undefined),
});
});
signalTarget.emit("SIGTERM");
await shutdown;
expect(preexistingSignalListener).toHaveBeenCalledOnce();
expect(embeddedPostgresExitHook).not.toHaveBeenCalled();
expect(snapshotCaptured).toBe(true);
});
});
describe("coordinateHeartbeatSchedulerShutdown", () => {
it("quiesces active scheduler work before capturing a hot-restart snapshot", async () => {
let snapshotCaptured = false;
let releaseScheduler!: () => void;
const schedulerIdle = new Promise<void>((resolve) => {
releaseScheduler = resolve;
});
const waitForHeartbeatSchedulerIdle = vi.fn(() => schedulerIdle);
const shutdown = coordinateHeartbeatSchedulerShutdown({
signal: "SIGTERM",
prepareHotRestartShutdown: vi.fn(async () => {
snapshotCaptured = true;
return { mode: "prepared" as const, skipDrain: true };
}),
waitForHeartbeatSchedulerIdle,
});
await vi.waitFor(() => expect(waitForHeartbeatSchedulerIdle).toHaveBeenCalledOnce());
expect(snapshotCaptured).toBe(false);
releaseScheduler();
const result = await shutdown;
expect(snapshotCaptured).toBe(true);
expect(result).toEqual({
hotRestart: { mode: "prepared", skipDrain: true },
preparationError: null,
waitedForSchedulerIdle: true,
});
});
it("quiesces scheduler work before selecting server-stdio runs to drain", async () => {
const waitForHeartbeatSchedulerIdle = vi.fn(async () => undefined);
const result = await coordinateHeartbeatSchedulerShutdown({
signal: "SIGTERM",
prepareHotRestartShutdown: vi.fn(async () => ({
mode: "acp_drain_required" as const,
skipDrain: false,
drainRunIds: ["acp-run"],
})),
waitForHeartbeatSchedulerIdle,
});
expect(waitForHeartbeatSchedulerIdle).toHaveBeenCalledOnce();
expect(result).toEqual({
hotRestart: {
mode: "acp_drain_required",
skipDrain: false,
drainRunIds: ["acp-run"],
},
preparationError: null,
waitedForSchedulerIdle: true,
});
});
it("preserves the scheduler idle wait for normal graceful shutdown", async () => {
let releaseScheduler!: () => void;
const schedulerIdle = new Promise<void>((resolve) => {
releaseScheduler = resolve;
});
const waitForHeartbeatSchedulerIdle = vi.fn(() => schedulerIdle);
let settled = false;
const shutdown = coordinateHeartbeatSchedulerShutdown({
signal: "SIGTERM",
prepareHotRestartShutdown: vi.fn(async () => ({
mode: "not_requested" as const,
skipDrain: false,
})),
waitForHeartbeatSchedulerIdle,
}).finally(() => {
settled = true;
});
await vi.waitFor(() => expect(waitForHeartbeatSchedulerIdle).toHaveBeenCalledOnce());
expect(settled).toBe(false);
releaseScheduler();
await expect(shutdown).resolves.toEqual({
hotRestart: { mode: "not_requested", skipDrain: false },
preparationError: null,
waitedForSchedulerIdle: true,
});
});
it("waits for scheduler idle when hot-restart preparation is unavailable", async () => {
const waitForHeartbeatSchedulerIdle = vi.fn(async () => undefined);
const result = await coordinateHeartbeatSchedulerShutdown({
signal: "SIGTERM",
prepareHotRestartShutdown: null,
waitForHeartbeatSchedulerIdle,
});
expect(waitForHeartbeatSchedulerIdle).toHaveBeenCalledOnce();
expect(result).toEqual({
hotRestart: null,
preparationError: null,
waitedForSchedulerIdle: true,
});
});
it("falls back to the scheduler idle wait when hot-restart preparation fails", async () => {
const preparationError = new Error("snapshot failed");
const waitForHeartbeatSchedulerIdle = vi.fn(async () => undefined);
const result = await coordinateHeartbeatSchedulerShutdown({
signal: "SIGTERM",
prepareHotRestartShutdown: vi.fn(async () => {
throw preparationError;
}),
waitForHeartbeatSchedulerIdle,
});
expect(waitForHeartbeatSchedulerIdle).toHaveBeenCalledOnce();
expect(result).toEqual({
hotRestart: null,
preparationError,
waitedForSchedulerIdle: true,
});
});
});
describe("service shutdown failure isolation", () => {
it("awaits remaining cleanup before reporting a scheduler failure", async () => {
const failure = new Error("plugin result could not be saved");
const gate = deferred();
const cleanup = vi.fn(() => gate.promise);
let finished = false;
const stopping = finishServiceShutdown(async () => { throw failure; }, cleanup)
.then(() => { finished = true; return undefined; }, error => { finished = true; return error; });
try {
await vi.waitFor(() => expect(cleanup).toHaveBeenCalledOnce());
expect(finished).toBe(false);
} finally { gate.resolve(); }
expect(await stopping).toBe(failure);
});
it("reports both failures after attempting cleanup", async () => {
const stopFailure = new Error("scheduler failure"), cleanupFailure = new Error("worker failure");
const cleanup = vi.fn(async () => { throw cleanupFailure; });
await expect(finishServiceShutdown(async () => { throw stopFailure; }, cleanup))
.rejects.toMatchObject({ errors: [stopFailure, cleanupFailure] });
expect(cleanup).toHaveBeenCalledOnce();
});
});