diff --git a/CHANGELOG.md b/CHANGELOG.md index 1f535e06c9..dca548fb03 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,3 +1,7 @@ +### Review sidecar preflight postpones a rate-limited account's candidates instead of banning them + +- `_preflight_review_agents` no longer ends its walk when every credential account has answered 429 twice in a row. A candidate set aside by `REVIEW_PREFLIGHT_ACCOUNT_SKIP_AFTER_429` is postponed to the end of the walk, and once the first pass ends with the readiness target unmet and probe budget left, the postponed candidates are probed in catalog order until the sixteen-probe budget is spent. On 2026-09-06 five sidecar boots whose probes began between 07:24Z and 08:05Z read `probed 6 / skipped 18 / ready 0` and failed closed: `.github` run 34016207820's six probes across all three accounts were refused 429 between 07:49:35.111Z and 07:49:35.767Z, so the rule set every account aside on two same-account requests about 310 ms apart and gave up with ten of sixteen probes unspent — and because deferral needs one ready route, nothing was served either; `keyverse#143`'s 08:20Z `noema-review` repeated it in a second repository (six probes, 369 ms, all 429). The pools are not dead in those minutes: run 34016093772 was inside its own preflight during that burst, and its `llama-3.2-11b` probes on the same two NVIDIA keys answered ready at 07:50:58.7Z and 07:50:59.0Z, 84 seconds after those keys refused. Whether the unspent probes would have found a ready route inside a burst is unmeasured and is not claimed; the change is justified by ending a walk under target with the budget in hand. Of the fourteen boots that ran the merged rule, eight spend all sixteen probes in the first pass and are unchanged; one (`argos` 34014143870, a serving boot at `12 / 12 / 3`) exhausts its candidates under budget and now gains a second pass, as do the five burst boots. The cost is stated rather than assumed: a refused probe costs about 120 ms, a silent one up to the 90 s receive timeout, and the postponed tail holds both (`google/gemma-4-31b-it` answered `TimeoutError` in 15 of the 19 probes that reached it), so the worst case adds up to about 15 minutes to a boot that still fails and the two-stage auto path goes from 8 to 24 requests including the priced stage. The second pass never draws on the shared escalation budget, so the priced fallback keeps the escalations it had. The report gains `postponed_probed_count` (`skipped_count` now counts postponed candidates the budget never reached) and, on a refused probe, `retry_after_s` when the response carried a whole-seconds `Retry-After` header — evidence only, nothing waits on it, so the next census can decide whether a delayed second pass is worth proposing. ADR-0029 is amended. Refs #1948, #1949. + ### Superseded OpenCode review dispatches coalesce before they take a runner - `opencode-review-dispatch.yml` now carries a workflow-level `concurrency` group keyed by the dispatched pull request (`opencode-review-dispatch--`, `cancel-in-progress: true`), matching `codeql-scan-dispatch.yml`'s workflow-level group and the rationale already recorded in `strix.yml`, `noema-review.yml` and `opencode-review.yml`: a job-level group is never evaluated while the whole run waits behind the organization job ceiling. The workflow kept its group only on the long `opencode-review-target` job, so two dispatches for one pull request each queued for hours and each was allocated a runner before the older one could be discarded. Measured on 2026-09-06: four of the five dispatch runs that passed `validate-pr-metadata` were rejected hours later by the privileged metadata check because the head had moved while they queued (runs `34002473295`, `34010256951`, `34015973300`, `34016922761`), each after `coverage-source-tree` and `coverage-evidence` had run. The privileged check itself is unchanged -- it rejected exactly what it should; what changes is that the superseded run is now cancelled at creation instead of spending a slot to discover its subject moved. diff --git a/docs/adr/0029-sidecar-preflight-lazy-fill.md b/docs/adr/0029-sidecar-preflight-lazy-fill.md index d2528b9883..166d49f9a8 100644 --- a/docs/adr/0029-sidecar-preflight-lazy-fill.md +++ b/docs/adr/0029-sidecar-preflight-lazy-fill.md @@ -30,7 +30,7 @@ The evening's rate-limit pressure is a confound; the mechanism is not. A fixed s The catalog is a **candidate list**, not the served set. `build_zdr_prioritized_catalog` keeps its tier-then-round-robin order (`#1939`) and is asked for up to `REVIEW_PREFLIGHT_MAX_TOTAL_ROUTES = 24` candidates (per-account cap unchanged at 8; the sidecar's `ORCHESTRATOR_CATALOG_LIMIT` default rises from 12 to 24). `_preflight_review_agents` probes candidates **in that order and stops** as soon as `REVIEW_PREFLIGHT_TARGET_READY = 8` routes are ready or `REVIEW_PREFLIGHT_MAX_PROBES = 16` probes have been spent, whichever comes first. The auto pool's split becomes 16 free candidates and up to 8 priced fallback candidates; the production `free` pool (the sidecar default; it has no fallback stage) lists all 24. A silent candidate's probe costs up to one transport timeout (one artifact spent 805 s on 19 probes), so the probe cap bounds preflight wall time as well as request count. -**Account skip.** A 429 at preflight is a per-key answer, not a per-model one. Once one credential account has answered 429 to `REVIEW_PREFLIGHT_ACCOUNT_SKIP_AFTER_429 = 2` consecutive probes, its remaining candidates are skipped without a probe and the walk continues with the other accounts' next candidates; the two probed routes are still deferred. Under the real 2026-09-06 candidate order (lane jan's table on `#1949`, rebuilt from `#1938`'s Strix artifact: both NVIDIA keys list deepseek ×2, gemma-3 ×2 (404), gemma-4-31b (empty), then the llama and muse routes; every OpenRouter free route answers 429) the plain sixteen-probe walk yields about five ready and five deferred and the readiness target is unreachable, because five probes go to an account whose every route had answered 429 in every artifact since 21:00Z and four to the dead gemma-3 entries. With the skip, the same sixteen probes reach both keys' `llama-3.2` routes and the target of eight. This is why the free pool lists 24 candidates while probing at most 16: the tail is reachable exactly when an account is skipped, and the report separates `skipped_count` from the unreached remainder (`candidate_count − probed_count − skipped_count`). A rate-limited hour therefore costs two probes per account instead of the full budget. +**Account skip.** *(The "skipped without a probe" and "two probes per account" claims in this paragraph are superseded by the 2026-09-06 amendment below: such a candidate is postponed, and the leftover budget is spent on it.)* A 429 at preflight is a per-key answer, not a per-model one. Once one credential account has answered 429 to `REVIEW_PREFLIGHT_ACCOUNT_SKIP_AFTER_429 = 2` consecutive probes, its remaining candidates are skipped without a probe and the walk continues with the other accounts' next candidates; the two probed routes are still deferred. Under the real 2026-09-06 candidate order (lane jan's table on `#1949`, rebuilt from `#1938`'s Strix artifact: both NVIDIA keys list deepseek ×2, gemma-3 ×2 (404), gemma-4-31b (empty), then the llama and muse routes; every OpenRouter free route answers 429) the plain sixteen-probe walk yields about five ready and five deferred and the readiness target is unreachable, because five probes go to an account whose every route had answered 429 in every artifact since 21:00Z and four to the dead gemma-3 entries. With the skip, the same sixteen probes reach both keys' `llama-3.2` routes and the target of eight. This is why the free pool lists 24 candidates while probing at most 16: the tail is reachable exactly when an account is skipped, and the report separates `skipped_count` from the unreached remainder (`candidate_count − probed_count − skipped_count`). A rate-limited hour therefore costs two probes per account instead of the full budget. The sidecar's job-log echo of the preflight JSON (`sed -n '1,400p'`, previously 160 lines) now fits 16 probed routes; the artifact copy was always complete. @@ -39,7 +39,7 @@ The report gains `candidate_count`, `target_ready` and `probe_budget`; `probed_c ## Consequences - **Good:** a dead candidate costs one probe and yields its place to the next candidate in the same account's list; a healthy hour stops after about eight to twelve probes instead of always twelve; a bad hour is bounded at sixteen probes per stage. -- **Cost:** in an hour where nothing is ready the sidecar sends up to 16 probes per stage where it sent 12, a third more against already exhausted keys. This is the price of finding routes past the dead ones; `#1948`'s shared rate ledger is the lever above it. The cap is also a wall-time bound: a 16-token probe can hold the full 90 s receive timeout (`#1661` run 34008191123, 04:48Z, both NVIDIA keys' deepseek-v4-pro probes at 90.06 s and 90.10 s), so a fully silent hour costs at most 16 × 90 s = 24 minutes of preflight against 18 today, and the account-skip rule cuts a rate-limited hour to two probes per account. +- **Cost:** in an hour where nothing is ready the sidecar sends up to 16 probes per stage where it sent 12, a third more against already exhausted keys. This is the price of finding routes past the dead ones; `#1948`'s shared rate ledger is the lever above it. The cap is also a wall-time bound: a 16-token probe can hold the full 90 s receive timeout (`#1661` run 34008191123, 04:48Z, both NVIDIA keys' deepseek-v4-pro probes at 90.06 s and 90.10 s), so a fully silent hour costs at most 16 × 90 s = 24 minutes of preflight against 18 today, and the account-skip rule cuts a rate-limited hour to two probes per account. *(That last clause is superseded by the 2026-09-06 amendment: a rate-limited hour now spends the whole probe budget rather than two probes per account.)* - **Unchanged:** a route that answers the probe and then goes silent at request time still costs the gateway's full retry budget (`contextual-orchestrator#1045`); readiness is measured at 16 tokens (`#1454`). - **Discriminator:** post-merge, `probed_count` versus `candidate_count` per boot and `ready_count` of the served set, read from the `runtime preflight summary` in the job log or the `noema-sidecar-evidence` artifact, compared with the table above. @@ -49,3 +49,35 @@ The report gains `candidate_count`, `target_ready` and `probe_budget`; `probed_c - **Exclude models that 404 by name** — a hard-coded exclusion list the next discovery change silently invalidates; rejected by constraint 1. The discovery-side question (why NIM lists models it does not serve) remains open in `contextual-orchestrator`. - **Family-level interleave inside each account's list before the cap** (jan's second layer) — would make each NVIDIA key's first six candidates span deepseek, gemma, llama, muse, minimax, mistral, but it needs a model-family equivalence derived from names, which ADR-0003/#1468 deliberately avoid; kept in reserve if the post-merge census shows same-family contention as the residual after the account skip. - **Probe all 24 candidates** — best served set, double the probe spend in the hour that can least afford it; rejected by constraint 2. + +## Amendment 2026-09-06: a set-aside candidate is postponed, not banned + +**Evidence.** Sixteen sidecar artifacts were collected on 2026-09-06 across `.github`, `argos`, `bandscope` and `naruon`; **fourteen** ran the merged rule (two, `argos` 34013128112 and `bandscope` 34013146167, still carry the pre-`#1949` report shape and are excluded). The fourteen fall into three classes, not two. + +| class | boots | `probed / skipped / ready` | second pass? | outcome | +|---|---|---|---|---| +| budget spent in the first pass | 8 | 16 / 4 / 5–6 | no — budget already gone | served; the sixth ready route (`llama-3.2-11b` on the second NVIDIA key, catalog position 17, ready in exactly these 8 artifacts) is reached **only** because four OpenRouter probes were set aside — the benefit the rule was designed for | +| candidates exhausted, budget left | 1 | 12 / 12 / 3 (`argos` 34014143870, 06:56Z) | **yes**, up to 4 probes | served with 5 deferred, but the target of 8 was unmet with 4 probes unspent | +| every account set aside | 5 | 6 / 18 / 0 (`rejected 6`, all 429) | **yes**, up to 10 probes | preflight failed closed | + +So the change is not confined to bursts: one served, ordinary-minute boot also ends its first pass under target with budget in hand. Only a boot that spends all sixteen probes in the first pass is untouched. + +The sidecar stderr of `.github` run 34016207820 shows its six probes (both NVIDIA keys' two deepseek routes, two OpenRouter routes) refused 429 between 07:49:35.111Z and 07:49:35.767Z. Because the walk is a round-robin across three accounts, "two consecutive 429s" on one account is two requests about **310 ms** apart (`nvidia_nim` at .111 and .422), not two probes a tenth of a second apart. The rule set all three accounts aside, the walk ended **with ten of its sixteen probes unspent**, and because deferral requires one ready route (`#1947`) nothing was served either. The five boots of that class span 07:24:50Z to 08:04:41Z. + +A refusal is not a verdict on the account. Run 34016093772 was inside its *own* preflight while that burst happened (its probes run from 07:46:21Z), and its `llama-3.2-11b` probes on the **same two NVIDIA keys** answered ready at 07:50:58.7Z and 07:50:59.0Z — 84 seconds after those keys refused 429 at 07:49:35Z. That boot ended `probed 16 / ready 5`. + +What is **not** measured: whether the ten unspent probes would have found a ready route *inside* the burst itself. No artifact answers it, because nothing records how long a refusal lasts — hence `retry_after_s` below. The pre-`#1949` walk failed similar windows for a different reason (`.github` runs 34006939646 / 34008191123 / 34008575125, 04:24–05:11Z: the same six 429s, then six gemma 404s, `ready 0` at `probed 12`), so the ban is not a regression this amendment invents; it is the ban meeting a 24-candidate list whose tail it can no longer reach. + +**Decision.** A candidate set aside by the account rule is appended to a postponed list in catalog order. Once the first pass ends with the readiness target unmet and probe budget left, the postponed candidates are probed in that order until the budget is spent; no account rule applies in that second pass. A boot that spends all sixteen probes in the first pass is unchanged; the other two classes above gain a second pass. The justification is not that the second pass rescues a burst — that is unmeasured — but that ending a walk under target with probe budget in hand is indefensible when the catalog's tail is where the ready routes live. Constraint 2 holds unchanged: at most sixteen probes per stage, and a silent second-pass probe is bounded by that count, not by a clock (ADR-0003 admits no time rule here). + +**Cost.** The second pass spends probes the walk used to abandon, so it lengthens the boot it rescues and the boot it does not. A refused probe costs about 120 ms. A **silent** one costs up to the full 90 s receive timeout (`#1661` run 34008191123, both NVIDIA keys' `deepseek-v4-pro` probes at 90.06 s and 90.10 s), and the postponed tail is full of them: `google/gemma-4-31b-it` answered `TimeoutError` in 15 of the 19 probes that reached it across these artifacts. The measured burst is therefore not a 1.2-second case — replaying 34016207820's catalog, its second pass would reach both `gemma-4-31b-it` entries, so about 3 minutes — and the worst case is 10 × 90 s ≈ **15 minutes** added to a boot that will still fail, taking a dead window from about 4 minutes to about 19 and holding the runner slot for it. + +**The two-stage path costs more than the free pool's figure.** Whenever a stage lists no more candidates than the probe budget — which is exactly the auto split, 16 free primary and 8 priced fallback — the account rule now saves nothing there, because the second pass re-probes everything it set aside. Measured on a two-account, all-429 auto run: `origin/main` sends 8 requests (4 primary, 4 priced), this design sends 24 (16 primary, 8 priced). The priced stage spends paid credit, so it doubles from 4 probes to 8 in a rate-limited hour. That is accepted for the same reason as the free pool — the priced stage only runs after every free route rejected, and stopping it half-probed is the same defect one layer down — but it is a real, stated cost, not a side effect. + +Two things are deliberately **not** traded away. The second pass never draws on the shared escalation budget (`REVIEW_PREFLIGHT_MAX_ESCALATIONS`, one counter for the whole run, carried into the priced stage by `#1458`): a postponed candidate that answers with the budget-too-small signature is rejected as `escalation_reserved_for_first_pass` rather than escalating, because otherwise candidates the previous design never probed would take escalations from the priced stage that had them, and a two-stage run measurably stops serving a route it used to serve. + +That competes directly with the org's 60-job ceiling work, and `#1949`'s measured benefit ("a dead window fails closed in about 4 minutes and returns the slot") is partly traded back for the chance to reach the catalog tail. It stays inside the probe budget this ADR bounds, `postponed_probed_count` plus the provisioning step's duration make the trade visible per boot, and `REVIEW_PREFLIGHT_MAX_PROBES` is the lever if the census says the exchange is bad. + +The report adds `postponed_probed_count`; `skipped_count` now means "postponed and never reached", and `candidate_count − probed_count − skipped_count` keeps its meaning. A refused probe additionally records `retry_after_s` when the response carried a whole-seconds `Retry-After` header (the HTTP-date form and out-of-range values record nothing). Nothing waits on that value; it exists so the next census can answer the question this amendment could not. + +**Discriminator.** `postponed_probed_count > 0` marks any boot that reached a second pass, which includes the `12 / 12 / 3` class as well as the burst class. To isolate the all-429 class, read the first `probed_count − postponed_probed_count` rows of `routes` (they are in probe order) and require every one to carry `http_status` 429. The next census asks (a) whether such boots end with `ready_count ≥ 1`, (b) what fraction of 429 rows carry `retry_after_s` and how long the refusals claim to last, (c) whether the healthy-minute figures (`ready 5–6`) are unchanged, and (d) the provisioning step's duration on those boots, so the benefit in (a) and the cost above are read from one table. If (a) is consistently 0 **and** (b) shows providers publishing a usable delay, the follow-up is to spend the second pass after that delay rather than immediately — a decision this ADR deliberately leaves to that data. `#1948`'s shared rate ledger remains the lever above all of it. diff --git a/scripts/ci/contextual_orchestrator_review_launcher.py b/scripts/ci/contextual_orchestrator_review_launcher.py index 39c43e24e1..e8c462abcc 100644 --- a/scripts/ci/contextual_orchestrator_review_launcher.py +++ b/scripts/ci/contextual_orchestrator_review_launcher.py @@ -58,23 +58,49 @@ # ``free`` pool lists all 24). A silent candidate's probe costs up to one # transport timeout (19 probes took 805 s in one artifact), so MAX_PROBES # bounds preflight wall time as well as request count. Candidates past the -# probe cap are reached only through the account-skip rule below, and the -# report separates ``skipped_count`` from the unreached tail so the evidence -# stays readable. +# probe cap are reached only when the account rule below sets earlier ones +# aside, and the report separates ``skipped_count`` (set aside, never probed) +# from the unreached tail so the evidence stays readable. REVIEW_PREFLIGHT_MAX_TOTAL_ROUTES = 24 REVIEW_PREFLIGHT_PRIMARY_ROUTE_LIMIT = 16 REVIEW_PREFLIGHT_TARGET_READY = 8 REVIEW_PREFLIGHT_MAX_PROBES = 16 -# A 429 at preflight is a per-key answer, not a per-model one: once one -# credential account has answered 429 to this many probes in a row, its -# remaining candidates are skipped without a probe and the walk moves on to -# the other accounts' next candidates. Under the real 2026-09-06 candidate -# order (jan's table on #1949) the round-robin would otherwise spend five of -# sixteen probes on an account whose every free route had answered 429 in -# every artifact since 21:00Z, and the readiness target was unreachable; with -# the skip the same sixteen probes reach both keys' llama routes. The two -# probed routes are still deferred (#1947); a skipped candidate is neither -# probed nor served. +# Once one credential account has answered 429 to this many probes in a row, +# its remaining candidates are set aside so the walk reaches the other +# accounts' next candidates first: under the real 2026-09-06 candidate order +# (jan's table on #1949) the round-robin would otherwise spend five of sixteen +# probes on an account whose every free route answered 429, and the readiness +# target was unreachable; setting them aside lets the same sixteen probes +# reach both keys' llama routes (catalog position 17, ready in eight of the +# fourteen merged-rule artifacts of 2026-09-06 and reached only this way). +# +# But the rule must not END the walk. When every account is set aside the walk +# stops with most of its probe budget unspent and the stage fails closed -- +# and because deferral needs one ready route (#1947), nothing is served +# either. Measured that day: `.github` run 34016207820 sent six probes across +# all three accounts between 07:49:35.111Z and 07:49:35.767Z, every one +# refused 429, and gave up with ten probes unspent; five runs between 07:24Z +# and 08:05Z read probed 6 / skipped 18 / ready 0. Because the walk is a +# round-robin, "two consecutive 429s" on one account is two requests about +# 310 ms apart (nvidia_nim at .111 and .422). +# +# A refusal is not a verdict on the account. Run 34016093772 was inside its +# own preflight during that burst, and its llama probes on the same two NVIDIA +# keys answered ready at 07:50:58.7 and 07:50:59.0 -- 84 s after those keys +# refused 429. Whether the unspent probes would find a ready route *inside* a +# burst is still unmeasured; that is what `retry_after_s` is for. What is +# certain is that failing closed with two thirds of the budget in hand is +# indefensible, and the cost of spending it is bounded by the probe count, not +# a clock: a refused probe costs about 120 ms, a silent one up to the 90 s +# receive timeout, and the postponed tail contains both (google/gemma-4-31b-it +# answered TimeoutError in 15 of the 19 probes that reached it). See ADR-0029's +# amendment for the full cost table. +# +# So a set-aside candidate is postponed, not banned: once the first pass ends +# with the target unmet and probes left, the postponed candidates are probed +# in catalog order until the budget is spent. Probed 429 routes are still +# deferred (#1947); a candidate the budget never reaches is neither probed nor +# served. REVIEW_PREFLIGHT_ACCOUNT_SKIP_AFTER_429 = 2 # ADR-0005: a single fixed max_tokens cannot fit every model in a heterogeneous # pool -- some spend internal reasoning tokens before visible content and need @@ -268,6 +294,46 @@ def _safe_http_status(exc: Exception) -> int | None: return None +def _safe_retry_after_seconds(exc: Exception) -> int | None: + """Return the response's ``Retry-After`` delay in whole seconds, if it sent one. + + Recorded so the evidence can answer a question this codebase cannot + answer today: when a preflight probe is refused with 429, do the + providers say how long the refusal lasts? The 2026-09-06 artifacts show + every probe of a burst refused inside a second (`.github` 34016207820 and + four sibling boots), with nothing in the evidence about how long the + refusal window actually was. Only the delta-seconds + form is read; the HTTP-date form and anything out of range record + nothing, because a wrong number here would be worse than no number. + This is evidence only -- no code waits on it (ADR-0003). + + Args: + exc: The exception a probe attempt raised. + + Returns: + The delay in seconds, or ``None`` when the response carried no + usable ``Retry-After`` header. + """ + headers = getattr(exc, "headers", None) + get_header = getattr(headers, "get", None) + if not callable(get_header): + return None + try: + raw = get_header("Retry-After") + except Exception: # noqa: BLE001 - a hostile header mapping is not evidence + return None + # ``isdecimal`` rather than ``isdigit``: a provider controls this header, + # and ``"²".isdigit()`` is True while ``int("²")`` raises. This + # runs inside the probe walk's exception handler, so a ValueError here + # would escape ``_preflight_review_agents`` -- whose callers catch only + # ``ReviewPreflightError`` -- and kill the boot before any evidence file + # is written. Every ``isdecimal`` string is accepted by ``int``. + if not isinstance(raw, str) or not raw.strip().isdecimal(): + return None + seconds = int(raw.strip()) + return seconds if 0 <= seconds <= 86400 else None + + def _response_finish_reason(response: object) -> str | None: """Return a bounded ``finish_reason`` string from an OpenAI-compatible response. @@ -329,6 +395,9 @@ def _record_provider_exception(row: dict[str, object], exc: Exception) -> None: http_status = _safe_http_status(exc) if http_status is not None: row["http_status"] = http_status + retry_after = _safe_retry_after_seconds(exc) + if retry_after is not None: + row["retry_after_s"] = retry_after row.pop("finish_reason", None) row.pop("reasoning_without_content", None) @@ -444,10 +513,13 @@ def _preflight_review_agents( candidate costs one probe rather than a served slot and a healthy pool is not probed to exhaustion. An account that has answered 429 to ``REVIEW_PREFLIGHT_ACCOUNT_SKIP_AFTER_429`` consecutive probes has its - remaining candidates skipped without a probe (a 429 is a per-key answer). - Unprobed candidates get no ``routes`` row; ``skipped_count`` counts the - skipped ones and ``candidate_count - probed_count - skipped_count`` the - unreached tail. + remaining candidates postponed behind the other accounts' candidates; + once the first pass ends with the target unmet and budget left, the + postponed candidates are probed in catalog order (a 429 is an answer + about the instant, not the account). Unprobed candidates get no + ``routes`` row; ``skipped_count`` counts the postponed candidates the + budget never reached, ``postponed_probed_count`` the ones it did, and + ``candidate_count - probed_count - skipped_count`` the unreached tail. Args: agents: Selected zero-cost model agents. @@ -468,17 +540,36 @@ def _preflight_review_agents( viable: list[object] = [] routes: list[dict[str, object]] = [] consecutive_429: dict[str, int] = {} - skipped = 0 + # Candidates the account rule set aside in the first pass, in catalog + # order. They are probed in a second pass while budget is left and the + # target is unmet; the ones that pass never reaches are the skipped ones. + postponed: list[object] = [] + postponed_probed = 0 # One entry per probe, in probe order: ``routes[i]`` describes - # ``probed[i]``. Skipped candidates appear in neither, so the deferral pass - # below must pair rows with this list, not with ``agents``. + # ``probed[i]``. A postponed candidate joins both only when its probe + # runs, so the deferral pass below must pair rows with this list, not + # with ``agents``. probed: list[object] = [] - for agent in agents: + walk = iter(agents) + second_pass = False + # A dedicated sentinel, not ``None``: ``None`` is a legal element of a + # candidate list and would silently truncate the walk. + exhausted = object() + while True: if len(viable) >= REVIEW_PREFLIGHT_TARGET_READY or len(routes) >= REVIEW_PREFLIGHT_MAX_PROBES: break + agent = next(walk, exhausted) + if agent is exhausted: + if second_pass or not postponed: + break + walk = iter(postponed) + second_pass = True + continue account = provider_account(str(getattr(agent, "provider_name", "") or "unknown")) - if consecutive_429.get(account, 0) >= REVIEW_PREFLIGHT_ACCOUNT_SKIP_AFTER_429: - skipped += 1 + if second_pass: + postponed_probed += 1 + elif consecutive_429.get(account, 0) >= REVIEW_PREFLIGHT_ACCOUNT_SKIP_AFTER_429: + postponed.append(agent) continue # Cleared here; only a 429 answer below restores it, incremented. streak_429 = consecutive_429.pop(account, 0) @@ -554,11 +645,27 @@ def _preflight_review_agents( # a specific policy without real telemetry on which candidates # actually need escalation would itself be the kind of unjustified # heuristic this design rejects elsewhere. - if not budget_signature or escalations_used >= REVIEW_PREFLIGHT_MAX_ESCALATIONS: + # The second pass never draws on the shared escalation budget. That + # budget is one counter for the whole run, spent in catalog order and + # carried into the priced fallback stage (#1458). Candidates in the + # second pass are ones the account rule had set aside and the previous + # design never probed at all, so letting them claim escalations would + # take them from stages that had them before: measured on a two-stage + # run where every primary candidate on one account answered 429, the + # priced fallback candidate that needs its escalation is denied one and + # the run stops serving a route it used to serve. + if ( + not budget_signature + or second_pass + or escalations_used >= REVIEW_PREFLIGHT_MAX_ESCALATIONS + ): row["status"] = "rejected" - row["error_type"] = ( - "invalid_chat_response" if not budget_signature else "escalation_budget_exhausted" - ) + if not budget_signature: + row["error_type"] = "invalid_chat_response" + elif second_pass: + row["error_type"] = "escalation_reserved_for_first_pass" + else: + row["error_type"] = "escalation_budget_exhausted" routes.append(row) continue escalations_used += 1 @@ -612,7 +719,8 @@ def _preflight_review_agents( # _preflight_with_fallback's "priced catalog only after every primary # route rejects" contract (ADR-0005) is unchanged. ``routes`` holds one # row per *probed* agent in probe order (every branch above appends once), - # and ``probed`` the matching agents -- skipped candidates are in neither. + # and ``probed`` the matching agents -- a postponed candidate is in both + # once its second-pass probe has run, and in neither otherwise. deferred: list[object] = [] if viable: for agent, row in zip(probed, routes): @@ -629,7 +737,8 @@ def _preflight_review_agents( "ready_count": len(viable), "deferred_count": len(deferred), "rejected_count": len(routes) - len(viable) - len(deferred), - "skipped_count": skipped, + "skipped_count": len(postponed) - postponed_probed, + "postponed_probed_count": postponed_probed, "target_ready": REVIEW_PREFLIGHT_TARGET_READY, "probe_budget": REVIEW_PREFLIGHT_MAX_PROBES, "account_skip_after_429": REVIEW_PREFLIGHT_ACCOUNT_SKIP_AFTER_429, diff --git a/tests/test_contextual_orchestrator_review_runtime_preflight.py b/tests/test_contextual_orchestrator_review_runtime_preflight.py index 0944c7ed2f..7f92162097 100644 --- a/tests/test_contextual_orchestrator_review_runtime_preflight.py +++ b/tests/test_contextual_orchestrator_review_runtime_preflight.py @@ -2102,9 +2102,127 @@ def _preflight_agents(*ids: str) -> list[SimpleNamespace]: class _StatusError(Exception): """Exception with a ``code`` attribute, the shape ``_safe_http_status`` reads.""" - def __init__(self, code: int) -> None: + def __init__(self, code: int, headers: object | None = None) -> None: super().__init__(f"HTTP Error {code}") self.code = code + if headers is not None: + self.headers = headers + + +@pytest.mark.parametrize( + ("headers", "expected"), + [ + ({"Retry-After": "37"}, 37), + ({"Retry-After": " 60 "}, 60), + ({"Retry-After": "0"}, 0), + ({"Retry-After": "Wed, 06 Sep 2026 08:00:00 GMT"}, None), + # "²".isdigit() is True but int("²") raises; the header is provider + # controlled and this runs inside the probe walk's exception handler, + # so an unguarded int() would kill the boot before any evidence file + # is written. Reached in production: HTTPError.headers decodes + # iso-8859-1, so byte 0xB2 arrives as this string. + ({"Retry-After": "²"}, None), + ({"Retry-After": "¹²"}, None), + # Arabic-Indic digits are decimal, so int() does parse them. + ({"Retry-After": "٣٠"}, 30), + ({"Retry-After": "-5"}, None), + ({"Retry-After": "999999"}, None), + ({"Retry-After": ""}, None), + ({}, None), + (None, None), + ("not-a-mapping", None), + ], +) +def test_preflight_records_only_a_usable_retry_after_delay( + headers: object | None, expected: int | None +) -> None: + """``retry_after_s`` records whole delta-seconds and nothing else. + + A 429 at preflight says nothing today about how long the refusal lasts + (`.github` run 34016207820 and `keyverse` #143 both refused every probe + inside a second). The delta-seconds form is recorded as evidence; the + HTTP-date form, out-of-range values and a hostile header object record + nothing, because a wrong number would be worse than no number. No code + waits on the value. + """ + namespace = _load_launcher() + row: dict[str, object] = {} + + namespace["_record_provider_exception"](row, _StatusError(429, headers)) + + assert row.get("retry_after_s") == expected + assert (row["status"], row["http_status"]) == ("rejected", 429) + + +def test_preflight_second_pass_does_not_spend_the_shared_escalation_budget() -> None: + """A postponed candidate never claims an escalation the priced stage still needs. + + ``escalations_used`` is one counter for the whole run, carried into the + priced fallback stage (#1458). Second-pass candidates are ones the account + rule had set aside and the previous design never probed, so letting them + escalate would take escalations from stages that had them before. Here the + first pass sets an account aside, and the postponed candidates all answer + with the budget-too-small signature: without the reservation each would + escalate and drain the shared budget. + """ + namespace = _load_launcher() + preflight = namespace["_preflight_review_agents"] + + def agent(account: str, index: int) -> SimpleNamespace: + return SimpleNamespace(id=f"{account}{index}", provider_name=account, model=f"{account}/m{index}", priority=0) + + agents = [agent("X", 1), agent("X", 2), agent("Y", 1), agent("X", 3), agent("X", 4)] + too_small = {"choices": [{"finish_reason": "length", "message": {"content": ""}}]} + client = _ProbeClient( + { + "X1": _StatusError(429), + "X2": _StatusError(429), + "Y1": _openai_text("OK"), + "X3": too_small, + "X4": too_small, + } + ) + + served, report = preflight(agents, client=client) + + assert [call[0].id for call in client.calls] == ["X1", "X2", "Y1", "X3", "X4"] + assert report["escalations_used"] == 0 + second_pass = report["routes"][3:] + assert [row["error_type"] for row in second_pass] == [ + "escalation_reserved_for_first_pass", + "escalation_reserved_for_first_pass", + ] + assert [row["attempts"] for row in second_pass] == [1, 1] + assert [a.id for a in served][:1] == ["Y1"] + + +def test_preflight_walk_treats_a_none_candidate_as_a_candidate() -> None: + """Exhaustion is a dedicated sentinel, so a ``None`` entry cannot truncate the walk.""" + namespace = _load_launcher() + preflight = namespace["_preflight_review_agents"] + agents: list[object] = [None, SimpleNamespace(id="B", provider_name="b", model="b/m", priority=0)] + client = _ProbeClient({"": _StatusError(404), "B": _openai_text("OK")}) + + served, report = preflight(agents, client=client) + + assert report["probed_count"] == 2 + assert [a.id for a in served] == ["B"] + + +def test_preflight_retry_after_survives_a_raising_header_mapping() -> None: + """A header mapping that raises is not evidence and never breaks the probe walk.""" + namespace = _load_launcher() + + class _HostileHeaders: + def get(self, name: str) -> str: + raise RuntimeError(name) + + row: dict[str, object] = {} + + namespace["_record_provider_exception"](row, _StatusError(429, _HostileHeaders())) + + assert "retry_after_s" not in row + assert row["status"] == "rejected" def test_preflight_defers_transient_probe_statuses_behind_ready_routes() -> None: @@ -2283,18 +2401,22 @@ def test_preflight_probe_budget_bounds_a_dead_hour() -> None: assert (report["rejected_count"], report["deferred_count"], report["skipped_count"]) == (budget, 0, 0) -def test_preflight_skips_an_account_after_consecutive_429s() -> None: - """A rate-limited hour costs two probes per account, not the whole budget. +def test_preflight_postpones_a_rate_limited_account_and_spends_the_leftover_budget() -> None: + """Two 429s set an account aside; the leftover budget is then spent on the postponed candidates. - A 429 at preflight is a per-key answer. Once one credential account has - answered 429 to REVIEW_PREFLIGHT_ACCOUNT_SKIP_AFTER_429 probes in a row, its - remaining candidates are skipped without a probe. With every account - rate-limited the walk ends after two probes per account and the stage - fails as before (no route is ready, so nothing is deferred either). + With every account answering 429 the first pass ends after two probes per + account with ten of sixteen probes unspent. The merged rule stopped the walk + there and failed the stage with the budget unused (2026-09-06 07:49:35Z: + six 429s within 656 ms across all three accounts, `.github` run + 34016207820). Now the postponed candidates are probed in catalog order + until the budget is spent; the stage still fails when nothing answers, and + the report says how many postponed candidates were probed and how many + were never reached. """ namespace = _load_launcher() preflight = namespace["_preflight_review_agents"] skip_after = namespace["REVIEW_PREFLIGHT_ACCOUNT_SKIP_AFTER_429"] + budget = namespace["REVIEW_PREFLIGHT_MAX_PROBES"] accounts = ("nvidia_nim", "nvidia_nim_sub", "openrouter") agents = [ SimpleNamespace(id=f"{account}_{index}", provider_name=account, model=f"{account}/m{index}", priority=-index) @@ -2307,13 +2429,62 @@ def test_preflight_skips_an_account_after_consecutive_429s() -> None: preflight(agents, client=client) report = failure.value.report - assert len(client.calls) == skip_after * len(accounts) == 6 - assert report["probed_count"] == 6 - assert report["skipped_count"] == len(agents) - 6 + first_pass = skip_after * len(accounts) + assert len(client.calls) == report["probed_count"] == budget == 16 + # First pass: two probes per account in catalog order; second pass: the + # postponed candidates in catalog order until the budget is spent. + assert [call[0].id for call in client.calls] == [agent.id for agent in agents[:budget]] + assert report["postponed_probed_count"] == budget - first_pass == 10 + assert report["skipped_count"] == len(agents) - budget == 8 assert report["account_skip_after_429"] == skip_after - assert [call[0].id for call in client.calls] == [ - agent.id for agent in agents[: skip_after * len(accounts)] + assert (report["ready_count"], report["deferred_count"], report["rejected_count"]) == (0, 0, budget) + + +def test_preflight_burst_of_429s_does_not_end_the_walk_before_a_ready_route() -> None: + """A refusal on every account's first candidates no longer hides a ready route further down the catalog. + + `.github` run 34016207820's six probes all answered 429 within 656 ms and + the merged rule gave up there, ten probes unspent. This test does NOT + claim those ten probes would have succeeded in that run -- that is + unmeasured, and `retry_after_s` was added to find out. It pins the + behaviour the rule owes the caller: when the refusals do not extend to + every candidate (one artifact shows two models on one key answering 529 + and ready in the same minute), the leftover budget reaches the route that + answers. Under the artifact order with both keys' deepseek routes + refusing, the sixteenth probe reaches the first llama route and the stage + serves it with the refused routes deferred behind it. + + It also pins the cost ADR-0029 bounds: two of the ten second-pass probes + land on the silent `gemma-4-31b` entries, each of which can hold the full + receive timeout in production. The budget, not a clock, is what limits it. + """ + namespace = _load_launcher() + preflight = namespace["_preflight_review_agents"] + budget = namespace["REVIEW_PREFLIGHT_MAX_PROBES"] + agents, outcomes = _artifact_order_candidates() + for agent in agents: + if "deepseek" in agent.model: + outcomes[agent.id] = _StatusError(429) + client = _ProbeClient(outcomes) + + served, report = preflight(agents, client=client) + + probed_ids = [call[0].id for call in client.calls] + assert probed_ids[:6] == [agent.id for agent in agents[:6]] + assert len(probed_ids) == report["probed_count"] == budget + assert probed_ids[-1] == "nvidia_nim_llama-3.2-11b" + assert report["postponed_probed_count"] == budget - 6 + assert report["skipped_count"] == len(agents) - budget + assert (report["ready_count"], report["deferred_count"], report["rejected_count"]) == (1, 9, 6) + second_pass = report["routes"][6:] + silent = [row for row in second_pass if row.get("error_type") == "TimeoutError"] + assert [row["agent_id"] for row in silent] == [ + "nvidia_nim_gemma-4-31b", + "nvidia_nim_sub_gemma-4-31b", ] + assert [agent.id for agent in served][:1] == ["nvidia_nim_llama-3.2-11b"] + # Every deferred route ranks behind the one ready route. + assert max(agent.priority for agent in served[1:]) < served[0].priority def _artifact_order_candidates() -> tuple[list[SimpleNamespace], dict[str, object]]: @@ -2321,9 +2492,23 @@ def _artifact_order_candidates() -> tuple[list[SimpleNamespace], dict[str, objec Two NVIDIA keys list the same models alphabetically -- two deepseek routes, the two gemma-3 entries that answer 404 on every run, a gemma-4 entry that - answers an empty completion, then the llama and muse routes that were ready - in every pre-#1939 artifact -- and every OpenRouter free route answers 429. - The catalog interleaves the three accounts tier-round-robin, eight each. + goes *silent* (`google/gemma-4-31b-it` answered ``TimeoutError`` in 15 of + the 19 probes that reached it across the 2026-09-06 artifacts, so modelling + it as an instant empty completion hid the dominant cost of walking the + catalog tail), then the llama and muse routes that were ready in every + pre-#1939 artifact -- and every OpenRouter free route answers 429. The + catalog interleaves the three accounts tier-round-robin, eight each. + + KNOWN OPTIMISM, deliberately left alone here: the artifacts also show + `meta/llama-3.2-90b-vision-instruct` answering ``TimeoutError`` on both + keys in every probe that reached it (17 of 17), while this fixture answers + it OK. Correcting that drops + ``test_preflight_reaches_both_keys_llama_routes_under_the_artifact_order`` + below its `ready_count == REVIEW_PREFLIGHT_TARGET_READY` assertion -- which + matches production, where no 2026-09-06 artifact ever reached eight ready + routes (the best was six). That is a question about #1949's readiness + target, not about postponement, so it is raised on #1948 rather than + changed under this PR. """ nvidia_models = [ "deepseek-v4-flash", @@ -2360,7 +2545,7 @@ def _artifact_order_candidates() -> tuple[list[SimpleNamespace], dict[str, objec elif model.startswith("gemma-3"): outcomes[agent.id] = _StatusError(404) elif model.startswith("gemma-4"): - outcomes[agent.id] = {"choices": [{"finish_reason": "stop", "message": {"content": ""}}]} + outcomes[agent.id] = TimeoutError("read timed out") else: outcomes[agent.id] = _openai_text("OK") return agents, outcomes @@ -2396,11 +2581,13 @@ def test_preflight_reaches_both_keys_llama_routes_under_the_artifact_order() -> def test_preflight_deferral_pairs_rows_with_probed_agents_after_skips() -> None: - """After an account is skipped, deferred rows still map to the agents that were probed. + """After an account is set aside, deferred rows still map to the agents that were probed. - Order: X answers 429 twice (then is skipped), Y is ready, Z answers 429 - once after X's skips began. Pairing rows with the original agent list - would demote the skipped X candidates instead of Z. + Order: X answers 429 twice (then is postponed), Y is ready, Z answers 429 + once after X's postponement began; the second pass probes X3..X5 with the + leftover budget, so the row list runs X1 X2 Y1 Z1 Y2 Z2 Y3 X3 X4 X5 while + the catalog runs X1 X2 Y1 X3 Z1 Y2 X4 Z2 X5 Y3. Pairing rows with the + catalog would demote the wrong candidates from the fourth row on. """ namespace = _load_launcher() preflight = namespace["_preflight_review_agents"] @@ -2422,9 +2609,12 @@ def agent(account: str, index: int) -> SimpleNamespace: served, report = preflight(agents, client=client) - assert [call[0].id for call in client.calls] == ["X1", "X2", "Y1", "Z1", "Y2", "Z2", "Y3"] - assert (report["ready_count"], report["deferred_count"], report["skipped_count"]) == (4, 3, 3) - assert [a.id for a in served] == ["Y1", "Y2", "Z2", "Y3", "X1", "X2", "Z1"] + assert [call[0].id for call in client.calls] == [ + "X1", "X2", "Y1", "Z1", "Y2", "Z2", "Y3", "X3", "X4", "X5", + ] + assert (report["ready_count"], report["deferred_count"], report["skipped_count"]) == (4, 6, 0) + assert report["postponed_probed_count"] == 3 + assert [a.id for a in served] == ["Y1", "Y2", "Z2", "Y3", "X1", "X2", "Z1", "X3", "X4", "X5"] assert all(a.priority == -namespace["REVIEW_PREFLIGHT_DEFERRED_PRIORITY_PENALTY"] for a in served[4:])