From 190954c68527fb511572bc563fc5fa570925d7dd Mon Sep 17 00:00:00 2001 From: derrickfink Date: Tue, 1 Sep 2026 17:37:34 -0600 Subject: [PATCH 1/2] fix(kb): confirm retrievability with a filtered query, and classify TEXT_INDEXED MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Two findings from running yesterday's fix, plus the handoff entries for both and for #901. The probe could not find its own document ----------------------------------------- `wait_until_retrievable` searched for the document *id as the query text* and checked whether that document came back in the top 5. A document id means nothing to an embedding model, so the search returned whatever the reranker preferred. Measured in dev with two documents present: query=DOC-40e985680a63 -> 5 chunks, ALL from DOC-db44eaf8f072 FOUND: False A perfectly retrievable document reported as not retrievable. It scales the wrong way: the more documents a knowledge base holds, the less likely the target lands in an unfiltered top-5, so every upload to a mature knowledge base would burn its poll budget and dead-letter — worse than the bug #901 fixed. It only ever worked while the knowledge base held exactly one document, where anything returned was necessarily the right thing. Now an `equals` filter on `document_id`, so a non-empty result IS proof and an empty one is a true negative. `equals` is already in ISOLATION_SAFE_FILTER_OPERATORS; a prefix operator would let DOC-1 confirm DOC-10. Verified against dev: each document returns 5 of its own chunks, a fabricated id returns none. TEXT_INDEXED is not in the SDK's enum ------------------------------------- The live service returned `TEXT_INDEXED` for a document with image extraction enabled — text searchable, media still processing — and the packaged model's `DocumentStatus` enum does not list it. So status handling must not be derived from that enum. Treated as in-flight rather than done: completing at that point would tell a user an image-only page is ready while the vision model is still running, which is the report this module exists to prevent. Unrecognised statuses now default to "keep waiting" too, so the next value AWS adds does not dead-letter documents. Also simplifies the flow: arriving to find a document already in flight used to raise immediately, which relied on redelivery that Lambda caps at 2 attempts. Both entry paths — just submitted, and found mid-flight — now share one bounded wait. Test-suite fix: an autouse fixture shortens the poll budgets. With the real 600 s budget the file took 20 minutes; it is now under 6 seconds. This is exactly why those constants are resolved at call time rather than bound as default arguments. `_FakeBackend` now models a knowledge base holding OTHER documents, and honours the filter. Without that, a probe ignoring its filter still passes — which is precisely how the query-by-id probe survived until a second document existed. Mutations verified caught: probe unfiltered, filter switched to a prefix operator, and TEXT_INDEXED dropped from the in-flight set. The third initially SURVIVED, because the unknown-status fallback also waits, making the mutation behaviour-equivalent; resolved by asserting the only thing that genuinely differs — that the status is classified rather than falling through the unknown branch. Not every surviving mutant means a missing test. Handoff: findings 37-39 recorded, including that §5.30's wrong constant had a second home nobody grepped for, and a correction — yesterday's claim that a measured 0.9 s gap "confirmed" the 0.75-1.03 s figure was false, since the fabricated timestamp meant it measured ingest-return to retrievable instead. 454 passed across lambdas/supply_chain/architecture; ruff clean. --- .kiro/specs/managed-kb-migration/HANDOFF.md | 105 +++++++- .../kb_migration/ingestion_consumer.py | 161 ++++++++---- .../lambdas/test_kb_ingestion_consumer.py | 233 +++++++++++++++++- 3 files changed, 435 insertions(+), 64 deletions(-) diff --git a/.kiro/specs/managed-kb-migration/HANDOFF.md b/.kiro/specs/managed-kb-migration/HANDOFF.md index 3ccf6c8c..b249a232 100644 --- a/.kiro/specs/managed-kb-migration/HANDOFF.md +++ b/.kiro/specs/managed-kb-migration/HANDOFF.md @@ -1,6 +1,6 @@ # Managed KB Migration — Handoff -**Last updated:** 2026-08-31 14:30 · **Shipped to production in 1.16.0, inert behind flags** · +**Last updated:** 2026-09-01 17:00 · **Shipped to production in 1.16.0, inert behind flags** · **A migration has completed end to end in dev; adding a document to it needed one more IAM action** Working state for this feature so a fresh session can pick it up without @@ -16,10 +16,11 @@ Four things invalidate earlier versions of this document: platform deploy succeeded on 2026-08-28, so `GSI7`, the Bedrock service role and the four Lambdas exist in **both** dev and prod. Earlier revisions of this file said "Nothing deployed"; that is no longer true. -2. **Eleven defects were found only by running it**, each reviewed clean and - deployed clean. They are §5 items 25–36 and they are the most useful part of - this document. Items 32–36 all trace to one root cause — the two engines were - never made exclusive — and are fixed in PR #900. +2. **Fourteen defects were found only by running it**, each reviewed clean and + deployed clean. They are §5 items 25–39 and they are the most useful part of + this document. Two clusters: 32–36 trace to the two engines never being made + exclusive (PR #900), and 37–39 to the ingestion consumer never actually knowing + when a document was ready (PRs #901, #902). Only §5.33 is still open. 3. **The `document_id` "known unknown" was a false alarm** and is now resolved with measurements — see §6. An earlier revision listed it as the top open risk. The probe was reading facade keys that have never existed. Two genuine findings came @@ -43,10 +44,10 @@ Four things invalidate earlier versions of this document: |---|---| | Spec | Complete. Requirement **8.5 was amended by measurement on 2026-08-31** — see §5.29 | | Implementation | Groups 1–14 except 14.5. A migration has completed `shadow → verify → promote → retain` in dev and serves from the managed backend | -| Tests | 640 infra (jest) · ~6,780 backend (pytest) · 1,936 frontend (vitest) · 5 pre-existing unrelated Strands failures | +| Tests | 640 infra (jest) · ~6,840 backend (pytest) · 1,936 frontend (vitest) · 5 pre-existing unrelated Strands failures | | Deployed | **dev and prod.** Flags off in prod; `migrationEnabled` on in dev | -| Open PRs | **#900** — engine exclusivity: the legacy pipeline stands down for a promoted KB (§5.32, §5.34) and deletion propagates to the managed engine (§5.36). Four CI checks green. Merging triggers **both** `backend.yml` (rag-ingestion + kb-sync images) and `platform.yml` (two new IAM grants). · **#899** — this document. · #898 merged as `ef2f4c9e` | -| Uncommitted | none — working tree clean as of 2026-08-31 14:30 | +| Open PRs | **#902** — the filtered retrievability probe (§5.38) and `TEXT_INDEXED` (§5.39), plus this document. · merged: #898 `ef2f4c9e`, #899, #900 `df93471c`, #901 `a4b660ba` | +| Uncommitted | none | ### Flag state (GitHub Environment variables) @@ -784,6 +785,92 @@ the managed engine at all. Every symptom below follows from that. --- +### The twelfth through fourteenth: the ingestion consumer never actually knew when a document was ready + +All three are one theme. The consumer had to answer "is this document usable yet?" +and every mechanism it used to answer was measuring something else. + +37. ✅ **Three stacked bugs left a fully retrievable document parked at + `uploading` forever** (fixed in PR #901). A 1.5 MB PDF, uploaded to a promoted + knowledge base: + + | | | + |---|---| + | **Wrong measurement** | The consumer polled a *retrieval* for 30 s, justified in its own header by the `INDEXED → retrievable` gap of "0.75–1.03 s". But the poll starts when the ingest call returns, so it had to cover `ingest → INDEXED → retrievable` — measured at 37–264 s for PDFs in the evaluation's §5.1, and 5 m 30 s for this file. The budget was smaller than the documented *lower bound*. | + | **Self-defeating retries** | `IngestKnowledgeBaseDocuments` is fire-and-forget and nothing asked Bedrock what it already knew, so "not indexed yet" and "never submitted" were indistinguishable. All three deliveries re-ingested, discarding progress. The document reached INDEXED **54 s after the final attempt was dead-lettered**. | + | **Fabricated timestamp** | `indexed_at = _now_iso()` ran right after the ingest call returned — recording when we *asked*, labelled as when indexing *finished*. | + + Fixed by probing `GetKnowledgeBaseDocuments` first and branching on the real + status, never re-ingesting work already in flight, and using Bedrock's own + `updatedAt`. + + ⚠️ **Lambda's async retry is capped at 2 attempts.** A hard service limit, and + it is why the wait has to happen *inside* one invocation. I first "fixed" this + with a `RetryPolicy` on the EventBridge target, which does nothing: for a + Lambda target EventBridge hands the event off and the function's own async + retry config governs. The construct now carries a comment saying so instead of + the useless setting. Do not add it back. + + **Why no test caught the fabricated timestamp:** the test asserted only that + `indexedAt` existed and was truthy, which any fabricated value satisfies. Same + shape as §5.28 — the fake modelled instant success, so a 30 s window looked + adequate for work that takes minutes. + + This is §5.30 for a second time. `verify` had the identical bug against the + identical 0.75–1.03 s figure; that fix never reached this component, which + inherited the constant. **When a wrong constant is found, grep for its other + homes.** + +38. ✅ **The retrievability probe searched for the document id as query text and + could not find its own document** (fixed in PR #902). `wait_until_retrievable` + ran `search(kb_ref, document_id, 5)` — the id *as the query* — then checked + whether that document appeared. A document id is meaningless to an embedding + model, so the search returned whatever the reranker preferred. Measured in dev + with two documents present: + + ``` + query=DOC-40e985680a63 -> 5 chunks, ALL from DOC-db44eaf8f072 FOUND ITSELF: False + ``` + + A perfectly retrievable document reported as not retrievable. **It scales the + wrong way:** the more documents a knowledge base holds, the less likely the + target lands in an unfiltered top-5, so every upload to a mature knowledge base + would burn its poll budget and dead-letter. It only ever worked while the + knowledge base held exactly one document — where anything returned was + necessarily the right thing. + + Fixed with an `equals` filter on `document_id`, so a non-empty result *is* + proof and an empty one is a true negative. Verified in dev: each document + returns 5 of its own chunks, a fabricated id returns none. + + ⚠️ **This is the third iteration on this one function, and I was wrong about + what it measured twice.** Note also that yesterday's claim that a measured + 0.9 s gap "confirmed the 0.75–1.03 s figure" was false — with the fabricated + timestamp it was measuring ingest-return → retrievable, not INDEXED → + retrievable. A number agreeing with your expectation is not confirmation. + +39. ✅ **The live service returns `TEXT_INDEXED`, which is not in the packaged + SDK's `DocumentStatus` enum** (handled in PR #902). Observed on a document with + image extraction enabled: `TEXT_INDEXED` (text searchable, media still + processing) then `INDEXED`. The enum in the packaged model lists twelve values + and this is not among them, so **do not derive status handling from the SDK + enum** — it is incomplete against the running service. + + Treated as in-flight, not done: marking a document complete at `TEXT_INDEXED` + would tell a user an image-only page is ready while the vision model is still + running, which is the exact report the consumer exists to prevent. Unrecognised + statuses now also default to "keep waiting" rather than "unknown, give up", so + the next undeclared value AWS adds does not dead-letter documents. + + **A mutation-testing note worth keeping:** removing `TEXT_INDEXED` from the + in-flight set is *behaviour-equivalent*, because the unknown-status fallback + also waits — so the mutation survived every behavioural assertion. The honest + resolution was to assert the only thing that genuinely differs: that the status + is classified, and does not fall through the unknown branch. Not every + surviving mutant means a missing test; some mean the mutation changes nothing. + +--- + ## 6. Remaining work ### Do these first @@ -798,7 +885,7 @@ the managed engine at all. Every symptom below follows from that. | Group | Notes | |---|---| -| **§5.33** the one fail-open line | The only finding from 2026-08-31 still open. `if not doc_ids: return vectors` in `_filter_vectors_by_document_status`. Make it fail closed with `METRIC_STATUS_FILTER_FAIL_CLOSED` like every other unprovable path in that function, and pin it with a test that mutation-fails. Lower stakes now that §5.36 removes deleted content from the managed engine, but still the one silent-serving path left | +| **§5.33** the one fail-open line — THE ONLY OPEN FINDING | The only finding from 2026-08-31 still open. `if not doc_ids: return vectors` in `_filter_vectors_by_document_status`. Make it fail closed with `METRIC_STATUS_FILTER_FAIL_CLOSED` like every other unprovable path in that function, and pin it with a test that mutation-fails. Lower stakes now that §5.36 removes deleted content from the managed engine, but still the one silent-serving path left | | **engine visibility** | Nothing logs *which* engine served a query — the resolver only logs on failure — so "is the new one actually working?" can only be answered from the KB record. One INFO line in the facade, plus a `Managed`/`Classic` badge in the knowledge base section, both unbuilt. Wanted before a wide rollout, because this feature's whole risk profile is silent regressions | | **14.4** one-click document retry | Req 21.2. Ingestion is S3-event-triggered and there is no reprocess endpoint, so this needs new backend against a live pipeline. The card currently directs the user to re-upload, which works today. Close it by building the endpoint **or** by amending Req 21.2 to accept re-upload | | **14.5** admin surface | not started. Filter by engine, stored bytes, document counts, bulk migrate, per-KB retry | diff --git a/backend/src/apis/app_api/kb_migration/ingestion_consumer.py b/backend/src/apis/app_api/kb_migration/ingestion_consumer.py index ba99c0b5..5af29c38 100644 --- a/backend/src/apis/app_api/kb_migration/ingestion_consumer.py +++ b/backend/src/apis/app_api/kb_migration/ingestion_consumer.py @@ -261,7 +261,19 @@ def set_document_terminal( #: a slow success into a permanent failure in dev — three redeliveries each #: re-ingested, and the document only reached INDEXED 54 s after the last attempt #: had already been dead-lettered. -DOC_STATUSES_IN_FLIGHT = frozenset({"STARTING", "PENDING", "IN_PROGRESS"}) +#: +#: ⚠️ ``TEXT_INDEXED`` is **not in the packaged service model's DocumentStatus +#: enum** — the live service returns statuses the SDK does not declare. Observed in +#: dev on a document with image extraction enabled: it reported ``TEXT_INDEXED`` +#: (text searchable, media still processing) and later became ``INDEXED``. It is +#: treated as in-flight rather than as done, because marking a document complete at +#: that point would tell the user an image-only page is ready while the vision +#: model has not finished — precisely the "upload worked but the assistant cannot +#: see it" report this module exists to prevent. Do not derive this set from the +#: SDK enum; it is deliberately wider. +DOC_STATUSES_IN_FLIGHT = frozenset( + {"STARTING", "PENDING", "IN_PROGRESS", "TEXT_INDEXED"} +) #: Terminal and unusable. Worth failing the document rather than retrying forever. DOC_STATUSES_FAILED = frozenset({"FAILED", "METADATA_UPDATE_FAILED"}) @@ -344,12 +356,36 @@ def wait_until_indexed( deadline = time.monotonic() + timeout_seconds status, updated_at = document_status(backend, kb_ref, document_id) - while status in DOC_STATUSES_IN_FLIGHT and time.monotonic() < deadline: + while _still_working(status, document_id) and time.monotonic() < deadline: sleep(interval_seconds) status, updated_at = document_status(backend, kb_ref, document_id) return status, updated_at +def _still_working(status: str, document_id: str) -> bool: + """Whether to keep waiting on ``status``. + + Anything not recognised counts as still working, deliberately. The live service + already returns at least one status the packaged model does not declare + (``TEXT_INDEXED``), so treating unknown values as terminal would dead-letter + documents the day AWS adds another. Waiting is bounded by the caller's deadline, + so the cost of guessing wrong here is one poll budget rather than a lost + document — and the log line names the value so it can be classified properly. + """ + if status in DOC_STATUSES_IN_FLIGHT: + return True + if status in (DOC_STATUS_INDEXED, DOC_STATUS_NOT_FOUND, *DOC_STATUSES_PARTIAL): + return False + if status in DOC_STATUSES_FAILED: + return False + logger.warning( + f"document {document_id} reported unrecognised status {status!r}; treating " + f"it as still indexing. If this is terminal, add it to the appropriate set " + f"in ingestion_consumer.py" + ) + return True + + def wait_until_retrievable( backend: Any, kb_ref: str, @@ -358,12 +394,34 @@ def wait_until_retrievable( interval_seconds: Optional[float] = None, sleep: Any = time.sleep, ) -> Optional[str]: - """Poll until a retrieval actually returns ``document_id``. - - Returns the timestamp at which it first became retrievable, or ``None`` on - timeout. A probe that itself errors is treated as "not yet", not as a document - failure: the document is usually fine and merely slow, and failing it would fail - uploads that are about to work. + """Confirm a retrieval really returns ``document_id``, filtered to that document. + + Returns the timestamp at which it was first confirmed, or ``None`` on timeout. + A probe that itself errors is treated as "not yet", not as a document failure: + the document is usually fine and merely slow, and failing it would fail uploads + that are about to work. + + THE FILTER IS THE WHOLE POINT + An earlier version searched for the document *id as the query text* and checked + whether that document appeared in the top 5 results. A document id carries no + meaning to an embedding model, so the search returned whatever the reranker + liked best — measured in dev with two documents in the knowledge base, querying + ``DOC-40e985680a63`` returned five chunks and every one of them belonged to a + *different* document. The probe reported "not retrievable" for a document that + was perfectly retrievable. + + That failure scales the wrong way: the more documents a knowledge base holds, + the less likely the target appears in an unfiltered top-5, so every upload to a + mature knowledge base would burn its full poll budget and then dead-letter. It + only ever worked when the knowledge base held a single document, where anything + returned was necessarily the right thing. + + An ``equals`` filter on ``document_id`` makes the question exact: chunks come + back only for this document, so a non-empty result *is* proof of retrievability + and an empty one is a true negative. Verified against dev: each document + returned 5 of its own chunks, and a fabricated id returned none. ``equals`` is + in ``ISOLATION_SAFE_FILTER_OPERATORS``, so it passes the adapter's filter + validation. The timeouts default to ``None`` and are resolved from the module constants *at call time*, rather than being bound as default arguments. Default arguments are @@ -378,14 +436,23 @@ def wait_until_retrievable( if interval_seconds is None: interval_seconds = RETRIEVABLE_POLL_INTERVAL_SECONDS + # Exact-match only. A prefix or substring operator would let `DOC-1` match + # `DOC-10` and confirm the wrong document as retrievable. + document_filter = {"equals": {"key": "document_id", "value": document_id}} + deadline = time.monotonic() + timeout_seconds while time.monotonic() < deadline: try: - chunks = asyncio.run(backend.search(kb_ref, document_id, 5)) + chunks = asyncio.run( + backend.search(kb_ref, document_id, 5, retrieval_filter=document_filter) + ) except Exception as exc: # noqa: BLE001 - a probe failure is not a document failure logger.warning(f"retrievability probe for {document_id} failed: {exc}") chunks = [] + # The filter already restricts the result set to this document, so anything + # coming back is the answer. The per-chunk check stays as a belt-and-braces + # guard against a filter that is silently ignored by a future API change. for chunk in chunks or []: metadata = getattr(chunk, "metadata", None) or {} if metadata.get("document_id") == document_id: @@ -463,17 +530,38 @@ def handle_object(bucket: str, key: str) -> Dict[str, Any]: return {"routed": "managed", "ingested": False, "document_id": document_id, "status": status} - if status in DOC_STATUSES_IN_FLIGHT: - # Already being indexed. Do NOT ingest again — that would discard the - # progress this invocation is waiting on. Leave it non-terminal so the - # event source brings us back, by which time Bedrock may have finished. + if status == DOC_STATUS_NOT_FOUND: + # Bedrock has never heard of it, so this is the first delivery. Submit. + try: + asyncio.run(backend.ingest(assistant_id, source)) + except Exception as exc: + logger.error(f"direct ingestion of {document_id} failed: {exc}", exc_info=True) + set_document_terminal(assistant_id, document_id, STATUS_FAILED, error=str(exc)) + raise + else: + # Already submitted — a redelivery, or a document still being worked on. + # Do NOT ingest again: re-submitting discards the progress this invocation + # is about to wait for, which is what turned a slow success into a + # permanent failure in dev. logger.info( - f"document {document_id} is {status} in the knowledge base; not " - f"re-ingesting, waiting for redelivery" + f"document {document_id} is already {status} in the knowledge base; " + f"not re-ingesting" ) - raise IngestionRoutingError( - f"document {document_id} is still {status}; leaving it for redelivery" + + # One wait, whichever way we arrived. Both "just submitted" and "found it + # mid-flight" need the same thing: give Bedrock time, bounded by a budget that + # fits inside this Lambda, because redelivery is capped at 2 retries. + if _still_working(status, document_id) or status == DOC_STATUS_NOT_FOUND: + status, bedrock_updated_at = wait_until_indexed(backend, assistant_id, document_id) + + if status in DOC_STATUSES_FAILED: + logger.error(f"document {document_id} became {status} during indexing") + set_document_terminal( + assistant_id, document_id, STATUS_FAILED, + error=f"the knowledge base reports this document as {status}", ) + return {"routed": "managed", "ingested": True, "document_id": document_id, + "status": status} if status in DOC_STATUSES_PARTIAL: logger.warning( @@ -481,37 +569,14 @@ def handle_object(bucket: str, key: str) -> Dict[str, Any]: f"content or metadata did not index" ) - already_indexed = status == DOC_STATUS_INDEXED or status in DOC_STATUSES_PARTIAL - - if not already_indexed: - try: - asyncio.run(backend.ingest(assistant_id, source)) - except Exception as exc: - logger.error(f"direct ingestion of {document_id} failed: {exc}", exc_info=True) - set_document_terminal(assistant_id, document_id, STATUS_FAILED, error=str(exc)) - raise - - # Submitted. Wait briefly for indexing so a small document finishes in this - # one invocation, then hand the slow ones back to redelivery. - status, bedrock_updated_at = wait_until_indexed(backend, assistant_id, document_id) - - if status in DOC_STATUSES_FAILED: - logger.error(f"document {document_id} became {status} during indexing") - set_document_terminal( - assistant_id, document_id, STATUS_FAILED, - error=f"the knowledge base reports this document as {status}", - ) - return {"routed": "managed", "ingested": True, "document_id": document_id, - "status": status} - - if status not in (DOC_STATUS_INDEXED, *DOC_STATUSES_PARTIAL): - # Still indexing. Deliberately NOT marked terminal, and deliberately - # not given an invented timestamp — the next delivery will find it - # INDEXED and record Bedrock's own. - raise IngestionRoutingError( - f"document {document_id} is {status} after submission; leaving it " - f"for redelivery to confirm indexing" - ) + if status not in (DOC_STATUS_INDEXED, *DOC_STATUSES_PARTIAL): + # Still not done inside our budget. Deliberately NOT marked terminal, and + # deliberately not given an invented timestamp — a later delivery will find + # it INDEXED and record Bedrock's own. + raise IngestionRoutingError( + f"document {document_id} is {status} after waiting; leaving it for " + f"redelivery to confirm indexing" + ) # INDEXED. `indexedAt` is Bedrock's OWN timestamp, not this process's clock — # an earlier version recorded `_now_iso()` immediately after the ingest call diff --git a/backend/tests/lambdas/test_kb_ingestion_consumer.py b/backend/tests/lambdas/test_kb_ingestion_consumer.py index cf0d07fe..909b0452 100644 --- a/backend/tests/lambdas/test_kb_ingestion_consumer.py +++ b/backend/tests/lambdas/test_kb_ingestion_consumer.py @@ -13,6 +13,7 @@ legacy must ingest NOTHING here, managed must ingest here and NOT fall back. """ +import logging from datetime import datetime, timezone from unittest.mock import MagicMock, patch @@ -122,11 +123,17 @@ class _FakeBackend: a slow one; the last value repeats forever. """ - def __init__(self, statuses=None): + def __init__(self, statuses=None, other_documents=("DOC-someone-else",)): self.ingested = [] self.status_calls = 0 + self.search_filters = [] self._statuses = list(statuses or ["NOT_FOUND", "INDEXED"]) self._agent_client = _FakeAgentClient(self) + # Models a knowledge base that holds OTHER documents too. Without this a + # probe that ignores its filter still passes, because the only document + # present is the one being looked for — which is exactly why the + # query-by-document-id probe survived until a second document existed. + self._other_documents = list(other_documents) def next_status(self): if len(self._statuses) > 1: @@ -145,10 +152,56 @@ async def ingest(self, kb_ref, source): self.ingested.append(source.document_id) return None - async def search(self, kb_ref, query, top_k=5): - chunk = MagicMock() - chunk.metadata = {"document_id": DOCUMENT_ID} - return [chunk] + async def search(self, kb_ref, query, top_k=5, retrieval_filter=None): + """Honours an ``equals`` filter on ``document_id``; otherwise ranks badly. + + The unfiltered branch returns the *other* documents, which is what the real + service did: a document id is meaningless to an embedding model, so an + unfiltered search returns whatever the reranker prefers. Measured in dev + with two documents, querying one id returned five chunks that all belonged + to the other. + """ + self.search_filters.append(retrieval_filter) + + wanted = None + if retrieval_filter: + equals = retrieval_filter.get("equals") or {} + if equals.get("key") == "document_id": + wanted = equals.get("value") + + if wanted is not None: + doc_ids = [wanted] if wanted == DOCUMENT_ID else [] + else: + doc_ids = list(self._other_documents) + + chunks = [] + for doc_id in doc_ids: + chunk = MagicMock() + chunk.metadata = {"document_id": doc_id} + chunk.document_id = doc_id + chunks.append(chunk) + return chunks + + +@pytest.fixture(autouse=True) +def _fast_polls(monkeypatch): + """Never wait production durations in a unit test. + + The consumer's budgets are deliberately long — INDEXED_POLL_TIMEOUT_SECONDS is + 600 s because Lambda's async retry is capped at 2 attempts, so the wait for + indexing has to happen inside one invocation. Left unpatched, the handful of + tests that exercise a document which never finishes indexing would hold this + file for over twenty minutes. + + This is exactly why those constants are resolved at CALL time rather than bound + as default arguments: a default argument is evaluated once at import and cannot + be patched, which an earlier version of this module got wrong and which cost a + 33-second test that silently ignored its own override. + """ + monkeypatch.setattr(ic, "INDEXED_POLL_TIMEOUT_SECONDS", 0.05) + monkeypatch.setattr(ic, "INDEXED_POLL_INTERVAL_SECONDS", 0.001) + monkeypatch.setattr(ic, "RETRIEVABLE_POLL_TIMEOUT_SECONDS", 0.05) + monkeypatch.setattr(ic, "RETRIEVABLE_POLL_INTERVAL_SECONDS", 0.001) # --------------------------------------------------------------------------- @@ -478,7 +531,7 @@ def test_a_redelivery_completes_the_document_without_a_second_ingest(self, table first = _FakeBackend(statuses=["NOT_FOUND", "IN_PROGRESS"]) with patch( "apis.shared.kb_backend.managed_backend.ManagedKbBackend", return_value=first - ), patch.object(ic, "INDEXED_POLL_TIMEOUT_SECONDS", 0.01): + ): with pytest.raises(ic.IngestionRoutingError): ic.handle_object(BUCKET, KEY) assert first.ingested == [DOCUMENT_ID] @@ -554,9 +607,175 @@ def _agent(self): fake = _ProbeBroken(statuses=["NOT_FOUND"]) with patch( "apis.shared.kb_backend.managed_backend.ManagedKbBackend", return_value=fake - ), patch.object(ic, "INDEXED_POLL_TIMEOUT_SECONDS", 0.01): + ): with pytest.raises(ic.IngestionRoutingError): ic.handle_object(BUCKET, KEY) assert fake.ingested == [DOCUMENT_ID], "a probe failure must not block ingestion" assert _doc(table)["status"] != "failed" + + +# --------------------------------------------------------------------------- +# The retrievability probe must ask an exact question +# --------------------------------------------------------------------------- +class TestTheRetrievabilityProbeIsFiltered: + """Found in dev on 2026-09-01, with two documents in the knowledge base. + + The probe searched for the document *id as the query text* and checked whether + that document came back in the top 5. A document id means nothing to an + embedding model, so the search returned whatever the reranker preferred: + querying `DOC-40e985680a63` returned five chunks and every one belonged to a + different document. A perfectly retrievable document was reported as not + retrievable. + + It scales the wrong way — the more documents a knowledge base holds, the less + likely the target appears in an unfiltered top-5 — so every upload to a mature + knowledge base would burn its poll budget and dead-letter. It only ever worked + while the knowledge base held exactly one document, where anything returned was + necessarily the right thing. + """ + + def _seed_managed(self, table): + _seed_kb(table, retrievalEngine="managed", awsKbId="KB123", awsDataSourceId="DS456") + + def test_the_probe_filters_to_the_document_being_confirmed(self, table): + self._seed_managed(table) + fake = _FakeBackend(statuses=["INDEXED"]) + + with patch( + "apis.shared.kb_backend.managed_backend.ManagedKbBackend", return_value=fake + ): + ic.handle_object(BUCKET, KEY) + + assert fake.search_filters, "the probe never searched" + assert all(f is not None for f in fake.search_filters), ( + "the retrievability probe searched WITHOUT a filter; with other " + "documents present it can return five chunks that all belong to " + "something else and report a good document as not retrievable" + ) + assert fake.search_filters[0] == { + "equals": {"key": "document_id", "value": DOCUMENT_ID} + } + + def test_the_filter_uses_exact_match_not_a_prefix(self, table): + """`startsWith` would let DOC-1 confirm DOC-10 as retrievable.""" + self._seed_managed(table) + fake = _FakeBackend(statuses=["INDEXED"]) + + with patch( + "apis.shared.kb_backend.managed_backend.ManagedKbBackend", return_value=fake + ): + ic.handle_object(BUCKET, KEY) + + operators = {op for f in fake.search_filters for op in (f or {})} + assert operators == {"equals"}, f"unsafe filter operator(s): {operators}" + + def test_a_document_confirms_even_when_others_rank_higher(self, table): + """The regression itself: other documents present must not hide this one.""" + self._seed_managed(table) + fake = _FakeBackend( + statuses=["INDEXED"], + other_documents=("DOC-noise-1", "DOC-noise-2", "DOC-noise-3"), + ) + + with patch( + "apis.shared.kb_backend.managed_backend.ManagedKbBackend", return_value=fake + ): + ic.handle_object(BUCKET, KEY) + + assert _doc(table)["status"] == "complete" + + +# --------------------------------------------------------------------------- +# Statuses the SDK does not declare +# --------------------------------------------------------------------------- +class TestUndeclaredStatusesAreWaitedOut: + """`TEXT_INDEXED` is returned by the live service and is NOT in the packaged + model's DocumentStatus enum. Observed in dev on a document with image + extraction enabled: TEXT_INDEXED first, INDEXED later.""" + + def _seed_managed(self, table): + _seed_kb(table, retrievalEngine="managed", awsKbId="KB123", awsDataSourceId="DS456") + + def test_text_indexed_is_not_treated_as_done(self, table): + """Marking complete here would claim an image-only page is ready while the + vision model is still running — the exact report this module prevents.""" + self._seed_managed(table) + fake = _FakeBackend(statuses=["TEXT_INDEXED"]) + + with patch( + "apis.shared.kb_backend.managed_backend.ManagedKbBackend", return_value=fake + ): + with pytest.raises(ic.IngestionRoutingError): + ic.handle_object(BUCKET, KEY) + + assert _doc(table)["status"] != "complete" + + def test_text_indexed_does_not_cause_a_re_ingest(self, table): + self._seed_managed(table) + fake = _FakeBackend(statuses=["TEXT_INDEXED"]) + + with patch( + "apis.shared.kb_backend.managed_backend.ManagedKbBackend", return_value=fake + ): + with pytest.raises(ic.IngestionRoutingError): + ic.handle_object(BUCKET, KEY) + + assert fake.ingested == [] + + def test_text_indexed_becoming_indexed_completes_the_document(self, table): + """The observed real sequence. It must converge, not stall.""" + self._seed_managed(table) + fake = _FakeBackend(statuses=["TEXT_INDEXED", "TEXT_INDEXED", "INDEXED"]) + + with patch( + "apis.shared.kb_backend.managed_backend.ManagedKbBackend", return_value=fake + ): + ic.handle_object(BUCKET, KEY) + + assert _doc(table)["status"] == "complete" + assert fake.ingested == [], "already submitted; must not re-ingest" + + def test_a_status_nobody_has_seen_before_is_waited_out_not_failed(self, table): + """A future AWS status value must not dead-letter documents.""" + self._seed_managed(table) + fake = _FakeBackend(statuses=["SOME_FUTURE_STATUS"]) + + with patch( + "apis.shared.kb_backend.managed_backend.ManagedKbBackend", return_value=fake + ): + with pytest.raises(ic.IngestionRoutingError): + ic.handle_object(BUCKET, KEY) + + item = _doc(table) + assert item["status"] != "failed", ( + "an unrecognised status failed the document; unknown values must be " + "waited out, because the service already returns one the SDK omits" + ) + + def test_text_indexed_is_a_classified_status_not_an_unknown_one(self, table, caplog): + """Recognition is the only thing that distinguishes it, so test that. + + Dropping TEXT_INDEXED from DOC_STATUSES_IN_FLIGHT is behaviour-equivalent: + `_still_working` waits on unrecognised statuses too, so the document is + handled identically either way. A mutation removing it therefore survives + every behavioural assertion — which means the only honest thing left to + assert is that we have CLASSIFIED it, and are not merely falling through the + unknown-status branch and logging a warning on every poll for a state we + have already seen in production and understand. + """ + self._seed_managed(table) + fake = _FakeBackend(statuses=["TEXT_INDEXED"]) + + with caplog.at_level(logging.WARNING): + with patch( + "apis.shared.kb_backend.managed_backend.ManagedKbBackend", return_value=fake + ): + with pytest.raises(ic.IngestionRoutingError): + ic.handle_object(BUCKET, KEY) + + assert "TEXT_INDEXED" in ic.DOC_STATUSES_IN_FLIGHT + assert not any("unrecognised status" in r.message for r in caplog.records), ( + "TEXT_INDEXED was handled by the unknown-status fallback; it is a state " + "we have observed in production and it should be classified explicitly" + ) From 04002663128a0333c66aadba4b6d2b5119d84bea Mon Sep 17 00:00:00 2001 From: derrickfink Date: Tue, 1 Sep 2026 17:39:07 -0600 Subject: [PATCH 2/2] docs(kb): correct the PR number for findings 38-39 I guessed #902 when writing the handoff entries; the PR is actually #908. #902 is an unrelated, already-merged PR, so those references pointed somewhere misleading. --- .kiro/specs/managed-kb-migration/HANDOFF.md | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/.kiro/specs/managed-kb-migration/HANDOFF.md b/.kiro/specs/managed-kb-migration/HANDOFF.md index b249a232..921b1d4b 100644 --- a/.kiro/specs/managed-kb-migration/HANDOFF.md +++ b/.kiro/specs/managed-kb-migration/HANDOFF.md @@ -20,7 +20,7 @@ Four things invalidate earlier versions of this document: deployed clean. They are §5 items 25–39 and they are the most useful part of this document. Two clusters: 32–36 trace to the two engines never being made exclusive (PR #900), and 37–39 to the ingestion consumer never actually knowing - when a document was ready (PRs #901, #902). Only §5.33 is still open. + when a document was ready (PRs #901, #908). Only §5.33 is still open. 3. **The `document_id` "known unknown" was a false alarm** and is now resolved with measurements — see §6. An earlier revision listed it as the top open risk. The probe was reading facade keys that have never existed. Two genuine findings came @@ -46,7 +46,7 @@ Four things invalidate earlier versions of this document: | Implementation | Groups 1–14 except 14.5. A migration has completed `shadow → verify → promote → retain` in dev and serves from the managed backend | | Tests | 640 infra (jest) · ~6,840 backend (pytest) · 1,936 frontend (vitest) · 5 pre-existing unrelated Strands failures | | Deployed | **dev and prod.** Flags off in prod; `migrationEnabled` on in dev | -| Open PRs | **#902** — the filtered retrievability probe (§5.38) and `TEXT_INDEXED` (§5.39), plus this document. · merged: #898 `ef2f4c9e`, #899, #900 `df93471c`, #901 `a4b660ba` | +| Open PRs | **#908** — the filtered retrievability probe (§5.38) and `TEXT_INDEXED` (§5.39), plus this document. · merged: #898 `ef2f4c9e`, #899, #900 `df93471c`, #901 `a4b660ba` | | Uncommitted | none | ### Flag state (GitHub Environment variables) @@ -822,7 +822,7 @@ and every mechanism it used to answer was measuring something else. homes.** 38. ✅ **The retrievability probe searched for the document id as query text and - could not find its own document** (fixed in PR #902). `wait_until_retrievable` + could not find its own document** (fixed in PR #908). `wait_until_retrievable` ran `search(kb_ref, document_id, 5)` — the id *as the query* — then checked whether that document appeared. A document id is meaningless to an embedding model, so the search returned whatever the reranker preferred. Measured in dev @@ -850,7 +850,7 @@ and every mechanism it used to answer was measuring something else. retrievable. A number agreeing with your expectation is not confirmation. 39. ✅ **The live service returns `TEXT_INDEXED`, which is not in the packaged - SDK's `DocumentStatus` enum** (handled in PR #902). Observed on a document with + SDK's `DocumentStatus` enum** (handled in PR #908). Observed on a document with image extraction enabled: `TEXT_INDEXED` (text searchable, media still processing) then `INDEXED`. The enum in the packaged model lists twelve values and this is not among them, so **do not derive status handling from the SDK