mirror of
https://github.com/paperclipai/paperclip.git
synced 2026-11-11 05:11:49 +01:00
test(restart-chaos): keep process start identity out of TM2/TM3 aging (#20500)
## Thinking Path > - Paperclip is the open source app people use to manage AI agents for work > - The restart-chaos harness (`tests/restart-chaos/`) checks recovery under faults. TM2 (host sleep) and TM3 (aged outage) move every database time back by an age. > - The aging also moved process start times: `controller_process_started_at`, `process_started_at`, and `processStartedAt` copies in JSON. > - A process start is identity, not a deadline. The server reads its own start from the OS once and compares it with the stamp an owner saved. A real sleep never changes it. > - After a shift, every live owner looked like a different process and failed its identity check, whatever its lease said. This harness artifact hid whether a lease fix works (#20474). > - This pull request keeps process start identity unaged and makes the grader's unshift skip it too. > - The benefit is that TM2/TM3 failures now come only from deadlines that really lapse, as on a real laptop. ## Linked Issues or Issue Description Refs #20458 (adds TM1–TM3) and #20474 (the lease fix whose proof wave exposed this). **What happened?** A TM2 wave against #20474 still failed at the 300 s renewal. The fix takes back a lapsed lease only for the same owner (token, attempt, generation, boot, pid and process start). The aging had moved the saved `controller_process_started_at` back by one hour. The live process still reported its real start, so the identity comparison failed. **Expected behavior** Aging moves deadlines and event times. It never moves facts that a real sleep cannot change, such as when a process started. **Steps to reproduce** Run `node cli/node_modules/tsx/dist/cli.mjs tests/restart-chaos/main.ts --env local --adapters codex --workloads B5 --faults TM2 --time-age-hours 1 --concurrency 1 --tasks 2 --seed 304 --server-from <#20474 checkout>`. Before this change it fails 0/2 (w-20261110T072106-s304). ## What Changed - `time-faults.ts`: add `isProcessIdentityTime`. `agingStatements` skips columns named for a process start. `paperclip_shift_json` keeps JSON keys named for a process start (any spelling) unchanged. `unshiftJson` skips the same keys, so the grader does not move them forward. - `time-faults.test.ts`: a unit test for the statements and the unshift. - `time-faults-db.test.ts`: the embedded-Postgres aging test now checks that a `controller_process_started_at` column and `processStartedAt` / `processStartedAtMs` JSON keys keep their values. - `README.md`: one paragraph under **Aging** that says why. ## Verification - `npx vitest run -c tests/restart-chaos/vitest.config.ts tests/restart-chaos/time-faults-db.test.ts tests/restart-chaos/time-faults.test.ts`: 26/26 pass. Without the `time-faults.ts` change, 2 fail (the new unit test, and the DB aging test's identity check). - `npx tsc --noEmit -p tests/restart-chaos` is clean. - Test-only change. No product code. ## Risks - Low. Only the harness changes. A column or key whose name contains "process started at" is no longer aged. If such a field were really a deadline, it would no longer lapse, but none is. ## Model Used - Claude Opus 5.5 (`claude-opus-5-5`), Anthropic, used in Claude Code with tool use (shell, file editing). ## 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 - [ ] I will address all Greptile and reviewer comments before requesting merge 🤖 Generated with [Claude Code](https://claude.com/claude-code) --------- Co-authored-by: Claude <noreply@anthropic.com>
This commit is contained in:
1 parent
2f59b9c67c
commit
182a7cd4fe
4 files changed
+53
-12
No files matched your search
@@ -739,6 +739,11 @@ past. The shift covers:
|
||||
- every time inside a `jsonb` column: ISO datetime strings keep their format, and whole numbers in the
|
||||
wave's epoch-millisecond window move too.
|
||||
|
||||
A process start (`process_started_at`, `controller_process_started_at`, and `processStartedAt` keys in
|
||||
JSON) is not aged. It is part of a process's identity: owners compare the stamp they saved with the
|
||||
start time the OS reports, and a real sleep never changes that. Aging it would make every live owner
|
||||
look like a different process, a harness artifact rather than a lapsed deadline.
|
||||
|
||||
The JSON pass matters. Receipts and snapshots keep copies of times (a continuation receipt stores the
|
||||
comment's `updatedAt` and compares it later). Shifting only the columns would fail those comparisons, a
|
||||
harness artifact rather than a product failure. Triggers are turned off for the shift (replica role) so
|
||||
|
||||
@@ -21,7 +21,8 @@ describe.skipIf(!support.supported)("aging a wave database", () => {
|
||||
db = createDb(temporary.connectionString, { maxConnections: 1 });
|
||||
evidenceDir = await mkdtemp(path.join(os.tmpdir(), "chaos-time-evidence-"));
|
||||
await db.$client.unsafe(`create table chaos_time_comments (id text primary key, updated_at timestamptz not null, body text not null)`);
|
||||
await db.$client.unsafe(`create table chaos_time_runs (id text primary key, status text, lease_expires_at timestamptz, finished_at timestamptz, context jsonb)`);
|
||||
await db.$client.unsafe(`create table chaos_time_runs (id text primary key, status text, lease_expires_at timestamptz, finished_at timestamptz, context jsonb,
|
||||
controller_process_started_at timestamptz)`);
|
||||
await db.$client.unsafe(`create table chaos_time_touch (id text primary key, updated_at timestamptz)`);
|
||||
// A trigger that would rewrite updated_at on every update: the shift must not fire it.
|
||||
await db.$client.unsafe(`create function chaos_time_touch_now() returns trigger language plpgsql as $$
|
||||
@@ -29,10 +30,12 @@ describe.skipIf(!support.supported)("aging a wave database", () => {
|
||||
await db.$client.unsafe(`create trigger chaos_time_touch_trigger before update on chaos_time_touch for each row execute function chaos_time_touch_now()`);
|
||||
await db.$client.unsafe(`insert into chaos_time_comments values ('c1', $1, '2026-11-09T12:00:00Z stays text')`, [new Date(NOON).toISOString()]);
|
||||
await db.$client.unsafe(`insert into chaos_time_touch values ('t1', $1)`, [new Date(NOON).toISOString()]);
|
||||
await db.$client.unsafe(`insert into chaos_time_runs values ('r1', 'running', $1, null, $2::jsonb)`, [
|
||||
await db.$client.unsafe(`insert into chaos_time_runs values ('r1', 'running', $1, null, $2::jsonb, $3)`, [
|
||||
new Date(NOON + 20 * 60_000).toISOString(),
|
||||
JSON.stringify({ commentUpdatedAt: new Date(NOON).toISOString(), pgStyle: "2026-11-09 12:00:00.5+00", plain: "2026-11-09T12:00:00Z",
|
||||
wallMs: NOON, count: 42, version: 20_261_109, note: "not 2026-11-09T12:00:00Z", nested: [{ at: "2026-11-09T12:00:00.123456+05:30" }] }),
|
||||
wallMs: NOON, count: 42, version: 20_261_109, note: "not 2026-11-09T12:00:00Z", nested: [{ at: "2026-11-09T12:00:00.123456+05:30" }],
|
||||
holder: { processStartedAt: "2026-11-09T11:30:00.000Z", processStartedAtMs: NOON - 30 * 60_000 } }),
|
||||
new Date(NOON - 30 * 60_000).toISOString(),
|
||||
]);
|
||||
}, 120_000);
|
||||
|
||||
@@ -50,8 +53,8 @@ describe.skipIf(!support.supported)("aging a wave database", () => {
|
||||
expect(result.tables.map(table => table.table)).toEqual(expect.arrayContaining(["chaos_time_comments", "chaos_time_runs", "chaos_time_touch"]));
|
||||
|
||||
const [comment] = await db.$client.unsafe(`select updated_at, body from chaos_time_comments`) as unknown as Array<{ updated_at: unknown; body: string }>;
|
||||
const [run] = await db.$client.unsafe(`select lease_expires_at, finished_at, context from chaos_time_runs`) as unknown as Array<{
|
||||
lease_expires_at: unknown; finished_at: unknown; context: Record<string, unknown> }>;
|
||||
const [run] = await db.$client.unsafe(`select lease_expires_at, finished_at, context, controller_process_started_at from chaos_time_runs`) as unknown as Array<{
|
||||
lease_expires_at: unknown; finished_at: unknown; context: Record<string, unknown>; controller_process_started_at: unknown }>;
|
||||
const [touched] = await db.$client.unsafe(`select updated_at from chaos_time_touch`) as unknown as Array<{ updated_at: unknown }>;
|
||||
expect(ms(comment!.updated_at)).toBe(NOON - age);
|
||||
expect(comment!.body).toBe("2026-11-09T12:00:00Z stays text");
|
||||
@@ -65,6 +68,9 @@ describe.skipIf(!support.supported)("aging a wave database", () => {
|
||||
pgStyle: "2026-11-08 10:00:00.5+00", plain: "2026-11-08T10:00:00Z", wallMs: NOON - age, count: 42, version: 20_261_109,
|
||||
note: "not 2026-11-09T12:00:00Z", nested: [{ at: "2026-11-08T10:00:00.123456+05:30" }],
|
||||
});
|
||||
// Process start identity is not a deadline: the live owner must still match its saved stamp.
|
||||
expect(ms(run!.controller_process_started_at)).toBe(NOON - 30 * 60_000);
|
||||
expect(run!.context.holder).toEqual({ processStartedAt: "2026-11-09T11:30:00.000Z", processStartedAtMs: NOON - 30 * 60_000 });
|
||||
|
||||
const evidence = JSON.parse(await readFile(result.evidencePath, "utf8")) as { ageMs: number; tables: Array<{ table: string; rows: number }> };
|
||||
expect(evidence.ageMs).toBe(age);
|
||||
|
||||
@@ -109,6 +109,20 @@ describe("aging", () => {
|
||||
+ "where \"created_at\" is not null or \"context_snapshot\" is not null");
|
||||
});
|
||||
|
||||
it("keeps process start identity: a real sleep never changes when a process started", () => {
|
||||
const statements = agingStatements([
|
||||
{ table: "heartbeat_runs", column: "started_at", kind: "timestamp" },
|
||||
{ table: "heartbeat_runs", column: "process_started_at", kind: "timestamp" },
|
||||
{ table: "native_run_finalizations", column: "controller_process_started_at", kind: "timestamp" },
|
||||
], HOUR, window);
|
||||
expect(statements.map(statement => [statement.table, statement.columns])).toEqual([["heartbeat_runs", ["started_at"]]]);
|
||||
const shifts = [{ faultId: "f01", ageMs: HOUR, appliedAt: Date.parse("2026-11-09T12:00:00Z"),
|
||||
waveStartedAt: Date.parse("2026-11-09T11:00:00Z") }];
|
||||
const aged = new Date(Date.parse("2026-11-09T11:30:00Z") - HOUR).toISOString();
|
||||
expect(unshiftJson({ processStartedAt: aged, leaseHolder: { process_started_at: aged }, at: aged }, shifts))
|
||||
.toEqual({ processStartedAt: aged, leaseHolder: { process_started_at: aged }, at: "2026-11-09T11:30:00.000Z" });
|
||||
});
|
||||
|
||||
it("takes whole seconds only, so fractional digits never change", () => {
|
||||
expect(() => agingStatements([], 0, window)).toThrow(/positive/);
|
||||
expect(() => agingStatements([], 1_500, window)).toThrow(/whole number of seconds/);
|
||||
|
||||
@@ -244,7 +244,8 @@ export type AgingColumn = { table: string; column: string; kind: "timestamp" | "
|
||||
* column it was copied from:
|
||||
* - an ISO datetime string keeps its exact format, separator and offset;
|
||||
* - a whole number in the epoch-millisecond window [lo, hi] (the wave's own times) moves by the age.
|
||||
* The age is whole seconds, so fractional digits never change.
|
||||
* The age is whole seconds, so fractional digits never change. A process start
|
||||
* (`processStartedAt`, any spelling) is identity, not a time: see `isProcessIdentityTime`.
|
||||
*/
|
||||
export const SHIFT_JSON_FUNCTION = [
|
||||
"create or replace function pg_temp.paperclip_shift_json(v jsonb, age_ms bigint, lo bigint, hi bigint)",
|
||||
@@ -253,7 +254,8 @@ export const SHIFT_JSON_FUNCTION = [
|
||||
"begin",
|
||||
" case jsonb_typeof(v)",
|
||||
" when 'object' then",
|
||||
" select coalesce(jsonb_object_agg(e.key, pg_temp.paperclip_shift_json(e.value, age_ms, lo, hi)), '{}'::jsonb) into r from jsonb_each(v) e;",
|
||||
" select coalesce(jsonb_object_agg(e.key, case when replace(lower(e.key), '_', '') like '%processstartedat%' then e.value",
|
||||
" else pg_temp.paperclip_shift_json(e.value, age_ms, lo, hi) end), '{}'::jsonb) into r from jsonb_each(v) e;",
|
||||
" return r;",
|
||||
" when 'array' then",
|
||||
" select coalesce(jsonb_agg(pg_temp.paperclip_shift_json(e.value, age_ms, lo, hi) order by e.ord), '[]'::jsonb) into r",
|
||||
@@ -278,12 +280,24 @@ export const SHIFT_JSON_FUNCTION = [
|
||||
"end $fn$",
|
||||
].join("\n");
|
||||
|
||||
/** One UPDATE per table, shifting all of its timestamp and JSON columns at once. */
|
||||
/**
|
||||
* A process start time is part of a process's identity (pid + start), read from
|
||||
* the OS and compared with the stamp an owner saved. A real sleep never changes
|
||||
* it, so aging it would make every live owner look like a different process: a
|
||||
* harness artifact, not a deadline that lapsed. Columns and JSON keys named for
|
||||
* a process start (`process_started_at`, `controller_process_started_at`,
|
||||
* `processStartedAt`, ...) keep their value.
|
||||
*/
|
||||
export function isProcessIdentityTime(name: string): boolean {
|
||||
return name.toLowerCase().replaceAll("_", "").includes("processstartedat");
|
||||
}
|
||||
|
||||
/** One UPDATE per table, shifting all of its timestamp and JSON columns at once (process start identity excepted). */
|
||||
export function agingStatements(columns: ReadonlyArray<AgingColumn>, ageMs: number,
|
||||
epochWindow: { lo: number; hi: number }): Array<{ table: string; columns: string[]; sql: string }> {
|
||||
if (!Number.isSafeInteger(ageMs) || ageMs <= 0 || ageMs % 1000 !== 0) throw new Error("Aging needs a positive whole number of seconds");
|
||||
const byTable = new Map<string, AgingColumn[]>();
|
||||
for (const column of columns) byTable.set(column.table, [...(byTable.get(column.table) ?? []), column]);
|
||||
for (const column of columns) if (!isProcessIdentityTime(column.column)) byTable.set(column.table, [...(byTable.get(column.table) ?? []), column]);
|
||||
const shift = (column: AgingColumn) => column.kind === "timestamp"
|
||||
? `${quote(column.column)} - interval '${ageMs} milliseconds'`
|
||||
: `pg_temp.paperclip_shift_json(${quote(column.column)}, ${ageMs}, ${Math.trunc(epochWindow.lo)}, ${Math.trunc(epochWindow.hi)})`;
|
||||
@@ -342,7 +356,8 @@ export async function ageWaveDatabase(input: { connectionString: string; faultId
|
||||
if (!recorded.has(statement.table)) continue;
|
||||
// Identity, state and times only: payload columns can carry run output.
|
||||
const keys = identityColumns.filter(key => key.table === statement.table).map(key => key.column);
|
||||
const times = columns.filter(column => column.table === statement.table && column.kind === "timestamp").map(column => column.column);
|
||||
const times = columns.filter(column => column.table === statement.table && column.kind === "timestamp"
|
||||
&& !isProcessIdentityTime(column.column)).map(column => column.column);
|
||||
const select = [...keys, ...times].map(quote).join(", ");
|
||||
const order = times.includes("created_at") ? " order by created_at desc" : "";
|
||||
before[statement.table] = await tx.unsafe(`select ${select} from public.${quote(statement.table)}${order} limit ${RECORDED_ROWS_PER_TABLE}`) as unknown as unknown[];
|
||||
@@ -359,7 +374,7 @@ export async function ageWaveDatabase(input: { connectionString: string; faultId
|
||||
const evidencePath = path.join(input.evidenceDir, `${input.faultId}.json`);
|
||||
await mkdir(input.evidenceDir, { recursive: true, mode: 0o700 });
|
||||
await writeFile(evidencePath, `${JSON.stringify({ faultId: input.faultId, ageMs: input.ageMs, startedAt, appliedAt,
|
||||
note: "Rows of the time-bound tables as they were before the shift; after the shift every timestamp shown is ageMs earlier.",
|
||||
note: "Rows of the time-bound tables as they were before the shift; after the shift every timestamp shown is ageMs earlier. Process start identity is not aged and not shown.",
|
||||
tables, rowsBefore: outcome.before }, null, 2)}\n`, { mode: 0o600 });
|
||||
return { faultId: input.faultId, ageMs: input.ageMs, appliedAt, waveStartedAt: input.waveStartedAt, startedAt, tables,
|
||||
totalRows: tables.reduce((sum, table) => sum + table.rows, 0), triggersDisabled, lockRetries, evidencePath };
|
||||
@@ -420,7 +435,8 @@ export function unshiftJson<T>(value: T, shifts: readonly AgingShift[]): T {
|
||||
}
|
||||
if (typeof node === "number") return shiftedEpochMs(node, shifts) ? unshiftMs(node, shifts) : node;
|
||||
if (Array.isArray(node)) return node.map(visit);
|
||||
if (node && typeof node === "object") return Object.fromEntries(Object.entries(node).map(([key, child]) => [key, visit(child)]));
|
||||
if (node && typeof node === "object") return Object.fromEntries(Object.entries(node)
|
||||
.map(([key, child]) => [key, isProcessIdentityTime(key) ? child : visit(child)]));
|
||||
return node;
|
||||
};
|
||||
return visit(value) as T;
|
||||
|
||||
Reference in new issue
Block a user