From 182a7cd4fed48e56a2a33209edbb522780abf58b Mon Sep 17 00:00:00 2001 From: Dotta <34892728+cryppadotta@users.noreply.github.com> Date: Tue, 10 Nov 2026 02:43:55 -0600 Subject: [PATCH] test(restart-chaos): keep process start identity out of TM2/TM3 aging (#20500) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit ## 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 --- tests/restart-chaos/README.md | 5 ++++ tests/restart-chaos/time-faults-db.test.ts | 16 ++++++++---- tests/restart-chaos/time-faults.test.ts | 14 ++++++++++ tests/restart-chaos/time-faults.ts | 30 +++++++++++++++++----- 4 files changed, 53 insertions(+), 12 deletions(-) diff --git a/tests/restart-chaos/README.md b/tests/restart-chaos/README.md index 4165a84c898..c863de70826 100644 --- a/tests/restart-chaos/README.md +++ b/tests/restart-chaos/README.md @@ -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 diff --git a/tests/restart-chaos/time-faults-db.test.ts b/tests/restart-chaos/time-faults-db.test.ts index f64ade2ba29..14c1d95fc0b 100644 --- a/tests/restart-chaos/time-faults-db.test.ts +++ b/tests/restart-chaos/time-faults-db.test.ts @@ -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 }>; + 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; 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); diff --git a/tests/restart-chaos/time-faults.test.ts b/tests/restart-chaos/time-faults.test.ts index cdc891a708d..ded26fb882d 100644 --- a/tests/restart-chaos/time-faults.test.ts +++ b/tests/restart-chaos/time-faults.test.ts @@ -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/); diff --git a/tests/restart-chaos/time-faults.ts b/tests/restart-chaos/time-faults.ts index e14e43aa096..feb8cd632ef 100644 --- a/tests/restart-chaos/time-faults.ts +++ b/tests/restart-chaos/time-faults.ts @@ -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, 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(); - 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(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;