From 85cbe560b8e2efb1fa9b1da6cc0e190e4f5fceb6 Mon Sep 17 00:00:00 2001 From: Eric Allam Date: Thu, 23 Jul 2026 23:21:56 +0100 Subject: [PATCH 1/9] fix(webapp): keep the rest of a batch when one run or span has un-ingestable JSON When a run's output/payload or a trace span's attributes contained JSON ClickHouse could not ingest (e.g. an object nested past its depth limit), the analytics insert aborted the whole batch. Because runs and events are written in per-batch inserts, one bad row made every other run or span in that batch go missing from the runs list, traces, and logs, even though the Postgres rows were fine. Both ClickHouse write paths now fall back to retrying the insert with input_format_allow_errors so ClickHouse skips only the rows it can't parse and commits the rest. The healthy insert path is unchanged; a successful row isolation logs at info, only a failed isolation insert is an error. --- ...uns-list-batch-drop-on-unparseable-json.md | 6 + .../services/runsReplicationService.server.ts | 264 +++++++++++------ .../clickhouseEventRepository.server.ts | 223 ++++++++++----- ...ckhouseEventRepositoryJsonRecovery.test.ts | 123 ++++++++ .../test/runsReplicationBenchmark.producer.ts | 23 ++ ...nsReplicationJsonRecoveryBenchmark.test.ts | 267 ++++++++++++++++++ .../runsReplicationService.part10.test.ts | 143 ++++++++++ 7 files changed, 885 insertions(+), 164 deletions(-) create mode 100644 .server-changes/fix-runs-list-batch-drop-on-unparseable-json.md create mode 100644 apps/webapp/test/clickhouseEventRepositoryJsonRecovery.test.ts create mode 100644 apps/webapp/test/runsReplicationJsonRecoveryBenchmark.test.ts create mode 100644 apps/webapp/test/runsReplicationService.part10.test.ts diff --git a/.server-changes/fix-runs-list-batch-drop-on-unparseable-json.md b/.server-changes/fix-runs-list-batch-drop-on-unparseable-json.md new file mode 100644 index 00000000000..2f35f93733e --- /dev/null +++ b/.server-changes/fix-runs-list-batch-drop-on-unparseable-json.md @@ -0,0 +1,6 @@ +--- +area: webapp +type: fix +--- + +Fixed a rare case where a single run or span carrying data that could not be ingested would make other runs or trace events in the same batch go missing from the runs list, traces, and logs. Now only the affected item is dropped and everything else is stored normally. diff --git a/apps/webapp/app/services/runsReplicationService.server.ts b/apps/webapp/app/services/runsReplicationService.server.ts index 732665461dd..5ffb38bd5f8 100644 --- a/apps/webapp/app/services/runsReplicationService.server.ts +++ b/apps/webapp/app/services/runsReplicationService.server.ts @@ -1,6 +1,7 @@ import type { ClickhouseFactory } from "~/services/clickhouse/clickhouseFactory.server"; import { type ClickHouse, + type ClickHouseSettings, type PayloadInsertArray, type TaskRunInsertArray, composeTaskRunVersion, @@ -175,14 +176,31 @@ export class RunsReplicationService { private _disableErrorFingerprinting: boolean; /** - * Counts batches that hit a ClickHouse `Cannot parse JSON object` failure - * that survived one sanitize-retry. These batches are dropped on the floor - * (returning success-ish to the caller so the retry layer doesn't spin on - * the same deterministic failure), and we track the drop count for - * observability. Counter only — does not gate behaviour. + * Counts batches dropped whole because even the row-isolation retry failed + * to insert anything (an unexpected terminal case). The common recovery now + * isolates the un-ingestable rows and lands the rest, so this should stay at + * zero in practice. Counter only — does not gate behaviour. */ private _permanentlyDroppedBatches = 0; + /** + * Counts batches that took the row-isolation recovery path — a + * `Cannot parse JSON object` failure the sanitizer could not repair, where we + * re-inserted with `input_format_allow_errors_*` so ClickHouse skipped the + * un-ingestable rows and landed the rest. Reliable per-event signal that user + * data is hitting the ceiling. + */ + private _rowIsolationRecoveries = 0; + + /** + * Best-effort count of individual rows ClickHouse skipped across those + * row-isolation retries, derived from the insert summary's `written_rows` + * when the client surfaces it (it is not always populated under concurrent + * inserts, so treat this as a lower bound; `_rowIsolationRecoveries` is the + * dependable event count). + */ + private _permanentlyDroppedRows = 0; + // Metrics private _replicationLagHistogram: Histogram; private _batchesFlushedCounter: Counter; @@ -416,6 +434,16 @@ export class RunsReplicationService { return this._permanentlyDroppedBatches; } + /** Exposed for tests and metrics — batches that took the row-isolation recovery path. */ + get rowIsolationRecoveries() { + return this._rowIsolationRecoveries; + } + + /** Exposed for tests and metrics — best-effort count of individual rows ClickHouse skipped during row-isolation retries. */ + get permanentlyDroppedRows() { + return this._permanentlyDroppedRows; + } + public async shutdown() { if (this._isShuttingDown) return; @@ -870,15 +898,11 @@ export class RunsReplicationService { payloadError = plErr; } - // Only count rows that actually landed in ClickHouse. `kind: "dropped"` - // means the recovery wrapper bailed (sanitizer no-op or sanitize-retry - // still failed) — those rows never made it, so they must not show up - // as successful inserts in the per-batch counter. - if (!trErr && trOutcome?.kind !== "dropped") { - this._taskRunsInsertedCounter.add(group.taskRunInserts.length); + if (!trErr && trOutcome && trOutcome.kind !== "dropped") { + this._taskRunsInsertedCounter.add(landedRowCount(group.taskRunInserts.length, trOutcome)); } - if (!plErr && plOutcome?.kind !== "dropped") { - this._payloadsInsertedCounter.add(group.payloadInserts.length); + if (!plErr && plOutcome && plOutcome.kind !== "dropped") { + this._payloadsInsertedCounter.add(landedRowCount(group.payloadInserts.length, plOutcome)); } } @@ -1034,10 +1058,14 @@ export class RunsReplicationService { return; } return await startSpan(this._tracer, "insertTaskRunsInserts", async (span) => { - const doInsert = async () => { + const doInsert = async (extraSettings?: ClickHouseSettings) => { const [insertError, insertResult] = await clickhouse.taskRuns.insertCompactArrays( taskRunInserts, - { params: { clickhouse_settings: this.#getClickhouseInsertSettings() } } + { + params: { + clickhouse_settings: { ...this.#getClickhouseInsertSettings(), ...extraSettings }, + }, + } ); if (insertError) { this.logger.error("Error inserting task run inserts attempt", { @@ -1068,10 +1096,14 @@ export class RunsReplicationService { return; } return await startSpan(this._tracer, "insertPayloadInserts", async (span) => { - const doInsert = async () => { + const doInsert = async (extraSettings?: ClickHouseSettings) => { const [insertError, insertResult] = await clickhouse.taskRuns.insertPayloadsCompactArrays( payloadInserts, - { params: { clickhouse_settings: this.#getClickhouseInsertSettings() } } + { + params: { + clickhouse_settings: { ...this.#getClickhouseInsertSettings(), ...extraSettings }, + }, + } ); if (insertError) { this.logger.error("Error inserting payload inserts attempt", { @@ -1094,36 +1126,38 @@ export class RunsReplicationService { } /** - * Wraps a ClickHouse insert with reactive UTF-16 sanitization for - * `Cannot parse JSON object` rejections. Mirrors the pattern from - * `ClickhouseEventRepository.#insertWithJsonParseRecovery` introduced - * in #3659 — same root cause (lone UTF-16 surrogates in user-provided - * JSON), same recovery shape: + * Wraps a ClickHouse insert with recovery for `Cannot parse JSON object` + * rejections so one un-ingestable row never drops its whole batch. Builds on + * the sanitize pattern from `ClickhouseEventRepository.#insertWithJsonParseRecovery` + * (#3659) and adds a final row-isolation fallback: * - * 1. Try the insert. Healthy batches pay zero scan cost. - * 2. On parse error, walk the whole batch via `sanitizeRows` and - * replace any lone-surrogate string with `"[invalid-utf16]"`. - * 3. Retry once. If the sanitizer found nothing or the retry also - * fails with the same error class, drop the batch loudly and - * return — do NOT rethrow, otherwise the surrounding - * `#insertWithRetry` layer would spin three more times on the - * same deterministic failure. - * 4. Non-parse errors propagate unchanged so the existing - * transient-retry path still handles them. - * - * The whole-batch scan (rather than slicing on the `at row N` hint) is - * deliberate: `at row N` semantics under `input_format_parallel_parsing` - * aren't stable enough to safely skip rows. The cost is bounded because - * `detectBadJsonStrings` exits in O(1) for clean strings. + * 1. Try the insert. Healthy batches pay zero recovery cost. + * 2. On a parse error, walk the batch via `sanitizeRows` and losslessly + * repair what we can in place (lone UTF-16 surrogates → `"[invalid-utf16]"`, + * out-of-range integers → their string form), then retry once. A clean + * retry keeps every row. + * 3. If the sanitizer found nothing to fix, or the retry still hits the same + * parse error (a structurally un-ingestable row, e.g. JSON nested past + * ClickHouse's `input_format_json_max_depth`), retry once more with + * `input_format_allow_errors_*` so ClickHouse skips only the un-parseable + * rows and lands the rest. Verified against ClickHouse 26.2 (the cloud + * version): the good rows land, the JSONCompactEachRowWithNames header is + * unaffected, both sync and async. + * 4. Only if that row-isolation insert itself fails do we drop the batch, + * and never rethrow a parse error — otherwise the surrounding + * `#insertWithRetry` layer would spin on the same deterministic failure. + * 5. Non-parse errors propagate unchanged so the transient-retry path still + * handles them. */ async #insertWithJsonParseRecovery( rows: T[], - doInsert: () => Promise, + doInsert: (extraSettings?: ClickHouseSettings) => Promise, contextLabel: string, attempt: number ): Promise< | { kind: "inserted"; insertResult: unknown } | { kind: "sanitized"; insertResult: unknown } + | { kind: "isolated"; insertResult: unknown; rowsSkipped: number | null } | { kind: "dropped" } > { try { @@ -1131,65 +1165,93 @@ export class RunsReplicationService { } catch (firstError) { if (!isClickHouseJsonParseError(firstError)) throw firstError; - const firstMessage = - typeof firstError === "object" && firstError !== null && "message" in firstError - ? String((firstError as { message?: unknown }).message ?? "") - : String(firstError); - + const firstMessage = errorMessage(firstError); const rowHint = parseRowNumberFromError(firstMessage); const { rowsTouched, fieldsSanitized } = sanitizeRows(rows); - if (fieldsSanitized === 0) { - this._permanentlyDroppedBatches += 1; - this.logger.error( - "Dropped batch — ClickHouse JSON parse error but sanitizer found nothing to fix", - { - contextLabel, - attempt, - batchSize: rows.length, - clickhouseRowHint: rowHint, - permanentlyDroppedBatches: this._permanentlyDroppedBatches, - sampleRow: JSON.stringify(rows[0] ?? null).slice(0, 1024), - clickhouseError: firstMessage.split("\n")[0], - } - ); - return { kind: "dropped" }; + if (fieldsSanitized > 0) { + this.logger.warn("Sanitizing batch after ClickHouse JSON parse error", { + contextLabel, + attempt, + batchSize: rows.length, + clickhouseRowHint: rowHint, + rowsTouched, + fieldsSanitized, + clickhouseError: firstMessage.split("\n")[0], + }); + + try { + return { kind: "sanitized", insertResult: await doInsert() }; + } catch (retryError) { + if (!isClickHouseJsonParseError(retryError)) throw retryError; + } } - this.logger.warn("Sanitizing batch after ClickHouse JSON parse error", { - contextLabel, - attempt, - batchSize: rows.length, - clickhouseRowHint: rowHint, - rowsTouched, - fieldsSanitized, - clickhouseError: firstMessage.split("\n")[0], + return await this.#insertIsolatingBadRows(rows, doInsert, contextLabel, attempt, firstMessage); + } + } + + /** + * Last-resort recovery: re-run the insert with `input_format_allow_errors_*` + * so ClickHouse skips the rows it cannot parse and lands the rest, rather than + * aborting the whole INSERT. Forces a synchronous insert so `written_rows` + * reflects exactly what landed and we can count what was lost. + */ + async #insertIsolatingBadRows( + rows: T[], + doInsert: (extraSettings?: ClickHouseSettings) => Promise, + contextLabel: string, + attempt: number, + firstMessage: string + ): Promise< + { kind: "isolated"; insertResult: unknown; rowsSkipped: number | null } | { kind: "dropped" } + > { + try { + const insertResult = await doInsert({ + input_format_allow_errors_num: String(rows.length), + input_format_allow_errors_ratio: 1, + async_insert: 0, }); - try { - return { kind: "sanitized", insertResult: await doInsert() }; - } catch (retryError) { - if (!isClickHouseJsonParseError(retryError)) throw retryError; - - this._permanentlyDroppedBatches += 1; - const retryMessage = - typeof retryError === "object" && retryError !== null && "message" in retryError - ? String((retryError as { message?: unknown }).message ?? "") - : String(retryError); - this.logger.error( - "Dropped batch after sanitize-retry still hit ClickHouse JSON parse error", - { - contextLabel, - attempt, - batchSize: rows.length, - permanentlyDroppedBatches: this._permanentlyDroppedBatches, - sampleRow: JSON.stringify(rows[0] ?? null).slice(0, 1024), - firstError: firstMessage.split("\n")[0], - retryError: retryMessage.split("\n")[0], - } - ); - return { kind: "dropped" }; + this._rowIsolationRecoveries += 1; + const writtenRows = extractWrittenRows(insertResult); + const rowsSkipped = writtenRows === null ? null : Math.max(0, rows.length - writtenRows); + if (rowsSkipped !== null) { + this._permanentlyDroppedRows += rowsSkipped; } + + this.logger.info( + "Isolated un-ingestable rows after ClickHouse JSON parse error — landed the rest of the batch", + { + contextLabel, + attempt, + batchSize: rows.length, + rowsSkipped, + rowIsolationRecoveries: this._rowIsolationRecoveries, + permanentlyDroppedRows: this._permanentlyDroppedRows, + sampleRow: JSON.stringify(rows[0] ?? null).slice(0, 1024), + clickhouseError: firstMessage.split("\n")[0], + } + ); + + return { kind: "isolated", insertResult, rowsSkipped }; + } catch (isolationError) { + if (!isClickHouseJsonParseError(isolationError)) throw isolationError; + + this._permanentlyDroppedBatches += 1; + this.logger.error( + "Dropped batch — row-isolation insert failed after ClickHouse JSON parse error", + { + contextLabel, + attempt, + batchSize: rows.length, + permanentlyDroppedBatches: this._permanentlyDroppedBatches, + sampleRow: JSON.stringify(rows[0] ?? null).slice(0, 1024), + firstError: firstMessage.split("\n")[0], + isolationError: errorMessage(isolationError).split("\n")[0], + } + ); + return { kind: "dropped" }; } } @@ -1542,3 +1604,27 @@ function lsnToUInt64(lsn: string): bigint { const [seg, off] = lsn.split("/"); return (BigInt("0x" + seg) << 32n) | BigInt("0x" + off); } + +function errorMessage(err: unknown): string { + return typeof err === "object" && err !== null && "message" in err + ? String((err as { message?: unknown }).message ?? "") + : String(err); +} + +function landedRowCount( + groupSize: number, + outcome: { kind: string; rowsSkipped?: number | null } +): number { + if (outcome.kind === "isolated" && typeof outcome.rowsSkipped === "number") { + return Math.max(0, groupSize - outcome.rowsSkipped); + } + return groupSize; +} + +function extractWrittenRows(insertResult: unknown): number | null { + const written = (insertResult as { summary?: { written_rows?: string } } | null | undefined) + ?.summary?.written_rows; + if (written === undefined) return null; + const parsed = Number(written); + return Number.isFinite(parsed) ? parsed : null; +} diff --git a/apps/webapp/app/v3/eventRepository/clickhouseEventRepository.server.ts b/apps/webapp/app/v3/eventRepository/clickhouseEventRepository.server.ts index 573097005ed..417b9bffa7f 100644 --- a/apps/webapp/app/v3/eventRepository/clickhouseEventRepository.server.ts +++ b/apps/webapp/app/v3/eventRepository/clickhouseEventRepository.server.ts @@ -1,5 +1,6 @@ import type { ClickHouse, + ClickHouseSettings, LlmMetricsV1Input, MetricsV1Input, TaskEventDetailedSummaryV1Result, @@ -121,14 +122,31 @@ export class ClickhouseEventRepository implements IEventRepository { private _tracer: Tracer; private _version: "v1" | "v2"; /** - * Counts batches that hit a ClickHouse JSON parse failure that survived - * one sanitize-retry. These batches are dropped on the floor (the scheduler - * is told the flush "succeeded" so its queue counter doesn't leak), and we - * track the drop count for observability. + * Counts batches dropped whole because even the row-isolation retry failed + * to insert anything (an unexpected terminal case). The common recovery now + * isolates the un-ingestable rows and lands the rest, so this should stay at + * zero in practice. */ private _permanentlyDroppedBatches = 0; private readonly _droppedBatchesCounter: Counter; + /** + * Counts batches that took the row-isolation recovery path — a + * `Cannot parse JSON object` failure the sanitizer could not repair, where we + * re-inserted with `input_format_allow_errors_*` so ClickHouse skipped the + * un-ingestable rows and landed the rest. Reliable per-event signal. + */ + private _rowIsolationRecoveries = 0; + private readonly _rowsIsolatedCounter: Counter; + + /** + * Best-effort count of individual rows ClickHouse skipped across those + * row-isolation retries, from the insert summary's `written_rows` when the + * client surfaces it (not always populated under concurrent inserts, so treat + * as a lower bound; `_rowIsolationRecoveries` is the dependable event count). + */ + private _permanentlyDroppedRows = 0; + constructor(config: ClickhouseEventRepositoryConfig) { this._clickhouse = config.clickhouse; this._config = config; @@ -140,6 +158,11 @@ export class ClickhouseEventRepository implements IEventRepository { description: "Batches permanently dropped after an unrecoverable ClickHouse JSON parse error", unit: "batches", }); + this._rowsIsolatedCounter = meter.createCounter("ingest.flush.rows_isolated", { + description: + "Batches that recovered by isolating un-ingestable rows (landed the rest) after a ClickHouse JSON parse error", + unit: "batches", + }); this._flushScheduler = new DynamicFlushScheduler({ name: `task_events_${this._version}`, @@ -194,6 +217,16 @@ export class ClickhouseEventRepository implements IEventRepository { return this._permanentlyDroppedBatches; } + /** Exposed for tests and metrics — batches that took the row-isolation recovery path. */ + get rowIsolationRecoveries() { + return this._rowIsolationRecoveries; + } + + /** Exposed for tests and metrics — best-effort count of individual rows ClickHouse skipped during row-isolation retries. */ + get permanentlyDroppedRows() { + return this._permanentlyDroppedRows; + } + /** * Clamps a start time (in nanoseconds) to now if it's too far in the past. * Returns the clamped value as a bigint. @@ -262,10 +295,10 @@ export class ClickhouseEventRepository implements IEventRepository { ? this._clickhouse.taskEventsV2.insert : this._clickhouse.taskEvents.insert; - const doInsert = async () => { + const doInsert = async (extraSettings?: ClickHouseSettings) => { const [insertError, insertResult] = await insertFn(events, { params: { - clickhouse_settings: this.#getClickhouseInsertSettings(), + clickhouse_settings: { ...this.#getClickhouseInsertSettings(), ...extraSettings }, }, }); if (insertError) throw insertError; @@ -296,10 +329,10 @@ export class ClickhouseEventRepository implements IEventRepository { } async #flushLlmMetricsBatch(flushId: string, rows: LlmMetricsV1Input[]) { - const doInsert = async () => { + const doInsert = async (extraSettings?: ClickHouseSettings) => { const [insertError, insertResult] = await this._clickhouse.llmMetrics.insert(rows, { params: { - clickhouse_settings: this.#getClickhouseInsertSettings(), + clickhouse_settings: { ...this.#getClickhouseInsertSettings(), ...extraSettings }, }, }); if (insertError) throw insertError; @@ -324,28 +357,35 @@ export class ClickhouseEventRepository implements IEventRepository { } /** - * Wraps a ClickHouse insert callable with reactive UTF-16 sanitization. + * Wraps a ClickHouse insert with recovery for `Cannot parse JSON object` + * rejections so one un-ingestable event never drops its whole batch. * - * On a `Cannot parse JSON object` failure: - * 1. Sanitize the batch from `max(0, parsedRowN - 1)` onwards (rows - * before the failing one parsed fine — known good). - * 2. Retry the insert once with the sanitized batch. - * 3. If the retry still fails with the same error class, log loudly, - * increment `permanentlyDroppedBatches`, and return without - * throwing — the scheduler's transient-retry path would just repeat - * the same deterministic failure. + * 1. Try the insert. Healthy batches pay zero recovery cost. + * 2. On a parse error, `sanitizeRows` losslessly repairs what it can in + * place (lone UTF-16 surrogates, out-of-range integers), then retries + * once. A clean retry keeps every row. + * 3. If the sanitizer found nothing, or the retry still hits the same parse + * error (a structurally un-ingestable row, e.g. JSON nested past + * ClickHouse's `input_format_json_max_depth`), retry once more with + * `input_format_allow_errors_*` so ClickHouse skips only the un-parseable + * rows and lands the rest. Verified against ClickHouse 26.2 (the cloud + * version) with the JSONEachRow insert format. + * 4. Only if that row-isolation insert itself fails do we drop the batch, + * and never rethrow a parse error — the scheduler would just repeat the + * same deterministic failure. * - * Non-parse errors propagate unchanged so the scheduler's existing - * backoff/retry behaviour still handles transient network or CH issues. + * Non-parse errors propagate unchanged so the scheduler's backoff/retry still + * handles transient network or CH issues. */ async #insertWithJsonParseRecovery( flushId: string, rows: T[], - doInsert: () => Promise, + doInsert: (extraSettings?: ClickHouseSettings) => Promise, contextLabel: string ): Promise< | { kind: "inserted"; insertResult: unknown } | { kind: "sanitized"; insertResult: unknown } + | { kind: "isolated"; insertResult: unknown; rowsSkipped: number | null } | { kind: "dropped" } > { try { @@ -353,73 +393,92 @@ export class ClickhouseEventRepository implements IEventRepository { } catch (firstError) { if (!isClickHouseJsonParseError(firstError)) throw firstError; - const firstMessage = - typeof firstError === "object" && firstError !== null && "message" in firstError - ? String((firstError as { message?: unknown }).message ?? "") - : String(firstError); - - // Sanitize the whole batch. ClickHouse's `at row N` index is logged - // for observability but not used to slice — its semantics under - // parallel parsing are not stable enough to safely skip rows. + const firstMessage = errorMessage(firstError); const rowHint = parseRowNumberFromError(firstMessage); const { rowsTouched, fieldsSanitized } = sanitizeRows(rows); - // Sanitizer found nothing to fix → retrying the exact same batch is - // guaranteed to hit the same deterministic parse failure. Skip the - // wasted ClickHouse round-trip and drop loudly. Throwing instead would - // hand the failure back to the scheduler's 3× transient-retry loop — - // exactly the retry storm this wrapper is designed to avoid. - if (fieldsSanitized === 0) { - this._permanentlyDroppedBatches += 1; - this._droppedBatchesCounter.add(1, { table: contextLabel }); - logger.error( - "Dropped batch — ClickHouse JSON parse error but sanitizer found nothing to fix", - { - flushId, - contextLabel, - batchSize: rows.length, - clickhouseRowHint: rowHint, - permanentlyDroppedBatches: this._permanentlyDroppedBatches, - sampleRow: JSON.stringify(rows[0] ?? null).slice(0, 1024), - clickhouseError: firstMessage.split("\n")[0], - } - ); - return { kind: "dropped" }; + if (fieldsSanitized > 0) { + logger.warn("Sanitizing batch after ClickHouse JSON parse error", { + flushId, + contextLabel, + batchSize: rows.length, + clickhouseRowHint: rowHint, + rowsTouched, + fieldsSanitized, + clickhouseError: firstMessage.split("\n")[0], + }); + + try { + return { kind: "sanitized", insertResult: await doInsert() }; + } catch (retryError) { + if (!isClickHouseJsonParseError(retryError)) throw retryError; + } } - logger.warn("Sanitizing batch after ClickHouse JSON parse error", { - flushId, - contextLabel, - batchSize: rows.length, - clickhouseRowHint: rowHint, - rowsTouched, - fieldsSanitized, - clickhouseError: firstMessage.split("\n")[0], + return await this.#insertIsolatingBadRows(flushId, rows, doInsert, contextLabel, firstMessage); + } + } + + /** + * Last-resort recovery: re-run the insert with `input_format_allow_errors_*` + * so ClickHouse skips the rows it cannot parse and lands the rest, rather than + * aborting the whole INSERT. Forces a synchronous insert so `written_rows` + * reflects what landed and we can count what was lost. + */ + async #insertIsolatingBadRows( + flushId: string, + rows: T[], + doInsert: (extraSettings?: ClickHouseSettings) => Promise, + contextLabel: string, + firstMessage: string + ): Promise< + { kind: "isolated"; insertResult: unknown; rowsSkipped: number | null } | { kind: "dropped" } + > { + try { + const insertResult = await doInsert({ + input_format_allow_errors_num: String(rows.length), + input_format_allow_errors_ratio: 1, + async_insert: 0, }); - try { - return { kind: "sanitized", insertResult: await doInsert() }; - } catch (retryError) { - if (!isClickHouseJsonParseError(retryError)) throw retryError; - - this._permanentlyDroppedBatches += 1; - this._droppedBatchesCounter.add(1, { table: contextLabel }); - const retryMessage = - typeof retryError === "object" && retryError !== null && "message" in retryError - ? String((retryError as { message?: unknown }).message ?? "") - : String(retryError); - logger.error("Dropped batch after sanitize-retry still hit ClickHouse JSON parse error", { + this._rowIsolationRecoveries += 1; + this._rowsIsolatedCounter.add(1, { table: contextLabel }); + const writtenRows = extractWrittenRows(insertResult); + const rowsSkipped = writtenRows === null ? null : Math.max(0, rows.length - writtenRows); + if (rowsSkipped !== null) { + this._permanentlyDroppedRows += rowsSkipped; + } + + logger.info( + "Isolated un-ingestable rows after ClickHouse JSON parse error — landed the rest of the batch", + { flushId, contextLabel, batchSize: rows.length, - permanentlyDroppedBatches: this._permanentlyDroppedBatches, + rowsSkipped, + rowIsolationRecoveries: this._rowIsolationRecoveries, + permanentlyDroppedRows: this._permanentlyDroppedRows, sampleRow: JSON.stringify(rows[0] ?? null).slice(0, 1024), - firstError: firstMessage.split("\n")[0], - retryError: retryMessage.split("\n")[0], - }); + clickhouseError: firstMessage.split("\n")[0], + } + ); - return { kind: "dropped" }; - } + return { kind: "isolated", insertResult, rowsSkipped }; + } catch (isolationError) { + if (!isClickHouseJsonParseError(isolationError)) throw isolationError; + + this._permanentlyDroppedBatches += 1; + this._droppedBatchesCounter.add(1, { table: contextLabel }); + logger.error("Dropped batch — row-isolation insert failed after ClickHouse JSON parse error", { + flushId, + contextLabel, + batchSize: rows.length, + permanentlyDroppedBatches: this._permanentlyDroppedBatches, + sampleRow: JSON.stringify(rows[0] ?? null).slice(0, 1024), + firstError: firstMessage.split("\n")[0], + isolationError: errorMessage(isolationError).split("\n")[0], + }); + return { kind: "dropped" }; } } @@ -2942,3 +3001,17 @@ function formatClickhouseUnsignedIntegerString(value: number | bigint): string { return Math.floor(value).toString(); } + +function errorMessage(err: unknown): string { + return typeof err === "object" && err !== null && "message" in err + ? String((err as { message?: unknown }).message ?? "") + : String(err); +} + +function extractWrittenRows(insertResult: unknown): number | null { + const written = (insertResult as { summary?: { written_rows?: string } } | null | undefined) + ?.summary?.written_rows; + if (written === undefined) return null; + const parsed = Number(written); + return Number.isFinite(parsed) ? parsed : null; +} diff --git a/apps/webapp/test/clickhouseEventRepositoryJsonRecovery.test.ts b/apps/webapp/test/clickhouseEventRepositoryJsonRecovery.test.ts new file mode 100644 index 00000000000..06786126485 --- /dev/null +++ b/apps/webapp/test/clickhouseEventRepositoryJsonRecovery.test.ts @@ -0,0 +1,123 @@ +import { ClickHouse, type TaskEventV2Input } from "@internal/clickhouse"; +import { clickhouseTest } from "@internal/testcontainers"; +import { describe, expect } from "vitest"; +import { z } from "zod"; +import { + ClickhouseEventRepository, + convertDateToClickhouseDateTime, +} from "~/v3/eventRepository/clickhouseEventRepository.server"; + +const TIMEOUT_MS = 60_000; + +function deeplyNested(depth: number): Record { + let node: Record = { leaf: 1 }; + for (let i = 0; i < depth; i++) { + node = { [`k${i}`]: node }; + } + return node; +} + +function startTime(baseMs: number, offsetMs: number): string { + const ns = ((BigInt(baseMs) + BigInt(offsetMs)) * 1_000_000n).toString(); + return `${ns.substring(0, 10)}.${ns.substring(10)}`; +} + +describe("ClickhouseEventRepository JSON parse recovery", () => { + clickhouseTest( + "lands the good events when one event in the batch has ClickHouse-unparseable attributes", + async ({ clickhouseContainer }) => { + const clickhouse = new ClickHouse({ + url: clickhouseContainer.getConnectionUrl(), + logLevel: "error", + }); + + const repository = new ClickhouseEventRepository({ + clickhouse, + version: "v2", + insertStrategy: "insert", + batchSize: 100, + flushInterval: 200, + }); + + const environmentId = "env_json_recovery_test"; + const organizationId = "org_json_recovery_test"; + const projectId = "proj_json_recovery_test"; + const traceId = "b".repeat(32); + const baseMs = Date.now(); + const expiresAt = convertDateToClickhouseDateTime( + new Date(baseMs + 365 * 24 * 60 * 60 * 1000) + ); + + function makeRow(i: number, attributes: unknown): TaskEventV2Input { + return { + environment_id: environmentId, + organization_id: organizationId, + project_id: projectId, + task_identifier: "json-recovery-task", + run_id: `run_${i}`, + start_time: startTime(baseMs, i), + duration: "1000000", + trace_id: traceId, + span_id: `span_recovery_${String(i).padStart(6, "0")}`, + parent_span_id: "", + message: `event ${i}`, + kind: "SPAN", + status: "OK", + attributes, + metadata: "{}", + expires_at: expiresAt, + }; + } + + const goodSpanIds: string[] = []; + let poisonSpanId = ""; + const rows: TaskEventV2Input[] = []; + for (let i = 0; i < 5; i++) { + const isPoison = i === 2; + const row = makeRow(i, isPoison ? deeplyNested(1500) : { ok: true, i }); + rows.push(row); + if (isPoison) { + poisonSpanId = row.span_id; + } else { + goodSpanIds.push(row.span_id); + } + } + + try { + (repository as any).addToBatch(rows); + + const queryEvents = clickhouse.reader.query({ + name: "event-recovery-check", + query: + "SELECT span_id FROM trigger_dev.task_events_v2 WHERE environment_id = {env_id:String}", + schema: z.object({ span_id: z.string() }), + params: z.object({ env_id: z.string() }), + }); + + const landedIds = await vi.waitFor( + async () => { + const [queryError, resultRows] = await queryEvents({ env_id: environmentId }); + expect(queryError).toBeNull(); + const ids = new Set((resultRows ?? []).map((r) => r.span_id)); + for (const id of goodSpanIds) { + expect(ids.has(id)).toBe(true); + } + return ids; + }, + { timeout: 30_000, interval: 250 } + ); + + for (const id of goodSpanIds) { + expect(landedIds.has(id)).toBe(true); + } + expect(landedIds.has(poisonSpanId)).toBe(false); + + expect(repository.permanentlyDroppedBatches).toBe(0); + expect(repository.rowIsolationRecoveries).toBeGreaterThanOrEqual(1); + } finally { + await (repository as any)._flushScheduler?.shutdown?.(); + } + }, + TIMEOUT_MS + ); +}); diff --git a/apps/webapp/test/runsReplicationBenchmark.producer.ts b/apps/webapp/test/runsReplicationBenchmark.producer.ts index 547d1318c46..efa981a3bf6 100644 --- a/apps/webapp/test/runsReplicationBenchmark.producer.ts +++ b/apps/webapp/test/runsReplicationBenchmark.producer.ts @@ -15,6 +15,16 @@ interface ProducerConfig { numRuns: number; errorRate: number; // 0.07 = 7% batchSize: number; + poisonRate?: number; + poisonDepth?: number; +} + +function deeplyNestedOutput(depth: number): Record { + let node: Record = { leaf: 1 }; + for (let i = 0; i < depth; i++) { + node = { [`k${i}`]: node }; + } + return node; } // Error templates for realistic variety @@ -108,6 +118,9 @@ async function runProducer(config: ProducerConfig) { const startTime = performance.now(); let created = 0; let withErrors = 0; + let poisoned = 0; + const poisonRate = config.poisonRate ?? 0; + const poisonDepth = config.poisonDepth ?? 1500; // Process in batches to avoid overwhelming the database for (let batch = 0; batch < Math.ceil(config.numRuns / config.batchSize); batch++) { @@ -120,6 +133,8 @@ async function runProducer(config: ProducerConfig) { const hasError = Math.random() < config.errorRate; const status = hasError ? "COMPLETED_WITH_ERRORS" : "COMPLETED_SUCCESSFULLY"; + const isPoison = Math.random() < poisonRate; + const runData: any = { friendlyId: `run_bench_${Date.now()}_${i}`, taskIdentifier: `benchmark-task-${i % 10}`, // Vary task identifiers @@ -142,6 +157,12 @@ async function runProducer(config: ProducerConfig) { withErrors++; } + if (isPoison) { + runData.output = JSON.stringify(deeplyNestedOutput(poisonDepth)); + runData.outputType = "application/json"; + poisoned++; + } + runs.push(runData); } @@ -168,6 +189,7 @@ async function runProducer(config: ProducerConfig) { console.log(`[Producer] Completed:`); console.log(` - Total runs: ${created}`); console.log(` - With errors: ${withErrors} (${((withErrors / created) * 100).toFixed(1)}%)`); + console.log(` - Poisoned: ${poisoned} (${((poisoned / created) * 100).toFixed(1)}%)`); console.log(` - Duration: ${duration.toFixed(0)}ms`); console.log(` - Throughput: ${throughput.toFixed(0)} runs/sec`); @@ -178,6 +200,7 @@ async function runProducer(config: ProducerConfig) { stats: { created, withErrors, + poisoned, duration, throughput, }, diff --git a/apps/webapp/test/runsReplicationJsonRecoveryBenchmark.test.ts b/apps/webapp/test/runsReplicationJsonRecoveryBenchmark.test.ts new file mode 100644 index 00000000000..8186e145ec6 --- /dev/null +++ b/apps/webapp/test/runsReplicationJsonRecoveryBenchmark.test.ts @@ -0,0 +1,267 @@ +import { ClickHouse } from "@internal/clickhouse"; +import { replicationContainerTest } from "@internal/testcontainers"; +import { fork } from "node:child_process"; +import path from "node:path"; +import { performance } from "node:perf_hooks"; +import { setTimeout } from "node:timers/promises"; +import { z } from "zod"; +import { RunsReplicationService } from "~/services/runsReplicationService.server"; +import { TestReplicationClickhouseFactory } from "./utils/testReplicationClickhouseFactory"; +import { createInMemoryMetrics, createInMemoryTracing } from "./utils/tracing"; + +vi.setConfig({ testTimeout: 300_000 }); + +const CONFIG = { + NUM_RUNS: parseInt(process.env.BENCHMARK_NUM_RUNS || "5000", 10), + PRODUCER_BATCH_SIZE: 100, + FLUSH_BATCH_SIZE: 50, + FLUSH_INTERVAL_MS: 100, + MAX_FLUSH_CONCURRENCY: 4, + REPLICATION_TIMEOUT_MS: 180_000, + POISON_RATE: parseFloat(process.env.BENCHMARK_POISON_RATE || "0.05"), +}; + +class ELUMonitor { + private samples: number[] = []; + private interval: NodeJS.Timeout | null = null; + + start(intervalMs = 100) { + this.samples = []; + performance.eventLoopUtilization(); + this.interval = setInterval(() => { + this.samples.push(performance.eventLoopUtilization().utilization * 100); + }, intervalMs); + } + + stop() { + if (this.interval) { + clearInterval(this.interval); + this.interval = null; + } + if (this.samples.length === 0) return { mean: 0, p50: 0, p95: 0, p99: 0, samples: 0 }; + const sorted = [...this.samples].sort((a, b) => a - b); + const mean = sorted.reduce((s, v) => s + v, 0) / sorted.length; + return { + mean, + p50: sorted[Math.floor(sorted.length * 0.5)], + p95: sorted[Math.floor(sorted.length * 0.95)], + p99: sorted[Math.floor(sorted.length * 0.99)], + samples: sorted.length, + }; + } +} + +function runProducer(config: { + postgresUrl: string; + organizationId: string; + projectId: string; + environmentId: string; + numRuns: number; + errorRate: number; + batchSize: number; + poisonRate: number; + poisonDepth: number; +}): Promise<{ created: number; withErrors: number; poisoned: number; duration: number }> { + return new Promise((resolve, reject) => { + const producerPath = path.join(__dirname, "runsReplicationBenchmark.producer.ts"); + const child = fork(producerPath, [JSON.stringify(config)], { + stdio: ["ignore", "pipe", "pipe", "ipc"], + execArgv: ["-r", "tsx/cjs"], + }); + child.stdout?.on("data", (d) => console.log(d.toString().trim())); + child.stderr?.on("data", (d) => console.error(d.toString().trim())); + child.on("message", (m: any) => { + if (m.type === "complete") resolve(m.stats); + else if (m.type === "error") reject(new Error(m.error)); + }); + child.on("error", reject); + child.on("exit", (code) => { + if (code !== 0) reject(new Error(`Producer exited with code ${code}`)); + }); + }); +} + +async function waitForCount( + clickhouse: ClickHouse, + organizationId: string, + expectedCount: number, + timeoutMs: number +): Promise<{ duration: number; count: number }> { + const startTime = performance.now(); + const deadline = startTime + timeoutMs; + const queryRuns = clickhouse.reader.query({ + name: "bench-count", + query: + "SELECT count(*) as count FROM trigger_dev.task_runs_v2 WHERE organization_id = {org_id:String}", + schema: z.object({ count: z.number() }), + params: z.object({ org_id: z.string() }), + }); + while (performance.now() < deadline) { + const [error, result] = await queryRuns({ org_id: organizationId }); + if (error) throw new Error(`Failed to query ClickHouse: ${error.message}`); + const count = result?.[0]?.count || 0; + if (count >= expectedCount) return { duration: performance.now() - startTime, count }; + await setTimeout(500); + } + const [, result] = await queryRuns({ org_id: organizationId }); + return { duration: performance.now() - startTime, count: result?.[0]?.count || 0 }; +} + +async function runScenario( + name: string, + poisonRate: number, + ctx: { clickhouseContainer: any; redisOptions: any; postgresContainer: any; prisma: any } +) { + const { clickhouseContainer, redisOptions, postgresContainer, prisma } = ctx; + + const organization = await prisma.organization.create({ + data: { title: `bench-${name}`, slug: `bench-${name}` }, + }); + const project = await prisma.project.create({ + data: { + name: `bench-${name}`, + slug: `bench-${name}`, + organizationId: organization.id, + externalRef: `bench-${name}`, + }, + }); + const runtimeEnvironment = await prisma.runtimeEnvironment.create({ + data: { + slug: `bench-${name}`, + type: "DEVELOPMENT", + projectId: project.id, + organizationId: organization.id, + apiKey: `bench-${name}`, + pkApiKey: `bench-${name}`, + shortcode: `bench-${name}`, + }, + }); + + const clickhouse = new ClickHouse({ + url: clickhouseContainer.getConnectionUrl(), + name: `bench-${name}`, + compression: { request: true }, + logLevel: "error", + }); + + const { tracer } = createInMemoryTracing(); + const metricsHelper = createInMemoryMetrics(); + + const service = new RunsReplicationService({ + clickhouseFactory: new TestReplicationClickhouseFactory(clickhouse), + pgConnectionUrl: postgresContainer.getConnectionUri(), + serviceName: `bench-${name}`, + slotName: `bench_${name.replace(/-/g, "_")}`, + publicationName: `bench_${name.replace(/-/g, "_")}_pub`, + redisOptions, + maxFlushConcurrency: CONFIG.MAX_FLUSH_CONCURRENCY, + flushIntervalMs: CONFIG.FLUSH_INTERVAL_MS, + flushBatchSize: CONFIG.FLUSH_BATCH_SIZE, + leaderLockTimeoutMs: 10000, + leaderLockExtendIntervalMs: 2000, + ackIntervalSeconds: 10, + tracer, + meter: metricsHelper.meter, + logLevel: "error", + }); + + await service.start(); + + const elu = new ELUMonitor(); + elu.start(100); + + let producerStats!: { created: number; withErrors: number; poisoned: number; duration: number }; + let replication!: { duration: number; count: number }; + let eluStats!: ReturnType; + + try { + producerStats = await runProducer({ + postgresUrl: postgresContainer.getConnectionUri(), + organizationId: organization.id, + projectId: project.id, + environmentId: runtimeEnvironment.id, + numRuns: CONFIG.NUM_RUNS, + errorRate: 0.07, + batchSize: CONFIG.PRODUCER_BATCH_SIZE, + poisonRate, + poisonDepth: 1500, + }); + + const expectedLanded = producerStats.created - producerStats.poisoned; + replication = await waitForCount( + clickhouse, + organization.id, + expectedLanded, + CONFIG.REPLICATION_TIMEOUT_MS + ); + } finally { + eluStats = elu.stop(); + await service.stop(); + await metricsHelper.shutdown(); + } + + const throughput = (replication.count / replication.duration) * 1000; + const expectedLanded = producerStats.created - producerStats.poisoned; + + console.log(`\n${"=".repeat(72)}`); + console.log(`SCENARIO: ${name} (poison rate ${(poisonRate * 100).toFixed(1)}%)`); + console.log(`${"=".repeat(72)}`); + console.log(`Produced: ${producerStats.created} runs (${producerStats.poisoned} poisoned)`); + console.log(`Landed in CH: ${replication.count} / expected ${expectedLanded}`); + console.log(`Repl dur: ${replication.duration.toFixed(0)}ms`); + console.log(`Throughput: ${throughput.toFixed(0)} runs/sec`); + console.log(`Row-isolation recoveries: ${service.rowIsolationRecoveries}`); + console.log(`Dropped rows (best-effort): ${service.permanentlyDroppedRows}`); + console.log(`Dropped batches (whole): ${service.permanentlyDroppedBatches}`); + console.log(`ELU mean=${eluStats.mean.toFixed(2)}% p50=${eluStats.p50.toFixed(2)}% p95=${eluStats.p95.toFixed(2)}% p99=${eluStats.p99.toFixed(2)}% (${eluStats.samples} samples)`); + console.log(`${"=".repeat(72)}\n`); + + return { name, poisonRate, producerStats, replication, eluStats, throughput, expectedLanded, service }; +} + +describe("RunsReplicationService JSON-recovery ELU benchmark", () => { + replicationContainerTest.skipIf(process.env.BENCHMARKS_ENABLED !== "1")( + "measures ELU on the healthy hot path vs the row-isolation recovery path", + async ({ clickhouseContainer, redisOptions, postgresContainer, prisma }) => { + await prisma.$executeRawUnsafe(`ALTER TABLE public."TaskRun" REPLICA IDENTITY FULL;`); + + const healthy = await runScenario("healthy-0pct", 0, { + clickhouseContainer, + redisOptions, + postgresContainer, + prisma, + }); + + const poisoned = await runScenario("poison", CONFIG.POISON_RATE, { + clickhouseContainer, + redisOptions, + postgresContainer, + prisma, + }); + + const eluMeanDelta = + ((poisoned.eluStats.mean - healthy.eluStats.mean) / healthy.eluStats.mean) * 100; + const eluP99Delta = + ((poisoned.eluStats.p99 - healthy.eluStats.p99) / healthy.eluStats.p99) * 100; + + console.log(`\n${"=".repeat(72)}`); + console.log("COMPARISON (healthy 0% -> poison)"); + console.log(`${"=".repeat(72)}`); + console.log( + `ELU mean: ${healthy.eluStats.mean.toFixed(2)}% -> ${poisoned.eluStats.mean.toFixed(2)}% (${eluMeanDelta > 0 ? "+" : ""}${eluMeanDelta.toFixed(1)}%)` + ); + console.log( + `ELU p99: ${healthy.eluStats.p99.toFixed(2)}% -> ${poisoned.eluStats.p99.toFixed(2)}% (${eluP99Delta > 0 ? "+" : ""}${eluP99Delta.toFixed(1)}%)` + ); + console.log(`${"=".repeat(72)}\n`); + + expect(healthy.replication.count).toBe(healthy.expectedLanded); + expect(healthy.service.rowIsolationRecoveries).toBe(0); + expect(healthy.service.permanentlyDroppedBatches).toBe(0); + + expect(poisoned.replication.count).toBe(poisoned.expectedLanded); + expect(poisoned.service.permanentlyDroppedBatches).toBe(0); + expect(poisoned.service.rowIsolationRecoveries).toBeGreaterThanOrEqual(1); + } + ); +}); diff --git a/apps/webapp/test/runsReplicationService.part10.test.ts b/apps/webapp/test/runsReplicationService.part10.test.ts new file mode 100644 index 00000000000..3f269430c42 --- /dev/null +++ b/apps/webapp/test/runsReplicationService.part10.test.ts @@ -0,0 +1,143 @@ +import { ClickHouse } from "@internal/clickhouse"; +import { replicationContainerTest } from "@internal/testcontainers"; +import { z } from "zod"; +import { RunsReplicationService } from "~/services/runsReplicationService.server"; +import { TestReplicationClickhouseFactory } from "./utils/testReplicationClickhouseFactory"; +import { createInMemoryTracing } from "./utils/tracing"; + +vi.setConfig({ testTimeout: 60_000 }); + +function deeplyNested(depth: number): Record { + let node: Record = { leaf: 1 }; + for (let i = 0; i < depth; i++) { + node = { [`k${i}`]: node }; + } + return node; +} + +describe("RunsReplicationService (part 10/10) — JSON parse recovery", () => { + replicationContainerTest( + "lands the good runs when one run in the batch has ClickHouse-unparseable JSON output", + async ({ clickhouseContainer, redisOptions, postgresContainer, prisma }) => { + await prisma.$executeRawUnsafe(`ALTER TABLE public."TaskRun" REPLICA IDENTITY FULL;`); + + const clickhouse = new ClickHouse({ + url: clickhouseContainer.getConnectionUrl(), + name: "runs-replication", + compression: { request: true }, + logLevel: "warn", + }); + + const { tracer } = createInMemoryTracing(); + + const runsReplicationService = new RunsReplicationService({ + clickhouseFactory: new TestReplicationClickhouseFactory(clickhouse), + pgConnectionUrl: postgresContainer.getConnectionUri(), + serviceName: "runs-replication", + slotName: "task_runs_to_clickhouse_v1", + publicationName: "task_runs_to_clickhouse_v1_publication", + redisOptions, + maxFlushConcurrency: 1, + flushIntervalMs: 500, + flushBatchSize: 50, + leaderLockTimeoutMs: 5000, + leaderLockExtendIntervalMs: 1000, + ackIntervalSeconds: 5, + tracer, + logLevel: "warn", + }); + + await runsReplicationService.start(); + + const organization = await prisma.organization.create({ + data: { title: "test", slug: "test" }, + }); + const project = await prisma.project.create({ + data: { + name: "test", + slug: "test", + organizationId: organization.id, + externalRef: "test", + }, + }); + const runtimeEnvironment = await prisma.runtimeEnvironment.create({ + data: { + slug: "test", + type: "DEVELOPMENT", + projectId: project.id, + organizationId: organization.id, + apiKey: "test", + pkApiKey: "test", + shortcode: "test", + }, + }); + + const goodRunIds: string[] = []; + let poisonRunId = ""; + + for (let i = 0; i < 5; i++) { + const isPoison = i === 2; + const output = isPoison + ? JSON.stringify(deeplyNested(1500)) + : JSON.stringify({ ok: true, i }); + + const run = await prisma.taskRun.create({ + data: { + friendlyId: `run_batchdrop_${i}`, + taskIdentifier: "my-task", + payload: JSON.stringify({ i }), + payloadType: "application/json", + output, + outputType: "application/json", + traceId: `trace_${i}`, + spanId: `span_${i}`, + queue: "test", + status: "COMPLETED_SUCCESSFULLY", + runtimeEnvironmentId: runtimeEnvironment.id, + projectId: project.id, + organizationId: organization.id, + environmentType: "DEVELOPMENT", + engine: "V2", + }, + }); + + if (isPoison) { + poisonRunId = run.id; + } else { + goodRunIds.push(run.id); + } + } + + const queryRuns = clickhouse.reader.query({ + name: "runs-replication-batchdrop", + query: + "SELECT run_id FROM trigger_dev.task_runs_v2 WHERE organization_id = {org_id:String}", + schema: z.object({ run_id: z.string() }), + params: z.object({ org_id: z.string() }), + }); + + const landedIds = await vi.waitFor( + async () => { + const [queryError, rows] = await queryRuns({ org_id: organization.id }); + expect(queryError).toBeNull(); + const ids = new Set((rows ?? []).map((r) => r.run_id)); + for (const id of goodRunIds) { + expect(ids.has(id)).toBe(true); + } + return ids; + }, + { timeout: 30_000, interval: 250 } + ); + + for (const id of goodRunIds) { + expect(landedIds.has(id)).toBe(true); + } + expect(landedIds.has(poisonRunId)).toBe(false); + + expect(runsReplicationService.permanentlyDroppedBatches).toBe(0); + expect(runsReplicationService.rowIsolationRecoveries).toBeGreaterThanOrEqual(1); + + await runsReplicationService.stop(); + } + ); +}); From e63fe85e44ba3c3ed3310b451dc8788993c57c7d Mon Sep 17 00:00:00 2001 From: Eric Allam Date: Fri, 24 Jul 2026 09:29:53 +0100 Subject: [PATCH 2/9] chore(webapp): rename batch row-isolation metric and emit run-replication drop/isolation counters Rename the event repository counter from ingest.flush.rows_isolated to ingest.flush.batches_row_isolated (it counts recovered batches, not rows, and the OTLP->Prometheus suffix would read as a row count otherwise). Add matching runs_replication.batches_row_isolated and runs_replication.batches_dropped OTEL counters so run-replication drops and isolations are alertable in production, not just readable in tests. --- .../services/runsReplicationService.server.ts | 26 ++++++++++++- .../clickhouseEventRepository.server.ts | 37 ++++++++++++------- ...nsReplicationJsonRecoveryBenchmark.test.ts | 15 +++++++- 3 files changed, 61 insertions(+), 17 deletions(-) diff --git a/apps/webapp/app/services/runsReplicationService.server.ts b/apps/webapp/app/services/runsReplicationService.server.ts index 5ffb38bd5f8..9eb3b895d07 100644 --- a/apps/webapp/app/services/runsReplicationService.server.ts +++ b/apps/webapp/app/services/runsReplicationService.server.ts @@ -209,6 +209,8 @@ export class RunsReplicationService { private _payloadsInsertedCounter: Counter; private _insertRetriesCounter: Counter; private _eventsProcessedCounter: Counter; + private _rowIsolatedBatchesCounter: Counter; + private _droppedBatchesCounter: Counter; private _flushDurationHistogram: Histogram; public readonly events: EventEmitter; @@ -262,6 +264,20 @@ export class RunsReplicationService { description: "Replication events processed (inserts, updates, deletes)", }); + this._rowIsolatedBatchesCounter = this._meter.createCounter( + "runs_replication.batches_row_isolated", + { + description: + "Batches recovered by isolating un-ingestable rows (landed the rest) after a ClickHouse JSON parse error", + unit: "batches", + } + ); + + this._droppedBatchesCounter = this._meter.createCounter("runs_replication.batches_dropped", { + description: "Batches permanently dropped after an unrecoverable ClickHouse JSON parse error", + unit: "batches", + }); + this._flushDurationHistogram = this._meter.createHistogram( "runs_replication.flush_duration_ms", { @@ -1187,7 +1203,13 @@ export class RunsReplicationService { } } - return await this.#insertIsolatingBadRows(rows, doInsert, contextLabel, attempt, firstMessage); + return await this.#insertIsolatingBadRows( + rows, + doInsert, + contextLabel, + attempt, + firstMessage + ); } } @@ -1214,6 +1236,7 @@ export class RunsReplicationService { }); this._rowIsolationRecoveries += 1; + this._rowIsolatedBatchesCounter.add(1, { table: contextLabel }); const writtenRows = extractWrittenRows(insertResult); const rowsSkipped = writtenRows === null ? null : Math.max(0, rows.length - writtenRows); if (rowsSkipped !== null) { @@ -1239,6 +1262,7 @@ export class RunsReplicationService { if (!isClickHouseJsonParseError(isolationError)) throw isolationError; this._permanentlyDroppedBatches += 1; + this._droppedBatchesCounter.add(1, { table: contextLabel }); this.logger.error( "Dropped batch — row-isolation insert failed after ClickHouse JSON parse error", { diff --git a/apps/webapp/app/v3/eventRepository/clickhouseEventRepository.server.ts b/apps/webapp/app/v3/eventRepository/clickhouseEventRepository.server.ts index 417b9bffa7f..8bee56dba82 100644 --- a/apps/webapp/app/v3/eventRepository/clickhouseEventRepository.server.ts +++ b/apps/webapp/app/v3/eventRepository/clickhouseEventRepository.server.ts @@ -137,7 +137,7 @@ export class ClickhouseEventRepository implements IEventRepository { * un-ingestable rows and landed the rest. Reliable per-event signal. */ private _rowIsolationRecoveries = 0; - private readonly _rowsIsolatedCounter: Counter; + private readonly _rowIsolatedBatchesCounter: Counter; /** * Best-effort count of individual rows ClickHouse skipped across those @@ -158,9 +158,9 @@ export class ClickhouseEventRepository implements IEventRepository { description: "Batches permanently dropped after an unrecoverable ClickHouse JSON parse error", unit: "batches", }); - this._rowsIsolatedCounter = meter.createCounter("ingest.flush.rows_isolated", { + this._rowIsolatedBatchesCounter = meter.createCounter("ingest.flush.batches_row_isolated", { description: - "Batches that recovered by isolating un-ingestable rows (landed the rest) after a ClickHouse JSON parse error", + "Batches recovered by isolating un-ingestable rows (landed the rest) after a ClickHouse JSON parse error", unit: "batches", }); @@ -415,7 +415,13 @@ export class ClickhouseEventRepository implements IEventRepository { } } - return await this.#insertIsolatingBadRows(flushId, rows, doInsert, contextLabel, firstMessage); + return await this.#insertIsolatingBadRows( + flushId, + rows, + doInsert, + contextLabel, + firstMessage + ); } } @@ -442,7 +448,7 @@ export class ClickhouseEventRepository implements IEventRepository { }); this._rowIsolationRecoveries += 1; - this._rowsIsolatedCounter.add(1, { table: contextLabel }); + this._rowIsolatedBatchesCounter.add(1, { table: contextLabel }); const writtenRows = extractWrittenRows(insertResult); const rowsSkipped = writtenRows === null ? null : Math.max(0, rows.length - writtenRows); if (rowsSkipped !== null) { @@ -469,15 +475,18 @@ export class ClickhouseEventRepository implements IEventRepository { this._permanentlyDroppedBatches += 1; this._droppedBatchesCounter.add(1, { table: contextLabel }); - logger.error("Dropped batch — row-isolation insert failed after ClickHouse JSON parse error", { - flushId, - contextLabel, - batchSize: rows.length, - permanentlyDroppedBatches: this._permanentlyDroppedBatches, - sampleRow: JSON.stringify(rows[0] ?? null).slice(0, 1024), - firstError: firstMessage.split("\n")[0], - isolationError: errorMessage(isolationError).split("\n")[0], - }); + logger.error( + "Dropped batch — row-isolation insert failed after ClickHouse JSON parse error", + { + flushId, + contextLabel, + batchSize: rows.length, + permanentlyDroppedBatches: this._permanentlyDroppedBatches, + sampleRow: JSON.stringify(rows[0] ?? null).slice(0, 1024), + firstError: firstMessage.split("\n")[0], + isolationError: errorMessage(isolationError).split("\n")[0], + } + ); return { kind: "dropped" }; } } diff --git a/apps/webapp/test/runsReplicationJsonRecoveryBenchmark.test.ts b/apps/webapp/test/runsReplicationJsonRecoveryBenchmark.test.ts index 8186e145ec6..254237a6022 100644 --- a/apps/webapp/test/runsReplicationJsonRecoveryBenchmark.test.ts +++ b/apps/webapp/test/runsReplicationJsonRecoveryBenchmark.test.ts @@ -213,10 +213,21 @@ async function runScenario( console.log(`Row-isolation recoveries: ${service.rowIsolationRecoveries}`); console.log(`Dropped rows (best-effort): ${service.permanentlyDroppedRows}`); console.log(`Dropped batches (whole): ${service.permanentlyDroppedBatches}`); - console.log(`ELU mean=${eluStats.mean.toFixed(2)}% p50=${eluStats.p50.toFixed(2)}% p95=${eluStats.p95.toFixed(2)}% p99=${eluStats.p99.toFixed(2)}% (${eluStats.samples} samples)`); + console.log( + `ELU mean=${eluStats.mean.toFixed(2)}% p50=${eluStats.p50.toFixed(2)}% p95=${eluStats.p95.toFixed(2)}% p99=${eluStats.p99.toFixed(2)}% (${eluStats.samples} samples)` + ); console.log(`${"=".repeat(72)}\n`); - return { name, poisonRate, producerStats, replication, eluStats, throughput, expectedLanded, service }; + return { + name, + poisonRate, + producerStats, + replication, + eluStats, + throughput, + expectedLanded, + service, + }; } describe("RunsReplicationService JSON-recovery ELU benchmark", () => { From 837b91a96d1b3699b6669d93f051630916a1e1c3 Mon Sep 17 00:00:00 2001 From: Eric Allam Date: Fri, 24 Jul 2026 10:45:47 +0100 Subject: [PATCH 3/9] refactor(webapp): share JSON-parse recovery and keep poison rows with their JSON stripped Extract the Cannot-parse-JSON recovery into one helper shared by the run replication and trace/event writers instead of a near-duplicate copy in each. Recovery now isolates the un-ingestable rows by bisection and re-inserts each with its JSON column emptied, so the row still lands: a run keeps its terminal status and a span keeps its place in the trace, and only the un-ingestable content is dropped. Clean rows land in full; a row that cannot parse even stripped is dropped and counted. --- ...uns-list-batch-drop-on-unparseable-json.md | 2 +- .../services/runsReplicationService.server.ts | 296 ++++++------------ .../clickhouseEventRepository.server.ts | 263 +++++----------- .../sanitizeRowsOnParseError.server.ts | 148 +++++++++ ...ckhouseEventRepositoryJsonRecovery.test.ts | 23 +- ...nsReplicationJsonRecoveryBenchmark.test.ts | 10 +- .../runsReplicationService.part10.test.ts | 26 +- 7 files changed, 370 insertions(+), 398 deletions(-) diff --git a/.server-changes/fix-runs-list-batch-drop-on-unparseable-json.md b/.server-changes/fix-runs-list-batch-drop-on-unparseable-json.md index 2f35f93733e..e6fa47e1a88 100644 --- a/.server-changes/fix-runs-list-batch-drop-on-unparseable-json.md +++ b/.server-changes/fix-runs-list-batch-drop-on-unparseable-json.md @@ -3,4 +3,4 @@ area: webapp type: fix --- -Fixed a rare case where a single run or span carrying data that could not be ingested would make other runs or trace events in the same batch go missing from the runs list, traces, and logs. Now only the affected item is dropped and everything else is stored normally. +Fixed a rare case where a single run or span carrying data that could not be ingested would make other runs or trace events in the same batch go missing from the runs list, traces, and logs. Now the whole batch is kept: the affected item still appears (a run keeps its status, a span keeps its place in the trace) with only its un-ingestable content dropped, and everything else is stored normally. diff --git a/apps/webapp/app/services/runsReplicationService.server.ts b/apps/webapp/app/services/runsReplicationService.server.ts index 9eb3b895d07..bf28b67cd41 100644 --- a/apps/webapp/app/services/runsReplicationService.server.ts +++ b/apps/webapp/app/services/runsReplicationService.server.ts @@ -7,6 +7,8 @@ import { composeTaskRunVersion, getPayloadField, getTaskRunField, + PAYLOAD_INDEX, + TASK_RUN_INDEX, } from "@internal/clickhouse"; import { type RedisOptions } from "@internal/redis"; import { @@ -42,9 +44,8 @@ import { detectBadJsonStrings } from "~/utils/detectBadJsonStrings"; import { calculateErrorFingerprint } from "~/utils/errorFingerprinting"; import { baseWorkerQueue } from "~/runEngine/concerns/workerQueueSplit.server"; import { - isClickHouseJsonParseError, - parseRowNumberFromError, - sanitizeRows, + insertWithJsonParseRecovery, + type JsonParseRecoveryOutcome, } from "~/v3/eventRepository/sanitizeRowsOnParseError.server"; interface TransactionEvent { @@ -176,28 +177,30 @@ export class RunsReplicationService { private _disableErrorFingerprinting: boolean; /** - * Counts batches dropped whole because even the row-isolation retry failed - * to insert anything (an unexpected terminal case). The common recovery now - * isolates the un-ingestable rows and lands the rest, so this should stay at - * zero in practice. Counter only — does not gate behaviour. + * Counts batches where every row was un-ingestable even with its JSON + * stripped, so nothing landed. Row isolation lands anything strippable, so + * this should stay at zero; a non-zero value means the recovery itself is + * failing. Counter only, does not gate behaviour. */ private _permanentlyDroppedBatches = 0; /** - * Counts batches that took the row-isolation recovery path — a + * Counts batches that took the row-isolation recovery path: a * `Cannot parse JSON object` failure the sanitizer could not repair, where we - * re-inserted with `input_format_allow_errors_*` so ClickHouse skipped the - * un-ingestable rows and landed the rest. Reliable per-event signal that user - * data is hitting the ceiling. + * bisected to the poison rows and landed the batch with their JSON stripped. + * Reliable per-event signal that user data is hitting the ceiling. */ private _rowIsolationRecoveries = 0; /** - * Best-effort count of individual rows ClickHouse skipped across those - * row-isolation retries, derived from the insert summary's `written_rows` - * when the client surfaces it (it is not always populated under concurrent - * inserts, so treat this as a lower bound; `_rowIsolationRecoveries` is the - * dependable event count). + * Counts rows that landed with their un-ingestable JSON column(s) stripped + * (the run kept its status, only the output/payload content was lost). + */ + private _rowsStripped = 0; + + /** + * Counts rows dropped entirely because they could not be parsed even with + * their JSON stripped. The true data-loss signal; expected to stay near zero. */ private _permanentlyDroppedRows = 0; @@ -210,6 +213,8 @@ export class RunsReplicationService { private _insertRetriesCounter: Counter; private _eventsProcessedCounter: Counter; private _rowIsolatedBatchesCounter: Counter; + private _rowsStrippedCounter: Counter; + private _rowsDroppedCounter: Counter; private _droppedBatchesCounter: Counter; private _flushDurationHistogram: Histogram; @@ -273,8 +278,20 @@ export class RunsReplicationService { } ); + this._rowsStrippedCounter = this._meter.createCounter("runs_replication.rows_stripped", { + description: + "Rows landed with their un-ingestable JSON stripped (kept the row, lost only the JSON content)", + unit: "rows", + }); + + this._rowsDroppedCounter = this._meter.createCounter("runs_replication.rows_dropped", { + description: + "Rows dropped entirely because they could not parse even with their JSON stripped", + unit: "rows", + }); + this._droppedBatchesCounter = this._meter.createCounter("runs_replication.batches_dropped", { - description: "Batches permanently dropped after an unrecoverable ClickHouse JSON parse error", + description: "Batches where every row was un-ingestable even with its JSON stripped", unit: "batches", }); @@ -445,7 +462,7 @@ export class RunsReplicationService { }); } - /** Exposed for tests and metrics — total batches lost to unrecoverable parse errors. */ + /** Exposed for tests and metrics — batches where nothing landed even after stripping JSON. */ get permanentlyDroppedBatches() { return this._permanentlyDroppedBatches; } @@ -455,7 +472,12 @@ export class RunsReplicationService { return this._rowIsolationRecoveries; } - /** Exposed for tests and metrics — best-effort count of individual rows ClickHouse skipped during row-isolation retries. */ + /** Exposed for tests and metrics — rows that landed with their un-ingestable JSON stripped. */ + get rowsStripped() { + return this._rowsStripped; + } + + /** Exposed for tests and metrics — rows dropped entirely (could not parse even stripped). */ get permanentlyDroppedRows() { return this._permanentlyDroppedRows; } @@ -914,10 +936,10 @@ export class RunsReplicationService { payloadError = plErr; } - if (!trErr && trOutcome && trOutcome.kind !== "dropped") { + if (!trErr && trOutcome) { this._taskRunsInsertedCounter.add(landedRowCount(group.taskRunInserts.length, trOutcome)); } - if (!plErr && plOutcome && plOutcome.kind !== "dropped") { + if (!plErr && plOutcome) { this._payloadsInsertedCounter.add(landedRowCount(group.payloadInserts.length, plOutcome)); } } @@ -1074,15 +1096,12 @@ export class RunsReplicationService { return; } return await startSpan(this._tracer, "insertTaskRunsInserts", async (span) => { - const doInsert = async (extraSettings?: ClickHouseSettings) => { - const [insertError, insertResult] = await clickhouse.taskRuns.insertCompactArrays( - taskRunInserts, - { - params: { - clickhouse_settings: { ...this.#getClickhouseInsertSettings(), ...extraSettings }, - }, - } - ); + const rawInsert = async (rows: TaskRunInsertArray[], extraSettings?: ClickHouseSettings) => { + const [insertError, insertResult] = await clickhouse.taskRuns.insertCompactArrays(rows, { + params: { + clickhouse_settings: { ...this.#getClickhouseInsertSettings(), ...extraSettings }, + }, + }); if (insertError) { this.logger.error("Error inserting task run inserts attempt", { error: insertError, @@ -1094,12 +1113,17 @@ export class RunsReplicationService { return insertResult; }; - return await this.#insertWithJsonParseRecovery( - taskRunInserts, - doInsert, - "task_runs_v2", - attempt - ); + const outcome = await insertWithJsonParseRecovery({ + rows: taskRunInserts, + contextLabel: "task_runs_v2", + logger: this.logger, + logContext: { attempt }, + insert: (rows) => rawInsert(rows), + insertSync: (rows) => rawInsert(rows, { async_insert: 0 }), + stripJsonColumns: stripTaskRunJsonColumns, + }); + this.#recordRecoveryOutcome(outcome, "task_runs_v2"); + return outcome; }); } @@ -1112,9 +1136,9 @@ export class RunsReplicationService { return; } return await startSpan(this._tracer, "insertPayloadInserts", async (span) => { - const doInsert = async (extraSettings?: ClickHouseSettings) => { + const rawInsert = async (rows: PayloadInsertArray[], extraSettings?: ClickHouseSettings) => { const [insertError, insertResult] = await clickhouse.taskRuns.insertPayloadsCompactArrays( - payloadInserts, + rows, { params: { clickhouse_settings: { ...this.#getClickhouseInsertSettings(), ...extraSettings }, @@ -1132,150 +1156,40 @@ export class RunsReplicationService { return insertResult; }; - return await this.#insertWithJsonParseRecovery( - payloadInserts, - doInsert, - "raw_task_runs_payload_v1", - attempt - ); + const outcome = await insertWithJsonParseRecovery({ + rows: payloadInserts, + contextLabel: "raw_task_runs_payload_v1", + logger: this.logger, + logContext: { attempt }, + insert: (rows) => rawInsert(rows), + insertSync: (rows) => rawInsert(rows, { async_insert: 0 }), + stripJsonColumns: stripPayloadJsonColumns, + }); + this.#recordRecoveryOutcome(outcome, "raw_task_runs_payload_v1"); + return outcome; }); } - /** - * Wraps a ClickHouse insert with recovery for `Cannot parse JSON object` - * rejections so one un-ingestable row never drops its whole batch. Builds on - * the sanitize pattern from `ClickhouseEventRepository.#insertWithJsonParseRecovery` - * (#3659) and adds a final row-isolation fallback: - * - * 1. Try the insert. Healthy batches pay zero recovery cost. - * 2. On a parse error, walk the batch via `sanitizeRows` and losslessly - * repair what we can in place (lone UTF-16 surrogates → `"[invalid-utf16]"`, - * out-of-range integers → their string form), then retry once. A clean - * retry keeps every row. - * 3. If the sanitizer found nothing to fix, or the retry still hits the same - * parse error (a structurally un-ingestable row, e.g. JSON nested past - * ClickHouse's `input_format_json_max_depth`), retry once more with - * `input_format_allow_errors_*` so ClickHouse skips only the un-parseable - * rows and lands the rest. Verified against ClickHouse 26.2 (the cloud - * version): the good rows land, the JSONCompactEachRowWithNames header is - * unaffected, both sync and async. - * 4. Only if that row-isolation insert itself fails do we drop the batch, - * and never rethrow a parse error — otherwise the surrounding - * `#insertWithRetry` layer would spin on the same deterministic failure. - * 5. Non-parse errors propagate unchanged so the transient-retry path still - * handles them. - */ - async #insertWithJsonParseRecovery( - rows: T[], - doInsert: (extraSettings?: ClickHouseSettings) => Promise, - contextLabel: string, - attempt: number - ): Promise< - | { kind: "inserted"; insertResult: unknown } - | { kind: "sanitized"; insertResult: unknown } - | { kind: "isolated"; insertResult: unknown; rowsSkipped: number | null } - | { kind: "dropped" } - > { - try { - return { kind: "inserted", insertResult: await doInsert() }; - } catch (firstError) { - if (!isClickHouseJsonParseError(firstError)) throw firstError; - - const firstMessage = errorMessage(firstError); - const rowHint = parseRowNumberFromError(firstMessage); - const { rowsTouched, fieldsSanitized } = sanitizeRows(rows); - - if (fieldsSanitized > 0) { - this.logger.warn("Sanitizing batch after ClickHouse JSON parse error", { - contextLabel, - attempt, - batchSize: rows.length, - clickhouseRowHint: rowHint, - rowsTouched, - fieldsSanitized, - clickhouseError: firstMessage.split("\n")[0], - }); + #recordRecoveryOutcome(outcome: JsonParseRecoveryOutcome, contextLabel: string) { + if (outcome.kind !== "recovered") { + return; + } - try { - return { kind: "sanitized", insertResult: await doInsert() }; - } catch (retryError) { - if (!isClickHouseJsonParseError(retryError)) throw retryError; - } - } + this._rowIsolationRecoveries += 1; + this._rowIsolatedBatchesCounter.add(1, { table: contextLabel }); - return await this.#insertIsolatingBadRows( - rows, - doInsert, - contextLabel, - attempt, - firstMessage - ); + if (outcome.rowsStripped > 0) { + this._rowsStripped += outcome.rowsStripped; + this._rowsStrippedCounter.add(outcome.rowsStripped, { table: contextLabel }); } - } - - /** - * Last-resort recovery: re-run the insert with `input_format_allow_errors_*` - * so ClickHouse skips the rows it cannot parse and lands the rest, rather than - * aborting the whole INSERT. Forces a synchronous insert so `written_rows` - * reflects exactly what landed and we can count what was lost. - */ - async #insertIsolatingBadRows( - rows: T[], - doInsert: (extraSettings?: ClickHouseSettings) => Promise, - contextLabel: string, - attempt: number, - firstMessage: string - ): Promise< - { kind: "isolated"; insertResult: unknown; rowsSkipped: number | null } | { kind: "dropped" } - > { - try { - const insertResult = await doInsert({ - input_format_allow_errors_num: String(rows.length), - input_format_allow_errors_ratio: 1, - async_insert: 0, - }); - this._rowIsolationRecoveries += 1; - this._rowIsolatedBatchesCounter.add(1, { table: contextLabel }); - const writtenRows = extractWrittenRows(insertResult); - const rowsSkipped = writtenRows === null ? null : Math.max(0, rows.length - writtenRows); - if (rowsSkipped !== null) { - this._permanentlyDroppedRows += rowsSkipped; + if (outcome.rowsDropped > 0) { + this._permanentlyDroppedRows += outcome.rowsDropped; + this._rowsDroppedCounter.add(outcome.rowsDropped, { table: contextLabel }); + if (outcome.rowsStripped === 0) { + this._permanentlyDroppedBatches += 1; + this._droppedBatchesCounter.add(1, { table: contextLabel }); } - - this.logger.info( - "Isolated un-ingestable rows after ClickHouse JSON parse error — landed the rest of the batch", - { - contextLabel, - attempt, - batchSize: rows.length, - rowsSkipped, - rowIsolationRecoveries: this._rowIsolationRecoveries, - permanentlyDroppedRows: this._permanentlyDroppedRows, - sampleRow: JSON.stringify(rows[0] ?? null).slice(0, 1024), - clickhouseError: firstMessage.split("\n")[0], - } - ); - - return { kind: "isolated", insertResult, rowsSkipped }; - } catch (isolationError) { - if (!isClickHouseJsonParseError(isolationError)) throw isolationError; - - this._permanentlyDroppedBatches += 1; - this._droppedBatchesCounter.add(1, { table: contextLabel }); - this.logger.error( - "Dropped batch — row-isolation insert failed after ClickHouse JSON parse error", - { - contextLabel, - attempt, - batchSize: rows.length, - permanentlyDroppedBatches: this._permanentlyDroppedBatches, - sampleRow: JSON.stringify(rows[0] ?? null).slice(0, 1024), - firstError: firstMessage.split("\n")[0], - isolationError: errorMessage(isolationError).split("\n")[0], - } - ); - return { kind: "dropped" }; } } @@ -1629,26 +1543,24 @@ function lsnToUInt64(lsn: string): bigint { return (BigInt("0x" + seg) << 32n) | BigInt("0x" + off); } -function errorMessage(err: unknown): string { - return typeof err === "object" && err !== null && "message" in err - ? String((err as { message?: unknown }).message ?? "") - : String(err); -} - -function landedRowCount( - groupSize: number, - outcome: { kind: string; rowsSkipped?: number | null } -): number { - if (outcome.kind === "isolated" && typeof outcome.rowsSkipped === "number") { - return Math.max(0, groupSize - outcome.rowsSkipped); +function landedRowCount(groupSize: number, outcome: JsonParseRecoveryOutcome): number { + if (outcome.kind === "recovered") { + return Math.max(0, groupSize - outcome.rowsDropped); } return groupSize; } -function extractWrittenRows(insertResult: unknown): number | null { - const written = (insertResult as { summary?: { written_rows?: string } } | null | undefined) - ?.summary?.written_rows; - if (written === undefined) return null; - const parsed = Number(written); - return Number.isFinite(parsed) ? parsed : null; +const STRIPPED_JSON: { data: unknown } = { data: undefined }; + +function stripTaskRunJsonColumns(row: TaskRunInsertArray): TaskRunInsertArray { + const stripped = [...row] as TaskRunInsertArray; + stripped[TASK_RUN_INDEX.output] = STRIPPED_JSON; + stripped[TASK_RUN_INDEX.error] = STRIPPED_JSON; + return stripped; +} + +function stripPayloadJsonColumns(row: PayloadInsertArray): PayloadInsertArray { + const stripped = [...row] as PayloadInsertArray; + stripped[PAYLOAD_INDEX.payload] = STRIPPED_JSON; + return stripped; } diff --git a/apps/webapp/app/v3/eventRepository/clickhouseEventRepository.server.ts b/apps/webapp/app/v3/eventRepository/clickhouseEventRepository.server.ts index 8bee56dba82..ca6e826dca6 100644 --- a/apps/webapp/app/v3/eventRepository/clickhouseEventRepository.server.ts +++ b/apps/webapp/app/v3/eventRepository/clickhouseEventRepository.server.ts @@ -67,9 +67,8 @@ import type { TraceSummary, } from "./eventRepository.types"; import { - isClickHouseJsonParseError, - parseRowNumberFromError, - sanitizeRows, + insertWithJsonParseRecovery, + type JsonParseRecoveryOutcome, } from "./sanitizeRowsOnParseError.server"; export type ClickhouseEventRepositoryConfig = { @@ -122,30 +121,35 @@ export class ClickhouseEventRepository implements IEventRepository { private _tracer: Tracer; private _version: "v1" | "v2"; /** - * Counts batches dropped whole because even the row-isolation retry failed - * to insert anything (an unexpected terminal case). The common recovery now - * isolates the un-ingestable rows and lands the rest, so this should stay at - * zero in practice. + * Counts batches where every row was un-ingestable even with its JSON + * stripped, so nothing landed. Row isolation lands anything strippable, so + * this should stay at zero; a non-zero value means the recovery is failing. */ private _permanentlyDroppedBatches = 0; private readonly _droppedBatchesCounter: Counter; /** - * Counts batches that took the row-isolation recovery path — a + * Counts batches that took the row-isolation recovery path: a * `Cannot parse JSON object` failure the sanitizer could not repair, where we - * re-inserted with `input_format_allow_errors_*` so ClickHouse skipped the - * un-ingestable rows and landed the rest. Reliable per-event signal. + * bisected to the poison rows and landed the batch with their JSON stripped. + * Reliable per-event signal. */ private _rowIsolationRecoveries = 0; private readonly _rowIsolatedBatchesCounter: Counter; /** - * Best-effort count of individual rows ClickHouse skipped across those - * row-isolation retries, from the insert summary's `written_rows` when the - * client surfaces it (not always populated under concurrent inserts, so treat - * as a lower bound; `_rowIsolationRecoveries` is the dependable event count). + * Counts rows that landed with their un-ingestable JSON stripped (the span + * kept its place in the trace, only the attributes content was lost). + */ + private _rowsStripped = 0; + private readonly _rowsStrippedCounter: Counter; + + /** + * Counts rows dropped entirely because they could not parse even with their + * JSON stripped. The true data-loss signal; expected to stay near zero. */ private _permanentlyDroppedRows = 0; + private readonly _rowsDroppedCounter: Counter; constructor(config: ClickhouseEventRepositoryConfig) { this._clickhouse = config.clickhouse; @@ -163,6 +167,16 @@ export class ClickhouseEventRepository implements IEventRepository { "Batches recovered by isolating un-ingestable rows (landed the rest) after a ClickHouse JSON parse error", unit: "batches", }); + this._rowsStrippedCounter = meter.createCounter("ingest.flush.rows_stripped", { + description: + "Rows landed with their un-ingestable JSON stripped (kept the row, lost only the JSON content)", + unit: "rows", + }); + this._rowsDroppedCounter = meter.createCounter("ingest.flush.rows_dropped", { + description: + "Rows dropped entirely because they could not parse even with their JSON stripped", + unit: "rows", + }); this._flushScheduler = new DynamicFlushScheduler({ name: `task_events_${this._version}`, @@ -212,7 +226,7 @@ export class ClickhouseEventRepository implements IEventRepository { return this._config.maximumLiveReloadingSetting ?? 1000; } - /** Exposed for tests and metrics — total batches lost to unrecoverable parse errors. */ + /** Exposed for tests and metrics — batches where nothing landed even after stripping JSON. */ get permanentlyDroppedBatches() { return this._permanentlyDroppedBatches; } @@ -222,7 +236,12 @@ export class ClickhouseEventRepository implements IEventRepository { return this._rowIsolationRecoveries; } - /** Exposed for tests and metrics — best-effort count of individual rows ClickHouse skipped during row-isolation retries. */ + /** Exposed for tests and metrics — rows that landed with their un-ingestable JSON stripped. */ + get rowsStripped() { + return this._rowsStripped; + } + + /** Exposed for tests and metrics — rows dropped entirely (could not parse even stripped). */ get permanentlyDroppedRows() { return this._permanentlyDroppedRows; } @@ -295,8 +314,12 @@ export class ClickhouseEventRepository implements IEventRepository { ? this._clickhouse.taskEventsV2.insert : this._clickhouse.taskEvents.insert; - const doInsert = async (extraSettings?: ClickHouseSettings) => { - const [insertError, insertResult] = await insertFn(events, { + const contextLabel = `task_events_${this._version}`; + const rawInsert = async ( + rows: (TaskEventV1Input | TaskEventV2Input)[], + extraSettings?: ClickHouseSettings + ) => { + const [insertError, insertResult] = await insertFn(rows, { params: { clickhouse_settings: { ...this.#getClickhouseInsertSettings(), ...extraSettings }, }, @@ -305,22 +328,20 @@ export class ClickhouseEventRepository implements IEventRepository { return insertResult; }; - const outcome = await this.#insertWithJsonParseRecovery( - flushId, - events, - doInsert, - `task_events_${this._version}` - ); - - if (outcome.kind === "dropped") { - // Loud log already emitted; nothing landed in ClickHouse — don't publish to Redis. - return; - } + const outcome = await insertWithJsonParseRecovery({ + rows: events, + contextLabel, + logger, + logContext: { flushId, version: this._version }, + insert: (rows) => rawInsert(rows), + insertSync: (rows) => rawInsert(rows, { async_insert: 0 }), + stripJsonColumns: stripTaskEventJsonColumns, + }); + this.#recordRecoveryOutcome(outcome, contextLabel); logger.debug("ClickhouseEventRepository.flushBatch Inserted batch into clickhouse", { events: events.length, - insertResult: outcome.insertResult, - sanitized: outcome.kind === "sanitized", + outcome: outcome.kind, version: this._version, }); @@ -329,8 +350,8 @@ export class ClickhouseEventRepository implements IEventRepository { } async #flushLlmMetricsBatch(flushId: string, rows: LlmMetricsV1Input[]) { - const doInsert = async (extraSettings?: ClickHouseSettings) => { - const [insertError, insertResult] = await this._clickhouse.llmMetrics.insert(rows, { + const rawInsert = async (batch: LlmMetricsV1Input[], extraSettings?: ClickHouseSettings) => { + const [insertError, insertResult] = await this._clickhouse.llmMetrics.insert(batch, { params: { clickhouse_settings: { ...this.#getClickhouseInsertSettings(), ...extraSettings }, }, @@ -339,155 +360,43 @@ export class ClickhouseEventRepository implements IEventRepository { return insertResult; }; - const outcome = await this.#insertWithJsonParseRecovery( - flushId, + const outcome = await insertWithJsonParseRecovery({ rows, - doInsert, - "llm_metrics_v1" - ); - - if (outcome.kind === "dropped") { - return; - } + contextLabel: "llm_metrics_v1", + logger, + logContext: { flushId }, + insert: (batch) => rawInsert(batch), + insertSync: (batch) => rawInsert(batch, { async_insert: 0 }), + stripJsonColumns: (row) => row, + }); + this.#recordRecoveryOutcome(outcome, "llm_metrics_v1"); logger.debug("ClickhouseEventRepository.flushLlmMetricsBatch Inserted LLM metrics batch", { rows: rows.length, - sanitized: outcome.kind === "sanitized", + outcome: outcome.kind, }); } - /** - * Wraps a ClickHouse insert with recovery for `Cannot parse JSON object` - * rejections so one un-ingestable event never drops its whole batch. - * - * 1. Try the insert. Healthy batches pay zero recovery cost. - * 2. On a parse error, `sanitizeRows` losslessly repairs what it can in - * place (lone UTF-16 surrogates, out-of-range integers), then retries - * once. A clean retry keeps every row. - * 3. If the sanitizer found nothing, or the retry still hits the same parse - * error (a structurally un-ingestable row, e.g. JSON nested past - * ClickHouse's `input_format_json_max_depth`), retry once more with - * `input_format_allow_errors_*` so ClickHouse skips only the un-parseable - * rows and lands the rest. Verified against ClickHouse 26.2 (the cloud - * version) with the JSONEachRow insert format. - * 4. Only if that row-isolation insert itself fails do we drop the batch, - * and never rethrow a parse error — the scheduler would just repeat the - * same deterministic failure. - * - * Non-parse errors propagate unchanged so the scheduler's backoff/retry still - * handles transient network or CH issues. - */ - async #insertWithJsonParseRecovery( - flushId: string, - rows: T[], - doInsert: (extraSettings?: ClickHouseSettings) => Promise, - contextLabel: string - ): Promise< - | { kind: "inserted"; insertResult: unknown } - | { kind: "sanitized"; insertResult: unknown } - | { kind: "isolated"; insertResult: unknown; rowsSkipped: number | null } - | { kind: "dropped" } - > { - try { - return { kind: "inserted", insertResult: await doInsert() }; - } catch (firstError) { - if (!isClickHouseJsonParseError(firstError)) throw firstError; - - const firstMessage = errorMessage(firstError); - const rowHint = parseRowNumberFromError(firstMessage); - const { rowsTouched, fieldsSanitized } = sanitizeRows(rows); - - if (fieldsSanitized > 0) { - logger.warn("Sanitizing batch after ClickHouse JSON parse error", { - flushId, - contextLabel, - batchSize: rows.length, - clickhouseRowHint: rowHint, - rowsTouched, - fieldsSanitized, - clickhouseError: firstMessage.split("\n")[0], - }); + #recordRecoveryOutcome(outcome: JsonParseRecoveryOutcome, contextLabel: string) { + if (outcome.kind !== "recovered") { + return; + } - try { - return { kind: "sanitized", insertResult: await doInsert() }; - } catch (retryError) { - if (!isClickHouseJsonParseError(retryError)) throw retryError; - } - } + this._rowIsolationRecoveries += 1; + this._rowIsolatedBatchesCounter.add(1, { table: contextLabel }); - return await this.#insertIsolatingBadRows( - flushId, - rows, - doInsert, - contextLabel, - firstMessage - ); + if (outcome.rowsStripped > 0) { + this._rowsStripped += outcome.rowsStripped; + this._rowsStrippedCounter.add(outcome.rowsStripped, { table: contextLabel }); } - } - - /** - * Last-resort recovery: re-run the insert with `input_format_allow_errors_*` - * so ClickHouse skips the rows it cannot parse and lands the rest, rather than - * aborting the whole INSERT. Forces a synchronous insert so `written_rows` - * reflects what landed and we can count what was lost. - */ - async #insertIsolatingBadRows( - flushId: string, - rows: T[], - doInsert: (extraSettings?: ClickHouseSettings) => Promise, - contextLabel: string, - firstMessage: string - ): Promise< - { kind: "isolated"; insertResult: unknown; rowsSkipped: number | null } | { kind: "dropped" } - > { - try { - const insertResult = await doInsert({ - input_format_allow_errors_num: String(rows.length), - input_format_allow_errors_ratio: 1, - async_insert: 0, - }); - this._rowIsolationRecoveries += 1; - this._rowIsolatedBatchesCounter.add(1, { table: contextLabel }); - const writtenRows = extractWrittenRows(insertResult); - const rowsSkipped = writtenRows === null ? null : Math.max(0, rows.length - writtenRows); - if (rowsSkipped !== null) { - this._permanentlyDroppedRows += rowsSkipped; + if (outcome.rowsDropped > 0) { + this._permanentlyDroppedRows += outcome.rowsDropped; + this._rowsDroppedCounter.add(outcome.rowsDropped, { table: contextLabel }); + if (outcome.rowsStripped === 0) { + this._permanentlyDroppedBatches += 1; + this._droppedBatchesCounter.add(1, { table: contextLabel }); } - - logger.info( - "Isolated un-ingestable rows after ClickHouse JSON parse error — landed the rest of the batch", - { - flushId, - contextLabel, - batchSize: rows.length, - rowsSkipped, - rowIsolationRecoveries: this._rowIsolationRecoveries, - permanentlyDroppedRows: this._permanentlyDroppedRows, - sampleRow: JSON.stringify(rows[0] ?? null).slice(0, 1024), - clickhouseError: firstMessage.split("\n")[0], - } - ); - - return { kind: "isolated", insertResult, rowsSkipped }; - } catch (isolationError) { - if (!isClickHouseJsonParseError(isolationError)) throw isolationError; - - this._permanentlyDroppedBatches += 1; - this._droppedBatchesCounter.add(1, { table: contextLabel }); - logger.error( - "Dropped batch — row-isolation insert failed after ClickHouse JSON parse error", - { - flushId, - contextLabel, - batchSize: rows.length, - permanentlyDroppedBatches: this._permanentlyDroppedBatches, - sampleRow: JSON.stringify(rows[0] ?? null).slice(0, 1024), - firstError: firstMessage.split("\n")[0], - isolationError: errorMessage(isolationError).split("\n")[0], - } - ); - return { kind: "dropped" }; } } @@ -3011,16 +2920,6 @@ function formatClickhouseUnsignedIntegerString(value: number | bigint): string { return Math.floor(value).toString(); } -function errorMessage(err: unknown): string { - return typeof err === "object" && err !== null && "message" in err - ? String((err as { message?: unknown }).message ?? "") - : String(err); -} - -function extractWrittenRows(insertResult: unknown): number | null { - const written = (insertResult as { summary?: { written_rows?: string } } | null | undefined) - ?.summary?.written_rows; - if (written === undefined) return null; - const parsed = Number(written); - return Number.isFinite(parsed) ? parsed : null; +function stripTaskEventJsonColumns(row: T): T { + return { ...row, attributes: {} }; } diff --git a/apps/webapp/app/v3/eventRepository/sanitizeRowsOnParseError.server.ts b/apps/webapp/app/v3/eventRepository/sanitizeRowsOnParseError.server.ts index 0374442200a..9d0e5882e85 100644 --- a/apps/webapp/app/v3/eventRepository/sanitizeRowsOnParseError.server.ts +++ b/apps/webapp/app/v3/eventRepository/sanitizeRowsOnParseError.server.ts @@ -162,3 +162,151 @@ export function sanitizeRows(rows: T[]): SanitizeResult { return result; } + +export function errorMessage(err: unknown): string { + return typeof err === "object" && err !== null && "message" in err + ? String((err as { message?: unknown }).message ?? "") + : String(err); +} + +export type JsonParseRecoveryLogger = { + info: (message: string, meta?: Record) => void; + warn: (message: string, meta?: Record) => void; +}; + +export type JsonParseRecoveryOutcome = + | { kind: "inserted"; insertResult: unknown } + | { kind: "sanitized"; insertResult: unknown } + | { kind: "recovered"; rowsStripped: number; rowsDropped: number }; + +/** + * Shared ClickHouse insert recovery for `Cannot parse JSON object` rejections, + * used by both ClickHouse writers (run replication and the trace/event + * repository) so a single un-ingestable row never drops its whole batch. + * + * 1. Try the insert. Healthy batches pay zero recovery cost. + * 2. On a parse error, `sanitizeRows` losslessly repairs what it can in place + * (lone UTF-16 surrogates, out-of-range integers) and retries once. A + * clean retry keeps every row untouched. + * 3. If the sanitizer can't help, isolate the un-ingestable rows by + * bisection (`at row N` is unstable under parallel parsing) and re-insert + * each poison row with its JSON column(s) emptied via `stripJsonColumns`, + * so the row still lands (e.g. a run keeps its terminal status, a span + * keeps its place in the trace) and only the un-ingestable content is + * lost. Clean rows land in full. A row that can't parse even stripped is + * dropped and counted. + * 4. Non-parse errors propagate unchanged so the caller's transient-retry + * path still handles them. + */ +export async function insertWithJsonParseRecovery(params: { + rows: T[]; + contextLabel: string; + logger: JsonParseRecoveryLogger; + logContext?: Record; + insert: (rows: T[]) => Promise; + insertSync: (rows: T[]) => Promise; + stripJsonColumns: (row: T) => T; +}): Promise { + const { rows, contextLabel, logger, logContext, insert, insertSync, stripJsonColumns } = params; + + try { + return { kind: "inserted", insertResult: await insert(rows) }; + } catch (firstError) { + if (!isClickHouseJsonParseError(firstError)) throw firstError; + + const firstMessage = errorMessage(firstError); + const rowHint = parseRowNumberFromError(firstMessage); + const { rowsTouched, fieldsSanitized } = sanitizeRows(rows); + + if (fieldsSanitized > 0) { + logger.warn("Sanitizing batch after ClickHouse JSON parse error", { + ...logContext, + contextLabel, + batchSize: rows.length, + clickhouseRowHint: rowHint, + rowsTouched, + fieldsSanitized, + clickhouseError: firstMessage.split("\n")[0], + }); + + try { + return { kind: "sanitized", insertResult: await insert(rows) }; + } catch (retryError) { + if (!isClickHouseJsonParseError(retryError)) throw retryError; + } + } + + const { rowsStripped, rowsDropped } = await isolateAndStripPoisonRows( + rows, + insertSync, + stripJsonColumns + ); + + logger.info( + "Isolated un-ingestable rows after ClickHouse JSON parse error — landed the batch with poison JSON stripped", + { + ...logContext, + contextLabel, + batchSize: rows.length, + rowsStripped, + rowsDropped, + sampleRow: JSON.stringify(rows[0] ?? null).slice(0, 1024), + clickhouseError: firstMessage.split("\n")[0], + } + ); + + return { kind: "recovered", rowsStripped, rowsDropped }; + } +} + +/** + * Precondition: inserting `rows` as-is throws a `Cannot parse JSON object` + * error. Bisects to isolate each un-ingestable row, lands clean rows in full, + * and re-inserts each poison row with its JSON column(s) stripped so it still + * lands. A row that can't parse even stripped is dropped. All inserts are + * synchronous so each subset's parse error surfaces. The two halves are probed + * concurrently so recovery wall-clock stays ~O(log n) round-trips rather than + * O(n), which matters when a poison burst would otherwise lag the shared + * replication stream. Returns exact counts. + */ +async function isolateAndStripPoisonRows( + rows: T[], + insertSync: (rows: T[]) => Promise, + stripJsonColumns: (row: T) => T +): Promise<{ rowsStripped: number; rowsDropped: number }> { + if (rows.length === 0) { + return { rowsStripped: 0, rowsDropped: 0 }; + } + + if (rows.length === 1) { + try { + await insertSync([stripJsonColumns(rows[0])]); + return { rowsStripped: 1, rowsDropped: 0 }; + } catch (error) { + if (!isClickHouseJsonParseError(error)) throw error; + return { rowsStripped: 0, rowsDropped: 1 }; + } + } + + const mid = rows.length >> 1; + + const recoverHalf = async (half: T[]) => { + try { + await insertSync(half); + return { rowsStripped: 0, rowsDropped: 0 }; + } catch (error) { + if (!isClickHouseJsonParseError(error)) throw error; + return isolateAndStripPoisonRows(half, insertSync, stripJsonColumns); + } + }; + + const [left, right] = await Promise.all([ + recoverHalf(rows.slice(0, mid)), + recoverHalf(rows.slice(mid)), + ]); + + return { + rowsStripped: left.rowsStripped + right.rowsStripped, + rowsDropped: left.rowsDropped + right.rowsDropped, + }; +} diff --git a/apps/webapp/test/clickhouseEventRepositoryJsonRecovery.test.ts b/apps/webapp/test/clickhouseEventRepositoryJsonRecovery.test.ts index 06786126485..fc748b39ddc 100644 --- a/apps/webapp/test/clickhouseEventRepositoryJsonRecovery.test.ts +++ b/apps/webapp/test/clickhouseEventRepositoryJsonRecovery.test.ts @@ -24,7 +24,7 @@ function startTime(baseMs: number, offsetMs: number): string { describe("ClickhouseEventRepository JSON parse recovery", () => { clickhouseTest( - "lands the good events when one event in the batch has ClickHouse-unparseable attributes", + "lands every event (poison event keeps its span, attributes stripped) when one event has ClickHouse-unparseable attributes", async ({ clickhouseContainer }) => { const clickhouse = new ClickHouse({ url: clickhouseContainer.getConnectionUrl(), @@ -89,31 +89,34 @@ describe("ClickhouseEventRepository JSON parse recovery", () => { const queryEvents = clickhouse.reader.query({ name: "event-recovery-check", query: - "SELECT span_id FROM trigger_dev.task_events_v2 WHERE environment_id = {env_id:String}", - schema: z.object({ span_id: z.string() }), + "SELECT span_id, toJSONString(attributes) AS attributes_json FROM trigger_dev.task_events_v2 WHERE environment_id = {env_id:String}", + schema: z.object({ span_id: z.string(), attributes_json: z.string() }), params: z.object({ env_id: z.string() }), }); - const landedIds = await vi.waitFor( + const rowsById = await vi.waitFor( async () => { const [queryError, resultRows] = await queryEvents({ env_id: environmentId }); expect(queryError).toBeNull(); - const ids = new Set((resultRows ?? []).map((r) => r.span_id)); - for (const id of goodSpanIds) { - expect(ids.has(id)).toBe(true); + const byId = new Map((resultRows ?? []).map((r) => [r.span_id, r])); + for (const id of [...goodSpanIds, poisonSpanId]) { + expect(byId.has(id)).toBe(true); } - return ids; + return byId; }, { timeout: 30_000, interval: 250 } ); for (const id of goodSpanIds) { - expect(landedIds.has(id)).toBe(true); + expect(rowsById.get(id)!.attributes_json).toContain('"ok":true'); } - expect(landedIds.has(poisonSpanId)).toBe(false); + + expect(rowsById.get(poisonSpanId)!.attributes_json).toBe("{}"); expect(repository.permanentlyDroppedBatches).toBe(0); + expect(repository.permanentlyDroppedRows).toBe(0); expect(repository.rowIsolationRecoveries).toBeGreaterThanOrEqual(1); + expect(repository.rowsStripped).toBeGreaterThanOrEqual(1); } finally { await (repository as any)._flushScheduler?.shutdown?.(); } diff --git a/apps/webapp/test/runsReplicationJsonRecoveryBenchmark.test.ts b/apps/webapp/test/runsReplicationJsonRecoveryBenchmark.test.ts index 254237a6022..b30454a5d80 100644 --- a/apps/webapp/test/runsReplicationJsonRecoveryBenchmark.test.ts +++ b/apps/webapp/test/runsReplicationJsonRecoveryBenchmark.test.ts @@ -187,7 +187,7 @@ async function runScenario( poisonDepth: 1500, }); - const expectedLanded = producerStats.created - producerStats.poisoned; + const expectedLanded = producerStats.created; replication = await waitForCount( clickhouse, organization.id, @@ -201,7 +201,7 @@ async function runScenario( } const throughput = (replication.count / replication.duration) * 1000; - const expectedLanded = producerStats.created - producerStats.poisoned; + const expectedLanded = producerStats.created; console.log(`\n${"=".repeat(72)}`); console.log(`SCENARIO: ${name} (poison rate ${(poisonRate * 100).toFixed(1)}%)`); @@ -211,7 +211,8 @@ async function runScenario( console.log(`Repl dur: ${replication.duration.toFixed(0)}ms`); console.log(`Throughput: ${throughput.toFixed(0)} runs/sec`); console.log(`Row-isolation recoveries: ${service.rowIsolationRecoveries}`); - console.log(`Dropped rows (best-effort): ${service.permanentlyDroppedRows}`); + console.log(`Rows stripped (kept row, lost JSON): ${service.rowsStripped}`); + console.log(`Rows dropped (unrecoverable): ${service.permanentlyDroppedRows}`); console.log(`Dropped batches (whole): ${service.permanentlyDroppedBatches}`); console.log( `ELU mean=${eluStats.mean.toFixed(2)}% p50=${eluStats.p50.toFixed(2)}% p95=${eluStats.p95.toFixed(2)}% p99=${eluStats.p99.toFixed(2)}% (${eluStats.samples} samples)` @@ -268,11 +269,14 @@ describe("RunsReplicationService JSON-recovery ELU benchmark", () => { expect(healthy.replication.count).toBe(healthy.expectedLanded); expect(healthy.service.rowIsolationRecoveries).toBe(0); + expect(healthy.service.rowsStripped).toBe(0); expect(healthy.service.permanentlyDroppedBatches).toBe(0); expect(poisoned.replication.count).toBe(poisoned.expectedLanded); expect(poisoned.service.permanentlyDroppedBatches).toBe(0); + expect(poisoned.service.permanentlyDroppedRows).toBe(0); expect(poisoned.service.rowIsolationRecoveries).toBeGreaterThanOrEqual(1); + expect(poisoned.service.rowsStripped).toBe(poisoned.producerStats.poisoned); } ); }); diff --git a/apps/webapp/test/runsReplicationService.part10.test.ts b/apps/webapp/test/runsReplicationService.part10.test.ts index 3f269430c42..0f1a6183afa 100644 --- a/apps/webapp/test/runsReplicationService.part10.test.ts +++ b/apps/webapp/test/runsReplicationService.part10.test.ts @@ -17,7 +17,7 @@ function deeplyNested(depth: number): Record { describe("RunsReplicationService (part 10/10) — JSON parse recovery", () => { replicationContainerTest( - "lands the good runs when one run in the batch has ClickHouse-unparseable JSON output", + "lands every run (poison run keeps its status, output stripped) when one run has ClickHouse-unparseable JSON output", async ({ clickhouseContainer, redisOptions, postgresContainer, prisma }) => { await prisma.$executeRawUnsafe(`ALTER TABLE public."TaskRun" REPLICA IDENTITY FULL;`); @@ -111,31 +111,37 @@ describe("RunsReplicationService (part 10/10) — JSON parse recovery", () => { const queryRuns = clickhouse.reader.query({ name: "runs-replication-batchdrop", query: - "SELECT run_id FROM trigger_dev.task_runs_v2 WHERE organization_id = {org_id:String}", - schema: z.object({ run_id: z.string() }), + "SELECT run_id, status, toJSONString(output) AS output_json FROM trigger_dev.task_runs_v2 FINAL WHERE organization_id = {org_id:String}", + schema: z.object({ run_id: z.string(), status: z.string(), output_json: z.string() }), params: z.object({ org_id: z.string() }), }); - const landedIds = await vi.waitFor( + const rowsById = await vi.waitFor( async () => { const [queryError, rows] = await queryRuns({ org_id: organization.id }); expect(queryError).toBeNull(); - const ids = new Set((rows ?? []).map((r) => r.run_id)); - for (const id of goodRunIds) { - expect(ids.has(id)).toBe(true); + const byId = new Map((rows ?? []).map((r) => [r.run_id, r])); + for (const id of [...goodRunIds, poisonRunId]) { + expect(byId.has(id)).toBe(true); } - return ids; + return byId; }, { timeout: 30_000, interval: 250 } ); for (const id of goodRunIds) { - expect(landedIds.has(id)).toBe(true); + const row = rowsById.get(id)!; + expect(row.output_json).toContain('"ok":true'); } - expect(landedIds.has(poisonRunId)).toBe(false); + + const poison = rowsById.get(poisonRunId)!; + expect(poison.status).toBe("COMPLETED_SUCCESSFULLY"); + expect(poison.output_json).toBe("{}"); expect(runsReplicationService.permanentlyDroppedBatches).toBe(0); + expect(runsReplicationService.permanentlyDroppedRows).toBe(0); expect(runsReplicationService.rowIsolationRecoveries).toBeGreaterThanOrEqual(1); + expect(runsReplicationService.rowsStripped).toBeGreaterThanOrEqual(1); await runsReplicationService.stop(); } From 4d1b362ccffc686398df1d2ae6a2b9e6d2e7288f Mon Sep 17 00:00:00 2001 From: Eric Allam Date: Fri, 24 Jul 2026 11:35:20 +0100 Subject: [PATCH 4/9] feat(webapp): cap row-isolation recovery cost against a poison flood Bound the per-batch isolation work so a burst of un-ingestable rows cannot lag the shared replication stream. Once a batch exceeds the isolation-insert budget the remaining rows are stripped and landed in one insert instead of bisected further. The ceiling is transparent for normal recovery and small run batches (they still isolate precisely); it only bites on a large batch that is heavily poisoned. Adds a recovery_cap_hits counter as the flood signal. --- .../services/runsReplicationService.server.ts | 25 ++++ .../clickhouseEventRepository.server.ts | 22 +++ .../sanitizeRowsOnParseError.server.ts | 88 +++++++++--- ...nsReplicationJsonRecoveryBenchmark.test.ts | 2 + .../test/sanitizeRowsOnParseError.test.ts | 126 ++++++++++++++++++ 5 files changed, 243 insertions(+), 20 deletions(-) diff --git a/apps/webapp/app/services/runsReplicationService.server.ts b/apps/webapp/app/services/runsReplicationService.server.ts index bf28b67cd41..3e3d922b739 100644 --- a/apps/webapp/app/services/runsReplicationService.server.ts +++ b/apps/webapp/app/services/runsReplicationService.server.ts @@ -192,6 +192,14 @@ export class RunsReplicationService { */ private _rowIsolationRecoveries = 0; + /** + * Counts batches whose isolation blew the per-batch insert budget (a poison + * flood), so the remaining rows were stripped in one insert instead of + * bisected further. A burst signal; clean rows in those batches also lose + * their JSON. + */ + private _recoveryCapHits = 0; + /** * Counts rows that landed with their un-ingestable JSON column(s) stripped * (the run kept its status, only the output/payload content was lost). @@ -213,6 +221,7 @@ export class RunsReplicationService { private _insertRetriesCounter: Counter; private _eventsProcessedCounter: Counter; private _rowIsolatedBatchesCounter: Counter; + private _recoveryCapHitsCounter: Counter; private _rowsStrippedCounter: Counter; private _rowsDroppedCounter: Counter; private _droppedBatchesCounter: Counter; @@ -278,6 +287,12 @@ export class RunsReplicationService { } ); + this._recoveryCapHitsCounter = this._meter.createCounter("runs_replication.recovery_cap_hits", { + description: + "Batches whose row isolation hit the per-batch insert budget and stripped the remainder in one insert (poison-flood signal)", + unit: "batches", + }); + this._rowsStrippedCounter = this._meter.createCounter("runs_replication.rows_stripped", { description: "Rows landed with their un-ingestable JSON stripped (kept the row, lost only the JSON content)", @@ -472,6 +487,11 @@ export class RunsReplicationService { return this._rowIsolationRecoveries; } + /** Exposed for tests and metrics — batches whose isolation hit the per-batch insert budget. */ + get recoveryCapHits() { + return this._recoveryCapHits; + } + /** Exposed for tests and metrics — rows that landed with their un-ingestable JSON stripped. */ get rowsStripped() { return this._rowsStripped; @@ -1178,6 +1198,11 @@ export class RunsReplicationService { this._rowIsolationRecoveries += 1; this._rowIsolatedBatchesCounter.add(1, { table: contextLabel }); + if (outcome.capped) { + this._recoveryCapHits += 1; + this._recoveryCapHitsCounter.add(1, { table: contextLabel }); + } + if (outcome.rowsStripped > 0) { this._rowsStripped += outcome.rowsStripped; this._rowsStrippedCounter.add(outcome.rowsStripped, { table: contextLabel }); diff --git a/apps/webapp/app/v3/eventRepository/clickhouseEventRepository.server.ts b/apps/webapp/app/v3/eventRepository/clickhouseEventRepository.server.ts index ca6e826dca6..1bdc0636043 100644 --- a/apps/webapp/app/v3/eventRepository/clickhouseEventRepository.server.ts +++ b/apps/webapp/app/v3/eventRepository/clickhouseEventRepository.server.ts @@ -137,6 +137,13 @@ export class ClickhouseEventRepository implements IEventRepository { private _rowIsolationRecoveries = 0; private readonly _rowIsolatedBatchesCounter: Counter; + /** + * Counts batches whose isolation blew the per-batch insert budget (a poison + * flood), so the remaining rows were stripped in one insert. A burst signal. + */ + private _recoveryCapHits = 0; + private readonly _recoveryCapHitsCounter: Counter; + /** * Counts rows that landed with their un-ingestable JSON stripped (the span * kept its place in the trace, only the attributes content was lost). @@ -167,6 +174,11 @@ export class ClickhouseEventRepository implements IEventRepository { "Batches recovered by isolating un-ingestable rows (landed the rest) after a ClickHouse JSON parse error", unit: "batches", }); + this._recoveryCapHitsCounter = meter.createCounter("ingest.flush.recovery_cap_hits", { + description: + "Batches whose row isolation hit the per-batch insert budget and stripped the remainder in one insert (poison-flood signal)", + unit: "batches", + }); this._rowsStrippedCounter = meter.createCounter("ingest.flush.rows_stripped", { description: "Rows landed with their un-ingestable JSON stripped (kept the row, lost only the JSON content)", @@ -236,6 +248,11 @@ export class ClickhouseEventRepository implements IEventRepository { return this._rowIsolationRecoveries; } + /** Exposed for tests and metrics — batches whose isolation hit the per-batch insert budget. */ + get recoveryCapHits() { + return this._recoveryCapHits; + } + /** Exposed for tests and metrics — rows that landed with their un-ingestable JSON stripped. */ get rowsStripped() { return this._rowsStripped; @@ -385,6 +402,11 @@ export class ClickhouseEventRepository implements IEventRepository { this._rowIsolationRecoveries += 1; this._rowIsolatedBatchesCounter.add(1, { table: contextLabel }); + if (outcome.capped) { + this._recoveryCapHits += 1; + this._recoveryCapHitsCounter.add(1, { table: contextLabel }); + } + if (outcome.rowsStripped > 0) { this._rowsStripped += outcome.rowsStripped; this._rowsStrippedCounter.add(outcome.rowsStripped, { table: contextLabel }); diff --git a/apps/webapp/app/v3/eventRepository/sanitizeRowsOnParseError.server.ts b/apps/webapp/app/v3/eventRepository/sanitizeRowsOnParseError.server.ts index 9d0e5882e85..234dc87a7b4 100644 --- a/apps/webapp/app/v3/eventRepository/sanitizeRowsOnParseError.server.ts +++ b/apps/webapp/app/v3/eventRepository/sanitizeRowsOnParseError.server.ts @@ -177,7 +177,21 @@ export type JsonParseRecoveryLogger = { export type JsonParseRecoveryOutcome = | { kind: "inserted"; insertResult: unknown } | { kind: "sanitized"; insertResult: unknown } - | { kind: "recovered"; rowsStripped: number; rowsDropped: number }; + | { kind: "recovered"; rowsStripped: number; rowsDropped: number; capped: boolean }; + +/** + * Default per-batch ceiling on the number of isolation inserts. Bisecting a + * batch tops out around ~3x its row count, so this leaves small batches (e.g. + * the ~50-row run-replication flushes) to isolate precisely even when heavily + * poisoned. It bites on the case that actually needs bounding: a large batch + * (e.g. thousands of trace events) with many un-ingestable rows, where precise + * isolation would otherwise run thousands of inserts and lag the shared + * replication stream. Once exceeded, the remaining subtree is stripped in one + * insert instead of bisected further. + */ +export const DEFAULT_MAX_ISOLATION_INSERTS = 256; + +type IsolationBudget = { inserts: number; capped: boolean }; /** * Shared ClickHouse insert recovery for `Cannot parse JSON object` rejections, @@ -195,7 +209,11 @@ export type JsonParseRecoveryOutcome = * keeps its place in the trace) and only the un-ingestable content is * lost. Clean rows land in full. A row that can't parse even stripped is * dropped and counted. - * 4. Non-parse errors propagate unchanged so the caller's transient-retry + * 4. Isolation is bounded by `maxIsolationInserts`. If a batch is so poisoned + * that it blows the budget, the remaining rows are stripped and landed in + * one insert (`capped`) rather than bisected further, so a poison flood + * degrades gracefully instead of lagging the whole stream. + * 5. Non-parse errors propagate unchanged so the caller's transient-retry * path still handles them. */ export async function insertWithJsonParseRecovery(params: { @@ -206,6 +224,7 @@ export async function insertWithJsonParseRecovery(params: { insert: (rows: T[]) => Promise; insertSync: (rows: T[]) => Promise; stripJsonColumns: (row: T) => T; + maxIsolationInserts?: number; }): Promise { const { rows, contextLabel, logger, logContext, insert, insertSync, stripJsonColumns } = params; @@ -236,26 +255,39 @@ export async function insertWithJsonParseRecovery(params: { } } + const budget: IsolationBudget = { + inserts: params.maxIsolationInserts ?? DEFAULT_MAX_ISOLATION_INSERTS, + capped: false, + }; const { rowsStripped, rowsDropped } = await isolateAndStripPoisonRows( rows, insertSync, - stripJsonColumns + stripJsonColumns, + budget ); - logger.info( - "Isolated un-ingestable rows after ClickHouse JSON parse error — landed the batch with poison JSON stripped", - { - ...logContext, - contextLabel, - batchSize: rows.length, - rowsStripped, - rowsDropped, - sampleRow: JSON.stringify(rows[0] ?? null).slice(0, 1024), - clickhouseError: firstMessage.split("\n")[0], - } - ); + const meta = { + ...logContext, + contextLabel, + batchSize: rows.length, + rowsStripped, + rowsDropped, + sampleRow: JSON.stringify(rows[0] ?? null).slice(0, 1024), + clickhouseError: firstMessage.split("\n")[0], + }; + if (budget.capped) { + logger.warn( + "Recovery cost cap hit — stripped the remaining rows in one insert (clean rows in the capped subtree also lost their JSON)", + meta + ); + } else { + logger.info( + "Isolated un-ingestable rows after ClickHouse JSON parse error — landed the batch with poison JSON stripped", + meta + ); + } - return { kind: "recovered", rowsStripped, rowsDropped }; + return { kind: "recovered", rowsStripped, rowsDropped, capped: budget.capped }; } } @@ -266,19 +298,34 @@ export async function insertWithJsonParseRecovery(params: { * lands. A row that can't parse even stripped is dropped. All inserts are * synchronous so each subset's parse error surfaces. The two halves are probed * concurrently so recovery wall-clock stays ~O(log n) round-trips rather than - * O(n), which matters when a poison burst would otherwise lag the shared - * replication stream. Returns exact counts. + * O(n). When `budget.inserts` is exhausted the remaining subtree is stripped + * and landed in a single insert (setting `budget.capped`) so a poison flood + * cannot do unbounded work. Returns exact counts. */ async function isolateAndStripPoisonRows( rows: T[], insertSync: (rows: T[]) => Promise, - stripJsonColumns: (row: T) => T + stripJsonColumns: (row: T) => T, + budget: IsolationBudget ): Promise<{ rowsStripped: number; rowsDropped: number }> { if (rows.length === 0) { return { rowsStripped: 0, rowsDropped: 0 }; } + if (budget.inserts <= 0) { + budget.capped = true; + budget.inserts -= 1; + try { + await insertSync(rows.map(stripJsonColumns)); + return { rowsStripped: rows.length, rowsDropped: 0 }; + } catch (error) { + if (!isClickHouseJsonParseError(error)) throw error; + return { rowsStripped: 0, rowsDropped: rows.length }; + } + } + if (rows.length === 1) { + budget.inserts -= 1; try { await insertSync([stripJsonColumns(rows[0])]); return { rowsStripped: 1, rowsDropped: 0 }; @@ -291,12 +338,13 @@ async function isolateAndStripPoisonRows( const mid = rows.length >> 1; const recoverHalf = async (half: T[]) => { + budget.inserts -= 1; try { await insertSync(half); return { rowsStripped: 0, rowsDropped: 0 }; } catch (error) { if (!isClickHouseJsonParseError(error)) throw error; - return isolateAndStripPoisonRows(half, insertSync, stripJsonColumns); + return isolateAndStripPoisonRows(half, insertSync, stripJsonColumns, budget); } }; diff --git a/apps/webapp/test/runsReplicationJsonRecoveryBenchmark.test.ts b/apps/webapp/test/runsReplicationJsonRecoveryBenchmark.test.ts index b30454a5d80..cf4ed8a2766 100644 --- a/apps/webapp/test/runsReplicationJsonRecoveryBenchmark.test.ts +++ b/apps/webapp/test/runsReplicationJsonRecoveryBenchmark.test.ts @@ -211,6 +211,7 @@ async function runScenario( console.log(`Repl dur: ${replication.duration.toFixed(0)}ms`); console.log(`Throughput: ${throughput.toFixed(0)} runs/sec`); console.log(`Row-isolation recoveries: ${service.rowIsolationRecoveries}`); + console.log(`Recovery cap hits: ${service.recoveryCapHits}`); console.log(`Rows stripped (kept row, lost JSON): ${service.rowsStripped}`); console.log(`Rows dropped (unrecoverable): ${service.permanentlyDroppedRows}`); console.log(`Dropped batches (whole): ${service.permanentlyDroppedBatches}`); @@ -275,6 +276,7 @@ describe("RunsReplicationService JSON-recovery ELU benchmark", () => { expect(poisoned.replication.count).toBe(poisoned.expectedLanded); expect(poisoned.service.permanentlyDroppedBatches).toBe(0); expect(poisoned.service.permanentlyDroppedRows).toBe(0); + expect(poisoned.service.recoveryCapHits).toBe(0); expect(poisoned.service.rowIsolationRecoveries).toBeGreaterThanOrEqual(1); expect(poisoned.service.rowsStripped).toBe(poisoned.producerStats.poisoned); } diff --git a/apps/webapp/test/sanitizeRowsOnParseError.test.ts b/apps/webapp/test/sanitizeRowsOnParseError.test.ts index e3353176624..9b3fcaca3d5 100644 --- a/apps/webapp/test/sanitizeRowsOnParseError.test.ts +++ b/apps/webapp/test/sanitizeRowsOnParseError.test.ts @@ -1,6 +1,7 @@ import { describe, it, expect } from "vitest"; import { INVALID_UTF16_SENTINEL, + insertWithJsonParseRecovery, isClickHouseJsonParseError, parseRowNumberFromError, sanitizeRows, @@ -10,6 +11,32 @@ import { const HIGH_SURROGATE = "\uD800"; const LOW_SURROGATE = "\uDC00"; +type FakeRow = { id: number; poison?: boolean; unstrippable?: boolean; stripped?: boolean }; + +const silentLogger = { info: () => {}, warn: () => {} }; + +function parseError() { + return new Error("Cannot parse JSON object here: {...}: (at row 1)"); +} + +/** + * Builds insert doubles for `insertWithJsonParseRecovery`: a synchronous insert + * that throws a parse error if any row is still poison/unstrippable and + * otherwise records the rows as landed, plus a strip that clears the poison + * marker (but cannot fix an `unstrippable` row). + */ +function makeHarness() { + const landed: FakeRow[] = []; + const insertSync = async (rows: FakeRow[]) => { + if (rows.some((r) => r.poison || r.unstrippable)) throw parseError(); + landed.push(...rows); + return undefined; + }; + const stripJsonColumns = (row: FakeRow): FakeRow => + row.unstrippable ? row : { ...row, poison: false, stripped: true }; + return { landed, insertSync, stripJsonColumns }; +} + describe("isClickHouseJsonParseError", () => { it("recognises ClickHouse's parse-error string", () => { const err = new Error( @@ -294,3 +321,102 @@ describe("sanitizeRows", () => { expect(rows[1].attributes.bigint).toBe("-100000000000000000000"); }); }); + +describe("insertWithJsonParseRecovery", () => { + const clean = (id: number): FakeRow => ({ id }); + + it("inserts a healthy batch with no recovery", async () => { + const { landed, insertSync, stripJsonColumns } = makeHarness(); + const rows = [clean(0), clean(1), clean(2)]; + + const outcome = await insertWithJsonParseRecovery({ + rows, + contextLabel: "test", + logger: silentLogger, + insert: insertSync, + insertSync, + stripJsonColumns, + }); + + expect(outcome.kind).toBe("inserted"); + expect(landed).toHaveLength(3); + }); + + it("isolates a poison row, strips it, and lands the rest in full", async () => { + const { landed, insertSync, stripJsonColumns } = makeHarness(); + const rows = [clean(0), clean(1), { id: 2, poison: true }, clean(3), clean(4)]; + + const outcome = await insertWithJsonParseRecovery({ + rows, + contextLabel: "test", + logger: silentLogger, + insert: insertSync, + insertSync, + stripJsonColumns, + }); + + expect(outcome).toEqual({ kind: "recovered", rowsStripped: 1, rowsDropped: 0, capped: false }); + expect(landed.map((r) => r.id).sort((a, b) => a - b)).toEqual([0, 1, 2, 3, 4]); + expect(landed.find((r) => r.id === 2)?.stripped).toBe(true); + expect(landed.filter((r) => r.id !== 2).every((r) => !r.stripped)).toBe(true); + }); + + it("drops a row that cannot parse even after stripping", async () => { + const { landed, insertSync, stripJsonColumns } = makeHarness(); + const rows = [clean(0), { id: 1, unstrippable: true }, clean(2)]; + + const outcome = await insertWithJsonParseRecovery({ + rows, + contextLabel: "test", + logger: silentLogger, + insert: insertSync, + insertSync, + stripJsonColumns, + }); + + expect(outcome).toEqual({ kind: "recovered", rowsStripped: 0, rowsDropped: 1, capped: false }); + expect(landed.map((r) => r.id).sort((a, b) => a - b)).toEqual([0, 2]); + }); + + it("caps recovery cost on a poison flood by stripping the remainder in one insert", async () => { + const { landed, insertSync, stripJsonColumns } = makeHarness(); + const rows = Array.from({ length: 8 }, (_, id) => ({ id, poison: true as const })); + + const outcome = await insertWithJsonParseRecovery({ + rows, + contextLabel: "test", + logger: silentLogger, + insert: insertSync, + insertSync, + stripJsonColumns, + maxIsolationInserts: 2, + }); + + expect(outcome.kind).toBe("recovered"); + if (outcome.kind === "recovered") { + expect(outcome.capped).toBe(true); + expect(outcome.rowsStripped).toBe(8); + expect(outcome.rowsDropped).toBe(0); + } + expect(landed).toHaveLength(8); + expect(landed.every((r) => r.stripped)).toBe(true); + }); + + it("rethrows non-parse errors so the caller's transient-retry path handles them", async () => { + const stripJsonColumns = (row: FakeRow): FakeRow => row; + const insert = async () => { + throw new Error("Connection refused"); + }; + + await expect( + insertWithJsonParseRecovery({ + rows: [clean(0)], + contextLabel: "test", + logger: silentLogger, + insert, + insertSync: insert, + stripJsonColumns, + }) + ).rejects.toThrow("Connection refused"); + }); +}); From 1ce21774b0d9569416bdd40a0e24fdbc064913a3 Mon Sep 17 00:00:00 2001 From: Eric Allam Date: Fri, 24 Jul 2026 11:55:46 +0100 Subject: [PATCH 5/9] fix(webapp): only count a dropped batch when nothing landed, and assert the isolation cap bounds inserts The whole-batch-dropped counter fired whenever a recovered batch stripped no rows but dropped at least one, which mislabels a batch where clean rows landed alongside one unrecoverable row. Gate it on rowsDropped === batchSize (nothing landed) instead. The cap unit test now also asserts the bounded insert count so a broken budget cannot pass unnoticed. --- .../app/services/runsReplicationService.server.ts | 12 ++++++++---- .../clickhouseEventRepository.server.ts | 12 ++++++++---- apps/webapp/test/sanitizeRowsOnParseError.test.ts | 7 +++++-- 3 files changed, 21 insertions(+), 10 deletions(-) diff --git a/apps/webapp/app/services/runsReplicationService.server.ts b/apps/webapp/app/services/runsReplicationService.server.ts index 3e3d922b739..596fb2f53b6 100644 --- a/apps/webapp/app/services/runsReplicationService.server.ts +++ b/apps/webapp/app/services/runsReplicationService.server.ts @@ -1142,7 +1142,7 @@ export class RunsReplicationService { insertSync: (rows) => rawInsert(rows, { async_insert: 0 }), stripJsonColumns: stripTaskRunJsonColumns, }); - this.#recordRecoveryOutcome(outcome, "task_runs_v2"); + this.#recordRecoveryOutcome(outcome, "task_runs_v2", taskRunInserts.length); return outcome; }); } @@ -1185,12 +1185,16 @@ export class RunsReplicationService { insertSync: (rows) => rawInsert(rows, { async_insert: 0 }), stripJsonColumns: stripPayloadJsonColumns, }); - this.#recordRecoveryOutcome(outcome, "raw_task_runs_payload_v1"); + this.#recordRecoveryOutcome(outcome, "raw_task_runs_payload_v1", payloadInserts.length); return outcome; }); } - #recordRecoveryOutcome(outcome: JsonParseRecoveryOutcome, contextLabel: string) { + #recordRecoveryOutcome( + outcome: JsonParseRecoveryOutcome, + contextLabel: string, + batchSize: number + ) { if (outcome.kind !== "recovered") { return; } @@ -1211,7 +1215,7 @@ export class RunsReplicationService { if (outcome.rowsDropped > 0) { this._permanentlyDroppedRows += outcome.rowsDropped; this._rowsDroppedCounter.add(outcome.rowsDropped, { table: contextLabel }); - if (outcome.rowsStripped === 0) { + if (outcome.rowsDropped === batchSize) { this._permanentlyDroppedBatches += 1; this._droppedBatchesCounter.add(1, { table: contextLabel }); } diff --git a/apps/webapp/app/v3/eventRepository/clickhouseEventRepository.server.ts b/apps/webapp/app/v3/eventRepository/clickhouseEventRepository.server.ts index 1bdc0636043..e1205d3d57d 100644 --- a/apps/webapp/app/v3/eventRepository/clickhouseEventRepository.server.ts +++ b/apps/webapp/app/v3/eventRepository/clickhouseEventRepository.server.ts @@ -354,7 +354,7 @@ export class ClickhouseEventRepository implements IEventRepository { insertSync: (rows) => rawInsert(rows, { async_insert: 0 }), stripJsonColumns: stripTaskEventJsonColumns, }); - this.#recordRecoveryOutcome(outcome, contextLabel); + this.#recordRecoveryOutcome(outcome, contextLabel, events.length); logger.debug("ClickhouseEventRepository.flushBatch Inserted batch into clickhouse", { events: events.length, @@ -386,7 +386,7 @@ export class ClickhouseEventRepository implements IEventRepository { insertSync: (batch) => rawInsert(batch, { async_insert: 0 }), stripJsonColumns: (row) => row, }); - this.#recordRecoveryOutcome(outcome, "llm_metrics_v1"); + this.#recordRecoveryOutcome(outcome, "llm_metrics_v1", rows.length); logger.debug("ClickhouseEventRepository.flushLlmMetricsBatch Inserted LLM metrics batch", { rows: rows.length, @@ -394,7 +394,11 @@ export class ClickhouseEventRepository implements IEventRepository { }); } - #recordRecoveryOutcome(outcome: JsonParseRecoveryOutcome, contextLabel: string) { + #recordRecoveryOutcome( + outcome: JsonParseRecoveryOutcome, + contextLabel: string, + batchSize: number + ) { if (outcome.kind !== "recovered") { return; } @@ -415,7 +419,7 @@ export class ClickhouseEventRepository implements IEventRepository { if (outcome.rowsDropped > 0) { this._permanentlyDroppedRows += outcome.rowsDropped; this._rowsDroppedCounter.add(outcome.rowsDropped, { table: contextLabel }); - if (outcome.rowsStripped === 0) { + if (outcome.rowsDropped === batchSize) { this._permanentlyDroppedBatches += 1; this._droppedBatchesCounter.add(1, { table: contextLabel }); } diff --git a/apps/webapp/test/sanitizeRowsOnParseError.test.ts b/apps/webapp/test/sanitizeRowsOnParseError.test.ts index 9b3fcaca3d5..01141228bf1 100644 --- a/apps/webapp/test/sanitizeRowsOnParseError.test.ts +++ b/apps/webapp/test/sanitizeRowsOnParseError.test.ts @@ -27,14 +27,16 @@ function parseError() { */ function makeHarness() { const landed: FakeRow[] = []; + let insertCalls = 0; const insertSync = async (rows: FakeRow[]) => { + insertCalls += 1; if (rows.some((r) => r.poison || r.unstrippable)) throw parseError(); landed.push(...rows); return undefined; }; const stripJsonColumns = (row: FakeRow): FakeRow => row.unstrippable ? row : { ...row, poison: false, stripped: true }; - return { landed, insertSync, stripJsonColumns }; + return { landed, insertSync, stripJsonColumns, insertCalls: () => insertCalls }; } describe("isClickHouseJsonParseError", () => { @@ -379,7 +381,7 @@ describe("insertWithJsonParseRecovery", () => { }); it("caps recovery cost on a poison flood by stripping the remainder in one insert", async () => { - const { landed, insertSync, stripJsonColumns } = makeHarness(); + const { landed, insertSync, stripJsonColumns, insertCalls } = makeHarness(); const rows = Array.from({ length: 8 }, (_, id) => ({ id, poison: true as const })); const outcome = await insertWithJsonParseRecovery({ @@ -400,6 +402,7 @@ describe("insertWithJsonParseRecovery", () => { } expect(landed).toHaveLength(8); expect(landed.every((r) => r.stripped)).toBe(true); + expect(insertCalls()).toBeLessThanOrEqual(6); }); it("rethrows non-parse errors so the caller's transient-retry path handles them", async () => { From 5079b65f8a99546a2628f3de343f705d64aa8213 Mon Sep 17 00:00:00 2001 From: Eric Allam Date: Fri, 24 Jul 2026 13:40:21 +0100 Subject: [PATCH 6/9] test(webapp): sample benchmark ELU as a per-window delta and build poison JSON iteratively The ELU monitor called eventLoopUtilization() with no args, which returns the cumulative average since thread start, so each sample smoothed out the spikes the percentile stats are meant to catch; sample the delta between consecutive readings instead. The benchmark producer now builds the deeply nested poison JSON as a string iteratively (and validates the depth) so it does not depend on runtime-specific deep JSON.stringify support. --- .../test/runsReplicationBenchmark.producer.ts | 13 +++++++------ .../runsReplicationJsonRecoveryBenchmark.test.ts | 6 ++++-- 2 files changed, 11 insertions(+), 8 deletions(-) diff --git a/apps/webapp/test/runsReplicationBenchmark.producer.ts b/apps/webapp/test/runsReplicationBenchmark.producer.ts index efa981a3bf6..3f34d5c9f80 100644 --- a/apps/webapp/test/runsReplicationBenchmark.producer.ts +++ b/apps/webapp/test/runsReplicationBenchmark.producer.ts @@ -19,12 +19,13 @@ interface ProducerConfig { poisonDepth?: number; } -function deeplyNestedOutput(depth: number): Record { - let node: Record = { leaf: 1 }; - for (let i = 0; i < depth; i++) { - node = { [`k${i}`]: node }; +function deeplyNestedJson(depth: number): string { + const safeDepth = Number.isSafeInteger(depth) && depth >= 0 ? depth : 0; + const open: string[] = []; + for (let i = 0; i < safeDepth; i++) { + open.push(`{"k${i}":`); } - return node; + return open.join("") + '{"leaf":1}' + "}".repeat(safeDepth); } // Error templates for realistic variety @@ -158,7 +159,7 @@ async function runProducer(config: ProducerConfig) { } if (isPoison) { - runData.output = JSON.stringify(deeplyNestedOutput(poisonDepth)); + runData.output = deeplyNestedJson(poisonDepth); runData.outputType = "application/json"; poisoned++; } diff --git a/apps/webapp/test/runsReplicationJsonRecoveryBenchmark.test.ts b/apps/webapp/test/runsReplicationJsonRecoveryBenchmark.test.ts index cf4ed8a2766..b672d9968a3 100644 --- a/apps/webapp/test/runsReplicationJsonRecoveryBenchmark.test.ts +++ b/apps/webapp/test/runsReplicationJsonRecoveryBenchmark.test.ts @@ -27,9 +27,11 @@ class ELUMonitor { start(intervalMs = 100) { this.samples = []; - performance.eventLoopUtilization(); + let last = performance.eventLoopUtilization(); this.interval = setInterval(() => { - this.samples.push(performance.eventLoopUtilization().utilization * 100); + const current = performance.eventLoopUtilization(); + this.samples.push(performance.eventLoopUtilization(current, last).utilization * 100); + last = current; }, intervalMs); } From 893f32069b9b5d17fc80e225b92f45f14653261d Mon Sep 17 00:00:00 2001 From: Eric Allam Date: Fri, 24 Jul 2026 16:21:57 +0100 Subject: [PATCH 7/9] fix(webapp,clickhouse): stop one un-ingestable JSON row dropping its whole ClickHouse batch When a single run output, trace span, or payload contained JSON ClickHouse could not ingest (for example nesting past its depth limit), the whole insert batch was rejected and those runs and spans silently vanished from the runs list, traces, and logs. Recovery is now per-table: - Runs: follow ClickHouse's failing-row hint to strip just the un-ingestable JSON column(s) so the run still lands with its status, up to a configurable limit (RUN_REPLICATION_MAX_POISON_STRIPS_PER_BATCH, default 1). Past the limit, land the rest with allow_errors and skip the remainder, so recovery cost stays flat on large flushes instead of re-sending the batch per row. - Trace events and payloads: land the batch with allow_errors so the good rows land in one pass and only the un-ingestable rows are skipped. Reading the failing-row hint needs a patch to @clickhouse/client-common, whose error parser otherwise discards the row number from the server response. --- ...uns-list-batch-drop-on-unparseable-json.md | 2 +- apps/webapp/app/env.server.ts | 1 + .../runsReplicationInstance.server.ts | 1 + .../services/runsReplicationService.server.ts | 37 +- .../clickhouseEventRepository.server.ts | 28 +- .../sanitizeRowsOnParseError.server.ts | 313 ++++++++++------- ...ckhouseEventRepositoryJsonRecovery.test.ts | 8 +- ...nsReplicationJsonRecoveryBenchmark.test.ts | 1 + .../runsReplicationService.part10.test.ts | 230 ++++++++---- .../test/sanitizeRowsOnParseError.test.ts | 326 +++++++++++++++--- .../clickhouse/src/client/client.ts | 13 +- .../clickhouse/src/client/errors.ts | 4 +- package.json | 3 +- .../@clickhouse__client-common@1.12.1.patch | 29 ++ pnpm-lock.yaml | 7 +- 15 files changed, 730 insertions(+), 273 deletions(-) create mode 100644 patches/@clickhouse__client-common@1.12.1.patch diff --git a/.server-changes/fix-runs-list-batch-drop-on-unparseable-json.md b/.server-changes/fix-runs-list-batch-drop-on-unparseable-json.md index e6fa47e1a88..fe56e609510 100644 --- a/.server-changes/fix-runs-list-batch-drop-on-unparseable-json.md +++ b/.server-changes/fix-runs-list-batch-drop-on-unparseable-json.md @@ -3,4 +3,4 @@ area: webapp type: fix --- -Fixed a rare case where a single run or span carrying data that could not be ingested would make other runs or trace events in the same batch go missing from the runs list, traces, and logs. Now the whole batch is kept: the affected item still appears (a run keeps its status, a span keeps its place in the trace) with only its un-ingestable content dropped, and everything else is stored normally. +Fixed a rare case where a single run or span carrying data that could not be ingested would make other runs or trace events in the same batch go missing from the runs list, traces, and logs. Now the rest of the batch is always kept: an affected run still appears with its status (only its un-ingestable output is dropped), and an affected trace event or payload is skipped instead of taking down everything around it. diff --git a/apps/webapp/app/env.server.ts b/apps/webapp/app/env.server.ts index 2d28827f7d7..45ef62b9dbe 100644 --- a/apps/webapp/app/env.server.ts +++ b/apps/webapp/app/env.server.ts @@ -1673,6 +1673,7 @@ const EnvironmentSchema = z RUN_REPLICATION_MAX_FLUSH_CONCURRENCY: z.coerce.number().int().default(2), RUN_REPLICATION_FLUSH_INTERVAL_MS: z.coerce.number().int().default(1000), RUN_REPLICATION_FLUSH_BATCH_SIZE: z.coerce.number().int().default(100), + RUN_REPLICATION_MAX_POISON_STRIPS_PER_BATCH: z.coerce.number().int().default(1), RUN_REPLICATION_LEADER_LOCK_TIMEOUT_MS: z.coerce.number().int().default(30_000), RUN_REPLICATION_LEADER_LOCK_EXTEND_INTERVAL_MS: z.coerce.number().int().default(10_000), RUN_REPLICATION_ACK_INTERVAL_SECONDS: z.coerce.number().int().default(10), diff --git a/apps/webapp/app/services/runsReplicationInstance.server.ts b/apps/webapp/app/services/runsReplicationInstance.server.ts index 15950aa9008..164ce07fb92 100644 --- a/apps/webapp/app/services/runsReplicationInstance.server.ts +++ b/apps/webapp/app/services/runsReplicationInstance.server.ts @@ -117,6 +117,7 @@ function initializeRunsReplicationInstance() { maxFlushConcurrency: env.RUN_REPLICATION_MAX_FLUSH_CONCURRENCY, flushIntervalMs: env.RUN_REPLICATION_FLUSH_INTERVAL_MS, flushBatchSize: env.RUN_REPLICATION_FLUSH_BATCH_SIZE, + maxPoisonStripsPerBatch: env.RUN_REPLICATION_MAX_POISON_STRIPS_PER_BATCH, leaderLockTimeoutMs: env.RUN_REPLICATION_LEADER_LOCK_TIMEOUT_MS, leaderLockExtendIntervalMs: env.RUN_REPLICATION_LEADER_LOCK_EXTEND_INTERVAL_MS, leaderLockAcquireAdditionalTimeMs: env.RUN_REPLICATION_LEADER_LOCK_ADDITIONAL_TIME_MS, diff --git a/apps/webapp/app/services/runsReplicationService.server.ts b/apps/webapp/app/services/runsReplicationService.server.ts index 596fb2f53b6..555bca49a6b 100644 --- a/apps/webapp/app/services/runsReplicationService.server.ts +++ b/apps/webapp/app/services/runsReplicationService.server.ts @@ -7,7 +7,6 @@ import { composeTaskRunVersion, getPayloadField, getTaskRunField, - PAYLOAD_INDEX, TASK_RUN_INDEX, } from "@internal/clickhouse"; import { type RedisOptions } from "@internal/redis"; @@ -44,7 +43,8 @@ import { detectBadJsonStrings } from "~/utils/detectBadJsonStrings"; import { calculateErrorFingerprint } from "~/utils/errorFingerprinting"; import { baseWorkerQueue } from "~/runEngine/concerns/workerQueueSplit.server"; import { - insertWithJsonParseRecovery, + insertWithBadRowSkip, + insertWithLimitedStrip, type JsonParseRecoveryOutcome, } from "~/v3/eventRepository/sanitizeRowsOnParseError.server"; @@ -114,6 +114,7 @@ export type RunsReplicationServiceOptions = { insertMaxDelayMs?: number; disablePayloadInsert?: boolean; disableErrorFingerprinting?: boolean; + maxPoisonStripsPerBatch?: number; }; type PostgresTaskRun = TaskRun & { masterQueue: string }; @@ -1133,14 +1134,24 @@ export class RunsReplicationService { return insertResult; }; - const outcome = await insertWithJsonParseRecovery({ + const outcome = await insertWithLimitedStrip({ rows: taskRunInserts, contextLabel: "task_runs_v2", logger: this.logger, logContext: { attempt }, insert: (rows) => rawInsert(rows), - insertSync: (rows) => rawInsert(rows, { async_insert: 0 }), + insertSync: (rows) => + rawInsert(rows, { async_insert: 0, input_format_parallel_parsing: 0 }), + insertAllowingBadRows: (rows) => + rawInsert(rows, { + async_insert: 0, + input_format_parallel_parsing: 0, + input_format_allow_errors_num: String(rows.length), + input_format_allow_errors_ratio: 1, + }), stripJsonColumns: stripTaskRunJsonColumns, + maxPoisonStrips: this.options.maxPoisonStripsPerBatch, + hasMaterializedViews: true, }); this.#recordRecoveryOutcome(outcome, "task_runs_v2", taskRunInserts.length); return outcome; @@ -1176,14 +1187,20 @@ export class RunsReplicationService { return insertResult; }; - const outcome = await insertWithJsonParseRecovery({ + const outcome = await insertWithBadRowSkip({ rows: payloadInserts, contextLabel: "raw_task_runs_payload_v1", logger: this.logger, logContext: { attempt }, insert: (rows) => rawInsert(rows), - insertSync: (rows) => rawInsert(rows, { async_insert: 0 }), - stripJsonColumns: stripPayloadJsonColumns, + insertAllowingBadRows: (rows) => + rawInsert(rows, { + async_insert: 0, + input_format_parallel_parsing: 0, + input_format_allow_errors_num: String(rows.length), + input_format_allow_errors_ratio: 1, + }), + hasMaterializedViews: false, }); this.#recordRecoveryOutcome(outcome, "raw_task_runs_payload_v1", payloadInserts.length); return outcome; @@ -1587,9 +1604,3 @@ function stripTaskRunJsonColumns(row: TaskRunInsertArray): TaskRunInsertArray { stripped[TASK_RUN_INDEX.error] = STRIPPED_JSON; return stripped; } - -function stripPayloadJsonColumns(row: PayloadInsertArray): PayloadInsertArray { - const stripped = [...row] as PayloadInsertArray; - stripped[PAYLOAD_INDEX.payload] = STRIPPED_JSON; - return stripped; -} diff --git a/apps/webapp/app/v3/eventRepository/clickhouseEventRepository.server.ts b/apps/webapp/app/v3/eventRepository/clickhouseEventRepository.server.ts index e1205d3d57d..3a2c34f0dfc 100644 --- a/apps/webapp/app/v3/eventRepository/clickhouseEventRepository.server.ts +++ b/apps/webapp/app/v3/eventRepository/clickhouseEventRepository.server.ts @@ -67,7 +67,7 @@ import type { TraceSummary, } from "./eventRepository.types"; import { - insertWithJsonParseRecovery, + insertWithBadRowSkip, type JsonParseRecoveryOutcome, } from "./sanitizeRowsOnParseError.server"; @@ -345,14 +345,19 @@ export class ClickhouseEventRepository implements IEventRepository { return insertResult; }; - const outcome = await insertWithJsonParseRecovery({ + const outcome = await insertWithBadRowSkip({ rows: events, contextLabel, logger, logContext: { flushId, version: this._version }, insert: (rows) => rawInsert(rows), - insertSync: (rows) => rawInsert(rows, { async_insert: 0 }), - stripJsonColumns: stripTaskEventJsonColumns, + insertAllowingBadRows: (rows) => + rawInsert(rows, { + async_insert: 0, + input_format_parallel_parsing: 0, + input_format_allow_errors_num: String(rows.length), + input_format_allow_errors_ratio: 1, + }), }); this.#recordRecoveryOutcome(outcome, contextLabel, events.length); @@ -377,14 +382,19 @@ export class ClickhouseEventRepository implements IEventRepository { return insertResult; }; - const outcome = await insertWithJsonParseRecovery({ + const outcome = await insertWithBadRowSkip({ rows, contextLabel: "llm_metrics_v1", logger, logContext: { flushId }, insert: (batch) => rawInsert(batch), - insertSync: (batch) => rawInsert(batch, { async_insert: 0 }), - stripJsonColumns: (row) => row, + insertAllowingBadRows: (batch) => + rawInsert(batch, { + async_insert: 0, + input_format_parallel_parsing: 0, + input_format_allow_errors_num: String(batch.length), + input_format_allow_errors_ratio: 1, + }), }); this.#recordRecoveryOutcome(outcome, "llm_metrics_v1", rows.length); @@ -2945,7 +2955,3 @@ function formatClickhouseUnsignedIntegerString(value: number | bigint): string { return Math.floor(value).toString(); } - -function stripTaskEventJsonColumns(row: T): T { - return { ...row, attributes: {} }; -} diff --git a/apps/webapp/app/v3/eventRepository/sanitizeRowsOnParseError.server.ts b/apps/webapp/app/v3/eventRepository/sanitizeRowsOnParseError.server.ts index 234dc87a7b4..d2e87230f72 100644 --- a/apps/webapp/app/v3/eventRepository/sanitizeRowsOnParseError.server.ts +++ b/apps/webapp/app/v3/eventRepository/sanitizeRowsOnParseError.server.ts @@ -169,6 +169,14 @@ export function errorMessage(err: unknown): string { : String(err); } +export function rawErrorMessage(err: unknown): string { + if (typeof err === "object" && err !== null) { + const raw = (err as { rawMessage?: unknown }).rawMessage; + if (typeof raw === "string" && raw.length > 0) return raw; + } + return errorMessage(err); +} + export type JsonParseRecoveryLogger = { info: (message: string, meta?: Record) => void; warn: (message: string, meta?: Record) => void; @@ -180,53 +188,54 @@ export type JsonParseRecoveryOutcome = | { kind: "recovered"; rowsStripped: number; rowsDropped: number; capped: boolean }; /** - * Default per-batch ceiling on the number of isolation inserts. Bisecting a - * batch tops out around ~3x its row count, so this leaves small batches (e.g. - * the ~50-row run-replication flushes) to isolate precisely even when heavily - * poisoned. It bites on the case that actually needs bounding: a large batch - * (e.g. thousands of trace events) with many un-ingestable rows, where precise - * isolation would otherwise run thousands of inserts and lag the shared - * replication stream. Once exceeded, the remaining subtree is stripped in one - * insert instead of bisected further. + * Default number of poison rows to isolate-and-strip precisely before bailing + * to a single `allow_errors` skip insert. One covers the common case (a single + * un-ingestable run in a flush) exactly, keeping that run's status. The bound + * matters because run-replication flushes are large (thousands of rows in prod) + * and stripping re-sends the whole batch once per poison row: without a small + * limit, a burst of un-ingestable runs in one flush would re-parse a large + * batch many times on the shared ClickHouse server. */ -export const DEFAULT_MAX_ISOLATION_INSERTS = 256; - -type IsolationBudget = { inserts: number; capped: boolean }; +export const DEFAULT_MAX_POISON_STRIPS = 1; /** - * Shared ClickHouse insert recovery for `Cannot parse JSON object` rejections, - * used by both ClickHouse writers (run replication and the trace/event - * repository) so a single un-ingestable row never drops its whole batch. + * ClickHouse insert recovery for `Cannot parse JSON object` rejections on the + * runs table, where the poison run should KEEP its status (its row lands with + * its JSON column emptied) rather than be dropped. * * 1. Try the insert. Healthy batches pay zero recovery cost. * 2. On a parse error, `sanitizeRows` losslessly repairs what it can in place - * (lone UTF-16 surrogates, out-of-range integers) and retries once. A - * clean retry keeps every row untouched. - * 3. If the sanitizer can't help, isolate the un-ingestable rows by - * bisection (`at row N` is unstable under parallel parsing) and re-insert - * each poison row with its JSON column(s) emptied via `stripJsonColumns`, - * so the row still lands (e.g. a run keeps its terminal status, a span - * keeps its place in the trace) and only the un-ingestable content is - * lost. Clean rows land in full. A row that can't parse even stripped is - * dropped and counted. - * 4. Isolation is bounded by `maxIsolationInserts`. If a batch is so poisoned - * that it blows the budget, the remaining rows are stripped and landed in - * one insert (`capped`) rather than bisected further, so a poison flood - * degrades gracefully instead of lagging the whole stream. - * 5. Non-parse errors propagate unchanged so the caller's transient-retry - * path still handles them. + * (lone UTF-16 surrogates, out-of-range integers) and retries once. + * 3. If the sanitizer can't help, follow ClickHouse's `at row N` hint to the + * un-ingestable row and re-insert with that row's JSON column(s) emptied + * via `stripJsonColumns`, up to `maxPoisonStrips` rows. Each stripped run + * still lands (keeps its terminal status); only its un-ingestable JSON is + * lost. `insertSync` disables parallel parsing so `at row N` is reliable. + * 4. Cost bound: once `maxPoisonStrips` rows have been stripped and the batch + * STILL fails (or the failing row can't be located), stop stripping and + * land the batch with one `allow_errors` insert — the stripped rows and + * every clean row land in a single pass and the remaining un-ingestable + * rows are skipped. Recovery stays a fixed handful of inserts no matter how + * large or poisoned the batch is (`capped` marks that the bail was taken). + * 5. Non-parse errors propagate unchanged. */ -export async function insertWithJsonParseRecovery(params: { +export async function insertWithLimitedStrip(params: { rows: T[]; contextLabel: string; logger: JsonParseRecoveryLogger; logContext?: Record; insert: (rows: T[]) => Promise; insertSync: (rows: T[]) => Promise; + insertAllowingBadRows: (rows: T[]) => Promise; stripJsonColumns: (row: T) => T; - maxIsolationInserts?: number; + maxPoisonStrips?: number; + hasMaterializedViews?: boolean; }): Promise { - const { rows, contextLabel, logger, logContext, insert, insertSync, stripJsonColumns } = params; + const { rows, contextLabel, logger, logContext, insert, insertSync, insertAllowingBadRows } = + params; + const stripJsonColumns = params.stripJsonColumns; + const maxPoisonStrips = params.maxPoisonStrips ?? DEFAULT_MAX_POISON_STRIPS; + const hasMaterializedViews = params.hasMaterializedViews ?? true; try { return { kind: "inserted", insertResult: await insert(rows) }; @@ -234,7 +243,6 @@ export async function insertWithJsonParseRecovery(params: { if (!isClickHouseJsonParseError(firstError)) throw firstError; const firstMessage = errorMessage(firstError); - const rowHint = parseRowNumberFromError(firstMessage); const { rowsTouched, fieldsSanitized } = sanitizeRows(rows); if (fieldsSanitized > 0) { @@ -242,7 +250,6 @@ export async function insertWithJsonParseRecovery(params: { ...logContext, contextLabel, batchSize: rows.length, - clickhouseRowHint: rowHint, rowsTouched, fieldsSanitized, clickhouseError: firstMessage.split("\n")[0], @@ -255,106 +262,170 @@ export async function insertWithJsonParseRecovery(params: { } } - const budget: IsolationBudget = { - inserts: params.maxIsolationInserts ?? DEFAULT_MAX_ISOLATION_INSERTS, - capped: false, - }; - const { rowsStripped, rowsDropped } = await isolateAndStripPoisonRows( - rows, - insertSync, - stripJsonColumns, - budget - ); + const working = rows.slice(); + const stripped = new Array(working.length).fill(false); + let rowsStripped = 0; + + let guard = maxPoisonStrips + 2; + while (guard-- > 0) { + let parseError: unknown; + try { + await insertSync(working); + if (rowsStripped > 0) { + logger.info( + "Stripped un-ingestable rows after ClickHouse JSON parse error — batch landed with their JSON emptied", + { + ...logContext, + contextLabel, + batchSize: rows.length, + rowsStripped, + clickhouseError: firstMessage.split("\n")[0], + } + ); + } + return { kind: "recovered", rowsStripped, rowsDropped: 0, capped: false }; + } catch (error) { + if (!isClickHouseJsonParseError(error)) throw error; + parseError = error; + } + + const hint = parseRowNumberFromError(rawErrorMessage(parseError)); + const index = hint === null ? -1 : hint - 1; + const canStrip = + rowsStripped < maxPoisonStrips && index >= 0 && index < working.length && !stripped[index]; - const meta = { - ...logContext, - contextLabel, - batchSize: rows.length, - rowsStripped, - rowsDropped, - sampleRow: JSON.stringify(rows[0] ?? null).slice(0, 1024), - clickhouseError: firstMessage.split("\n")[0], - }; - if (budget.capped) { - logger.warn( - "Recovery cost cap hit — stripped the remaining rows in one insert (clean rows in the capped subtree also lost their JSON)", - meta - ); - } else { - logger.info( - "Isolated un-ingestable rows after ClickHouse JSON parse error — landed the batch with poison JSON stripped", - meta - ); + if (!canStrip) break; + + working[index] = stripJsonColumns(working[index]); + stripped[index] = true; + rowsStripped += 1; } - return { kind: "recovered", rowsStripped, rowsDropped, capped: budget.capped }; + const insertResult = await insertAllowingBadRows(working); + const rowsDropped = droppedRowCount(insertResult, working.length, hasMaterializedViews); + + logger.warn( + "Hit the poison-row strip limit — landed the batch via allow_errors and skipped the remaining un-ingestable rows", + { + ...logContext, + contextLabel, + batchSize: rows.length, + rowsStripped, + rowsDropped, + landedRows: writtenRowCount(insertResult), + clickhouseError: firstMessage.split("\n")[0], + } + ); + + return { kind: "recovered", rowsStripped, rowsDropped, capped: true }; } } +function writtenRowCount(insertResult: unknown): number | null { + if (typeof insertResult === "object" && insertResult !== null) { + const summary = (insertResult as { summary?: { written_rows?: unknown } }).summary; + const written = summary?.written_rows; + if (typeof written === "number" && Number.isFinite(written)) return written; + if (typeof written === "string" && written.length > 0) { + const parsed = Number.parseInt(written, 10); + if (Number.isFinite(parsed)) return parsed; + } + } + return null; +} + /** - * Precondition: inserting `rows` as-is throws a `Cannot parse JSON object` - * error. Bisects to isolate each un-ingestable row, lands clean rows in full, - * and re-inserts each poison row with its JSON column(s) stripped so it still - * lands. A row that can't parse even stripped is dropped. All inserts are - * synchronous so each subset's parse error surfaces. The two halves are probed - * concurrently so recovery wall-clock stays ~O(log n) round-trips rather than - * O(n). When `budget.inserts` is exhausted the remaining subtree is stripped - * and landed in a single insert (setting `budget.capped`) so a poison flood - * cannot do unbounded work. Returns exact counts. + * Derives how many rows a `allow_errors` insert dropped, from the insert + * summary's `written_rows`. This is exact only when `written_rows` is a clean + * count of the target-table rows. On tables with row-multiplying materialized + * views, ClickHouse folds the MV-written rows into `written_rows` too, so a + * partial-drop count isn't derivable; the only reliable signal there is + * `written_rows === 0`, which means the whole batch was dropped (no base rows, + * so no MV rows either). */ -async function isolateAndStripPoisonRows( - rows: T[], - insertSync: (rows: T[]) => Promise, - stripJsonColumns: (row: T) => T, - budget: IsolationBudget -): Promise<{ rowsStripped: number; rowsDropped: number }> { - if (rows.length === 0) { - return { rowsStripped: 0, rowsDropped: 0 }; - } +function droppedRowCount( + insertResult: unknown, + batchSize: number, + hasMaterializedViews: boolean +): number { + const written = writtenRowCount(insertResult); + if (written === null) return 0; + if (written === 0) return batchSize; + if (hasMaterializedViews) return 0; + return Math.max(0, batchSize - written); +} - if (budget.inserts <= 0) { - budget.capped = true; - budget.inserts -= 1; - try { - await insertSync(rows.map(stripJsonColumns)); - return { rowsStripped: rows.length, rowsDropped: 0 }; - } catch (error) { - if (!isClickHouseJsonParseError(error)) throw error; - return { rowsStripped: 0, rowsDropped: rows.length }; - } - } +/** + * Shared ClickHouse insert recovery that SKIPS un-ingestable rows, for the + * high-volume append-only tables (trace events, run payloads) where dropping a + * single un-ingestable row is acceptable and precise row isolation isn't worth + * its re-parse cost on the shared ClickHouse server. + * + * 1. Try the insert. Healthy batches pay zero recovery cost. + * 2. On a parse error, `sanitizeRows` losslessly repairs what it can in place + * and retries once, so a repairable row still lands in full. + * 3. If the sanitizer can't help, re-insert once with ClickHouse's + * `input_format_allow_errors_*` so the good rows land in a single pass and + * only the un-ingestable rows are skipped. A poison flood costs one extra + * insert regardless of how many rows are bad. + * 4. Non-parse errors propagate unchanged. + * + * The batch-level recovery is always counted by the caller; the per-row dropped + * count is exact on tables without row-multiplying materialized views and + * whole-batch-only on tables that have them (see `droppedRowCount`). + */ +export async function insertWithBadRowSkip(params: { + rows: T[]; + contextLabel: string; + logger: JsonParseRecoveryLogger; + logContext?: Record; + insert: (rows: T[]) => Promise; + insertAllowingBadRows: (rows: T[]) => Promise; + hasMaterializedViews?: boolean; +}): Promise { + const { rows, contextLabel, logger, logContext, insert, insertAllowingBadRows } = params; + const hasMaterializedViews = params.hasMaterializedViews ?? true; - if (rows.length === 1) { - budget.inserts -= 1; - try { - await insertSync([stripJsonColumns(rows[0])]); - return { rowsStripped: 1, rowsDropped: 0 }; - } catch (error) { - if (!isClickHouseJsonParseError(error)) throw error; - return { rowsStripped: 0, rowsDropped: 1 }; - } - } + try { + return { kind: "inserted", insertResult: await insert(rows) }; + } catch (firstError) { + if (!isClickHouseJsonParseError(firstError)) throw firstError; - const mid = rows.length >> 1; + const firstMessage = errorMessage(firstError); + const { rowsTouched, fieldsSanitized } = sanitizeRows(rows); + + if (fieldsSanitized > 0) { + logger.warn("Sanitizing batch after ClickHouse JSON parse error", { + ...logContext, + contextLabel, + batchSize: rows.length, + rowsTouched, + fieldsSanitized, + clickhouseError: firstMessage.split("\n")[0], + }); - const recoverHalf = async (half: T[]) => { - budget.inserts -= 1; - try { - await insertSync(half); - return { rowsStripped: 0, rowsDropped: 0 }; - } catch (error) { - if (!isClickHouseJsonParseError(error)) throw error; - return isolateAndStripPoisonRows(half, insertSync, stripJsonColumns, budget); + try { + return { kind: "sanitized", insertResult: await insert(rows) }; + } catch (retryError) { + if (!isClickHouseJsonParseError(retryError)) throw retryError; + } } - }; - const [left, right] = await Promise.all([ - recoverHalf(rows.slice(0, mid)), - recoverHalf(rows.slice(mid)), - ]); + const insertResult = await insertAllowingBadRows(rows); + const rowsDropped = droppedRowCount(insertResult, rows.length, hasMaterializedViews); - return { - rowsStripped: left.rowsStripped + right.rowsStripped, - rowsDropped: left.rowsDropped + right.rowsDropped, - }; + logger.info( + "Skipped un-ingestable rows after ClickHouse JSON parse error — landed the rest of the batch", + { + ...logContext, + contextLabel, + batchSize: rows.length, + rowsDropped, + landedRows: writtenRowCount(insertResult), + clickhouseError: firstMessage.split("\n")[0], + } + ); + + return { kind: "recovered", rowsStripped: 0, rowsDropped, capped: false }; + } } diff --git a/apps/webapp/test/clickhouseEventRepositoryJsonRecovery.test.ts b/apps/webapp/test/clickhouseEventRepositoryJsonRecovery.test.ts index fc748b39ddc..695046965ae 100644 --- a/apps/webapp/test/clickhouseEventRepositoryJsonRecovery.test.ts +++ b/apps/webapp/test/clickhouseEventRepositoryJsonRecovery.test.ts @@ -24,7 +24,7 @@ function startTime(baseMs: number, offsetMs: number): string { describe("ClickhouseEventRepository JSON parse recovery", () => { clickhouseTest( - "lands every event (poison event keeps its span, attributes stripped) when one event has ClickHouse-unparseable attributes", + "lands the good events and skips the poison event when one event has ClickHouse-unparseable attributes", async ({ clickhouseContainer }) => { const clickhouse = new ClickHouse({ url: clickhouseContainer.getConnectionUrl(), @@ -99,7 +99,7 @@ describe("ClickhouseEventRepository JSON parse recovery", () => { const [queryError, resultRows] = await queryEvents({ env_id: environmentId }); expect(queryError).toBeNull(); const byId = new Map((resultRows ?? []).map((r) => [r.span_id, r])); - for (const id of [...goodSpanIds, poisonSpanId]) { + for (const id of goodSpanIds) { expect(byId.has(id)).toBe(true); } return byId; @@ -111,12 +111,12 @@ describe("ClickhouseEventRepository JSON parse recovery", () => { expect(rowsById.get(id)!.attributes_json).toContain('"ok":true'); } - expect(rowsById.get(poisonSpanId)!.attributes_json).toBe("{}"); + expect(rowsById.has(poisonSpanId)).toBe(false); expect(repository.permanentlyDroppedBatches).toBe(0); expect(repository.permanentlyDroppedRows).toBe(0); expect(repository.rowIsolationRecoveries).toBeGreaterThanOrEqual(1); - expect(repository.rowsStripped).toBeGreaterThanOrEqual(1); + expect(repository.rowsStripped).toBe(0); } finally { await (repository as any)._flushScheduler?.shutdown?.(); } diff --git a/apps/webapp/test/runsReplicationJsonRecoveryBenchmark.test.ts b/apps/webapp/test/runsReplicationJsonRecoveryBenchmark.test.ts index b672d9968a3..7e97dba5d14 100644 --- a/apps/webapp/test/runsReplicationJsonRecoveryBenchmark.test.ts +++ b/apps/webapp/test/runsReplicationJsonRecoveryBenchmark.test.ts @@ -159,6 +159,7 @@ async function runScenario( maxFlushConcurrency: CONFIG.MAX_FLUSH_CONCURRENCY, flushIntervalMs: CONFIG.FLUSH_INTERVAL_MS, flushBatchSize: CONFIG.FLUSH_BATCH_SIZE, + maxPoisonStripsPerBatch: CONFIG.NUM_RUNS, leaderLockTimeoutMs: 10000, leaderLockExtendIntervalMs: 2000, ackIntervalSeconds: 10, diff --git a/apps/webapp/test/runsReplicationService.part10.test.ts b/apps/webapp/test/runsReplicationService.part10.test.ts index 0f1a6183afa..13f20097025 100644 --- a/apps/webapp/test/runsReplicationService.part10.test.ts +++ b/apps/webapp/test/runsReplicationService.part10.test.ts @@ -15,9 +15,80 @@ function deeplyNested(depth: number): Record { return node; } +function createService( + clickhouse: ClickHouse, + postgresUrl: string, + redisOptions: any, + flushIntervalMs = 500 +) { + const { tracer } = createInMemoryTracing(); + return new RunsReplicationService({ + clickhouseFactory: new TestReplicationClickhouseFactory(clickhouse), + pgConnectionUrl: postgresUrl, + serviceName: "runs-replication", + slotName: "task_runs_to_clickhouse_v1", + publicationName: "task_runs_to_clickhouse_v1_publication", + redisOptions, + maxFlushConcurrency: 1, + flushIntervalMs, + flushBatchSize: 50, + leaderLockTimeoutMs: 5000, + leaderLockExtendIntervalMs: 1000, + ackIntervalSeconds: 5, + tracer, + logLevel: "warn", + }); +} + +async function setupProject(prisma: any) { + const organization = await prisma.organization.create({ data: { title: "test", slug: "test" } }); + const project = await prisma.project.create({ + data: { name: "test", slug: "test", organizationId: organization.id, externalRef: "test" }, + }); + const runtimeEnvironment = await prisma.runtimeEnvironment.create({ + data: { + slug: "test", + type: "DEVELOPMENT", + projectId: project.id, + organizationId: organization.id, + apiKey: "test", + pkApiKey: "test", + shortcode: "test", + }, + }); + return { organization, project, runtimeEnvironment }; +} + +async function createRun( + prisma: any, + ctx: { organization: any; project: any; runtimeEnvironment: any }, + i: number, + isPoison: boolean +) { + return prisma.taskRun.create({ + data: { + friendlyId: `run_batchdrop_${i}`, + taskIdentifier: "my-task", + payload: JSON.stringify({ i }), + payloadType: "application/json", + output: isPoison ? JSON.stringify(deeplyNested(1500)) : JSON.stringify({ ok: true, i }), + outputType: "application/json", + traceId: `trace_${i}`, + spanId: `span_${i}`, + queue: "test", + status: "COMPLETED_SUCCESSFULLY", + runtimeEnvironmentId: ctx.runtimeEnvironment.id, + projectId: ctx.project.id, + organizationId: ctx.organization.id, + environmentType: "DEVELOPMENT", + engine: "V2", + }, + }); +} + describe("RunsReplicationService (part 10/10) — JSON parse recovery", () => { replicationContainerTest( - "lands every run (poison run keeps its status, output stripped) when one run has ClickHouse-unparseable JSON output", + "strips a single poison run and lands every run (poison run keeps its status, output stripped)", async ({ clickhouseContainer, redisOptions, postgresContainer, prisma }) => { await prisma.$executeRawUnsafe(`ALTER TABLE public."TaskRun" REPLICA IDENTITY FULL;`); @@ -28,84 +99,22 @@ describe("RunsReplicationService (part 10/10) — JSON parse recovery", () => { logLevel: "warn", }); - const { tracer } = createInMemoryTracing(); - - const runsReplicationService = new RunsReplicationService({ - clickhouseFactory: new TestReplicationClickhouseFactory(clickhouse), - pgConnectionUrl: postgresContainer.getConnectionUri(), - serviceName: "runs-replication", - slotName: "task_runs_to_clickhouse_v1", - publicationName: "task_runs_to_clickhouse_v1_publication", - redisOptions, - maxFlushConcurrency: 1, - flushIntervalMs: 500, - flushBatchSize: 50, - leaderLockTimeoutMs: 5000, - leaderLockExtendIntervalMs: 1000, - ackIntervalSeconds: 5, - tracer, - logLevel: "warn", - }); - + const runsReplicationService = createService( + clickhouse, + postgresContainer.getConnectionUri(), + redisOptions + ); await runsReplicationService.start(); - const organization = await prisma.organization.create({ - data: { title: "test", slug: "test" }, - }); - const project = await prisma.project.create({ - data: { - name: "test", - slug: "test", - organizationId: organization.id, - externalRef: "test", - }, - }); - const runtimeEnvironment = await prisma.runtimeEnvironment.create({ - data: { - slug: "test", - type: "DEVELOPMENT", - projectId: project.id, - organizationId: organization.id, - apiKey: "test", - pkApiKey: "test", - shortcode: "test", - }, - }); + const ctx = await setupProject(prisma); const goodRunIds: string[] = []; let poisonRunId = ""; - for (let i = 0; i < 5; i++) { const isPoison = i === 2; - const output = isPoison - ? JSON.stringify(deeplyNested(1500)) - : JSON.stringify({ ok: true, i }); - - const run = await prisma.taskRun.create({ - data: { - friendlyId: `run_batchdrop_${i}`, - taskIdentifier: "my-task", - payload: JSON.stringify({ i }), - payloadType: "application/json", - output, - outputType: "application/json", - traceId: `trace_${i}`, - spanId: `span_${i}`, - queue: "test", - status: "COMPLETED_SUCCESSFULLY", - runtimeEnvironmentId: runtimeEnvironment.id, - projectId: project.id, - organizationId: organization.id, - environmentType: "DEVELOPMENT", - engine: "V2", - }, - }); - - if (isPoison) { - poisonRunId = run.id; - } else { - goodRunIds.push(run.id); - } + const run = await createRun(prisma, ctx, i, isPoison); + if (isPoison) poisonRunId = run.id; + else goodRunIds.push(run.id); } const queryRuns = clickhouse.reader.query({ @@ -118,7 +127,7 @@ describe("RunsReplicationService (part 10/10) — JSON parse recovery", () => { const rowsById = await vi.waitFor( async () => { - const [queryError, rows] = await queryRuns({ org_id: organization.id }); + const [queryError, rows] = await queryRuns({ org_id: ctx.organization.id }); expect(queryError).toBeNull(); const byId = new Map((rows ?? []).map((r) => [r.run_id, r])); for (const id of [...goodRunIds, poisonRunId]) { @@ -130,8 +139,7 @@ describe("RunsReplicationService (part 10/10) — JSON parse recovery", () => { ); for (const id of goodRunIds) { - const row = rowsById.get(id)!; - expect(row.output_json).toContain('"ok":true'); + expect(rowsById.get(id)!.output_json).toContain('"ok":true'); } const poison = rowsById.get(poisonRunId)!; @@ -140,10 +148,82 @@ describe("RunsReplicationService (part 10/10) — JSON parse recovery", () => { expect(runsReplicationService.permanentlyDroppedBatches).toBe(0); expect(runsReplicationService.permanentlyDroppedRows).toBe(0); + expect(runsReplicationService.recoveryCapHits).toBe(0); expect(runsReplicationService.rowIsolationRecoveries).toBeGreaterThanOrEqual(1); expect(runsReplicationService.rowsStripped).toBeGreaterThanOrEqual(1); await runsReplicationService.stop(); } ); + + replicationContainerTest( + "strips up to the limit then skips the excess poison via allow_errors (2 poison, limit 1)", + async ({ clickhouseContainer, redisOptions, postgresContainer, prisma }) => { + await prisma.$executeRawUnsafe(`ALTER TABLE public."TaskRun" REPLICA IDENTITY FULL;`); + + const clickhouse = new ClickHouse({ + url: clickhouseContainer.getConnectionUrl(), + name: "runs-replication", + compression: { request: true }, + logLevel: "warn", + }); + + const runsReplicationService = createService( + clickhouse, + postgresContainer.getConnectionUri(), + redisOptions, + 3000 + ); + await runsReplicationService.start(); + + const ctx = await setupProject(prisma); + + const goodRunIds: string[] = []; + const poisonRunIds: string[] = []; + for (let i = 0; i < 5; i++) { + const isPoison = i === 1 || i === 3; + const run = await createRun(prisma, ctx, i, isPoison); + if (isPoison) poisonRunIds.push(run.id); + else goodRunIds.push(run.id); + } + + const queryRuns = clickhouse.reader.query({ + name: "runs-replication-bail", + query: + "SELECT run_id, status, toJSONString(output) AS output_json FROM trigger_dev.task_runs_v2 FINAL WHERE organization_id = {org_id:String}", + schema: z.object({ run_id: z.string(), status: z.string(), output_json: z.string() }), + params: z.object({ org_id: z.string() }), + }); + + const rowsById = await vi.waitFor( + async () => { + const [queryError, rows] = await queryRuns({ org_id: ctx.organization.id }); + expect(queryError).toBeNull(); + const byId = new Map((rows ?? []).map((r) => [r.run_id, r])); + for (const id of goodRunIds) { + expect(byId.has(id)).toBe(true); + } + expect(runsReplicationService.recoveryCapHits).toBeGreaterThanOrEqual(1); + return byId; + }, + { timeout: 30_000, interval: 250 } + ); + + for (const id of goodRunIds) { + expect(rowsById.get(id)!.output_json).toContain('"ok":true'); + } + + const landedPoison = poisonRunIds.filter((id) => rowsById.has(id)); + expect(landedPoison).toHaveLength(1); + const strippedPoison = rowsById.get(landedPoison[0]!)!; + expect(strippedPoison.status).toBe("COMPLETED_SUCCESSFULLY"); + expect(strippedPoison.output_json).toBe("{}"); + + expect(runsReplicationService.permanentlyDroppedBatches).toBe(0); + expect(runsReplicationService.rowsStripped).toBeGreaterThanOrEqual(1); + expect(runsReplicationService.recoveryCapHits).toBeGreaterThanOrEqual(1); + + await runsReplicationService.stop(); + } + ); }); diff --git a/apps/webapp/test/sanitizeRowsOnParseError.test.ts b/apps/webapp/test/sanitizeRowsOnParseError.test.ts index 01141228bf1..5d3bd4e7cfa 100644 --- a/apps/webapp/test/sanitizeRowsOnParseError.test.ts +++ b/apps/webapp/test/sanitizeRowsOnParseError.test.ts @@ -1,7 +1,8 @@ import { describe, it, expect } from "vitest"; import { INVALID_UTF16_SENTINEL, - insertWithJsonParseRecovery, + insertWithBadRowSkip, + insertWithLimitedStrip, isClickHouseJsonParseError, parseRowNumberFromError, sanitizeRows, @@ -11,32 +12,56 @@ import { const HIGH_SURROGATE = "\uD800"; const LOW_SURROGATE = "\uDC00"; -type FakeRow = { id: number; poison?: boolean; unstrippable?: boolean; stripped?: boolean }; +type FakeRow = { + id: number; + poison?: boolean; + unstrippable?: boolean; + stripped?: boolean; + msg?: string; +}; const silentLogger = { info: () => {}, warn: () => {} }; -function parseError() { - return new Error("Cannot parse JSON object here: {...}: (at row 1)"); +function parseErrorAtRow(oneBasedRow: number) { + return new Error( + `Cannot parse JSON object here: {...}: (at row ${oneBasedRow})\n: While executing ParallelParsingBlockInputFormat.` + ); } /** - * Builds insert doubles for `insertWithJsonParseRecovery`: a synchronous insert - * that throws a parse error if any row is still poison/unstrippable and - * otherwise records the rows as landed, plus a strip that clears the poison - * marker (but cannot fix an `unstrippable` row). + * Builds insert doubles for `insertWithLimitedStrip`: an insert that fails at + * the first still-poison row (reporting ClickHouse's 1-based `at row N`), an + * allow-bad-rows insert that lands only the good rows and reports the landed + * count in a summary, and a strip that clears the poison marker (but cannot fix + * an `unstrippable` row). */ function makeHarness() { const landed: FakeRow[] = []; let insertCalls = 0; + let allowCalls = 0; const insertSync = async (rows: FakeRow[]) => { insertCalls += 1; - if (rows.some((r) => r.poison || r.unstrippable)) throw parseError(); + const badIndex = rows.findIndex((r) => r.poison || r.unstrippable); + if (badIndex >= 0) throw parseErrorAtRow(badIndex + 1); landed.push(...rows); - return undefined; + return { summary: { written_rows: String(rows.length) } }; + }; + const insertAllowingBadRows = async (rows: FakeRow[]) => { + allowCalls += 1; + const good = rows.filter((r) => !(r.poison || r.unstrippable)); + landed.push(...good); + return { summary: { written_rows: String(good.length) } }; }; const stripJsonColumns = (row: FakeRow): FakeRow => row.unstrippable ? row : { ...row, poison: false, stripped: true }; - return { landed, insertSync, stripJsonColumns, insertCalls: () => insertCalls }; + return { + landed, + insertSync, + insertAllowingBadRows, + stripJsonColumns, + insertCalls: () => insertCalls, + allowCalls: () => allowCalls, + }; } describe("isClickHouseJsonParseError", () => { @@ -324,36 +349,41 @@ describe("sanitizeRows", () => { }); }); -describe("insertWithJsonParseRecovery", () => { +describe("insertWithLimitedStrip", () => { const clean = (id: number): FakeRow => ({ id }); it("inserts a healthy batch with no recovery", async () => { - const { landed, insertSync, stripJsonColumns } = makeHarness(); + const { landed, insertSync, insertAllowingBadRows, stripJsonColumns, allowCalls } = + makeHarness(); const rows = [clean(0), clean(1), clean(2)]; - const outcome = await insertWithJsonParseRecovery({ + const outcome = await insertWithLimitedStrip({ rows, contextLabel: "test", logger: silentLogger, insert: insertSync, insertSync, + insertAllowingBadRows, stripJsonColumns, }); expect(outcome.kind).toBe("inserted"); expect(landed).toHaveLength(3); + expect(allowCalls()).toBe(0); }); - it("isolates a poison row, strips it, and lands the rest in full", async () => { - const { landed, insertSync, stripJsonColumns } = makeHarness(); + it("strips a single poison row and lands the rest in full without bailing", async () => { + const { landed, insertSync, insertAllowingBadRows, stripJsonColumns, allowCalls } = + makeHarness(); const rows = [clean(0), clean(1), { id: 2, poison: true }, clean(3), clean(4)]; - const outcome = await insertWithJsonParseRecovery({ + const outcome = await insertWithLimitedStrip({ rows, contextLabel: "test", logger: silentLogger, insert: insertSync, insertSync, + insertAllowingBadRows, stripJsonColumns, }); @@ -361,64 +391,280 @@ describe("insertWithJsonParseRecovery", () => { expect(landed.map((r) => r.id).sort((a, b) => a - b)).toEqual([0, 1, 2, 3, 4]); expect(landed.find((r) => r.id === 2)?.stripped).toBe(true); expect(landed.filter((r) => r.id !== 2).every((r) => !r.stripped)).toBe(true); + expect(allowCalls()).toBe(0); }); - it("drops a row that cannot parse even after stripping", async () => { - const { landed, insertSync, stripJsonColumns } = makeHarness(); - const rows = [clean(0), { id: 1, unstrippable: true }, clean(2)]; + it("strips up to the limit, then bails to allow_errors and skips the excess poison", async () => { + const { landed, insertSync, insertAllowingBadRows, stripJsonColumns, allowCalls } = + makeHarness(); + const rows = [clean(0), { id: 1, poison: true }, clean(2), { id: 3, poison: true }, clean(4)]; - const outcome = await insertWithJsonParseRecovery({ + const outcome = await insertWithLimitedStrip({ rows, contextLabel: "test", logger: silentLogger, insert: insertSync, insertSync, + insertAllowingBadRows, stripJsonColumns, + maxPoisonStrips: 1, + hasMaterializedViews: false, }); - expect(outcome).toEqual({ kind: "recovered", rowsStripped: 0, rowsDropped: 1, capped: false }); - expect(landed.map((r) => r.id).sort((a, b) => a - b)).toEqual([0, 2]); + expect(outcome).toEqual({ kind: "recovered", rowsStripped: 1, rowsDropped: 1, capped: true }); + expect(allowCalls()).toBe(1); + expect(landed.map((r) => r.id).sort((a, b) => a - b)).toEqual([0, 1, 2, 4]); + expect(landed.find((r) => r.id === 1)?.stripped).toBe(true); + expect(landed.some((r) => r.id === 3)).toBe(false); }); - it("caps recovery cost on a poison flood by stripping the remainder in one insert", async () => { - const { landed, insertSync, stripJsonColumns, insertCalls } = makeHarness(); - const rows = Array.from({ length: 8 }, (_, id) => ({ id, poison: true as const })); + it("strips every poison row when the limit is high enough", async () => { + const { landed, insertSync, insertAllowingBadRows, stripJsonColumns, allowCalls } = + makeHarness(); + const rows = [clean(0), { id: 1, poison: true }, { id: 2, poison: true }, clean(3)]; - const outcome = await insertWithJsonParseRecovery({ + const outcome = await insertWithLimitedStrip({ rows, contextLabel: "test", logger: silentLogger, insert: insertSync, insertSync, + insertAllowingBadRows, stripJsonColumns, - maxIsolationInserts: 2, + maxPoisonStrips: 3, + }); + + expect(outcome).toEqual({ kind: "recovered", rowsStripped: 2, rowsDropped: 0, capped: false }); + expect(allowCalls()).toBe(0); + expect(landed.map((r) => r.id).sort((a, b) => a - b)).toEqual([0, 1, 2, 3]); + }); + + it("bails to allow_errors when the failing row cannot be located", async () => { + const landed: FakeRow[] = []; + let allowCalls = 0; + const insertSync = async (rows: FakeRow[]) => { + if (rows.some((r) => r.poison)) { + throw new Error("Cannot parse JSON object here: {...} (no row hint here)"); + } + landed.push(...rows); + return { summary: { written_rows: String(rows.length) } }; + }; + const insertAllowingBadRows = async (rows: FakeRow[]) => { + allowCalls += 1; + const good = rows.filter((r) => !r.poison); + landed.push(...good); + return { summary: { written_rows: String(good.length) } }; + }; + + const outcome = await insertWithLimitedStrip({ + rows: [clean(0), { id: 1, poison: true }, clean(2)], + contextLabel: "test", + logger: silentLogger, + insert: insertSync, + insertSync, + insertAllowingBadRows, + stripJsonColumns: (row) => row, + hasMaterializedViews: false, }); - expect(outcome.kind).toBe("recovered"); - if (outcome.kind === "recovered") { - expect(outcome.capped).toBe(true); - expect(outcome.rowsStripped).toBe(8); - expect(outcome.rowsDropped).toBe(0); - } - expect(landed).toHaveLength(8); - expect(landed.every((r) => r.stripped)).toBe(true); - expect(insertCalls()).toBeLessThanOrEqual(6); + expect(outcome).toEqual({ kind: "recovered", rowsStripped: 0, rowsDropped: 1, capped: true }); + expect(allowCalls).toBe(1); + expect(landed.map((r) => r.id).sort((a, b) => a - b)).toEqual([0, 2]); }); it("rethrows non-parse errors so the caller's transient-retry path handles them", async () => { - const stripJsonColumns = (row: FakeRow): FakeRow => row; const insert = async () => { throw new Error("Connection refused"); }; await expect( - insertWithJsonParseRecovery({ + insertWithLimitedStrip({ rows: [clean(0)], contextLabel: "test", logger: silentLogger, insert, insertSync: insert, - stripJsonColumns, + insertAllowingBadRows: insert, + stripJsonColumns: (row) => row, + }) + ).rejects.toThrow("Connection refused"); + }); +}); + +/** + * Builds insert doubles for `insertWithBadRowSkip`: a normal insert that fails + * whole when any row is poison, plus an allow-bad-rows insert that lands only + * the good rows and reports the landed count in a ClickHouse-style summary + * (`written_rows`) so the recovery can derive how many rows were skipped. + */ +function makeSkipHarness() { + const landed: FakeRow[] = []; + let insertCalls = 0; + let allowCalls = 0; + const insert = async (rows: FakeRow[]) => { + insertCalls += 1; + const badIndex = rows.findIndex((r) => r.poison || r.unstrippable); + if (badIndex >= 0) throw parseErrorAtRow(badIndex + 1); + landed.push(...rows); + return { summary: { written_rows: String(rows.length) } }; + }; + const insertAllowingBadRows = async (rows: FakeRow[]) => { + allowCalls += 1; + const good = rows.filter((r) => !(r.poison || r.unstrippable)); + landed.push(...good); + return { summary: { written_rows: String(good.length) } }; + }; + return { + landed, + insert, + insertAllowingBadRows, + insertCalls: () => insertCalls, + allowCalls: () => allowCalls, + }; +} + +describe("insertWithBadRowSkip", () => { + const clean = (id: number): FakeRow => ({ id }); + + it("inserts a healthy batch with no recovery", async () => { + const { landed, insert, insertAllowingBadRows, allowCalls } = makeSkipHarness(); + + const outcome = await insertWithBadRowSkip({ + rows: [clean(0), clean(1), clean(2)], + contextLabel: "test", + logger: silentLogger, + insert, + insertAllowingBadRows, + }); + + expect(outcome.kind).toBe("inserted"); + expect(landed).toHaveLength(3); + expect(allowCalls()).toBe(0); + }); + + it("skips the poison rows in one extra insert and counts drops exactly on a table with no materialized views", async () => { + const { landed, insert, insertAllowingBadRows, insertCalls, allowCalls } = makeSkipHarness(); + const rows = [clean(0), { id: 1, poison: true }, clean(2), { id: 3, poison: true }, clean(4)]; + + const outcome = await insertWithBadRowSkip({ + rows, + contextLabel: "test", + logger: silentLogger, + insert, + insertAllowingBadRows, + hasMaterializedViews: false, + }); + + expect(outcome).toEqual({ kind: "recovered", rowsStripped: 0, rowsDropped: 2, capped: false }); + expect(landed.map((r) => r.id).sort((a, b) => a - b)).toEqual([0, 2, 4]); + expect(insertCalls()).toBe(1); + expect(allowCalls()).toBe(1); + }); + + it("counts only whole-batch drops on a table with materialized views (partial drop uncountable)", async () => { + const inflatedSummary = (goodCount: number) => ({ + summary: { written_rows: String(goodCount * 3) }, + }); + const insert = async (rows: FakeRow[]) => { + if (rows.some((r) => r.poison)) throw parseErrorAtRow(1); + return inflatedSummary(rows.length); + }; + const insertAllowingBadRows = async (rows: FakeRow[]) => + inflatedSummary(rows.filter((r) => !r.poison).length); + + const partial = await insertWithBadRowSkip({ + rows: [clean(0), { id: 1, poison: true }, clean(2)], + contextLabel: "test", + logger: silentLogger, + insert, + insertAllowingBadRows, + hasMaterializedViews: true, + }); + expect(partial).toEqual({ kind: "recovered", rowsStripped: 0, rowsDropped: 0, capped: false }); + + const wholeBatch = await insertWithBadRowSkip({ + rows: [ + { id: 0, poison: true }, + { id: 1, poison: true }, + ], + contextLabel: "test", + logger: silentLogger, + insert, + insertAllowingBadRows, + hasMaterializedViews: true, + }); + expect(wholeBatch).toEqual({ + kind: "recovered", + rowsStripped: 0, + rowsDropped: 2, + capped: false, + }); + }); + + it("sanitizes a repairable batch and lands it in full without skipping any row", async () => { + const landed: FakeRow[] = []; + let allowCalls = 0; + const insert = async (rows: FakeRow[]) => { + if (rows.some((r) => typeof r.msg === "string" && r.msg.includes(HIGH_SURROGATE))) { + throw parseErrorAtRow(1); + } + landed.push(...rows); + return { summary: { written_rows: String(rows.length) } }; + }; + const insertAllowingBadRows = async (rows: FakeRow[]) => { + allowCalls += 1; + landed.push(...rows); + return { summary: { written_rows: String(rows.length) } }; + }; + const rows: FakeRow[] = [ + { id: 0, msg: `bad ${HIGH_SURROGATE}` }, + { id: 1, msg: "clean" }, + ]; + + const outcome = await insertWithBadRowSkip({ + rows, + contextLabel: "test", + logger: silentLogger, + insert, + insertAllowingBadRows, + }); + + expect(outcome.kind).toBe("sanitized"); + expect(allowCalls).toBe(0); + expect(landed).toHaveLength(2); + expect(rows[0].msg).toBe(INVALID_UTF16_SENTINEL); + }); + + it("reports zero dropped when the summary has no written_rows count", async () => { + const insert = async (rows: FakeRow[]) => { + if (rows.some((r) => r.poison)) throw parseErrorAtRow(1); + return undefined; + }; + const insertAllowingBadRows = async () => ({ summary: {} }); + + const outcome = await insertWithBadRowSkip({ + rows: [{ id: 0, poison: true }, clean(1)], + contextLabel: "test", + logger: silentLogger, + insert, + insertAllowingBadRows, + }); + + expect(outcome).toEqual({ kind: "recovered", rowsStripped: 0, rowsDropped: 0, capped: false }); + }); + + it("rethrows non-parse errors so the caller's transient-retry path handles them", async () => { + const insert = async () => { + throw new Error("Connection refused"); + }; + + await expect( + insertWithBadRowSkip({ + rows: [clean(0)], + contextLabel: "test", + logger: silentLogger, + insert, + insertAllowingBadRows: insert, }) ).rejects.toThrow("Connection refused"); }); diff --git a/internal-packages/clickhouse/src/client/client.ts b/internal-packages/clickhouse/src/client/client.ts index d91f86b428f..33ff2d3db9e 100644 --- a/internal-packages/clickhouse/src/client/client.ts +++ b/internal-packages/clickhouse/src/client/client.ts @@ -719,7 +719,7 @@ export class ClickhouseClient implements ClickhouseReader, ClickhouseWriter { recordClickhouseError(span, clickhouseError); - return [new InsertError(clickhouseError.message), null]; + return [toInsertError(clickhouseError), null]; } this.logger.debug("Inserted into clickhouse", { @@ -810,7 +810,7 @@ export class ClickhouseClient implements ClickhouseReader, ClickhouseWriter { }); recordClickhouseError(span, clickhouseError); - return [new InsertError(clickhouseError.message), null]; + return [toInsertError(clickhouseError), null]; } return [null, result]; @@ -872,7 +872,7 @@ export class ClickhouseClient implements ClickhouseReader, ClickhouseWriter { recordClickhouseError(span, clickhouseError); - return [new InsertError(clickhouseError.message), null]; + return [toInsertError(clickhouseError), null]; } this.logger.debug("Inserted into clickhouse", { @@ -971,7 +971,7 @@ export class ClickhouseClient implements ClickhouseReader, ClickhouseWriter { }); recordClickhouseError(span, clickhouseError); - return [new InsertError(clickhouseError.message), null]; + return [toInsertError(clickhouseError), null]; } this.logger.debug("Inserted into clickhouse", { @@ -1001,6 +1001,11 @@ export class ClickhouseClient implements ClickhouseReader, ClickhouseWriter { } } +function toInsertError(error: Error): InsertError { + const rawMessage = error instanceof ClickHouseError ? error.rawMessage : undefined; + return new InsertError(error.message, { rawMessage }); +} + function recordClickhouseError(span: Span, error: Error): void { if (error instanceof ClickHouseError) { span.setAttributes({ diff --git a/internal-packages/clickhouse/src/client/errors.ts b/internal-packages/clickhouse/src/client/errors.ts index a620fb54649..c0ceacb830f 100644 --- a/internal-packages/clickhouse/src/client/errors.ts +++ b/internal-packages/clickhouse/src/client/errors.ts @@ -24,10 +24,12 @@ export abstract class BaseError ex export class InsertError extends BaseError { public readonly retry = true; public readonly name = InsertError.name; - constructor(message: string) { + public readonly rawMessage?: string; + constructor(message: string, options?: { rawMessage?: string }) { super({ message, }); + this.rawMessage = options?.rawMessage; } } export class QueryError extends BaseError<{ query: string }> { diff --git a/package.json b/package.json index f5987056204..2708b06be73 100644 --- a/package.json +++ b/package.json @@ -91,7 +91,8 @@ "@window-splitter/state@1.1.3": "patches/@window-splitter__state@1.1.3.patch", "streamdown@2.5.0": "patches/streamdown@2.5.0.patch", "tsup@8.4.0": "patches/tsup@8.4.0.patch", - "@remix-run/router@1.23.3": "patches/@remix-run__router@1.23.3.patch" + "@remix-run/router@1.23.3": "patches/@remix-run__router@1.23.3.patch", + "@clickhouse/client-common@1.12.1": "patches/@clickhouse__client-common@1.12.1.patch" }, "overrides": { "typescript": "catalog:", diff --git a/patches/@clickhouse__client-common@1.12.1.patch b/patches/@clickhouse__client-common@1.12.1.patch new file mode 100644 index 00000000000..eb4dc08a000 --- /dev/null +++ b/patches/@clickhouse__client-common@1.12.1.patch @@ -0,0 +1,29 @@ +diff --git a/dist/error/error.d.ts b/dist/error/error.d.ts +index fb04ebb65a8c7115c465093462edaafa14a814de..30b370bf2eb8ba7491c249db96d565a67fe367c6 100644 +--- a/dist/error/error.d.ts ++++ b/dist/error/error.d.ts +@@ -7,6 +7,7 @@ interface ParsedClickHouseError { + export declare class ClickHouseError extends Error { + readonly code: string; + readonly type: string | undefined; ++ rawMessage?: string; + constructor({ message, code, type }: ParsedClickHouseError); + } + export declare function parseError(input: string | Error): ClickHouseError | Error; +diff --git a/dist/error/error.js b/dist/error/error.js +index e06fa4ab36537c2a448857c1b001e70cd771bfe5..9750bd7e1285ac8cf2c8095b592ed344126176b6 100644 +--- a/dist/error/error.js ++++ b/dist/error/error.js +@@ -35,7 +35,11 @@ function parseError(input) { + const match = message.match(errorRe); + const groups = match?.groups; + if (groups) { +- return new ClickHouseError(groups); ++ const error = new ClickHouseError(groups); ++ if (!inputIsError && groups.message.startsWith("Cannot parse JSON object")) { ++ error.rawMessage = message; ++ } ++ return error; + } + else { + return inputIsError ? input : new Error(input); diff --git a/pnpm-lock.yaml b/pnpm-lock.yaml index 2849a27dd58..7bf625e41a8 100644 --- a/pnpm-lock.yaml +++ b/pnpm-lock.yaml @@ -58,6 +58,9 @@ patchedDependencies: '@changesets/assemble-release-plan@5.2.4': hash: a7a12643e8d89a00d5322f750c292e8567b5ee0fc9c613a238a1184c25533e4b path: patches/@changesets__assemble-release-plan@5.2.4.patch + '@clickhouse/client-common@1.12.1': + hash: 870d9f887c4057af8fa50fb52936fb7e8463f62f5e88e70b804c3a7445c98b4d + path: patches/@clickhouse__client-common@1.12.1.patch '@kubernetes/client-node@1.0.0': hash: ba1a06f46256cdb8d6faf7167246692c0de2e7cd846a9dc0f13be0137e1c3745 path: patches/@kubernetes__client-node@1.0.0.patch @@ -17695,7 +17698,7 @@ snapshots: '@clickhouse/client-common@1.11.1': {} - '@clickhouse/client-common@1.12.1': {} + '@clickhouse/client-common@1.12.1(patch_hash=870d9f887c4057af8fa50fb52936fb7e8463f62f5e88e70b804c3a7445c98b4d)': {} '@clickhouse/client@1.11.1': dependencies: @@ -17703,7 +17706,7 @@ snapshots: '@clickhouse/client@1.12.1': dependencies: - '@clickhouse/client-common': 1.12.1 + '@clickhouse/client-common': 1.12.1(patch_hash=870d9f887c4057af8fa50fb52936fb7e8463f62f5e88e70b804c3a7445c98b4d) '@codemirror/autocomplete@6.4.0(@codemirror/language@6.3.2)(@codemirror/state@6.2.0)(@codemirror/view@6.7.2)(@lezer/common@1.3.0)': dependencies: From 08c0887835c7d45cb798a6428d18a6891a2d3657 Mon Sep 17 00:00:00 2001 From: Eric Allam Date: Sat, 25 Jul 2026 10:16:51 +0100 Subject: [PATCH 8/9] fix(webapp,clickhouse): keep ClickHouse row snippets out of logs The untruncated ClickHouse error text is kept only so the recovery path can read the failing-row hint, but ClickHouse embeds a snippet of the offending row in its parse errors. It is now a non-enumerable field, so structured logging and error reporting cannot pick it up while direct reads still work. The dropped-row count reported zero on tables whose materialized views fold MV rows into written_rows, which reads as "no data lost" when rows had in fact been skipped. Reaching an allow_errors insert always means at least one row is un-ingestable, so the count now reports that floor and flags itself inexact, and a batch only counts as wholly dropped when ClickHouse's summary says so exactly. The skip path logs at warn to match, since it always loses a row. Also drops the two event-repository counters that could never leave zero (that path skips rows rather than stripping columns, so nothing fed them), and names the two causes of an allow_errors bail as a bailReason log field instead of reporting both as a strip-budget hit. --- .../services/runsReplicationService.server.ts | 25 +-- .../clickhouseEventRepository.server.ts | 75 ++------- .../sanitizeRowsOnParseError.server.ts | 146 +++++++++++++----- ...ckhouseEventRepositoryJsonRecovery.test.ts | 3 +- .../runsReplicationService.part10.test.ts | 1 + .../test/sanitizeRowsOnParseError.test.ts | 63 ++++++-- .../clickhouse/src/client/errors.test.ts | 29 ++++ .../clickhouse/src/client/errors.ts | 14 +- 8 files changed, 235 insertions(+), 121 deletions(-) create mode 100644 internal-packages/clickhouse/src/client/errors.test.ts diff --git a/apps/webapp/app/services/runsReplicationService.server.ts b/apps/webapp/app/services/runsReplicationService.server.ts index 555bca49a6b..59e55f1a62f 100644 --- a/apps/webapp/app/services/runsReplicationService.server.ts +++ b/apps/webapp/app/services/runsReplicationService.server.ts @@ -181,23 +181,26 @@ export class RunsReplicationService { * Counts batches where every row was un-ingestable even with its JSON * stripped, so nothing landed. Row isolation lands anything strippable, so * this should stay at zero; a non-zero value means the recovery itself is - * failing. Counter only, does not gate behaviour. + * failing. Only incremented when ClickHouse's summary says so exactly + * (`written_rows === 0`). Counter only, does not gate behaviour. */ private _permanentlyDroppedBatches = 0; /** * Counts batches that took the row-isolation recovery path: a * `Cannot parse JSON object` failure the sanitizer could not repair, where we - * bisected to the poison rows and landed the batch with their JSON stripped. - * Reliable per-event signal that user data is hitting the ceiling. + * followed ClickHouse's `at row N` hint to the poison rows and landed the batch + * with their JSON stripped. Reliable per-event signal that user data is hitting + * the ceiling. */ private _rowIsolationRecoveries = 0; /** - * Counts batches whose isolation blew the per-batch insert budget (a poison - * flood), so the remaining rows were stripped in one insert instead of - * bisected further. A burst signal; clean rows in those batches also lose - * their JSON. + * Counts batches that gave up on isolating rows precisely and fell back to a + * single `allow_errors` insert, either because the per-batch strip budget was + * spent (a poison flood) or because ClickHouse gave no usable row hint. The + * remaining un-ingestable rows are skipped; `bailReason` in the log line says + * which cause it was. */ private _recoveryCapHits = 0; @@ -210,6 +213,8 @@ export class RunsReplicationService { /** * Counts rows dropped entirely because they could not be parsed even with * their JSON stripped. The true data-loss signal; expected to stay near zero. + * A lower bound on `task_runs_v2`, whose materialized views make the exact + * count underivable from ClickHouse's insert summary (see `droppedRowCount`). */ private _permanentlyDroppedRows = 0; @@ -290,7 +295,7 @@ export class RunsReplicationService { this._recoveryCapHitsCounter = this._meter.createCounter("runs_replication.recovery_cap_hits", { description: - "Batches whose row isolation hit the per-batch insert budget and stripped the remainder in one insert (poison-flood signal)", + "Batches that fell back to a single allow_errors insert instead of isolating rows, because the per-batch strip budget was spent or ClickHouse gave no usable row hint", unit: "batches", }); @@ -302,7 +307,7 @@ export class RunsReplicationService { this._rowsDroppedCounter = this._meter.createCounter("runs_replication.rows_dropped", { description: - "Rows dropped entirely because they could not parse even with their JSON stripped", + "Rows dropped entirely because they could not parse even with their JSON stripped; a lower bound on task_runs_v2, whose materialized views make the exact count underivable from ClickHouse's insert summary", unit: "rows", }); @@ -1232,7 +1237,7 @@ export class RunsReplicationService { if (outcome.rowsDropped > 0) { this._permanentlyDroppedRows += outcome.rowsDropped; this._rowsDroppedCounter.add(outcome.rowsDropped, { table: contextLabel }); - if (outcome.rowsDropped === batchSize) { + if (outcome.rowsDroppedExact && outcome.rowsDropped === batchSize) { this._permanentlyDroppedBatches += 1; this._droppedBatchesCounter.add(1, { table: contextLabel }); } diff --git a/apps/webapp/app/v3/eventRepository/clickhouseEventRepository.server.ts b/apps/webapp/app/v3/eventRepository/clickhouseEventRepository.server.ts index 3a2c34f0dfc..781d9983c7b 100644 --- a/apps/webapp/app/v3/eventRepository/clickhouseEventRepository.server.ts +++ b/apps/webapp/app/v3/eventRepository/clickhouseEventRepository.server.ts @@ -121,39 +121,28 @@ export class ClickhouseEventRepository implements IEventRepository { private _tracer: Tracer; private _version: "v1" | "v2"; /** - * Counts batches where every row was un-ingestable even with its JSON - * stripped, so nothing landed. Row isolation lands anything strippable, so - * this should stay at zero; a non-zero value means the recovery is failing. + * Counts batches where every row was un-ingestable, so nothing landed. Only + * incremented when ClickHouse's summary says so exactly (`written_rows === 0`); + * expected to stay at zero, since a whole batch of un-ingestable events means + * something upstream is broken rather than one bad payload. */ private _permanentlyDroppedBatches = 0; private readonly _droppedBatchesCounter: Counter; /** - * Counts batches that took the row-isolation recovery path: a - * `Cannot parse JSON object` failure the sanitizer could not repair, where we - * bisected to the poison rows and landed the batch with their JSON stripped. - * Reliable per-event signal. + * Counts batches that took the bad-row-skip recovery path: a + * `Cannot parse JSON object` failure the sanitizer could not repair, where one + * `allow_errors` insert landed the good rows and skipped the un-ingestable + * ones. Every such batch lost at least one row, so this is the alertable + * signal for these tables. */ private _rowIsolationRecoveries = 0; private readonly _rowIsolatedBatchesCounter: Counter; /** - * Counts batches whose isolation blew the per-batch insert budget (a poison - * flood), so the remaining rows were stripped in one insert. A burst signal. - */ - private _recoveryCapHits = 0; - private readonly _recoveryCapHitsCounter: Counter; - - /** - * Counts rows that landed with their un-ingestable JSON stripped (the span - * kept its place in the trace, only the attributes content was lost). - */ - private _rowsStripped = 0; - private readonly _rowsStrippedCounter: Counter; - - /** - * Counts rows dropped entirely because they could not parse even with their - * JSON stripped. The true data-loss signal; expected to stay near zero. + * Counts rows skipped as un-ingestable. A floor, not an exact count: these + * tables carry row-multiplying materialized views, so ClickHouse's insert + * summary can't separate skipped base rows from MV rows (see `droppedRowCount`). */ private _permanentlyDroppedRows = 0; private readonly _rowsDroppedCounter: Counter; @@ -171,22 +160,12 @@ export class ClickhouseEventRepository implements IEventRepository { }); this._rowIsolatedBatchesCounter = meter.createCounter("ingest.flush.batches_row_isolated", { description: - "Batches recovered by isolating un-ingestable rows (landed the rest) after a ClickHouse JSON parse error", + "Batches recovered by skipping un-ingestable rows (landed the rest) after a ClickHouse JSON parse error; each lost at least one row", unit: "batches", }); - this._recoveryCapHitsCounter = meter.createCounter("ingest.flush.recovery_cap_hits", { - description: - "Batches whose row isolation hit the per-batch insert budget and stripped the remainder in one insert (poison-flood signal)", - unit: "batches", - }); - this._rowsStrippedCounter = meter.createCounter("ingest.flush.rows_stripped", { - description: - "Rows landed with their un-ingestable JSON stripped (kept the row, lost only the JSON content)", - unit: "rows", - }); this._rowsDroppedCounter = meter.createCounter("ingest.flush.rows_dropped", { description: - "Rows dropped entirely because they could not parse even with their JSON stripped", + "Rows skipped as un-ingestable, as a lower bound: these tables' materialized views make the exact count underivable from ClickHouse's insert summary", unit: "rows", }); @@ -243,22 +222,12 @@ export class ClickhouseEventRepository implements IEventRepository { return this._permanentlyDroppedBatches; } - /** Exposed for tests and metrics — batches that took the row-isolation recovery path. */ + /** Exposed for tests and metrics — batches that took the bad-row-skip recovery path. */ get rowIsolationRecoveries() { return this._rowIsolationRecoveries; } - /** Exposed for tests and metrics — batches whose isolation hit the per-batch insert budget. */ - get recoveryCapHits() { - return this._recoveryCapHits; - } - - /** Exposed for tests and metrics — rows that landed with their un-ingestable JSON stripped. */ - get rowsStripped() { - return this._rowsStripped; - } - - /** Exposed for tests and metrics — rows dropped entirely (could not parse even stripped). */ + /** Exposed for tests and metrics — rows skipped as un-ingestable (a lower bound). */ get permanentlyDroppedRows() { return this._permanentlyDroppedRows; } @@ -416,20 +385,10 @@ export class ClickhouseEventRepository implements IEventRepository { this._rowIsolationRecoveries += 1; this._rowIsolatedBatchesCounter.add(1, { table: contextLabel }); - if (outcome.capped) { - this._recoveryCapHits += 1; - this._recoveryCapHitsCounter.add(1, { table: contextLabel }); - } - - if (outcome.rowsStripped > 0) { - this._rowsStripped += outcome.rowsStripped; - this._rowsStrippedCounter.add(outcome.rowsStripped, { table: contextLabel }); - } - if (outcome.rowsDropped > 0) { this._permanentlyDroppedRows += outcome.rowsDropped; this._rowsDroppedCounter.add(outcome.rowsDropped, { table: contextLabel }); - if (outcome.rowsDropped === batchSize) { + if (outcome.rowsDroppedExact && outcome.rowsDropped === batchSize) { this._permanentlyDroppedBatches += 1; this._droppedBatchesCounter.add(1, { table: contextLabel }); } diff --git a/apps/webapp/app/v3/eventRepository/sanitizeRowsOnParseError.server.ts b/apps/webapp/app/v3/eventRepository/sanitizeRowsOnParseError.server.ts index d2e87230f72..f2fd672af72 100644 --- a/apps/webapp/app/v3/eventRepository/sanitizeRowsOnParseError.server.ts +++ b/apps/webapp/app/v3/eventRepository/sanitizeRowsOnParseError.server.ts @@ -182,10 +182,35 @@ export type JsonParseRecoveryLogger = { warn: (message: string, meta?: Record) => void; }; +/** + * Why recovery stopped isolating rows and fell back to a single `allow_errors` + * insert. Both causes land the same way, so they share the `capped` flag and its + * counter; this distinguishes them in logs. + */ +export type RecoveryBailReason = + /** The per-batch strip budget (`maxPoisonStrips`) was spent. A poison flood. */ + | "strip_budget_spent" + /** ClickHouse gave no usable `at row N` hint, so there was no row to strip. */ + | "row_not_locatable" + /** The loop guard tripped without either of the above. Should not happen. */ + | "strip_attempts_exhausted"; + export type JsonParseRecoveryOutcome = | { kind: "inserted"; insertResult: unknown } | { kind: "sanitized"; insertResult: unknown } - | { kind: "recovered"; rowsStripped: number; rowsDropped: number; capped: boolean }; + | { + kind: "recovered"; + rowsStripped: number; + rowsDropped: number; + /** + * False when `rowsDropped` is a floor rather than an exact count, which is + * the case on tables with row-multiplying materialized views. Callers + * should read `rowsDropped` as "at least this many" when this is false. + */ + rowsDroppedExact: boolean; + capped: boolean; + bailReason?: RecoveryBailReason; + }; /** * Default number of poison rows to isolate-and-strip precisely before bailing @@ -265,6 +290,7 @@ export async function insertWithLimitedStrip(params: { const working = rows.slice(); const stripped = new Array(working.length).fill(false); let rowsStripped = 0; + let bailReason: RecoveryBailReason = "strip_attempts_exhausted"; let guard = maxPoisonStrips + 2; while (guard-- > 0) { @@ -283,18 +309,30 @@ export async function insertWithLimitedStrip(params: { } ); } - return { kind: "recovered", rowsStripped, rowsDropped: 0, capped: false }; + return { + kind: "recovered", + rowsStripped, + rowsDropped: 0, + rowsDroppedExact: true, + capped: false, + }; } catch (error) { if (!isClickHouseJsonParseError(error)) throw error; parseError = error; } + if (rowsStripped >= maxPoisonStrips) { + bailReason = "strip_budget_spent"; + break; + } + const hint = parseRowNumberFromError(rawErrorMessage(parseError)); const index = hint === null ? -1 : hint - 1; - const canStrip = - rowsStripped < maxPoisonStrips && index >= 0 && index < working.length && !stripped[index]; - if (!canStrip) break; + if (index < 0 || index >= working.length || stripped[index]) { + bailReason = "row_not_locatable"; + break; + } working[index] = stripJsonColumns(working[index]); stripped[index] = true; @@ -302,22 +340,28 @@ export async function insertWithLimitedStrip(params: { } const insertResult = await insertAllowingBadRows(working); - const rowsDropped = droppedRowCount(insertResult, working.length, hasMaterializedViews); - - logger.warn( - "Hit the poison-row strip limit — landed the batch via allow_errors and skipped the remaining un-ingestable rows", - { - ...logContext, - contextLabel, - batchSize: rows.length, - rowsStripped, - rowsDropped, - landedRows: writtenRowCount(insertResult), - clickhouseError: firstMessage.split("\n")[0], - } - ); - - return { kind: "recovered", rowsStripped, rowsDropped, capped: true }; + const dropped = droppedRowCount(insertResult, working.length, hasMaterializedViews); + + logger.warn("Landed the batch via allow_errors and skipped the remaining un-ingestable rows", { + ...logContext, + contextLabel, + bailReason, + batchSize: rows.length, + rowsStripped, + rowsDropped: dropped.rows, + rowsDroppedExact: dropped.exact, + landedRows: writtenRowCount(insertResult), + clickhouseError: firstMessage.split("\n")[0], + }); + + return { + kind: "recovered", + rowsStripped, + rowsDropped: dropped.rows, + rowsDroppedExact: dropped.exact, + capped: true, + bailReason, + }; } } @@ -335,24 +379,36 @@ function writtenRowCount(insertResult: unknown): number | null { } /** - * Derives how many rows a `allow_errors` insert dropped, from the insert - * summary's `written_rows`. This is exact only when `written_rows` is a clean - * count of the target-table rows. On tables with row-multiplying materialized - * views, ClickHouse folds the MV-written rows into `written_rows` too, so a - * partial-drop count isn't derivable; the only reliable signal there is - * `written_rows === 0`, which means the whole batch was dropped (no base rows, - * so no MV rows either). + * Reaching an `allow_errors` insert means the batch still failed to parse after + * everything cheaper was tried, so at least one row is un-ingestable and will be + * skipped. This is the floor we report when the exact count isn't derivable — + * reporting 0 there would read as "no data lost", which is the opposite of what + * happened. + */ +const MINIMUM_DROPPED_ROWS = 1; + +/** + * Derives how many rows an `allow_errors` insert dropped, from the insert + * summary's `written_rows`. + * + * Exact only when `written_rows` is a clean count of the target-table rows. On + * tables with row-multiplying materialized views ClickHouse folds the MV-written + * rows into `written_rows` too, so a partial-drop count isn't derivable; the only + * exact signal there is `written_rows === 0`, meaning the whole batch was dropped + * (no base rows, so no MV rows either). Everywhere else on such a table the + * result is the `MINIMUM_DROPPED_ROWS` floor flagged `exact: false`, so callers + * can say "at least one" instead of a confident zero. */ function droppedRowCount( insertResult: unknown, batchSize: number, hasMaterializedViews: boolean -): number { +): { rows: number; exact: boolean } { const written = writtenRowCount(insertResult); - if (written === null) return 0; - if (written === 0) return batchSize; - if (hasMaterializedViews) return 0; - return Math.max(0, batchSize - written); + if (written === null) return { rows: MINIMUM_DROPPED_ROWS, exact: false }; + if (written === 0) return { rows: batchSize, exact: true }; + if (hasMaterializedViews) return { rows: MINIMUM_DROPPED_ROWS, exact: false }; + return { rows: Math.max(0, batchSize - written), exact: true }; } /** @@ -370,9 +426,12 @@ function droppedRowCount( * insert regardless of how many rows are bad. * 4. Non-parse errors propagate unchanged. * - * The batch-level recovery is always counted by the caller; the per-row dropped - * count is exact on tables without row-multiplying materialized views and - * whole-batch-only on tables that have them (see `droppedRowCount`). + * The batch-level recovery is always counted by the caller. The per-row dropped + * count is exact on tables without row-multiplying materialized views; on tables + * that have them it is a floor of one flagged `rowsDroppedExact: false`, since + * ClickHouse's summary can't separate skipped base rows from MV rows (see + * `droppedRowCount`). Reaching the skip insert always means real data loss, so it + * logs at warn. */ export async function insertWithBadRowSkip(params: { rows: T[]; @@ -412,20 +471,27 @@ export async function insertWithBadRowSkip(params: { } const insertResult = await insertAllowingBadRows(rows); - const rowsDropped = droppedRowCount(insertResult, rows.length, hasMaterializedViews); + const dropped = droppedRowCount(insertResult, rows.length, hasMaterializedViews); - logger.info( + logger.warn( "Skipped un-ingestable rows after ClickHouse JSON parse error — landed the rest of the batch", { ...logContext, contextLabel, batchSize: rows.length, - rowsDropped, + rowsDropped: dropped.rows, + rowsDroppedExact: dropped.exact, landedRows: writtenRowCount(insertResult), clickhouseError: firstMessage.split("\n")[0], } ); - return { kind: "recovered", rowsStripped: 0, rowsDropped, capped: false }; + return { + kind: "recovered", + rowsStripped: 0, + rowsDropped: dropped.rows, + rowsDroppedExact: dropped.exact, + capped: false, + }; } } diff --git a/apps/webapp/test/clickhouseEventRepositoryJsonRecovery.test.ts b/apps/webapp/test/clickhouseEventRepositoryJsonRecovery.test.ts index 695046965ae..375d7c4498d 100644 --- a/apps/webapp/test/clickhouseEventRepositoryJsonRecovery.test.ts +++ b/apps/webapp/test/clickhouseEventRepositoryJsonRecovery.test.ts @@ -114,9 +114,8 @@ describe("ClickhouseEventRepository JSON parse recovery", () => { expect(rowsById.has(poisonSpanId)).toBe(false); expect(repository.permanentlyDroppedBatches).toBe(0); - expect(repository.permanentlyDroppedRows).toBe(0); expect(repository.rowIsolationRecoveries).toBeGreaterThanOrEqual(1); - expect(repository.rowsStripped).toBe(0); + expect(repository.permanentlyDroppedRows).toBeGreaterThanOrEqual(1); } finally { await (repository as any)._flushScheduler?.shutdown?.(); } diff --git a/apps/webapp/test/runsReplicationService.part10.test.ts b/apps/webapp/test/runsReplicationService.part10.test.ts index 13f20097025..cab9cef8657 100644 --- a/apps/webapp/test/runsReplicationService.part10.test.ts +++ b/apps/webapp/test/runsReplicationService.part10.test.ts @@ -222,6 +222,7 @@ describe("RunsReplicationService (part 10/10) — JSON parse recovery", () => { expect(runsReplicationService.permanentlyDroppedBatches).toBe(0); expect(runsReplicationService.rowsStripped).toBeGreaterThanOrEqual(1); expect(runsReplicationService.recoveryCapHits).toBeGreaterThanOrEqual(1); + expect(runsReplicationService.permanentlyDroppedRows).toBeGreaterThanOrEqual(1); await runsReplicationService.stop(); } diff --git a/apps/webapp/test/sanitizeRowsOnParseError.test.ts b/apps/webapp/test/sanitizeRowsOnParseError.test.ts index 5d3bd4e7cfa..720188fbd36 100644 --- a/apps/webapp/test/sanitizeRowsOnParseError.test.ts +++ b/apps/webapp/test/sanitizeRowsOnParseError.test.ts @@ -387,7 +387,13 @@ describe("insertWithLimitedStrip", () => { stripJsonColumns, }); - expect(outcome).toEqual({ kind: "recovered", rowsStripped: 1, rowsDropped: 0, capped: false }); + expect(outcome).toEqual({ + kind: "recovered", + rowsStripped: 1, + rowsDropped: 0, + rowsDroppedExact: true, + capped: false, + }); expect(landed.map((r) => r.id).sort((a, b) => a - b)).toEqual([0, 1, 2, 3, 4]); expect(landed.find((r) => r.id === 2)?.stripped).toBe(true); expect(landed.filter((r) => r.id !== 2).every((r) => !r.stripped)).toBe(true); @@ -411,7 +417,14 @@ describe("insertWithLimitedStrip", () => { hasMaterializedViews: false, }); - expect(outcome).toEqual({ kind: "recovered", rowsStripped: 1, rowsDropped: 1, capped: true }); + expect(outcome).toEqual({ + kind: "recovered", + rowsStripped: 1, + rowsDropped: 1, + rowsDroppedExact: true, + capped: true, + bailReason: "strip_budget_spent", + }); expect(allowCalls()).toBe(1); expect(landed.map((r) => r.id).sort((a, b) => a - b)).toEqual([0, 1, 2, 4]); expect(landed.find((r) => r.id === 1)?.stripped).toBe(true); @@ -434,7 +447,13 @@ describe("insertWithLimitedStrip", () => { maxPoisonStrips: 3, }); - expect(outcome).toEqual({ kind: "recovered", rowsStripped: 2, rowsDropped: 0, capped: false }); + expect(outcome).toEqual({ + kind: "recovered", + rowsStripped: 2, + rowsDropped: 0, + rowsDroppedExact: true, + capped: false, + }); expect(allowCalls()).toBe(0); expect(landed.map((r) => r.id).sort((a, b) => a - b)).toEqual([0, 1, 2, 3]); }); @@ -467,7 +486,14 @@ describe("insertWithLimitedStrip", () => { hasMaterializedViews: false, }); - expect(outcome).toEqual({ kind: "recovered", rowsStripped: 0, rowsDropped: 1, capped: true }); + expect(outcome).toEqual({ + kind: "recovered", + rowsStripped: 0, + rowsDropped: 1, + rowsDroppedExact: true, + capped: true, + bailReason: "row_not_locatable", + }); expect(allowCalls).toBe(1); expect(landed.map((r) => r.id).sort((a, b) => a - b)).toEqual([0, 2]); }); @@ -555,13 +581,19 @@ describe("insertWithBadRowSkip", () => { hasMaterializedViews: false, }); - expect(outcome).toEqual({ kind: "recovered", rowsStripped: 0, rowsDropped: 2, capped: false }); + expect(outcome).toEqual({ + kind: "recovered", + rowsStripped: 0, + rowsDropped: 2, + rowsDroppedExact: true, + capped: false, + }); expect(landed.map((r) => r.id).sort((a, b) => a - b)).toEqual([0, 2, 4]); expect(insertCalls()).toBe(1); expect(allowCalls()).toBe(1); }); - it("counts only whole-batch drops on a table with materialized views (partial drop uncountable)", async () => { + it("floors a partial drop at one on a table with materialized views, and counts a whole-batch drop exactly", async () => { const inflatedSummary = (goodCount: number) => ({ summary: { written_rows: String(goodCount * 3) }, }); @@ -580,7 +612,13 @@ describe("insertWithBadRowSkip", () => { insertAllowingBadRows, hasMaterializedViews: true, }); - expect(partial).toEqual({ kind: "recovered", rowsStripped: 0, rowsDropped: 0, capped: false }); + expect(partial).toEqual({ + kind: "recovered", + rowsStripped: 0, + rowsDropped: 1, + rowsDroppedExact: false, + capped: false, + }); const wholeBatch = await insertWithBadRowSkip({ rows: [ @@ -597,6 +635,7 @@ describe("insertWithBadRowSkip", () => { kind: "recovered", rowsStripped: 0, rowsDropped: 2, + rowsDroppedExact: true, capped: false, }); }); @@ -635,7 +674,7 @@ describe("insertWithBadRowSkip", () => { expect(rows[0].msg).toBe(INVALID_UTF16_SENTINEL); }); - it("reports zero dropped when the summary has no written_rows count", async () => { + it("floors the dropped count at one when the summary has no written_rows count", async () => { const insert = async (rows: FakeRow[]) => { if (rows.some((r) => r.poison)) throw parseErrorAtRow(1); return undefined; @@ -650,7 +689,13 @@ describe("insertWithBadRowSkip", () => { insertAllowingBadRows, }); - expect(outcome).toEqual({ kind: "recovered", rowsStripped: 0, rowsDropped: 0, capped: false }); + expect(outcome).toEqual({ + kind: "recovered", + rowsStripped: 0, + rowsDropped: 1, + rowsDroppedExact: false, + capped: false, + }); }); it("rethrows non-parse errors so the caller's transient-retry path handles them", async () => { diff --git a/internal-packages/clickhouse/src/client/errors.test.ts b/internal-packages/clickhouse/src/client/errors.test.ts new file mode 100644 index 00000000000..12e4d43169b --- /dev/null +++ b/internal-packages/clickhouse/src/client/errors.test.ts @@ -0,0 +1,29 @@ +import { describe, expect, it } from "vitest"; +import { InsertError } from "./errors.js"; + +describe("InsertError.rawMessage", () => { + const rawMessage = + 'Code: 117. DB::Exception: Cannot parse JSON object here: {"secret":"customer-payload"}: (at row 3)'; + + it("is readable by the recovery path", () => { + expect(new InsertError("Cannot parse JSON object here", { rawMessage }).rawMessage).toBe( + rawMessage + ); + }); + + it("stays out of anything that serializes own enumerable properties", () => { + const error = new InsertError("Cannot parse JSON object here", { rawMessage }); + + expect(Object.keys(error)).not.toContain("rawMessage"); + expect(JSON.stringify(error)).not.toContain("customer-payload"); + expect(JSON.stringify({ ...error })).not.toContain("customer-payload"); + expect(error.toString()).not.toContain("customer-payload"); + }); + + it("is absent rather than undefined-valued when no raw message is supplied", () => { + const error = new InsertError("boom"); + + expect(error.rawMessage).toBeUndefined(); + expect(Object.keys(error)).not.toContain("rawMessage"); + }); +}); diff --git a/internal-packages/clickhouse/src/client/errors.ts b/internal-packages/clickhouse/src/client/errors.ts index c0ceacb830f..906aa87e13d 100644 --- a/internal-packages/clickhouse/src/client/errors.ts +++ b/internal-packages/clickhouse/src/client/errors.ts @@ -24,12 +24,22 @@ export abstract class BaseError ex export class InsertError extends BaseError { public readonly retry = true; public readonly name = InsertError.name; - public readonly rawMessage?: string; + /** + * Untruncated ClickHouse error text, kept only so the JSON-parse recovery path + * can read the `(at row N)` hint that `message` drops. Defined non-enumerable + * on purpose: ClickHouse embeds a snippet of the offending row in its parse + * errors, so this must not reach structured logs or error reporting, both of + * which serialize own enumerable properties. Direct reads still work. + */ + declare readonly rawMessage?: string; constructor(message: string, options?: { rawMessage?: string }) { super({ message, }); - this.rawMessage = options?.rawMessage; + Object.defineProperty(this, "rawMessage", { + value: options?.rawMessage, + enumerable: false, + }); } } export class QueryError extends BaseError<{ query: string }> { From 1c3448541dc09631772061520bb11924056d831d Mon Sep 17 00:00:00 2001 From: Eric Allam Date: Mon, 27 Jul 2026 22:53:37 +0100 Subject: [PATCH 9/9] fix(clickhouse): make the patched rawMessage non-enumerable at the source Making the field non-enumerable only on InsertError left the leak open one layer down: the client logs the raw ClickHouseError at every insert-error site before converting it, and the patch assigned rawMessage as a plain enumerable property, so the offending-row snippet still reached structured logs. The patch now defines the field non-enumerable itself. Covers the patch's behaviour with a test that reads the row hint back through the public parseError export, which also fails loudly if the patch ever stops being applied. --- .../clickhouse/src/client/errors.test.ts | 24 ++++++++++++++++--- .../@clickhouse__client-common@1.12.1.patch | 2 +- pnpm-lock.yaml | 6 ++--- 3 files changed, 25 insertions(+), 7 deletions(-) diff --git a/internal-packages/clickhouse/src/client/errors.test.ts b/internal-packages/clickhouse/src/client/errors.test.ts index 12e4d43169b..037de63f8d9 100644 --- a/internal-packages/clickhouse/src/client/errors.test.ts +++ b/internal-packages/clickhouse/src/client/errors.test.ts @@ -1,10 +1,28 @@ +import { ClickHouseError, parseError } from "@clickhouse/client"; import { describe, expect, it } from "vitest"; import { InsertError } from "./errors.js"; -describe("InsertError.rawMessage", () => { - const rawMessage = - 'Code: 117. DB::Exception: Cannot parse JSON object here: {"secret":"customer-payload"}: (at row 3)'; +const rawMessage = + 'Code: 117. DB::Exception: Cannot parse JSON object here: {"secret":"customer-payload"}: (at row 3) (INCORRECT_DATA) (version 26.2.1.1)'; + +describe("patched ClickHouseError.rawMessage", () => { + it("carries the untruncated text so the recovery path can read the row hint", () => { + const error = parseError(rawMessage); + + expect(error).toBeInstanceOf(ClickHouseError); + expect((error as ClickHouseError).rawMessage).toContain("at row 3"); + }); + it("stays out of anything that serializes own enumerable properties", () => { + const error = parseError(rawMessage); + + expect(Object.keys(error)).not.toContain("rawMessage"); + expect(JSON.stringify(error)).not.toContain("customer-payload"); + expect(JSON.stringify({ ...error })).not.toContain("customer-payload"); + }); +}); + +describe("InsertError.rawMessage", () => { it("is readable by the recovery path", () => { expect(new InsertError("Cannot parse JSON object here", { rawMessage }).rawMessage).toBe( rawMessage diff --git a/patches/@clickhouse__client-common@1.12.1.patch b/patches/@clickhouse__client-common@1.12.1.patch index eb4dc08a000..b5e0ac03add 100644 --- a/patches/@clickhouse__client-common@1.12.1.patch +++ b/patches/@clickhouse__client-common@1.12.1.patch @@ -21,7 +21,7 @@ index e06fa4ab36537c2a448857c1b001e70cd771bfe5..9750bd7e1285ac8cf2c8095b592ed344 - return new ClickHouseError(groups); + const error = new ClickHouseError(groups); + if (!inputIsError && groups.message.startsWith("Cannot parse JSON object")) { -+ error.rawMessage = message; ++ Object.defineProperty(error, "rawMessage", { value: message, enumerable: false }); + } + return error; } diff --git a/pnpm-lock.yaml b/pnpm-lock.yaml index 7bf625e41a8..0ffa2ee1def 100644 --- a/pnpm-lock.yaml +++ b/pnpm-lock.yaml @@ -59,7 +59,7 @@ patchedDependencies: hash: a7a12643e8d89a00d5322f750c292e8567b5ee0fc9c613a238a1184c25533e4b path: patches/@changesets__assemble-release-plan@5.2.4.patch '@clickhouse/client-common@1.12.1': - hash: 870d9f887c4057af8fa50fb52936fb7e8463f62f5e88e70b804c3a7445c98b4d + hash: 784ccad1302960bef63d3f9df9085d5d2fb748593d47030ee00a937e945f3c9d path: patches/@clickhouse__client-common@1.12.1.patch '@kubernetes/client-node@1.0.0': hash: ba1a06f46256cdb8d6faf7167246692c0de2e7cd846a9dc0f13be0137e1c3745 @@ -17698,7 +17698,7 @@ snapshots: '@clickhouse/client-common@1.11.1': {} - '@clickhouse/client-common@1.12.1(patch_hash=870d9f887c4057af8fa50fb52936fb7e8463f62f5e88e70b804c3a7445c98b4d)': {} + '@clickhouse/client-common@1.12.1(patch_hash=784ccad1302960bef63d3f9df9085d5d2fb748593d47030ee00a937e945f3c9d)': {} '@clickhouse/client@1.11.1': dependencies: @@ -17706,7 +17706,7 @@ snapshots: '@clickhouse/client@1.12.1': dependencies: - '@clickhouse/client-common': 1.12.1(patch_hash=870d9f887c4057af8fa50fb52936fb7e8463f62f5e88e70b804c3a7445c98b4d) + '@clickhouse/client-common': 1.12.1(patch_hash=784ccad1302960bef63d3f9df9085d5d2fb748593d47030ee00a937e945f3c9d) '@codemirror/autocomplete@6.4.0(@codemirror/language@6.3.2)(@codemirror/state@6.2.0)(@codemirror/view@6.7.2)(@lezer/common@1.3.0)': dependencies: