From 1038c7e64973cd0dcd9d2fc11d649d280957ada1 Mon Sep 17 00:00:00 2001 From: Izaak Gough Date: Tue, 11 Aug 2026 11:26:27 +0100 Subject: [PATCH 01/21] fix(firestore-bigquery-export): scope insert retry to schema lag `isRetryableInsertionError` was declared `async` but called without `await`, so the guard evaluated an always-truthy promise. Every insert failure was retried once with `ignoreUnknownValues: true`, and its allowlist of expected errors never ran. The allowlist could not have worked regardless: it read `e.response.insertErrors.errors`, but `insertErrors` is an array on the raw `insertAll` response, so the guard never passed and the predicate always returned `true`. Together these meant any schema mismatch, not just a column we had just added, was retried with unknown fields ignored. BigQuery then accepted the row with those fields silently dropped and the write reported success. Split the predicate in two, both synchronous: a schema lag check that positively matches unknown-field errors naming columns this tracker adds to an existing table, and a transient check for failures with no partial-failure body. Only the former retries with `ignoreUnknownValues`; the latter retries with options unchanged. Also key the failed-transactions backup off whether the attempt is terminal rather than off `retry`. `retry` meant "a retry is available" at the guard but was read as "this is the second attempt" at the backup, which only coincided while the retry branch was unconditional. Without this, a non-retryable first attempt would throw without backing up. --- .../__tests__/bigquery/insertRetry.test.ts | 275 ++++++++++++++++++ .../src/bigquery/index.ts | 147 +++++++--- 2 files changed, 381 insertions(+), 41 deletions(-) create mode 100644 firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts diff --git a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts new file mode 100644 index 000000000..3db1c0077 --- /dev/null +++ b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts @@ -0,0 +1,275 @@ +/** + * Copyright 2026 Google LLC + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * https://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +import { FirestoreBigQueryEventHistoryTracker } from "../../bigquery"; +import { ChangeTrackerConfig } from "../../bigquery/types"; +import handleFailedTransactions from "../../bigquery/handleFailedTransactions"; + +jest.mock("../../bigquery/handleFailedTransactions", () => ({ + __esModule: true, + default: jest.fn().mockResolvedValue(undefined), +})); + +const handleFailedTransactionsMock = handleFailedTransactions as jest.Mock; + +process.env.PROJECT_ID = "test-project"; + +const config = ( + overrides: Partial = {} +): ChangeTrackerConfig => + ({ + datasetId: "dataset", + tableId: "table", + datasetLocation: "us", + backupTableId: "backup", + transformFunction: "", + partitioning: { granularity: "NONE" }, + clustering: [], + bqProjectId: "test-project", + ...overrides, + } as ChangeTrackerConfig); + +/** + * Builds the error shape `@google-cloud/bigquery` actually throws: a + * `PartialFailureError` whose `response` is the raw `insertAll` body, where + * `insertErrors` is an array. Its own `errors` property is the remapped copy + * that drops `location`. + */ +function partialFailure( + fieldErrors: Array<{ message: string; location?: string }> +) { + const e: any = new Error("insert failed"); + e.name = "PartialFailureError"; + e.errors = [ + { + row: {}, + errors: fieldErrors.map(({ message }) => ({ + message, + reason: "invalid", + })), + }, + ]; + e.response = { + kind: "bigquery#tableDataInsertAllResponse", + insertErrors: [{ index: 0, errors: fieldErrors }], + }; + return e; +} + +/** An error with no partial-failure body, e.g. a network or quota failure. */ +function transportFailure() { + const e: any = new Error("ECONNRESET"); + e.code = "ECONNRESET"; + return e; +} + +const ROWS = [{ insertId: "e1", json: { event_id: "e1" } }]; + +/** + * Returns a tracker whose inserts are served by `insert`, so no BigQuery + * client is needed. + */ +function trackerWith( + insert: jest.Mock, + overrides?: Partial +) { + const tracker = new FirestoreBigQueryEventHistoryTracker(config(overrides)); + + jest.spyOn(tracker as any, "bigqueryDataset").mockReturnValue({ + table: () => ({ insert }), + }); + + return tracker; +} + +/** Invokes the private insert path directly. */ +const insertData = (tracker: FirestoreBigQueryEventHistoryTracker) => + (tracker as any).insertData(ROWS); + +describe("insertData retry behaviour", () => { + beforeEach(() => { + jest.clearAllMocks(); + }); + + describe("a column we just added is not streamable yet", () => { + it("retries once ignoring unknown values, and succeeds", async () => { + const insert = jest + .fn() + .mockRejectedValueOnce( + partialFailure([ + { message: "no such field.", location: "document_id" }, + ]) + ) + .mockResolvedValueOnce(undefined); + + await expect(insertData(trackerWith(insert))).resolves.toBeUndefined(); + + expect(insert).toHaveBeenCalledTimes(2); + expect(insert.mock.calls[0][1]).toMatchObject({ + ignoreUnknownValues: false, + }); + expect(insert.mock.calls[1][1]).toMatchObject({ + ignoreUnknownValues: true, + }); + expect(handleFailedTransactionsMock).not.toHaveBeenCalled(); + }); + + it("matches the inlined message form that omits location", async () => { + const insert = jest + .fn() + .mockRejectedValueOnce( + partialFailure([{ message: "no such field: path_params." }]) + ) + .mockResolvedValueOnce(undefined); + + await expect(insertData(trackerWith(insert))).resolves.toBeUndefined(); + + expect(insert).toHaveBeenCalledTimes(2); + expect(insert.mock.calls[1][1]).toMatchObject({ + ignoreUnknownValues: true, + }); + }); + + it("backs up and throws when the retry also fails", async () => { + const error = partialFailure([ + { message: "no such field.", location: "old_data" }, + ]); + const insert = jest.fn().mockRejectedValue(error); + const tracker = trackerWith(insert); + + await expect(insertData(tracker)).rejects.toThrow("insert failed"); + + expect(insert).toHaveBeenCalledTimes(2); + expect(handleFailedTransactionsMock).toHaveBeenCalledTimes(1); + expect(tracker._initialized).toBe(false); + }); + }); + + describe("schema drift we did not add", () => { + it("does not retry, and does not silently drop the field", async () => { + const insert = jest + .fn() + .mockRejectedValue( + partialFailure([{ message: "no such field.", location: "user_age" }]) + ); + + await expect(insertData(trackerWith(insert))).rejects.toThrow( + "insert failed" + ); + + expect(insert).toHaveBeenCalledTimes(1); + expect(handleFailedTransactionsMock).toHaveBeenCalledTimes(1); + }); + + it("does not retry when only some rejected fields are ours", async () => { + const insert = jest.fn().mockRejectedValue( + partialFailure([ + { message: "no such field.", location: "document_id" }, + { message: "no such field.", location: "user_age" }, + ]) + ); + + await expect(insertData(trackerWith(insert))).rejects.toThrow( + "insert failed" + ); + + expect(insert).toHaveBeenCalledTimes(1); + }); + + it("does not retry a rejection that is not an unknown field", async () => { + const insert = jest.fn().mockRejectedValue( + partialFailure([ + { + message: "Cannot convert value to timestamp.", + location: "timestamp", + }, + ]) + ); + + await expect(insertData(trackerWith(insert))).rejects.toThrow( + "insert failed" + ); + + expect(insert).toHaveBeenCalledTimes(1); + }); + }); + + describe("transient failures", () => { + it("retries once with options unchanged", async () => { + const insert = jest + .fn() + .mockRejectedValueOnce(transportFailure()) + .mockResolvedValueOnce(undefined); + + await expect(insertData(trackerWith(insert))).resolves.toBeUndefined(); + + expect(insert).toHaveBeenCalledTimes(2); + expect(insert.mock.calls[1][1]).toMatchObject({ + ignoreUnknownValues: false, + }); + expect(handleFailedTransactionsMock).not.toHaveBeenCalled(); + }); + + it("backs up and throws when the retry also fails", async () => { + const insert = jest.fn().mockRejectedValue(transportFailure()); + + await expect(insertData(trackerWith(insert))).rejects.toThrow( + "ECONNRESET" + ); + + expect(insert).toHaveBeenCalledTimes(2); + expect(handleFailedTransactionsMock).toHaveBeenCalledTimes(1); + }); + }); + + describe("backup collection", () => { + it("is skipped when no backupTableId is configured", async () => { + const insert = jest + .fn() + .mockRejectedValue( + partialFailure([{ message: "no such field.", location: "user_age" }]) + ); + + await expect( + insertData(trackerWith(insert, { backupTableId: undefined })) + ).rejects.toThrow("insert failed"); + + expect(handleFailedTransactionsMock).not.toHaveBeenCalled(); + }); + + it("is used for a terminal failure on the first attempt", async () => { + const insert = jest + .fn() + .mockRejectedValue( + partialFailure([{ message: "no such field.", location: "user_age" }]) + ); + + await expect(insertData(trackerWith(insert))).rejects.toThrow( + "insert failed" + ); + + // Regression guard: this failure never reaches a second attempt, so a + // backup condition keyed on "this is the second attempt" would skip it. + expect(insert).toHaveBeenCalledTimes(1); + expect(handleFailedTransactionsMock).toHaveBeenCalledTimes(1); + expect(handleFailedTransactionsMock).toHaveBeenCalledWith( + ROWS, + expect.objectContaining({ backupTableId: "backup" }), + expect.any(Error) + ); + }); + }); +}); diff --git a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts index edc7052ba..fcc431c42 100644 --- a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts +++ b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts @@ -47,6 +47,55 @@ import type { ChangeTrackerConfig } from "./types"; import { PartitioningConfig } from "./partitioning/config"; export type { ChangeTrackerConfig } from "./types"; +/** A single error entry from a raw `insertAll` partial-failure response. */ +interface InsertAllError { + message?: string; + location?: string; + reason?: string; +} + +/** + * Flattens the per-field errors out of a BigQuery insert failure. + * + * `PartialFailureError` carries the raw `insertAll` response on `response`, + * where `insertErrors` is an array of `{ index, errors }`. The error's own + * `errors` property is a remapped copy that keeps only `message` and `reason`, + * so it cannot be used to identify which column BigQuery rejected. + * + * Returns an empty array for any failure that is not a partial failure, e.g. a + * network error or a quota rejection. + */ +function extractInsertErrors(e: any): InsertAllError[] { + const insertErrors = e?.response?.insertErrors; + + if (!Array.isArray(insertErrors)) return []; + + return insertErrors.flatMap((insertError) => + Array.isArray(insertError?.errors) ? insertError.errors : [] + ); +} + +/** + * Whether an error entry reports an unknown field naming one of `columns`. + * + * BigQuery has reported this two ways: a bare `"no such field."` with the + * column in `location`, and an inlined `"no such field: document_id."`. Match + * either, and treat an unattributable message as not matching so that we fail + * loudly rather than dropping data. + */ +function isUnknownFieldError( + error: InsertAllError, + columns: string[] +): boolean { + const message = error.message ?? ""; + + if (!/^no such field/i.test(message)) return false; + + if (error.location) return columns.includes(error.location); + + return columns.some((column) => message.includes(column)); +} + /** * An FirestoreEventHistoryTracker that exports data to BigQuery. * @@ -154,39 +203,45 @@ export class FirestoreBigQueryEventHistoryTracker } /** - * Check whether a failed operation is retryable or not. - * Reasons for retrying: - * 1) We added a new column to our schema. Sometimes BQ is not ready to stream insertion records immediately - * after adding a new column to an existing table (https://issuetracker.google.com/35905247) + * Whether a failed insertion is the one case it is safe to retry while + * ignoring unknown values: a column this tracker adds to an existing table + * that BigQuery is not ready to stream into yet + * (https://issuetracker.google.com/35905247). + * + * Every field BigQuery rejected must be one of those columns. Any other + * unknown field is real schema drift, and retrying it with + * `ignoreUnknownValues` would silently drop the user's data. + * + * Deliberately not `async`: the result is used in a boolean guard, and a + * promise there is always truthy. */ - private async isRetryableInsertionError(e) { - let isRetryable = true; - const expectedErrors = [ - { message: "no such field.", location: documentIdField.name }, - { message: "no such field.", location: documentPathParams.name }, + private isSchemaLagInsertionError(e: any): boolean { + const errors = extractInsertErrors(e); + + // Without per-field detail we cannot show the retry is safe. + if (!errors.length) return false; + + // The columns initializeRawChangeLogTable adds to an existing table. + const addedColumns = [ + documentIdField.name, + documentPathParams.name, + oldDataField.name, ]; - if ( - e.response && - e.response.insertErrors && - e.response.insertErrors.errors - ) { - const errors = e.response.insertErrors.errors; - errors?.forEach((error) => { - let isExpected = false; - expectedErrors?.forEach((expectedError) => { - if ( - error.message === expectedError.message && - error.location === expectedError.location - ) { - isExpected = true; - } - }); - if (!isExpected) { - isRetryable = false; - } - }); - } - return isRetryable; + + return errors.every((error) => isUnknownFieldError(error, addedColumns)); + } + + /** + * Whether a failed insertion is worth one plain retry, with options + * unchanged. + * + * A failure with no partial-failure body — a network blip, a quota + * rejection, a 5xx — says nothing about our schema, so retrying it as-is is + * safe. A partial failure we did not recognise is BigQuery rejecting the + * shape of the data itself, which a plain retry cannot fix. + */ + private isTransientInsertionError(e: any): boolean { + return extractInsertErrors(e).length === 0; } /** @@ -233,18 +288,28 @@ export class FirestoreBigQueryEventHistoryTracker await table.insert(rows, options); logs.dataInserted(rows.length); } catch (e) { - if (retry && this.isRetryableInsertionError(e)) { - retry = false; - logs.dataInsertRetried(rows.length); - return this.insertData( - rows, - { ...overrideOptions, ignoreUnknownValues: true }, - retry - ); + if (retry) { + // A column we just added may not be streamable yet. Retry ignoring the + // fields BigQuery does not know about, so the rest of the row lands. + if (this.isSchemaLagInsertionError(e)) { + logs.dataInsertRetried(rows.length); + return this.insertData( + rows, + { ...overrideOptions, ignoreUnknownValues: true }, + false + ); + } + + // Transient failures deserve a retry, but not with + // `ignoreUnknownValues` — that would silently drop real data. + if (this.isTransientInsertionError(e)) { + logs.dataInsertRetried(rows.length); + return this.insertData(rows, overrideOptions, false); + } } - // Exceeded number of retries, save in failed collection - if (!retry && this.config.backupTableId) { + // Terminal: no further attempt will be made for these rows. + if (this.config.backupTableId) { await handleFailedTransactions(rows, this.config, e); } From be6bda6454828db4f41c62b81ccbeb2000dd535e Mon Sep 17 00:00:00 2001 From: Izaak Gough Date: Tue, 11 Aug 2026 11:34:49 +0100 Subject: [PATCH 02/21] fix(firestore-bigquery-export): narrow retry allowlist to two columns `old_data` is also added to existing tables by initializeRawChangeLogTable, so it shares the streaming-lag exposure, but the lag has never been observed for it and the allowlist governs what we are willing to silently drop. Keep it to the two columns the original allowlist named. An unlisted column now takes the terminal path: the rows are backed up, the error is thrown and the tracker reinitializes, so the schema still reconciles and the trigger retry redelivers. That is a better outcome than dropping the column's contents. --- .../__tests__/bigquery/insertRetry.test.ts | 20 ++++++++++++++++++- .../src/bigquery/index.ts | 20 +++++++++---------- 2 files changed, 29 insertions(+), 11 deletions(-) diff --git a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts index 3db1c0077..5fcdf8926 100644 --- a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts +++ b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts @@ -145,7 +145,7 @@ describe("insertData retry behaviour", () => { it("backs up and throws when the retry also fails", async () => { const error = partialFailure([ - { message: "no such field.", location: "old_data" }, + { message: "no such field.", location: "path_params" }, ]); const insert = jest.fn().mockRejectedValue(error); const tracker = trackerWith(insert); @@ -156,6 +156,24 @@ describe("insertData retry behaviour", () => { expect(handleFailedTransactionsMock).toHaveBeenCalledTimes(1); expect(tracker._initialized).toBe(false); }); + + it("does not extend the allowlist to old_data", async () => { + // old_data is also added to existing tables, but is deliberately not + // allowlisted: it takes the terminal path so the rows are backed up and + // the tracker reinitializes, rather than the column being dropped. + const insert = jest + .fn() + .mockRejectedValue( + partialFailure([{ message: "no such field.", location: "old_data" }]) + ); + + await expect(insertData(trackerWith(insert))).rejects.toThrow( + "insert failed" + ); + + expect(insert).toHaveBeenCalledTimes(1); + expect(handleFailedTransactionsMock).toHaveBeenCalledTimes(1); + }); }); describe("schema drift we did not add", () => { diff --git a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts index fcc431c42..f84d25e80 100644 --- a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts +++ b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts @@ -221,12 +221,12 @@ export class FirestoreBigQueryEventHistoryTracker // Without per-field detail we cannot show the retry is safe. if (!errors.length) return false; - // The columns initializeRawChangeLogTable adds to an existing table. - const addedColumns = [ - documentIdField.name, - documentPathParams.name, - oldDataField.name, - ]; + // Deliberately narrow. `old_data` is also added to existing tables by + // initializeRawChangeLogTable, but the lag has never been observed for it, + // and every column listed here is one whose contents we are willing to + // drop. An unlisted column takes the terminal path instead, which backs the + // rows up and reinitializes, so the schema still reconciles. + const addedColumns = [documentIdField.name, documentPathParams.name]; return errors.every((error) => isUnknownFieldError(error, addedColumns)); } @@ -235,9 +235,9 @@ export class FirestoreBigQueryEventHistoryTracker * Whether a failed insertion is worth one plain retry, with options * unchanged. * - * A failure with no partial-failure body — a network blip, a quota - * rejection, a 5xx — says nothing about our schema, so retrying it as-is is - * safe. A partial failure we did not recognise is BigQuery rejecting the + * A failure with no partial-failure body (a network blip, a quota rejection, + * a 5xx) says nothing about our schema, so retrying it as-is is safe. + * A partial failure we did not recognise is BigQuery rejecting the * shape of the data itself, which a plain retry cannot fix. */ private isTransientInsertionError(e: any): boolean { @@ -301,7 +301,7 @@ export class FirestoreBigQueryEventHistoryTracker } // Transient failures deserve a retry, but not with - // `ignoreUnknownValues` — that would silently drop real data. + // `ignoreUnknownValues`, which would silently drop real data. if (this.isTransientInsertionError(e)) { logs.dataInsertRetried(rows.length); return this.insertData(rows, overrideOptions, false); From 12c77d6283b21ba21e66470413bbb5ec85f41cba Mon Sep 17 00:00:00 2001 From: Izaak Gough Date: Tue, 11 Aug 2026 11:46:38 +0100 Subject: [PATCH 03/21] fix(firestore-bigquery-export): match unknown field names exactly The fallback for the inlined `"no such field: document_id."` form used a substring test, so a user column whose name contains an allowlisted one, such as `document_id_v2`, matched. That column would then be retried with `ignoreUnknownValues` and silently dropped, which is the exact failure this change set out to remove. Parse the field name out of the message and compare it whole. A message with no colon and no `location` still does not match, so it takes the terminal path. --- .../src/__tests__/bigquery/insertRetry.test.ts | 16 ++++++++++++++++ .../src/bigquery/index.ts | 8 +++++++- 2 files changed, 23 insertions(+), 1 deletion(-) diff --git a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts index 5fcdf8926..e922785b8 100644 --- a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts +++ b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts @@ -157,6 +157,22 @@ describe("insertData retry behaviour", () => { expect(tracker._initialized).toBe(false); }); + it("does not match a column that merely contains an allowlisted name", async () => { + // A user column named document_id_v2 must not be mistaken for + // document_id, or its contents would be silently dropped. + const insert = jest + .fn() + .mockRejectedValue( + partialFailure([{ message: "no such field: document_id_v2." }]) + ); + + await expect(insertData(trackerWith(insert))).rejects.toThrow( + "insert failed" + ); + + expect(insert).toHaveBeenCalledTimes(1); + }); + it("does not extend the allowlist to old_data", async () => { // old_data is also added to existing tables, but is deliberately not // allowlisted: it takes the terminal path so the rows are backed up and diff --git a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts index f84d25e80..5b55b01c9 100644 --- a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts +++ b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts @@ -91,9 +91,15 @@ function isUnknownFieldError( if (!/^no such field/i.test(message)) return false; + // The bare form names the column in `location`. if (error.location) return columns.includes(error.location); - return columns.some((column) => message.includes(column)); + // The inlined form carries the column in the message. Compare the whole name: + // a substring test would match a user column such as `document_id_v2` and + // silently drop it. + const named = message.match(/^no such field:\s*(.+?)\.?$/i); + + return named ? columns.includes(named[1]) : false; } /** From 122cae61195043c89587d3e9d681a2b62510eb5a Mon Sep 17 00:00:00 2001 From: Izaak Gough Date: Tue, 11 Aug 2026 12:01:45 +0100 Subject: [PATCH 04/21] fix(firestore-bigquery-export): keep old_data allowlisted, protect the cause Restore `old_data` to the retry allowlist. Excluding it was a regression, not a tightening: on the current code every unknown field is tolerated by dropping it, so a row hitting the streaming-buffer lag after `old_data` is added to an existing table lands today with that column null. Excluded, the same event instead fails terminally and is lost once the caller exhausts its retries, because nothing on the write path reconciles the schema. `_initialized = false` does not achieve that: `record()` only calls `initialize()` when `!skipInit`, and both the extension and the kit set `skipInit: true`. The allowlist now covers exactly the three columns initializeRawChangeLogTable adds to a table that already exists, and a parameterised test pins all three. Also stop the terminal path from destroying the error it is reporting: - Wrap the backup write. A Firestore batch failure replaced the insert error, so the caller lost the cause it needs to decide whether to retry, and the error logging was skipped too. - Make classification defensive to match `extractInsertErrors`. A null entry in `errors`, or a non-object thrown value, raised a `TypeError` from inside the catch block, which replaced the original error and skipped the backup write entirely. The `_initialized` assertion in the existing test was vacuous, since the flag starts `false` and `initialize()` never runs under these mocks. It now sets the flag first, so it fails against an implementation that never clears it. --- .../__tests__/bigquery/insertRetry.test.ts | 89 +++++++++++++++---- .../src/bigquery/index.ts | 30 +++++-- .../src/logs.ts | 6 ++ 3 files changed, 99 insertions(+), 26 deletions(-) diff --git a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts index e922785b8..14fb820b9 100644 --- a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts +++ b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts @@ -150,6 +150,10 @@ describe("insertData retry behaviour", () => { const insert = jest.fn().mockRejectedValue(error); const tracker = trackerWith(insert); + // Must start true, or asserting false below passes against an + // implementation that never clears the flag at all. + tracker._initialized = true; + await expect(insertData(tracker)).rejects.toThrow("insert failed"); expect(insert).toHaveBeenCalledTimes(2); @@ -173,23 +177,27 @@ describe("insertData retry behaviour", () => { expect(insert).toHaveBeenCalledTimes(1); }); - it("does not extend the allowlist to old_data", async () => { - // old_data is also added to existing tables, but is deliberately not - // allowlisted: it takes the terminal path so the rows are backed up and - // the tracker reinitializes, rather than the column being dropped. - const insert = jest - .fn() - .mockRejectedValue( - partialFailure([{ message: "no such field.", location: "old_data" }]) - ); - - await expect(insertData(trackerWith(insert))).rejects.toThrow( - "insert failed" - ); - - expect(insert).toHaveBeenCalledTimes(1); - expect(handleFailedTransactionsMock).toHaveBeenCalledTimes(1); - }); + it.each(["document_id", "path_params", "old_data"])( + "covers %s, every column added to an existing table", + async (column) => { + // Dropping any of these from the allowlist would turn a row that lands + // today, with that column null, into an event lost once the caller + // exhausts its retries. + const insert = jest + .fn() + .mockRejectedValueOnce( + partialFailure([{ message: "no such field.", location: column }]) + ) + .mockResolvedValueOnce(undefined); + + await expect(insertData(trackerWith(insert))).resolves.toBeUndefined(); + + expect(insert).toHaveBeenCalledTimes(2); + expect(insert.mock.calls[1][1]).toMatchObject({ + ignoreUnknownValues: true, + }); + } + ); }); describe("schema drift we did not add", () => { @@ -241,6 +249,33 @@ describe("insertData retry behaviour", () => { }); }); + describe("malformed failures", () => { + it("survives a null entry in the errors array", async () => { + // Not producible by the current library, but classifying must never throw + // from inside the catch block: that would lose the real error and skip + // the backup entirely. + const insert = jest.fn().mockRejectedValue({ + message: "insert failed", + response: { insertErrors: [{ index: 0, errors: [null] }] }, + }); + + await expect(insertData(trackerWith(insert))).rejects.toMatchObject({ + message: "insert failed", + }); + + expect(insert).toHaveBeenCalledTimes(1); + expect(handleFailedTransactionsMock).toHaveBeenCalledTimes(1); + }); + + it("survives a non-object thrown value", async () => { + const insert = jest.fn().mockRejectedValue(undefined); + + await expect(insertData(trackerWith(insert))).rejects.toBeUndefined(); + + expect(handleFailedTransactionsMock).toHaveBeenCalledTimes(1); + }); + }); + describe("transient failures", () => { it("retries once with options unchanged", async () => { const insert = jest @@ -284,6 +319,26 @@ describe("insertData retry behaviour", () => { expect(handleFailedTransactionsMock).not.toHaveBeenCalled(); }); + it("does not let its own failure mask the insert error", async () => { + handleFailedTransactionsMock.mockRejectedValueOnce( + new Error("firestore batch failed") + ); + + const insert = jest + .fn() + .mockRejectedValue( + partialFailure([{ message: "no such field.", location: "user_age" }]) + ); + + // The caller needs the real cause to decide whether to retry, so the + // backup error must not replace it. + await expect(insertData(trackerWith(insert))).rejects.toThrow( + "insert failed" + ); + + expect(handleFailedTransactionsMock).toHaveBeenCalledTimes(1); + }); + it("is used for a terminal failure on the first attempt", async () => { const insert = jest .fn() diff --git a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts index 5b55b01c9..6e6d39485 100644 --- a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts +++ b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts @@ -87,7 +87,9 @@ function isUnknownFieldError( error: InsertAllError, columns: string[] ): boolean { - const message = error.message ?? ""; + // Defensive to match extractInsertErrors: a null entry must classify as not + // matching, not throw from inside the catch block and lose the real error. + const message = error?.message ?? ""; if (!/^no such field/i.test(message)) return false; @@ -227,12 +229,16 @@ export class FirestoreBigQueryEventHistoryTracker // Without per-field detail we cannot show the retry is safe. if (!errors.length) return false; - // Deliberately narrow. `old_data` is also added to existing tables by - // initializeRawChangeLogTable, but the lag has never been observed for it, - // and every column listed here is one whose contents we are willing to - // drop. An unlisted column takes the terminal path instead, which backs the - // rows up and reinitializes, so the schema still reconciles. - const addedColumns = [documentIdField.name, documentPathParams.name]; + // Every column initializeRawChangeLogTable adds to a table that already + // exists, and so every column exposed to the lag. All three must stay + // listed: dropping one from this list would turn a row that lands today + // (with that column null) into an event lost after the caller exhausts its + // retries, since nothing on the write path reconciles the schema. + const addedColumns = [ + documentIdField.name, + documentPathParams.name, + oldDataField.name, + ]; return errors.every((error) => isUnknownFieldError(error, addedColumns)); } @@ -316,12 +322,18 @@ export class FirestoreBigQueryEventHistoryTracker // Terminal: no further attempt will be made for these rows. if (this.config.backupTableId) { - await handleFailedTransactions(rows, this.config, e); + try { + await handleFailedTransactions(rows, this.config, e); + } catch (backupError) { + // Never let a failed backup write mask the insert error that caused + // it. The caller needs the original cause to decide whether to retry. + logs.failedBackupWrite(backupError); + } } // Reinitializing in case the destintation table is modified. this._initialized = false; - logs.bigQueryTableInsertErrors(e.errors); + logs.bigQueryTableInsertErrors(e?.errors); throw e; } } diff --git a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/logs.ts b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/logs.ts index 9b1b2f658..db7cabccc 100644 --- a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/logs.ts +++ b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/logs.ts @@ -227,6 +227,12 @@ export const bigQueryTableInsertErrors = ( }); }; +export const failedBackupWrite = (error: unknown) => { + logger.warn( + `Could not write failed rows to the backup collection. The original insert error is still thrown. Backup error: ${error}` + ); +}; + export const updatedClustering = (fields: string) => { logger.info(`Clustering updated with new settings fields: ${fields}`); }; From 5920826ffe5900d4418afe8ac32b479c62b3e783 Mon Sep 17 00:00:00 2001 From: Izaak Gough Date: Tue, 11 Aug 2026 14:10:06 +0100 Subject: [PATCH 05/21] fix(firestore-bigquery-export): allowlist the partition column, split retries Three gaps found in review. The allowlist was missing the user-configured partition column. addPartitioningToSchema adds it to a table that already exists, exactly as the other three are added, and getPartitionValue writes it into every row. An extension user setting TIME_PARTITIONING_FIELD on an existing changelog would hit the streaming lag on that column and, without this, lose the event instead of landing the row with the column null. Derive the list from the partitioning config so it stays complete. The two retries are now tracked separately. Sharing one budget meant a transient blip on the first attempt consumed the retry a schema lag needed on the second, so a row that lands today was lost. Each is spent at most once, bounding this layer at three attempts. bigQueryTableInsertErrors is called on the terminal path and was not defensive, so a bad entry in the library's remapped `errors` copy threw and replaced the insert error the caller needs. It now checks for arrays and reads entries optionally. This closes the same hole the earlier `e?.errors` change only half covered. --- .../__tests__/bigquery/insertRetry.test.ts | 126 ++++++++++++++++++ .../src/bigquery/index.ts | 79 +++++++---- .../src/logs.ts | 14 +- 3 files changed, 190 insertions(+), 29 deletions(-) diff --git a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts index 14fb820b9..56654173b 100644 --- a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts +++ b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts @@ -249,6 +249,101 @@ describe("insertData retry behaviour", () => { }); }); + describe("the user-configured partition column", () => { + // addPartitioningToSchema adds this column to an existing table too, so it + // has the same exposure as the other three. + const partitioned = { + partitioning: { + granularity: "HOUR", + bigqueryColumnName: "created_at", + bigqueryColumnType: "TIMESTAMP", + firestoreFieldName: "createdAt", + }, + } as Partial; + + it("is treated as schema lag when field partitioning is configured", async () => { + const insert = jest + .fn() + .mockRejectedValueOnce( + partialFailure([ + { message: "no such field.", location: "created_at" }, + ]) + ) + .mockResolvedValueOnce(undefined); + + await expect( + insertData(trackerWith(insert, partitioned)) + ).resolves.toBeUndefined(); + + expect(insert).toHaveBeenCalledTimes(2); + expect(insert.mock.calls[1][1]).toMatchObject({ + ignoreUnknownValues: true, + }); + }); + + it("is not allowlisted when no partitioning is configured", async () => { + const insert = jest + .fn() + .mockRejectedValue( + partialFailure([ + { message: "no such field.", location: "created_at" }, + ]) + ); + + await expect(insertData(trackerWith(insert))).rejects.toThrow( + "insert failed" + ); + + expect(insert).toHaveBeenCalledTimes(1); + }); + }); + + describe("a transient blip followed by a schema lag", () => { + it("can still retry the schema lag", async () => { + // The two retries are tracked separately, so the blip must not consume + // the one the lag needs. Without that, the row is lost. + const insert = jest + .fn() + .mockRejectedValueOnce(transportFailure()) + .mockRejectedValueOnce( + partialFailure([ + { message: "no such field.", location: "document_id" }, + ]) + ) + .mockResolvedValueOnce(undefined); + + await expect(insertData(trackerWith(insert))).resolves.toBeUndefined(); + + expect(insert).toHaveBeenCalledTimes(3); + expect(insert.mock.calls[1][1]).toMatchObject({ + ignoreUnknownValues: false, + }); + expect(insert.mock.calls[2][1]).toMatchObject({ + ignoreUnknownValues: true, + }); + expect(handleFailedTransactionsMock).not.toHaveBeenCalled(); + }); + + it("spends each retry at most once, bounding attempts at three", async () => { + const insert = jest + .fn() + .mockRejectedValueOnce(transportFailure()) + .mockRejectedValueOnce( + partialFailure([ + { message: "no such field.", location: "document_id" }, + ]) + ) + .mockRejectedValue(transportFailure()); + + await expect(insertData(trackerWith(insert))).rejects.toThrow( + "ECONNRESET" + ); + + expect(insert).toHaveBeenCalledTimes(3); + expect(handleFailedTransactionsMock).toHaveBeenCalledTimes(1); + }); + }); + describe("malformed failures", () => { it("survives a null entry in the errors array", async () => { // Not producible by the current library, but classifying must never throw @@ -274,6 +369,37 @@ describe("insertData retry behaviour", () => { expect(handleFailedTransactionsMock).toHaveBeenCalledTimes(1); }); + + it("still reports the insert error when error logging hits a bad entry", async () => { + // `e.errors` is the library's remapped copy and is logged on the terminal + // path. A bad entry there must not replace the error the caller sees. + const error: any = new Error("insert failed"); + error.errors = [null]; + error.response = { + insertErrors: [ + { index: 0, errors: [{ message: "no such field.", location: "x" }] }, + ], + }; + + const insert = jest.fn().mockRejectedValue(error); + + await expect(insertData(trackerWith(insert))).rejects.toThrow( + "insert failed" + ); + + expect(handleFailedTransactionsMock).toHaveBeenCalledTimes(1); + }); + + it("still reports the insert error when errors is not an array", async () => { + const error: any = new Error("insert failed"); + error.errors = { nested: "not an array" }; + + const insert = jest.fn().mockRejectedValue(error); + + await expect(insertData(trackerWith(insert))).rejects.toThrow( + "insert failed" + ); + }); }); describe("transient failures", () => { diff --git a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts index 6e6d39485..b9bb06304 100644 --- a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts +++ b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts @@ -229,18 +229,39 @@ export class FirestoreBigQueryEventHistoryTracker // Without per-field detail we cannot show the retry is safe. if (!errors.length) return false; - // Every column initializeRawChangeLogTable adds to a table that already - // exists, and so every column exposed to the lag. All three must stay - // listed: dropping one from this list would turn a row that lands today - // (with that column null) into an event lost after the caller exhausts its - // retries, since nothing on the write path reconciles the schema. - const addedColumns = [ + return errors.every((error) => + isUnknownFieldError(error, this.columnsAddedToExistingTables()) + ); + } + + /** + * The columns initializeRawChangeLogTable adds to a table that already + * exists, and so every column exposed to the lag. + * + * This list must stay complete. Omitting a column turns a row that lands + * today, with that column null, into an event lost once the caller exhausts + * its retries, because nothing on the write path reconciles the schema. + */ + private columnsAddedToExistingTables(): string[] { + const columns = [ documentIdField.name, documentPathParams.name, oldDataField.name, ]; - return errors.every((error) => isUnknownFieldError(error, addedColumns)); + // addPartitioningToSchema adds the partition column to an existing table + // under the same conditions, so it has the same exposure. + const partitionColumn = this.partitioningConfig.getBigQueryColumnName(); + + if ( + partitionColumn && + (this.partitioningConfig.isFirestoreFieldPartitioning() || + this.partitioningConfig.isFirestoreTimestampPartitioning()) + ) { + columns.push(partitionColumn); + } + + return columns; } /** @@ -284,7 +305,11 @@ export class FirestoreBigQueryEventHistoryTracker private async insertData( rows: bigquery.RowMetadata[], overrideOptions: InsertRowsOptions = {}, - retry: boolean = true + // Tracked separately, so a transient blip on the first attempt cannot + // consume the retry that a schema lag on a later attempt needs. Each is + // spent at most once, bounding this layer at three attempts. + allowSchemaLagRetry: boolean = true, + allowTransientRetry: boolean = true ) { const options = { skipInvalidRows: false, @@ -300,24 +325,28 @@ export class FirestoreBigQueryEventHistoryTracker await table.insert(rows, options); logs.dataInserted(rows.length); } catch (e) { - if (retry) { - // A column we just added may not be streamable yet. Retry ignoring the - // fields BigQuery does not know about, so the rest of the row lands. - if (this.isSchemaLagInsertionError(e)) { - logs.dataInsertRetried(rows.length); - return this.insertData( - rows, - { ...overrideOptions, ignoreUnknownValues: true }, - false - ); - } + // A column we just added may not be streamable yet. Retry ignoring the + // fields BigQuery does not know about, so the rest of the row lands. + if (allowSchemaLagRetry && this.isSchemaLagInsertionError(e)) { + logs.dataInsertRetried(rows.length); + return this.insertData( + rows, + { ...overrideOptions, ignoreUnknownValues: true }, + false, + allowTransientRetry + ); + } - // Transient failures deserve a retry, but not with - // `ignoreUnknownValues`, which would silently drop real data. - if (this.isTransientInsertionError(e)) { - logs.dataInsertRetried(rows.length); - return this.insertData(rows, overrideOptions, false); - } + // Transient failures deserve a retry, but not with + // `ignoreUnknownValues`, which would silently drop real data. + if (allowTransientRetry && this.isTransientInsertionError(e)) { + logs.dataInsertRetried(rows.length); + return this.insertData( + rows, + overrideOptions, + allowSchemaLagRetry, + false + ); } // Terminal: no further attempt will be made for these rows. diff --git a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/logs.ts b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/logs.ts index db7cabccc..ac9fd7c2a 100644 --- a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/logs.ts +++ b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/logs.ts @@ -217,12 +217,18 @@ export const bigQueryTableInsertErrors = ( ) => { logger.warn(`Error when inserting data to table.`); - insertErrors?.forEach((error) => { + // Defensive throughout: this runs on the terminal path of a failed insert, + // and throwing here would replace the insert error the caller needs. + if (!Array.isArray(insertErrors)) return; + + insertErrors.forEach((error) => { logger.warn("ROW DATA JSON:"); - logger.warn(error.row); + logger.warn(error?.row); + + if (!Array.isArray(error?.errors)) return; - error.errors?.forEach((error) => - logger.warn(`ROW ERROR MESSAGE: ${error.message}`) + error.errors.forEach((error) => + logger.warn(`ROW ERROR MESSAGE: ${error?.message}`) ); }); }; From 44ed867442fac6e5a7014d5404dc4af1f555c759 Mon Sep 17 00:00:00 2001 From: Izaak Gough Date: Tue, 11 Aug 2026 14:37:17 +0100 Subject: [PATCH 06/21] fix(firestore-bigquery-export): stop allowlisting a partition column that is never added The schema-lag retry re-sends an insert with `ignoreUnknownValues: true`, which drops every field BigQuery rejected, so the allowlist that gates it must hold only columns this tracker really does add to a table that already exists. `columnsAddedToExistingTables` appended the partition column whenever Firestore-field or Firestore-timestamp partitioning was configured, but `addPartitioningToSchema` returns early without adding anything when the column name is already in the schema. The Firestore-timestamp strategy is exactly that case: its column is `timestamp`, which is always in `RawChangelogSchema`. On a table missing a `timestamp` column, the retry therefore dropped the Firestore commit timestamp of every row, and kept doing so, since `initializeRawChangeLogTable` never back-fills it. The same held for any configured name that collides with a base column. The partition column is now appended only when its name is not already a `RawChangelogSchema` field. The exclusion is deliberately scoped to that column alone: `old_data` is a base column that `initializeRawChangeLogTable` genuinely does add to pre-existing tables, so it stays allowlisted. Also pins two behaviours in `insertData` that no test previously covered, both on the ordering schema lag then transient blip: the schema-lag retry passes `allowTransientRetry` through, and the transient retry passes `overrideOptions` through. Breaking either used to leave the suite green. `columnsAddedToExistingTables` is now called once per classification rather than once per rejected field. --- .../__tests__/bigquery/insertRetry.test.ts | 84 +++++++++++++++++++ .../src/bigquery/index.ts | 21 +++-- 2 files changed, 98 insertions(+), 7 deletions(-) diff --git a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts index 56654173b..ba3580d4c 100644 --- a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts +++ b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts @@ -296,6 +296,58 @@ describe("insertData retry behaviour", () => { expect(insert).toHaveBeenCalledTimes(1); }); + + it("is not allowlisted under the Firestore timestamp strategy", async () => { + // That strategy partitions by the base `timestamp` column, which + // addPartitioningToSchema never adds because the name is already in the + // schema. Allowlisting it would drop the Firestore commit timestamp of + // every row on a table that lacks the column, permanently. + const insert = jest + .fn() + .mockRejectedValue( + partialFailure([{ message: "no such field.", location: "timestamp" }]) + ); + + await expect( + insertData( + trackerWith(insert, { + partitioning: { + granularity: "DAY", + bigqueryColumnName: "timestamp", + }, + } as Partial) + ) + ).rejects.toThrow("insert failed"); + + expect(insert).toHaveBeenCalledTimes(1); + expect(handleFailedTransactionsMock).toHaveBeenCalledTimes(1); + }); + + it("is not allowlisted when field partitioning names a base column", async () => { + // Same early return, reached by any configured name that collides with a + // base column rather than only by `timestamp`. + const insert = jest + .fn() + .mockRejectedValue( + partialFailure([{ message: "no such field.", location: "data" }]) + ); + + await expect( + insertData( + trackerWith(insert, { + partitioning: { + granularity: "DAY", + bigqueryColumnName: "data", + bigqueryColumnType: "TIMESTAMP", + firestoreFieldName: "someField", + }, + } as Partial) + ) + ).rejects.toThrow("insert failed"); + + expect(insert).toHaveBeenCalledTimes(1); + expect(handleFailedTransactionsMock).toHaveBeenCalledTimes(1); + }); }); describe("a transient blip followed by a schema lag", () => { @@ -344,6 +396,38 @@ describe("insertData retry behaviour", () => { }); }); + describe("a schema lag followed by a transient blip", () => { + it("can still retry the blip, and keeps ignoring unknown values", async () => { + // The schema-lag retry must hand the transient retry on rather than + // spend it, and it must hand `ignoreUnknownValues` on with it. Losing + // either turns the blip into a lost row or a repeat of the same + // rejection. + const insert = jest + .fn() + .mockRejectedValueOnce( + partialFailure([ + { message: "no such field.", location: "document_id" }, + ]) + ) + .mockRejectedValueOnce(transportFailure()) + .mockResolvedValueOnce(undefined); + + await expect(insertData(trackerWith(insert))).resolves.toBeUndefined(); + + expect(insert).toHaveBeenCalledTimes(3); + expect(insert.mock.calls[0][1]).toMatchObject({ + ignoreUnknownValues: false, + }); + expect(insert.mock.calls[1][1]).toMatchObject({ + ignoreUnknownValues: true, + }); + expect(insert.mock.calls[2][1]).toMatchObject({ + ignoreUnknownValues: true, + }); + expect(handleFailedTransactionsMock).not.toHaveBeenCalled(); + }); + }); + describe("malformed failures", () => { it("survives a null entry in the errors array", async () => { // Not producible by the current library, but classifying must never throw diff --git a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts index b9bb06304..457887bda 100644 --- a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts +++ b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts @@ -229,18 +229,21 @@ export class FirestoreBigQueryEventHistoryTracker // Without per-field detail we cannot show the retry is safe. if (!errors.length) return false; - return errors.every((error) => - isUnknownFieldError(error, this.columnsAddedToExistingTables()) - ); + const addedColumns = this.columnsAddedToExistingTables(); + + return errors.every((error) => isUnknownFieldError(error, addedColumns)); } /** - * The columns initializeRawChangeLogTable adds to a table that already - * exists, and so every column exposed to the lag. + * The columns this tracker adds to a table that already exists, and so every + * column exposed to the lag. * * This list must stay complete. Omitting a column turns a row that lands * today, with that column null, into an event lost once the caller exhausts * its retries, because nothing on the write path reconciles the schema. + * + * It must also stay exact. Listing a column that is never added makes the + * retry drop that column's value on a table missing it, forever. */ private columnsAddedToExistingTables(): string[] { const columns = [ @@ -250,13 +253,17 @@ export class FirestoreBigQueryEventHistoryTracker ]; // addPartitioningToSchema adds the partition column to an existing table - // under the same conditions, so it has the same exposure. + // under the same conditions, so it has the same exposure. It returns early + // when the column name is already in the schema though, and every base + // column is, so a colliding name is never actually added. The Firestore + // timestamp strategy is exactly that case: its column is `timestamp`. const partitionColumn = this.partitioningConfig.getBigQueryColumnName(); if ( partitionColumn && (this.partitioningConfig.isFirestoreFieldPartitioning() || - this.partitioningConfig.isFirestoreTimestampPartitioning()) + this.partitioningConfig.isFirestoreTimestampPartitioning()) && + !RawChangelogSchema.fields.some((field) => field.name === partitionColumn) ) { columns.push(partitionColumn); } From 8d1fce4a4babe906976a58d6483825067ff25a62 Mon Sep 17 00:00:00 2001 From: Izaak Gough Date: Tue, 11 Aug 2026 15:08:33 +0100 Subject: [PATCH 07/21] fix(firestore-bigquery-export): gate path_params on wildcardIds in the retry allowlist `columnsAddedToExistingTables` gates the schema-lag retry, which re-sends an insert with `ignoreUnknownValues: true` and so discards every column BigQuery rejected. It listed `path_params` unconditionally, but `initializeRawChangeLogTable` only adds that column, and `record` only emits the key, when `wildcardIds` is set. That divergence is reachable without wildcard ids. `transformRows` posts the rows to the user-supplied `transformFunction` endpoint and uses the response verbatim, so a transform can add a `path_params` key. BigQuery then rejects a column the table does not have, the allowlist tolerates it, and the retry drops whatever the transform put there on every insert, permanently, while `logs.dataInserted` still reports success. `path_params` is now allowlisted only when `wildcardIds` is set, and a test pins the terminal path when it is not. The comment above the partition-column guard claimed `addPartitioningToSchema` returns early because every base column is already in the schema, so a colliding name is never actually added. That is false: it is called with `metadata.schema.fields`, the live table's fields, so the early return only fires when the table already has the column, and on a table missing `timestamp` the column really is added. The replacement states the exclusion for what it is, a judgement call about a column that orders the latest view and keys the partition, and says why the same reasoning must not be extended to `old_data`, `document_id` or `path_params`. Two test comments repeated the same false claim and are corrected the same way. `logs.dataInsertRetried` said "(ignoring unknown columns)" on both retry paths, but the transient path passes options through unchanged and does not ignore anything, so an operator investigating suspected column loss could not tell the two apart. It is split into `dataInsertRetriedIgnoringUnknownColumns` and `dataInsertRetriedAfterTransientError`, both still at debug with the row count. --- .../__tests__/bigquery/insertRetry.test.ts | 102 +++++++++++++++--- .../src/bigquery/index.ts | 41 ++++--- .../src/logs.ts | 15 ++- 3 files changed, 131 insertions(+), 27 deletions(-) diff --git a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts index ba3580d4c..75518377c 100644 --- a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts +++ b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts @@ -17,6 +17,7 @@ import { FirestoreBigQueryEventHistoryTracker } from "../../bigquery"; import { ChangeTrackerConfig } from "../../bigquery/types"; import handleFailedTransactions from "../../bigquery/handleFailedTransactions"; +import { logger } from "../../logger"; jest.mock("../../bigquery/handleFailedTransactions", () => ({ __esModule: true, @@ -135,7 +136,9 @@ describe("insertData retry behaviour", () => { ) .mockResolvedValueOnce(undefined); - await expect(insertData(trackerWith(insert))).resolves.toBeUndefined(); + await expect( + insertData(trackerWith(insert, { wildcardIds: true })) + ).resolves.toBeUndefined(); expect(insert).toHaveBeenCalledTimes(2); expect(insert.mock.calls[1][1]).toMatchObject({ @@ -148,7 +151,7 @@ describe("insertData retry behaviour", () => { { message: "no such field.", location: "path_params" }, ]); const insert = jest.fn().mockRejectedValue(error); - const tracker = trackerWith(insert); + const tracker = trackerWith(insert, { wildcardIds: true }); // Must start true, or asserting false below passes against an // implementation that never clears the flag at all. @@ -177,9 +180,18 @@ describe("insertData retry behaviour", () => { expect(insert).toHaveBeenCalledTimes(1); }); - it.each(["document_id", "path_params", "old_data"])( + // `path_params` needs its own config: `initializeRawChangeLogTable` only + // adds that column, and `record` only emits the key, when wildcard ids are + // enabled. + const addedColumns: Array<[string, Partial]> = [ + ["document_id", {}], + ["old_data", {}], + ["path_params", { wildcardIds: true }], + ]; + + it.each(addedColumns)( "covers %s, every column added to an existing table", - async (column) => { + async (column, overrides) => { // Dropping any of these from the allowlist would turn a row that lands // today, with that column null, into an event lost once the caller // exhausts its retries. @@ -190,7 +202,9 @@ describe("insertData retry behaviour", () => { ) .mockResolvedValueOnce(undefined); - await expect(insertData(trackerWith(insert))).resolves.toBeUndefined(); + await expect( + insertData(trackerWith(insert, overrides)) + ).resolves.toBeUndefined(); expect(insert).toHaveBeenCalledTimes(2); expect(insert.mock.calls[1][1]).toMatchObject({ @@ -198,6 +212,29 @@ describe("insertData retry behaviour", () => { }); } ); + + it("does not allowlist path_params when wildcard ids are disabled", async () => { + // Without wildcard ids the column is never created, so a rejected + // `path_params` is not our schema lag. `transformRows` hands the response + // of a user-supplied endpoint straight to the insert, so a transform can + // inject the key: allowlisting it there would discard whatever the + // transform put in it on every insert, forever, while still logging + // success. + const insert = jest + .fn() + .mockRejectedValue( + partialFailure([ + { message: "no such field.", location: "path_params" }, + ]) + ); + + await expect(insertData(trackerWith(insert))).rejects.toThrow( + "insert failed" + ); + + expect(insert).toHaveBeenCalledTimes(1); + expect(handleFailedTransactionsMock).toHaveBeenCalledTimes(1); + }); }); describe("schema drift we did not add", () => { @@ -251,7 +288,7 @@ describe("insertData retry behaviour", () => { describe("the user-configured partition column", () => { // addPartitioningToSchema adds this column to an existing table too, so it - // has the same exposure as the other three. + // has the same exposure as the base columns above. const partitioned = { partitioning: { granularity: "HOUR", @@ -298,10 +335,11 @@ describe("insertData retry behaviour", () => { }); it("is not allowlisted under the Firestore timestamp strategy", async () => { - // That strategy partitions by the base `timestamp` column, which - // addPartitioningToSchema never adds because the name is already in the - // schema. Allowlisting it would drop the Firestore commit timestamp of - // every row on a table that lacks the column, permanently. + // That strategy partitions by the base `timestamp` column. On a table + // that lacks it the column really is added, so this is a deliberate + // choice rather than dead code: `timestamp` orders the latest view and + // keys the partition, so allowlisting it would silently misfile every + // affected row for good, where failing writes a backup row and throws. const insert = jest .fn() .mockRejectedValue( @@ -324,8 +362,8 @@ describe("insertData retry behaviour", () => { }); it("is not allowlisted when field partitioning names a base column", async () => { - // Same early return, reached by any configured name that collides with a - // base column rather than only by `timestamp`. + // The exclusion is keyed on the collision, not on `timestamp`, so any + // configured name that matches a base column reaches it. const insert = jest .fn() .mockRejectedValue( @@ -571,4 +609,44 @@ describe("insertData retry behaviour", () => { ); }); }); + + describe("retry logging", () => { + let debug: jest.SpyInstance; + + beforeEach(() => { + debug = jest.spyOn(logger, "debug").mockImplementation(() => undefined); + }); + + afterEach(() => { + debug.mockRestore(); + }); + + it("distinguishes the retry that drops columns from the one that does not", async () => { + // Only the schema-lag retry discards unknown columns. An operator + // investigating suspected column loss has nothing else to tell the two + // retries apart, so one message must not stand for both. + const insert = jest + .fn() + .mockRejectedValueOnce( + partialFailure([ + { message: "no such field.", location: "document_id" }, + ]) + ) + .mockRejectedValueOnce(transportFailure()) + .mockResolvedValueOnce(undefined); + + await expect(insertData(trackerWith(insert))).resolves.toBeUndefined(); + + const messages = debug.mock.calls.map(([message]) => String(message)); + const dropped = messages.filter((message) => + message.includes("ignoring unknown columns") + ); + + expect(dropped).toHaveLength(1); + expect(dropped[0]).toContain(`${ROWS.length} row(s)`); + expect( + messages.filter((message) => message.includes("transient")) + ).toHaveLength(1); + }); + }); }); diff --git a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts index 457887bda..e868b275d 100644 --- a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts +++ b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts @@ -246,17 +246,32 @@ export class FirestoreBigQueryEventHistoryTracker * retry drop that column's value on a table missing it, forever. */ private columnsAddedToExistingTables(): string[] { - const columns = [ - documentIdField.name, - documentPathParams.name, - oldDataField.name, - ]; - - // addPartitioningToSchema adds the partition column to an existing table - // under the same conditions, so it has the same exposure. It returns early - // when the column name is already in the schema though, and every base - // column is, so a colliding name is never actually added. The Firestore - // timestamp strategy is exactly that case: its column is `timestamp`. + const columns = [documentIdField.name, oldDataField.name]; + + // `path_params` is only ever added, and only ever emitted by `record`, when + // wildcard ids are enabled. Listing it unconditionally meant a transform + // function, whose response `transformRows` uses verbatim, could inject the + // key into a table that has no such column and have it discarded on every + // insert, for good. + if (this.config.wildcardIds) { + columns.push(documentPathParams.name); + } + + // The partition column is also added to an existing table, so it shares the + // same exposure. It is deliberately excluded when its name collides with a + // base changelog column, which in practice means the Firestore timestamp + // strategy, whose column is `timestamp`. + // + // That exclusion is a judgement call, not dead code: `addPartitioningToSchema` + // is called with the live table's fields, so its early return only fires + // when the table already has the column. On a table missing `timestamp` the + // column really is added, so the lag is reachable. But `timestamp` is + // NULLABLE and is the ordering key for the latest view as well as the + // partition key, so tolerating the drop would silently misfile every + // affected row for good. Failing instead writes a backup row and throws, + // which the caller can retry. That reasoning does not extend to `old_data`, + // `document_id` or `path_params`: those are nullable metadata, where a + // dropped column costs one field and allowlisting keeps the event. const partitionColumn = this.partitioningConfig.getBigQueryColumnName(); if ( @@ -335,7 +350,7 @@ export class FirestoreBigQueryEventHistoryTracker // A column we just added may not be streamable yet. Retry ignoring the // fields BigQuery does not know about, so the rest of the row lands. if (allowSchemaLagRetry && this.isSchemaLagInsertionError(e)) { - logs.dataInsertRetried(rows.length); + logs.dataInsertRetriedIgnoringUnknownColumns(rows.length); return this.insertData( rows, { ...overrideOptions, ignoreUnknownValues: true }, @@ -347,7 +362,7 @@ export class FirestoreBigQueryEventHistoryTracker // Transient failures deserve a retry, but not with // `ignoreUnknownValues`, which would silently drop real data. if (allowTransientRetry && this.isTransientInsertionError(e)) { - logs.dataInsertRetried(rows.length); + logs.dataInsertRetriedAfterTransientError(rows.length); return this.insertData( rows, overrideOptions, diff --git a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/logs.ts b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/logs.ts index ac9fd7c2a..54c877d56 100644 --- a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/logs.ts +++ b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/logs.ts @@ -137,9 +137,20 @@ export const dataInserted = (rowCount: number) => { logger.debug(`Inserted ${rowCount} row(s) of data into BigQuery`); }; -export const dataInsertRetried = (rowCount: number) => { +/** + * The two retry paths must be distinguishable in the logs: only one of them + * discards columns, and an operator investigating suspected column loss has no + * other way to tell which retry ran. + */ +export const dataInsertRetriedIgnoringUnknownColumns = (rowCount: number) => { + logger.debug( + `Retrying insert of ${rowCount} row(s) of data into BigQuery, ignoring unknown columns` + ); +}; + +export const dataInsertRetriedAfterTransientError = (rowCount: number) => { logger.debug( - `Retried to insert ${rowCount} row(s) of data into BigQuery (ignoring unknown columns)` + `Retrying insert of ${rowCount} row(s) of data into BigQuery after a transient failure, with options unchanged` ); }; From 2583e3e6479c148dfdcc921a52cab338d76a7edb Mon Sep 17 00:00:00 2001 From: Izaak Gough Date: Wed, 12 Aug 2026 11:36:19 +0100 Subject: [PATCH 08/21] fix(firestore-bigquery-export): retry partial failures BigQuery says to retry `isTransientInsertionError` treated the presence of `response.insertErrors` as proof that a plain retry could not help, on the reasoning that a partial failure is BigQuery rejecting the shape of the data. That is only true of `invalid`. `backendError`, `internalError`, `rateLimitExceeded` and `timeout` also arrive as `insertErrors` entries, and those are exactly the failures a plain retry fixes, so a batch BigQuery asked us to resend went straight to the backup collection and threw. Classification now reads `reason`, which `InsertAllError` already carried and nothing used. A partial failure is transient only when every entry names a reason BigQuery documents as retryable, so an unclassifiable entry still fails closed. `stopped` is on that list because it marks a row skipped after another row in the same request failed, and never appears on its own. The schema-lag check still runs first, so an unknown-field entry never reaches this path. The retry that discards columns now warns instead of logging at debug. It is the one path that leaves a column permanently null for the rows it recovers, and `logger` defaults to INFO, so the only record of that loss was suppressed unless an operator had already gone looking for it. The transient retry stays at debug: it changes nothing about the data. The partition-column guard no longer tests `isFirestoreTimestampPartitioning`. `determineType` only returns that type when the configured column is `timestamp`, which is always in `RawChangelogSchema.fields`, so the collision check below it rejected the column every time and the disjunct could not contribute. Reading it as live code cost a reviewer a trip through `partitioning/config.ts` to work out that it was not. The comment states the exclusion directly instead, and keeps the collision check, which a field strategy pointed at `data` still reaches. Also corrects that comment's claim that `timestamp` is NULLABLE. It is REQUIRED in `RawChangelogSchema`; NULLABLE is true of the column `getNewPartitionField` adds, which is the case the comment is about. The `partialFailure` test helper now takes a `reason` and defaults it to `invalid` as BigQuery would, so the existing cases keep classifying as they did. Four tests added: a retryable partial failure retries with options unchanged, a mixed batch and an unclassifiable entry stay terminal, and the drop-columns message lands on `warn` rather than `debug`. --- .../__tests__/bigquery/insertRetry.test.ts | 104 ++++++++++++++++-- .../src/bigquery/index.ts | 56 +++++++--- .../src/logs.ts | 8 +- 3 files changed, 143 insertions(+), 25 deletions(-) diff --git a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts index 75518377c..8bdf80648 100644 --- a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts +++ b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts @@ -50,22 +50,26 @@ const config = ( * that drops `location`. */ function partialFailure( - fieldErrors: Array<{ message: string; location?: string }> + fieldErrors: Array<{ message: string; location?: string; reason?: string }> ) { + // BigQuery always sets a reason on these entries, so default it rather than + // leaving it undefined: classification reads it. + const entries = fieldErrors.map((fieldError) => ({ + reason: "invalid", + ...fieldError, + })); + const e: any = new Error("insert failed"); e.name = "PartialFailureError"; e.errors = [ { row: {}, - errors: fieldErrors.map(({ message }) => ({ - message, - reason: "invalid", - })), + errors: entries.map(({ message, reason }) => ({ message, reason })), }, ]; e.response = { kind: "bigquery#tableDataInsertAllResponse", - insertErrors: [{ index: 0, errors: fieldErrors }], + insertErrors: [{ index: 0, errors: entries }], }; return e; } @@ -525,6 +529,61 @@ describe("insertData retry behaviour", () => { }); describe("transient failures", () => { + it("retries a partial failure whose reasons are all retryable", async () => { + // A rate limit or backend error arrives as a partial failure, not as a + // bare transport error. Classifying it as terminal would send a batch + // BigQuery asked us to resend straight to the backup collection. + const insert = jest + .fn() + .mockRejectedValueOnce( + partialFailure([ + { message: "Backend error.", reason: "backendError" }, + { message: "Row skipped.", reason: "stopped" }, + ]) + ) + .mockResolvedValueOnce(undefined); + + await expect(insertData(trackerWith(insert))).resolves.toBeUndefined(); + + expect(insert).toHaveBeenCalledTimes(2); + // Never with ignoreUnknownValues: nothing here says a column is unknown. + expect(insert.mock.calls[1][1]).toMatchObject({ + ignoreUnknownValues: false, + }); + expect(handleFailedTransactionsMock).not.toHaveBeenCalled(); + }); + + it("does not retry when any reason is not retryable", async () => { + const insert = jest.fn().mockRejectedValue( + partialFailure([ + { message: "Backend error.", reason: "backendError" }, + { message: "Cannot convert value.", reason: "invalid" }, + ]) + ); + + await expect(insertData(trackerWith(insert))).rejects.toThrow( + "insert failed" + ); + + expect(insert).toHaveBeenCalledTimes(1); + expect(handleFailedTransactionsMock).toHaveBeenCalledTimes(1); + }); + + it("does not retry a partial failure with no reason to judge", async () => { + // Fail closed: an entry we cannot classify is not evidence of a blip. + const insert = jest + .fn() + .mockRejectedValue( + partialFailure([{ message: "", reason: undefined }]) + ); + + await expect(insertData(trackerWith(insert))).rejects.toThrow( + "insert failed" + ); + + expect(insert).toHaveBeenCalledTimes(1); + }); + it("retries once with options unchanged", async () => { const insert = jest .fn() @@ -612,13 +671,42 @@ describe("insertData retry behaviour", () => { describe("retry logging", () => { let debug: jest.SpyInstance; + let warn: jest.SpyInstance; beforeEach(() => { debug = jest.spyOn(logger, "debug").mockImplementation(() => undefined); + warn = jest.spyOn(logger, "warn").mockImplementation(() => undefined); }); afterEach(() => { debug.mockRestore(); + warn.mockRestore(); + }); + + it("warns rather than debugs when a retry drops columns", async () => { + // Debug is suppressed at the default log level, so an operator would + // have to already suspect the loss to see the only record of it. + const insert = jest + .fn() + .mockRejectedValueOnce( + partialFailure([ + { message: "no such field.", location: "document_id" }, + ]) + ) + .mockResolvedValueOnce(undefined); + + await expect(insertData(trackerWith(insert))).resolves.toBeUndefined(); + + expect( + warn.mock.calls.filter(([message]) => + String(message).includes("ignoring unknown columns") + ) + ).toHaveLength(1); + expect( + debug.mock.calls.filter(([message]) => + String(message).includes("ignoring unknown columns") + ) + ).toHaveLength(0); }); it("distinguishes the retry that drops columns from the one that does not", async () => { @@ -637,7 +725,9 @@ describe("insertData retry behaviour", () => { await expect(insertData(trackerWith(insert))).resolves.toBeUndefined(); - const messages = debug.mock.calls.map(([message]) => String(message)); + const messages = [...debug.mock.calls, ...warn.mock.calls].map( + ([message]) => String(message) + ); const dropped = messages.filter((message) => message.includes("ignoring unknown columns") ); diff --git a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts index e868b275d..14ad8c226 100644 --- a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts +++ b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts @@ -54,6 +54,21 @@ interface InsertAllError { reason?: string; } +/** + * The `insertAll` error reasons BigQuery documents as worth retrying. + * + * `stopped` means the row was not inserted because another row in the same + * request failed, so it never appears on its own. The reason that does appear + * alongside it decides whether the request is retryable. + */ +const RETRYABLE_INSERT_REASONS = [ + "backendError", + "internalError", + "rateLimitExceeded", + "timeout", + "stopped", +]; + /** * Flattens the per-field errors out of a BigQuery insert failure. * @@ -258,26 +273,26 @@ export class FirestoreBigQueryEventHistoryTracker } // The partition column is also added to an existing table, so it shares the - // same exposure. It is deliberately excluded when its name collides with a - // base changelog column, which in practice means the Firestore timestamp - // strategy, whose column is `timestamp`. + // same exposure. Only the Firestore field strategy is listed. The Firestore + // timestamp strategy is excluded by construction, since its column is + // always `timestamp`, which the collision check below would reject anyway. // - // That exclusion is a judgement call, not dead code: `addPartitioningToSchema` + // Both exclusions are a judgement call, not dead code: `addPartitioningToSchema` // is called with the live table's fields, so its early return only fires // when the table already has the column. On a table missing `timestamp` the - // column really is added, so the lag is reachable. But `timestamp` is - // NULLABLE and is the ordering key for the latest view as well as the - // partition key, so tolerating the drop would silently misfile every - // affected row for good. Failing instead writes a backup row and throws, - // which the caller can retry. That reasoning does not extend to `old_data`, - // `document_id` or `path_params`: those are nullable metadata, where a - // dropped column costs one field and allowlisting keeps the event. + // column really is added, as NULLABLE. But `timestamp` is the ordering key + // for the latest view as well as the partition key, so tolerating the drop + // would silently misfile every affected row for good. Failing instead + // writes a backup row and throws, which the caller can retry. The same goes + // for a field strategy pointed at any other base column, `data` say. That + // reasoning does not extend to `old_data`, `document_id` or `path_params`: + // those are nullable metadata, where a dropped column costs one field and + // allowlisting keeps the event. const partitionColumn = this.partitioningConfig.getBigQueryColumnName(); if ( partitionColumn && - (this.partitioningConfig.isFirestoreFieldPartitioning() || - this.partitioningConfig.isFirestoreTimestampPartitioning()) && + this.partitioningConfig.isFirestoreFieldPartitioning() && !RawChangelogSchema.fields.some((field) => field.name === partitionColumn) ) { columns.push(partitionColumn); @@ -292,11 +307,20 @@ export class FirestoreBigQueryEventHistoryTracker * * A failure with no partial-failure body (a network blip, a quota rejection, * a 5xx) says nothing about our schema, so retrying it as-is is safe. - * A partial failure we did not recognise is BigQuery rejecting the - * shape of the data itself, which a plain retry cannot fix. + * + * A partial failure qualifies only when every entry names a reason BigQuery + * documents as retryable. Anything else is BigQuery rejecting the shape of + * the data itself, which a plain retry cannot fix. The schema-lag check runs + * first, so an unknown-field entry never reaches here. */ private isTransientInsertionError(e: any): boolean { - return extractInsertErrors(e).length === 0; + const errors = extractInsertErrors(e); + + if (!errors.length) return true; + + return errors.every((error) => + RETRYABLE_INSERT_REASONS.includes(error?.reason) + ); } /** diff --git a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/logs.ts b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/logs.ts index 54c877d56..055d7d281 100644 --- a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/logs.ts +++ b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/logs.ts @@ -141,10 +141,14 @@ export const dataInserted = (rowCount: number) => { * The two retry paths must be distinguishable in the logs: only one of them * discards columns, and an operator investigating suspected column loss has no * other way to tell which retry ran. + * + * Warn rather than debug: this is the one path that leaves a column permanently + * null for the rows it recovers, and debug is suppressed at the default log + * level, so an operator would have had to already suspect the loss to see it. */ export const dataInsertRetriedIgnoringUnknownColumns = (rowCount: number) => { - logger.debug( - `Retrying insert of ${rowCount} row(s) of data into BigQuery, ignoring unknown columns` + logger.warn( + `Retrying insert of ${rowCount} row(s) of data into BigQuery, ignoring unknown columns. Any column BigQuery rejected will be null for these rows.` ); }; From a04cae6b376ae0534f39a99ec79d92a2aaae688a Mon Sep 17 00:00:00 2001 From: Izaak Gough Date: Wed, 12 Aug 2026 15:57:20 +0100 Subject: [PATCH 09/21] fix(firestore-bigquery-export): drop only the columns BigQuery named A live instance reports one unknown field per row, not all of them, so the schema-lag retry's `ignoreUnknownValues` also discarded fields BigQuery never mentioned, including real drift. It now removes just the columns named and leaves the option off, so any other unknown column still fails the insert and reaches the backup. Each retry must remove a column not removed before, which bounds the recursion. Also fixes the backup write, which called `settings()` on the Firestore singleton on every failure and so threw on all but the first, leaving one event per instance backed up. Surfaced by the try/catch added earlier, which reported it rather than masking the insert error. --- .../__tests__/bigquery/backupSettings.test.ts | 99 ++++++++++ .../__tests__/bigquery/insertRetry.test.ts | 169 ++++++++++++++---- .../src/bigquery/handleFailedTransactions.ts | 33 +++- .../src/bigquery/index.ts | 116 ++++++++---- .../src/logs.ts | 13 +- 5 files changed, 347 insertions(+), 83 deletions(-) create mode 100644 firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/backupSettings.test.ts diff --git a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/backupSettings.test.ts b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/backupSettings.test.ts new file mode 100644 index 000000000..c77ab62e4 --- /dev/null +++ b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/backupSettings.test.ts @@ -0,0 +1,99 @@ +/** + * Copyright 2026 Google LLC + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * https://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +import { ChangeTrackerConfig } from "../../bigquery/types"; + +const commit = jest.fn(); +const set = jest.fn(); +const settings = jest.fn(); + +const batch = jest.fn(() => ({ set, commit })); +const collection = jest.fn(() => ({ doc: (id: string) => ({ id }) })); + +jest.mock("firebase-admin", () => ({ apps: [{}] })); +jest.mock("firebase-admin/app", () => ({ initializeApp: jest.fn() })); +jest.mock("firebase-admin/firestore", () => ({ + // One instance per database id, as the real `getFirestore` returns. + getFirestore: jest.fn(() => ({ settings, batch, collection })), +})); + +const config = { + backupTableId: "bq_failures", + firestoreInstanceId: "(default)", +} as ChangeTrackerConfig; + +const ROWS = [{ insertId: "e1", json: { event_id: "e1" } }]; + +/** Fresh module, so the module-level "already configured" set starts empty. */ +const loadHandler = () => { + let handler: any; + jest.isolateModules(() => { + handler = require("../../bigquery/handleFailedTransactions").default; + }); + return handler; +}; + +describe("handleFailedTransactions Firestore settings", () => { + beforeEach(() => { + jest.clearAllMocks(); + commit.mockResolvedValue(undefined); + settings.mockImplementation(() => undefined); + }); + + it("applies settings once across repeated failures", async () => { + // `settings()` may only be called once per instance, and only before the + // instance is used. Calling it on every batch threw on every call after the + // first, so only one failure per function instance was ever backed up. + const handler = loadHandler(); + + await handler(ROWS, config, new Error("insert failed")); + await handler(ROWS, config, new Error("insert failed")); + + expect(settings).toHaveBeenCalledTimes(1); + expect(commit).toHaveBeenCalledTimes(2); + }); + + it("still writes the backup when settings cannot be applied", async () => { + // Another part of the process may have reached the instance first. That + // costs `ignoreUndefinedProperties`, not the backup itself. + settings.mockImplementation(() => { + throw new Error("Firestore has already been initialized"); + }); + + const handler = loadHandler(); + + await expect( + handler(ROWS, config, new Error("insert failed")) + ).resolves.toBeUndefined(); + + expect(commit).toHaveBeenCalledTimes(1); + }); + + it("writes one document per row, keyed by insertId", async () => { + const handler = loadHandler(); + + await handler( + [{ insertId: "a" }, { insertId: "b" }], + config, + new Error("boom") + ); + + expect(collection).toHaveBeenCalledWith("bq_failures"); + expect(set).toHaveBeenCalledTimes(2); + expect(set.mock.calls[0][0]).toMatchObject({ id: "a" }); + expect(set.mock.calls[0][1]).toMatchObject({ error_details: "boom" }); + }); +}); diff --git a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts index 8bdf80648..419742da9 100644 --- a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts +++ b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts @@ -81,7 +81,28 @@ function transportFailure() { return e; } -const ROWS = [{ insertId: "e1", json: { event_id: "e1" } }]; +/** + * Deliberately carries every column the allowlist can name, so that asserting a + * column was removed from a retry is a real assertion rather than one that + * passes because the key was never there. + */ +const ROWS = [ + { + insertId: "e1", + json: { + event_id: "e1", + data: "{}", + document_id: "d1", + old_data: null, + path_params: "{}", + created_at: "2026-01-01 00:00:00", + }, + }, +]; + +/** The payload of the row passed to the nth `insert` call, 0-indexed. */ +const payloadOf = (insert: jest.Mock, call: number) => + insert.mock.calls[call][0][0].json; /** * Returns a tracker whose inserts are served by `insert`, so no BigQuery @@ -110,7 +131,7 @@ describe("insertData retry behaviour", () => { }); describe("a column we just added is not streamable yet", () => { - it("retries once ignoring unknown values, and succeeds", async () => { + it("retries once without the rejected column, and succeeds", async () => { const insert = jest .fn() .mockRejectedValueOnce( @@ -123,11 +144,17 @@ describe("insertData retry behaviour", () => { await expect(insertData(trackerWith(insert))).resolves.toBeUndefined(); expect(insert).toHaveBeenCalledTimes(2); - expect(insert.mock.calls[0][1]).toMatchObject({ - ignoreUnknownValues: false, + expect(payloadOf(insert, 0)).toHaveProperty("document_id"); + expect(payloadOf(insert, 1)).not.toHaveProperty("document_id"); + // Everything else must survive: only what BigQuery named is dropped. + expect(payloadOf(insert, 1)).toMatchObject({ + event_id: "e1", + data: "{}", }); + // Never ignoreUnknownValues, which would also discard fields BigQuery did + // not name. expect(insert.mock.calls[1][1]).toMatchObject({ - ignoreUnknownValues: true, + ignoreUnknownValues: false, }); expect(handleFailedTransactionsMock).not.toHaveBeenCalled(); }); @@ -145,9 +172,76 @@ describe("insertData retry behaviour", () => { ).resolves.toBeUndefined(); expect(insert).toHaveBeenCalledTimes(2); - expect(insert.mock.calls[1][1]).toMatchObject({ - ignoreUnknownValues: true, - }); + expect(payloadOf(insert, 1)).not.toHaveProperty("path_params"); + }); + + it("does not ignore an unknown field BigQuery did not name", async () => { + // A live instance reports one unknown field per row, not all of them. So + // a table missing `document_id` while a transform has injected a stray + // key surfaces as a rejection naming only `document_id`. Retrying with + // ignoreUnknownValues would have discarded the stray key too, silently, + // which is the loss this whole change exists to prevent. + const insert = jest + .fn() + .mockRejectedValueOnce( + partialFailure([ + { message: "no such field.", location: "document_id" }, + ]) + ) + .mockRejectedValueOnce( + partialFailure([{ message: "no such field.", location: "injected" }]) + ); + + await expect(insertData(trackerWith(insert))).rejects.toThrow( + "insert failed" + ); + + expect(insert).toHaveBeenCalledTimes(2); + expect(payloadOf(insert, 1)).not.toHaveProperty("document_id"); + // Terminal, so the row reaches the backup with the stray key intact + // rather than being dropped and reported as a success. + expect(handleFailedTransactionsMock).toHaveBeenCalledTimes(1); + }); + + it("strips one column per retry when BigQuery names them one at a time", async () => { + const insert = jest + .fn() + .mockRejectedValueOnce( + partialFailure([{ message: "no such field.", location: "old_data" }]) + ) + .mockRejectedValueOnce( + partialFailure([ + { message: "no such field.", location: "document_id" }, + ]) + ) + .mockResolvedValueOnce(undefined); + + await expect(insertData(trackerWith(insert))).resolves.toBeUndefined(); + + expect(insert).toHaveBeenCalledTimes(3); + expect(payloadOf(insert, 1)).not.toHaveProperty("old_data"); + expect(payloadOf(insert, 2)).not.toHaveProperty("old_data"); + expect(payloadOf(insert, 2)).not.toHaveProperty("document_id"); + expect(handleFailedTransactionsMock).not.toHaveBeenCalled(); + }); + + it("gives up when a retry makes no progress", async () => { + // The same column rejected twice means removing it did not help, so there + // is nothing further to try. Without this the recursion never ends. + const insert = jest + .fn() + .mockRejectedValue( + partialFailure([ + { message: "no such field.", location: "document_id" }, + ]) + ); + + await expect(insertData(trackerWith(insert))).rejects.toThrow( + "insert failed" + ); + + expect(insert).toHaveBeenCalledTimes(2); + expect(handleFailedTransactionsMock).toHaveBeenCalledTimes(1); }); it("backs up and throws when the retry also fails", async () => { @@ -211,9 +305,7 @@ describe("insertData retry behaviour", () => { ).resolves.toBeUndefined(); expect(insert).toHaveBeenCalledTimes(2); - expect(insert.mock.calls[1][1]).toMatchObject({ - ignoreUnknownValues: true, - }); + expect(payloadOf(insert, 1)).not.toHaveProperty(column); } ); @@ -317,9 +409,7 @@ describe("insertData retry behaviour", () => { ).resolves.toBeUndefined(); expect(insert).toHaveBeenCalledTimes(2); - expect(insert.mock.calls[1][1]).toMatchObject({ - ignoreUnknownValues: true, - }); + expect(payloadOf(insert, 1)).not.toHaveProperty("created_at"); }); it("is not allowlisted when no partitioning is configured", async () => { @@ -409,16 +499,12 @@ describe("insertData retry behaviour", () => { await expect(insertData(trackerWith(insert))).resolves.toBeUndefined(); expect(insert).toHaveBeenCalledTimes(3); - expect(insert.mock.calls[1][1]).toMatchObject({ - ignoreUnknownValues: false, - }); - expect(insert.mock.calls[2][1]).toMatchObject({ - ignoreUnknownValues: true, - }); + expect(payloadOf(insert, 1)).toHaveProperty("document_id"); + expect(payloadOf(insert, 2)).not.toHaveProperty("document_id"); expect(handleFailedTransactionsMock).not.toHaveBeenCalled(); }); - it("spends each retry at most once, bounding attempts at three", async () => { + it("spends the transient retry at most once", async () => { const insert = jest .fn() .mockRejectedValueOnce(transportFailure()) @@ -439,11 +525,10 @@ describe("insertData retry behaviour", () => { }); describe("a schema lag followed by a transient blip", () => { - it("can still retry the blip, and keeps ignoring unknown values", async () => { + it("can still retry the blip, and keeps the column stripped", async () => { // The schema-lag retry must hand the transient retry on rather than - // spend it, and it must hand `ignoreUnknownValues` on with it. Losing - // either turns the blip into a lost row or a repeat of the same - // rejection. + // spend it, and the rows it hands on must stay stripped. Losing either + // turns the blip into a lost row or a repeat of the same rejection. const insert = jest .fn() .mockRejectedValueOnce( @@ -457,15 +542,9 @@ describe("insertData retry behaviour", () => { await expect(insertData(trackerWith(insert))).resolves.toBeUndefined(); expect(insert).toHaveBeenCalledTimes(3); - expect(insert.mock.calls[0][1]).toMatchObject({ - ignoreUnknownValues: false, - }); - expect(insert.mock.calls[1][1]).toMatchObject({ - ignoreUnknownValues: true, - }); - expect(insert.mock.calls[2][1]).toMatchObject({ - ignoreUnknownValues: true, - }); + expect(payloadOf(insert, 0)).toHaveProperty("document_id"); + expect(payloadOf(insert, 1)).not.toHaveProperty("document_id"); + expect(payloadOf(insert, 2)).not.toHaveProperty("document_id"); expect(handleFailedTransactionsMock).not.toHaveBeenCalled(); }); }); @@ -699,16 +778,32 @@ describe("insertData retry behaviour", () => { expect( warn.mock.calls.filter(([message]) => - String(message).includes("ignoring unknown columns") + String(message).includes("without document_id") ) ).toHaveLength(1); expect( debug.mock.calls.filter(([message]) => - String(message).includes("ignoring unknown columns") + String(message).includes("without document_id") ) ).toHaveLength(0); }); + it("names the columns it dropped", async () => { + // "a column was dropped" is not actionable. Which one is. + const insert = jest + .fn() + .mockRejectedValueOnce( + partialFailure([{ message: "no such field.", location: "old_data" }]) + ) + .mockResolvedValueOnce(undefined); + + await expect(insertData(trackerWith(insert))).resolves.toBeUndefined(); + + const messages = warn.mock.calls.map(([message]) => String(message)); + + expect(messages.some((m) => m.includes("without old_data"))).toBe(true); + }); + it("distinguishes the retry that drops columns from the one that does not", async () => { // Only the schema-lag retry discards unknown columns. An operator // investigating suspected column loss has nothing else to tell the two @@ -729,7 +824,7 @@ describe("insertData retry behaviour", () => { ([message]) => String(message) ); const dropped = messages.filter((message) => - message.includes("ignoring unknown columns") + message.includes("without document_id") ); expect(dropped).toHaveLength(1); diff --git a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/handleFailedTransactions.ts b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/handleFailedTransactions.ts index 4addaeec9..a67ebaea9 100644 --- a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/handleFailedTransactions.ts +++ b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/handleFailedTransactions.ts @@ -7,15 +7,40 @@ if (!admin.apps.length) { initializeApp(); } +/** + * Firestore instances whose `settings()` call has already been attempted. + * + * `getFirestore` returns one instance per database id, and `settings()` may only + * be called once on it, before it is used. Calling it on every failed batch + * therefore threw on every call after the first, so only the first failure in an + * instance's lifetime was ever backed up. + */ +const settingsApplied = new Set(); + +function backupFirestore(instanceId: string) { + const db = getFirestore(instanceId); + + if (!settingsApplied.has(instanceId)) { + settingsApplied.add(instanceId); + + try { + db.settings({ ignoreUndefinedProperties: true }); + } catch (settingsError) { + // Something else in the process reached this instance first. The backup + // still goes ahead, but an undefined value in a row will now throw from + // `set()` instead of being skipped. + } + } + + return db; +} + export default async ( rows: any[], config: ChangeTrackerConfig, e: Error ): Promise => { - const db = getFirestore(config.firestoreInstanceId!); - db.settings({ - ignoreUndefinedProperties: true, - }); + const db = backupFirestore(config.firestoreInstanceId!); const batchArray = [db.batch()]; let operationCounter = 0; diff --git a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts index 14ad8c226..461660876 100644 --- a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts +++ b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts @@ -91,32 +91,54 @@ function extractInsertErrors(e: any): InsertAllError[] { } /** - * Whether an error entry reports an unknown field naming one of `columns`. + * The column an error entry reports as unknown, if it names one of `columns`. + * Null for anything else, so that an entry we cannot attribute fails loudly + * rather than causing data to be dropped. * - * BigQuery has reported this two ways: a bare `"no such field."` with the - * column in `location`, and an inlined `"no such field: document_id."`. Match - * either, and treat an unattributable message as not matching so that we fail - * loudly rather than dropping data. + * A live instance sends both forms at once: `location` set to the column, and + * an inlined `"no such field: document_id."`. Older responses carried only the + * bare `"no such field."` with `location`, so both are handled. */ -function isUnknownFieldError( +function unknownFieldColumn( error: InsertAllError, columns: string[] -): boolean { +): string | null { // Defensive to match extractInsertErrors: a null entry must classify as not // matching, not throw from inside the catch block and lose the real error. const message = error?.message ?? ""; - if (!/^no such field/i.test(message)) return false; + if (!/^no such field/i.test(message)) return null; // The bare form names the column in `location`. - if (error.location) return columns.includes(error.location); + if (error.location) { + return columns.includes(error.location) ? error.location : null; + } // The inlined form carries the column in the message. Compare the whole name: // a substring test would match a user column such as `document_id_v2` and // silently drop it. const named = message.match(/^no such field:\s*(.+?)\.?$/i); - return named ? columns.includes(named[1]) : false; + return named && columns.includes(named[1]) ? named[1] : null; +} + +/** + * Copies `rows` with `columns` removed from each payload. + * + * Rows are inserted with `raw: true`, so the payload is under `json`. + */ +function withoutColumns( + rows: bigquery.RowMetadata[], + columns: string[] +): bigquery.RowMetadata[] { + return rows.map((row) => { + if (!row?.json) return row; + + const json = { ...row.json }; + columns.forEach((column) => delete json[column]); + + return { ...row, json }; + }); } /** @@ -226,27 +248,35 @@ export class FirestoreBigQueryEventHistoryTracker } /** - * Whether a failed insertion is the one case it is safe to retry while - * ignoring unknown values: a column this tracker adds to an existing table - * that BigQuery is not ready to stream into yet - * (https://issuetracker.google.com/35905247). + * The rejected columns when a failed insertion is the one case it is safe to + * retry: a column this tracker adds to an existing table that BigQuery is not + * ready to stream into yet (https://issuetracker.google.com/35905247). * - * Every field BigQuery rejected must be one of those columns. Any other - * unknown field is real schema drift, and retrying it with - * `ignoreUnknownValues` would silently drop the user's data. + * Empty unless every field BigQuery rejected is one of those columns. Any + * other unknown field is real schema drift, and dropping it would lose the + * user's data. * - * Deliberately not `async`: the result is used in a boolean guard, and a - * promise there is always truthy. + * Deliberately not `async`: the result is used in a guard, and a promise + * there is always truthy. */ - private isSchemaLagInsertionError(e: any): boolean { + private schemaLagColumns(e: any): string[] { const errors = extractInsertErrors(e); // Without per-field detail we cannot show the retry is safe. - if (!errors.length) return false; + if (!errors.length) return []; const addedColumns = this.columnsAddedToExistingTables(); + const rejected: string[] = []; + + for (const error of errors) { + const column = unknownFieldColumn(error, addedColumns); - return errors.every((error) => isUnknownFieldError(error, addedColumns)); + if (!column) return []; + + rejected.push(column); + } + + return rejected; } /** @@ -351,10 +381,12 @@ export class FirestoreBigQueryEventHistoryTracker private async insertData( rows: bigquery.RowMetadata[], overrideOptions: InsertRowsOptions = {}, - // Tracked separately, so a transient blip on the first attempt cannot - // consume the retry that a schema lag on a later attempt needs. Each is - // spent at most once, bounding this layer at three attempts. - allowSchemaLagRetry: boolean = true, + // Columns a schema-lag retry has already removed. Each retry must remove at + // least one column BigQuery has not named before, so this layer is bounded + // at one attempt per column in `columnsAddedToExistingTables`, plus one. + strippedColumns: string[] = [], + // Tracked separately from the above, so a transient blip on the first + // attempt cannot consume the retry a schema lag on a later attempt needs. allowTransientRetry: boolean = true ) { const options = { @@ -371,14 +403,25 @@ export class FirestoreBigQueryEventHistoryTracker await table.insert(rows, options); logs.dataInserted(rows.length); } catch (e) { - // A column we just added may not be streamable yet. Retry ignoring the - // fields BigQuery does not know about, so the rest of the row lands. - if (allowSchemaLagRetry && this.isSchemaLagInsertionError(e)) { - logs.dataInsertRetriedIgnoringUnknownColumns(rows.length); + // A column we just added may not be streamable yet. Remove the columns + // BigQuery named and retry, so the rest of the row lands. + // + // Deliberately not `ignoreUnknownValues`. A live instance reports one + // unknown field per row rather than all of them, so ignoring unknown + // values would also discard fields BigQuery never mentioned, including + // real drift this retry is not meant to tolerate. Removing only what it + // named leaves any other unknown column failing the insert, where it is + // backed up rather than lost. + const lagColumns = this.schemaLagColumns(e).filter( + (column) => !strippedColumns.includes(column) + ); + + if (lagColumns.length) { + logs.dataInsertRetriedWithoutColumns(rows.length, lagColumns); return this.insertData( - rows, - { ...overrideOptions, ignoreUnknownValues: true }, - false, + withoutColumns(rows, lagColumns), + overrideOptions, + [...strippedColumns, ...lagColumns], allowTransientRetry ); } @@ -387,12 +430,7 @@ export class FirestoreBigQueryEventHistoryTracker // `ignoreUnknownValues`, which would silently drop real data. if (allowTransientRetry && this.isTransientInsertionError(e)) { logs.dataInsertRetriedAfterTransientError(rows.length); - return this.insertData( - rows, - overrideOptions, - allowSchemaLagRetry, - false - ); + return this.insertData(rows, overrideOptions, strippedColumns, false); } // Terminal: no further attempt will be made for these rows. diff --git a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/logs.ts b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/logs.ts index 055d7d281..a468f7393 100644 --- a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/logs.ts +++ b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/logs.ts @@ -139,16 +139,23 @@ export const dataInserted = (rowCount: number) => { /** * The two retry paths must be distinguishable in the logs: only one of them - * discards columns, and an operator investigating suspected column loss has no + * drops columns, and an operator investigating suspected column loss has no * other way to tell which retry ran. * * Warn rather than debug: this is the one path that leaves a column permanently * null for the rows it recovers, and debug is suppressed at the default log * level, so an operator would have had to already suspect the loss to see it. + * Naming the columns means the log says which fields were lost, not just that + * something was. */ -export const dataInsertRetriedIgnoringUnknownColumns = (rowCount: number) => { +export const dataInsertRetriedWithoutColumns = ( + rowCount: number, + columns: string[] +) => { logger.warn( - `Retrying insert of ${rowCount} row(s) of data into BigQuery, ignoring unknown columns. Any column BigQuery rejected will be null for these rows.` + `Retrying insert of ${rowCount} row(s) of data into BigQuery without ${columns.join( + ", " + )}. BigQuery does not have those columns yet, so they will be null for these rows.` ); }; From 0892288bc5843f5df23f3687a7dcb3fba4e76658 Mon Sep 17 00:00:00 2001 From: Izaak Gough Date: Wed, 12 Aug 2026 16:26:13 +0100 Subject: [PATCH 10/21] fix(firestore-bigquery-export): ignore stopped rows when recognising schema lag With `skipInvalidRows` false BigQuery rejects the whole request and marks the rows it did not attempt as `stopped`. `schemaLagColumns` treated those entries as unattributable and bailed, so no multi-row batch could be recognised as lag, while `isTransientInsertionError` counted the same reason as retryable. The two now agree. `scripts/import` records batches, so this was reachable. `handleFailedTransactions` no longer reads `.message` off the caught value directly. It is not always an Error, and the TypeError left the caller reporting a failed backup with nothing written, for the malformed failures where the row is least recoverable elsewhere. Also dedupes the rejected column list, which repeated per row in the log line, and corrects the comment claiming `document_id` is metadata costing one field. It is a grouping key in the default latest view, so a dropped value can show a document twice there until a later write lands. Still allowlisted: the lag is transient and recovers, where a lost event does not. --- .../__tests__/bigquery/backupSettings.test.ts | 20 ++++++- .../__tests__/bigquery/insertRetry.test.ts | 57 +++++++++++++++++++ .../src/bigquery/handleFailedTransactions.ts | 9 ++- .../src/bigquery/index.ts | 24 ++++++-- 4 files changed, 103 insertions(+), 7 deletions(-) diff --git a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/backupSettings.test.ts b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/backupSettings.test.ts index c77ab62e4..524633f75 100644 --- a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/backupSettings.test.ts +++ b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/backupSettings.test.ts @@ -26,7 +26,9 @@ const collection = jest.fn(() => ({ doc: (id: string) => ({ id }) })); jest.mock("firebase-admin", () => ({ apps: [{}] })); jest.mock("firebase-admin/app", () => ({ initializeApp: jest.fn() })); jest.mock("firebase-admin/firestore", () => ({ - // One instance per database id, as the real `getFirestore` returns. + // A fresh object per call, deliberately: the guard must key on the database + // id rather than on instance identity, so this would catch a guard that + // relied on getting the same object back. getFirestore: jest.fn(() => ({ settings, batch, collection })), })); @@ -82,6 +84,22 @@ describe("handleFailedTransactions Firestore settings", () => { expect(commit).toHaveBeenCalledTimes(1); }); + it("still writes the backup when the thrown value is not an Error", async () => { + // `insertData` reports whatever it caught, so this reaches the handler. + // Reading `.message` off it threw a TypeError, which the caller reported as + // a failed backup, so nothing was written for the very failures where the + // row is least recoverable from elsewhere. The retry suite could not catch + // this: it mocks this module, so it only proves the call site was reached. + const handler = loadHandler(); + + await expect( + handler(ROWS, config, undefined as any) + ).resolves.toBeUndefined(); + + expect(commit).toHaveBeenCalledTimes(1); + expect(typeof set.mock.calls[0][1].error_details).toBe("string"); + }); + it("writes one document per row, keyed by insertId", async () => { const handler = loadHandler(); diff --git a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts index 419742da9..385b35eb6 100644 --- a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts +++ b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts @@ -225,6 +225,60 @@ describe("insertData retry behaviour", () => { expect(handleFailedTransactionsMock).not.toHaveBeenCalled(); }); + it("ignores stopped rows when recognising the lag", async () => { + // With skipInvalidRows false BigQuery rejects the whole request and marks + // the rows it did not attempt as `stopped`. Those entries say nothing + // about the schema. Treating them as unattributable meant no multi-row + // batch could ever be recognised as lag, which `scripts/import` hits + // because it records batches rather than single events. + const insert = jest + .fn() + .mockRejectedValueOnce( + partialFailure([ + { + message: "Row skipped due to another row's error.", + reason: "stopped", + }, + { message: "no such field.", location: "document_id" }, + ]) + ) + .mockResolvedValueOnce(undefined); + + await expect(insertData(trackerWith(insert))).resolves.toBeUndefined(); + + expect(insert).toHaveBeenCalledTimes(2); + expect(payloadOf(insert, 1)).not.toHaveProperty("document_id"); + expect(handleFailedTransactionsMock).not.toHaveBeenCalled(); + }); + + it("names a column once however many rows rejected it", async () => { + const insert = jest + .fn() + .mockRejectedValueOnce( + partialFailure([ + { message: "no such field.", location: "document_id" }, + { message: "no such field.", location: "document_id" }, + ]) + ) + .mockResolvedValueOnce(undefined); + + const warn = jest + .spyOn(logger, "warn") + .mockImplementation(() => undefined); + + await expect(insertData(trackerWith(insert))).resolves.toBeUndefined(); + + const messages = warn.mock.calls.map(([message]) => String(message)); + warn.mockRestore(); + + expect( + messages.some((m) => m.includes("without document_id, document_id")) + ).toBe(false); + expect(messages.some((m) => m.includes("without document_id"))).toBe( + true + ); + }); + it("gives up when a retry makes no progress", async () => { // The same column rejected twice means removing it did not help, so there // is nothing further to try. Without this the recursion never ends. @@ -572,6 +626,9 @@ describe("insertData retry behaviour", () => { await expect(insertData(trackerWith(insert))).rejects.toBeUndefined(); + // This only shows the backup was reached, since the module is mocked + // here. That it actually writes a row for a non-Error is pinned in + // backupSettings.test.ts against the real handler. expect(handleFailedTransactionsMock).toHaveBeenCalledTimes(1); }); diff --git a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/handleFailedTransactions.ts b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/handleFailedTransactions.ts index a67ebaea9..b7900726c 100644 --- a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/handleFailedTransactions.ts +++ b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/handleFailedTransactions.ts @@ -41,6 +41,13 @@ export default async ( e: Error ): Promise => { const db = backupFirestore(config.firestoreInstanceId!); + + // The caught value is not always an Error: `insertData` reports whatever it + // caught. Reading `.message` off a non-object threw a TypeError from here, + // which the caller then reported as a failed backup, so nothing was written + // for exactly the malformed failures the backup is most needed for. + const errorDetails = (e as any)?.message ?? String(e); + const batchArray = [db.batch()]; let operationCounter = 0; @@ -51,7 +58,7 @@ export default async ( batchArray[batchIndex].set(ref, { ...row, - error_details: e.message, + error_details: errorDetails, }); operationCounter++; diff --git a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts index 461660876..0ece73d34 100644 --- a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts +++ b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts @@ -269,6 +269,13 @@ export class FirestoreBigQueryEventHistoryTracker const rejected: string[] = []; for (const error of errors) { + // `stopped` marks a row BigQuery did not attempt, because another row in + // the same request failed and `skipInvalidRows` is false. It says nothing + // about the schema, so treating it as unattributable would stop any + // multi-row batch from ever being recognised as lag. `scripts/import` + // records batches, so this is reachable. + if (error?.reason === "stopped") continue; + const column = unknownFieldColumn(error, addedColumns); if (!column) return []; @@ -276,7 +283,8 @@ export class FirestoreBigQueryEventHistoryTracker rejected.push(column); } - return rejected; + // One entry per row, so the same column appears once per rejected row. + return [...new Set(rejected)]; } /** @@ -314,10 +322,16 @@ export class FirestoreBigQueryEventHistoryTracker // for the latest view as well as the partition key, so tolerating the drop // would silently misfile every affected row for good. Failing instead // writes a backup row and throws, which the caller can retry. The same goes - // for a field strategy pointed at any other base column, `data` say. That - // reasoning does not extend to `old_data`, `document_id` or `path_params`: - // those are nullable metadata, where a dropped column costs one field and - // allowlisting keeps the event. + // for a field strategy pointed at any other base column, `data` say. + // + // The columns above are not free either, so this is a trade-off rather than + // a clean line. `document_id` and `path_params` are grouping keys in the + // latest view (`snapshot.ts:150` and `:191`, and the legacy form is the + // default), so a document written both during the lag and after it groups + // twice and appears twice in `_latest`. That is accepted here because the + // lag is transient and self-correcting, where losing the event is not, and + // because the view recovers once a later write lands with the column set. + // `timestamp` gets no such recovery, which is why it is excluded. const partitionColumn = this.partitioningConfig.getBigQueryColumnName(); if ( From 537dff425703eb371c54b771581de9af1f7f56f5 Mon Sep 17 00:00:00 2001 From: Izaak Gough Date: Wed, 12 Aug 2026 17:04:47 +0100 Subject: [PATCH 11/21] test(firestore-bigquery-export): use the stopped entry shape BigQuery sends A live instance sends `stopped` with an empty message and location, so `reason` is the only field identifying it. The fixture guessed a descriptive message, which made the test weaker than the case it stands for. --- .../src/__tests__/bigquery/insertRetry.test.ts | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts index 385b35eb6..28f9c2967 100644 --- a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts +++ b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts @@ -231,14 +231,14 @@ describe("insertData retry behaviour", () => { // about the schema. Treating them as unattributable meant no multi-row // batch could ever be recognised as lag, which `scripts/import` hits // because it records batches rather than single events. + // + // The empty message and location are the shape a live instance sends, so + // `reason` is the only thing that identifies this entry. const insert = jest .fn() .mockRejectedValueOnce( partialFailure([ - { - message: "Row skipped due to another row's error.", - reason: "stopped", - }, + { message: "", location: "", reason: "stopped" }, { message: "no such field.", location: "document_id" }, ]) ) From 05af747c85b7396538719198fb7dc429453c1499 Mon Sep 17 00:00:00 2001 From: Izaak Gough Date: Wed, 12 Aug 2026 18:17:12 +0100 Subject: [PATCH 12/21] fix(firestore-bigquery-export): record real error details in insert backups A rejected BigQuery insert throws a PartialFailureError whose own message is the empty string, because the library builds that message from the entries of `errors`, and those entries carry no message of their own. The backup writer read `.message` with `??`, which only falls back on null and undefined, so every backup document written for a real failure recorded an empty `error_details` and told the operator nothing. It now falls back to the per-field messages nested under `errors[].errors[].message`, deduplicated and capped in count and length so the field stays bounded. A populated top-level message still wins, and no shape of the caught value can throw, since this runs inside the caller's catch block. --- .../__tests__/bigquery/backupSettings.test.ts | 123 ++++++++++++++++++ .../src/bigquery/handleFailedTransactions.ts | 92 ++++++++++++- 2 files changed, 210 insertions(+), 5 deletions(-) diff --git a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/backupSettings.test.ts b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/backupSettings.test.ts index 524633f75..19c57ac9d 100644 --- a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/backupSettings.test.ts +++ b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/backupSettings.test.ts @@ -115,3 +115,126 @@ describe("handleFailedTransactions Firestore settings", () => { expect(set.mock.calls[0][1]).toMatchObject({ error_details: "boom" }); }); }); + +/** + * A stand-in for `@google-cloud/bigquery`'s `PartialFailureError`, built the + * same way: one entry per failed row, each nesting the per-field errors, and a + * top-level `message` that `@google-cloud/common` leaves empty because those + * entries carry no `message` of their own. + */ +const partialFailure = (groups: any[]) => + Object.assign(new Error(""), { name: "PartialFailureError", errors: groups }); + +describe("handleFailedTransactions error details", () => { + beforeEach(() => { + jest.clearAllMocks(); + commit.mockResolvedValue(undefined); + settings.mockImplementation(() => undefined); + }); + + const detailsFor = async (e: any) => { + // Cleared per call, so a test may describe more than one failure shape. + set.mockClear(); + + await loadHandler()(ROWS, config, e); + + return set.mock.calls[0][1].error_details; + }; + + it("records the nested per-field messages when the top-level message is empty", async () => { + // The observed failure. `PartialFailureError.message` is "", and `??` only + // falls back on null and undefined, so every backup document written for a + // real rejected insert recorded an empty string and told the operator + // nothing about why the row failed. + const details = await detailsFor( + partialFailure([ + { + errors: [ + { message: "no such field: document_id.", reason: "invalid" }, + ], + row: { insertId: "e1" }, + }, + ]) + ); + + expect(details).toBe("no such field: document_id."); + }); + + it("deduplicates messages shared across failed rows", async () => { + // A batch normally fails the same way for every row, so repeating one + // message 500 times would push out the detail that differs. + const details = await detailsFor( + partialFailure([ + { errors: [{ message: "no such field: document_id." }] }, + { errors: [{ message: "no such field: document_id." }] }, + { errors: [{ message: "no such field: old_data." }] }, + ]) + ); + + expect(details).toBe( + "no such field: document_id.; no such field: old_data." + ); + }); + + it("caps the number of messages and the total length", async () => { + // `error_details` is a Firestore field, so it must not grow with the + // number of distinct failures in the batch. + const details = await detailsFor( + partialFailure( + Array.from({ length: 9 }, (_, i) => ({ + errors: [{ message: `${"x".repeat(400)} ${i}` }], + })) + ) + ); + + expect(details).toHaveLength(1000); + expect(details.endsWith("...")).toBe(true); + + const short = await detailsFor( + partialFailure( + Array.from({ length: 8 }, (_, i) => ({ + errors: [{ message: `field ${i}` }], + })) + ) + ); + + expect(short).toBe("field 0; field 1; field 2; field 3; field 4 (+3 more)"); + }); + + it("prefers a populated top-level message over the nested ones", async () => { + const details = await detailsFor( + Object.assign(new Error("quota exceeded"), { + errors: [{ errors: [{ message: "no such field: document_id." }] }], + }) + ); + + expect(details).toBe("quota exceeded"); + }); + + it("still writes a string for every malformed shape of `errors`", async () => { + // This runs inside the caller's catch block: anything thrown here is + // reported as a failed backup and the row is lost, so no shape of the + // caught value may throw. + const shapes: any[] = [ + partialFailure([]), + Object.assign(new Error(""), { errors: "not an array" }), + Object.assign(new Error(""), { errors: [null, undefined] }), + Object.assign(new Error(""), { errors: [{ errors: null }] }), + Object.assign(new Error(""), { errors: [{ errors: [null] }] }), + Object.assign(new Error(""), { errors: [{ errors: [{}] }] }), + Object.assign(new Error(""), { errors: [{ errors: [{ message: 42 }] }] }), + "a plain string", + 42, + null, + Object.create(null), + ]; + + for (const shape of shapes) { + jest.clearAllMocks(); + + await expect(loadHandler()(ROWS, config, shape)).resolves.toBeUndefined(); + + expect(typeof set.mock.calls[0][1].error_details).toBe("string"); + } + }); +}); diff --git a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/handleFailedTransactions.ts b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/handleFailedTransactions.ts index b7900726c..290eafed8 100644 --- a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/handleFailedTransactions.ts +++ b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/handleFailedTransactions.ts @@ -35,6 +35,92 @@ function backupFirestore(instanceId: string) { return db; } +/** Distinct messages recorded before the rest are counted instead. */ +const MAX_ERROR_MESSAGES = 5; + +/** Cap, so one bad insert cannot write an unbounded Firestore field. */ +const MAX_ERROR_DETAILS_LENGTH = 1000; + +function truncate(value: string): string { + return value.length > MAX_ERROR_DETAILS_LENGTH + ? `${value.slice(0, MAX_ERROR_DETAILS_LENGTH - 3)}...` + : value; +} + +/** + * The per-field messages a `PartialFailureError` nests under + * `errors[].errors[].message`, deduplicated and capped. + * + * One failure can name several rows, and each row several fields, but a whole + * batch usually fails the same way, so the distinct messages are what an + * operator needs. Returns `""` when there is nothing usable to report. + */ +function nestedErrorMessages(e: unknown): string { + const groups = (e as any)?.errors; + + if (!Array.isArray(groups)) return ""; + + const messages = new Set(); + + for (const group of groups) { + const inner = (group as any)?.errors; + const entries = Array.isArray(inner) ? inner : [group]; + + for (const entry of entries) { + const message = (entry as any)?.message; + + if (typeof message === "string" && message.length > 0) { + messages.add(message); + } + } + } + + if (messages.size === 0) return ""; + + const all = Array.from(messages); + const shown = all.slice(0, MAX_ERROR_MESSAGES); + const remaining = all.length - shown.length; + + return remaining > 0 + ? `${shown.join("; ")} (+${remaining} more)` + : shown.join("; "); +} + +/** + * A description of a failed insert that an operator can act on. + * + * The caught value is not always an Error: `insertData` reports whatever it + * caught. Reading `.message` off a non-object threw a TypeError from here, + * which the caller then reported as a failed backup, so nothing was written + * for exactly the malformed failures the backup is most needed for. + * + * Its message is also not always populated. The common failure is a + * `PartialFailureError`, whose message `@google-cloud/common` builds from the + * `message` of each entry in `errors`. Those entries are `{ errors, row }` + * pairs and carry no `message` of their own, so the message it builds is the + * empty string, and the reason for the failure ("no such field: document_id.") + * is only reachable one level further down. `??` kept that empty string, + * because it falls back on null and undefined but not on "". + */ +function describeError(e: unknown): string { + const message = (e as any)?.message; + + if (typeof message === "string" && message.length > 0) { + return truncate(message); + } + + const nested = nestedErrorMessages(e); + + if (nested.length > 0) return truncate(nested); + + try { + return truncate(String(e)); + } catch (stringifyError) { + // A value whose `toString` throws, or an object with a null prototype. + return "Unknown error"; + } +} + export default async ( rows: any[], config: ChangeTrackerConfig, @@ -42,11 +128,7 @@ export default async ( ): Promise => { const db = backupFirestore(config.firestoreInstanceId!); - // The caught value is not always an Error: `insertData` reports whatever it - // caught. Reading `.message` off a non-object threw a TypeError from here, - // which the caller then reported as a failed backup, so nothing was written - // for exactly the malformed failures the backup is most needed for. - const errorDetails = (e as any)?.message ?? String(e); + const errorDetails = describeError(e); const batchArray = [db.batch()]; From 1d97d6ee56af71404ecfb643269d77b568c580ff Mon Sep 17 00:00:00 2001 From: Izaak Gough Date: Wed, 12 Aug 2026 18:47:07 +0100 Subject: [PATCH 13/21] fix(firestore-bigquery-export): stop allowlisting document_id `document_id` is the one column the default latest view groups on without wrapping in `FIRST_VALUE`, so a row that lands with it null forms its own group and the document appears twice in `_latest`. The changelog is append-only, so the duplicate never clears, and the later ordinary write is what creates it. Verified against a live instance: with both rows present the legacy view returns two rows for one document, while the standard view syntax returns one. An earlier comment here claimed the opposite, that the view recovers once a later write lands. Tolerating the drop traded a delayed event for permanent silent duplication of the view people query, so `document_id` now takes the terminal path and the caller retries until BigQuery catches up. The remaining entries are the columns the view wraps in `FIRST_VALUE`, where a null really does heal on the next write: `old_data`, `path_params` when wildcard ids are on, and a custom partition column. The tests use `old_data` as their allowlisted column throughout, since `document_id` no longer is. --- .../__tests__/bigquery/insertRetry.test.ts | 118 ++++++++++-------- .../src/bigquery/index.ts | 34 +++-- 2 files changed, 88 insertions(+), 64 deletions(-) diff --git a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts index 28f9c2967..e782f8d5b 100644 --- a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts +++ b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts @@ -84,7 +84,8 @@ function transportFailure() { /** * Deliberately carries every column the allowlist can name, so that asserting a * column was removed from a retry is a real assertion rather than one that - * passes because the key was never there. + * passes because the key was never there. `document_id` is here too, though it + * is not allowlisted, so the test that it is refused has something to refuse. */ const ROWS = [ { @@ -93,7 +94,7 @@ const ROWS = [ event_id: "e1", data: "{}", document_id: "d1", - old_data: null, + old_data: '{"was":"here"}', path_params: "{}", created_at: "2026-01-01 00:00:00", }, @@ -135,17 +136,15 @@ describe("insertData retry behaviour", () => { const insert = jest .fn() .mockRejectedValueOnce( - partialFailure([ - { message: "no such field.", location: "document_id" }, - ]) + partialFailure([{ message: "no such field.", location: "old_data" }]) ) .mockResolvedValueOnce(undefined); await expect(insertData(trackerWith(insert))).resolves.toBeUndefined(); expect(insert).toHaveBeenCalledTimes(2); - expect(payloadOf(insert, 0)).toHaveProperty("document_id"); - expect(payloadOf(insert, 1)).not.toHaveProperty("document_id"); + expect(payloadOf(insert, 0)).toHaveProperty("old_data"); + expect(payloadOf(insert, 1)).not.toHaveProperty("old_data"); // Everything else must survive: only what BigQuery named is dropped. expect(payloadOf(insert, 1)).toMatchObject({ event_id: "e1", @@ -177,16 +176,14 @@ describe("insertData retry behaviour", () => { it("does not ignore an unknown field BigQuery did not name", async () => { // A live instance reports one unknown field per row, not all of them. So - // a table missing `document_id` while a transform has injected a stray - // key surfaces as a rejection naming only `document_id`. Retrying with + // a table missing `old_data` while a transform has injected a stray key + // surfaces as a rejection naming only `old_data`. Retrying with // ignoreUnknownValues would have discarded the stray key too, silently, // which is the loss this whole change exists to prevent. const insert = jest .fn() .mockRejectedValueOnce( - partialFailure([ - { message: "no such field.", location: "document_id" }, - ]) + partialFailure([{ message: "no such field.", location: "old_data" }]) ) .mockRejectedValueOnce( partialFailure([{ message: "no such field.", location: "injected" }]) @@ -197,13 +194,15 @@ describe("insertData retry behaviour", () => { ); expect(insert).toHaveBeenCalledTimes(2); - expect(payloadOf(insert, 1)).not.toHaveProperty("document_id"); + expect(payloadOf(insert, 1)).not.toHaveProperty("old_data"); // Terminal, so the row reaches the backup with the stray key intact // rather than being dropped and reported as a success. expect(handleFailedTransactionsMock).toHaveBeenCalledTimes(1); }); it("strips one column per retry when BigQuery names them one at a time", async () => { + // Confirmed live: a row missing two allowlisted columns comes back naming + // only one of them, so the loop has to make progress across attempts. const insert = jest .fn() .mockRejectedValueOnce( @@ -211,20 +210,44 @@ describe("insertData retry behaviour", () => { ) .mockRejectedValueOnce( partialFailure([ - { message: "no such field.", location: "document_id" }, + { message: "no such field.", location: "path_params" }, ]) ) .mockResolvedValueOnce(undefined); - await expect(insertData(trackerWith(insert))).resolves.toBeUndefined(); + await expect( + insertData(trackerWith(insert, { wildcardIds: true })) + ).resolves.toBeUndefined(); expect(insert).toHaveBeenCalledTimes(3); expect(payloadOf(insert, 1)).not.toHaveProperty("old_data"); expect(payloadOf(insert, 2)).not.toHaveProperty("old_data"); - expect(payloadOf(insert, 2)).not.toHaveProperty("document_id"); + expect(payloadOf(insert, 2)).not.toHaveProperty("path_params"); expect(handleFailedTransactionsMock).not.toHaveBeenCalled(); }); + it("does not allowlist document_id, which the latest view groups on", async () => { + // `document_id` is added to existing tables like the others, but it is the + // one column the default latest view groups on without wrapping in + // FIRST_VALUE, so a row landing with it null shows the document twice in + // `_latest` and the changelog being append-only means that never clears. + // Verified against a live instance. Failing keeps the event recoverable. + const insert = jest + .fn() + .mockRejectedValue( + partialFailure([ + { message: "no such field.", location: "document_id" }, + ]) + ); + + await expect(insertData(trackerWith(insert))).rejects.toThrow( + "insert failed" + ); + + expect(insert).toHaveBeenCalledTimes(1); + expect(handleFailedTransactionsMock).toHaveBeenCalledTimes(1); + }); + it("ignores stopped rows when recognising the lag", async () => { // With skipInvalidRows false BigQuery rejects the whole request and marks // the rows it did not attempt as `stopped`. Those entries say nothing @@ -239,7 +262,7 @@ describe("insertData retry behaviour", () => { .mockRejectedValueOnce( partialFailure([ { message: "", location: "", reason: "stopped" }, - { message: "no such field.", location: "document_id" }, + { message: "no such field.", location: "old_data" }, ]) ) .mockResolvedValueOnce(undefined); @@ -247,7 +270,7 @@ describe("insertData retry behaviour", () => { await expect(insertData(trackerWith(insert))).resolves.toBeUndefined(); expect(insert).toHaveBeenCalledTimes(2); - expect(payloadOf(insert, 1)).not.toHaveProperty("document_id"); + expect(payloadOf(insert, 1)).not.toHaveProperty("old_data"); expect(handleFailedTransactionsMock).not.toHaveBeenCalled(); }); @@ -256,8 +279,8 @@ describe("insertData retry behaviour", () => { .fn() .mockRejectedValueOnce( partialFailure([ - { message: "no such field.", location: "document_id" }, - { message: "no such field.", location: "document_id" }, + { message: "no such field.", location: "old_data" }, + { message: "no such field.", location: "old_data" }, ]) ) .mockResolvedValueOnce(undefined); @@ -272,11 +295,9 @@ describe("insertData retry behaviour", () => { warn.mockRestore(); expect( - messages.some((m) => m.includes("without document_id, document_id")) + messages.some((m) => m.includes("without old_data, old_data")) ).toBe(false); - expect(messages.some((m) => m.includes("without document_id"))).toBe( - true - ); + expect(messages.some((m) => m.includes("without old_data"))).toBe(true); }); it("gives up when a retry makes no progress", async () => { @@ -285,9 +306,7 @@ describe("insertData retry behaviour", () => { const insert = jest .fn() .mockRejectedValue( - partialFailure([ - { message: "no such field.", location: "document_id" }, - ]) + partialFailure([{ message: "no such field.", location: "old_data" }]) ); await expect(insertData(trackerWith(insert))).rejects.toThrow( @@ -317,12 +336,12 @@ describe("insertData retry behaviour", () => { }); it("does not match a column that merely contains an allowlisted name", async () => { - // A user column named document_id_v2 must not be mistaken for - // document_id, or its contents would be silently dropped. + // A user column named old_data_v2 must not be mistaken for old_data, + // or its contents would be silently dropped. const insert = jest .fn() .mockRejectedValue( - partialFailure([{ message: "no such field: document_id_v2." }]) + partialFailure([{ message: "no such field: old_data_v2." }]) ); await expect(insertData(trackerWith(insert))).rejects.toThrow( @@ -336,7 +355,6 @@ describe("insertData retry behaviour", () => { // adds that column, and `record` only emits the key, when wildcard ids are // enabled. const addedColumns: Array<[string, Partial]> = [ - ["document_id", {}], ["old_data", {}], ["path_params", { wildcardIds: true }], ]; @@ -406,7 +424,7 @@ describe("insertData retry behaviour", () => { it("does not retry when only some rejected fields are ours", async () => { const insert = jest.fn().mockRejectedValue( partialFailure([ - { message: "no such field.", location: "document_id" }, + { message: "no such field.", location: "old_data" }, { message: "no such field.", location: "user_age" }, ]) ); @@ -544,17 +562,15 @@ describe("insertData retry behaviour", () => { .fn() .mockRejectedValueOnce(transportFailure()) .mockRejectedValueOnce( - partialFailure([ - { message: "no such field.", location: "document_id" }, - ]) + partialFailure([{ message: "no such field.", location: "old_data" }]) ) .mockResolvedValueOnce(undefined); await expect(insertData(trackerWith(insert))).resolves.toBeUndefined(); expect(insert).toHaveBeenCalledTimes(3); - expect(payloadOf(insert, 1)).toHaveProperty("document_id"); - expect(payloadOf(insert, 2)).not.toHaveProperty("document_id"); + expect(payloadOf(insert, 1)).toHaveProperty("old_data"); + expect(payloadOf(insert, 2)).not.toHaveProperty("old_data"); expect(handleFailedTransactionsMock).not.toHaveBeenCalled(); }); @@ -563,9 +579,7 @@ describe("insertData retry behaviour", () => { .fn() .mockRejectedValueOnce(transportFailure()) .mockRejectedValueOnce( - partialFailure([ - { message: "no such field.", location: "document_id" }, - ]) + partialFailure([{ message: "no such field.", location: "old_data" }]) ) .mockRejectedValue(transportFailure()); @@ -586,9 +600,7 @@ describe("insertData retry behaviour", () => { const insert = jest .fn() .mockRejectedValueOnce( - partialFailure([ - { message: "no such field.", location: "document_id" }, - ]) + partialFailure([{ message: "no such field.", location: "old_data" }]) ) .mockRejectedValueOnce(transportFailure()) .mockResolvedValueOnce(undefined); @@ -596,9 +608,9 @@ describe("insertData retry behaviour", () => { await expect(insertData(trackerWith(insert))).resolves.toBeUndefined(); expect(insert).toHaveBeenCalledTimes(3); - expect(payloadOf(insert, 0)).toHaveProperty("document_id"); - expect(payloadOf(insert, 1)).not.toHaveProperty("document_id"); - expect(payloadOf(insert, 2)).not.toHaveProperty("document_id"); + expect(payloadOf(insert, 0)).toHaveProperty("old_data"); + expect(payloadOf(insert, 1)).not.toHaveProperty("old_data"); + expect(payloadOf(insert, 2)).not.toHaveProperty("old_data"); expect(handleFailedTransactionsMock).not.toHaveBeenCalled(); }); }); @@ -825,9 +837,7 @@ describe("insertData retry behaviour", () => { const insert = jest .fn() .mockRejectedValueOnce( - partialFailure([ - { message: "no such field.", location: "document_id" }, - ]) + partialFailure([{ message: "no such field.", location: "old_data" }]) ) .mockResolvedValueOnce(undefined); @@ -835,12 +845,12 @@ describe("insertData retry behaviour", () => { expect( warn.mock.calls.filter(([message]) => - String(message).includes("without document_id") + String(message).includes("without old_data") ) ).toHaveLength(1); expect( debug.mock.calls.filter(([message]) => - String(message).includes("without document_id") + String(message).includes("without old_data") ) ).toHaveLength(0); }); @@ -868,9 +878,7 @@ describe("insertData retry behaviour", () => { const insert = jest .fn() .mockRejectedValueOnce( - partialFailure([ - { message: "no such field.", location: "document_id" }, - ]) + partialFailure([{ message: "no such field.", location: "old_data" }]) ) .mockRejectedValueOnce(transportFailure()) .mockResolvedValueOnce(undefined); @@ -881,7 +889,7 @@ describe("insertData retry behaviour", () => { ([message]) => String(message) ); const dropped = messages.filter((message) => - message.includes("without document_id") + message.includes("without old_data") ); expect(dropped).toHaveLength(1); diff --git a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts index 0ece73d34..6da57549b 100644 --- a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts +++ b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts @@ -299,7 +299,23 @@ export class FirestoreBigQueryEventHistoryTracker * retry drop that column's value on a table missing it, forever. */ private columnsAddedToExistingTables(): string[] { - const columns = [documentIdField.name, oldDataField.name]; + // `document_id` is deliberately absent, though it is added to existing + // tables and so is exposed to the lag. It is the one column the default + // latest view groups on without wrapping in `FIRST_VALUE` + // (`snapshot.ts:128` and `:150`), so a row that lands with it null forms a + // separate group from the same document's later rows, and the document + // appears twice in `_latest`. Verified against a live instance: with the + // lag row and a later ordinary row both present, the legacy view returns + // two rows for one document, and the changelog is append-only so the + // duplicate never clears. The later write is what creates it. + // + // Tolerating the drop would therefore trade a delayed event for permanent, + // silent duplication of the view people query. Failing instead writes a + // backup row and throws, and the caller retries until BigQuery catches up. + // The standard view syntax is immune, since its join narrows to the latest + // timestamp before grouping, but it is off by default and is the user's + // setting rather than ours to rely on. + const columns = [oldDataField.name]; // `path_params` is only ever added, and only ever emitted by `record`, when // wildcard ids are enabled. Listing it unconditionally meant a transform @@ -324,14 +340,14 @@ export class FirestoreBigQueryEventHistoryTracker // writes a backup row and throws, which the caller can retry. The same goes // for a field strategy pointed at any other base column, `data` say. // - // The columns above are not free either, so this is a trade-off rather than - // a clean line. `document_id` and `path_params` are grouping keys in the - // latest view (`snapshot.ts:150` and `:191`, and the legacy form is the - // default), so a document written both during the lag and after it groups - // twice and appears twice in `_latest`. That is accepted here because the - // lag is transient and self-correcting, where losing the event is not, and - // because the view recovers once a later write lands with the column set. - // `timestamp` gets no such recovery, which is why it is excluded. + // The rule this all follows: a column is safe to drop only if a null it + // leaves behind heals on its own. The latest view wraps every column except + // `document_name` and `document_id` in `FIRST_VALUE(...) OVER (PARTITION BY + // document_name ORDER BY timestamp DESC)` (`snapshot.ts:134-140`), so their + // value is taken from the document's newest row and a null from the lag + // disappears as soon as any later row lands. `old_data`, `path_params` and a + // custom partition column are all in that set. `document_id` and + // `timestamp` are not, which is why neither is listed. const partitionColumn = this.partitioningConfig.getBigQueryColumnName(); if ( From f9fd512611451ca6d4a18d7186bb85ed451d057b Mon Sep 17 00:00:00 2001 From: Izaak Gough Date: Wed, 12 Aug 2026 19:19:03 +0100 Subject: [PATCH 14/21] Revert "fix(firestore-bigquery-export): stop allowlisting document_id" This reverts commit 1d97d6ee56af71404ecfb643269d77b568c580ff. Dropping `document_id` from the allowlist does prevent a duplicate row in the legacy latest view, but not a new one. The column is added to an existing table as a schema change with no backfill, so every pre-upgrade row is already null and any document written either side of the upgrade already duplicates permanently. The lag adds a few rows to a set that is already there. Losing the event is worse, because the caller's retries are finite and nothing reconciles the schema afterwards, so the change never reaches BigQuery at all. The comment is rewritten rather than restored. Two claims in it were wrong: a custom partition column is not `FIRST_VALUE`-wrapped, it is absent from the view entirely since the view is built from `RawChangelogViewSchema`, and `timestamp` is wrapped, so it is excluded for being the partition and ordering key rather than for anything to do with the view. The docstring no longer says the list must stay complete, which the deliberate `timestamp` omission contradicts. --- .../__tests__/bigquery/insertRetry.test.ts | 118 ++++++++---------- .../src/bigquery/index.ts | 57 ++++----- 2 files changed, 84 insertions(+), 91 deletions(-) diff --git a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts index e782f8d5b..28f9c2967 100644 --- a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts +++ b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts @@ -84,8 +84,7 @@ function transportFailure() { /** * Deliberately carries every column the allowlist can name, so that asserting a * column was removed from a retry is a real assertion rather than one that - * passes because the key was never there. `document_id` is here too, though it - * is not allowlisted, so the test that it is refused has something to refuse. + * passes because the key was never there. */ const ROWS = [ { @@ -94,7 +93,7 @@ const ROWS = [ event_id: "e1", data: "{}", document_id: "d1", - old_data: '{"was":"here"}', + old_data: null, path_params: "{}", created_at: "2026-01-01 00:00:00", }, @@ -136,15 +135,17 @@ describe("insertData retry behaviour", () => { const insert = jest .fn() .mockRejectedValueOnce( - partialFailure([{ message: "no such field.", location: "old_data" }]) + partialFailure([ + { message: "no such field.", location: "document_id" }, + ]) ) .mockResolvedValueOnce(undefined); await expect(insertData(trackerWith(insert))).resolves.toBeUndefined(); expect(insert).toHaveBeenCalledTimes(2); - expect(payloadOf(insert, 0)).toHaveProperty("old_data"); - expect(payloadOf(insert, 1)).not.toHaveProperty("old_data"); + expect(payloadOf(insert, 0)).toHaveProperty("document_id"); + expect(payloadOf(insert, 1)).not.toHaveProperty("document_id"); // Everything else must survive: only what BigQuery named is dropped. expect(payloadOf(insert, 1)).toMatchObject({ event_id: "e1", @@ -176,14 +177,16 @@ describe("insertData retry behaviour", () => { it("does not ignore an unknown field BigQuery did not name", async () => { // A live instance reports one unknown field per row, not all of them. So - // a table missing `old_data` while a transform has injected a stray key - // surfaces as a rejection naming only `old_data`. Retrying with + // a table missing `document_id` while a transform has injected a stray + // key surfaces as a rejection naming only `document_id`. Retrying with // ignoreUnknownValues would have discarded the stray key too, silently, // which is the loss this whole change exists to prevent. const insert = jest .fn() .mockRejectedValueOnce( - partialFailure([{ message: "no such field.", location: "old_data" }]) + partialFailure([ + { message: "no such field.", location: "document_id" }, + ]) ) .mockRejectedValueOnce( partialFailure([{ message: "no such field.", location: "injected" }]) @@ -194,15 +197,13 @@ describe("insertData retry behaviour", () => { ); expect(insert).toHaveBeenCalledTimes(2); - expect(payloadOf(insert, 1)).not.toHaveProperty("old_data"); + expect(payloadOf(insert, 1)).not.toHaveProperty("document_id"); // Terminal, so the row reaches the backup with the stray key intact // rather than being dropped and reported as a success. expect(handleFailedTransactionsMock).toHaveBeenCalledTimes(1); }); it("strips one column per retry when BigQuery names them one at a time", async () => { - // Confirmed live: a row missing two allowlisted columns comes back naming - // only one of them, so the loop has to make progress across attempts. const insert = jest .fn() .mockRejectedValueOnce( @@ -210,44 +211,20 @@ describe("insertData retry behaviour", () => { ) .mockRejectedValueOnce( partialFailure([ - { message: "no such field.", location: "path_params" }, + { message: "no such field.", location: "document_id" }, ]) ) .mockResolvedValueOnce(undefined); - await expect( - insertData(trackerWith(insert, { wildcardIds: true })) - ).resolves.toBeUndefined(); + await expect(insertData(trackerWith(insert))).resolves.toBeUndefined(); expect(insert).toHaveBeenCalledTimes(3); expect(payloadOf(insert, 1)).not.toHaveProperty("old_data"); expect(payloadOf(insert, 2)).not.toHaveProperty("old_data"); - expect(payloadOf(insert, 2)).not.toHaveProperty("path_params"); + expect(payloadOf(insert, 2)).not.toHaveProperty("document_id"); expect(handleFailedTransactionsMock).not.toHaveBeenCalled(); }); - it("does not allowlist document_id, which the latest view groups on", async () => { - // `document_id` is added to existing tables like the others, but it is the - // one column the default latest view groups on without wrapping in - // FIRST_VALUE, so a row landing with it null shows the document twice in - // `_latest` and the changelog being append-only means that never clears. - // Verified against a live instance. Failing keeps the event recoverable. - const insert = jest - .fn() - .mockRejectedValue( - partialFailure([ - { message: "no such field.", location: "document_id" }, - ]) - ); - - await expect(insertData(trackerWith(insert))).rejects.toThrow( - "insert failed" - ); - - expect(insert).toHaveBeenCalledTimes(1); - expect(handleFailedTransactionsMock).toHaveBeenCalledTimes(1); - }); - it("ignores stopped rows when recognising the lag", async () => { // With skipInvalidRows false BigQuery rejects the whole request and marks // the rows it did not attempt as `stopped`. Those entries say nothing @@ -262,7 +239,7 @@ describe("insertData retry behaviour", () => { .mockRejectedValueOnce( partialFailure([ { message: "", location: "", reason: "stopped" }, - { message: "no such field.", location: "old_data" }, + { message: "no such field.", location: "document_id" }, ]) ) .mockResolvedValueOnce(undefined); @@ -270,7 +247,7 @@ describe("insertData retry behaviour", () => { await expect(insertData(trackerWith(insert))).resolves.toBeUndefined(); expect(insert).toHaveBeenCalledTimes(2); - expect(payloadOf(insert, 1)).not.toHaveProperty("old_data"); + expect(payloadOf(insert, 1)).not.toHaveProperty("document_id"); expect(handleFailedTransactionsMock).not.toHaveBeenCalled(); }); @@ -279,8 +256,8 @@ describe("insertData retry behaviour", () => { .fn() .mockRejectedValueOnce( partialFailure([ - { message: "no such field.", location: "old_data" }, - { message: "no such field.", location: "old_data" }, + { message: "no such field.", location: "document_id" }, + { message: "no such field.", location: "document_id" }, ]) ) .mockResolvedValueOnce(undefined); @@ -295,9 +272,11 @@ describe("insertData retry behaviour", () => { warn.mockRestore(); expect( - messages.some((m) => m.includes("without old_data, old_data")) + messages.some((m) => m.includes("without document_id, document_id")) ).toBe(false); - expect(messages.some((m) => m.includes("without old_data"))).toBe(true); + expect(messages.some((m) => m.includes("without document_id"))).toBe( + true + ); }); it("gives up when a retry makes no progress", async () => { @@ -306,7 +285,9 @@ describe("insertData retry behaviour", () => { const insert = jest .fn() .mockRejectedValue( - partialFailure([{ message: "no such field.", location: "old_data" }]) + partialFailure([ + { message: "no such field.", location: "document_id" }, + ]) ); await expect(insertData(trackerWith(insert))).rejects.toThrow( @@ -336,12 +317,12 @@ describe("insertData retry behaviour", () => { }); it("does not match a column that merely contains an allowlisted name", async () => { - // A user column named old_data_v2 must not be mistaken for old_data, - // or its contents would be silently dropped. + // A user column named document_id_v2 must not be mistaken for + // document_id, or its contents would be silently dropped. const insert = jest .fn() .mockRejectedValue( - partialFailure([{ message: "no such field: old_data_v2." }]) + partialFailure([{ message: "no such field: document_id_v2." }]) ); await expect(insertData(trackerWith(insert))).rejects.toThrow( @@ -355,6 +336,7 @@ describe("insertData retry behaviour", () => { // adds that column, and `record` only emits the key, when wildcard ids are // enabled. const addedColumns: Array<[string, Partial]> = [ + ["document_id", {}], ["old_data", {}], ["path_params", { wildcardIds: true }], ]; @@ -424,7 +406,7 @@ describe("insertData retry behaviour", () => { it("does not retry when only some rejected fields are ours", async () => { const insert = jest.fn().mockRejectedValue( partialFailure([ - { message: "no such field.", location: "old_data" }, + { message: "no such field.", location: "document_id" }, { message: "no such field.", location: "user_age" }, ]) ); @@ -562,15 +544,17 @@ describe("insertData retry behaviour", () => { .fn() .mockRejectedValueOnce(transportFailure()) .mockRejectedValueOnce( - partialFailure([{ message: "no such field.", location: "old_data" }]) + partialFailure([ + { message: "no such field.", location: "document_id" }, + ]) ) .mockResolvedValueOnce(undefined); await expect(insertData(trackerWith(insert))).resolves.toBeUndefined(); expect(insert).toHaveBeenCalledTimes(3); - expect(payloadOf(insert, 1)).toHaveProperty("old_data"); - expect(payloadOf(insert, 2)).not.toHaveProperty("old_data"); + expect(payloadOf(insert, 1)).toHaveProperty("document_id"); + expect(payloadOf(insert, 2)).not.toHaveProperty("document_id"); expect(handleFailedTransactionsMock).not.toHaveBeenCalled(); }); @@ -579,7 +563,9 @@ describe("insertData retry behaviour", () => { .fn() .mockRejectedValueOnce(transportFailure()) .mockRejectedValueOnce( - partialFailure([{ message: "no such field.", location: "old_data" }]) + partialFailure([ + { message: "no such field.", location: "document_id" }, + ]) ) .mockRejectedValue(transportFailure()); @@ -600,7 +586,9 @@ describe("insertData retry behaviour", () => { const insert = jest .fn() .mockRejectedValueOnce( - partialFailure([{ message: "no such field.", location: "old_data" }]) + partialFailure([ + { message: "no such field.", location: "document_id" }, + ]) ) .mockRejectedValueOnce(transportFailure()) .mockResolvedValueOnce(undefined); @@ -608,9 +596,9 @@ describe("insertData retry behaviour", () => { await expect(insertData(trackerWith(insert))).resolves.toBeUndefined(); expect(insert).toHaveBeenCalledTimes(3); - expect(payloadOf(insert, 0)).toHaveProperty("old_data"); - expect(payloadOf(insert, 1)).not.toHaveProperty("old_data"); - expect(payloadOf(insert, 2)).not.toHaveProperty("old_data"); + expect(payloadOf(insert, 0)).toHaveProperty("document_id"); + expect(payloadOf(insert, 1)).not.toHaveProperty("document_id"); + expect(payloadOf(insert, 2)).not.toHaveProperty("document_id"); expect(handleFailedTransactionsMock).not.toHaveBeenCalled(); }); }); @@ -837,7 +825,9 @@ describe("insertData retry behaviour", () => { const insert = jest .fn() .mockRejectedValueOnce( - partialFailure([{ message: "no such field.", location: "old_data" }]) + partialFailure([ + { message: "no such field.", location: "document_id" }, + ]) ) .mockResolvedValueOnce(undefined); @@ -845,12 +835,12 @@ describe("insertData retry behaviour", () => { expect( warn.mock.calls.filter(([message]) => - String(message).includes("without old_data") + String(message).includes("without document_id") ) ).toHaveLength(1); expect( debug.mock.calls.filter(([message]) => - String(message).includes("without old_data") + String(message).includes("without document_id") ) ).toHaveLength(0); }); @@ -878,7 +868,9 @@ describe("insertData retry behaviour", () => { const insert = jest .fn() .mockRejectedValueOnce( - partialFailure([{ message: "no such field.", location: "old_data" }]) + partialFailure([ + { message: "no such field.", location: "document_id" }, + ]) ) .mockRejectedValueOnce(transportFailure()) .mockResolvedValueOnce(undefined); @@ -889,7 +881,7 @@ describe("insertData retry behaviour", () => { ([message]) => String(message) ); const dropped = messages.filter((message) => - message.includes("without old_data") + message.includes("without document_id") ); expect(dropped).toHaveLength(1); diff --git a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts index 6da57549b..8be6748c6 100644 --- a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts +++ b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts @@ -291,31 +291,17 @@ export class FirestoreBigQueryEventHistoryTracker * The columns this tracker adds to a table that already exists, and so every * column exposed to the lag. * - * This list must stay complete. Omitting a column turns a row that lands - * today, with that column null, into an event lost once the caller exhausts - * its retries, because nothing on the write path reconciles the schema. + * Every column added belongs here unless dropping it would cost more than + * losing the event, and `timestamp` below is the only one that does. Omitting + * a column turns a row that lands today, with that column null, into an event + * lost once the caller exhausts its retries, because nothing on the write + * path reconciles the schema. * * It must also stay exact. Listing a column that is never added makes the * retry drop that column's value on a table missing it, forever. */ private columnsAddedToExistingTables(): string[] { - // `document_id` is deliberately absent, though it is added to existing - // tables and so is exposed to the lag. It is the one column the default - // latest view groups on without wrapping in `FIRST_VALUE` - // (`snapshot.ts:128` and `:150`), so a row that lands with it null forms a - // separate group from the same document's later rows, and the document - // appears twice in `_latest`. Verified against a live instance: with the - // lag row and a later ordinary row both present, the legacy view returns - // two rows for one document, and the changelog is append-only so the - // duplicate never clears. The later write is what creates it. - // - // Tolerating the drop would therefore trade a delayed event for permanent, - // silent duplication of the view people query. Failing instead writes a - // backup row and throws, and the caller retries until BigQuery catches up. - // The standard view syntax is immune, since its join narrows to the latest - // timestamp before grouping, but it is off by default and is the user's - // setting rather than ours to rely on. - const columns = [oldDataField.name]; + const columns = [documentIdField.name, oldDataField.name]; // `path_params` is only ever added, and only ever emitted by `record`, when // wildcard ids are enabled. Listing it unconditionally meant a transform @@ -340,14 +326,29 @@ export class FirestoreBigQueryEventHistoryTracker // writes a backup row and throws, which the caller can retry. The same goes // for a field strategy pointed at any other base column, `data` say. // - // The rule this all follows: a column is safe to drop only if a null it - // leaves behind heals on its own. The latest view wraps every column except - // `document_name` and `document_id` in `FIRST_VALUE(...) OVER (PARTITION BY - // document_name ORDER BY timestamp DESC)` (`snapshot.ts:134-140`), so their - // value is taken from the document's newest row and a null from the lag - // disappears as soon as any later row lands. `old_data`, `path_params` and a - // custom partition column are all in that set. `document_id` and - // `timestamp` are not, which is why neither is listed. + // The columns above are not free either, so this is a trade-off rather than + // a clean line. `document_id` is the one of them the default latest view + // does not wrap in `FIRST_VALUE`: the legacy query selects it raw and then + // groups on it (`snapshot.ts:133` and `:150`), so a row that lands with it + // null forms its own group and the document appears twice in `_latest`. The + // changelog is append-only, so a later write does not clear the duplicate. + // `old_data` and `path_params` are wrapped (`snapshot.ts:134-140`), and a + // null there is simply replaced by the newest row's value. + // + // Tolerating the drop is still the better trade, because the duplication is + // not new. `document_id` is added to an existing table as a schema change + // and nothing backfills it, so on exactly the tables this lag can affect + // every pre-upgrade row is already null, and every document written both + // before and after the upgrade already appears twice in the legacy view, + // permanently. The lag adds a handful of rows to a set that is already + // there. Losing the event has no such floor: the caller's retries are + // finite and nothing reconciles the schema afterwards, so the change never + // reaches BigQuery at all. + // + // `timestamp` is wrapped like the rest, so its exclusion above is not a view + // concern; it is excluded for being the partition and ordering key. A custom + // partition column is not in the view at all, since the view is built from + // `RawChangelogViewSchema` rather than the live table's fields. const partitionColumn = this.partitioningConfig.getBigQueryColumnName(); if ( From 1143acef6cc1c02c6f534bef7e433dd941b48d34 Mon Sep 17 00:00:00 2001 From: Izaak Gough Date: Wed, 12 Aug 2026 19:32:58 +0100 Subject: [PATCH 15/21] fix(firestore-bigquery-export): back up the row the caller built A schema-lag retry recursed with the reduced payload, so `rows` at the terminal level was already missing whatever an earlier retry had stripped, and that is what reached the backup collection. BigQuery names one unknown field per row, so a strip followed by a terminal rejection for a different column is the ordinary case rather than a corner, and the backup is the only record of the row. `rows` now stays as the caller built it for the whole chain and the columns are removed at the insert call instead, so the reduction applies to the payload only. Nothing else needed to change, since the accumulated list was already threaded through the recursion. --- .../node_modules | 1 + .../__tests__/bigquery/insertRetry.test.ts | 28 +++++++++++++++++++ .../src/bigquery/index.ts | 19 +++++++++---- 3 files changed, 43 insertions(+), 5 deletions(-) create mode 120000 firestore-bigquery-export/firestore-bigquery-change-tracker/node_modules diff --git a/firestore-bigquery-export/firestore-bigquery-change-tracker/node_modules b/firestore-bigquery-export/firestore-bigquery-change-tracker/node_modules new file mode 120000 index 000000000..65c347c06 --- /dev/null +++ b/firestore-bigquery-export/firestore-bigquery-change-tracker/node_modules @@ -0,0 +1 @@ +/Users/izaak/invertase/extensions/firestore-bigquery-export/firestore-bigquery-change-tracker/node_modules \ No newline at end of file diff --git a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts index 28f9c2967..7b1a670b1 100644 --- a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts +++ b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts @@ -316,6 +316,34 @@ describe("insertData retry behaviour", () => { expect(tracker._initialized).toBe(false); }); + it("backs up the row the caller gave us, not the one the retry reduced", async () => { + // BigQuery names one unknown field per row, so a lag strip is routinely + // followed by a terminal rejection naming a different column. The backup + // is the only record of that row, so it must not be missing the column an + // earlier retry removed from the payload. + const insert = jest + .fn() + .mockRejectedValueOnce( + partialFailure([{ message: "no such field: document_id." }]) + ) + .mockRejectedValueOnce( + partialFailure([{ message: "no such field: injected_col." }]) + ); + + await expect(insertData(trackerWith(insert))).rejects.toThrow( + "insert failed" + ); + + // Without this the assertion below could pass against an implementation + // that never stripped anything in the first place. + expect(payloadOf(insert, 1)).not.toHaveProperty("document_id"); + expect(handleFailedTransactionsMock).toHaveBeenCalledWith( + ROWS, + expect.anything(), + expect.anything() + ); + }); + it("does not match a column that merely contains an allowlisted name", async () => { // A user column named document_id_v2 must not be mistaken for // document_id, or its contents would be silently dropped. diff --git a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts index 8be6748c6..9eece62f2 100644 --- a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts +++ b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts @@ -131,6 +131,9 @@ function withoutColumns( rows: bigquery.RowMetadata[], columns: string[] ): bigquery.RowMetadata[] { + // The ordinary insert strips nothing, so leave it its own rows. + if (!columns.length) return rows; + return rows.map((row) => { if (!row?.json) return row; @@ -408,13 +411,19 @@ export class FirestoreBigQueryEventHistoryTracker /** * Inserts rows of data into the BigQuery raw change log table. + * + * `rows` stays as the caller built it for the whole retry chain. A schema-lag + * retry narrows only the payload sent to BigQuery, so the backup written on + * the terminal path still holds every column, including any an earlier retry + * had to remove. */ private async insertData( rows: bigquery.RowMetadata[], overrideOptions: InsertRowsOptions = {}, - // Columns a schema-lag retry has already removed. Each retry must remove at - // least one column BigQuery has not named before, so this layer is bounded - // at one attempt per column in `columnsAddedToExistingTables`, plus one. + // Columns a schema-lag retry has already removed from the payload. Each + // retry must remove at least one column BigQuery has not named before, so + // this layer is bounded at one attempt per column in + // `columnsAddedToExistingTables`, plus one. strippedColumns: string[] = [], // Tracked separately from the above, so a transient blip on the first // attempt cannot consume the retry a schema lag on a later attempt needs. @@ -431,7 +440,7 @@ export class FirestoreBigQueryEventHistoryTracker const table = dataset.table(this.rawChangeLogTableName()); logs.dataInserting(rows.length); - await table.insert(rows, options); + await table.insert(withoutColumns(rows, strippedColumns), options); logs.dataInserted(rows.length); } catch (e) { // A column we just added may not be streamable yet. Remove the columns @@ -450,7 +459,7 @@ export class FirestoreBigQueryEventHistoryTracker if (lagColumns.length) { logs.dataInsertRetriedWithoutColumns(rows.length, lagColumns); return this.insertData( - withoutColumns(rows, lagColumns), + rows, overrideOptions, [...strippedColumns, ...lagColumns], allowTransientRetry From 02ec2fe7435de79c663b9edb2d8375054158fb58 Mon Sep 17 00:00:00 2001 From: Izaak Gough Date: Wed, 12 Aug 2026 19:42:39 +0100 Subject: [PATCH 16/21] fix(firestore-bigquery-export): record the reason when an entry has no message Three small defects in the backup writer, all found by the review of 05af747c. A `stopped` entry carries an empty message and an empty location, so `reason` is the only field identifying it, and a failure whose entries are all `stopped` recorded nothing but the error's class name. The reason is now used when the message is empty. `truncate` ran after the `(+N more)` marker was appended, so the count could be the part that got cut off. The messages are truncated instead, leaving room for the marker, and the result still fits the cap. `describeError` read `.message` outside its `try`, so a throwing getter escaped into the caller's catch block and was reported as a failed backup. The whole body is guarded now, which is what its commit message already claimed. --- .../__tests__/bigquery/backupSettings.test.ts | 48 ++++++++++++++++- .../src/bigquery/handleFailedTransactions.ts | 54 +++++++++++++------ 2 files changed, 83 insertions(+), 19 deletions(-) diff --git a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/backupSettings.test.ts b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/backupSettings.test.ts index 19c57ac9d..f3f4d8aeb 100644 --- a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/backupSettings.test.ts +++ b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/backupSettings.test.ts @@ -187,8 +187,12 @@ describe("handleFailedTransactions error details", () => { ) ); - expect(details).toHaveLength(1000); - expect(details.endsWith("...")).toBe(true); + // The count is the part an operator needs most when the messages are too + // long to keep, so it must survive the truncation rather than be cut off + // by it. The cap still holds. + expect(details.length).toBeLessThanOrEqual(1000); + expect(details.endsWith(" (+4 more)")).toBe(true); + expect(details).toContain("..."); const short = await detailsFor( partialFailure( @@ -201,6 +205,46 @@ describe("handleFailedTransactions error details", () => { expect(short).toBe("field 0; field 1; field 2; field 3; field 4 (+3 more)"); }); + it("falls back to the reason when an entry carries no message", async () => { + // A `stopped` entry, the row BigQuery did not attempt, arrives with an + // empty message and an empty location, so the reason is all there is. A + // batch rejected entirely this way used to record only the class name. + const details = await detailsFor( + partialFailure([ + { errors: [{ message: "", location: "", reason: "stopped" }] }, + { errors: [{ message: "", location: "", reason: "stopped" }] }, + ]) + ); + + expect(details).toBe("stopped"); + }); + + it("prefers an entry's message over its reason", async () => { + const details = await detailsFor( + partialFailure([ + { + errors: [ + { message: "no such field: document_id.", reason: "invalid" }, + ], + }, + ]) + ); + + expect(details).toBe("no such field: document_id."); + }); + + it("survives an error whose message getter throws", async () => { + // Nothing here may throw: this runs inside the caller's catch block, so an + // escape is reported as a failed backup and the row is lost. + const hostile = { + get message(): string { + throw new Error("hostile getter"); + }, + }; + + await expect(detailsFor(hostile)).resolves.toBe("Unknown error"); + }); + it("prefers a populated top-level message over the nested ones", async () => { const details = await detailsFor( Object.assign(new Error("quota exceeded"), { diff --git a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/handleFailedTransactions.ts b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/handleFailedTransactions.ts index 290eafed8..9b17cf045 100644 --- a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/handleFailedTransactions.ts +++ b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/handleFailedTransactions.ts @@ -41,10 +41,11 @@ const MAX_ERROR_MESSAGES = 5; /** Cap, so one bad insert cannot write an unbounded Firestore field. */ const MAX_ERROR_DETAILS_LENGTH = 1000; -function truncate(value: string): string { - return value.length > MAX_ERROR_DETAILS_LENGTH - ? `${value.slice(0, MAX_ERROR_DETAILS_LENGTH - 3)}...` - : value; +function truncate( + value: string, + limit: number = MAX_ERROR_DETAILS_LENGTH +): string { + return value.length > limit ? `${value.slice(0, limit - 3)}...` : value; } /** @@ -71,6 +72,17 @@ function nestedErrorMessages(e: unknown): string { if (typeof message === "string" && message.length > 0) { messages.add(message); + continue; + } + + // A `stopped` entry, the row BigQuery did not attempt, carries an empty + // `message` and an empty `location`, so `reason` is the only field that + // identifies it. Without this a failure whose entries are all `stopped` + // recorded nothing but the error's class name. + const reason = (entry as any)?.reason; + + if (typeof reason === "string" && reason.length > 0) { + messages.add(reason); } } } @@ -80,10 +92,14 @@ function nestedErrorMessages(e: unknown): string { const all = Array.from(messages); const shown = all.slice(0, MAX_ERROR_MESSAGES); const remaining = all.length - shown.length; - - return remaining > 0 - ? `${shown.join("; ")} (+${remaining} more)` - : shown.join("; "); + const suffix = remaining > 0 ? ` (+${remaining} more)` : ""; + + // Truncating the messages rather than the finished string, so the count is + // not the part that gets cut off. The result still fits the cap. + return `${truncate( + shown.join("; "), + MAX_ERROR_DETAILS_LENGTH - suffix.length + )}${suffix}`; } /** @@ -103,20 +119,24 @@ function nestedErrorMessages(e: unknown): string { * because it falls back on null and undefined but not on "". */ function describeError(e: unknown): string { - const message = (e as any)?.message; + // The whole body is guarded, not just `String(e)`, so that reading `.message` + // off a value with a throwing getter cannot escape either. + try { + const message = (e as any)?.message; - if (typeof message === "string" && message.length > 0) { - return truncate(message); - } + if (typeof message === "string" && message.length > 0) { + return truncate(message); + } - const nested = nestedErrorMessages(e); + // Already capped, so it is not truncated a second time here. + const nested = nestedErrorMessages(e); - if (nested.length > 0) return truncate(nested); + if (nested.length > 0) return nested; - try { return truncate(String(e)); - } catch (stringifyError) { - // A value whose `toString` throws, or an object with a null prototype. + } catch (describeFailure) { + // A value whose `toString` or `message` throws, or an object with a null + // prototype. return "Unknown error"; } } From 95636723b3491229b89dc541806664d01574f24e Mon Sep 17 00:00:00 2001 From: Izaak Gough Date: Wed, 12 Aug 2026 21:29:04 +0100 Subject: [PATCH 17/21] test(firestore-bigquery-export): build a changelog table that only lacks old_data The e2e case for adding `old_data` created its table with a single unrelated `Name` column, so the insert was rejected for the five base changelog columns that were missing as well. It passed only because every insert failure used to be retried with `ignoreUnknownValues`, which discarded them and reported success. Those columns are never added to a table that already exists, so the insert now fails closed and the test failed with it. The table is now a valid changelog that predates `old_data`, which is what the test is named for. The column is added during initialize and the insert lands. --- .../src/__tests__/bigquery/e2e.test.ts | 16 ++++++++++++++-- 1 file changed, 14 insertions(+), 2 deletions(-) diff --git a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/e2e.test.ts b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/e2e.test.ts index a17fa7414..52eb8bc94 100644 --- a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/e2e.test.ts +++ b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/e2e.test.ts @@ -798,8 +798,20 @@ describe("e2e", () => { test("successfully adds old data field if it does not yet exist", async () => { const event: FirestoreDocumentChangeEvent = changeTrackerEvent({}); - /** Create a table without an old_data column */ - let schema = [{ name: "Name", type: "STRING" }]; + /** + * Create a table that is a valid changelog in every respect except that + * it predates `old_data`, which is the case this test is about. + * + * It used to be created with a single unrelated `Name` column, so the + * insert was rejected for the five base columns that were missing too. + * That passed only because every insert failure was retried with + * `ignoreUnknownValues`, which discarded them and reported success. + * Those columns are never added to a table that already exists, so the + * insert now fails closed rather than dropping the row's contents. + */ + let schema = RawChangelogSchema.fields.filter( + (field) => field.name !== "old_data" + ); let [originalRawTable] = await dataset.createTable(table_raw_changelog, { schema, From d44b8e3f53a615369d8a2d299e45e200480a01fd Mon Sep 17 00:00:00 2001 From: Izaak Gough Date: Wed, 12 Aug 2026 22:08:06 +0100 Subject: [PATCH 18/21] fix(firestore-bigquery-export): stop allowlisting the custom partition column The column is added by `addPartitioningToSchema`, which only runs when `tableRequiresUpdate` is true, and that is false for a table which is already time-partitioned. So an operator moving such a table to field partitioning gets a column that is never added, and allowlisting it meant every insert stripped it and reported success, permanently. That is the exactness failure the docstring warns about. Little is lost by excluding it: the value comes from a document field that `data` already carries, and an existing table cannot be repartitioned anyway. The lag retry also now clears `_initialized`. Stripping is only safe while the column exists and BigQuery has not caught up, and nothing distinguishes that from a column that was really dropped. Re-running initialize on the next batch bounds the mistake to one batch instead of the life of the instance. The comment about which columns a null heals in was wrong for the standard view syntax. Only `event_id`, `data` and `old_data` are safe under both: the standard view wraps just those and groups on everything else, so `path_params` costs a duplicate row there exactly as `document_id` does. The trade is unchanged. --- .../__tests__/bigquery/insertRetry.test.ts | 42 +++++++-- .../src/bigquery/index.ts | 91 +++++++++---------- 2 files changed, 78 insertions(+), 55 deletions(-) diff --git a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts index 7b1a670b1..8fdb51872 100644 --- a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts +++ b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts @@ -344,6 +344,27 @@ describe("insertData retry behaviour", () => { ); }); + it("clears initialization so a column that is really gone comes back", async () => { + // Stripping is only safe while the column exists and BigQuery has not + // caught up. Nothing here can tell that case from a column that was + // actually dropped, so the next batch must re-run initialize. Otherwise a + // warm instance strips it for its whole life and reports success. + const insert = jest + .fn() + .mockRejectedValueOnce( + partialFailure([{ message: "no such field: old_data." }]) + ) + .mockResolvedValueOnce(undefined); + + const tracker = trackerWith(insert); + tracker._initialized = true; + + await expect(insertData(tracker)).resolves.toBeUndefined(); + + expect(insert).toHaveBeenCalledTimes(2); + expect(tracker._initialized).toBe(false); + }); + it("does not match a column that merely contains an allowlisted name", async () => { // A user column named document_id_v2 must not be mistaken for // document_id, or its contents would be silently dropped. @@ -465,8 +486,6 @@ describe("insertData retry behaviour", () => { }); describe("the user-configured partition column", () => { - // addPartitioningToSchema adds this column to an existing table too, so it - // has the same exposure as the base columns above. const partitioned = { partitioning: { granularity: "HOUR", @@ -476,22 +495,27 @@ describe("insertData retry behaviour", () => { }, } as Partial; - it("is treated as schema lag when field partitioning is configured", async () => { + it("is not allowlisted, even under the strategy that adds it", async () => { + // It is added only when `tableRequiresUpdate` is true, and that is false + // for a table which is already time-partitioned. So on exactly that table + // the column is never added, and allowlisting it would strip it from + // every row and report success, forever. Failing is recoverable, and + // little is lost either way: the value comes from a document field that + // `data` already carries. const insert = jest .fn() - .mockRejectedValueOnce( + .mockRejectedValue( partialFailure([ { message: "no such field.", location: "created_at" }, ]) - ) - .mockResolvedValueOnce(undefined); + ); await expect( insertData(trackerWith(insert, partitioned)) - ).resolves.toBeUndefined(); + ).rejects.toThrow("insert failed"); - expect(insert).toHaveBeenCalledTimes(2); - expect(payloadOf(insert, 1)).not.toHaveProperty("created_at"); + expect(insert).toHaveBeenCalledTimes(1); + expect(handleFailedTransactionsMock).toHaveBeenCalledTimes(1); }); it("is not allowlisted when no partitioning is configured", async () => { diff --git a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts index 9eece62f2..d869148a3 100644 --- a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts +++ b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts @@ -295,10 +295,10 @@ export class FirestoreBigQueryEventHistoryTracker * column exposed to the lag. * * Every column added belongs here unless dropping it would cost more than - * losing the event, and `timestamp` below is the only one that does. Omitting - * a column turns a row that lands today, with that column null, into an event - * lost once the caller exhausts its retries, because nothing on the write - * path reconciles the schema. + * losing the event, or it is not reliably added at all. Both exceptions are + * below. Omitting a column turns a row that lands today, with that column + * null, into an event lost once the caller exhausts its retries, because + * nothing on the write path reconciles the schema. * * It must also stay exact. Listing a column that is never added makes the * retry drop that column's value on a table missing it, forever. @@ -315,53 +315,44 @@ export class FirestoreBigQueryEventHistoryTracker columns.push(documentPathParams.name); } - // The partition column is also added to an existing table, so it shares the - // same exposure. Only the Firestore field strategy is listed. The Firestore - // timestamp strategy is excluded by construction, since its column is - // always `timestamp`, which the collision check below would reject anyway. + // The custom partition column is deliberately absent, though it is added to + // an existing table under the Firestore field strategy. It is added only + // when `tableRequiresUpdate` returns true, and that returns false for a + // table which is already time-partitioned + // (`checkUpdates.ts:39-44` via `isValidPartitionForExistingTable`, which is + // `!isPartitioned`). So an operator moving an already-partitioned table to + // field partitioning gets a column that is never added, and listing it here + // would make every insert strip it and report success, forever. That is the + // exactness failure this docstring warns about. `timestamp` is excluded + // too, for being the partition and ordering key: a silent null there + // misfiles the row for good, where a failure the caller can retry does not. // - // Both exclusions are a judgement call, not dead code: `addPartitioningToSchema` - // is called with the live table's fields, so its early return only fires - // when the table already has the column. On a table missing `timestamp` the - // column really is added, as NULLABLE. But `timestamp` is the ordering key - // for the latest view as well as the partition key, so tolerating the drop - // would silently misfile every affected row for good. Failing instead - // writes a backup row and throws, which the caller can retry. The same goes - // for a field strategy pointed at any other base column, `data` say. + // Little is lost by excluding it. The value is derived from a field of the + // document, which is serialised whole into `data` (`:200`, and `old_data` + // for a delete), so the row still carries it. And `Partitioning` refuses to + // repartition an existing table anyway, so the column has nowhere to go. // // The columns above are not free either, so this is a trade-off rather than - // a clean line. `document_id` is the one of them the default latest view - // does not wrap in `FIRST_VALUE`: the legacy query selects it raw and then - // groups on it (`snapshot.ts:133` and `:150`), so a row that lands with it - // null forms its own group and the document appears twice in `_latest`. The - // changelog is append-only, so a later write does not clear the duplicate. - // `old_data` and `path_params` are wrapped (`snapshot.ts:134-140`), and a - // null there is simply replaced by the newest row's value. + // a clean line. A null in a column the latest view groups on makes that row + // its own group, so the document appears twice in `_latest`, and the + // changelog is append-only so a later write does not clear the duplicate. + // Which columns those are depends on the view syntax, and only `event_id`, + // `data` and `old_data` are safe under both. The legacy view groups on + // `document_name` and `document_id` and wraps everything else in + // `FIRST_VALUE` (`snapshot.ts:126-152`). The standard view wraps only + // `nonGroupFields`, in `ANY_VALUE`, and groups on everything else, + // `path_params` and `timestamp` included (`snapshot.ts:174-194`). So + // `document_id` costs a duplicate on either, and `path_params` costs one on + // the standard syntax. // - // Tolerating the drop is still the better trade, because the duplication is - // not new. `document_id` is added to an existing table as a schema change - // and nothing backfills it, so on exactly the tables this lag can affect + // Tolerating that is still the better trade, because the duplication is not + // new. These columns are added to an existing table as a schema change with + // nothing backfilling them, so on exactly the tables this lag can affect // every pre-upgrade row is already null, and every document written both - // before and after the upgrade already appears twice in the legacy view, - // permanently. The lag adds a handful of rows to a set that is already - // there. Losing the event has no such floor: the caller's retries are - // finite and nothing reconciles the schema afterwards, so the change never - // reaches BigQuery at all. - // - // `timestamp` is wrapped like the rest, so its exclusion above is not a view - // concern; it is excluded for being the partition and ordering key. A custom - // partition column is not in the view at all, since the view is built from - // `RawChangelogViewSchema` rather than the live table's fields. - const partitionColumn = this.partitioningConfig.getBigQueryColumnName(); - - if ( - partitionColumn && - this.partitioningConfig.isFirestoreFieldPartitioning() && - !RawChangelogSchema.fields.some((field) => field.name === partitionColumn) - ) { - columns.push(partitionColumn); - } - + // before and after the upgrade already appears twice. The lag adds a + // handful of rows to a set that is already there. Losing the event has no + // such floor: the caller's retries are finite and nothing reconciles the + // schema afterwards, so the change never reaches BigQuery at all. return columns; } @@ -458,6 +449,14 @@ export class FirestoreBigQueryEventHistoryTracker if (lagColumns.length) { logs.dataInsertRetriedWithoutColumns(rows.length, lagColumns); + + // The whole case for stripping a column is that it exists and BigQuery + // has not caught up yet. When that is wrong, and the column really is + // gone, nothing here notices. Clearing this makes the next batch run + // `initialize` and add it back, so a mistaken lag costs one batch + // rather than the life of the instance. + this._initialized = false; + return this.insertData( rows, overrideOptions, From 48578a13cbadb72104d04fe88ba06db6bb792804 Mon Sep 17 00:00:00 2001 From: Izaak Gough Date: Thu, 13 Aug 2026 10:52:42 +0100 Subject: [PATCH 19/21] chore: drop accidentally committed node_modules symlink --- .../firestore-bigquery-change-tracker/node_modules | 1 - 1 file changed, 1 deletion(-) delete mode 120000 firestore-bigquery-export/firestore-bigquery-change-tracker/node_modules diff --git a/firestore-bigquery-export/firestore-bigquery-change-tracker/node_modules b/firestore-bigquery-export/firestore-bigquery-change-tracker/node_modules deleted file mode 120000 index 65c347c06..000000000 --- a/firestore-bigquery-export/firestore-bigquery-change-tracker/node_modules +++ /dev/null @@ -1 +0,0 @@ -/Users/izaak/invertase/extensions/firestore-bigquery-export/firestore-bigquery-change-tracker/node_modules \ No newline at end of file From 50cf12212b9bf107d04da0666ddef17b77400741 Mon Sep 17 00:00:00 2001 From: Izaak Gough Date: Thu, 13 Aug 2026 11:06:47 +0100 Subject: [PATCH 20/21] docs(firestore-bigquery-export): trim the comments on the insert retry Cut the bug narration, the line-number references, and the trade-off essays, keeping the constraints a reader cannot get from the code. --- .../__tests__/bigquery/backupSettings.test.ts | 48 ++---- .../src/__tests__/bigquery/e2e.test.ts | 13 +- .../__tests__/bigquery/insertRetry.test.ts | 133 +++++---------- .../src/bigquery/handleFailedTransactions.ts | 47 ++---- .../src/bigquery/index.ts | 154 ++++++------------ .../src/logs.ts | 12 +- 6 files changed, 126 insertions(+), 281 deletions(-) diff --git a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/backupSettings.test.ts b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/backupSettings.test.ts index f3f4d8aeb..19220ce30 100644 --- a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/backupSettings.test.ts +++ b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/backupSettings.test.ts @@ -26,9 +26,8 @@ const collection = jest.fn(() => ({ doc: (id: string) => ({ id }) })); jest.mock("firebase-admin", () => ({ apps: [{}] })); jest.mock("firebase-admin/app", () => ({ initializeApp: jest.fn() })); jest.mock("firebase-admin/firestore", () => ({ - // A fresh object per call, deliberately: the guard must key on the database - // id rather than on instance identity, so this would catch a guard that - // relied on getting the same object back. + // A fresh object per call, deliberately: the guard must key on the database id + // rather than on instance identity. getFirestore: jest.fn(() => ({ settings, batch, collection })), })); @@ -56,9 +55,6 @@ describe("handleFailedTransactions Firestore settings", () => { }); it("applies settings once across repeated failures", async () => { - // `settings()` may only be called once per instance, and only before the - // instance is used. Calling it on every batch threw on every call after the - // first, so only one failure per function instance was ever backed up. const handler = loadHandler(); await handler(ROWS, config, new Error("insert failed")); @@ -69,8 +65,6 @@ describe("handleFailedTransactions Firestore settings", () => { }); it("still writes the backup when settings cannot be applied", async () => { - // Another part of the process may have reached the instance first. That - // costs `ignoreUndefinedProperties`, not the backup itself. settings.mockImplementation(() => { throw new Error("Firestore has already been initialized"); }); @@ -85,11 +79,7 @@ describe("handleFailedTransactions Firestore settings", () => { }); it("still writes the backup when the thrown value is not an Error", async () => { - // `insertData` reports whatever it caught, so this reaches the handler. - // Reading `.message` off it threw a TypeError, which the caller reported as - // a failed backup, so nothing was written for the very failures where the - // row is least recoverable from elsewhere. The retry suite could not catch - // this: it mocks this module, so it only proves the call site was reached. + // `insertData` reports whatever it caught, so a non-Error reaches here. const handler = loadHandler(); await expect( @@ -117,10 +107,9 @@ describe("handleFailedTransactions Firestore settings", () => { }); /** - * A stand-in for `@google-cloud/bigquery`'s `PartialFailureError`, built the - * same way: one entry per failed row, each nesting the per-field errors, and a - * top-level `message` that `@google-cloud/common` leaves empty because those - * entries carry no `message` of their own. + * A stand-in for `@google-cloud/bigquery`'s `PartialFailureError`: one entry per + * failed row nesting the per-field errors, and the empty top-level `message` + * that `@google-cloud/common` builds from entries carrying none. */ const partialFailure = (groups: any[]) => Object.assign(new Error(""), { name: "PartialFailureError", errors: groups }); @@ -142,10 +131,7 @@ describe("handleFailedTransactions error details", () => { }; it("records the nested per-field messages when the top-level message is empty", async () => { - // The observed failure. `PartialFailureError.message` is "", and `??` only - // falls back on null and undefined, so every backup document written for a - // real rejected insert recorded an empty string and told the operator - // nothing about why the row failed. + // The shape a real rejected insert arrives in. const details = await detailsFor( partialFailure([ { @@ -161,8 +147,6 @@ describe("handleFailedTransactions error details", () => { }); it("deduplicates messages shared across failed rows", async () => { - // A batch normally fails the same way for every row, so repeating one - // message 500 times would push out the detail that differs. const details = await detailsFor( partialFailure([ { errors: [{ message: "no such field: document_id." }] }, @@ -177,8 +161,6 @@ describe("handleFailedTransactions error details", () => { }); it("caps the number of messages and the total length", async () => { - // `error_details` is a Firestore field, so it must not grow with the - // number of distinct failures in the batch. const details = await detailsFor( partialFailure( Array.from({ length: 9 }, (_, i) => ({ @@ -187,9 +169,7 @@ describe("handleFailedTransactions error details", () => { ) ); - // The count is the part an operator needs most when the messages are too - // long to keep, so it must survive the truncation rather than be cut off - // by it. The cap still holds. + // The count must survive the truncation rather than be cut off by it. expect(details.length).toBeLessThanOrEqual(1000); expect(details.endsWith(" (+4 more)")).toBe(true); expect(details).toContain("..."); @@ -206,9 +186,8 @@ describe("handleFailedTransactions error details", () => { }); it("falls back to the reason when an entry carries no message", async () => { - // A `stopped` entry, the row BigQuery did not attempt, arrives with an - // empty message and an empty location, so the reason is all there is. A - // batch rejected entirely this way used to record only the class name. + // A `stopped` entry, the row BigQuery did not attempt, arrives with an empty + // message and an empty location, so the reason is all there is. const details = await detailsFor( partialFailure([ { errors: [{ message: "", location: "", reason: "stopped" }] }, @@ -234,8 +213,6 @@ describe("handleFailedTransactions error details", () => { }); it("survives an error whose message getter throws", async () => { - // Nothing here may throw: this runs inside the caller's catch block, so an - // escape is reported as a failed backup and the row is lost. const hostile = { get message(): string { throw new Error("hostile getter"); @@ -256,9 +233,8 @@ describe("handleFailedTransactions error details", () => { }); it("still writes a string for every malformed shape of `errors`", async () => { - // This runs inside the caller's catch block: anything thrown here is - // reported as a failed backup and the row is lost, so no shape of the - // caught value may throw. + // The handler runs inside the caller's catch block, so a throw here is + // reported as a failed backup and the row is lost. const shapes: any[] = [ partialFailure([]), Object.assign(new Error(""), { errors: "not an array" }), diff --git a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/e2e.test.ts b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/e2e.test.ts index 1dc38260f..6c1642411 100644 --- a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/e2e.test.ts +++ b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/e2e.test.ts @@ -815,15 +815,10 @@ describe("e2e", () => { const event: FirestoreDocumentChangeEvent = changeTrackerEvent({}); /** - * Create a table that is a valid changelog in every respect except that - * it predates `old_data`, which is the case this test is about. - * - * It used to be created with a single unrelated `Name` column, so the - * insert was rejected for the five base columns that were missing too. - * That passed only because every insert failure was retried with - * `ignoreUnknownValues`, which discarded them and reported success. - * Those columns are never added to a table that already exists, so the - * insert now fails closed rather than dropping the row's contents. + * A valid changelog in every respect except that it predates `old_data`, + * which is the case this test is about. The base columns are never added + * to a table that already exists, so a table missing those as well would + * fail the insert outright rather than exercise the lag retry. */ let schema = RawChangelogSchema.fields.filter( (field) => field.name !== "old_data" diff --git a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts index 8fdb51872..49b369b63 100644 --- a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts +++ b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts @@ -44,16 +44,14 @@ const config = ( } as ChangeTrackerConfig); /** - * Builds the error shape `@google-cloud/bigquery` actually throws: a - * `PartialFailureError` whose `response` is the raw `insertAll` body, where - * `insertErrors` is an array. Its own `errors` property is the remapped copy - * that drops `location`. + * The error shape `@google-cloud/bigquery` actually throws: `response` is the raw + * `insertAll` body, where `insertErrors` is an array, and the error's own + * `errors` is the remapped copy that drops `location`. */ function partialFailure( fieldErrors: Array<{ message: string; location?: string; reason?: string }> ) { - // BigQuery always sets a reason on these entries, so default it rather than - // leaving it undefined: classification reads it. + // BigQuery always sets a reason on these entries, and classification reads it. const entries = fieldErrors.map((fieldError) => ({ reason: "invalid", ...fieldError, @@ -82,9 +80,8 @@ function transportFailure() { } /** - * Deliberately carries every column the allowlist can name, so that asserting a - * column was removed from a retry is a real assertion rather than one that - * passes because the key was never there. + * Carries every column the allowlist can name, so that asserting one was removed + * cannot pass because the key was never there. */ const ROWS = [ { @@ -146,13 +143,10 @@ describe("insertData retry behaviour", () => { expect(insert).toHaveBeenCalledTimes(2); expect(payloadOf(insert, 0)).toHaveProperty("document_id"); expect(payloadOf(insert, 1)).not.toHaveProperty("document_id"); - // Everything else must survive: only what BigQuery named is dropped. expect(payloadOf(insert, 1)).toMatchObject({ event_id: "e1", data: "{}", }); - // Never ignoreUnknownValues, which would also discard fields BigQuery did - // not name. expect(insert.mock.calls[1][1]).toMatchObject({ ignoreUnknownValues: false, }); @@ -176,11 +170,8 @@ describe("insertData retry behaviour", () => { }); it("does not ignore an unknown field BigQuery did not name", async () => { - // A live instance reports one unknown field per row, not all of them. So - // a table missing `document_id` while a transform has injected a stray - // key surfaces as a rejection naming only `document_id`. Retrying with - // ignoreUnknownValues would have discarded the stray key too, silently, - // which is the loss this whole change exists to prevent. + // BigQuery names one unknown field per row, so a stray key alongside a + // lagging column only surfaces on the retry. const insert = jest .fn() .mockRejectedValueOnce( @@ -198,8 +189,6 @@ describe("insertData retry behaviour", () => { expect(insert).toHaveBeenCalledTimes(2); expect(payloadOf(insert, 1)).not.toHaveProperty("document_id"); - // Terminal, so the row reaches the backup with the stray key intact - // rather than being dropped and reported as a success. expect(handleFailedTransactionsMock).toHaveBeenCalledTimes(1); }); @@ -226,14 +215,9 @@ describe("insertData retry behaviour", () => { }); it("ignores stopped rows when recognising the lag", async () => { - // With skipInvalidRows false BigQuery rejects the whole request and marks - // the rows it did not attempt as `stopped`. Those entries say nothing - // about the schema. Treating them as unattributable meant no multi-row - // batch could ever be recognised as lag, which `scripts/import` hits - // because it records batches rather than single events. - // - // The empty message and location are the shape a live instance sends, so - // `reason` is the only thing that identifies this entry. + // With `skipInvalidRows` false BigQuery marks the rows it did not attempt + // as `stopped`, with the empty message and location a live instance sends, + // so `reason` is the only thing identifying the entry. const insert = jest .fn() .mockRejectedValueOnce( @@ -280,8 +264,8 @@ describe("insertData retry behaviour", () => { }); it("gives up when a retry makes no progress", async () => { - // The same column rejected twice means removing it did not help, so there - // is nothing further to try. Without this the recursion never ends. + // Bounds the recursion: the same column rejected twice means removing it + // did not help. const insert = jest .fn() .mockRejectedValue( @@ -306,7 +290,7 @@ describe("insertData retry behaviour", () => { const tracker = trackerWith(insert, { wildcardIds: true }); // Must start true, or asserting false below passes against an - // implementation that never clears the flag at all. + // implementation that never clears the flag. tracker._initialized = true; await expect(insertData(tracker)).rejects.toThrow("insert failed"); @@ -317,10 +301,8 @@ describe("insertData retry behaviour", () => { }); it("backs up the row the caller gave us, not the one the retry reduced", async () => { - // BigQuery names one unknown field per row, so a lag strip is routinely - // followed by a terminal rejection naming a different column. The backup - // is the only record of that row, so it must not be missing the column an - // earlier retry removed from the payload. + // A strip followed by a terminal rejection for a different column is the + // ordinary case, and the backup is the only record of the row. const insert = jest .fn() .mockRejectedValueOnce( @@ -335,7 +317,7 @@ describe("insertData retry behaviour", () => { ); // Without this the assertion below could pass against an implementation - // that never stripped anything in the first place. + // that never stripped anything. expect(payloadOf(insert, 1)).not.toHaveProperty("document_id"); expect(handleFailedTransactionsMock).toHaveBeenCalledWith( ROWS, @@ -345,10 +327,8 @@ describe("insertData retry behaviour", () => { }); it("clears initialization so a column that is really gone comes back", async () => { - // Stripping is only safe while the column exists and BigQuery has not - // caught up. Nothing here can tell that case from a column that was - // actually dropped, so the next batch must re-run initialize. Otherwise a - // warm instance strips it for its whole life and reports success. + // Nothing here can tell a lagging column from one that was actually + // dropped, so a warm instance must not strip it for its whole life. const insert = jest .fn() .mockRejectedValueOnce( @@ -366,8 +346,6 @@ describe("insertData retry behaviour", () => { }); it("does not match a column that merely contains an allowlisted name", async () => { - // A user column named document_id_v2 must not be mistaken for - // document_id, or its contents would be silently dropped. const insert = jest .fn() .mockRejectedValue( @@ -381,9 +359,8 @@ describe("insertData retry behaviour", () => { expect(insert).toHaveBeenCalledTimes(1); }); - // `path_params` needs its own config: `initializeRawChangeLogTable` only - // adds that column, and `record` only emits the key, when wildcard ids are - // enabled. + // `path_params` needs its own config: the column is only added, and the key + // only emitted, when wildcard ids are enabled. const addedColumns: Array<[string, Partial]> = [ ["document_id", {}], ["old_data", {}], @@ -393,9 +370,6 @@ describe("insertData retry behaviour", () => { it.each(addedColumns)( "covers %s, every column added to an existing table", async (column, overrides) => { - // Dropping any of these from the allowlist would turn a row that lands - // today, with that column null, into an event lost once the caller - // exhausts its retries. const insert = jest .fn() .mockRejectedValueOnce( @@ -413,12 +387,8 @@ describe("insertData retry behaviour", () => { ); it("does not allowlist path_params when wildcard ids are disabled", async () => { - // Without wildcard ids the column is never created, so a rejected - // `path_params` is not our schema lag. `transformRows` hands the response - // of a user-supplied endpoint straight to the insert, so a transform can - // inject the key: allowlisting it there would discard whatever the - // transform put in it on every insert, forever, while still logging - // success. + // The column is never created here, but a transform function can still + // inject the key, since `transformRows` uses its response verbatim. const insert = jest .fn() .mockRejectedValue( @@ -496,12 +466,8 @@ describe("insertData retry behaviour", () => { } as Partial; it("is not allowlisted, even under the strategy that adds it", async () => { - // It is added only when `tableRequiresUpdate` is true, and that is false - // for a table which is already time-partitioned. So on exactly that table - // the column is never added, and allowlisting it would strip it from - // every row and report success, forever. Failing is recoverable, and - // little is lost either way: the value comes from a document field that - // `data` already carries. + // `tableRequiresUpdate` is false for a table that is already + // time-partitioned, so on exactly that table the column is never added. const insert = jest .fn() .mockRejectedValue( @@ -535,11 +501,9 @@ describe("insertData retry behaviour", () => { }); it("is not allowlisted under the Firestore timestamp strategy", async () => { - // That strategy partitions by the base `timestamp` column. On a table - // that lacks it the column really is added, so this is a deliberate - // choice rather than dead code: `timestamp` orders the latest view and - // keys the partition, so allowlisting it would silently misfile every - // affected row for good, where failing writes a backup row and throws. + // Excluded deliberately rather than for want of a code path: `timestamp` + // keys the partition and orders the latest view, so a null misfiles the + // row instead of costing an event the caller can retry. const insert = jest .fn() .mockRejectedValue( @@ -590,8 +554,6 @@ describe("insertData retry behaviour", () => { describe("a transient blip followed by a schema lag", () => { it("can still retry the schema lag", async () => { - // The two retries are tracked separately, so the blip must not consume - // the one the lag needs. Without that, the row is lost. const insert = jest .fn() .mockRejectedValueOnce(transportFailure()) @@ -632,9 +594,6 @@ describe("insertData retry behaviour", () => { describe("a schema lag followed by a transient blip", () => { it("can still retry the blip, and keeps the column stripped", async () => { - // The schema-lag retry must hand the transient retry on rather than - // spend it, and the rows it hands on must stay stripped. Losing either - // turns the blip into a lost row or a repeat of the same rejection. const insert = jest .fn() .mockRejectedValueOnce( @@ -657,9 +616,8 @@ describe("insertData retry behaviour", () => { describe("malformed failures", () => { it("survives a null entry in the errors array", async () => { - // Not producible by the current library, but classifying must never throw - // from inside the catch block: that would lose the real error and skip - // the backup entirely. + // Not producible by the current library, but classifying runs inside the + // catch block, where a throw loses the real error and skips the backup. const insert = jest.fn().mockRejectedValue({ message: "insert failed", response: { insertErrors: [{ index: 0, errors: [null] }] }, @@ -678,15 +636,13 @@ describe("insertData retry behaviour", () => { await expect(insertData(trackerWith(insert))).rejects.toBeUndefined(); - // This only shows the backup was reached, since the module is mocked - // here. That it actually writes a row for a non-Error is pinned in - // backupSettings.test.ts against the real handler. + // Only shows the backup was reached, since the module is mocked here. That + // it writes a row for a non-Error is pinned in backupSettings.test.ts. expect(handleFailedTransactionsMock).toHaveBeenCalledTimes(1); }); it("still reports the insert error when error logging hits a bad entry", async () => { - // `e.errors` is the library's remapped copy and is logged on the terminal - // path. A bad entry there must not replace the error the caller sees. + // `e.errors` is the remapped copy logged on the terminal path. const error: any = new Error("insert failed"); error.errors = [null]; error.response = { @@ -718,9 +674,8 @@ describe("insertData retry behaviour", () => { describe("transient failures", () => { it("retries a partial failure whose reasons are all retryable", async () => { - // A rate limit or backend error arrives as a partial failure, not as a - // bare transport error. Classifying it as terminal would send a batch - // BigQuery asked us to resend straight to the backup collection. + // A rate limit or backend error arrives as a partial failure rather than a + // bare transport error. const insert = jest .fn() .mockRejectedValueOnce( @@ -734,7 +689,6 @@ describe("insertData retry behaviour", () => { await expect(insertData(trackerWith(insert))).resolves.toBeUndefined(); expect(insert).toHaveBeenCalledTimes(2); - // Never with ignoreUnknownValues: nothing here says a column is unknown. expect(insert.mock.calls[1][1]).toMatchObject({ ignoreUnknownValues: false, }); @@ -758,7 +712,7 @@ describe("insertData retry behaviour", () => { }); it("does not retry a partial failure with no reason to judge", async () => { - // Fail closed: an entry we cannot classify is not evidence of a blip. + // Fails closed: an entry we cannot classify is not evidence of a blip. const insert = jest .fn() .mockRejectedValue( @@ -825,8 +779,6 @@ describe("insertData retry behaviour", () => { partialFailure([{ message: "no such field.", location: "user_age" }]) ); - // The caller needs the real cause to decide whether to retry, so the - // backup error must not replace it. await expect(insertData(trackerWith(insert))).rejects.toThrow( "insert failed" ); @@ -845,8 +797,8 @@ describe("insertData retry behaviour", () => { "insert failed" ); - // Regression guard: this failure never reaches a second attempt, so a - // backup condition keyed on "this is the second attempt" would skip it. + // This failure never reaches a second attempt, so a backup condition keyed + // on "this is the second attempt" would skip it. expect(insert).toHaveBeenCalledTimes(1); expect(handleFailedTransactionsMock).toHaveBeenCalledTimes(1); expect(handleFailedTransactionsMock).toHaveBeenCalledWith( @@ -872,8 +824,7 @@ describe("insertData retry behaviour", () => { }); it("warns rather than debugs when a retry drops columns", async () => { - // Debug is suppressed at the default log level, so an operator would - // have to already suspect the loss to see the only record of it. + // Debug is suppressed at the default log level. const insert = jest .fn() .mockRejectedValueOnce( @@ -898,7 +849,6 @@ describe("insertData retry behaviour", () => { }); it("names the columns it dropped", async () => { - // "a column was dropped" is not actionable. Which one is. const insert = jest .fn() .mockRejectedValueOnce( @@ -914,9 +864,8 @@ describe("insertData retry behaviour", () => { }); it("distinguishes the retry that drops columns from the one that does not", async () => { - // Only the schema-lag retry discards unknown columns. An operator - // investigating suspected column loss has nothing else to tell the two - // retries apart, so one message must not stand for both. + // Only one of the two retries drops columns, and the logs are the only + // thing telling an operator which one ran. const insert = jest .fn() .mockRejectedValueOnce( diff --git a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/handleFailedTransactions.ts b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/handleFailedTransactions.ts index 74eb426b8..45423cf4b 100644 --- a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/handleFailedTransactions.ts +++ b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/handleFailedTransactions.ts @@ -24,12 +24,8 @@ if (!admin.apps.length) { } /** - * Firestore instances whose `settings()` call has already been attempted. - * - * `getFirestore` returns one instance per database id, and `settings()` may only - * be called once on it, before it is used. Calling it on every failed batch - * therefore threw on every call after the first, so only the first failure in an - * instance's lifetime was ever backed up. + * `settings()` may only be called once per Firestore instance, and only before + * the instance is used, so it is attempted once per database id. */ const settingsApplied = new Set(); @@ -43,8 +39,7 @@ function backupFirestore(instanceId: string) { db.settings({ ignoreUndefinedProperties: true }); } catch (settingsError) { // Something else in the process reached this instance first. The backup - // still goes ahead, but an undefined value in a row will now throw from - // `set()` instead of being skipped. + // still goes ahead, without `ignoreUndefinedProperties`. } } @@ -66,11 +61,8 @@ function truncate( /** * The per-field messages a `PartialFailureError` nests under - * `errors[].errors[].message`, deduplicated and capped. - * - * One failure can name several rows, and each row several fields, but a whole - * batch usually fails the same way, so the distinct messages are what an - * operator needs. Returns `""` when there is nothing usable to report. + * `errors[].errors[].message`, deduplicated because a batch usually fails the + * same way for every row. `""` when there is nothing usable to report. */ function nestedErrorMessages(e: unknown): string { const groups = (e as any)?.errors; @@ -91,10 +83,8 @@ function nestedErrorMessages(e: unknown): string { continue; } - // A `stopped` entry, the row BigQuery did not attempt, carries an empty - // `message` and an empty `location`, so `reason` is the only field that - // identifies it. Without this a failure whose entries are all `stopped` - // recorded nothing but the error's class name. + // A `stopped` entry, the row BigQuery did not attempt, arrives with an + // empty `message` and an empty `location`, so `reason` is all there is. const reason = (entry as any)?.reason; if (typeof reason === "string" && reason.length > 0) { @@ -111,7 +101,7 @@ function nestedErrorMessages(e: unknown): string { const suffix = remaining > 0 ? ` (+${remaining} more)` : ""; // Truncating the messages rather than the finished string, so the count is - // not the part that gets cut off. The result still fits the cap. + // not the part that gets cut off. return `${truncate( shown.join("; "), MAX_ERROR_DETAILS_LENGTH - suffix.length @@ -121,22 +111,15 @@ function nestedErrorMessages(e: unknown): string { /** * A description of a failed insert that an operator can act on. * - * The caught value is not always an Error: `insertData` reports whatever it - * caught. Reading `.message` off a non-object threw a TypeError from here, - * which the caller then reported as a failed backup, so nothing was written - * for exactly the malformed failures the backup is most needed for. - * - * Its message is also not always populated. The common failure is a - * `PartialFailureError`, whose message `@google-cloud/common` builds from the - * `message` of each entry in `errors`. Those entries are `{ errors, row }` - * pairs and carry no `message` of their own, so the message it builds is the - * empty string, and the reason for the failure ("no such field: document_id.") - * is only reachable one level further down. `??` kept that empty string, - * because it falls back on null and undefined but not on "". + * `insertData` reports whatever it caught, so this is not always an Error and + * its `message` is not always populated. On the common failure it never is: a + * `PartialFailureError`'s message is built by `@google-cloud/common` from the + * `message` of each entry in `errors`, and those entries are `{ errors, row }` + * pairs carrying none, so the real reason sits one level further down. */ function describeError(e: unknown): string { - // The whole body is guarded, not just `String(e)`, so that reading `.message` - // off a value with a throwing getter cannot escape either. + // This runs inside the caller's catch block, where a throw is reported as a + // failed backup, so the whole body is guarded rather than just `String(e)`. try { const message = (e as any)?.message; diff --git a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts index d869148a3..7f4f48307 100644 --- a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts +++ b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts @@ -57,9 +57,8 @@ interface InsertAllError { /** * The `insertAll` error reasons BigQuery documents as worth retrying. * - * `stopped` means the row was not inserted because another row in the same - * request failed, so it never appears on its own. The reason that does appear - * alongside it decides whether the request is retryable. + * `stopped` marks a row BigQuery did not attempt because another row in the same + * request failed, so it never appears alone, and the reason beside it decides. */ const RETRYABLE_INSERT_REASONS = [ "backendError", @@ -70,15 +69,11 @@ const RETRYABLE_INSERT_REASONS = [ ]; /** - * Flattens the per-field errors out of a BigQuery insert failure. + * Flattens the per-field errors out of a BigQuery insert failure. Empty for any + * failure that is not a partial failure, such as a network or quota error. * - * `PartialFailureError` carries the raw `insertAll` response on `response`, - * where `insertErrors` is an array of `{ index, errors }`. The error's own - * `errors` property is a remapped copy that keeps only `message` and `reason`, - * so it cannot be used to identify which column BigQuery rejected. - * - * Returns an empty array for any failure that is not a partial failure, e.g. a - * network error or a quota rejection. + * Read from `response.insertErrors` rather than the error's own `errors`, which + * is a remapped copy that drops `location` and so cannot identify the column. */ function extractInsertErrors(e: any): InsertAllError[] { const insertErrors = e?.response?.insertErrors; @@ -103,8 +98,8 @@ function unknownFieldColumn( error: InsertAllError, columns: string[] ): string | null { - // Defensive to match extractInsertErrors: a null entry must classify as not - // matching, not throw from inside the catch block and lose the real error. + // This runs inside a catch block, so a malformed entry must classify as not + // matching rather than throw and lose the real error. const message = error?.message ?? ""; if (!/^no such field/i.test(message)) return null; @@ -131,7 +126,6 @@ function withoutColumns( rows: bigquery.RowMetadata[], columns: string[] ): bigquery.RowMetadata[] { - // The ordinary insert strips nothing, so leave it its own rows. if (!columns.length) return rows; return rows.map((row) => { @@ -272,11 +266,9 @@ export class FirestoreBigQueryEventHistoryTracker const rejected: string[] = []; for (const error of errors) { - // `stopped` marks a row BigQuery did not attempt, because another row in - // the same request failed and `skipInvalidRows` is false. It says nothing - // about the schema, so treating it as unattributable would stop any - // multi-row batch from ever being recognised as lag. `scripts/import` - // records batches, so this is reachable. + // A row BigQuery did not attempt, because `skipInvalidRows` is false and + // another row in the request failed. It says nothing about the schema, and + // skipping it is what lets a multi-row batch be recognised as lag at all. if (error?.reason === "stopped") continue; const column = unknownFieldColumn(error, addedColumns); @@ -291,82 +283,47 @@ export class FirestoreBigQueryEventHistoryTracker } /** - * The columns this tracker adds to a table that already exists, and so every - * column exposed to the lag. + * The columns this tracker adds to a table that already exists, and so the + * only columns a lag retry may drop. * - * Every column added belongs here unless dropping it would cost more than - * losing the event, or it is not reliably added at all. Both exceptions are - * below. Omitting a column turns a row that lands today, with that column - * null, into an event lost once the caller exhausts its retries, because - * nothing on the write path reconciles the schema. + * Exact in both directions. A column missing from here turns a row that would + * land with that column null into an event lost once the caller exhausts its + * retries, because nothing on the write path reconciles the schema. A column + * listed here that is never actually added is worse: every insert strips it + * and reports success, for the life of the table. * - * It must also stay exact. Listing a column that is never added makes the - * retry drop that column's value on a table missing it, forever. + * A null in a column the latest view groups on duplicates the document in + * `_latest`, permanently, since the changelog is append-only. That is accepted + * for the columns below, because those tables already hold pre-upgrade rows + * with the same nulls, and not accepted for `timestamp`, the partition and + * ordering key, where a null misfiles the row instead. */ private columnsAddedToExistingTables(): string[] { const columns = [documentIdField.name, oldDataField.name]; - // `path_params` is only ever added, and only ever emitted by `record`, when - // wildcard ids are enabled. Listing it unconditionally meant a transform - // function, whose response `transformRows` uses verbatim, could inject the - // key into a table that has no such column and have it discarded on every - // insert, for good. + // Only added, and only emitted by `record`, when wildcard ids are on. A + // transform function can inject the key regardless, and `transformRows` uses + // its response verbatim, so listing it unconditionally would strip it from + // every insert into a table that has no such column. if (this.config.wildcardIds) { columns.push(documentPathParams.name); } - // The custom partition column is deliberately absent, though it is added to - // an existing table under the Firestore field strategy. It is added only - // when `tableRequiresUpdate` returns true, and that returns false for a - // table which is already time-partitioned - // (`checkUpdates.ts:39-44` via `isValidPartitionForExistingTable`, which is - // `!isPartitioned`). So an operator moving an already-partitioned table to - // field partitioning gets a column that is never added, and listing it here - // would make every insert strip it and report success, forever. That is the - // exactness failure this docstring warns about. `timestamp` is excluded - // too, for being the partition and ordering key: a silent null there - // misfiles the row for good, where a failure the caller can retry does not. - // - // Little is lost by excluding it. The value is derived from a field of the - // document, which is serialised whole into `data` (`:200`, and `old_data` - // for a delete), so the row still carries it. And `Partitioning` refuses to - // repartition an existing table anyway, so the column has nowhere to go. - // - // The columns above are not free either, so this is a trade-off rather than - // a clean line. A null in a column the latest view groups on makes that row - // its own group, so the document appears twice in `_latest`, and the - // changelog is append-only so a later write does not clear the duplicate. - // Which columns those are depends on the view syntax, and only `event_id`, - // `data` and `old_data` are safe under both. The legacy view groups on - // `document_name` and `document_id` and wraps everything else in - // `FIRST_VALUE` (`snapshot.ts:126-152`). The standard view wraps only - // `nonGroupFields`, in `ANY_VALUE`, and groups on everything else, - // `path_params` and `timestamp` included (`snapshot.ts:174-194`). So - // `document_id` costs a duplicate on either, and `path_params` costs one on - // the standard syntax. - // - // Tolerating that is still the better trade, because the duplication is not - // new. These columns are added to an existing table as a schema change with - // nothing backfilling them, so on exactly the tables this lag can affect - // every pre-upgrade row is already null, and every document written both - // before and after the upgrade already appears twice. The lag adds a - // handful of rows to a set that is already there. Losing the event has no - // such floor: the caller's retries are finite and nothing reconciles the - // schema afterwards, so the change never reaches BigQuery at all. + // The custom partition column is absent even though the Firestore field + // strategy adds it to an existing table, because `tableRequiresUpdate` is + // false for a table that is already time-partitioned, so on exactly those + // tables the column is never added. Little is lost: the value comes from a + // document field that `data` already carries whole. return columns; } /** - * Whether a failed insertion is worth one plain retry, with options - * unchanged. - * - * A failure with no partial-failure body (a network blip, a quota rejection, - * a 5xx) says nothing about our schema, so retrying it as-is is safe. + * Whether a failed insertion is worth one plain retry, with options unchanged. * * A partial failure qualifies only when every entry names a reason BigQuery - * documents as retryable. Anything else is BigQuery rejecting the shape of - * the data itself, which a plain retry cannot fix. The schema-lag check runs - * first, so an unknown-field entry never reaches here. + * documents as retryable. Anything else is a rejection of the data itself, + * which a plain retry cannot fix. A failure with no partial-failure body says + * nothing about the schema, so it is retried as-is. */ private isTransientInsertionError(e: any): boolean { const errors = extractInsertErrors(e); @@ -403,21 +360,18 @@ export class FirestoreBigQueryEventHistoryTracker /** * Inserts rows of data into the BigQuery raw change log table. * - * `rows` stays as the caller built it for the whole retry chain. A schema-lag - * retry narrows only the payload sent to BigQuery, so the backup written on - * the terminal path still holds every column, including any an earlier retry - * had to remove. + * `rows` stays as the caller built it for the whole retry chain, and columns + * are removed at the `insert` call, so the backup written on the terminal path + * still holds every column. */ private async insertData( rows: bigquery.RowMetadata[], overrideOptions: InsertRowsOptions = {}, // Columns a schema-lag retry has already removed from the payload. Each - // retry must remove at least one column BigQuery has not named before, so - // this layer is bounded at one attempt per column in - // `columnsAddedToExistingTables`, plus one. + // retry must remove one not removed before, which bounds the recursion. strippedColumns: string[] = [], - // Tracked separately from the above, so a transient blip on the first - // attempt cannot consume the retry a schema lag on a later attempt needs. + // Tracked separately, so a transient blip on the first attempt cannot + // consume the retry a schema lag on a later attempt needs. allowTransientRetry: boolean = true ) { const options = { @@ -437,12 +391,10 @@ export class FirestoreBigQueryEventHistoryTracker // A column we just added may not be streamable yet. Remove the columns // BigQuery named and retry, so the rest of the row lands. // - // Deliberately not `ignoreUnknownValues`. A live instance reports one - // unknown field per row rather than all of them, so ignoring unknown - // values would also discard fields BigQuery never mentioned, including - // real drift this retry is not meant to tolerate. Removing only what it - // named leaves any other unknown column failing the insert, where it is - // backed up rather than lost. + // Deliberately not `ignoreUnknownValues`, which would also discard fields + // BigQuery never mentioned: it reports one unknown field per row, not all + // of them. Removing only what it named leaves any other unknown column + // failing the insert, where it is backed up rather than lost. const lagColumns = this.schemaLagColumns(e).filter( (column) => !strippedColumns.includes(column) ); @@ -450,11 +402,9 @@ export class FirestoreBigQueryEventHistoryTracker if (lagColumns.length) { logs.dataInsertRetriedWithoutColumns(rows.length, lagColumns); - // The whole case for stripping a column is that it exists and BigQuery - // has not caught up yet. When that is wrong, and the column really is - // gone, nothing here notices. Clearing this makes the next batch run - // `initialize` and add it back, so a mistaken lag costs one batch - // rather than the life of the instance. + // If the column is genuinely gone rather than lagging, this makes the + // next batch run `initialize` and add it back, so the mistake costs one + // batch rather than the life of the instance. this._initialized = false; return this.insertData( @@ -465,8 +415,6 @@ export class FirestoreBigQueryEventHistoryTracker ); } - // Transient failures deserve a retry, but not with - // `ignoreUnknownValues`, which would silently drop real data. if (allowTransientRetry && this.isTransientInsertionError(e)) { logs.dataInsertRetriedAfterTransientError(rows.length); return this.insertData(rows, overrideOptions, strippedColumns, false); @@ -477,8 +425,8 @@ export class FirestoreBigQueryEventHistoryTracker try { await handleFailedTransactions(rows, this.config, e); } catch (backupError) { - // Never let a failed backup write mask the insert error that caused - // it. The caller needs the original cause to decide whether to retry. + // The caller needs the insert error to decide whether to retry, so a + // failed backup write must not replace it. logs.failedBackupWrite(backupError); } } diff --git a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/logs.ts b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/logs.ts index a468f7393..f649ab23a 100644 --- a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/logs.ts +++ b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/logs.ts @@ -138,15 +138,9 @@ export const dataInserted = (rowCount: number) => { }; /** - * The two retry paths must be distinguishable in the logs: only one of them - * drops columns, and an operator investigating suspected column loss has no - * other way to tell which retry ran. - * - * Warn rather than debug: this is the one path that leaves a column permanently - * null for the rows it recovers, and debug is suppressed at the default log - * level, so an operator would have had to already suspect the loss to see it. - * Naming the columns means the log says which fields were lost, not just that - * something was. + * Warn rather than debug, and name the columns: this is the one retry path that + * leaves a column permanently null for the rows it recovers, and debug is + * suppressed at the default log level. */ export const dataInsertRetriedWithoutColumns = ( rowCount: number, From ae252f9dd51eb878e5eb27d0af0c929680797e87 Mon Sep 17 00:00:00 2001 From: Izaak Gough Date: Thu, 13 Aug 2026 11:18:43 +0100 Subject: [PATCH 21/21] docs(firestore-bigquery-export): trim the comments further Cut the sentences that restate the code or justify a choice the PR description already argues. --- .../__tests__/bigquery/backupSettings.test.ts | 10 +- .../__tests__/bigquery/insertRetry.test.ts | 32 ++--- .../src/bigquery/handleFailedTransactions.ts | 28 ++--- .../src/bigquery/index.ts | 119 ++++++------------ .../src/logs.ts | 7 +- 5 files changed, 70 insertions(+), 126 deletions(-) diff --git a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/backupSettings.test.ts b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/backupSettings.test.ts index 19220ce30..562b84f52 100644 --- a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/backupSettings.test.ts +++ b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/backupSettings.test.ts @@ -107,9 +107,8 @@ describe("handleFailedTransactions Firestore settings", () => { }); /** - * A stand-in for `@google-cloud/bigquery`'s `PartialFailureError`: one entry per - * failed row nesting the per-field errors, and the empty top-level `message` - * that `@google-cloud/common` builds from entries carrying none. + * A stand-in for `PartialFailureError`: one entry per failed row nesting the + * per-field errors, and the empty message `@google-cloud/common` builds from them. */ const partialFailure = (groups: any[]) => Object.assign(new Error(""), { name: "PartialFailureError", errors: groups }); @@ -187,7 +186,7 @@ describe("handleFailedTransactions error details", () => { it("falls back to the reason when an entry carries no message", async () => { // A `stopped` entry, the row BigQuery did not attempt, arrives with an empty - // message and an empty location, so the reason is all there is. + // message and location, so the reason is all there is. const details = await detailsFor( partialFailure([ { errors: [{ message: "", location: "", reason: "stopped" }] }, @@ -233,8 +232,7 @@ describe("handleFailedTransactions error details", () => { }); it("still writes a string for every malformed shape of `errors`", async () => { - // The handler runs inside the caller's catch block, so a throw here is - // reported as a failed backup and the row is lost. + // The handler runs inside the caller's catch block, so a throw loses the row. const shapes: any[] = [ partialFailure([]), Object.assign(new Error(""), { errors: "not an array" }), diff --git a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts index 49b369b63..6a34d486d 100644 --- a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts +++ b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/__tests__/bigquery/insertRetry.test.ts @@ -97,14 +97,11 @@ const ROWS = [ }, ]; -/** The payload of the row passed to the nth `insert` call, 0-indexed. */ +/** The row payload of the nth `insert` call, 0-indexed. */ const payloadOf = (insert: jest.Mock, call: number) => insert.mock.calls[call][0][0].json; -/** - * Returns a tracker whose inserts are served by `insert`, so no BigQuery - * client is needed. - */ +/** A tracker whose inserts are served by `insert`, so no client is needed. */ function trackerWith( insert: jest.Mock, overrides?: Partial @@ -216,8 +213,7 @@ describe("insertData retry behaviour", () => { it("ignores stopped rows when recognising the lag", async () => { // With `skipInvalidRows` false BigQuery marks the rows it did not attempt - // as `stopped`, with the empty message and location a live instance sends, - // so `reason` is the only thing identifying the entry. + // as `stopped`, with the empty message and location a live instance sends. const insert = jest .fn() .mockRejectedValueOnce( @@ -264,8 +260,7 @@ describe("insertData retry behaviour", () => { }); it("gives up when a retry makes no progress", async () => { - // Bounds the recursion: the same column rejected twice means removing it - // did not help. + // Bounds the recursion: the same column twice means removing it did not help. const insert = jest .fn() .mockRejectedValue( @@ -302,7 +297,7 @@ describe("insertData retry behaviour", () => { it("backs up the row the caller gave us, not the one the retry reduced", async () => { // A strip followed by a terminal rejection for a different column is the - // ordinary case, and the backup is the only record of the row. + // ordinary case, and the backup is the only record of the row that is left. const insert = jest .fn() .mockRejectedValueOnce( @@ -316,8 +311,7 @@ describe("insertData retry behaviour", () => { "insert failed" ); - // Without this the assertion below could pass against an implementation - // that never stripped anything. + // Without this, the assertion below passes even if nothing was stripped. expect(payloadOf(insert, 1)).not.toHaveProperty("document_id"); expect(handleFailedTransactionsMock).toHaveBeenCalledWith( ROWS, @@ -501,9 +495,8 @@ describe("insertData retry behaviour", () => { }); it("is not allowlisted under the Firestore timestamp strategy", async () => { - // Excluded deliberately rather than for want of a code path: `timestamp` - // keys the partition and orders the latest view, so a null misfiles the - // row instead of costing an event the caller can retry. + // Excluded deliberately, not for want of a code path: `timestamp` keys the + // partition, so a null misfiles the row rather than costing an event. const insert = jest .fn() .mockRejectedValue( @@ -526,8 +519,7 @@ describe("insertData retry behaviour", () => { }); it("is not allowlisted when field partitioning names a base column", async () => { - // The exclusion is keyed on the collision, not on `timestamp`, so any - // configured name that matches a base column reaches it. + // Keyed on the collision, not on `timestamp`, so any base-column name hits it. const insert = jest .fn() .mockRejectedValue( @@ -674,7 +666,7 @@ describe("insertData retry behaviour", () => { describe("transient failures", () => { it("retries a partial failure whose reasons are all retryable", async () => { - // A rate limit or backend error arrives as a partial failure rather than a + // A rate limit or backend error arrives as a partial failure, not as a // bare transport error. const insert = jest .fn() @@ -864,8 +856,8 @@ describe("insertData retry behaviour", () => { }); it("distinguishes the retry that drops columns from the one that does not", async () => { - // Only one of the two retries drops columns, and the logs are the only - // thing telling an operator which one ran. + // Only one of the two retries drops columns, and the logs are all an + // operator has to tell them apart. const insert = jest .fn() .mockRejectedValueOnce( diff --git a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/handleFailedTransactions.ts b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/handleFailedTransactions.ts index 45423cf4b..2ad56c6a9 100644 --- a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/handleFailedTransactions.ts +++ b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/handleFailedTransactions.ts @@ -23,10 +23,7 @@ if (!admin.apps.length) { initializeApp(); } -/** - * `settings()` may only be called once per Firestore instance, and only before - * the instance is used, so it is attempted once per database id. - */ +/** `settings()` may only be called once per instance, and before it is used. */ const settingsApplied = new Set(); function backupFirestore(instanceId: string) { @@ -38,8 +35,8 @@ function backupFirestore(instanceId: string) { try { db.settings({ ignoreUndefinedProperties: true }); } catch (settingsError) { - // Something else in the process reached this instance first. The backup - // still goes ahead, without `ignoreUndefinedProperties`. + // Something else reached this instance first. The backup still goes + // ahead, without `ignoreUndefinedProperties`. } } @@ -62,7 +59,7 @@ function truncate( /** * The per-field messages a `PartialFailureError` nests under * `errors[].errors[].message`, deduplicated because a batch usually fails the - * same way for every row. `""` when there is nothing usable to report. + * same way for every row. */ function nestedErrorMessages(e: unknown): string { const groups = (e as any)?.errors; @@ -84,7 +81,7 @@ function nestedErrorMessages(e: unknown): string { } // A `stopped` entry, the row BigQuery did not attempt, arrives with an - // empty `message` and an empty `location`, so `reason` is all there is. + // empty `message` and `location`, so `reason` is all there is. const reason = (entry as any)?.reason; if (typeof reason === "string" && reason.length > 0) { @@ -109,17 +106,14 @@ function nestedErrorMessages(e: unknown): string { } /** - * A description of a failed insert that an operator can act on. - * - * `insertData` reports whatever it caught, so this is not always an Error and - * its `message` is not always populated. On the common failure it never is: a - * `PartialFailureError`'s message is built by `@google-cloud/common` from the - * `message` of each entry in `errors`, and those entries are `{ errors, row }` - * pairs carrying none, so the real reason sits one level further down. + * `insertData` reports whatever it caught, so this is not always an Error, and on + * the common failure its `message` is empty: `@google-cloud/common` builds a + * `PartialFailureError`'s message from entries that carry none, so the real + * reason sits one level down. */ function describeError(e: unknown): string { - // This runs inside the caller's catch block, where a throw is reported as a - // failed backup, so the whole body is guarded rather than just `String(e)`. + // Runs inside the caller's catch block, where a throw is reported as a failed + // backup, so the whole body is guarded rather than just `String(e)`. try { const message = (e as any)?.message; diff --git a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts index 7f4f48307..f24d9e1f4 100644 --- a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts +++ b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts @@ -47,7 +47,6 @@ import type { ChangeTrackerConfig } from "./types"; import { PartitioningConfig } from "./partitioning/config"; export type { ChangeTrackerConfig } from "./types"; -/** A single error entry from a raw `insertAll` partial-failure response. */ interface InsertAllError { message?: string; location?: string; @@ -55,10 +54,9 @@ interface InsertAllError { } /** - * The `insertAll` error reasons BigQuery documents as worth retrying. - * - * `stopped` marks a row BigQuery did not attempt because another row in the same - * request failed, so it never appears alone, and the reason beside it decides. + * The `insertAll` error reasons BigQuery documents as worth retrying. `stopped` + * marks a row BigQuery did not attempt, and never appears without one of the + * others alongside it. */ const RETRYABLE_INSERT_REASONS = [ "backendError", @@ -69,9 +67,6 @@ const RETRYABLE_INSERT_REASONS = [ ]; /** - * Flattens the per-field errors out of a BigQuery insert failure. Empty for any - * failure that is not a partial failure, such as a network or quota error. - * * Read from `response.insertErrors` rather than the error's own `errors`, which * is a remapped copy that drops `location` and so cannot identify the column. */ @@ -86,42 +81,31 @@ function extractInsertErrors(e: any): InsertAllError[] { } /** - * The column an error entry reports as unknown, if it names one of `columns`. - * Null for anything else, so that an entry we cannot attribute fails loudly - * rather than causing data to be dropped. - * - * A live instance sends both forms at once: `location` set to the column, and - * an inlined `"no such field: document_id."`. Older responses carried only the - * bare `"no such field."` with `location`, so both are handled. + * Null for anything it cannot attribute, so an unrecognised entry fails the + * insert rather than dropping data. Two response forms exist: the bare + * `"no such field."` naming the column in `location`, and an inlined + * `"no such field: document_id."`. */ function unknownFieldColumn( error: InsertAllError, columns: string[] ): string | null { - // This runs inside a catch block, so a malformed entry must classify as not - // matching rather than throw and lose the real error. + // Runs inside a catch block, so a malformed entry must not throw. const message = error?.message ?? ""; if (!/^no such field/i.test(message)) return null; - // The bare form names the column in `location`. if (error.location) { return columns.includes(error.location) ? error.location : null; } - // The inlined form carries the column in the message. Compare the whole name: - // a substring test would match a user column such as `document_id_v2` and - // silently drop it. + // Whole name, not a substring: `document_id_v2` must not match `document_id`. const named = message.match(/^no such field:\s*(.+?)\.?$/i); return named && columns.includes(named[1]) ? named[1] : null; } -/** - * Copies `rows` with `columns` removed from each payload. - * - * Rows are inserted with `raw: true`, so the payload is under `json`. - */ +/** Rows are inserted with `raw: true`, so the payload is under `json`. */ function withoutColumns( rows: bigquery.RowMetadata[], columns: string[] @@ -245,16 +229,12 @@ export class FirestoreBigQueryEventHistoryTracker } /** - * The rejected columns when a failed insertion is the one case it is safe to - * retry: a column this tracker adds to an existing table that BigQuery is not - * ready to stream into yet (https://issuetracker.google.com/35905247). - * - * Empty unless every field BigQuery rejected is one of those columns. Any - * other unknown field is real schema drift, and dropping it would lose the - * user's data. + * The rejected columns when an insert failure is the one case it is safe to + * retry: a column added to an existing table that BigQuery is not ready to + * stream into yet (https://issuetracker.google.com/35905247). Any other unknown + * field is real drift, and dropping it would lose the user's data. * - * Deliberately not `async`: the result is used in a guard, and a promise - * there is always truthy. + * Not `async`: the result is used in a guard, where a promise is always truthy. */ private schemaLagColumns(e: any): string[] { const errors = extractInsertErrors(e); @@ -266,9 +246,8 @@ export class FirestoreBigQueryEventHistoryTracker const rejected: string[] = []; for (const error of errors) { - // A row BigQuery did not attempt, because `skipInvalidRows` is false and - // another row in the request failed. It says nothing about the schema, and - // skipping it is what lets a multi-row batch be recognised as lag at all. + // A row BigQuery did not attempt because another in the request failed. + // Skipping it is what lets a multi-row batch be recognised as lag at all. if (error?.reason === "stopped") continue; const column = unknownFieldColumn(error, addedColumns); @@ -283,47 +262,35 @@ export class FirestoreBigQueryEventHistoryTracker } /** - * The columns this tracker adds to a table that already exists, and so the - * only columns a lag retry may drop. - * - * Exact in both directions. A column missing from here turns a row that would - * land with that column null into an event lost once the caller exhausts its - * retries, because nothing on the write path reconciles the schema. A column - * listed here that is never actually added is worse: every insert strips it - * and reports success, for the life of the table. + * The only columns a lag retry may drop. Exact in both directions: one missing + * costs the event once the caller's retries run out, and one listed that is + * never actually added is stripped from every insert for the table's life. * * A null in a column the latest view groups on duplicates the document in - * `_latest`, permanently, since the changelog is append-only. That is accepted - * for the columns below, because those tables already hold pre-upgrade rows - * with the same nulls, and not accepted for `timestamp`, the partition and - * ordering key, where a null misfiles the row instead. + * `_latest` permanently. Accepted for these, whose tables already hold + * pre-upgrade rows with the same nulls; not for `timestamp`, where a null + * misfiles the row instead. */ private columnsAddedToExistingTables(): string[] { const columns = [documentIdField.name, oldDataField.name]; - // Only added, and only emitted by `record`, when wildcard ids are on. A - // transform function can inject the key regardless, and `transformRows` uses - // its response verbatim, so listing it unconditionally would strip it from - // every insert into a table that has no such column. + // Only added, and only emitted, when wildcard ids are on. A transform + // function can inject the key regardless: `transformRows` uses its response + // verbatim. if (this.config.wildcardIds) { columns.push(documentPathParams.name); } // The custom partition column is absent even though the Firestore field - // strategy adds it to an existing table, because `tableRequiresUpdate` is - // false for a table that is already time-partitioned, so on exactly those - // tables the column is never added. Little is lost: the value comes from a - // document field that `data` already carries whole. + // strategy adds it, because `tableRequiresUpdate` is false for an already + // time-partitioned table, so on exactly those tables it is never added. return columns; } /** - * Whether a failed insertion is worth one plain retry, with options unchanged. - * - * A partial failure qualifies only when every entry names a reason BigQuery - * documents as retryable. Anything else is a rejection of the data itself, - * which a plain retry cannot fix. A failure with no partial-failure body says - * nothing about the schema, so it is retried as-is. + * Qualifies only when every entry names a reason BigQuery documents as + * retryable; anything else is a rejection of the data, which a retry cannot + * fix. A failure with no partial-failure body says nothing about the schema. */ private isTransientInsertionError(e: any): boolean { const errors = extractInsertErrors(e); @@ -360,9 +327,8 @@ export class FirestoreBigQueryEventHistoryTracker /** * Inserts rows of data into the BigQuery raw change log table. * - * `rows` stays as the caller built it for the whole retry chain, and columns - * are removed at the `insert` call, so the backup written on the terminal path - * still holds every column. + * Columns are removed at the `insert` call rather than from `rows`, so the + * backup on the terminal path still holds every column. */ private async insertData( rows: bigquery.RowMetadata[], @@ -370,8 +336,7 @@ export class FirestoreBigQueryEventHistoryTracker // Columns a schema-lag retry has already removed from the payload. Each // retry must remove one not removed before, which bounds the recursion. strippedColumns: string[] = [], - // Tracked separately, so a transient blip on the first attempt cannot - // consume the retry a schema lag on a later attempt needs. + // Tracked separately, so a blip cannot consume the retry a later lag needs. allowTransientRetry: boolean = true ) { const options = { @@ -388,13 +353,11 @@ export class FirestoreBigQueryEventHistoryTracker await table.insert(withoutColumns(rows, strippedColumns), options); logs.dataInserted(rows.length); } catch (e) { - // A column we just added may not be streamable yet. Remove the columns - // BigQuery named and retry, so the rest of the row lands. + // A column we just added may not be streamable yet, so remove the ones + // BigQuery named and retry. // - // Deliberately not `ignoreUnknownValues`, which would also discard fields - // BigQuery never mentioned: it reports one unknown field per row, not all - // of them. Removing only what it named leaves any other unknown column - // failing the insert, where it is backed up rather than lost. + // Not `ignoreUnknownValues`: BigQuery reports one unknown field per row, so + // that would also discard fields it never mentioned. const lagColumns = this.schemaLagColumns(e).filter( (column) => !strippedColumns.includes(column) ); @@ -403,8 +366,7 @@ export class FirestoreBigQueryEventHistoryTracker logs.dataInsertRetriedWithoutColumns(rows.length, lagColumns); // If the column is genuinely gone rather than lagging, this makes the - // next batch run `initialize` and add it back, so the mistake costs one - // batch rather than the life of the instance. + // next batch re-run `initialize` and add it back. this._initialized = false; return this.insertData( @@ -425,8 +387,7 @@ export class FirestoreBigQueryEventHistoryTracker try { await handleFailedTransactions(rows, this.config, e); } catch (backupError) { - // The caller needs the insert error to decide whether to retry, so a - // failed backup write must not replace it. + // A failed backup must not replace the insert error the caller needs. logs.failedBackupWrite(backupError); } } diff --git a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/logs.ts b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/logs.ts index f649ab23a..1930bdc7d 100644 --- a/firestore-bigquery-export/firestore-bigquery-change-tracker/src/logs.ts +++ b/firestore-bigquery-export/firestore-bigquery-change-tracker/src/logs.ts @@ -139,8 +139,7 @@ export const dataInserted = (rowCount: number) => { /** * Warn rather than debug, and name the columns: this is the one retry path that - * leaves a column permanently null for the rows it recovers, and debug is - * suppressed at the default log level. + * leaves a column permanently null, and debug is off at the default log level. */ export const dataInsertRetriedWithoutColumns = ( rowCount: number, @@ -233,8 +232,8 @@ export const bigQueryTableInsertErrors = ( ) => { logger.warn(`Error when inserting data to table.`); - // Defensive throughout: this runs on the terminal path of a failed insert, - // and throwing here would replace the insert error the caller needs. + // Runs on the terminal path of a failed insert, so a throw here would replace + // the insert error the caller needs. if (!Array.isArray(insertErrors)) return; insertErrors.forEach((error) => {