1use 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#[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#[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 Rule(RuleCitation),
54 Default { caller_block: bool },
56 RuntimeInvariant { reason: String },
60 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#[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#[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#[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#[derive(Debug, Clone, Copy, PartialEq, Eq, Default, Serialize, Deserialize)]
100#[serde(rename_all = "kebab-case", tag = "kind")]
101pub enum EntryPath {
102 #[default]
104 GatedOp,
105 PackageCheck,
107 RedirectHop {
109 parent_call_index: u64,
110 index: u32,
111 },
112 Git,
113 FileTool,
115}
116
117#[derive(Debug, Clone, Copy, PartialEq, Eq, Serialize, Deserialize)]
119pub struct SourceLine {
120 pub line: u32,
121 pub column: Option<u32>,
122}
123
124#[derive(Debug, Clone, Copy, PartialEq, Eq, Serialize)]
126pub struct CallTicket {
127 pub call_index: u64,
129 pub seq: u64,
132 pub at_micros: u64,
134 pub line: Option<SourceLine>,
135}
136
137#[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
150pub trait DecisionRecorder: Send + Sync {
153 fn begin_call(&self, caller: &str, capability: &str, line: Option<SourceLine>) -> CallTicket;
155 fn mark_last_filtered(&self);
157 fn wants_line(&self) -> bool;
163 fn note_line_capture(&self, frames: usize);
166 fn enter_host_call(&self) -> u64;
169 fn exit_host_call(&self, marker: u64, returned: bool);
172 fn wants_payload(&self, _call_index: u64) -> bool {
176 true
177 }
178 fn call_payload(&self, call_index: u64, side: Side, payload: Payload<'_>);
180 fn call_usage(&self, call_index: u64, usage: ModelUsage);
182}
183
184pub trait RecordObserver: Send + Sync {
191 fn call_started(&self, _call: &CallRecord) {}
192 fn decision(&self, _record: &DecisionRecord) {}
193 fn call_finished(&self, _call: &CallRecord) {}
197 fn console_line(&self, _line: &ConsoleLine<'_>) {}
200}
201
202#[derive(Debug, Clone, Copy)]
204pub struct ConsoleLine<'a> {
205 pub text: &'a str,
206 pub written_micros: u64,
208 pub after_call: Option<u64>,
210 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 pub context: Value,
223 pub context_truncated: bool,
224 pub context_digest: u64,
226 pub allowed: bool,
227 pub action: DecisionAction,
228 pub cause: DecisionCause,
229 pub near_misses: Vec<NearMissRecord>,
230 pub source: String,
232 pub rule: Option<usize>,
233 pub reason: Option<String>,
234 pub entry_path: EntryPath,
235 pub line: Option<SourceLine>,
236 pub filtered: bool,
238 pub payload_dropped: bool,
240}
241
242#[derive(Debug, Clone)]
243pub struct DecisionLogConfig {
244 pub max_decisions: usize,
246 pub max_context_value_bytes: usize,
248 pub max_recorder_bytes: u64,
251 pub max_line_capture_frames: u64,
265 pub max_calls: usize,
267 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#[derive(Debug, Clone, Default)]
287pub struct DecisionLogOutput {
288 pub records: Vec<DecisionRecord>,
289 pub truncated: bool,
293 pub dropped: u64,
295 pub line_frames: u64,
297 pub calls: Vec<CallRecord>,
299 pub calls_dropped: u64,
301}
302
303const 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;
309const 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 lines_exhausted: bool,
335 bytes_exhausted: bool,
338 calls: Vec<CallRecord>,
339 open_calls: Vec<(u64, usize)>,
341 calls_dropped: u64,
342}
343
344pub 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 pub fn install(data: &mut StoreData, config: DecisionLogConfig) -> Arc<Self> {
361 Self::install_observed(data, config, None)
362 }
363
364 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 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 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 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 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 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 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 fn payload_limit(&self) -> u64 {
469 let max = self.config.max_recorder_bytes;
470 max.saturating_sub(max / RECORD_RESERVE_DIVISOR)
471 }
472
473 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 fn record(&self, decision: &AuditDecision<'_>) {
516 let mut state = self.lock();
517 let ticket = match decision.site.ticket {
518 Some(ticket) => ticket,
519 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 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 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 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 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 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 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 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 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 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
820fn 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 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 (context.saturating_add(misses) as u64).saturating_mul(2)
855}
856
857pub(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
906fn 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
916pub(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 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 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 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}