diff --git a/docs/product-technical-gap-baseline.md b/docs/product-technical-gap-baseline.md index 1cc9e20313..3c3de63dff 100644 --- a/docs/product-technical-gap-baseline.md +++ b/docs/product-technical-gap-baseline.md @@ -2776,6 +2776,37 @@ prose" convention already stated in `CLAUDE.md`. **Confirmed landed and working in production — 2026-09-05.** The `.github`-side follow-up named above shipped: `ContextualWisdomLab/.github#1831` ("ground verdicts and classify gateway errors," merged 2026-09-04), with a same-day test/coverage hardening pass in `#1835` and a further refinement in `#1850`. `call_llm` now distinguishes `urllib.error.HTTPError` specifically, labels that case `active_phase = "response_error"` (replacing the misleading generic label a plain transport failure would get), and calls a new `_extract_http_error_telemetry(exc)` helper that actually reads and parses the gateway's error response body — closing the exact `exc.read()` gap this entry named. Live confirmation, found incidentally while handling an unrelated Autofix event on `ContextualWisdomLab/.github#1757`: a fresh gateway failure on that PR (job `101084475966`, 2026-09-04T20:45:17Z) logged `HTTPError: HTTP Error 502: Bad Gateway; caller attempts=1, duration=284.7s, phase=response_error, served_model=google/gemma-4-31b-it` — a real model name, not `unknown`. The underlying gateway instability itself (a 502 after 284.7s) remains a separate, still-open, still-recurring problem this entry does not resolve — but the telemetry gap that made every prior instance of it undiagnosable is now closed. +## Item 4: the underlying provider-pool stall itself, root-caused — 2026-09-03 + +**Status:** Open. The prior entry above explicitly left this unresolved ("This does not fix the underlying 649-second provider stall itself — that remains a real, separate, unresolved question"). This entry answers that question with direct code evidence plus nine same-day, cross-repository data points showing the stall duration growing over the course of the day, and proposes a design direction — not yet implemented, and deliberately not implemented in this pass given the change touches shared production routing code in `contextual-orchestrator` and no maintainer/owner discussion of the tradeoff has happened yet. + +**Fresh evidence, nine data points across two observation periods — seven on 2026-09-03 and two follow-ups on 2026-09-05 — growing.** The first seven are `noema-review`'s "Prepare Noema model verdict" step failing with `HTTPError: HTTP Error 502` (one, the earliest, `500`), `phase=connecting` (per the entry above, this label covers the whole wait, not literal TCP connect), `served_model=unknown`, `caller attempts=1`: +- `ContextualWisdomLab/contextual-orchestrator#1028` (later push): `duration=3913.0s` (1h5m13s) — run [`33767309930`](https://github.com/ContextualWisdomLab/contextual-orchestrator/actions/runs/33767309930/job/100688363895). The largest data point yet, on a *later* head of the same PR listed below (`33c5ede0`, after this session's own unrelated test fix landed) — confirms the stall recurs across separate pushes to the same PR, not a one-off tied to a specific commit. +- `ContextualWisdomLab/contextual-orchestrator#1032`: `duration=2604.3s` (43m24s) — run [`33726444754`](https://github.com/ContextualWisdomLab/contextual-orchestrator/actions/runs/33726444754/job/100556361214). No PR-specific defect: only check failing, no other actionable issue found on this PR (unlike `#1028` below, which separately had a real, fixed test bug). +- `ContextualWisdomLab/contextual-orchestrator#1028`: `duration=2296.6s` (38m17s) — run [`33702758879`](https://github.com/ContextualWisdomLab/contextual-orchestrator/actions/runs/33702758879/job/100485372257). Notable: this is `contextual-orchestrator`'s own CI, stalled by `contextual-orchestrator`'s own gateway — the same pool the review sidecar routes through is congested regardless of which repository's PR triggered the request. +- `ContextualWisdomLab/mightyETL#330`: `duration=2161.9s` (36m2s) — run [`33701944041`](https://github.com/ContextualWisdomLab/mightyETL/actions/runs/33701944041/job/100482910533) (found and relayed by a peer session; that PR's `strix` check also failed separately, log expired `BlobNotFound`, cause not independently confirmed). +- `ContextualWisdomLab/.github#1689`: `duration=1462.9s` (24m23s) — run [`33701909483`](https://github.com/ContextualWisdomLab/.github/actions/runs/33701909483/job/100482801962). +- `ContextualWisdomLab/naruon#1539`: `duration=1332.6s` (22m13s) — run [`33702091175`](https://github.com/ContextualWisdomLab/naruon/actions/runs/33702091175/job/100483351489) (found and relayed by the same peer session). +- The prior entry's own `fast-mlsirm#1518` data point: `duration=649.5s` (10m49s, `HTTP 500` — the one exception the parenthetical above already carves out, restated here directly on its own bullet to remove any ambiguity), earlier the same day. + +**The eighth and ninth, both 2026-09-05, break the `phase=connecting`/`served_model=unknown` pattern.** `ContextualWisdomLab/contextual-orchestrator#1032` (a later push, distinct from the same-numbered PR above): `duration=2298.7s` (38m19s), `caller attempts=1` — run [`33913723320`](https://github.com/ContextualWisdomLab/contextual-orchestrator/actions/runs/33913723320/job/101232657191). This one reports `phase=response_error` (not `connecting`) and `served_model=deepseek-ai/deepseek-v4-flash-0731` (populated, not `unknown`) — the first data point in this series carrying the exact attribution detail `#1037`'s fix (recorded two entries above) was built to surface, though `#1037` was still unmerged at the time this ran. The stall duration itself is unchanged in kind (still a multi-thousand-second wait ending in a gateway-side failure); only the caller's *visibility* into which model/phase it was waiting on has improved. Rerun triggered per the standing procedure; not a new code change. + +The ninth, roughly an hour later: `ContextualWisdomLab/contextual-orchestrator#1028` (a still-later push, distinct from both prior `#1028` data points above): `duration=2773.8s` (46m14s), `caller attempts=1` — run [`33919286473`](https://github.com/ContextualWisdomLab/contextual-orchestrator/actions/runs/33919286473/job/101236471242). Same `phase=response_error` / `served_model=deepseek-ai/deepseek-v4-flash-0731` shape as the eighth — two consecutive same-day instances now, both against the identical served model, suggesting this specific model's route may be the one currently saturated rather than the pool broadly. Rerun triggered per the standing procedure; not a new code change. + +Sequence across the two observation periods (the seven 2026-09-03 points and the two 2026-09-05 follow-ups, ordered by duration rather than by time): 649.5s → 1332.6s → 1462.9s → 2161.9s → 2296.6s → 2298.7s → 2604.3s → 2773.8s → 3913.0s. Not proof of a monotonic trend on nine points from five different repositories and two separate days, but consistent with a shared-capacity resource degrading as each day's cumulative concurrent CI load (8+ sessions, dozens of repositories, all routing `noema-review`/`strix`/`opencode-review` through the same `orchestrator/free` pool) increases. + +**Root cause, from direct code reading of `contextual-orchestrator@464da4715b495b5eaaa593eba3796e2d976ee0c9`'s `contextual_orchestrator/orchestrator.py`.** `TaskOrchestrator._invoke`'s failover loop (`:7762`, `for agent in candidates:`) iterates the **entire ranked free-tier candidate pool** — `free_selected_count` in `.github#1689`'s own sidecar preflight log was 12 — serially, with no overall wall-clock budget for the request as a whole. **Correction (Devin Review): the per-candidate cost is roughly double the figure this entry first computed.** Each candidate's `self.client.chat()` call is itself internally retried by `ModelClient` (`orchestrator.py:1699-1709`, `timeout=90` seconds per HTTP attempt, `max_retries=2` → 3 total attempts, full-jitter exponential backoff capped at `retry_backoff_cap=8.0` seconds between attempts) — but `_invoke`'s own outer loop (`:7841`, `action is ToolFallbackAction.RETRY_SAME_AGENT and retry_attempt < retry_limit`) separately re-invokes that *entire* 3-attempt `self.client.chat()` call up to `retry_limit = min(self.tool_retry_attempts, MAX_TOOL_RETRY_ATTEMPTS)` more times, and a retryable transport failure (`classify_provider_transport_failure`, `tool_fallback.py:148-154`) always classifies as `RETRY_SAME_AGENT`. With the default `tool_retry_attempts=1` (`orchestrator.py:3849`), that is 2 outer passes, each covering 3 inner attempts: **up to 6 total HTTP attempts per candidate**, not 3 — worst case ≈ `2 × 3 × 90s ≈ 540s` before backoff (outer-loop backoff is small, `tool_retry_backoff_seconds=0.25` default, `:3850`; inner-loop backoff is likewise a few seconds at most, not the dominant term). There is a real per-candidate circuit breaker in this loop (`self._circuit`/`_circuit_open`, see the correction further below) but it cannot skip a candidate known-bad from very recent history the way the original draft of this entry assumed — the correction below explains why in detail. Roughly 3 candidates each hitting close to the corrected worst case (`3 × ~540s ≈ 1620s`) is in the same order of magnitude as the actual `.github#1689` observation (`1462.9s`) — closer to 2-3 simultaneously-slow candidates than the 5 this entry originally estimated from the uncorrected math; the smaller and larger observed values across this entry's data points are consistent with fewer or more of the pool's 12 members being simultaneously slow rather than fast-failing (an immediate 429/503 response costs very little; a member that accepts the connection and then hangs costs close to the full 6-attempt budget) — exactly the shape you'd expect from a shared free-tier pool under uneven, fluctuating saturation across many concurrent callers org-wide. + +**Why this is a real gap, not a config bug.** No single number here is wrong in isolation — a 90-second per-attempt timeout, 2 internal retries, an outer same-agent retry, and up to six HTTP attempts per candidate (two outer `self.client.chat()` calls from the default `tool_retry_attempts=1`, each with up to three provider attempts from `max_retries=2`) are all individually reasonable, and `docs/product-goal-directive.md` §8 deliberately forbids capping total model-inference wall-clock (see the entry above and `docs/doctoring/autofix-and-noema-review-model-job-timeout-removal.md`). The gap is structural: **the failover loop has no mechanism to fail fast past a candidate that is very likely to fail again.** The correction immediately below explains precisely why not — it is *not* simply that existing state (`self._circuit`, `_group_router`/`#911`'s observation store) goes unconsulted; even consulting it would not help, for a deeper reason tied to how this specific caller is deployed. Read the correction before treating this paragraph's framing as complete. Regardless of mechanism, pool saturation shows up as linearly-compounding serial wait rather than either a fast failure or a bounded worst case. This also directly costs Actions job-slot capacity: every one of these six runs held a `noema-review` job (and its GitHub Actions runner) for 10-43 minutes before failing, worsening the same 60-job organization concurrency ceiling this document's queue-congestion entries already treat as a standing constraint — including, per the `contextual-orchestrator#1028`/`#1032` data points, `contextual-orchestrator`'s own required checks. + +**Correction (2026-09-04): both mechanisms this entry originally proposed already exist in `contextual-orchestrator`, and neither can help the review-sidecar deployment. Traced to the actual, deeper constraint.** A closer read of `TaskOrchestrator` found that (1) a real circuit breaker already exists (`self._circuit`, `_record_failure`/`_circuit_open`, `orchestrator.py:7972-8018`, `circuit_failure_threshold=3`, `circuit_reset_seconds=30.0`) and is already wired into `_failover_candidates` (`:7968`, `healthy = [agent for agent in eligible if not self._circuit_open(agent.id)]`), which is what actually produces `_invoke`'s `candidates` list (`:7683`); and (2) a concurrent-racing path already exists too (`_equivalent_race_members`/`race_members`, `:7410-7433`, `:7707-7750`) and is already checked immediately before the serial loop for the `"text"` capability, the exact capability a chat-completion review request uses. + +**Why both are structurally inert for this failure mode.** The circuit breaker is per-process, in-memory state (`self._circuit` is a plain instance dict) that needs 3 accumulated failures for one candidate before it opens — but the review sidecar boots a **brand-new orchestrator process for every single CI job** (confirmed directly: `contextual_orchestrator_review_sidecar.sh`'s own log line, `"starting review sidecar on 127.0.0.1:18080"`, printed fresh on every job in every job log this document cites), and each sidecar makes exactly one real `/v1/chat/completions` request before the job ends. There is no second request in the same process to benefit from a circuit that only opens after the first one's own candidate-walk already paid most of the cost. `#911`'s routing-observation ledger (`self._group_router`) has the identical structural problem — also in-memory, also reset to empty on every fresh boot, so a skip-fast check reading it (this entry's original item (1)) would have been just as inert as the circuit breaker, not a fix. The racing path is inert for a different, more fundamental reason: `_equivalent_race_members` (`:7414`) requires candidates to share a `group_name` **and** carry a declared `endpoint_equivalence` contract (`EndpointEquivalenceContract`, `hedge_eligible=True`, `execution_policy="immediate_race"`) proving they are interchangeable replicas of the *same* model across redundant endpoints. The free-tier pool's members are declared as ordinary discovered agents with **no `group_name` at all** (confirmed: zero occurrences of `group_name` anywhere in `model_discovery.py` or `provider_catalog_bootstrap.py`) and are genuinely *different models* (DeepSeek, Gemma, Llama variants, per the preflight evidence above) — not redundant copies of one model, so racing them would mean sometimes accepting a materially weaker model's answer over a not-yet-finished stronger one. That is a real product-quality tradeoff, not a mechanical extension of the existing replica-racing design. + +**Revised proposed direction, still not implemented here, now split by tradeoff.** Two genuinely different fixes, not the two originally proposed: (1) **persist** circuit-breaker and/or routing-observation state across the ephemeral sidecar's process boundary (a shared file, or a lightweight external store keyed by pool/model identity) so that congestion learned by one CI job's sidecar benefits the next one within the reset window — this is a design candidate, not a verified fix: persisting the state alone does not guarantee a fast exit, for two reasons visible at `contextual-orchestrator@a080297`. First, `_failover_candidates` ends in `return healthy or eligible` (`orchestrator.py:7971-7973`), so when *every* candidate's circuit is open the full pool is probed again no matter how faithfully that state was restored; who owns all-open re-entry versus concurrent recovery probes has to be decided explicitly, and silently returning an empty list would change the current exploration policy rather than fix it. Second, `_circuit_open` compares `time.monotonic()` against the stored `opened_at` (`:7980`, written from `time.monotonic()` at `:7999`), a clock that is only meaningful within one host and one boot, so a persisted store needs its own expiry/TTL definition and a reconstruction rule rather than the raw value. A read-only probe run during review of this record confirmed both: with two candidates injected circuit-open, `_failover_candidates` returned both; an `opened_at=1000` restored under a different clock origin stayed open at a current value of 100 and closed immediately at 10000. It is also real new infrastructure (concurrency-safe cross-process state, cache invalidation, and a decision about whether/how a review sidecar should share state with production traffic at all) rather than a small change; (2) **extend racing to non-equivalent fallback candidates** for the free-tier pool specifically — cheaper to build (reuse the existing concurrent machinery) but requires an explicit, named product decision about accepting a faster-but-possibly-weaker answer over a slower-but-stronger one, which is exactly the kind of tradeoff `docs/product-goal-directive.md` §8's "no fixed inference-time cap" policy was written to prevent being smuggled in as an implementation detail. Neither is implemented in this pass. This is shared production routing code in `contextual-orchestrator`, and — now more than before this correction — the right next step is a design decision from whoever owns that tradeoff, not another unilateral attempt at a small mechanical patch. + +**A concrete, lower-effort path to direction (1) already exists, half-built, sitting unmerged.** `contextual-orchestrator#911` ("Persist bounded model-group routing observations," open, not merged, `Devin`-reviewed, `2537 passed` at its own head) adds exactly the persistence primitive direction (1) calls for: a new `routing_observation_store.py` (`RoutingObservationStore`, a time-windowed SQLite-backed store keyed by `member_id`/`success`/`latency_seconds`) that lets `ModelGroupRouter`'s ledger survive across separate gateway processes within a configured wall-clock window (`--routing-observation-window-seconds`/`--state-db`). This is real, tested, already-built cross-process persistence infrastructure. **But it persists the wrong ledger for this specific gap**: `#911` wires the store into `_group_router`/`_quality_router` (the *ranking* ledgers `ModelGroupRouter.member_score`/`ranked_member_ids` read) — and, per the entry above, ranking is only ever consulted for candidates that share a `group_name`, which the free-tier pool's discovered agents never have. The mechanism that *is* consulted regardless of grouping — the circuit breaker (`self._circuit`, `_record_failure`/`_circuit_open`) — is not touched by `#911` at all; it stays exactly as in-memory and per-process as before. The design candidate once `#911` lands — pending verification, not a low-risk step — is to route `self._circuit`'s reads/writes through the same `RoutingObservationStore` mechanism `#911` already built and tested, with a replay window that is a separate policy value, **not** `circuit_reset_seconds`. Why the reset constant cannot serve, verified at `contextual-orchestrator@a080297`: `_circuit_open` resets an open circuit to zero failures once `time.monotonic() - opened_at >= circuit_reset_seconds` (30.0, `:3959`, `:7980-7982`), so an open state persisted by one CI job is already expired when the next job — minutes later, one request per process — reads it; pre-open failure counts never decay by time (`:7996` only increments), but `_record_success` pops the whole entry (`:8019`), so a single success erases the accumulated history; and neither record function reads latency, so a candidate that takes 600 seconds and then *succeeds* leaves the breaker untouched. The replay window therefore has to be sized from the observed stall durations in this entry (649–3913 s), and whether persisted breaker state carries any signal at all depends on whether the stall is made of errors/timeouts (which `_record_failure` sees) or of slow successes (which it does not) — a measurement this entry's data points do not yet separate. Its completion criteria, none of which the persistence primitive supplies by itself: a replay window decoupled from the reset constant, a timeout-vs-slow-success breakdown of the observed stalls, ownership of all-open re-entry (the `return healthy or eligible` branch above), a shared expiry/TTL contract that does not depend on one process's monotonic clock, a bound on concurrent recovery probes, and verification that state stays isolated per provider/account. Extending the existing reliability tests for it means reproducing all candidates open, differing clock origins, and the allowed concurrent-probe count. A global inference timeout or racing weaker models is not a substitute (see the tradeoff split above and `docs/product-goal-directive.md` §8). Not attempted in this pass: `#911` itself is unmerged and could still change shape before landing, and building on top of an unmerged PR risks needing a full rebase; flagging this connection (also left as a comment on `#911` itself) so whoever picks up either PR next has the concrete linkage. + ## Item 41: CodeQL PR `startup_failure` blocking merges org-wide — dispatch-safe re-admission in progress **2026-09-04 correction.** The emergency ruleset removal below fixed the old