Skip to main content

featherbit/debug/
trace.rs

1//! Trace records and context snapshots.
2//!
3//! A [`Trace`] is one policy execution — a live request or a sandbox run —
4//! recorded as an initial [`ContextSnapshot`] plus one [`NodeStep`] per node
5//! the engine walked.
6//!
7//! # Why one snapshot per step, not before/after pairs
8//!
9//! The [`Context`] flows strictly linearly: every plugin takes it by value and
10//! hands it back in both the `Ok` and `Err` arms of [`PluginResult`], so
11//! `before(step N) == after(step N - 1)` and `before(step 0) == Trace::initial`
12//! are guaranteed by the plugin contract itself. Storing explicit pairs would
13//! double memory for exactly zero information.
14//!
15//! The "what did this plugin change" view is therefore *derived*, not stored:
16//! see [`crate::debug::diff`], which is computed at read time so the traced
17//! request path stays cheap.
18//!
19//! [`PluginResult`]: crate::plugins::PluginResult
20
21use std::collections::{BTreeMap, HashSet};
22
23use bytes::Bytes;
24use serde::Serialize;
25
26use crate::context::{Context, GatewayError};
27
28/// Placeholder substituted for any value the redaction policy matches.
29pub const REDACTED: &str = "<redacted>";
30
31/// Header names always redacted, regardless of configuration.
32const DEFAULT_REDACT_HEADERS: &[&str] = &[
33    "authorization",
34    "proxy-authorization",
35    "cookie",
36    "set-cookie",
37    "x-api-key",
38    "api-key",
39    "apikey",
40    "x-auth-token",
41    "x-access-token",
42    "x-csrf-token",
43    "x-amz-security-token",
44    "x-forwarded-client-cert",
45];
46
47/// Query parameters always redacted. OAuth/OIDC put codes and tokens in the
48/// query string, so omitting these would leak on every `openid-connect` trace.
49const DEFAULT_REDACT_QUERY: &[&str] = &[
50    "access_token",
51    "id_token",
52    "refresh_token",
53    "token",
54    "api_key",
55    "apikey",
56    "code",
57    "client_secret",
58    "state",
59];
60
61/// Substrings that mark a `context.message` key as secret-bearing.
62///
63/// `message` is free-form (plugins and Lua scripts write whatever they like),
64/// so substring matching is the only defence that scales. Deliberately **not**
65/// bare `key`: that would redact `consumer.key_id`, which is exactly what a
66/// developer needs to see.
67const DEFAULT_REDACT_MESSAGE_SUBSTRINGS: &[&str] = &[
68    "secret",
69    "password",
70    "passwd",
71    "token",
72    "credential",
73    "private_key",
74    "authorization",
75    "jwt",
76];
77
78/// Case-insensitive denylists used when capturing a snapshot.
79///
80/// Built-ins are always applied; configured names *extend* them rather than
81/// replacing them, so an operator cannot accidentally widen exposure by
82/// setting a short custom list.
83#[derive(Debug, Clone)]
84pub struct RedactionPolicy {
85    headers: HashSet<String>,
86    query_params: HashSet<String>,
87    message_keys: HashSet<String>,
88    message_substrings: Vec<String>,
89}
90
91impl Default for RedactionPolicy {
92    fn default() -> Self {
93        Self::new(&[], &[], &[])
94    }
95}
96
97impl RedactionPolicy {
98    /// Builds the policy from the configured extra names.
99    pub fn new(headers: &[String], query_params: &[String], message_keys: &[String]) -> Self {
100        let lower = |extra: &[String], builtin: &[&str]| -> HashSet<String> {
101            builtin
102                .iter()
103                .map(|s| s.to_string())
104                .chain(extra.iter().map(|s| s.to_lowercase()))
105                .collect()
106        };
107        Self {
108            headers: lower(headers, DEFAULT_REDACT_HEADERS),
109            query_params: lower(query_params, DEFAULT_REDACT_QUERY),
110            message_keys: message_keys.iter().map(|s| s.to_lowercase()).collect(),
111            message_substrings: DEFAULT_REDACT_MESSAGE_SUBSTRINGS
112                .iter()
113                .map(|s| s.to_string())
114                .collect(),
115        }
116    }
117
118    fn header_is_secret(&self, name: &str) -> bool {
119        self.headers.contains(&name.to_lowercase())
120    }
121
122    fn query_is_secret(&self, name: &str) -> bool {
123        self.query_params.contains(&name.to_lowercase())
124    }
125
126    fn message_is_secret(&self, key: &str) -> bool {
127        let lower = key.to_lowercase();
128        self.message_keys.contains(&lower)
129            || self
130                .message_substrings
131                .iter()
132                .any(|s| lower.contains(s.as_str()))
133    }
134}
135
136/// How a captured body was handled.
137#[derive(Debug, Clone, Default, Serialize, PartialEq)]
138pub struct BodyCapture {
139    /// Byte length of the real body. Always recorded — it is free, and answers
140    /// "did the body change size?" without capturing the content.
141    pub len: usize,
142    /// The body text, present only when body capture is enabled, the body
143    /// changed since the previous step, and the content is valid UTF-8.
144    #[serde(skip_serializing_if = "Option::is_none")]
145    pub text: Option<String>,
146    /// True when `text` was clipped to the configured limit.
147    #[serde(skip_serializing_if = "std::ops::Not::not", default)]
148    pub truncated: bool,
149    /// True when the body is byte-identical to the previous step's, so the
150    /// text was deliberately not repeated.
151    #[serde(skip_serializing_if = "std::ops::Not::not", default)]
152    pub unchanged: bool,
153    /// True when the body is not valid UTF-8 (an image, blob, …). `text` is
154    /// omitted rather than rendered as replacement-character mojibake; `len`
155    /// still reports the true size.
156    #[serde(skip_serializing_if = "std::ops::Not::not", default)]
157    pub binary: bool,
158}
159
160/// Redacted view of `Context.request`.
161#[derive(Debug, Clone, Serialize, PartialEq)]
162pub struct RequestSnapshot {
163    pub method: String,
164    pub path: String,
165    pub host: String,
166    pub scheme: String,
167    pub headers: BTreeMap<String, Vec<String>>,
168    pub query_params: BTreeMap<String, Vec<String>>,
169    pub body: BodyCapture,
170}
171
172/// Redacted view of `Context.response`.
173#[derive(Debug, Clone, Serialize, PartialEq)]
174pub struct ResponseSnapshot {
175    pub status_code: u16,
176    pub headers: BTreeMap<String, Vec<String>>,
177    pub body: BodyCapture,
178}
179
180/// A redacted point-in-time view of the whole [`Context`].
181///
182/// `BTreeMap` throughout (not `HashMap`) so key order is deterministic: stable
183/// UI rendering, stable diffs, stable test assertions.
184#[derive(Debug, Clone, Serialize, PartialEq)]
185pub struct ContextSnapshot {
186    pub request: RequestSnapshot,
187    pub response: ResponseSnapshot,
188    pub message: BTreeMap<String, serde_json::Value>,
189    pub errors: Vec<GatewayError>,
190}
191
192/// Knobs for capturing a snapshot, resolved from `DebugConfig`.
193#[derive(Debug, Clone)]
194pub struct CaptureOptions {
195    pub capture_bodies: bool,
196    pub max_body_bytes: usize,
197    pub redaction: RedactionPolicy,
198}
199
200impl Default for CaptureOptions {
201    fn default() -> Self {
202        Self {
203            capture_bodies: false,
204            max_body_bytes: 8192,
205            redaction: RedactionPolicy::default(),
206        }
207    }
208}
209
210/// The bodies seen at the previous step, used to avoid storing an unchanged
211/// body once per node. Cloning `Bytes` is a refcount bump, not a copy.
212#[derive(Debug, Clone, Default)]
213pub struct PreviousBodies {
214    pub request: Option<Bytes>,
215    pub response: Option<Bytes>,
216}
217
218impl ContextSnapshot {
219    /// Captures `ctx`, applying redaction **at capture time**.
220    ///
221    /// Redaction is never deferred to read time: a secret must not enter the
222    /// trace buffer at all, because the buffer outlives the request.
223    pub fn capture(ctx: &Context, opts: &CaptureOptions, prev: &PreviousBodies) -> Self {
224        Self {
225            request: RequestSnapshot {
226                method: ctx.request.method.clone(),
227                path: ctx.request.path.clone(),
228                host: ctx.request.host.clone(),
229                scheme: ctx.request.scheme.clone(),
230                headers: redact_map(&ctx.request.headers, |k| opts.redaction.header_is_secret(k)),
231                query_params: redact_map(&ctx.request.query_params, |k| {
232                    opts.redaction.query_is_secret(k)
233                }),
234                body: capture_body(&ctx.request.body, prev.request.as_ref(), opts),
235            },
236            response: ResponseSnapshot {
237                status_code: ctx.response.status_code,
238                headers: redact_map(&ctx.response.headers, |k| {
239                    opts.redaction.header_is_secret(k)
240                }),
241                body: capture_body(&ctx.response.body, prev.response.as_ref(), opts),
242            },
243            message: ctx
244                .message
245                .iter()
246                .map(|(k, v)| {
247                    let value = if opts.redaction.message_is_secret(k) {
248                        serde_json::Value::String(REDACTED.to_string())
249                    } else {
250                        v.clone()
251                    };
252                    (k.clone(), value)
253                })
254                .collect(),
255            errors: ctx.errors.clone(),
256        }
257    }
258}
259
260/// Redacts a header/query map into a deterministic `BTreeMap`, preserving the
261/// arity of multi-valued entries so the shape of the request is still visible.
262fn redact_map(
263    src: &std::collections::HashMap<String, Vec<String>>,
264    is_secret: impl Fn(&str) -> bool,
265) -> BTreeMap<String, Vec<String>> {
266    src.iter()
267        .map(|(k, values)| {
268            let out = if is_secret(k) {
269                values.iter().map(|_| REDACTED.to_string()).collect()
270            } else {
271                values.clone()
272            };
273            (k.clone(), out)
274        })
275        .collect()
276}
277
278/// Records the body length always, and the text only when capture is on and the
279/// bytes differ from the previous step.
280fn capture_body(body: &Bytes, prev: Option<&Bytes>, opts: &CaptureOptions) -> BodyCapture {
281    let len = body.len();
282    if !opts.capture_bodies {
283        return BodyCapture {
284            len,
285            ..Default::default()
286        };
287    }
288    if let Some(p) = prev {
289        if p == body {
290            return BodyCapture {
291                len,
292                unchanged: true,
293                ..Default::default()
294            };
295        }
296    }
297    let truncated = len > opts.max_body_bytes;
298    let slice = if truncated {
299        &body[..opts.max_body_bytes]
300    } else {
301        &body[..]
302    };
303
304    // Classify the content. A valid-UTF-8 body is shown as text; a genuinely
305    // binary one (image, blob, ...) is not rendered — mojibake helps no one —
306    // only its size is reported. The subtlety: a *text* body clipped by the
307    // limit can end mid-multibyte-char, which is not binary. `Utf8Error`
308    // distinguishes the two: `error_len() == None` means "unexpected end" (our
309    // truncation split a char), while `Some(_)` means an invalid byte in the
310    // middle (real binary).
311    match std::str::from_utf8(slice) {
312        Ok(s) => BodyCapture {
313            len,
314            text: Some(s.to_string()),
315            truncated,
316            ..Default::default()
317        },
318        Err(e) if e.error_len().is_none() => {
319            // Valid text, cut mid-char: keep the valid prefix.
320            let valid = std::str::from_utf8(&slice[..e.valid_up_to()]).unwrap_or("");
321            BodyCapture {
322                len,
323                text: Some(valid.to_string()),
324                truncated: true,
325                ..Default::default()
326            }
327        }
328        Err(_) => BodyCapture {
329            len,
330            binary: true,
331            truncated,
332            ..Default::default()
333        },
334    }
335}
336
337/// Whether a node returned success or routed through its error port.
338#[derive(Debug, Clone, Serialize, PartialEq)]
339#[serde(tag = "kind", rename_all = "snake_case")]
340pub enum StepOutcome {
341    Success,
342    Error { code: String, message: String },
343}
344
345/// Which edge the engine followed after a node — including the cases where
346/// there was none, which is what makes an unwired `error` port visible.
347#[derive(Debug, Clone, Copy, Serialize, PartialEq)]
348#[serde(rename_all = "snake_case")]
349pub enum EdgeKind {
350    /// Followed the node's success edge.
351    Success,
352    /// Followed the node's own `error` edge.
353    Error,
354    /// Fell through to the policy-level `error_handler`.
355    CatchAll,
356    /// Stopped at a terminal `client` node.
357    Terminal,
358    /// Succeeded but had no success edge to follow.
359    EndOfChain,
360    /// Errored with neither an error edge nor a catch-all — the engine wrote a
361    /// generic 500 and stopped.
362    Unhandled,
363    /// The edge pointed at a node id that does not exist.
364    NodeNotFound,
365}
366
367/// One node execution.
368#[derive(Debug, Clone, Serialize)]
369pub struct NodeStep {
370    pub index: usize,
371    pub node_id: String,
372    pub node_type: String,
373    pub outcome: StepOutcome,
374    pub duration_us: u64,
375    pub edge: EdgeKind,
376    #[serde(skip_serializing_if = "Option::is_none")]
377    pub next_node_id: Option<String>,
378    /// The context as it stood *after* this node ran.
379    pub after: ContextSnapshot,
380}
381
382/// Whether a trace came from live traffic or a sandbox run.
383#[derive(Debug, Clone, Copy, Serialize, PartialEq)]
384#[serde(rename_all = "snake_case")]
385pub enum TraceSource {
386    Request,
387    Sandbox,
388}
389
390/// One complete policy execution.
391#[derive(Debug, Clone, Serialize)]
392pub struct Trace {
393    pub id: String,
394    /// Monotonic sequence number, giving stable newest-first ordering
395    /// independent of clock skew.
396    pub seq: u64,
397    pub source: TraceSource,
398    pub started_ms: u64,
399    #[serde(skip_serializing_if = "Option::is_none")]
400    pub route: Option<String>,
401    pub policy: String,
402    pub method: String,
403    pub path: String,
404    pub status: u16,
405    pub duration_us: u64,
406    pub captured_bodies: bool,
407    pub initial: ContextSnapshot,
408    pub steps: Vec<NodeStep>,
409    /// Human-readable notes about the recording itself (limits hit, etc.).
410    pub notes: Vec<String>,
411}
412
413#[cfg(test)]
414mod tests {
415    use super::*;
416    use crate::context::{GatewayRequest, GatewayResponse, Protocol};
417    use std::collections::HashMap;
418
419    fn ctx() -> Context {
420        let mut headers = HashMap::new();
421        headers.insert(
422            "authorization".to_string(),
423            vec!["Bearer supersecret".to_string()],
424        );
425        headers.insert("accept".to_string(), vec!["application/json".to_string()]);
426        let mut query = HashMap::new();
427        query.insert("code".to_string(), vec!["oauth-code-xyz".to_string()]);
428        query.insert("page".to_string(), vec!["2".to_string()]);
429        let mut message = HashMap::new();
430        message.insert(
431            "consumer.key_id".to_string(),
432            serde_json::json!("alice-key"),
433        );
434        message.insert("access_token".to_string(), serde_json::json!("tok-123"));
435        message.insert("user_id".to_string(), serde_json::json!("alice"));
436        Context {
437            request: GatewayRequest {
438                method: "POST".to_string(),
439                path: "/api/hello".to_string(),
440                host: "h".to_string(),
441                scheme: "http".to_string(),
442                headers,
443                query_params: query,
444                body: Bytes::from_static(b"request-body"),
445                remote_addr: "1.2.3.4:5".to_string(),
446                protocol: Protocol::Http1,
447            },
448            response: GatewayResponse {
449                status_code: 200,
450                headers: HashMap::new(),
451                body: Bytes::from_static(b"response-body"),
452            },
453            message,
454            errors: Vec::new(),
455        }
456    }
457
458    fn opts(capture_bodies: bool) -> CaptureOptions {
459        CaptureOptions {
460            capture_bodies,
461            ..Default::default()
462        }
463    }
464
465    #[test]
466    fn test_body_length_recorded_but_text_withheld_by_default() {
467        let s = ContextSnapshot::capture(&ctx(), &opts(false), &PreviousBodies::default());
468        // The size is always useful and always free; the content is not captured.
469        assert_eq!(s.request.body.len, 12);
470        assert_eq!(s.response.body.len, 13);
471        assert!(s.request.body.text.is_none());
472        assert!(s.response.body.text.is_none());
473    }
474
475    #[test]
476    fn test_bodies_captured_when_enabled() {
477        let s = ContextSnapshot::capture(&ctx(), &opts(true), &PreviousBodies::default());
478        assert_eq!(s.request.body.text.as_deref(), Some("request-body"));
479        assert_eq!(s.response.body.text.as_deref(), Some("response-body"));
480        assert!(!s.request.body.truncated);
481    }
482
483    #[test]
484    fn test_body_truncated_at_limit() {
485        let o = CaptureOptions {
486            capture_bodies: true,
487            max_body_bytes: 4,
488            ..Default::default()
489        };
490        let s = ContextSnapshot::capture(&ctx(), &o, &PreviousBodies::default());
491        assert_eq!(s.request.body.text.as_deref(), Some("requ"));
492        assert!(s.request.body.truncated);
493        // The true length is still reported, not the truncated one.
494        assert_eq!(s.request.body.len, 12);
495    }
496
497    /// A binary body (e.g. a PNG) must be labelled, never rendered as mojibake,
498    /// and must never break capture.
499    #[test]
500    fn test_binary_body_is_flagged_not_rendered() {
501        let mut c = ctx();
502        // PNG magic bytes + a NUL — not valid UTF-8.
503        c.response.body = Bytes::from_static(&[0x89, b'P', b'N', b'G', 0x0d, 0x00, 0xff, 0xfe]);
504        let s = ContextSnapshot::capture(&c, &opts(true), &PreviousBodies::default());
505        assert!(
506            s.response.body.binary,
507            "non-UTF-8 body should be flagged binary"
508        );
509        assert!(
510            s.response.body.text.is_none(),
511            "binary body must not be rendered as text"
512        );
513        assert_eq!(s.response.body.len, 8, "true size still reported");
514    }
515
516    /// Valid UTF-8 text that happens to be clipped mid-multibyte-char is text,
517    /// not binary — the truncation must not be mistaken for corruption.
518    #[test]
519    fn test_multibyte_text_truncated_midchar_is_still_text() {
520        let mut c = ctx();
521        // "é" is two bytes (0xc3 0xa9); a 3-byte limit cuts the second one.
522        c.request.body = Bytes::from_static("aéb".as_bytes()); // a, é(2 bytes), b = 4 bytes
523        let o = CaptureOptions {
524            capture_bodies: true,
525            max_body_bytes: 2,
526            ..Default::default()
527        };
528        let s = ContextSnapshot::capture(&c, &o, &PreviousBodies::default());
529        // Byte 2 splits 'é', so only "a" is valid — kept as text, flagged truncated.
530        assert!(
531            !s.request.body.binary,
532            "truncated text must not be called binary"
533        );
534        assert_eq!(s.request.body.text.as_deref(), Some("a"));
535        assert!(s.request.body.truncated);
536    }
537
538    #[test]
539    fn test_unchanged_body_is_not_repeated() {
540        let c = ctx();
541        let prev = PreviousBodies {
542            request: Some(c.request.body.clone()),
543            response: Some(Bytes::from_static(b"different")),
544        };
545        let s = ContextSnapshot::capture(&c, &opts(true), &prev);
546        assert!(
547            s.request.body.unchanged,
548            "identical body should not be stored again"
549        );
550        assert!(s.request.body.text.is_none());
551        assert_eq!(s.request.body.len, 12, "length still recorded when deduped");
552        // The response body did change, so it is captured.
553        assert_eq!(s.response.body.text.as_deref(), Some("response-body"));
554    }
555
556    #[test]
557    fn test_default_denylists_redact() {
558        let s = ContextSnapshot::capture(&ctx(), &opts(false), &PreviousBodies::default());
559        assert_eq!(s.request.headers["authorization"], vec![REDACTED]);
560        assert_eq!(s.request.headers["accept"], vec!["application/json"]);
561        // OAuth codes live in the query string -- redacting headers alone is not enough.
562        assert_eq!(s.request.query_params["code"], vec![REDACTED]);
563        assert_eq!(s.request.query_params["page"], vec!["2"]);
564        assert_eq!(s.message["access_token"], serde_json::json!(REDACTED));
565    }
566
567    /// The substring rule must not swallow `consumer.key_id` -- that is exactly
568    /// the value a developer is trying to see.
569    #[test]
570    fn test_key_id_survives_redaction() {
571        let s = ContextSnapshot::capture(&ctx(), &opts(false), &PreviousBodies::default());
572        assert_eq!(s.message["consumer.key_id"], serde_json::json!("alice-key"));
573        assert_eq!(s.message["user_id"], serde_json::json!("alice"));
574    }
575
576    #[test]
577    fn test_redaction_is_case_insensitive() {
578        let mut c = ctx();
579        c.request.headers.clear();
580        c.request
581            .headers
582            .insert("Authorization".to_string(), vec!["x".to_string()]);
583        c.request
584            .headers
585            .insert("X-API-Key".to_string(), vec!["y".to_string()]);
586        let s = ContextSnapshot::capture(&c, &opts(false), &PreviousBodies::default());
587        assert_eq!(s.request.headers["Authorization"], vec![REDACTED]);
588        assert_eq!(s.request.headers["X-API-Key"], vec![REDACTED]);
589    }
590
591    #[test]
592    fn test_multi_valued_header_arity_preserved() {
593        let mut c = ctx();
594        c.response.headers.insert(
595            "set-cookie".to_string(),
596            vec!["a=1".to_string(), "b=2".to_string()],
597        );
598        let s = ContextSnapshot::capture(&c, &opts(false), &PreviousBodies::default());
599        // Two cookies were set: that shape is visible, the values are not.
600        assert_eq!(s.response.headers["set-cookie"], vec![REDACTED, REDACTED]);
601    }
602
603    /// Configured names must *extend* the built-ins, never replace them.
604    #[test]
605    fn test_config_extends_builtin_denylist() {
606        let o = CaptureOptions {
607            redaction: RedactionPolicy::new(
608                &["x-custom-secret".to_string()],
609                &[],
610                &["tenant".to_string()],
611            ),
612            ..Default::default()
613        };
614        let mut c = ctx();
615        c.request
616            .headers
617            .insert("x-custom-secret".to_string(), vec!["s".to_string()]);
618        c.message
619            .insert("tenant".to_string(), serde_json::json!("acme"));
620        let s = ContextSnapshot::capture(&c, &o, &PreviousBodies::default());
621        assert_eq!(s.request.headers["x-custom-secret"], vec![REDACTED]);
622        assert_eq!(s.message["tenant"], serde_json::json!(REDACTED));
623        // ...and the built-ins still apply.
624        assert_eq!(s.request.headers["authorization"], vec![REDACTED]);
625    }
626}