diff --git a/crates/aisix-core/src/models/guardrail.rs b/crates/aisix-core/src/models/guardrail.rs index 9b55fb97c..7b7514f9f 100644 --- a/crates/aisix-core/src/models/guardrail.rs +++ b/crates/aisix-core/src/models/guardrail.rs @@ -860,20 +860,39 @@ pub struct GuardrailMonitorHit { /// reason, and any upstream detail are never captured (#153 / #932 /// no-leak criterion). /// -/// One entry per `(guardrail_name, hook, action)`: a guardrail that masks -/// forty string leaves of one tool result reports a single entry whose -/// `counts` and `duration_us` are summed across those leaves. +/// One entry per `(guardrail_name, hook, action, error_type)`: a guardrail +/// that masks forty string leaves of one tool result reports a single entry +/// whose `counts` and `duration_us` are summed across those leaves. +/// +/// An empty array alongside `guardrail_blocked: true` is a legitimate +/// state, not a contradiction: a streamed response aborted by the +/// guardrail buffer cap is refused without any member returning a verdict, +/// so there is no policy to name. Read the array as "which policies acted, +/// when one did", never as an inverse of the boolean. #[derive(Debug, Clone, Default, PartialEq, Eq, Serialize, Deserialize)] pub struct GuardrailEnforcedHit { /// The configured (row) name of the guardrail that fired. pub guardrail_name: String, /// Which side it fired on: `input` or `output`. pub hook: String, - /// What it did: `masked` (content was rewritten and the request - /// continued) or `blocked` (the request was refused). + /// What it did: + /// + /// - `masked` — content was rewritten and the request continued. + /// - `blocked` — the guardrail's content policy refused the request. + /// - `blocked_unavailable` — the guardrail could not evaluate the + /// request and its configuration refuses what it cannot check + /// (`fail_open: false`, or a mandatory rule). The request was + /// refused because the check was unavailable, not because the + /// content matched a policy. pub action: String, + /// Why the check was unavailable, on `blocked_unavailable` only: a + /// short, bounded cause such as `lakera_timeout` or + /// `presidio_5xx`. Empty for every other action. + #[serde(default, skip_serializing_if = "String::is_empty")] + pub error_type: String, /// detector/rule name → number of spans masked (`masked` only; empty - /// for `blocked`). Same key space as `redacted_entity_counts`. + /// for the two refusal actions). Same key space as + /// `redacted_entity_counts`. #[serde(default, skip_serializing_if = "std::collections::BTreeMap::is_empty")] pub counts: std::collections::BTreeMap, /// Wall-clock time this guardrail spent on this hook, in @@ -907,7 +926,16 @@ pub struct GuardrailExecution<'a> { /// (monitor mode). pub result: &'static str, /// Bounded failure tag (e.g. `lakera_timeout`) when the guardrail could - /// not evaluate and failed open (`result = bypassed`); `None` otherwise. + /// not evaluate: on `result = bypassed` (it failed OPEN and the request + /// continued) and, since AISIX-Cloud#1365, on `result = blocked` when + /// it failed CLOSED and the request was refused instead. `None` for + /// every outcome the guardrail actually decided. + /// + /// `result` deliberately does not distinguish those two blocks — it is + /// a shipped metric label with alerting attached, and splitting its + /// value domain would silently stop an existing `result="blocked"` + /// alert from counting outages. `error_type != None` is the + /// discriminator on this side; the audit event uses a separate action. pub error_type: Option<&'a str>, /// Wall-clock time the member call took. pub elapsed: std::time::Duration, diff --git a/crates/aisix-guardrails/src/aliyun.rs b/crates/aisix-guardrails/src/aliyun.rs index d76fe13a3..63dbd0406 100644 --- a/crates/aisix-guardrails/src/aliyun.rs +++ b/crates/aisix-guardrails/src/aliyun.rs @@ -370,7 +370,10 @@ impl AliyunTextModerationGuardrail { if fail_open { GuardrailVerdict::Bypass { reason: tag.into() } } else { - GuardrailVerdict::block(format!("aliyun text moderation unavailable ({tag})")) + GuardrailVerdict::block_unavailable( + format!("aliyun text moderation unavailable ({tag})"), + tag, + ) } } } diff --git a/crates/aisix-guardrails/src/aliyun_ai_guardrail.rs b/crates/aisix-guardrails/src/aliyun_ai_guardrail.rs index 75109a9a5..97f44585b 100644 --- a/crates/aisix-guardrails/src/aliyun_ai_guardrail.rs +++ b/crates/aisix-guardrails/src/aliyun_ai_guardrail.rs @@ -601,7 +601,10 @@ impl AliyunAiGuardrail { if fail_open { GuardrailVerdict::Bypass { reason: tag.into() } } else { - GuardrailVerdict::block(format!("aliyun AI guardrail unavailable ({tag})")) + GuardrailVerdict::block_unavailable( + format!("aliyun AI guardrail unavailable ({tag})"), + tag, + ) } } } diff --git a/crates/aisix-guardrails/src/audit.rs b/crates/aisix-guardrails/src/audit.rs index 81b647803..925fd6c1e 100644 --- a/crates/aisix-guardrails/src/audit.rs +++ b/crates/aisix-guardrails/src/audit.rs @@ -23,16 +23,21 @@ use std::time::Duration; use aisix_core::models::GuardrailEnforcedHit; -/// Coalescing key: one entry per guardrail row, per hook, per action. -type HitKey = (String, &'static str, &'static str); +/// Coalescing key: one entry per guardrail row, per hook, per action — +/// and, for the one action that carries a cause, per cause. The cause is +/// part of the key rather than merged in because two different causes are +/// two different facts; in practice a member refuses at most once per +/// hook, so the extra dimension adds no entries. +type HitKey = (String, &'static str, &'static str, String); /// Per-request accumulator of enforced guardrail hits. /// /// Coalescing matters for correctness, not just tidiness: the redacting /// hooks run once per JSON string leaf on the `/mcp` path, so a tool /// result with forty scannable leaves would otherwise produce forty -/// identical entries. Entries merge by `(guardrail_name, hook, action)`, -/// summing per-detector counts and elapsed time. +/// identical entries. Entries merge by +/// `(guardrail_name, hook, action, error_type)`, summing per-detector +/// counts and elapsed time. #[derive(Debug, Default)] pub struct GuardrailAuditLog { hits: Mutex>, @@ -43,7 +48,10 @@ impl GuardrailAuditLog { Self::default() } - /// Record one enforcing outcome. `counts` is empty for `blocked`. + /// Record one enforcing outcome. `counts` is empty for both refusal + /// actions. `error_type` is the bounded cause carried by + /// `blocked_unavailable` and `None` everywhere else + /// (AISIX-Cloud#1365). /// /// A poisoned lock is swallowed rather than propagated: losing an /// audit entry is bad, but panicking a request that a guardrail just @@ -53,18 +61,26 @@ impl GuardrailAuditLog { guardrail_name: &str, hook: &'static str, action: &'static str, + error_type: Option<&str>, elapsed: Duration, counts: &BTreeMap, ) { let Ok(mut hits) = self.hits.lock() else { return; }; + let error_type = error_type.unwrap_or_default(); let entry = hits - .entry((guardrail_name.to_owned(), hook, action)) + .entry(( + guardrail_name.to_owned(), + hook, + action, + error_type.to_owned(), + )) .or_insert_with(|| GuardrailEnforcedHit { guardrail_name: guardrail_name.to_owned(), hook: hook.to_owned(), action: action.to_owned(), + error_type: error_type.to_owned(), ..Default::default() }); for (detector, n) in counts { @@ -76,7 +92,8 @@ impl GuardrailAuditLog { .saturating_add(elapsed.as_micros().min(u32::MAX as u128) as u32); } - /// Snapshot the hits recorded so far, in `(name, hook, action)` order. + /// Snapshot the hits recorded so far, in + /// `(name, hook, action, error_type)` order. /// /// Non-destructive on purpose: a handler that emits more than one /// usage event per request (a per-attempt event plus the terminal @@ -105,6 +122,7 @@ mod tests { "pii-guard", "output", "masked", + None, Duration::from_micros(40), &counts(&[("email", 2)]), ); @@ -112,6 +130,7 @@ mod tests { "pii-guard", "output", "masked", + None, Duration::from_micros(60), &counts(&[("email", 1), ("phone", 3)]), ); @@ -133,6 +152,7 @@ mod tests { "g", "input", "masked", + None, Duration::ZERO, &counts(&[("ip", 1)]), ); @@ -140,14 +160,16 @@ mod tests { "g", "output", "masked", + None, Duration::ZERO, &counts(&[("ip", 1)]), ); - log.record("g", "output", "blocked", Duration::ZERO, &none); + log.record("g", "output", "blocked", None, Duration::ZERO, &none); log.record( "other", "input", "masked", + None, Duration::ZERO, &counts(&[("ip", 1)]), ); @@ -176,7 +198,14 @@ mod tests { #[test] fn snapshot_does_not_drain() { let log = GuardrailAuditLog::new(); - log.record("g", "input", "blocked", Duration::ZERO, &BTreeMap::new()); + log.record( + "g", + "input", + "blocked", + None, + Duration::ZERO, + &BTreeMap::new(), + ); assert_eq!(log.snapshot().len(), 1); assert_eq!(log.snapshot().len(), 1); } diff --git a/crates/aisix-guardrails/src/bedrock.rs b/crates/aisix-guardrails/src/bedrock.rs index 134c61444..02faa2d95 100644 --- a/crates/aisix-guardrails/src/bedrock.rs +++ b/crates/aisix-guardrails/src/bedrock.rs @@ -300,7 +300,7 @@ impl BedrockGuardrail { reason: reason.into(), } } else { - GuardrailVerdict::block(format!("bedrock unavailable ({reason})")) + GuardrailVerdict::block_unavailable(format!("bedrock unavailable ({reason})"), reason) } } } diff --git a/crates/aisix-guardrails/src/build.rs b/crates/aisix-guardrails/src/build.rs index 11ecdc56c..923877543 100644 --- a/crates/aisix-guardrails/src/build.rs +++ b/crates/aisix-guardrails/src/build.rs @@ -761,9 +761,17 @@ impl MandatoryGuardrail { // Carry the row name so downstream handlers can name the // guardrail in the 422 envelope (#519 B.4b) — `block()` would // drop it to `None` and surface an unnamed content-filter block. + // + // The `Bypass` reason IS the kind's bounded failure tag, so + // this conversion is the one place that knows, structurally, + // that the refusal is an outage rather than a policy + // decision — carry it (AISIX-Cloud#1365). Without it the + // audit trail reports a `mandatory` row's upstream outage + // exactly like a real content violation. GuardrailVerdict::Block { reason: format!("mandatory guardrail unavailable: {reason}"), guardrail_name: Some(self.row_name.clone()), + unavailable: Some(crate::bounded_failure_tag(&reason)), } } other => other, @@ -1605,6 +1613,10 @@ mod tests { GuardrailVerdict::Block { reason: "mandatory guardrail unavailable: upstream_unreachable".to_string(), guardrail_name: Some("remote".to_string()), + // AISIX-Cloud#1365: a mandatory row's Bypass→Block is an + // availability failure by construction, so the bypass tag + // survives the conversion. + unavailable: Some("upstream_unreachable".to_string()), }, "mandatory input Bypass must become a named Block, got {vin:?}", ); @@ -1614,6 +1626,10 @@ mod tests { GuardrailVerdict::Block { reason: "mandatory guardrail unavailable: upstream_unreachable".to_string(), guardrail_name: Some("remote".to_string()), + // AISIX-Cloud#1365: a mandatory row's Bypass→Block is an + // availability failure by construction, so the bypass tag + // survives the conversion. + unavailable: Some("upstream_unreachable".to_string()), }, "mandatory output Bypass must become a named Block, got {vout:?}", ); diff --git a/crates/aisix-guardrails/src/chain.rs b/crates/aisix-guardrails/src/chain.rs index 7639d7a8a..b57ea48a8 100644 --- a/crates/aisix-guardrails/src/chain.rs +++ b/crates/aisix-guardrails/src/chain.rs @@ -141,6 +141,20 @@ impl GuardrailChain { .unwrap_or_default() } + /// The request's audit log handle, for a caller that outlives the + /// chain value: a streaming emitter running inside a `move` closure + /// after the handler frame is gone, or a handler whose chain is + /// erased to `Arc` (the trait carries no `enforced_hits`). + /// Clone it at the same point `applied()` is snapshotted and read it + /// with [`GuardrailAuditLog::snapshot`] when the usage event is built. + /// + /// `None` for a chain resolved with nothing attached — that request + /// can never produce an enforced hit, so the absent log and an empty + /// snapshot mean the same thing. + pub fn audit_log(&self) -> Option> { + self.audit.clone() + } + /// Borrow both execution receivers for one fold. fn recorders(&self) -> Recorders<'_> { Recorders { @@ -183,15 +197,24 @@ impl GuardrailChain { /// Block surfaces as `would_block` (via its hits), not `blocked`. `masked` /// only arises on the segment pass — the sync per-field redactors are not /// timed here. The `error_type` is the bounded per-kind failure tag a -/// `Bypass` carries (e.g. `lakera_timeout`); fail-closed failures surface -/// as `blocked` with no tag (the tag only exists structured on `Bypass`). +/// `Bypass` carries (e.g. `lakera_timeout`) — and, since AISIX-Cloud#1365, +/// the same tag on a fail-CLOSED block, which is an availability failure +/// wearing a block's clothes. +/// +/// `result` deliberately stays `blocked` for that case. It is a shipped +/// Prometheus label (AISIX-Cloud#1076) with operator alerting attached, and +/// splitting its value domain would silently stop an existing +/// `result="blocked"` alert from counting outages. Populating `error_type` +/// only widens an existing label instead, so `sum by (result)` is unchanged +/// while `error_type != "none"` separates the two. The audit event, which +/// is unreleased, does split them — see [`record_execution`]. fn classify_execution<'v>( verdict: &'v GuardrailVerdict, masked: bool, hits: &[GuardrailMonitorHit], ) -> (&'static str, Option<&'v str>) { match verdict { - GuardrailVerdict::Block { .. } => ("blocked", None), + GuardrailVerdict::Block { unavailable, .. } => ("blocked", unavailable.as_deref()), GuardrailVerdict::Bypass { reason } => ("bypassed", Some(reason.as_str())), GuardrailVerdict::Allow => { if masked { @@ -229,13 +252,14 @@ struct Recorders<'a> { /// `would_*` results belong to `guardrail_monitor_hits` — routing them /// here would make an enforcing hit indistinguishable from a staged one. /// -/// One caveat a reader of the audit trail needs: `blocked` is the -/// ENFORCED outcome, which covers a fail-CLOSED availability failure as -/// well as a content decision. A member with `fail_open: false` (or a -/// `mandatory` one) whose upstream is unreachable returns `Block`, not -/// `Bypass` — see [`classify_execution`] — so it lands here indis- -/// tinguishable from a policy hit. AISIX-Cloud#1365 tracks separating -/// the two. +/// The two are told apart on the audit event (AISIX-Cloud#1365): a member +/// with `fail_open: false` (or a `mandatory` one) whose upstream is +/// unreachable returns `Block`, not `Bypass`, and records +/// `blocked_unavailable` plus the bounded failure tag rather than +/// `blocked`. That matters because the naive read of `action = "blocked"` +/// is "this content violated policy X" — which, for a provider outage on a +/// fail-closed row, is a wrong answer rather than a missing one, and one a +/// compliance review would act on. // Five of the eight describe one member execution (verdict, masked, hits, // counts) plus where to report it; splitting them into a struct would put a // name on a grouping that exists only here. @@ -276,7 +300,16 @@ fn record_execution( ("masked", Some(counts)) => counts, _ => &empty, }; - audit.record(&member.name, phase, result, elapsed, counts); + // A tagged block is an outage, not a policy decision. Splitting it + // into its own action — rather than leaving it to a reader who + // remembers to also check `error_type` — is what makes the naive + // query `action = 'blocked'` correct by construction + // (AISIX-Cloud#1365). + let action = match (result, error_type) { + ("blocked", Some(_)) => "blocked_unavailable", + _ => result, + }; + audit.record(&member.name, phase, action, error_type, elapsed, counts); } } @@ -289,15 +322,22 @@ fn attribute_block( member_name: &str, reason: String, guardrail_name: Option, + // Carried through untouched: whether the block was a content decision + // or a fail-closed availability failure is the member's fact, not the + // chain's, and re-attributing the name must not lose it + // (AISIX-Cloud#1365). + unavailable: Option, ) -> GuardrailVerdict { match guardrail_name { Some(_) => GuardrailVerdict::Block { reason, guardrail_name, + unavailable, }, None => GuardrailVerdict::Block { reason: format!("guardrail '{member_name}': {reason}"), guardrail_name: Some(member_name.to_owned()), + unavailable, }, } } @@ -353,7 +393,8 @@ impl Guardrail for GuardrailChain { GuardrailVerdict::Block { reason, guardrail_name, - } => return attribute_block(&m.name, reason, guardrail_name), + unavailable, + } => return attribute_block(&m.name, reason, guardrail_name, unavailable), GuardrailVerdict::Bypass { reason } => { // First bypass sticks; downstream guardrails still // get to inspect the request (they may Block). @@ -389,7 +430,8 @@ impl Guardrail for GuardrailChain { GuardrailVerdict::Block { reason, guardrail_name, - } => return attribute_block(&m.name, reason, guardrail_name), + unavailable, + } => return attribute_block(&m.name, reason, guardrail_name, unavailable), GuardrailVerdict::Bypass { reason } => { if bypass.is_none() { bypass = Some(reason); @@ -432,7 +474,13 @@ impl Guardrail for GuardrailChain { GuardrailVerdict::Block { reason, guardrail_name, - } => return (attribute_block(&m.name, reason, guardrail_name), hits), + unavailable, + } => { + return ( + attribute_block(&m.name, reason, guardrail_name, unavailable), + hits, + ) + } GuardrailVerdict::Bypass { reason } => { if bypass.is_none() { bypass = Some(reason); @@ -472,7 +520,13 @@ impl Guardrail for GuardrailChain { GuardrailVerdict::Block { reason, guardrail_name, - } => return (attribute_block(&m.name, reason, guardrail_name), hits), + unavailable, + } => { + return ( + attribute_block(&m.name, reason, guardrail_name, unavailable), + hits, + ) + } GuardrailVerdict::Bypass { reason } => { if bypass.is_none() { bypass = Some(reason); @@ -518,7 +572,13 @@ impl Guardrail for GuardrailChain { GuardrailVerdict::Block { reason, guardrail_name, - } => return (attribute_block(&m.name, reason, guardrail_name), hits), + unavailable, + } => { + return ( + attribute_block(&m.name, reason, guardrail_name, unavailable), + hits, + ) + } GuardrailVerdict::Bypass { reason } => { if bypass.is_none() { bypass = Some(reason); @@ -560,7 +620,13 @@ impl Guardrail for GuardrailChain { GuardrailVerdict::Block { reason, guardrail_name, - } => return (attribute_block(&m.name, reason, guardrail_name), hits), + unavailable, + } => { + return ( + attribute_block(&m.name, reason, guardrail_name, unavailable), + hits, + ) + } GuardrailVerdict::Bypass { reason } => { if bypass.is_none() { bypass = Some(reason); @@ -620,7 +686,8 @@ impl Guardrail for GuardrailChain { GuardrailVerdict::Block { reason, guardrail_name, - } => return attribute_block(&m.name, reason, guardrail_name), + unavailable, + } => return attribute_block(&m.name, reason, guardrail_name, unavailable), GuardrailVerdict::Bypass { reason } => { if bypass.is_none() { bypass = Some(reason); @@ -656,7 +723,8 @@ impl Guardrail for GuardrailChain { GuardrailVerdict::Block { reason, guardrail_name, - } => return attribute_block(&m.name, reason, guardrail_name), + unavailable, + } => return attribute_block(&m.name, reason, guardrail_name, unavailable), GuardrailVerdict::Bypass { reason } => { if bypass.is_none() { bypass = Some(reason); @@ -750,9 +818,10 @@ async fn fold_segments( GuardrailVerdict::Block { reason, guardrail_name, + unavailable, } => { return SegmentsOutcome { - verdict: attribute_block(&m.name, reason, guardrail_name), + verdict: attribute_block(&m.name, reason, guardrail_name, unavailable), masked: None, counts: std::collections::BTreeMap::new(), monitor_hits, @@ -819,7 +888,14 @@ fn fold_redactions<'a>( // `kind: "pii"` MCP path the audit chain exists for. Recorded only // when this member actually rewrote something. if let (Some(audit), Some(r)) = (audit, next.as_ref()) { - audit.record(&m.name, phase, "masked", started.elapsed(), &r.counts); + audit.record( + &m.name, + phase, + "masked", + /* error_type */ None, + started.elapsed(), + &r.counts, + ); } if let Some(r) = next { current = Some(match current.take() { @@ -875,6 +951,107 @@ mod tests { assert_eq!(hits[0].action, "blocked"); } + /// AISIX-Cloud#1365: a fail-CLOSED refusal is an outage, not a policy + /// decision, and the audit trail has to say which. Before this the two + /// were the same `action: "blocked"` entry, so a provider outage on a + /// `fail_open: false` row stamped every request in the window as a + /// content violation — a wrong answer for a compliance review, not a + /// missing one. + #[tokio::test] + async fn a_fail_closed_block_is_audited_apart_from_a_policy_block() { + struct Unavailable; + #[async_trait] + impl Guardrail for Unavailable { + fn name(&self) -> &'static str { + "unavailable" + } + async fn check_input(&self, _req: &ChatFormat) -> GuardrailVerdict { + // What every remote guardrail's `handle_failure` returns + // when it cannot reach its upstream and `fail_open` is off. + GuardrailVerdict::block_unavailable( + "lakera guard unavailable (lakera_timeout)", + "lakera_timeout", + ) + } + } + + let audit = Arc::new(GuardrailAuditLog::new()); + let chain = GuardrailChain::new_with_applied( + vec![( + "lakera-prod".to_owned(), + Arc::new(Unavailable) as Arc, + )], + vec![AppliedGuardrail { + kind: "lakera".to_owned(), + hook: "input".to_owned(), + }], + ) + .with_audit_log(Some(Arc::clone(&audit))); + + // The REQUEST still gets refused — separating the two must not + // weaken the fail-closed guarantee itself. + assert!(chain.check_input(&req("anything")).await.is_block()); + + let hits = chain.enforced_hits(); + assert_eq!(hits.len(), 1, "{hits:?}"); + assert_eq!(hits[0].guardrail_name, "lakera-prod"); + assert_eq!(hits[0].action, "blocked_unavailable"); + assert_eq!(hits[0].error_type, "lakera_timeout"); + + // ...and the ordinary content block is untouched: it keeps the + // bare `blocked` action and gains no cause, so `action = + // "blocked"` still means exactly "this content violated policy". + let audit = Arc::new(GuardrailAuditLog::new()); + let policy = GuardrailChain::new(vec![Arc::new(KeywordBlocklist::new(vec![ + KeywordRule::literal("nope"), + ])) as Arc]) + .with_audit_log(Some(Arc::clone(&audit))); + assert!(policy.check_input(&req("nope")).await.is_block()); + let hits = policy.enforced_hits(); + assert_eq!(hits.len(), 1, "{hits:?}"); + assert_eq!(hits[0].action, "blocked"); + assert!(hits[0].error_type.is_empty()); + } + + /// The Prometheus `result` label deliberately does NOT split + /// (AISIX-Cloud#1365): it is a shipped label with operator alerting + /// attached, so an existing `result="blocked"` alert must keep + /// counting outages. The cause rides `error_type`, which was already + /// a label and merely gains values. + #[tokio::test] + async fn the_metrics_result_label_keeps_counting_fail_closed_as_blocked() { + #[derive(Default)] + struct Recorder(std::sync::Mutex>); + impl GuardrailMetricsSink for Recorder { + fn record_guardrail_execution(&self, exec: &GuardrailExecution<'_>) { + self.0.lock().unwrap().push(( + exec.result.to_owned(), + exec.error_type.unwrap_or("none").to_owned(), + )); + } + } + struct Unavailable; + #[async_trait] + impl Guardrail for Unavailable { + fn name(&self) -> &'static str { + "unavailable" + } + async fn check_input(&self, _req: &ChatFormat) -> GuardrailVerdict { + GuardrailVerdict::block_unavailable("presidio unavailable", "presidio_5xx") + } + } + + let sink = Arc::new(Recorder::default()); + let chain = GuardrailChain::new(vec![Arc::new(Unavailable) as Arc]) + .with_metrics_sink(Some(Arc::clone(&sink) as Arc)); + assert!(chain.check_input(&req("hi")).await.is_block()); + + assert_eq!( + sink.0.lock().unwrap().as_slice(), + [("blocked".to_owned(), "presidio_5xx".to_owned())], + ); + } + /// An allowed request records nothing: `allowed` and `bypassed` are /// not enforcement events, and the two monitor-mode results belong to /// `guardrail_monitor_hits` instead. @@ -972,6 +1149,7 @@ mod tests { GuardrailVerdict::Block { reason, guardrail_name, + .. } => { assert_eq!(guardrail_name.as_deref(), Some("block-secrets")); assert!( @@ -1015,6 +1193,7 @@ mod tests { GuardrailVerdict::Block { reason, guardrail_name, + .. } => { assert_eq!(guardrail_name.as_deref(), Some("inner-rule")); assert!( diff --git a/crates/aisix-guardrails/src/lakera.rs b/crates/aisix-guardrails/src/lakera.rs index b6e6dcf5c..c254ba7d2 100644 --- a/crates/aisix-guardrails/src/lakera.rs +++ b/crates/aisix-guardrails/src/lakera.rs @@ -289,7 +289,7 @@ impl LakeraGuardrail { if fail_open { GuardrailVerdict::Bypass { reason: tag.into() } } else { - GuardrailVerdict::block(format!("lakera guard unavailable ({tag})")) + GuardrailVerdict::block_unavailable(format!("lakera guard unavailable ({tag})"), tag) } } } diff --git a/crates/aisix-guardrails/src/lib.rs b/crates/aisix-guardrails/src/lib.rs index 356106175..e8cec2105 100644 --- a/crates/aisix-guardrails/src/lib.rs +++ b/crates/aisix-guardrails/src/lib.rs @@ -236,12 +236,48 @@ pub enum GuardrailVerdict { /// `None` when the verdict came from a bare guardrail outside a /// chain. guardrail_name: Option, + /// Set when this block is an AVAILABILITY failure rather than a + /// content decision: a remote guardrail with `fail_open: false` + /// (or a `mandatory` row) that could not reach its upstream blocks + /// instead of bypassing, and the two are otherwise + /// indistinguishable to every consumer downstream + /// (AISIX-Cloud#1365). + /// + /// Carries the same bounded per-kind failure tag a `Bypass` puts + /// in its reason (e.g. `lakera_timeout`) — a closed vocabulary, + /// never free text and never matched content, so it is safe on a + /// metric label and on the wire (#153). + unavailable: Option, }, Bypass { reason: String, }, } +/// Clamp a failure tag to the shape a metric label and an audit field can +/// safely carry: lowercase alphanumerics and underscores, at most 64 bytes. +/// +/// Every producer already passes a `bypass_tag()` constant, so this is a +/// no-op today. It is here because the TYPE cannot say so: the tag is a +/// `String` (`MandatoryGuardrail` forwards whatever reason the inner +/// guardrail's `Bypass` carried), it lands on an unsanitized Prometheus +/// label, and it reaches the usage event that #153 forbids putting content +/// on. A future guardrail that returns a free-text bypass reason would +/// otherwise mint one metric series per distinct string. +pub(crate) fn bounded_failure_tag(tag: &str) -> String { + let cleaned: String = tag + .chars() + .map(|c| c.to_ascii_lowercase()) + .filter(|c| c.is_ascii_lowercase() || c.is_ascii_digit() || *c == '_') + .take(64) + .collect(); + if cleaned.is_empty() { + "unknown".to_owned() + } else { + cleaned + } +} + impl GuardrailVerdict { /// `Block` verdict with no guardrail-name attribution (the chain fills /// the name in). Implementations use this so they don't repeat @@ -250,6 +286,35 @@ impl GuardrailVerdict { GuardrailVerdict::Block { reason: reason.into(), guardrail_name: None, + unavailable: None, + } + } + + /// `Block` for a fail-CLOSED AVAILABILITY failure (AISIX-Cloud#1365): + /// the guardrail could not evaluate, and its configuration says an + /// un-evaluated request is refused rather than let through. + /// + /// `tag` is the guardrail kind's bounded failure tag — the same value + /// the fail-OPEN branch puts in `Bypass::reason`, so one outage reads + /// the same whichever way the row is configured. + pub fn block_unavailable(reason: impl Into, tag: impl Into) -> Self { + GuardrailVerdict::Block { + reason: reason.into(), + guardrail_name: None, + unavailable: Some(bounded_failure_tag(&tag.into())), + } + } + + /// The bounded failure tag when this verdict is a fail-closed + /// availability block; `None` for a content decision and for every + /// non-block verdict. + pub fn unavailable_tag(&self) -> Option<&str> { + match self { + GuardrailVerdict::Block { + unavailable: Some(tag), + .. + } => Some(tag.as_str()), + _ => None, } } @@ -928,8 +993,47 @@ mod tests { GuardrailVerdict::Block { reason: "x".into(), guardrail_name: None, + unavailable: None, }, ); + // A plain content block carries no cause; a fail-closed one does, + // and that is the only difference a consumer can see + // (AISIX-Cloud#1365). + assert_eq!(GuardrailVerdict::block("x").unavailable_tag(), None); + assert!(GuardrailVerdict::block_unavailable("x", "lakera_timeout").is_block()); + assert_eq!( + GuardrailVerdict::block_unavailable("x", "lakera_timeout").unavailable_tag(), + Some("lakera_timeout"), + ); + assert_eq!(GuardrailVerdict::Allow.unavailable_tag(), None); + // The tag reaches an unsanitized Prometheus label and the usage + // event, so it is clamped at construction rather than trusted: + // every producer passes a `bypass_tag()` constant today, but the + // field's TYPE is `String` and cannot say so. + assert_eq!( + GuardrailVerdict::block_unavailable("x", "presidio_5xx").unavailable_tag(), + Some("presidio_5xx"), + "a real tag must survive the clamp unchanged", + ); + assert_eq!( + GuardrailVerdict::block_unavailable("x", "Lakera Timeout: 500ms!").unavailable_tag(), + Some("lakeratimeout500ms"), + ); + assert_eq!( + GuardrailVerdict::block_unavailable("x", "!!!").unavailable_tag(), + Some("unknown"), + ); + assert_eq!( + GuardrailVerdict::block_unavailable("x", "a".repeat(200)) + .unavailable_tag() + .map(str::len), + Some(64), + "an unbounded tag must not mint an unbounded metric series", + ); + assert_eq!( + GuardrailVerdict::Bypass { reason: "y".into() }.unavailable_tag(), + None, + ); assert!(!GuardrailVerdict::Allow.is_bypass()); assert!(GuardrailVerdict::Bypass { reason: "y".into() }.is_bypass()); assert!(!GuardrailVerdict::Bypass { reason: "y".into() }.is_block()); diff --git a/crates/aisix-guardrails/src/openai_moderation.rs b/crates/aisix-guardrails/src/openai_moderation.rs index c8b07411d..1eadc9b60 100644 --- a/crates/aisix-guardrails/src/openai_moderation.rs +++ b/crates/aisix-guardrails/src/openai_moderation.rs @@ -236,7 +236,10 @@ impl OpenaiModerationGuardrail { if fail_open { GuardrailVerdict::Bypass { reason: tag.into() } } else { - GuardrailVerdict::block(format!("openai moderation unavailable ({tag})")) + GuardrailVerdict::block_unavailable( + format!("openai moderation unavailable ({tag})"), + tag, + ) } } } diff --git a/crates/aisix-guardrails/src/presidio.rs b/crates/aisix-guardrails/src/presidio.rs index 97a55a89f..613b54cd4 100644 --- a/crates/aisix-guardrails/src/presidio.rs +++ b/crates/aisix-guardrails/src/presidio.rs @@ -348,7 +348,7 @@ impl PresidioGuardrail { if fail_open { GuardrailVerdict::Bypass { reason: tag.into() } } else { - GuardrailVerdict::block(format!("presidio unavailable ({tag})")) + GuardrailVerdict::block_unavailable(format!("presidio unavailable ({tag})"), tag) } } } diff --git a/crates/aisix-guardrails/src/prompt_shield.rs b/crates/aisix-guardrails/src/prompt_shield.rs index 1e54fdc53..1d6dc841e 100644 --- a/crates/aisix-guardrails/src/prompt_shield.rs +++ b/crates/aisix-guardrails/src/prompt_shield.rs @@ -206,7 +206,10 @@ impl PromptShieldGuardrail { if fail_open { GuardrailVerdict::Bypass { reason: tag.into() } } else { - GuardrailVerdict::block(format!("azure content safety unavailable ({tag})")) + GuardrailVerdict::block_unavailable( + format!("azure content safety unavailable ({tag})"), + tag, + ) } } } diff --git a/crates/aisix-guardrails/src/text_moderation.rs b/crates/aisix-guardrails/src/text_moderation.rs index 073628df4..f36d38d5e 100644 --- a/crates/aisix-guardrails/src/text_moderation.rs +++ b/crates/aisix-guardrails/src/text_moderation.rs @@ -229,7 +229,10 @@ impl TextModerationGuardrail { if fail_open { GuardrailVerdict::Bypass { reason: tag.into() } } else { - GuardrailVerdict::block(format!("azure content safety unavailable ({tag})")) + GuardrailVerdict::block_unavailable( + format!("azure content safety unavailable ({tag})"), + tag, + ) } } diff --git a/crates/aisix-obs/src/sink/record.rs b/crates/aisix-obs/src/sink/record.rs index 1e868eb9d..3b5c867c2 100644 --- a/crates/aisix-obs/src/sink/record.rs +++ b/crates/aisix-obs/src/sink/record.rs @@ -197,23 +197,40 @@ mod tests { #[test] fn enforced_hits_ride_the_flattened_exporter_wire() { let rec = SinkRecord::metadata_only(UsageEvent { - guardrail_enforced_hits: vec![aisix_core::GuardrailEnforcedHit { - guardrail_name: "eda-mask".into(), - hook: "output".into(), - action: "masked".into(), - counts: [("eda_version".to_owned(), 2u32)].into_iter().collect(), - duration_us: 41, - }], + guardrail_enforced_hits: vec![ + aisix_core::GuardrailEnforcedHit { + guardrail_name: "eda-mask".into(), + hook: "output".into(), + action: "masked".into(), + counts: [("eda_version".to_owned(), 2u32)].into_iter().collect(), + duration_us: 41, + ..Default::default() + }, + // AISIX-Cloud#1365: the fail-closed refusal is a distinct + // action carrying a bounded cause, and the SOC exporters must + // see the distinction the /logs badge sees — an auditor + // reading the NDJSON drop has no control plane to ask. + aisix_core::GuardrailEnforcedHit { + guardrail_name: "lakera-prod".into(), + hook: "input".into(), + action: "blocked_unavailable".into(), + error_type: "lakera_timeout".into(), + ..Default::default() + }, + ], ..UsageEvent::default() }); let json = serde_json::to_value(&rec).unwrap(); let hits = json["guardrail_enforced_hits"] .as_array() .expect("flattened onto the record, not nested under `usage`"); - assert_eq!(hits.len(), 1); + assert_eq!(hits.len(), 2); assert_eq!(hits[0]["guardrail_name"], "eda-mask"); assert_eq!(hits[0]["action"], "masked"); assert_eq!(hits[0]["counts"]["eda_version"], 2); + assert!(hits[0].get("error_type").is_none()); + assert_eq!(hits[1]["action"], "blocked_unavailable"); + assert_eq!(hits[1]["error_type"], "lakera_timeout"); let bare = serde_json::to_value(SinkRecord::metadata_only(UsageEvent::default())).unwrap(); assert!(bare.get("guardrail_enforced_hits").is_none()); diff --git a/crates/aisix-obs/src/usage.rs b/crates/aisix-obs/src/usage.rs index 63e9036b9..3ffae354e 100644 --- a/crates/aisix-obs/src/usage.rs +++ b/crates/aisix-obs/src/usage.rs @@ -1378,6 +1378,7 @@ mod tests { action: "masked".into(), counts: [("eda_version".to_owned(), 3u32)].into_iter().collect(), duration_us: 87, + ..Default::default() }, GuardrailEnforcedHit { guardrail_name: "deny-secrets".into(), @@ -1385,6 +1386,16 @@ mod tests { action: "blocked".into(), ..Default::default() }, + // AISIX-Cloud#1365: a fail-closed refusal is its own + // action so the naive read of `action = "blocked"` — "this + // content violated policy" — stays true. + GuardrailEnforcedHit { + guardrail_name: "lakera-prod".into(), + hook: "input".into(), + action: "blocked_unavailable".into(), + error_type: "lakera_timeout".into(), + ..Default::default() + }, ], ..Default::default() }; @@ -1395,6 +1406,11 @@ mod tests { assert!(json.contains(r#""eda_version":3"#)); assert!(json.contains(r#""duration_us":87"#)); assert!(json.contains(r#""action":"blocked""#)); + assert!(json.contains(r#""action":"blocked_unavailable""#)); + assert!(json.contains(r#""error_type":"lakera_timeout""#)); + // Only the fail-closed entry carries a cause: an ordinary policy + // block must not acquire one, or the two collapse again. + assert_eq!(json.matches(r#""error_type""#).count(), 1); // A block reports no counts. The fixture leaves its duration at // zero so both stay off the wire here; a production block does // carry `duration_us` — the member's own evaluation time. diff --git a/crates/aisix-proxy/src/audio.rs b/crates/aisix-proxy/src/audio.rs index ec2c2ada5..d31d346c2 100644 --- a/crates/aisix-proxy/src/audio.rs +++ b/crates/aisix-proxy/src/audio.rs @@ -124,6 +124,11 @@ pub async fn transcriptions( // reused by the emits below (#941) — see the note on its signature. let mut snapshot = None; + // See `embeddings`: filled inside `multipart_dispatch` so the failure + // branch — where a guardrail block lands — stamps the enforced hits + // too (AISIX-Cloud#1330 / #1024). + let mut audit = crate::usage_attr::GuardrailAudit::default(); + match multipart_dispatch( &state, &mut snapshot, @@ -134,6 +139,7 @@ pub async fn transcriptions( "/audio/transcriptions", &request_id, &client, + &mut audit, ) .await { @@ -182,6 +188,7 @@ pub async fn transcriptions( status, elapsed, &client, + &audit, ); } success.response @@ -235,6 +242,7 @@ pub async fn transcriptions( status, err.kind(), &client, + crate::usage_attr::enforced_hits(&audit), ); err.into_response() } @@ -276,6 +284,11 @@ pub async fn translations( // reused by the emits below (#941) — see the note on its signature. let mut snapshot = None; + // See `embeddings`: filled inside `multipart_dispatch` so the failure + // branch — where a guardrail block lands — stamps the enforced hits + // too (AISIX-Cloud#1330 / #1024). + let mut audit = crate::usage_attr::GuardrailAudit::default(); + match multipart_dispatch( &state, &mut snapshot, @@ -286,6 +299,7 @@ pub async fn translations( "/audio/translations", &request_id, &client, + &mut audit, ) .await { @@ -334,6 +348,7 @@ pub async fn translations( status, elapsed, &client, + &audit, ); } success.response @@ -386,6 +401,7 @@ pub async fn translations( status, err.kind(), &client, + crate::usage_attr::enforced_hits(&audit), ); err.into_response() } @@ -432,7 +448,21 @@ pub async fn speech( // One snapshot for the whole request (#941) — see `embeddings`. let snapshot = state.snapshot.load(); - match speech_dispatch(&state, &snapshot, &auth, body, &request_id, &client).await { + // See `embeddings`: filled inside `speech_dispatch` so the failure + // branch — where a guardrail block lands — stamps the enforced hits + // too (AISIX-Cloud#1330 / #1024). + let mut audit = crate::usage_attr::GuardrailAudit::default(); + match speech_dispatch( + &state, + &snapshot, + &auth, + body, + &request_id, + &client, + &mut audit, + ) + .await + { Ok(success) => { let elapsed = started.elapsed(); let status = success.response.status().as_u16(); @@ -493,6 +523,7 @@ pub async fn speech( success.monitor_hits, /* guardrail_blocked */ false, success.captured_content.as_ref(), + &audit, ); success.response } @@ -538,6 +569,7 @@ pub async fn speech( status, err.kind(), &client, + crate::usage_attr::enforced_hits(&audit), ); err.into_response() } @@ -772,6 +804,7 @@ fn observe_transcript_events( /// Collect all multipart fields, resolve the model, swap in the upstream /// model id, then rebuild and forward the multipart form. +#[allow(clippy::too_many_arguments)] async fn multipart_dispatch( state: &ProxyState, // Out-param, not an input: the snapshot is loaded HERE, once the @@ -786,6 +819,7 @@ async fn multipart_dispatch( upstream_path: &str, request_id: &str, client_ctx: &ClientContext, + audit_out: &mut crate::usage_attr::GuardrailAudit, ) -> Result { // The request clock for the streamed relay's end-of-stream emit // (#998): the handler has long returned by the time it fires, so it @@ -864,6 +898,7 @@ async fn multipart_dispatch( }; let resolved_chain = state.guardrail_index.resolve(&guardrail_ctx); let applied_guardrails = resolved_chain.applied().to_vec(); + *audit_out = resolved_chain.audit_log(); // #998: relay the upstream SSE live, or hold it back to scan it? // An output guardrail that can block or mask has to see the whole @@ -898,6 +933,7 @@ async fn multipart_dispatch( if let aisix_guardrails::GuardrailVerdict::Block { reason, guardrail_name, + .. } = verdict { // Per #153 the matched-pattern detail stays in ops logs only. @@ -1237,6 +1273,15 @@ async fn multipart_dispatch( let pk_id_c = pk_entry.id.to_string(); let api_key_id_c = auth.entry.id.clone(); let applied_c = applied_guardrails.clone(); + // The chain itself does not survive into the relay closure, so + // clone the audit handle here — the same line `applied` is + // snapshotted — and read it at end-of-stream. It carries the + // INPUT-side hits: this is the live-relay branch, which a + // block- or mask-capable chain never reaches (`live_relay` + // sends those down the buffered path above), so its end-of- + // stream scan is monitor-only by construction and writes no + // enforced hit of its own (AISIX-Cloud#1330 / #1024). + let audit_c = audit_out.clone(); let redactions_c = redactions.clone(); let input_monitor_hits = monitor_hits.clone(); let client_c = client_ctx.clone(); @@ -1296,6 +1341,7 @@ async fn multipart_dispatch( monitor_hits, /* guardrail_blocked */ false, captured_content.as_ref(), + &audit_c, ); }, ); @@ -1386,6 +1432,7 @@ async fn multipart_dispatch( if let aisix_guardrails::GuardrailVerdict::Block { reason, guardrail_name, + .. } = verdict { // Per #153 the matched-pattern detail stays in ops logs only. @@ -1525,6 +1572,7 @@ async fn speech_dispatch( mut body: Value, request_id: &str, client_ctx: &ClientContext, + audit_out: &mut crate::usage_attr::GuardrailAudit, ) -> Result { let model_name = body .get("model") @@ -1559,6 +1607,7 @@ async fn speech_dispatch( // Record which guardrails govern this request (#379 parity) for the emitted // UsageEvent. Empty when none attached. let applied_guardrails = resolved_chain.applied().to_vec(); + *audit_out = resolved_chain.audit_log(); let mut monitor_hits: Vec = Vec::new(); if !resolved_chain.is_empty() { let chat = speech_input_to_chat(&model_name, &body); @@ -1568,6 +1617,7 @@ async fn speech_dispatch( if let aisix_guardrails::GuardrailVerdict::Block { reason, guardrail_name, + .. } = verdict { // Per #153 the matched-pattern detail stays in ops logs only. @@ -1934,6 +1984,7 @@ fn emit_audio_usage( status: u16, elapsed: Duration, client: &ClientContext, + audit: &crate::usage_attr::GuardrailAudit, ) { let (prompt_tokens, completion_tokens) = success.usage.unwrap_or((0, 0)); emit_usage_event( @@ -1958,6 +2009,7 @@ fn emit_audio_usage( success.monitor_hits.clone(), success.guardrail_blocked, success.captured_content.as_ref(), + audit, ); } @@ -2003,6 +2055,11 @@ fn emit_usage_event( // Captured request/response content (#700). Forwarded only to `fan_out`, // never to the CP sink. content: Option<&CapturedContent>, + // The request's enforced-guardrail audit handle (AISIX-Cloud#1330). + // Cloned into the streaming closure at the same point `applied` is, + // so the held-back relay's end-of-stream emit reports the output-hook + // mask that ran after the handler frame was already gone. + audit: &crate::usage_attr::GuardrailAudit, ) { let mut event = UsageEvent { request_id: request_id.to_string(), @@ -2025,6 +2082,7 @@ fn emit_usage_event( redacted_entity_counts, guardrail_monitor_hits, guardrail_blocked, + guardrail_enforced_hits: crate::usage_attr::enforced_hits(audit), ..Default::default() }; // Per-PK telemetry attribution, same lookup as chat / messages / @@ -3688,4 +3746,181 @@ mod tests { assert!(event.guardrail_blocked, "event must be marked blocked"); assert_eq!((event.prompt_tokens, event.completion_tokens), (21, 7)); } + + /// AISIX-Cloud#1330 / #1024: a guardrail BLOCK leaves this handler + /// through `Err`, so the terminal usage event is the shared + /// zero-token error event. That branch is the one an auditor reads — + /// "which policy refused this request" — and a drain wired only into + /// the success path misses it silently. + #[tokio::test] + async fn blocked_request_names_the_policy_on_the_usage_event() { + let upstream = MockServer::start().await; + let snap = new_snap(&upstream.uri()); + snap.models.insert(tts_model("my-tts")); + snap.apikeys.insert(apikey_entry(&["*"])); + snap.guardrails.insert(keyword_input_guardrail("BLOCKME")); + + let (tx, mut rx) = tokio::sync::mpsc::channel(8); + let app = build_app_with_sink(snap, tx); + let resp = tower::ServiceExt::oneshot( + app, + speech_req(r#"{"model":"my-tts","input":"say BLOCKME aloud","voice":"alloy"}"#), + ) + .await + .unwrap(); + assert_eq!(resp.status(), StatusCode::UNPROCESSABLE_ENTITY); + + let ev = tokio::time::timeout(std::time::Duration::from_millis(500), rx.recv()) + .await + .expect("UsageEvent must be emitted for the refusal") + .expect("usage_sink sender dropped"); + assert_eq!(ev.guardrail_enforced_hits.len(), 1, "{ev:?}"); + assert_eq!(ev.guardrail_enforced_hits[0].guardrail_name, "t"); + assert_eq!(ev.guardrail_enforced_hits[0].hook, "input"); + assert_eq!(ev.guardrail_enforced_hits[0].action, "blocked"); + let wire = serde_json::to_string(&ev).unwrap(); + assert!(!wire.contains("BLOCKME"), "{wire}"); + } + + /// [`transcription_multipart_with_prompt`] plus `stream=true`, i.e. + /// what a caller that wants the transcript incrementally AND supplies + /// prompt text sends — the shape that reaches the relay closure. + fn streaming_transcription_multipart_with_prompt( + model: &str, + prompt: &str, + ) -> (String, axum::body::Body) { + let body = format!( + "--b\r\nContent-Disposition: form-data; name=\"model\"\r\n\r\n{model}\r\n\ + --b\r\nContent-Disposition: form-data; name=\"stream\"\r\n\r\ntrue\r\n\ + --b\r\nContent-Disposition: form-data; name=\"prompt\"\r\n\r\n{prompt}\r\n\ + --b\r\nContent-Disposition: form-data; name=\"file\"; filename=\"a.mp3\"\r\n\ + Content-Type: audio/mpeg\r\n\r\nID3fakeaudio\r\n--b--\r\n" + ); + ( + "multipart/form-data; boundary=b".to_string(), + axum::body::Body::from(body), + ) + } + + /// A `kind: "pii"` row masking a version string on the INPUT hook — + /// what an audio `prompt` actually gets, as opposed to the keyword + /// BLOCK the sibling tests drive. + fn masking_input_guardrail() -> ResourceEntry { + let g: aisix_core::Guardrail = serde_json::from_str( + r#"{"name":"eda-mask","enabled":true,"hook_point":"input","kind":"pii","detectors":[],"custom_patterns":[{"name":"eda_version","regex":"version\\s*:\\s*(\\d+(?:\\.\\d+)+)","action":"mask","replacement":"***"}]}"#, + ) + .unwrap(); + ResourceEntry::new("g-mask", g, 1) + } + + /// AISIX-Cloud#1330 / #1024: the NON-streaming transcription's own + /// emitter (`emit_audio_usage`) drains too. The sibling refusal test + /// drives `/v1/audio/speech`, which is a different dispatch entirely, + /// so without this the whole multipart surface's success path is + /// unasserted. + #[tokio::test] + async fn transcription_mask_names_the_policy_on_the_usage_event() { + let upstream = MockServer::start().await; + Mock::given(method("POST")) + .and(path("/v1/audio/transcriptions")) + .respond_with(ResponseTemplate::new(200).set_body_json(serde_json::json!({ + "text": "hello world", + "usage": {"type": "tokens", "input_tokens": 4, "output_tokens": 2, "total_tokens": 6} + }))) + .mount(&upstream) + .await; + + let snap = new_snap(&upstream.uri()); + snap.models.insert(whisper_model("my-transcribe")); + snap.apikeys.insert(apikey_entry(&["*"])); + snap.guardrails.insert(masking_input_guardrail()); + + let (tx, mut rx) = tokio::sync::mpsc::channel(8); + let app = build_app_with_sink(snap, tx); + let (ct, body) = + transcription_multipart_with_prompt("my-transcribe", "build version: 9.9.9 ok"); + let req = Request::builder() + .method("POST") + .uri("/v1/audio/transcriptions") + .header("authorization", "Bearer sk-caller") + .header("content-type", ct) + .body(body) + .unwrap(); + let resp = tower::ServiceExt::oneshot(app, req).await.unwrap(); + assert_eq!(resp.status(), StatusCode::OK); + + // The masked prompt is what actually reached the provider. + let seen = upstream.received_requests().await.unwrap(); + let forwarded = String::from_utf8_lossy(&seen[0].body).into_owned(); + assert!(forwarded.contains("***"), "{forwarded}"); + assert!(!forwarded.contains("9.9.9"), "{forwarded}"); + + let ev = tokio::time::timeout(std::time::Duration::from_millis(500), rx.recv()) + .await + .expect("UsageEvent must be emitted") + .expect("usage_sink sender dropped"); + assert_eq!(ev.guardrail_enforced_hits.len(), 1, "{ev:?}"); + assert_eq!(ev.guardrail_enforced_hits[0].guardrail_name, "eda-mask"); + assert_eq!(ev.guardrail_enforced_hits[0].hook, "input"); + assert_eq!(ev.guardrail_enforced_hits[0].action, "masked"); + let wire = serde_json::to_string(&ev).unwrap(); + assert!(!wire.contains("9.9.9"), "{wire}"); + } + + /// The STREAMED transcription relay's end-of-stream emit — the one + /// emitter on this surface that runs from a `move` closure after the + /// handler frame is gone, and the reason the audit handle is cloned + /// beside `applied_guardrails` rather than read from the chain. + /// Nothing else in the suite reaches it. + #[tokio::test] + async fn streamed_transcription_mask_names_the_policy_on_the_usage_event() { + let upstream = MockServer::start().await; + let sse = "\ +data: {\"type\":\"transcript.text.delta\",\"delta\":\"hello\"}\n\n\ +data: {\"type\":\"transcript.text.done\",\"text\":\"hello world\"}\n\n\ +data: [DONE]\n\n"; + Mock::given(method("POST")) + .and(path("/v1/audio/transcriptions")) + .respond_with( + ResponseTemplate::new(200) + .insert_header("content-type", "text/event-stream") + .set_body_string(sse), + ) + .mount(&upstream) + .await; + + let snap = new_snap(&upstream.uri()); + snap.models.insert(whisper_model("my-transcribe")); + snap.apikeys.insert(apikey_entry(&["*"])); + snap.guardrails.insert(masking_input_guardrail()); + + let (tx, mut rx) = tokio::sync::mpsc::channel(8); + let app = build_app_with_sink(snap, tx); + let (ct, body) = streaming_transcription_multipart_with_prompt( + "my-transcribe", + "build version: 9.9.9 ok", + ); + let req = Request::builder() + .method("POST") + .uri("/v1/audio/transcriptions") + .header("authorization", "Bearer sk-caller") + .header("content-type", ct) + .body(body) + .unwrap(); + let resp = tower::ServiceExt::oneshot(app, req).await.unwrap(); + assert_eq!(resp.status(), StatusCode::OK); + // Drain the body so the relay's end-of-stream emit runs. + let _ = to_bytes(resp.into_body(), usize::MAX).await.unwrap(); + + let ev = tokio::time::timeout(std::time::Duration::from_millis(1000), rx.recv()) + .await + .expect("the streamed relay must emit a UsageEvent") + .expect("usage_sink sender dropped"); + assert_eq!(ev.guardrail_enforced_hits.len(), 1, "{ev:?}"); + assert_eq!(ev.guardrail_enforced_hits[0].guardrail_name, "eda-mask"); + assert_eq!(ev.guardrail_enforced_hits[0].hook, "input"); + assert_eq!(ev.guardrail_enforced_hits[0].action, "masked"); + let wire = serde_json::to_string(&ev).unwrap(); + assert!(!wire.contains("9.9.9"), "{wire}"); + } } diff --git a/crates/aisix-proxy/src/chat.rs b/crates/aisix-proxy/src/chat.rs index 61c0c58f7..7c39307e8 100644 --- a/crates/aisix-proxy/src/chat.rs +++ b/crates/aisix-proxy/src/chat.rs @@ -135,6 +135,10 @@ pub async fn chat_completions( // Filled by `dispatch` with monitor-mode guardrail observations // (AISIX-Cloud#562), same dual-path lifecycle as `applied_guardrails`. let mut monitor_hits: Vec = Vec::new(); + // Filled by `dispatch` with the request's ENFORCE-mode audit handle + // (AISIX-Cloud#1330 / #1024), same dual-path lifecycle again — the + // guardrail-block path is exactly where a `blocked` hit is recorded. + let mut audit = crate::usage_attr::GuardrailAudit::default(); // One snapshot for the whole request (#941). Dispatch, the quota gate, // the terminal metric emits and the usage events all read this handle // instead of loading their own, so a request sees ONE config generation @@ -151,6 +155,7 @@ pub async fn chat_completions( &mut applied_guardrails, &mut redaction_counts, &mut monitor_hits, + &mut audit, ) .await; @@ -215,6 +220,7 @@ pub async fn chat_completions( // ...and the terminal trace spans. /* terminal_last */ false, + &audit, ); // The streaming path wires the WINNER's telemetry into the SSE // stream's on_complete callback (it has to wait for the @@ -291,6 +297,7 @@ pub async fn chat_completions( // upstream; any other no-attempt success did. /* dispatched */ winner.is_some() || success.cache_hit_layer.is_none(), + &audit, ); } // Inject x-ratelimit-* headers so OpenAI SDK clients see the @@ -507,6 +514,7 @@ pub async fn chat_completions( // billed-then-blocked event below is terminal instead. /* terminal_last */ charge.is_none(), + &audit, ); // Terminal event: // - output-blocked (charge present): the WINNING attempt was @@ -585,6 +593,7 @@ pub async fn chat_completions( // Billed-then-blocked: the upstream answered. /* dispatched */ true, + &audit, ); } None if routing.attempts.is_empty() => { @@ -623,6 +632,7 @@ pub async fn chat_completions( // `elapsed` is handler time, not an upstream call. /* dispatched */ false, + &audit, ); } None => { @@ -1208,6 +1218,11 @@ async fn dispatch( // Out-param: monitor-mode guardrail observations (AISIX-Cloud#562), // same lifecycle as `redactions_out`. monitor_hits_out: &mut Vec, + // Out-param: the request's ENFORCE-mode audit handle (AISIX-Cloud#1330), + // same lifecycle as `applied_out` — and filled at the same line, for the + // same reason: the concrete chain is about to be erased to + // `Arc`, which carries neither `applied()` nor the log. + audit_out: &mut crate::usage_attr::GuardrailAudit, ) -> Result { if req.messages.is_empty() { return Err(DispatchFailure::new( @@ -1269,6 +1284,15 @@ async fn dispatch( // local copy for the streaming on_complete closure below. let applied_guardrails = resolved.applied().to_vec(); *applied_out = applied_guardrails.clone(); + // Taken HERE for the same reason `applied()` is: below, the concrete + // chain is erased to `Arc` and — when a local-model + // guardrail is configured — re-wrapped with `GuardrailChain::new`, + // which leaves the new outer chain's audit log unset. Reading the + // handle after that point would return `None` and every enforced hit + // on the chat path would go unattributed while every other endpoint + // reported normally. The inner chain keeps its own recorders, so its + // members still write here (AISIX-Cloud#1330 / #1024). + *audit_out = resolved.audit_log(); let resolved_chain: std::sync::Arc = std::sync::Arc::new(resolved); // AISIX-Cloud#1331 MVP: the env-injected local-model guardrail joins @@ -1311,6 +1335,7 @@ async fn dispatch( GuardrailVerdict::Block { reason, guardrail_name, + .. } => { // The verdict's `reason` carries matched-pattern detail // (e.g. `"input blocked by literal \"forbidden-token\""`). @@ -1466,6 +1491,7 @@ async fn dispatch( reservation, &resolved_chain, &applied_guardrails, + audit_out, bypass_reason, &model_id, &auth.entry.id, @@ -1903,6 +1929,11 @@ async fn dispatch( // Applied guardrail set (#379), owned for the move into on_complete so // the streamed-response telemetry event records which guardrails ran. let applied_guardrails_for_telem = applied_guardrails.clone(); + // Same line, same reason: the chain does not survive into the + // on_complete closure, so the audit handle is cloned here and read + // at stream end — where the held-back output hook has just recorded + // whatever it masked (AISIX-Cloud#1330 / #1024). + let audit_for_telem = audit_out.clone(); // Input-side PII mask counts (#932), captured before the stream so // the end-of-stream event merges them with the output-side counts // accumulated in `comp.redacted_entity_counts`. @@ -2086,6 +2117,7 @@ async fn dispatch( /* terminal */ true, /* dispatched */ true, + &audit_for_telem, ); // #1002: comp.total_tokens is the cache-inclusive total (an // Anthropic upstream bridged to an OpenAI-shape client folds @@ -2413,6 +2445,7 @@ async fn dispatch( GuardrailVerdict::Block { reason, guardrail_name, + .. } => { tracing::warn!( guardrail_hook = "output", @@ -2999,6 +3032,7 @@ async fn dispatch( GuardrailVerdict::Block { reason, guardrail_name, + .. } => { // Output filter fires AFTER the upstream call, so the // provider has already billed for these tokens. Surface @@ -3231,6 +3265,12 @@ async fn dispatch_ensemble( reservation: aisix_ratelimit::MultiReservation, resolved_chain: &Arc, applied_guardrails: &[AppliedGuardrail], + // The request's ENFORCE-mode audit handle, threaded beside + // `applied_guardrails` because the erased chain above carries neither + // (AISIX-Cloud#1330). The ensemble's judge event is the request's + // terminal one, so it is the event that must report the parent chain's + // enforced hits. + audit: &crate::usage_attr::GuardrailAudit, mut bypass_reason: Option, model_id: &str, api_key_id: &str, @@ -3352,6 +3392,7 @@ async fn dispatch_ensemble( /* content */ None, /* terminal */ false, /* dispatched */ true, + audit, ); }; @@ -3619,6 +3660,8 @@ async fn dispatch_ensemble( crate::usage_attr::metric_model_label(snapshot, &req.model).into_owned(); let api_key_id_for_telem = api_key_id.to_string(); let applied_guardrails_for_telem = applied_guardrails.to_vec(); + // See the single-upstream streaming path. + let audit_for_telem = audit.clone(); let client_for_telem = client.clone(); let bypass_for_telem = bypass_reason.clone().unwrap_or_default(); // Input-side PII mask counts (#932); merged with the streamed judge's @@ -3725,6 +3768,7 @@ async fn dispatch_ensemble( /* content */ None, /* terminal */ false, /* dispatched */ true, + &audit_for_telem, ); } let judge_pk = @@ -3787,6 +3831,7 @@ async fn dispatch_ensemble( /* terminal */ true, /* dispatched */ true, + &audit_for_telem, ); // SLO histograms (AISIX-Cloud#1011): the handler's // record_success is stream-gated, so the ensemble stream @@ -4003,6 +4048,7 @@ async fn dispatch_ensemble( /* terminal */ terminal_judge, /* dispatched */ true, + audit, ); }; @@ -4032,6 +4078,7 @@ async fn dispatch_ensemble( GuardrailVerdict::Block { reason, guardrail_name, + .. } => { tracing::warn!( guardrail_hook = "output", @@ -4290,6 +4337,8 @@ fn emit_usage_event( // the HANDLER's elapsed time, which must not fabricate an upstream // CLIENT span. dispatched: bool, + // The request's enforced-guardrail audit handle (AISIX-Cloud#1330). + audit: &crate::usage_attr::GuardrailAudit, ) { // Per-PK telemetry attribution tags. An unresolved key (the // pre-dispatch error paths) yields default (all empty / false) tags → @@ -4323,6 +4372,10 @@ fn emit_usage_event( applied_guardrails: extras.applied_guardrails, redacted_entity_counts: extras.redacted_entity_counts, guardrail_monitor_hits: extras.guardrail_monitor_hits, + // Guardrails run once per REQUEST, not once per attempt, so only the + // terminal event carries them — a superseded attempt (or an ensemble + // panel member) would otherwise repeat the same hit. + guardrail_enforced_hits: crate::usage_attr::terminal_enforced_hits(terminal, audit), cache_status: extras.cache_status, cache_hit_layer: extras.cache_hit_layer, cache_similarity: extras.cache_similarity, @@ -4524,6 +4577,9 @@ fn emit_failed_attempts( // carries the trace's SERVER + logical spans. False on the success // path, where the winner's event is the terminal one. terminal_last: bool, + // The request's enforced-guardrail audit handle (AISIX-Cloud#1330); + // stamped only on the event this call marks terminal. + audit: &crate::usage_attr::GuardrailAudit, ) { let last_failed = routing.attempts.iter().rposition(|a| !a.success); for (i, rec) in routing @@ -4571,6 +4627,7 @@ fn emit_failed_attempts( // attempt never reached an upstream. /* dispatched */ rec.dispatched, + audit, ); } } @@ -5239,7 +5296,11 @@ where ctx.chain.check_output_observed(&synthesized).await; guard.comp().monitor_hits.extend(hits); match verdict { - aisix_guardrails::GuardrailVerdict::Block { reason, guardrail_name } => { + aisix_guardrails::GuardrailVerdict::Block { + reason, + guardrail_name, + .. + } => { tracing::warn!( guardrail_hook = "output", model = %ctx.model_name, @@ -5443,7 +5504,11 @@ where ); } match verdict { - aisix_guardrails::GuardrailVerdict::Block { reason, guardrail_name } => { + aisix_guardrails::GuardrailVerdict::Block { + reason, + guardrail_name, + .. + } => { tracing::warn!( guardrail_hook = "output", model = %ctx.model_name, @@ -5527,7 +5592,11 @@ where let (verdict, hits) = ctx.chain.check_output_observed(&synthesized).await; guard.comp().monitor_hits.extend(hits); match verdict { - aisix_guardrails::GuardrailVerdict::Block { reason, guardrail_name } => { + aisix_guardrails::GuardrailVerdict::Block { + reason, + guardrail_name, + .. + } => { // Mirror the non-streaming path's #153 // redaction contract: the wire-level message // names only the guardrail that fired (#519 diff --git a/crates/aisix-proxy/src/completions.rs b/crates/aisix-proxy/src/completions.rs index 97bfdfa8b..b8d214de8 100644 --- a/crates/aisix-proxy/src/completions.rs +++ b/crates/aisix-proxy/src/completions.rs @@ -128,7 +128,21 @@ pub async fn completions( // One snapshot for the whole request (#941) — see `embeddings`. let snapshot = state.snapshot.load(); - match dispatch(&state, &snapshot, &auth, body, &request_id, &client).await { + // See `embeddings`: the handle is filled inside `dispatch` so the + // failure branch — where a guardrail block lands — stamps the enforced + // hits too (AISIX-Cloud#1330 / #1024). + let mut audit = crate::usage_attr::GuardrailAudit::default(); + match dispatch( + &state, + &snapshot, + &auth, + body, + &request_id, + &client, + &mut audit, + ) + .await + { Ok(success) => { let elapsed = started.elapsed(); // Audit MEDIUM-2 on PR #426: use the actual response @@ -192,6 +206,7 @@ pub async fn completions( success.redactions.clone(), success.monitor_hits.clone(), success.captured_content.as_ref(), + &audit, ); } success.response @@ -237,6 +252,7 @@ pub async fn completions( status, err.kind(), &client, + crate::usage_attr::enforced_hits(&audit), ); err.into_response() } @@ -271,6 +287,7 @@ async fn dispatch( mut body: Value, request_id: &str, client_ctx: &ClientContext, + audit_out: &mut crate::usage_attr::GuardrailAudit, ) -> Result { let model_name = body .get("model") @@ -303,6 +320,7 @@ async fn dispatch( team_id: auth.key().team_id.as_deref(), }; let resolved_chain = state.guardrail_index.resolve(&guardrail_ctx); + *audit_out = resolved_chain.audit_log(); let mut input_seg_counts = crate::redact::RedactionCounts::new(); let mut monitor_hits: Vec = Vec::new(); if !resolved_chain.is_empty() { @@ -326,6 +344,7 @@ async fn dispatch( if let aisix_guardrails::GuardrailVerdict::Block { reason, guardrail_name, + .. } = verdict { // Per #153 the matched-pattern detail stays in ops logs only. @@ -492,6 +511,7 @@ async fn dispatch( if let aisix_guardrails::GuardrailVerdict::Block { reason, guardrail_name, + .. } = verdict { // Per #153 the matched-pattern detail stays in ops logs only. @@ -701,6 +721,8 @@ fn emit_usage_event( // Captured request/response content for content-capturing exporters // (AISIX-Cloud#947). Forwarded only to `fan_out`, never to the CP sink. content: Option<&CapturedContent>, + // The request's enforced-guardrail audit handle (AISIX-Cloud#1330). + audit: &crate::usage_attr::GuardrailAudit, ) { let mut event = UsageEvent { request_id: request_id.to_string(), @@ -725,6 +747,7 @@ fn emit_usage_event( guardrail_blocked, redacted_entity_counts, guardrail_monitor_hits, + guardrail_enforced_hits: crate::usage_attr::enforced_hits(audit), ..Default::default() }; crate::usage_attr::apply_pk_telemetry(&mut event, pk); @@ -1568,4 +1591,118 @@ mod tests { "a 500 must mark the model in cooldown, got {status:?}" ); } + + /// AISIX-Cloud#1330 / #1024: a guardrail BLOCK leaves this handler + /// through `Err`, so the terminal usage event is the shared + /// zero-token error event. That branch is the one an auditor reads — + /// "which policy refused this request" — and a drain wired only into + /// the success path misses it silently. + #[tokio::test] + async fn blocked_request_names_the_policy_on_the_usage_event() { + use aisix_obs::UsageSink; + + let upstream = MockServer::start().await; + let snap = new_snap(&upstream.uri()); + snap.models.insert(model_entry("my-completions")); + snap.apikeys.insert(apikey_entry(&["*"])); + snap.guardrails.insert(keyword_input_guardrail("BLOCKME")); + + let (tx, mut rx) = tokio::sync::mpsc::channel(8); + let hub = Arc::new(Hub::new()); + hub.register_specialized("openai", Arc::new(OpenAiBridge::new())); + let handle = SnapshotHandle::new(snap); + let app = crate::build_router( + crate::ProxyState::new(handle, hub, &cfg()) + .without_cache() + .with_usage_sink(UsageSink::new(tx)), + ); + + let resp = tower::ServiceExt::oneshot( + app, + make_req(serde_json::json!({"model": "my-completions", "prompt": "please BLOCKME"})), + ) + .await + .unwrap(); + assert_eq!(resp.status(), StatusCode::UNPROCESSABLE_ENTITY); + + let ev = tokio::time::timeout(std::time::Duration::from_millis(500), rx.recv()) + .await + .expect("UsageEvent must be emitted for the refusal") + .expect("usage_sink sender dropped"); + assert_eq!(ev.guardrail_enforced_hits.len(), 1, "{ev:?}"); + assert_eq!(ev.guardrail_enforced_hits[0].guardrail_name, "t"); + assert_eq!(ev.guardrail_enforced_hits[0].hook, "input"); + assert_eq!(ev.guardrail_enforced_hits[0].action, "blocked"); + let wire = serde_json::to_string(&ev).unwrap(); + assert!(!wire.contains("BLOCKME"), "{wire}"); + } + /// A `kind: "pii"` row whose one custom pattern masks a version string + /// on input — the in-process rewrite this handler actually performs, + /// as opposed to the keyword BLOCK the sibling test drives. + fn masking_input_guardrail() -> ResourceEntry { + let g: aisix_core::Guardrail = serde_json::from_str( + r#"{"name":"eda-mask","enabled":true,"hook_point":"input","kind":"pii","detectors":[],"custom_patterns":[{"name":"eda_version","regex":"version\\s*:\\s*(\\d+(?:\\.\\d+)+)","action":"mask","replacement":"***"}]}"#, + ) + .unwrap(); + ResourceEntry::new("g-mask", g, 1) + } + + /// AISIX-Cloud#1330 / #1024: the SUCCESS emitter drains too. + /// + /// The sibling test drives a refusal, which leaves through the shared + /// error event — so on its own it would stay green if the drain were + /// deleted from the success path. An enforcing MASK is the case that + /// only the success emitter can report, and the case a masking + /// deployment lives on: the request is served, nothing errors, and + /// without the drain the /logs row is indistinguishable from one no + /// guardrail touched. + #[tokio::test] + async fn masked_request_names_the_policy_on_the_usage_event() { + use aisix_obs::UsageSink; + + let upstream = MockServer::start().await; + Mock::given(method("POST")) + .and(path("/completions")) + .respond_with(ResponseTemplate::new(200).set_body_json(serde_json::json!({ + "object": "text_completion", + "choices": [{"text": "ok", "index": 0, "finish_reason": "stop"}], + "usage": {"prompt_tokens": 1, "completion_tokens": 1, "total_tokens": 2} + }))) + .mount(&upstream) + .await; + + let snap = new_snap(&upstream.uri()); + snap.models.insert(model_entry("instruct")); + snap.apikeys.insert(apikey_entry(&["*"])); + snap.guardrails.insert(masking_input_guardrail()); + + let (tx, mut rx) = tokio::sync::mpsc::channel(8); + let hub = Arc::new(Hub::new()); + hub.register_specialized("openai", Arc::new(OpenAiBridge::new())); + let handle = SnapshotHandle::new(snap); + let app = crate::build_router( + crate::ProxyState::new(handle, hub, &cfg()) + .without_cache() + .with_usage_sink(UsageSink::new(tx)), + ); + + let resp = tower::ServiceExt::oneshot( + app, + make_req(serde_json::json!({"model": "instruct", "prompt": "build version: 9.9.9 ok"})), + ) + .await + .unwrap(); + assert_eq!(resp.status(), StatusCode::OK); + + let ev = tokio::time::timeout(std::time::Duration::from_millis(500), rx.recv()) + .await + .expect("UsageEvent must be emitted") + .expect("usage_sink sender dropped"); + assert_eq!(ev.guardrail_enforced_hits.len(), 1, "{ev:?}"); + assert_eq!(ev.guardrail_enforced_hits[0].guardrail_name, "eda-mask"); + assert_eq!(ev.guardrail_enforced_hits[0].hook, "input"); + assert_eq!(ev.guardrail_enforced_hits[0].action, "masked"); + let wire = serde_json::to_string(&ev).unwrap(); + assert!(!wire.contains("9.9.9"), "{wire}"); + } } diff --git a/crates/aisix-proxy/src/embeddings.rs b/crates/aisix-proxy/src/embeddings.rs index b1962598c..6fc38707d 100644 --- a/crates/aisix-proxy/src/embeddings.rs +++ b/crates/aisix-proxy/src/embeddings.rs @@ -121,7 +121,22 @@ pub async fn embeddings( // at entry — see the module note on `ProxyState::snapshot`. let snapshot = state.snapshot.load(); - match dispatch(&state, &snapshot, &auth, body, &request_id, &client).await { + // Cloned off the resolved chain inside `dispatch` so BOTH terminal + // branches below can stamp the request's enforced guardrail hits — the + // failure branch most of all, since a guardrail block arrives here as + // an error (AISIX-Cloud#1330 / #1024). + let mut audit = crate::usage_attr::GuardrailAudit::default(); + match dispatch( + &state, + &snapshot, + &auth, + body, + &request_id, + &client, + &mut audit, + ) + .await + { Ok(success) => { let elapsed = started.elapsed(); // The actual response status, not a hardcoded 200: the 501 @@ -190,6 +205,7 @@ pub async fn embeddings( success.redactions.clone(), success.monitor_hits.clone(), success.captured_content.as_ref(), + &audit, ); } success.response @@ -234,6 +250,7 @@ pub async fn embeddings( status, err.kind(), &client, + crate::usage_attr::enforced_hits(&audit), ); err.into_response() } @@ -291,6 +308,7 @@ async fn dispatch( mut body: EmbeddingRequestBody, request_id: &str, client_ctx: &ClientContext, + audit_out: &mut crate::usage_attr::GuardrailAudit, ) -> Result { let model_entry = crate::model_resolve::resolve_model(snapshot, &body.model) .ok_or_else(|| ProxyError::ModelNotFound(body.model.clone()))?; @@ -332,6 +350,9 @@ async fn dispatch( // UsageEvent surfaces them in Logs, like chat / messages. Empty when no // guardrail is attached. let applied_guardrails = resolved_chain.applied().to_vec(); + // Same line, same reason: fill the caller's out-param so the failure + // path — the one a Block takes — can surface the enforced hits too. + *audit_out = resolved_chain.audit_log(); let mut monitor_hits: Vec = Vec::new(); if !resolved_chain.is_empty() { let chat = embeddings_input_to_chat(&body.model, &body.input); @@ -341,6 +362,7 @@ async fn dispatch( if let aisix_guardrails::GuardrailVerdict::Block { reason, guardrail_name, + .. } = verdict { // Per #153 keep the matched-pattern detail in ops logs only; the @@ -637,6 +659,8 @@ fn emit_usage_event( // Captured request/response content (#700). Forwarded only to `fan_out`, // never to the CP sink. content: Option<&CapturedContent>, + // The request's enforced-guardrail audit handle (AISIX-Cloud#1330). + audit: &crate::usage_attr::GuardrailAudit, ) { // Only populate fields meaningful to /v1/embeddings; rely on // UsageEvent's `#[derive(Default)]` for everything else. Wire-level @@ -681,6 +705,7 @@ fn emit_usage_event( applied_guardrails: applied_guardrails.to_vec(), redacted_entity_counts, guardrail_monitor_hits, + guardrail_enforced_hits: crate::usage_attr::enforced_hits(audit), client_source_ip: client.source_ip.clone(), client_user_agent: client.user_agent.clone(), ..Default::default() @@ -1897,4 +1922,127 @@ mod tests { "a 500 must mark the model in cooldown, got {status:?}" ); } + + /// AISIX-Cloud#1330 / #1024: a guardrail BLOCK leaves this handler + /// through `Err`, so the terminal usage event is the shared + /// zero-token error event. That branch is the one an auditor reads — + /// "which policy refused this request" — and a drain wired only into + /// the success path misses it silently. + #[tokio::test] + async fn blocked_request_names_the_policy_on_the_usage_event() { + use aisix_obs::UsageSink; + + let upstream = MockServer::start().await; + let snap = new_snap(&upstream.uri()); + snap.models.insert(model_entry("my-embed")); + snap.apikeys.insert(apikey_entry(&["*"])); + snap.guardrails.insert(keyword_input_guardrail("BLOCKME")); + + let (tx, mut rx) = tokio::sync::mpsc::channel(8); + let hub = Arc::new(Hub::new()); + hub.register_specialized("openai", Arc::new(OpenAiBridge::new())); + let handle = SnapshotHandle::new(snap); + let app = crate::build_router( + crate::ProxyState::new(handle, hub, &cfg()) + .without_cache() + .with_usage_sink(UsageSink::new(tx)), + ); + + let resp = tower::ServiceExt::oneshot( + app, + make_req(serde_json::json!({"model": "my-embed", "input": "please BLOCKME"})), + ) + .await + .unwrap(); + assert_eq!(resp.status(), StatusCode::UNPROCESSABLE_ENTITY); + + let ev = tokio::time::timeout(std::time::Duration::from_millis(500), rx.recv()) + .await + .expect("UsageEvent must be emitted for the refusal") + .expect("usage_sink sender dropped"); + assert_eq!(ev.guardrail_enforced_hits.len(), 1, "{ev:?}"); + assert_eq!(ev.guardrail_enforced_hits[0].guardrail_name, "test-block"); + assert_eq!(ev.guardrail_enforced_hits[0].hook, "input"); + assert_eq!(ev.guardrail_enforced_hits[0].action, "blocked"); + // #153: the blocklist literal is caller content, not audit data. + let wire = serde_json::to_string(&ev).unwrap(); + assert!(!wire.contains("BLOCKME"), "{wire}"); + } + /// A `kind: "pii"` row whose one custom pattern masks a version string + /// on input — the in-process rewrite this handler actually performs, + /// as opposed to the keyword BLOCK the sibling test drives. + fn masking_input_guardrail() -> ResourceEntry { + let g: aisix_core::Guardrail = serde_json::from_str( + r#"{"name":"eda-mask","enabled":true,"hook_point":"input","kind":"pii","detectors":[],"custom_patterns":[{"name":"eda_version","regex":"version\\s*:\\s*(\\d+(?:\\.\\d+)+)","action":"mask","replacement":"***"}]}"#, + ) + .unwrap(); + ResourceEntry::new("g-mask", g, 1) + } + + /// AISIX-Cloud#1330 / #1024: the SUCCESS emitter drains too. + /// + /// The sibling test drives a refusal, which leaves through the shared + /// error event — so on its own it would stay green if the drain were + /// deleted from the success path. An enforcing MASK is the case that + /// only the success emitter can report, and the case a masking + /// deployment lives on: the request is served, nothing errors, and + /// without the drain the /logs row is indistinguishable from one no + /// guardrail touched. + #[tokio::test] + async fn masked_request_names_the_policy_on_the_usage_event() { + use aisix_obs::UsageSink; + + let upstream = MockServer::start().await; + Mock::given(method("POST")) + .and(path("/embeddings")) + .respond_with(ResponseTemplate::new(200).set_body_json(serde_json::json!({ + "object": "list", + "data": [{"object": "embedding", "index": 0, "embedding": [0.1_f32]}], + "model": "text-embedding-3-small", + "usage": {"prompt_tokens": 3, "total_tokens": 3} + }))) + .mount(&upstream) + .await; + + let snap = new_snap(&upstream.uri()); + snap.models.insert(model_entry("my-embed")); + snap.apikeys.insert(apikey_entry(&["*"])); + snap.guardrails.insert(masking_input_guardrail()); + + let (tx, mut rx) = tokio::sync::mpsc::channel(8); + let hub = Arc::new(Hub::new()); + hub.register_specialized("openai", Arc::new(OpenAiBridge::new())); + let handle = SnapshotHandle::new(snap); + let app = crate::build_router( + crate::ProxyState::new(handle, hub, &cfg()) + .without_cache() + .with_usage_sink(UsageSink::new(tx)), + ); + + let resp = tower::ServiceExt::oneshot( + app, + make_req(serde_json::json!({"model": "my-embed", "input": "build version: 9.9.9 ok"})), + ) + .await + .unwrap(); + assert_eq!(resp.status(), StatusCode::OK); + + let ev = tokio::time::timeout(std::time::Duration::from_millis(500), rx.recv()) + .await + .expect("UsageEvent must be emitted") + .expect("usage_sink sender dropped"); + assert_eq!(ev.guardrail_enforced_hits.len(), 1, "{ev:?}"); + assert_eq!(ev.guardrail_enforced_hits[0].guardrail_name, "eda-mask"); + assert_eq!(ev.guardrail_enforced_hits[0].hook, "input"); + assert_eq!(ev.guardrail_enforced_hits[0].action, "masked"); + assert_eq!( + ev.guardrail_enforced_hits[0] + .counts + .get("eda_version") + .copied(), + Some(1) + ); + let wire = serde_json::to_string(&ev).unwrap(); + assert!(!wire.contains("9.9.9"), "{wire}"); + } } diff --git a/crates/aisix-proxy/src/images.rs b/crates/aisix-proxy/src/images.rs index 107f677ba..016370ba7 100644 --- a/crates/aisix-proxy/src/images.rs +++ b/crates/aisix-proxy/src/images.rs @@ -101,7 +101,21 @@ pub async fn image_generations( // One snapshot for the whole request (#941) — see `embeddings`. let snapshot = state.snapshot.load(); - match dispatch(&state, &snapshot, &auth, body, &request_id, &client).await { + // See `embeddings`: filled inside `dispatch` so the failure branch — + // where a guardrail block lands — stamps the enforced hits too + // (AISIX-Cloud#1330 / #1024). + let mut audit = crate::usage_attr::GuardrailAudit::default(); + match dispatch( + &state, + &snapshot, + &auth, + body, + &request_id, + &client, + &mut audit, + ) + .await + { Ok(success) => { let elapsed = started.elapsed(); // The actual response status, not a hardcoded 200: the 501 @@ -168,6 +182,7 @@ pub async fn image_generations( success.redactions.clone(), success.monitor_hits.clone(), success.captured_content.as_ref(), + &audit, ); } success.response @@ -213,6 +228,7 @@ pub async fn image_generations( status, err.kind(), &client, + crate::usage_attr::enforced_hits(&audit), ); err.into_response() } @@ -237,6 +253,7 @@ async fn dispatch( mut body: Value, request_id: &str, client_ctx: &ClientContext, + audit_out: &mut crate::usage_attr::GuardrailAudit, ) -> Result { // Owned so the #696 in-place prompt masking below can borrow `body` // mutably. @@ -271,6 +288,7 @@ async fn dispatch( team_id: auth.key().team_id.as_deref(), }; let resolved_chain = state.guardrail_index.resolve(&guardrail_ctx); + *audit_out = resolved_chain.audit_log(); // Record which guardrails govern this request (#379 parity) so the emitted // UsageEvent surfaces them in Logs, like chat / messages. Empty when no // guardrail is attached. @@ -284,6 +302,7 @@ async fn dispatch( if let aisix_guardrails::GuardrailVerdict::Block { reason, guardrail_name, + .. } = verdict { // Per #153 the matched-pattern detail stays in ops logs only. @@ -501,6 +520,9 @@ pub(crate) fn emit_usage_event( // Captured request/response content (#700). Forwarded only to `fan_out`, // never to the CP sink. content: Option<&CapturedContent>, + // The request's enforced-guardrail audit handle (AISIX-Cloud#1330). + // Shared by both image surfaces, like the rest of this emit. + audit: &crate::usage_attr::GuardrailAudit, ) { let mut event = UsageEvent { request_id: request_id.to_string(), @@ -521,6 +543,7 @@ pub(crate) fn emit_usage_event( client_user_agent: client.user_agent.clone(), redacted_entity_counts, guardrail_monitor_hits, + guardrail_enforced_hits: crate::usage_attr::enforced_hits(audit), ..Default::default() }; crate::usage_attr::apply_pk_telemetry(&mut event, pk); @@ -1334,4 +1357,114 @@ mod tests { "a 500 must mark the model in cooldown, got {status:?}" ); } + + /// AISIX-Cloud#1330 / #1024: a guardrail BLOCK leaves this handler + /// through `Err`, so the terminal usage event is the shared + /// zero-token error event. That branch is the one an auditor reads — + /// "which policy refused this request" — and a drain wired only into + /// the success path misses it silently. + #[tokio::test] + async fn blocked_request_names_the_policy_on_the_usage_event() { + use aisix_obs::UsageSink; + + let upstream = MockServer::start().await; + let snap = new_snap(&upstream.uri()); + snap.models.insert(model_entry("my-image")); + snap.apikeys.insert(apikey_entry(&["*"])); + snap.guardrails.insert(keyword_input_guardrail("BLOCKME")); + + let (tx, mut rx) = tokio::sync::mpsc::channel(8); + let hub = Arc::new(Hub::new()); + hub.register_specialized("openai", Arc::new(OpenAiBridge::new())); + let handle = SnapshotHandle::new(snap); + let app = crate::build_router( + crate::ProxyState::new(handle, hub, &cfg()) + .without_cache() + .with_usage_sink(UsageSink::new(tx)), + ); + + let resp = tower::ServiceExt::oneshot( + app, + make_req(serde_json::json!({"model": "my-image", "prompt": "please BLOCKME"})), + ) + .await + .unwrap(); + assert_eq!(resp.status(), StatusCode::UNPROCESSABLE_ENTITY); + + let ev = tokio::time::timeout(std::time::Duration::from_millis(500), rx.recv()) + .await + .expect("UsageEvent must be emitted for the refusal") + .expect("usage_sink sender dropped"); + assert_eq!(ev.guardrail_enforced_hits.len(), 1, "{ev:?}"); + assert_eq!(ev.guardrail_enforced_hits[0].guardrail_name, "t"); + assert_eq!(ev.guardrail_enforced_hits[0].hook, "input"); + assert_eq!(ev.guardrail_enforced_hits[0].action, "blocked"); + let wire = serde_json::to_string(&ev).unwrap(); + assert!(!wire.contains("BLOCKME"), "{wire}"); + } + /// A `kind: "pii"` row whose one custom pattern masks a version string + /// on input — the in-process rewrite this handler actually performs, + /// as opposed to the keyword BLOCK the sibling test drives. + fn masking_input_guardrail() -> ResourceEntry { + let g: aisix_core::Guardrail = serde_json::from_str( + r#"{"name":"eda-mask","enabled":true,"hook_point":"input","kind":"pii","detectors":[],"custom_patterns":[{"name":"eda_version","regex":"version\\s*:\\s*(\\d+(?:\\.\\d+)+)","action":"mask","replacement":"***"}]}"#, + ) + .unwrap(); + ResourceEntry::new("g-mask", g, 1) + } + + /// AISIX-Cloud#1330 / #1024: the SUCCESS emitter drains too. + /// + /// The sibling test drives a refusal, which leaves through the shared + /// error event — so on its own it would stay green if the drain were + /// deleted from the success path. An enforcing MASK is the case that + /// only the success emitter can report, and the case a masking + /// deployment lives on: the request is served, nothing errors, and + /// without the drain the /logs row is indistinguishable from one no + /// guardrail touched. + #[tokio::test] + async fn masked_request_names_the_policy_on_the_usage_event() { + use aisix_obs::UsageSink; + + let upstream = MockServer::start().await; + Mock::given(method("POST")) + .and(path("/images/generations")) + .respond_with(ResponseTemplate::new(200).set_body_json(upstream_response())) + .mount(&upstream) + .await; + + let snap = new_snap(&upstream.uri()); + snap.models.insert(model_entry("dalle")); + snap.apikeys.insert(apikey_entry(&["*"])); + snap.guardrails.insert(masking_input_guardrail()); + + let (tx, mut rx) = tokio::sync::mpsc::channel(8); + let hub = Arc::new(Hub::new()); + hub.register_specialized("openai", Arc::new(OpenAiBridge::new())); + let handle = SnapshotHandle::new(snap); + let app = crate::build_router( + crate::ProxyState::new(handle, hub, &cfg()) + .without_cache() + .with_usage_sink(UsageSink::new(tx)), + ); + + let resp = tower::ServiceExt::oneshot( + app, + make_req(serde_json::json!({"model": "dalle", "prompt": "draw version: 9.9.9 ok"})), + ) + .await + .unwrap(); + assert_eq!(resp.status(), StatusCode::OK); + + let ev = tokio::time::timeout(std::time::Duration::from_millis(500), rx.recv()) + .await + .expect("UsageEvent must be emitted") + .expect("usage_sink sender dropped"); + assert_eq!(ev.guardrail_enforced_hits.len(), 1, "{ev:?}"); + assert_eq!(ev.guardrail_enforced_hits[0].guardrail_name, "eda-mask"); + assert_eq!(ev.guardrail_enforced_hits[0].hook, "input"); + assert_eq!(ev.guardrail_enforced_hits[0].action, "masked"); + let wire = serde_json::to_string(&ev).unwrap(); + assert!(!wire.contains("9.9.9"), "{wire}"); + } } diff --git a/crates/aisix-proxy/src/images_edits.rs b/crates/aisix-proxy/src/images_edits.rs index 7a444271b..9779aee0a 100644 --- a/crates/aisix-proxy/src/images_edits.rs +++ b/crates/aisix-proxy/src/images_edits.rs @@ -106,6 +106,11 @@ pub async fn image_edits( // the emits below (#941) — see the note on audio's multipart_dispatch. let mut snapshot = None; + // See `embeddings`: filled inside `dispatch` so the failure branch — + // where a guardrail block lands — stamps the enforced hits too + // (AISIX-Cloud#1330 / #1024). + let mut audit = crate::usage_attr::GuardrailAudit::default(); + match dispatch( &state, &mut snapshot, @@ -113,6 +118,7 @@ pub async fn image_edits( multipart, &request_id, &client, + &mut audit, ) .await { @@ -167,6 +173,7 @@ pub async fn image_edits( success.redactions.clone(), success.monitor_hits.clone(), success.captured_content.as_ref(), + &audit, ); success.response } @@ -217,6 +224,7 @@ pub async fn image_edits( status, err.kind(), &client, + crate::usage_attr::enforced_hits(&audit), ); err.into_response() } @@ -236,6 +244,7 @@ async fn dispatch( mut multipart: Multipart, request_id: &str, client_ctx: &ClientContext, + audit_out: &mut crate::usage_attr::GuardrailAudit, ) -> Result { // Collect all fields first so we can find `model` before building the // outgoing reqwest multipart. @@ -311,6 +320,7 @@ async fn dispatch( }; let resolved_chain = state.guardrail_index.resolve(&guardrail_ctx); let applied_guardrails = resolved_chain.applied().to_vec(); + *audit_out = resolved_chain.audit_log(); let mut redactions = crate::redact::RedactionCounts::new(); let mut monitor_hits: Vec = Vec::new(); if !resolved_chain.is_empty() { @@ -332,6 +342,7 @@ async fn dispatch( if let aisix_guardrails::GuardrailVerdict::Block { reason, guardrail_name, + .. } = verdict { // Per #153 the matched-pattern detail stays in ops logs only. @@ -1173,4 +1184,90 @@ mod tests { .unwrap(); assert_eq!(resp.status(), StatusCode::BAD_GATEWAY); } + + /// AISIX-Cloud#1330 / #1024: a guardrail BLOCK leaves this handler + /// through `Err`, so the terminal usage event is the shared + /// zero-token error event. That branch is the one an auditor reads — + /// "which policy refused this request" — and a drain wired only into + /// the success path misses it silently. + #[tokio::test] + async fn blocked_request_names_the_policy_on_the_usage_event() { + let upstream = MockServer::start().await; + let snap = new_snap(&upstream.uri()); + snap.models.insert(model_entry("my-image")); + snap.apikeys.insert(apikey_entry(&["*"])); + snap.guardrails.insert(keyword_input_guardrail("BLOCKME")); + + let (tx, mut rx) = tokio::sync::mpsc::channel(8); + let app = build_app_with_sink(snap, tx); + + let resp = tower::ServiceExt::oneshot(app, make_req("my-image", "please BLOCKME")) + .await + .unwrap(); + assert_eq!(resp.status(), StatusCode::UNPROCESSABLE_ENTITY); + + let ev = tokio::time::timeout(std::time::Duration::from_millis(500), rx.recv()) + .await + .expect("UsageEvent must be emitted for the refusal") + .expect("usage_sink sender dropped"); + assert_eq!(ev.guardrail_enforced_hits.len(), 1, "{ev:?}"); + assert_eq!(ev.guardrail_enforced_hits[0].guardrail_name, "t"); + assert_eq!(ev.guardrail_enforced_hits[0].hook, "input"); + assert_eq!(ev.guardrail_enforced_hits[0].action, "blocked"); + let wire = serde_json::to_string(&ev).unwrap(); + assert!(!wire.contains("BLOCKME"), "{wire}"); + } + /// A `kind: "pii"` row whose one custom pattern masks a version string + /// on input — the in-process rewrite this handler actually performs, + /// as opposed to the keyword BLOCK the sibling test drives. + fn masking_input_guardrail() -> ResourceEntry { + let g: aisix_core::Guardrail = serde_json::from_str( + r#"{"name":"eda-mask","enabled":true,"hook_point":"input","kind":"pii","detectors":[],"custom_patterns":[{"name":"eda_version","regex":"version\\s*:\\s*(\\d+(?:\\.\\d+)+)","action":"mask","replacement":"***"}]}"#, + ) + .unwrap(); + ResourceEntry::new("g-mask", g, 1) + } + + /// AISIX-Cloud#1330 / #1024: the SUCCESS emitter drains too. + /// + /// The sibling test drives a refusal, which leaves through the shared + /// error event — so on its own it would stay green if the drain were + /// deleted from the success path. An enforcing MASK is the case that + /// only the success emitter can report, and the case a masking + /// deployment lives on: the request is served, nothing errors, and + /// without the drain the /logs row is indistinguishable from one no + /// guardrail touched. + #[tokio::test] + async fn masked_request_names_the_policy_on_the_usage_event() { + let upstream = MockServer::start().await; + Mock::given(method("POST")) + .and(path("/v1/images/edits")) + .respond_with(ResponseTemplate::new(200).set_body_json(upstream_response())) + .mount(&upstream) + .await; + + let snap = new_snap(&upstream.uri()); + snap.models.insert(model_entry("my-image")); + snap.apikeys.insert(apikey_entry(&["*"])); + snap.guardrails.insert(masking_input_guardrail()); + + let (tx, mut rx) = tokio::sync::mpsc::channel(8); + let app = build_app_with_sink(snap, tx); + + let resp = tower::ServiceExt::oneshot(app, make_req("my-image", "draw version: 9.9.9 ok")) + .await + .unwrap(); + assert_eq!(resp.status(), StatusCode::OK); + + let ev = tokio::time::timeout(std::time::Duration::from_millis(500), rx.recv()) + .await + .expect("UsageEvent must be emitted") + .expect("usage_sink sender dropped"); + assert_eq!(ev.guardrail_enforced_hits.len(), 1, "{ev:?}"); + assert_eq!(ev.guardrail_enforced_hits[0].guardrail_name, "eda-mask"); + assert_eq!(ev.guardrail_enforced_hits[0].hook, "input"); + assert_eq!(ev.guardrail_enforced_hits[0].action, "masked"); + let wire = serde_json::to_string(&ev).unwrap(); + assert!(!wire.contains("9.9.9"), "{wire}"); + } } diff --git a/crates/aisix-proxy/src/jobs.rs b/crates/aisix-proxy/src/jobs.rs index b3e80ad1d..ffe5b2343 100644 --- a/crates/aisix-proxy/src/jobs.rs +++ b/crates/aisix-proxy/src/jobs.rs @@ -442,6 +442,10 @@ async fn scan_input_blob( target: &JobTarget, blob: &[u8], monitor_hits: &mut Vec, + // Accumulated rather than handed back as one handle: the input and + // output scans resolve their own chain, so a request can produce two + // audit logs (AISIX-Cloud#1330 / #1024). + enforced_hits: &mut Vec, ) -> Result<(), ProxyError> { let ctx = aisix_guardrails::RequestContext { passthrough_route_id: "", @@ -462,9 +466,13 @@ async fn scan_input_blob( ); let (verdict, hits) = aisix_guardrails::Guardrail::check_input_observed(&chain, &chat).await; monitor_hits.extend(hits); + // Drained BEFORE the block branch: a `blocked` hit is exactly the one + // that leaves through `Err`, and the caller's `?` would drop it. + enforced_hits.extend(chain.enforced_hits()); if let aisix_guardrails::GuardrailVerdict::Block { reason, guardrail_name, + .. } = verdict { tracing::warn!( @@ -487,6 +495,10 @@ async fn scan_output_blob( target: &JobTarget, blob: &[u8], monitor_hits: &mut Vec, + // Accumulated rather than handed back as one handle: the input and + // output scans resolve their own chain, so a request can produce two + // audit logs (AISIX-Cloud#1330 / #1024). + enforced_hits: &mut Vec, ) -> Result<(), ProxyError> { let ctx = aisix_guardrails::RequestContext { passthrough_route_id: "", @@ -508,9 +520,12 @@ async fn scan_output_blob( }; let (verdict, hits) = aisix_guardrails::Guardrail::check_output_observed(&chain, &synth).await; monitor_hits.extend(hits); + // See `scan_input_blob`. + enforced_hits.extend(chain.enforced_hits()); if let aisix_guardrails::GuardrailVerdict::Block { reason, guardrail_name, + .. } = verdict { tracing::warn!( @@ -580,6 +595,9 @@ fn emit_job_usage_event( elapsed: Duration, client: &ClientContext, guardrail_monitor_hits: Vec, + // What an ENFORCING guardrail actually did to this request + // (AISIX-Cloud#1330). + guardrail_enforced_hits: Vec, ) { let mut event = UsageEvent { request_id: request_id.to_string(), @@ -596,6 +614,7 @@ fn emit_job_usage_event( client_source_ip: client.source_ip.clone(), client_user_agent: client.user_agent.clone(), guardrail_monitor_hits, + guardrail_enforced_hits, ..Default::default() }; let pk = crate::usage_attr::ResolvedPk::resolve(snap, &target.pk_entry.id); @@ -674,6 +693,7 @@ fn finish( request_id: String, result: Result<(Response, JobTarget), ProxyError>, monitor_hits: Vec, + enforced_hits: Vec, ) -> Response { let elapsed = started.elapsed(); // `path` carries the real job/file id — bounded route template only. @@ -714,6 +734,7 @@ fn finish( elapsed, client, monitor_hits, + enforced_hits, ); if let Ok(hv) = HeaderValue::from_str(&request_id) { resp.headers_mut().insert("x-aisix-request-id", hv); @@ -755,6 +776,7 @@ fn finish( status, err.kind(), client, + enforced_hits, ); err.into_response() } @@ -833,6 +855,7 @@ pub(crate) async fn create_file( } }; let mut monitor_hits: Vec = Vec::new(); + let mut enforced_hits: Vec = Vec::new(); // Loaded below, after the upload is drained — see the note in // `audio::multipart_dispatch` (#941 audit M2). let mut snapshot = None; @@ -906,7 +929,15 @@ pub(crate) async fn create_file( // Batch/fine-tune input files carry end-user content — scan them // like any other inbound payload. - scan_input_blob(&state, &auth, &target, &file_bytes, &mut monitor_hits).await?; + scan_input_blob( + &state, + &auth, + &target, + &file_bytes, + &mut monitor_hits, + &mut enforced_hits, + ) + .await?; let _reservation = crate::quota::enforce( &state, snapshot, @@ -929,7 +960,15 @@ pub(crate) async fn create_file( &request_id, ) .await?; - scan_output_blob(&state, &auth, &target, &bytes, &mut monitor_hits).await?; + scan_output_blob( + &state, + &auth, + &target, + &bytes, + &mut monitor_hits, + &mut enforced_hits, + ) + .await?; let model = target.display_name().to_string(); Ok(( json_response(status, &resp_headers, bytes, Some(&model)), @@ -952,6 +991,7 @@ pub(crate) async fn create_file( request_id, result, monitor_hits, + enforced_hits, ) } @@ -1106,6 +1146,7 @@ pub(crate) async fn create_batch( }; let request_id = client.request_id.clone(); let mut monitor_hits: Vec = Vec::new(); + let mut enforced_hits: Vec = Vec::new(); // One snapshot for the whole request (#941) — see `embeddings`. let snapshot = state.snapshot.load(); @@ -1149,7 +1190,15 @@ pub(crate) async fn create_batch( } let out_body = Bytes::from(serde_json::to_vec(&req_json).unwrap_or_default()); - scan_input_blob(&state, &auth, &target, &out_body, &mut monitor_hits).await?; + scan_input_blob( + &state, + &auth, + &target, + &out_body, + &mut monitor_hits, + &mut enforced_hits, + ) + .await?; let _reservation = crate::quota::enforce( &state, &snapshot, @@ -1172,7 +1221,15 @@ pub(crate) async fn create_batch( &request_id, ) .await?; - scan_output_blob(&state, &auth, &target, &bytes, &mut monitor_hits).await?; + scan_output_blob( + &state, + &auth, + &target, + &bytes, + &mut monitor_hits, + &mut enforced_hits, + ) + .await?; let model = target.display_name().to_string(); Ok(( json_response(status, &resp_headers, bytes, Some(&model)), @@ -1193,6 +1250,7 @@ pub(crate) async fn create_batch( request_id, result, monitor_hits, + enforced_hits, ) } @@ -1208,6 +1266,7 @@ pub(crate) async fn get_batch( let request_id = client.request_id.clone(); let (raw, embedded) = routed_model_hint(&id, ¶ms, &headers); let mut monitor_hits: Vec = Vec::new(); + let mut enforced_hits: Vec = Vec::new(); // One snapshot for the whole request (#941) — see `embeddings`. let snapshot = state.snapshot.load(); @@ -1238,7 +1297,15 @@ pub(crate) async fn get_batch( &request_id, ) .await?; - scan_output_blob(&state, &auth, &target, &bytes, &mut monitor_hits).await?; + scan_output_blob( + &state, + &auth, + &target, + &bytes, + &mut monitor_hits, + &mut enforced_hits, + ) + .await?; // Batch cost attribution (#720): first observation of a completed // batch downloads the output JSONL and emits real token usage. @@ -1268,6 +1335,7 @@ pub(crate) async fn get_batch( request_id, result, monitor_hits, + enforced_hits, ) } @@ -1362,6 +1430,7 @@ pub(crate) async fn create_ft_job( }; let request_id = client.request_id.clone(); let mut monitor_hits: Vec = Vec::new(); + let mut enforced_hits: Vec = Vec::new(); // One snapshot for the whole request (#941) — see `embeddings`. let snapshot = state.snapshot.load(); @@ -1402,7 +1471,15 @@ pub(crate) async fn create_ft_job( } let out_body = Bytes::from(serde_json::to_vec(&req_json).unwrap_or_default()); - scan_input_blob(&state, &auth, &target, &out_body, &mut monitor_hits).await?; + scan_input_blob( + &state, + &auth, + &target, + &out_body, + &mut monitor_hits, + &mut enforced_hits, + ) + .await?; let _reservation = crate::quota::enforce( &state, &snapshot, @@ -1425,7 +1502,15 @@ pub(crate) async fn create_ft_job( &request_id, ) .await?; - scan_output_blob(&state, &auth, &target, &bytes, &mut monitor_hits).await?; + scan_output_blob( + &state, + &auth, + &target, + &bytes, + &mut monitor_hits, + &mut enforced_hits, + ) + .await?; let model = target.display_name().to_string(); Ok(( json_response(status, &resp_headers, bytes, Some(&model)), @@ -1446,6 +1531,7 @@ pub(crate) async fn create_ft_job( request_id, result, monitor_hits, + enforced_hits, ) } @@ -1570,6 +1656,7 @@ async fn forward_simple( let log_path = spec.log_path.clone(); let label = spec.label; let mut monitor_hits: Vec = Vec::new(); + let mut enforced_hits: Vec = Vec::new(); // One snapshot for the whole request (#941) — see `embeddings`. let snapshot = state.snapshot.load(); @@ -1586,7 +1673,15 @@ async fn forward_simple( let target = resolve_target(&snapshot, &auth, wanted.as_deref(), &client)?; if let Some(body) = &spec.body { - scan_input_blob(&state, &auth, &target, body, &mut monitor_hits).await?; + scan_input_blob( + &state, + &auth, + &target, + body, + &mut monitor_hits, + &mut enforced_hits, + ) + .await?; } let _reservation = crate::quota::enforce( &state, @@ -1608,7 +1703,15 @@ async fn forward_simple( }; let (status, resp_headers, bytes) = send_upstream(&state, &target, spec.method, &url, body, &request_id).await?; - scan_output_blob(&state, &auth, &target, &bytes, &mut monitor_hits).await?; + scan_output_blob( + &state, + &auth, + &target, + &bytes, + &mut monitor_hits, + &mut enforced_hits, + ) + .await?; let resp = if spec.relay_raw_body { let mut resp = Response::builder() @@ -1639,6 +1742,7 @@ async fn forward_simple( request_id, result, monitor_hits, + enforced_hits, ) } @@ -2529,4 +2633,68 @@ mod tests { "got {v}" ); } + + /// AISIX-Cloud#1330 / #1024: the jobs surface scans an uploaded blob + /// with its own resolved chain, and a block leaves through `Err`. The + /// hits are therefore accumulated inside the scan — BEFORE the block + /// branch returns — rather than read back from a chain the `?` has + /// already discarded. + #[tokio::test] + async fn blocked_upload_names_the_policy_on_the_usage_event() { + let upstream = MockServer::start().await; + Mock::given(wm_method("POST")) + .and(path("/v1/files")) + .respond_with(ResponseTemplate::new(200).set_body_json(serde_json::json!({ + "id": "file-abc", + "object": "file", + "purpose": "batch", + "filename": "input.jsonl" + }))) + .expect(0) + .mount(&upstream) + .await; + + let snap = AisixSnapshot::new(); + snap.provider_keys.insert(openai_pk(PK_A, &upstream.uri())); + snap.models.insert(model("m-a", "jobs-a", PK_A)); + snap.apikeys.insert(apikey_entry(&["*"])); + // The uploaded blob carries `custom_id`, so blocking on that + // literal refuses the upload without touching the fixture. + let g: aisix_core::Guardrail = serde_json::from_str( + r#"{"name":"test-block","enabled":true,"hook_point":"input","fail_open":false,"kind":"keyword","patterns":[{"kind":"literal","value":"custom_id"}]}"#, + ) + .unwrap(); + snap.guardrails + .insert(aisix_core::resource::ResourceEntry::new("g-1", g, 1)); + let (app, mut rx) = build_app_with_sink(snap); + + let boundary = "XBOUNDARYX"; + let req = Request::builder() + .method("POST") + .uri("/v1/files") + .header("authorization", "Bearer sk-caller") + .header( + "content-type", + format!("multipart/form-data; boundary={boundary}"), + ) + .body(axum::body::Body::from(multipart_body( + boundary, + Some("jobs-a"), + ))) + .unwrap(); + + let resp = app.oneshot(req).await.unwrap(); + assert_eq!(resp.status(), StatusCode::UNPROCESSABLE_ENTITY); + + let ev = tokio::time::timeout(std::time::Duration::from_millis(500), rx.recv()) + .await + .expect("UsageEvent must be emitted for the refusal") + .expect("usage_sink sender dropped"); + assert_eq!(ev.guardrail_enforced_hits.len(), 1, "{ev:?}"); + assert_eq!(ev.guardrail_enforced_hits[0].guardrail_name, "test-block"); + assert_eq!(ev.guardrail_enforced_hits[0].hook, "input"); + assert_eq!(ev.guardrail_enforced_hits[0].action, "blocked"); + let wire = serde_json::to_string(&ev).unwrap(); + assert!(!wire.contains("custom_id"), "{wire}"); + } } diff --git a/crates/aisix-proxy/src/lib.rs b/crates/aisix-proxy/src/lib.rs index 0e76283f8..a923e3f78 100644 --- a/crates/aisix-proxy/src/lib.rs +++ b/crates/aisix-proxy/src/lib.rs @@ -9984,4 +9984,269 @@ data: [DONE]\n\n"; "the judge produced no response, so no judge usage event" ); } + + // ───────────────────────────────────────────────────────────────── + // AISIX-Cloud#1330 / #1024 — enforced guardrail hits on the LLM + // handler family's usage events. + // + // The gap these cover is SILENT: nothing errors and no metric goes to + // zero when the drain is missing, so the only signal is a /logs row + // that reads exactly like "no guardrail acted". `guardrail_blocked` + // covers the refusal case loudly enough; an enforced MASK on a + // non-`/mcp` endpoint was invisible end to end. + // ───────────────────────────────────────────────────────────────── + + /// A `kind: "pii"` row whose one custom pattern masks a version + /// string on both hooks — the in-process mask the audit chain exists + /// for, and the shape the POC deployment actually runs. + const MASKING_GUARDRAIL: &str = r#"{ + "name": "eda-mask", + "kind": "pii", + "hook_point": "both", + "detectors": [], + "custom_patterns": [ + {"name": "eda_version", "regex": "version\\s*:\\s*(\\d+(?:\\.\\d+)+)", "action": "mask", "replacement": "***"} + ] + }"#; + + /// The enforced-hit entry a chain produces for [`MASKING_GUARDRAIL`], + /// asserted the same way on every endpoint so a family member that + /// drifts is obvious in the diff. + #[track_caller] + fn assert_masked_by_eda(event: &aisix_obs::UsageEvent, hook: &str) { + let hits = &event.guardrail_enforced_hits; + assert!( + !hits.is_empty(), + "the enforcing mask left no audit trail on the usage event: {event:?}", + ); + let hit = hits + .iter() + .find(|h| h.hook == hook) + .unwrap_or_else(|| panic!("no `{hook}`-hook enforced hit in {hits:?}")); + assert_eq!(hit.guardrail_name, "eda-mask"); + assert_eq!(hit.action, "masked"); + assert_eq!(hit.counts.get("eda_version").copied(), Some(1)); + // #153: names and counts only — never the value that was masked. + let wire = serde_json::to_string(event).expect("event serialises"); + assert!( + !wire.contains("9.9.9"), + "masked value reached the event: {wire}" + ); + } + + fn chat_request(model: &str, streaming: bool) -> Request { + let body = serde_json::json!({ + "model": model, + "messages": [{"role": "user", "content": "hello"}], + "stream": streaming, + }); + Request::builder() + .method("POST") + .uri("/v1/chat/completions") + .header("authorization", "Bearer sk-caller") + .header("content-type", "application/json") + .body(Body::from(body.to_string())) + .unwrap() + } + + /// Non-streaming `/v1/chat/completions`: an output-hook mask names the + /// row that rewrote the response on the terminal usage event. + #[tokio::test] + async fn chat_usage_event_carries_the_enforced_mask() { + use aisix_obs::UsageSink; + + let upstream = MockServer::start().await; + Mock::given(method("POST")) + .and(path("/chat/completions")) + .respond_with(ResponseTemplate::new(200).set_body_json(serde_json::json!({ + "id": "cmpl-mask-1", + "model": "gpt-4o-2024-08-06", + "choices": [{ + "index": 0, + "message": {"role": "assistant", "content": "the version: 9.9.9 build"}, + "finish_reason": "stop" + }], + "usage": {"prompt_tokens": 4, "completion_tokens": 6, "total_tokens": 10} + }))) + .mount(&upstream) + .await; + + let (tx, mut rx) = tokio::sync::mpsc::channel(8); + let hub = Arc::new(Hub::new()); + hub.register_specialized("openai", Arc::new(OpenAiBridge::new())); + let snap = seed_snapshot("my-gpt4", &["my-gpt4"], &upstream.uri()); + let state = build_state(snap, hub); + seed_guardrail(&state.snapshot, "g-mask", MASKING_GUARDRAIL); + let app = build_router(state.with_usage_sink(UsageSink::new(tx))); + + let resp = run(app, chat_request("my-gpt4", false)).await; + assert_eq!(resp.status(), StatusCode::OK); + let body = to_bytes(resp.into_body(), usize::MAX).await.unwrap(); + let body = String::from_utf8(body.to_vec()).unwrap(); + assert!(body.contains("***"), "the response was not masked: {body}"); + + let event = tokio::time::timeout(std::time::Duration::from_millis(500), rx.recv()) + .await + .expect("usage event was never emitted") + .expect("sender dropped without sending"); + assert_masked_by_eda(&event, "output"); + } + + /// Streaming `/v1/chat/completions` — pitfall (1) of #1024. The + /// end-of-stream event is built inside a `move` closure that runs from + /// a Drop guard after the handler frame is gone, so the chain is not + /// in scope there; the audit handle has to be cloned beside + /// `applied_guardrails` and read in the closure. A drain that only + /// covers the non-streaming branch leaves streamed traffic — which is + /// most Claude-Code / Codex traffic — silently unattributed. + #[tokio::test] + async fn streaming_chat_usage_event_carries_the_enforced_mask() { + use aisix_obs::UsageSink; + + let upstream = MockServer::start().await; + let sse = "\ +data: {\"id\":\"cmpl-mask-2\",\"model\":\"gpt-4o-2024-08-06\",\"choices\":[{\"index\":0,\"delta\":{\"role\":\"assistant\"},\"finish_reason\":null}]}\n\n\ +data: {\"id\":\"cmpl-mask-2\",\"model\":\"gpt-4o-2024-08-06\",\"choices\":[{\"index\":0,\"delta\":{\"content\":\"the version: 9.9.9 build\"},\"finish_reason\":null}]}\n\n\ +data: {\"id\":\"cmpl-mask-2\",\"model\":\"gpt-4o-2024-08-06\",\"choices\":[{\"index\":0,\"delta\":{},\"finish_reason\":\"stop\"}]}\n\n\ +data: [DONE]\n\n"; + Mock::given(method("POST")) + .and(path("/chat/completions")) + .respond_with( + ResponseTemplate::new(200) + .insert_header("content-type", "text/event-stream") + .set_body_string(sse), + ) + .mount(&upstream) + .await; + + let (tx, mut rx) = tokio::sync::mpsc::channel(8); + let hub = Arc::new(Hub::new()); + hub.register_specialized("openai", Arc::new(OpenAiBridge::new())); + let snap = seed_snapshot("my-gpt4", &["my-gpt4"], &upstream.uri()); + let state = build_state(snap, hub); + seed_guardrail(&state.snapshot, "g-mask", MASKING_GUARDRAIL); + let app = build_router(state.with_usage_sink(UsageSink::new(tx))); + + let resp = run(app, chat_request("my-gpt4", true)).await; + assert_eq!(resp.status(), StatusCode::OK); + let body = to_bytes(resp.into_body(), usize::MAX).await.unwrap(); + let body = String::from_utf8(body.to_vec()).unwrap(); + assert!(body.contains("***"), "the stream was not masked: {body}"); + assert!( + !body.contains("9.9.9"), + "the stream leaked the value: {body}" + ); + + let event = tokio::time::timeout(std::time::Duration::from_millis(500), rx.recv()) + .await + .expect("usage event was never emitted") + .expect("sender dropped without sending"); + assert_masked_by_eda(&event, "output"); + } + + /// Pitfall (2) of #1024, chat-only. When a local-model guardrail is + /// configured, `dispatch` re-wraps the resolved chain with + /// `GuardrailChain::new(vec![resolved, local])` — and `new` leaves the + /// OUTER chain's audit log unset. Reading the handle after that point + /// yields `None`, so every attachment-row hit on the chat path would + /// go unattributed while every sibling endpoint reported normally. + /// The handle is therefore taken from the attachment-resolved chain, + /// at the same line `applied()` is snapshotted. + #[tokio::test] + async fn chat_enforced_hits_survive_the_local_model_rewrap() { + use aisix_obs::UsageSink; + + /// Stands in for the env-injected local-model guardrail: a member + /// that never blocks and never masks, present only to force the + /// re-wrap branch. Its own verdicts are irrelevant here — what is + /// under test is that wrapping does not lose the INNER chain's log. + struct InertLocalModel; + #[axum::async_trait] + impl aisix_guardrails::Guardrail for InertLocalModel { + fn name(&self) -> &'static str { + "local-model" + } + async fn check_input( + &self, + _req: &aisix_gateway::ChatFormat, + ) -> aisix_guardrails::GuardrailVerdict { + aisix_guardrails::GuardrailVerdict::Allow + } + } + + let upstream = MockServer::start().await; + Mock::given(method("POST")) + .and(path("/chat/completions")) + .respond_with(ResponseTemplate::new(200).set_body_json(serde_json::json!({ + "id": "cmpl-mask-3", + "model": "gpt-4o-2024-08-06", + "choices": [{ + "index": 0, + "message": {"role": "assistant", "content": "the version: 9.9.9 build"}, + "finish_reason": "stop" + }], + "usage": {"prompt_tokens": 4, "completion_tokens": 6, "total_tokens": 10} + }))) + .mount(&upstream) + .await; + + let (tx, mut rx) = tokio::sync::mpsc::channel(8); + let hub = Arc::new(Hub::new()); + hub.register_specialized("openai", Arc::new(OpenAiBridge::new())); + let snap = seed_snapshot("my-gpt4", &["my-gpt4"], &upstream.uri()); + let state = build_state(snap, hub).with_local_model_guardrail( + Arc::new(InertLocalModel) as Arc + ); + seed_guardrail(&state.snapshot, "g-mask", MASKING_GUARDRAIL); + let app = build_router(state.with_usage_sink(UsageSink::new(tx))); + + let resp = run(app, chat_request("my-gpt4", false)).await; + assert_eq!(resp.status(), StatusCode::OK); + + let event = tokio::time::timeout(std::time::Duration::from_millis(500), rx.recv()) + .await + .expect("usage event was never emitted") + .expect("sender dropped without sending"); + assert_masked_by_eda(&event, "output"); + } + + /// The refusal path: a guardrail BLOCK leaves through `Err`, so the + /// terminal event is built by the failure branch. That branch is the + /// one an auditor reads — "which policy refused this request" — and + /// the one a drain wired only into the success path silently misses. + #[tokio::test] + async fn chat_usage_event_names_the_policy_that_blocked() { + use aisix_obs::UsageSink; + + let upstream = MockServer::start().await; + let (tx, mut rx) = tokio::sync::mpsc::channel(8); + let hub = Arc::new(Hub::new()); + hub.register_specialized("openai", Arc::new(OpenAiBridge::new())); + let snap = seed_snapshot("my-gpt4", &["my-gpt4"], &upstream.uri()); + let state = build_state(snap, hub); + seed_guardrail( + &state.snapshot, + "g-deny", + r#"{"name":"deny-secrets","kind":"keyword","hook_point":"input","patterns":[{"kind":"literal","value":"hello"}]}"#, + ); + let app = build_router(state.with_usage_sink(UsageSink::new(tx))); + + let resp = run(app, chat_request("my-gpt4", false)).await; + assert_eq!(resp.status(), StatusCode::UNPROCESSABLE_ENTITY); + + let event = tokio::time::timeout(std::time::Duration::from_millis(500), rx.recv()) + .await + .expect("usage event was never emitted") + .expect("sender dropped without sending"); + assert!(event.guardrail_blocked); + assert_eq!(event.guardrail_enforced_hits.len(), 1, "{event:?}"); + let hit = &event.guardrail_enforced_hits[0]; + assert_eq!(hit.guardrail_name, "deny-secrets"); + assert_eq!(hit.hook, "input"); + // A policy decision, not an outage — AISIX-Cloud#1365 keeps the + // two apart, and a bare `blocked` is what "content violated the + // policy" must continue to mean. + assert_eq!(hit.action, "blocked"); + assert!(hit.error_type.is_empty()); + } } diff --git a/crates/aisix-proxy/src/mcp.rs b/crates/aisix-proxy/src/mcp.rs index 53e612278..a7c46c34e 100644 --- a/crates/aisix-proxy/src/mcp.rs +++ b/crates/aisix-proxy/src/mcp.rs @@ -413,6 +413,7 @@ async fn dispatch( if let aisix_guardrails::GuardrailVerdict::Block { reason, guardrail_name, + .. } = verdict { tracing::warn!( @@ -797,6 +798,7 @@ async fn apply_output_guardrails( if let aisix_guardrails::GuardrailVerdict::Block { reason, guardrail_name, + .. } = verdict { tracing::warn!( diff --git a/crates/aisix-proxy/src/messages.rs b/crates/aisix-proxy/src/messages.rs index 09a2fb6a5..955540aee 100644 --- a/crates/aisix-proxy/src/messages.rs +++ b/crates/aisix-proxy/src/messages.rs @@ -134,6 +134,10 @@ pub async fn messages( // Filled by `dispatch` with monitor-mode guardrail observations // (AISIX-Cloud#562), same lifecycle as `redaction_counts`. let mut monitor_hits: Vec = Vec::new(); + // Filled by `dispatch` with the request's ENFORCE-mode audit handle + // (AISIX-Cloud#1330 / #1024), same dual-path lifecycle again — the + // input-block path is exactly where a `blocked` hit is recorded. + let mut audit = crate::usage_attr::GuardrailAudit::default(); // #890 req-1: capture the client's streaming intent before dispatch // (which mutates the body). let stream_requested = body @@ -151,6 +155,7 @@ pub async fn messages( &mut applied_guardrails, &mut redaction_counts, &mut monitor_hits, + &mut audit, ) .await { @@ -244,6 +249,7 @@ pub async fn messages( // ...and the terminal trace spans. /* terminal_last */ false, + &audit, ); if !usage_handled_by_stream { // Winning-attempt classification (#655). Direct models have @@ -293,6 +299,7 @@ pub async fn messages( captured_content, /* terminal */ true, /* dispatched */ true, + &audit, ); } response @@ -394,6 +401,7 @@ pub async fn messages( // emission; the pre-dispatch branch below covers empty. /* terminal_last */ !routing.attempts.is_empty(), + &audit, ); // Pre-dispatch failure (model-not-found, auth, budget, guardrail // block before any upstream attempt) records no attempts — emit a @@ -431,6 +439,7 @@ pub async fn messages( // Pre-dispatch failure: no upstream was contacted. /* dispatched */ false, + &audit, ); } // /v1/messages must return Anthropic-shape error envelope @@ -470,6 +479,9 @@ fn emit_failed_attempts_anthropic( // event is the request's terminal emission, so it carries the trace's // SERVER + logical spans. False on the success path. terminal_last: bool, + // The request's enforced-guardrail audit handle (AISIX-Cloud#1330); + // stamped only on the event this call marks terminal. + audit: &crate::usage_attr::GuardrailAudit, ) { let last_failed = routing.attempts.iter().rposition(|a| !a.success); for (i, rec) in routing @@ -515,6 +527,7 @@ fn emit_failed_attempts_anthropic( // attempt never reached an upstream. /* dispatched */ rec.dispatched, + audit, ); } } @@ -541,6 +554,10 @@ async fn dispatch( // Out-param: monitor-mode guardrail observations (AISIX-Cloud#562), // same lifecycle as `redactions_out`. monitor_hits_out: &mut Vec, + // Out-param: the request's ENFORCE-mode audit handle, cloned off the + // resolved chain at the same point `applied_out` is filled + // (AISIX-Cloud#1330). + audit_out: &mut crate::usage_attr::GuardrailAudit, ) -> Result { // Extract and resolve model. let model_name = body @@ -583,6 +600,7 @@ async fn dispatch( // event records which guardrails governed the request even when the input // check below blocks it (#379 / closes the anthropic gap in #519). *applied_out = resolved_chain.applied().to_vec(); + *audit_out = resolved_chain.audit_log(); if !resolved_chain.is_empty() { if let Ok(chat) = aisix_provider_anthropic::parse_inbound_request(body) { let (verdict, hits) = aisix_guardrails::Guardrail::check_input_non_segment_observed( @@ -606,6 +624,7 @@ async fn dispatch( if let aisix_guardrails::GuardrailVerdict::Block { reason, guardrail_name, + .. } = verdict { // AISIX-Cloud#1013: mask before returning so the failure @@ -1316,6 +1335,11 @@ async fn anthropic_passthrough_dispatch( // Applied guardrail set (#379), owned for the move into the // end-of-stream telemetry closure. let applied_guardrails_c = resolved_chain.applied().to_vec(); + // Same line, same reason: the chain itself does not survive into the + // Drop-guard emit, so the audit handle is cloned here and read at + // stream end — where the output-hook mask has just been recorded + // (AISIX-Cloud#1330 / #1024). + let audit_c = resolved_chain.audit_log(); let stream_guardrail = if resolved_chain.is_empty() { None } else { @@ -1473,6 +1497,7 @@ async fn anthropic_passthrough_dispatch( /* terminal */ true, /* dispatched */ true, + &audit_c, ); }, ); @@ -1595,6 +1620,7 @@ async fn anthropic_passthrough_dispatch( if let aisix_guardrails::GuardrailVerdict::Block { reason, guardrail_name, + .. } = verdict { tracing::warn!( @@ -1975,6 +2001,8 @@ async fn cross_provider_dispatch( // Applied guardrail set (#379), owned for the move into the // end-of-stream telemetry closure. let applied_guardrails_for_telem = resolved_chain.applied().to_vec(); + // See the sibling passthrough path. + let audit_for_telem = resolved_chain.audit_log(); let stream_guardrail = if resolved_chain.is_empty() { None } else { @@ -2121,6 +2149,7 @@ async fn cross_provider_dispatch( /* terminal */ true, /* dispatched */ true, + &audit_for_telem, ); }, ); @@ -2190,6 +2219,7 @@ async fn cross_provider_dispatch( if let aisix_guardrails::GuardrailVerdict::Block { reason, guardrail_name, + .. } = verdict { tracing::warn!( @@ -2519,6 +2549,7 @@ fn build_anthropic_sse_stream( if let aisix_guardrails::GuardrailVerdict::Block { reason, guardrail_name, + .. } = verdict { tracing::warn!( @@ -2820,6 +2851,8 @@ fn emit_anthropic_usage_event( // Whether the work this event describes actually reached an upstream — // false for a pre-dispatch failure, whose `elapsed` is handler time. dispatched: bool, + // The request's enforced-guardrail audit handle (AISIX-Cloud#1330). + audit: &crate::usage_attr::GuardrailAudit, ) { // Per-PK telemetry attribution (#302 M17 / AISIX-Cloud#436). // Same shape as chat.rs's emit_usage_event — look up the @@ -2863,6 +2896,10 @@ fn emit_anthropic_usage_event( applied_guardrails, redacted_entity_counts, guardrail_monitor_hits, + // Guardrails run once per REQUEST, not once per attempt, so only + // the terminal event carries them — a superseded attempt would + // otherwise repeat the same hit once per retry. + guardrail_enforced_hits: crate::usage_attr::terminal_enforced_hits(terminal, audit), ..Default::default() }; // Handler label "messages" — Anthropic /v1/messages inbound @@ -3528,6 +3565,7 @@ where if let aisix_guardrails::GuardrailVerdict::Block { reason, guardrail_name, + .. } = verdict { tracing::warn!( @@ -5358,4 +5396,172 @@ data: [DONE]\n\n"; ) .await; } + + // ───────────────────────────────────────────────────────────────── + // AISIX-Cloud#1330 / #1024 — `/v1/messages` is one of the two + // families the handler-family rule names by hand: it carries + // Claude-Code traffic, and before the drain an enforcing mask here + // showed up in Prometheus while the /logs row for the same request + // looked exactly like "no guardrail acted". + // ───────────────────────────────────────────────────────────────── + + /// The same in-process masking row the chat tests use. + fn seed_masking_guardrail(snap: &AisixSnapshot) { + let row: aisix_core::models::Guardrail = serde_json::from_str( + r#"{ + "name": "eda-mask", + "kind": "pii", + "hook_point": "both", + "detectors": [], + "custom_patterns": [ + {"name": "eda_version", "regex": "version\\s*:\\s*(\\d+(?:\\.\\d+)+)", "action": "mask", "replacement": "***"} + ] + }"#, + ) + .unwrap(); + snap.guardrails.insert(ResourceEntry::new("g-mask", row, 1)); + } + + #[track_caller] + fn assert_masked_by_eda(event: &aisix_obs::UsageEvent) { + let hits = &event.guardrail_enforced_hits; + assert!( + !hits.is_empty(), + "the enforcing mask left no audit trail on the usage event: {event:?}", + ); + let hit = hits + .iter() + .find(|h| h.hook == "output") + .unwrap_or_else(|| panic!("no output-hook enforced hit in {hits:?}")); + assert_eq!(hit.guardrail_name, "eda-mask"); + assert_eq!(hit.action, "masked"); + assert_eq!(hit.counts.get("eda_version").copied(), Some(1)); + let wire = serde_json::to_string(event).expect("event serialises"); + assert!( + !wire.contains("9.9.9"), + "masked value reached the event: {wire}" + ); + } + + /// Non-streaming `/v1/messages`. + #[tokio::test] + async fn messages_usage_event_carries_the_enforced_mask() { + use aisix_obs::UsageSink; + + let upstream = MockServer::start().await; + Mock::given(method("POST")) + .and(path("/v1/messages")) + .respond_with(ResponseTemplate::new(200).set_body_json(serde_json::json!({ + "id": "msg_mask_1", + "type": "message", + "role": "assistant", + "content": [{"type": "text", "text": "the version: 9.9.9 build"}], + "model": "claude-3-5-haiku-20241022", + "stop_reason": "end_turn", + "usage": {"input_tokens": 10, "output_tokens": 3} + }))) + .mount(&upstream) + .await; + + let (tx, mut rx) = tokio::sync::mpsc::channel(4); + let snap = new_snap_anthropic(&upstream.uri()); + snap.models.insert(anthropic_model("my-claude")); + snap.apikeys.insert(apikey_entry(&["*"])); + seed_masking_guardrail(&snap); + + let hub = Arc::new(Hub::new()); + hub.register_specialized("anthropic", Arc::new(AnthropicBridge::new())); + let handle = SnapshotHandle::new(snap); + let state = crate::ProxyState::new(handle, hub, &cfg()) + .without_cache() + .with_usage_sink(UsageSink::new(tx)); + let app = crate::build_router(state); + + let resp = app + .oneshot(make_req(serde_json::json!({ + "model": "my-claude", + "messages": [{"role": "user", "content": "hi"}], + "max_tokens": 100, + }))) + .await + .unwrap(); + assert_eq!(resp.status(), StatusCode::OK); + let body = + String::from_utf8(to_bytes(resp.into_body(), 65536).await.unwrap().to_vec()).unwrap(); + assert!(body.contains("***"), "the response was not masked: {body}"); + + let event = tokio::time::timeout(std::time::Duration::from_millis(500), rx.recv()) + .await + .expect("usage event was never emitted") + .expect("usage event sender dropped"); + assert_masked_by_eda(&event); + } + + /// Streaming `/v1/messages` — pitfall (1) of #1024. The terminal event + /// is emitted from the stream's Drop guard, where the chain is long + /// gone; only a cloned audit handle can carry the mask that the + /// hold-back release just applied. + #[tokio::test] + async fn streaming_messages_usage_event_carries_the_enforced_mask() { + use aisix_obs::UsageSink; + + let upstream = MockServer::start().await; + let sse = "\ +event: message_start\ndata: {\"type\":\"message_start\",\"message\":{\"id\":\"msg_mask_2\",\"role\":\"assistant\",\"content\":[],\"model\":\"claude-3-5-haiku-20241022\",\"stop_reason\":null,\"usage\":{\"input_tokens\":37,\"output_tokens\":1}}}\n\n\ +event: content_block_start\ndata: {\"type\":\"content_block_start\",\"index\":0,\"content_block\":{\"type\":\"text\",\"text\":\"\"}}\n\n\ +event: content_block_delta\ndata: {\"type\":\"content_block_delta\",\"index\":0,\"delta\":{\"type\":\"text_delta\",\"text\":\"the version: 9.9.9 build\"}}\n\n\ +event: content_block_stop\ndata: {\"type\":\"content_block_stop\",\"index\":0}\n\n\ +event: message_delta\ndata: {\"type\":\"message_delta\",\"delta\":{\"stop_reason\":\"end_turn\"},\"usage\":{\"output_tokens\":52}}\n\n\ +event: message_stop\ndata: {\"type\":\"message_stop\"}\n\n"; + Mock::given(method("POST")) + .and(path("/v1/messages")) + .respond_with( + ResponseTemplate::new(200) + .insert_header("content-type", "text/event-stream") + .set_body_string(sse), + ) + .mount(&upstream) + .await; + + let (tx, mut rx) = tokio::sync::mpsc::channel(4); + let snap = new_snap_anthropic(&upstream.uri()); + snap.models.insert(anthropic_model("my-claude")); + snap.apikeys.insert(apikey_entry(&["*"])); + seed_masking_guardrail(&snap); + + let hub = Arc::new(Hub::new()); + hub.register_specialized("anthropic", Arc::new(AnthropicBridge::new())); + let handle = SnapshotHandle::new(snap); + let state = crate::ProxyState::new(handle, hub, &cfg()) + .without_cache() + .with_usage_sink(UsageSink::new(tx)); + let app = crate::build_router(state); + + let resp = app + .oneshot(make_req(serde_json::json!({ + "model": "my-claude", + "messages": [{"role": "user", "content": "hi"}], + "max_tokens": 100, + "stream": true, + }))) + .await + .unwrap(); + assert_eq!(resp.status(), StatusCode::OK); + let streamed = + String::from_utf8(to_bytes(resp.into_body(), 65536).await.unwrap().to_vec()).unwrap(); + assert!( + streamed.contains("***"), + "the stream was not masked: {streamed}" + ); + assert!( + !streamed.contains("9.9.9"), + "the stream leaked the value: {streamed}" + ); + + let event = tokio::time::timeout(std::time::Duration::from_millis(500), rx.recv()) + .await + .expect("usage event was never emitted") + .expect("usage event sender dropped"); + assert_masked_by_eda(&event); + } } diff --git a/crates/aisix-proxy/src/passthrough_route.rs b/crates/aisix-proxy/src/passthrough_route.rs index 35b59ad6b..7b471c6d6 100644 --- a/crates/aisix-proxy/src/passthrough_route.rs +++ b/crates/aisix-proxy/src/passthrough_route.rs @@ -364,7 +364,15 @@ pub async fn entry( let route_name = matched.entry.value.name.clone(); - match dispatch(&state, &snapshot, &matched, req, &client, started).await { + // Filled inside `dispatch` at chain resolution, so the failure branch + // — where an input-guardrail block lands — stamps the enforced hits + // too (AISIX-Cloud#1330 / #1024). + let mut audit = crate::usage_attr::GuardrailAudit::default(); + match dispatch( + &state, &snapshot, &matched, req, &client, started, &mut audit, + ) + .await + { Ok(resp) => resp, Err(RouteError { error, auth }) => { let status = error.status().as_u16(); @@ -401,6 +409,7 @@ pub async fn entry( status, error.kind(), &client, + crate::usage_attr::enforced_hits(&audit), ); // The route matched before the pipeline failed, so a rejected // request still attributes to it — an operator triaging 401s @@ -455,6 +464,7 @@ async fn dispatch( req: Request, client: &crate::client_ip::ClientContext, started: Instant, + audit_out: &mut crate::usage_attr::GuardrailAudit, ) -> Result { let route = &matched.entry.value; let route_id: &str = &matched.entry.id; @@ -616,6 +626,7 @@ async fn dispatch( team_id: auth.key().team_id.as_deref(), }; let resolved_chain = state.guardrail_index.resolve(&guardrail_ctx); + *audit_out = resolved_chain.audit_log(); let mut monitor_hits: Vec = Vec::new(); // Envelope detection: once per exchange, from the request body's @@ -635,6 +646,7 @@ async fn dispatch( if let aisix_guardrails::GuardrailVerdict::Block { reason, guardrail_name, + .. } = verdict { // Per #153 the matched-pattern detail stays in ops logs only. @@ -853,6 +865,7 @@ async fn dispatch( error_class: String::new(), error_message: String::new(), monitor_hits, + audit: audit_out.clone(), captured_prompt, content_cap: content_cap.map(|c| c as usize), response_text: String::new(), @@ -913,6 +926,7 @@ async fn dispatch( if let aisix_guardrails::GuardrailVerdict::Block { reason, guardrail_name, + .. } = verdict { tracing::warn!( @@ -1795,7 +1809,11 @@ fn stream_response( { let text = format!("{overlap_tail}{scan_buf}"); match scan_output(&chain, &route_name, &text, &mut telemetry).await { - GuardrailVerdict::Block { reason, guardrail_name } => { + GuardrailVerdict::Block { + reason, + guardrail_name, + .. + } => { tracing::warn!( guardrail_hook = "output", route = %route_name, @@ -1869,7 +1887,11 @@ fn stream_response( } let text = format!("{overlap_tail}{scan_buf}"); if !chain.is_empty() && !text.is_empty() { - if let GuardrailVerdict::Block { reason, guardrail_name } = + if let GuardrailVerdict::Block { + reason, + guardrail_name, + .. + } = scan_output(&chain, &route_name, &text, &mut telemetry).await { tracing::warn!( @@ -2041,6 +2063,11 @@ struct RouteTelemetry { error_class: String, error_message: String, monitor_hits: Vec, + /// The request's ENFORCE-mode audit handle (AISIX-Cloud#1330). Held + /// rather than snapshotted at construction: this struct's emit runs + /// from the relay's `Drop`, long after the output hook has recorded + /// whatever it masked. + audit: crate::usage_attr::GuardrailAudit, captured_prompt: Option, content_cap: Option, response_text: String, @@ -2154,6 +2181,7 @@ impl RouteTelemetry { client_user_agent: self.client_user_agent.clone(), guardrail_blocked: self.guardrail_blocked, guardrail_monitor_hits: std::mem::take(&mut self.monitor_hits), + guardrail_enforced_hits: crate::usage_attr::enforced_hits(&self.audit), ..Default::default() }; crate::usage_attr::apply_pk_telemetry(&mut event, &pk); @@ -3199,4 +3227,66 @@ mod tests { push_capped(&mut buf, "more", None); assert!(buf.len() <= 3); } + + /// AISIX-Cloud#1330 / #1024: an input-guardrail block on a + /// passthrough route leaves through `RouteError`, and the terminal + /// event is built by the handler's failure branch — the only place a + /// refused passthrough request appears in Logs at all. + #[tokio::test] + async fn blocked_request_names_the_policy_on_the_usage_event() { + use aisix_obs::UsageSink; + + let upstream = MockServer::start().await; + Mock::given(wm_method("POST")) + .and(wm_path("/v1/chat/completions")) + .respond_with(ResponseTemplate::new(200).set_body_json(serde_json::json!({}))) + .expect(0) + .mount(&upstream) + .await; + + let snap = AisixSnapshot::new(); + snap.provider_keys + .insert(provider_key_entry("http://unused")); + snap.apikeys.insert(apikey_entry("sk-caller", Some(&["*"]))); + snap.passthrough_routes + .insert(inject_route(&upstream.uri())); + let g: aisix_core::Guardrail = serde_json::from_str( + r#"{"name":"test-block","enabled":true,"hook_point":"input","fail_open":false,"kind":"keyword","patterns":[{"kind":"literal","value":"BLOCKME"}]}"#, + ) + .unwrap(); + snap.guardrails.insert(ResourceEntry::new("g-1", g, 1)); + + let (tx, mut rx) = tokio::sync::mpsc::channel(8); + let hub = Arc::new(Hub::new()); + let handle = SnapshotHandle::new(snap); + let app = crate::build_router( + crate::ProxyState::new(handle, hub, &cfg()) + .without_cache() + .with_usage_sink(UsageSink::new(tx)), + ); + + let req = Request::builder() + .method("POST") + .uri("/passthrough/openai/v1/chat/completions") + .header("authorization", "Bearer sk-caller") + .header("content-type", "application/json") + .body(axum::body::Body::from( + serde_json::json!({"model": "x", "messages": [{"role": "user", "content": "please BLOCKME"}]}) + .to_string(), + )) + .unwrap(); + let resp = app.oneshot(req).await.unwrap(); + assert_eq!(resp.status(), StatusCode::UNPROCESSABLE_ENTITY); + + let ev = tokio::time::timeout(std::time::Duration::from_millis(500), rx.recv()) + .await + .expect("UsageEvent must be emitted for the refusal") + .expect("usage_sink sender dropped"); + assert_eq!(ev.guardrail_enforced_hits.len(), 1, "{ev:?}"); + assert_eq!(ev.guardrail_enforced_hits[0].guardrail_name, "test-block"); + assert_eq!(ev.guardrail_enforced_hits[0].hook, "input"); + assert_eq!(ev.guardrail_enforced_hits[0].action, "blocked"); + let wire = serde_json::to_string(&ev).unwrap(); + assert!(!wire.contains("BLOCKME"), "{wire}"); + } } diff --git a/crates/aisix-proxy/src/realtime.rs b/crates/aisix-proxy/src/realtime.rs index 616d6bf15..87987c2cd 100644 --- a/crates/aisix-proxy/src/realtime.rs +++ b/crates/aisix-proxy/src/realtime.rs @@ -201,6 +201,9 @@ pub(crate) async fn realtime( status, err.kind(), &client, + // Refused before the handshake, so no chain was ever + // resolved and no guardrail can have enforced anything. + Vec::new(), ); err.into_response() } @@ -487,6 +490,9 @@ async fn run_session( team_id: auth.key().team_id.as_deref(), }; let chain = state.guardrail_index.resolve(&guardrail_ctx); + // Read back on every terminal emit below — the session's own event and + // the upstream-connect failure (AISIX-Cloud#1330 / #1024). + let audit = chain.audit_log(); let (mut client_tx, mut client_rx) = client_ws.split(); @@ -541,6 +547,7 @@ async fn run_session( 502, "transport", &client, + crate::usage_attr::enforced_hits(&audit), ); return; } @@ -772,6 +779,7 @@ async fn run_session( client_source_ip: client.source_ip.clone(), client_user_agent: client.user_agent.clone(), guardrail_monitor_hits: monitor_hits, + guardrail_enforced_hits: crate::usage_attr::enforced_hits(&audit), ..Default::default() }; crate::usage_attr::apply_pk_telemetry(&mut event, &pk); @@ -851,6 +859,7 @@ async fn guardrail_block_event( if let aisix_guardrails::GuardrailVerdict::Block { reason, guardrail_name, + .. } = verdict { let side = if input_side { "input" } else { "output" }; @@ -1367,4 +1376,57 @@ mod tests { ); assert_eq!(rx.try_recv().expect("recorded").status_code, 405); } + + /// AISIX-Cloud#1330 / #1024: a realtime session's terminal usage + /// event is emitted once, when the socket closes — including when a + /// guardrail refused a frame and closed it. The audit handle is read + /// there rather than at chain resolution because an output-hook mask + /// can land at any point in the session's life. + #[tokio::test] + async fn blocked_frame_names_the_policy_on_the_session_usage_event() { + let (up_addr, _handshake, _frames) = spawn_upstream().await; + let snap = snapshot(&format!("http://{up_addr}/v1"), "openai", "openai"); + let g: aisix_core::Guardrail = serde_json::from_str( + r#"{"name":"test-block","enabled":true,"hook_point":"input","fail_open":false,"kind":"keyword","patterns":[{"kind":"literal","value":"BLOCKME"}]}"#, + ) + .unwrap(); + snap.guardrails + .insert(aisix_core::resource::ResourceEntry::new("g-1", g, 1)); + let (addr, _state, mut rx) = serve(snap).await; + + let mut req = format!("ws://{addr}/v1/realtime?model=rt-model") + .into_client_request() + .unwrap(); + req.headers_mut() + .insert("authorization", "Bearer sk-caller".parse().unwrap()); + let (ws, _) = tokio_tungstenite::connect_async(req) + .await + .expect("handshake"); + let (mut tx, mut client_rx) = ws.split(); + + tx.send(TgMessage::Text( + serde_json::json!({"type": "session.update", "session": {"instructions": "please BLOCKME"}}) + .to_string(), + )) + .await + .unwrap(); + // Drain until the gateway closes the socket, so the session's + // terminal emit has run. + while let Some(Ok(msg)) = client_rx.next().await { + if matches!(msg, TgMessage::Close(_)) { + break; + } + } + + let ev = tokio::time::timeout(std::time::Duration::from_secs(2), rx.recv()) + .await + .expect("the session must emit a UsageEvent") + .expect("usage_sink sender dropped"); + assert_eq!(ev.guardrail_enforced_hits.len(), 1, "{ev:?}"); + assert_eq!(ev.guardrail_enforced_hits[0].guardrail_name, "test-block"); + assert_eq!(ev.guardrail_enforced_hits[0].hook, "input"); + assert_eq!(ev.guardrail_enforced_hits[0].action, "blocked"); + let wire = serde_json::to_string(&ev).unwrap(); + assert!(!wire.contains("BLOCKME"), "{wire}"); + } } diff --git a/crates/aisix-proxy/src/rerank.rs b/crates/aisix-proxy/src/rerank.rs index 504f4d66d..efe7c6b91 100644 --- a/crates/aisix-proxy/src/rerank.rs +++ b/crates/aisix-proxy/src/rerank.rs @@ -111,7 +111,21 @@ pub async fn rerank( // One snapshot for the whole request (#941) — see `embeddings`. let snapshot = state.snapshot.load(); - match dispatch(&state, &snapshot, &auth, &mut body, &request_id, &client).await { + // See `embeddings`: filled inside `dispatch` so the failure branch — + // where a guardrail block lands — stamps the enforced hits too + // (AISIX-Cloud#1330 / #1024). + let mut audit = crate::usage_attr::GuardrailAudit::default(); + match dispatch( + &state, + &snapshot, + &auth, + &mut body, + &request_id, + &client, + &mut audit, + ) + .await + { Ok(success) => { let elapsed = started.elapsed(); let status = success.response.status().as_u16(); @@ -168,6 +182,7 @@ pub async fn rerank( success.redactions.clone(), success.monitor_hits.clone(), success.captured_content.as_ref(), + &audit, ); } success.response @@ -213,6 +228,7 @@ pub async fn rerank( status, err.kind(), &client, + crate::usage_attr::enforced_hits(&audit), ); err.into_response() } @@ -251,6 +267,7 @@ async fn dispatch( body: &mut Value, request_id: &str, client_ctx: &ClientContext, + audit_out: &mut crate::usage_attr::GuardrailAudit, ) -> Result { let model_name = body .get("model") @@ -286,6 +303,7 @@ async fn dispatch( // UsageEvent surfaces them in Logs, like chat / messages. Empty when no // guardrail is attached. let applied_guardrails = resolved_chain.applied().to_vec(); + *audit_out = resolved_chain.audit_log(); let mut monitor_hits: Vec = Vec::new(); if !resolved_chain.is_empty() { let chat = rerank_input_to_chat(&model_name, &*body); @@ -295,6 +313,7 @@ async fn dispatch( if let aisix_guardrails::GuardrailVerdict::Block { reason, guardrail_name, + .. } = verdict { // Per #153 the matched-pattern detail stays in ops logs only. @@ -674,6 +693,8 @@ fn emit_usage_event( // Captured request/response content (#700). Forwarded only to `fan_out`, // never to the CP sink. content: Option<&CapturedContent>, + // The request's enforced-guardrail audit handle (AISIX-Cloud#1330). + audit: &crate::usage_attr::GuardrailAudit, ) { let mut event = UsageEvent { request_id: request_id.to_string(), @@ -694,6 +715,7 @@ fn emit_usage_event( client_user_agent: client.user_agent.clone(), redacted_entity_counts, guardrail_monitor_hits, + guardrail_enforced_hits: crate::usage_attr::enforced_hits(audit), ..Default::default() }; // Per-PK attribution tags (provider_kind / provider_featured / @@ -1946,4 +1968,125 @@ mod tests { "mask counts must reach the UsageEvent" ); } + + /// AISIX-Cloud#1330 / #1024: a guardrail BLOCK leaves this handler + /// through `Err`, so the terminal usage event is the shared + /// zero-token error event. That branch is the one an auditor reads — + /// "which policy refused this request" — and a drain wired only into + /// the success path misses it silently. + #[tokio::test] + async fn blocked_request_names_the_policy_on_the_usage_event() { + use aisix_obs::UsageSink; + + let upstream = MockServer::start().await; + let snap = new_snap(&upstream.uri()); + snap.models.insert(openai_model("rerank-model")); + snap.apikeys.insert(apikey_entry(&["*"])); + snap.guardrails.insert(keyword_input_guardrail("BLOCKME")); + + let (tx, mut rx) = tokio::sync::mpsc::channel(8); + let hub = Arc::new(Hub::new()); + hub.register_specialized("openai", Arc::new(OpenAiBridge::new())); + let handle = SnapshotHandle::new(snap); + let app = crate::build_router( + crate::ProxyState::new(handle, hub, &cfg()) + .without_cache() + .with_usage_sink(UsageSink::new(tx)), + ); + + let resp = tower::ServiceExt::oneshot( + app, + make_req(serde_json::json!({ + "model": "rerank-model", + "query": "please BLOCKME", + "documents": ["a"] + })), + ) + .await + .unwrap(); + assert_eq!(resp.status(), StatusCode::UNPROCESSABLE_ENTITY); + + let ev = tokio::time::timeout(std::time::Duration::from_millis(500), rx.recv()) + .await + .expect("UsageEvent must be emitted for the refusal") + .expect("usage_sink sender dropped"); + assert_eq!(ev.guardrail_enforced_hits.len(), 1, "{ev:?}"); + assert_eq!(ev.guardrail_enforced_hits[0].guardrail_name, "t"); + assert_eq!(ev.guardrail_enforced_hits[0].hook, "input"); + assert_eq!(ev.guardrail_enforced_hits[0].action, "blocked"); + let wire = serde_json::to_string(&ev).unwrap(); + assert!(!wire.contains("BLOCKME"), "{wire}"); + } + /// A `kind: "pii"` row whose one custom pattern masks a version string + /// on input — the in-process rewrite this handler actually performs, + /// as opposed to the keyword BLOCK the sibling test drives. + fn masking_input_guardrail() -> ResourceEntry { + let g: aisix_core::Guardrail = serde_json::from_str( + r#"{"name":"eda-mask","enabled":true,"hook_point":"input","kind":"pii","detectors":[],"custom_patterns":[{"name":"eda_version","regex":"version\\s*:\\s*(\\d+(?:\\.\\d+)+)","action":"mask","replacement":"***"}]}"#, + ) + .unwrap(); + ResourceEntry::new("g-mask", g, 1) + } + + /// AISIX-Cloud#1330 / #1024: the SUCCESS emitter drains too. + /// + /// The sibling test drives a refusal, which leaves through the shared + /// error event — so on its own it would stay green if the drain were + /// deleted from the success path. An enforcing MASK is the case that + /// only the success emitter can report, and the case a masking + /// deployment lives on: the request is served, nothing errors, and + /// without the drain the /logs row is indistinguishable from one no + /// guardrail touched. + #[tokio::test] + async fn masked_request_names_the_policy_on_the_usage_event() { + use aisix_obs::UsageSink; + + let upstream = MockServer::start().await; + Mock::given(method("POST")) + .and(path("/v1/rerank")) + .respond_with(ResponseTemplate::new(200).set_body_json(serde_json::json!({ + "results": [{"index": 0, "relevance_score": 0.9}], + "usage": {"prompt_tokens": 4, "total_tokens": 4} + }))) + .mount(&upstream) + .await; + + let snap = new_snap(&upstream.uri()); + snap.models.insert(openai_model("rerank-model")); + snap.apikeys.insert(apikey_entry(&["*"])); + snap.guardrails.insert(masking_input_guardrail()); + + let (tx, mut rx) = tokio::sync::mpsc::channel(8); + let hub = Arc::new(Hub::new()); + hub.register_specialized("openai", Arc::new(OpenAiBridge::new())); + let handle = SnapshotHandle::new(snap); + let app = crate::build_router( + crate::ProxyState::new(handle, hub, &cfg()) + .without_cache() + .with_usage_sink(UsageSink::new(tx)), + ); + + let resp = tower::ServiceExt::oneshot( + app, + make_req(serde_json::json!({ + "model": "rerank-model", + "query": "build version: 9.9.9 ok", + "documents": ["clean"] + })), + ) + .await + .unwrap(); + assert_eq!(resp.status(), StatusCode::OK); + + let ev = tokio::time::timeout(std::time::Duration::from_millis(500), rx.recv()) + .await + .expect("UsageEvent must be emitted") + .expect("usage_sink sender dropped"); + assert_eq!(ev.guardrail_enforced_hits.len(), 1, "{ev:?}"); + assert_eq!(ev.guardrail_enforced_hits[0].guardrail_name, "eda-mask"); + assert_eq!(ev.guardrail_enforced_hits[0].hook, "input"); + assert_eq!(ev.guardrail_enforced_hits[0].action, "masked"); + let wire = serde_json::to_string(&ev).unwrap(); + assert!(!wire.contains("9.9.9"), "{wire}"); + } } diff --git a/crates/aisix-proxy/src/responses.rs b/crates/aisix-proxy/src/responses.rs index e93a26f3c..cfe945bc4 100644 --- a/crates/aisix-proxy/src/responses.rs +++ b/crates/aisix-proxy/src/responses.rs @@ -213,6 +213,10 @@ pub async fn responses( // Filled by `dispatch` with monitor-mode guardrail observations // (AISIX-Cloud#562), same lifecycle as `redaction_counts`. let mut monitor_hits: Vec = Vec::new(); + // Filled by `dispatch` at chain resolution with the request's + // ENFORCE-mode audit handle (AISIX-Cloud#1330 / #1024), same lifecycle + // again — read back by whichever emit below is the terminal one. + let mut audit = crate::usage_attr::GuardrailAudit::default(); // One snapshot for the whole request (#941) — see `embeddings`. let snapshot = state.snapshot.load(); match dispatch( @@ -225,6 +229,7 @@ pub async fn responses( &client, &mut redaction_counts, &mut monitor_hits, + &mut audit, ) .await { @@ -287,6 +292,7 @@ pub async fn responses( // The winner's event carries the terminal spans. /* terminal_last */ false, + &audit, ); // Issue #404: emit UsageEvent so cp-api's budget ledger // and customer-facing /logs analytics see /v1/responses @@ -355,6 +361,7 @@ pub async fn responses( success.captured_content.as_ref(), /* terminal */ true, /* dispatched */ true, + &audit, ); } } @@ -452,6 +459,7 @@ pub async fn responses( // emission; the pre-dispatch branch below covers empty. /* terminal_last */ !routing.attempts.is_empty(), + &audit, ); // Pre-dispatch failure (model-not-found, auth, budget) records no // attempts — emit a single terminal event carrying the failure @@ -483,6 +491,7 @@ pub async fn responses( // Pre-dispatch failure: no upstream contacted. /* dispatched */ false, + &audit, ); } err.into_response() @@ -512,6 +521,11 @@ async fn dispatch( // Out-param: monitor-mode guardrail observations (AISIX-Cloud#562), // same lifecycle as `redactions_out`. monitor_hits_out: &mut Vec, + // Out-param: the request's ENFORCE-mode audit handle, cloned off the + // resolved chain (AISIX-Cloud#1330). Handed back rather than read here + // because the terminal event is built by the caller — and, on the + // streaming paths, from a closure that runs after both frames are gone. + audit_out: &mut crate::usage_attr::GuardrailAudit, ) -> Result { let model_name = body .get("model") @@ -552,6 +566,7 @@ async fn dispatch( // response body (which outlives this handler) for end-of-stream output // guardrails (#825), mirroring /v1/messages. let resolved_chain = Arc::new(state.guardrail_index.resolve(&guardrail_ctx)); + *audit_out = resolved_chain.audit_log(); if !resolved_chain.is_empty() { let chat = responses_input_to_chat(&model_name, body); let (verdict, hits) = aisix_guardrails::Guardrail::check_input_non_segment_observed( @@ -575,6 +590,7 @@ async fn dispatch( if let aisix_guardrails::GuardrailVerdict::Block { reason, guardrail_name, + .. } = verdict { // Per #153 the matched-pattern detail stays in ops logs only; the @@ -1333,6 +1349,7 @@ async fn responses_to_target( if let aisix_guardrails::GuardrailVerdict::Block { reason, guardrail_name, + .. } = verdict { // Per #153 the matched-pattern detail stays in ops logs only. @@ -1474,6 +1491,11 @@ async fn responses_to_target( // call (e.g. all Codex traffic, which always streams) was invisible // to the dashboard Logs and the budget ledger. let state_c = state.clone(); + // The chain does not survive into the end-of-stream closure, so + // clone the audit handle here and read it there — the streaming + // paths are where an output-hook mask actually lands + // (AISIX-Cloud#1330 / #1024). + let audit_c = chain.audit_log(); let request_id_c = request_id.to_string(); let model_id_c = model_id.to_string(); let requested_model_c = requested_model.to_string(); @@ -1622,6 +1644,7 @@ async fn responses_to_target( captured_content.as_ref(), /* terminal */ true, /* dispatched */ true, + &audit_c, ); }, ); @@ -1725,6 +1748,7 @@ async fn responses_to_target( if let aisix_guardrails::GuardrailVerdict::Block { reason, guardrail_name, + .. } = verdict { // Per #153 the matched-pattern detail stays in ops logs only. @@ -1977,6 +2001,11 @@ async fn responses_cross_provider_to_target( }; let state_c = state.clone(); + // The chain does not survive into the end-of-stream closure, so + // clone the audit handle here and read it there — the streaming + // paths are where an output-hook mask actually lands + // (AISIX-Cloud#1330 / #1024). + let audit_c = chain.audit_log(); let request_id_c = request_id.to_string(); let model_id_c = model_id.to_string(); let requested_model_c = requested_model.to_string(); @@ -2119,6 +2148,7 @@ async fn responses_cross_provider_to_target( captured_content.as_ref(), /* terminal */ true, /* dispatched */ true, + &audit_c, ); }, ); @@ -2229,6 +2259,7 @@ async fn responses_cross_provider_to_target( if let aisix_guardrails::GuardrailVerdict::Block { reason, guardrail_name, + .. } = verdict { tracing::warn!( @@ -2944,6 +2975,8 @@ fn emit_usage_event( // Whether the work this event describes actually reached an upstream — // false for a pre-dispatch failure, whose `elapsed` is handler time. dispatched: bool, + // The request's enforced-guardrail audit handle (AISIX-Cloud#1330). + audit: &crate::usage_attr::GuardrailAudit, ) { let tags = pk.telemetry_tags(); let mut event = UsageEvent { @@ -2982,6 +3015,8 @@ fn emit_usage_event( guardrail_blocked, redacted_entity_counts, guardrail_monitor_hits, + // See `emit_zero_token_event`: request-scoped, so terminal only. + guardrail_enforced_hits: crate::usage_attr::terminal_enforced_hits(terminal, audit), ..Default::default() }; crate::usage_attr::apply_jwt_identity(&mut event, client.jwt.as_ref()); @@ -3065,6 +3100,8 @@ fn emit_zero_token_event( // Whether this attempt actually reached an upstream — false on the // pre-dispatch path, true for a recorded failed attempt. dispatched: bool, + // The request's enforced-guardrail audit handle (AISIX-Cloud#1330). + audit: &crate::usage_attr::GuardrailAudit, ) { let pk = ResolvedPk::resolve(snap, provider_key_id); let tags = pk.telemetry_tags(); @@ -3091,6 +3128,10 @@ fn emit_zero_token_event( byo_label: sanitize_tag(tags.byo_label.unwrap_or_default()), client_source_ip: client.source_ip.clone(), client_user_agent: client.user_agent.clone(), + // Guardrails run once per REQUEST, not once per attempt, so a + // superseded attempt's event would repeat the same hit per retry. + // Only the terminal event carries them. + guardrail_enforced_hits: crate::usage_attr::terminal_enforced_hits(terminal, audit), ..Default::default() }; crate::usage_attr::apply_jwt_identity(&mut event, client.jwt.as_ref()); @@ -3128,6 +3169,9 @@ fn emit_failed_attempts( // event is the request's terminal emission, so it carries the trace's // SERVER + logical spans. False on the success path. terminal_last: bool, + // The request's enforced-guardrail audit handle (AISIX-Cloud#1330); + // stamped only on the event this call marks terminal. + audit: &crate::usage_attr::GuardrailAudit, ) { let last_failed = routing.attempts.iter().rposition(|a| !a.success); for (i, rec) in routing @@ -3165,6 +3209,7 @@ fn emit_failed_attempts( // attempt never reached an upstream. /* dispatched */ rec.dispatched, + audit, ); } } @@ -5666,4 +5711,170 @@ data: [DONE]\n\n"; // the accumulation stops near the cap instead of growing 100x. assert!(text.len() <= 20, "delta buffer must stay near the cap"); } + + // ───────────────────────────────────────────────────────────────── + // AISIX-Cloud#1330 / #1024 — `/v1/responses` is the other family the + // handler-family rule names by hand: it carries Codex traffic, and a + // chat-only test would stay green forever while this one silently + // reported nothing. + // ───────────────────────────────────────────────────────────────── + + /// The same in-process masking row the chat / messages tests use. + fn masking_guardrail() -> ResourceEntry { + let row: aisix_core::models::Guardrail = serde_json::from_str( + r#"{ + "name": "eda-mask", + "kind": "pii", + "hook_point": "both", + "detectors": [], + "custom_patterns": [ + {"name": "eda_version", "regex": "version\\s*:\\s*(\\d+(?:\\.\\d+)+)", "action": "mask", "replacement": "***"} + ] + }"#, + ) + .unwrap(); + ResourceEntry::new("g-mask", row, 1) + } + + /// `spans` is how many times the pattern occurs in what the upstream + /// actually sent: the Responses streaming wire shape repeats the full + /// text on the terminal `response.completed` event, so a value that + /// appears once to a reader is two masked spans on the wire. + #[track_caller] + fn assert_masked_by_eda(event: &aisix_obs::UsageEvent, spans: u32) { + let hits = &event.guardrail_enforced_hits; + assert!( + !hits.is_empty(), + "the enforcing mask left no audit trail on the usage event: {event:?}", + ); + let hit = hits + .iter() + .find(|h| h.hook == "output") + .unwrap_or_else(|| panic!("no output-hook enforced hit in {hits:?}")); + assert_eq!(hit.guardrail_name, "eda-mask"); + assert_eq!(hit.action, "masked"); + assert_eq!(hit.counts.get("eda_version").copied(), Some(spans)); + let wire = serde_json::to_string(event).expect("event serialises"); + assert!( + !wire.contains("9.9.9"), + "masked value reached the event: {wire}" + ); + } + + /// Non-streaming `/v1/responses`. + #[tokio::test] + async fn responses_usage_event_carries_the_enforced_mask() { + use aisix_obs::UsageSink; + + let upstream = MockServer::start().await; + Mock::given(method("POST")) + .and(path("/v1/responses")) + .respond_with(ResponseTemplate::new(200).set_body_json(serde_json::json!({ + "id": "resp-mask-1", + "object": "response", + "model": "gpt-4o-2024-08-06", + "output": [{ + "type": "message", + "id": "msg-1", + "role": "assistant", + "content": [{"type": "output_text", "text": "the version: 9.9.9 build"}] + }], + "usage": {"input_tokens": 5, "output_tokens": 7, "total_tokens": 12} + }))) + .mount(&upstream) + .await; + + let snap = new_snap_openai(&upstream.uri()); + snap.models.insert(openai_model("gpt-4o-resp")); + snap.apikeys.insert(apikey_entry(&["*"])); + snap.guardrails.insert(masking_guardrail()); + + let (tx, mut rx) = tokio::sync::mpsc::channel(8); + let hub = Arc::new(Hub::new()); + hub.register_specialized("openai", Arc::new(OpenAiBridge::new())); + let handle = SnapshotHandle::new(snap); + let state = crate::ProxyState::new(handle, hub, &cfg()) + .without_cache() + .with_usage_sink(UsageSink::new(tx)); + let app = crate::build_router(state); + + let resp = app + .oneshot(make_req( + serde_json::json!({"model": "gpt-4o-resp", "input": "hi"}), + )) + .await + .unwrap(); + assert_eq!(resp.status(), StatusCode::OK); + let body = + String::from_utf8(to_bytes(resp.into_body(), 65536).await.unwrap().to_vec()).unwrap(); + assert!(body.contains("***"), "the response was not masked: {body}"); + + let event = tokio::time::timeout(std::time::Duration::from_millis(500), rx.recv()) + .await + .expect("usage event was never emitted") + .expect("usage_sink sender dropped"); + assert_masked_by_eda(&event, 1); + } + + /// Streaming `/v1/responses` — pitfall (1) of #1024 on the Codex path. + #[tokio::test] + async fn streaming_responses_usage_event_carries_the_enforced_mask() { + use aisix_obs::UsageSink; + + let upstream = MockServer::start().await; + let sse = "event: response.output_text.delta\n\ + data: {\"type\":\"response.output_text.delta\",\"delta\":\"the version: 9.9.9 build\"}\n\n\ + event: response.completed\n\ + data: {\"type\":\"response.completed\",\"response\":{\"output\":[{\"type\":\"message\",\"content\":[{\"type\":\"output_text\",\"text\":\"the version: 9.9.9 build\"}]}],\"usage\":{\"input_tokens\":5,\"output_tokens\":7,\"total_tokens\":12}}}\n\n\ + data: [DONE]\n\n"; + Mock::given(method("POST")) + .and(path("/v1/responses")) + .respond_with( + ResponseTemplate::new(200) + .insert_header("content-type", "text/event-stream") + .set_body_string(sse), + ) + .mount(&upstream) + .await; + + let snap = new_snap_openai(&upstream.uri()); + snap.models.insert(openai_model("gpt-4o-resp")); + snap.apikeys.insert(apikey_entry(&["*"])); + snap.guardrails.insert(masking_guardrail()); + + let (tx, mut rx) = tokio::sync::mpsc::channel(8); + let hub = Arc::new(Hub::new()); + hub.register_specialized("openai", Arc::new(OpenAiBridge::new())); + let handle = SnapshotHandle::new(snap); + let state = crate::ProxyState::new(handle, hub, &cfg()) + .without_cache() + .with_usage_sink(UsageSink::new(tx)); + let app = crate::build_router(state); + + let resp = app + .oneshot(make_req( + serde_json::json!({"model": "gpt-4o-resp", "input": "hi", "stream": true}), + )) + .await + .unwrap(); + assert_eq!(resp.status(), StatusCode::OK); + // Drain the body so the stream's Drop guard fires the usage event. + let streamed = + String::from_utf8(to_bytes(resp.into_body(), 65536).await.unwrap().to_vec()).unwrap(); + assert!( + streamed.contains("***"), + "the stream was not masked: {streamed}" + ); + assert!( + !streamed.contains("9.9.9"), + "the stream leaked the value: {streamed}" + ); + + let event = tokio::time::timeout(std::time::Duration::from_millis(1000), rx.recv()) + .await + .expect("usage event was never emitted") + .expect("usage_sink sender dropped"); + // Two spans: the delta frame and the terminal event's repeat. + assert_masked_by_eda(&event, 2); + } } diff --git a/crates/aisix-proxy/src/responses_bridge.rs b/crates/aisix-proxy/src/responses_bridge.rs index ada5775ee..c5f4f38e6 100644 --- a/crates/aisix-proxy/src/responses_bridge.rs +++ b/crates/aisix-proxy/src/responses_bridge.rs @@ -1286,7 +1286,11 @@ pub fn build_responses_bridge_stream( seg_counts, ); } - if let aisix_guardrails::GuardrailVerdict::Block { reason, guardrail_name } = verdict { + if let aisix_guardrails::GuardrailVerdict::Block { + reason, + guardrail_name, + .. + } = verdict { tracing::warn!( guardrail_hook = "output", model = %model_label, diff --git a/crates/aisix-proxy/src/usage_attr.rs b/crates/aisix-proxy/src/usage_attr.rs index c796b6d49..f0bb81d85 100644 --- a/crates/aisix-proxy/src/usage_attr.rs +++ b/crates/aisix-proxy/src/usage_attr.rs @@ -25,6 +25,53 @@ use crate::chat::sanitize_tag; use crate::client_ip::ClientContext; use crate::state::ProxyState; +/// The request's ENFORCE-mode guardrail audit handle (AISIX-Cloud#1330), +/// cloned off the resolved chain with +/// [`GuardrailChain::audit_log`](aisix_guardrails::GuardrailChain::audit_log) +/// at the point the chain is resolved. +/// +/// Threaded rather than re-derived because the read has to happen at +/// terminal-event time, which is routinely a different frame from the +/// chain's: a streaming emitter runs from a `move` closure after the +/// handler returned, and `chat.rs` erases its chain to `Arc` +/// before the output hook even runs. `None` — no chain resolved, the +/// dominant guardrail-free deployment — reads identically to an empty +/// snapshot, so no call site needs to branch on it. +pub(crate) type GuardrailAudit = Option>; + +/// Snapshot `audit` into a terminal `UsageEvent`'s +/// `guardrail_enforced_hits`. +/// +/// Terminal events only: guardrails run once per request, not once per +/// attempt, so stamping a per-attempt event would report the same hit +/// once per retry. +/// +/// Reading does not consume the log, and that is load-bearing rather than +/// incidental: the retrying families call this from emitters that also +/// serve superseded attempts, and a destructive read would leave whichever +/// event happened to go out first holding the only copy. +pub(crate) fn enforced_hits(audit: &GuardrailAudit) -> Vec { + audit.as_ref().map(|a| a.snapshot()).unwrap_or_default() +} + +/// [`enforced_hits`] for the retrying families (chat / messages / +/// responses), whose emitters serve both the terminal event and the +/// superseded per-attempt ones and are told which they are building. +/// +/// Written as one helper rather than an `if` at each emitter so the rule +/// — request-scoped attribution rides the terminal event only — is stated +/// once and cannot be applied inconsistently across the three. +pub(crate) fn terminal_enforced_hits( + terminal: bool, + audit: &GuardrailAudit, +) -> Vec { + if terminal { + enforced_hits(audit) + } else { + Vec::new() + } +} + /// Stamp how the caller established its principal onto a usage event. /// /// The ordinary credential path leaves the field empty (the shape on the @@ -367,6 +414,12 @@ pub(crate) fn emit_error_usage_event( status_code: u16, error_class: &str, client: &ClientContext, + // The request's enforced guardrail hits. The failure path is where a + // `blocked` hit lands — a guardrail refusal IS the error — so the + // error event is the one that must not drop it. Drained by the caller + // (`enforced_hits(&audit)`) rather than taken as a handle: the jobs + // surface accumulates across two separately resolved chains. + enforced: Vec, ) { let event = build_error_usage_event( inbound_protocol, @@ -376,6 +429,7 @@ pub(crate) fn emit_error_usage_event( status_code, error_class, client, + enforced, ); // The failed request's own attribution, off the same cell // `request_metrics::LastTarget` reads — so the usage-event counters and @@ -397,6 +451,7 @@ pub(crate) fn emit_error_usage_event( /// The [`emit_error_usage_event`] event without the emission, for a caller /// that attributes handler-specific fields (e.g. the passthrough route name) /// before handing it to [`emit_prepared_usage_event`]. +#[allow(clippy::too_many_arguments)] pub(crate) fn build_error_usage_event( inbound_protocol: &'static str, request_id: &str, @@ -405,6 +460,7 @@ pub(crate) fn build_error_usage_event( status_code: u16, error_class: &str, client: &ClientContext, + enforced: Vec, ) -> UsageEvent { let mut event = UsageEvent { request_id: request_id.to_string(), @@ -416,6 +472,7 @@ pub(crate) fn build_error_usage_event( error_class: error_class.to_string(), client_source_ip: client.source_ip.clone(), client_user_agent: client.user_agent.clone(), + guardrail_enforced_hits: enforced, ..Default::default() }; apply_jwt_identity(&mut event, client.jwt.as_ref()); diff --git a/crates/aisix-proxy/src/videos.rs b/crates/aisix-proxy/src/videos.rs index 3bc2644e1..2959e295f 100644 --- a/crates/aisix-proxy/src/videos.rs +++ b/crates/aisix-proxy/src/videos.rs @@ -1537,7 +1537,11 @@ pub async fn create_video( // One snapshot for the whole request (#941) — see `embeddings`. let snapshot = state.snapshot.load(); - match dispatch_create(&state, &snapshot, &auth, body, &client).await { + // See `embeddings`: filled inside `dispatch_create` so the failure + // branch — where a guardrail block lands — stamps the enforced hits + // too (AISIX-Cloud#1330 / #1024). + let mut audit = crate::usage_attr::GuardrailAudit::default(); + match dispatch_create(&state, &snapshot, &auth, body, &client, &mut audit).await { Ok(success) => { let status = success.response.status().as_u16(); // Label by the RESOLVED entry's display_name, not the requested @@ -1571,6 +1575,7 @@ pub async fn create_video( success.monitor_hits.clone(), status, started.elapsed(), + &audit, ); } success.response @@ -1592,6 +1597,7 @@ pub async fn create_video( status, err.kind(), &client, + crate::usage_attr::enforced_hits(&audit), ); err.into_response() } @@ -1616,6 +1622,7 @@ async fn dispatch_create( auth: &AuthenticatedKey, body: VideoCreateBody, client: &ClientContext, + audit_out: &mut crate::usage_attr::GuardrailAudit, ) -> Result { let model_entry = crate::model_resolve::resolve_model(snapshot, &body.model) .ok_or_else(|| ProxyError::ModelNotFound(body.model.clone()))?; @@ -1660,6 +1667,7 @@ async fn dispatch_create( }; let resolved_chain = state.guardrail_index.resolve(&guardrail_ctx); let applied_guardrails = resolved_chain.applied().to_vec(); + *audit_out = resolved_chain.audit_log(); let mut monitor_hits: Vec = Vec::new(); if !resolved_chain.is_empty() { let chat = aisix_gateway::ChatFormat::new( @@ -1672,6 +1680,7 @@ async fn dispatch_create( if let aisix_guardrails::GuardrailVerdict::Block { reason, guardrail_name, + .. } = verdict { // Matched-pattern detail stays in ops logs only (#153). @@ -1989,6 +1998,8 @@ fn emit_submit_usage_event( guardrail_monitor_hits: Vec, status_code: u16, elapsed: Duration, + // The request's enforced-guardrail audit handle (AISIX-Cloud#1330). + audit: &crate::usage_attr::GuardrailAudit, ) { let mut event = UsageEvent { request_id: client.request_id.clone(), @@ -2004,6 +2015,7 @@ fn emit_submit_usage_event( inbound_protocol: "openai".to_string(), applied_guardrails: applied_guardrails.to_vec(), guardrail_monitor_hits, + guardrail_enforced_hits: crate::usage_attr::enforced_hits(audit), client_source_ip: client.source_ip.clone(), client_user_agent: client.user_agent.clone(), ..Default::default() @@ -3896,4 +3908,50 @@ mod tests { .unwrap() .contains("download URL has expired")); } + + /// AISIX-Cloud#1330 / #1024: a guardrail BLOCK leaves this handler + /// through `Err`, so the terminal usage event is the shared + /// zero-token error event. That branch is the one an auditor reads — + /// "which policy refused this request" — and a drain wired only into + /// the success path misses it silently. + #[tokio::test] + async fn blocked_request_names_the_policy_on_the_usage_event() { + use aisix_obs::UsageSink; + + let upstream = MockServer::start().await; + let snap = new_snap(&upstream.uri(), "alibaba", ""); + let g: aisix_core::Guardrail = serde_json::from_str( + r#"{"name":"test-block","enabled":true,"hook_point":"input","fail_open":false,"kind":"keyword","patterns":[{"kind":"literal","value":"BLOCKME"}]}"#, + ) + .unwrap(); + snap.guardrails.insert(ResourceEntry::new("g-1", g, 1)); + + let (tx, mut rx) = tokio::sync::mpsc::channel(8); + let hub = Arc::new(Hub::new()); + let handle = SnapshotHandle::new(snap); + let app = crate::build_router( + crate::ProxyState::new(handle, hub, &cfg()) + .without_cache() + .with_usage_sink(UsageSink::new(tx)), + ); + + let resp = tower::ServiceExt::oneshot( + app, + post_videos(serde_json::json!({"model": "my-video", "prompt": "please BLOCKME now"})), + ) + .await + .unwrap(); + assert_eq!(resp.status(), StatusCode::UNPROCESSABLE_ENTITY); + + let ev = tokio::time::timeout(std::time::Duration::from_millis(500), rx.recv()) + .await + .expect("UsageEvent must be emitted for the refusal") + .expect("usage_sink sender dropped"); + assert_eq!(ev.guardrail_enforced_hits.len(), 1, "{ev:?}"); + assert_eq!(ev.guardrail_enforced_hits[0].guardrail_name, "test-block"); + assert_eq!(ev.guardrail_enforced_hits[0].hook, "input"); + assert_eq!(ev.guardrail_enforced_hits[0].action, "blocked"); + let wire = serde_json::to_string(&ev).unwrap(); + assert!(!wire.contains("BLOCKME"), "{wire}"); + } } diff --git a/tests/e2e/src/cases/guardrail-enforced-hits-llm-family-e2e.test.ts b/tests/e2e/src/cases/guardrail-enforced-hits-llm-family-e2e.test.ts new file mode 100644 index 000000000..69893d8ab --- /dev/null +++ b/tests/e2e/src/cases/guardrail-enforced-hits-llm-family-e2e.test.ts @@ -0,0 +1,491 @@ +import { createHash } from "node:crypto"; +import { afterAll, beforeAll, describe, expect, test } from "vitest"; +import { + decodedTextFor, + EtcdClient, + pickFreePort, + ProxyClient, + SeedClient, + spawnApp, + startMockSls, + startOpenAiUpstream, + waitConfigPropagation, + waitForToken, + type MockSls, + type OpenAiUpstream, + type SpawnedApp, +} from "../harness/index.js"; + +// E2E: `UsageEvent.guardrail_enforced_hits` across the LLM handler family +// (api7/aisix#1024), against a real DP + etcd + a real SOC export target. +// +// AISIX-Cloud#1330 shipped the audit chain on `/mcp` only. The gap on the +// rest of the family was SILENT: an ENFORCING mask on `/v1/messages` or +// `/v1/responses` showed up in Prometheus and rewrote the response, while +// the /logs row for that same request looked exactly like "no guardrail +// acted". `/v1/messages` carries Claude-Code traffic and `/v1/responses` +// carries Codex traffic, so a chat-only test would have stayed green +// forever while the two families that matter misbehaved — which is why +// both are driven here by hand, streaming and not. +// +// One guardrail row governs every endpoint. Each endpoint gets its OWN +// detector inside that row, matching a marker only that endpoint's +// upstream emits, so the exported entry's `counts` key says which handler +// produced it — no ordering assumptions, no cross-talk between cases. +// +// Pinned contract, per endpoint: +// - the exported usage event carries an enforced-hit entry naming the +// configured ROW (not the detector, not the kind), the hook it fired +// on, and `action: "masked"`; +// - the per-detector count is the endpoint's own detector; +// - the masked VALUE never reaches the SOC target (#153 no-leak). + +const KEY = "sk-enforced-hits-llm-e2e"; +const sha256 = (s: string) => createHash("sha256").update(s).digest("hex"); + +const CREDENTIAL_REF = "mock"; +const SLS_PROJECT = "aisix-e2e-obs"; +const LOGSTORE = "enforced-hits-llm"; + +const ROW = "llm-family-mask"; + +/** Per-endpoint marker + the detector name that masks it. */ +const CASES = { + chat: { marker: "chatmark-7f3a01", detector: "chat_marker" }, + chatStream: { marker: "streammark-7f3a02", detector: "chat_stream_marker" }, + messages: { marker: "msgmark-7f3a03", detector: "messages_marker" }, + responses: { marker: "respmark-7f3a04", detector: "responses_marker" }, +} as const; + +interface EnforcedHit { + guardrail_name: string; + hook: string; + action: string; + error_type?: string; + counts?: Record; + duration_us?: number; +} + +/** + * Pull every `guardrail_enforced_hits` array the exporter rendered. + * + * The SLS encoder writes each field with `serde_json::to_value`, whose + * objects are BTreeMap-ordered, so an entry's first key is `action` rather + * than the struct's declaration order. Both spellings are accepted so a + * later encoder change does not silently turn this into a no-op match. + * + * `guardrail_monitor_hits` renders with the same leading keys, so its + * entries are dropped by their `would_*` actions — otherwise adding a + * monitor-mode member to one of these rows would make the per-endpoint + * assertions below compare a staged hit against an enforced contract. + */ +const hitsIn = (decoded: string): EnforcedHit[] => + [...decoded.matchAll(/\[\{"(?:action|guardrail_name)":.*?\}\]/g)] + .map((m) => { + try { + return JSON.parse(m[0]) as EnforcedHit[]; + } catch { + return null; + } + }) + .filter((a): a is EnforcedHit[] => Array.isArray(a)) + .flat() + .filter((h) => !h.action?.startsWith("would_")); + +describe("guardrail enforced hits on the LLM handler family", () => { + let app: SpawnedApp | undefined; + let sls: MockSls | undefined; + const upstreams: OpenAiUpstream[] = []; + let etcdReachable = false; + + beforeAll(async () => { + const etcd = new EtcdClient(); + etcdReachable = await etcd.ping(); + if (!etcdReachable) return; + + // One upstream per endpoint: the mock serves a single canned reply on + // every path, and the four endpoints need four different wire shapes + // (plus one of them streams). Separate servers keep the cases + // independent of the order vitest runs them in. + const chatUp = await startOpenAiUpstream({ + nonStreamBody: { + id: "cmpl-enforced-1", + object: "chat.completion", + model: "gpt-4o-2024-08-06", + choices: [ + { + index: 0, + message: { role: "assistant", content: `build ${CASES.chat.marker} done` }, + finish_reason: "stop", + }, + ], + usage: { prompt_tokens: 5, completion_tokens: 4, total_tokens: 9 }, + }, + }); + const chatStreamUp = await startOpenAiUpstream({ + streamEvents: [ + JSON.stringify({ + id: "cmpl-enforced-2", + model: "gpt-4o-2024-08-06", + choices: [{ index: 0, delta: { role: "assistant" }, finish_reason: null }], + }), + JSON.stringify({ + id: "cmpl-enforced-2", + model: "gpt-4o-2024-08-06", + choices: [ + { + index: 0, + delta: { content: `build ${CASES.chatStream.marker} done` }, + finish_reason: null, + }, + ], + }), + JSON.stringify({ + id: "cmpl-enforced-2", + model: "gpt-4o-2024-08-06", + choices: [{ index: 0, delta: {}, finish_reason: "stop" }], + }), + "[DONE]", + ], + eventDelayMs: 2, + }); + const messagesUp = await startOpenAiUpstream({ + nonStreamBody: { + id: "msg_enforced_3", + type: "message", + role: "assistant", + content: [{ type: "text", text: `build ${CASES.messages.marker} done` }], + model: "claude-3-5-haiku-20241022", + stop_reason: "end_turn", + usage: { input_tokens: 6, output_tokens: 4 }, + }, + }); + const responsesUp = await startOpenAiUpstream({ + nonStreamBody: { + id: "resp-enforced-4", + object: "response", + model: "gpt-4o-2024-08-06", + output: [ + { + type: "message", + id: "msg-1", + role: "assistant", + content: [{ type: "output_text", text: `build ${CASES.responses.marker} done` }], + }, + ], + usage: { input_tokens: 6, output_tokens: 4, total_tokens: 10 }, + }, + }); + upstreams.push(chatUp, chatStreamUp, messagesUp, responsesUp); + + sls = await startMockSls(); + app = await spawnApp({ + extraEnv: { + [`SLS_CRED_${CREDENTIAL_REF.toUpperCase()}_AK_ID`]: "mock-akid", + [`SLS_CRED_${CREDENTIAL_REF.toUpperCase()}_AK_SECRET`]: "mock-secret", + }, + }); + + const seed = new SeedClient(etcd, app.etcdPrefix); + await seed.createObservabilityExporter({ + name: "sls-enforced-hits", + enabled: true, + kind: "aliyun_sls", + endpoint: sls.url, + project: SLS_PROJECT, + logstore: LOGSTORE, + credential_ref: CREDENTIAL_REF, + }); + // ONE row governs the whole family — which is the point: the drain + // must be present at every handler's terminal event, not just at the + // one whose test was written first. + await seed.createGuardrail({ + name: ROW, + enabled: true, + hook_point: "both", + kind: "pii", + custom_patterns: Object.values(CASES).map((c) => ({ + name: c.detector, + regex: c.marker, + action: "mask", + replacement: "***", + })), + }); + + const mk = async ( + display: string, + provider: string, + modelName: string, + up: OpenAiUpstream, + ): Promise => { + const pk = await seed.createProviderKey({ + display_name: `${display}-pk`, + secret: "sk-mock-upstream", + api_base: up.baseUrl, + provider, + adapter: provider, + }); + await seed.createModel({ + display_name: display, + provider, + model_name: modelName, + provider_key_id: pk.id, + }); + }; + await mk("enforced-chat", "openai", "gpt-4o", chatUp); + await mk("enforced-chat-stream", "openai", "gpt-4o", chatStreamUp); + await mk("enforced-messages", "anthropic", "claude-3-5-haiku-20241022", messagesUp); + await mk("enforced-responses", "openai", "gpt-4o", responsesUp); + + // Caller key LAST (AGENTS.md gate rule): a key that authenticates + // implies every row above is already in the snapshot. + await seed.createApiKey({ key_hash: sha256(KEY), allowed_models: ["*"] }); + // Gate on the key authenticating, not on a masked request: a gate that + // exercises the behavior under test fails by timeout instead of by an + // assertion, and its own traffic would be exported alongside the cases'. + const proxy = new ProxyClient(app.proxyUrl, KEY); + await waitConfigPropagation(async () => (await proxy.listModels()).status === 200); + }, 90_000); + + afterAll(async () => { + await app?.exit(); + await Promise.all(upstreams.map((u) => u.close())); + await sls?.close(); + }); + + /** + * Assert the row that masked is named on the exported event, with the + * endpoint's own detector count — and that the value it masked is not + * anywhere in the SOC feed. + * + * Gated on the requested MODEL, which rides every event this endpoint + * emits and is therefore independent of the array under test. Waiting on + * the detector name would look equivalent — it also rides + * `redacted_entity_counts` — but that couples the gate to a second field + * that could itself regress, and then a lost drain fails by burning the + * 10s poll instead of by the assertion below (tests/e2e/AGENTS.md). + */ + const expectAuditedMask = async ( + model: string, + detector: string, + marker: string, + ): Promise => { + await waitForToken(sls!, LOGSTORE, model); + const decoded = decodedTextFor(sls!, LOGSTORE); + + const hits = hitsIn(decoded).filter( + (h) => h.guardrail_name === ROW && Object.keys(h.counts ?? {}).includes(detector), + ); + expect( + hits.length, + `no enforced-hit entry for detector '${detector}' — the handler masked the response but its usage event reported nothing`, + ).toBeGreaterThan(0); + for (const hit of hits) { + expect(hit.action).toBe("masked"); + expect(hit.hook).toBe("output"); + expect(hit.counts?.[detector]).toBeGreaterThan(0); + // A mask is not a refusal, so no cause rides along + // (AISIX-Cloud#1365). + expect(hit.error_type ?? "").toBe(""); + } + // The masked value is caller content, never audit data (#153). + expect(decoded).not.toContain(marker); + }; + + const post = (path: string, body: unknown): Promise => + fetch(`${app!.proxyUrl}${path}`, { + method: "POST", + headers: { "content-type": "application/json", authorization: `Bearer ${KEY}` }, + body: JSON.stringify(body), + }); + + test("/v1/chat/completions (non-streaming) names the row that masked", async (ctx) => { + if (!etcdReachable || !app || !sls) return ctx.skip(); + + const res = await post("/v1/chat/completions", { + model: "enforced-chat", + messages: [{ role: "user", content: "go" }], + }); + expect(res.status).toBe(200); + const body = await res.text(); + expect(body).toContain("***"); + expect(body).not.toContain(CASES.chat.marker); + + await expectAuditedMask("enforced-chat", CASES.chat.detector, CASES.chat.marker); + }); + + test("/v1/chat/completions (streaming) names the row that masked", async (ctx) => { + if (!etcdReachable || !app || !sls) return ctx.skip(); + + // The streaming terminal event is emitted from the response body's + // Drop guard, long after the handler frame is gone — the case the + // per-handler drain has to reach through a cloned audit handle. + const res = await post("/v1/chat/completions", { + model: "enforced-chat-stream", + messages: [{ role: "user", content: "go" }], + stream: true, + }); + expect(res.status).toBe(200); + const body = await res.text(); + expect(body).toContain("***"); + expect(body).not.toContain(CASES.chatStream.marker); + + await expectAuditedMask("enforced-chat-stream", CASES.chatStream.detector, CASES.chatStream.marker); + }); + + test("/v1/messages names the row that masked (Claude-Code path)", async (ctx) => { + if (!etcdReachable || !app || !sls) return ctx.skip(); + + const res = await post("/v1/messages", { + model: "enforced-messages", + max_tokens: 64, + messages: [{ role: "user", content: "go" }], + }); + expect(res.status).toBe(200); + const body = await res.text(); + expect(body).toContain("***"); + expect(body).not.toContain(CASES.messages.marker); + + await expectAuditedMask("enforced-messages", CASES.messages.detector, CASES.messages.marker); + }); + + test("/v1/responses names the row that masked (Codex path)", async (ctx) => { + if (!etcdReachable || !app || !sls) return ctx.skip(); + + const res = await post("/v1/responses", { + model: "enforced-responses", + input: "go", + }); + expect(res.status).toBe(200); + const body = await res.text(); + expect(body).toContain("***"); + expect(body).not.toContain(CASES.responses.marker); + + await expectAuditedMask("enforced-responses", CASES.responses.detector, CASES.responses.marker); + }); +}); + +// AISIX-Cloud#1365: the third enforcement state. +// +// A guardrail with `fail_open: false` returns a REFUSAL when its upstream +// is unreachable — the same verdict a content violation produces. Reported +// as plain `blocked`, a 30-second provider outage stamps every request in +// that window as a policy violation, and an operator reading /logs (or the +// CSV an auditor pulls) concludes a burst of customer prompts broke policy +// when the provider was simply down. That is a wrong answer, not a missing +// one, which is why it gets its own action and carries the cause. +// +// Its own app + env: the guardrail is env-scoped and refuses every request, +// so it cannot share a snapshot with the masking cases above. +describe("a fail-closed guardrail outage is audited apart from a policy block", () => { + let app: SpawnedApp | undefined; + let sls: MockSls | undefined; + let upstream: OpenAiUpstream | undefined; + let etcdReachable = false; + + const DEAD_LOGSTORE = "enforced-hits-unavailable"; + + beforeAll(async () => { + const etcd = new EtcdClient(); + etcdReachable = await etcd.ping(); + if (!etcdReachable) return; + + upstream = await startOpenAiUpstream({}); + sls = await startMockSls(); + app = await spawnApp({ + extraEnv: { + [`SLS_CRED_${CREDENTIAL_REF.toUpperCase()}_AK_ID`]: "mock-akid", + [`SLS_CRED_${CREDENTIAL_REF.toUpperCase()}_AK_SECRET`]: "mock-secret", + }, + }); + + const seed = new SeedClient(etcd, app.etcdPrefix); + await seed.createObservabilityExporter({ + name: "sls-enforced-unavailable", + enabled: true, + kind: "aliyun_sls", + endpoint: sls.url, + project: SLS_PROJECT, + logstore: DEAD_LOGSTORE, + credential_ref: CREDENTIAL_REF, + }); + // A real remote guardrail pointed at a port nothing listens on. Not a + // stub of a failure — the actual connect error the DP classifies. + const deadPort = await pickFreePort(); + await seed.createGuardrail({ + name: "presidio-prod", + enabled: true, + hook_point: "input", + fail_open: false, + kind: "presidio", + analyzer_url: `http://127.0.0.1:${deadPort}`, + anonymizer_url: `http://127.0.0.1:${deadPort}`, + timeout_ms: 500, + }); + const pk = await seed.createProviderKey({ + display_name: "unavailable-pk", + secret: "sk-mock-upstream", + api_base: upstream.baseUrl, + provider: "openai", + adapter: "openai", + }); + await seed.createModel({ + display_name: "enforced-unavailable", + provider: "openai", + model_name: "gpt-4o", + provider_key_id: pk.id, + }); + await seed.createApiKey({ key_hash: sha256(KEY), allowed_models: ["*"] }); + const proxy = new ProxyClient(app.proxyUrl, KEY); + await waitConfigPropagation(async () => (await proxy.listModels()).status === 200); + }, 90_000); + + afterAll(async () => { + await app?.exit(); + await upstream?.close(); + await sls?.close(); + }); + + test("the refusal records blocked_unavailable with its cause, not blocked", async (ctx) => { + if (!etcdReachable || !app || !sls) return ctx.skip(); + + const res = await fetch(`${app.proxyUrl}/v1/chat/completions`, { + method: "POST", + headers: { "content-type": "application/json", authorization: `Bearer ${KEY}` }, + body: JSON.stringify({ + model: "enforced-unavailable", + messages: [{ role: "user", content: "anything at all" }], + }), + }); + // Fail-closed still means closed — separating the two attributions + // must not weaken the guarantee itself. + expect(res.status).toBe(422); + + // Waited on the requested MODEL, not the guardrail row: the row name + // rides only the array under test, so waiting on it would turn a lost + // drain into a 10s timeout instead of the assertion below — the + // failure mode tests/e2e/AGENTS.md calls out. + await waitForToken(sls, DEAD_LOGSTORE, "enforced-unavailable"); + const decoded = decodedTextFor(sls, DEAD_LOGSTORE); + const all = hitsIn(decoded); + const hits = all.filter((h) => h.guardrail_name === "presidio-prod"); + expect(hits.length).toBeGreaterThan(0); + for (const hit of hits) { + expect( + hit.action, + "an unreachable guardrail upstream must not be reported as a policy decision", + ).toBe("blocked_unavailable"); + expect(hit.hook).toBe("input"); + // A bounded per-kind cause, never free text and never the request. + expect(hit.error_type ?? "").toMatch(/^presidio_/); + expect(hit.counts ?? {}).toEqual({}); + } + // ...and no entry ANYWHERE in this logstore claims a policy decision, + // which is the whole failure mode: one row saying `blocked` here is one + // row an auditor counts as a customer violation. Checked against the + // unfiltered set — re-checking `hits` would be a tautology, since the + // loop above has already established what every entry in it says, and + // this app's exporter serves only this test. + expect(all.filter((h) => h.action === "blocked")).toHaveLength(0); + }); +});