Skip to main content

submilli_engine/runtime/
decision.rs

1//! Decision records: what an embedder's recorder sees of each capability decision.
2//!
3//! The recorder is a [`SecurityCheck`] decorator ([`DecisionLog::install`]): it forwards
4//! every call to the check it wraps, including `audit`, so the embedder's own audit sees
5//! exactly what it would without a recorder, and taps the same `audit` calls. Recording
6//! never changes a decision, never fails a call, and never charges guest fuel.
7//!
8//! Observation work (the source-line backtrace per call) is never charged to guest fuel;
9//! see [`DecisionLogConfig::max_line_capture_frames`] for why and what bounds it. Lines stop
10//! being captured when the decision cap is reached, when the byte budget cannot fit even a
11//! bare record, after a record has been dropped whole for want of bytes, or when that frame
12//! budget is exceeded. A later, smaller record may still be kept after such a drop, without
13//! a line. Other truncation (a byte-budget payload drop, the pair cap) does not stop them.
14//!
15//! Record buffers are charged against the recorder's own byte budget, separate from the
16//! run's memory limit so that recording never changes a run's memory behavior, and a
17//! per-run decision cap; a run that reaches either is marked truncated rather than refused.
18
19use std::collections::HashMap;
20use std::sync::atomic::{AtomicU64, Ordering};
21use std::sync::{Arc, Mutex, MutexGuard};
22use std::time::Instant;
23
24use serde::{Deserialize, Serialize};
25use serde_json::Value;
26
27use super::StoreData;
28use super::call_log::{self, CallOutcome, CallRecord, ModelUsage, Payload, Side};
29use super::security::{AuditDecision, CheckOutcome, SecurityCheck};
30
31/// What the policy decided. `AskHuman` is a denial today (the approval flow is deferred),
32/// kept distinct so a record can say "deferred".
33#[derive(Debug, Clone, Copy, PartialEq, Eq, Serialize, Deserialize)]
34#[serde(rename_all = "kebab-case")]
35pub enum DecisionAction {
36    Allow,
37    Deny,
38    AskHuman,
39}
40
41/// A rule located by caller block and zero-based position.
42#[derive(Debug, Clone, PartialEq, Eq, Serialize, Deserialize)]
43pub struct RuleCitation {
44    pub caller: String,
45    pub index: usize,
46    pub name: Option<String>,
47}
48
49#[derive(Debug, Clone, PartialEq, Serialize, Deserialize)]
50#[serde(rename_all = "kebab-case", tag = "kind")]
51pub enum DecisionCause {
52    /// A rule matched.
53    Rule(RuleCitation),
54    /// No rule matched. `caller_block` is whether the caller has any rules.
55    Default { caller_block: bool },
56    /// A runtime invariant refused the call ahead of, or instead of, the policy:
57    /// an unattributable caller, `main` calling a `main_denial` capability, a read-only
58    /// volume, a quota or egress refusal, or a path the policy could not normalize.
59    RuntimeInvariant { reason: String },
60    /// The installed policy does not explain its decisions.
61    Unexplained,
62}
63
64#[derive(Debug, Clone, PartialEq, Eq, Serialize, Deserialize)]
65#[serde(rename_all = "kebab-case", tag = "kind", content = "variable")]
66pub enum FailureReasonRecord {
67    FieldMissing,
68    VariableNotBound(String),
69    NotSatisfied,
70}
71
72/// One comparison that kept a rule's filter from matching.
73#[derive(Debug, Clone, PartialEq, Serialize, Deserialize)]
74pub struct FailureRecord {
75    pub comparison: String,
76    pub actual: Option<Value>,
77    pub expected: Option<String>,
78    pub reason: FailureReasonRecord,
79    pub negated: bool,
80}
81
82/// A rule that named the capability but whose filter rejected the call.
83#[derive(Debug, Clone, PartialEq, Serialize, Deserialize)]
84pub struct NearMissRecord {
85    pub rule: RuleCitation,
86    pub filter: String,
87    pub failures: Vec<FailureRecord>,
88}
89
90/// The policy's reasoning for one decision.
91#[derive(Debug, Clone, PartialEq, Serialize)]
92pub struct DecisionExplanation {
93    pub action: DecisionAction,
94    pub cause: DecisionCause,
95    pub near_misses: Vec<NearMissRecord>,
96}
97
98/// Which seam produced a decision.
99#[derive(Debug, Clone, Copy, PartialEq, Eq, Default, Serialize, Deserialize)]
100#[serde(rename_all = "kebab-case", tag = "kind")]
101pub enum EntryPath {
102    /// A gated standard-library operation.
103    #[default]
104    GatedOp,
105    /// A package's `security.check` call, attributed to its consumer.
106    PackageCheck,
107    /// A redirect hop of `parent_call_index`'s request; `index` counts its hops from 0.
108    RedirectHop {
109        parent_call_index: u64,
110        index: u32,
111    },
112    Git,
113    /// A file tool of the server, outside any program run.
114    FileTool,
115}
116
117/// A position in the submitted program.
118#[derive(Debug, Clone, Copy, PartialEq, Eq, Serialize, Deserialize)]
119pub struct SourceLine {
120    pub line: u32,
121    pub column: Option<u32>,
122}
123
124/// Identity of one host call, assigned when it begins.
125#[derive(Debug, Clone, Copy, PartialEq, Eq, Serialize)]
126pub struct CallTicket {
127    /// Run-wide, in call order; counts every call the recorder saw.
128    pub call_index: u64,
129    /// Counts the calls of this (caller, capability) pair in the run, denials included,
130    /// from 1. Zero when the recorder stopped tracking pairs at its cap.
131    pub seq: u64,
132    /// Microseconds since the recorder was installed, from a clock that only moves forward.
133    pub at_micros: u64,
134    pub line: Option<SourceLine>,
135}
136
137/// The call a decision belongs to and how it arrived.
138#[derive(Debug, Clone, Copy, Default)]
139pub struct CallSite {
140    pub ticket: Option<CallTicket>,
141    pub entry: EntryPath,
142}
143
144impl CallSite {
145    pub fn new(ticket: Option<CallTicket>, entry: EntryPath) -> Self {
146        Self { ticket, entry }
147    }
148}
149
150/// The runtime's side of a recorder: identity for each call. Record contents arrive through
151/// [`SecurityCheck::audit`].
152pub trait DecisionRecorder: Send + Sync {
153    /// A new host call. `line` is the program line that led to it, when known.
154    fn begin_call(&self, caller: &str, capability: &str, line: Option<SourceLine>) -> CallTicket;
155    /// Marks the latest call's record as a denial the host function treated as a filter.
156    fn mark_last_filtered(&self);
157    /// Whether the next call's source line would be kept. Callers check it before paying
158    /// for a backtrace; it is false once the decision cap is reached, the byte budget cannot
159    /// fit even a bare record, a record has been dropped whole for want of bytes, or the
160    /// frame budget is exceeded. Other truncation (a payload drop, the pair cap) does not
161    /// turn it off.
162    fn wants_line(&self) -> bool;
163    /// Counts the frames of a backtrace captured for a line. Past the recorder's frame
164    /// budget it marks the run truncated and stops further captures.
165    fn note_line_capture(&self, frames: usize);
166    /// A host function that can begin calls was entered. Returns the marker its
167    /// [`exit_host_call`](Self::exit_host_call) passes back.
168    fn enter_host_call(&self) -> u64;
169    /// That host function returned (`returned`) or failed. Ends every call begun since
170    /// `marker` that is still open; a nested host function has ended its own already.
171    fn exit_host_call(&self, marker: u64, returned: bool);
172    /// Whether a payload for the call `call_index` would be kept: the call is open and the
173    /// payload budget is not spent. Callers check it before building a payload. The
174    /// default asks for every payload.
175    fn wants_payload(&self, _call_index: u64) -> bool {
176        true
177    }
178    /// One side of a call that reached outside the program.
179    fn call_payload(&self, call_index: u64, side: Side, payload: Payload<'_>);
180    /// Token counts a model provider reported for a call.
181    fn call_usage(&self, call_index: u64, usage: ModelUsage);
182}
183
184/// Sees records as they are made, for an embedder that streams a run while it executes.
185///
186/// Called on the thread running the program, after the recorder has released its lock.
187/// It must not block: an implementation that cannot keep up drops what it cannot hold.
188/// What it sees is also in the [`DecisionLogOutput`] the run ends with, unless the
189/// recorder's own caps dropped it there.
190pub trait RecordObserver: Send + Sync {
191    fn call_started(&self, _call: &CallRecord) {}
192    fn decision(&self, _record: &DecisionRecord) {}
193    /// The call as it ended, without its payload contents: each side's meta is `Null`
194    /// and it has no body and no masked header names, but it keeps its size, digest,
195    /// truncation flag, timing, and usage.
196    fn call_finished(&self, _call: &CallRecord) {}
197    /// A line the program wrote to its console. Not in the [`DecisionLogOutput`]: the
198    /// run's console holds the text.
199    fn console_line(&self, _line: &ConsoleLine<'_>) {}
200}
201
202/// A console line, placed on the run's clock among its calls.
203#[derive(Debug, Clone, Copy)]
204pub struct ConsoleLine<'a> {
205    pub text: &'a str,
206    /// Microseconds since the recorder started, on the clock its calls use.
207    pub written_micros: u64,
208    /// The last call begun before the line was written; `None` before the first.
209    pub after_call: Option<u64>,
210    /// `text` is the start of a longer line.
211    pub truncated: bool,
212}
213
214#[derive(Debug, Clone, Serialize, Deserialize)]
215pub struct DecisionRecord {
216    pub call_index: u64,
217    pub seq: u64,
218    pub at_micros: u64,
219    pub caller: String,
220    pub capability: String,
221    /// Capped; see [`DecisionLogConfig::max_context_value_bytes`].
222    pub context: Value,
223    pub context_truncated: bool,
224    /// Hash of the full context, kept when the payload copy is dropped.
225    pub context_digest: u64,
226    pub allowed: bool,
227    pub action: DecisionAction,
228    pub cause: DecisionCause,
229    pub near_misses: Vec<NearMissRecord>,
230    /// The audit's source: `policy`, `invariant`, `read_only`, `quota`, `egress_guard`.
231    pub source: String,
232    pub rule: Option<usize>,
233    pub reason: Option<String>,
234    pub entry_path: EntryPath,
235    pub line: Option<SourceLine>,
236    /// A denial the host function swallowed to filter a listing.
237    pub filtered: bool,
238    /// The context and near misses were dropped to stay within the recorder's byte budget.
239    pub payload_dropped: bool,
240}
241
242#[derive(Debug, Clone)]
243pub struct DecisionLogConfig {
244    /// Decisions kept per run; later ones are counted and mark the run truncated.
245    pub max_decisions: usize,
246    /// Longest string kept in a recorded context; longer ones end in a marker.
247    pub max_context_value_bytes: usize,
248    /// Bytes the recorder may hold, independent of the run's memory limit. Past it, payloads
249    /// are dropped (verdict and digest kept), then whole records.
250    pub max_recorder_bytes: u64,
251    /// Wasm frames the recorder may walk, summed over the run's source-line captures.
252    ///
253    /// Line capture is observation work, deliberately left uncharged to guest fuel so that
254    /// recording never changes a run: a recorded run spends exactly the fuel an unrecorded
255    /// one does (R19). That deviates from AGENTS.md, "Fuel for host functions", which asks
256    /// host work to be charged; this budget bounds the work instead, together with the
257    /// decision cap. The fuel plan's "Gated functions call `check_security`" bullet
258    /// (`plans/sub-1269-host-fuel-costs.md`) is the written record of the deviation.
259    ///
260    /// The budget is checked before each capture, so it can be exceeded by at most one
261    /// stack: the capture that crosses it keeps its line. Past it no new line is captured
262    /// and the run is marked truncated (a redirect hop or git worker check may still carry
263    /// a line captured earlier).
264    pub max_line_capture_frames: u64,
265    /// Calls kept per run; later ones are counted and mark the run truncated.
266    pub max_calls: usize,
267    /// Longest body copy a call's request or response keeps. Its digest and size always
268    /// describe the full body.
269    pub max_payload_bytes: usize,
270}
271
272impl Default for DecisionLogConfig {
273    fn default() -> Self {
274        Self {
275            max_decisions: 10_000,
276            max_context_value_bytes: 1024,
277            max_recorder_bytes: 16 * 1024 * 1024,
278            max_line_capture_frames: 1_000_000,
279            max_calls: 10_000,
280            max_payload_bytes: 1024 * 1024,
281        }
282    }
283}
284
285/// What a run recorded.
286#[derive(Debug, Clone, Default)]
287pub struct DecisionLogOutput {
288    pub records: Vec<DecisionRecord>,
289    /// Some decision was not kept in full: past the cap, over the byte budget, beyond the
290    /// pairs the recorder tracks, or the line-capture frame budget was exceeded (after which
291    /// no new lines are captured).
292    pub truncated: bool,
293    /// Decisions not kept at all.
294    pub dropped: u64,
295    /// Wasm frames walked by line captures over the run (diagnostic).
296    pub line_frames: u64,
297    /// The run's calls in the order they began.
298    pub calls: Vec<CallRecord>,
299    /// Calls not kept at all, past the cap or the byte budget.
300    pub calls_dropped: u64,
301}
302
303/// Distinct (caller, capability) pairs tracked per run. Capability names come from
304/// `security.check` calls, so the set is not bounded by the catalog.
305const MAX_TRACKED_PAIRS: usize = 4096;
306const PAIR_OVERHEAD_BYTES: u64 = 96;
307const RECORD_BASE_BYTES: u64 = std::mem::size_of::<DecisionRecord>() as u64;
308const CALL_BASE_BYTES: u64 = std::mem::size_of::<CallRecord>() as u64;
309/// The share of the recorder's byte budget, as a divisor, kept for what must survive a
310/// run that moves a lot of data. One rule: payload bodies and metas stop at the reserve;
311/// the digest-only record of a payload whose copy was dropped, and decision records, may
312/// use it.
313const RECORD_RESERVE_DIVISOR: u64 = 4;
314const MAX_CONTEXT_DEPTH: usize = 8;
315const MAX_CONTEXT_ENTRIES: usize = 64;
316
317#[derive(Default)]
318struct PairState {
319    count: u64,
320    last: Option<CallTicket>,
321}
322
323#[derive(Default)]
324struct LogState {
325    records: Vec<DecisionRecord>,
326    pairs: HashMap<(String, String), PairState>,
327    next_call_index: u64,
328    last_call_index: Option<u64>,
329    truncated: bool,
330    dropped: u64,
331    charged: u64,
332    line_frames: u64,
333    /// The frame budget was exceeded: no new lines are captured.
334    lines_exhausted: bool,
335    /// A record was dropped whole for want of bytes: no new lines are captured. A smaller
336    /// later record may still be kept, without a line.
337    bytes_exhausted: bool,
338    calls: Vec<CallRecord>,
339    /// Position in `calls` of each call still running, in call order.
340    open_calls: Vec<(u64, usize)>,
341    calls_dropped: u64,
342}
343
344/// The per-run recorder.
345pub struct DecisionLog {
346    state: Mutex<LogState>,
347    config: DecisionLogConfig,
348    started: Instant,
349    clock: AtomicU64,
350    observer: Option<Arc<dyn RecordObserver>>,
351}
352
353impl DecisionLog {
354    /// Wraps the store's security check in a recording decorator. Returns the log to read
355    /// results from.
356    ///
357    /// Install it outermost: after any embedder wrapper of the check (such as the server's
358    /// audit decorator). Other wrappers do not forward [`SecurityCheck::recorder`], so a
359    /// recorder installed beneath one is invisible to the host functions that begin calls.
360    pub fn install(data: &mut StoreData, config: DecisionLogConfig) -> Arc<Self> {
361        Self::install_observed(data, config, None)
362    }
363
364    /// [`install`](Self::install), with an observer that sees each record as it is made.
365    pub fn install_observed(
366        data: &mut StoreData,
367        config: DecisionLogConfig,
368        observer: Option<Arc<dyn RecordObserver>>,
369    ) -> Arc<Self> {
370        let log = Self::new(config, observer);
371        data.security_check = log.wrap(data.security_check.clone());
372        log
373    }
374
375    /// A log not yet attached to a run; [`wrap`](Self::wrap) a check to record through it.
376    /// The clock starts now.
377    pub fn new(config: DecisionLogConfig, observer: Option<Arc<dyn RecordObserver>>) -> Arc<Self> {
378        Arc::new(Self {
379            state: Mutex::new(LogState::default()),
380            config,
381            started: Instant::now(),
382            clock: AtomicU64::new(0),
383            observer,
384        })
385    }
386
387    /// `inner`, with every decision it audits also recorded here. For a check made outside
388    /// a program run, such as a server's file tool; a run uses [`install`](Self::install).
389    pub fn wrap(self: &Arc<Self>, inner: Arc<dyn SecurityCheck>) -> Arc<dyn SecurityCheck> {
390        Arc::new(RecordingCheck {
391            inner,
392            log: self.clone(),
393        })
394    }
395
396    /// Takes the run's records and releases their byte charge. Call once, when the
397    /// run ends: the truncation flags, drop count, and call numbering describe the
398    /// whole run, so a later call would not describe only its own records.
399    pub fn finish(&self) -> DecisionLogOutput {
400        let mut state = self.lock();
401        let records = std::mem::take(&mut state.records);
402        for (_, position) in std::mem::take(&mut state.open_calls) {
403            if let Some(call) = state.calls.get_mut(position) {
404                call.outcome = Some(CallOutcome::Unfinished);
405            }
406        }
407        let output = DecisionLogOutput {
408            records,
409            truncated: state.truncated,
410            dropped: state.dropped,
411            line_frames: state.line_frames,
412            calls: std::mem::take(&mut state.calls),
413            calls_dropped: state.calls_dropped,
414        };
415        state.charged = 0;
416        state.pairs.clear();
417        output
418    }
419
420    /// Reports a console line to the observer, stamped with the run's clock and the last
421    /// call begun.
422    pub fn console_line(&self, text: &str, truncated: bool) {
423        let Some(observer) = &self.observer else {
424            return;
425        };
426        let after_call = self.lock().last_call_index;
427        observer.console_line(&ConsoleLine {
428            text,
429            written_micros: self.now_micros(),
430            after_call,
431            truncated,
432        });
433    }
434
435    fn lock(&self) -> MutexGuard<'_, LogState> {
436        // A poisoned lock means a recorder call panicked while it may have been updating
437        // this state, so the state could be partly updated. Recovering is acceptable here
438        // (unlike the accepted poisoned-lock panics in AGENTS.md) only because the log is
439        // observation-only: it never feeds a decision, so a skewed record cannot change
440        // what the run is allowed to do.
441        self.state
442            .lock()
443            .unwrap_or_else(std::sync::PoisonError::into_inner)
444    }
445
446    fn now_micros(&self) -> u64 {
447        let elapsed = u64::try_from(self.started.elapsed().as_micros()).unwrap_or(u64::MAX);
448        let previous = self.clock.fetch_max(elapsed, Ordering::Relaxed);
449        previous.max(elapsed)
450    }
451
452    fn charge(&self, state: &mut LogState, bytes: u64) -> bool {
453        self.charge_within(state, bytes, self.config.max_recorder_bytes)
454    }
455
456    /// Charges `bytes` if the total stays within `limit`.
457    fn charge_within(&self, state: &mut LogState, bytes: u64, limit: u64) -> bool {
458        let next = state.charged.saturating_add(bytes);
459        if next > limit {
460            return false;
461        }
462        state.charged = next;
463        true
464    }
465
466    /// The most the recorder's charge may reach for payload bodies and metas: the budget
467    /// less the reserve. Digest-only records and decisions may spend the reserve.
468    fn payload_limit(&self) -> u64 {
469        let max = self.config.max_recorder_bytes;
470        max.saturating_sub(max / RECORD_RESERVE_DIVISOR)
471    }
472
473    /// Whether the decision cap and the byte budget leave room for one more bare record.
474    fn can_keep_another(&self, state: &LogState) -> bool {
475        state.records.len() < self.config.max_decisions
476            && state.charged.saturating_add(RECORD_BASE_BYTES) <= self.config.max_recorder_bytes
477    }
478
479    fn begin(
480        &self,
481        state: &mut LogState,
482        caller: &str,
483        capability: &str,
484        line: Option<SourceLine>,
485    ) -> CallTicket {
486        let call_index = state.next_call_index;
487        state.next_call_index = state.next_call_index.saturating_add(1);
488        state.last_call_index = Some(call_index);
489        let key = (caller.to_owned(), capability.to_owned());
490        if !state.pairs.contains_key(&key) {
491            let cost = (caller.len() + capability.len()) as u64 + PAIR_OVERHEAD_BYTES;
492            if state.pairs.len() >= MAX_TRACKED_PAIRS || !self.charge(state, cost) {
493                state.truncated = true;
494                return CallTicket {
495                    call_index,
496                    seq: 0,
497                    at_micros: self.now_micros(),
498                    line,
499                };
500            }
501        }
502        let pair = state.pairs.entry(key).or_default();
503        pair.count = pair.count.saturating_add(1);
504        let ticket = CallTicket {
505            call_index,
506            seq: pair.count,
507            at_micros: self.now_micros(),
508            line,
509        };
510        pair.last = Some(ticket);
511        ticket
512    }
513
514    /// Stores what the audit saw. Called from the decorator's `audit`.
515    fn record(&self, decision: &AuditDecision<'_>) {
516        let mut state = self.lock();
517        let ticket = match decision.site.ticket {
518            Some(ticket) => ticket,
519            // A decision with no call is its own call, never a follow-up of another one.
520            None => self.begin(&mut state, decision.caller, decision.capability, None),
521        };
522        if state.records.len() >= self.config.max_decisions || state.records.try_reserve(1).is_err()
523        {
524            state.truncated = true;
525            state.dropped = state.dropped.saturating_add(1);
526            return;
527        }
528        let mut record = self.build(decision, ticket);
529        let minimal = RECORD_BASE_BYTES
530            + (record.caller.len()
531                + record.capability.len()
532                + record.source.len()
533                + record.reason.as_ref().map_or(0, String::len)) as u64;
534        let payload = payload_bytes(&record);
535        if !self.charge(&mut state, minimal.saturating_add(payload)) {
536            // Keep the digest and the verdict; drop what carries the bytes.
537            record.context = Value::Null;
538            record.near_misses = Vec::new();
539            record.payload_dropped = true;
540            record.context_truncated = true;
541            state.truncated = true;
542            if !self.charge(&mut state, minimal) {
543                state.bytes_exhausted = true;
544                state.dropped = state.dropped.saturating_add(1);
545                return;
546            }
547        }
548        let observed = self.observer.as_ref().map(|_| record.clone());
549        state.records.push(record);
550        drop(state);
551        if let (Some(observer), Some(record)) = (&self.observer, observed) {
552            observer.decision(&record);
553        }
554    }
555
556    /// Opens the call `ticket` begins. Over the call cap or the byte budget it is
557    /// counted and the run marked truncated.
558    fn open_call(
559        &self,
560        state: &mut LogState,
561        caller: &str,
562        capability: &str,
563        ticket: CallTicket,
564    ) -> Option<CallRecord> {
565        let cost =
566            CALL_BASE_BYTES.saturating_add(caller.len().saturating_add(capability.len()) as u64);
567        if state.calls.len() >= self.config.max_calls
568            || state.calls.try_reserve(1).is_err()
569            || state.open_calls.try_reserve(1).is_err()
570            || !self.charge(state, cost)
571        {
572            state.truncated = true;
573            state.calls_dropped = state.calls_dropped.saturating_add(1);
574            return None;
575        }
576        let call = CallRecord {
577            call_index: ticket.call_index,
578            caller: caller.to_owned(),
579            capability: capability.to_owned(),
580            started_micros: ticket.at_micros,
581            ended_micros: None,
582            outcome: None,
583            line: ticket.line,
584            request: None,
585            response: None,
586            usage: None,
587        };
588        let observed = self.observer.as_ref().map(|_| call.clone());
589        state
590            .open_calls
591            .push((ticket.call_index, state.calls.len()));
592        state.calls.push(call);
593        observed
594    }
595
596    fn call_mut(state: &mut LogState, call_index: u64) -> Option<&mut CallRecord> {
597        let position = state
598            .open_calls
599            .iter()
600            .rev()
601            .find(|(index, _)| *index == call_index)
602            .map(|(_, position)| *position)?;
603        state.calls.get_mut(position)
604    }
605
606    fn build(&self, decision: &AuditDecision<'_>, ticket: CallTicket) -> DecisionRecord {
607        let digest = digest_of(decision.context);
608        let (context, mut context_truncated) = if decision.capability == "secrets.get" {
609            // The key name is the record; nothing else a secret read carries is kept.
610            let name = decision.context.get("name").cloned().unwrap_or(Value::Null);
611            cap_context(
612                &serde_json::json!({ "name": name }),
613                self.config.max_context_value_bytes,
614            )
615        } else {
616            cap_context(decision.context, self.config.max_context_value_bytes)
617        };
618        let (action, cause, near_misses) = match decision.explanation {
619            Some(explanation) => (
620                enforced_action(decision.allowed, Some(explanation.action)),
621                explanation.cause.clone(),
622                self.capped_near_misses(&explanation.near_misses, &mut context_truncated),
623            ),
624            None => (
625                enforced_action(decision.allowed, None),
626                fallback_cause(decision),
627                Vec::new(),
628            ),
629        };
630        DecisionRecord {
631            call_index: ticket.call_index,
632            seq: ticket.seq,
633            at_micros: ticket.at_micros,
634            caller: decision.caller.to_owned(),
635            capability: decision.capability.to_owned(),
636            context,
637            context_truncated,
638            context_digest: digest,
639            allowed: decision.allowed,
640            action,
641            cause,
642            near_misses,
643            source: decision.source.to_owned(),
644            rule: decision.rule,
645            reason: decision.reason.map(str::to_owned),
646            entry_path: decision.site.entry,
647            line: ticket.line,
648            filtered: false,
649            payload_dropped: false,
650        }
651    }
652
653    /// Near misses carry the call's actual values, which are as unbounded as the context.
654    fn capped_near_misses(
655        &self,
656        near_misses: &[NearMissRecord],
657        truncated: &mut bool,
658    ) -> Vec<NearMissRecord> {
659        let max = self.config.max_context_value_bytes;
660        near_misses
661            .iter()
662            .map(|miss| NearMissRecord {
663                rule: miss.rule.clone(),
664                filter: miss.filter.clone(),
665                failures: miss
666                    .failures
667                    .iter()
668                    .map(|failure| FailureRecord {
669                        actual: failure
670                            .actual
671                            .as_ref()
672                            .map(|actual| cap_value(actual, max, 0, truncated)),
673                        ..failure.clone()
674                    })
675                    .collect(),
676            })
677            .collect()
678    }
679}
680
681impl DecisionRecorder for DecisionLog {
682    fn begin_call(&self, caller: &str, capability: &str, line: Option<SourceLine>) -> CallTicket {
683        let mut state = self.lock();
684        let ticket = self.begin(&mut state, caller, capability, line);
685        let opened = self.open_call(&mut state, caller, capability, ticket);
686        drop(state);
687        if let (Some(observer), Some(call)) = (&self.observer, opened) {
688            observer.call_started(&call);
689        }
690        ticket
691    }
692
693    fn enter_host_call(&self) -> u64 {
694        self.lock().next_call_index
695    }
696
697    fn exit_host_call(&self, marker: u64, returned: bool) {
698        let mut state = self.lock();
699        let Some(first) = state
700            .open_calls
701            .iter()
702            .position(|(index, _)| *index >= marker)
703        else {
704            return;
705        };
706        let ended = self.now_micros();
707        let closing: Vec<_> = state.open_calls.drain(first..).collect();
708        let mut finished = Vec::new();
709        for (_, position) in closing {
710            if let Some(call) = state.calls.get_mut(position) {
711                call.ended_micros = Some(ended);
712                call.outcome = Some(if returned {
713                    CallOutcome::Returned
714                } else {
715                    CallOutcome::Failed
716                });
717                if self.observer.is_some() {
718                    // Observers report sizes and timing; the bodies stay in the log.
719                    finished.push(call.without_bodies());
720                }
721            }
722        }
723        drop(state);
724        if let Some(observer) = &self.observer {
725            for call in &finished {
726                observer.call_finished(call);
727            }
728        }
729    }
730
731    fn wants_payload(&self, call_index: u64) -> bool {
732        let mut state = self.lock();
733        // Past the payload limit a record of it, at least its digest, still fits the
734        // budget, so a payload is wanted until even that cannot be charged.
735        Self::call_mut(&mut state, call_index).is_some()
736            && state.charged.saturating_add(call_log::DIGEST_ONLY_COST)
737                <= self.config.max_recorder_bytes
738    }
739
740    fn call_payload(&self, call_index: u64, side: Side, payload: Payload<'_>) {
741        let room = {
742            let mut state = self.lock();
743            // A call that was not kept, or has ended, takes no payload: skip the hashing
744            // and the copy.
745            if Self::call_mut(&mut state, call_index).is_none() {
746                return;
747            }
748            self.payload_limit().saturating_sub(state.charged)
749        };
750        let record = call_log::capture(
751            &payload,
752            self.config.max_context_value_bytes,
753            room,
754            self.config.max_payload_bytes,
755        );
756        let mut state = self.lock();
757        // The lock was released while the payload was hashed, so the call may have ended.
758        if Self::call_mut(&mut state, call_index).is_none() {
759            return;
760        }
761        let cost = call_log::payload_cost(&record);
762        let record = if self.charge_within(&mut state, cost, self.payload_limit()) {
763            record
764        } else {
765            // Only the digest and the size enter the reserve.
766            state.truncated = true;
767            let mut kept = record.digest_only();
768            kept.truncated = true;
769            if !self.charge(&mut state, call_log::payload_cost(&kept)) {
770                return;
771            }
772            kept
773        };
774        let Some(call) = Self::call_mut(&mut state, call_index) else {
775            return;
776        };
777        match side {
778            Side::Request => call.request = Some(Box::new(record)),
779            Side::Response => call.response = Some(Box::new(record)),
780        }
781    }
782
783    fn call_usage(&self, call_index: u64, usage: ModelUsage) {
784        let mut state = self.lock();
785        if let Some(call) = Self::call_mut(&mut state, call_index) {
786            call.usage = Some(usage);
787        }
788    }
789
790    fn wants_line(&self) -> bool {
791        let state = self.lock();
792        !state.lines_exhausted && !state.bytes_exhausted && self.can_keep_another(&state)
793    }
794
795    fn note_line_capture(&self, frames: usize) {
796        let mut state = self.lock();
797        state.line_frames = state.line_frames.saturating_add(frames as u64);
798        if state.line_frames > self.config.max_line_capture_frames {
799            state.lines_exhausted = true;
800            state.truncated = true;
801        }
802    }
803
804    fn mark_last_filtered(&self) {
805        let mut state = self.lock();
806        let Some(last) = state.last_call_index else {
807            return;
808        };
809        if let Some(record) = state
810            .records
811            .iter_mut()
812            .rev()
813            .find(|record| record.call_index == last)
814        {
815            record.filtered = true;
816        }
817    }
818}
819
820/// The action the enforcement path took; the explanation only refines a denial into
821/// `AskHuman`, so a disagreeing explanation cannot change what is recorded as allowed.
822fn enforced_action(allowed: bool, explained: Option<DecisionAction>) -> DecisionAction {
823    match (allowed, explained) {
824        (true, _) => DecisionAction::Allow,
825        (false, Some(DecisionAction::AskHuman)) => DecisionAction::AskHuman,
826        (false, _) => DecisionAction::Deny,
827    }
828}
829
830fn fallback_cause(decision: &AuditDecision<'_>) -> DecisionCause {
831    if decision.source == "policy" {
832        return DecisionCause::Unexplained;
833    }
834    DecisionCause::RuntimeInvariant {
835        reason: decision.reason.unwrap_or_default().to_owned(),
836    }
837}
838
839fn digest_of(context: &Value) -> u64 {
840    use std::hash::{Hash, Hasher};
841    let Ok(text) = serde_json::to_string(context) else {
842        return 0;
843    };
844    // `DefaultHasher::new()` is keyed with fixed constants, so a digest is stable in a run.
845    let mut hasher = std::collections::hash_map::DefaultHasher::new();
846    text.hash(&mut hasher);
847    hasher.finish()
848}
849
850fn payload_bytes(record: &DecisionRecord) -> u64 {
851    let context = serde_json::to_string(&record.context).map_or(0, |text| text.len());
852    let misses = serde_json::to_string(&record.near_misses).map_or(0, |text| text.len());
853    // Parsed JSON costs several times its text; charge generously.
854    (context.saturating_add(misses) as u64).saturating_mul(2)
855}
856
857/// Caps a recorded context: long strings, deep nesting, and wide containers each end in a
858/// marker. Returns whether anything was cut.
859pub(crate) fn cap_context(context: &Value, max_string_bytes: usize) -> (Value, bool) {
860    let mut truncated = false;
861    let capped = cap_value(context, max_string_bytes, 0, &mut truncated);
862    (capped, truncated)
863}
864
865fn cap_value(value: &Value, max_string: usize, depth: usize, truncated: &mut bool) -> Value {
866    match value {
867        Value::String(text) => Value::String(cap_text(text, max_string, truncated)),
868        Value::Array(_) | Value::Object(_) if depth >= MAX_CONTEXT_DEPTH => {
869            *truncated = true;
870            Value::String("…[truncated, nested too deep]".to_owned())
871        }
872        Value::Array(items) => {
873            if items.len() > MAX_CONTEXT_ENTRIES {
874                *truncated = true;
875            }
876            Value::Array(
877                items
878                    .iter()
879                    .take(MAX_CONTEXT_ENTRIES)
880                    .map(|item| cap_value(item, max_string, depth + 1, truncated))
881                    .collect(),
882            )
883        }
884        Value::Object(fields) => {
885            if fields.len() > MAX_CONTEXT_ENTRIES {
886                *truncated = true;
887            }
888            Value::Object(
889                fields
890                    .iter()
891                    .take(MAX_CONTEXT_ENTRIES)
892                    .enumerate()
893                    .map(|(position, (key, item))| {
894                        (
895                            capped_key(key, position, max_string, truncated),
896                            cap_value(item, max_string, depth + 1, truncated),
897                        )
898                    })
899                    .collect(),
900            )
901        }
902        other => other.clone(),
903    }
904}
905
906/// A capped object key. Two long keys can share their kept prefix, so a cut key
907/// also names its position in the object to keep both entries.
908fn capped_key(key: &str, position: usize, max: usize, truncated: &mut bool) -> String {
909    let capped = cap_text(key, max, truncated);
910    if capped.len() == key.len() {
911        return capped;
912    }
913    format!("{capped} #{position}")
914}
915
916/// `text` cut to `max` bytes at a character boundary, ending in a marker when cut.
917pub(crate) fn cap_text(text: &str, max: usize, truncated: &mut bool) -> String {
918    if text.len() <= max {
919        return text.to_owned();
920    }
921    *truncated = true;
922    let mut end = max;
923    while end > 0 && !text.is_char_boundary(end) {
924        end -= 1;
925    }
926    let kept = text.get(..end).unwrap_or_default();
927    format!(
928        "{kept}…[truncated, {} of {} bytes kept]",
929        kept.len(),
930        text.len()
931    )
932}
933
934struct RecordingCheck {
935    inner: Arc<dyn SecurityCheck>,
936    log: Arc<DecisionLog>,
937}
938
939impl SecurityCheck for RecordingCheck {
940    fn audit(&self, decision: AuditDecision<'_>) {
941        self.inner.audit(decision);
942        self.log.record(&decision);
943    }
944
945    fn audit_context<'a>(
946        &self,
947        capability: &str,
948        context: &'a Value,
949        cwd: &str,
950    ) -> std::borrow::Cow<'a, Value> {
951        self.inner.audit_context(capability, context, cwd)
952    }
953
954    fn check_with_cwd(
955        &self,
956        caller: &str,
957        capability: &str,
958        context: &Value,
959        cwd: &str,
960    ) -> CheckOutcome {
961        self.inner.check_with_cwd(caller, capability, context, cwd)
962    }
963
964    fn check(&self, caller: &str, capability: &str, context: &Value) -> CheckOutcome {
965        self.inner.check(caller, capability, context)
966    }
967
968    fn recorder(&self) -> Option<&dyn DecisionRecorder> {
969        Some(self.log.as_ref())
970    }
971
972    fn explain(
973        &self,
974        caller: &str,
975        capability: &str,
976        context: &Value,
977        cwd: &str,
978    ) -> Option<DecisionExplanation> {
979        self.inner.explain(caller, capability, context, cwd)
980    }
981}
982
983#[cfg(test)]
984mod tests {
985    use super::*;
986    use crate::runtime::Vfs;
987
988    fn log_with(config: DecisionLogConfig) -> (StoreData, Arc<DecisionLog>) {
989        let mut data = StoreData::with_vfs_and_cap(Vfs::none(), 1 << 20);
990        let log = DecisionLog::install(&mut data, config);
991        (data, log)
992    }
993
994    fn audit_denied(data: &StoreData, ticket: CallTicket) {
995        let context = serde_json::json!({});
996        data.security_check.audit(
997            AuditDecision::new("main", "fs.read", &context, false, "policy", None, None)
998                .with_site(CallSite::new(Some(ticket), EntryPath::GatedOp)),
999        );
1000    }
1001
1002    #[test]
1003    fn a_call_still_open_at_finish_is_unfinished() {
1004        let (data, log) = log_with(DecisionLogConfig::default());
1005        let recorder = data.security_check.recorder().unwrap();
1006        recorder.enter_host_call();
1007        recorder.begin_call("main", "http.get", None);
1008        let output = log.finish();
1009        let [call] = output.calls.as_slice() else {
1010            panic!("one call: {output:?}");
1011        };
1012        assert_eq!(call.outcome, Some(CallOutcome::Unfinished));
1013        assert_eq!(call.ended_micros, None);
1014    }
1015
1016    #[test]
1017    fn payload_copies_leave_the_decision_reserve_free() {
1018        let max = 64 * 1024;
1019        let (data, log) = log_with(DecisionLogConfig {
1020            max_recorder_bytes: max,
1021            ..DecisionLogConfig::default()
1022        });
1023        let recorder = data.security_check.recorder().unwrap();
1024        let body = vec![b'x'; 20 * 1024];
1025        for _ in 0..6 {
1026            let ticket = recorder.begin_call("main", "http.get", None);
1027            recorder.call_payload(
1028                ticket.call_index,
1029                Side::Response,
1030                Payload::meta(serde_json::Value::Null).with_body(&body),
1031            );
1032        }
1033        assert!(
1034            log.lock().charged <= max - max / RECORD_RESERVE_DIVISOR + 6 * 256,
1035            "bodies stay out of the reserve; only digests may enter it"
1036        );
1037        let output = log.finish();
1038        let responses: Vec<_> = output
1039            .calls
1040            .iter()
1041            .filter_map(|call| call.response.as_deref())
1042            .collect();
1043        assert_eq!(responses.len(), 6, "every payload keeps a record");
1044        assert!(responses.iter().any(|payload| payload.body.is_some()));
1045        let cut = responses
1046            .iter()
1047            .find(|payload| payload.body.is_none())
1048            .expect("a payload past the reserve keeps no body");
1049        assert!(cut.truncated && cut.bytes == body.len() as u64 && !cut.digest.is_empty());
1050        assert!(output.truncated);
1051    }
1052
1053    #[test]
1054    fn digest_only_records_do_not_spend_the_reserve_on_masked_names() {
1055        let max = 64 * 1024;
1056        let (data, log) = log_with(DecisionLogConfig {
1057            max_recorder_bytes: max,
1058            ..DecisionLogConfig::default()
1059        });
1060        let recorder = data.security_check.recorder().unwrap();
1061        let body = vec![b'x'; 20 * 1024];
1062        for _ in 0..6 {
1063            let ticket = recorder.begin_call("main", "http.get", None);
1064            recorder.call_payload(
1065                ticket.call_index,
1066                Side::Response,
1067                Payload::meta(serde_json::Value::Null).with_body(&body),
1068            );
1069        }
1070        let before = log.lock().charged;
1071        let names: Vec<String> = (0..64)
1072            .map(|i| format!("x-token-{i}-{}", "n".repeat(900)))
1073            .collect();
1074        let ticket = recorder.begin_call("main", "http.get", None);
1075        recorder.call_payload(
1076            ticket.call_index,
1077            Side::Response,
1078            Payload::meta(serde_json::Value::Null)
1079                .with_body(&body)
1080                .with_masked(names),
1081        );
1082        let spent = log.lock().charged - before;
1083        assert!(
1084            spent < 512,
1085            "a payload past the limit enters the reserve as a digest and a size: {spent}"
1086        );
1087        audit_denied(&data, recorder.begin_call("main", "fs.read", None));
1088        let output = log.finish();
1089        assert_eq!(output.records.len(), 1, "a later denial is still recorded");
1090        let last = output
1091            .calls
1092            .iter()
1093            .rev()
1094            .find_map(|call| call.response.as_deref());
1095        assert!(last.is_some_and(|payload| payload.masked_headers.is_empty()));
1096    }
1097
1098    #[test]
1099    fn a_body_is_sized_to_the_room_its_record_leaves() {
1100        let max = 16 * 1024;
1101        let (data, log) = log_with(DecisionLogConfig {
1102            max_recorder_bytes: max,
1103            ..DecisionLogConfig::default()
1104        });
1105        let recorder = data.security_check.recorder().unwrap();
1106        let body = vec![b'x'; 64 * 1024];
1107        let meta = serde_json::json!({ "url": "https://x.test/" });
1108        let ticket = recorder.begin_call("main", "http.get", None);
1109        recorder.call_payload(
1110            ticket.call_index,
1111            Side::Response,
1112            Payload::meta(meta.clone()).with_body(&body),
1113        );
1114        let charged = log.lock().charged;
1115        assert!(
1116            charged <= log.payload_limit(),
1117            "the copy fits what it is charged"
1118        );
1119        let output = log.finish();
1120        let payload = output.calls[0]
1121            .response
1122            .as_deref()
1123            .expect("a response record");
1124        let kept = match &payload.body {
1125            Some(call_log::BodyCopy::Text(text)) => text.len(),
1126            other => panic!("a cut text body is kept as text: {other:?}"),
1127        };
1128        assert!(payload.truncated && kept > 0 && kept < body.len());
1129        assert_eq!(payload.bytes, body.len() as u64);
1130        // Binary bodies are charged as base64: a quarter more.
1131        let (data, log) = log_with(DecisionLogConfig {
1132            max_recorder_bytes: max,
1133            ..DecisionLogConfig::default()
1134        });
1135        let recorder = data.security_check.recorder().unwrap();
1136        let binary = vec![0xffu8; 64 * 1024];
1137        let ticket = recorder.begin_call("main", "http.get", None);
1138        recorder.call_payload(
1139            ticket.call_index,
1140            Side::Response,
1141            Payload::meta(meta).with_body(&binary),
1142        );
1143        let output = log.finish();
1144        let payload = output.calls[0]
1145            .response
1146            .as_deref()
1147            .expect("a response record");
1148        let Some(call_log::BodyCopy::Base64(text)) = &payload.body else {
1149            panic!("a binary body is kept as base64: {payload:?}");
1150        };
1151        assert!(payload.truncated);
1152        assert!(text.len() as u64 <= max - max / RECORD_RESERVE_DIVISOR);
1153    }
1154
1155    #[test]
1156    fn a_payload_is_wanted_exactly_while_its_digest_only_record_fits() {
1157        let max = 4096;
1158        let (data, log) = log_with(DecisionLogConfig {
1159            max_recorder_bytes: max,
1160            ..DecisionLogConfig::default()
1161        });
1162        let recorder = data.security_check.recorder().unwrap();
1163        recorder.enter_host_call();
1164        let ticket = recorder.begin_call("main", "http.get", None);
1165        log.lock().charged = max - call_log::DIGEST_ONLY_COST;
1166        assert!(recorder.wants_payload(ticket.call_index));
1167        log.lock().charged = max - call_log::DIGEST_ONLY_COST + 1;
1168        assert!(!recorder.wants_payload(ticket.call_index));
1169    }
1170
1171    #[test]
1172    fn a_body_with_no_room_is_not_copied() {
1173        let (data, log) = log_with(DecisionLogConfig {
1174            max_recorder_bytes: 1024,
1175            ..DecisionLogConfig::default()
1176        });
1177        let recorder = data.security_check.recorder().unwrap();
1178        let ticket = recorder.begin_call("main", "http.get", None);
1179        let meta = serde_json::json!({ "url": "u".repeat(400) });
1180        recorder.call_payload(
1181            ticket.call_index,
1182            Side::Response,
1183            Payload::meta(meta).with_body(&[b'x'; 4096]),
1184        );
1185        let output = log.finish();
1186        let payload = output.calls[0]
1187            .response
1188            .as_deref()
1189            .expect("a response record");
1190        assert!(payload.body.is_none() && payload.truncated);
1191        assert_eq!(payload.bytes, 4096);
1192    }
1193
1194    #[test]
1195    fn a_payload_is_wanted_while_its_call_is_open_and_the_budget_lasts() {
1196        let (data, _log) = log_with(DecisionLogConfig {
1197            max_recorder_bytes: 4096,
1198            ..DecisionLogConfig::default()
1199        });
1200        let recorder = data.security_check.recorder().unwrap();
1201        recorder.enter_host_call();
1202        let ticket = recorder.begin_call("main", "http.get", None);
1203        assert!(recorder.wants_payload(ticket.call_index));
1204        assert!(
1205            !recorder.wants_payload(ticket.call_index + 1),
1206            "no such call"
1207        );
1208        recorder.exit_host_call(0, true);
1209        assert!(!recorder.wants_payload(ticket.call_index), "the call ended");
1210    }
1211
1212    #[test]
1213    fn a_full_log_stops_asking_for_lines() {
1214        let (data, log) = log_with(DecisionLogConfig {
1215            max_decisions: 2,
1216            ..DecisionLogConfig::default()
1217        });
1218        let recorder = data.security_check.recorder().unwrap();
1219        for _ in 0..2 {
1220            assert!(recorder.wants_line());
1221            audit_denied(&data, recorder.begin_call("main", "fs.read", None));
1222        }
1223        assert!(!recorder.wants_line(), "the cap is reached");
1224        audit_denied(&data, recorder.begin_call("main", "fs.read", None));
1225        assert!(!recorder.wants_line(), "still off once the log is full");
1226        assert!(log.finish().truncated);
1227    }
1228
1229    #[test]
1230    fn a_byte_budget_payload_drop_keeps_asking_for_lines() {
1231        let (data, log) = log_with(DecisionLogConfig {
1232            max_recorder_bytes: 4 * RECORD_BASE_BYTES,
1233            ..DecisionLogConfig::default()
1234        });
1235        let recorder = data.security_check.recorder().unwrap();
1236        let context = serde_json::json!({ "path": "p".repeat(900) });
1237        let ticket = recorder.begin_call("main", "fs.read", None);
1238        data.security_check.audit(
1239            AuditDecision::new("main", "fs.read", &context, true, "policy", None, None)
1240                .with_site(CallSite::new(Some(ticket), EntryPath::GatedOp)),
1241        );
1242        assert!(recorder.wants_line(), "a minimal record still fits");
1243        let output = log.finish();
1244        assert!(output.truncated);
1245        assert!(output.records.iter().any(|r| r.payload_dropped));
1246    }
1247
1248    #[test]
1249    fn filling_the_pair_cap_keeps_asking_for_lines() {
1250        let (data, log) = log_with(DecisionLogConfig::default());
1251        let recorder = data.security_check.recorder().unwrap();
1252        for index in 0..=MAX_TRACKED_PAIRS {
1253            recorder.begin_call("main", &format!("cap.{index}"), None);
1254        }
1255        assert!(recorder.wants_line());
1256        assert!(log.finish().truncated, "the pair cap truncates");
1257    }
1258
1259    #[test]
1260    fn lines_stop_once_the_byte_budget_cannot_fit_a_record() {
1261        let (data, log) = log_with(DecisionLogConfig {
1262            max_recorder_bytes: 3 * RECORD_BASE_BYTES,
1263            ..DecisionLogConfig::default()
1264        });
1265        let recorder = data.security_check.recorder().unwrap();
1266        let mut captures = 0;
1267        for _ in 0..20 {
1268            if recorder.wants_line() {
1269                captures += 1;
1270                recorder.note_line_capture(5);
1271            }
1272            audit_denied(&data, recorder.begin_call("main", "fs.read", None));
1273        }
1274        let output = log.finish();
1275        assert!(output.dropped > 0, "records were dropped whole");
1276        assert!(
1277            captures < 20 && output.line_frames == 5 * captures,
1278            "capture stopped: {captures} captures"
1279        );
1280        assert!(
1281            captures <= output.records.len() as u64 + 1,
1282            "no captures beyond the first dropped record: {captures} for {} kept",
1283            output.records.len()
1284        );
1285    }
1286
1287    #[test]
1288    fn a_budget_below_one_bare_record_wants_no_line() {
1289        for max_recorder_bytes in [0, RECORD_BASE_BYTES - 1] {
1290            let (data, _log) = log_with(DecisionLogConfig {
1291                max_recorder_bytes,
1292                ..DecisionLogConfig::default()
1293            });
1294            let recorder = data.security_check.recorder().unwrap();
1295            assert!(!recorder.wants_line(), "budget {max_recorder_bytes}");
1296        }
1297    }
1298
1299    #[test]
1300    fn a_whole_record_drop_stops_lines_though_a_bare_record_would_fit() {
1301        let (data, log) = log_with(DecisionLogConfig {
1302            // After the call's pair is charged, the leftover is a bare record plus 2 bytes:
1303            // less than this record's strings need. No call records take a share.
1304            max_recorder_bytes: PAIR_OVERHEAD_BYTES
1305                + "main".len() as u64
1306                + "fs.read".len() as u64
1307                + RECORD_BASE_BYTES
1308                + 2,
1309            max_calls: 0,
1310            ..DecisionLogConfig::default()
1311        });
1312        let recorder = data.security_check.recorder().unwrap();
1313        assert!(recorder.wants_line(), "a bare record fits before any call");
1314        let ticket = recorder.begin_call("main", "fs.read", None);
1315        assert!(
1316            recorder.wants_line(),
1317            "a bare record still fits after the call"
1318        );
1319        audit_denied(&data, ticket);
1320        assert!(!recorder.wants_line(), "the drop turns lines off");
1321        let output = log.finish();
1322        assert_eq!(output.dropped, 1);
1323        assert!(output.records.is_empty());
1324    }
1325
1326    #[test]
1327    fn the_line_capture_frame_budget_truncates_the_log_once_exceeded() {
1328        let (data, log) = log_with(DecisionLogConfig {
1329            max_line_capture_frames: 10,
1330            ..DecisionLogConfig::default()
1331        });
1332        let recorder = data.security_check.recorder().unwrap();
1333        recorder.note_line_capture(10);
1334        assert!(recorder.wants_line(), "at the budget is still within it");
1335        recorder.note_line_capture(1);
1336        assert!(!recorder.wants_line());
1337        assert!(log.finish().truncated);
1338    }
1339
1340    #[test]
1341    fn a_secret_read_keeps_the_key_name_and_nothing_else() {
1342        let (data, log) = log_with(DecisionLogConfig::default());
1343        let context = serde_json::json!({ "name": "api-key", "value": "s3cret" });
1344        data.security_check.audit(AuditDecision::new(
1345            "main",
1346            "secrets.get",
1347            &context,
1348            false,
1349            "invariant",
1350            None,
1351            Some("refused"),
1352        ));
1353        let output = log.finish();
1354        let [record] = output.records.as_slice() else {
1355            panic!("one record");
1356        };
1357        assert_eq!(record.context, serde_json::json!({ "name": "api-key" }));
1358        assert!(!format!("{record:?}").contains("s3cret"));
1359    }
1360
1361    #[test]
1362    fn an_exhausted_recorder_budget_keeps_the_verdict_and_drops_the_payload() {
1363        // Room for the pair bookkeeping and a bare record, not for a big context.
1364        let (data, log) = log_with(DecisionLogConfig {
1365            max_recorder_bytes: 2048,
1366            ..DecisionLogConfig::default()
1367        });
1368        let context = serde_json::json!({ "path": "p".repeat(900) });
1369        let recorder = data.security_check.recorder().unwrap();
1370        let ticket = recorder.begin_call("main", "fs.read", None);
1371        data.security_check.audit(
1372            AuditDecision::new("main", "fs.read", &context, true, "policy", None, None)
1373                .with_site(CallSite::new(Some(ticket), EntryPath::GatedOp)),
1374        );
1375        let output = log.finish();
1376        assert!(output.truncated);
1377        let [record] = output.records.as_slice() else {
1378            panic!("the verdict is kept: {output:?}");
1379        };
1380        assert!(record.allowed && record.payload_dropped);
1381        assert_eq!(record.context, serde_json::Value::Null);
1382        assert_ne!(record.context_digest, 0, "the digest survives");
1383        assert_eq!(
1384            data.tenant_limits.host_attached_bytes(),
1385            0,
1386            "the run's memory budget is not touched"
1387        );
1388    }
1389
1390    #[test]
1391    fn caps_mark_long_strings_deep_nesting_and_wide_containers() {
1392        let long = serde_json::json!({ "a": "é".repeat(100) });
1393        let (capped, truncated) = cap_context(&long, 11);
1394        assert!(truncated);
1395        let text = capped["a"].as_str().unwrap();
1396        assert!(
1397            text.starts_with("éééé") && text.contains("truncated"),
1398            "{text}"
1399        );
1400
1401        let mut nested = serde_json::json!(1);
1402        for _ in 0..20 {
1403            nested = serde_json::json!([nested]);
1404        }
1405        assert!(cap_context(&nested, 100).1);
1406
1407        let wide = Value::Array((0..200).map(Value::from).collect());
1408        let (capped, truncated) = cap_context(&wide, 100);
1409        assert!(truncated);
1410        assert_eq!(capped.as_array().unwrap().len(), MAX_CONTEXT_ENTRIES);
1411
1412        let small = serde_json::json!({ "host": "x", "n": [1, 2] });
1413        assert_eq!(cap_context(&small, 100), (small.clone(), false));
1414    }
1415
1416    #[test]
1417    fn finish_refunds_the_recorders_budget() {
1418        let (data, log) = log_with(DecisionLogConfig {
1419            max_recorder_bytes: 4096,
1420            ..DecisionLogConfig::default()
1421        });
1422        let context = serde_json::json!({ "path": "p".repeat(300) });
1423        for _ in 0..2 {
1424            data.security_check.audit(AuditDecision::new(
1425                "main", "fs.read", &context, true, "policy", None, None,
1426            ));
1427            let output = log.finish();
1428            assert!(!output.truncated && output.records.len() == 1, "{output:?}");
1429        }
1430        assert_eq!(data.tenant_limits.host_attached_bytes(), 0);
1431    }
1432
1433    #[test]
1434    fn long_keys_sharing_a_prefix_both_survive_capping() {
1435        let long = "k".repeat(100);
1436        let value = serde_json::json!({ format!("{long}a"): 1, format!("{long}b"): 2 });
1437        let mut truncated = false;
1438        let Value::Object(capped) = cap_value(&value, 16, 0, &mut truncated) else {
1439            panic!("expected an object");
1440        };
1441        assert!(truncated);
1442        assert_eq!(capped.len(), 2, "{capped:?}");
1443        let mut values: Vec<_> = capped.values().cloned().collect();
1444        values.sort_by_key(Value::as_i64);
1445        assert_eq!(values, vec![serde_json::json!(1), serde_json::json!(2)]);
1446    }
1447
1448    #[test]
1449    fn near_miss_actual_values_and_keys_are_capped_like_the_context() {
1450        let (data, log) = log_with(DecisionLogConfig {
1451            max_context_value_bytes: 16,
1452            ..DecisionLogConfig::default()
1453        });
1454        let explanation = DecisionExplanation {
1455            action: DecisionAction::Deny,
1456            cause: DecisionCause::Default { caller_block: true },
1457            near_misses: vec![NearMissRecord {
1458                rule: RuleCitation {
1459                    caller: "main".into(),
1460                    index: 0,
1461                    name: None,
1462                },
1463                filter: "f".into(),
1464                failures: vec![FailureRecord {
1465                    comparison: "c".into(),
1466                    actual: Some(serde_json::json!({ "k".repeat(100): "v".repeat(100) })),
1467                    expected: None,
1468                    reason: FailureReasonRecord::NotSatisfied,
1469                    negated: false,
1470                }],
1471            }],
1472        };
1473        let context = serde_json::json!({});
1474        data.security_check.audit(
1475            AuditDecision::new("main", "fs.read", &context, false, "policy", None, None)
1476                .with_explanation(Some(&explanation)),
1477        );
1478        let output = log.finish();
1479        let [record] = output.records.as_slice() else {
1480            panic!("one record");
1481        };
1482        assert!(record.context_truncated);
1483        let actual = record.near_misses[0].failures[0].actual.as_ref().unwrap();
1484        assert!(
1485            serde_json::to_string(actual).unwrap().len() < 150,
1486            "{actual}"
1487        );
1488    }
1489}