Skip to content

Commit 1d4eb7b

Browse files
committed
fix(run-store): address review on the sweep, and make the timestamp parity real
The sweep discovered keyspaces by their cur key, which the append script writes only when an entry is valid. A keyspace whose entries all carry an error has no cur and no index, so neither sweep rule could ever see it and it leaked with no expiry, which is the same unbounded leak the second rule exists to close. It now scans on the entry hash, which every append writes, and the age probe falls back to the newest instant in that hash when the index is empty. Enumerating a run's cycle keys used KEYS. That command iterates the whole database and blocks while it does, and a hash tag routes a key without scoping the scan, so a sweep pass would have issued one full keyspace scan per run. It now reads the dense cycle high-water counter the append script maintains, which is the same source the store's own terminal-expiry loop uses, and pipelines the existence checks into one round trip. The timestamp parity assertion was still tautological. The previous commit added a note saying the builders receive an independent instant and did not change the builder calls, which kept reading the value off the row under test. Every case now mints one instant, passes it to the store, and gives the builder the same value, so a write site that stops forwarding the caller's instant fails here. Also documents what an injected fault actually does at each write path, since only the birth path rethrows, and scopes a run count in the chaos suite to the environment under test.
1 parent ea0e17b commit 1d4eb7b

5 files changed

Lines changed: 164 additions & 30 deletions

File tree

internal-packages/run-engine/src/engine/tests/snapshotStoreChaos.test.ts

Lines changed: 3 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -186,7 +186,9 @@ describe("snapshot store crash boundaries", () => {
186186
expect(faults.fired("afterRedisBirthBeforePg")).toBe(1);
187187

188188
// The harmless state: no run row, so nothing can ever read a run that has no snapshot.
189-
const runsAfterCrash = await prisma.taskRun.count();
189+
const runsAfterCrash = await prisma.taskRun.count({
190+
where: { runtimeEnvironmentId: environment.id },
191+
});
190192
expect(runsAfterCrash).toBe(0);
191193

192194
// A crashed birth must not poison the path: the next trigger runs to completion.

internal-packages/run-store/src/snapshotEntry.parity.test.ts

Lines changed: 40 additions & 18 deletions
Original file line numberDiff line numberDiff line change
@@ -24,11 +24,14 @@ import {
2424

2525
/**
2626
* NOTE ON createdAt. An earlier version of this suite built the expected entry with
27-
* `createdAt: row.createdAt` and then asserted the two matched, which is tautological and hid a
28-
* real divergence: seven of the eight write sites stamped the entry from the app clock while
29-
* Postgres stamped its own column default, so the stores held different instants. The builders are
30-
* now given an INDEPENDENT instant, and the row must carry that same value because the decorator
31-
* passes it through to Postgres.
27+
* `createdAt: row.createdAt`, reading the value off the row it was checking and then asserting the
28+
* two matched. That can never fail, and it hid a real divergence: seven of the eight write sites
29+
* stamped the entry from the app clock while Postgres stamped its own column default, so the two
30+
* stores held different instants for one snapshot.
31+
*
32+
* Every case now mints ONE instant, passes it to the store call, and gives the builder the same
33+
* value. The row must carry it because the write site forwards it. A write site that stops
34+
* forwarding the caller's instant fails here.
3235
*
3336
* Compares only what the entry claims. The Redis model carries no `updatedAt` and no join rows, and
3437
* it holds `createdAt` as an ISO string, so those are checked separately or not at all.
@@ -56,9 +59,13 @@ function assertParity(entry: SnapshotEntryInput, row: Record<string, unknown>) {
5659
expect((row.updatedAt as Date).toISOString()).toBe(entry.createdAt);
5760
}
5861

62+
/** Five minutes in the past, so a database default could never coincide with it. */
63+
const independentStamp = new Date(Date.now() - 5 * 60 * 1000);
64+
5965
function birthSnapshot(id: string, env: SnapshotFixtureEnv) {
6066
return {
6167
id,
68+
createdAt: independentStamp,
6269
engine: "V2" as const,
6370
executionStatus: "RUN_CREATED" as const,
6471
description: "Run was created",
@@ -81,7 +88,7 @@ describe("entry to Postgres row parity", () => {
8188
await store.createRun({ data: buildCreateRunData(runId, env), snapshot });
8289

8390
const row = await prisma.taskRunExecutionSnapshot.findFirstOrThrow({ where: { id } });
84-
assertParity(entryFromCreateRun({ id, runId, createdAt: row.createdAt }, snapshot), row);
91+
assertParity(entryFromCreateRun({ id, runId, createdAt: independentStamp }, snapshot), row);
8592
});
8693

8794
postgresTest("createRun with an associated waitpoint, legacy schema", async ({ prisma }) => {
@@ -107,7 +114,7 @@ describe("entry to Postgres row parity", () => {
107114
});
108115

109116
const row = await prisma.taskRunExecutionSnapshot.findFirstOrThrow({ where: { id } });
110-
assertParity(entryFromCreateRun({ id, runId, createdAt: row.createdAt }, snapshot), row);
117+
assertParity(entryFromCreateRun({ id, runId, createdAt: independentStamp }, snapshot), row);
111118
});
112119

113120
postgresTest("createRun carries the worker and runner ids", async ({ prisma }) => {
@@ -121,7 +128,7 @@ describe("entry to Postgres row parity", () => {
121128
await store.createRun({ data: buildCreateRunData(runId, env), snapshot });
122129

123130
const row = await prisma.taskRunExecutionSnapshot.findFirstOrThrow({ where: { id } });
124-
assertParity(entryFromCreateRun({ id, runId, createdAt: row.createdAt }, snapshot), row);
131+
assertParity(entryFromCreateRun({ id, runId, createdAt: independentStamp }, snapshot), row);
125132
});
126133

127134
postgresTest("createCancelledRun", async ({ prisma }) => {
@@ -149,7 +156,7 @@ describe("entry to Postgres row parity", () => {
149156
});
150157

151158
const row = await prisma.taskRunExecutionSnapshot.findFirstOrThrow({ where: { id } });
152-
assertParity(entryFromCreateRun({ id, runId, createdAt: row.createdAt }, snapshot), row);
159+
assertParity(entryFromCreateRun({ id, runId, createdAt: independentStamp }, snapshot), row);
153160
});
154161

155162
postgresTest("completeAttemptSuccess", async ({ prisma }) => {
@@ -158,6 +165,7 @@ describe("entry to Postgres row parity", () => {
158165
const id = generateInternalId();
159166
const snapshot = {
160167
id,
168+
createdAt: independentStamp,
161169
executionStatus: "FINISHED" as const,
162170
description: "Run completed",
163171
runStatus: "COMPLETED_SUCCESSFULLY" as const,
@@ -182,7 +190,7 @@ describe("entry to Postgres row parity", () => {
182190

183191
const row = await prisma.taskRunExecutionSnapshot.findFirstOrThrow({ where: { id } });
184192
assertParity(
185-
entryFromCompletion({ id, runId: run.id, createdAt: row.createdAt }, snapshot),
193+
entryFromCompletion({ id, runId: run.id, createdAt: independentStamp }, snapshot),
186194
row
187195
);
188196
});
@@ -193,6 +201,7 @@ describe("entry to Postgres row parity", () => {
193201
const id = generateInternalId();
194202
const snapshot = {
195203
id,
204+
createdAt: independentStamp,
196205
engine: "V2" as const,
197206
executionStatus: "FINISHED" as const,
198207
description: "Run expired",
@@ -215,7 +224,10 @@ describe("entry to Postgres row parity", () => {
215224
);
216225

217226
const row = await prisma.taskRunExecutionSnapshot.findFirstOrThrow({ where: { id } });
218-
assertParity(entryFromExpire({ id, runId: run.id, createdAt: row.createdAt }, snapshot), row);
227+
assertParity(
228+
entryFromExpire({ id, runId: run.id, createdAt: independentStamp }, snapshot),
229+
row
230+
);
219231
});
220232

221233
postgresTest("expireParkedRun", async ({ prisma }) => {
@@ -224,6 +236,7 @@ describe("entry to Postgres row parity", () => {
224236
const id = generateInternalId();
225237
const snapshot = {
226238
id,
239+
createdAt: independentStamp,
227240
engine: "V2" as const,
228241
executionStatus: "FINISHED" as const,
229242
description: "Parked run expired",
@@ -244,7 +257,10 @@ describe("entry to Postgres row parity", () => {
244257

245258
expect(result.count).toBe(1);
246259
const row = await prisma.taskRunExecutionSnapshot.findFirstOrThrow({ where: { id } });
247-
assertParity(entryFromExpire({ id, runId: run.id, createdAt: row.createdAt }, snapshot), row);
260+
assertParity(
261+
entryFromExpire({ id, runId: run.id, createdAt: independentStamp }, snapshot),
262+
row
263+
);
248264
});
249265

250266
postgresTest("rescheduleRun with every default applied", async ({ prisma }) => {
@@ -253,6 +269,7 @@ describe("entry to Postgres row parity", () => {
253269
const id = generateInternalId();
254270
const snapshot = {
255271
id,
272+
createdAt: independentStamp,
256273
environmentId: env.id,
257274
environmentType: env.type,
258275
projectId: env.projectId,
@@ -266,7 +283,7 @@ describe("entry to Postgres row parity", () => {
266283

267284
const row = await prisma.taskRunExecutionSnapshot.findFirstOrThrow({ where: { id } });
268285
assertParity(
269-
entryFromReschedule({ id, runId: run.id, createdAt: row.createdAt }, snapshot),
286+
entryFromReschedule({ id, runId: run.id, createdAt: independentStamp }, snapshot),
270287
row
271288
);
272289
});
@@ -277,6 +294,7 @@ describe("entry to Postgres row parity", () => {
277294
const id = generateInternalId();
278295
const snapshot = {
279296
id,
297+
createdAt: independentStamp,
280298
environmentId: env.id,
281299
environmentType: env.type,
282300
projectId: env.projectId,
@@ -293,7 +311,7 @@ describe("entry to Postgres row parity", () => {
293311

294312
const row = await prisma.taskRunExecutionSnapshot.findFirstOrThrow({ where: { id } });
295313
assertParity(
296-
entryFromReschedule({ id, runId: run.id, createdAt: row.createdAt }, snapshot),
314+
entryFromReschedule({ id, runId: run.id, createdAt: independentStamp }, snapshot),
297315
row
298316
);
299317
});
@@ -314,6 +332,7 @@ describe("entry to Postgres row parity", () => {
314332
const id = generateInternalId();
315333
const snapshot = {
316334
id,
335+
createdAt: independentStamp,
317336
previousSnapshotId: previous.id,
318337
attemptNumber: 1,
319338
environmentId: env.id,
@@ -337,7 +356,7 @@ describe("entry to Postgres row parity", () => {
337356
});
338357

339358
const row = await prisma.taskRunExecutionSnapshot.findFirstOrThrow({ where: { id } });
340-
assertParity(entryFromLock({ id, runId: run.id, createdAt: row.createdAt }, snapshot), row);
359+
assertParity(entryFromLock({ id, runId: run.id, createdAt: independentStamp }, snapshot), row);
341360
});
342361

343362
postgresTest("createExecutionSnapshot, the standalone site", async ({ prisma }) => {
@@ -346,6 +365,7 @@ describe("entry to Postgres row parity", () => {
346365
const id = generateInternalId();
347366
const input = {
348367
id,
368+
createdAt: independentStamp,
349369
run: { id: run.id, status: "EXECUTING" as const, attemptNumber: 2 },
350370
snapshot: { executionStatus: "EXECUTING" as const, description: "Run started" },
351371
environmentId: env.id,
@@ -359,7 +379,7 @@ describe("entry to Postgres row parity", () => {
359379
const row = await prisma.taskRunExecutionSnapshot.findFirstOrThrow({ where: { id } });
360380
expect(created.id).toBe(id);
361381
assertParity(
362-
entryFromCreateExecutionSnapshot({ id, runId: run.id, createdAt: row.createdAt }, input),
382+
entryFromCreateExecutionSnapshot({ id, runId: run.id, createdAt: independentStamp }, input),
363383
row
364384
);
365385
});
@@ -370,6 +390,7 @@ describe("entry to Postgres row parity", () => {
370390
const id = generateInternalId();
371391
const input = {
372392
id,
393+
createdAt: independentStamp,
373394
run: { id: run.id, status: "DEQUEUED" as const, attemptNumber: 1 },
374395
snapshot: { executionStatus: "PENDING_EXECUTING" as const, description: "Run was dequeued" },
375396
environmentId: env.id,
@@ -383,7 +404,7 @@ describe("entry to Postgres row parity", () => {
383404
const row = await prisma.taskRunExecutionSnapshot.findFirstOrThrow({ where: { id } });
384405
expect(row.runStatus).toBe("PENDING");
385406
assertParity(
386-
entryFromCreateExecutionSnapshot({ id, runId: run.id, createdAt: row.createdAt }, input),
407+
entryFromCreateExecutionSnapshot({ id, runId: run.id, createdAt: independentStamp }, input),
387408
row
388409
);
389410
});
@@ -394,6 +415,7 @@ describe("entry to Postgres row parity", () => {
394415
const id = generateInternalId();
395416
const input = {
396417
id,
418+
createdAt: independentStamp,
397419
run: { id: run.id, status: "EXECUTING" as const, attemptNumber: 1 },
398420
snapshot: { executionStatus: "EXECUTING" as const, description: "Stale write" },
399421
error: "snapshot is not the latest",
@@ -408,7 +430,7 @@ describe("entry to Postgres row parity", () => {
408430
const row = await prisma.taskRunExecutionSnapshot.findFirstOrThrow({ where: { id } });
409431
expect(row.isValid).toBe(false);
410432
assertParity(
411-
entryFromCreateExecutionSnapshot({ id, runId: run.id, createdAt: row.createdAt }, input),
433+
entryFromCreateExecutionSnapshot({ id, runId: run.id, createdAt: independentStamp }, input),
412434
row
413435
);
414436
});

internal-packages/run-store/src/snapshotFaultInjection.ts

Lines changed: 9 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -20,9 +20,15 @@ export type SnapshotFaultInjector = (
2020
) => void;
2121

2222
/**
23-
* Thrown by a test injector. The write path tells this apart from a real append failure: an injected
24-
* fault models a process that died, so it is rethrown rather than retried, while a real failure is
25-
* retried and then handed to the repair job.
23+
* Thrown by a test injector. The write path tells this apart from a real append failure, because an
24+
* injected fault models a process that died rather than a call that failed. The two write paths then
25+
* do different things with it, and both differ from a real failure:
26+
*
27+
* - A transition skips its remaining retries, hands the run to the repair job, and does NOT rethrow.
28+
* Postgres has already committed, so the caller must not see an error.
29+
* - A birth rethrows, so the Postgres insert never runs and the crash leaves an orphaned keyspace
30+
* with no run row, which is the harmless state that ordering exists to produce.
31+
* - A real append failure is retried, and only then handed to the repair job.
2632
*/
2733
export class InjectedSnapshotFault extends Error {
2834
readonly boundary: SnapshotFaultBoundary;

internal-packages/run-store/src/snapshotOrphanSweeper.test.ts

Lines changed: 41 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -310,6 +310,47 @@ describe("SnapshotOrphanSweeper", () => {
310310
}
311311
);
312312

313+
containerTest(
314+
"discovers and reaps a keyspace whose entries are all invalid",
315+
async ({ prisma, redisOptions }) => {
316+
const store = new RedisSnapshotStore({ redisOptions, completedTtlMs: COMPLETED_TTL_MS });
317+
const runStore = new PostgresRunStore({ prisma, readOnlyPrisma: prisma });
318+
const sweeper = new SnapshotOrphanSweeper({
319+
redisOptions,
320+
runStore: runStore as unknown as RunStore,
321+
completedTtlMs: COMPLETED_TTL_MS,
322+
orphanAgeMs: ORPHAN_AGE_MS,
323+
});
324+
const probe = createRedisClient(redisOptions, { onError: () => {} });
325+
try {
326+
const env = await seedSnapshotEnvironment(prisma);
327+
const runId = generateInternalId();
328+
const old = new Date(Date.now() - 2 * ORPHAN_AGE_MS);
329+
330+
// The append script writes `cur` and indexes the entry only when it is valid, so a keyspace
331+
// whose entries all carry an error has neither. A sweep that discovers keyspaces by their
332+
// `cur` key would never see this one, and neither rule would ever apply to it.
333+
await store.append({
334+
entry: { ...birthEntry(runId, env, old), error: "stale write" },
335+
kind: "birth",
336+
isTerminal: false,
337+
});
338+
339+
const keys = snapshotKeys(runId);
340+
expect(await probe.exists(keys.e)).toBe(1);
341+
expect(await probe.exists(keys.cur)).toBe(0);
342+
343+
const result = await sweeper.sweep();
344+
345+
expect(result.deleted).toBe(1);
346+
expect(await probe.exists(keys.e)).toBe(0);
347+
expect(await probe.exists(keys.seq)).toBe(0);
348+
} finally {
349+
await Promise.all([store.quit(), sweeper.quit(), probe.quit().catch(() => {})]);
350+
}
351+
}
352+
);
353+
313354
containerTest("processes every keyspace across batches", async ({ prisma, redisOptions }) => {
314355
const store = new RedisSnapshotStore({ redisOptions, completedTtlMs: COMPLETED_TTL_MS });
315356
const runStore = new PostgresRunStore({ prisma, readOnlyPrisma: prisma });

0 commit comments

Comments
 (0)