From 8ffd6531750f834fabbd2188446d69b034be5311 Mon Sep 17 00:00:00 2001 From: Seongho Bae Date: Tue, 22 Sep 2026 01:29:18 +0900 Subject: [PATCH 01/10] feat(routing): opt-in observed-outcome health quarantine before selection Adds TaskOrchestrator(observed_health_quarantine=False). When an operator enables it, served-request outcomes weight the per-agent breaker by failure class: a slow post-send failure (timeout, dropped connection, 408/502/504) demotes the member behind healthy siblings for the next request; two slow (or three fast) failures or a >=60% windowed failure rate quarantine it for a cooldown longer than one failing attempt (360 s); a half-open probe recovers it or re-opens with a doubled, capped cooldown; an all-open pool falls back least-recently-failed first. The default stays the legacy 3/30 breaker per the 2026-09-07 no-heuristics boundary in product-technical-gap-baseline.md; flag-off changes are observability only (circuit_opened fields, all-open fallback log line, routing_evidence.health snapshot). State stays in memory under the existing lock; timeouts, retry/replay authorization, 413/429 handling and model defaults are unchanged. scripts/replay_health_quarantine.py replays the 101 sanitized Noema sidecar logs through the same breaker code (flag off reproduces the deployed breaker with 0 skips); the doctoring runbook records RED/GREEN, replay results, limits and owner decisions. Co-Authored-By: Claude Opus 5 Claude-Session: https://claude.ai/code/session_012ABB9sb4szFEteww67UYZy --- AGENTS.md | 6 + contextual_orchestrator/orchestrator.py | 322 +++++++++++++++++- ...th-quarantine-replay-preflight-whatif.json | 25 ++ ...erved-health-quarantine-replay-served.json | 25 ++ docs/doctoring/observed-health-quarantine.md | 216 ++++++++++++ docs/product-technical-gap-baseline.md | 9 + scripts/replay_health_quarantine.py | 300 ++++++++++++++++ tests/test_measured_routing_evidence.py | 2 +- tests/test_observed_health_quarantine.py | 292 ++++++++++++++++ 9 files changed, 1179 insertions(+), 18 deletions(-) create mode 100644 docs/doctoring/observed-health-quarantine-replay-preflight-whatif.json create mode 100644 docs/doctoring/observed-health-quarantine-replay-served.json create mode 100644 docs/doctoring/observed-health-quarantine.md create mode 100644 scripts/replay_health_quarantine.py create mode 100644 tests/test_observed_health_quarantine.py diff --git a/AGENTS.md b/AGENTS.md index 155d3bad3..badf00324 100644 --- a/AGENTS.md +++ b/AGENTS.md @@ -140,6 +140,12 @@ push or open a PR. unknown-outcome no-replay controls alongside it. Transport spies are not wire delivery evidence. Preserve the default-null model timeout. +- Observed-health quarantine (`observed_health_quarantine`, operator opt-in, + default off = legacy 3/30) weights slow post-send failures for breaker and + candidate order only; it never authorizes retry or changes timeouts. Keep + the never-empty fallback and in-memory restart semantics. Replay limits and + owner decisions: `docs/doctoring/observed-health-quarantine.md`. + - Endpoint races require a complete operator-reviewed equivalence contract. Never infer equivalence from provider/model names, and never treat missing loser usage as free or zero-cost execution. diff --git a/contextual_orchestrator/orchestrator.py b/contextual_orchestrator/orchestrator.py index 6b7a69d80..6dca0f643 100644 --- a/contextual_orchestrator/orchestrator.py +++ b/contextual_orchestrator/orchestrator.py @@ -2036,6 +2036,48 @@ def _is_omit_equivalent_control(key: str, value: Any) -> bool: return False +#: Observed-health failure classes (bounded vocabulary, see +#: docs/doctoring/observed-health-quarantine.md). ``slow_transport`` is a +#: failure that typically spends a full provider round trip before failing +#: (read timeout, dropped connection, gateway 504/502/408): the Noema sidecar +#: evidence measured those at p50 ~265-302 s each. ``fast`` is an immediate +#: rejection (404, 400, 500, malformed body). 429 and 413 never reach the +#: health ledger at all -- quota and request size are not member health. +_SLOW_HEALTH_ERROR_CODES = frozenset({"provider_timeout", "provider_connection_error"}) +_SLOW_HEALTH_PROVIDER_STATUSES = frozenset({408, 502, 504}) + + +def classify_health_failure(exc: BaseException | None) -> str: + """Classify one failed provider attempt for the observed-health ledger. + + Returns ``"slow_transport"`` or ``"fast"``. The class only changes how + much one failure weighs and how long a resulting quarantine lasts; it + never authorizes a retry or replay (that stays with the failure-boundary + classifiers in :mod:`contextual_orchestrator.tool_fallback`). + """ + if isinstance(exc, ProviderUpstreamError): + if ( + exc.error_code in _SLOW_HEALTH_ERROR_CODES + or exc.provider_status in _SLOW_HEALTH_PROVIDER_STATUSES + ): + return "slow_transport" + return "fast" + if isinstance(exc, urllib.error.HTTPError): + return "slow_transport" if exc.code in _SLOW_HEALTH_PROVIDER_STATUSES else "fast" + if isinstance( + exc, + ( + urllib.error.URLError, + TimeoutError, + ConnectionError, + socket.timeout, + http.client.HTTPException, + ), + ): + return "slow_transport" + return "fast" + + def _is_request_too_large_error(exc: BaseException) -> bool: """Recognize request-size rejection through a bounded exception chain.""" current: BaseException | None = exc @@ -5535,6 +5577,7 @@ def __init__( token_counter: Any = None, rate_limit_wait_seconds: float = 30.0, rate_limit_unknown_cooldown_seconds: float = 5.0, + observed_health_quarantine: bool = False, ) -> None: self._assistant_message_local = threading.local() self._output_budget_local = threading.local() @@ -5655,6 +5698,31 @@ def __init__( self._provider_readiness_lock = threading.Lock() self.circuit_failure_threshold = 3 self.circuit_reset_seconds = 30.0 + # Observed-outcome health ledger layered on the breaker above (see + # docs/doctoring/observed-health-quarantine.md). Explicit operator + # opt-in: the product-technical-gap-baseline no-heuristics boundary + # (2026-09-07) keeps automatic exclusion at the legacy 3/30 policy + # unless an operator enables this. When False, every knob below is + # inert and the breaker behaves exactly as before. In-memory only: a + # process restart starts every member unquarantined. A slow-class + # failure weighs slow_failure_weight toward the threshold and, once it + # trips, cools down for slow_failure_cooldown_seconds -- longer than + # the longest observed slow failure (302.3 s), unlike + # circuit_reset_seconds; the replay sweep (300/360/450/600/1200 s) is + # in the runbook. A half-open failure doubles the cooldown up to + # circuit_max_cooldown_seconds; nothing is excluded permanently. + # These are breaker knobs only: no timeout, retry or 413/429 policy. + if not isinstance(observed_health_quarantine, bool): + raise TypeError("observed_health_quarantine must be a boolean") + self.observed_health_quarantine = observed_health_quarantine + self._circuit_health: dict[str, dict[str, Any]] = {} + self._circuit_clock: Callable[[], float] | None = None + self.slow_failure_weight = 2.0 + self.slow_failure_cooldown_seconds = 360.0 + self.circuit_max_cooldown_seconds = 3600.0 + self.circuit_failure_window = 10 + self.circuit_failure_rate_min_observations = 6 + self.circuit_failure_rate_threshold = 0.6 # Per-agent provider-declared quota cooldown (Retry-After / x-ratelimit-reset*), # tracked separately from the health circuit breaker above: a 429 is quota # exhaustion, not a model health failure, so it must never trip or feed @@ -6152,7 +6220,9 @@ def proxy_completion( result = self.client.proxy_send(agent, endpoint, upstream) except Exception as exc: if _is_ambiguous_passthrough_transport_failure(exc): - self._record_failure(agent.id) + self._record_failure( + agent.id, failure_class=classify_health_failure(exc) + ) if agent.group_name: self._group_router.observe_failure(agent.id) unknown = ProviderUpstreamError( @@ -6357,7 +6427,10 @@ def proxy_completion( # * Explicit concrete model: never reaches this # multi-candidate loop; kept as defense in depth # with the typed ``provider_outcome_unknown``. - self._record_failure(candidate.id) + self._record_failure( + candidate.id, + failure_class=classify_health_failure(exc), + ) if candidate.group_name: self._group_router.observe_failure(candidate.id) attempt_receipts.append( @@ -6453,7 +6526,10 @@ def proxy_completion( or (rate_limit_signal is not None and rate_limit_signal[0] == 429) ) if not skip_breaker: - self._record_failure(candidate.id) + self._record_failure( + candidate.id, + failure_class=classify_health_failure(exc), + ) if candidate.group_name and not skip_breaker: self._group_router.observe_failure(candidate.id) continue @@ -7818,7 +7894,9 @@ def stream_route( last_error = upstream decision = classify_provider_transport_failure(upstream.retryable) if decision.circuit_failure: - self._record_failure(agent.id) + self._record_failure( + agent.id, failure_class=classify_health_failure(upstream) + ) if decision.action is ToolFallbackAction.FAIL_CLOSED: raise upstream from None if not request_too_large: @@ -11005,7 +11083,7 @@ def attempt(agent: ModelAgent) -> EndpointAttempt[Any]: and exc.error_code == "model_not_found" ): excluded_agent_ids.add(agent.id) - self._record_failure(agent.id) + self._record_failure(agent.id, failure_class="fast") break # The primary chat call is a bounded, side-effect-free # model request, not a tool invocation: classify from @@ -11041,7 +11119,9 @@ def attempt(agent: ModelAgent) -> EndpointAttempt[Any]: retry_attempt += 1 self._record_tool_fallback(agent.id, decision, retry_attempt) if decision.circuit_failure: # pragma: no branch - retry-classified failures always trip the circuit - self._record_failure(agent.id) + self._record_failure( + agent.id, failure_class=classify_health_failure(exc) + ) if self.tool_retry_backoff_seconds: retry_ceiling = min( self.tool_retry_backoff_seconds @@ -11056,7 +11136,9 @@ def attempt(agent: ModelAgent) -> EndpointAttempt[Any]: action = decision.action self._record_tool_fallback(agent.id, decision, retry_attempt) if decision.circuit_failure: - self._record_failure(agent.id) + self._record_failure( + agent.id, failure_class=classify_health_failure(exc) + ) if action is ToolFallbackAction.FAIL_CLOSED: raise ToolFallbackStoppedError(agent.id, decision) from None break @@ -11277,8 +11359,15 @@ def _failover_candidates( ] eligible = [agent for agent in ordered if not agent.disabled and role not in agent.provider_exclusions] healthy = [agent for agent in eligible if not self._circuit_open(agent.id)] - # If every eligible agent is circuit-open, still probe them rather than fail with no attempt. - healthy = healthy or eligible + # Observed served-request health: demote members whose latest failure + # was slow or that await a half-open probe. If every eligible agent is + # circuit-open, still probe them (least-recently-failed first) rather + # than fail with no attempt. + healthy = ( + self._order_by_observed_health(healthy) + if healthy + else self._all_open_fallback(eligible) + ) if skip_rate_limited: not_rate_limited = [ agent for agent in healthy if self._rate_limit_remaining(agent.id) is None @@ -11445,46 +11534,227 @@ def _served_tool_calls(response: Any, api_surface: str) -> list[Any] | None: else TaskOrchestrator._chat_response_tool_calls(response) ) + def _circuit_now(self) -> float: + """Return the breaker clock (monotonic unless a test injects one).""" + clock = self._circuit_clock + return clock() if clock is not None else time.monotonic() + + def _circuit_health_entry(self, agent_id: str) -> dict[str, Any]: + """Return (creating) one member's observed-health entry; caller holds the lock.""" + health = self._circuit_health.get(agent_id) + if health is None: + health = { + "score": 0.0, + "slow_streak": False, + "slow_trip": False, + "level": 0, + "half_open": False, + "open_count": 0, + "last_failure_at": None, + "last_failure_class": None, + "window": deque(maxlen=max(1, int(self.circuit_failure_window))), + } + self._circuit_health[agent_id] = health + return health + + def _circuit_cooldown(self, health: Mapping[str, Any] | None) -> float: + """Current cooldown: slow trips outlast one failing attempt; half-open failures double it.""" + if health is None or not self.observed_health_quarantine: + return float(self.circuit_reset_seconds) + base = ( + self.slow_failure_cooldown_seconds + if health["slow_trip"] + else self.circuit_reset_seconds + ) + return float( + min(base * (2.0 ** min(int(health["level"]), 16)), self.circuit_max_cooldown_seconds) + ) + def _circuit_open(self, agent_id: str) -> bool: with self._circuit_lock: state = self._circuit.get(agent_id) - if not state or state["failures"] < self.circuit_failure_threshold: + if not state or not state["opened_at"]: return False - if time.monotonic() - state["opened_at"] >= self.circuit_reset_seconds: + health = self._circuit_health.get(agent_id) + cooldown = self._circuit_cooldown(health) + if self._circuit_now() - state["opened_at"] >= cooldown: state["failures"] = 0.0 state["opened_at"] = 0.0 + if health is not None: + health["half_open"] = self.observed_health_quarantine + health["score"] = 0.0 + health["slow_streak"] = False reset_occurred = True else: reset_occurred = False if reset_occurred: if _LOGGER.isEnabledFor(logging.DEBUG): _LOGGER.debug("circuit_reset agent_id=%s", agent_id) + if not self.observed_health_quarantine: + return False + _LOGGER.info( + "circuit_half_open agent_id=%s cooldown_seconds=%s request_id=%s", + agent_id, + cooldown, + current_request_id() or "-", + ) return False return True - def _record_failure(self, agent_id: str) -> None: + def _circuit_demoted(self, agent_id: str) -> bool: + """True while a member awaits its half-open probe or its latest failure was slow.""" + if not self.observed_health_quarantine: + return False + with self._circuit_lock: + health = self._circuit_health.get(agent_id) + return bool(health and (health["half_open"] or health["slow_streak"])) + + def _order_by_observed_health(self, agents: list[ModelAgent]) -> list[ModelAgent]: + """Stable-demote suspect members behind members with no recent slow failure.""" + demoted = {agent.id for agent in agents if self._circuit_demoted(agent.id)} + if not demoted: + return agents + return [a for a in agents if a.id not in demoted] + [ + a for a in agents if a.id in demoted + ] + + def _all_open_fallback(self, agents: list[ModelAgent]) -> list[ModelAgent]: + """Never return an empty pool: order all-open members least-recently-failed first. + + With the quarantine disabled the legacy ranked order is kept; only + the fallback is logged. + """ + if not agents: + return agents + if not self.observed_health_quarantine: + _LOGGER.warning( + "circuit_all_open_fallback candidate_count=%d selected_agent_id=%s request_id=%s", + len(agents), + agents[0].id, + current_request_id() or "-", + ) + return agents + with self._circuit_lock: + last_failed = { + agent.id: (self._circuit_health.get(agent.id) or {}).get("last_failure_at") + for agent in agents + } + ordered = sorted( + agents, + key=lambda agent: -math.inf + if last_failed[agent.id] is None + else last_failed[agent.id], + ) + _LOGGER.warning( + "circuit_all_open_fallback candidate_count=%d selected_agent_id=%s request_id=%s", + len(ordered), + ordered[0].id, + current_request_id() or "-", + ) + return ordered + + def circuit_health_snapshot(self) -> dict[str, dict[str, Any]]: + """Bounded per-member breaker/health evidence (no prompt or provider text).""" + agents = {agent.id: agent for agent in self.candidates} + now = self._circuit_now() + snapshot: dict[str, dict[str, Any]] = {} + with self._circuit_lock: + for agent_id in sorted(set(self._circuit) | set(self._circuit_health)): + state = self._circuit.get(agent_id) or {"failures": 0.0, "opened_at": 0.0} + health = self._circuit_health.get(agent_id) + cooldown = self._circuit_cooldown(health) + window = list(health["window"]) if health else [] + remaining = 0.0 + if state["opened_at"]: + remaining = max(0.0, cooldown - (now - state["opened_at"])) + if state["opened_at"] and remaining > 0: + status = "open" + elif state["opened_at"] or (health and health["half_open"]): + status = "half_open" + else: + status = "closed" + agent = agents.get(agent_id) + snapshot[agent_id] = { + "state": status, + "model": agent.model if agent else None, + "provider": ( + agent.provider_name or self._infer_provider_name(agent.base_url) + if agent + else None + ), + "consecutive_failures": int(state["failures"]), + "weighted_score": float(health["score"]) if health else 0.0, + "last_failure_class": health["last_failure_class"] if health else None, + "cooldown_seconds": cooldown, + "remaining_seconds": round(remaining, 3), + "window_size": len(window), + "window_failure_rate": ( + round(sum(window) / len(window), 4) if window else None + ), + "open_count": int(health["open_count"]) if health else 0, + } + return snapshot + + def _record_failure(self, agent_id: str, *, failure_class: str | None = None) -> None: + """Record one failed attempt; ``failure_class`` comes from :func:`classify_health_failure`.""" + failure_class = failure_class or "unclassified" + enabled = self.observed_health_quarantine + slow = failure_class == "slow_transport" opened = False + trigger = "" + cooldown = 0.0 with self._circuit_lock: + now = self._circuit_now() state = self._circuit.setdefault(agent_id, {"failures": 0.0, "opened_at": 0.0}) state["failures"] += 1.0 failures = state["failures"] - if failures >= self.circuit_failure_threshold and not state["opened_at"]: - state["opened_at"] = time.monotonic() + health = self._circuit_health_entry(agent_id) + health["score"] += self.slow_failure_weight if slow and enabled else 1.0 + health["slow_streak"] = health["slow_streak"] or slow + health["last_failure_at"] = now + health["last_failure_class"] = failure_class + window = health["window"] + window.append(True) + if not state["opened_at"]: + if enabled and health["half_open"]: + trigger = "half_open_failure" + elif health["score"] >= self.circuit_failure_threshold: + trigger = "consecutive" + elif ( + enabled + and len(window) >= self.circuit_failure_rate_min_observations + and sum(window) / len(window) >= self.circuit_failure_rate_threshold + ): + trigger = "failure_rate" + if trigger: + if health["half_open"]: + health["level"] += 1 + health["half_open"] = False + health["slow_trip"] = health["slow_trip"] or health["slow_streak"] + health["open_count"] += 1 + cooldown = self._circuit_cooldown(health) + # A zero clock reading would read as "closed"; keep it truthy. + state["opened_at"] = now or 1e-9 opened = True if _LOGGER.isEnabledFor(logging.DEBUG): _LOGGER.debug( - "circuit_failure agent_id=%s failures=%s threshold=%s", + "circuit_failure agent_id=%s failures=%s threshold=%s failure_class=%s", agent_id, failures, self.circuit_failure_threshold, + failure_class, ) if opened: _LOGGER.warning( - "circuit_opened agent_id=%s failures=%s threshold=%s reset_seconds=%s", + "circuit_opened agent_id=%s failures=%s threshold=%s reset_seconds=%s " + "failure_class=%s trigger=%s request_id=%s", agent_id, failures, self.circuit_failure_threshold, - self.circuit_reset_seconds, + cooldown, + failure_class, + trigger, + current_request_id() or "-", ) def _record_embedding_failure( @@ -11513,8 +11783,25 @@ def _record_embedding_failure( def _record_success(self, agent_id: str) -> None: with self._circuit_lock: cleared = self._circuit.pop(agent_id, None) + health = self._circuit_health_entry(agent_id) + recovered = bool(health["half_open"]) + health["score"] = 0.0 + health["slow_streak"] = False + health["half_open"] = False + # A closed breaker escalates from zero again. + health["level"] = 0 + health["slow_trip"] = False + if recovered: + health["window"].clear() + health["window"].append(False) if cleared is not None and _LOGGER.isEnabledFor(logging.DEBUG): _LOGGER.debug("circuit_cleared agent_id=%s", agent_id) + if recovered: + _LOGGER.info( + "circuit_recovered agent_id=%s request_id=%s", + agent_id, + current_request_id() or "-", + ) #: Statuses for which an absent Retry-After/x-ratelimit-reset* still #: records an assumed cooldown. Deliberately 429 only: 503 ("service @@ -19049,6 +19336,7 @@ def admin_state( "routing_evidence": { "transport": self._group_router.snapshot(), "quality": self._quality_router.snapshot(), + "health": self.circuit_health_snapshot(), }, "recent_workflow_runs": [ self._shorten_run(run) diff --git a/docs/doctoring/observed-health-quarantine-replay-preflight-whatif.json b/docs/doctoring/observed-health-quarantine-replay-preflight-whatif.json new file mode 100644 index 000000000..c8d8db1b0 --- /dev/null +++ b/docs/doctoring/observed-health-quarantine-replay-preflight-whatif.json @@ -0,0 +1,25 @@ +{ + "demote_skips": 160.0, + "demotion": true, + "false_positive_episodes": 1.0, + "forced_fallback_attempts": 15.0, + "harmful_removals": 1.0, + "harmful_removals_after_slow_transport": 1.0, + "harmful_requests": 1.0, + "include_preflight": true, + "policy_overrides": { + "observed_health_quarantine": true + }, + "quarantine_episodes": 61.0, + "quarantine_skips": 10.0, + "runs": 101, + "saved_failed_seconds": 36831.6, + "saved_failed_seconds_after_fast": 490.1, + "saved_failed_seconds_after_slow_transport": 36341.5, + "saved_failed_seconds_by_demote_skip": 35205.8, + "saved_failed_seconds_by_quarantine_skip": 1625.8, + "saved_slow_failure_seconds": 36319.6, + "served_attempts": 1627.0, + "served_failed_seconds": 111064.9, + "served_slow_failure_seconds": 100261.0 +} diff --git a/docs/doctoring/observed-health-quarantine-replay-served.json b/docs/doctoring/observed-health-quarantine-replay-served.json new file mode 100644 index 000000000..86bfc3b61 --- /dev/null +++ b/docs/doctoring/observed-health-quarantine-replay-served.json @@ -0,0 +1,25 @@ +{ + "demote_skips": 160.0, + "demotion": true, + "false_positive_episodes": 1.0, + "forced_fallback_attempts": 15.0, + "harmful_removals": 1.0, + "harmful_removals_after_slow_transport": 1.0, + "harmful_requests": 1.0, + "include_preflight": false, + "policy_overrides": { + "observed_health_quarantine": true + }, + "quarantine_episodes": 37.0, + "quarantine_skips": 10.0, + "runs": 101, + "saved_failed_seconds": 36831.6, + "saved_failed_seconds_after_fast": 490.1, + "saved_failed_seconds_after_slow_transport": 36341.5, + "saved_failed_seconds_by_demote_skip": 35205.8, + "saved_failed_seconds_by_quarantine_skip": 1625.8, + "saved_slow_failure_seconds": 36319.6, + "served_attempts": 1627.0, + "served_failed_seconds": 111064.9, + "served_slow_failure_seconds": 100261.0 +} diff --git a/docs/doctoring/observed-health-quarantine.md b/docs/doctoring/observed-health-quarantine.md new file mode 100644 index 000000000..ca01178be --- /dev/null +++ b/docs/doctoring/observed-health-quarantine.md @@ -0,0 +1,216 @@ +--- +title: "Observed-outcome health quarantine for served-request candidate selection" +status: "Proposed (operator opt-in; default off)" +date: "2026-09-22" +scope: "feat/observed-health-quarantine (base origin/main 5665b0ad)" +--- + +# Observed-outcome health quarantine + +## Problem (measured, biased sample) + +Evidence source (read-only, not committed): the sanitized Noema sidecar +artifacts under +`CO-LEAD-EVIDENCE-20260920/research-support-20260921/noema-real-path-measurement-20260922/` +in the lead workspace. There are 101 runs from 8 repositories. Twelve runs sit +under the hidden `.github/` directory, which the evidence directory's own +scripts skip, so its `summary.txt` covers 89 runs. The deployed pin was +`767e67f`. **The upload step ran on `failure()` only, so this sample +over-represents failed runs; none of the numbers below are population rates.** + +- Served review requests: p50 1670 s, p90 4567 s. +- RemoteDisconnected (p50 265 s) and HTTP 504 (p50 302 s) make up about 94 % + of failed-attempt wall time. +- Within a single run, the same agent slow-failed again on 165 extra attempts + across 36 runs. Most of these were NVIDIA NIM `deepseek-v4-flash-0731` (both + accounts), `llama-3.2-90b-vision-instruct` and `gemma-4-31b-it`. +- The legacy breaker opens after three unweighted consecutive failures. Its + `circuit_reset_seconds = 30` is shorter than one ~300 s failing attempt, and + the reset zeroes the counter. This is the second and third gap recorded in + `docs/product-technical-gap-baseline.md` (2026-09-06 amendment). + +## Policy boundary: explicit operator opt-in + +`docs/product-technical-gap-baseline.md` (no-heuristics boundary, 2026-09-07) +keeps automatic candidate exclusion at the legacy 3/30 policy unless an +operator supplies the decision. This change therefore ships the mechanism +behind `TaskOrchestrator(..., observed_health_quarantine=False)`. + +With the flag off (the default, and what the sidecar runs today), the breaker +is behavior-identical to the legacy one: weight 1, a 30 s reset that zeroes +the counter, no failure-rate trigger, no half-open state and no demotion. The +only additions are observability: extra `circuit_opened` fields, the +`circuit_all_open_fallback` log line and the `routing_evidence.health` +snapshot. + +The values below are repository-proposed and backed only by the replay in +this document. Enabling them, and choosing how the sidecar passes the flag +(CLI or KV bootstrap, following the `rate_limit_wait_seconds` precedent), is +an owner decision. #1000, #911 and #1082 still own the broader routing repair. + +## Design (flag on) + +The breaker ledger already sits in front of candidate selection: +`_failover_candidates` filters with `_circuit_open` before any attempt. The +mechanism therefore extends that ledger rather than adding a second breaker. + +| Concern | Behavior | +| --- | --- | +| Signal | Real served-request outcomes. Every existing `_record_failure` / `_record_success` call site feeds the ledger. Where the exception is in hand (`_invoke`, `stream_route`, and the explicit and virtual passthrough loops), the call passes `failure_class=classify_health_failure(exc)`. The launcher preflight is not duplicated. | +| Failure class | `slow_transport`: `provider_timeout` or `provider_connection_error`, status 408/502/504, or a raw timeout, reset, `RemoteDisconnected` or `URLError`. `fast`: everything else. Call sites that pass no class count as `unclassified` with weight 1. 413 and passthrough 429 never reach the ledger, the same as before. | +| Demotion | Once a member's latest failure is slow, `_failover_candidates` keeps it eligible but stable-sorts it behind members without a recent slow failure. The result of request N therefore changes the order for request N+1. A single failure never excludes a member. | +| Quarantine | The breaker opens when any of these holds: (a) the weighted consecutive score (slow = `slow_failure_weight` 2.0, else 1.0) reaches `circuit_failure_threshold` 3, which means two slow failures or three fast ones; (b) at least 6 of the last 10 outcomes are recorded and the failure rate is at least 0.6 (a single success no longer erases the evidence); (c) the half-open probe fails. | +| Cooldown | A trip that involved a slow failure lasts `slow_failure_cooldown_seconds` (360 s, longer than the longest observed slow failure of 302.3 s). A trip from fast failures only uses `circuit_reset_seconds` (30 s). Each half-open failure doubles the cooldown, capped at `circuit_max_cooldown_seconds` (3600 s). Any success resets the escalation level. Exclusion is never permanent. | +| Half-open / recovery | When the cooldown expires, the member becomes eligible again but stays demoted, so it is probed only after healthy members. A success clears the state and logs `circuit_recovered`. A failure re-opens the breaker immediately with the escalated cooldown. | +| Never empty | If every eligible member is open, `_failover_candidates` returns all of them, least-recently-failed first, and logs WARNING `circuit_all_open_fallback candidate_count=N selected_agent_id=... request_id=...`. With the flag off, the legacy ranked order is kept and only the log line is added. The embedding path's explicit 503 when all members are open (`_capability_agents`) is unchanged. However, the flag-on failure-rate and half-open triggers apply to every `_record_failure` caller, including `_record_embedding_failure`, `_record_race_attempt` and synthesis repair. | +| Metrics | WARNING `circuit_opened ... reset_seconds= failure_class=... trigger=consecutive|failure_rate|half_open_failure request_id=...`; INFO `circuit_half_open`, `circuit_recovered`; DEBUG `circuit_failure ... failure_class=...`. `circuit_health_snapshot()` holds bounded per-member fields: state, model, provider, counts, class, cooldown, remaining, window rate and open count. It is exposed at `admin_state()["routing_evidence"]["health"]`; `test_measured_routing_evidence` pins the key set. No prompt text or provider body text is included. | +| Concurrency | All ledger reads and writes happen under `_circuit_lock`. Concurrent failures open the breaker exactly once (tested with 16 threads). | +| Restart | State is in memory only. After a process restart, every member starts unquarantined and undemoted. Each Noema sidecar is a fresh process, so learning is scoped to one run. | +| Unchanged | Model timeouts (the default null timeout stays), retry and replay authorization, 413/429 handling and model-policy defaults are all untouched. The class only weights health; it never authorizes a retry. | + +Compatibility note: `_circuit_open` now tests `opened_at` instead of +`failures >= threshold`. With the flag off the two tests are equivalent, +because every failure weighs 1. `_circuit` entries keep their exact legacy +shape (`{"failures", "opened_at"}`). The new state lives in `_circuit_health`. + +## RED / GREEN + +- New contracts: `tests/test_observed_health_quarantine.py`, 10 tests. Nine + cover the enabled path; one pins that the default stays legacy 3/30. +- RED on unmodified `origin/main` `5665b0ad`: collection fails with + `ImportError: cannot import name 'classify_health_failure'`. To get a + behavioral RED, the import was removed and the original nine tests were + re-run: 9 failed. The key assertion was + `test_served_slow_failure_demotes_agent_for_the_next_request`: + `['slow_worker', 'steady_worker'] != ['steady_worker', 'slow_worker']`, + meaning request N+1 still tried the member that had just slow-failed. +- GREEN: `python3 -m pytest tests/test_observed_health_quarantine.py tests/test_measured_routing_evidence.py -q -W error`. +- Full `pytest tests` (non-strict) on base and head: the only difference was + `test_admin_state_exposes_both_routing_ledgers`, which pinned + `{"transport", "quality"}` and is updated for the additive `health` key. + The other 200 failures and 31 errors are identical on `origin/main`. They + are pre-existing: a `cost_router` import error, `selection_design` + KeyErrors, egress allowlist and paper-inventory contracts. +- `-W error` on the 13 neighbor suites: base and head are both nonclean (81 + and 82 failing ids in one run each, with different sets). The failures are + dominated by the pre-existing `_TemporaryFileCloser` and unclosed + `HTTPError` ResourceWarnings owned by the HTTP resource runbook (#1140). + They are not attributed to this change. + +## Replay + +`scripts/replay_health_quarantine.py` is kept under `scripts/` because that +is where the repository keeps runnable analysis. It replays each run through +a fresh `TaskOrchestrator`, running the same breaker code with an injected +clock set to the log timestamps. + +- **Pairing.** Each failure line is paired with the latest open attempt of the + same request and agent, as in `noema_phase.py`. On the 89 non-hidden runs + this reproduces the evidence summary's served failed seconds exactly + (92,186 s). +- **What feeds the ledger.** A served failure feeds the ledger only if the + deployed log shows the deployed path charged it, meaning a + `circuit_failure` line follows it. 413 is never charged. Served 429 on the + `_invoke` path is charged. +- **Forced attempts.** An attempt that started while the deployed breaker was + open (`circuit_opened` less than 30 s earlier, not cleared) was forced by + the never-empty fallback or by a pinned model. The replay never counts such + an attempt as skippable (`forced_fallback_attempts`). +- **Fidelity check.** With the flag off (`--legacy-like`), the replay skips + **0** attempts, and all 30 of its open-state hits coincide with forced + attempts. So the replay reproduces the deployed breaker. + +```bash +python3 scripts/replay_health_quarantine.py \ + --json docs/doctoring/observed-health-quarantine-replay-served.json +python3 scripts/replay_health_quarantine.py --include-preflight \ + --json docs/doctoring/observed-health-quarantine-replay-preflight-whatif.json +python3 scripts/replay_health_quarantine.py --legacy-like # deployed default +python3 scripts/replay_health_quarantine.py --no-demotion +``` + +Results for all 101 runs, served requests only, flag on +(`observed-health-quarantine-replay-served.json`): + +| Metric | Value | +| --- | --- | +| Served attempts / failed seconds / slow-failure seconds | 1627 / 111,065 s / 100,261 s | +| Estimated failed seconds avoided | **36,832 s** (slow-class 36,320 s, about 36 % of served slow-failure seconds) | +| … by demotion (a member tried after a sibling that succeeded) | 35,206 s over 160 skipped attempts | +| … by quarantine exclusion | 1,626 s over 10 skipped attempts | +| Quarantine episodes | 37 (15 open-state hits were forced and not skipped) | +| False-positive episodes (the first attempt after opening would have succeeded) | **1** of 37 | +| Harmful removals (a skipped attempt was its step's eventual success) | **1** attempt in 1 request (upper bound) | + +Sensitivity to `slow_failure_cooldown_seconds`, flag on, all other settings +at their defaults: + +| Cooldown | Saved s | Quarantine skips | FP episodes | Harmful removals / requests | +| --- | --- | --- | --- | --- | +| 300 s | 36,832 | 10 | 1 | 1 / 1 | +| **360 s (proposed)** | 36,832 | 10 | 1 | 1 / 1 | +| 450 s | 37,090 | 13 | 2 | 3 / 3 | +| 600 s | 38,181 | 21 | 3 | 7 / 4 | +| 1200 s | 38,237 | 26 | 2 | 8 / 5 | + +Other variants: + +- `--no-demotion` saves 13,606 s but produces 129 episodes and 10 harmful + removals across 7 requests. Demotion is the main lever, and it also keeps + harm down. +- `--legacy-like` (the deployed default) saves 0 s by construction. + +Preflight what-if (`--include-preflight`): launcher preflight probes +(`request_id=-`) run inside the sidecar process but call `ModelClient` +directly. No preflight failure in the 101 logs was followed by a +`circuit_failure` line, so deployment does not feed them to the ledger. + +Feeding them anyway adds 24 episodes. Each one opens on the served failure +that follows a preflight slow failure: the preflight failure was strike one. +(Replayed `circuit_opened` lines show `request_id=-` only because the replay +sets no request context.) The savings do not change (36,832 s) for two +reasons. That served re-hit was itself not demote-skippable, because no +healthier sibling succeeded later in the same step. And no later served +attempt reached those members inside the cooldown. This is the unrecovered +`slow_s_on_preflight_known_bad` in the evidence `summary.txt`. + +### Counterfactual limits + +- A skipped attempt's outcome is never fed back into the policy, because the + gateway would not have observed it. +- Success durations are not logged, so a success is observed at the start of + its attempt. +- The replay cannot know which substitute the gateway would have tried after + an exclusion. It also cannot know whether a skip under the new policy would + instead have hit the all-open fallback. Harmful counts are therefore upper + bounds, and saved seconds ignore any substitute cost. +- A conducted request is split into failover steps, one ending at each + success. Demotion credit requires that a non-demoted, non-open sibling + succeeded later in the same step. +- The ceiling is within-run repetition only, because every run starts from a + fresh process. +- The sample is biased toward failed runs, and savings will be smaller on + healthy runs. None of this is customer-latency evidence until served + p50/p90 are re-measured on a deployed pin with the flag on. + +## Owner decisions / open questions + +1. Whether and how to enable `observed_health_quarantine` for the sidecar + (CLI or KV bootstrap). The default stays off under the 2026-09-07 + boundary. +2. The proposed cooldown is 360 s. The corrected sweep shows 300–360 s + dominating 600 s: slightly lower savings, but 1 harmful removal instead + of 7. This is tuned on a biased sample. +3. On the `_invoke` path, a served 429 is still charged to the breaker as a + fast failure (144 recorded occurrences in the replayed logs), while the + passthrough path excludes 429 as quota. This inconsistency predates this + change and is left as it is. +4. A persisted health ledger across restarts is not implemented, so the + gateway starts unquarantined. + +## Reference + +- J. Dean and L. A. Barroso, "The Tail at Scale," *Communications of the ACM* + 56(2), 2013, doi:10.1145/2408776.2408794 (already in `docs/papers/README.md`). + It motivates keeping slow replicas off the critical path. It does not + establish these weights or cooldowns, which rest only on the replay above. diff --git a/docs/product-technical-gap-baseline.md b/docs/product-technical-gap-baseline.md index 703ec7f08..28f85008a 100644 --- a/docs/product-technical-gap-baseline.md +++ b/docs/product-technical-gap-baseline.md @@ -5722,6 +5722,15 @@ repository-authored values. #1000 owns the broad routing repair; #911's observations can remain evidence but are not by themselves a production policy. +**Amendment (2026-09-22): operator opt-in mechanism, default unchanged.** +`TaskOrchestrator(observed_health_quarantine=True)` adds failure-class +weighting, a cooldown longer than one slow attempt, a failure-rate window that +a single success cannot erase, a half-open probe, and demotion of members +whose last failure was slow. The default stays `False`, which is the legacy +3/30 policy, per the boundary above. Replay evidence, proposed values and the +enablement decision are in +[the observed-health runbook](doctoring/observed-health-quarantine.md). + ## 2026-09-12 Optimizer cardinality acceptance and calibration boundary Frozen `090b4ec841cfc78b45248b561f1cef6396b57429` rejects incomplete/extra diff --git a/scripts/replay_health_quarantine.py b/scripts/replay_health_quarantine.py new file mode 100644 index 000000000..2ffd464bc --- /dev/null +++ b/scripts/replay_health_quarantine.py @@ -0,0 +1,300 @@ +"""Replay sanitized Noema sidecar logs through the observed-health breaker. + +Usage:: + + python3 scripts/replay_health_quarantine.py [--include-preflight] [--json OUT] + +```` holds ``//contextual-orchestrator-sidecar.stderr.log`` +files (the raw artifacts are evidence, not repository content; see +``docs/doctoring/observed-health-quarantine.md``). Each run is one sidecar +process, so each run replays against a fresh ``TaskOrchestrator`` -- the same +breaker code the gateway runs, driven by an injected clock set to the log +timestamps. Nothing here reaches a provider. + +Counterfactual limits (stated, not hidden): a skipped attempt's outcome is +never fed to the policy (the gateway would not have observed it); the +successful attempt's duration is not logged, so a success is observed at its +start time; the replay cannot model which substitute candidate the gateway +would have tried instead, so "harmful" counts are upper bounds. +""" + +from __future__ import annotations + +import argparse +import datetime as dt +import http.client +import json +import re +import sys +import urllib.error +from collections import defaultdict, deque +from pathlib import Path + +sys.path.insert(0, str(Path(__file__).resolve().parents[1])) + +from contextual_orchestrator import ModelAgent, TaskOrchestrator # noqa: E402 +from contextual_orchestrator.orchestrator import classify_health_failure # noqa: E402 + +_TS = r"(\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2},\d{3}) " +_ATTEMPT = re.compile(_TS + r"provider_attempt agent_id=(\S+) model=(\S+) attempt=\S+ request_id=(\S+)") +_FAILED = re.compile( + _TS + r"provider_attempt_failed agent_id=(\S+) model=\S+ attempt=\S+ " + r"error_type=(\S+) transient=\S+ provider_status=(\S+) request_id=(\S+)" +) +_CIRCUIT_FAILURE = re.compile(_TS + r"circuit_failure agent_id=(\S+)") +_CIRCUIT_EDGE = re.compile(_TS + r"circuit_(opened|cleared) agent_id=(\S+)") +#: Legacy reset window of the deployed pin: an attempt that started while +#: the deployed breaker was open was forced (all-open fallback or a pinned +#: model), so no breaker policy could have skipped it. +_DEPLOYED_RESET_SECONDS = 30.0 +#: Statuses the gateway never charges to member health (quota is tracked by +#: the rate-limit cooldown on the passthrough path; size is the request's). +_NEVER_HEALTH = {"413"} + + +def _epoch(stamp: str) -> float: + return dt.datetime.strptime(stamp, "%Y-%m-%d %H:%M:%S,%f").timestamp() + + +def _synthetic_failure(error_type: str, status: str) -> BaseException: + """Rebuild a bounded exception shape so the real classifier decides the class.""" + if error_type == "HTTPError" and status.isdigit(): + return urllib.error.HTTPError("https://replay.invalid", int(status), "replay", None, None) + if error_type == "RemoteDisconnected": + return http.client.RemoteDisconnected("replay") + if error_type == "ConnectionResetError": + return ConnectionResetError("replay") + if error_type in {"TimeoutError", "timeout"}: + return TimeoutError("replay") + return RuntimeError("replay") + + +def parse_run(path: Path) -> list[dict]: + """Pair each failure line with the latest open attempt of the same request/agent. + + Sequential roles reuse one agent inside one request, so an earlier open + attempt that never failed is a success (same pairing as the evidence + directory's noema_phase.py). + """ + attempts: list[dict] = [] + open_by_key: dict[tuple[str, str], deque[int]] = defaultdict(deque) + lines = path.read_text(errors="replace").splitlines() + deployed_open: dict[str, float | None] = {} + for index, line in enumerate(lines): + match = _ATTEMPT.match(line) + if match: + stamp, agent_id, model, request_id = match.groups() + attempts.append( + { + "start": _epoch(stamp), "end": None, "agent_id": agent_id, + "model": model, "request_id": request_id, "ok": True, + "error_type": None, "status": None, "recorded": True, + "forced": ( + deployed_open.get(agent_id) is not None + and _epoch(stamp) - deployed_open[agent_id] < _DEPLOYED_RESET_SECONDS + ), + } + ) + open_by_key[(request_id, agent_id)].append(len(attempts) - 1) + continue + edge = _CIRCUIT_EDGE.match(line) + if edge: + deployed_open[edge.group(3)] = ( + _epoch(edge.group(1)) if edge.group(2) == "opened" else None + ) + continue + match = _FAILED.match(line) + if not match: + continue + stamp, agent_id, error_type, status, request_id = match.groups() + queue = open_by_key.get((request_id, agent_id)) + if not queue: + continue + attempt = attempts[queue.pop()] + attempt.update(end=_epoch(stamp), ok=False, error_type=error_type, status=status) + # Did the deployed path charge this failure to the breaker? The + # deployed log prints circuit_failure right after a recorded failure. + following = lines[index + 1 : index + 4] + attempt["recorded"] = any( + (m := _CIRCUIT_FAILURE.match(item)) and m.group(2) == agent_id for item in following + ) + for attempt in attempts: + if attempt["end"] is None: + attempt["end"] = attempt["start"] + return attempts + + +def _assign_steps(attempts: list[dict]) -> None: + """Split each served request into failover steps, each ending at one success. + + A conducted request runs several roles (planner/worker/verifier/...), so + one request can hold several successes; the candidate chain that precedes + each success is one step. + """ + by_request: dict[str, list[dict]] = defaultdict(list) + for attempt in attempts: + by_request[attempt["request_id"]].append(attempt) + for request_id, items in by_request.items(): + step: list[dict] = [] + for attempt in sorted(items, key=lambda item: item["start"]): + attempt["step"] = step + step.append(attempt) + if attempt["ok"]: + step = [] + + +def replay_run( + attempts: list[dict], + *, + include_preflight: bool, + totals: dict, + policy: dict | None = None, + demotion: bool = True, +) -> None: + """Drive one fresh orchestrator through one run's attempts in time order. + + ``policy`` overrides breaker attributes (for sensitivity runs); + ``demotion=False`` ignores slow-failure demotion to isolate quarantine. + """ + agents = {} + for attempt in attempts: + agents.setdefault(attempt["agent_id"], ModelAgent(attempt["agent_id"], attempt["model"])) + orchestrator = TaskOrchestrator(list(agents.values())) + for name, value in (policy or {}).items(): + setattr(orchestrator, name, value) + clock = {"now": 0.0} + orchestrator._circuit_clock = lambda: clock["now"] + _assign_steps(attempts) + + def available(agent_id: str) -> bool: + return not orchestrator._circuit_open(agent_id) and not orchestrator._circuit_demoted( + agent_id + ) + + events = [] + for index, attempt in enumerate(attempts): + events.append((attempt["start"], 1, index)) + events.append((attempt["end"], 0 if not attempt["ok"] else 2, index)) + events.sort() + skipped: set[int] = set() + first_after_open: set[str] = set() + harmful_requests: set[str] = set() + for stamp, kind, index in events: + clock["now"] = stamp + attempt = attempts[index] + served = attempt["request_id"] != "-" + agent_id = attempt["agent_id"] + if kind == 1: + if not served: + continue + totals["served_attempts"] += 1 + duration = attempt["end"] - attempt["start"] + slow = not attempt["ok"] and classify_health_failure( + _synthetic_failure(attempt["error_type"], attempt["status"]) + ) == "slow_transport" + if not attempt["ok"]: + totals["served_failed_seconds"] += duration + if slow: + totals["served_slow_failure_seconds"] += duration + probe_is_next = agent_id in first_after_open + first_after_open.discard(agent_id) + action = None + if orchestrator._circuit_open(agent_id): + if attempt["forced"]: + # The deployed breaker was already open and the attempt + # still ran: the never-empty fallback applies here too. + totals["forced_fallback_attempts"] += 1 + else: + action = "quarantine_skip" + elif demotion and orchestrator._circuit_demoted(agent_id) and any( + other["ok"] and other["agent_id"] != agent_id and available(other["agent_id"]) + for other in attempt["step"] + if other["start"] >= attempt["start"] + ): + action = "demote_skip" + if action is None: + continue + skipped.add(index) + totals[action + "s"] += 1 + trip_class = ( + orchestrator.circuit_health_snapshot()[agent_id]["last_failure_class"] + ) + if attempt["ok"]: + # The skipped attempt was this step's eventual success. + totals["harmful_removals"] += 1 + totals[f"harmful_removals_after_{trip_class}"] += 1 + harmful_requests.add(attempt["request_id"]) + if action == "quarantine_skip" and probe_is_next: + totals["false_positive_episodes"] += 1 + else: + totals["saved_failed_seconds"] += duration + if slow: + totals["saved_slow_failure_seconds"] += duration + totals[f"saved_failed_seconds_after_{trip_class}"] += duration + totals[f"saved_failed_seconds_by_{action}"] += duration + continue + if index in skipped or (not served and not include_preflight): + continue + if attempt["ok"]: + orchestrator._record_success(agent_id) + continue + if attempt["status"] in _NEVER_HEALTH: + continue + if served and not attempt["recorded"]: + continue # the deployed path did not charge it to the breaker + before = orchestrator.circuit_health_snapshot().get(agent_id, {}).get("open_count", 0) + orchestrator._record_failure( + agent_id, + failure_class=classify_health_failure( + _synthetic_failure(attempt["error_type"], attempt["status"]) + ), + ) + if orchestrator.circuit_health_snapshot()[agent_id]["open_count"] > before: + totals["quarantine_episodes"] += 1 + first_after_open.add(agent_id) + if not served: + totals["preflight_triggered_episodes"] += 1 + totals["harmful_requests"] += len(harmful_requests) + + +def main(argv: list[str] | None = None) -> dict: + """Replay every run under ``artifacts_dir`` and print one bounded JSON summary.""" + parser = argparse.ArgumentParser(description=__doc__.splitlines()[0]) + parser.add_argument("artifacts_dir", type=Path) + parser.add_argument("--include-preflight", action="store_true") + parser.add_argument("--json", type=Path) + parser.add_argument("--no-demotion", action="store_true") + parser.add_argument( + "--legacy-like", + action="store_true", + help="baseline: the deployed default (quarantine opt-in off, legacy 3/30)", + ) + args = parser.parse_args(argv) + logs = sorted(args.artifacts_dir.glob("*/*/contextual-orchestrator-sidecar.stderr.log")) + totals: dict = defaultdict(float) + policy = {"observed_health_quarantine": not args.legacy_like} + demotion = not (args.no_demotion or args.legacy_like) + for path in logs: + replay_run( + parse_run(path), + include_preflight=args.include_preflight, + totals=totals, + policy=policy, + demotion=demotion, + ) + summary = { + "runs": len(logs), + "include_preflight": args.include_preflight, + "demotion": demotion, + "policy_overrides": policy, + **{key: round(value, 1) for key, value in sorted(totals.items())}, + } + text = json.dumps(summary, indent=2, sort_keys=True) + print(text) + if args.json: + args.json.write_text(text + "\n") + return summary + + +if __name__ == "__main__": + main() diff --git a/tests/test_measured_routing_evidence.py b/tests/test_measured_routing_evidence.py index 5a0c35a30..2741dba99 100644 --- a/tests/test_measured_routing_evidence.py +++ b/tests/test_measured_routing_evidence.py @@ -369,7 +369,7 @@ def test_admin_state_exposes_both_routing_ledgers() -> None: orchestrator = _orch(ModelAgent("worker_agent", "mock", tags=("reasoning",))) orchestrator._quality_router.observe_success("worker_agent", 0.5, output_tokens=25) evidence = orchestrator.admin_state()["routing_evidence"] - assert set(evidence) == {"transport", "quality"} + assert set(evidence) == {"transport", "quality", "health"} assert evidence["quality"]["worker_agent"]["ewma_tokens_per_second"] == pytest.approx(50.0) assert evidence["transport"]["worker_agent"]["ewma_tokens_per_second"] is None diff --git a/tests/test_observed_health_quarantine.py b/tests/test_observed_health_quarantine.py new file mode 100644 index 000000000..1153fe59d --- /dev/null +++ b/tests/test_observed_health_quarantine.py @@ -0,0 +1,292 @@ +"""Observed-outcome health quarantine for served-request candidate selection. + +Evidence: 101 sanitized Noema sidecar artifacts (deployed pin 767e67f) showed +the same agent slow-failing (RemoteDisconnected / HTTP 504, p50 ~265-302 s) +repeatedly within one run, while the legacy breaker's 30 s reset expired +before a single ~300 s failure finished. These contracts pin the repair: a +served request's slow failure must influence the next request's candidate +order, repeated slow failures quarantine the agent for a cooldown longer than +one failing attempt, and a half-open probe recovers it. +""" + +from __future__ import annotations + +import http.client +import io +import logging +import sys +import threading +from collections.abc import Iterator +from concurrent.futures import ThreadPoolExecutor +from contextlib import contextmanager +from dataclasses import replace +from pathlib import Path + +sys.path.insert(0, str(Path(__file__).resolve().parents[1])) + +from contextual_orchestrator import ModelAgent, TaskOrchestrator # noqa: E402 +from contextual_orchestrator.orchestrator import ( # noqa: E402 + ModelClient, + classify_health_failure, +) +from contextual_orchestrator.provider_errors import ProviderUpstreamError # noqa: E402 + +_LOGGER_NAME = "contextual_orchestrator.orchestrator" + + +@contextmanager +def _captured_logs(level: int) -> Iterator[io.StringIO]: + """Attach an isolated handler to the orchestrator logger only.""" + logger = logging.getLogger(_LOGGER_NAME) + previous_level, previous_propagate = logger.level, logger.propagate + buffer = io.StringIO() + handler = logging.StreamHandler(buffer) + logger.addHandler(handler) + logger.setLevel(level) + logger.propagate = False + try: + yield buffer + finally: + logger.removeHandler(handler) + handler.close() + logger.setLevel(previous_level) + logger.propagate = previous_propagate + + +def _gateway_timeout(agent_id: str) -> ProviderUpstreamError: + return ProviderUpstreamError( + agent_id=agent_id, + model="mock", + error_code="provider_timeout", + message="provider timed out", + client_status=504, + provider_status=504, + retryable=True, + ) + + +class _ScriptedClient(ModelClient): + """Fail the agents listed in ``down`` with a slow-class 504; record every call.""" + + def __init__(self) -> None: + super().__init__() + self.down: set[str] = set() + self.calls: list[str] = [] + + def chat(self, agent: ModelAgent, messages: list, temperature: float = 0.2) -> str: # type: ignore[override] + self.calls.append(agent.id) + if agent.id in self.down: + raise _gateway_timeout(agent.id) + return f"answer from {agent.id}" + + +class _Clock: + def __init__(self) -> None: + self.now = 1000.0 + + def __call__(self) -> float: + return self.now + + +def _pool(enabled: bool = True) -> tuple[TaskOrchestrator, _ScriptedClient, _Clock]: + agents = [ + ModelAgent("slow_worker", "mock", tags=("reasoning", "writing"), priority=5), + ModelAgent("steady_worker", "mock", tags=("reasoning", "writing"), priority=1), + ] + client = _ScriptedClient() + orchestrator = TaskOrchestrator( + agents, + client=client, + tool_retry_backoff_seconds=0.0, + observed_health_quarantine=enabled, + ) + orchestrator.policy = replace(orchestrator.policy, realtime_judge=False) + orchestrator.tool_retry_attempts = 0 + clock = _Clock() + orchestrator._circuit_clock = clock + return orchestrator, client, clock + + +def _serve(orchestrator: TaskOrchestrator) -> str: + primary = orchestrator._agent("slow_worker") + _output, served, _model, _usage = orchestrator._invoke( + primary, [{"role": "system", "content": "Role: worker"}], text="task", role="worker" + ) + return served + + +def _order(orchestrator: TaskOrchestrator) -> list[str]: + primary = orchestrator._agent("slow_worker") + return [agent.id for agent in orchestrator._failover_candidates(primary, "task", "worker")] + + +def test_failure_classes_separate_slow_post_send_from_fast_rejections() -> None: + assert classify_health_failure(_gateway_timeout("a")) == "slow_transport" + assert classify_health_failure(http.client.RemoteDisconnected("closed")) == "slow_transport" + assert classify_health_failure(TimeoutError("read timed out")) == "slow_transport" + not_found = ProviderUpstreamError( + agent_id="a", model="m", error_code="model_not_found", message="x", + client_status=404, provider_status=404, + ) + assert classify_health_failure(not_found) == "fast" + assert classify_health_failure(RuntimeError("opaque")) == "fast" + + +def test_served_slow_failure_demotes_agent_for_the_next_request() -> None: + orchestrator, client, _clock = _pool() + client.down.add("slow_worker") + + assert _serve(orchestrator) == "steady_worker" # request N: slow failure recorded + assert client.calls == ["slow_worker", "steady_worker"] + + # One slow failure never quarantines ... + assert orchestrator._circuit_open("slow_worker") is False + # ... but request N+1 tries the healthy sibling first and never pays the + # ~300 s failure again when that sibling succeeds. + assert _order(orchestrator) == ["steady_worker", "slow_worker"] + client.calls.clear() + assert _serve(orchestrator) == "steady_worker" + assert client.calls == ["steady_worker"] + + +def test_single_fast_failure_neither_quarantines_nor_demotes() -> None: + orchestrator, _client, _clock = _pool() + orchestrator._record_failure("slow_worker", failure_class="fast") + assert orchestrator._circuit_open("slow_worker") is False + assert _order(orchestrator) == ["slow_worker", "steady_worker"] + + +def test_repeated_slow_failures_quarantine_past_one_failing_attempt_then_recover() -> None: + orchestrator, client, clock = _pool() + orchestrator._record_failure("slow_worker", failure_class="slow_transport") + with _captured_logs(logging.INFO) as buffer: + orchestrator._record_failure("slow_worker", failure_class="slow_transport") + opened = buffer.getvalue() + assert "circuit_opened agent_id=slow_worker" in opened + assert "failure_class=slow_transport" in opened + assert orchestrator._circuit_open("slow_worker") is True + assert _order(orchestrator) == ["steady_worker"] + + # The legacy 30 s reset is shorter than one ~300 s slow failure; the + # slow-class cooldown must outlast it. + clock.now += 301.0 + assert orchestrator._circuit_open("slow_worker") is True + + clock.now += orchestrator.slow_failure_cooldown_seconds + with _captured_logs(logging.INFO) as buffer: + assert orchestrator._circuit_open("slow_worker") is False + assert "circuit_half_open agent_id=slow_worker" in buffer.getvalue() + # Half-open: eligible again, but tried only after healthy siblings. + assert _order(orchestrator) == ["steady_worker", "slow_worker"] + + client.down.clear() + client.down.add("steady_worker") + with _captured_logs(logging.INFO) as buffer: + assert _serve(orchestrator) == "slow_worker" # the half-open probe succeeds + assert "circuit_recovered agent_id=slow_worker" in buffer.getvalue() + assert orchestrator.circuit_health_snapshot()["slow_worker"]["state"] == "closed" + + +def test_half_open_failure_reopens_with_escalated_bounded_cooldown() -> None: + orchestrator, _client, clock = _pool() + for _ in range(2): + orchestrator._record_failure("slow_worker", failure_class="slow_transport") + first = orchestrator.circuit_health_snapshot()["slow_worker"]["cooldown_seconds"] + clock.now += first + assert orchestrator._circuit_open("slow_worker") is False # half-open + orchestrator._record_failure("slow_worker", failure_class="slow_transport") + assert orchestrator._circuit_open("slow_worker") is True + second = orchestrator.circuit_health_snapshot()["slow_worker"]["cooldown_seconds"] + assert second == 2 * first + for _ in range(10): + clock.now += orchestrator.circuit_health_snapshot()["slow_worker"]["cooldown_seconds"] + assert orchestrator._circuit_open("slow_worker") is False + orchestrator._record_failure("slow_worker", failure_class="slow_transport") + capped = orchestrator.circuit_health_snapshot()["slow_worker"]["cooldown_seconds"] + assert capped == orchestrator.circuit_max_cooldown_seconds + + +def test_observed_failure_rate_quarantines_an_intermittently_failing_agent() -> None: + orchestrator, _client, _clock = _pool() + # Never three consecutive failures, but most recent outcomes failed. + for outcome in ("fail", "ok", "fail", "fail", "ok", "fail", "fail"): + if outcome == "fail": + orchestrator._record_failure("slow_worker", failure_class="fast") + else: + orchestrator._record_success("slow_worker") + assert orchestrator._circuit_open("slow_worker") is True + snapshot = orchestrator.circuit_health_snapshot()["slow_worker"] + assert snapshot["window_failure_rate"] >= orchestrator.circuit_failure_rate_threshold + + +def test_all_quarantined_pool_falls_back_to_least_recently_failed_member() -> None: + orchestrator, _client, clock = _pool() + for _ in range(2): + orchestrator._record_failure("slow_worker", failure_class="slow_transport") + clock.now += 5.0 + for _ in range(2): + orchestrator._record_failure("steady_worker", failure_class="slow_transport") + with _captured_logs(logging.WARNING) as buffer: + order = _order(orchestrator) + fallback = buffer.getvalue() + assert order == ["slow_worker", "steady_worker"] # never an empty pool + assert "circuit_all_open_fallback candidate_count=2 selected_agent_id=slow_worker" in fallback + + +def test_concurrent_slow_failures_open_the_circuit_exactly_once() -> None: + orchestrator, _client, _clock = _pool() + calls = 16 + barrier = threading.Barrier(calls, timeout=2.0) + + def record(_index: int) -> None: + barrier.wait() + orchestrator._record_failure("slow_worker", failure_class="slow_transport") + + with _captured_logs(logging.WARNING) as buffer: + with ThreadPoolExecutor(max_workers=calls) as pool: + list(pool.map(record, range(calls))) + output = buffer.getvalue() + assert output.count("circuit_opened agent_id=slow_worker") == 1 + assert orchestrator._circuit["slow_worker"]["failures"] == float(calls) + snapshot = orchestrator.circuit_health_snapshot()["slow_worker"] + assert snapshot["state"] == "open" + assert snapshot["consecutive_failures"] == calls + + +def test_default_orchestrator_keeps_the_legacy_breaker_policy() -> None: + """Without the operator opt-in, weights, cooldowns and demotion stay legacy 3/30.""" + orchestrator, client, clock = _pool(enabled=False) + assert TaskOrchestrator([ModelAgent("solo_worker", "mock")]).observed_health_quarantine is False + client.down.add("slow_worker") + _serve(orchestrator) + assert _order(orchestrator) == ["slow_worker", "steady_worker"] # no demotion + orchestrator._record_failure("slow_worker", failure_class="slow_transport") + assert orchestrator._circuit_open("slow_worker") is False # two slow != three strikes + orchestrator._record_failure("slow_worker", failure_class="slow_transport") + assert orchestrator._circuit_open("slow_worker") is True + clock.now += orchestrator.circuit_reset_seconds + assert orchestrator._circuit_open("slow_worker") is False + orchestrator._record_failure("slow_worker", failure_class="slow_transport") + assert orchestrator._circuit_open("slow_worker") is False # counter restarts from zero + + +def test_health_snapshot_is_bounded_and_prompt_free() -> None: + orchestrator, client, _clock = _pool() + client.down.add("slow_worker") + _serve(orchestrator) + snapshot = orchestrator.circuit_health_snapshot() + assert set(snapshot["slow_worker"]) == { + "state", "model", "provider", "consecutive_failures", "weighted_score", + "last_failure_class", "cooldown_seconds", "remaining_seconds", + "window_size", "window_failure_rate", "open_count", + } + assert "task" not in repr(snapshot) + assert orchestrator.admin_state()["routing_evidence"]["health"] == snapshot + + +if __name__ == "__main__": + for name, fn in sorted(globals().items()): + if name.startswith("test_") and callable(fn): + fn() + print(f"ok {name}") + print("ok") From 56276d6530dcc5bbc458189220a79fbb3a9022b6 Mon Sep 17 00:00:00 2001 From: Seongho Bae Date: Tue, 22 Sep 2026 02:10:59 +0900 Subject: [PATCH 02/10] docs(routing): record two-sided replay fidelity and flag-on test scope Co-Authored-By: Claude Opus 5 Claude-Session: https://claude.ai/code/session_012ABB9sb4szFEteww67UYZy --- docs/doctoring/observed-health-quarantine.md | 20 ++++++++++++++++---- 1 file changed, 16 insertions(+), 4 deletions(-) diff --git a/docs/doctoring/observed-health-quarantine.md b/docs/doctoring/observed-health-quarantine.md index ca01178be..0ff432774 100644 --- a/docs/doctoring/observed-health-quarantine.md +++ b/docs/doctoring/observed-health-quarantine.md @@ -88,9 +88,17 @@ shape (`{"failures", "opened_at"}`). The new state lives in `_circuit_health`. - Full `pytest tests` (non-strict) on base and head: the only difference was `test_admin_state_exposes_both_routing_ledgers`, which pinned `{"transport", "quality"}` and is updated for the additive `health` key. - The other 200 failures and 31 errors are identical on `origin/main`. They - are pre-existing: a `cost_router` import error, `selection_design` - KeyErrors, egress allowlist and paper-inventory contracts. + A second full run also failed + `test_provider_error_taxonomy.py::test_invoke_preserves_final_classified_failure_across_candidates`. + That test is a wall-clock rate-limit-wait flake: it failed 1 of 4 + isolated runs on unmodified `origin/main` as well. The other 200 failures + and 31 errors are identical on `origin/main`. They are pre-existing: a + `cost_router` import error, `selection_design` KeyErrors, egress allowlist + and paper-inventory contracts. +- Flag-on behavior is exercised through `_invoke` and `_failover_candidates` + only. `route_once`, virtual-selector `proxy_completion`, `stream_route` and + `conduct` ran only with the flag off (full suite). An end-to-end flag-on + test belongs with the enablement decision. - `-W error` on the 13 neighbor suites: base and head are both nonclean (81 and 82 failing ids in one run each, with different sets). The failures are dominated by the pre-existing `_TemporaryFileCloser` and unclosed @@ -118,7 +126,11 @@ clock set to the log timestamps. an attempt as skippable (`forced_fallback_attempts`). - **Fidelity check.** With the flag off (`--legacy-like`), the replay skips **0** attempts, and all 30 of its open-state hits coincide with forced - attempts. So the replay reproduces the deployed breaker. + attempts. The check also runs the other way: the replayed `circuit_opened` + count matches the deployed log's count exactly in 99 of 101 runs. In total + the replay opens 64 times against 66 deployed; in the two differing runs + the replay opens one fewer time, so it errs conservative. The replay + therefore reproduces the deployed breaker. ```bash python3 scripts/replay_health_quarantine.py \ From 87804a5ef1ca48accafc595b7da4047cf150d0d7 Mon Sep 17 00:00:00 2001 From: Seongho Bae Date: Tue, 22 Sep 2026 02:33:21 +0900 Subject: [PATCH 03/10] fix(routing): apply opt-in health order to triage and judge picks; HTTP e2e HTTP end-to-end contracts (route, conduct, stream, structured proxy_completion) for demotion, half-open recovery/doubling and the all-open fallback. RED showed conduct and the structured proxy path still sent the model-judge call, and auto-mode triage its single call, to a demoted member: both pick the first ranked agent outside _failover_candidates. With observed_health_quarantine on they now skip open members and try demoted ones last; flag off is unchanged. Co-Authored-By: Claude Opus 5 Claude-Session: https://claude.ai/code/session_012ABB9sb4szFEteww67UYZy --- contextual_orchestrator/orchestrator.py | 20 +- tests/test_observed_health_quarantine_http.py | 310 ++++++++++++++++++ 2 files changed, 328 insertions(+), 2 deletions(-) create mode 100644 tests/test_observed_health_quarantine_http.py diff --git a/contextual_orchestrator/orchestrator.py b/contextual_orchestrator/orchestrator.py index 6dca0f643..5bace4997 100644 --- a/contextual_orchestrator/orchestrator.py +++ b/contextual_orchestrator/orchestrator.py @@ -10398,7 +10398,7 @@ def _compute_triage_verdict(self, text: str) -> bool: ] if not candidates: return False - triage_agent = candidates[0] + triage_agent = self._observed_health_order(candidates)[0] messages: list[ChatMessage] = [ {"role": "system", "content": self.TRIAGE_SYSTEM_PROMPT}, {"role": "user", "content": text}, @@ -11618,6 +11618,20 @@ def _order_by_observed_health(self, agents: list[ModelAgent]) -> list[ModelAgent a for a in agents if a.id in demoted ] + def _observed_health_order(self, agents: list[ModelAgent]) -> list[ModelAgent]: + """Order an auxiliary single-call pick (triage, judge) by observed health. + + These picks take the first ranked agent without the failover loop, so + with the opt-in quarantine they skip open members and try demoted + ones last (never-empty fallback). Flag off: unchanged legacy order. + """ + if not self.observed_health_quarantine or not agents: + return agents + healthy = [agent for agent in agents if not self._circuit_open(agent.id)] + if not healthy: + return self._all_open_fallback(agents) + return self._order_by_observed_health(healthy) + def _all_open_fallback(self, agents: list[ModelAgent]) -> list[ModelAgent]: """Never return an empty pool: order all-open members least-recently-failed first. @@ -12233,7 +12247,9 @@ def _model_judge_verification( try: judge = next( agent - for agent in self._ranked_agents(task, "verifier", free_only=free_only) + for agent in self._observed_health_order( + self._ranked_agents(task, "verifier", free_only=free_only) + ) if allowed_agent_ids is None or agent.id in allowed_agent_ids if excluded_agent_ids is None or agent.id not in excluded_agent_ids ) diff --git a/tests/test_observed_health_quarantine_http.py b/tests/test_observed_health_quarantine_http.py new file mode 100644 index 000000000..18b5fe187 --- /dev/null +++ b/tests/test_observed_health_quarantine_http.py @@ -0,0 +1,310 @@ +"""HTTP end-to-end contracts for the opt-in observed-health quarantine. + +Each of the four served paths behind ``/v1/chat/completions`` -- route +(``route_once``), conduct, streaming (``stream_route``) and the structured +provider path (``proxy_completion``) -- must apply the same policy when +``observed_health_quarantine=True``: (a) one slow failure demotes the member +for the next request, (b) after the cooldown the half-open probe recovers on +success or doubles the cooldown on failure, and (c) an all-quarantined pool +still serves, least-recently-failed first. Providers are a controllable +in-process client over ``mock://`` agents; time is the breaker's injected +monotonic clock, so nothing sleeps. +""" + +from __future__ import annotations + +import io +import json +import logging +import sys +import threading +import urllib.error +import urllib.request +from collections.abc import Iterator +from contextlib import contextmanager +from dataclasses import replace +from pathlib import Path +from typing import Any + +import pytest + +sys.path.insert(0, str(Path(__file__).resolve().parents[1])) + +from contextual_orchestrator import ModelAgent, TaskOrchestrator # noqa: E402 +from contextual_orchestrator.orchestrator import ModelClient # noqa: E402 +from contextual_orchestrator.provider_errors import ProviderUpstreamError # noqa: E402 +from contextual_orchestrator.server import SecurityConfig, build_server # noqa: E402 + +_TOKEN = "observed_health_quarantine_http_token" +_TAGS = ("reasoning", "writing", "planning", "coding", "implementation", "verification", "review") +_PATHS = ("route", "conduct", "stream", "proxy") + + +def _timeout(agent: ModelAgent, transport: str) -> ProviderUpstreamError: + return ProviderUpstreamError( + agent_id=agent.id, + model=agent.model, + error_code="provider_timeout", + message="provider timed out", + client_status=504, + provider_status=504, + retryable=True, + transport=transport, + ) + + +class _ControlledProvider(ModelClient): + """Every served transport fails with a slow-class 504 for agents in ``down``.""" + + def __init__(self) -> None: + super().__init__() + self.down: set[str] = set() + self.calls: list[str] = [] + self._lock = threading.Lock() + + def _attempt(self, agent: ModelAgent, transport: str) -> None: + with self._lock: + self.calls.append(agent.id) + if agent.id in self.down: + raise _timeout(agent, transport) + + def chat(self, agent: ModelAgent, messages: list, *args: Any, **kwargs: Any) -> str: # type: ignore[override] + self._attempt(agent, "chat") + return f"answer from {agent.id}" + + def stream_chat(self, agent: ModelAgent, messages: list, *args: Any, **kwargs: Any): # type: ignore[override] + self._attempt(agent, "stream") + yield f"answer from {agent.id}" + + def proxy_send_once(self, agent: ModelAgent, endpoint: str, payload: dict[str, Any]) -> dict[str, Any]: # type: ignore[override] + self._attempt(agent, "passthrough") + return { + "id": "chatcmpl_test", + "object": "chat.completion", + "model": agent.model, + "choices": [ + { + "index": 0, + "message": {"role": "assistant", "content": json.dumps({"answer": agent.id})}, + "finish_reason": "stop", + } + ], + } + + proxy_send = proxy_send_once + + def take_usage(self) -> None: + return None + + +class _Clock: + def __init__(self) -> None: + self.now = 10_000.0 + + def __call__(self) -> float: + return self.now + + +@contextmanager +def _gateway(enabled: bool = True) -> Iterator[tuple[TaskOrchestrator, _ControlledProvider, _Clock, int]]: + agents = [ + ModelAgent("slow_worker", "slow-model", base_url="mock://slow.example", tags=_TAGS, priority=10), + ModelAgent("steady_worker", "steady-model", base_url="mock://steady.example", tags=_TAGS, priority=1), + ] + provider = _ControlledProvider() + orchestrator = TaskOrchestrator( + agents, + client=provider, + tool_retry_backoff_seconds=0.0, + observed_health_quarantine=enabled, + ) + orchestrator.policy = replace(orchestrator.policy, realtime_judge=False) + orchestrator.tool_retry_attempts = 0 + clock = _Clock() + orchestrator._circuit_clock = clock + server = build_server(orchestrator, port=0, security=SecurityConfig(auth_token=_TOKEN)) + thread = threading.Thread(target=server.serve_forever, daemon=True) + thread.start() + try: + yield orchestrator, provider, clock, server.server_address[1] + finally: + server.shutdown() + thread.join(timeout=5) + server.server_close() + + +def _body(path: str) -> dict[str, Any]: + body: dict[str, Any] = { + "model": TaskOrchestrator.AUTO_MODEL, + "messages": [{"role": "user", "content": "summarize the incident"}], + } + if path == "proxy": + # Virtual selector + response_format: the structured provider path + # (proxy_completion(single_agent=False) -> conduct stages + structured + # synthesis failover), the HTTP route that reaches proxy_completion. + body["response_format"] = {"type": "json_object"} + else: + body["mode"] = "conduct" if path == "conduct" else "route" + if path == "stream": + body["stream"] = True + return body + + +def _send(port: int, path: str) -> int: + request = urllib.request.Request( + f"http://127.0.0.1:{port}/v1/chat/completions", + data=json.dumps(_body(path)).encode("utf-8"), + headers={ + "content-type": "application/json", + "authorization": f"Bearer {_TOKEN}", + "connection": "close", + }, + method="POST", + ) + try: + with urllib.request.urlopen(request, timeout=15) as response: + payload = response.read().decode("utf-8") + status = response.status + except urllib.error.HTTPError as exc: + with exc: + exc.read() + return exc.code + if path == "stream" and '"error"' in payload: + return 502 # a terminal SSE error frame after the 200 header + return status + + +def _request(orchestrator: TaskOrchestrator, provider: _ControlledProvider, port: int, path: str) -> tuple[int, list[str]]: + provider.calls.clear() + status = _send(port, path) + return status, list(provider.calls) + + +def _state(orchestrator: TaskOrchestrator, agent_id: str) -> dict[str, Any]: + return orchestrator.circuit_health_snapshot()[agent_id] + + +@contextmanager +def _captured(level: int) -> Iterator[io.StringIO]: + logger = logging.getLogger("contextual_orchestrator.orchestrator") + previous_level, previous_propagate = logger.level, logger.propagate + buffer = io.StringIO() + handler = logging.StreamHandler(buffer) + logger.addHandler(handler) + logger.setLevel(level) + logger.propagate = False + try: + yield buffer + finally: + logger.removeHandler(handler) + handler.close() + logger.setLevel(previous_level) + logger.propagate = previous_propagate + + +def _quarantine_slow_worker(orchestrator, provider, port, path) -> None: + """Drive both members down so ``slow_worker`` reaches two slow strikes.""" + provider.down = {"slow_worker"} + status, calls = _request(orchestrator, provider, port, path) + assert status == 200 and calls[:2] == ["slow_worker", "steady_worker"], (status, calls) + provider.down = {"slow_worker", "steady_worker"} + _request(orchestrator, provider, port, path) + assert _state(orchestrator, "slow_worker")["state"] == "open" + + +@pytest.mark.parametrize("path", _PATHS) +def test_one_slow_failure_demotes_member_for_next_http_request(path: str) -> None: + with _gateway() as (orchestrator, provider, _clock, port): + provider.down = {"slow_worker"} + status, calls = _request(orchestrator, provider, port, path) + assert status == 200, (path, status, calls) + assert calls[:2] == ["slow_worker", "steady_worker"], (path, calls) + assert _state(orchestrator, "slow_worker")["state"] == "closed" # demoted, not quarantined + + status, calls = _request(orchestrator, provider, port, path) + assert status == 200, (path, status, calls) + assert "slow_worker" not in calls, (path, calls) + assert calls[0] == "steady_worker", (path, calls) + + +@pytest.mark.parametrize("path", _PATHS) +def test_half_open_probe_recovers_on_success_over_http(path: str) -> None: + with _gateway() as (orchestrator, provider, clock, port): + _quarantine_slow_worker(orchestrator, provider, port, path) + provider.down = set() + status, calls = _request(orchestrator, provider, port, path) + assert status == 200 and "slow_worker" not in calls, (path, status, calls) + + clock.now += _state(orchestrator, "slow_worker")["cooldown_seconds"] + provider.down = {"steady_worker"} # the demoted half-open member is reached + with _captured(logging.INFO) as buffer: + status, calls = _request(orchestrator, provider, port, path) + assert status == 200 and "slow_worker" in calls, (path, status, calls) + assert "circuit_half_open agent_id=slow_worker" in buffer.getvalue() + assert "circuit_recovered agent_id=slow_worker" in buffer.getvalue() + assert _state(orchestrator, "slow_worker")["state"] == "closed" + + +@pytest.mark.parametrize("path", _PATHS) +def test_half_open_probe_failure_doubles_cooldown_over_http(path: str) -> None: + with _gateway() as (orchestrator, provider, clock, port): + _quarantine_slow_worker(orchestrator, provider, port, path) + first = _state(orchestrator, "slow_worker")["cooldown_seconds"] + clock.now += first + provider.down = {"slow_worker", "steady_worker"} + with _captured(logging.WARNING) as buffer: + _request(orchestrator, provider, port, path) + assert "trigger=half_open_failure" in buffer.getvalue(), (path, buffer.getvalue()) + assert _state(orchestrator, "slow_worker")["state"] == "open" + assert _state(orchestrator, "slow_worker")["cooldown_seconds"] == 2 * first + + +@pytest.mark.parametrize("path", _PATHS) +def test_all_quarantined_pool_still_serves_least_recently_failed_first(path: str) -> None: + with _gateway() as (orchestrator, provider, clock, port): + _quarantine_slow_worker(orchestrator, provider, port, path) + clock.now += 5.0 + provider.down = {"steady_worker"} + _request(orchestrator, provider, port, path) # steady's second slow strike + assert _state(orchestrator, "steady_worker")["state"] == "open" + + provider.down = set() + with _captured(logging.WARNING) as buffer: + status, calls = _request(orchestrator, provider, port, path) + assert status == 200, (path, status, calls) + assert calls[0] == "slow_worker", (path, calls) # failed longest ago + assert "circuit_all_open_fallback" in buffer.getvalue() + + +def test_auto_mode_triage_pick_follows_observed_health() -> None: + """The uncached triage call is one direct pick; it must not re-hit a demoted member.""" + with _gateway() as (orchestrator, provider, _clock, port): + provider.down = {"slow_worker"} + _request(orchestrator, provider, port, "route") # slow strike: demoted + provider.calls.clear() + body = { + "model": TaskOrchestrator.AUTO_MODEL, + "messages": [{"role": "user", "content": "triage this distinct prompt"}], + } + request = urllib.request.Request( + f"http://127.0.0.1:{port}/v1/chat/completions", + data=json.dumps(body).encode("utf-8"), + headers={"content-type": "application/json", "authorization": f"Bearer {_TOKEN}"}, + method="POST", + ) + with urllib.request.urlopen(request, timeout=15) as response: + assert response.status == 200 + response.read() + assert "slow_worker" not in provider.calls, provider.calls + + +def test_flag_off_http_route_keeps_legacy_order() -> None: + with _gateway(enabled=False) as (orchestrator, provider, _clock, port): + provider.down = {"slow_worker"} + _request(orchestrator, provider, port, "route") + status, calls = _request(orchestrator, provider, port, "route") + assert status == 200 and calls == ["slow_worker", "steady_worker"] + + +if __name__ == "__main__": + sys.exit(pytest.main([__file__, "-q"])) From b073b16071607aa78ccc8934c4eb535aa52e753d Mon Sep 17 00:00:00 2001 From: Seongho Bae Date: Tue, 22 Sep 2026 03:16:57 +0900 Subject: [PATCH 04/10] feat(routing): KV activation switch, sidecar measurement, 429 study - One deployable switch: KV setting CONTEXTUAL_ORCHESTRATOR_OBSERVED_HEALTH_QUARANTINE, read once at TaskOrchestrator construction (explicit argument wins; unset = off; invalid value fails construction). register_review_credentials copies it from bootstrap env like the gateway token, so the .github launcher needs only a pin bump and one env value. Startup INFO line and admin_state routing_evidence.health_policy make it auditable. - classify_health_failure treats provider_outcome_unknown (ModelClient's wrapping of a dropped chat connection) and model_timeout as slow; the sidecar-shaped measurement exposed the misclassification. - scripts/measure_health_quarantine_sidecar.py: launcher-shaped synthetic measurement (fake provider at _open_provider, no egress). - tests/test_rate_limit_breaker_asymmetry.py pins that _invoke charges a provider 429 to the breaker while passthrough does not (unchanged); replay gains --exclude-429 and deployed 429-in-streak counts. - Runbook: e2e RED/GREEN, measurement, activation handoff, 429 analysis; 360 s cooldown stated as an experimental candidate. Default stays off. Co-Authored-By: Claude Opus 5 Claude-Session: https://claude.ai/code/session_012ABB9sb4szFEteww67UYZy --- AGENTS.md | 3 +- contextual_orchestrator/orchestrator.py | 95 +++++- contextual_orchestrator/review_gateway.py | 8 +- ...-health-quarantine-replay-exclude-429.json | 29 ++ ...th-quarantine-replay-preflight-whatif.json | 5 + ...erved-health-quarantine-replay-served.json | 5 + ...d-health-quarantine-sidecar-synthetic.json | 245 +++++++++++++++ docs/doctoring/observed-health-quarantine.md | 293 ++++++++++++++++-- docs/product-technical-gap-baseline.md | 5 +- scripts/measure_health_quarantine_sidecar.py | 233 ++++++++++++++ scripts/replay_health_quarantine.py | 48 +++ tests/test_measured_routing_evidence.py | 2 +- tests/test_observed_health_quarantine.py | 61 ++++ tests/test_rate_limit_breaker_asymmetry.py | 125 ++++++++ 14 files changed, 1127 insertions(+), 30 deletions(-) create mode 100644 docs/doctoring/observed-health-quarantine-replay-exclude-429.json create mode 100644 docs/doctoring/observed-health-quarantine-sidecar-synthetic.json create mode 100644 scripts/measure_health_quarantine_sidecar.py create mode 100644 tests/test_rate_limit_breaker_asymmetry.py diff --git a/AGENTS.md b/AGENTS.md index badf00324..04839a413 100644 --- a/AGENTS.md +++ b/AGENTS.md @@ -140,7 +140,8 @@ push or open a PR. unknown-outcome no-replay controls alongside it. Transport spies are not wire delivery evidence. Preserve the default-null model timeout. -- Observed-health quarantine (`observed_health_quarantine`, operator opt-in, +- Observed-health quarantine (one switch: KV setting + `CONTEXTUAL_ORCHESTRATOR_OBSERVED_HEALTH_QUARANTINE`, operator opt-in, default off = legacy 3/30) weights slow post-send failures for breaker and candidate order only; it never authorizes retry or changes timeouts. Keep the never-empty fallback and in-memory restart semantics. Replay limits and diff --git a/contextual_orchestrator/orchestrator.py b/contextual_orchestrator/orchestrator.py index 5bace4997..7a12cae63 100644 --- a/contextual_orchestrator/orchestrator.py +++ b/contextual_orchestrator/orchestrator.py @@ -2043,10 +2043,62 @@ def _is_omit_equivalent_control(key: str, value: Any) -> bool: #: evidence measured those at p50 ~265-302 s each. ``fast`` is an immediate #: rejection (404, 400, 500, malformed body). 429 and 413 never reach the #: health ledger at all -- quota and request size are not member health. -_SLOW_HEALTH_ERROR_CODES = frozenset({"provider_timeout", "provider_connection_error"}) +_SLOW_HEALTH_ERROR_CODES = frozenset( + { + "provider_timeout", + "provider_connection_error", + # ModelClient wraps a dropped/timed-out chat connection as + # provider_outcome_unknown before _invoke sees it; an administrator + # model deadline is likewise a full post-send wait. + PROVIDER_OUTCOME_UNKNOWN_CODE, + "model_timeout", + } +) _SLOW_HEALTH_PROVIDER_STATUSES = frozenset({408, 502, 504}) +#: The single deployable switch for the observed-health quarantine: a KV +#: (credential-registry) setting read once at ``TaskOrchestrator`` +#: construction. Bootstrap may copy it from the environment into the KV +#: (``review_gateway.register_review_credentials``); runtime never reads env. +OBSERVED_HEALTH_QUARANTINE_SETTING = "CONTEXTUAL_ORCHESTRATOR_OBSERVED_HEALTH_QUARANTINE" +_SWITCH_ON = frozenset({"enabled", "true", "on", "1"}) +_SWITCH_OFF = frozenset({"disabled", "false", "off", "0"}) + + +def _resolve_observed_health_quarantine(explicit: bool | None) -> tuple[bool, str]: + """Resolve the quarantine switch and its audit source. + + An explicit boolean wins (``source='argument'``). Otherwise the KV value + decides (``'kv'``); unset is off (``'default'``). A value that is neither + on nor off fails construction instead of silently picking a policy. A + KV backend error keeps the legacy policy (``'kv_unavailable'``). + """ + if explicit is not None: + if not isinstance(explicit, bool): + raise TypeError("observed_health_quarantine must be a boolean or None") + return explicit, "argument" + try: + raw = get_credential(OBSERVED_HEALTH_QUARANTINE_SETTING) + except Exception: # noqa: BLE001 - an unreadable KV keeps the legacy breaker + _LOGGER.warning( + "observed_health_quarantine_kv_unavailable setting=%s enabled=False", + OBSERVED_HEALTH_QUARANTINE_SETTING, + ) + return False, "kv_unavailable" + if raw is None or not str(raw).strip(): + return False, "default" + value = str(raw).strip().casefold() + if value in _SWITCH_ON: + return True, "kv" + if value in _SWITCH_OFF: + return False, "kv" + raise ValueError( + f"{OBSERVED_HEALTH_QUARANTINE_SETTING} must be one of " + "enabled/disabled/true/false/on/off/1/0" + ) + + def classify_health_failure(exc: BaseException | None) -> str: """Classify one failed provider attempt for the observed-health ledger. @@ -5577,7 +5629,7 @@ def __init__( token_counter: Any = None, rate_limit_wait_seconds: float = 30.0, rate_limit_unknown_cooldown_seconds: float = 5.0, - observed_health_quarantine: bool = False, + observed_health_quarantine: bool | None = None, ) -> None: self._assistant_message_local = threading.local() self._output_budget_local = threading.local() @@ -5712,9 +5764,13 @@ def __init__( # in the runbook. A half-open failure doubles the cooldown up to # circuit_max_cooldown_seconds; nothing is excluded permanently. # These are breaker knobs only: no timeout, retry or 413/429 policy. - if not isinstance(observed_health_quarantine, bool): - raise TypeError("observed_health_quarantine must be a boolean") - self.observed_health_quarantine = observed_health_quarantine + # One deployable switch: an explicit constructor boolean wins; + # otherwise the KV setting OBSERVED_HEALTH_QUARANTINE_SETTING is read + # once here (KV, not env). Unset means off (legacy 3/30). + ( + self.observed_health_quarantine, + self.observed_health_quarantine_source, + ) = _resolve_observed_health_quarantine(observed_health_quarantine) self._circuit_health: dict[str, dict[str, Any]] = {} self._circuit_clock: Callable[[], float] | None = None self.slow_failure_weight = 2.0 @@ -5723,6 +5779,16 @@ def __init__( self.circuit_failure_window = 10 self.circuit_failure_rate_min_observations = 6 self.circuit_failure_rate_threshold = 0.6 + # Startup audit line: which breaker policy this process serves with + # (the review sidecar logs at DEBUG, so it lands in the CI artifact). + _LOGGER.info( + "observed_health_quarantine enabled=%s source=%s setting=%s " + "slow_failure_cooldown_seconds=%s", + self.observed_health_quarantine, + self.observed_health_quarantine_source, + OBSERVED_HEALTH_QUARANTINE_SETTING, + self.slow_failure_cooldown_seconds, + ) # Per-agent provider-declared quota cooldown (Retry-After / x-ratelimit-reset*), # tracked separately from the health circuit breaker above: a 429 is quota # exhaustion, not a model health failure, so it must never trip or feed @@ -11667,6 +11733,24 @@ def _all_open_fallback(self, agents: list[ModelAgent]) -> list[ModelAgent]: ) return ordered + def circuit_health_policy(self) -> dict[str, Any]: + """Audit view of the active breaker policy and where the switch came from.""" + return { + "observed_health_quarantine": self.observed_health_quarantine, + "source": self.observed_health_quarantine_source, + "setting_name": OBSERVED_HEALTH_QUARANTINE_SETTING, + "circuit_failure_threshold": self.circuit_failure_threshold, + "circuit_reset_seconds": float(self.circuit_reset_seconds), + "slow_failure_weight": float(self.slow_failure_weight), + "slow_failure_cooldown_seconds": float(self.slow_failure_cooldown_seconds), + "circuit_max_cooldown_seconds": float(self.circuit_max_cooldown_seconds), + "circuit_failure_window": int(self.circuit_failure_window), + "circuit_failure_rate_min_observations": int( + self.circuit_failure_rate_min_observations + ), + "circuit_failure_rate_threshold": float(self.circuit_failure_rate_threshold), + } + def circuit_health_snapshot(self) -> dict[str, dict[str, Any]]: """Bounded per-member breaker/health evidence (no prompt or provider text).""" agents = {agent.id: agent for agent in self.candidates} @@ -19353,6 +19437,7 @@ def admin_state( "transport": self._group_router.snapshot(), "quality": self._quality_router.snapshot(), "health": self.circuit_health_snapshot(), + "health_policy": self.circuit_health_policy(), }, "recent_workflow_runs": [ self._shorten_run(run) diff --git a/contextual_orchestrator/review_gateway.py b/contextual_orchestrator/review_gateway.py index 219341bb7..8b481a82b 100644 --- a/contextual_orchestrator/review_gateway.py +++ b/contextual_orchestrator/review_gateway.py @@ -27,7 +27,7 @@ discover_all_models, general_free_serving_candidates, ) -from .orchestrator import ModelClient, TaskOrchestrator +from .orchestrator import OBSERVED_HEALTH_QUARANTINE_SETTING, ModelClient, TaskOrchestrator from .provider_bootstrap import PROVIDER_ACCEPTED_CREDENTIAL_NAMES from .server import SecurityConfig, serve from .tool_fallback import MAX_TOOL_RETRY_ATTEMPTS @@ -170,6 +170,12 @@ def register_review_credentials( if auth_value and auth_value.strip(): register_credential(REVIEW_AUTH_CREDENTIAL_NAME, auth_value) registered.append(REVIEW_AUTH_CREDENTIAL_NAME) + # Operator opt-in breaker switch (not a credential): bootstrap transport + # only; TaskOrchestrator reads and validates it from the KV at startup. + switch_value = environment.get(OBSERVED_HEALTH_QUARANTINE_SETTING, "") + if isinstance(switch_value, str) and switch_value.strip(): + register_credential(OBSERVED_HEALTH_QUARANTINE_SETTING, switch_value.strip()) + registered.append(OBSERVED_HEALTH_QUARANTINE_SETTING) return tuple(registered) diff --git a/docs/doctoring/observed-health-quarantine-replay-exclude-429.json b/docs/doctoring/observed-health-quarantine-replay-exclude-429.json new file mode 100644 index 000000000..191a80ea9 --- /dev/null +++ b/docs/doctoring/observed-health-quarantine-replay-exclude-429.json @@ -0,0 +1,29 @@ +{ + "demote_skips": 130.0, + "demotion": true, + "deployed_circuit_opened": 66.0, + "deployed_opened_with_429_in_streak": 11.0, + "exclude_429": true, + "false_positive_episodes": 1.0, + "forced_fallback_attempts": 10.0, + "harmful_removals": 1.0, + "harmful_removals_after_slow_transport": 1.0, + "harmful_requests": 1.0, + "include_preflight": false, + "policy_overrides": { + "observed_health_quarantine": true + }, + "quarantine_episodes": 32.0, + "quarantine_skips": 10.0, + "runs": 101, + "saved_failed_seconds": 36827.5, + "saved_failed_seconds_after_fast": 486.0, + "saved_failed_seconds_after_slow_transport": 36341.5, + "saved_failed_seconds_by_demote_skip": 35201.7, + "saved_failed_seconds_by_quarantine_skip": 1625.8, + "saved_slow_failure_seconds": 36319.6, + "served_429_charged": 144.0, + "served_attempts": 1627.0, + "served_failed_seconds": 111064.9, + "served_slow_failure_seconds": 100261.0 +} diff --git a/docs/doctoring/observed-health-quarantine-replay-preflight-whatif.json b/docs/doctoring/observed-health-quarantine-replay-preflight-whatif.json index c8d8db1b0..0487a7030 100644 --- a/docs/doctoring/observed-health-quarantine-replay-preflight-whatif.json +++ b/docs/doctoring/observed-health-quarantine-replay-preflight-whatif.json @@ -1,6 +1,10 @@ { "demote_skips": 160.0, "demotion": true, + "deployed_circuit_opened": 66.0, + "deployed_opened_with_429_in_streak": 11.0, + "episodes_with_429_in_streak": 15.0, + "exclude_429": false, "false_positive_episodes": 1.0, "forced_fallback_attempts": 15.0, "harmful_removals": 1.0, @@ -19,6 +23,7 @@ "saved_failed_seconds_by_demote_skip": 35205.8, "saved_failed_seconds_by_quarantine_skip": 1625.8, "saved_slow_failure_seconds": 36319.6, + "served_429_charged": 117.0, "served_attempts": 1627.0, "served_failed_seconds": 111064.9, "served_slow_failure_seconds": 100261.0 diff --git a/docs/doctoring/observed-health-quarantine-replay-served.json b/docs/doctoring/observed-health-quarantine-replay-served.json index 86bfc3b61..3c6f4be22 100644 --- a/docs/doctoring/observed-health-quarantine-replay-served.json +++ b/docs/doctoring/observed-health-quarantine-replay-served.json @@ -1,6 +1,10 @@ { "demote_skips": 160.0, "demotion": true, + "deployed_circuit_opened": 66.0, + "deployed_opened_with_429_in_streak": 11.0, + "episodes_with_429_in_streak": 5.0, + "exclude_429": false, "false_positive_episodes": 1.0, "forced_fallback_attempts": 15.0, "harmful_removals": 1.0, @@ -19,6 +23,7 @@ "saved_failed_seconds_by_demote_skip": 35205.8, "saved_failed_seconds_by_quarantine_skip": 1625.8, "saved_slow_failure_seconds": 36319.6, + "served_429_charged": 117.0, "served_attempts": 1627.0, "served_failed_seconds": 111064.9, "served_slow_failure_seconds": 100261.0 diff --git a/docs/doctoring/observed-health-quarantine-sidecar-synthetic.json b/docs/doctoring/observed-health-quarantine-sidecar-synthetic.json new file mode 100644 index 000000000..7798a08e5 --- /dev/null +++ b/docs/doctoring/observed-health-quarantine-sidecar-synthetic.json @@ -0,0 +1,245 @@ +{ + "kv": { + "circuit_opened_lines": 0, + "health_policy": { + "circuit_failure_rate_min_observations": 6, + "circuit_failure_rate_threshold": 0.6, + "circuit_failure_threshold": 3, + "circuit_failure_window": 10, + "circuit_max_cooldown_seconds": 3600.0, + "circuit_reset_seconds": 30.0, + "observed_health_quarantine": true, + "setting_name": "CONTEXTUAL_ORCHESTRATOR_OBSERVED_HEALTH_QUARANTINE", + "slow_failure_cooldown_seconds": 360.0, + "slow_failure_weight": 2.0, + "source": "kv" + }, + "mode": "kv", + "provider_calls_by_kind": { + "chat": 17, + "structured": 16, + "triage": 0 + }, + "requests": [ + { + "latency_ms": 453.5, + "provider_attempts": 5, + "slow_attempts": 1, + "status": 200 + }, + { + "latency_ms": 30.3, + "provider_attempts": 4, + "slow_attempts": 0, + "status": 200 + }, + { + "latency_ms": 30.2, + "provider_attempts": 4, + "slow_attempts": 0, + "status": 200 + }, + { + "latency_ms": 31.9, + "provider_attempts": 4, + "slow_attempts": 0, + "status": 200 + }, + { + "latency_ms": 32.0, + "provider_attempts": 4, + "slow_attempts": 0, + "status": 200 + }, + { + "latency_ms": 34.5, + "provider_attempts": 4, + "slow_attempts": 0, + "status": 200 + }, + { + "latency_ms": 33.7, + "provider_attempts": 4, + "slow_attempts": 0, + "status": 200 + }, + { + "latency_ms": 38.6, + "provider_attempts": 4, + "slow_attempts": 0, + "status": 200 + } + ], + "slow_calls_by_kind": { + "chat": 1, + "structured": 0, + "triage": 0 + }, + "slow_seconds": 0.265, + "total_latency_ms": 684.7, + "total_provider_attempts": 33, + "total_slow_attempts": 1 + }, + "off": { + "circuit_opened_lines": 1, + "health_policy": { + "circuit_failure_rate_min_observations": 6, + "circuit_failure_rate_threshold": 0.6, + "circuit_failure_threshold": 3, + "circuit_failure_window": 10, + "circuit_max_cooldown_seconds": 3600.0, + "circuit_reset_seconds": 30.0, + "observed_health_quarantine": false, + "setting_name": "CONTEXTUAL_ORCHESTRATOR_OBSERVED_HEALTH_QUARANTINE", + "slow_failure_cooldown_seconds": 360.0, + "slow_failure_weight": 2.0, + "source": "default" + }, + "mode": "off", + "provider_calls_by_kind": { + "chat": 19, + "structured": 16, + "triage": 0 + }, + "requests": [ + { + "latency_ms": 1113.5, + "provider_attempts": 5, + "slow_attempts": 3, + "status": 200 + }, + { + "latency_ms": 839.1, + "provider_attempts": 5, + "slow_attempts": 3, + "status": 200 + }, + { + "latency_ms": 842.5, + "provider_attempts": 5, + "slow_attempts": 3, + "status": 200 + }, + { + "latency_ms": 567.2, + "provider_attempts": 4, + "slow_attempts": 2, + "status": 200 + }, + { + "latency_ms": 571.3, + "provider_attempts": 4, + "slow_attempts": 2, + "status": 200 + }, + { + "latency_ms": 567.8, + "provider_attempts": 4, + "slow_attempts": 2, + "status": 200 + }, + { + "latency_ms": 560.2, + "provider_attempts": 4, + "slow_attempts": 2, + "status": 200 + }, + { + "latency_ms": 564.7, + "provider_attempts": 4, + "slow_attempts": 2, + "status": 200 + } + ], + "slow_calls_by_kind": { + "chat": 3, + "structured": 16, + "triage": 0 + }, + "slow_seconds": 0.265, + "total_latency_ms": 5626.3, + "total_provider_attempts": 35, + "total_slow_attempts": 19 + }, + "on": { + "circuit_opened_lines": 0, + "health_policy": { + "circuit_failure_rate_min_observations": 6, + "circuit_failure_rate_threshold": 0.6, + "circuit_failure_threshold": 3, + "circuit_failure_window": 10, + "circuit_max_cooldown_seconds": 3600.0, + "circuit_reset_seconds": 30.0, + "observed_health_quarantine": true, + "setting_name": "CONTEXTUAL_ORCHESTRATOR_OBSERVED_HEALTH_QUARANTINE", + "slow_failure_cooldown_seconds": 360.0, + "slow_failure_weight": 2.0, + "source": "argument" + }, + "mode": "on", + "provider_calls_by_kind": { + "chat": 17, + "structured": 16, + "triage": 0 + }, + "requests": [ + { + "latency_ms": 475.6, + "provider_attempts": 5, + "slow_attempts": 1, + "status": 200 + }, + { + "latency_ms": 32.0, + "provider_attempts": 4, + "slow_attempts": 0, + "status": 200 + }, + { + "latency_ms": 32.1, + "provider_attempts": 4, + "slow_attempts": 0, + "status": 200 + }, + { + "latency_ms": 33.2, + "provider_attempts": 4, + "slow_attempts": 0, + "status": 200 + }, + { + "latency_ms": 31.8, + "provider_attempts": 4, + "slow_attempts": 0, + "status": 200 + }, + { + "latency_ms": 30.8, + "provider_attempts": 4, + "slow_attempts": 0, + "status": 200 + }, + { + "latency_ms": 34.0, + "provider_attempts": 4, + "slow_attempts": 0, + "status": 200 + }, + { + "latency_ms": 35.6, + "provider_attempts": 4, + "slow_attempts": 0, + "status": 200 + } + ], + "slow_calls_by_kind": { + "chat": 1, + "structured": 0, + "triage": 0 + }, + "slow_seconds": 0.265, + "total_latency_ms": 705.1, + "total_provider_attempts": 33, + "total_slow_attempts": 1 + } +} \ No newline at end of file diff --git a/docs/doctoring/observed-health-quarantine.md b/docs/doctoring/observed-health-quarantine.md index 0ff432774..ed8547cad 100644 --- a/docs/doctoring/observed-health-quarantine.md +++ b/docs/doctoring/observed-health-quarantine.md @@ -34,7 +34,10 @@ over-represents failed runs; none of the numbers below are population rates.** `docs/product-technical-gap-baseline.md` (no-heuristics boundary, 2026-09-07) keeps automatic candidate exclusion at the legacy 3/30 policy unless an operator supplies the decision. This change therefore ships the mechanism -behind `TaskOrchestrator(..., observed_health_quarantine=False)`. +behind one operator switch, which is **off by default**: the KV setting +`CONTEXTUAL_ORCHESTRATOR_OBSERVED_HEALTH_QUARANTINE` (see "Activation switch" +below), or an explicit `TaskOrchestrator(observed_health_quarantine=...)` +argument, which wins over the KV value. With the flag off (the default, and what the sidecar runs today), the breaker is behavior-identical to the legacy one: weight 1, a 30 s reset that zeroes @@ -43,9 +46,10 @@ only additions are observability: extra `circuit_opened` fields, the `circuit_all_open_fallback` log line and the `routing_evidence.health` snapshot. -The values below are repository-proposed and backed only by the replay in -this document. Enabling them, and choosing how the sidecar passes the flag -(CLI or KV bootstrap, following the `rate_limit_wait_seconds` precedent), is +The values below are repository-proposed and backed only by the replay and +synthetic measurement in this document. **The 360 s slow cooldown is an +experimental candidate supported by the 101-artifact replay (biased toward +failed runs), not a validated production constant.** Enabling the switch is an owner decision. #1000, #911 and #1082 still own the broader routing repair. ## Design (flag on) @@ -56,8 +60,8 @@ mechanism therefore extends that ledger rather than adding a second breaker. | Concern | Behavior | | --- | --- | -| Signal | Real served-request outcomes. Every existing `_record_failure` / `_record_success` call site feeds the ledger. Where the exception is in hand (`_invoke`, `stream_route`, and the explicit and virtual passthrough loops), the call passes `failure_class=classify_health_failure(exc)`. The launcher preflight is not duplicated. | -| Failure class | `slow_transport`: `provider_timeout` or `provider_connection_error`, status 408/502/504, or a raw timeout, reset, `RemoteDisconnected` or `URLError`. `fast`: everything else. Call sites that pass no class count as `unclassified` with weight 1. 413 and passthrough 429 never reach the ledger, the same as before. | +| Signal | Real served-request outcomes. Every existing `_record_failure` / `_record_success` call site feeds the ledger. Where the exception is in hand (`_invoke`, `stream_route`, and the explicit and virtual passthrough loops), the call passes `failure_class=classify_health_failure(exc)`. The launcher preflight is not duplicated. The two single-call picks outside the failover loop, auto-mode triage and the conduct model judge, use the same order when the switch is on: open members are skipped and demoted ones are tried last. | +| Failure class | `slow_transport`: `provider_timeout`, `provider_connection_error`, `provider_outcome_unknown` (how `ModelClient` wraps a dropped chat connection before `_invoke` sees it) or `model_timeout`; status 408/502/504; or a raw timeout, reset, `RemoteDisconnected` or `URLError`. `fast`: everything else. Call sites that pass no class count as `unclassified` with weight 1. 413 and passthrough 429 never reach the ledger, the same as before. | | Demotion | Once a member's latest failure is slow, `_failover_candidates` keeps it eligible but stable-sorts it behind members without a recent slow failure. The result of request N therefore changes the order for request N+1. A single failure never excludes a member. | | Quarantine | The breaker opens when any of these holds: (a) the weighted consecutive score (slow = `slow_failure_weight` 2.0, else 1.0) reaches `circuit_failure_threshold` 3, which means two slow failures or three fast ones; (b) at least 6 of the last 10 outcomes are recorded and the failure rate is at least 0.6 (a single success no longer erases the evidence); (c) the half-open probe fails. | | Cooldown | A trip that involved a slow failure lasts `slow_failure_cooldown_seconds` (360 s, longer than the longest observed slow failure of 302.3 s). A trip from fast failures only uses `circuit_reset_seconds` (30 s). Each half-open failure doubles the cooldown, capped at `circuit_max_cooldown_seconds` (3600 s). Any success resets the escalation level. Exclusion is never permanent. | @@ -95,10 +99,8 @@ shape (`{"failures", "opened_at"}`). The new state lives in `_circuit_health`. and 31 errors are identical on `origin/main`. They are pre-existing: a `cost_router` import error, `selection_design` KeyErrors, egress allowlist and paper-inventory contracts. -- Flag-on behavior is exercised through `_invoke` and `_failover_candidates` - only. `route_once`, virtual-selector `proxy_completion`, `stream_route` and - `conduct` ran only with the flag off (full suite). An end-to-end flag-on - test belongs with the enablement decision. +- Flag-on behavior is exercised end to end over HTTP on all four served + paths. See "HTTP end-to-end (four paths)" below. - `-W error` on the 13 neighbor suites: base and head are both nonclean (81 and 82 failing ids in one run each, with different sets). The failures are dominated by the pre-existing `_TemporaryFileCloser` and unclosed @@ -205,20 +207,271 @@ attempt reached those members inside the cooldown. This is the unrecovered healthy runs. None of this is customer-latency evidence until served p50/p90 are re-measured on a deployed pin with the flag on. +## HTTP end-to-end (four paths) + +`tests/test_observed_health_quarantine_http.py` runs the real server +(`build_server` and `POST /v1/chat/completions`) with +`observed_health_quarantine=True`. Agents are `mock://`; a controllable +in-process `ModelClient` fails the "down" agents with a slow-class 504 on +`chat`, `stream_chat` and `proxy_send_once`. Time comes from the breaker's +injected monotonic clock (`_circuit_clock`), so nothing sleeps. That clock is +patched rather than the global `time.monotonic`, so that rate-limit and +server threads keep real time. + +The four paths: + +- **route:** `mode=route`, which reaches `route_once`. +- **conduct:** `mode=conduct`. +- **stream:** `mode=route` with `stream=true`, which reaches `stream_route`. +- **proxy:** `orchestrator/auto` plus `response_format`. This is the only + `/v1/chat/completions` route into `proxy_completion` (it runs + `single_agent=False`, then conduct stages and structured synthesis + failover). A virtual selector with only `tools` is conducted instead; the + virtual passthrough loop is reached by direct callers. + +Each path is checked for: + +- (a) the next request after one slow failure does not call the demoted + member; +- (b1) after the cooldown, the half-open probe runs and recovers + (`circuit_half_open`, then `circuit_recovered`); +- (b2) a failed probe re-opens the breaker with twice the cooldown + (`trigger=half_open_failure`); +- (c) an all-open pool still serves, least-recently-failed first + (`circuit_all_open_fallback`). + +One extra test covers the auto-mode triage pick, and one pins that the flag +off keeps the legacy order. + +**RED at `56276d65`**, with the proxy case already on the structured path: +5 failed, 13 passed. The failures were: + +- `demotes[conduct]`, `demotes[proxy]`, `recovers[conduct]` and + `recovers[proxy]`. The conduct **model-judge** call + (`_model_judge_verification` picks the first ranked verifier) still went to + the demoted slow member. +- `test_auto_mode_triage_pick_follows_observed_health`. The auto-mode + **triage** call (`_compute_triage_verdict` picks `candidates[0]`) still went + to the demoted member. + +Both picks bypass `_failover_candidates`. The first draft, which used `tools` +for the proxy case, also failed `proxy` (b2) and (c), but those were conduct +behaviors reached through the wrong route and not a proxy defect. + +**Minimal fix:** `_observed_health_order()` is applied to those two single-call +picks and is a no-op when the flag is off. + +**GREEN:** the new files together (`test_observed_health_quarantine.py`, +`test_observed_health_quarantine_http.py`, `test_measured_routing_evidence.py`, +`test_review_gateway.py`, `test_rate_limit_breaker_asymmetry.py`) pass under +`-W error`. + +A second RED came from the sidecar measurement below. `ModelClient` wraps a +dropped chat connection as `provider_outcome_unknown` before `_invoke` sees +it, and the classifier called that `fast`. The failing assertion was +`test_wrapped_post_send_failures_stay_slow_class`: +`AssertionError: provider_outcome_unknown / assert 'fast' == 'slow_transport'`. +`provider_outcome_unknown` and `model_timeout` are now in the slow set. The +replay was unaffected, because it classifies the raw logged error types. + +## Synthetic sidecar-shaped measurement + +The deployed entrypoint is `ContextualWisdomLab/.github` +`scripts/ci/contextual_orchestrator_review_launcher.py` (read at `.github` +`origin/main` `e6334e229`; not modified). It calls +`configure_logging(DEBUG)` with the timestamped sidecar format, then +`register_review_credentials(os.environ)`, `ModelClient(...)`, +`TaskOrchestrator(agents, client=client)` and `serve(...)`. + +`scripts/measure_health_quarantine_sidecar.py` mirrors that construction in +one process per mode. Loopback egress is blocked, so the fake provider is +patched at `ModelClient._open_provider` on a reserved `.invalid` host. +Nothing leaves the process, and the real retry loop, logging, failover, +judge and breaker all run. + +- `slow_free_agent` has priority 10 and raises `RemoteDisconnected` after + 0.265 s, the evidence p50 of 265 s at a 1/1000 time scale. +- `steady_free_agent` has priority 1 and answers in 5 ms. + +The script sends 8 sequential `orchestrator/free` requests, each with a +distinct prompt, and parses `http_request latency_ms` and `provider_attempt` +lines from the DEBUG log. Output: +`observed-health-quarantine-sidecar-synthetic.json`. + +**This is synthetic and not provider-real.** It shows the policy's mechanical +effect on one fixed failure pattern, not customer latency. + +| Mode | Σ latency_ms (8 req) | Per request (ms) | Slow-agent calls (chat / judge) | provider_attempt lines | All 200 | +| --- | --- | --- | --- | --- | --- | +| off (default) | 5626.3 | 1113.5, 839.1, 842.5, 567.2, 571.3, 567.8, 560.2, 564.7 | 3 / 16 | 35 | yes | +| on (argument) | 705.1 | 475.6, 32.0, 32.1, 33.2, 31.8, 30.8, 34.0, 35.6 | 1 / 0 | 33 | yes | +| on (KV switch, launcher-identical construction) | 684.7 | 453.5, 30.3, 30.2, 31.9, 32.0, 34.5, 33.7, 38.6 | 1 / 0 | 33 | yes | + +With the flag off, the legacy breaker opened once (after the 3rd chat +failure), but the model judge kept picking the slow member: 2 structured +calls per request, 16 in total. The legacy judge pick ignores the breaker. +With the flag on, the slow member is hit once, then demoted for both the +failover loop and the judge. + +## Activation switch and consumer handoff + +**The one switch** is the KV (credential-registry) setting +`CONTEXTUAL_ORCHESTRATOR_OBSERVED_HEALTH_QUARANTINE`. +`TaskOrchestrator.__init__` reads it once with `get_credential`, following +the "KV, not env" rule. + +- `enabled`/`true`/`on`/`1` turns the quarantine on; `disabled`/`false`/`off`/`0` + turns it off. +- Unset means off, with source `default`. +- Any other value fails construction with a `ValueError`, so a typo cannot + silently pick a policy. +- If the KV is unreadable, the legacy policy is kept and a WARNING is logged + (source `kv_unavailable`). +- An explicit constructor boolean wins over the KV (source `argument`). + +`review_gateway.register_review_credentials()` is the bootstrap function the +launcher already imports. It copies the setting from the bootstrap +environment into the KV, in the same way it copies the gateway token. + +**Why it is deployable:** the launcher constructs +`TaskOrchestrator(agents, client=client)` without policy arguments and +already calls `register_review_credentials(os.environ)` before constructing. +Honoring the switch therefore needs no copied launcher code, only a pin bump +and one environment value. + +**Why it is auditable:** + +- At construction, every process logs INFO + `observed_health_quarantine enabled= source=default|kv|argument|kv_unavailable setting=... slow_failure_cooldown_seconds=...`. + The sidecar logs at DEBUG, so the line lands in the uploaded + `contextual-orchestrator-sidecar.stderr.log`. +- `admin_state()["routing_evidence"]["health_policy"]` reports the switch, + its source and every knob. +- `register_review_credentials` returns the setting name in its + `registered` tuple. + +This is covered by `test_kv_switch_is_the_single_deployable_activation_and_is_audited` +and `test_kv_switch_off_values_and_invalid_value_fail_closed`. + +**Consumer handoff** (for `ContextualWisdomLab/.github`; not done here): + +1. Bump `ORCHESTRATOR_PIN_SHA` to a merged commit that contains this change. +2. On the step that runs `scripts/ci/contextual_orchestrator_review_launcher.py` + (the sidecar step in `noema-review.yml`, and in `strix.yml` and + `opencode-review-dispatch.yml` if they adopt it), add one step env value: + `CONTEXTUAL_ORCHESTRATOR_OBSERVED_HEALTH_QUARANTINE: enabled`. + Use a repository variable (for example + `${{ vars.CO_OBSERVED_HEALTH_QUARANTINE || 'disabled' }}`) so the owner can + roll back without a code change. The value is a non-secret toggle. +3. Verify in the uploaded sidecar log that the startup line reads + `observed_health_quarantine enabled=True source=kv`. Then re-measure + served p50/p90 and slow-failure seconds against this runbook's baseline + before calling it an improvement. + +No launcher Python change is needed. + +## 429 study (analysis only; 429 behavior unchanged) + +**Code, at this branch:** + +- `_invoke` (`orchestrator.py` ~11137–11204) records the quota cooldown + (`if exc.provider_status in (429, 503): self._record_rate_limit(...)`). + It then classifies the error as + `decision = classify_provider_transport_failure(exc.retryable)`. A 429 is + `retryable=True`, and `tool_fallback.classify_provider_transport_failure` + returns `circuit_failure=True` for every retryable failure (the + `retryable` branch of `_decision(..., circuit_failure=True)`). So the + breaker is charged at `if decision.circuit_failure: self._record_failure(...)`. + The code comment there says "retry-classified failures always trip the + circuit". +- `stream_route` (~7961) follows the same pattern + (`classify_provider_transport_failure(upstream.retryable)` then + `_record_failure`), so a pre-byte stream 429 is charged as well. +- The virtual passthrough loop in `proxy_completion` (~6587–6592) sets + `skip_breaker = request_too_large or capability_mismatch or (rate_limit_signal is not None and rate_limit_signal[0] == 429)`. + A 429 is recorded only as a quota cooldown. + +**What pins each behavior:** + +- Passthrough: `tests/test_rate_limit_aware_admission.py::test_429_does_not_trip_circuit_breaker_but_503_still_does`, + and the constructor comment (~5793) stating that a 429 "must never trip or + feed `_circuit`". +- `_invoke`: no test asserts that a provider 429 charges the breaker. The + behavior follows only from `classify_provider_transport_failure`'s + contract. It contradicts the constructor comment and the gateway rule that + provider availability is transport evidence. +- `tests/test_orchestrator_dispatch_boundaries.py::test_invoke_retries_idempotent_rate_limits_with_circuit_and_backoff` + concerns a *tool* rate limit, and it clears on success. + +**Reproduction:** `tests/test_rate_limit_breaker_asymmetry.py` uses one +fixture. The first-ranked agent returns HTTP 429 with `Retry-After: 7` at +`ModelClient._open_provider`, and the second agent succeeds. The same pool +and messages go through `route_once` and through `proxy_completion`. + +- Both paths record the quota cooldown. +- `route_once` leaves `_circuit["first_agent"]["failures"] == 1.0`. +- `proxy_completion` leaves `"first_agent" not in _circuit`. + +**Replay quantification (101 artifacts):** + +- Served 429 attempts that the deployed path charged to the breaker (a + `circuit_failure` line follows): **144**. 12 more were not charged. +- Deployed log: **11 of 66** `circuit_opened` events (16.7 %) had a 429 in + the charged streak since the last clear/reset. +- Legacy replay (flag off): 64 episodes, 11 with a 429 in the streak. + Excluding 429 gives 53 episodes. +- Flag on: 37 episodes, 5 with a 429 in the streak. Excluding 429 gives 32 + episodes (`observed-health-quarantine-replay-exclude-429.json`). +- Estimated saved seconds: **36,831.6 s including 429 vs 36,827.5 s + excluding it (Δ 4.1 s)**. False-positive episodes are 1 vs 1, and harmful + removals 1 vs 1. Charged 429s are fast (p50 0.1 s), so skipping them saves + almost nothing, while each one moves a member toward the open state. + +**Arguments:** + +- *For counting 429 as health:* a member that is persistently throttled is + unavailable to this gateway, and a breaker trip moves traffic elsewhere + sooner. +- *Against:* + - 429 is account or quota capacity, not model correctness or endpoint + health. It is often shared by sibling models on the same key, so charging + one member mislabels the cause. + - The gateway already has a dedicated, provider-stated quota mechanism + (`_record_rate_limit`, `Retry-After`), and `_failover_candidates` already + skips cooling-down members. A breaker trip adds a second, unrelated + cooldown (30 s legacy; 30 s or more under the quarantine) on top of the + provider's own. + - AGENTS.md treats request-size 413 as never member health, and provider + uptime as transport evidence rather than quality. The same reasoning + keeps quota out of health. + - The two chat paths disagree today, so the same provider response has + different consequences depending on the request shape. + +**Recommendation (not implemented):** make `_invoke` and `stream_route` +match the passthrough path. Keep recording the 429 quota cooldown, but do not +call `_record_failure` for a provider 429. Leave 503 as a real availability +signal, as the passthrough path does. + +- Land it as its own PR with a RED on the fixture above, flipping the + `route_once` assertion. +- Check `test_tool_execution_fallback` and `test_rate_limit_aware_admission` + for storm-wait interactions. +- On this evidence the throughput effect is negligible (Δ 4.1 s over 101 + runs). The benefit is correctness and consistency, not speed. + ## Owner decisions / open questions -1. Whether and how to enable `observed_health_quarantine` for the sidecar - (CLI or KV bootstrap). The default stays off under the 2026-09-07 - boundary. -2. The proposed cooldown is 360 s. The corrected sweep shows 300–360 s - dominating 600 s: slightly lower savings, but 1 harmful removal instead - of 7. This is tuned on a biased sample. -3. On the `_invoke` path, a served 429 is still charged to the breaker as a - fast failure (144 recorded occurrences in the replayed logs), while the - passthrough path excludes 429 as quota. This inconsistency predates this - change and is left as it is. +1. Whether to set the switch in the review workflows. The default stays off + under the 2026-09-07 boundary. The consumer handoff is above. +2. The 360 s cooldown is an experimental candidate. The corrected sweep + shows 300–360 s dominating 600 s: slightly lower savings, but 1 harmful + removal instead of 7. This is tuned on a biased sample. +3. Whether to adopt the 429 recommendation above in a separate PR. 4. A persisted health ledger across restarts is not implemented, so the gateway starts unquarantined. +5. With the flag off, the legacy judge pick still ignores the breaker. This + is shown in the synthetic measurement (16 judge calls to an already-open + member) and is left unchanged here. ## Reference diff --git a/docs/product-technical-gap-baseline.md b/docs/product-technical-gap-baseline.md index 28f85008a..ccb20c498 100644 --- a/docs/product-technical-gap-baseline.md +++ b/docs/product-technical-gap-baseline.md @@ -5723,10 +5723,11 @@ observations can remain evidence but are not by themselves a production policy. **Amendment (2026-09-22): operator opt-in mechanism, default unchanged.** -`TaskOrchestrator(observed_health_quarantine=True)` adds failure-class +The KV setting `CONTEXTUAL_ORCHESTRATOR_OBSERVED_HEALTH_QUARANTINE=enabled` +(or `TaskOrchestrator(observed_health_quarantine=True)`) adds failure-class weighting, a cooldown longer than one slow attempt, a failure-rate window that a single success cannot erase, a half-open probe, and demotion of members -whose last failure was slow. The default stays `False`, which is the legacy +whose last failure was slow. The default stays off, which is the legacy 3/30 policy, per the boundary above. Replay evidence, proposed values and the enablement decision are in [the observed-health runbook](doctoring/observed-health-quarantine.md). diff --git a/scripts/measure_health_quarantine_sidecar.py b/scripts/measure_health_quarantine_sidecar.py new file mode 100644 index 000000000..8f514b6c1 --- /dev/null +++ b/scripts/measure_health_quarantine_sidecar.py @@ -0,0 +1,233 @@ +"""Synthetic sidecar-shaped measurement of the observed-health quarantine. + +Mirrors the construction in ``ContextualWisdomLab/.github`` +``scripts/ci/contextual_orchestrator_review_launcher.py`` (read-only +reference): ``configure_logging`` at DEBUG with the sidecar timestamp format, +``register_review_credentials`` from a bootstrap mapping, a ``ModelClient`` +with the review sampling settings, ``TaskOrchestrator(agents, client=client)`` +and the real HTTP server. Loopback egress is blocked, so the provider is a +fake patched at the lowest transport seam (``ModelClient._open_provider``, +the pattern ``tests/test_ci_gateway_bootstrap.py`` uses) on a reserved +``.invalid`` host; the real retry loop, ``provider_attempt`` logging, +failover, judge and breaker all run and nothing leaves the process: + +* ``slow_free_agent`` drops the connection (``RemoteDisconnected``) after + ``--slow-seconds`` (the evidence p50 is 265 s; the default 0.265 s is a + 1/1000 time scale); +* ``steady_free_agent`` answers after ``--fast-seconds``. + +It sends ``--requests`` sequential ``orchestrator/free`` chat completions and +prints per-request ``http_request`` latency and ``provider_attempt`` counts +parsed from the process log. **Synthetic, not provider-real**: it measures the +policy's effect on this fixed failure pattern only. + +Usage:: + + python3 scripts/measure_health_quarantine_sidecar.py --mode off|on|kv [--requests 8] + +``on`` passes ``observed_health_quarantine=True``; ``kv`` constructs the +orchestrator exactly as the launcher does and seeds the KV switch through +``register_review_credentials`` instead. +""" + +from __future__ import annotations + +import argparse +import http.client +import io +import json +import logging +import re +import sys +import threading +import time +import urllib.request +from pathlib import Path +from typing import Any + +sys.path.insert(0, str(Path(__file__).resolve().parents[1])) + +from contextual_orchestrator import ModelAgent, TaskOrchestrator # noqa: E402 +from contextual_orchestrator.debug_logging import configure_logging # noqa: E402 +from contextual_orchestrator.orchestrator import ModelClient # noqa: E402 +from contextual_orchestrator.review_gateway import ( # noqa: E402 + REVIEW_AUTH_CREDENTIAL_NAME, + register_review_credentials, +) +from contextual_orchestrator.server import SecurityConfig, build_server # noqa: E402 + +SIDECAR_LOG_FORMAT = "%(asctime)s %(levelname)s %(name)s %(message)s" +SWITCH_NAME = "CONTEXTUAL_ORCHESTRATOR_OBSERVED_HEALTH_QUARANTINE" +_TOKEN = "synthetic_sidecar_measurement_token" +_TAGS = ("cost:free", "reasoning", "writing", "planning", "coding", "verification") +_HTTP = re.compile(r"http_request method=POST path=/v1/chat/completions status=(\d+) latency_ms=([\d.]+) .*request_id=(\w+)") +_ATTEMPT = re.compile(r"provider_attempt agent_id=(\S+) .* request_id=(\w+)") + + +class _FakeResponse: + """Minimal context-managed provider response (the shape ``_open_provider`` returns).""" + + def __init__(self, content: str) -> None: + self._body = json.dumps( + { + "id": "chatcmpl_synthetic", + "object": "chat.completion", + "created": 0, + "model": "synthetic", + "choices": [ + {"index": 0, "message": {"role": "assistant", "content": content}, "finish_reason": "stop"} + ], + "usage": {"prompt_tokens": 10, "completion_tokens": 5, "total_tokens": 15}, + } + ).encode("utf-8") + self.status = 200 + self.headers: dict[str, str] = {} + + def read(self, amount: int | None = None) -> bytes: + body, self._body = self._body, b"" + return body + + def getheader(self, name: str, default: str | None = None) -> str | None: + return default + + def close(self) -> None: + self._body = b"" + + def __enter__(self) -> "_FakeResponse": + return self + + def __exit__(self, *exc_info: object) -> bool: + self.close() + return False + + +def _fake_open_provider(slow_seconds: float, fast_seconds: float, seen: list[dict[str, Any]]): + """Return an ``_open_provider`` replacement; nothing leaves the process.""" + + def _open_provider(self, request, destination=None, *, timeout=None): + del self, destination, timeout + payload = json.loads(request.data.decode("utf-8")) if request.data else {} + model = payload.get("model", "") + messages = payload.get("messages") or [] + system = messages[0].get("content", "") if messages else "" + kind = ( + "triage" + if system == TaskOrchestrator.TRIAGE_SYSTEM_PROMPT + else "structured" if payload.get("response_format") else "chat" + ) + seen.append({"model": model, "kind": kind}) + if model == "vendor/slow-model": + time.sleep(slow_seconds) + raise http.client.RemoteDisconnected("synthetic remote end closed connection") + time.sleep(fast_seconds) + if kind == "triage": + return _FakeResponse('{"workflow_required": false}') + return _FakeResponse("synthetic review answer citing evidence, risks and caveats") + + return _open_provider + + +def run(mode: str, requests: int, slow_seconds: float, fast_seconds: float) -> dict[str, Any]: + """Serve one sidecar-shaped process, send the requests, return parsed metrics.""" + buffer = io.StringIO() + configure_logging("DEBUG") + root = logging.getLogger() + handler = logging.StreamHandler(buffer) + root.addHandler(handler) + for item in root.handlers: + item.setFormatter(logging.Formatter(SIDECAR_LOG_FORMAT)) + bootstrap = {"NVIDIA_NIM_API_KEY": "synthetic-not-a-key", REVIEW_AUTH_CREDENTIAL_NAME: _TOKEN} + if mode == "kv": + bootstrap[SWITCH_NAME] = "enabled" + register_review_credentials(bootstrap) + seen: list[dict[str, Any]] = [] + ModelClient._validate_provider = lambda self, agent: None + ModelClient._open_provider = _fake_open_provider(slow_seconds, fast_seconds, seen) + agents = [ + ModelAgent("slow_free_agent", "vendor/slow-model", base_url="https://provider.invalid/v1", + api_key_env="NVIDIA_NIM_API_KEY", tags=_TAGS, priority=10), + ModelAgent("steady_free_agent", "vendor/steady-model", base_url="https://provider.invalid/v1", + api_key_env="NVIDIA_NIM_API_KEY", tags=_TAGS, priority=1), + ] + client = ModelClient(max_output_tokens=2048, temperature=0.1) + kwargs = {"observed_health_quarantine": True} if mode == "on" else {} + orchestrator = TaskOrchestrator(agents, client=client, **kwargs) + server = build_server(orchestrator, port=0, security=SecurityConfig(auth_token=_TOKEN)) + thread = threading.Thread(target=server.serve_forever, daemon=True) + thread.start() + port = server.server_address[1] + try: + for index in range(requests): + body = { + "model": TaskOrchestrator.FREE_MODEL, + "messages": [{"role": "user", "content": f"review change set {index}"}], + } + request = urllib.request.Request( + f"http://127.0.0.1:{port}/v1/chat/completions", + data=json.dumps(body).encode("utf-8"), + headers={"content-type": "application/json", "authorization": f"Bearer {_TOKEN}"}, + method="POST", + ) + with urllib.request.urlopen(request, timeout=60) as response: + response.read() + finally: + server.shutdown() + thread.join(timeout=5) + server.server_close() + root.removeHandler(handler) + handler.close() + log = buffer.getvalue() + attempts: dict[str, list[str]] = {} + for line in log.splitlines(): + match = _ATTEMPT.search(line) + if match: + attempts.setdefault(match.group(2), []).append(match.group(1)) + rows = [] + for line in log.splitlines(): + match = _HTTP.search(line) + if match: + status, latency, request_id = match.groups() + tried = attempts.get(request_id, []) + rows.append( + { + "status": int(status), + "latency_ms": float(latency), + "provider_attempts": len(tried), + "slow_attempts": tried.count("slow_free_agent"), + } + ) + return { + "mode": mode, + "health_policy": orchestrator.admin_state()["routing_evidence"].get("health_policy"), + "slow_seconds": slow_seconds, + "requests": rows, + "total_latency_ms": round(sum(row["latency_ms"] for row in rows), 1), + "total_provider_attempts": sum(row["provider_attempts"] for row in rows), + "total_slow_attempts": sum(row["slow_attempts"] for row in rows), + "circuit_opened_lines": log.count("circuit_opened "), + "provider_calls_by_kind": { + kind: sum(1 for item in seen if item["kind"] == kind) + for kind in ("triage", "chat", "structured") + }, + "slow_calls_by_kind": { + kind: sum(1 for item in seen if item["kind"] == kind and item["model"] == "vendor/slow-model") + for kind in ("triage", "chat", "structured") + }, + } + + +def main(argv: list[str] | None = None) -> dict[str, Any]: + """Parse arguments, run one mode, print JSON.""" + parser = argparse.ArgumentParser(description=__doc__.splitlines()[0]) + parser.add_argument("--mode", choices=("off", "on", "kv"), required=True) + parser.add_argument("--requests", type=int, default=8) + parser.add_argument("--slow-seconds", type=float, default=0.265) + parser.add_argument("--fast-seconds", type=float, default=0.005) + args = parser.parse_args(argv) + result = run(args.mode, args.requests, args.slow_seconds, args.fast_seconds) + print(json.dumps(result, indent=2, sort_keys=True)) + return result + + +if __name__ == "__main__": + main() diff --git a/scripts/replay_health_quarantine.py b/scripts/replay_health_quarantine.py index 2ffd464bc..a3fc673d0 100644 --- a/scripts/replay_health_quarantine.py +++ b/scripts/replay_health_quarantine.py @@ -150,11 +150,14 @@ def replay_run( totals: dict, policy: dict | None = None, demotion: bool = True, + exclude_429: bool = False, ) -> None: """Drive one fresh orchestrator through one run's attempts in time order. ``policy`` overrides breaker attributes (for sensitivity runs); ``demotion=False`` ignores slow-failure demotion to isolate quarantine. + ``exclude_429=True`` is the 429-study counterfactual: served provider + 429s are kept out of the ledger (as the passthrough path already does). """ agents = {} for attempt in attempts: @@ -179,6 +182,7 @@ def available(agent_id: str) -> bool: skipped: set[int] = set() first_after_open: set[str] = set() harmful_requests: set[str] = set() + streak_429: dict[str, bool] = {} for stamp, kind, index in events: clock["now"] = stamp attempt = attempts[index] @@ -237,9 +241,14 @@ def available(agent_id: str) -> bool: continue if attempt["ok"]: orchestrator._record_success(agent_id) + streak_429[agent_id] = False continue if attempt["status"] in _NEVER_HEALTH: continue + if served and attempt["status"] == "429" and attempt["recorded"]: + totals["served_429_charged"] += 1 + if exclude_429: + continue if served and not attempt["recorded"]: continue # the deployed path did not charge it to the breaker before = orchestrator.circuit_health_snapshot().get(agent_id, {}).get("open_count", 0) @@ -249,14 +258,47 @@ def available(agent_id: str) -> bool: _synthetic_failure(attempt["error_type"], attempt["status"]) ), ) + streak_429[agent_id] = streak_429.get(agent_id, False) or attempt["status"] == "429" if orchestrator.circuit_health_snapshot()[agent_id]["open_count"] > before: totals["quarantine_episodes"] += 1 + if streak_429[agent_id]: + totals["episodes_with_429_in_streak"] += 1 + streak_429[agent_id] = False first_after_open.add(agent_id) if not served: totals["preflight_triggered_episodes"] += 1 totals["harmful_requests"] += len(harmful_requests) +def deployed_429_opens(path: Path) -> dict[str, int]: + """Count deployed ``circuit_opened`` events whose charged streak held a 429. + + Reads the deployed (legacy 3/30) log itself, independent of the replay: + the charged failures for an agent since its last clear/reset/open. + """ + streak: dict[str, list[str]] = defaultdict(list) + last_status: dict[str, str] = {} + counts = {"deployed_circuit_opened": 0, "deployed_opened_with_429_in_streak": 0} + for line in path.read_text(errors="replace").splitlines(): + failed = _FAILED.match(line) + if failed: + last_status[failed.group(2)] = failed.group(4) + continue + charged = _CIRCUIT_FAILURE.match(line) + if charged: + streak[charged.group(2)].append(last_status.get(charged.group(2), "?")) + continue + edge = re.match(_TS + r"circuit_(opened|cleared|reset) agent_id=(\S+)", line) + if edge: + agent_id = edge.group(3) + if edge.group(2) == "opened": + counts["deployed_circuit_opened"] += 1 + if "429" in streak[agent_id]: + counts["deployed_opened_with_429_in_streak"] += 1 + streak[agent_id] = [] + return counts + + def main(argv: list[str] | None = None) -> dict: """Replay every run under ``artifacts_dir`` and print one bounded JSON summary.""" parser = argparse.ArgumentParser(description=__doc__.splitlines()[0]) @@ -264,6 +306,7 @@ def main(argv: list[str] | None = None) -> dict: parser.add_argument("--include-preflight", action="store_true") parser.add_argument("--json", type=Path) parser.add_argument("--no-demotion", action="store_true") + parser.add_argument("--exclude-429", action="store_true") parser.add_argument( "--legacy-like", action="store_true", @@ -281,12 +324,17 @@ def main(argv: list[str] | None = None) -> dict: totals=totals, policy=policy, demotion=demotion, + exclude_429=args.exclude_429, ) + deployed = deployed_429_opens(path) + for key, value in deployed.items(): + totals[key] += value summary = { "runs": len(logs), "include_preflight": args.include_preflight, "demotion": demotion, "policy_overrides": policy, + "exclude_429": args.exclude_429, **{key: round(value, 1) for key, value in sorted(totals.items())}, } text = json.dumps(summary, indent=2, sort_keys=True) diff --git a/tests/test_measured_routing_evidence.py b/tests/test_measured_routing_evidence.py index 2741dba99..4b47dc9be 100644 --- a/tests/test_measured_routing_evidence.py +++ b/tests/test_measured_routing_evidence.py @@ -369,7 +369,7 @@ def test_admin_state_exposes_both_routing_ledgers() -> None: orchestrator = _orch(ModelAgent("worker_agent", "mock", tags=("reasoning",))) orchestrator._quality_router.observe_success("worker_agent", 0.5, output_tokens=25) evidence = orchestrator.admin_state()["routing_evidence"] - assert set(evidence) == {"transport", "quality", "health"} + assert set(evidence) == {"transport", "quality", "health", "health_policy"} assert evidence["quality"]["worker_agent"]["ewma_tokens_per_second"] == pytest.approx(50.0) assert evidence["transport"]["worker_agent"]["ewma_tokens_per_second"] is None diff --git a/tests/test_observed_health_quarantine.py b/tests/test_observed_health_quarantine.py index 1153fe59d..0b67a8c25 100644 --- a/tests/test_observed_health_quarantine.py +++ b/tests/test_observed_health_quarantine.py @@ -29,7 +29,14 @@ ModelClient, classify_health_failure, ) +from contextual_orchestrator.credentials import ( # noqa: E402 + InMemoryCredentialBackend, + register_credential, + set_backend, +) +from contextual_orchestrator.orchestrator import OBSERVED_HEALTH_QUARANTINE_SETTING # noqa: E402 from contextual_orchestrator.provider_errors import ProviderUpstreamError # noqa: E402 +from contextual_orchestrator.review_gateway import register_review_credentials # noqa: E402 _LOGGER_NAME = "contextual_orchestrator.orchestrator" @@ -132,6 +139,16 @@ def test_failure_classes_separate_slow_post_send_from_fast_rejections() -> None: assert classify_health_failure(RuntimeError("opaque")) == "fast" +def test_wrapped_post_send_failures_stay_slow_class() -> None: + """ModelClient wraps a dropped connection as provider_outcome_unknown before _invoke sees it.""" + for code in ("provider_outcome_unknown", "model_timeout"): + wrapped = ProviderUpstreamError( + agent_id="a", model="m", error_code=code, message="x", + client_status=502, provider_status=None, retryable=False, + ) + assert classify_health_failure(wrapped) == "slow_transport", code + + def test_served_slow_failure_demotes_agent_for_the_next_request() -> None: orchestrator, client, _clock = _pool() client.down.add("slow_worker") @@ -284,6 +301,50 @@ def test_health_snapshot_is_bounded_and_prompt_free() -> None: assert orchestrator.admin_state()["routing_evidence"]["health"] == snapshot +@contextmanager +def _fresh_kv() -> Iterator[None]: + set_backend(InMemoryCredentialBackend()) + try: + yield + finally: + set_backend(None) + + +def _launcher_shaped() -> TaskOrchestrator: + """Construct exactly as the review launcher does: no policy argument.""" + return TaskOrchestrator([ModelAgent("solo_worker", "mock")], client=ModelClient()) + + +def test_kv_switch_is_the_single_deployable_activation_and_is_audited() -> None: + with _fresh_kv(): + default = _launcher_shaped() + assert (default.observed_health_quarantine, default.observed_health_quarantine_source) == (False, "default") + register_review_credentials({OBSERVED_HEALTH_QUARANTINE_SETTING: "enabled\n"}) + with _captured_logs(logging.INFO) as buffer: + enabled = _launcher_shaped() + assert enabled.observed_health_quarantine is True + assert f"observed_health_quarantine enabled=True source=kv setting={OBSERVED_HEALTH_QUARANTINE_SETTING}" in buffer.getvalue() + policy = enabled.admin_state()["routing_evidence"]["health_policy"] + assert policy["observed_health_quarantine"] is True and policy["source"] == "kv" + assert policy["slow_failure_cooldown_seconds"] == 360.0 + # An explicit constructor boolean still wins over the KV value. + assert TaskOrchestrator([ModelAgent("solo_worker", "mock")], observed_health_quarantine=False).observed_health_quarantine is False + + +def test_kv_switch_off_values_and_invalid_value_fail_closed() -> None: + with _fresh_kv(): + register_credential(OBSERVED_HEALTH_QUARANTINE_SETTING, "disabled") + off = _launcher_shaped() + assert (off.observed_health_quarantine, off.observed_health_quarantine_source) == (False, "kv") + register_credential(OBSERVED_HEALTH_QUARANTINE_SETTING, "maybe") + try: + _launcher_shaped() + except ValueError as exc: + assert OBSERVED_HEALTH_QUARANTINE_SETTING in str(exc) + else: # pragma: no cover + raise AssertionError("an unrecognized switch value must fail construction") + + if __name__ == "__main__": for name, fn in sorted(globals().items()): if name.startswith("test_") and callable(fn): diff --git a/tests/test_rate_limit_breaker_asymmetry.py b/tests/test_rate_limit_breaker_asymmetry.py new file mode 100644 index 000000000..d285ab5e1 --- /dev/null +++ b/tests/test_rate_limit_breaker_asymmetry.py @@ -0,0 +1,125 @@ +"""Characterize (not endorse) how the two chat paths charge a provider 429. + +One identical provider response -- HTTP 429 with ``Retry-After: 7`` from the +first-ranked agent, success from the second -- is served at the lowest +transport seam (``ModelClient._open_provider``) to the same pool and the same +request through (1) ``route_once`` -> ``_invoke`` and (2) the virtual +passthrough loop in ``proxy_completion``. Both record the quota cooldown; only +``_invoke`` also charges the breaker. The policy analysis lives in +``docs/doctoring/observed-health-quarantine.md`` ("429 study"); this file pins +current behavior so a future change is deliberate. +""" + +from __future__ import annotations + +import http.client +import json +import sys +import urllib.error +from dataclasses import replace +from pathlib import Path + +import pytest + +sys.path.insert(0, str(Path(__file__).resolve().parents[1])) + +from contextual_orchestrator import ModelAgent, TaskOrchestrator # noqa: E402 +from contextual_orchestrator.credentials import ( # noqa: E402 + InMemoryCredentialBackend, + register_credential, + set_backend, +) +from contextual_orchestrator.orchestrator import ModelClient # noqa: E402 + + +class _Response: + def __init__(self) -> None: + self._body = json.dumps( + { + "id": "chatcmpl_ok", + "object": "chat.completion", + "created": 0, + "model": "second-model", + "choices": [{"index": 0, "message": {"role": "assistant", "content": "ok"}, "finish_reason": "stop"}], + } + ).encode("utf-8") + self.status = 200 + self.headers: dict[str, str] = {} + + def read(self, amount: int | None = None) -> bytes: + body, self._body = self._body, b"" + return body + + def getheader(self, name: str, default: str | None = None) -> str | None: + return default + + def close(self) -> None: + self._body = b"" + + def __enter__(self) -> "_Response": + return self + + def __exit__(self, *exc_info: object) -> bool: + self.close() + return False + + +def _rate_limited() -> urllib.error.HTTPError: + headers = http.client.HTTPMessage() + headers["Retry-After"] = "7" + return urllib.error.HTTPError("https://provider.invalid/v1/chat/completions", 429, "Too Many Requests", headers, None) + + +@pytest.fixture +def pool(monkeypatch: pytest.MonkeyPatch): + set_backend(InMemoryCredentialBackend()) + register_credential("SYNTHETIC_PROVIDER_KEY", "synthetic") + raised: list[urllib.error.HTTPError] = [] # the fake provider owns its responses + + def open_provider(self, request, destination=None, *, timeout=None): + del self, destination, timeout + if json.loads(request.data.decode("utf-8"))["model"] == "first-model": + raised.append(_rate_limited()) + raise raised[-1] + return _Response() + + monkeypatch.setattr(ModelClient, "_validate_provider", lambda self, agent: None) + monkeypatch.setattr(ModelClient, "_open_provider", open_provider) + agents = [ + ModelAgent("first_agent", "first-model", base_url="https://provider.invalid/v1", + api_key_env="SYNTHETIC_PROVIDER_KEY", tags=("reasoning", "writing"), priority=10), + ModelAgent("second_agent", "second-model", base_url="https://provider.invalid/v2", + api_key_env="SYNTHETIC_PROVIDER_KEY", tags=("reasoning", "writing"), priority=1), + ] + orchestrator = TaskOrchestrator( + agents, + client=ModelClient(max_retries=0), + tool_retry_attempts=0, + tool_retry_backoff_seconds=0.0, + rate_limit_wait_seconds=0.0, + ) + orchestrator.policy = replace(orchestrator.policy, realtime_judge=False) + orchestrator._triage_fn = lambda text: False + try: + yield orchestrator + finally: + for error in raised: + error.close() + set_backend(None) + + +_MESSAGES = [{"role": "user", "content": "summarize the incident"}] + + +def test_invoke_path_charges_provider_429_to_the_breaker(pool: TaskOrchestrator) -> None: + result = pool.route_once(list(_MESSAGES), model_name=TaskOrchestrator.AUTO_MODEL) + assert result["trace"][0]["served_agent_id"] == "second_agent" + assert pool._rate_limit_remaining("first_agent") is not None # quota cooldown recorded + assert pool._circuit["first_agent"]["failures"] == 1.0 # ... and a health failure + + +def test_passthrough_path_keeps_provider_429_out_of_the_breaker(pool: TaskOrchestrator) -> None: + response = pool.proxy_completion({"model": TaskOrchestrator.AUTO_MODEL, "messages": list(_MESSAGES)}) + assert response["choices"][0]["message"]["content"] == "ok" + assert pool._rate_limit_remaining("first_agent") is not None # quota cooldown recorded + assert "first_agent" not in pool._circuit # ... but no health failure From 3d34be2e6ba0c776d33be3c3d04789752580befd Mon Sep 17 00:00:00 2001 From: Seongho Bae Date: Tue, 22 Sep 2026 03:50:19 +0900 Subject: [PATCH 05/10] fix(routing): keep provider 429 out of breaker health on every chat path _invoke and stream_route charged a provider 429 to the circuit breaker (and the observed-health ledger) while the passthrough loop skipped it. A 429 is quota capacity, not member health. Both paths now share _charges_breaker, mirroring passthrough skip_breaker: a 429 records only the quota cooldown (stream_route now records one; it recorded none), and a 503 still charges the breaker. Model-group stability observation is unchanged. The pinning regression runs one fixture through route, stream and passthrough. RED at b073b160: route charged failures=1.0 and stream recorded no cooldown. Replay defaults now exclude 429 as the code does; --include-429/--legacy-like reproduce the deployed pin. The synthetic sidecar output is labelled SYNTHETIC. The feature default stays off, and the 360 s cooldown remains an experimental candidate. Co-Authored-By: Claude Opus 5 Claude-Session: https://claude.ai/code/session_012ABB9sb4szFEteww67UYZy --- AGENTS.md | 6 +- contextual_orchestrator/orchestrator.py | 29 +++- ...health-quarantine-replay-include-429.json} | 17 +- ...th-quarantine-replay-preflight-whatif.json | 17 +- ...erved-health-quarantine-replay-served.json | 17 +- ...d-health-quarantine-sidecar-synthetic.json | 57 +++---- docs/doctoring/observed-health-quarantine.md | 39 +++-- scripts/measure_health_quarantine_sidecar.py | 1 + scripts/replay_health_quarantine.py | 17 +- tests/test_rate_limit_breaker_asymmetry.py | 146 +++++++++++------- 10 files changed, 217 insertions(+), 129 deletions(-) rename docs/doctoring/{observed-health-quarantine-replay-exclude-429.json => observed-health-quarantine-replay-include-429.json} (67%) diff --git a/AGENTS.md b/AGENTS.md index 04839a413..6dfed5907 100644 --- a/AGENTS.md +++ b/AGENTS.md @@ -144,8 +144,10 @@ push or open a PR. `CONTEXTUAL_ORCHESTRATOR_OBSERVED_HEALTH_QUARANTINE`, operator opt-in, default off = legacy 3/30) weights slow post-send failures for breaker and candidate order only; it never authorizes retry or changes timeouts. Keep - the never-empty fallback and in-memory restart semantics. Replay limits and - owner decisions: `docs/doctoring/observed-health-quarantine.md`. + the never-empty fallback and in-memory restart semantics. A provider 429 + records only the quota cooldown on every chat path; 503 still charges the + breaker. Replay limits and owner decisions: + `docs/doctoring/observed-health-quarantine.md`. - Endpoint races require a complete operator-reviewed equivalence contract. Never infer equivalence from provider/model names, and never treat missing loser diff --git a/contextual_orchestrator/orchestrator.py b/contextual_orchestrator/orchestrator.py index 7a12cae63..4bed0f24f 100644 --- a/contextual_orchestrator/orchestrator.py +++ b/contextual_orchestrator/orchestrator.py @@ -7959,7 +7959,18 @@ def stream_route( raise last_error = upstream decision = classify_provider_transport_failure(upstream.retryable) - if decision.circuit_failure: + rate_limit_signal = self._rate_limited_provider_signal(upstream) + if rate_limit_signal is not None: + # Same quota cooldown _invoke and passthrough record. + signal_status, signal_http_error = rate_limit_signal + self._record_rate_limit( + agent.id, + resolve_retry_after_seconds(signal_http_error) + if signal_http_error is not None + else upstream.extra_detail.get("retry_after_seconds"), + status=signal_status, + ) + if decision.circuit_failure and self._charges_breaker(upstream): self._record_failure( agent.id, failure_class=classify_health_failure(upstream) ) @@ -11184,7 +11195,7 @@ def attempt(agent: ModelAgent) -> EndpointAttempt[Any]: ): retry_attempt += 1 self._record_tool_fallback(agent.id, decision, retry_attempt) - if decision.circuit_failure: # pragma: no branch - retry-classified failures always trip the circuit + if decision.circuit_failure and self._charges_breaker(exc): self._record_failure( agent.id, failure_class=classify_health_failure(exc) ) @@ -11201,7 +11212,7 @@ def attempt(agent: ModelAgent) -> EndpointAttempt[Any]: decision = downgrade_to_failover(decision) action = decision.action self._record_tool_fallback(agent.id, decision, retry_attempt) - if decision.circuit_failure: + if decision.circuit_failure and self._charges_breaker(exc): self._record_failure( agent.id, failure_class=classify_health_failure(exc) ) @@ -12226,6 +12237,18 @@ def _rate_limited_provider_signal( current = current.__context__ return None + def _charges_breaker(self, exc: BaseException) -> bool: + """Whether a failed attempt counts against member health. + + A provider 429 is quota capacity, not model health: it records only + the quota cooldown (:meth:`_record_rate_limit`) and never feeds the + breaker or the observed-health ledger -- the passthrough loop's + ``skip_breaker`` rule, shared by ``_invoke`` and ``stream_route``. + A 503 stays an availability failure. + """ + signal = self._rate_limited_provider_signal(exc) + return signal is None or signal[0] != 429 + def _agent(self, agent_id: str) -> ModelAgent: for agent in self.candidates: if agent.id == agent_id and _agent_matches_request_endpoint(agent): diff --git a/docs/doctoring/observed-health-quarantine-replay-exclude-429.json b/docs/doctoring/observed-health-quarantine-replay-include-429.json similarity index 67% rename from docs/doctoring/observed-health-quarantine-replay-exclude-429.json rename to docs/doctoring/observed-health-quarantine-replay-include-429.json index 191a80ea9..3c6f4be22 100644 --- a/docs/doctoring/observed-health-quarantine-replay-exclude-429.json +++ b/docs/doctoring/observed-health-quarantine-replay-include-429.json @@ -1,11 +1,12 @@ { - "demote_skips": 130.0, + "demote_skips": 160.0, "demotion": true, "deployed_circuit_opened": 66.0, "deployed_opened_with_429_in_streak": 11.0, - "exclude_429": true, + "episodes_with_429_in_streak": 5.0, + "exclude_429": false, "false_positive_episodes": 1.0, - "forced_fallback_attempts": 10.0, + "forced_fallback_attempts": 15.0, "harmful_removals": 1.0, "harmful_removals_after_slow_transport": 1.0, "harmful_requests": 1.0, @@ -13,16 +14,16 @@ "policy_overrides": { "observed_health_quarantine": true }, - "quarantine_episodes": 32.0, + "quarantine_episodes": 37.0, "quarantine_skips": 10.0, "runs": 101, - "saved_failed_seconds": 36827.5, - "saved_failed_seconds_after_fast": 486.0, + "saved_failed_seconds": 36831.6, + "saved_failed_seconds_after_fast": 490.1, "saved_failed_seconds_after_slow_transport": 36341.5, - "saved_failed_seconds_by_demote_skip": 35201.7, + "saved_failed_seconds_by_demote_skip": 35205.8, "saved_failed_seconds_by_quarantine_skip": 1625.8, "saved_slow_failure_seconds": 36319.6, - "served_429_charged": 144.0, + "served_429_charged": 117.0, "served_attempts": 1627.0, "served_failed_seconds": 111064.9, "served_slow_failure_seconds": 100261.0 diff --git a/docs/doctoring/observed-health-quarantine-replay-preflight-whatif.json b/docs/doctoring/observed-health-quarantine-replay-preflight-whatif.json index 0487a7030..12f159627 100644 --- a/docs/doctoring/observed-health-quarantine-replay-preflight-whatif.json +++ b/docs/doctoring/observed-health-quarantine-replay-preflight-whatif.json @@ -1,12 +1,11 @@ { - "demote_skips": 160.0, + "demote_skips": 130.0, "demotion": true, "deployed_circuit_opened": 66.0, "deployed_opened_with_429_in_streak": 11.0, - "episodes_with_429_in_streak": 15.0, - "exclude_429": false, + "exclude_429": true, "false_positive_episodes": 1.0, - "forced_fallback_attempts": 15.0, + "forced_fallback_attempts": 10.0, "harmful_removals": 1.0, "harmful_removals_after_slow_transport": 1.0, "harmful_requests": 1.0, @@ -14,16 +13,16 @@ "policy_overrides": { "observed_health_quarantine": true }, - "quarantine_episodes": 61.0, + "quarantine_episodes": 46.0, "quarantine_skips": 10.0, "runs": 101, - "saved_failed_seconds": 36831.6, - "saved_failed_seconds_after_fast": 490.1, + "saved_failed_seconds": 36827.5, + "saved_failed_seconds_after_fast": 486.0, "saved_failed_seconds_after_slow_transport": 36341.5, - "saved_failed_seconds_by_demote_skip": 35205.8, + "saved_failed_seconds_by_demote_skip": 35201.7, "saved_failed_seconds_by_quarantine_skip": 1625.8, "saved_slow_failure_seconds": 36319.6, - "served_429_charged": 117.0, + "served_429_charged": 144.0, "served_attempts": 1627.0, "served_failed_seconds": 111064.9, "served_slow_failure_seconds": 100261.0 diff --git a/docs/doctoring/observed-health-quarantine-replay-served.json b/docs/doctoring/observed-health-quarantine-replay-served.json index 3c6f4be22..191a80ea9 100644 --- a/docs/doctoring/observed-health-quarantine-replay-served.json +++ b/docs/doctoring/observed-health-quarantine-replay-served.json @@ -1,12 +1,11 @@ { - "demote_skips": 160.0, + "demote_skips": 130.0, "demotion": true, "deployed_circuit_opened": 66.0, "deployed_opened_with_429_in_streak": 11.0, - "episodes_with_429_in_streak": 5.0, - "exclude_429": false, + "exclude_429": true, "false_positive_episodes": 1.0, - "forced_fallback_attempts": 15.0, + "forced_fallback_attempts": 10.0, "harmful_removals": 1.0, "harmful_removals_after_slow_transport": 1.0, "harmful_requests": 1.0, @@ -14,16 +13,16 @@ "policy_overrides": { "observed_health_quarantine": true }, - "quarantine_episodes": 37.0, + "quarantine_episodes": 32.0, "quarantine_skips": 10.0, "runs": 101, - "saved_failed_seconds": 36831.6, - "saved_failed_seconds_after_fast": 490.1, + "saved_failed_seconds": 36827.5, + "saved_failed_seconds_after_fast": 486.0, "saved_failed_seconds_after_slow_transport": 36341.5, - "saved_failed_seconds_by_demote_skip": 35205.8, + "saved_failed_seconds_by_demote_skip": 35201.7, "saved_failed_seconds_by_quarantine_skip": 1625.8, "saved_slow_failure_seconds": 36319.6, - "served_429_charged": 117.0, + "served_429_charged": 144.0, "served_attempts": 1627.0, "served_failed_seconds": 111064.9, "served_slow_failure_seconds": 100261.0 diff --git a/docs/doctoring/observed-health-quarantine-sidecar-synthetic.json b/docs/doctoring/observed-health-quarantine-sidecar-synthetic.json index 7798a08e5..ed28031d7 100644 --- a/docs/doctoring/observed-health-quarantine-sidecar-synthetic.json +++ b/docs/doctoring/observed-health-quarantine-sidecar-synthetic.json @@ -14,6 +14,7 @@ "slow_failure_weight": 2.0, "source": "kv" }, + "label": "SYNTHETIC - fake in-process provider at 1/1000 time scale; not provider-real", "mode": "kv", "provider_calls_by_kind": { "chat": 17, @@ -22,49 +23,49 @@ }, "requests": [ { - "latency_ms": 453.5, + "latency_ms": 412.1, "provider_attempts": 5, "slow_attempts": 1, "status": 200 }, { - "latency_ms": 30.3, + "latency_ms": 38.1, "provider_attempts": 4, "slow_attempts": 0, "status": 200 }, { - "latency_ms": 30.2, + "latency_ms": 38.0, "provider_attempts": 4, "slow_attempts": 0, "status": 200 }, { - "latency_ms": 31.9, + "latency_ms": 35.5, "provider_attempts": 4, "slow_attempts": 0, "status": 200 }, { - "latency_ms": 32.0, + "latency_ms": 36.1, "provider_attempts": 4, "slow_attempts": 0, "status": 200 }, { - "latency_ms": 34.5, + "latency_ms": 33.1, "provider_attempts": 4, "slow_attempts": 0, "status": 200 }, { - "latency_ms": 33.7, + "latency_ms": 31.7, "provider_attempts": 4, "slow_attempts": 0, "status": 200 }, { - "latency_ms": 38.6, + "latency_ms": 31.3, "provider_attempts": 4, "slow_attempts": 0, "status": 200 @@ -76,7 +77,7 @@ "triage": 0 }, "slow_seconds": 0.265, - "total_latency_ms": 684.7, + "total_latency_ms": 655.9, "total_provider_attempts": 33, "total_slow_attempts": 1 }, @@ -95,6 +96,7 @@ "slow_failure_weight": 2.0, "source": "default" }, + "label": "SYNTHETIC - fake in-process provider at 1/1000 time scale; not provider-real", "mode": "off", "provider_calls_by_kind": { "chat": 19, @@ -103,49 +105,49 @@ }, "requests": [ { - "latency_ms": 1113.5, + "latency_ms": 1339.2, "provider_attempts": 5, "slow_attempts": 3, "status": 200 }, { - "latency_ms": 839.1, + "latency_ms": 834.7, "provider_attempts": 5, "slow_attempts": 3, "status": 200 }, { - "latency_ms": 842.5, + "latency_ms": 835.8, "provider_attempts": 5, "slow_attempts": 3, "status": 200 }, { - "latency_ms": 567.2, + "latency_ms": 560.8, "provider_attempts": 4, "slow_attempts": 2, "status": 200 }, { - "latency_ms": 571.3, + "latency_ms": 563.0, "provider_attempts": 4, "slow_attempts": 2, "status": 200 }, { - "latency_ms": 567.8, + "latency_ms": 556.8, "provider_attempts": 4, "slow_attempts": 2, "status": 200 }, { - "latency_ms": 560.2, + "latency_ms": 556.1, "provider_attempts": 4, "slow_attempts": 2, "status": 200 }, { - "latency_ms": 564.7, + "latency_ms": 554.3, "provider_attempts": 4, "slow_attempts": 2, "status": 200 @@ -157,7 +159,7 @@ "triage": 0 }, "slow_seconds": 0.265, - "total_latency_ms": 5626.3, + "total_latency_ms": 5800.7, "total_provider_attempts": 35, "total_slow_attempts": 19 }, @@ -176,6 +178,7 @@ "slow_failure_weight": 2.0, "source": "argument" }, + "label": "SYNTHETIC - fake in-process provider at 1/1000 time scale; not provider-real", "mode": "on", "provider_calls_by_kind": { "chat": 17, @@ -184,49 +187,49 @@ }, "requests": [ { - "latency_ms": 475.6, + "latency_ms": 445.1, "provider_attempts": 5, "slow_attempts": 1, "status": 200 }, { - "latency_ms": 32.0, + "latency_ms": 29.4, "provider_attempts": 4, "slow_attempts": 0, "status": 200 }, { - "latency_ms": 32.1, + "latency_ms": 33.1, "provider_attempts": 4, "slow_attempts": 0, "status": 200 }, { - "latency_ms": 33.2, + "latency_ms": 30.8, "provider_attempts": 4, "slow_attempts": 0, "status": 200 }, { - "latency_ms": 31.8, + "latency_ms": 27.1, "provider_attempts": 4, "slow_attempts": 0, "status": 200 }, { - "latency_ms": 30.8, + "latency_ms": 32.2, "provider_attempts": 4, "slow_attempts": 0, "status": 200 }, { - "latency_ms": 34.0, + "latency_ms": 30.9, "provider_attempts": 4, "slow_attempts": 0, "status": 200 }, { - "latency_ms": 35.6, + "latency_ms": 30.4, "provider_attempts": 4, "slow_attempts": 0, "status": 200 @@ -238,7 +241,7 @@ "triage": 0 }, "slow_seconds": 0.265, - "total_latency_ms": 705.1, + "total_latency_ms": 659.0, "total_provider_attempts": 33, "total_slow_attempts": 1 } diff --git a/docs/doctoring/observed-health-quarantine.md b/docs/doctoring/observed-health-quarantine.md index ed8547cad..84d5bafd1 100644 --- a/docs/doctoring/observed-health-quarantine.md +++ b/docs/doctoring/observed-health-quarantine.md @@ -61,7 +61,7 @@ mechanism therefore extends that ledger rather than adding a second breaker. | Concern | Behavior | | --- | --- | | Signal | Real served-request outcomes. Every existing `_record_failure` / `_record_success` call site feeds the ledger. Where the exception is in hand (`_invoke`, `stream_route`, and the explicit and virtual passthrough loops), the call passes `failure_class=classify_health_failure(exc)`. The launcher preflight is not duplicated. The two single-call picks outside the failover loop, auto-mode triage and the conduct model judge, use the same order when the switch is on: open members are skipped and demoted ones are tried last. | -| Failure class | `slow_transport`: `provider_timeout`, `provider_connection_error`, `provider_outcome_unknown` (how `ModelClient` wraps a dropped chat connection before `_invoke` sees it) or `model_timeout`; status 408/502/504; or a raw timeout, reset, `RemoteDisconnected` or `URLError`. `fast`: everything else. Call sites that pass no class count as `unclassified` with weight 1. 413 and passthrough 429 never reach the ledger, the same as before. | +| Failure class | `slow_transport`: `provider_timeout`, `provider_connection_error`, `provider_outcome_unknown` (how `ModelClient` wraps a dropped chat connection before `_invoke` sees it) or `model_timeout`; status 408/502/504; or a raw timeout, reset, `RemoteDisconnected` or `URLError`. `fast`: everything else. Call sites that pass no class count as `unclassified` with weight 1. 413 and provider 429 never reach the ledger on any chat path (route, stream, passthrough); 503 does. | | Demotion | Once a member's latest failure is slow, `_failover_candidates` keeps it eligible but stable-sorts it behind members without a recent slow failure. The result of request N therefore changes the order for request N+1. A single failure never excludes a member. | | Quarantine | The breaker opens when any of these holds: (a) the weighted consecutive score (slow = `slow_failure_weight` 2.0, else 1.0) reaches `circuit_failure_threshold` 3, which means two slow failures or three fast ones; (b) at least 6 of the last 10 outcomes are recorded and the failure rate is at least 0.6 (a single success no longer erases the evidence); (c) the half-open probe fails. | | Cooldown | A trip that involved a slow failure lasts `slow_failure_cooldown_seconds` (360 s, longer than the longest observed slow failure of 302.3 s). A trip from fast failures only uses `circuit_reset_seconds` (30 s). Each half-open failure doubles the cooldown, capped at `circuit_max_cooldown_seconds` (3600 s). Any success resets the escalation level. Exclusion is never permanent. | @@ -70,7 +70,7 @@ mechanism therefore extends that ledger rather than adding a second breaker. | Metrics | WARNING `circuit_opened ... reset_seconds= failure_class=... trigger=consecutive|failure_rate|half_open_failure request_id=...`; INFO `circuit_half_open`, `circuit_recovered`; DEBUG `circuit_failure ... failure_class=...`. `circuit_health_snapshot()` holds bounded per-member fields: state, model, provider, counts, class, cooldown, remaining, window rate and open count. It is exposed at `admin_state()["routing_evidence"]["health"]`; `test_measured_routing_evidence` pins the key set. No prompt text or provider body text is included. | | Concurrency | All ledger reads and writes happen under `_circuit_lock`. Concurrent failures open the breaker exactly once (tested with 16 threads). | | Restart | State is in memory only. After a process restart, every member starts unquarantined and undemoted. Each Noema sidecar is a fresh process, so learning is scoped to one run. | -| Unchanged | Model timeouts (the default null timeout stays), retry and replay authorization, 413/429 handling and model-policy defaults are all untouched. The class only weights health; it never authorizes a retry. | +| Unchanged | Model timeouts (the default null timeout stays), retry and replay authorization, 413 handling and model-policy defaults are all untouched. Provider 429 handling was aligned across paths (see the 429 section). The class only weights health; it never authorizes a retry. | Compatibility note: `_circuit_open` now tests `opened_at` instead of `failures >= threshold`. With the flag off the two tests are equivalent, @@ -120,8 +120,9 @@ clock set to the log timestamps. (92,186 s). - **What feeds the ledger.** A served failure feeds the ledger only if the deployed log shows the deployed path charged it, meaning a - `circuit_failure` line follows it. 413 is never charged. Served 429 on the - `_invoke` path is charged. + `circuit_failure` line follows it. 413 is never charged. The deployed pin + charged served 429 on the `_invoke` path; `--legacy-like`/`--include-429` + replay that, while the default replay excludes 429 as current code does. - **Forced attempts.** An attempt that started while the deployed breaker was open (`circuit_opened` less than 30 s earlier, not cleared) was forced by the never-empty fallback or by a pinned model. The replay never counts such @@ -139,6 +140,8 @@ python3 scripts/replay_health_quarantine.py \ --json docs/doctoring/observed-health-quarantine-replay-served.json python3 scripts/replay_health_quarantine.py --include-preflight \ --json docs/doctoring/observed-health-quarantine-replay-preflight-whatif.json +python3 scripts/replay_health_quarantine.py --include-429 \ + --json docs/doctoring/observed-health-quarantine-replay-include-429.json python3 scripts/replay_health_quarantine.py --legacy-like # deployed default python3 scripts/replay_health_quarantine.py --no-demotion ``` @@ -370,9 +373,23 @@ and `test_kv_switch_off_values_and_invalid_value_fail_closed`. No launcher Python change is needed. -## 429 study (analysis only; 429 behavior unchanged) +## 429 policy (implemented on this branch) -**Code, at this branch:** +A provider 429 now records only the quota cooldown on every chat path: +`_invoke` and `stream_route` share `TaskOrchestrator._charges_breaker`, which +mirrors the passthrough `skip_breaker` rule. A 503 still charges the breaker. +`stream_route` previously recorded no quota cooldown at all; it now records +one. Model-group stability observation (`_group_router.observe_failure`) is +unchanged: `_invoke` and `stream_route` still observe a 429 there, while +passthrough skips it. That residual difference is out of scope here. + +Pinning regression: `tests/test_rate_limit_breaker_asymmetry.py`, one fixture +through route, stream and passthrough. For 429 it asserts the cooldown is +recorded, `_circuit` has no entry and the health ledger is empty. For 503 it +asserts exactly one breaker failure. RED at `b073b160`: route charged the +breaker (`failures == 1.0`) and stream recorded no cooldown. + +**Code before this change (`b073b160`), kept for the record:** - `_invoke` (`orchestrator.py` ~11137–11204) records the quota cooldown (`if exc.provider_status in (429, 503): self._record_rate_limit(...)`). @@ -420,8 +437,10 @@ and messages go through `route_once` and through `proxy_completion`. the charged streak since the last clear/reset. - Legacy replay (flag off): 64 episodes, 11 with a 429 in the streak. Excluding 429 gives 53 episodes. -- Flag on: 37 episodes, 5 with a 429 in the streak. Excluding 429 gives 32 - episodes (`observed-health-quarantine-replay-exclude-429.json`). +- Flag on: 37 episodes, 5 with a 429 in the streak + (`observed-health-quarantine-replay-include-429.json`). Excluding 429, as + current code does, gives 32 episodes + (`observed-health-quarantine-replay-served.json`). - Estimated saved seconds: **36,831.6 s including 429 vs 36,827.5 s excluding it (Δ 4.1 s)**. False-positive episodes are 1 vs 1, and harmful removals 1 vs 1. Charged 429s are fast (p50 0.1 s), so skipping them saves @@ -447,7 +466,7 @@ and messages go through `route_once` and through `proxy_completion`. - The two chat paths disagree today, so the same provider response has different consequences depending on the request shape. -**Recommendation (not implemented):** make `_invoke` and `stream_route` +**Decision (implemented above):** make `_invoke` and `stream_route` match the passthrough path. Keep recording the 429 quota cooldown, but do not call `_record_failure` for a provider 429. Leave 503 as a real availability signal, as the passthrough path does. @@ -466,7 +485,7 @@ signal, as the passthrough path does. 2. The 360 s cooldown is an experimental candidate. The corrected sweep shows 300–360 s dominating 600 s: slightly lower savings, but 1 harmful removal instead of 7. This is tuned on a biased sample. -3. Whether to adopt the 429 recommendation above in a separate PR. +3. The 429 alignment is implemented; whether model-group stability should also skip 429 (as passthrough does) is open. 4. A persisted health ledger across restarts is not implemented, so the gateway starts unquarantined. 5. With the flag off, the legacy judge pick still ignores the breaker. This diff --git a/scripts/measure_health_quarantine_sidecar.py b/scripts/measure_health_quarantine_sidecar.py index 8f514b6c1..c48ebd1ce 100644 --- a/scripts/measure_health_quarantine_sidecar.py +++ b/scripts/measure_health_quarantine_sidecar.py @@ -197,6 +197,7 @@ def run(mode: str, requests: int, slow_seconds: float, fast_seconds: float) -> d } ) return { + "label": "SYNTHETIC - fake in-process provider at 1/1000 time scale; not provider-real", "mode": mode, "health_policy": orchestrator.admin_state()["routing_evidence"].get("health_policy"), "slow_seconds": slow_seconds, diff --git a/scripts/replay_health_quarantine.py b/scripts/replay_health_quarantine.py index a3fc673d0..ee4987919 100644 --- a/scripts/replay_health_quarantine.py +++ b/scripts/replay_health_quarantine.py @@ -156,8 +156,10 @@ def replay_run( ``policy`` overrides breaker attributes (for sensitivity runs); ``demotion=False`` ignores slow-failure demotion to isolate quarantine. - ``exclude_429=True`` is the 429-study counterfactual: served provider - 429s are kept out of the ledger (as the passthrough path already does). + ``exclude_429=True`` mirrors current code: every chat path keeps a + provider 429 out of the breaker/ledger. The deployed pin (767e67f) + charged ``_invoke`` 429s, so ``--legacy-like`` and ``--include-429`` + replay with them included. """ agents = {} for attempt in attempts: @@ -306,7 +308,11 @@ def main(argv: list[str] | None = None) -> dict: parser.add_argument("--include-preflight", action="store_true") parser.add_argument("--json", type=Path) parser.add_argument("--no-demotion", action="store_true") - parser.add_argument("--exclude-429", action="store_true") + parser.add_argument( + "--include-429", + action="store_true", + help="charge served 429s as the deployed pin did (default: excluded, as current code)", + ) parser.add_argument( "--legacy-like", action="store_true", @@ -317,6 +323,7 @@ def main(argv: list[str] | None = None) -> dict: totals: dict = defaultdict(float) policy = {"observed_health_quarantine": not args.legacy_like} demotion = not (args.no_demotion or args.legacy_like) + exclude_429 = not (args.include_429 or args.legacy_like) for path in logs: replay_run( parse_run(path), @@ -324,7 +331,7 @@ def main(argv: list[str] | None = None) -> dict: totals=totals, policy=policy, demotion=demotion, - exclude_429=args.exclude_429, + exclude_429=exclude_429, ) deployed = deployed_429_opens(path) for key, value in deployed.items(): @@ -334,7 +341,7 @@ def main(argv: list[str] | None = None) -> dict: "include_preflight": args.include_preflight, "demotion": demotion, "policy_overrides": policy, - "exclude_429": args.exclude_429, + "exclude_429": exclude_429, **{key: round(value, 1) for key, value in sorted(totals.items())}, } text = json.dumps(summary, indent=2, sort_keys=True) diff --git a/tests/test_rate_limit_breaker_asymmetry.py b/tests/test_rate_limit_breaker_asymmetry.py index d285ab5e1..5b535ccc4 100644 --- a/tests/test_rate_limit_breaker_asymmetry.py +++ b/tests/test_rate_limit_breaker_asymmetry.py @@ -1,13 +1,19 @@ -"""Characterize (not endorse) how the two chat paths charge a provider 429. - -One identical provider response -- HTTP 429 with ``Retry-After: 7`` from the -first-ranked agent, success from the second -- is served at the lowest -transport seam (``ModelClient._open_provider``) to the same pool and the same -request through (1) ``route_once`` -> ``_invoke`` and (2) the virtual -passthrough loop in ``proxy_completion``. Both record the quota cooldown; only -``_invoke`` also charges the breaker. The policy analysis lives in -``docs/doctoring/observed-health-quarantine.md`` ("429 study"); this file pins -current behavior so a future change is deliberate. +"""Pin one breaker contract for a provider 429 across every chat path. + +One identical provider response from the first-ranked agent -- HTTP 429 with +``Retry-After: 7``, or HTTP 503 -- is served at the lowest transport seam +(``ModelClient._open_provider``) while the second agent succeeds. The same +pool and request then go through ``route_once`` (``_invoke``), +``stream_route`` and the virtual passthrough loop in ``proxy_completion``: + +* 429 is quota capacity, not member health: every path records the quota + cooldown and none charges the circuit breaker or the observed-health ledger + (the passthrough ``skip_breaker`` rule, now shared); +* 503 stays an availability failure: exactly one breaker failure. + +Before this was unified, ``_invoke`` and ``stream_route`` charged a 429 to +the breaker (see the 429 study in +``docs/doctoring/observed-health-quarantine.md``). """ from __future__ import annotations @@ -31,30 +37,40 @@ ) from contextual_orchestrator.orchestrator import ModelClient # noqa: E402 +_MESSAGES = [{"role": "user", "content": "summarize the incident"}] + class _Response: - def __init__(self) -> None: - self._body = json.dumps( - { + """A provider 200: JSON for chat/passthrough, SSE lines for streaming.""" + + def __init__(self, stream: bool) -> None: + if stream: + chunk = {"model": "second-model", "choices": [{"index": 0, "delta": {"content": "ok"}}]} + self._lines = [f"data: {json.dumps(chunk)}\n".encode(), b"data: [DONE]\n"] + else: + body = { "id": "chatcmpl_ok", "object": "chat.completion", "created": 0, "model": "second-model", "choices": [{"index": 0, "message": {"role": "assistant", "content": "ok"}, "finish_reason": "stop"}], } - ).encode("utf-8") + self._lines = [json.dumps(body).encode("utf-8")] self.status = 200 self.headers: dict[str, str] = {} + def __iter__(self): + return iter(self._lines) + def read(self, amount: int | None = None) -> bytes: - body, self._body = self._body, b"" + body, self._lines = b"".join(self._lines), [] return body def getheader(self, name: str, default: str | None = None) -> str | None: return default def close(self) -> None: - self._body = b"" + self._lines = [] def __enter__(self) -> "_Response": return self @@ -64,62 +80,80 @@ def __exit__(self, *exc_info: object) -> bool: return False -def _rate_limited() -> urllib.error.HTTPError: +def _provider_error(status: int) -> urllib.error.HTTPError: headers = http.client.HTTPMessage() - headers["Retry-After"] = "7" - return urllib.error.HTTPError("https://provider.invalid/v1/chat/completions", 429, "Too Many Requests", headers, None) + if status == 429: + headers["Retry-After"] = "7" + return urllib.error.HTTPError( + "https://provider.invalid/v1/chat/completions", status, "provider error", headers, None + ) @pytest.fixture -def pool(monkeypatch: pytest.MonkeyPatch): +def pool_for(monkeypatch: pytest.MonkeyPatch): set_backend(InMemoryCredentialBackend()) register_credential("SYNTHETIC_PROVIDER_KEY", "synthetic") raised: list[urllib.error.HTTPError] = [] # the fake provider owns its responses - def open_provider(self, request, destination=None, *, timeout=None): - del self, destination, timeout - if json.loads(request.data.decode("utf-8"))["model"] == "first-model": - raised.append(_rate_limited()) - raise raised[-1] - return _Response() - - monkeypatch.setattr(ModelClient, "_validate_provider", lambda self, agent: None) - monkeypatch.setattr(ModelClient, "_open_provider", open_provider) - agents = [ - ModelAgent("first_agent", "first-model", base_url="https://provider.invalid/v1", - api_key_env="SYNTHETIC_PROVIDER_KEY", tags=("reasoning", "writing"), priority=10), - ModelAgent("second_agent", "second-model", base_url="https://provider.invalid/v2", - api_key_env="SYNTHETIC_PROVIDER_KEY", tags=("reasoning", "writing"), priority=1), - ] - orchestrator = TaskOrchestrator( - agents, - client=ModelClient(max_retries=0), - tool_retry_attempts=0, - tool_retry_backoff_seconds=0.0, - rate_limit_wait_seconds=0.0, - ) - orchestrator.policy = replace(orchestrator.policy, realtime_judge=False) - orchestrator._triage_fn = lambda text: False + def build(status: int) -> TaskOrchestrator: + def open_provider(self, request, destination=None, *, timeout=None): + del self, destination, timeout + payload = json.loads(request.data.decode("utf-8")) + if payload["model"] == "first-model": + raised.append(_provider_error(status)) + raise raised[-1] + return _Response(stream=bool(payload.get("stream"))) + + monkeypatch.setattr(ModelClient, "_validate_provider", lambda self, agent: None) + monkeypatch.setattr(ModelClient, "_open_provider", open_provider) + agents = [ + ModelAgent("first_agent", "first-model", base_url="https://provider.invalid/v1", + api_key_env="SYNTHETIC_PROVIDER_KEY", tags=("reasoning", "writing"), priority=10), + ModelAgent("second_agent", "second-model", base_url="https://provider.invalid/v2", + api_key_env="SYNTHETIC_PROVIDER_KEY", tags=("reasoning", "writing"), priority=1), + ] + orchestrator = TaskOrchestrator( + agents, + client=ModelClient(max_retries=0), + tool_retry_attempts=0, + tool_retry_backoff_seconds=0.0, + rate_limit_wait_seconds=0.0, + observed_health_quarantine=True, + ) + orchestrator.policy = replace(orchestrator.policy, realtime_judge=False) + orchestrator._triage_fn = lambda text: False + return orchestrator + try: - yield orchestrator + yield build finally: for error in raised: error.close() set_backend(None) -_MESSAGES = [{"role": "user", "content": "summarize the incident"}] +def _serve(orchestrator: TaskOrchestrator, path: str) -> str: + if path == "route": + result = orchestrator.route_once(list(_MESSAGES), model_name=TaskOrchestrator.AUTO_MODEL) + return result["answer"] + if path == "stream": + return "".join(orchestrator.stream_route(list(_MESSAGES), model_name=TaskOrchestrator.AUTO_MODEL)) + response = orchestrator.proxy_completion({"model": TaskOrchestrator.AUTO_MODEL, "messages": list(_MESSAGES)}) + return response["choices"][0]["message"]["content"] -def test_invoke_path_charges_provider_429_to_the_breaker(pool: TaskOrchestrator) -> None: - result = pool.route_once(list(_MESSAGES), model_name=TaskOrchestrator.AUTO_MODEL) - assert result["trace"][0]["served_agent_id"] == "second_agent" - assert pool._rate_limit_remaining("first_agent") is not None # quota cooldown recorded - assert pool._circuit["first_agent"]["failures"] == 1.0 # ... and a health failure +@pytest.mark.parametrize("path", ["route", "stream", "passthrough"]) +def test_provider_429_records_quota_cooldown_but_never_breaker_health(pool_for, path: str) -> None: + orchestrator = pool_for(429) + assert _serve(orchestrator, path) == "ok" + assert orchestrator._rate_limit_remaining("first_agent") is not None, path + assert "first_agent" not in orchestrator._circuit, (path, orchestrator._circuit) + health = orchestrator.circuit_health_snapshot().get("first_agent") + assert health is None or health["window_failure_rate"] in (None, 0.0), (path, health) -def test_passthrough_path_keeps_provider_429_out_of_the_breaker(pool: TaskOrchestrator) -> None: - response = pool.proxy_completion({"model": TaskOrchestrator.AUTO_MODEL, "messages": list(_MESSAGES)}) - assert response["choices"][0]["message"]["content"] == "ok" - assert pool._rate_limit_remaining("first_agent") is not None # quota cooldown recorded - assert "first_agent" not in pool._circuit # ... but no health failure +@pytest.mark.parametrize("path", ["route", "stream", "passthrough"]) +def test_provider_503_still_counts_as_one_breaker_failure(pool_for, path: str) -> None: + orchestrator = pool_for(503) + assert _serve(orchestrator, path) == "ok" + assert orchestrator._circuit["first_agent"]["failures"] == 1.0, path From b06a0cce07b86b60e72c0dfd8ba2755f74122f53 Mon Sep 17 00:00:00 2001 From: Seongho Bae Date: Tue, 22 Sep 2026 09:40:52 +0900 Subject: [PATCH 06/10] chore(scripts): document the loopback-only urllib call in the sidecar measurement Semgrep flagged dynamic-urllib-use-detected in the synthetic sidecar measurement script. The URL is a fixed http://127.0.0.1 origin whose port comes from the local server the script starts; suppress inline with that justification, matching the existing precedent in openrouter_uptime.py. Co-Authored-By: Claude Opus 5 Claude-Session: https://claude.ai/code/session_012ABB9sb4szFEteww67UYZy --- scripts/measure_health_quarantine_sidecar.py | 1 + 1 file changed, 1 insertion(+) diff --git a/scripts/measure_health_quarantine_sidecar.py b/scripts/measure_health_quarantine_sidecar.py index c48ebd1ce..bc50c8373 100644 --- a/scripts/measure_health_quarantine_sidecar.py +++ b/scripts/measure_health_quarantine_sidecar.py @@ -168,6 +168,7 @@ def run(mode: str, requests: int, slow_seconds: float, fast_seconds: float) -> d headers={"content-type": "application/json", "authorization": f"Bearer {_TOKEN}"}, method="POST", ) + # nosemgrep: python.lang.security.audit.dynamic-urllib-use-detected.dynamic-urllib-use-detected - fixed http://127.0.0.1 scheme/host; the port is the ephemeral local server this script just started, never external input. with urllib.request.urlopen(request, timeout=60) as response: response.read() finally: From 462ccacc22abb667800cc752c04f2825eb2a9193 Mon Sep 17 00:00:00 2001 From: Seongho Bae Date: Tue, 22 Sep 2026 14:14:19 +0900 Subject: [PATCH 07/10] fix(security): annotate bound-parameter SQL placeholders for Semgrep The measurement export joins only "?" placeholders into the IN clause and binds every request id, so it is not SQL injection. The Semgrep gate on this head reported both statements (the rule also matches main at the same code when run alone); suppress inline with the rule id and reason, as the existing rename/drop statements do. Co-Authored-By: Claude Opus 5 Claude-Session: https://claude.ai/code/session_012ABB9sb4szFEteww67UYZy --- contextual_orchestrator/orchestrator.py | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/contextual_orchestrator/orchestrator.py b/contextual_orchestrator/orchestrator.py index 4bed0f24f..f82286ecb 100644 --- a/contextual_orchestrator/orchestrator.py +++ b/contextual_orchestrator/orchestrator.py @@ -5364,14 +5364,14 @@ def load_decision_window(self, limit: int = 256) -> dict[str, Any]: diagnostics = [] if request_ids: placeholders = ",".join("?" for _ in request_ids) - phases = self._conn.execute( + phases = self._conn.execute( # nosemgrep: python.sqlalchemy.security.sqlalchemy-execute-raw-query.sqlalchemy-execute-raw-query -- only "?" placeholders are concatenated; every value is bound "SELECT kind, key, payload FROM orchestration_records " "WHERE kind IN ('initial_decision', 'decision_receipt') " "AND key IN (" + placeholders + ") " "ORDER BY seq DESC LIMIT ?", (*request_ids, 2 * limit + 1), ).fetchall() - diagnostics = self._conn.execute( + diagnostics = self._conn.execute( # nosemgrep: python.sqlalchemy.security.sqlalchemy-execute-raw-query.sqlalchemy-execute-raw-query -- only "?" placeholders are concatenated; every value is bound "SELECT kind, key, payload FROM orchestration_records " "WHERE kind IN ('provider_dispatch', 'auxiliary_dispatch') " "AND key IN (" + placeholders + ") ORDER BY seq DESC LIMIT ?", From ee58cb093ead272ab1774cf5923133cad00cf083 Mon Sep 17 00:00:00 2001 From: Seongho Bae Date: Sun, 27 Sep 2026 08:06:42 +0900 Subject: [PATCH 08/10] test(routing): fail uncalibrated health-policy activation --- .../test_observed_health_policy_authority.py | 37 +++++++++++++++++++ 1 file changed, 37 insertions(+) create mode 100644 tests/test_observed_health_policy_authority.py diff --git a/tests/test_observed_health_policy_authority.py b/tests/test_observed_health_policy_authority.py new file mode 100644 index 000000000..5316aab7c --- /dev/null +++ b/tests/test_observed_health_policy_authority.py @@ -0,0 +1,37 @@ +"""Fail closed while observed-health admission has no released authority.""" + +from __future__ import annotations + +import inspect + +import pytest + +from contextual_orchestrator import ModelAgent, TaskOrchestrator +from contextual_orchestrator.credentials import ( + InMemoryCredentialBackend, + register_credential, + set_backend, +) + + +def test_uncalibrated_constructor_activation_is_not_supported() -> None: + """A boolean opt-in cannot authorize heuristic model admission.""" + assert "observed_health_quarantine" not in inspect.signature(TaskOrchestrator).parameters + with pytest.raises(TypeError, match="observed_health_quarantine"): + TaskOrchestrator( + [ModelAgent("worker_one", "mock/worker")], + observed_health_quarantine=True, + ) + + +def test_uncalibrated_kv_activation_has_no_runtime_surface() -> None: + """A KV flag cannot substitute for released calibration evidence.""" + set_backend(InMemoryCredentialBackend()) + try: + register_credential( + "CONTEXTUAL_ORCHESTRATOR_OBSERVED_HEALTH_QUARANTINE", "enabled" + ) + orchestrator = TaskOrchestrator([ModelAgent("worker_one", "mock/worker")]) + assert not hasattr(orchestrator, "observed_health_quarantine") + finally: + set_backend(None) From 1e14fc732c97a5438e552608b381bd3754435bb2 Mon Sep 17 00:00:00 2001 From: Seongho Bae Date: Sun, 27 Sep 2026 08:13:00 +0900 Subject: [PATCH 09/10] fix(routing): remove uncalibrated health admission --- AGENTS.md | 9 - CHANGELOG.d/observed-health-authority.md | 3 + contextual_orchestrator/orchestrator.py | 441 +-------------- contextual_orchestrator/review_gateway.py | 8 +- ...-health-quarantine-replay-include-429.json | 30 -- ...th-quarantine-replay-preflight-whatif.json | 29 - ...erved-health-quarantine-replay-served.json | 29 - ...d-health-quarantine-sidecar-synthetic.json | 248 --------- docs/doctoring/observed-health-quarantine.md | 500 ------------------ docs/product-technical-gap-baseline.md | 32 +- scripts/measure_health_quarantine_sidecar.py | 235 -------- scripts/replay_health_quarantine.py | 355 ------------- tests/test_measured_routing_evidence.py | 2 +- tests/test_observed_health_quarantine.py | 353 ------------- tests/test_observed_health_quarantine_http.py | 310 ----------- tests/test_rate_limit_breaker_asymmetry.py | 99 ++-- 16 files changed, 104 insertions(+), 2579 deletions(-) create mode 100644 CHANGELOG.d/observed-health-authority.md delete mode 100644 docs/doctoring/observed-health-quarantine-replay-include-429.json delete mode 100644 docs/doctoring/observed-health-quarantine-replay-preflight-whatif.json delete mode 100644 docs/doctoring/observed-health-quarantine-replay-served.json delete mode 100644 docs/doctoring/observed-health-quarantine-sidecar-synthetic.json delete mode 100644 docs/doctoring/observed-health-quarantine.md delete mode 100644 scripts/measure_health_quarantine_sidecar.py delete mode 100644 scripts/replay_health_quarantine.py delete mode 100644 tests/test_observed_health_quarantine.py delete mode 100644 tests/test_observed_health_quarantine_http.py diff --git a/AGENTS.md b/AGENTS.md index 6dfed5907..155d3bad3 100644 --- a/AGENTS.md +++ b/AGENTS.md @@ -140,15 +140,6 @@ push or open a PR. unknown-outcome no-replay controls alongside it. Transport spies are not wire delivery evidence. Preserve the default-null model timeout. -- Observed-health quarantine (one switch: KV setting - `CONTEXTUAL_ORCHESTRATOR_OBSERVED_HEALTH_QUARANTINE`, operator opt-in, - default off = legacy 3/30) weights slow post-send failures for breaker and - candidate order only; it never authorizes retry or changes timeouts. Keep - the never-empty fallback and in-memory restart semantics. A provider 429 - records only the quota cooldown on every chat path; 503 still charges the - breaker. Replay limits and owner decisions: - `docs/doctoring/observed-health-quarantine.md`. - - Endpoint races require a complete operator-reviewed equivalence contract. Never infer equivalence from provider/model names, and never treat missing loser usage as free or zero-cost execution. diff --git a/CHANGELOG.d/observed-health-authority.md b/CHANGELOG.d/observed-health-authority.md new file mode 100644 index 000000000..50589d9d3 --- /dev/null +++ b/CHANGELOG.d/observed-health-authority.md @@ -0,0 +1,3 @@ +- Removed the uncalibrated observed-health model-admission switch; explicit or + KV activation now has no supported runtime surface. Provider HTTP 429 still + records quota cooldown evidence without charging breaker health. diff --git a/contextual_orchestrator/orchestrator.py b/contextual_orchestrator/orchestrator.py index f82286ecb..b303a568f 100644 --- a/contextual_orchestrator/orchestrator.py +++ b/contextual_orchestrator/orchestrator.py @@ -2036,100 +2036,6 @@ def _is_omit_equivalent_control(key: str, value: Any) -> bool: return False -#: Observed-health failure classes (bounded vocabulary, see -#: docs/doctoring/observed-health-quarantine.md). ``slow_transport`` is a -#: failure that typically spends a full provider round trip before failing -#: (read timeout, dropped connection, gateway 504/502/408): the Noema sidecar -#: evidence measured those at p50 ~265-302 s each. ``fast`` is an immediate -#: rejection (404, 400, 500, malformed body). 429 and 413 never reach the -#: health ledger at all -- quota and request size are not member health. -_SLOW_HEALTH_ERROR_CODES = frozenset( - { - "provider_timeout", - "provider_connection_error", - # ModelClient wraps a dropped/timed-out chat connection as - # provider_outcome_unknown before _invoke sees it; an administrator - # model deadline is likewise a full post-send wait. - PROVIDER_OUTCOME_UNKNOWN_CODE, - "model_timeout", - } -) -_SLOW_HEALTH_PROVIDER_STATUSES = frozenset({408, 502, 504}) - - -#: The single deployable switch for the observed-health quarantine: a KV -#: (credential-registry) setting read once at ``TaskOrchestrator`` -#: construction. Bootstrap may copy it from the environment into the KV -#: (``review_gateway.register_review_credentials``); runtime never reads env. -OBSERVED_HEALTH_QUARANTINE_SETTING = "CONTEXTUAL_ORCHESTRATOR_OBSERVED_HEALTH_QUARANTINE" -_SWITCH_ON = frozenset({"enabled", "true", "on", "1"}) -_SWITCH_OFF = frozenset({"disabled", "false", "off", "0"}) - - -def _resolve_observed_health_quarantine(explicit: bool | None) -> tuple[bool, str]: - """Resolve the quarantine switch and its audit source. - - An explicit boolean wins (``source='argument'``). Otherwise the KV value - decides (``'kv'``); unset is off (``'default'``). A value that is neither - on nor off fails construction instead of silently picking a policy. A - KV backend error keeps the legacy policy (``'kv_unavailable'``). - """ - if explicit is not None: - if not isinstance(explicit, bool): - raise TypeError("observed_health_quarantine must be a boolean or None") - return explicit, "argument" - try: - raw = get_credential(OBSERVED_HEALTH_QUARANTINE_SETTING) - except Exception: # noqa: BLE001 - an unreadable KV keeps the legacy breaker - _LOGGER.warning( - "observed_health_quarantine_kv_unavailable setting=%s enabled=False", - OBSERVED_HEALTH_QUARANTINE_SETTING, - ) - return False, "kv_unavailable" - if raw is None or not str(raw).strip(): - return False, "default" - value = str(raw).strip().casefold() - if value in _SWITCH_ON: - return True, "kv" - if value in _SWITCH_OFF: - return False, "kv" - raise ValueError( - f"{OBSERVED_HEALTH_QUARANTINE_SETTING} must be one of " - "enabled/disabled/true/false/on/off/1/0" - ) - - -def classify_health_failure(exc: BaseException | None) -> str: - """Classify one failed provider attempt for the observed-health ledger. - - Returns ``"slow_transport"`` or ``"fast"``. The class only changes how - much one failure weighs and how long a resulting quarantine lasts; it - never authorizes a retry or replay (that stays with the failure-boundary - classifiers in :mod:`contextual_orchestrator.tool_fallback`). - """ - if isinstance(exc, ProviderUpstreamError): - if ( - exc.error_code in _SLOW_HEALTH_ERROR_CODES - or exc.provider_status in _SLOW_HEALTH_PROVIDER_STATUSES - ): - return "slow_transport" - return "fast" - if isinstance(exc, urllib.error.HTTPError): - return "slow_transport" if exc.code in _SLOW_HEALTH_PROVIDER_STATUSES else "fast" - if isinstance( - exc, - ( - urllib.error.URLError, - TimeoutError, - ConnectionError, - socket.timeout, - http.client.HTTPException, - ), - ): - return "slow_transport" - return "fast" - - def _is_request_too_large_error(exc: BaseException) -> bool: """Recognize request-size rejection through a bounded exception chain.""" current: BaseException | None = exc @@ -5364,14 +5270,14 @@ def load_decision_window(self, limit: int = 256) -> dict[str, Any]: diagnostics = [] if request_ids: placeholders = ",".join("?" for _ in request_ids) - phases = self._conn.execute( # nosemgrep: python.sqlalchemy.security.sqlalchemy-execute-raw-query.sqlalchemy-execute-raw-query -- only "?" placeholders are concatenated; every value is bound + phases = self._conn.execute( "SELECT kind, key, payload FROM orchestration_records " "WHERE kind IN ('initial_decision', 'decision_receipt') " "AND key IN (" + placeholders + ") " "ORDER BY seq DESC LIMIT ?", (*request_ids, 2 * limit + 1), ).fetchall() - diagnostics = self._conn.execute( # nosemgrep: python.sqlalchemy.security.sqlalchemy-execute-raw-query.sqlalchemy-execute-raw-query -- only "?" placeholders are concatenated; every value is bound + diagnostics = self._conn.execute( "SELECT kind, key, payload FROM orchestration_records " "WHERE kind IN ('provider_dispatch', 'auxiliary_dispatch') " "AND key IN (" + placeholders + ") ORDER BY seq DESC LIMIT ?", @@ -5629,7 +5535,6 @@ def __init__( token_counter: Any = None, rate_limit_wait_seconds: float = 30.0, rate_limit_unknown_cooldown_seconds: float = 5.0, - observed_health_quarantine: bool | None = None, ) -> None: self._assistant_message_local = threading.local() self._output_budget_local = threading.local() @@ -5750,45 +5655,6 @@ def __init__( self._provider_readiness_lock = threading.Lock() self.circuit_failure_threshold = 3 self.circuit_reset_seconds = 30.0 - # Observed-outcome health ledger layered on the breaker above (see - # docs/doctoring/observed-health-quarantine.md). Explicit operator - # opt-in: the product-technical-gap-baseline no-heuristics boundary - # (2026-09-07) keeps automatic exclusion at the legacy 3/30 policy - # unless an operator enables this. When False, every knob below is - # inert and the breaker behaves exactly as before. In-memory only: a - # process restart starts every member unquarantined. A slow-class - # failure weighs slow_failure_weight toward the threshold and, once it - # trips, cools down for slow_failure_cooldown_seconds -- longer than - # the longest observed slow failure (302.3 s), unlike - # circuit_reset_seconds; the replay sweep (300/360/450/600/1200 s) is - # in the runbook. A half-open failure doubles the cooldown up to - # circuit_max_cooldown_seconds; nothing is excluded permanently. - # These are breaker knobs only: no timeout, retry or 413/429 policy. - # One deployable switch: an explicit constructor boolean wins; - # otherwise the KV setting OBSERVED_HEALTH_QUARANTINE_SETTING is read - # once here (KV, not env). Unset means off (legacy 3/30). - ( - self.observed_health_quarantine, - self.observed_health_quarantine_source, - ) = _resolve_observed_health_quarantine(observed_health_quarantine) - self._circuit_health: dict[str, dict[str, Any]] = {} - self._circuit_clock: Callable[[], float] | None = None - self.slow_failure_weight = 2.0 - self.slow_failure_cooldown_seconds = 360.0 - self.circuit_max_cooldown_seconds = 3600.0 - self.circuit_failure_window = 10 - self.circuit_failure_rate_min_observations = 6 - self.circuit_failure_rate_threshold = 0.6 - # Startup audit line: which breaker policy this process serves with - # (the review sidecar logs at DEBUG, so it lands in the CI artifact). - _LOGGER.info( - "observed_health_quarantine enabled=%s source=%s setting=%s " - "slow_failure_cooldown_seconds=%s", - self.observed_health_quarantine, - self.observed_health_quarantine_source, - OBSERVED_HEALTH_QUARANTINE_SETTING, - self.slow_failure_cooldown_seconds, - ) # Per-agent provider-declared quota cooldown (Retry-After / x-ratelimit-reset*), # tracked separately from the health circuit breaker above: a 429 is quota # exhaustion, not a model health failure, so it must never trip or feed @@ -6286,9 +6152,7 @@ def proxy_completion( result = self.client.proxy_send(agent, endpoint, upstream) except Exception as exc: if _is_ambiguous_passthrough_transport_failure(exc): - self._record_failure( - agent.id, failure_class=classify_health_failure(exc) - ) + self._record_failure(agent.id) if agent.group_name: self._group_router.observe_failure(agent.id) unknown = ProviderUpstreamError( @@ -6493,10 +6357,7 @@ def proxy_completion( # * Explicit concrete model: never reaches this # multi-candidate loop; kept as defense in depth # with the typed ``provider_outcome_unknown``. - self._record_failure( - candidate.id, - failure_class=classify_health_failure(exc), - ) + self._record_failure(candidate.id) if candidate.group_name: self._group_router.observe_failure(candidate.id) attempt_receipts.append( @@ -6592,10 +6453,7 @@ def proxy_completion( or (rate_limit_signal is not None and rate_limit_signal[0] == 429) ) if not skip_breaker: - self._record_failure( - candidate.id, - failure_class=classify_health_failure(exc), - ) + self._record_failure(candidate.id) if candidate.group_name and not skip_breaker: self._group_router.observe_failure(candidate.id) continue @@ -7961,7 +7819,6 @@ def stream_route( decision = classify_provider_transport_failure(upstream.retryable) rate_limit_signal = self._rate_limited_provider_signal(upstream) if rate_limit_signal is not None: - # Same quota cooldown _invoke and passthrough record. signal_status, signal_http_error = rate_limit_signal self._record_rate_limit( agent.id, @@ -7971,9 +7828,7 @@ def stream_route( status=signal_status, ) if decision.circuit_failure and self._charges_breaker(upstream): - self._record_failure( - agent.id, failure_class=classify_health_failure(upstream) - ) + self._record_failure(agent.id) if decision.action is ToolFallbackAction.FAIL_CLOSED: raise upstream from None if not request_too_large: @@ -10475,7 +10330,7 @@ def _compute_triage_verdict(self, text: str) -> bool: ] if not candidates: return False - triage_agent = self._observed_health_order(candidates)[0] + triage_agent = candidates[0] messages: list[ChatMessage] = [ {"role": "system", "content": self.TRIAGE_SYSTEM_PROMPT}, {"role": "user", "content": text}, @@ -11160,7 +11015,7 @@ def attempt(agent: ModelAgent) -> EndpointAttempt[Any]: and exc.error_code == "model_not_found" ): excluded_agent_ids.add(agent.id) - self._record_failure(agent.id, failure_class="fast") + self._record_failure(agent.id) break # The primary chat call is a bounded, side-effect-free # model request, not a tool invocation: classify from @@ -11196,9 +11051,7 @@ def attempt(agent: ModelAgent) -> EndpointAttempt[Any]: retry_attempt += 1 self._record_tool_fallback(agent.id, decision, retry_attempt) if decision.circuit_failure and self._charges_breaker(exc): - self._record_failure( - agent.id, failure_class=classify_health_failure(exc) - ) + self._record_failure(agent.id) if self.tool_retry_backoff_seconds: retry_ceiling = min( self.tool_retry_backoff_seconds @@ -11213,9 +11066,7 @@ def attempt(agent: ModelAgent) -> EndpointAttempt[Any]: action = decision.action self._record_tool_fallback(agent.id, decision, retry_attempt) if decision.circuit_failure and self._charges_breaker(exc): - self._record_failure( - agent.id, failure_class=classify_health_failure(exc) - ) + self._record_failure(agent.id) if action is ToolFallbackAction.FAIL_CLOSED: raise ToolFallbackStoppedError(agent.id, decision) from None break @@ -11436,15 +11287,8 @@ def _failover_candidates( ] eligible = [agent for agent in ordered if not agent.disabled and role not in agent.provider_exclusions] healthy = [agent for agent in eligible if not self._circuit_open(agent.id)] - # Observed served-request health: demote members whose latest failure - # was slow or that await a half-open probe. If every eligible agent is - # circuit-open, still probe them (least-recently-failed first) rather - # than fail with no attempt. - healthy = ( - self._order_by_observed_health(healthy) - if healthy - else self._all_open_fallback(eligible) - ) + # If every eligible agent is circuit-open, still probe them rather than fail with no attempt. + healthy = healthy or eligible if skip_rate_limited: not_rate_limited = [ agent for agent in healthy if self._rate_limit_remaining(agent.id) is None @@ -11611,259 +11455,46 @@ def _served_tool_calls(response: Any, api_surface: str) -> list[Any] | None: else TaskOrchestrator._chat_response_tool_calls(response) ) - def _circuit_now(self) -> float: - """Return the breaker clock (monotonic unless a test injects one).""" - clock = self._circuit_clock - return clock() if clock is not None else time.monotonic() - - def _circuit_health_entry(self, agent_id: str) -> dict[str, Any]: - """Return (creating) one member's observed-health entry; caller holds the lock.""" - health = self._circuit_health.get(agent_id) - if health is None: - health = { - "score": 0.0, - "slow_streak": False, - "slow_trip": False, - "level": 0, - "half_open": False, - "open_count": 0, - "last_failure_at": None, - "last_failure_class": None, - "window": deque(maxlen=max(1, int(self.circuit_failure_window))), - } - self._circuit_health[agent_id] = health - return health - - def _circuit_cooldown(self, health: Mapping[str, Any] | None) -> float: - """Current cooldown: slow trips outlast one failing attempt; half-open failures double it.""" - if health is None or not self.observed_health_quarantine: - return float(self.circuit_reset_seconds) - base = ( - self.slow_failure_cooldown_seconds - if health["slow_trip"] - else self.circuit_reset_seconds - ) - return float( - min(base * (2.0 ** min(int(health["level"]), 16)), self.circuit_max_cooldown_seconds) - ) - def _circuit_open(self, agent_id: str) -> bool: with self._circuit_lock: state = self._circuit.get(agent_id) - if not state or not state["opened_at"]: + if not state or state["failures"] < self.circuit_failure_threshold: return False - health = self._circuit_health.get(agent_id) - cooldown = self._circuit_cooldown(health) - if self._circuit_now() - state["opened_at"] >= cooldown: + if time.monotonic() - state["opened_at"] >= self.circuit_reset_seconds: state["failures"] = 0.0 state["opened_at"] = 0.0 - if health is not None: - health["half_open"] = self.observed_health_quarantine - health["score"] = 0.0 - health["slow_streak"] = False reset_occurred = True else: reset_occurred = False if reset_occurred: if _LOGGER.isEnabledFor(logging.DEBUG): _LOGGER.debug("circuit_reset agent_id=%s", agent_id) - if not self.observed_health_quarantine: - return False - _LOGGER.info( - "circuit_half_open agent_id=%s cooldown_seconds=%s request_id=%s", - agent_id, - cooldown, - current_request_id() or "-", - ) return False return True - def _circuit_demoted(self, agent_id: str) -> bool: - """True while a member awaits its half-open probe or its latest failure was slow.""" - if not self.observed_health_quarantine: - return False - with self._circuit_lock: - health = self._circuit_health.get(agent_id) - return bool(health and (health["half_open"] or health["slow_streak"])) - - def _order_by_observed_health(self, agents: list[ModelAgent]) -> list[ModelAgent]: - """Stable-demote suspect members behind members with no recent slow failure.""" - demoted = {agent.id for agent in agents if self._circuit_demoted(agent.id)} - if not demoted: - return agents - return [a for a in agents if a.id not in demoted] + [ - a for a in agents if a.id in demoted - ] - - def _observed_health_order(self, agents: list[ModelAgent]) -> list[ModelAgent]: - """Order an auxiliary single-call pick (triage, judge) by observed health. - - These picks take the first ranked agent without the failover loop, so - with the opt-in quarantine they skip open members and try demoted - ones last (never-empty fallback). Flag off: unchanged legacy order. - """ - if not self.observed_health_quarantine or not agents: - return agents - healthy = [agent for agent in agents if not self._circuit_open(agent.id)] - if not healthy: - return self._all_open_fallback(agents) - return self._order_by_observed_health(healthy) - - def _all_open_fallback(self, agents: list[ModelAgent]) -> list[ModelAgent]: - """Never return an empty pool: order all-open members least-recently-failed first. - - With the quarantine disabled the legacy ranked order is kept; only - the fallback is logged. - """ - if not agents: - return agents - if not self.observed_health_quarantine: - _LOGGER.warning( - "circuit_all_open_fallback candidate_count=%d selected_agent_id=%s request_id=%s", - len(agents), - agents[0].id, - current_request_id() or "-", - ) - return agents - with self._circuit_lock: - last_failed = { - agent.id: (self._circuit_health.get(agent.id) or {}).get("last_failure_at") - for agent in agents - } - ordered = sorted( - agents, - key=lambda agent: -math.inf - if last_failed[agent.id] is None - else last_failed[agent.id], - ) - _LOGGER.warning( - "circuit_all_open_fallback candidate_count=%d selected_agent_id=%s request_id=%s", - len(ordered), - ordered[0].id, - current_request_id() or "-", - ) - return ordered - - def circuit_health_policy(self) -> dict[str, Any]: - """Audit view of the active breaker policy and where the switch came from.""" - return { - "observed_health_quarantine": self.observed_health_quarantine, - "source": self.observed_health_quarantine_source, - "setting_name": OBSERVED_HEALTH_QUARANTINE_SETTING, - "circuit_failure_threshold": self.circuit_failure_threshold, - "circuit_reset_seconds": float(self.circuit_reset_seconds), - "slow_failure_weight": float(self.slow_failure_weight), - "slow_failure_cooldown_seconds": float(self.slow_failure_cooldown_seconds), - "circuit_max_cooldown_seconds": float(self.circuit_max_cooldown_seconds), - "circuit_failure_window": int(self.circuit_failure_window), - "circuit_failure_rate_min_observations": int( - self.circuit_failure_rate_min_observations - ), - "circuit_failure_rate_threshold": float(self.circuit_failure_rate_threshold), - } - - def circuit_health_snapshot(self) -> dict[str, dict[str, Any]]: - """Bounded per-member breaker/health evidence (no prompt or provider text).""" - agents = {agent.id: agent for agent in self.candidates} - now = self._circuit_now() - snapshot: dict[str, dict[str, Any]] = {} - with self._circuit_lock: - for agent_id in sorted(set(self._circuit) | set(self._circuit_health)): - state = self._circuit.get(agent_id) or {"failures": 0.0, "opened_at": 0.0} - health = self._circuit_health.get(agent_id) - cooldown = self._circuit_cooldown(health) - window = list(health["window"]) if health else [] - remaining = 0.0 - if state["opened_at"]: - remaining = max(0.0, cooldown - (now - state["opened_at"])) - if state["opened_at"] and remaining > 0: - status = "open" - elif state["opened_at"] or (health and health["half_open"]): - status = "half_open" - else: - status = "closed" - agent = agents.get(agent_id) - snapshot[agent_id] = { - "state": status, - "model": agent.model if agent else None, - "provider": ( - agent.provider_name or self._infer_provider_name(agent.base_url) - if agent - else None - ), - "consecutive_failures": int(state["failures"]), - "weighted_score": float(health["score"]) if health else 0.0, - "last_failure_class": health["last_failure_class"] if health else None, - "cooldown_seconds": cooldown, - "remaining_seconds": round(remaining, 3), - "window_size": len(window), - "window_failure_rate": ( - round(sum(window) / len(window), 4) if window else None - ), - "open_count": int(health["open_count"]) if health else 0, - } - return snapshot - - def _record_failure(self, agent_id: str, *, failure_class: str | None = None) -> None: - """Record one failed attempt; ``failure_class`` comes from :func:`classify_health_failure`.""" - failure_class = failure_class or "unclassified" - enabled = self.observed_health_quarantine - slow = failure_class == "slow_transport" + def _record_failure(self, agent_id: str) -> None: opened = False - trigger = "" - cooldown = 0.0 with self._circuit_lock: - now = self._circuit_now() state = self._circuit.setdefault(agent_id, {"failures": 0.0, "opened_at": 0.0}) state["failures"] += 1.0 failures = state["failures"] - health = self._circuit_health_entry(agent_id) - health["score"] += self.slow_failure_weight if slow and enabled else 1.0 - health["slow_streak"] = health["slow_streak"] or slow - health["last_failure_at"] = now - health["last_failure_class"] = failure_class - window = health["window"] - window.append(True) - if not state["opened_at"]: - if enabled and health["half_open"]: - trigger = "half_open_failure" - elif health["score"] >= self.circuit_failure_threshold: - trigger = "consecutive" - elif ( - enabled - and len(window) >= self.circuit_failure_rate_min_observations - and sum(window) / len(window) >= self.circuit_failure_rate_threshold - ): - trigger = "failure_rate" - if trigger: - if health["half_open"]: - health["level"] += 1 - health["half_open"] = False - health["slow_trip"] = health["slow_trip"] or health["slow_streak"] - health["open_count"] += 1 - cooldown = self._circuit_cooldown(health) - # A zero clock reading would read as "closed"; keep it truthy. - state["opened_at"] = now or 1e-9 + if failures >= self.circuit_failure_threshold and not state["opened_at"]: + state["opened_at"] = time.monotonic() opened = True if _LOGGER.isEnabledFor(logging.DEBUG): _LOGGER.debug( - "circuit_failure agent_id=%s failures=%s threshold=%s failure_class=%s", + "circuit_failure agent_id=%s failures=%s threshold=%s", agent_id, failures, self.circuit_failure_threshold, - failure_class, ) if opened: _LOGGER.warning( - "circuit_opened agent_id=%s failures=%s threshold=%s reset_seconds=%s " - "failure_class=%s trigger=%s request_id=%s", + "circuit_opened agent_id=%s failures=%s threshold=%s reset_seconds=%s", agent_id, failures, self.circuit_failure_threshold, - cooldown, - failure_class, - trigger, - current_request_id() or "-", + self.circuit_reset_seconds, ) def _record_embedding_failure( @@ -11892,25 +11523,8 @@ def _record_embedding_failure( def _record_success(self, agent_id: str) -> None: with self._circuit_lock: cleared = self._circuit.pop(agent_id, None) - health = self._circuit_health_entry(agent_id) - recovered = bool(health["half_open"]) - health["score"] = 0.0 - health["slow_streak"] = False - health["half_open"] = False - # A closed breaker escalates from zero again. - health["level"] = 0 - health["slow_trip"] = False - if recovered: - health["window"].clear() - health["window"].append(False) if cleared is not None and _LOGGER.isEnabledFor(logging.DEBUG): _LOGGER.debug("circuit_cleared agent_id=%s", agent_id) - if recovered: - _LOGGER.info( - "circuit_recovered agent_id=%s request_id=%s", - agent_id, - current_request_id() or "-", - ) #: Statuses for which an absent Retry-After/x-ratelimit-reset* still #: records an assumed cooldown. Deliberately 429 only: 503 ("service @@ -12238,14 +11852,7 @@ def _rate_limited_provider_signal( return None def _charges_breaker(self, exc: BaseException) -> bool: - """Whether a failed attempt counts against member health. - - A provider 429 is quota capacity, not model health: it records only - the quota cooldown (:meth:`_record_rate_limit`) and never feeds the - breaker or the observed-health ledger -- the passthrough loop's - ``skip_breaker`` rule, shared by ``_invoke`` and ``stream_route``. - A 503 stays an availability failure. - """ + """Return false when provider quota, rather than member health, failed.""" signal = self._rate_limited_provider_signal(exc) return signal is None or signal[0] != 429 @@ -12354,9 +11961,7 @@ def _model_judge_verification( try: judge = next( agent - for agent in self._observed_health_order( - self._ranked_agents(task, "verifier", free_only=free_only) - ) + for agent in self._ranked_agents(task, "verifier", free_only=free_only) if allowed_agent_ids is None or agent.id in allowed_agent_ids if excluded_agent_ids is None or agent.id not in excluded_agent_ids ) @@ -19459,8 +19064,6 @@ def admin_state( "routing_evidence": { "transport": self._group_router.snapshot(), "quality": self._quality_router.snapshot(), - "health": self.circuit_health_snapshot(), - "health_policy": self.circuit_health_policy(), }, "recent_workflow_runs": [ self._shorten_run(run) diff --git a/contextual_orchestrator/review_gateway.py b/contextual_orchestrator/review_gateway.py index 8b481a82b..219341bb7 100644 --- a/contextual_orchestrator/review_gateway.py +++ b/contextual_orchestrator/review_gateway.py @@ -27,7 +27,7 @@ discover_all_models, general_free_serving_candidates, ) -from .orchestrator import OBSERVED_HEALTH_QUARANTINE_SETTING, ModelClient, TaskOrchestrator +from .orchestrator import ModelClient, TaskOrchestrator from .provider_bootstrap import PROVIDER_ACCEPTED_CREDENTIAL_NAMES from .server import SecurityConfig, serve from .tool_fallback import MAX_TOOL_RETRY_ATTEMPTS @@ -170,12 +170,6 @@ def register_review_credentials( if auth_value and auth_value.strip(): register_credential(REVIEW_AUTH_CREDENTIAL_NAME, auth_value) registered.append(REVIEW_AUTH_CREDENTIAL_NAME) - # Operator opt-in breaker switch (not a credential): bootstrap transport - # only; TaskOrchestrator reads and validates it from the KV at startup. - switch_value = environment.get(OBSERVED_HEALTH_QUARANTINE_SETTING, "") - if isinstance(switch_value, str) and switch_value.strip(): - register_credential(OBSERVED_HEALTH_QUARANTINE_SETTING, switch_value.strip()) - registered.append(OBSERVED_HEALTH_QUARANTINE_SETTING) return tuple(registered) diff --git a/docs/doctoring/observed-health-quarantine-replay-include-429.json b/docs/doctoring/observed-health-quarantine-replay-include-429.json deleted file mode 100644 index 3c6f4be22..000000000 --- a/docs/doctoring/observed-health-quarantine-replay-include-429.json +++ /dev/null @@ -1,30 +0,0 @@ -{ - "demote_skips": 160.0, - "demotion": true, - "deployed_circuit_opened": 66.0, - "deployed_opened_with_429_in_streak": 11.0, - "episodes_with_429_in_streak": 5.0, - "exclude_429": false, - "false_positive_episodes": 1.0, - "forced_fallback_attempts": 15.0, - "harmful_removals": 1.0, - "harmful_removals_after_slow_transport": 1.0, - "harmful_requests": 1.0, - "include_preflight": false, - "policy_overrides": { - "observed_health_quarantine": true - }, - "quarantine_episodes": 37.0, - "quarantine_skips": 10.0, - "runs": 101, - "saved_failed_seconds": 36831.6, - "saved_failed_seconds_after_fast": 490.1, - "saved_failed_seconds_after_slow_transport": 36341.5, - "saved_failed_seconds_by_demote_skip": 35205.8, - "saved_failed_seconds_by_quarantine_skip": 1625.8, - "saved_slow_failure_seconds": 36319.6, - "served_429_charged": 117.0, - "served_attempts": 1627.0, - "served_failed_seconds": 111064.9, - "served_slow_failure_seconds": 100261.0 -} diff --git a/docs/doctoring/observed-health-quarantine-replay-preflight-whatif.json b/docs/doctoring/observed-health-quarantine-replay-preflight-whatif.json deleted file mode 100644 index 12f159627..000000000 --- a/docs/doctoring/observed-health-quarantine-replay-preflight-whatif.json +++ /dev/null @@ -1,29 +0,0 @@ -{ - "demote_skips": 130.0, - "demotion": true, - "deployed_circuit_opened": 66.0, - "deployed_opened_with_429_in_streak": 11.0, - "exclude_429": true, - "false_positive_episodes": 1.0, - "forced_fallback_attempts": 10.0, - "harmful_removals": 1.0, - "harmful_removals_after_slow_transport": 1.0, - "harmful_requests": 1.0, - "include_preflight": true, - "policy_overrides": { - "observed_health_quarantine": true - }, - "quarantine_episodes": 46.0, - "quarantine_skips": 10.0, - "runs": 101, - "saved_failed_seconds": 36827.5, - "saved_failed_seconds_after_fast": 486.0, - "saved_failed_seconds_after_slow_transport": 36341.5, - "saved_failed_seconds_by_demote_skip": 35201.7, - "saved_failed_seconds_by_quarantine_skip": 1625.8, - "saved_slow_failure_seconds": 36319.6, - "served_429_charged": 144.0, - "served_attempts": 1627.0, - "served_failed_seconds": 111064.9, - "served_slow_failure_seconds": 100261.0 -} diff --git a/docs/doctoring/observed-health-quarantine-replay-served.json b/docs/doctoring/observed-health-quarantine-replay-served.json deleted file mode 100644 index 191a80ea9..000000000 --- a/docs/doctoring/observed-health-quarantine-replay-served.json +++ /dev/null @@ -1,29 +0,0 @@ -{ - "demote_skips": 130.0, - "demotion": true, - "deployed_circuit_opened": 66.0, - "deployed_opened_with_429_in_streak": 11.0, - "exclude_429": true, - "false_positive_episodes": 1.0, - "forced_fallback_attempts": 10.0, - "harmful_removals": 1.0, - "harmful_removals_after_slow_transport": 1.0, - "harmful_requests": 1.0, - "include_preflight": false, - "policy_overrides": { - "observed_health_quarantine": true - }, - "quarantine_episodes": 32.0, - "quarantine_skips": 10.0, - "runs": 101, - "saved_failed_seconds": 36827.5, - "saved_failed_seconds_after_fast": 486.0, - "saved_failed_seconds_after_slow_transport": 36341.5, - "saved_failed_seconds_by_demote_skip": 35201.7, - "saved_failed_seconds_by_quarantine_skip": 1625.8, - "saved_slow_failure_seconds": 36319.6, - "served_429_charged": 144.0, - "served_attempts": 1627.0, - "served_failed_seconds": 111064.9, - "served_slow_failure_seconds": 100261.0 -} diff --git a/docs/doctoring/observed-health-quarantine-sidecar-synthetic.json b/docs/doctoring/observed-health-quarantine-sidecar-synthetic.json deleted file mode 100644 index ed28031d7..000000000 --- a/docs/doctoring/observed-health-quarantine-sidecar-synthetic.json +++ /dev/null @@ -1,248 +0,0 @@ -{ - "kv": { - "circuit_opened_lines": 0, - "health_policy": { - "circuit_failure_rate_min_observations": 6, - "circuit_failure_rate_threshold": 0.6, - "circuit_failure_threshold": 3, - "circuit_failure_window": 10, - "circuit_max_cooldown_seconds": 3600.0, - "circuit_reset_seconds": 30.0, - "observed_health_quarantine": true, - "setting_name": "CONTEXTUAL_ORCHESTRATOR_OBSERVED_HEALTH_QUARANTINE", - "slow_failure_cooldown_seconds": 360.0, - "slow_failure_weight": 2.0, - "source": "kv" - }, - "label": "SYNTHETIC - fake in-process provider at 1/1000 time scale; not provider-real", - "mode": "kv", - "provider_calls_by_kind": { - "chat": 17, - "structured": 16, - "triage": 0 - }, - "requests": [ - { - "latency_ms": 412.1, - "provider_attempts": 5, - "slow_attempts": 1, - "status": 200 - }, - { - "latency_ms": 38.1, - "provider_attempts": 4, - "slow_attempts": 0, - "status": 200 - }, - { - "latency_ms": 38.0, - "provider_attempts": 4, - "slow_attempts": 0, - "status": 200 - }, - { - "latency_ms": 35.5, - "provider_attempts": 4, - "slow_attempts": 0, - "status": 200 - }, - { - "latency_ms": 36.1, - "provider_attempts": 4, - "slow_attempts": 0, - "status": 200 - }, - { - "latency_ms": 33.1, - "provider_attempts": 4, - "slow_attempts": 0, - "status": 200 - }, - { - "latency_ms": 31.7, - "provider_attempts": 4, - "slow_attempts": 0, - "status": 200 - }, - { - "latency_ms": 31.3, - "provider_attempts": 4, - "slow_attempts": 0, - "status": 200 - } - ], - "slow_calls_by_kind": { - "chat": 1, - "structured": 0, - "triage": 0 - }, - "slow_seconds": 0.265, - "total_latency_ms": 655.9, - "total_provider_attempts": 33, - "total_slow_attempts": 1 - }, - "off": { - "circuit_opened_lines": 1, - "health_policy": { - "circuit_failure_rate_min_observations": 6, - "circuit_failure_rate_threshold": 0.6, - "circuit_failure_threshold": 3, - "circuit_failure_window": 10, - "circuit_max_cooldown_seconds": 3600.0, - "circuit_reset_seconds": 30.0, - "observed_health_quarantine": false, - "setting_name": "CONTEXTUAL_ORCHESTRATOR_OBSERVED_HEALTH_QUARANTINE", - "slow_failure_cooldown_seconds": 360.0, - "slow_failure_weight": 2.0, - "source": "default" - }, - "label": "SYNTHETIC - fake in-process provider at 1/1000 time scale; not provider-real", - "mode": "off", - "provider_calls_by_kind": { - "chat": 19, - "structured": 16, - "triage": 0 - }, - "requests": [ - { - "latency_ms": 1339.2, - "provider_attempts": 5, - "slow_attempts": 3, - "status": 200 - }, - { - "latency_ms": 834.7, - "provider_attempts": 5, - "slow_attempts": 3, - "status": 200 - }, - { - "latency_ms": 835.8, - "provider_attempts": 5, - "slow_attempts": 3, - "status": 200 - }, - { - "latency_ms": 560.8, - "provider_attempts": 4, - "slow_attempts": 2, - "status": 200 - }, - { - "latency_ms": 563.0, - "provider_attempts": 4, - "slow_attempts": 2, - "status": 200 - }, - { - "latency_ms": 556.8, - "provider_attempts": 4, - "slow_attempts": 2, - "status": 200 - }, - { - "latency_ms": 556.1, - "provider_attempts": 4, - "slow_attempts": 2, - "status": 200 - }, - { - "latency_ms": 554.3, - "provider_attempts": 4, - "slow_attempts": 2, - "status": 200 - } - ], - "slow_calls_by_kind": { - "chat": 3, - "structured": 16, - "triage": 0 - }, - "slow_seconds": 0.265, - "total_latency_ms": 5800.7, - "total_provider_attempts": 35, - "total_slow_attempts": 19 - }, - "on": { - "circuit_opened_lines": 0, - "health_policy": { - "circuit_failure_rate_min_observations": 6, - "circuit_failure_rate_threshold": 0.6, - "circuit_failure_threshold": 3, - "circuit_failure_window": 10, - "circuit_max_cooldown_seconds": 3600.0, - "circuit_reset_seconds": 30.0, - "observed_health_quarantine": true, - "setting_name": "CONTEXTUAL_ORCHESTRATOR_OBSERVED_HEALTH_QUARANTINE", - "slow_failure_cooldown_seconds": 360.0, - "slow_failure_weight": 2.0, - "source": "argument" - }, - "label": "SYNTHETIC - fake in-process provider at 1/1000 time scale; not provider-real", - "mode": "on", - "provider_calls_by_kind": { - "chat": 17, - "structured": 16, - "triage": 0 - }, - "requests": [ - { - "latency_ms": 445.1, - "provider_attempts": 5, - "slow_attempts": 1, - "status": 200 - }, - { - "latency_ms": 29.4, - "provider_attempts": 4, - "slow_attempts": 0, - "status": 200 - }, - { - "latency_ms": 33.1, - "provider_attempts": 4, - "slow_attempts": 0, - "status": 200 - }, - { - "latency_ms": 30.8, - "provider_attempts": 4, - "slow_attempts": 0, - "status": 200 - }, - { - "latency_ms": 27.1, - "provider_attempts": 4, - "slow_attempts": 0, - "status": 200 - }, - { - "latency_ms": 32.2, - "provider_attempts": 4, - "slow_attempts": 0, - "status": 200 - }, - { - "latency_ms": 30.9, - "provider_attempts": 4, - "slow_attempts": 0, - "status": 200 - }, - { - "latency_ms": 30.4, - "provider_attempts": 4, - "slow_attempts": 0, - "status": 200 - } - ], - "slow_calls_by_kind": { - "chat": 1, - "structured": 0, - "triage": 0 - }, - "slow_seconds": 0.265, - "total_latency_ms": 659.0, - "total_provider_attempts": 33, - "total_slow_attempts": 1 - } -} \ No newline at end of file diff --git a/docs/doctoring/observed-health-quarantine.md b/docs/doctoring/observed-health-quarantine.md deleted file mode 100644 index 84d5bafd1..000000000 --- a/docs/doctoring/observed-health-quarantine.md +++ /dev/null @@ -1,500 +0,0 @@ ---- -title: "Observed-outcome health quarantine for served-request candidate selection" -status: "Proposed (operator opt-in; default off)" -date: "2026-09-22" -scope: "feat/observed-health-quarantine (base origin/main 5665b0ad)" ---- - -# Observed-outcome health quarantine - -## Problem (measured, biased sample) - -Evidence source (read-only, not committed): the sanitized Noema sidecar -artifacts under -`CO-LEAD-EVIDENCE-20260920/research-support-20260921/noema-real-path-measurement-20260922/` -in the lead workspace. There are 101 runs from 8 repositories. Twelve runs sit -under the hidden `.github/` directory, which the evidence directory's own -scripts skip, so its `summary.txt` covers 89 runs. The deployed pin was -`767e67f`. **The upload step ran on `failure()` only, so this sample -over-represents failed runs; none of the numbers below are population rates.** - -- Served review requests: p50 1670 s, p90 4567 s. -- RemoteDisconnected (p50 265 s) and HTTP 504 (p50 302 s) make up about 94 % - of failed-attempt wall time. -- Within a single run, the same agent slow-failed again on 165 extra attempts - across 36 runs. Most of these were NVIDIA NIM `deepseek-v4-flash-0731` (both - accounts), `llama-3.2-90b-vision-instruct` and `gemma-4-31b-it`. -- The legacy breaker opens after three unweighted consecutive failures. Its - `circuit_reset_seconds = 30` is shorter than one ~300 s failing attempt, and - the reset zeroes the counter. This is the second and third gap recorded in - `docs/product-technical-gap-baseline.md` (2026-09-06 amendment). - -## Policy boundary: explicit operator opt-in - -`docs/product-technical-gap-baseline.md` (no-heuristics boundary, 2026-09-07) -keeps automatic candidate exclusion at the legacy 3/30 policy unless an -operator supplies the decision. This change therefore ships the mechanism -behind one operator switch, which is **off by default**: the KV setting -`CONTEXTUAL_ORCHESTRATOR_OBSERVED_HEALTH_QUARANTINE` (see "Activation switch" -below), or an explicit `TaskOrchestrator(observed_health_quarantine=...)` -argument, which wins over the KV value. - -With the flag off (the default, and what the sidecar runs today), the breaker -is behavior-identical to the legacy one: weight 1, a 30 s reset that zeroes -the counter, no failure-rate trigger, no half-open state and no demotion. The -only additions are observability: extra `circuit_opened` fields, the -`circuit_all_open_fallback` log line and the `routing_evidence.health` -snapshot. - -The values below are repository-proposed and backed only by the replay and -synthetic measurement in this document. **The 360 s slow cooldown is an -experimental candidate supported by the 101-artifact replay (biased toward -failed runs), not a validated production constant.** Enabling the switch is -an owner decision. #1000, #911 and #1082 still own the broader routing repair. - -## Design (flag on) - -The breaker ledger already sits in front of candidate selection: -`_failover_candidates` filters with `_circuit_open` before any attempt. The -mechanism therefore extends that ledger rather than adding a second breaker. - -| Concern | Behavior | -| --- | --- | -| Signal | Real served-request outcomes. Every existing `_record_failure` / `_record_success` call site feeds the ledger. Where the exception is in hand (`_invoke`, `stream_route`, and the explicit and virtual passthrough loops), the call passes `failure_class=classify_health_failure(exc)`. The launcher preflight is not duplicated. The two single-call picks outside the failover loop, auto-mode triage and the conduct model judge, use the same order when the switch is on: open members are skipped and demoted ones are tried last. | -| Failure class | `slow_transport`: `provider_timeout`, `provider_connection_error`, `provider_outcome_unknown` (how `ModelClient` wraps a dropped chat connection before `_invoke` sees it) or `model_timeout`; status 408/502/504; or a raw timeout, reset, `RemoteDisconnected` or `URLError`. `fast`: everything else. Call sites that pass no class count as `unclassified` with weight 1. 413 and provider 429 never reach the ledger on any chat path (route, stream, passthrough); 503 does. | -| Demotion | Once a member's latest failure is slow, `_failover_candidates` keeps it eligible but stable-sorts it behind members without a recent slow failure. The result of request N therefore changes the order for request N+1. A single failure never excludes a member. | -| Quarantine | The breaker opens when any of these holds: (a) the weighted consecutive score (slow = `slow_failure_weight` 2.0, else 1.0) reaches `circuit_failure_threshold` 3, which means two slow failures or three fast ones; (b) at least 6 of the last 10 outcomes are recorded and the failure rate is at least 0.6 (a single success no longer erases the evidence); (c) the half-open probe fails. | -| Cooldown | A trip that involved a slow failure lasts `slow_failure_cooldown_seconds` (360 s, longer than the longest observed slow failure of 302.3 s). A trip from fast failures only uses `circuit_reset_seconds` (30 s). Each half-open failure doubles the cooldown, capped at `circuit_max_cooldown_seconds` (3600 s). Any success resets the escalation level. Exclusion is never permanent. | -| Half-open / recovery | When the cooldown expires, the member becomes eligible again but stays demoted, so it is probed only after healthy members. A success clears the state and logs `circuit_recovered`. A failure re-opens the breaker immediately with the escalated cooldown. | -| Never empty | If every eligible member is open, `_failover_candidates` returns all of them, least-recently-failed first, and logs WARNING `circuit_all_open_fallback candidate_count=N selected_agent_id=... request_id=...`. With the flag off, the legacy ranked order is kept and only the log line is added. The embedding path's explicit 503 when all members are open (`_capability_agents`) is unchanged. However, the flag-on failure-rate and half-open triggers apply to every `_record_failure` caller, including `_record_embedding_failure`, `_record_race_attempt` and synthesis repair. | -| Metrics | WARNING `circuit_opened ... reset_seconds= failure_class=... trigger=consecutive|failure_rate|half_open_failure request_id=...`; INFO `circuit_half_open`, `circuit_recovered`; DEBUG `circuit_failure ... failure_class=...`. `circuit_health_snapshot()` holds bounded per-member fields: state, model, provider, counts, class, cooldown, remaining, window rate and open count. It is exposed at `admin_state()["routing_evidence"]["health"]`; `test_measured_routing_evidence` pins the key set. No prompt text or provider body text is included. | -| Concurrency | All ledger reads and writes happen under `_circuit_lock`. Concurrent failures open the breaker exactly once (tested with 16 threads). | -| Restart | State is in memory only. After a process restart, every member starts unquarantined and undemoted. Each Noema sidecar is a fresh process, so learning is scoped to one run. | -| Unchanged | Model timeouts (the default null timeout stays), retry and replay authorization, 413 handling and model-policy defaults are all untouched. Provider 429 handling was aligned across paths (see the 429 section). The class only weights health; it never authorizes a retry. | - -Compatibility note: `_circuit_open` now tests `opened_at` instead of -`failures >= threshold`. With the flag off the two tests are equivalent, -because every failure weighs 1. `_circuit` entries keep their exact legacy -shape (`{"failures", "opened_at"}`). The new state lives in `_circuit_health`. - -## RED / GREEN - -- New contracts: `tests/test_observed_health_quarantine.py`, 10 tests. Nine - cover the enabled path; one pins that the default stays legacy 3/30. -- RED on unmodified `origin/main` `5665b0ad`: collection fails with - `ImportError: cannot import name 'classify_health_failure'`. To get a - behavioral RED, the import was removed and the original nine tests were - re-run: 9 failed. The key assertion was - `test_served_slow_failure_demotes_agent_for_the_next_request`: - `['slow_worker', 'steady_worker'] != ['steady_worker', 'slow_worker']`, - meaning request N+1 still tried the member that had just slow-failed. -- GREEN: `python3 -m pytest tests/test_observed_health_quarantine.py tests/test_measured_routing_evidence.py -q -W error`. -- Full `pytest tests` (non-strict) on base and head: the only difference was - `test_admin_state_exposes_both_routing_ledgers`, which pinned - `{"transport", "quality"}` and is updated for the additive `health` key. - A second full run also failed - `test_provider_error_taxonomy.py::test_invoke_preserves_final_classified_failure_across_candidates`. - That test is a wall-clock rate-limit-wait flake: it failed 1 of 4 - isolated runs on unmodified `origin/main` as well. The other 200 failures - and 31 errors are identical on `origin/main`. They are pre-existing: a - `cost_router` import error, `selection_design` KeyErrors, egress allowlist - and paper-inventory contracts. -- Flag-on behavior is exercised end to end over HTTP on all four served - paths. See "HTTP end-to-end (four paths)" below. -- `-W error` on the 13 neighbor suites: base and head are both nonclean (81 - and 82 failing ids in one run each, with different sets). The failures are - dominated by the pre-existing `_TemporaryFileCloser` and unclosed - `HTTPError` ResourceWarnings owned by the HTTP resource runbook (#1140). - They are not attributed to this change. - -## Replay - -`scripts/replay_health_quarantine.py` is kept under `scripts/` because that -is where the repository keeps runnable analysis. It replays each run through -a fresh `TaskOrchestrator`, running the same breaker code with an injected -clock set to the log timestamps. - -- **Pairing.** Each failure line is paired with the latest open attempt of the - same request and agent, as in `noema_phase.py`. On the 89 non-hidden runs - this reproduces the evidence summary's served failed seconds exactly - (92,186 s). -- **What feeds the ledger.** A served failure feeds the ledger only if the - deployed log shows the deployed path charged it, meaning a - `circuit_failure` line follows it. 413 is never charged. The deployed pin - charged served 429 on the `_invoke` path; `--legacy-like`/`--include-429` - replay that, while the default replay excludes 429 as current code does. -- **Forced attempts.** An attempt that started while the deployed breaker was - open (`circuit_opened` less than 30 s earlier, not cleared) was forced by - the never-empty fallback or by a pinned model. The replay never counts such - an attempt as skippable (`forced_fallback_attempts`). -- **Fidelity check.** With the flag off (`--legacy-like`), the replay skips - **0** attempts, and all 30 of its open-state hits coincide with forced - attempts. The check also runs the other way: the replayed `circuit_opened` - count matches the deployed log's count exactly in 99 of 101 runs. In total - the replay opens 64 times against 66 deployed; in the two differing runs - the replay opens one fewer time, so it errs conservative. The replay - therefore reproduces the deployed breaker. - -```bash -python3 scripts/replay_health_quarantine.py \ - --json docs/doctoring/observed-health-quarantine-replay-served.json -python3 scripts/replay_health_quarantine.py --include-preflight \ - --json docs/doctoring/observed-health-quarantine-replay-preflight-whatif.json -python3 scripts/replay_health_quarantine.py --include-429 \ - --json docs/doctoring/observed-health-quarantine-replay-include-429.json -python3 scripts/replay_health_quarantine.py --legacy-like # deployed default -python3 scripts/replay_health_quarantine.py --no-demotion -``` - -Results for all 101 runs, served requests only, flag on -(`observed-health-quarantine-replay-served.json`): - -| Metric | Value | -| --- | --- | -| Served attempts / failed seconds / slow-failure seconds | 1627 / 111,065 s / 100,261 s | -| Estimated failed seconds avoided | **36,832 s** (slow-class 36,320 s, about 36 % of served slow-failure seconds) | -| … by demotion (a member tried after a sibling that succeeded) | 35,206 s over 160 skipped attempts | -| … by quarantine exclusion | 1,626 s over 10 skipped attempts | -| Quarantine episodes | 37 (15 open-state hits were forced and not skipped) | -| False-positive episodes (the first attempt after opening would have succeeded) | **1** of 37 | -| Harmful removals (a skipped attempt was its step's eventual success) | **1** attempt in 1 request (upper bound) | - -Sensitivity to `slow_failure_cooldown_seconds`, flag on, all other settings -at their defaults: - -| Cooldown | Saved s | Quarantine skips | FP episodes | Harmful removals / requests | -| --- | --- | --- | --- | --- | -| 300 s | 36,832 | 10 | 1 | 1 / 1 | -| **360 s (proposed)** | 36,832 | 10 | 1 | 1 / 1 | -| 450 s | 37,090 | 13 | 2 | 3 / 3 | -| 600 s | 38,181 | 21 | 3 | 7 / 4 | -| 1200 s | 38,237 | 26 | 2 | 8 / 5 | - -Other variants: - -- `--no-demotion` saves 13,606 s but produces 129 episodes and 10 harmful - removals across 7 requests. Demotion is the main lever, and it also keeps - harm down. -- `--legacy-like` (the deployed default) saves 0 s by construction. - -Preflight what-if (`--include-preflight`): launcher preflight probes -(`request_id=-`) run inside the sidecar process but call `ModelClient` -directly. No preflight failure in the 101 logs was followed by a -`circuit_failure` line, so deployment does not feed them to the ledger. - -Feeding them anyway adds 24 episodes. Each one opens on the served failure -that follows a preflight slow failure: the preflight failure was strike one. -(Replayed `circuit_opened` lines show `request_id=-` only because the replay -sets no request context.) The savings do not change (36,832 s) for two -reasons. That served re-hit was itself not demote-skippable, because no -healthier sibling succeeded later in the same step. And no later served -attempt reached those members inside the cooldown. This is the unrecovered -`slow_s_on_preflight_known_bad` in the evidence `summary.txt`. - -### Counterfactual limits - -- A skipped attempt's outcome is never fed back into the policy, because the - gateway would not have observed it. -- Success durations are not logged, so a success is observed at the start of - its attempt. -- The replay cannot know which substitute the gateway would have tried after - an exclusion. It also cannot know whether a skip under the new policy would - instead have hit the all-open fallback. Harmful counts are therefore upper - bounds, and saved seconds ignore any substitute cost. -- A conducted request is split into failover steps, one ending at each - success. Demotion credit requires that a non-demoted, non-open sibling - succeeded later in the same step. -- The ceiling is within-run repetition only, because every run starts from a - fresh process. -- The sample is biased toward failed runs, and savings will be smaller on - healthy runs. None of this is customer-latency evidence until served - p50/p90 are re-measured on a deployed pin with the flag on. - -## HTTP end-to-end (four paths) - -`tests/test_observed_health_quarantine_http.py` runs the real server -(`build_server` and `POST /v1/chat/completions`) with -`observed_health_quarantine=True`. Agents are `mock://`; a controllable -in-process `ModelClient` fails the "down" agents with a slow-class 504 on -`chat`, `stream_chat` and `proxy_send_once`. Time comes from the breaker's -injected monotonic clock (`_circuit_clock`), so nothing sleeps. That clock is -patched rather than the global `time.monotonic`, so that rate-limit and -server threads keep real time. - -The four paths: - -- **route:** `mode=route`, which reaches `route_once`. -- **conduct:** `mode=conduct`. -- **stream:** `mode=route` with `stream=true`, which reaches `stream_route`. -- **proxy:** `orchestrator/auto` plus `response_format`. This is the only - `/v1/chat/completions` route into `proxy_completion` (it runs - `single_agent=False`, then conduct stages and structured synthesis - failover). A virtual selector with only `tools` is conducted instead; the - virtual passthrough loop is reached by direct callers. - -Each path is checked for: - -- (a) the next request after one slow failure does not call the demoted - member; -- (b1) after the cooldown, the half-open probe runs and recovers - (`circuit_half_open`, then `circuit_recovered`); -- (b2) a failed probe re-opens the breaker with twice the cooldown - (`trigger=half_open_failure`); -- (c) an all-open pool still serves, least-recently-failed first - (`circuit_all_open_fallback`). - -One extra test covers the auto-mode triage pick, and one pins that the flag -off keeps the legacy order. - -**RED at `56276d65`**, with the proxy case already on the structured path: -5 failed, 13 passed. The failures were: - -- `demotes[conduct]`, `demotes[proxy]`, `recovers[conduct]` and - `recovers[proxy]`. The conduct **model-judge** call - (`_model_judge_verification` picks the first ranked verifier) still went to - the demoted slow member. -- `test_auto_mode_triage_pick_follows_observed_health`. The auto-mode - **triage** call (`_compute_triage_verdict` picks `candidates[0]`) still went - to the demoted member. - -Both picks bypass `_failover_candidates`. The first draft, which used `tools` -for the proxy case, also failed `proxy` (b2) and (c), but those were conduct -behaviors reached through the wrong route and not a proxy defect. - -**Minimal fix:** `_observed_health_order()` is applied to those two single-call -picks and is a no-op when the flag is off. - -**GREEN:** the new files together (`test_observed_health_quarantine.py`, -`test_observed_health_quarantine_http.py`, `test_measured_routing_evidence.py`, -`test_review_gateway.py`, `test_rate_limit_breaker_asymmetry.py`) pass under -`-W error`. - -A second RED came from the sidecar measurement below. `ModelClient` wraps a -dropped chat connection as `provider_outcome_unknown` before `_invoke` sees -it, and the classifier called that `fast`. The failing assertion was -`test_wrapped_post_send_failures_stay_slow_class`: -`AssertionError: provider_outcome_unknown / assert 'fast' == 'slow_transport'`. -`provider_outcome_unknown` and `model_timeout` are now in the slow set. The -replay was unaffected, because it classifies the raw logged error types. - -## Synthetic sidecar-shaped measurement - -The deployed entrypoint is `ContextualWisdomLab/.github` -`scripts/ci/contextual_orchestrator_review_launcher.py` (read at `.github` -`origin/main` `e6334e229`; not modified). It calls -`configure_logging(DEBUG)` with the timestamped sidecar format, then -`register_review_credentials(os.environ)`, `ModelClient(...)`, -`TaskOrchestrator(agents, client=client)` and `serve(...)`. - -`scripts/measure_health_quarantine_sidecar.py` mirrors that construction in -one process per mode. Loopback egress is blocked, so the fake provider is -patched at `ModelClient._open_provider` on a reserved `.invalid` host. -Nothing leaves the process, and the real retry loop, logging, failover, -judge and breaker all run. - -- `slow_free_agent` has priority 10 and raises `RemoteDisconnected` after - 0.265 s, the evidence p50 of 265 s at a 1/1000 time scale. -- `steady_free_agent` has priority 1 and answers in 5 ms. - -The script sends 8 sequential `orchestrator/free` requests, each with a -distinct prompt, and parses `http_request latency_ms` and `provider_attempt` -lines from the DEBUG log. Output: -`observed-health-quarantine-sidecar-synthetic.json`. - -**This is synthetic and not provider-real.** It shows the policy's mechanical -effect on one fixed failure pattern, not customer latency. - -| Mode | Σ latency_ms (8 req) | Per request (ms) | Slow-agent calls (chat / judge) | provider_attempt lines | All 200 | -| --- | --- | --- | --- | --- | --- | -| off (default) | 5626.3 | 1113.5, 839.1, 842.5, 567.2, 571.3, 567.8, 560.2, 564.7 | 3 / 16 | 35 | yes | -| on (argument) | 705.1 | 475.6, 32.0, 32.1, 33.2, 31.8, 30.8, 34.0, 35.6 | 1 / 0 | 33 | yes | -| on (KV switch, launcher-identical construction) | 684.7 | 453.5, 30.3, 30.2, 31.9, 32.0, 34.5, 33.7, 38.6 | 1 / 0 | 33 | yes | - -With the flag off, the legacy breaker opened once (after the 3rd chat -failure), but the model judge kept picking the slow member: 2 structured -calls per request, 16 in total. The legacy judge pick ignores the breaker. -With the flag on, the slow member is hit once, then demoted for both the -failover loop and the judge. - -## Activation switch and consumer handoff - -**The one switch** is the KV (credential-registry) setting -`CONTEXTUAL_ORCHESTRATOR_OBSERVED_HEALTH_QUARANTINE`. -`TaskOrchestrator.__init__` reads it once with `get_credential`, following -the "KV, not env" rule. - -- `enabled`/`true`/`on`/`1` turns the quarantine on; `disabled`/`false`/`off`/`0` - turns it off. -- Unset means off, with source `default`. -- Any other value fails construction with a `ValueError`, so a typo cannot - silently pick a policy. -- If the KV is unreadable, the legacy policy is kept and a WARNING is logged - (source `kv_unavailable`). -- An explicit constructor boolean wins over the KV (source `argument`). - -`review_gateway.register_review_credentials()` is the bootstrap function the -launcher already imports. It copies the setting from the bootstrap -environment into the KV, in the same way it copies the gateway token. - -**Why it is deployable:** the launcher constructs -`TaskOrchestrator(agents, client=client)` without policy arguments and -already calls `register_review_credentials(os.environ)` before constructing. -Honoring the switch therefore needs no copied launcher code, only a pin bump -and one environment value. - -**Why it is auditable:** - -- At construction, every process logs INFO - `observed_health_quarantine enabled= source=default|kv|argument|kv_unavailable setting=... slow_failure_cooldown_seconds=...`. - The sidecar logs at DEBUG, so the line lands in the uploaded - `contextual-orchestrator-sidecar.stderr.log`. -- `admin_state()["routing_evidence"]["health_policy"]` reports the switch, - its source and every knob. -- `register_review_credentials` returns the setting name in its - `registered` tuple. - -This is covered by `test_kv_switch_is_the_single_deployable_activation_and_is_audited` -and `test_kv_switch_off_values_and_invalid_value_fail_closed`. - -**Consumer handoff** (for `ContextualWisdomLab/.github`; not done here): - -1. Bump `ORCHESTRATOR_PIN_SHA` to a merged commit that contains this change. -2. On the step that runs `scripts/ci/contextual_orchestrator_review_launcher.py` - (the sidecar step in `noema-review.yml`, and in `strix.yml` and - `opencode-review-dispatch.yml` if they adopt it), add one step env value: - `CONTEXTUAL_ORCHESTRATOR_OBSERVED_HEALTH_QUARANTINE: enabled`. - Use a repository variable (for example - `${{ vars.CO_OBSERVED_HEALTH_QUARANTINE || 'disabled' }}`) so the owner can - roll back without a code change. The value is a non-secret toggle. -3. Verify in the uploaded sidecar log that the startup line reads - `observed_health_quarantine enabled=True source=kv`. Then re-measure - served p50/p90 and slow-failure seconds against this runbook's baseline - before calling it an improvement. - -No launcher Python change is needed. - -## 429 policy (implemented on this branch) - -A provider 429 now records only the quota cooldown on every chat path: -`_invoke` and `stream_route` share `TaskOrchestrator._charges_breaker`, which -mirrors the passthrough `skip_breaker` rule. A 503 still charges the breaker. -`stream_route` previously recorded no quota cooldown at all; it now records -one. Model-group stability observation (`_group_router.observe_failure`) is -unchanged: `_invoke` and `stream_route` still observe a 429 there, while -passthrough skips it. That residual difference is out of scope here. - -Pinning regression: `tests/test_rate_limit_breaker_asymmetry.py`, one fixture -through route, stream and passthrough. For 429 it asserts the cooldown is -recorded, `_circuit` has no entry and the health ledger is empty. For 503 it -asserts exactly one breaker failure. RED at `b073b160`: route charged the -breaker (`failures == 1.0`) and stream recorded no cooldown. - -**Code before this change (`b073b160`), kept for the record:** - -- `_invoke` (`orchestrator.py` ~11137–11204) records the quota cooldown - (`if exc.provider_status in (429, 503): self._record_rate_limit(...)`). - It then classifies the error as - `decision = classify_provider_transport_failure(exc.retryable)`. A 429 is - `retryable=True`, and `tool_fallback.classify_provider_transport_failure` - returns `circuit_failure=True` for every retryable failure (the - `retryable` branch of `_decision(..., circuit_failure=True)`). So the - breaker is charged at `if decision.circuit_failure: self._record_failure(...)`. - The code comment there says "retry-classified failures always trip the - circuit". -- `stream_route` (~7961) follows the same pattern - (`classify_provider_transport_failure(upstream.retryable)` then - `_record_failure`), so a pre-byte stream 429 is charged as well. -- The virtual passthrough loop in `proxy_completion` (~6587–6592) sets - `skip_breaker = request_too_large or capability_mismatch or (rate_limit_signal is not None and rate_limit_signal[0] == 429)`. - A 429 is recorded only as a quota cooldown. - -**What pins each behavior:** - -- Passthrough: `tests/test_rate_limit_aware_admission.py::test_429_does_not_trip_circuit_breaker_but_503_still_does`, - and the constructor comment (~5793) stating that a 429 "must never trip or - feed `_circuit`". -- `_invoke`: no test asserts that a provider 429 charges the breaker. The - behavior follows only from `classify_provider_transport_failure`'s - contract. It contradicts the constructor comment and the gateway rule that - provider availability is transport evidence. -- `tests/test_orchestrator_dispatch_boundaries.py::test_invoke_retries_idempotent_rate_limits_with_circuit_and_backoff` - concerns a *tool* rate limit, and it clears on success. - -**Reproduction:** `tests/test_rate_limit_breaker_asymmetry.py` uses one -fixture. The first-ranked agent returns HTTP 429 with `Retry-After: 7` at -`ModelClient._open_provider`, and the second agent succeeds. The same pool -and messages go through `route_once` and through `proxy_completion`. - -- Both paths record the quota cooldown. -- `route_once` leaves `_circuit["first_agent"]["failures"] == 1.0`. -- `proxy_completion` leaves `"first_agent" not in _circuit`. - -**Replay quantification (101 artifacts):** - -- Served 429 attempts that the deployed path charged to the breaker (a - `circuit_failure` line follows): **144**. 12 more were not charged. -- Deployed log: **11 of 66** `circuit_opened` events (16.7 %) had a 429 in - the charged streak since the last clear/reset. -- Legacy replay (flag off): 64 episodes, 11 with a 429 in the streak. - Excluding 429 gives 53 episodes. -- Flag on: 37 episodes, 5 with a 429 in the streak - (`observed-health-quarantine-replay-include-429.json`). Excluding 429, as - current code does, gives 32 episodes - (`observed-health-quarantine-replay-served.json`). -- Estimated saved seconds: **36,831.6 s including 429 vs 36,827.5 s - excluding it (Δ 4.1 s)**. False-positive episodes are 1 vs 1, and harmful - removals 1 vs 1. Charged 429s are fast (p50 0.1 s), so skipping them saves - almost nothing, while each one moves a member toward the open state. - -**Arguments:** - -- *For counting 429 as health:* a member that is persistently throttled is - unavailable to this gateway, and a breaker trip moves traffic elsewhere - sooner. -- *Against:* - - 429 is account or quota capacity, not model correctness or endpoint - health. It is often shared by sibling models on the same key, so charging - one member mislabels the cause. - - The gateway already has a dedicated, provider-stated quota mechanism - (`_record_rate_limit`, `Retry-After`), and `_failover_candidates` already - skips cooling-down members. A breaker trip adds a second, unrelated - cooldown (30 s legacy; 30 s or more under the quarantine) on top of the - provider's own. - - AGENTS.md treats request-size 413 as never member health, and provider - uptime as transport evidence rather than quality. The same reasoning - keeps quota out of health. - - The two chat paths disagree today, so the same provider response has - different consequences depending on the request shape. - -**Decision (implemented above):** make `_invoke` and `stream_route` -match the passthrough path. Keep recording the 429 quota cooldown, but do not -call `_record_failure` for a provider 429. Leave 503 as a real availability -signal, as the passthrough path does. - -- Land it as its own PR with a RED on the fixture above, flipping the - `route_once` assertion. -- Check `test_tool_execution_fallback` and `test_rate_limit_aware_admission` - for storm-wait interactions. -- On this evidence the throughput effect is negligible (Δ 4.1 s over 101 - runs). The benefit is correctness and consistency, not speed. - -## Owner decisions / open questions - -1. Whether to set the switch in the review workflows. The default stays off - under the 2026-09-07 boundary. The consumer handoff is above. -2. The 360 s cooldown is an experimental candidate. The corrected sweep - shows 300–360 s dominating 600 s: slightly lower savings, but 1 harmful - removal instead of 7. This is tuned on a biased sample. -3. The 429 alignment is implemented; whether model-group stability should also skip 429 (as passthrough does) is open. -4. A persisted health ledger across restarts is not implemented, so the - gateway starts unquarantined. -5. With the flag off, the legacy judge pick still ignores the breaker. This - is shown in the synthetic measurement (16 judge calls to an already-open - member) and is left unchanged here. - -## Reference - -- J. Dean and L. A. Barroso, "The Tail at Scale," *Communications of the ACM* - 56(2), 2013, doi:10.1145/2408776.2408794 (already in `docs/papers/README.md`). - It motivates keeping slow replicas off the critical path. It does not - establish these weights or cooldowns, which rest only on the replay above. diff --git a/docs/product-technical-gap-baseline.md b/docs/product-technical-gap-baseline.md index ccb20c498..ace0be664 100644 --- a/docs/product-technical-gap-baseline.md +++ b/docs/product-technical-gap-baseline.md @@ -5722,16 +5722,6 @@ repository-authored values. #1000 owns the broad routing repair; #911's observations can remain evidence but are not by themselves a production policy. -**Amendment (2026-09-22): operator opt-in mechanism, default unchanged.** -The KV setting `CONTEXTUAL_ORCHESTRATOR_OBSERVED_HEALTH_QUARANTINE=enabled` -(or `TaskOrchestrator(observed_health_quarantine=True)`) adds failure-class -weighting, a cooldown longer than one slow attempt, a failure-rate window that -a single success cannot erase, a half-open probe, and demotion of members -whose last failure was slow. The default stays off, which is the legacy -3/30 policy, per the boundary above. Replay evidence, proposed values and the -enablement decision are in -[the observed-health runbook](doctoring/observed-health-quarantine.md). - ## 2026-09-12 Optimizer cardinality acceptance and calibration boundary Frozen `090b4ec841cfc78b45248b561f1cef6396b57429` rejects incomplete/extra @@ -7169,3 +7159,25 @@ keeps the value administrator-owned through `OrchestrationPolicy`, and adds `tests/test_paper_contracts.py::test_generated_plan_bound_comes_from_policy` (prompt and parser follow the policy value; default stays 6). Not established: an ablation of the bound itself, which belongs to the #568 equal-budget lane. + +## 2026-09-27 Observed-health admission authority — Proposed + +PR #1221 exposed an operator-activatable routing policy whose fixed weight, +failure-rate threshold, observation window, cooldown, exponential escalation, +and all-open ordering changed candidate admission without a released +mathematical, statistical, psychometric, standards-based, or experimentally +validated authority. An opt-in Boolean or KV value records intent, not evidence; +the failure-only sidecar replay is explicitly biased and cannot calibrate those +decisions. + +RED `ee58cb09` proves both supported activation surfaces remained reachable: +the constructor accepted `observed_health_quarantine=True`, and KV `enabled` +activated the same heuristic policy. The forward repair removes that +decision-affecting runtime surface and its replay artifacts instead of replacing +one arbitrary policy with another. The independent provider boundary remains: +HTTP 429 records quota cooldown evidence but never breaker health, while 503 +remains an availability failure. Focused authority and three-path HTTP status +contracts must be GREEN on the exact successor before review. A future health +policy requires immutable owner identity, executable calibration provenance, +validated sampling/failure denominators, and a versioned released contract; +until then activation fails closed. diff --git a/scripts/measure_health_quarantine_sidecar.py b/scripts/measure_health_quarantine_sidecar.py deleted file mode 100644 index bc50c8373..000000000 --- a/scripts/measure_health_quarantine_sidecar.py +++ /dev/null @@ -1,235 +0,0 @@ -"""Synthetic sidecar-shaped measurement of the observed-health quarantine. - -Mirrors the construction in ``ContextualWisdomLab/.github`` -``scripts/ci/contextual_orchestrator_review_launcher.py`` (read-only -reference): ``configure_logging`` at DEBUG with the sidecar timestamp format, -``register_review_credentials`` from a bootstrap mapping, a ``ModelClient`` -with the review sampling settings, ``TaskOrchestrator(agents, client=client)`` -and the real HTTP server. Loopback egress is blocked, so the provider is a -fake patched at the lowest transport seam (``ModelClient._open_provider``, -the pattern ``tests/test_ci_gateway_bootstrap.py`` uses) on a reserved -``.invalid`` host; the real retry loop, ``provider_attempt`` logging, -failover, judge and breaker all run and nothing leaves the process: - -* ``slow_free_agent`` drops the connection (``RemoteDisconnected``) after - ``--slow-seconds`` (the evidence p50 is 265 s; the default 0.265 s is a - 1/1000 time scale); -* ``steady_free_agent`` answers after ``--fast-seconds``. - -It sends ``--requests`` sequential ``orchestrator/free`` chat completions and -prints per-request ``http_request`` latency and ``provider_attempt`` counts -parsed from the process log. **Synthetic, not provider-real**: it measures the -policy's effect on this fixed failure pattern only. - -Usage:: - - python3 scripts/measure_health_quarantine_sidecar.py --mode off|on|kv [--requests 8] - -``on`` passes ``observed_health_quarantine=True``; ``kv`` constructs the -orchestrator exactly as the launcher does and seeds the KV switch through -``register_review_credentials`` instead. -""" - -from __future__ import annotations - -import argparse -import http.client -import io -import json -import logging -import re -import sys -import threading -import time -import urllib.request -from pathlib import Path -from typing import Any - -sys.path.insert(0, str(Path(__file__).resolve().parents[1])) - -from contextual_orchestrator import ModelAgent, TaskOrchestrator # noqa: E402 -from contextual_orchestrator.debug_logging import configure_logging # noqa: E402 -from contextual_orchestrator.orchestrator import ModelClient # noqa: E402 -from contextual_orchestrator.review_gateway import ( # noqa: E402 - REVIEW_AUTH_CREDENTIAL_NAME, - register_review_credentials, -) -from contextual_orchestrator.server import SecurityConfig, build_server # noqa: E402 - -SIDECAR_LOG_FORMAT = "%(asctime)s %(levelname)s %(name)s %(message)s" -SWITCH_NAME = "CONTEXTUAL_ORCHESTRATOR_OBSERVED_HEALTH_QUARANTINE" -_TOKEN = "synthetic_sidecar_measurement_token" -_TAGS = ("cost:free", "reasoning", "writing", "planning", "coding", "verification") -_HTTP = re.compile(r"http_request method=POST path=/v1/chat/completions status=(\d+) latency_ms=([\d.]+) .*request_id=(\w+)") -_ATTEMPT = re.compile(r"provider_attempt agent_id=(\S+) .* request_id=(\w+)") - - -class _FakeResponse: - """Minimal context-managed provider response (the shape ``_open_provider`` returns).""" - - def __init__(self, content: str) -> None: - self._body = json.dumps( - { - "id": "chatcmpl_synthetic", - "object": "chat.completion", - "created": 0, - "model": "synthetic", - "choices": [ - {"index": 0, "message": {"role": "assistant", "content": content}, "finish_reason": "stop"} - ], - "usage": {"prompt_tokens": 10, "completion_tokens": 5, "total_tokens": 15}, - } - ).encode("utf-8") - self.status = 200 - self.headers: dict[str, str] = {} - - def read(self, amount: int | None = None) -> bytes: - body, self._body = self._body, b"" - return body - - def getheader(self, name: str, default: str | None = None) -> str | None: - return default - - def close(self) -> None: - self._body = b"" - - def __enter__(self) -> "_FakeResponse": - return self - - def __exit__(self, *exc_info: object) -> bool: - self.close() - return False - - -def _fake_open_provider(slow_seconds: float, fast_seconds: float, seen: list[dict[str, Any]]): - """Return an ``_open_provider`` replacement; nothing leaves the process.""" - - def _open_provider(self, request, destination=None, *, timeout=None): - del self, destination, timeout - payload = json.loads(request.data.decode("utf-8")) if request.data else {} - model = payload.get("model", "") - messages = payload.get("messages") or [] - system = messages[0].get("content", "") if messages else "" - kind = ( - "triage" - if system == TaskOrchestrator.TRIAGE_SYSTEM_PROMPT - else "structured" if payload.get("response_format") else "chat" - ) - seen.append({"model": model, "kind": kind}) - if model == "vendor/slow-model": - time.sleep(slow_seconds) - raise http.client.RemoteDisconnected("synthetic remote end closed connection") - time.sleep(fast_seconds) - if kind == "triage": - return _FakeResponse('{"workflow_required": false}') - return _FakeResponse("synthetic review answer citing evidence, risks and caveats") - - return _open_provider - - -def run(mode: str, requests: int, slow_seconds: float, fast_seconds: float) -> dict[str, Any]: - """Serve one sidecar-shaped process, send the requests, return parsed metrics.""" - buffer = io.StringIO() - configure_logging("DEBUG") - root = logging.getLogger() - handler = logging.StreamHandler(buffer) - root.addHandler(handler) - for item in root.handlers: - item.setFormatter(logging.Formatter(SIDECAR_LOG_FORMAT)) - bootstrap = {"NVIDIA_NIM_API_KEY": "synthetic-not-a-key", REVIEW_AUTH_CREDENTIAL_NAME: _TOKEN} - if mode == "kv": - bootstrap[SWITCH_NAME] = "enabled" - register_review_credentials(bootstrap) - seen: list[dict[str, Any]] = [] - ModelClient._validate_provider = lambda self, agent: None - ModelClient._open_provider = _fake_open_provider(slow_seconds, fast_seconds, seen) - agents = [ - ModelAgent("slow_free_agent", "vendor/slow-model", base_url="https://provider.invalid/v1", - api_key_env="NVIDIA_NIM_API_KEY", tags=_TAGS, priority=10), - ModelAgent("steady_free_agent", "vendor/steady-model", base_url="https://provider.invalid/v1", - api_key_env="NVIDIA_NIM_API_KEY", tags=_TAGS, priority=1), - ] - client = ModelClient(max_output_tokens=2048, temperature=0.1) - kwargs = {"observed_health_quarantine": True} if mode == "on" else {} - orchestrator = TaskOrchestrator(agents, client=client, **kwargs) - server = build_server(orchestrator, port=0, security=SecurityConfig(auth_token=_TOKEN)) - thread = threading.Thread(target=server.serve_forever, daemon=True) - thread.start() - port = server.server_address[1] - try: - for index in range(requests): - body = { - "model": TaskOrchestrator.FREE_MODEL, - "messages": [{"role": "user", "content": f"review change set {index}"}], - } - request = urllib.request.Request( - f"http://127.0.0.1:{port}/v1/chat/completions", - data=json.dumps(body).encode("utf-8"), - headers={"content-type": "application/json", "authorization": f"Bearer {_TOKEN}"}, - method="POST", - ) - # nosemgrep: python.lang.security.audit.dynamic-urllib-use-detected.dynamic-urllib-use-detected - fixed http://127.0.0.1 scheme/host; the port is the ephemeral local server this script just started, never external input. - with urllib.request.urlopen(request, timeout=60) as response: - response.read() - finally: - server.shutdown() - thread.join(timeout=5) - server.server_close() - root.removeHandler(handler) - handler.close() - log = buffer.getvalue() - attempts: dict[str, list[str]] = {} - for line in log.splitlines(): - match = _ATTEMPT.search(line) - if match: - attempts.setdefault(match.group(2), []).append(match.group(1)) - rows = [] - for line in log.splitlines(): - match = _HTTP.search(line) - if match: - status, latency, request_id = match.groups() - tried = attempts.get(request_id, []) - rows.append( - { - "status": int(status), - "latency_ms": float(latency), - "provider_attempts": len(tried), - "slow_attempts": tried.count("slow_free_agent"), - } - ) - return { - "label": "SYNTHETIC - fake in-process provider at 1/1000 time scale; not provider-real", - "mode": mode, - "health_policy": orchestrator.admin_state()["routing_evidence"].get("health_policy"), - "slow_seconds": slow_seconds, - "requests": rows, - "total_latency_ms": round(sum(row["latency_ms"] for row in rows), 1), - "total_provider_attempts": sum(row["provider_attempts"] for row in rows), - "total_slow_attempts": sum(row["slow_attempts"] for row in rows), - "circuit_opened_lines": log.count("circuit_opened "), - "provider_calls_by_kind": { - kind: sum(1 for item in seen if item["kind"] == kind) - for kind in ("triage", "chat", "structured") - }, - "slow_calls_by_kind": { - kind: sum(1 for item in seen if item["kind"] == kind and item["model"] == "vendor/slow-model") - for kind in ("triage", "chat", "structured") - }, - } - - -def main(argv: list[str] | None = None) -> dict[str, Any]: - """Parse arguments, run one mode, print JSON.""" - parser = argparse.ArgumentParser(description=__doc__.splitlines()[0]) - parser.add_argument("--mode", choices=("off", "on", "kv"), required=True) - parser.add_argument("--requests", type=int, default=8) - parser.add_argument("--slow-seconds", type=float, default=0.265) - parser.add_argument("--fast-seconds", type=float, default=0.005) - args = parser.parse_args(argv) - result = run(args.mode, args.requests, args.slow_seconds, args.fast_seconds) - print(json.dumps(result, indent=2, sort_keys=True)) - return result - - -if __name__ == "__main__": - main() diff --git a/scripts/replay_health_quarantine.py b/scripts/replay_health_quarantine.py deleted file mode 100644 index ee4987919..000000000 --- a/scripts/replay_health_quarantine.py +++ /dev/null @@ -1,355 +0,0 @@ -"""Replay sanitized Noema sidecar logs through the observed-health breaker. - -Usage:: - - python3 scripts/replay_health_quarantine.py [--include-preflight] [--json OUT] - -```` holds ``//contextual-orchestrator-sidecar.stderr.log`` -files (the raw artifacts are evidence, not repository content; see -``docs/doctoring/observed-health-quarantine.md``). Each run is one sidecar -process, so each run replays against a fresh ``TaskOrchestrator`` -- the same -breaker code the gateway runs, driven by an injected clock set to the log -timestamps. Nothing here reaches a provider. - -Counterfactual limits (stated, not hidden): a skipped attempt's outcome is -never fed to the policy (the gateway would not have observed it); the -successful attempt's duration is not logged, so a success is observed at its -start time; the replay cannot model which substitute candidate the gateway -would have tried instead, so "harmful" counts are upper bounds. -""" - -from __future__ import annotations - -import argparse -import datetime as dt -import http.client -import json -import re -import sys -import urllib.error -from collections import defaultdict, deque -from pathlib import Path - -sys.path.insert(0, str(Path(__file__).resolve().parents[1])) - -from contextual_orchestrator import ModelAgent, TaskOrchestrator # noqa: E402 -from contextual_orchestrator.orchestrator import classify_health_failure # noqa: E402 - -_TS = r"(\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2},\d{3}) " -_ATTEMPT = re.compile(_TS + r"provider_attempt agent_id=(\S+) model=(\S+) attempt=\S+ request_id=(\S+)") -_FAILED = re.compile( - _TS + r"provider_attempt_failed agent_id=(\S+) model=\S+ attempt=\S+ " - r"error_type=(\S+) transient=\S+ provider_status=(\S+) request_id=(\S+)" -) -_CIRCUIT_FAILURE = re.compile(_TS + r"circuit_failure agent_id=(\S+)") -_CIRCUIT_EDGE = re.compile(_TS + r"circuit_(opened|cleared) agent_id=(\S+)") -#: Legacy reset window of the deployed pin: an attempt that started while -#: the deployed breaker was open was forced (all-open fallback or a pinned -#: model), so no breaker policy could have skipped it. -_DEPLOYED_RESET_SECONDS = 30.0 -#: Statuses the gateway never charges to member health (quota is tracked by -#: the rate-limit cooldown on the passthrough path; size is the request's). -_NEVER_HEALTH = {"413"} - - -def _epoch(stamp: str) -> float: - return dt.datetime.strptime(stamp, "%Y-%m-%d %H:%M:%S,%f").timestamp() - - -def _synthetic_failure(error_type: str, status: str) -> BaseException: - """Rebuild a bounded exception shape so the real classifier decides the class.""" - if error_type == "HTTPError" and status.isdigit(): - return urllib.error.HTTPError("https://replay.invalid", int(status), "replay", None, None) - if error_type == "RemoteDisconnected": - return http.client.RemoteDisconnected("replay") - if error_type == "ConnectionResetError": - return ConnectionResetError("replay") - if error_type in {"TimeoutError", "timeout"}: - return TimeoutError("replay") - return RuntimeError("replay") - - -def parse_run(path: Path) -> list[dict]: - """Pair each failure line with the latest open attempt of the same request/agent. - - Sequential roles reuse one agent inside one request, so an earlier open - attempt that never failed is a success (same pairing as the evidence - directory's noema_phase.py). - """ - attempts: list[dict] = [] - open_by_key: dict[tuple[str, str], deque[int]] = defaultdict(deque) - lines = path.read_text(errors="replace").splitlines() - deployed_open: dict[str, float | None] = {} - for index, line in enumerate(lines): - match = _ATTEMPT.match(line) - if match: - stamp, agent_id, model, request_id = match.groups() - attempts.append( - { - "start": _epoch(stamp), "end": None, "agent_id": agent_id, - "model": model, "request_id": request_id, "ok": True, - "error_type": None, "status": None, "recorded": True, - "forced": ( - deployed_open.get(agent_id) is not None - and _epoch(stamp) - deployed_open[agent_id] < _DEPLOYED_RESET_SECONDS - ), - } - ) - open_by_key[(request_id, agent_id)].append(len(attempts) - 1) - continue - edge = _CIRCUIT_EDGE.match(line) - if edge: - deployed_open[edge.group(3)] = ( - _epoch(edge.group(1)) if edge.group(2) == "opened" else None - ) - continue - match = _FAILED.match(line) - if not match: - continue - stamp, agent_id, error_type, status, request_id = match.groups() - queue = open_by_key.get((request_id, agent_id)) - if not queue: - continue - attempt = attempts[queue.pop()] - attempt.update(end=_epoch(stamp), ok=False, error_type=error_type, status=status) - # Did the deployed path charge this failure to the breaker? The - # deployed log prints circuit_failure right after a recorded failure. - following = lines[index + 1 : index + 4] - attempt["recorded"] = any( - (m := _CIRCUIT_FAILURE.match(item)) and m.group(2) == agent_id for item in following - ) - for attempt in attempts: - if attempt["end"] is None: - attempt["end"] = attempt["start"] - return attempts - - -def _assign_steps(attempts: list[dict]) -> None: - """Split each served request into failover steps, each ending at one success. - - A conducted request runs several roles (planner/worker/verifier/...), so - one request can hold several successes; the candidate chain that precedes - each success is one step. - """ - by_request: dict[str, list[dict]] = defaultdict(list) - for attempt in attempts: - by_request[attempt["request_id"]].append(attempt) - for request_id, items in by_request.items(): - step: list[dict] = [] - for attempt in sorted(items, key=lambda item: item["start"]): - attempt["step"] = step - step.append(attempt) - if attempt["ok"]: - step = [] - - -def replay_run( - attempts: list[dict], - *, - include_preflight: bool, - totals: dict, - policy: dict | None = None, - demotion: bool = True, - exclude_429: bool = False, -) -> None: - """Drive one fresh orchestrator through one run's attempts in time order. - - ``policy`` overrides breaker attributes (for sensitivity runs); - ``demotion=False`` ignores slow-failure demotion to isolate quarantine. - ``exclude_429=True`` mirrors current code: every chat path keeps a - provider 429 out of the breaker/ledger. The deployed pin (767e67f) - charged ``_invoke`` 429s, so ``--legacy-like`` and ``--include-429`` - replay with them included. - """ - agents = {} - for attempt in attempts: - agents.setdefault(attempt["agent_id"], ModelAgent(attempt["agent_id"], attempt["model"])) - orchestrator = TaskOrchestrator(list(agents.values())) - for name, value in (policy or {}).items(): - setattr(orchestrator, name, value) - clock = {"now": 0.0} - orchestrator._circuit_clock = lambda: clock["now"] - _assign_steps(attempts) - - def available(agent_id: str) -> bool: - return not orchestrator._circuit_open(agent_id) and not orchestrator._circuit_demoted( - agent_id - ) - - events = [] - for index, attempt in enumerate(attempts): - events.append((attempt["start"], 1, index)) - events.append((attempt["end"], 0 if not attempt["ok"] else 2, index)) - events.sort() - skipped: set[int] = set() - first_after_open: set[str] = set() - harmful_requests: set[str] = set() - streak_429: dict[str, bool] = {} - for stamp, kind, index in events: - clock["now"] = stamp - attempt = attempts[index] - served = attempt["request_id"] != "-" - agent_id = attempt["agent_id"] - if kind == 1: - if not served: - continue - totals["served_attempts"] += 1 - duration = attempt["end"] - attempt["start"] - slow = not attempt["ok"] and classify_health_failure( - _synthetic_failure(attempt["error_type"], attempt["status"]) - ) == "slow_transport" - if not attempt["ok"]: - totals["served_failed_seconds"] += duration - if slow: - totals["served_slow_failure_seconds"] += duration - probe_is_next = agent_id in first_after_open - first_after_open.discard(agent_id) - action = None - if orchestrator._circuit_open(agent_id): - if attempt["forced"]: - # The deployed breaker was already open and the attempt - # still ran: the never-empty fallback applies here too. - totals["forced_fallback_attempts"] += 1 - else: - action = "quarantine_skip" - elif demotion and orchestrator._circuit_demoted(agent_id) and any( - other["ok"] and other["agent_id"] != agent_id and available(other["agent_id"]) - for other in attempt["step"] - if other["start"] >= attempt["start"] - ): - action = "demote_skip" - if action is None: - continue - skipped.add(index) - totals[action + "s"] += 1 - trip_class = ( - orchestrator.circuit_health_snapshot()[agent_id]["last_failure_class"] - ) - if attempt["ok"]: - # The skipped attempt was this step's eventual success. - totals["harmful_removals"] += 1 - totals[f"harmful_removals_after_{trip_class}"] += 1 - harmful_requests.add(attempt["request_id"]) - if action == "quarantine_skip" and probe_is_next: - totals["false_positive_episodes"] += 1 - else: - totals["saved_failed_seconds"] += duration - if slow: - totals["saved_slow_failure_seconds"] += duration - totals[f"saved_failed_seconds_after_{trip_class}"] += duration - totals[f"saved_failed_seconds_by_{action}"] += duration - continue - if index in skipped or (not served and not include_preflight): - continue - if attempt["ok"]: - orchestrator._record_success(agent_id) - streak_429[agent_id] = False - continue - if attempt["status"] in _NEVER_HEALTH: - continue - if served and attempt["status"] == "429" and attempt["recorded"]: - totals["served_429_charged"] += 1 - if exclude_429: - continue - if served and not attempt["recorded"]: - continue # the deployed path did not charge it to the breaker - before = orchestrator.circuit_health_snapshot().get(agent_id, {}).get("open_count", 0) - orchestrator._record_failure( - agent_id, - failure_class=classify_health_failure( - _synthetic_failure(attempt["error_type"], attempt["status"]) - ), - ) - streak_429[agent_id] = streak_429.get(agent_id, False) or attempt["status"] == "429" - if orchestrator.circuit_health_snapshot()[agent_id]["open_count"] > before: - totals["quarantine_episodes"] += 1 - if streak_429[agent_id]: - totals["episodes_with_429_in_streak"] += 1 - streak_429[agent_id] = False - first_after_open.add(agent_id) - if not served: - totals["preflight_triggered_episodes"] += 1 - totals["harmful_requests"] += len(harmful_requests) - - -def deployed_429_opens(path: Path) -> dict[str, int]: - """Count deployed ``circuit_opened`` events whose charged streak held a 429. - - Reads the deployed (legacy 3/30) log itself, independent of the replay: - the charged failures for an agent since its last clear/reset/open. - """ - streak: dict[str, list[str]] = defaultdict(list) - last_status: dict[str, str] = {} - counts = {"deployed_circuit_opened": 0, "deployed_opened_with_429_in_streak": 0} - for line in path.read_text(errors="replace").splitlines(): - failed = _FAILED.match(line) - if failed: - last_status[failed.group(2)] = failed.group(4) - continue - charged = _CIRCUIT_FAILURE.match(line) - if charged: - streak[charged.group(2)].append(last_status.get(charged.group(2), "?")) - continue - edge = re.match(_TS + r"circuit_(opened|cleared|reset) agent_id=(\S+)", line) - if edge: - agent_id = edge.group(3) - if edge.group(2) == "opened": - counts["deployed_circuit_opened"] += 1 - if "429" in streak[agent_id]: - counts["deployed_opened_with_429_in_streak"] += 1 - streak[agent_id] = [] - return counts - - -def main(argv: list[str] | None = None) -> dict: - """Replay every run under ``artifacts_dir`` and print one bounded JSON summary.""" - parser = argparse.ArgumentParser(description=__doc__.splitlines()[0]) - parser.add_argument("artifacts_dir", type=Path) - parser.add_argument("--include-preflight", action="store_true") - parser.add_argument("--json", type=Path) - parser.add_argument("--no-demotion", action="store_true") - parser.add_argument( - "--include-429", - action="store_true", - help="charge served 429s as the deployed pin did (default: excluded, as current code)", - ) - parser.add_argument( - "--legacy-like", - action="store_true", - help="baseline: the deployed default (quarantine opt-in off, legacy 3/30)", - ) - args = parser.parse_args(argv) - logs = sorted(args.artifacts_dir.glob("*/*/contextual-orchestrator-sidecar.stderr.log")) - totals: dict = defaultdict(float) - policy = {"observed_health_quarantine": not args.legacy_like} - demotion = not (args.no_demotion or args.legacy_like) - exclude_429 = not (args.include_429 or args.legacy_like) - for path in logs: - replay_run( - parse_run(path), - include_preflight=args.include_preflight, - totals=totals, - policy=policy, - demotion=demotion, - exclude_429=exclude_429, - ) - deployed = deployed_429_opens(path) - for key, value in deployed.items(): - totals[key] += value - summary = { - "runs": len(logs), - "include_preflight": args.include_preflight, - "demotion": demotion, - "policy_overrides": policy, - "exclude_429": exclude_429, - **{key: round(value, 1) for key, value in sorted(totals.items())}, - } - text = json.dumps(summary, indent=2, sort_keys=True) - print(text) - if args.json: - args.json.write_text(text + "\n") - return summary - - -if __name__ == "__main__": - main() diff --git a/tests/test_measured_routing_evidence.py b/tests/test_measured_routing_evidence.py index 4b47dc9be..5a0c35a30 100644 --- a/tests/test_measured_routing_evidence.py +++ b/tests/test_measured_routing_evidence.py @@ -369,7 +369,7 @@ def test_admin_state_exposes_both_routing_ledgers() -> None: orchestrator = _orch(ModelAgent("worker_agent", "mock", tags=("reasoning",))) orchestrator._quality_router.observe_success("worker_agent", 0.5, output_tokens=25) evidence = orchestrator.admin_state()["routing_evidence"] - assert set(evidence) == {"transport", "quality", "health", "health_policy"} + assert set(evidence) == {"transport", "quality"} assert evidence["quality"]["worker_agent"]["ewma_tokens_per_second"] == pytest.approx(50.0) assert evidence["transport"]["worker_agent"]["ewma_tokens_per_second"] is None diff --git a/tests/test_observed_health_quarantine.py b/tests/test_observed_health_quarantine.py deleted file mode 100644 index 0b67a8c25..000000000 --- a/tests/test_observed_health_quarantine.py +++ /dev/null @@ -1,353 +0,0 @@ -"""Observed-outcome health quarantine for served-request candidate selection. - -Evidence: 101 sanitized Noema sidecar artifacts (deployed pin 767e67f) showed -the same agent slow-failing (RemoteDisconnected / HTTP 504, p50 ~265-302 s) -repeatedly within one run, while the legacy breaker's 30 s reset expired -before a single ~300 s failure finished. These contracts pin the repair: a -served request's slow failure must influence the next request's candidate -order, repeated slow failures quarantine the agent for a cooldown longer than -one failing attempt, and a half-open probe recovers it. -""" - -from __future__ import annotations - -import http.client -import io -import logging -import sys -import threading -from collections.abc import Iterator -from concurrent.futures import ThreadPoolExecutor -from contextlib import contextmanager -from dataclasses import replace -from pathlib import Path - -sys.path.insert(0, str(Path(__file__).resolve().parents[1])) - -from contextual_orchestrator import ModelAgent, TaskOrchestrator # noqa: E402 -from contextual_orchestrator.orchestrator import ( # noqa: E402 - ModelClient, - classify_health_failure, -) -from contextual_orchestrator.credentials import ( # noqa: E402 - InMemoryCredentialBackend, - register_credential, - set_backend, -) -from contextual_orchestrator.orchestrator import OBSERVED_HEALTH_QUARANTINE_SETTING # noqa: E402 -from contextual_orchestrator.provider_errors import ProviderUpstreamError # noqa: E402 -from contextual_orchestrator.review_gateway import register_review_credentials # noqa: E402 - -_LOGGER_NAME = "contextual_orchestrator.orchestrator" - - -@contextmanager -def _captured_logs(level: int) -> Iterator[io.StringIO]: - """Attach an isolated handler to the orchestrator logger only.""" - logger = logging.getLogger(_LOGGER_NAME) - previous_level, previous_propagate = logger.level, logger.propagate - buffer = io.StringIO() - handler = logging.StreamHandler(buffer) - logger.addHandler(handler) - logger.setLevel(level) - logger.propagate = False - try: - yield buffer - finally: - logger.removeHandler(handler) - handler.close() - logger.setLevel(previous_level) - logger.propagate = previous_propagate - - -def _gateway_timeout(agent_id: str) -> ProviderUpstreamError: - return ProviderUpstreamError( - agent_id=agent_id, - model="mock", - error_code="provider_timeout", - message="provider timed out", - client_status=504, - provider_status=504, - retryable=True, - ) - - -class _ScriptedClient(ModelClient): - """Fail the agents listed in ``down`` with a slow-class 504; record every call.""" - - def __init__(self) -> None: - super().__init__() - self.down: set[str] = set() - self.calls: list[str] = [] - - def chat(self, agent: ModelAgent, messages: list, temperature: float = 0.2) -> str: # type: ignore[override] - self.calls.append(agent.id) - if agent.id in self.down: - raise _gateway_timeout(agent.id) - return f"answer from {agent.id}" - - -class _Clock: - def __init__(self) -> None: - self.now = 1000.0 - - def __call__(self) -> float: - return self.now - - -def _pool(enabled: bool = True) -> tuple[TaskOrchestrator, _ScriptedClient, _Clock]: - agents = [ - ModelAgent("slow_worker", "mock", tags=("reasoning", "writing"), priority=5), - ModelAgent("steady_worker", "mock", tags=("reasoning", "writing"), priority=1), - ] - client = _ScriptedClient() - orchestrator = TaskOrchestrator( - agents, - client=client, - tool_retry_backoff_seconds=0.0, - observed_health_quarantine=enabled, - ) - orchestrator.policy = replace(orchestrator.policy, realtime_judge=False) - orchestrator.tool_retry_attempts = 0 - clock = _Clock() - orchestrator._circuit_clock = clock - return orchestrator, client, clock - - -def _serve(orchestrator: TaskOrchestrator) -> str: - primary = orchestrator._agent("slow_worker") - _output, served, _model, _usage = orchestrator._invoke( - primary, [{"role": "system", "content": "Role: worker"}], text="task", role="worker" - ) - return served - - -def _order(orchestrator: TaskOrchestrator) -> list[str]: - primary = orchestrator._agent("slow_worker") - return [agent.id for agent in orchestrator._failover_candidates(primary, "task", "worker")] - - -def test_failure_classes_separate_slow_post_send_from_fast_rejections() -> None: - assert classify_health_failure(_gateway_timeout("a")) == "slow_transport" - assert classify_health_failure(http.client.RemoteDisconnected("closed")) == "slow_transport" - assert classify_health_failure(TimeoutError("read timed out")) == "slow_transport" - not_found = ProviderUpstreamError( - agent_id="a", model="m", error_code="model_not_found", message="x", - client_status=404, provider_status=404, - ) - assert classify_health_failure(not_found) == "fast" - assert classify_health_failure(RuntimeError("opaque")) == "fast" - - -def test_wrapped_post_send_failures_stay_slow_class() -> None: - """ModelClient wraps a dropped connection as provider_outcome_unknown before _invoke sees it.""" - for code in ("provider_outcome_unknown", "model_timeout"): - wrapped = ProviderUpstreamError( - agent_id="a", model="m", error_code=code, message="x", - client_status=502, provider_status=None, retryable=False, - ) - assert classify_health_failure(wrapped) == "slow_transport", code - - -def test_served_slow_failure_demotes_agent_for_the_next_request() -> None: - orchestrator, client, _clock = _pool() - client.down.add("slow_worker") - - assert _serve(orchestrator) == "steady_worker" # request N: slow failure recorded - assert client.calls == ["slow_worker", "steady_worker"] - - # One slow failure never quarantines ... - assert orchestrator._circuit_open("slow_worker") is False - # ... but request N+1 tries the healthy sibling first and never pays the - # ~300 s failure again when that sibling succeeds. - assert _order(orchestrator) == ["steady_worker", "slow_worker"] - client.calls.clear() - assert _serve(orchestrator) == "steady_worker" - assert client.calls == ["steady_worker"] - - -def test_single_fast_failure_neither_quarantines_nor_demotes() -> None: - orchestrator, _client, _clock = _pool() - orchestrator._record_failure("slow_worker", failure_class="fast") - assert orchestrator._circuit_open("slow_worker") is False - assert _order(orchestrator) == ["slow_worker", "steady_worker"] - - -def test_repeated_slow_failures_quarantine_past_one_failing_attempt_then_recover() -> None: - orchestrator, client, clock = _pool() - orchestrator._record_failure("slow_worker", failure_class="slow_transport") - with _captured_logs(logging.INFO) as buffer: - orchestrator._record_failure("slow_worker", failure_class="slow_transport") - opened = buffer.getvalue() - assert "circuit_opened agent_id=slow_worker" in opened - assert "failure_class=slow_transport" in opened - assert orchestrator._circuit_open("slow_worker") is True - assert _order(orchestrator) == ["steady_worker"] - - # The legacy 30 s reset is shorter than one ~300 s slow failure; the - # slow-class cooldown must outlast it. - clock.now += 301.0 - assert orchestrator._circuit_open("slow_worker") is True - - clock.now += orchestrator.slow_failure_cooldown_seconds - with _captured_logs(logging.INFO) as buffer: - assert orchestrator._circuit_open("slow_worker") is False - assert "circuit_half_open agent_id=slow_worker" in buffer.getvalue() - # Half-open: eligible again, but tried only after healthy siblings. - assert _order(orchestrator) == ["steady_worker", "slow_worker"] - - client.down.clear() - client.down.add("steady_worker") - with _captured_logs(logging.INFO) as buffer: - assert _serve(orchestrator) == "slow_worker" # the half-open probe succeeds - assert "circuit_recovered agent_id=slow_worker" in buffer.getvalue() - assert orchestrator.circuit_health_snapshot()["slow_worker"]["state"] == "closed" - - -def test_half_open_failure_reopens_with_escalated_bounded_cooldown() -> None: - orchestrator, _client, clock = _pool() - for _ in range(2): - orchestrator._record_failure("slow_worker", failure_class="slow_transport") - first = orchestrator.circuit_health_snapshot()["slow_worker"]["cooldown_seconds"] - clock.now += first - assert orchestrator._circuit_open("slow_worker") is False # half-open - orchestrator._record_failure("slow_worker", failure_class="slow_transport") - assert orchestrator._circuit_open("slow_worker") is True - second = orchestrator.circuit_health_snapshot()["slow_worker"]["cooldown_seconds"] - assert second == 2 * first - for _ in range(10): - clock.now += orchestrator.circuit_health_snapshot()["slow_worker"]["cooldown_seconds"] - assert orchestrator._circuit_open("slow_worker") is False - orchestrator._record_failure("slow_worker", failure_class="slow_transport") - capped = orchestrator.circuit_health_snapshot()["slow_worker"]["cooldown_seconds"] - assert capped == orchestrator.circuit_max_cooldown_seconds - - -def test_observed_failure_rate_quarantines_an_intermittently_failing_agent() -> None: - orchestrator, _client, _clock = _pool() - # Never three consecutive failures, but most recent outcomes failed. - for outcome in ("fail", "ok", "fail", "fail", "ok", "fail", "fail"): - if outcome == "fail": - orchestrator._record_failure("slow_worker", failure_class="fast") - else: - orchestrator._record_success("slow_worker") - assert orchestrator._circuit_open("slow_worker") is True - snapshot = orchestrator.circuit_health_snapshot()["slow_worker"] - assert snapshot["window_failure_rate"] >= orchestrator.circuit_failure_rate_threshold - - -def test_all_quarantined_pool_falls_back_to_least_recently_failed_member() -> None: - orchestrator, _client, clock = _pool() - for _ in range(2): - orchestrator._record_failure("slow_worker", failure_class="slow_transport") - clock.now += 5.0 - for _ in range(2): - orchestrator._record_failure("steady_worker", failure_class="slow_transport") - with _captured_logs(logging.WARNING) as buffer: - order = _order(orchestrator) - fallback = buffer.getvalue() - assert order == ["slow_worker", "steady_worker"] # never an empty pool - assert "circuit_all_open_fallback candidate_count=2 selected_agent_id=slow_worker" in fallback - - -def test_concurrent_slow_failures_open_the_circuit_exactly_once() -> None: - orchestrator, _client, _clock = _pool() - calls = 16 - barrier = threading.Barrier(calls, timeout=2.0) - - def record(_index: int) -> None: - barrier.wait() - orchestrator._record_failure("slow_worker", failure_class="slow_transport") - - with _captured_logs(logging.WARNING) as buffer: - with ThreadPoolExecutor(max_workers=calls) as pool: - list(pool.map(record, range(calls))) - output = buffer.getvalue() - assert output.count("circuit_opened agent_id=slow_worker") == 1 - assert orchestrator._circuit["slow_worker"]["failures"] == float(calls) - snapshot = orchestrator.circuit_health_snapshot()["slow_worker"] - assert snapshot["state"] == "open" - assert snapshot["consecutive_failures"] == calls - - -def test_default_orchestrator_keeps_the_legacy_breaker_policy() -> None: - """Without the operator opt-in, weights, cooldowns and demotion stay legacy 3/30.""" - orchestrator, client, clock = _pool(enabled=False) - assert TaskOrchestrator([ModelAgent("solo_worker", "mock")]).observed_health_quarantine is False - client.down.add("slow_worker") - _serve(orchestrator) - assert _order(orchestrator) == ["slow_worker", "steady_worker"] # no demotion - orchestrator._record_failure("slow_worker", failure_class="slow_transport") - assert orchestrator._circuit_open("slow_worker") is False # two slow != three strikes - orchestrator._record_failure("slow_worker", failure_class="slow_transport") - assert orchestrator._circuit_open("slow_worker") is True - clock.now += orchestrator.circuit_reset_seconds - assert orchestrator._circuit_open("slow_worker") is False - orchestrator._record_failure("slow_worker", failure_class="slow_transport") - assert orchestrator._circuit_open("slow_worker") is False # counter restarts from zero - - -def test_health_snapshot_is_bounded_and_prompt_free() -> None: - orchestrator, client, _clock = _pool() - client.down.add("slow_worker") - _serve(orchestrator) - snapshot = orchestrator.circuit_health_snapshot() - assert set(snapshot["slow_worker"]) == { - "state", "model", "provider", "consecutive_failures", "weighted_score", - "last_failure_class", "cooldown_seconds", "remaining_seconds", - "window_size", "window_failure_rate", "open_count", - } - assert "task" not in repr(snapshot) - assert orchestrator.admin_state()["routing_evidence"]["health"] == snapshot - - -@contextmanager -def _fresh_kv() -> Iterator[None]: - set_backend(InMemoryCredentialBackend()) - try: - yield - finally: - set_backend(None) - - -def _launcher_shaped() -> TaskOrchestrator: - """Construct exactly as the review launcher does: no policy argument.""" - return TaskOrchestrator([ModelAgent("solo_worker", "mock")], client=ModelClient()) - - -def test_kv_switch_is_the_single_deployable_activation_and_is_audited() -> None: - with _fresh_kv(): - default = _launcher_shaped() - assert (default.observed_health_quarantine, default.observed_health_quarantine_source) == (False, "default") - register_review_credentials({OBSERVED_HEALTH_QUARANTINE_SETTING: "enabled\n"}) - with _captured_logs(logging.INFO) as buffer: - enabled = _launcher_shaped() - assert enabled.observed_health_quarantine is True - assert f"observed_health_quarantine enabled=True source=kv setting={OBSERVED_HEALTH_QUARANTINE_SETTING}" in buffer.getvalue() - policy = enabled.admin_state()["routing_evidence"]["health_policy"] - assert policy["observed_health_quarantine"] is True and policy["source"] == "kv" - assert policy["slow_failure_cooldown_seconds"] == 360.0 - # An explicit constructor boolean still wins over the KV value. - assert TaskOrchestrator([ModelAgent("solo_worker", "mock")], observed_health_quarantine=False).observed_health_quarantine is False - - -def test_kv_switch_off_values_and_invalid_value_fail_closed() -> None: - with _fresh_kv(): - register_credential(OBSERVED_HEALTH_QUARANTINE_SETTING, "disabled") - off = _launcher_shaped() - assert (off.observed_health_quarantine, off.observed_health_quarantine_source) == (False, "kv") - register_credential(OBSERVED_HEALTH_QUARANTINE_SETTING, "maybe") - try: - _launcher_shaped() - except ValueError as exc: - assert OBSERVED_HEALTH_QUARANTINE_SETTING in str(exc) - else: # pragma: no cover - raise AssertionError("an unrecognized switch value must fail construction") - - -if __name__ == "__main__": - for name, fn in sorted(globals().items()): - if name.startswith("test_") and callable(fn): - fn() - print(f"ok {name}") - print("ok") diff --git a/tests/test_observed_health_quarantine_http.py b/tests/test_observed_health_quarantine_http.py deleted file mode 100644 index 18b5fe187..000000000 --- a/tests/test_observed_health_quarantine_http.py +++ /dev/null @@ -1,310 +0,0 @@ -"""HTTP end-to-end contracts for the opt-in observed-health quarantine. - -Each of the four served paths behind ``/v1/chat/completions`` -- route -(``route_once``), conduct, streaming (``stream_route``) and the structured -provider path (``proxy_completion``) -- must apply the same policy when -``observed_health_quarantine=True``: (a) one slow failure demotes the member -for the next request, (b) after the cooldown the half-open probe recovers on -success or doubles the cooldown on failure, and (c) an all-quarantined pool -still serves, least-recently-failed first. Providers are a controllable -in-process client over ``mock://`` agents; time is the breaker's injected -monotonic clock, so nothing sleeps. -""" - -from __future__ import annotations - -import io -import json -import logging -import sys -import threading -import urllib.error -import urllib.request -from collections.abc import Iterator -from contextlib import contextmanager -from dataclasses import replace -from pathlib import Path -from typing import Any - -import pytest - -sys.path.insert(0, str(Path(__file__).resolve().parents[1])) - -from contextual_orchestrator import ModelAgent, TaskOrchestrator # noqa: E402 -from contextual_orchestrator.orchestrator import ModelClient # noqa: E402 -from contextual_orchestrator.provider_errors import ProviderUpstreamError # noqa: E402 -from contextual_orchestrator.server import SecurityConfig, build_server # noqa: E402 - -_TOKEN = "observed_health_quarantine_http_token" -_TAGS = ("reasoning", "writing", "planning", "coding", "implementation", "verification", "review") -_PATHS = ("route", "conduct", "stream", "proxy") - - -def _timeout(agent: ModelAgent, transport: str) -> ProviderUpstreamError: - return ProviderUpstreamError( - agent_id=agent.id, - model=agent.model, - error_code="provider_timeout", - message="provider timed out", - client_status=504, - provider_status=504, - retryable=True, - transport=transport, - ) - - -class _ControlledProvider(ModelClient): - """Every served transport fails with a slow-class 504 for agents in ``down``.""" - - def __init__(self) -> None: - super().__init__() - self.down: set[str] = set() - self.calls: list[str] = [] - self._lock = threading.Lock() - - def _attempt(self, agent: ModelAgent, transport: str) -> None: - with self._lock: - self.calls.append(agent.id) - if agent.id in self.down: - raise _timeout(agent, transport) - - def chat(self, agent: ModelAgent, messages: list, *args: Any, **kwargs: Any) -> str: # type: ignore[override] - self._attempt(agent, "chat") - return f"answer from {agent.id}" - - def stream_chat(self, agent: ModelAgent, messages: list, *args: Any, **kwargs: Any): # type: ignore[override] - self._attempt(agent, "stream") - yield f"answer from {agent.id}" - - def proxy_send_once(self, agent: ModelAgent, endpoint: str, payload: dict[str, Any]) -> dict[str, Any]: # type: ignore[override] - self._attempt(agent, "passthrough") - return { - "id": "chatcmpl_test", - "object": "chat.completion", - "model": agent.model, - "choices": [ - { - "index": 0, - "message": {"role": "assistant", "content": json.dumps({"answer": agent.id})}, - "finish_reason": "stop", - } - ], - } - - proxy_send = proxy_send_once - - def take_usage(self) -> None: - return None - - -class _Clock: - def __init__(self) -> None: - self.now = 10_000.0 - - def __call__(self) -> float: - return self.now - - -@contextmanager -def _gateway(enabled: bool = True) -> Iterator[tuple[TaskOrchestrator, _ControlledProvider, _Clock, int]]: - agents = [ - ModelAgent("slow_worker", "slow-model", base_url="mock://slow.example", tags=_TAGS, priority=10), - ModelAgent("steady_worker", "steady-model", base_url="mock://steady.example", tags=_TAGS, priority=1), - ] - provider = _ControlledProvider() - orchestrator = TaskOrchestrator( - agents, - client=provider, - tool_retry_backoff_seconds=0.0, - observed_health_quarantine=enabled, - ) - orchestrator.policy = replace(orchestrator.policy, realtime_judge=False) - orchestrator.tool_retry_attempts = 0 - clock = _Clock() - orchestrator._circuit_clock = clock - server = build_server(orchestrator, port=0, security=SecurityConfig(auth_token=_TOKEN)) - thread = threading.Thread(target=server.serve_forever, daemon=True) - thread.start() - try: - yield orchestrator, provider, clock, server.server_address[1] - finally: - server.shutdown() - thread.join(timeout=5) - server.server_close() - - -def _body(path: str) -> dict[str, Any]: - body: dict[str, Any] = { - "model": TaskOrchestrator.AUTO_MODEL, - "messages": [{"role": "user", "content": "summarize the incident"}], - } - if path == "proxy": - # Virtual selector + response_format: the structured provider path - # (proxy_completion(single_agent=False) -> conduct stages + structured - # synthesis failover), the HTTP route that reaches proxy_completion. - body["response_format"] = {"type": "json_object"} - else: - body["mode"] = "conduct" if path == "conduct" else "route" - if path == "stream": - body["stream"] = True - return body - - -def _send(port: int, path: str) -> int: - request = urllib.request.Request( - f"http://127.0.0.1:{port}/v1/chat/completions", - data=json.dumps(_body(path)).encode("utf-8"), - headers={ - "content-type": "application/json", - "authorization": f"Bearer {_TOKEN}", - "connection": "close", - }, - method="POST", - ) - try: - with urllib.request.urlopen(request, timeout=15) as response: - payload = response.read().decode("utf-8") - status = response.status - except urllib.error.HTTPError as exc: - with exc: - exc.read() - return exc.code - if path == "stream" and '"error"' in payload: - return 502 # a terminal SSE error frame after the 200 header - return status - - -def _request(orchestrator: TaskOrchestrator, provider: _ControlledProvider, port: int, path: str) -> tuple[int, list[str]]: - provider.calls.clear() - status = _send(port, path) - return status, list(provider.calls) - - -def _state(orchestrator: TaskOrchestrator, agent_id: str) -> dict[str, Any]: - return orchestrator.circuit_health_snapshot()[agent_id] - - -@contextmanager -def _captured(level: int) -> Iterator[io.StringIO]: - logger = logging.getLogger("contextual_orchestrator.orchestrator") - previous_level, previous_propagate = logger.level, logger.propagate - buffer = io.StringIO() - handler = logging.StreamHandler(buffer) - logger.addHandler(handler) - logger.setLevel(level) - logger.propagate = False - try: - yield buffer - finally: - logger.removeHandler(handler) - handler.close() - logger.setLevel(previous_level) - logger.propagate = previous_propagate - - -def _quarantine_slow_worker(orchestrator, provider, port, path) -> None: - """Drive both members down so ``slow_worker`` reaches two slow strikes.""" - provider.down = {"slow_worker"} - status, calls = _request(orchestrator, provider, port, path) - assert status == 200 and calls[:2] == ["slow_worker", "steady_worker"], (status, calls) - provider.down = {"slow_worker", "steady_worker"} - _request(orchestrator, provider, port, path) - assert _state(orchestrator, "slow_worker")["state"] == "open" - - -@pytest.mark.parametrize("path", _PATHS) -def test_one_slow_failure_demotes_member_for_next_http_request(path: str) -> None: - with _gateway() as (orchestrator, provider, _clock, port): - provider.down = {"slow_worker"} - status, calls = _request(orchestrator, provider, port, path) - assert status == 200, (path, status, calls) - assert calls[:2] == ["slow_worker", "steady_worker"], (path, calls) - assert _state(orchestrator, "slow_worker")["state"] == "closed" # demoted, not quarantined - - status, calls = _request(orchestrator, provider, port, path) - assert status == 200, (path, status, calls) - assert "slow_worker" not in calls, (path, calls) - assert calls[0] == "steady_worker", (path, calls) - - -@pytest.mark.parametrize("path", _PATHS) -def test_half_open_probe_recovers_on_success_over_http(path: str) -> None: - with _gateway() as (orchestrator, provider, clock, port): - _quarantine_slow_worker(orchestrator, provider, port, path) - provider.down = set() - status, calls = _request(orchestrator, provider, port, path) - assert status == 200 and "slow_worker" not in calls, (path, status, calls) - - clock.now += _state(orchestrator, "slow_worker")["cooldown_seconds"] - provider.down = {"steady_worker"} # the demoted half-open member is reached - with _captured(logging.INFO) as buffer: - status, calls = _request(orchestrator, provider, port, path) - assert status == 200 and "slow_worker" in calls, (path, status, calls) - assert "circuit_half_open agent_id=slow_worker" in buffer.getvalue() - assert "circuit_recovered agent_id=slow_worker" in buffer.getvalue() - assert _state(orchestrator, "slow_worker")["state"] == "closed" - - -@pytest.mark.parametrize("path", _PATHS) -def test_half_open_probe_failure_doubles_cooldown_over_http(path: str) -> None: - with _gateway() as (orchestrator, provider, clock, port): - _quarantine_slow_worker(orchestrator, provider, port, path) - first = _state(orchestrator, "slow_worker")["cooldown_seconds"] - clock.now += first - provider.down = {"slow_worker", "steady_worker"} - with _captured(logging.WARNING) as buffer: - _request(orchestrator, provider, port, path) - assert "trigger=half_open_failure" in buffer.getvalue(), (path, buffer.getvalue()) - assert _state(orchestrator, "slow_worker")["state"] == "open" - assert _state(orchestrator, "slow_worker")["cooldown_seconds"] == 2 * first - - -@pytest.mark.parametrize("path", _PATHS) -def test_all_quarantined_pool_still_serves_least_recently_failed_first(path: str) -> None: - with _gateway() as (orchestrator, provider, clock, port): - _quarantine_slow_worker(orchestrator, provider, port, path) - clock.now += 5.0 - provider.down = {"steady_worker"} - _request(orchestrator, provider, port, path) # steady's second slow strike - assert _state(orchestrator, "steady_worker")["state"] == "open" - - provider.down = set() - with _captured(logging.WARNING) as buffer: - status, calls = _request(orchestrator, provider, port, path) - assert status == 200, (path, status, calls) - assert calls[0] == "slow_worker", (path, calls) # failed longest ago - assert "circuit_all_open_fallback" in buffer.getvalue() - - -def test_auto_mode_triage_pick_follows_observed_health() -> None: - """The uncached triage call is one direct pick; it must not re-hit a demoted member.""" - with _gateway() as (orchestrator, provider, _clock, port): - provider.down = {"slow_worker"} - _request(orchestrator, provider, port, "route") # slow strike: demoted - provider.calls.clear() - body = { - "model": TaskOrchestrator.AUTO_MODEL, - "messages": [{"role": "user", "content": "triage this distinct prompt"}], - } - request = urllib.request.Request( - f"http://127.0.0.1:{port}/v1/chat/completions", - data=json.dumps(body).encode("utf-8"), - headers={"content-type": "application/json", "authorization": f"Bearer {_TOKEN}"}, - method="POST", - ) - with urllib.request.urlopen(request, timeout=15) as response: - assert response.status == 200 - response.read() - assert "slow_worker" not in provider.calls, provider.calls - - -def test_flag_off_http_route_keeps_legacy_order() -> None: - with _gateway(enabled=False) as (orchestrator, provider, _clock, port): - provider.down = {"slow_worker"} - _request(orchestrator, provider, port, "route") - status, calls = _request(orchestrator, provider, port, "route") - assert status == 200 and calls == ["slow_worker", "steady_worker"] - - -if __name__ == "__main__": - sys.exit(pytest.main([__file__, "-q"])) diff --git a/tests/test_rate_limit_breaker_asymmetry.py b/tests/test_rate_limit_breaker_asymmetry.py index 5b535ccc4..8d5a5b748 100644 --- a/tests/test_rate_limit_breaker_asymmetry.py +++ b/tests/test_rate_limit_breaker_asymmetry.py @@ -1,51 +1,34 @@ -"""Pin one breaker contract for a provider 429 across every chat path. - -One identical provider response from the first-ranked agent -- HTTP 429 with -``Retry-After: 7``, or HTTP 503 -- is served at the lowest transport seam -(``ModelClient._open_provider``) while the second agent succeeds. The same -pool and request then go through ``route_once`` (``_invoke``), -``stream_route`` and the virtual passthrough loop in ``proxy_completion``: - -* 429 is quota capacity, not member health: every path records the quota - cooldown and none charges the circuit breaker or the observed-health ledger - (the passthrough ``skip_breaker`` rule, now shared); -* 503 stays an availability failure: exactly one breaker failure. - -Before this was unified, ``_invoke`` and ``stream_route`` charged a 429 to -the breaker (see the 429 study in -``docs/doctoring/observed-health-quarantine.md``). -""" +"""Pin provider 429 quota evidence across each chat path.""" from __future__ import annotations import http.client import json -import sys import urllib.error from dataclasses import replace -from pathlib import Path import pytest -sys.path.insert(0, str(Path(__file__).resolve().parents[1])) - -from contextual_orchestrator import ModelAgent, TaskOrchestrator # noqa: E402 -from contextual_orchestrator.credentials import ( # noqa: E402 +from contextual_orchestrator import ModelAgent, TaskOrchestrator +from contextual_orchestrator.credentials import ( InMemoryCredentialBackend, register_credential, set_backend, ) -from contextual_orchestrator.orchestrator import ModelClient # noqa: E402 +from contextual_orchestrator.orchestrator import ModelClient _MESSAGES = [{"role": "user", "content": "summarize the incident"}] class _Response: - """A provider 200: JSON for chat/passthrough, SSE lines for streaming.""" + """A provider 200 response for chat, passthrough, or streaming.""" def __init__(self, stream: bool) -> None: if stream: - chunk = {"model": "second-model", "choices": [{"index": 0, "delta": {"content": "ok"}}]} + chunk = { + "model": "second-model", + "choices": [{"index": 0, "delta": {"content": "ok"}}], + } self._lines = [f"data: {json.dumps(chunk)}\n".encode(), b"data: [DONE]\n"] else: body = { @@ -53,9 +36,15 @@ def __init__(self, stream: bool) -> None: "object": "chat.completion", "created": 0, "model": "second-model", - "choices": [{"index": 0, "message": {"role": "assistant", "content": "ok"}, "finish_reason": "stop"}], + "choices": [ + { + "index": 0, + "message": {"role": "assistant", "content": "ok"}, + "finish_reason": "stop", + } + ], } - self._lines = [json.dumps(body).encode("utf-8")] + self._lines = [json.dumps(body).encode()] self.status = 200 self.headers: dict[str, str] = {} @@ -63,10 +52,12 @@ def __iter__(self): return iter(self._lines) def read(self, amount: int | None = None) -> bytes: + del amount body, self._lines = b"".join(self._lines), [] return body def getheader(self, name: str, default: str | None = None) -> str | None: + del name return default def close(self) -> None: @@ -76,6 +67,7 @@ def __enter__(self) -> "_Response": return self def __exit__(self, *exc_info: object) -> bool: + del exc_info self.close() return False @@ -85,20 +77,25 @@ def _provider_error(status: int) -> urllib.error.HTTPError: if status == 429: headers["Retry-After"] = "7" return urllib.error.HTTPError( - "https://provider.invalid/v1/chat/completions", status, "provider error", headers, None + "https://provider.invalid/v1/chat/completions", + status, + "provider error", + headers, + None, ) @pytest.fixture def pool_for(monkeypatch: pytest.MonkeyPatch): + """Return a two-member pool whose first provider yields one HTTP error.""" set_backend(InMemoryCredentialBackend()) register_credential("SYNTHETIC_PROVIDER_KEY", "synthetic") - raised: list[urllib.error.HTTPError] = [] # the fake provider owns its responses + raised: list[urllib.error.HTTPError] = [] def build(status: int) -> TaskOrchestrator: def open_provider(self, request, destination=None, *, timeout=None): del self, destination, timeout - payload = json.loads(request.data.decode("utf-8")) + payload = json.loads(request.data.decode()) if payload["model"] == "first-model": raised.append(_provider_error(status)) raise raised[-1] @@ -106,19 +103,29 @@ def open_provider(self, request, destination=None, *, timeout=None): monkeypatch.setattr(ModelClient, "_validate_provider", lambda self, agent: None) monkeypatch.setattr(ModelClient, "_open_provider", open_provider) - agents = [ - ModelAgent("first_agent", "first-model", base_url="https://provider.invalid/v1", - api_key_env="SYNTHETIC_PROVIDER_KEY", tags=("reasoning", "writing"), priority=10), - ModelAgent("second_agent", "second-model", base_url="https://provider.invalid/v2", - api_key_env="SYNTHETIC_PROVIDER_KEY", tags=("reasoning", "writing"), priority=1), - ] orchestrator = TaskOrchestrator( - agents, + [ + ModelAgent( + "first_agent", + "first-model", + base_url="https://provider.invalid/v1", + api_key_env="SYNTHETIC_PROVIDER_KEY", + tags=("reasoning", "writing"), + priority=10, + ), + ModelAgent( + "second_agent", + "second-model", + base_url="https://provider.invalid/v2", + api_key_env="SYNTHETIC_PROVIDER_KEY", + tags=("reasoning", "writing"), + priority=1, + ), + ], client=ModelClient(max_retries=0), tool_retry_attempts=0, tool_retry_backoff_seconds=0.0, rate_limit_wait_seconds=0.0, - observed_health_quarantine=True, ) orchestrator.policy = replace(orchestrator.policy, realtime_judge=False) orchestrator._triage_fn = lambda text: False @@ -137,23 +144,27 @@ def _serve(orchestrator: TaskOrchestrator, path: str) -> str: result = orchestrator.route_once(list(_MESSAGES), model_name=TaskOrchestrator.AUTO_MODEL) return result["answer"] if path == "stream": - return "".join(orchestrator.stream_route(list(_MESSAGES), model_name=TaskOrchestrator.AUTO_MODEL)) - response = orchestrator.proxy_completion({"model": TaskOrchestrator.AUTO_MODEL, "messages": list(_MESSAGES)}) + return "".join( + orchestrator.stream_route(list(_MESSAGES), model_name=TaskOrchestrator.AUTO_MODEL) + ) + response = orchestrator.proxy_completion( + {"model": TaskOrchestrator.AUTO_MODEL, "messages": list(_MESSAGES)} + ) return response["choices"][0]["message"]["content"] @pytest.mark.parametrize("path", ["route", "stream", "passthrough"]) -def test_provider_429_records_quota_cooldown_but_never_breaker_health(pool_for, path: str) -> None: +def test_provider_429_records_quota_but_not_breaker_health(pool_for, path: str) -> None: + """A quota response cannot become member-health evidence.""" orchestrator = pool_for(429) assert _serve(orchestrator, path) == "ok" assert orchestrator._rate_limit_remaining("first_agent") is not None, path assert "first_agent" not in orchestrator._circuit, (path, orchestrator._circuit) - health = orchestrator.circuit_health_snapshot().get("first_agent") - assert health is None or health["window_failure_rate"] in (None, 0.0), (path, health) @pytest.mark.parametrize("path", ["route", "stream", "passthrough"]) def test_provider_503_still_counts_as_one_breaker_failure(pool_for, path: str) -> None: + """A provider availability failure remains breaker evidence.""" orchestrator = pool_for(503) assert _serve(orchestrator, path) == "ok" assert orchestrator._circuit["first_agent"]["failures"] == 1.0, path From c577b8e53eb3df7ed3b2392da5fc3be78780f1cd Mon Sep 17 00:00:00 2001 From: Seongho Bae Date: Wed, 30 Sep 2026 16:19:03 +0900 Subject: [PATCH 10/10] fix(document-review): scan data URIs linearly Replace the attacker-controlled unanchored data-URI regex with a disjoint-segment linear scanner while preserving fail-closed inline-media detection. Exact verification: - 71 document-diff tests passed with warnings fatal - document_diff_review.py statement/branch coverage: 100% - compileall and changed-surface E/F/I lint passed - git diff --check passed --- .../document-diff-data-uri-linear-scan.md | 5 +++ .../document_diff_review.py | 28 +++++++++++++-- .../document-diff-data-uri-redos-20260930.md | 36 +++++++++++++++++++ docs/product-technical-gap-baseline.md | 6 ++++ tests/test_document_diff_review.py | 20 +++++++++++ 5 files changed, 93 insertions(+), 2 deletions(-) create mode 100644 CHANGELOG.d/document-diff-data-uri-linear-scan.md create mode 100644 docs/doctoring/document-diff-data-uri-redos-20260930.md diff --git a/CHANGELOG.d/document-diff-data-uri-linear-scan.md b/CHANGELOG.d/document-diff-data-uri-linear-scan.md new file mode 100644 index 000000000..134b28a31 --- /dev/null +++ b/CHANGELOG.d/document-diff-data-uri-linear-scan.md @@ -0,0 +1,5 @@ +### Security + +- Replace the document-diff data-URI regular expression with a linear scanner, + preserving the existing fail-closed inline-media boundary without exposing + attacker-controlled text to polynomial regular-expression work. diff --git a/contextual_orchestrator/document_diff_review.py b/contextual_orchestrator/document_diff_review.py index eb0e6d970..4ecc37d12 100644 --- a/contextual_orchestrator/document_diff_review.py +++ b/contextual_orchestrator/document_diff_review.py @@ -89,7 +89,6 @@ _REPO = re.compile(r"[A-Za-z0-9_.-]{1,100}/[A-Za-z0-9_.-]{1,100}") _BLOB = re.compile(r"[0-9a-f]{40}(?:[0-9a-f]{24})?") _OBJECT_HASH = re.compile(r"sha256:[0-9a-f]{64}") -_DATA_URI = re.compile(r"data:[^,\s]*,", re.IGNORECASE) _BASE64_RUN = re.compile(r"[A-Za-z0-9+/_-]{200,}={0,2}") _RESIDENT_REGISTRATION_NUMBER = re.compile(r"(? DocumentDiffReviewErr return DocumentDiffReviewError(code, message, status) +def _contains_inline_data_uri(value: str) -> bool: + """Detect a data URI in one linear scan without attacker-driven regex work.""" + normalized_value = value.casefold() + search_start = 0 + while True: + prefix_start = normalized_value.find("data:", search_start) + if prefix_start < 0: + return False + header_index = prefix_start + len("data:") + while header_index < len(normalized_value): + character = normalized_value[header_index] + if character == ",": + return True + if character.isspace(): + break + header_index += 1 + if header_index == len(normalized_value): + return False + search_start = header_index + 1 + + def _exact_object(value: Any, allowed: frozenset[str], field: str, *, required: frozenset[str]) -> dict[str, Any]: """Require a JSON object whose keys are known and whose required keys exist.""" if type(value) is not dict: @@ -126,7 +146,11 @@ def _exact_object(value: Any, allowed: frozenset[str], field: str, *, required: def _scan_for_leaks(value: str, field: str) -> None: """Reject inline binary/media, credentials, and resident identifiers.""" - if any(signature in value for signature in _BINARY_SIGNATURES) or _DATA_URI.search(value) or _BASE64_RUN.search(value): + if ( + any(signature in value for signature in _BINARY_SIGNATURES) + or _contains_inline_data_uri(value) + or _BASE64_RUN.search(value) + ): raise _reject("inline_binary_content", f"{field} must not carry inline binary or media data", 422) if any(pattern.search(value) for pattern in SECRET_PATTERNS): raise _reject("secret_detected", f"{field} matches a credential pattern", 422) diff --git a/docs/doctoring/document-diff-data-uri-redos-20260930.md b/docs/doctoring/document-diff-data-uri-redos-20260930.md new file mode 100644 index 000000000..c92643e90 --- /dev/null +++ b/docs/doctoring/document-diff-data-uri-redos-20260930.md @@ -0,0 +1,36 @@ +# Document diff data-URI ReDoS RCA + +Status: Proposed until protected integration and exact-head hosted Checks. + +## Incident + +The Python CodeQL dispatch for +`ContextualWisdomLab/contextual-orchestrator#1221@4dcf9e32b057cde83bca67bfd45975fc6deda458` +reported `py/polynomial-redos` with security severity 7.5 at +`contextual_orchestrator/document_diff_review.py:129`. Central run +`36447487525`, job `109084173022`, preserved SARIF artifact `11026927998` +with digest +`sha256:0145d9b03e8c0064c2a57be79bc3f8168bcd45dc93b488aa4a4b1f81c23898a5`. + +## Root cause + +The data-URI boundary searched caller-controlled extracted document text with +`data:[^,\s]*,`. Repeated `data:` prefixes let the unanchored expression retry +over overlapping suffixes. The per-object byte ceiling bounded the input, but +did not make polynomial work an acceptable security boundary. + +## Repair and invariant + +The replacement scans disjoint text segments. It finds a case-insensitive +`data:` prefix, advances once until comma, whitespace, or end, and resumes only +after the terminating whitespace. A comma before whitespace remains a data URI +and is rejected. Broken headers remain ordinary text, and a later valid header +is still found. Binary signatures, long base64 runs, credentials, resident +registration numbers, byte budgets, and provider-call admission are unchanged. + +RED imported the absent linear scanner and failed collection. GREEN covers +ordinary and upper-case data URIs, whitespace termination, a later valid URI, +and 1,600 repeated attacker-controlled prefixes with and without a terminal +comma. Hosted CodeQL on the repaired exact head remains the authoritative +acceptance gate; this record does not convert queued, skipped, or stale results +into success. diff --git a/docs/product-technical-gap-baseline.md b/docs/product-technical-gap-baseline.md index 8d8def6b0..660da7213 100644 --- a/docs/product-technical-gap-baseline.md +++ b/docs/product-technical-gap-baseline.md @@ -1,5 +1,11 @@ # Contextual Orchestrator: Product & Technical Gap Baseline +## 2026-09-30 document diff data-URI scan — Proposed + +| Gap ID | Status | Exact-head evidence | Repair / next gate | +|---|---|---|---| +| CO-DOCUMENT-DIFF-REDOS-01 | **Proposed — source repaired; hosted acceptance pending** | `contextual-orchestrator#1221@4dcf9e32b057cde83bca67bfd45975fc6deda458`; central CodeQL run `36447487525`, Python job `109084173022`, rule `py/polynomial-redos`, security severity 7.5, `contextual_orchestrator/document_diff_review.py:129`; SARIF artifact `11026927998`, digest `sha256:0145d9b03e8c0064c2a57be79bc3f8168bcd45dc93b488aa4a4b1f81c23898a5`. | Replace the unanchored data-URI regular expression with a disjoint-segment linear scanner while preserving fail-closed inline-media rejection. RED imports the absent scanner; GREEN covers ordinary, case-insensitive, whitespace-terminated, later-valid, and 1,600-prefix adversarial inputs. Re-run exact-head CodeQL only after this cause change; protected Checks and independent review remain required. | + ## 2026-09-19 free multimodal review routing — Proposed Canonical owner PR diff --git a/tests/test_document_diff_review.py b/tests/test_document_diff_review.py index b3df584a4..7a999aa02 100644 --- a/tests/test_document_diff_review.py +++ b/tests/test_document_diff_review.py @@ -29,6 +29,7 @@ from contextual_orchestrator import ModelAgent, TaskOrchestrator # noqa: E402 from contextual_orchestrator.document_diff_review import ( # noqa: E402 DocumentDiffReviewError, + _contains_inline_data_uri, validate_document_diff_envelope, validate_document_diff_findings, ) @@ -256,6 +257,25 @@ def _mutated(**changes) -> dict: return envelope +@pytest.mark.parametrize( + ("value", "expected"), + [ + ("caption data:image/png;base64,AAAA", True), + ("DATA:text/plain,review", True), + ("data:not-a-uri because-whitespace,", False), + (("data:" * 1600) + "suffix", False), + (("data:" * 1600) + ",", True), + ("data:broken header\nthen DATA:image/png;base64,AAAA", True), + ], +) +def test_inline_data_uri_detection_is_linear_and_preserves_fail_closed_boundary( + value: str, + expected: bool, +) -> None: + """Repeated attacker-controlled prefixes must not trigger regex backtracking.""" + assert _contains_inline_data_uri(value) is expected + + @pytest.mark.parametrize( ("envelope", "status", "code"), [