Skip to content

Commit 790d604

Browse files
pcncTrigger.dev RepoOps
authored andcommitted
fix(run-store): retry run-ops replica reads cancelled by a recovery conflict
Retry run-ops read-replica queries that a hot-standby replica cancels with a recovery conflict, instead of failing the request. Mono-RevId: 7293c398c3168ca0a601b01e1584567d8841fa4a
1 parent 906a8b1 commit 790d604

9 files changed

Lines changed: 1408 additions & 27 deletions

File tree

‎apps/webapp/app/db.server.ts‎

Lines changed: 84 additions & 27 deletions
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,7 @@
11
import {
22
Prisma,
33
PrismaClient,
4+
TokenBucketRetryBudget,
45
boundedIn,
56
$transaction as transac,
67
type PrismaClientOrTransaction,
@@ -11,7 +12,7 @@ import {
1112
type WebhookReplicaDatabase,
1213
} from "@trigger.dev/database";
1314
import { RunOpsPrismaClient } from "@internal/run-ops-database";
14-
import { markReadReplicaClient } from "@internal/run-store";
15+
import { markReadReplicaClient, withReplicaRecoveryConflictRetry } from "@internal/run-store";
1516
import { PrismaPg } from "@prisma/adapter-pg";
1617
import { Pool } from "pg";
1718
import invariant from "tiny-invariant";
@@ -172,6 +173,55 @@ function captureInfraErrorsRunOps(client: RunOpsPrismaClient): RunOpsPrismaClien
172173
) as unknown as RunOpsPrismaClient;
173174
}
174175

176+
// At most one budget-exhausted warn per replica per interval, so a long burst can't flood the logs.
177+
const RECOVERY_CONFLICT_BUDGET_EXHAUSTED_LOG_INTERVAL_MS = 30_000;
178+
179+
// A run-ops replica cancels a read that blocks WAL replay ("conflict with recovery"); the same read
180+
// a moment later normally succeeds. Applied to the dedicated run-ops replicas (new and gen-2 shards),
181+
// not the legacy one. Each replica gets its own budget, so a conflict burst on one shard can't spend
182+
// another's retries; the builders run once per database, and an aliased shard shares its target's
183+
// client and budget.
184+
//
185+
// Applied after the other extensions so tracing and error capture see one call and its final
186+
// outcome, and before markReadReplicaClient, which brands the returned object.
187+
//
188+
// An empty budget means cancelled reads are failing again, so that is logged with the number of
189+
// refusals since the previous warn. Refusals that fall inside the interval are only reported by the
190+
// next warn, so the tail of a burst that ends inside the interval is never logged.
191+
function retryRunOpsReplicaRecoveryConflicts(
192+
clientType: string,
193+
client: RunOpsPrismaClient
194+
): RunOpsPrismaClient {
195+
let lastExhaustedLogAt = 0;
196+
let exhaustedSinceLastLog = 0;
197+
return withReplicaRecoveryConflictRetry(client, {
198+
maxAttempts: 3,
199+
backoffMinMs: 25,
200+
backoffMaxMs: 100,
201+
budget: new TokenBucketRetryBudget({ ratePerSec: 20, burst: 50 }),
202+
onRetry: (info) => {
203+
logger.info("Retrying a run-ops replica read cancelled by a recovery conflict", {
204+
clientType,
205+
...info,
206+
});
207+
},
208+
onBudgetExhausted: (info) => {
209+
exhaustedSinceLastLog++;
210+
const now = Date.now();
211+
if (now - lastExhaustedLogAt < RECOVERY_CONFLICT_BUDGET_EXHAUSTED_LOG_INTERVAL_MS) {
212+
return;
213+
}
214+
logger.warn("Run-ops replica recovery-conflict retry budget exhausted; reads are failing", {
215+
clientType,
216+
...info,
217+
exhaustedSinceLastLog,
218+
});
219+
lastExhaustedLogAt = now;
220+
exhaustedSinceLastLog = 0;
221+
},
222+
});
223+
}
224+
175225
export const prisma = singleton("prisma", () =>
176226
registerTransactionResilience(
177227
captureInfrastructureErrors(
@@ -390,7 +440,8 @@ export function selectRunOpsTopology(
390440
// assertRunOpsSplitSentinel(). Because the builder callbacks only run when
391441
// splitEnabled is true, single-DB reuses prisma/$replica by reference and opens
392442
// nothing new. The builders apply the SAME wrapper pair the control-plane
393-
// singletons use (captureInfrastructureErrors(tagDatasource(datasource, clientType, raw))).
443+
// singletons use (captureInfrastructureErrors(tagDatasource(datasource, clientType, raw))); the new
444+
// and shard replicas also get retryRunOpsReplicaRecoveryConflicts.
394445
const runOpsTopology: RunOpsTopology = singleton("runOpsTopology", () => {
395446
const newUrl = env.RUN_OPS_DATABASE_URL;
396447
// Gate on the opt-in flag too: the distinct-DB sentinel only runs when the flag is on.
@@ -466,19 +517,22 @@ const runOpsTopology: RunOpsTopology = singleton("runOpsTopology", () => {
466517
// which this callback never touches, so the writer stays unbranded.
467518
buildNewReplica: (url, clientType) =>
468519
markReadReplicaClient(
469-
captureInfraErrorsRunOps(
470-
tagDatasourceRunOps(
471-
"run-ops-replica",
472-
clientType,
473-
buildRunOpsClient({
474-
url,
520+
retryRunOpsReplicaRecoveryConflicts(
521+
clientType,
522+
captureInfraErrorsRunOps(
523+
tagDatasourceRunOps(
524+
"run-ops-replica",
475525
clientType,
476-
role: "replica",
477-
connectionLimit: newPoolKnobs.replicaConnectionLimit,
478-
poolTimeout: newPoolKnobs.replicaPoolTimeout,
479-
connectTimeout: newPoolKnobs.replicaConnectionTimeout,
480-
useDriverAdapter: newPoolKnobs.replicaDriverAdapter,
481-
})
526+
buildRunOpsClient({
527+
url,
528+
clientType,
529+
role: "replica",
530+
connectionLimit: newPoolKnobs.replicaConnectionLimit,
531+
poolTimeout: newPoolKnobs.replicaPoolTimeout,
532+
connectTimeout: newPoolKnobs.replicaConnectionTimeout,
533+
useDriverAdapter: newPoolKnobs.replicaDriverAdapter,
534+
})
535+
)
482536
)
483537
)
484538
),
@@ -547,19 +601,22 @@ const runOpsTopology: RunOpsTopology = singleton("runOpsTopology", () => {
547601
const descriptor = shardDescriptorsByKey.get(shard.key);
548602
const knobs = resolveRunOpsPoolKnobs("new", descriptor?.knobs);
549603
return markReadReplicaClient(
550-
captureInfraErrorsRunOps(
551-
tagDatasourceRunOps(
552-
"run-ops-replica",
553-
`run-ops-shard-${shard.key}-replica`,
554-
buildRunOpsClient({
555-
url: shard.replicaUrl!,
556-
clientType: `run-ops-shard-${shard.key}-replica`,
557-
role: "replica",
558-
connectionLimit: knobs.replicaConnectionLimit,
559-
poolTimeout: knobs.replicaPoolTimeout,
560-
connectTimeout: knobs.replicaConnectionTimeout,
561-
useDriverAdapter: knobs.replicaDriverAdapter,
562-
})
604+
retryRunOpsReplicaRecoveryConflicts(
605+
`run-ops-shard-${shard.key}-replica`,
606+
captureInfraErrorsRunOps(
607+
tagDatasourceRunOps(
608+
"run-ops-replica",
609+
`run-ops-shard-${shard.key}-replica`,
610+
buildRunOpsClient({
611+
url: shard.replicaUrl!,
612+
clientType: `run-ops-shard-${shard.key}-replica`,
613+
role: "replica",
614+
connectionLimit: knobs.replicaConnectionLimit,
615+
poolTimeout: knobs.replicaPoolTimeout,
616+
connectTimeout: knobs.replicaConnectionTimeout,
617+
useDriverAdapter: knobs.replicaDriverAdapter,
618+
})
619+
)
563620
)
564621
)
565622
);

‎internal-packages/run-store/src/index.ts‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -2,6 +2,7 @@ export * from "./types.js";
22
export * from "./PostgresRunStore.js";
33
export * from "./runOpsStore.js";
44
export * from "./readReplicaClient.js";
5+
export * from "./replicaRecoveryConflictRetry.js";
56
export * from "./redisSnapshotStore.js";
67
export * from "./snapshotKeys.js";
78
export * from "./pendingIndex.js";
Lines changed: 206 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,206 @@
1+
import {
2+
connectReaderClient,
3+
type HotStandby,
4+
hotStandbyTest,
5+
type ReaderClientDriver,
6+
} from "@internal/testcontainers";
7+
import type { RunOpsPrismaClient } from "@internal/run-ops-database";
8+
import { describe, expect } from "vitest";
9+
import { PostgresRunStore } from "./PostgresRunStore.js";
10+
import { markReadReplicaClient } from "./readReplicaClient.js";
11+
import {
12+
replicaRecoveryConflictSqlstate,
13+
withReplicaRecoveryConflictRetry,
14+
} from "./replicaRecoveryConflictRetry.js";
15+
import { seedRecoveryConflictRun } from "./testFixtures/recoveryConflictRun.js";
16+
17+
// The same retry the plain-Postgres tests drive with a gate, here against cancellations a real hot
18+
// standby raises during WAL replay.
19+
20+
const DRIVERS: ReaderClientDriver[] = ["engine", "adapter"];
21+
22+
async function caught(promise: Promise<unknown>): Promise<unknown> {
23+
try {
24+
await promise;
25+
} catch (error) {
26+
return error;
27+
}
28+
throw new Error("expected the read to be cancelled, but it succeeded");
29+
}
30+
31+
async function poll(what: string, check: () => boolean, timeoutMs = 5_000) {
32+
const deadline = Date.now() + timeoutMs;
33+
while (!check()) {
34+
if (Date.now() > deadline) throw new Error(`timed out waiting for ${what}`);
35+
await new Promise((r) => setTimeout(r, 10));
36+
}
37+
}
38+
39+
async function seed(hotStandby: HotStandby) {
40+
const writer = connectReaderClient(hotStandby.primaryUrl, "engine");
41+
try {
42+
return await seedRecoveryConflictRun(writer.client);
43+
} finally {
44+
await writer.disconnect();
45+
await hotStandby.waitForReplay();
46+
}
47+
}
48+
49+
function wrappedReplica(client: RunOpsPrismaClient) {
50+
const retries: Array<{ model?: string; operation: string; attempt: number; sqlstate?: string }> =
51+
[];
52+
const replica = markReadReplicaClient(
53+
withReplicaRecoveryConflictRetry(client, {
54+
maxAttempts: 3,
55+
backoffMinMs: 25,
56+
backoffMaxMs: 100,
57+
onRetry: (info) => retries.push(info),
58+
})
59+
);
60+
return { replica, retries };
61+
}
62+
63+
describe("replica recovery-conflict retry on a real hot standby", () => {
64+
hotStandbyTest(
65+
"a lock conflict (40001) is recognised in every shape, and a run read through the store recovers",
66+
{ timeout: 300_000 },
67+
async ({ hotStandby }) => {
68+
const run = await seed(hotStandby);
69+
70+
for (const driver of DRIVERS) {
71+
const reader = connectReaderClient(hotStandby.standbyUrl, driver);
72+
const bare = reader.client;
73+
try {
74+
// Connect first, so the read under test is the one that blocks.
75+
await bare.taskRun.findFirst({ where: { id: run.runId }, select: { id: true } });
76+
77+
// The bare client surfaces the cancellation in the shapes the classifier expects.
78+
for (const kind of ["model", "raw"] as const) {
79+
const before = await hotStandby.conflicts();
80+
const conflict = await hotStandby.armLockConflict("TaskRun");
81+
try {
82+
const cancelled = caught(
83+
kind === "model"
84+
? bare.taskRun.findFirst({ where: { id: run.runId }, select: { id: true } })
85+
: bare.$queryRawUnsafe(`SELECT id FROM "TaskRun" LIMIT 1`)
86+
);
87+
await conflict.waitForBlockedRead();
88+
await conflict.fire();
89+
const error = await cancelled;
90+
91+
expect(error, `${driver} ${kind}`).toMatchObject(
92+
kind === "model"
93+
? { name: "PrismaClientKnownRequestError", code: "P2034" }
94+
: {
95+
name: "PrismaClientKnownRequestError",
96+
code: "P2010",
97+
meta: { code: "40001" },
98+
}
99+
);
100+
expect(replicaRecoveryConflictSqlstate(error), `${driver} ${kind}`).toBe("40001");
101+
expect((await hotStandby.conflicts()).lock, driver).toBe(before.lock + 1);
102+
} finally {
103+
await conflict.release();
104+
}
105+
}
106+
107+
// Through the wrapped replica and the store, the cancelled read is retried. The retry
108+
// blocks on the still-armed lock and completes once it is released.
109+
const { replica, retries } = wrappedReplica(bare);
110+
const store = new PostgresRunStore({
111+
prisma: bare as never,
112+
readOnlyPrisma: replica as never,
113+
schemaVariant: "dedicated",
114+
});
115+
const before = await hotStandby.conflicts();
116+
const conflict = await hotStandby.armLockConflict("TaskRun");
117+
try {
118+
const found = store.findRun({ id: run.runId }, { select: { id: true } });
119+
await conflict.waitForBlockedRead();
120+
await conflict.fire();
121+
await poll(`${driver}: the retry`, () => retries.length === 1);
122+
await conflict.release();
123+
124+
await expect(found, driver).resolves.toEqual({ id: run.runId });
125+
expect(retries, driver).toEqual([
126+
expect.objectContaining({ model: "TaskRun", attempt: 1, sqlstate: "40001" }),
127+
]);
128+
expect((await hotStandby.conflicts()).lock, driver).toBe(before.lock + 1);
129+
} finally {
130+
await conflict.release();
131+
}
132+
} finally {
133+
await reader.disconnect();
134+
}
135+
}
136+
}
137+
);
138+
139+
// The backend-side buffer deadlock: replay already waits on a buffer pin the read's transaction
140+
// holds (an open cursor) when the read starts waiting on a lock replay holds. A plain model read
141+
// can't be driven into this ordering on demand, so this checks the 40P01 shape a real standby
142+
// produces, and that a read inside a transaction is not retried.
143+
hotStandbyTest(
144+
"a buffer deadlock with replay (40P01) is recognised, and is not retried inside a transaction",
145+
{ timeout: 300_000 },
146+
async ({ hotStandby }) => {
147+
await seed(hotStandby);
148+
await hotStandby.primarySql([
149+
"CREATE TABLE hot_standby_pin (id int PRIMARY KEY, v int NOT NULL)",
150+
"INSERT INTO hot_standby_pin SELECT i, 0 FROM generate_series(1, 20) i",
151+
]);
152+
// Long enough for the standby's deadlock check to run before replay gives up waiting.
153+
await hotStandby.setMaxStandbyStreamingDelay(30_000);
154+
155+
let n = 0;
156+
for (const driver of DRIVERS) {
157+
for (const kind of ["model", "raw"] as const) {
158+
const label = `${driver} ${kind}`;
159+
// Fresh unfrozen tuples, so the VACUUM FREEZE below logs a freeze that needs the pin.
160+
await hotStandby.primarySql("UPDATE hot_standby_pin SET v = v + 1");
161+
await hotStandby.waitForReplay();
162+
163+
const reader = connectReaderClient(hotStandby.standbyUrl, driver);
164+
const { replica, retries } = wrappedReplica(reader.client);
165+
const gid = `pin_${++n}`;
166+
try {
167+
const error = await caught(
168+
replica.$transaction(
169+
async (tx) => {
170+
await tx.$executeRawUnsafe(
171+
"DECLARE pin CURSOR FOR SELECT id FROM hot_standby_pin"
172+
);
173+
await tx.$queryRawUnsafe("FETCH FORWARD 1 FROM pin");
174+
await hotStandby.primarySql([
175+
"BEGIN",
176+
`LOCK TABLE "TaskRun" IN ACCESS EXCLUSIVE MODE`,
177+
`PREPARE TRANSACTION '${gid}'`,
178+
]);
179+
// Replay takes the lock, then waits on our pin to apply the freeze.
180+
await hotStandby.primarySql("VACUUM FREEZE hot_standby_pin");
181+
await hotStandby.waitForReplayBlockedOnPin();
182+
await (kind === "model"
183+
? tx.taskRun.findFirst({ select: { id: true } })
184+
: tx.$queryRawUnsafe(`SELECT id FROM "TaskRun" LIMIT 1`));
185+
},
186+
{ timeout: 20_000, maxWait: 10_000 }
187+
)
188+
);
189+
190+
expect(error, label).toMatchObject(
191+
kind === "model"
192+
? { name: "PrismaClientUnknownRequestError" }
193+
: { name: "PrismaClientKnownRequestError", code: "P2010", meta: { code: "40P01" } }
194+
);
195+
expect(String((error as Error).message), label).toMatch(/conflict with recovery/);
196+
expect(replicaRecoveryConflictSqlstate(error), label).toBe("40P01");
197+
expect(retries, label).toEqual([]);
198+
} finally {
199+
await hotStandby.primarySql(`COMMIT PREPARED '${gid}'`).catch(() => {});
200+
await reader.disconnect();
201+
}
202+
}
203+
}
204+
}
205+
);
206+
});

0 commit comments

Comments
 (0)