--- title: Incident post mortem — silent 200s on the batappli context description: Post mortem of a production incident: an unbounded RAG fallback, a dead provider slot, and a failure that surfaced to clients as a success. date: 2026-09-05 lang: en-US author: Julien Béranger model: Claude Opus 5 source: https://julienberanger.com/qgen-post-mortem-sept-4-2026 --- # Incident post mortem — silent 200s on the batappli context | | | |---|---| | **Incident date** | 4 September 2026 | | **Detected** | 5 September 2026, from `/home/ubuntu/.pm2/logs/qgen-error.log` (last 500 lines) | | **Severity** | High — user-facing requests failed while returning HTTP 200 | | **Status** | Resolved 5 September 2026, verified in production | | **Author** | julien@strat.cc | > Note: the errors analysed here are from **4 September 2026**, not August — the > file name is kept as-is for continuity with the archive. ## Summary Five requests against the `batappli` context failed end to end (15:05, 15:07, 15:08, 15:14 and 21:46 UTC), each ending in an unhandled `TypeError: Cannot read properties of undefined (reading 'substring')`. A single transient Mistral rate limit on a cheap auxiliary call was enough to make **every** model in the fallback sequence fail, because the degradation path built a prompt larger than any model's context window. The resulting crash then hid the failure from the caller: the API answered **HTTP 200 with `output: undefined`**. The incident had two independent contributing defects — an unbounded RAG fallback, and a missing error path in `ask()` — plus a latent configuration problem: the Mistral models configured for both roles were not callable on the current subscription tier at all. ## Impact - 5 known failed requests on the `batappli` context, all returning a successful-looking empty response rather than an error. - Clients had no way to distinguish "no answer" from "empty answer": no non-2xx status, no error body. - The Mistral branch of the fallback sequence was effectively dead for the whole period (403 `tier_not_allowed`), so provider redundancy was one provider thinner than assumed. - No data loss, no persistence corruption. ## Timeline (UTC) | Time | Event | |---|---| | 2026-09-04 15:05 | First failure: `429` on the RAG selection call to `mistral-small-latest` | | 2026-09-04 15:05 | Selection fallback loads the entire `batappli` context (~4.8 MB → ~2.25 M tokens) | | 2026-09-04 15:05 | All four models in the fallback sequence reject the prompt | | 2026-09-04 15:05 | `ask()` crashes on `undefined.substring(...)`, outer catch returns 200 | | 2026-09-04 15:07, 15:08, 15:14, 21:46 | Same cascade repeats, four more times | | 2026-09-05 ~07:00 | Incident found while reviewing `qgen-error.log` | | 2026-09-05 07:24 | Fixes committed (`035e0f9`) and deployed | | 2026-09-05 07:36 | Production verification run passes against `83.228.208.214:3000` | ## The cascade 1. **Rate limit on the RAG selection call.** `RagService.selectRelevantFiles` called `mistral-small-latest` to pick which context files are relevant. Mistral answered `429 {"message":"Rate limit exceeded","code":"1300"}`. ``` ERROR [MistralService] Mistral API error response: {"object":"error","message":"Rate limit exceeded",...} ERROR [RagService] Error in file selection for context batappli: Failed to process message with Mistral AI (mistral-small-latest) ``` 2. **The fallback loaded the entire context.** On selection failure the service returned *every* file in the index. `data/contexts/batappli` is ~4.8 MB, so the system prompt became roughly 2 million tokens — larger than any configured model's context window. What was meant as graceful degradation was in fact a guaranteed failure. 3. **Every model in the fallback sequence rejected the prompt**, each for its own reason, so retrying across providers could not help: | Model | Error | |---|---| | `anthropic` | `prompt is too long: 2250703 tokens > 200000 maximum` | | `mistral` | `403 tier_not_allowed` — "This model is not available in your subscription tier" | | `openai` | `429 rate_limit_exceeded` — TPM limit 200 000, requested 1 205 848 | | `deepseek` | `maximum context length is 1048576 tokens, requested 2008311` | ``` ERROR [AppService] All models in fallback sequence failed. Last error: Failed to process message with DeepSeek ``` 4. **The failure crashed the logger instead of being reported.** With no model succeeding, `output` stayed `undefined`; `JSON.stringify(undefined)` returns `undefined`, and the log-append step called `.substring(0, 10)` on it: ``` ERROR [AppService] TypeError: Cannot read properties of undefined (reading 'substring') at AppService.ask (/home/ubuntu/qgen/dist/app.service.js:542:35) ``` The outer `try/catch` in `ask()` then swallowed the exception and returned **HTTP 200 with `output: undefined`** — the client saw a successful-looking empty response rather than an error. ## Root causes - **Unbounded RAG fallback.** Falling back to "all files" is only viable for small contexts. At 4.8 MB it turned a recoverable 429 into a total outage for that request. - **Wrong Mistral models for the subscription tier.** `mistral-small-latest` (selection) was rate-limited on essentially every call and `mistral-large-latest` (generation) returned `403 tier_not_allowed`. The 429 that triggered the incident was therefore not a transient blip but the steady state; and the Mistral slot in the fallback sequence could never succeed. - **`RAG_SELECTION_MODEL` was ignored.** The config key existed but `RagService` hardcoded the model name, so the misconfiguration could not be corrected without a code change. - **No retry on the selection call.** A single 429 on a cheap, fast call took down the whole request path; one retry with backoff would have avoided all five failures. - **Failure treated as success.** `ask()` had no error path for "no model produced output", so the fault surfaced as a crash in unrelated logging code and then as a silent 200. ## Resolution All changes shipped in `035e0f9` (5 September 2026), with test mocks updated in `59be1d9`. **1. Bounded the RAG degradation path.** `src/rag/rag.service.ts` — on selection failure the fallback now returns `RAG_REQUIRED_FILES` plus at most `RAG_MAX_FILES` other files, and logs the degradation at `warn`: ```ts const selectedFiles = [ ...requiredFiles, ...allFiles.filter((f) => !requiredFiles.includes(f)).slice(0, maxFiles), ]; this.logger.warn( `Falling back to ${selectedFiles.length}/${allFiles.length} files: ...`, ); ``` A selection failure now costs relevance, not the request. **2. Made failure visible.** `src/app.service.ts` — when no model succeeds, `ask()` throws `ServiceUnavailableException` carrying the last provider error, and the outer catch re-throws `HttpException`s instead of converting them into a 200. The log-append call is also guarded against a non-string output, so the `.substring` crash cannot recur: ```ts if (!modelProcessed) { throw new ServiceUnavailableException( `All models failed to process the request. Last error: ${lastErrorMessage}`, ); } ``` **3. Moved both Mistral roles to the Ministral family**, the only one this subscription tier can actually call: | Role | Before | After | |---|---|---| | RAG file selection | `mistral-small-latest` (429 `rate_limited`) | `ministral-3b-latest` | | Response generation | `mistral-large-latest` (403 `tier_not_allowed`) | `ministral-8b-latest` | `RagService` now honours `RAG_SELECTION_MODEL` (defaulting to `ministral-3b-latest`) instead of hardcoding the model, and `.env.template` was updated to match — so the next tier change is a config edit, not a deploy. **4. Fixed the cost and attribution bookkeeping** exposed by the same log review. `MistralService` now carries per-model rates rather than one flat rate, so a call is billed at the rate of the model actually used; responses report the Mistral model actually called instead of the hardcoded label `mistral-large-2411`; off-topic verdicts are attributed to the selection model that produced them. Rates were re-verified against provider pricing pages (2026-08-31), which also surfaced missing `COST_RATES` entries for `gpt-4o-mini`, `mistral-large-latest` and `deepseek-v4-flash` — these had been falling through to a $15/$75-per-million default and were billed up to 100× too high. **5. Updated the tests to the new contract.** `src/app.service.spec.ts` — the test asserting the old "return an empty response" behaviour now asserts the exception (`should fail loudly if all models fail`). ## Verification Production acceptance run against `http://83.228.208.214:3000`, 5 September 2026 07:36 UTC: ``` pnpm test:mur-blanc:prod PASS test/acceptance/mur-blanc.e2e-spec.ts (39.528 s) Mur Blanc Query (acceptance) ✓ should handle white wall painting quote request (7157 ms) ✓ should return valid JSON with correct schema (5605 ms) ✓ should maintain consistent schema across multi-turn conversation (25184 ms) Test Suites: 1 passed, 1 total Tests: 3 passed, 3 total ``` Full transcript: `test/output/2026-09-05T07-36-30-190Z-mur-blanc.md`. What it confirms: - **RAG selection succeeded** — `ministral-3b-latest` selected 6 files out of 112 available (`selectionMethod: "rag-two-step"`), for $0.0005086. The chronic 429s are gone, so the degradation path is not being exercised at all. - **Generation succeeded** on `claude-haiku-4-5-20251001` in 7.04 s, at $0.02919 total — an amount consistent with a ~104 K-token prompt, not a 2 M-token one. - **Schema held across three turns** — all responses used `devis.contenu.articles`, the `contenu` wrapper and `conditions`, with no forbidden fields. ## Remaining follow-ups - **No retry/backoff** on the selection call. The model switch removed the trigger, but not the fragility: one 429 still degrades the request. A single retry with backoff would close this. - **`docs/FALLBACKS.md` is stale.** It still documents "System loads ALL files from the context" as the selection fallback (line 23), the old `mistral-small-latest` selection model (lines 16, 231), and `mistral-large-2411` as the generation default. It should be rewritten against the current behaviour. - **Jest does not exit** after the acceptance run ("asynchronous operations that weren't stopped"). Test-harness hygiene only — unrelated to this incident, but it will mask a real hang eventually. Worth a `--detectOpenHandles` pass. - **No alerting on this class of failure.** The incident was found by reading logs a day later. Now that all-models-failed raises a 503, it is possible to alert on it. ## Other errors visible in the same log - **`OFF_TOPIC` logged as ERROR** (~50 occurrences, April–September). This is normal control flow — the off-topic guardrail firing — logged at error level. Pure noise; belongs at `warn` or `debug`. - **`Cannot find module '/home/ubuntu/qgen/dist/main'`** (repeated, earliest entries). PM2 restart-looping against a missing build — the service was started before `pnpm build` had produced `dist/`. - **Anthropic `invalid_request_error`: "Your credit balance is too low"** (7 July, ~12 requests). Billing exhaustion, since resolved; note that requests did *not* fall through to another provider cleanly at the time. ## Lessons 1. **A degradation path that can't succeed is not a degradation path.** Falling back to "everything" was never viable for a 4.8 MB context; it should have been bounded by the same limit as the happy path from the start. 2. **Never turn a failure into a 200.** The `.substring` crash was noisy and easy to find; the silent success it produced was the actually dangerous part, and it hid the outage from every client. 3. **Verify that configured models are callable on the current tier.** Both Mistral models had been failing on every request — one at 429, one at 403 — without anyone noticing, because the failures were absorbed by fallbacks. 4. **Config keys that are not read are worse than no config key.** `RAG_SELECTION_MODEL` looked like the remediation lever and wasn't wired up.