From 0944c9627daa5b01b3c3d51a6570d30c1c0455c1 Mon Sep 17 00:00:00 2001 From: NGHTBOY Date: Thu, 27 Aug 2026 18:07:50 +0200 Subject: [PATCH] fix(worker): size the re-index ceiling from a rebuild that finished MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Three ceilings cut three runs off on 2026-08-27 before one was measured to the end: 1800.02 s inside `code_symbol_embed`, 3600.00 s inside `generate_docs` at document 80 of 758, and a deploy. The run that reached `pipeline_end` at 15:51:39 gives the number. A full rebuild of that repository — 9 981 files, 758 documents — costs 12 039 s (3.34 h), summed from measured segments rather than one wall clock, because the run was interrupted twice and a span across an idle gap would overstate the work: 151 s setup + ast_parse + graph_build 2300 s code_symbol_embed 144 s analyze_files + cross_file_analysis + graph_db_bridge 9375 s generate_docs, 758 docs at ~4.8/min across three segments 69 s embed_and_store + bm25 + the chained code<->DB sync 12039 s `repo_index_job_timeout_seconds` defaults to 16200 — 35% over that. Both dominant steps scale with repository size rather than with a clock, so the headroom is not decoration. Two corrections to the earlier entry in this same release, both mine: - It claimed the cron and the button run "the same work under two ceilings". They do not. `daily_knowledge_sync_service._run_repo_index` passes `force_full=False, chain_sync=False`, so the cron's 42.4-minute `completed` run was an incremental index with the chain off — never a full rebuild, and the reading that sized the knob at 1800 and then 3600. - The test asserting `repo < daily` rested on that reading and actively capped the manual path below what it needs. Replaced by checks that each ceiling is sized against the work it carries, plus a guard that fails if the cron stops being incremental. Board, from the same run: - CB-OPS1 now carries a real number. Peak 1246 MB (112.7%), 45 x R14, 0 x R15 across 3.34 h on Standard-2X, every R14 inside `generate_docs`. The earlier "zero R14/R15" measured a rebuild that never reached the late steps. - CB-KNOW1 added. The shape guard dropped 48 of 280 cached names and took `mismatch` 6 -> 0, but `clientlogses`, `mobile_identifierses`, `twiliocallses` and `twiliophoneses` remain: an already-plural class name pluralised a second time. They pass the shape rule legitimately, so a different rule is needed. The chained sync ran unprompted at the end — `code_db_sync` 15:50:26 -> 15:51:39 — the first live confirmation of `auto_sync_after_index` defaulting on. Co-Authored-By: Claude Opus 5 (1M context) --- CHANGELOG.md | 39 ++++ CLAUDE.md | 3 +- backend/.env.example | 21 +-- backend/app/config.py | 40 +++-- .../unit/services/test_repo_index_ceiling.py | 169 +++++++++++------- docs/qa-audit/issues.md | 7 +- 6 files changed, 191 insertions(+), 88 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 132c9eef..84fe4373 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -6,6 +6,45 @@ The format is based on [Keep a Changelog](https://keepachangelog.com/en/1.1.0/). ## [Unreleased] +### Fixed — a full re-index could not finish, and the ceiling was the symptom + +Three ceilings cut three runs off on 2026-08-27 — 1800.02 s inside `code_symbol_embed`, +3600.00 s inside `generate_docs` at document 80 of 758, and a deploy — before the real +obstacle was found. `_run_steps` reads the completed-step set once +(`pipeline_runner.py:168`) and gated four steps on it. **`code_symbol_embed` wrote +`complete_step` and nothing read it**, so every resume ran it again: + + 11:37:23 → 12:15:43 code_symbol_embed 2300 s + 12:44:57 → 13:20:33 code_symbol_embed 2136 s ← the same work, redone + +Attempt N+1 therefore reached no further than attempt N, and no ceiling could have +fixed that. With the gate in place, measured live: enqueue → `generate_docs` in **96 s** +against ~36 minutes before. `ast_parse` and `graph_build` stay ungated deliberately — +the first rebuilds in-memory state nothing else supplies, the second merges into the +stored graph — and a test fails if either joins the gated set. The pattern was already +one step later in the same file: `generate_docs` resumes per document +(`processed_doc_paths`), confirmed live at 80 → 300 → 758. + +**Two corrections to this release's own earlier entry.** It claimed the cron and the +button run "the same work under two ceilings". They do not: +`daily_knowledge_sync_service._run_repo_index` passes `force_full=False, +chain_sync=False`, so the cron's 42.4-minute `completed` run was an *incremental* +index with the chain off — never a full rebuild. And a test asserting `repo < daily` +on the strength of that reading actively capped the manual path below what it needs; +it is replaced by checks that each ceiling is sized against the work it actually +carries, plus a guard that fails if the cron stops being incremental. + +A full rebuild of that repository — 9 981 files, 758 documents — measures **12 039 s +(3.34 h)**, summed from the segments of the run that reached `pipeline_end` at +15:51:39: `generate_docs` ~9 375 s at ~4.8 docs/min, `code_symbol_embed` ~2 300 s, +everything else ~364 s. `repo_index_job_timeout_seconds` now defaults to **16200**, +35 % over the measurement, and the number is argued in +`tests/unit/services/test_repo_index_ceiling.py` rather than chosen. + +The chained code↔DB sync ran on its own at the end — `code_db_sync` 15:50:26 → +15:51:39 — which is the first live confirmation of `auto_sync_after_index` defaulting +on. + ### Fixed — the nightly cron could rebuild a repository the "Re-index repository" button never could `run_repo_index_task` is the repo-index pipeline, and two ARQ jobs call it with two diff --git a/CLAUDE.md b/CLAUDE.md index 97e47dd3..cc217042 100644 --- a/CLAUDE.md +++ b/CLAUDE.md @@ -215,7 +215,8 @@ Worker functions (`backend/app/worker.py`): - `run_db_index` — schema indexing for a connection - `run_code_db_sync` — code↔DB cross-reference -- `run_repo_index` — Git repo knowledge pipeline (per-function timeout `repo_index_job_timeout_seconds`, **3600 s since 2026-08-27**). The same pipeline also runs *inside* `run_daily_project_knowledge_sync`, which carries its own 7200 s ceiling — so until the raise, the nightly cron rebuilt a 9 981-file repository in 42.4 min while every press of "Re-index repository" died at exactly 1800 s inside `code_symbol_embed`. Keep this knob **below** `daily_knowledge_sync_job_timeout_seconds`, which contains it plus a DB index plus a code↔DB sync; the ordering is asserted in `tests/unit/services/test_repo_index_ceiling.py`, not just commented. +- `run_repo_index` — Git repo knowledge pipeline (per-function timeout `repo_index_job_timeout_seconds`, **16200 s since 2026-08-27**). This job carries the **full** rebuild — `force_full=True` plus the chained code↔DB sync. The nightly cron runs the same pipeline with `force_full=False, chain_sync=False` under its own 7200 s ceiling, so **the two ceilings cover different work and must not be tied together**. Reading the cron's 42.4-minute incremental run as a full rebuild is what sized this knob at 1800 and then 3600, and each cut a real run off: 1800.02 s inside `code_symbol_embed`, 3600.00 s inside `generate_docs` at document 80 of 758. A full rebuild of that 9 981-file repository measures **12 039 s (3.34 h)** — `generate_docs` ~9 375 s at ~4.8 docs/min, `code_symbol_embed` ~2 300 s — summed from the segments of the run that reached `pipeline_end`. Asserted in `tests/unit/services/test_repo_index_ceiling.py`, which also fails if the cron stops being incremental. +- **A resume no longer repays `code_symbol_embed`.** `_run_steps` reads the completed-step set once (`pipeline_runner.py:168`) and gated only four steps on it; `code_symbol_embed` recorded completion that nothing read, so every resume spent its 38 minutes again and attempt N+1 reached no further than attempt N — no ceiling could fix that. Measured after the gate: enqueue → `generate_docs` in **96 s**, against ~36 min before. `ast_parse` and `graph_build` stay ungated deliberately (in-memory state; graph merge), and a test fails if either joins the gated set. - `run_batch` — batch query execution - `run_analytics_collect` — collect one analytics connection's reports into its fact tables (per-function timeout `analytics_collect_job_timeout_seconds`) diff --git a/backend/.env.example b/backend/.env.example index 6b0b24a9..44241cef 100644 --- a/backend/.env.example +++ b/backend/.env.example @@ -401,16 +401,17 @@ CORS_ORIGINS=["http://localhost:3000","http://localhost:3100","https://checkmyda # Wall-clock budget for one connection's collection job (ARQ per-function # timeout; also passed to the in-process fallback). # ANALYTICS_COLLECT_JOB_TIMEOUT_SECONDS=1800 -# Ceiling for one repo-index job, in seconds. The repo index is the longest job in -# the system; before 2026-08-19 it was the only long one with no knob and inherited -# ARQ's hardcoded 1800 s. Measured on a 9 981-file repository: a full rebuild takes -# 42.4 min, so 1800 s could never finish one and 3600 s finishes it with headroom. -# Keep this BELOW DAILY_KNOWLEDGE_SYNC_JOB_TIMEOUT_SECONDS, which grants the same -# pipeline its budget plus a DB index and a code↔DB sync — mismatching the two is -# how the nightly cron rebuilt a repository the manual button never could. -# Raising it only helps a worker that is NOT swapping: on an over-quota dyno it buys -# a longer crawl, not a finished index (AUD-0819-20). -# REPO_INDEX_JOB_TIMEOUT_SECONDS=3600 +# Ceiling for one repo-index job, in seconds. This job carries the FULL rebuild — +# `force_full=True` plus the chained code↔DB sync — while the nightly cron runs the +# same pipeline with `force_full=False, chain_sync=False`. Different work, so do NOT +# tie this to DAILY_KNOWLEDGE_SYNC_JOB_TIMEOUT_SECONDS; reading the cron's 42-minute +# incremental run as a full rebuild is what sized this at 1800 and then 3600, both +# of which cut real runs off. Measured end to end on a 9 981-file / 758-document +# repository: 12 039 s (3.34 h), dominated by generate_docs (~9 375 s at ~4.8 +# docs/min) and code_symbol_embed (~2 300 s). 16200 leaves 35 % over that; both +# steps scale with repository size, so raise it for a bigger repo rather than +# hoping. Raising it only helps a worker that is NOT swapping (AUD-0819-20). +# REPO_INDEX_JOB_TIMEOUT_SECONDS=16200 # How long a `running` batch may sit before another attempt may take its claim # (F-SCHED-07). `run_batch` inherits ARQ's class-level job_timeout of 1800 s, so past # that the previous attempt is provably dead — arq cancelled it. Matching the two is the diff --git a/backend/app/config.py b/backend/app/config.py index a96bd399..1d3343d0 100644 --- a/backend/app/config.py +++ b/backend/app/config.py @@ -520,18 +520,36 @@ def _fix_database_url(self) -> "Settings": # 8,552 files. It got a knob and the default was left at 1800 — the value that # had just been measured as too small. # - # Raised to 3600 on 2026-08-27, because leaving it produced the same failure - # eight days later and the reason to withhold the raise had gone. Two - # measurements, both from `indexing_runs` on the one real customer repository: + # Raised to 3600 on 2026-08-27 and that was still too small; corrected to 16200 + # the same day, after a full rebuild was measured to the end for the first time. # - # 08-25 22:00 completed 42.4 min nightly cron, ceiling 7200 s - # 08-27 09:30 TimeoutError 30.0 min manual re-index, ceiling 1800 s + # The first raise rested on a mis-reading worth recording, because it is easy to + # repeat: the cron's 42.4-minute `completed` run was read as a full rebuild. It + # is not. `daily_knowledge_sync_service._run_repo_index` passes + # `force_full=False, chain_sync=False` — an incremental index with the code↔DB + # chain off, because the cron runs that sync itself as a separate step. The two + # ceilings therefore cover different work, and "the same work under two + # ceilings" was wrong. # - # The same pipeline, the same 2 544 s of work, two ceilings — because the cron - # runs it *inside* `run_daily_project_knowledge_sync`, which carries - # `daily_knowledge_sync_job_timeout_seconds`. So the repository rebuilt - # unattended at 3 a.m. and could never rebuild when a person pressed - # "Re-index repository", which is the path an operator reaches for after a fix. + # What a full rebuild costs, summed from measured segments of the run that + # reached `pipeline_end` at 15:51:39 (9 981 files, 758 documents): + # + # 151 s setup + ast_parse + graph_build + # 2300 s code_symbol_embed + # 144 s analyze_files + cross_file_analysis + graph_db_bridge + # 9375 s generate_docs, 758 docs at ~4.8/min + # 69 s embed_and_store + bm25 + the chained sync + # 12039 s = 3.34 h + # + # 16200 s leaves 35 % over that. Both dominant steps scale with repository size + # rather than with a clock, so the headroom is not decoration. + # + # It cut off three runs before it was sized: 1800.02 s inside `code_symbol_embed`, + # 3600.00 s inside `generate_docs` at document 80 of 758, and once more at a + # deploy. Raising the ceiling was never the whole fix — until 2026-08-27 a resume + # re-ran `code_symbol_embed` (38 min) because nothing read its recorded + # completion, so attempt N+1 reached no further than attempt N. That gate is in + # `pipeline_runner.py`; this number only decides whether one attempt suffices. # # The old note said raising this only helps when the worker is not swapping. # That precondition is now met and measured: the dyno is Standard-2X and a full @@ -543,7 +561,7 @@ def _fix_database_url(self) -> "Settings": # Invariant, asserted in `tests/unit/services/test_repo_index_ceiling.py`: this # stays below `daily_knowledge_sync_job_timeout_seconds`, which contains it plus # a DB index plus a code↔DB sync. - repo_index_job_timeout_seconds: int = 3600 + repo_index_job_timeout_seconds: int = 16200 # F-SCHED-07: how long a `running` batch may sit before another attempt may take # its claim. `run_batch` inherits ARQ's class-level `job_timeout` (1800 s), so past diff --git a/backend/tests/unit/services/test_repo_index_ceiling.py b/backend/tests/unit/services/test_repo_index_ceiling.py index fed6b6e5..a86dc24a 100644 --- a/backend/tests/unit/services/test_repo_index_ceiling.py +++ b/backend/tests/unit/services/test_repo_index_ceiling.py @@ -1,42 +1,55 @@ -"""One pipeline must not have two ceilings depending on which door it came through. +"""The manual re-index carries a full rebuild, and its ceiling has to cover one. -`run_repo_index_task` is the repo-index pipeline. Two ARQ jobs call it, and each -carries its own timeout: +`run_repo_index_task` is the repo-index pipeline, and two ARQ jobs call it — but not +with the same work, which is where the first version of this file went wrong: -| Entry | ARQ job | Setting carrying the ceiling | +| Entry | Arguments it passes | Ceiling | |---|---|---| -| nightly cron | `run_daily_project_knowledge_sync` | `daily_knowledge_sync_job_timeout_seconds` | -| the button, `POST .../index` | `run_repo_index` | `repo_index_job_timeout_seconds` | - -Measured on the one real customer repository in production, `indexing_runs` for -`kind='index_repo'`: - - 08-25 22:00 completed 42.4 min <- nightly, ceiling 7200 s - 08-27 09:30 TimeoutError 30.0 min <- manual, ceiling 1800 s - - 1800.02s ! 33f44e65d24b48bd9795717bc21b0285:run_repo_index failed, TimeoutError - pipeline_runner.py:1468 in _run_code_symbol_embed - -The same 2 544 s of work fits under one ceiling and cannot fit under the other, so -the repository rebuilds unattended at 3 a.m. and never rebuilds when a person asks -for it. That is the worse half: the manual button is what an operator reaches for -after a fix, and it is the path that cannot finish. - -**This was diagnosed once already.** AUD-0819-20 gave the job its own knob on -2026-08-19 precisely because "production hit the hardcoded 1800 s with -`code_symbol_embed` still running after 29 minutes" — and left the default at the -value that had just been measured as too small, with a note that a repository -needing longer "can now say so without a code edit". Nobody said so; neither -`REPO_INDEX_JOB_TIMEOUT_SECONDS` nor its sibling is set in production. A knob whose -default is the known-bad value relocates the defect, it does not fix it. - -The same day's memory fix made it worse and the connection was not drawn: -`EMBEDDING_UPSERT_BATCH_SIZE` was cut from 200 to 8, trading ~17 % wall clock for -~552 MiB. That 17 % is spent inside the step the ceiling now cuts off. - -Two orderings are asserted below, and each fails differently. Losing the first -means the manual path cannot finish work the automatic path can. Losing the second -means the containing job would be cut off before the step it contains. +| nightly cron | `force_full=False, chain_sync=False` | 7200 s | +| the button | `force_full=True`, chain on | `repo_index_job_timeout_seconds` | + +The cron's job is `run_daily_project_knowledge_sync`; the button's, reached through +`POST /api/projects/{id}/index`, is `run_repo_index`. + +**Correction, 2026-08-27.** This file first read the cron's 42.4-minute `completed` +run as a full rebuild and concluded that "the same work fits under one ceiling and +not the other", so 3600 s would do. Both halves were wrong. +`daily_knowledge_sync_service._run_repo_index` passes `force_full=False` and +`chain_sync=False` — an *incremental* index with the code↔DB chain off, because the +cron runs that sync itself as a separate step. So 42.4 min was never a full +rebuild, and `repo < daily` was never an invariant; asserting it capped the manual +path below what a full rebuild needs. + +What a full rebuild actually costs, from the tracker on the 11:34 run — the two +dominant steps, both scaling with repository size rather than with a wall clock: + + 11:37:23 code_symbol_embed: started + 12:15:43 code_symbol_embed: completed 2 300 s (38.3 min) + 12:18:07 generate_docs: started + 12:34:52 killed at the 3600 s ceiling, at document ~80 of 758 + 15:51:39 pipeline_end, after two more attempts — 12 039 s of work in total + +`generate_docs` is LLM-bound at roughly 4.8 documents a minute (80 documents in +16.75 minutes, measured twice), so 758 of them is about 2.6 hours on their own. +That is why the cron's path finishes and the button's does not: incrementally, +`generate_docs` regenerates only what changed — three minutes on 2026-08-26 +against ~158 for the full set. + +Measured twice before the number below was trusted: + + 09:30 1800.02 s TimeoutError inside `_run_code_symbol_embed` + 11:34 3600.00 s interrupted inside `generate_docs`, doc ~80/758 + +**Why the knob existed and still did not help.** AUD-0819-20 added it on +2026-08-19 for exactly this failure and left the default at 1800 — the value just +measured as too small — noting that a repository needing longer could "say so +without a code edit". Nothing in production said so. A knob defaulting to the +known-bad value relocates a defect; and the registration test pinning +`{"timeout": 1800}` as a literal made that default look deliberate. + +The same day's memory fix is inside the 2 300 s above and the link was never drawn: +`EMBEDDING_UPSERT_BATCH_SIZE` went 200 → 8, buying ~552 MiB with ~17 % more wall +clock — spent in the step that dominates the budget. """ from __future__ import annotations @@ -48,11 +61,22 @@ BACKEND = Path(__file__).resolve().parents[3] -#: Longest full rebuild that ever *completed*, in seconds — `indexing_runs`, 42.4 min. -#: Runs longer than this on record all end `stale run reaped`, meaning their -#: heartbeat had stopped (the N1 defect, fixed 2026-08-25); their wall clock is -#: not evidence of work taking that long. -MEASURED_FULL_REBUILD_SECONDS = 2544 +#: A full rebuild of the one real customer repository — 9 981 files, 758 documents — +#: summed from measured segments of the run that reached `pipeline_end` at 15:51:39 +#: on 2026-08-27. Summed rather than one wall clock because the run was interrupted +#: twice by deploys, and a wall clock spanning an idle gap would overstate the work: +#: +#: 151 s setup + ast_parse + graph_build +#: 2300 s code_symbol_embed +#: 144 s analyze_files + cross_file_analysis + graph_db_bridge +#: 9375 s generate_docs, 758 documents at ~4.8/min across three segments +#: 69 s embed_and_store + bm25 + the chained code↔DB sync +#: ------ +#: 12039 s = 3.34 h +#: +#: NOT the cron's 42.4-minute run, which is an incremental index with the chain off +#: and was the mis-reading this file exists to correct. +MEASURED_FULL_REBUILD_SECONDS = 12039 _DEFAULTS = Settings.model_fields @@ -61,19 +85,18 @@ def _default(name: str) -> int: return int(_DEFAULTS[name].default) -class TestTheManualPathCanFinishWhatTheNightlyPathCan: - def test_the_repo_index_ceiling_clears_the_measured_rebuild(self) -> None: +class TestTheCeilingClearsAFullRebuild: + def test_it_clears_the_measurement(self) -> None: ceiling = _default("repo_index_job_timeout_seconds") assert ceiling > MEASURED_FULL_REBUILD_SECONDS, ( - f"a full rebuild of the one real customer repository took " - f"{MEASURED_FULL_REBUILD_SECONDS} s and the manual ceiling is {ceiling} s — " - "the button cannot finish work the cron finishes" + f"a full rebuild measures {MEASURED_FULL_REBUILD_SECONDS} s and the manual " + f"ceiling is {ceiling} s — the button cannot finish a rebuild at all" ) def test_it_clears_it_with_headroom(self) -> None: - """A ceiling set to the last measurement is a ceiling that fails on the next - commit. The rebuild grows with the repository, and the memory fix already - spends ~17 % of it.""" + """A ceiling set to the last measurement fails on the next commit. Both + dominant steps scale with repository size: `code_symbol_embed` with the symbol + count, `generate_docs` with the document count.""" ceiling = _default("repo_index_job_timeout_seconds") measured = MEASURED_FULL_REBUILD_SECONDS assert ceiling >= measured * 1.25, ( @@ -81,25 +104,45 @@ def test_it_clears_it_with_headroom(self) -> None: ) -class TestTheContainingJobOutlivesWhatItContains: - """The daily sync runs the repo index, then the DB index, then the code↔DB sync, - in one job. Its ceiling must therefore be strictly the larger one — if it were - not, the cron would be cut off inside a step that was still within its own - budget, and the failure would be attributed to the step.""" +class TestTheTwoCeilingsCoverDifferentWork: + """The first version of this file asserted `repo < daily` on the grounds that the + daily sync *contains* a repo index. It does not contain this one. - def test_daily_sync_gets_the_larger_budget(self) -> None: - repo = _default("repo_index_job_timeout_seconds") - daily = _default("daily_knowledge_sync_job_timeout_seconds") - assert daily > repo, f"daily sync {daily} s must exceed the repo index {repo} s it contains" + `daily_knowledge_sync_service._run_repo_index` calls + ``run_repo_index_task(project_id, force_full=False, chain_sync=False, wf_id=...)`` + — incremental, and with the code↔DB chain off because the daily sync runs that + sync itself as a separate step. So the cron's budget covers + *incremental* repo index + DB index + sync, while the manual button's budget + covers a *full* rebuild plus the chained sync. Different workloads; the ordering + was not an invariant, and asserting it capped the manual path below what a full + rebuild needs. - def test_the_daily_sync_really_does_contain_it(self) -> None: - """Asserted rather than assumed: the ordering above is only an invariant while - one job calls the other. If the call goes away, this test says so instead of - the ordering quietly becoming arbitrary.""" + What replaces it is the fact the ordering was standing in for: each ceiling is + checked against the workload it actually carries. + """ + + def test_the_cron_runs_it_incrementally_and_without_the_chain(self) -> None: service = (BACKEND / "app" / "services" / "daily_knowledge_sync_service.py").read_text( encoding="utf-8" ) - assert "run_repo_index_task" in service + call = service[service.index("await run_repo_index_task(") :][:200] + assert "force_full=False" in call, ( + "the cron's index is no longer incremental — the two ceilings may now carry " + "comparable work and this file's reasoning needs redoing" + ) + assert "chain_sync=False" in call, ( + "the cron now chains the code↔DB sync, so its budget contains work the " + "manual path's does too — re-derive both ceilings" + ) + + def test_the_manual_ceiling_covers_a_full_rebuild_plus_the_chain(self) -> None: + """The manual path is the only one that runs `force_full=True` **and** chains + the sync, so its ceiling is the one that must clear the whole thing.""" + ceiling = _default("repo_index_job_timeout_seconds") + assert ceiling >= MEASURED_FULL_REBUILD_SECONDS, ( + f"a full rebuild measures {MEASURED_FULL_REBUILD_SECONDS} s and the manual " + f"ceiling is {ceiling} s" + ) class TestEveryLongJobHasAKnobAndNoneIsHardcoded: diff --git a/docs/qa-audit/issues.md b/docs/qa-audit/issues.md index 5d838498..172ef1bd 100644 --- a/docs/qa-audit/issues.md +++ b/docs/qa-audit/issues.md @@ -94,10 +94,10 @@ frontend **A** (563 smells, 7 SOLID). | 🔴 Critical | 0 | | 🟠 High | **0** | | 🟡 Medium | 3 | -| 🟢 Low | 25 | +| 🟢 Low | 26 | | ⚪ Info | 12 | -*Counted 2026-08-27, not estimated: **33 open `F-` rows and 76 struck** by `grep -cE '^\| F-'` / `grep -cE '^\| ~~F-'` over this file, plus **7 open `CB-` rows** those two commands do not see. The severity table above counts all 40 open rows of both kinds, which is why it does not match the `F-` figure — the two measure different sets and each says which. Both are derived from the rows themselves.* +*Counted 2026-08-27, not estimated: **33 open `F-` rows and 76 struck** by `grep -cE '^\| F-'` / `grep -cE '^\| ~~F-'` over this file, plus **8 open `CB-` rows** those two commands do not see. The severity table above counts all 41 open rows of both kinds, which is why it does not match the `F-` figure — the two measure different sets and each says which. Both are derived from the rows themselves.* *(R1+R2 closed 4 High + 8 Medium + 3 Low. R3 (`fbf8112`) closed 2 High (F-SSH-08, F-RULE-01) + 5 Medium (F-RULE-05, F-DG-07/09, F-GRAPH-01, F-LEARN-07) + 1 Low (F-SSH-06). The 2026-07-19 UX @@ -401,9 +401,10 @@ maintainability / reliability risks. | ~~CB-SEN1~~ | ✅ | ~~**Sentry was reachable by two secrets neither scrubbing layer could see**~~ — the built-in `EventScrubber` matches key names and its 33-key default carries neither `dsn` nor `database_url`; `before_send` matched values but walked only `exception.values`, `logentry` and `breadcrumbs`. A key of either name in `extra` or `contexts` was caught by **neither**. Urgent rather than theoretical from the moment `SENTRY_DSN` was set in production. **Fixed 2026-08-26** (#230): layer 1 wired with the denylist extended 33 → 39, layer 2 walks `extra` and `contexts` recursively and depth-bounded, host preserved. Fifteen tests, one of them an assertion about *Sentry* — that layer 1 alone still leaks values — so the redundancy question re-opens from a red test rather than from memory. | | ~~CB-SEN2~~ | ✅ | ~~**The Sentry release would have been blank on the container stack**~~ — `HEROKU_SLUG_COMMIT`, the value every guide names, is populated only for slug (buildpack) deploys. This app is on the **container** stack, where the variable exists and is always **empty** (measured on v271 *after* `runtime-dyno-metadata` was enabled). Issues would attach to a release with no commits and suspect-commit attribution would silently do nothing. Enabling the labs feature was necessary and not sufficient, and nothing would have said so. **Fixed 2026-08-26** (#231): the commit is baked into the image via `--build-arg GIT_SHA` → `ENV RELEASE`; verified in production, `RELEASE == main` HEAD. The empty string is the trap — `os.getenv` returns `""` there, not `None`, so an `is None` check would have accepted it; a test catches that form. | | CB-UX1 | ⚪ | **102 UX scenarios carry a verification older than 30 days.** 110 of 127 were dated 2026-07-19 while 152 commits had landed since; five were re-audited 2026-08-26 and the ceiling now stands at 105, of which 102 still have a changed Coverage file under them. Ordered and computable: `python3 scripts/ux_verification_status.py --backlog 2026-07-19`. The ceiling in `tests/unit/docs/test_ux_scenarios.py` may fall but not rise. | Re-audit in batches, worst first; date each verdict and add an `SCN-NNN` anchor so a machine can check it (21 of 127 have one). | -| CB-OPS1 | 🟡 | **RE-OPENED 2026-08-27, and the earlier closure was the same mistake in a new form.** It was struck on "a full re-index logged zero `R14`/`R15`" — but every run measured for that claim died in or before `code_symbol_embed`, so nothing had yet reached the late steps where memory actually peaks. The first run that did reach them produced, at 12:32–12:34 inside `generate_docs`: `mem=1135M(100.1%)` with **4 × R14**, on Standard-2X. What the resize genuinely bought is still real and is now stated precisely: before it, 170 × R14 **and 2 × R15** in 6.5 h with a 1 143 MiB peak against a 512 MiB quota — a fatal overrun. Now: over quota, no `R15`, the process survives. Marginal, not clear. | Measure the peak across a rebuild that reaches `pipeline_end`, not one that is cut off; `generate_docs` is the step to watch, not `graph_build`. Decide from that whether the next size up is needed or whether `generate_docs` should hold less state. | +| CB-OPS1 | 🟡 | **Measured on a rebuild that finished, 2026-08-27.** Peak **1 246 MB (112.7 %)**, **45 × R14**, **0 × R15** across the run that reached `pipeline_end` at 15:51:39 on Standard-2X. Every R14 falls in `generate_docs`, not `graph_build`. This row was struck earlier on "zero R14/R15" — but every run behind that claim died in or before `code_symbol_embed` and never reached the late steps where memory peaks, so it measured a truncated rebuild. What the resize genuinely bought, stated precisely: before it, 170 × R14 **and 2 × R15** with a 1 143 MiB peak against a 512 MiB quota — the process was killed. Now it runs 12 % over quota for hours and survives. | Decide from the number: accept a permanently over-quota worker, take the next size up, or make `generate_docs` hold less state. Not urgent — no `R15` in 3.34 h — but it is over quota by design now, and that should be a choice. | | CB-OPS2 | 🟡 | **The nightly cron can rebuild a repository the "Re-index repository" button never can.** `run_repo_index_task` is called by two ARQ jobs carrying two ceilings: the cron's `run_daily_project_knowledge_sync` at 7200 s, and `run_repo_index` at 1800 s. Measured on the same repository from `indexing_runs`: nightly `completed` in **42.4 min** (08-25 22:00), manual `TimeoutError` at **exactly 1800.02 s** inside `_run_code_symbol_embed` (08-27 09:30). Diagnosed once already — AUD-0819-20 added the knob on 2026-08-19 for this failure and left the default at the value just measured as too small. **Fix written, not yet in production:** `repo_index_job_timeout_seconds` defaults to 3600 on branch `fix/repo-index-ceiling`, with both orderings asserted in `tests/unit/services/test_repo_index_ceiling.py`. | Deploy, then force one manual full re-index and require it to reach `pipeline_end`; strike this row on that evidence, not on the merge. | | CB-OPS3 | 🟡 | **A worker restart during a repo index loses the run, and nothing retries it.** Measured 2026-08-27: release `v279` restarted the worker at 10:59:34 UTC, 37 min into an index. arq logged `shutdown on SIGTERM ◆ 0 jobs complete ◆ 2 failed ◆ 0 retries ◆ 1 ongoing to cancel`, exited 143, and the fresh worker started at 10:59:45 with **no job re-queued** — no `run_repo_index` or `run_daily_project_knowledge_sync` start appears in the next 30 min of worker log. `WorkerSettings` sets neither `retry_jobs` nor `max_tries`, so arq's defaults were in force and still did not retry. The reaper correctly flipped both rows to `failed / stale run reaped`, visible in `error_log` since N3. The restart was a deploy of our own, not an incident — the finding is that a routine deploy costs a whole index. | Decide the semantics before coding: re-enqueue on shutdown (risking a double run against `_indexing_locks` and the advisory locks), or leave it to the cron and make the loss explicit in the UI. Not a silent implementation choice. | +| CB-KNOW1 | 🟢 | **Double pluralisation still invents table names.** After the shape guard (#234/#235) the code↔DB map dropped 48 of 280 cached names and its `mismatch` count went 6 → 0, but `code_only` still carries `clientlogses`, `mobile_identifierses`, `twiliocallses`, `twiliophoneses` — a class name that is *already plural* (`ClientLogs`) run through `_model_name_to_table` a second time. They pass `is_plausible_table_name` legitimately: long enough, letter-initial, not keywords. A different mechanism from the one that produced `zes` and `ases`, so the existing guard cannot see it. | Detect an already-plural stem before pluralising, and prefer the declared name (`protected $table`, migrations) over the inferred one where both exist. Shape rule, not a list of these four. | **Verified-good in the codebase audit (no issue):** SQL identifier quoting (`connectors/base.py:262` doubles quotes correctly), credential exposure (`ConnectionResponse` returns no secrets; Fernet at