Skip to content

fix(firestore-bigquery-export): scope insert retry to schema lag - #2937

Open
IzaakGough wants to merge 22 commits into
nextfrom
fix/bq-insert-retry-allowlist
Open

fix(firestore-bigquery-export): scope insert retry to schema lag#2937
IzaakGough wants to merge 22 commits into
nextfrom
fix/bq-insert-retry-allowlist

Conversation

@IzaakGough

@IzaakGough IzaakGough commented Aug 11, 2026

Copy link
Copy Markdown

The bug

The retry guard was an async function called without await, so it was always truthy and every insert failure retried with ignoreUnknownValues: true. Unknown fields were dropped and the write reported success. Since 2020 (2de70201), untested.

The fix

The retry now removes only the columns BigQuery named, and only the ones we add to existing tables (document_id, old_data, and path_params with wildcardIds). Anything else fails the insert and backs up the full row.

Two adjacent bugs go with it: settings() was called on every failure though it may only be called once, so every backup after the first threw; and error_details was always empty.

Testing

52 new offline tests, tsc --noEmit clean, plus verified against a live BigQuery instance.

To decide

Allowlisting document_id costs a duplicate row in the legacy _latest view, taken because those tables already duplicate every pre-upgrade row. Needs a CHANGELOG note and a tracker version bump.

`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.
@IzaakGough
IzaakGough marked this pull request as draft August 11, 2026 10:28

@gemini-code-assist gemini-code-assist Bot left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Code Review

This pull request refactors the BigQuery insertion retry logic in the Firestore BigQuery Event History Tracker to safely handle schema lag and transient failures, and adds comprehensive unit tests. The reviewer noted that using substring matching (message.includes(column)) to identify unknown fields could lead to false positives and silent data loss (e.g., matching document_id_v2 against document_id), and suggested parsing the exact field name from the error message instead.

Comment thread firestore-bigquery-export/firestore-bigquery-change-tracker/src/bigquery/index.ts Outdated
`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.
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.
…e 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.
… 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.
…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.
…e 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.
…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`.
@IzaakGough
IzaakGough marked this pull request as ready for review August 12, 2026 11:33
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.
…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.
… 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.
…ackups

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.
`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.
This reverts commit 1d97d6e.

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.
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.
…o message

Three small defects in the backup writer, all found by the review of 05af747.

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.
…cks 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.
…n 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.
Cut the bug narration, the line-number references, and the trade-off
essays, keeping the constraints a reader cannot get from the code.
Cut the sentences that restate the code or justify a choice the PR
description already argues.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants