Visitar URL original
fix(webapp): keep the metadata flush loop alive when a buffered opera… · triggerdotdev/trigger.dev@53441fd · GitHub
Skip to content

Commit 53441fd

Browse files
myftijaTrigger.dev RepoOps
authored andcommitted
fix(webapp): keep the metadata flush loop alive when a buffered operation cannot be applied
The batched metadata flusher, which writes parent and root run metadata, no longer stops when a buffered operation cannot be applied. That operation is now skipped and logged on its own, and the run's other buffered operations are written. A metadata key that names nothing below the root, such as `$.` or `$..`, is refused with a validation error for parent and root metadata and ignored for a run's own metadata. Mono-RevId: 25f352b330af6829f3c8eae78a61a02368e44ba9
1 parent e20bad2 commit 53441fd

5 files changed

Lines changed: 601 additions & 33 deletions

File tree

Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,5 @@
1+
---
2+
"@trigger.dev/core": patch
3+
---
4+
5+
Fix parent and root metadata updates being lost after one update could not be applied. Only that update is now skipped, and the rest are written. Metadata keys that name only the root, such as `$.` or `$..`, are now ignored on a run's own metadata instead of throwing, and rejected for parent and root metadata, which fails the whole request.

‎apps/webapp/app/services/metadata/updateMetadata.server.ts‎

Lines changed: 127 additions & 29 deletions
Original file line numberDiff line numberDiff line change
@@ -12,7 +12,7 @@ import {
1212
MetadataTooLargeError,
1313
} from "~/utils/packets";
1414
import { ServiceValidationError } from "~/v3/services/common.server";
15-
import { Effect, Either, Option, Schedule, Duration, Fiber } from "effect";
15+
import { Cause, Effect, Either, Option, Schedule, Duration, Fiber } from "effect";
1616
import { type RuntimeFiber } from "effect/Fiber";
1717
import { setTimeout } from "timers/promises";
1818
import type { LogLevel } from "@trigger.dev/core/logger";
@@ -32,6 +32,8 @@ import {
3232
const RUN_UPDATABLE_WINDOW_MS = 60 * 60 * 1000; // 1 hour
3333

3434
const MAX_DRAIN_BATCHES_PER_TICK = 100;
35+
const MAX_DROPS_LOGGED = 20;
36+
const MAX_LOGGED_CHARS = 200;
3537

3638
class MetadataClaimLostError extends Error {
3739
constructor(runId: string) {
@@ -51,6 +53,44 @@ class MetadataWriteOutcomeUnknownError extends Error {
5153
}
5254
}
5355

56+
type DroppedOperation = { operation: RunMetadataChangeOperation; error: unknown };
57+
58+
// A dropped operation may not be well formed.
59+
function loggedKey(operation: RunMetadataChangeOperation): string | undefined {
60+
const key = (operation as { key?: unknown }).key;
61+
return typeof key === "string" ? key.slice(0, MAX_LOGGED_CHARS) : undefined;
62+
}
63+
64+
function applyOrSalvage(
65+
metadata: Record<string, unknown>,
66+
operations: RunMetadataChangeOperation[],
67+
budgetMs: number
68+
): { newMetadata: Record<string, unknown>; applied: number; dropped: DroppedOperation[] } {
69+
let newMetadata = metadata;
70+
let applied = 0;
71+
let deadline: number | undefined;
72+
const dropped: DroppedOperation[] = [];
73+
const apply = (segment: RunMetadataChangeOperation[]): void => {
74+
try {
75+
// Copies: a value enters the metadata by reference, so a failed attempt may have mutated it.
76+
const result = applyMetadataOperations(newMetadata, structuredClone(segment));
77+
newMetadata = result.newMetadata;
78+
applied += segment.length - result.unappliedOperations.length;
79+
} catch (error) {
80+
deadline ??= performance.now() + budgetMs;
81+
if (segment.length <= 1 || performance.now() >= deadline) {
82+
dropped.push(...segment.map((operation) => ({ operation, error })));
83+
return;
84+
}
85+
const half = Math.ceil(segment.length / 2);
86+
apply(segment.slice(0, half));
87+
apply(segment.slice(half));
88+
}
89+
};
90+
apply(operations);
91+
return { newMetadata, applied, dropped };
92+
}
93+
5494
function isClaimLost(error: unknown): boolean {
5595
return error instanceof MetadataClaimLostError;
5696
}
@@ -91,6 +131,8 @@ export type UpdateMetadataServiceOptions = {
91131
/** Retries of one run's flush before its operations go back to the buffer for a later tick. */
92132
flushMaxRetries?: number;
93133
maximumSize?: number;
134+
/** How long after a batch's first throw the flusher keeps splitting it; after that a failing segment is dropped whole. */
135+
salvageBudgetMs?: number;
94136
logger?: Logger;
95137
logLevel?: LogLevel;
96138
/** Called after the batched flusher writes a run's buffered operations, with everything
@@ -116,6 +158,8 @@ type RequeueReason =
116158
| "claim_lost"
117159
| "read_failed";
118160

161+
type DropReason = "apply_failed" | "too_large" | "run_missing" | "invalid_packet" | "defect";
162+
119163
export class UpdateMetadataService {
120164
private readonly _buffer: MetadataOperationBuffer;
121165
private _flushFiber: RuntimeFiber<void> | null = null;
@@ -127,8 +171,10 @@ export class UpdateMetadataService {
127171
private readonly drainBatchSize: number;
128172
private readonly flushMaxRetries: number;
129173
private readonly maximumSize: number;
174+
private readonly salvageBudgetMs: number;
130175
private readonly logger: Logger;
131176
private readonly requeueCounter: Counter;
177+
private readonly dropCounter: Counter;
132178
private runsPending: number | undefined;
133179

134180
constructor(private readonly options: UpdateMetadataServiceOptions) {
@@ -141,6 +187,7 @@ export class UpdateMetadataService {
141187
this.drainBatchSize = options.drainBatchSize ?? 10;
142188
this.flushMaxRetries = options.flushMaxRetries ?? 5;
143189
this.maximumSize = options.maximumSize ?? 1024 * 1024 * 1; // 1MB
190+
this.salvageBudgetMs = options.salvageBudgetMs ?? 50;
144191
this.logger = options.logger ?? new Logger("UpdateMetadataService", options.logLevel ?? "info");
145192

146193
const meter = options.meter ?? getMeter("metadata-flush");
@@ -149,6 +196,10 @@ export class UpdateMetadataService {
149196
"Runs whose buffered metadata operations were not written on this attempt, by reason",
150197
unit: "runs",
151198
});
199+
this.dropCounter = meter.createCounter("metadata.buffer.drops", {
200+
description: "Buffered metadata operations the flusher dropped, by reason",
201+
unit: "operations",
202+
});
152203
meter
153204
.createObservableGauge("metadata.buffer.runs_pending", {
154205
description:
@@ -180,10 +231,10 @@ export class UpdateMetadataService {
180231

181232
yield* _(
182233
this._drainBufferedOperations().pipe(
183-
Effect.catchAll((error) =>
234+
Effect.catchAllCause((cause) =>
184235
Effect.sync(() => {
185236
this.logger.error("[UpdateMetadataService] Failed to drain buffered operations", {
186-
error,
237+
error: Cause.squash(cause),
187238
});
188239
})
189240
)
@@ -221,7 +272,20 @@ export class UpdateMetadataService {
221272
}
222273

223274
for (const claim of claims) {
224-
yield* _(this._processClaim(claim));
275+
yield* _(
276+
this._processClaim(claim).pipe(
277+
Effect.catchAllDefect((defect) => {
278+
this.logger.error(
279+
"[UpdateMetadataService] Dropping a claim whose processing threw",
280+
{
281+
runId: claim.runId,
282+
error: defect,
283+
}
284+
);
285+
return this.#ackWithDrops(claim, "defect");
286+
})
287+
)
288+
);
225289
}
226290

227291
if (claims.length < this.drainBatchSize) {
@@ -274,7 +338,7 @@ export class UpdateMetadataService {
274338
}
275339

276340
if (!current.right) {
277-
yield* _(this._ackClaim(claim));
341+
yield* _(this.#ackWithDrops(claim, "run_missing"));
278342
return;
279343
}
280344

@@ -294,8 +358,9 @@ export class UpdateMetadataService {
294358
}
295359
}
296360

361+
const dropped: DroppedOperation[] = [];
297362
yield* _(
298-
this._updateRunWithOperations(claim, processedOps).pipe(
363+
this._updateRunWithOperations(claim, processedOps, dropped).pipe(
299364
// Catch MetadataTooLargeError before retry logic
300365
Effect.catchIf(
301366
(error) => error instanceof MetadataTooLargeError,
@@ -308,10 +373,11 @@ export class UpdateMetadataService {
308373
if (this.flushLoggingEnabled) {
309374
this.logger.warn(`[UpdateMetadataService] Metadata too large for run`, {
310375
runId,
311-
operationsCount: processedOps.length,
376+
operationsCount: claim.operations.length,
312377
error: error.message,
313378
});
314379
}
380+
return "too_large" as const;
315381
})
316382
),
317383
Effect.retry({
@@ -322,7 +388,7 @@ export class UpdateMetadataService {
322388
!isClaimLost(error) && !isWriteOutcomeUnknown(error) && !isWriteNotSent(error),
323389
}),
324390
Effect.matchEffect({
325-
onSuccess: () => this._ackClaim(claim),
391+
onSuccess: (wholeReason) => this.#ackWithDrops(claim, wholeReason, dropped),
326392
onFailure: (error) =>
327393
Effect.gen(this, function* (__) {
328394
if (isClaimLost(error)) {
@@ -370,6 +436,33 @@ export class UpdateMetadataService {
370436
this.requeueCounter.add(1, { reason });
371437
}
372438

439+
#recordDrop(reason: DropReason, count: number) {
440+
this.dropCounter.add(count, { reason });
441+
}
442+
443+
#ackWithDrops(
444+
claim: MetadataBufferClaim,
445+
wholeReason?: DropReason,
446+
dropped: DroppedOperation[] = []
447+
) {
448+
if (wholeReason) {
449+
this.#recordDrop(wholeReason, claim.operations.length - dropped.length);
450+
}
451+
if (dropped.length > 0) {
452+
this.#recordDrop("apply_failed", dropped.length);
453+
this.logger.warn(`[UpdateMetadataService] Dropped operations that could not be applied`, {
454+
runId: claim.runId,
455+
droppedCount: dropped.length,
456+
dropped: dropped.slice(0, MAX_DROPS_LOGGED).map(({ operation, error }) => ({
457+
type: operation.type,
458+
key: loggedKey(operation),
459+
error: String(error).slice(0, MAX_LOGGED_CHARS),
460+
})),
461+
});
462+
}
463+
return this._ackClaim(claim);
464+
}
465+
373466
private _ackClaim = (claim: MetadataBufferClaim, options?: { count?: number }) =>
374467
Effect.tryPromise(() => this._buffer.ack(claim, options)).pipe(
375468
Effect.catchAll((error) =>
@@ -396,7 +489,8 @@ export class UpdateMetadataService {
396489

397490
private _updateRunWithOperations = (
398491
claim: MetadataBufferClaim,
399-
operations: BufferedRunMetadataChangeOperation[]
492+
operations: BufferedRunMetadataChangeOperation[],
493+
dropped: DroppedOperation[]
400494
) => {
401495
const runId = claim.runId;
402496
return Effect.gen(this, function* (_) {
@@ -424,9 +518,9 @@ export class UpdateMetadataService {
424518
if (!run) {
425519
this.logger.warn(`[UpdateMetadataService] Dropping operations for missing run`, {
426520
runId,
427-
operationsCount: operations.length,
521+
operationsCount: claim.operations.length,
428522
});
429-
return;
523+
return "run_missing" as const;
430524
}
431525

432526
// Testing hook after read
@@ -442,15 +536,14 @@ export class UpdateMetadataService {
442536
)
443537
);
444538

445-
// Apply operations and update
446-
const applyResult = applyMetadataOperations(
447-
metadata,
448-
operations.map((op) => op.operation)
449-
);
450-
451-
if (applyResult.unappliedOperations.length === operations.length) {
539+
const skip = new Set(dropped.map(({ operation }) => operation));
540+
const attempted = operations
541+
.map((op) => op.operation)
542+
.filter((operation) => !skip.has(operation));
543+
const applyResult = applyOrSalvage(metadata, attempted, this.salvageBudgetMs);
544+
dropped.push(...applyResult.dropped);
545+
if (applyResult.applied === 0) {
452546
this.logger.warn(`No operations applied for run ${runId}`);
453-
// If no operations were applied, return
454547
return;
455548
}
456549

@@ -472,7 +565,7 @@ export class UpdateMetadataService {
472565
if (!newMetadataPacket) {
473566
// Log and skip if metadata is invalid
474567
this.logger.warn(`Invalid metadata after operations, skipping update`);
475-
return;
568+
return "invalid_packet" as const;
476569
}
477570

478571
// Testing hook before update
@@ -522,16 +615,21 @@ export class UpdateMetadataService {
522615
}
523616

524617
yield* Effect.sync(() => {
525-
this.options.onRunFlushed?.({
526-
runId,
527-
environmentId: run.runtimeEnvironmentId,
528-
tags: run.runTags,
529-
batchId: run.batchId,
530-
updatedAtMs: writeTime.getTime(),
531-
});
618+
try {
619+
this.options.onRunFlushed?.({
620+
runId,
621+
environmentId: run.runtimeEnvironmentId,
622+
tags: run.runTags,
623+
batchId: run.batchId,
624+
updatedAtMs: writeTime.getTime(),
625+
});
626+
} catch (error) {
627+
this.logger.error("[UpdateMetadataService] onRunFlushed threw after the write", {
628+
runId,
629+
error,
630+
});
631+
}
532632
});
533-
534-
return result;
535633
});
536634
};
537635

0 commit comments

Comments
 (0)