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 AskAdmin,
40}
41
42#[derive(Debug, Clone, PartialEq, Eq, Serialize, Deserialize)]
44pub struct RuleCitation {
45 pub caller: String,
46 pub index: usize,
47 pub name: Option<String>,
48}
49
50#[derive(Debug, Clone, PartialEq, Serialize, Deserialize)]
51#[serde(rename_all = "kebab-case", tag = "kind")]
52pub enum DecisionCause {
53 Rule(RuleCitation),
55 Default { caller_block: bool },
57 RuntimeInvariant { reason: String },
61 Unexplained,
63}
64
65#[derive(Debug, Clone, PartialEq, Eq, Serialize, Deserialize)]
66#[serde(rename_all = "kebab-case", tag = "kind", content = "variable")]
67pub enum FailureReasonRecord {
68 FieldMissing,
69 VariableNotBound(String),
70 NotSatisfied,
71}
72
73#[derive(Debug, Clone, PartialEq, Serialize, Deserialize)]
75pub struct FailureRecord {
76 pub comparison: String,
77 pub actual: Option<Value>,
78 pub expected: Option<String>,
79 pub reason: FailureReasonRecord,
80 pub negated: bool,
81}
82
83#[derive(Debug, Clone, PartialEq, Serialize, Deserialize)]
85pub struct NearMissRecord {
86 pub rule: RuleCitation,
87 pub filter: String,
88 pub failures: Vec<FailureRecord>,
89}
90
91#[derive(Debug, Clone, PartialEq, Serialize)]
93pub struct DecisionExplanation {
94 pub action: DecisionAction,
95 pub cause: DecisionCause,
96 pub near_misses: Vec<NearMissRecord>,
97}
98
99#[derive(Debug, Clone, Copy, PartialEq, Eq, Default, Serialize, Deserialize)]
101#[serde(rename_all = "kebab-case", tag = "kind")]
102pub enum EntryPath {
103 #[default]
105 GatedOp,
106 PackageCheck,
108 RedirectHop {
110 parent_call_index: u64,
111 index: u32,
112 },
113 Git,
114 FileTool,
116}
117
118#[derive(Debug, Clone, Copy, PartialEq, Eq, Serialize, Deserialize)]
120pub struct SourceLine {
121 pub line: u32,
122 pub column: Option<u32>,
123}
124
125#[derive(Debug, Clone, PartialEq, Eq, Serialize, Deserialize)]
128pub struct PackageLine {
129 pub package: String,
130 pub module: String,
133 #[serde(default, skip_serializing_if = "Option::is_none")]
135 pub function: Option<String>,
136 pub line: u32,
137 #[serde(default, skip_serializing_if = "Option::is_none")]
138 pub column: Option<u32>,
139}
140
141#[derive(Debug, Clone, Default, PartialEq, Eq)]
144pub struct CallOrigin {
145 pub line: Option<SourceLine>,
146 pub package: Option<PackageLine>,
147}
148
149#[derive(Debug, Clone, Copy, PartialEq, Eq, Serialize)]
151pub struct CallTicket {
152 pub call_index: u64,
154 pub seq: u64,
157 pub at_micros: u64,
159 pub line: Option<SourceLine>,
160}
161
162#[derive(Debug, Clone, Copy, Default)]
164pub struct CallSite {
165 pub ticket: Option<CallTicket>,
166 pub entry: EntryPath,
167}
168
169impl CallSite {
170 pub fn new(ticket: Option<CallTicket>, entry: EntryPath) -> Self {
171 Self { ticket, entry }
172 }
173}
174
175pub trait DecisionRecorder: Send + Sync {
178 fn begin_call(&self, caller: &str, capability: &str, origin: CallOrigin) -> CallTicket;
181 fn mark_last_filtered(&self);
183 fn wants_line(&self) -> bool;
189 fn note_line_capture(&self, frames: usize);
192 fn enter_host_call(&self) -> u64;
195 fn exit_host_call(&self, marker: u64, returned: bool);
198 fn wants_payload(&self, _call_index: u64) -> bool {
202 true
203 }
204 fn call_payload(&self, call_index: u64, side: Side, payload: Payload<'_>);
206 fn call_usage(&self, call_index: u64, usage: ModelUsage);
208}
209
210pub trait RecordObserver: Send + Sync {
217 fn call_started(&self, _call: &CallRecord) {}
218 fn decision(&self, _record: &DecisionRecord) {}
219 fn call_finished(&self, _call: &CallRecord) {}
223 fn console_line(&self, _line: &ConsoleLine<'_>) {}
226}
227
228#[derive(Debug, Clone, Copy)]
230pub struct ConsoleLine<'a> {
231 pub text: &'a str,
232 pub written_micros: u64,
234 pub after_call: Option<u64>,
236 pub truncated: bool,
238}
239
240#[derive(Debug, Clone, Serialize, Deserialize)]
241pub struct DecisionRecord {
242 pub call_index: u64,
243 pub seq: u64,
244 pub at_micros: u64,
245 pub caller: String,
246 pub capability: String,
247 pub context: Value,
249 pub context_truncated: bool,
250 pub context_digest: u64,
252 pub allowed: bool,
253 pub action: DecisionAction,
254 pub cause: DecisionCause,
255 pub near_misses: Vec<NearMissRecord>,
256 pub source: String,
258 pub rule: Option<usize>,
259 pub reason: Option<String>,
260 pub entry_path: EntryPath,
261 pub line: Option<SourceLine>,
262 pub filtered: bool,
264 pub payload_dropped: bool,
266}
267
268#[derive(Debug, Clone)]
269pub struct DecisionLogConfig {
270 pub max_decisions: usize,
272 pub max_context_value_bytes: usize,
274 pub max_recorder_bytes: u64,
277 pub max_line_capture_frames: u64,
291 pub max_calls: usize,
293 pub max_payload_bytes: usize,
296}
297
298impl Default for DecisionLogConfig {
299 fn default() -> Self {
300 Self {
301 max_decisions: 10_000,
302 max_context_value_bytes: 1024,
303 max_recorder_bytes: 16 * 1024 * 1024,
304 max_line_capture_frames: 1_000_000,
305 max_calls: 10_000,
306 max_payload_bytes: 1024 * 1024,
307 }
308 }
309}
310
311#[derive(Debug, Clone, Default)]
313pub struct DecisionLogOutput {
314 pub records: Vec<DecisionRecord>,
315 pub truncated: bool,
319 pub dropped: u64,
321 pub line_frames: u64,
323 pub calls: Vec<CallRecord>,
325 pub calls_dropped: u64,
327}
328
329const MAX_TRACKED_PAIRS: usize = 4096;
332const PAIR_OVERHEAD_BYTES: u64 = 96;
333const RECORD_BASE_BYTES: u64 = std::mem::size_of::<DecisionRecord>() as u64;
334const CALL_BASE_BYTES: u64 = std::mem::size_of::<CallRecord>() as u64;
335const RECORD_RESERVE_DIVISOR: u64 = 4;
340const MAX_CONTEXT_DEPTH: usize = 8;
341const MAX_CONTEXT_ENTRIES: usize = 64;
342
343#[derive(Default)]
344struct PairState {
345 count: u64,
346 last: Option<CallTicket>,
347}
348
349#[derive(Default)]
350struct LogState {
351 records: Vec<DecisionRecord>,
352 pairs: HashMap<(String, String), PairState>,
353 next_call_index: u64,
354 last_call_index: Option<u64>,
355 truncated: bool,
356 dropped: u64,
357 charged: u64,
358 line_frames: u64,
359 lines_exhausted: bool,
361 bytes_exhausted: bool,
364 calls: Vec<CallRecord>,
365 open_calls: Vec<(u64, usize)>,
367 calls_dropped: u64,
368}
369
370pub struct DecisionLog {
372 state: Mutex<LogState>,
373 config: DecisionLogConfig,
374 started: Instant,
375 clock: AtomicU64,
376 observer: Option<Arc<dyn RecordObserver>>,
377}
378
379impl DecisionLog {
380 pub fn install(data: &mut StoreData, config: DecisionLogConfig) -> Arc<Self> {
387 Self::install_observed(data, config, None)
388 }
389
390 pub fn install_observed(
392 data: &mut StoreData,
393 config: DecisionLogConfig,
394 observer: Option<Arc<dyn RecordObserver>>,
395 ) -> Arc<Self> {
396 let log = Self::new(config, observer);
397 data.security_check = log.wrap(data.security_check.clone());
398 log
399 }
400
401 pub fn new(config: DecisionLogConfig, observer: Option<Arc<dyn RecordObserver>>) -> Arc<Self> {
404 Arc::new(Self {
405 state: Mutex::new(LogState::default()),
406 config,
407 started: Instant::now(),
408 clock: AtomicU64::new(0),
409 observer,
410 })
411 }
412
413 pub fn wrap(self: &Arc<Self>, inner: Arc<dyn SecurityCheck>) -> Arc<dyn SecurityCheck> {
416 Arc::new(RecordingCheck {
417 inner,
418 log: self.clone(),
419 })
420 }
421
422 pub fn finish(&self) -> DecisionLogOutput {
426 let mut state = self.lock();
427 let records = std::mem::take(&mut state.records);
428 for (_, position) in std::mem::take(&mut state.open_calls) {
429 if let Some(call) = state.calls.get_mut(position) {
430 call.outcome = Some(CallOutcome::Unfinished);
431 }
432 }
433 let output = DecisionLogOutput {
434 records,
435 truncated: state.truncated,
436 dropped: state.dropped,
437 line_frames: state.line_frames,
438 calls: std::mem::take(&mut state.calls),
439 calls_dropped: state.calls_dropped,
440 };
441 state.charged = 0;
442 state.pairs.clear();
443 output
444 }
445
446 pub fn console_line(&self, text: &str, truncated: bool) {
449 let Some(observer) = &self.observer else {
450 return;
451 };
452 let after_call = self.lock().last_call_index;
453 observer.console_line(&ConsoleLine {
454 text,
455 written_micros: self.now_micros(),
456 after_call,
457 truncated,
458 });
459 }
460
461 fn lock(&self) -> MutexGuard<'_, LogState> {
462 self.state
468 .lock()
469 .unwrap_or_else(std::sync::PoisonError::into_inner)
470 }
471
472 fn now_micros(&self) -> u64 {
473 let elapsed = u64::try_from(self.started.elapsed().as_micros()).unwrap_or(u64::MAX);
474 let previous = self.clock.fetch_max(elapsed, Ordering::Relaxed);
475 previous.max(elapsed)
476 }
477
478 fn charge(&self, state: &mut LogState, bytes: u64) -> bool {
479 self.charge_within(state, bytes, self.config.max_recorder_bytes)
480 }
481
482 fn charge_within(&self, state: &mut LogState, bytes: u64, limit: u64) -> bool {
484 let next = state.charged.saturating_add(bytes);
485 if next > limit {
486 return false;
487 }
488 state.charged = next;
489 true
490 }
491
492 fn payload_limit(&self) -> u64 {
495 let max = self.config.max_recorder_bytes;
496 max.saturating_sub(max / RECORD_RESERVE_DIVISOR)
497 }
498
499 fn can_keep_another(&self, state: &LogState) -> bool {
501 state.records.len() < self.config.max_decisions
502 && state.charged.saturating_add(RECORD_BASE_BYTES) <= self.config.max_recorder_bytes
503 }
504
505 fn begin(
506 &self,
507 state: &mut LogState,
508 caller: &str,
509 capability: &str,
510 line: Option<SourceLine>,
511 ) -> CallTicket {
512 let call_index = state.next_call_index;
513 state.next_call_index = state.next_call_index.saturating_add(1);
514 state.last_call_index = Some(call_index);
515 let key = (caller.to_owned(), capability.to_owned());
516 if !state.pairs.contains_key(&key) {
517 let cost = (caller.len() + capability.len()) as u64 + PAIR_OVERHEAD_BYTES;
518 if state.pairs.len() >= MAX_TRACKED_PAIRS || !self.charge(state, cost) {
519 state.truncated = true;
520 return CallTicket {
521 call_index,
522 seq: 0,
523 at_micros: self.now_micros(),
524 line,
525 };
526 }
527 }
528 let pair = state.pairs.entry(key).or_default();
529 pair.count = pair.count.saturating_add(1);
530 let ticket = CallTicket {
531 call_index,
532 seq: pair.count,
533 at_micros: self.now_micros(),
534 line,
535 };
536 pair.last = Some(ticket);
537 ticket
538 }
539
540 fn record(&self, decision: &AuditDecision<'_>) {
542 let mut state = self.lock();
543 let ticket = match decision.site.ticket {
544 Some(ticket) => ticket,
545 None => self.begin(&mut state, decision.caller, decision.capability, None),
547 };
548 if state.records.len() >= self.config.max_decisions || state.records.try_reserve(1).is_err()
549 {
550 state.truncated = true;
551 state.dropped = state.dropped.saturating_add(1);
552 return;
553 }
554 let mut record = self.build(decision, ticket);
555 let minimal = RECORD_BASE_BYTES
556 + (record.caller.len()
557 + record.capability.len()
558 + record.source.len()
559 + record.reason.as_ref().map_or(0, String::len)) as u64;
560 let payload = payload_bytes(&record);
561 if !self.charge(&mut state, minimal.saturating_add(payload)) {
562 record.context = Value::Null;
564 record.near_misses = Vec::new();
565 record.payload_dropped = true;
566 record.context_truncated = true;
567 state.truncated = true;
568 if !self.charge(&mut state, minimal) {
569 state.bytes_exhausted = true;
570 state.dropped = state.dropped.saturating_add(1);
571 return;
572 }
573 }
574 let observed = self.observer.as_ref().map(|_| record.clone());
575 state.records.push(record);
576 drop(state);
577 if let (Some(observer), Some(record)) = (&self.observer, observed) {
578 observer.decision(&record);
579 }
580 }
581
582 fn open_call(
585 &self,
586 state: &mut LogState,
587 caller: &str,
588 capability: &str,
589 ticket: CallTicket,
590 package_line: Option<PackageLine>,
591 ) -> Option<CallRecord> {
592 let package_bytes = package_line.as_ref().map_or(0, |at| {
593 at.package.len() + at.module.len() + at.function.as_ref().map_or(0, String::len)
594 });
595 let cost = CALL_BASE_BYTES.saturating_add(
596 caller
597 .len()
598 .saturating_add(capability.len())
599 .saturating_add(package_bytes) as u64,
600 );
601 if state.calls.len() >= self.config.max_calls
602 || state.calls.try_reserve(1).is_err()
603 || state.open_calls.try_reserve(1).is_err()
604 || !self.charge(state, cost)
605 {
606 state.truncated = true;
607 state.calls_dropped = state.calls_dropped.saturating_add(1);
608 return None;
609 }
610 let call = CallRecord {
611 call_index: ticket.call_index,
612 caller: caller.to_owned(),
613 capability: capability.to_owned(),
614 started_micros: ticket.at_micros,
615 ended_micros: None,
616 outcome: None,
617 line: ticket.line,
618 package_line,
619 request: None,
620 response: None,
621 usage: None,
622 };
623 let observed = self.observer.as_ref().map(|_| call.clone());
624 state
625 .open_calls
626 .push((ticket.call_index, state.calls.len()));
627 state.calls.push(call);
628 observed
629 }
630
631 fn call_mut(state: &mut LogState, call_index: u64) -> Option<&mut CallRecord> {
632 let position = state
633 .open_calls
634 .iter()
635 .rev()
636 .find(|(index, _)| *index == call_index)
637 .map(|(_, position)| *position)?;
638 state.calls.get_mut(position)
639 }
640
641 fn build(&self, decision: &AuditDecision<'_>, ticket: CallTicket) -> DecisionRecord {
642 let digest = digest_of(decision.context);
643 let (context, mut context_truncated) = if decision.capability == "secrets.get" {
644 let name = decision.context.get("name").cloned().unwrap_or(Value::Null);
646 cap_context(
647 &serde_json::json!({ "name": name }),
648 self.config.max_context_value_bytes,
649 )
650 } else {
651 cap_context(decision.context, self.config.max_context_value_bytes)
652 };
653 let (action, cause, near_misses) = match decision.explanation {
654 Some(explanation) => (
655 enforced_action(decision.allowed, Some(explanation.action)),
656 explanation.cause.clone(),
657 self.capped_near_misses(&explanation.near_misses, &mut context_truncated),
658 ),
659 None => (
660 enforced_action(decision.allowed, None),
661 fallback_cause(decision),
662 Vec::new(),
663 ),
664 };
665 DecisionRecord {
666 call_index: ticket.call_index,
667 seq: ticket.seq,
668 at_micros: ticket.at_micros,
669 caller: decision.caller.to_owned(),
670 capability: decision.capability.to_owned(),
671 context,
672 context_truncated,
673 context_digest: digest,
674 allowed: decision.allowed,
675 action,
676 cause,
677 near_misses,
678 source: decision.source.to_owned(),
679 rule: decision.rule,
680 reason: decision.reason.map(str::to_owned),
681 entry_path: decision.site.entry,
682 line: ticket.line,
683 filtered: false,
684 payload_dropped: false,
685 }
686 }
687
688 fn capped_near_misses(
690 &self,
691 near_misses: &[NearMissRecord],
692 truncated: &mut bool,
693 ) -> Vec<NearMissRecord> {
694 let max = self.config.max_context_value_bytes;
695 near_misses
696 .iter()
697 .map(|miss| NearMissRecord {
698 rule: miss.rule.clone(),
699 filter: miss.filter.clone(),
700 failures: miss
701 .failures
702 .iter()
703 .map(|failure| FailureRecord {
704 actual: failure
705 .actual
706 .as_ref()
707 .map(|actual| cap_value(actual, max, 0, truncated)),
708 ..failure.clone()
709 })
710 .collect(),
711 })
712 .collect()
713 }
714}
715
716impl DecisionRecorder for DecisionLog {
717 fn begin_call(&self, caller: &str, capability: &str, origin: CallOrigin) -> CallTicket {
718 let mut state = self.lock();
719 let ticket = self.begin(&mut state, caller, capability, origin.line);
720 let opened = self.open_call(&mut state, caller, capability, ticket, origin.package);
721 drop(state);
722 if let (Some(observer), Some(call)) = (&self.observer, opened) {
723 observer.call_started(&call);
724 }
725 ticket
726 }
727
728 fn enter_host_call(&self) -> u64 {
729 self.lock().next_call_index
730 }
731
732 fn exit_host_call(&self, marker: u64, returned: bool) {
733 let mut state = self.lock();
734 let Some(first) = state
735 .open_calls
736 .iter()
737 .position(|(index, _)| *index >= marker)
738 else {
739 return;
740 };
741 let ended = self.now_micros();
742 let closing: Vec<_> = state.open_calls.drain(first..).collect();
743 let mut finished = Vec::new();
744 for (_, position) in closing {
745 if let Some(call) = state.calls.get_mut(position) {
746 call.ended_micros = Some(ended);
747 call.outcome = Some(if returned {
748 CallOutcome::Returned
749 } else {
750 CallOutcome::Failed
751 });
752 if self.observer.is_some() {
753 finished.push(call.without_bodies());
755 }
756 }
757 }
758 drop(state);
759 if let Some(observer) = &self.observer {
760 for call in &finished {
761 observer.call_finished(call);
762 }
763 }
764 }
765
766 fn wants_payload(&self, call_index: u64) -> bool {
767 let mut state = self.lock();
768 Self::call_mut(&mut state, call_index).is_some()
771 && state.charged.saturating_add(call_log::DIGEST_ONLY_COST)
772 <= self.config.max_recorder_bytes
773 }
774
775 fn call_payload(&self, call_index: u64, side: Side, payload: Payload<'_>) {
776 let room = {
777 let mut state = self.lock();
778 if Self::call_mut(&mut state, call_index).is_none() {
781 return;
782 }
783 self.payload_limit().saturating_sub(state.charged)
784 };
785 let record = call_log::capture(
786 &payload,
787 self.config.max_context_value_bytes,
788 room,
789 self.config.max_payload_bytes,
790 );
791 let mut state = self.lock();
792 if Self::call_mut(&mut state, call_index).is_none() {
794 return;
795 }
796 let cost = call_log::payload_cost(&record);
797 let record = if self.charge_within(&mut state, cost, self.payload_limit()) {
798 record
799 } else {
800 state.truncated = true;
802 let mut kept = record.digest_only();
803 kept.truncated = true;
804 if !self.charge(&mut state, call_log::payload_cost(&kept)) {
805 return;
806 }
807 kept
808 };
809 let Some(call) = Self::call_mut(&mut state, call_index) else {
810 return;
811 };
812 match side {
813 Side::Request => call.request = Some(Box::new(record)),
814 Side::Response => call.response = Some(Box::new(record)),
815 }
816 }
817
818 fn call_usage(&self, call_index: u64, usage: ModelUsage) {
819 let mut state = self.lock();
820 if let Some(call) = Self::call_mut(&mut state, call_index) {
821 call.usage = Some(usage);
822 }
823 }
824
825 fn wants_line(&self) -> bool {
826 let state = self.lock();
827 !state.lines_exhausted && !state.bytes_exhausted && self.can_keep_another(&state)
828 }
829
830 fn note_line_capture(&self, frames: usize) {
831 let mut state = self.lock();
832 state.line_frames = state.line_frames.saturating_add(frames as u64);
833 if state.line_frames > self.config.max_line_capture_frames {
834 state.lines_exhausted = true;
835 state.truncated = true;
836 }
837 }
838
839 fn mark_last_filtered(&self) {
840 let mut state = self.lock();
841 let Some(last) = state.last_call_index else {
842 return;
843 };
844 if let Some(record) = state
845 .records
846 .iter_mut()
847 .rev()
848 .find(|record| record.call_index == last)
849 {
850 record.filtered = true;
851 }
852 }
853}
854
855fn enforced_action(allowed: bool, explained: Option<DecisionAction>) -> DecisionAction {
858 match (allowed, explained) {
859 (_, Some(asked @ (DecisionAction::AskHuman | DecisionAction::AskAdmin))) => asked,
860 (true, _) => DecisionAction::Allow,
861 (false, _) => DecisionAction::Deny,
862 }
863}
864
865fn fallback_cause(decision: &AuditDecision<'_>) -> DecisionCause {
866 if matches!(decision.source, "policy" | "human" | "admin") {
867 return DecisionCause::Unexplained;
868 }
869 DecisionCause::RuntimeInvariant {
870 reason: decision.reason.unwrap_or_default().to_owned(),
871 }
872}
873
874fn digest_of(context: &Value) -> u64 {
875 use std::hash::{Hash, Hasher};
876 let Ok(text) = serde_json::to_string(context) else {
877 return 0;
878 };
879 let mut hasher = std::collections::hash_map::DefaultHasher::new();
881 text.hash(&mut hasher);
882 hasher.finish()
883}
884
885fn payload_bytes(record: &DecisionRecord) -> u64 {
886 let context = serde_json::to_string(&record.context).map_or(0, |text| text.len());
887 let misses = serde_json::to_string(&record.near_misses).map_or(0, |text| text.len());
888 (context.saturating_add(misses) as u64).saturating_mul(2)
890}
891
892pub(crate) fn cap_context(context: &Value, max_string_bytes: usize) -> (Value, bool) {
895 let mut truncated = false;
896 let capped = cap_value(context, max_string_bytes, 0, &mut truncated);
897 (capped, truncated)
898}
899
900fn cap_value(value: &Value, max_string: usize, depth: usize, truncated: &mut bool) -> Value {
901 match value {
902 Value::String(text) => Value::String(cap_text(text, max_string, truncated)),
903 Value::Array(_) | Value::Object(_) if depth >= MAX_CONTEXT_DEPTH => {
904 *truncated = true;
905 Value::String("…[truncated, nested too deep]".to_owned())
906 }
907 Value::Array(items) => {
908 if items.len() > MAX_CONTEXT_ENTRIES {
909 *truncated = true;
910 }
911 Value::Array(
912 items
913 .iter()
914 .take(MAX_CONTEXT_ENTRIES)
915 .map(|item| cap_value(item, max_string, depth + 1, truncated))
916 .collect(),
917 )
918 }
919 Value::Object(fields) => {
920 if fields.len() > MAX_CONTEXT_ENTRIES {
921 *truncated = true;
922 }
923 Value::Object(
924 fields
925 .iter()
926 .take(MAX_CONTEXT_ENTRIES)
927 .enumerate()
928 .map(|(position, (key, item))| {
929 (
930 capped_key(key, position, max_string, truncated),
931 cap_value(item, max_string, depth + 1, truncated),
932 )
933 })
934 .collect(),
935 )
936 }
937 other => other.clone(),
938 }
939}
940
941fn capped_key(key: &str, position: usize, max: usize, truncated: &mut bool) -> String {
944 let capped = cap_text(key, max, truncated);
945 if capped.len() == key.len() {
946 return capped;
947 }
948 format!("{capped} #{position}")
949}
950
951pub(crate) fn cap_text(text: &str, max: usize, truncated: &mut bool) -> String {
953 if text.len() <= max {
954 return text.to_owned();
955 }
956 *truncated = true;
957 let mut end = max;
958 while end > 0 && !text.is_char_boundary(end) {
959 end -= 1;
960 }
961 let kept = text.get(..end).unwrap_or_default();
962 format!(
963 "{kept}…[truncated, {} of {} bytes kept]",
964 kept.len(),
965 text.len()
966 )
967}
968
969struct RecordingCheck {
970 inner: Arc<dyn SecurityCheck>,
971 log: Arc<DecisionLog>,
972}
973
974impl SecurityCheck for RecordingCheck {
975 fn audit(&self, decision: AuditDecision<'_>) {
976 self.inner.audit(decision);
977 self.log.record(&decision);
978 }
979
980 fn audit_context<'a>(
981 &self,
982 capability: &str,
983 context: &'a Value,
984 cwd: &str,
985 ) -> std::borrow::Cow<'a, Value> {
986 self.inner.audit_context(capability, context, cwd)
987 }
988
989 fn check_with_cwd(
990 &self,
991 caller: &str,
992 capability: &str,
993 context: &Value,
994 cwd: &str,
995 ) -> CheckOutcome {
996 self.inner.check_with_cwd(caller, capability, context, cwd)
997 }
998
999 fn check(&self, caller: &str, capability: &str, context: &Value) -> CheckOutcome {
1000 self.inner.check(caller, capability, context)
1001 }
1002
1003 fn recorder(&self) -> Option<&dyn DecisionRecorder> {
1004 Some(self.log.as_ref())
1005 }
1006
1007 fn explain(
1008 &self,
1009 caller: &str,
1010 capability: &str,
1011 context: &Value,
1012 cwd: &str,
1013 ) -> Option<DecisionExplanation> {
1014 self.inner.explain(caller, capability, context, cwd)
1015 }
1016}
1017
1018#[cfg(test)]
1019mod tests {
1020 use super::*;
1021 use crate::runtime::Vfs;
1022
1023 fn log_with(config: DecisionLogConfig) -> (StoreData, Arc<DecisionLog>) {
1024 let mut data = StoreData::with_vfs_and_cap("test-run".into(), Vfs::none(), 1 << 20);
1025 let log = DecisionLog::install(&mut data, config);
1026 (data, log)
1027 }
1028
1029 fn audit_denied(data: &StoreData, ticket: CallTicket) {
1030 let context = serde_json::json!({});
1031 data.security_check.audit(
1032 AuditDecision::new("main", "fs.read", &context, false, "policy", None, None)
1033 .with_site(CallSite::new(Some(ticket), EntryPath::GatedOp)),
1034 );
1035 }
1036
1037 #[test]
1038 fn a_call_still_open_at_finish_is_unfinished() {
1039 let (data, log) = log_with(DecisionLogConfig::default());
1040 let recorder = data.security_check.recorder().unwrap();
1041 recorder.enter_host_call();
1042 recorder.begin_call("main", "http.get", CallOrigin::default());
1043 let output = log.finish();
1044 let [call] = output.calls.as_slice() else {
1045 panic!("one call: {output:?}");
1046 };
1047 assert_eq!(call.outcome, Some(CallOutcome::Unfinished));
1048 assert_eq!(call.ended_micros, None);
1049 }
1050
1051 #[test]
1052 fn payload_copies_leave_the_decision_reserve_free() {
1053 let max = 64 * 1024;
1054 let (data, log) = log_with(DecisionLogConfig {
1055 max_recorder_bytes: max,
1056 ..DecisionLogConfig::default()
1057 });
1058 let recorder = data.security_check.recorder().unwrap();
1059 let body = vec![b'x'; 20 * 1024];
1060 for _ in 0..6 {
1061 let ticket = recorder.begin_call("main", "http.get", CallOrigin::default());
1062 recorder.call_payload(
1063 ticket.call_index,
1064 Side::Response,
1065 Payload::meta(serde_json::Value::Null).with_body(&body),
1066 );
1067 }
1068 assert!(
1069 log.lock().charged <= max - max / RECORD_RESERVE_DIVISOR + 6 * 256,
1070 "bodies stay out of the reserve; only digests may enter it"
1071 );
1072 let output = log.finish();
1073 let responses: Vec<_> = output
1074 .calls
1075 .iter()
1076 .filter_map(|call| call.response.as_deref())
1077 .collect();
1078 assert_eq!(responses.len(), 6, "every payload keeps a record");
1079 assert!(responses.iter().any(|payload| payload.body.is_some()));
1080 let cut = responses
1081 .iter()
1082 .find(|payload| payload.body.is_none())
1083 .expect("a payload past the reserve keeps no body");
1084 assert!(cut.truncated && cut.bytes == body.len() as u64 && !cut.digest.is_empty());
1085 assert!(output.truncated);
1086 }
1087
1088 #[test]
1089 fn digest_only_records_do_not_spend_the_reserve_on_masked_names() {
1090 let max = 64 * 1024;
1091 let (data, log) = log_with(DecisionLogConfig {
1092 max_recorder_bytes: max,
1093 ..DecisionLogConfig::default()
1094 });
1095 let recorder = data.security_check.recorder().unwrap();
1096 let body = vec![b'x'; 20 * 1024];
1097 for _ in 0..6 {
1098 let ticket = recorder.begin_call("main", "http.get", CallOrigin::default());
1099 recorder.call_payload(
1100 ticket.call_index,
1101 Side::Response,
1102 Payload::meta(serde_json::Value::Null).with_body(&body),
1103 );
1104 }
1105 let before = log.lock().charged;
1106 let names: Vec<String> = (0..64)
1107 .map(|i| format!("x-token-{i}-{}", "n".repeat(900)))
1108 .collect();
1109 let ticket = recorder.begin_call("main", "http.get", CallOrigin::default());
1110 recorder.call_payload(
1111 ticket.call_index,
1112 Side::Response,
1113 Payload::meta(serde_json::Value::Null)
1114 .with_body(&body)
1115 .with_masked(names),
1116 );
1117 let spent = log.lock().charged - before;
1118 assert!(
1119 spent < 512,
1120 "a payload past the limit enters the reserve as a digest and a size: {spent}"
1121 );
1122 audit_denied(
1123 &data,
1124 recorder.begin_call("main", "fs.read", CallOrigin::default()),
1125 );
1126 let output = log.finish();
1127 assert_eq!(output.records.len(), 1, "a later denial is still recorded");
1128 let last = output
1129 .calls
1130 .iter()
1131 .rev()
1132 .find_map(|call| call.response.as_deref());
1133 assert!(last.is_some_and(|payload| payload.masked_headers.is_empty()));
1134 }
1135
1136 #[test]
1137 fn a_body_is_sized_to_the_room_its_record_leaves() {
1138 let max = 16 * 1024;
1139 let (data, log) = log_with(DecisionLogConfig {
1140 max_recorder_bytes: max,
1141 ..DecisionLogConfig::default()
1142 });
1143 let recorder = data.security_check.recorder().unwrap();
1144 let body = vec![b'x'; 64 * 1024];
1145 let meta = serde_json::json!({ "url": "https://x.test/" });
1146 let ticket = recorder.begin_call("main", "http.get", CallOrigin::default());
1147 recorder.call_payload(
1148 ticket.call_index,
1149 Side::Response,
1150 Payload::meta(meta.clone()).with_body(&body),
1151 );
1152 let charged = log.lock().charged;
1153 assert!(
1154 charged <= log.payload_limit(),
1155 "the copy fits what it is charged"
1156 );
1157 let output = log.finish();
1158 let payload = output.calls[0]
1159 .response
1160 .as_deref()
1161 .expect("a response record");
1162 let kept = match &payload.body {
1163 Some(call_log::BodyCopy::Text(text)) => text.len(),
1164 other => panic!("a cut text body is kept as text: {other:?}"),
1165 };
1166 assert!(payload.truncated && kept > 0 && kept < body.len());
1167 assert_eq!(payload.bytes, body.len() as u64);
1168 let (data, log) = log_with(DecisionLogConfig {
1170 max_recorder_bytes: max,
1171 ..DecisionLogConfig::default()
1172 });
1173 let recorder = data.security_check.recorder().unwrap();
1174 let binary = vec![0xffu8; 64 * 1024];
1175 let ticket = recorder.begin_call("main", "http.get", CallOrigin::default());
1176 recorder.call_payload(
1177 ticket.call_index,
1178 Side::Response,
1179 Payload::meta(meta).with_body(&binary),
1180 );
1181 let output = log.finish();
1182 let payload = output.calls[0]
1183 .response
1184 .as_deref()
1185 .expect("a response record");
1186 let Some(call_log::BodyCopy::Base64(text)) = &payload.body else {
1187 panic!("a binary body is kept as base64: {payload:?}");
1188 };
1189 assert!(payload.truncated);
1190 assert!(text.len() as u64 <= max - max / RECORD_RESERVE_DIVISOR);
1191 }
1192
1193 #[test]
1194 fn a_payload_is_wanted_exactly_while_its_digest_only_record_fits() {
1195 let max = 4096;
1196 let (data, log) = log_with(DecisionLogConfig {
1197 max_recorder_bytes: max,
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", CallOrigin::default());
1203 log.lock().charged = max - call_log::DIGEST_ONLY_COST;
1204 assert!(recorder.wants_payload(ticket.call_index));
1205 log.lock().charged = max - call_log::DIGEST_ONLY_COST + 1;
1206 assert!(!recorder.wants_payload(ticket.call_index));
1207 }
1208
1209 #[test]
1210 fn a_body_with_no_room_is_not_copied() {
1211 let (data, log) = log_with(DecisionLogConfig {
1212 max_recorder_bytes: 1024,
1213 ..DecisionLogConfig::default()
1214 });
1215 let recorder = data.security_check.recorder().unwrap();
1216 let ticket = recorder.begin_call("main", "http.get", CallOrigin::default());
1217 let meta = serde_json::json!({ "url": "u".repeat(400) });
1218 recorder.call_payload(
1219 ticket.call_index,
1220 Side::Response,
1221 Payload::meta(meta).with_body(&[b'x'; 4096]),
1222 );
1223 let output = log.finish();
1224 let payload = output.calls[0]
1225 .response
1226 .as_deref()
1227 .expect("a response record");
1228 assert!(payload.body.is_none() && payload.truncated);
1229 assert_eq!(payload.bytes, 4096);
1230 }
1231
1232 #[test]
1233 fn a_payload_is_wanted_while_its_call_is_open_and_the_budget_lasts() {
1234 let (data, _log) = log_with(DecisionLogConfig {
1235 max_recorder_bytes: 4096,
1236 ..DecisionLogConfig::default()
1237 });
1238 let recorder = data.security_check.recorder().unwrap();
1239 recorder.enter_host_call();
1240 let ticket = recorder.begin_call("main", "http.get", CallOrigin::default());
1241 assert!(recorder.wants_payload(ticket.call_index));
1242 assert!(
1243 !recorder.wants_payload(ticket.call_index + 1),
1244 "no such call"
1245 );
1246 recorder.exit_host_call(0, true);
1247 assert!(!recorder.wants_payload(ticket.call_index), "the call ended");
1248 }
1249
1250 #[test]
1251 fn a_full_log_stops_asking_for_lines() {
1252 let (data, log) = log_with(DecisionLogConfig {
1253 max_decisions: 2,
1254 ..DecisionLogConfig::default()
1255 });
1256 let recorder = data.security_check.recorder().unwrap();
1257 for _ in 0..2 {
1258 assert!(recorder.wants_line());
1259 audit_denied(
1260 &data,
1261 recorder.begin_call("main", "fs.read", CallOrigin::default()),
1262 );
1263 }
1264 assert!(!recorder.wants_line(), "the cap is reached");
1265 audit_denied(
1266 &data,
1267 recorder.begin_call("main", "fs.read", CallOrigin::default()),
1268 );
1269 assert!(!recorder.wants_line(), "still off once the log is full");
1270 assert!(log.finish().truncated);
1271 }
1272
1273 #[test]
1274 fn a_byte_budget_payload_drop_keeps_asking_for_lines() {
1275 let (data, log) = log_with(DecisionLogConfig {
1276 max_recorder_bytes: 4 * RECORD_BASE_BYTES,
1277 ..DecisionLogConfig::default()
1278 });
1279 let recorder = data.security_check.recorder().unwrap();
1280 let context = serde_json::json!({ "path": "p".repeat(900) });
1281 let ticket = recorder.begin_call("main", "fs.read", CallOrigin::default());
1282 data.security_check.audit(
1283 AuditDecision::new("main", "fs.read", &context, true, "policy", None, None)
1284 .with_site(CallSite::new(Some(ticket), EntryPath::GatedOp)),
1285 );
1286 assert!(recorder.wants_line(), "a minimal record still fits");
1287 let output = log.finish();
1288 assert!(output.truncated);
1289 assert!(output.records.iter().any(|r| r.payload_dropped));
1290 }
1291
1292 #[test]
1293 fn filling_the_pair_cap_keeps_asking_for_lines() {
1294 let (data, log) = log_with(DecisionLogConfig::default());
1295 let recorder = data.security_check.recorder().unwrap();
1296 for index in 0..=MAX_TRACKED_PAIRS {
1297 recorder.begin_call("main", &format!("cap.{index}"), CallOrigin::default());
1298 }
1299 assert!(recorder.wants_line());
1300 assert!(log.finish().truncated, "the pair cap truncates");
1301 }
1302
1303 #[test]
1304 fn lines_stop_once_the_byte_budget_cannot_fit_a_record() {
1305 let (data, log) = log_with(DecisionLogConfig {
1306 max_recorder_bytes: 3 * RECORD_BASE_BYTES,
1307 ..DecisionLogConfig::default()
1308 });
1309 let recorder = data.security_check.recorder().unwrap();
1310 let mut captures = 0;
1311 for _ in 0..20 {
1312 if recorder.wants_line() {
1313 captures += 1;
1314 recorder.note_line_capture(5);
1315 }
1316 audit_denied(
1317 &data,
1318 recorder.begin_call("main", "fs.read", CallOrigin::default()),
1319 );
1320 }
1321 let output = log.finish();
1322 assert!(output.dropped > 0, "records were dropped whole");
1323 assert!(
1324 captures < 20 && output.line_frames == 5 * captures,
1325 "capture stopped: {captures} captures"
1326 );
1327 assert!(
1328 captures <= output.records.len() as u64 + 1,
1329 "no captures beyond the first dropped record: {captures} for {} kept",
1330 output.records.len()
1331 );
1332 }
1333
1334 #[test]
1335 fn a_budget_below_one_bare_record_wants_no_line() {
1336 for max_recorder_bytes in [0, RECORD_BASE_BYTES - 1] {
1337 let (data, _log) = log_with(DecisionLogConfig {
1338 max_recorder_bytes,
1339 ..DecisionLogConfig::default()
1340 });
1341 let recorder = data.security_check.recorder().unwrap();
1342 assert!(!recorder.wants_line(), "budget {max_recorder_bytes}");
1343 }
1344 }
1345
1346 #[test]
1347 fn a_whole_record_drop_stops_lines_though_a_bare_record_would_fit() {
1348 let (data, log) = log_with(DecisionLogConfig {
1349 max_recorder_bytes: PAIR_OVERHEAD_BYTES
1352 + "main".len() as u64
1353 + "fs.read".len() as u64
1354 + RECORD_BASE_BYTES
1355 + 2,
1356 max_calls: 0,
1357 ..DecisionLogConfig::default()
1358 });
1359 let recorder = data.security_check.recorder().unwrap();
1360 assert!(recorder.wants_line(), "a bare record fits before any call");
1361 let ticket = recorder.begin_call("main", "fs.read", CallOrigin::default());
1362 assert!(
1363 recorder.wants_line(),
1364 "a bare record still fits after the call"
1365 );
1366 audit_denied(&data, ticket);
1367 assert!(!recorder.wants_line(), "the drop turns lines off");
1368 let output = log.finish();
1369 assert_eq!(output.dropped, 1);
1370 assert!(output.records.is_empty());
1371 }
1372
1373 #[test]
1374 fn the_line_capture_frame_budget_truncates_the_log_once_exceeded() {
1375 let (data, log) = log_with(DecisionLogConfig {
1376 max_line_capture_frames: 10,
1377 ..DecisionLogConfig::default()
1378 });
1379 let recorder = data.security_check.recorder().unwrap();
1380 recorder.note_line_capture(10);
1381 assert!(recorder.wants_line(), "at the budget is still within it");
1382 recorder.note_line_capture(1);
1383 assert!(!recorder.wants_line());
1384 assert!(log.finish().truncated);
1385 }
1386
1387 #[test]
1388 fn a_secret_read_keeps_the_key_name_and_nothing_else() {
1389 let (data, log) = log_with(DecisionLogConfig::default());
1390 let context = serde_json::json!({ "name": "api-key", "value": "s3cret" });
1391 data.security_check.audit(AuditDecision::new(
1392 "main",
1393 "secrets.get",
1394 &context,
1395 false,
1396 "invariant",
1397 None,
1398 Some("refused"),
1399 ));
1400 let output = log.finish();
1401 let [record] = output.records.as_slice() else {
1402 panic!("one record");
1403 };
1404 assert_eq!(record.context, serde_json::json!({ "name": "api-key" }));
1405 assert!(!format!("{record:?}").contains("s3cret"));
1406 }
1407
1408 #[test]
1409 fn an_exhausted_recorder_budget_keeps_the_verdict_and_drops_the_payload() {
1410 let (data, log) = log_with(DecisionLogConfig {
1412 max_recorder_bytes: 2048,
1413 ..DecisionLogConfig::default()
1414 });
1415 let context = serde_json::json!({ "path": "p".repeat(900) });
1416 let recorder = data.security_check.recorder().unwrap();
1417 let ticket = recorder.begin_call("main", "fs.read", CallOrigin::default());
1418 data.security_check.audit(
1419 AuditDecision::new("main", "fs.read", &context, true, "policy", None, None)
1420 .with_site(CallSite::new(Some(ticket), EntryPath::GatedOp)),
1421 );
1422 let output = log.finish();
1423 assert!(output.truncated);
1424 let [record] = output.records.as_slice() else {
1425 panic!("the verdict is kept: {output:?}");
1426 };
1427 assert!(record.allowed && record.payload_dropped);
1428 assert_eq!(record.context, serde_json::Value::Null);
1429 assert_ne!(record.context_digest, 0, "the digest survives");
1430 assert_eq!(
1431 data.tenant_limits.host_attached_bytes(),
1432 0,
1433 "the run's memory budget is not touched"
1434 );
1435 }
1436
1437 #[test]
1438 fn caps_mark_long_strings_deep_nesting_and_wide_containers() {
1439 let long = serde_json::json!({ "a": "é".repeat(100) });
1440 let (capped, truncated) = cap_context(&long, 11);
1441 assert!(truncated);
1442 let text = capped["a"].as_str().unwrap();
1443 assert!(
1444 text.starts_with("éééé") && text.contains("truncated"),
1445 "{text}"
1446 );
1447
1448 let mut nested = serde_json::json!(1);
1449 for _ in 0..20 {
1450 nested = serde_json::json!([nested]);
1451 }
1452 assert!(cap_context(&nested, 100).1);
1453
1454 let wide = Value::Array((0..200).map(Value::from).collect());
1455 let (capped, truncated) = cap_context(&wide, 100);
1456 assert!(truncated);
1457 assert_eq!(capped.as_array().unwrap().len(), MAX_CONTEXT_ENTRIES);
1458
1459 let small = serde_json::json!({ "host": "x", "n": [1, 2] });
1460 assert_eq!(cap_context(&small, 100), (small.clone(), false));
1461 }
1462
1463 #[test]
1464 fn finish_refunds_the_recorders_budget() {
1465 let (data, log) = log_with(DecisionLogConfig {
1466 max_recorder_bytes: 4096,
1467 ..DecisionLogConfig::default()
1468 });
1469 let context = serde_json::json!({ "path": "p".repeat(300) });
1470 for _ in 0..2 {
1471 data.security_check.audit(AuditDecision::new(
1472 "main", "fs.read", &context, true, "policy", None, None,
1473 ));
1474 let output = log.finish();
1475 assert!(!output.truncated && output.records.len() == 1, "{output:?}");
1476 }
1477 assert_eq!(data.tenant_limits.host_attached_bytes(), 0);
1478 }
1479
1480 #[test]
1481 fn long_keys_sharing_a_prefix_both_survive_capping() {
1482 let long = "k".repeat(100);
1483 let value = serde_json::json!({ format!("{long}a"): 1, format!("{long}b"): 2 });
1484 let mut truncated = false;
1485 let Value::Object(capped) = cap_value(&value, 16, 0, &mut truncated) else {
1486 panic!("expected an object");
1487 };
1488 assert!(truncated);
1489 assert_eq!(capped.len(), 2, "{capped:?}");
1490 let mut values: Vec<_> = capped.values().cloned().collect();
1491 values.sort_by_key(Value::as_i64);
1492 assert_eq!(values, vec![serde_json::json!(1), serde_json::json!(2)]);
1493 }
1494
1495 #[test]
1496 fn near_miss_actual_values_and_keys_are_capped_like_the_context() {
1497 let (data, log) = log_with(DecisionLogConfig {
1498 max_context_value_bytes: 16,
1499 ..DecisionLogConfig::default()
1500 });
1501 let explanation = DecisionExplanation {
1502 action: DecisionAction::Deny,
1503 cause: DecisionCause::Default { caller_block: true },
1504 near_misses: vec![NearMissRecord {
1505 rule: RuleCitation {
1506 caller: "main".into(),
1507 index: 0,
1508 name: None,
1509 },
1510 filter: "f".into(),
1511 failures: vec![FailureRecord {
1512 comparison: "c".into(),
1513 actual: Some(serde_json::json!({ "k".repeat(100): "v".repeat(100) })),
1514 expected: None,
1515 reason: FailureReasonRecord::NotSatisfied,
1516 negated: false,
1517 }],
1518 }],
1519 };
1520 let context = serde_json::json!({});
1521 data.security_check.audit(
1522 AuditDecision::new("main", "fs.read", &context, false, "policy", None, None)
1523 .with_explanation(Some(&explanation)),
1524 );
1525 let output = log.finish();
1526 let [record] = output.records.as_slice() else {
1527 panic!("one record");
1528 };
1529 assert!(record.context_truncated);
1530 let actual = record.near_misses[0].failures[0].actual.as_ref().unwrap();
1531 assert!(
1532 serde_json::to_string(actual).unwrap().len() < 150,
1533 "{actual}"
1534 );
1535 }
1536}