Skip to content

Commit 7b54c35

Browse files
nicktrnnicktrn
authored
fix(otel): prevent infinite retry loops on unicode hex escape errors (#2337)
* prevent infinite retry loop for unicode errors * structured logs for prisma events * preserve all prisma event fields * either use structured logs or stdout, never both * split runs repo tests * decrease test shards to 8
1 parent 60b8c76 commit 7b54c35

File tree

5 files changed

+963
-777
lines changed

5 files changed

+963
-777
lines changed

‎.github/workflows/unit-tests-webapp.yml

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -12,8 +12,8 @@ jobs:
1212
runs-on: ubuntu-latest
1313
strategy:
1414
matrix:
15-
shardIndex: [1, 2, 3, 4, 5, 6, 7, 8, 9, 10]
16-
shardTotal: [10]
15+
shardIndex: [1, 2, 3, 4, 5, 6, 7, 8]
16+
shardTotal: [8]
1717
env:
1818
DOCKERHUB_USERNAME: ${{ secrets.DOCKERHUB_USERNAME }}
1919
SHARD_INDEX: ${{ matrix.shardIndex }}

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

Lines changed: 138 additions & 20 deletions
Original file line numberDiff line numberDiff line change
@@ -122,30 +122,89 @@ function getClient() {
122122
url: databaseUrl.href,
123123
},
124124
},
125-
// @ts-expect-error
126125
log: [
126+
// events
127127
{
128-
emit: "stdout",
128+
emit: "event",
129129
level: "error",
130130
},
131131
{
132-
emit: "stdout",
132+
emit: "event",
133133
level: "info",
134134
},
135135
{
136-
emit: "stdout",
136+
emit: "event",
137137
level: "warn",
138138
},
139-
].concat(
140-
process.env.VERBOSE_PRISMA_LOGS === "1"
139+
// stdout
140+
...((process.env.PRISMA_LOG_TO_STDOUT === "1"
141141
? [
142-
{ emit: "event", level: "query" },
143-
{ emit: "stdout", level: "query" },
142+
{
143+
emit: "stdout",
144+
level: "error",
145+
},
146+
{
147+
emit: "stdout",
148+
level: "info",
149+
},
150+
{
151+
emit: "stdout",
152+
level: "warn",
153+
},
144154
]
145-
: []
146-
),
155+
: []) satisfies Prisma.LogDefinition[]),
156+
// verbose
157+
...((process.env.VERBOSE_PRISMA_LOGS === "1"
158+
? [
159+
{
160+
emit: "event",
161+
level: "query",
162+
},
163+
{
164+
emit: "stdout",
165+
level: "query",
166+
},
167+
]
168+
: []) satisfies Prisma.LogDefinition[]),
169+
],
147170
});
148171

172+
// Only use structured logging if we're not already logging to stdout
173+
if (process.env.PRISMA_LOG_TO_STDOUT !== "1") {
174+
client.$on("info", (log) => {
175+
logger.info("PrismaClient info", {
176+
clientType: "writer",
177+
event: {
178+
timestamp: log.timestamp,
179+
message: log.message,
180+
target: log.target,
181+
},
182+
});
183+
});
184+
185+
client.$on("warn", (log) => {
186+
logger.warn("PrismaClient warn", {
187+
clientType: "writer",
188+
event: {
189+
timestamp: log.timestamp,
190+
message: log.message,
191+
target: log.target,
192+
},
193+
});
194+
});
195+
196+
client.$on("error", (log) => {
197+
logger.error("PrismaClient error", {
198+
clientType: "writer",
199+
event: {
200+
timestamp: log.timestamp,
201+
message: log.message,
202+
target: log.target,
203+
},
204+
});
205+
});
206+
}
207+
149208
// connect eagerly
150209
client.$connect();
151210

@@ -174,30 +233,89 @@ function getReplicaClient() {
174233
url: replicaUrl.href,
175234
},
176235
},
177-
// @ts-expect-error
178236
log: [
237+
// events
179238
{
180-
emit: "stdout",
239+
emit: "event",
181240
level: "error",
182241
},
183242
{
184-
emit: "stdout",
243+
emit: "event",
185244
level: "info",
186245
},
187246
{
188-
emit: "stdout",
247+
emit: "event",
189248
level: "warn",
190249
},
191-
].concat(
192-
process.env.VERBOSE_PRISMA_LOGS === "1"
250+
// stdout
251+
...((process.env.PRISMA_LOG_TO_STDOUT === "1"
193252
? [
194-
{ emit: "event", level: "query" },
195-
{ emit: "stdout", level: "query" },
253+
{
254+
emit: "stdout",
255+
level: "error",
256+
},
257+
{
258+
emit: "stdout",
259+
level: "info",
260+
},
261+
{
262+
emit: "stdout",
263+
level: "warn",
264+
},
196265
]
197-
: []
198-
),
266+
: []) satisfies Prisma.LogDefinition[]),
267+
// verbose
268+
...((process.env.VERBOSE_PRISMA_LOGS === "1"
269+
? [
270+
{
271+
emit: "event",
272+
level: "query",
273+
},
274+
{
275+
emit: "stdout",
276+
level: "query",
277+
},
278+
]
279+
: []) satisfies Prisma.LogDefinition[]),
280+
],
199281
});
200282

283+
// Only use structured logging if we're not already logging to stdout
284+
if (process.env.PRISMA_LOG_TO_STDOUT !== "1") {
285+
replicaClient.$on("info", (log) => {
286+
logger.info("PrismaClient info", {
287+
clientType: "reader",
288+
event: {
289+
timestamp: log.timestamp,
290+
message: log.message,
291+
target: log.target,
292+
},
293+
});
294+
});
295+
296+
replicaClient.$on("warn", (log) => {
297+
logger.warn("PrismaClient warn", {
298+
clientType: "reader",
299+
event: {
300+
timestamp: log.timestamp,
301+
message: log.message,
302+
target: log.target,
303+
},
304+
});
305+
});
306+
307+
replicaClient.$on("error", (log) => {
308+
logger.error("PrismaClient error", {
309+
clientType: "reader",
310+
event: {
311+
timestamp: log.timestamp,
312+
message: log.message,
313+
target: log.target,
314+
},
315+
});
316+
});
317+
}
318+
201319
// connect eagerly
202320
replicaClient.$connect();
203321

‎apps/webapp/app/v3/eventRepository.server.ts

Lines changed: 72 additions & 20 deletions
Original file line numberDiff line numberDiff line change
@@ -1230,25 +1230,23 @@ export class EventRepository {
12301230

12311231
return events;
12321232
} catch (error) {
1233-
if (error instanceof Prisma.PrismaClientUnknownRequestError) {
1234-
logger.error("Failed to insert events, most likely because of null characters", {
1235-
error: {
1236-
name: error.name,
1237-
message: error.message,
1238-
stack: error.stack,
1239-
clientVersion: error.clientVersion,
1240-
},
1233+
if (isRetriablePrismaError(error)) {
1234+
const isKnownError = error instanceof Prisma.PrismaClientKnownRequestError;
1235+
span.setAttribute("prisma_error_type", isKnownError ? "known" : "unknown");
1236+
1237+
const errorDetails = getPrismaErrorDetails(error);
1238+
if (errorDetails.code) {
1239+
span.setAttribute("prisma_error_code", errorDetails.code);
1240+
}
1241+
1242+
logger.error("Failed to insert events, will attempt bisection", {
1243+
error: errorDetails,
12411244
});
12421245

12431246
if (events.length === 1) {
12441247
logger.debug("Attempting to insert event individually and it failed", {
12451248
event: events[0],
1246-
error: {
1247-
name: error.name,
1248-
message: error.message,
1249-
stack: error.stack,
1250-
clientVersion: error.clientVersion,
1251-
},
1249+
error: errorDetails,
12521250
});
12531251

12541252
span.setAttribute("failed_event_count", 1);
@@ -1258,12 +1256,7 @@ export class EventRepository {
12581256

12591257
if (depth > MAX_FLUSH_DEPTH) {
12601258
logger.error("Failed to insert events, reached maximum depth", {
1261-
error: {
1262-
name: error.name,
1263-
message: error.message,
1264-
stack: error.stack,
1265-
clientVersion: error.clientVersion,
1266-
},
1259+
error: errorDetails,
12671260
depth,
12681261
eventsCount: events.length,
12691262
});
@@ -1917,3 +1910,62 @@ export async function recordRunDebugLog(
19171910
},
19181911
});
19191912
}
1913+
1914+
/**
1915+
* Extracts error details from Prisma errors in a type-safe way.
1916+
* Only includes 'code' property for PrismaClientKnownRequestError.
1917+
*/
1918+
function getPrismaErrorDetails(
1919+
error: Prisma.PrismaClientUnknownRequestError | Prisma.PrismaClientKnownRequestError
1920+
): {
1921+
name: string;
1922+
message: string;
1923+
stack: string | undefined;
1924+
clientVersion: string;
1925+
code?: string;
1926+
} {
1927+
const base = {
1928+
name: error.name,
1929+
message: error.message,
1930+
stack: error.stack,
1931+
clientVersion: error.clientVersion,
1932+
};
1933+
1934+
if (error instanceof Prisma.PrismaClientKnownRequestError) {
1935+
return { ...base, code: error.code };
1936+
}
1937+
1938+
return base;
1939+
}
1940+
1941+
/**
1942+
* Checks if a PrismaClientKnownRequestError is a Unicode/hex escape error.
1943+
*/
1944+
function isUnicodeError(error: Prisma.PrismaClientKnownRequestError): boolean {
1945+
return (
1946+
error.message.includes("lone leading surrogate in hex escape") ||
1947+
error.message.includes("unexpected end of hex escape") ||
1948+
error.message.includes("invalid Unicode") ||
1949+
error.message.includes("invalid escape sequence")
1950+
);
1951+
}
1952+
1953+
/**
1954+
* Determines if a Prisma error should be retried with bisection logic.
1955+
* Returns true for errors that might be resolved by splitting the batch.
1956+
*/
1957+
function isRetriablePrismaError(
1958+
error: unknown
1959+
): error is Prisma.PrismaClientUnknownRequestError | Prisma.PrismaClientKnownRequestError {
1960+
if (error instanceof Prisma.PrismaClientUnknownRequestError) {
1961+
// Always retry unknown errors with bisection
1962+
return true;
1963+
}
1964+
1965+
if (error instanceof Prisma.PrismaClientKnownRequestError) {
1966+
// Only retry known errors if they're Unicode/hex escape related
1967+
return isUnicodeError(error);
1968+
}
1969+
1970+
return false;
1971+
}

0 commit comments

Comments
 (0)