[Bug][Backend][Data] Metadata extraction has no idempotency guard — a single upload inserted 2× full page sets (342 dupes, 2026-07-18); answers #509's open questions #862

Open
opened 2026-07-26 23:59:41 +00:00 by spikerj · 1 comment
Owner

Follow-up to #509. That issue fixed the SHA-dedup half (WasDuplicateUploadOrchestrator deletes the redundant extraction, UploadOrchestrator.cs:515). Its hypothesis (1)"metadata re-extraction inserts a fresh page set per attempt" — and its proposed fix (a)"idempotency key on metadata extraction per uploadId" — were never implemented, and there is now direct evidence the gap is still live.

This ticket also supplies the Mongo inspection #509 asked for under "Needs".

Evidence: duplication six days after #509 shipped

#509's fix merged 0ab84211 at 2026-07-12T18:25:03Z. Book 6a5ad504421cf4743b18299f (godot-best-practices-efficient-game-development.pdf, ISBN 9781835465110) was duplicated on 2026-07-18T01:19Z.

Crucially it was one workflow, one book.created — not a re-upload, so #509's SHA path never applied:

  • Workflow 6a5acc9dab286814013d3ec4, Status: failed, FailedStage: "Quiz" (GPU/VRAM — unrelated to the duplication), RetryCount: 0
  • Exactly one book.created event at 01:21:09 → BookId: 6a5ad504…
  • Yet 684 book-pages rows for 342 distinct page numbers, plus 128 book-page-images rows for 64 distinct images
  • All 684 inserted in a single ~23s burst, 01:19:25→01:19:48, each page present exactly twice
  • The two copies were byte-identical apart from CreatedAt / UpdatedAt / DescriptionGeneratedAt (text, metadata, descriptions, image paths all identical)

Extraction ran 00:45:40 → 01:21:07 (~35 min), i.e. long enough for a redelivery/second run.

Root cause: the staging window has no unique key

MetadataExtractionService inserts every page with a placeholder BookId:

  • MetadataExtractionService.cs:246BookId = ObjectId.Empty (also :502, :712, :760)
  • UploadOrchestrator.cs:559 — back-fills the real BookId only after book.created, selecting by p.Isbn == isbn && p.BookId == ObjectId.Empty

So between insert and back-fill every in-flight page carries ObjectId.Empty. Nothing prevents a second extraction run for the same upload from inserting a complete second page set; the back-fill then stamps the real BookId onto all of them. That is exactly the [1,1,2,2,3,3] inflation #509 described, reached by a different route.

Why the declared unique index cannot be the fix

SpikerDbContext declares HasIndex(e => new { e.BookId, e.PageNumber }).IsUnique() (:537). That index was inert until MongoIndexBootstrapper shipped (PR #479). Creating it as declared breaks concurrent uploads: while two uploads overlap in the staging window, both have page 1 as {ObjectId.Empty, 1} → E11000 → the second upload's extraction dies.

Confirmed empirically today, and worked around by making both indexes partial:

partialFilterExpression: { BookId: { $gt: ObjectId("000000000000000000000000") } }

ObjectId.Empty is the minimum ObjectId, so this applies uniqueness only to back-filled rows. Verified both directions: two uploads can stage page 1 concurrently, and a duplicate on a real BookId is still rejected. Index names are unchanged so MongoIndexHealthCheck (name-match) stays green.

This leaves the actual gap open — both godot copies were inserted while BookId was still ObjectId.Empty, so a partial index would not have stopped them.

What a real fix needs

{Isbn, PageNumber} unique is the tempting shape (system ISBNs are per-extraction-unique) but it conflicts with the #509 re-upload flow: a genuine re-upload of the same real ISBN would fail extraction rather than reach the WasDuplicate cleanup. Needs a deliberate choice among:

  1. Idempotency per uploadId#509's original fix (a): skip extraction if pages already exist for this upload. Requires an UploadId on BookPage (not currently stored).
  2. Stage under a per-upload key instead of the shared ObjectId.Empty sentinel, then a unique index on {stagingKey, PageNumber} works cleanly and the concurrency conflict disappears with it.
  3. Consumer-level dedupe on the extraction message.

(2) also removes the need for the partial-index workaround.

Cleanup already applied to prod

  • book-pages: 345 duplicate pairs removed (342 godot + 3 from a soft-deleted test book), 3276 → 2931
  • book-page-images: 64 pairs removed, 2088 → 2024
  • user-profiles: 1 pair removed (unrelated double-submit 51ms apart, byte-identical, no inbound _id references), 16 → 15
  • Policy was keep-newest; the live godot book verified intact at 342 pages / 342 distinct page numbers

Also found: game-art-loadouts was capped at one row globally

Unrelated to the above but found in the same sweep. The collection carried a stale hand-created index ux_user_game on {userId:1, gameId:1} (camelCase) — no document has those fields, and being unique and non-sparse, every row indexed as {null, null}. Probe insert confirmed:

E11000 duplicate key error … index: ux_user_game dup key: { userId: null, gameId: null }

No second user could ever save a loadout. Dropped it, along with the redundant ux_user_game_pascal (correct keys {UserId:1, GameId:1}, non-canonical name — the source of the bootstrapper's IndexOptionsConflict), and created the canonical UserId_1_GameId_1. Verified: two distinct users insert fine, true duplicates still rejected.

Separate follow-up worth filing

MongoIndexBootstrapper matches existing indexes by name only, so any cluster with a hand-named equivalent will report Degraded forever even though the constraint is enforced. Consider matching on key-spec + uniqueness and logging a name mismatch instead of failing.

Follow-up to #509. That issue fixed the **SHA-dedup** half (`WasDuplicate` → `UploadOrchestrator` deletes the redundant extraction, `UploadOrchestrator.cs:515`). Its hypothesis **(1)** — *"metadata re-extraction inserts a fresh page set per attempt"* — and its proposed fix **(a)** — *"idempotency key on metadata extraction per uploadId"* — were **never implemented**, and there is now direct evidence the gap is still live. This ticket also supplies the Mongo inspection #509 asked for under "Needs". ## Evidence: duplication six days *after* #509 shipped #509's fix merged `0ab84211` at **2026-07-12T18:25:03Z**. Book `6a5ad504421cf4743b18299f` (`godot-best-practices-efficient-game-development.pdf`, ISBN 9781835465110) was duplicated on **2026-07-18T01:19Z**. Crucially it was **one workflow, one `book.created`** — not a re-upload, so #509's SHA path never applied: - Workflow `6a5acc9dab286814013d3ec4`, `Status: failed`, `FailedStage: "Quiz"` (GPU/VRAM — unrelated to the duplication), `RetryCount: 0` - Exactly one `book.created` event at 01:21:09 → `BookId: 6a5ad504…` - Yet **684 `book-pages` rows for 342 distinct page numbers**, plus 128 `book-page-images` rows for 64 distinct images - All 684 inserted in a single ~23s burst, 01:19:25→01:19:48, each page present exactly twice - The two copies were byte-identical apart from `CreatedAt` / `UpdatedAt` / `DescriptionGeneratedAt` (text, metadata, descriptions, image paths all identical) Extraction ran 00:45:40 → 01:21:07 (~35 min), i.e. long enough for a redelivery/second run. ## Root cause: the staging window has no unique key `MetadataExtractionService` inserts every page with a placeholder BookId: - `MetadataExtractionService.cs:246` — `BookId = ObjectId.Empty` (also `:502`, `:712`, `:760`) - `UploadOrchestrator.cs:559` — back-fills the real `BookId` only after `book.created`, selecting by `p.Isbn == isbn && p.BookId == ObjectId.Empty` So between insert and back-fill every in-flight page carries `ObjectId.Empty`. Nothing prevents a second extraction run for the same upload from inserting a complete second page set; the back-fill then stamps the real `BookId` onto **all** of them. That is exactly the `[1,1,2,2,3,3]` inflation #509 described, reached by a different route. ## Why the declared unique index cannot be the fix `SpikerDbContext` declares `HasIndex(e => new { e.BookId, e.PageNumber }).IsUnique()` (`:537`). That index was inert until `MongoIndexBootstrapper` shipped (PR #479). Creating it as declared **breaks concurrent uploads**: while two uploads overlap in the staging window, both have page 1 as `{ObjectId.Empty, 1}` → E11000 → the second upload's extraction dies. Confirmed empirically today, and worked around by making both indexes partial: ```js partialFilterExpression: { BookId: { $gt: ObjectId("000000000000000000000000") } } ``` `ObjectId.Empty` is the minimum ObjectId, so this applies uniqueness only to back-filled rows. Verified both directions: two uploads can stage page 1 concurrently, and a duplicate on a real `BookId` is still rejected. Index names are unchanged so `MongoIndexHealthCheck` (name-match) stays green. **This leaves the actual gap open** — both godot copies were inserted while `BookId` was still `ObjectId.Empty`, so a partial index would not have stopped them. ## What a real fix needs `{Isbn, PageNumber}` unique is the tempting shape (system ISBNs are per-extraction-unique) but it **conflicts with the #509 re-upload flow**: a genuine re-upload of the same real ISBN would fail extraction rather than reach the `WasDuplicate` cleanup. Needs a deliberate choice among: 1. **Idempotency per uploadId** — #509's original fix (a): skip extraction if pages already exist for this upload. Requires an `UploadId` on `BookPage` (not currently stored). 2. **Stage under a per-upload key** instead of the shared `ObjectId.Empty` sentinel, then a unique index on `{stagingKey, PageNumber}` works cleanly and the concurrency conflict disappears with it. 3. Consumer-level dedupe on the extraction message. (2) also removes the need for the partial-index workaround. ## Cleanup already applied to prod - `book-pages`: 345 duplicate pairs removed (342 godot + 3 from a soft-deleted test book), 3276 → 2931 - `book-page-images`: 64 pairs removed, 2088 → 2024 - `user-profiles`: 1 pair removed (unrelated double-submit 51ms apart, byte-identical, no inbound `_id` references), 16 → 15 - Policy was keep-newest; the live godot book verified intact at 342 pages / 342 distinct page numbers ## Also found: `game-art-loadouts` was capped at one row globally Unrelated to the above but found in the same sweep. The collection carried a stale hand-created index `ux_user_game` on `{userId:1, gameId:1}` (camelCase) — **no document has those fields**, and being unique and non-sparse, every row indexed as `{null, null}`. Probe insert confirmed: ``` E11000 duplicate key error … index: ux_user_game dup key: { userId: null, gameId: null } ``` No second user could ever save a loadout. Dropped it, along with the redundant `ux_user_game_pascal` (correct keys `{UserId:1, GameId:1}`, non-canonical name — the source of the bootstrapper's `IndexOptionsConflict`), and created the canonical `UserId_1_GameId_1`. Verified: two distinct users insert fine, true duplicates still rejected. ## Separate follow-up worth filing `MongoIndexBootstrapper` matches existing indexes by **name only**, so any cluster with a hand-named equivalent will report Degraded forever even though the constraint is enforced. Consider matching on key-spec + uniqueness and logging a name mismatch instead of failing.
Author
Owner

Audited against origin/masterNOT DONE, no implementing code for any candidate fix. Plus undocumented prod/code drift that's worth knowing about. Notes updated.

None of the three candidate fixes exist:

  • No UploadId on BookPagegit grep -rn "UploadId" origin/master -- '*BookPage*' → no output.
  • No idempotency check before inserting a page set. MetadataExtractionService.cs still inserts with BookId = ObjectId.Empty at the cited :246, :502, :712, :760, and issues no read query against the DbContext at allAnyAsync, FirstOrDefault, Where, idempot, dedupe, duplicat all return nothing.
  • No per-upload staging key; UploadOrchestrator.cs:507 still back-fills by p.Isbn == isbn && p.BookId == ObjectId.Empty.
  • No consumer-level dedupe: MetadataExtractionConsumer.cs never reads the inbound MessageId, and its retry path (:184-192, with requeue: true at :154 when DLQ is off) re-runs the full page insert unguarded — which is precisely the redelivery route this ticket suspected.

Drift worth flagging — the prod workaround is invisible to the code. The partial unique index applied by hand to production exists nowhere in the repo:

  • SpikerDbContext.cs:540 still declares a plain HasIndex(e => new { e.BookId, e.PageNumber }).IsUnique() (same at :557), and git grep -n "partialFilterExpression\|PartialFilter\|HasFilter" origin/master returns nothing.
  • MongoIndexBootstrapper.cs:92-96 reconciles by name only, and its DeclaredIndex record (:195) has no field capable of carrying a filter expression.

So the hand-made partial index keeps its canonical name, is accepted as "already present", is never reconciled against the declaration, and MongoIndexHealthCheck stays green — while line 540 tells any reader that a plain unique index is in force. The workaround survives deploys invisibly, and a fresh environment provisioned from code would get the plain unique index, which (per this ticket's own analysis) breaks concurrent uploads because pages stage with BookId = ObjectId.Empty.

That reconciliation gap is arguably worth its own ticket regardless of how the idempotency fix lands.

Audited against `origin/master` — **NOT DONE, no implementing code for any candidate fix. Plus undocumented prod/code drift that's worth knowing about.** Notes updated. **None of the three candidate fixes exist:** - No `UploadId` on `BookPage` — `git grep -rn "UploadId" origin/master -- '*BookPage*'` → no output. - No idempotency check before inserting a page set. `MetadataExtractionService.cs` still inserts with `BookId = ObjectId.Empty` at the cited `:246`, `:502`, `:712`, `:760`, and issues **no read query against the DbContext at all** — `AnyAsync`, `FirstOrDefault`, `Where`, `idempot`, `dedupe`, `duplicat` all return nothing. - No per-upload staging key; `UploadOrchestrator.cs:507` still back-fills by `p.Isbn == isbn && p.BookId == ObjectId.Empty`. - No consumer-level dedupe: `MetadataExtractionConsumer.cs` never reads the inbound `MessageId`, and its retry path (`:184-192`, with `requeue: true` at `:154` when DLQ is off) re-runs the full page insert unguarded — which is precisely the redelivery route this ticket suspected. **Drift worth flagging — the prod workaround is invisible to the code.** The partial unique index applied by hand to production exists nowhere in the repo: - `SpikerDbContext.cs:540` still declares a **plain** `HasIndex(e => new { e.BookId, e.PageNumber }).IsUnique()` (same at `:557`), and `git grep -n "partialFilterExpression\|PartialFilter\|HasFilter" origin/master` returns nothing. - `MongoIndexBootstrapper.cs:92-96` reconciles **by name only**, and its `DeclaredIndex` record (`:195`) has no field capable of carrying a filter expression. So the hand-made partial index keeps its canonical name, is accepted as "already present", is never reconciled against the declaration, and `MongoIndexHealthCheck` stays green — while line 540 tells any reader that a plain unique index is in force. The workaround survives deploys invisibly, and a fresh environment provisioned from code would get the *plain* unique index, which (per this ticket's own analysis) breaks concurrent uploads because pages stage with `BookId = ObjectId.Empty`. That reconciliation gap is arguably worth its own ticket regardless of how the idempotency fix lands.
Sign in to join this conversation.