diff --git a/crates/gateway/ARCHITECTURE.md b/crates/gateway/ARCHITECTURE.md index 5bba15ac..520e6f3e 100644 --- a/crates/gateway/ARCHITECTURE.md +++ b/crates/gateway/ARCHITECTURE.md @@ -2375,10 +2375,24 @@ Two deliberate non-cases, plus one same-provider retry: provider but OpenRouter (`remedy::unfunded_402`), and the walk cools that key as `logging` would (same metric, same warn line) before moving on. OpenRouter's `402` may be one request larger than the balance ("This request requires more credits"), which must not cool a shared key (D180, D200), - so an OpenRouter `402` the walk fails over on cools nothing; one it relays (OpenRouter last in the - row, as it is unless the row leads with it or `x-beyond-order` puts it first) is read and cooled - as above. An abandoned `FullBody` attempt never cools from its body in `logging`, so a body that + so one OpenRouter `402` the walk fails over on cools nothing by itself; one it relays (OpenRouter + last in the row, as it is unless the row leads with it or `x-beyond-order` puts it first) is read + and cooled as above. An abandoned `FullBody` attempt never cools from its body in `logging`, so a body that raced the parent's drop is not counted twice. No work on any other status. +- **A run of unread OpenRouter `402`s cools the key (D261).** Each OpenRouter `402` the walk fails + over on (either abandoning path) is a strike against that pool key + (`Provider::strike_unread_402`, a relaxed `AtomicU32` beside the key's cooldown); the + `OPENROUTER_402_STRIKES`th (3) in a row cools it through the same path as D258 (same metric + reason `unfunded`, same warn line). Any 2xx from the key resets its count + (`Provider::key_served`: one relaxed load on the 2xx path, and a store only when the count is + non-zero), and any cooling spends it. A key already cooling does not count the `402`s of requests + sent before it cooled, so a burst cools it once. A too-costly `402` is that request's, so a funded + account's next ordinary request resets the count; a near-empty account sent only large requests + may cool for `KEY_COOLDOWN`, which is the accepted cost. A relayed OpenRouter `402` is read + instead: out of credit cools (and so resets), too costly neither counts nor resets. Checking the + balance out of band was rejected: `GET /api/v1/key` reports only a per-key limit (null for a key + drawing on account credit) and `GET /api/v1/credits` needs a management key. Per replica, in + memory, nothing stored. - **When every candidate 5xxes, the client gets the last provider's own status**, not a synthetic error. Better diagnostics than an exhausted retry loop produces. @@ -2902,7 +2916,7 @@ already gone gets nothing, and a response that has started cannot be replaced. | Client stalls mid-upload (stops sending, connection open) | Ends at the first body read timeout: pingora's HTTP/1.1 one (60s), or `read_timeout_secs` on the upstream (the only clock for h2c). Either way a JSON 408 (`request body timed out`), the client's own timeout: no failover, no breaker failure, no key cooled, nothing billed (D260). | Client retry, which is a fresh request. `tests/cancellation.rs` pins it over HTTP/1.1, h2c and chunked. | | Provider brownout (sustained 5xx) | After `circuit_breaker_threshold` 5xx/connect failures in the window that are also at least half its outcomes (so a 50% brownout counts), the breaker opens; requests fast-fail 503 (`circuit_open`) instead of stalling against the read timeout. | Auto: after `circuit_breaker_reset_secs` a half-open probe is admitted — success closes the breaker, failure reopens it. Per-provider, so other providers are unaffected. | | Provider throttles (429 storm) | Walk the next unused pool key on the same provider when the body is replayable; the last 429 is relayed with `Retry-After` if the upstream sent one. Does **not** trip the breaker (provider is healthy). Does **not** fail over to another vendor. | Client `Retry-After` backoff after keys are exhausted; no gateway-side circuit action. | -| Pool key out of credit (a credit-balance 400, `insufficient_quota`) | Relayed with a neutral message (the head is relayed before the body says why), the key cooled off for 60s (`ai_key_auth_failures_total{reason="unfunded"}`); a catalog walk leaves the provider out while all its keys cool, so later requests go to the row's next candidate (D180). A `402` a catalog walk fails over on is served by the next candidate and cools the key at the head, except OpenRouter's (D258). Not a breaker failure. | Fund the account or replace the key; the warn line `pool key is out of credit` names provider and key index. | +| Pool key out of credit (a credit-balance 400, `insufficient_quota`) | Relayed with a neutral message (the head is relayed before the body says why), the key cooled off for 60s (`ai_key_auth_failures_total{reason="unfunded"}`); a catalog walk leaves the provider out while all its keys cool, so later requests go to the row's next candidate (D180). A `402` a catalog walk fails over on is served by the next candidate and cools the key at the head (D258); OpenRouter's cools it on the third in a row with no 2xx between (D261). Not a breaker failure. | Fund the account or replace the key; the warn line `pool key is out of credit` names provider and key index. | | Pool key revoked (401) | Walk the next pool key on the same provider when the body is replayable, and cool the refused key off for 60s so later requests start on a good one (`ai_key_auth_failures_total{reason="revoked"}`; a 403 naming the key counts as `key_named_403`). The last key's 401 is relayed on a provider route, a candidate failure on a catalog walk. A 403 never walks or cools (a catalog walk fails over on it), except that one whose body names the key cools it. Not a breaker failure. | Replace the key in config; the metric says which provider (log line names the key index). | | Response body > 128KB before usage chunk | Tail compaction fires: `drain(..half)` discards first half, keeps tail. Usage extracted from retained tail. | No action — SSE usage is always in the final `data:` line, which always lands in the tail. | | Client cancels mid-request (ESC on a slow turn) | Relayed as a downstream abort. **Not** counted against the provider's breaker — pingora tags it `ErrorSource::Downstream`. A streaming 2xx cut short this way is billed an estimate (`usage_estimated=true`), not zero. The tenant slot is released. | None. `tests/cancellation.rs` pins the breaker halves; `tests/cut_short.rs` the billing. | diff --git a/crates/gateway/src/proxy.rs b/crates/gateway/src/proxy.rs index 21215c1b..1fa7931d 100644 --- a/crates/gateway/src/proxy.rs +++ b/crates/gateway/src/proxy.rs @@ -1770,6 +1770,23 @@ impl AiProxy { provider.mark_key_bad(key); } + /// Judge a `402` a catalog walk abandons at its head, unread (`by_status`: `None` for any other + /// answer, else [`remedy::unfunded_402`]'s verdict). Out of credit by its status alone: cool + /// the key (D258). OpenRouter's, which may be one request too costly instead: a strike against + /// the key, and the [`route::OPENROUTER_402_STRIKES`]th in a row with no 2xx between cools it + /// (D261). A relayed 402 is read by `logging` instead: out of credit cools the key (which spends + /// its strikes), too costly neither counts nor resets one. + fn abandon_402(&self, rc: &RequestCtx, by_status: Option, status: u16) { + let cool = match by_status { + Some(true) => true, + Some(false) => rc.provider.strike_unread_402(rc.pool_key), + None => false, + }; + if cool { + self.cool_unfunded_key(&rc.request_id, &rc.provider, rc.pool_key, status); + } + } + /// Resolve a 2xx's pending health verdict from the first response bytes: count an /// error-in-200 against the candidate's breaker. fn settle_health(&self, rc: &mut RequestCtx, chunk: &[u8], end_of_stream: bool) { @@ -5010,6 +5027,10 @@ impl ProxyHttp for AiProxy { return Ok(()); }; let status = upstream_response.status.as_u16(); + // A 2xx says this key's account pays: forget its unread OpenRouter 402s (D261). + if rc.managed && (200..300).contains(&status) { + rc.provider.key_served(rc.pool_key); + } // Managed 401: this pool key is revoked (D71). Never the caller's fault. Cool it off so // later requests start on a good key, then walk like a 429. Not a 403 (D84, see @@ -5101,14 +5122,12 @@ impl ProxyHttp for AiProxy { // tells `logging` an account is out of credit (D180), and every later request would pay a // round trip to it first. A 402 says so by its status alone except on OpenRouter, whose // 402 may be one request too large for the balance (`remedy::unfunded_402`): cool that key - // here, as `logging` would have, on either abandoning path below (D258). - let unfunded = key_failure - && status == 402 - && rc - .auto - .as_ref() - .and_then(|a| a.candidate_at(at)) - .is_some_and(|c| remedy::unfunded_402(c.provider)); + // here, as `logging` would have, on either abandoning path below (D258). OpenRouter's + // unread 402 is a strike against its key instead, and enough in a row cool it (D261). + let unfunded_402 = (key_failure && status == 402) + .then(|| rc.auto.as_ref().and_then(|a| a.candidate_at(at))) + .flatten() + .map(|c| remedy::unfunded_402(c.provider)); // Fail over only when the body is **provably** replayable: fully read, and small enough // that pingora buffered all of it. // @@ -5143,8 +5162,8 @@ impl ProxyHttp for AiProxy { ); rc.relay_abandoned = fb.record(RelayRetry::Candidate(orig)); // Not recorded (the final attempt): this answer is relayed and `logging` reads it. - if unfunded && rc.relay_abandoned { - self.cool_unfunded_key(&rc.request_id, &rc.provider, rc.pool_key, status); + if rc.relay_abandoned { + self.abandon_402(rc, unfunded_402, status); } return Ok(()); } @@ -5178,9 +5197,7 @@ impl ProxyHttp for AiProxy { { b.record_success_for(permit); } - if unfunded { - self.cool_unfunded_key(&rc.request_id, &rc.provider, rc.pool_key, status); - } + self.abandon_402(rc, unfunded_402, status); rc.advance_candidate(at); let mut e = pingora_core::Error::new(pingora_core::ErrorType::HTTPStatus(status)); e.set_retry(true); diff --git a/crates/gateway/src/route.rs b/crates/gateway/src/route.rs index 51716acd..0687ce28 100644 --- a/crates/gateway/src/route.rs +++ b/crates/gateway/src/route.rs @@ -26,7 +26,7 @@ use crate::circuit_breaker::CircuitBreaker; use crate::metrics::ProviderMetrics; use crate::secret::Secret; use std::sync::OnceLock; -use std::sync::atomic::{AtomicU64, Ordering}; +use std::sync::atomic::{AtomicU32, AtomicU64, Ordering}; use std::time::{Duration, Instant}; /// The shared provider table. `KNOWN_PROVIDERS` is the gateway-routable subset — the BYO-only rows @@ -592,6 +592,11 @@ pub struct PoolAuth { /// round trip to a revoked or unfunded key on every request. Shared across requests; relaxed /// ordering, since a stale read costs only one more walk. bad_until_ms: AtomicU64, + /// OpenRouter `402`s on this key whose cause went unread (a catalog walk failed over on the + /// head, so the body never said whether the account is empty or one request was too costly) + /// since its last 2xx or cooldown: [`OPENROUTER_402_STRIKES`] in a row cool it (D261). Zero + /// on every other provider's keys. Relaxed, like `bad_until_ms`. + unread_402s: AtomicU32, } impl PoolAuth { @@ -651,6 +656,11 @@ pub fn key_finders(key: &str) -> Box<[memchr::memmem::Finder<'static>]> { /// skipped as a request's first key. pub const KEY_COOLDOWN: Duration = Duration::from_secs(60); +/// How many OpenRouter `402`s in a row, unread and with no 2xx from the key between them, cool the +/// key as out of credit (D261). A `402` that is one request too costly for a funded account is +/// that request's, so a success soon resets the count; an empty account answers every request so. +pub const OPENROUTER_402_STRIKES: u32 = 3; + /// Monotonic milliseconds since the first call, plus one (so 0 stays "never failed"). Coarse /// enough for a cooldown, and an `AtomicU64` holds it where an `Instant` would need a lock. fn clock_ms() -> u64 { @@ -725,6 +735,33 @@ impl Provider { let cooldown = u64::try_from(KEY_COOLDOWN.as_millis()).unwrap_or(u64::MAX); k.bad_until_ms .store(clock_ms().saturating_add(cooldown), Ordering::Relaxed); + // Cooled: the strikes are spent. Once the cooldown passes the key starts afresh. + k.unread_402s.store(0, Ordering::Relaxed); + } + } + + /// Count an OpenRouter `402` on pool key `i` whose body went unread (D261): whether it is the + /// [`OPENROUTER_402_STRIKES`]th in a row, which cools the key (the caller does, through the + /// usual out-of-credit path). Exactly one of any concurrent strikes past the threshold + /// answers `true`, and a key already cooling does not count the `402`s of requests sent + /// before it cooled, so a burst cools it once. + pub fn strike_unread_402(&self, i: u8) -> bool { + self.pool_auth.get(usize::from(i)).is_some_and(|k| { + !k.cooling(clock_ms()) + && k.unread_402s + .fetch_add(1, Ordering::Relaxed) + .saturating_add(1) + == OPENROUTER_402_STRIKES + }) + } + + /// Pool key `i` answered a 2xx: its account pays, so forget its unread `402`s (D261). A load + /// and nothing else on the common path, where the count is already zero. + pub fn key_served(&self, i: u8) { + if let Some(k) = self.pool_auth.get(usize::from(i)) + && k.unread_402s.load(Ordering::Relaxed) != 0 + { + k.unread_402s.store(0, Ordering::Relaxed); } } @@ -766,6 +803,7 @@ impl Provider { key_at, finders, bad_until_ms: AtomicU64::new(0), + unread_402s: AtomicU32::new(0), } }) .collect(); @@ -1208,6 +1246,84 @@ mod tests { assert_eq!(p.first_key(), 0, "the cooldown has passed"); } + fn openrouter(keys: &[&str]) -> Provider { + Provider::resolve( + "openrouter", + "openrouter.ai:443".to_string(), + Dialect::OpenAi, + AuthScheme::Bearer, + keys, + ProviderMetrics::disconnected(), + None, + ) + } + + /// Strike `p`'s key `i` until a strike says to cool it, then cool it as the proxy does: how + /// many strikes that took, or `None` past twice the threshold. + fn strike_until_cooled(p: &Provider, i: u8) -> Option { + (1..=OPENROUTER_402_STRIKES * 2).find(|_| { + let cool = p.strike_unread_402(i); + if cool { + p.mark_key_bad(i); + } + cool + }) + } + + /// The [`OPENROUTER_402_STRIKES`]th unread 402 in a row cools the key, a 2xx between them + /// starts the count over, and the count is per key (D261). + #[test] + fn unread_402s_in_a_row_cool_only_their_own_key() { + let p = openrouter(&["sk-a", "sk-b"]); + for _ in 1..OPENROUTER_402_STRIKES { + assert!(!p.strike_unread_402(0)); + } + p.key_served(0); + p.key_served(1); + for _ in 1..OPENROUTER_402_STRIKES { + assert!(!p.strike_unread_402(0), "a 2xx started the count over"); + assert!(!p.strike_unread_402(1), "key 1's count is its own"); + } + assert!(p.strike_unread_402(0)); + assert!( + !p.strike_unread_402(0), + "a strike racing the cooling one past the threshold does not cool it again" + ); + p.mark_key_bad(0); + assert_eq!(p.first_key(), 1); + assert!(p.strike_unread_402(1), "key 1 had its own run"); + assert!(!p.strike_unread_402(9), "no such key"); + } + + /// A cooling key does not count the 402s of requests sent before it cooled; once its cooldown + /// passes it needs a full run again (D261). + #[test] + fn a_cooled_key_counts_afresh_once_its_cooldown_has_passed() { + let p = openrouter(&["sk-a", "sk-b"]); + assert_eq!(strike_until_cooled(&p, 0), Some(OPENROUTER_402_STRIKES)); + for _ in 0..OPENROUTER_402_STRIKES * 2 { + assert!(!p.strike_unread_402(0), "cooling: not counted"); + } + assert_eq!(p.pool_auth[0].unread_402s.load(Ordering::Relaxed), 0); + p.pool_auth[0] + .bad_until_ms + .store(clock_ms().saturating_add(50), Ordering::Relaxed); + std::thread::sleep(Duration::from_millis(80)); + assert_eq!(p.first_key(), 0, "the cooldown has passed"); + assert_eq!(strike_until_cooled(&p, 0), Some(OPENROUTER_402_STRIKES)); + } + + /// Any cooling (a 401's too) spends the strikes, so a key back from it needs a full run. + #[test] + fn cooling_a_key_spends_its_strikes() { + let p = openrouter(&["sk-a"]); + for _ in 1..OPENROUTER_402_STRIKES { + assert!(!p.strike_unread_402(0)); + } + p.mark_key_bad(0); + assert_eq!(p.pool_auth[0].unread_402s.load(Ordering::Relaxed), 0); + } + #[test] fn precomputed_header_values_match_the_string_form() { // The per-request insert now clones these instead of re-validating and re-copying the diff --git a/crates/gateway/tests/common/mod.rs b/crates/gateway/tests/common/mod.rs index ee2d1a6c..a917583f 100644 --- a/crates/gateway/tests/common/mod.rs +++ b/crates/gateway/tests/common/mod.rs @@ -518,6 +518,10 @@ pub enum Mode { /// Reply with exactly this status, content type, and body — for fixtures that belong to one /// test file (a provider's real stream shape, an error body with no `error` key). Raw(u16, &'static str, &'static str), + /// [`Raw`](Mode::Raw) for a request whose body contains the marker (the first field), the + /// [`Json`](Mode::Json) 200 otherwise: one upstream that refuses some requests and serves the + /// rest, as OpenRouter does a request too costly for the balance left. + RawWhenBody(&'static str, u16, &'static str, &'static str), /// Answer with this status, then never send the body: an upstream that fails and hangs. The /// gateway must not wait on an attempt it abandoned. StatusThenStall(u16), @@ -739,7 +743,11 @@ fn canned_body(mode: Mode) -> (&'static str, Bytes) { // A slow reply, and the surviving requests of a close-on-Nth mock, are ordinary successes. Mode::StallSse => ("text/event-stream", Bytes::from(stall_sse(false))), Mode::AnthropicStallSse => ("text/event-stream", Bytes::from(stall_sse(true))), - Mode::Json | Mode::Slow(_) | Mode::CloseOnReusedConnection | Mode::ThrottleKey(_) => ( + Mode::Json + | Mode::Slow(_) + | Mode::CloseOnReusedConnection + | Mode::ThrottleKey(_) + | Mode::RawWhenBody(..) => ( "application/json", Bytes::from_static(CANNED_JSON.as_bytes()), ), @@ -880,6 +888,16 @@ async fn mock_handle( // not retry — correctly, since it cannot know how much the upstream consumed. Draining first // puts the failure squarely on the response-header read, which is the `ReusedOnly` shape this // mode exists to produce. + let mode = match mode { + Mode::RawWhenBody(marker, status, ct, raw) => { + if memchr::memmem::find(&body, marker.as_bytes()).is_some() { + Mode::Raw(status, ct, raw) + } else { + Mode::Json + } + } + m => m, + }; if matches!(mode, Mode::CloseOnReusedConnection) && on_conn > 0 { return Err(std::io::Error::other("mock closing a reused connection")); } diff --git a/crates/gateway/tests/reliability_openrouter_402.rs b/crates/gateway/tests/reliability_openrouter_402.rs new file mode 100644 index 00000000..c3f7de8a --- /dev/null +++ b/crates/gateway/tests/reliability_openrouter_402.rs @@ -0,0 +1,249 @@ +//! An OpenRouter `402` a catalog walk fails over on is read at the head only, so it cannot say +//! whether the account is out of credit or one request was too costly for the balance left (D258). +//! A run of them on one key with no success between is the account: the key cools (D261). +//! +//! Run via `mise run test:integration:rs`. + +#![allow(clippy::unwrap_used, clippy::expect_used, clippy::panic)] + +mod common; + +use beyond_ai::route::OPENROUTER_402_STRIKES; +use common::*; + +/// OpenRouter's answer on an account with no credit left. +const OPENROUTER_NO_CREDIT: &str = r#"{"error":{"message":"Insufficient credits. This account never purchased credits. Make sure your key is on the correct account or org, and if so, purchase more at https://openrouter.ai/settings/credits","code":402}}"#; + +/// OpenRouter's answer to one request larger than a funded balance can pay for. +const OPENROUTER_TOO_COSTLY: &str = r#"{"error":{"message":"This request requires more credits, or fewer max_tokens. You requested up to 64000 tokens, but can only afford 1234. To increase, visit https://openrouter.ai/settings/credits and add more credits","code":402}}"#; + +/// What the too-costly mock refuses: a request whose prompt says so. +const TOO_BIG: &str = "too-big"; + +/// [`OPENROUTER_402_STRIKES`] as a request count. +fn strikes() -> usize { + usize::try_from(OPENROUTER_402_STRIKES).unwrap() +} + +/// One managed request on claude-opus-4-8 with OpenRouter first: (status, served by, body). +async fn send(gw: &Gateway, key: &str, prompt: &str) -> (u16, Option, String) { + let resp = test_client() + .post(format!("{}/v1/chat/completions", gw.url())) + .header("authorization", format!("Bearer {key}")) + .header("content-type", "application/json") + .header("x-beyond-order", "openrouter,anthropic") + .body(format!( + r#"{{"model":"claude-opus-4-8","messages":[{{"role":"user","content":"{prompt}"}}]}}"# + )) + .send() + .await + .unwrap(); + let status = resp.status().as_u16(); + let by = resp + .headers() + .get("x-beyond-provider") + .map(|v| v.to_str().unwrap().to_owned()); + (status, by, resp.text().await.unwrap()) +} + +async fn gateway(openrouter: &MockUpstream, anthropic: &MockUpstream, pubkey: &[u8]) -> Gateway { + Gateway::builder(unused_nats_port(), &anthropic.authority(), &b64(pubkey)) + .providers(&["anthropic", "openrouter"]) + .provider_authority("openrouter", &openrouter.authority()) + .provider_authority("anthropic", &anthropic.authority()) + .start() + .await +} + +/// OpenRouter leads the walk and 402s every request: each fails over to Anthropic and is served, +/// and the [`OPENROUTER_402_STRIKES`]th in a row cools OpenRouter's key, so every request after +/// it goes straight to Anthropic. Holds for a body pingora replays and for one past its 64 KiB +/// retry buffer, which fails over by a `FullBody` re-run. +/// claim: REL-4 +/// defect: D261 +#[tokio::test] +async fn openrouter_402s_in_a_row_cool_its_key() { + let (pubkey, sk) = test_keypair(161); + let key = billing_vkey(&sk, 161); + let large = "x".repeat(100 * 1024); + let mut failures = Vec::new(); + for prompt in ["hi", large.as_str()] { + let size = prompt.len(); + let openrouter = + MockUpstream::start(Mode::Raw(402, "application/json", OPENROUTER_NO_CREDIT)).await; + let anthropic = MockUpstream::start(Mode::AnthropicJson).await; + let gw = gateway(&openrouter, &anthropic, &pubkey).await; + let requests = strikes() + 3; + for n in 1..=requests { + let (status, by, text) = send(&gw, &key, prompt).await; + if status != 200 || by.as_deref() != Some("anthropic") { + failures.push(format!( + "({size} B) request {n}: {status} by {by:?}: {text}" + )); + } + } + let cooled = gw + .metric("ai_key_auth_failures_total", r#"reason="unfunded""#) + .await; + if openrouter.hits() != strikes() || anthropic.hits() != requests || cooled != 1.0 { + failures.push(format!( + "({size} B): {} hits on OpenRouter (want {}), {} on Anthropic (want {requests}), {cooled} keys cooled (want 1)", + openrouter.hits(), + strikes(), + anthropic.hits(), + )); + } + if !gw.log().contains("pool key is out of credit; cooling it") { + failures.push(format!("({size} B): no cooling warn line")); + } + if !failures.is_empty() { + failures.push(gw.log()); + break; + } + } + assert!(failures.is_empty(), "{}", failures.join("\n\n")); +} + +/// A funded OpenRouter account refuses only the requests too costly for its balance. Runs of +/// those one short of [`OPENROUTER_402_STRIKES`], each ended by a request OpenRouter serves, never +/// cool the key: every request reaches OpenRouter, the costly ones fail over to Anthropic and the +/// rest are served by OpenRouter. +/// claim: REL-4 +/// defect: D261 +#[tokio::test] +async fn too_costly_openrouter_402s_between_successes_never_cool_its_key() { + let (pubkey, sk) = test_keypair(162); + let key = billing_vkey(&sk, 162); + let openrouter = MockUpstream::start(Mode::RawWhenBody( + TOO_BIG, + 402, + "application/json", + OPENROUTER_TOO_COSTLY, + )) + .await; + let anthropic = MockUpstream::start(Mode::AnthropicJson).await; + let gw = gateway(&openrouter, &anthropic, &pubkey).await; + let mut failures = Vec::new(); + let mut sent = 0; + let mut costly = 0; + for round in 1..=3 { + for _ in 1..strikes() { + let (status, by, text) = send(&gw, &key, TOO_BIG).await; + sent += 1; + costly += 1; + if status != 200 || by.as_deref() != Some("anthropic") { + failures.push(format!("round {round}, costly: {status} by {by:?}: {text}")); + } + } + let (status, by, text) = send(&gw, &key, "hi").await; + sent += 1; + if status != 200 || by.as_deref() != Some("openrouter") { + failures.push(format!("round {round}, small: {status} by {by:?}: {text}")); + } + } + let cooled = gw + .metric("ai_key_auth_failures_total", r#"reason="unfunded""#) + .await; + if openrouter.hits() != sent || anthropic.hits() != costly || cooled != 0.0 { + failures.push(format!( + "{} hits on OpenRouter (want {sent}), {} on Anthropic (want {costly}), {cooled} keys cooled (want 0)", + openrouter.hits(), + anthropic.hits(), + )); + } + if !failures.is_empty() { + failures.push(gw.log()); + } + assert!(failures.is_empty(), "{}", failures.join("\n\n")); +} + +/// Many requests 402 on OpenRouter at once: every one is served by Anthropic, and the key is cooled +/// once, not once per [`OPENROUTER_402_STRIKES`] of the burst (a key already cooling does not +/// count the 402s of requests sent before it cooled). +/// claim: REL-4 +/// defect: D261 +#[tokio::test] +async fn a_burst_of_openrouter_402s_cools_its_key_once() { + let (pubkey, sk) = test_keypair(163); + let key = billing_vkey(&sk, 163); + let openrouter = + MockUpstream::start(Mode::Raw(402, "application/json", OPENROUTER_NO_CREDIT)).await; + let anthropic = MockUpstream::start(Mode::AnthropicJson).await; + let gw = gateway(&openrouter, &anthropic, &pubkey).await; + let burst = 24; + let mut tasks = Vec::with_capacity(burst); + for _ in 0..burst { + let (url, key) = (gw.url(), key.clone()); + tasks.push(tokio::spawn(async move { + let resp = test_client() + .post(format!("{url}/v1/chat/completions")) + .header("authorization", format!("Bearer {key}")) + .header("content-type", "application/json") + .header("x-beyond-order", "openrouter,anthropic") + .body(r#"{"model":"claude-opus-4-8","messages":[{"role":"user","content":"hi"}]}"#) + .send() + .await + .unwrap(); + resp.status().as_u16() + })); + } + let mut statuses = Vec::with_capacity(burst); + for t in tasks { + statuses.push(t.await.unwrap()); + } + // Then the key is cooling: this one goes straight to Anthropic. + let before = openrouter.hits(); + let (status, by, text) = send(&gw, &key, "hi").await; + let cooled = gw + .metric("ai_key_auth_failures_total", r#"reason="unfunded""#) + .await; + assert!( + statuses.iter().all(|s| *s == 200) + && status == 200 + && by.as_deref() == Some("anthropic") + && openrouter.hits() == before + && openrouter.hits() >= strikes() + && cooled == 1.0, + "burst statuses {statuses:?}; after it {status} by {by:?} ({text}); {} hits on OpenRouter ({before} before the last); {cooled} keys cooled (want 1)\n\n{}", + openrouter.hits(), + gw.log(), + ); +} + +/// Only a 402 is a strike. A 403 the walk fails over on is a refusal of this request or account, +/// never a sign the key is out of credit (D84): however many come in a row, OpenRouter's key is not +/// cooled and every request still tries it first. +/// claim: REL-4 +/// defect: D261 +#[tokio::test] +async fn openrouter_403s_in_a_row_never_cool_its_key() { + let (pubkey, sk) = test_keypair(164); + let key = billing_vkey(&sk, 164); + let openrouter = MockUpstream::start(Mode::Raw( + 403, + "application/json", + r#"{"error":{"message":"forbidden","code":403}}"#, + )) + .await; + let anthropic = MockUpstream::start(Mode::AnthropicJson).await; + let gw = gateway(&openrouter, &anthropic, &pubkey).await; + let requests = strikes() + 2; + for n in 1..=requests { + let (status, by, text) = send(&gw, &key, "hi").await; + assert_eq!( + (status, by.as_deref()), + (200, Some("anthropic")), + "request {n}: {text}\n{}", + gw.log() + ); + } + let cooled = gw + .metric("ai_key_auth_failures_total", r#"reason="unfunded""#) + .await; + assert_eq!( + (openrouter.hits(), cooled), + (requests, 0.0), + "every request tries OpenRouter and no key cools\n{}", + gw.log() + ); +} diff --git a/crates/gateway/tests/reliability_unfunded_key.rs b/crates/gateway/tests/reliability_unfunded_key.rs index 3846abf6..0e5ead3c 100644 --- a/crates/gateway/tests/reliability_unfunded_key.rs +++ b/crates/gateway/tests/reliability_unfunded_key.rs @@ -7,6 +7,7 @@ mod common; +use beyond_ai::route::OPENROUTER_402_STRIKES; use common::*; use serde_json::Value; @@ -268,7 +269,8 @@ async fn an_unfunded_candidate_cools_off_from_any_catalog_slot() { /// next candidate, and every request after it, for the cooldown, goes straight to it. OpenRouter's /// 402 can instead be one request larger than the balance ("This request requires more credits"), /// which a smaller request is not: that one fails over too, and cools nothing, so OpenRouter keeps -/// getting the row's requests. Both hold for a body pingora replays and for one past its 64 KiB +/// getting the row's requests (until enough arrive in a row with no success between them: D261, +/// `reliability_openrouter_402.rs`, so this sends one fewer). Both hold for a body pingora replays and for one past its 64 KiB /// retry buffer, which fails over by a `FullBody` re-run. /// claim: REL-4 /// defect: D258 @@ -311,7 +313,9 @@ async fn a_402_the_walk_fails_over_on_cools_an_unfunded_key() { .provider_authority(next, &serving.authority()) .start() .await; - for n in 1..=3 { + // Below OpenRouter's strike count (D261), which would cool its key. + let requests = if cools { 3 } else { strikes() - 1 }; + for n in 1..=requests { let resp = test_client() .post(format!("{}/v1/chat/completions", gw.url())) .header("authorization", format!("Bearer {key}")) @@ -338,8 +342,8 @@ async fn a_402_the_walk_fails_over_on_cools_an_unfunded_key() { let cooled = gw .metric("ai_key_auth_failures_total", r#"reason="unfunded""#) .await; - let (want_hits, want_cooled) = if cools { (1, 1.0) } else { (3, 0.0) }; - if refusing.hits() != want_hits || serving.hits() != 3 || cooled != want_cooled { + let (want_hits, want_cooled) = if cools { (1, 1.0) } else { (requests, 0.0) }; + if refusing.hits() != want_hits || serving.hits() != requests || cooled != want_cooled { failures.push(format!( "{first} ({size} B): {} hits on its 402 (want {want_hits}), {} on {next}, {cooled} keys cooled (want {want_cooled})", refusing.hits(), @@ -353,3 +357,8 @@ async fn a_402_the_walk_fails_over_on_cools_an_unfunded_key() { } assert!(failures.is_empty(), "{}", failures.join("\n\n")); } + +/// [`OPENROUTER_402_STRIKES`] as a request count. +fn strikes() -> usize { + usize::try_from(OPENROUTER_402_STRIKES).unwrap() +} diff --git a/verify/defects.toml b/verify/defects.toml index c19e1f91..ff92ff4e 100644 --- a/verify/defects.toml +++ b/verify/defects.toml @@ -2568,7 +2568,7 @@ claims = ["REL-4"] state = "fixed" test = "a_402_the_walk_fails_over_on_cools_an_unfunded_key" fix = "a7c753a" -note = "Reading the refused 402's body before abandoning it, as first proposed, is not possible: pingora 0.9's upstream_response_filter gets the head only, the upstream session is not reachable from any hook, and an Err there drops the connection with the body unread (the same reason D180 could not fail over the request that saw the answer). So the status decides, where it can: remedy::unfunded_402 says a 402 is out of credit by its status alone on every provider but OpenRouter, whose 402 may be one request larger than the balance (\"This request requires more credits\", which must not cool the shared key: D180, D200). upstream_response_filter cools the key (AiProxy::cool_unfunded_key: same metric reason, same warn line as logging's D180 path) on both abandoning paths, the in-place retry and a recorded FullBody retry; a FullBody final attempt is relayed and cooled from its body as before. No new state (Provider::mark_key_bad, the existing key cooldown) and no work on any other status, the 2xx path included. logging no longer cools from the body of an abandoned FullBody attempt (relay_abandoned), which raced the parent's drop and would count a head-cooled 402 twice; this also makes a FullBody key walk's abandoned bodies deterministically unread, as ARCHITECTURE.md already said. Limit: an OpenRouter 402 the walk fails over on still cools nothing, so a row that leads with OpenRouter (or an x-beyond-order that puts it first) keeps a round trip to an unfunded OpenRouter account; by default the aggregator is last in the walk (D253), where its 402 is relayed and cooled from the body. Also tested: remedy::tests::only_openrouter_needs_the_body_of_a_402; the same test asserts the OpenRouter too-costly 402 fails over and cools nothing (OpenRouter is sent all three requests) for both body sizes." +note = "Reading the refused 402's body before abandoning it, as first proposed, is not possible: pingora 0.9's upstream_response_filter gets the head only, the upstream session is not reachable from any hook, and an Err there drops the connection with the body unread (the same reason D180 could not fail over the request that saw the answer). So the status decides, where it can: remedy::unfunded_402 says a 402 is out of credit by its status alone on every provider but OpenRouter, whose 402 may be one request larger than the balance (\"This request requires more credits\", which must not cool the shared key: D180, D200). upstream_response_filter cools the key (AiProxy::cool_unfunded_key: same metric reason, same warn line as logging's D180 path) on both abandoning paths, the in-place retry and a recorded FullBody retry; a FullBody final attempt is relayed and cooled from its body as before. No new state (Provider::mark_key_bad, the existing key cooldown) and no work on any other status, the 2xx path included. logging no longer cools from the body of an abandoned FullBody attempt (relay_abandoned), which raced the parent's drop and would count a head-cooled 402 twice; this also makes a FullBody key walk's abandoned bodies deterministically unread, as ARCHITECTURE.md already said. Limit: an OpenRouter 402 the walk fails over on still cools nothing, so a row that leads with OpenRouter (or an x-beyond-order that puts it first) keeps a round trip to an unfunded OpenRouter account (lifted by D261: a run of them cools the key); by default the aggregator is last in the walk (D253), where its 402 is relayed and cooled from the body. Also tested: remedy::tests::only_openrouter_needs_the_body_of_a_402; the same test asserts the OpenRouter too-costly 402 fails over and cools nothing (OpenRouter is sent all three requests) for both body sizes." [[defect]] id = "D259" @@ -2595,5 +2595,19 @@ evidence = "Hermetic (cancellation.rs, read_timeout_secs = 1, primary and fallba claims = ["REL-1", "SEC-16", "BIL-3"] state = "fixed" test = "a_client_stalled_mid_upload_is_not_failed_over" -fix = "3e5c0d3" +fix = "f470b2b" note = "Fixed: error_while_proxy retags a ReadTimedout while the client still owes body bytes (client_stalled_upload: body_bytes_fed > 0 and !is_body_done, any source) as a downstream error before the delivered/failover decision. The walk ends with no failover, logging releases the breaker permit, body_delivered stays false (no estimate, outcome client_cancelled), and fail_to_proxy answers 408 'request body timed out', the same answer as pingora's HTTP/1.1 body read timeout. Zero bytes fed is excluded (an Expect: 100-continue client waits on the provider). Error path only. Not changed: pingora marks an HTTP/2 upstream connection for shutdown on any upstream read timeout before the hook runs. A chunked body on a catalog walk is read whole before connecting, so its stall is pingora's downstream 408; a_client_stalled_mid_chunked_upload_times_out_as_its_own pins a streamed chunked stall on a provider route." + +[[defect]] +id = "D261" +severity = "low" +area = "Reliability" +title = "An OpenRouter 402 a catalog walk fails over on never cools its key: a walk that leads with OpenRouter pays a round trip to an unfunded account on every request" +impact = "D258 cools a 402 the walk fails over on by its status alone, except OpenRouter's, whose 402 may be one request too costly for a funded balance (which must not cool a shared key: D180, D200) and whose body a failover never reads. So a row that leads with OpenRouter, or an x-beyond-order that puts it first, sent every request to an OpenRouter account with no credit left before failing over, for as long as it stayed unfunded." +confidence = "high" +evidence = "Hermetic: openrouter_402s_in_a_row_cool_its_key. With x-beyond-order openrouter,anthropic on claude-opus-4-8 and an OpenRouter mock answering an out-of-credit 402, before the fix OpenRouter was sent all six requests (each failed over to Anthropic and served 200) and ai_key_auth_failures_total{reason=\"unfunded\"} read 0; the limit D258's note recorded." +claims = ["REL-4"] +state = "fixed" +test = "openrouter_402s_in_a_row_cool_its_key" +fix = "0357214" +note = "Checking the balance out of band was rejected: OpenRouter's GET /api/v1/key answers an inference key with its own spending limit only (limit_remaining is null for a key that draws on account credit, the common case), and GET /api/v1/credits, the account balance, needs a management key, which cannot make completions and the gateway does not hold. Fixed by a heuristic instead: each OpenRouter 402 the walk fails over on (either abandoning path: in-place retry, recorded FullBody retry) is a strike against that pool key (Provider::strike_unread_402: a relaxed AtomicU32 beside the key's cooldown, per replica, nothing stored), and route::OPENROUTER_402_STRIKES (3) in a row cool it through AiProxy::cool_unfunded_key (same metric reason, same warn line as D180/D258). Any 2xx from the key resets the count (Provider::key_served in upstream_response_filter: one relaxed load, a store only when non-zero) and any cooling spends it; a key already cooling does not count the 402s of requests sent before it cooled, so a burst cools it once. A relayed OpenRouter 402 is read as before: out of credit cools, too costly neither counts nor resets. Cost: a near-empty account sent only requests too costly for it may cool for KEY_COOLDOWN although a smaller request would be served. Also tested: too_costly_openrouter_402s_between_successes_never_cool_its_key, a_burst_of_openrouter_402s_cools_its_key_once, route::tests::{unread_402s_in_a_row_cool_only_their_own_key, a_cooled_key_counts_afresh_once_its_cooldown_has_passed, cooling_a_key_spends_its_strikes}; D258's test now sends one fewer than the strike count for its OpenRouter case."