1pub mod harness_adapt;
7pub mod harness_metrics;
8pub mod observability;
9pub mod tool_receipts;
10
11pub use observability::{
12 evaluate_alerts, summarize, summarize_log, Alert, AlertKind, AlertThresholds, MetricsSummary,
13};
14
15use car_secrets::{
16 atomic_replace_private_file, create_private_file, open_private_append, revalidate_private_file,
17 revalidate_private_path,
18};
19use chrono::{DateTime, Utc};
20use serde::{Deserialize, Serialize};
21use serde_json::Value;
22use std::collections::{HashMap, HashSet, VecDeque};
23use std::fs;
24use std::future::Future;
25use std::io::{BufRead, BufReader, BufWriter, Read, Seek, SeekFrom, Write};
26use std::path::{Path, PathBuf};
27use std::pin::Pin;
28use std::sync::{mpsc, Arc, Condvar, Mutex, Weak};
29use std::task::{Context, Poll, Waker};
30use std::thread;
31use std::time::{Duration, Instant};
32use uuid::Uuid;
33
34#[derive(Debug, Clone, Copy, PartialEq, Eq, Serialize, Deserialize)]
35#[serde(rename_all = "camelCase")]
36pub struct EventLogStats {
37 pub events: usize,
38 pub spans: usize,
39 pub approx_event_bytes: usize,
40 pub approx_span_bytes: usize,
41}
42
43#[derive(Debug, Clone, PartialEq, Eq, Hash, Serialize, Deserialize, schemars::JsonSchema)]
45#[serde(rename_all = "snake_case")]
46pub enum EventKind {
47 RunStarted,
49 RunCancellationRequested,
51 RunCancellationResult,
53 ProposalReceived,
54 ProposalCompleted,
57 ActionValidated,
58 ActionRejected,
59 ActionExecuting,
60 ActionSucceeded,
61 ActionFailed,
62 ActionSkipped,
63 ActionRetrying,
64 ActionDeduplicated,
65 PolicyViolation,
66 StateChanged,
67 StateSnapshot,
68 StateCommitted,
72 StateRollback,
73 SkillDistilled,
75 SkillEvolved,
76 SkillDeprecated,
77 EvolutionTriggered,
78 CandidatePromoted,
82 CandidateRejected,
85 Consolidated,
87 ProactiveMemoryMaintained,
92 ProactiveMemoryIntervention,
93 ReplanAttempted,
95 ReplanProposalReceived,
96 ReplanRejected,
97 ReplanExhausted,
98 VoiceFastTurnStarted,
102 VoiceFastTurnEnded,
103 VoiceSidecarResolved,
104 VoiceSidecarFailed,
105 VoiceSidecarTimedOut,
106 VoiceTurnCancelled,
107 VoiceBridgePlayed,
108 GateAccepted,
114 GateRejected,
115 ModelFallback,
142 SessionScope,
149 PermissionDecision,
166 ApprovalRecorded,
172 BranchDecision,
179 AlternativeRejected,
185 InferenceMetered,
190 ModelCallRefused,
198 TransactionConflict,
205 AdmissionGateDecision,
215 ToolReceiptHallucination,
221 GoalEvaluated,
228 TurnCompleted,
236 RunCompleted,
239 WorkerStarted,
246 WorkerStartsOmitted,
250}
251
252#[derive(Debug, Clone, Serialize, Deserialize, PartialEq)]
254#[serde(rename_all = "snake_case")]
255pub enum SpanStatus {
256 Ok,
257 Error,
258 Unset,
259}
260
261#[derive(Debug, Clone, Serialize, Deserialize)]
263pub struct Span {
264 pub trace_id: String,
265 pub span_id: String,
266 pub parent_span_id: Option<String>,
267 pub name: String,
268 pub start_time: DateTime<Utc>,
269 pub end_time: Option<DateTime<Utc>>,
270 pub status: SpanStatus,
271 pub attributes: HashMap<String, Value>,
272}
273
274pub mod metric_keys {
279 pub const DURATION_MS: &str = "duration_ms";
281 pub const TOKENS_IN: &str = "tokens_in";
283 pub const TOKENS_OUT: &str = "tokens_out";
285 pub const COST_USD: &str = "cost_usd";
287}
288
289#[derive(Debug, Clone, Copy, Default, PartialEq, Serialize, Deserialize)]
295pub struct Metrics {
296 #[serde(default, skip_serializing_if = "Option::is_none")]
297 pub duration_ms: Option<f64>,
298 #[serde(default, skip_serializing_if = "Option::is_none")]
299 pub tokens_in: Option<u64>,
300 #[serde(default, skip_serializing_if = "Option::is_none")]
301 pub tokens_out: Option<u64>,
302 #[serde(default, skip_serializing_if = "Option::is_none")]
303 pub cost_usd: Option<f64>,
304}
305
306impl Metrics {
307 pub fn latency(duration_ms: f64) -> Self {
309 Self {
310 duration_ms: Some(duration_ms),
311 ..Default::default()
312 }
313 }
314
315 pub fn inference(tokens_in: u64, tokens_out: u64, cost_usd: Option<f64>) -> Self {
317 Self {
318 duration_ms: None,
319 tokens_in: Some(tokens_in),
320 tokens_out: Some(tokens_out),
321 cost_usd,
322 }
323 }
324
325 pub fn with_duration(mut self, duration_ms: f64) -> Self {
326 self.duration_ms = Some(duration_ms);
327 self
328 }
329
330 fn merge_into(&self, data: &mut HashMap<String, Value>) {
332 if let Some(d) = self.duration_ms {
333 data.insert(metric_keys::DURATION_MS.into(), Value::from(d));
334 }
335 if let Some(t) = self.tokens_in {
336 data.insert(metric_keys::TOKENS_IN.into(), Value::from(t));
337 }
338 if let Some(t) = self.tokens_out {
339 data.insert(metric_keys::TOKENS_OUT.into(), Value::from(t));
340 }
341 if let Some(c) = self.cost_usd {
342 data.insert(metric_keys::COST_USD.into(), Value::from(c));
343 }
344 }
345}
346
347#[derive(Debug, Clone, PartialEq, Serialize, Deserialize, schemars::JsonSchema)]
349pub struct Event {
350 pub kind: EventKind,
351 #[serde(default, skip_serializing_if = "Option::is_none")]
354 pub run_id: Option<String>,
355 #[serde(default, skip_serializing_if = "Option::is_none")]
358 pub client_id: Option<String>,
359 #[serde(default, skip_serializing_if = "Option::is_none")]
363 pub policy_session_id: Option<String>,
364 #[serde(default, skip_serializing_if = "Option::is_none")]
365 pub action_id: Option<String>,
366 #[serde(default, skip_serializing_if = "Option::is_none")]
367 pub proposal_id: Option<String>,
368 #[serde(default)]
369 pub data: HashMap<String, Value>,
370 #[serde(default = "Utc::now")]
371 pub timestamp: DateTime<Utc>,
372 #[serde(default, skip_serializing_if = "Option::is_none")]
377 pub prev_hash: Option<String>,
378 #[serde(default, skip_serializing_if = "Option::is_none")]
381 pub hash: Option<String>,
382}
383
384impl Event {
385 pub fn duration_ms(&self) -> Option<f64> {
387 self.data
388 .get(metric_keys::DURATION_MS)
389 .and_then(Value::as_f64)
390 }
391
392 pub fn tokens_in(&self) -> Option<u64> {
394 self.data
395 .get(metric_keys::TOKENS_IN)
396 .and_then(Value::as_u64)
397 }
398
399 pub fn tokens_out(&self) -> Option<u64> {
401 self.data
402 .get(metric_keys::TOKENS_OUT)
403 .and_then(Value::as_u64)
404 }
405
406 pub fn cost_usd(&self) -> Option<f64> {
408 self.data.get(metric_keys::COST_USD).and_then(Value::as_f64)
409 }
410
411 pub fn metrics(&self) -> Metrics {
413 Metrics {
414 duration_ms: self.duration_ms(),
415 tokens_in: self.tokens_in(),
416 tokens_out: self.tokens_out(),
417 cost_usd: self.cost_usd(),
418 }
419 }
420}
421
422#[derive(Debug, Clone, Copy, Default, PartialEq, Serialize, Deserialize)]
426pub struct MetricsTotals {
427 pub duration_ms: f64,
428 pub tokens_in: u64,
429 pub tokens_out: u64,
430 pub tokens: u64,
431 pub cost_usd: f64,
432 pub metered_events: usize,
434}
435
436pub fn metrics_totals_of(events: &[Event]) -> MetricsTotals {
445 let mut totals = MetricsTotals::default();
446 for ev in events {
447 if ev.data.contains_key(SUMMARY_OF) {
448 continue;
449 }
450 let m = ev.metrics();
451 let mut metered = false;
452 if let Some(d) = m.duration_ms {
453 totals.duration_ms += d;
454 metered = true;
455 }
456 if let Some(t) = m.tokens_in {
457 totals.tokens_in = totals.tokens_in.saturating_add(t);
458 metered = true;
459 }
460 if let Some(t) = m.tokens_out {
461 totals.tokens_out = totals.tokens_out.saturating_add(t);
462 metered = true;
463 }
464 if let Some(c) = m.cost_usd {
465 totals.cost_usd += c;
466 metered = true;
467 }
468 if metered {
469 totals.metered_events += 1;
470 }
471 }
472 totals.tokens = totals.tokens_in.saturating_add(totals.tokens_out);
473 totals
474}
475
476#[derive(Debug, Clone, Default, PartialEq, Serialize, Deserialize)]
479pub struct AgentCost {
480 pub agent: String,
481 pub calls: u64,
483 pub tokens_in: u64,
484 pub tokens_out: u64,
485 pub cost_usd: f64,
486}
487
488pub const SUMMARY_OF: &str = "summary_of";
503
504pub fn cost_by_agent_of(events: &[Event]) -> Vec<AgentCost> {
515 use std::collections::BTreeMap;
516 let mut map: BTreeMap<String, AgentCost> = BTreeMap::new();
517 for e in events {
518 if e.kind != EventKind::InferenceMetered || e.data.contains_key(SUMMARY_OF) {
519 continue;
520 }
521 let agent = e
522 .data
523 .get("agent")
524 .and_then(|v| v.as_str())
525 .unwrap_or("unknown")
526 .to_string();
527 let entry = map.entry(agent.clone()).or_insert_with(|| AgentCost {
528 agent,
529 ..Default::default()
530 });
531 entry.calls += 1;
532 entry.tokens_in = entry.tokens_in.saturating_add(e.tokens_in().unwrap_or(0));
533 entry.tokens_out = entry.tokens_out.saturating_add(e.tokens_out().unwrap_or(0));
534 entry.cost_usd += e.cost_usd().unwrap_or(0.0);
535 }
536 map.into_values().collect()
537}
538
539enum JournalMessage {
558 Async(String),
559 Critical {
560 line: String,
561 known_existing: bool,
562 ack: JournalAcknowledgement,
563 },
564 #[cfg(test)]
565 Shutdown,
566}
567
568pub const MAX_CRITICAL_ACKNOWLEDGEMENT_TIMEOUT: Duration = Duration::from_secs(30);
572
573const DEFAULT_CRITICAL_ACKNOWLEDGEMENT_CAPACITY: usize = 64;
574
575#[derive(Debug, Clone, Copy, PartialEq, Eq)]
579pub enum JournalFailurePoint {
580 AsyncWrite,
581 Write,
582 Flush,
583 Fsync,
584 HoldAcknowledgement,
588}
589
590#[derive(Debug, Clone, Default)]
591pub struct JournalFailureInjector {
592 failures: Arc<Mutex<VecDeque<JournalFailurePoint>>>,
593 held_acknowledgements: Arc<Mutex<Vec<JournalAcknowledgement>>>,
594 critical_passes: Arc<Mutex<usize>>,
595}
596
597impl JournalFailureInjector {
598 pub fn fail_next(&self, point: JournalFailurePoint) {
599 self.failures
600 .lock()
601 .expect("journal failure injector mutex poisoned")
602 .push_back(point);
603 }
604
605 #[doc(hidden)]
609 pub fn pass_next_critical(&self, count: usize) {
610 *self
611 .critical_passes
612 .lock()
613 .expect("journal critical-pass mutex poisoned") += count;
614 }
615
616 fn take_critical_pass(&self) -> bool {
617 let mut passes = self
618 .critical_passes
619 .lock()
620 .expect("journal critical-pass mutex poisoned");
621 if *passes == 0 {
622 return false;
623 }
624 *passes -= 1;
625 true
626 }
627
628 fn take(&self, point: JournalFailurePoint) -> bool {
629 let mut failures = self
630 .failures
631 .lock()
632 .expect("journal failure injector mutex poisoned");
633 if failures.front() == Some(&point) {
634 failures.pop_front();
635 true
636 } else {
637 false
638 }
639 }
640
641 fn hold_acknowledgement(&self, ack: JournalAcknowledgement) {
642 self.held_acknowledgements
643 .lock()
644 .expect("journal held-acknowledgement mutex poisoned")
645 .push(ack);
646 }
647
648 #[doc(hidden)]
651 pub fn held_acknowledgement_count(&self) -> usize {
652 self.held_acknowledgements
653 .lock()
654 .expect("journal held-acknowledgement mutex poisoned")
655 .len()
656 }
657
658 #[doc(hidden)]
661 pub fn release_held_acknowledgements(&self) {
662 let acknowledgements: Vec<_> = self
663 .held_acknowledgements
664 .lock()
665 .expect("journal held-acknowledgement mutex poisoned")
666 .drain(..)
667 .collect();
668 for acknowledgement in acknowledgements {
669 acknowledgement.send(Ok(()));
670 }
671 }
672}
673
674#[derive(Debug)]
675enum CriticalPreAcceptanceError {
676 WriterUnavailable,
677 WriterStopped,
678 CoordinatorUnavailable(String),
679 CapacityExhausted { capacity: usize },
680 InvalidAcknowledgementTimeout { requested: Duration },
681}
682
683impl std::fmt::Display for CriticalPreAcceptanceError {
684 fn fmt(&self, formatter: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
685 match self {
686 Self::WriterUnavailable => write!(formatter, "journal writer thread is unavailable"),
687 Self::WriterStopped => {
688 write!(
689 formatter,
690 "journal writer stopped before accepting critical append"
691 )
692 }
693 Self::CoordinatorUnavailable(reason) => write!(
694 formatter,
695 "critical acknowledgement coordinator is unavailable: {reason}"
696 ),
697 Self::CapacityExhausted { capacity } => write!(
698 formatter,
699 "critical acknowledgement capacity is exhausted ({capacity} in flight)"
700 ),
701 Self::InvalidAcknowledgementTimeout { requested } => write!(
702 formatter,
703 "critical acknowledgement timeout must be between 1ns and {}ms, got {}ms",
704 MAX_CRITICAL_ACKNOWLEDGEMENT_TIMEOUT.as_millis(),
705 requested.as_millis()
706 ),
707 }
708 }
709}
710
711#[derive(Debug)]
712enum CriticalPostAcceptanceError {
713 DurabilityFailure(String),
714 AcknowledgementTimedOut { timeout: Duration },
715 CoordinatorStopped,
716}
717
718impl std::fmt::Display for CriticalPostAcceptanceError {
719 fn fmt(&self, formatter: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
720 match self {
721 Self::DurabilityFailure(reason) => write!(formatter, "{reason}"),
722 Self::AcknowledgementTimedOut { timeout } => write!(
723 formatter,
724 "journal writer did not acknowledge within {}ms",
725 timeout.as_millis()
726 ),
727 Self::CoordinatorStopped => {
728 write!(
729 formatter,
730 "acknowledgement coordinator stopped after enqueue"
731 )
732 }
733 }
734 }
735}
736
737struct AsyncAcknowledgementState {
738 terminal: bool,
739 result: Option<Result<(), CriticalPostAcceptanceError>>,
740 waker: Option<Waker>,
741}
742
743struct AsyncAcknowledgementEntry {
744 id: u64,
745 deadline: Instant,
746 timeout: Duration,
747 manager: Weak<AsyncAcknowledgementManagerInner>,
748 state: Mutex<AsyncAcknowledgementState>,
749}
750
751impl AsyncAcknowledgementEntry {
752 fn complete(&self, result: Result<(), CriticalPostAcceptanceError>) {
753 self.complete_deciding(|| result);
754 }
755
756 fn complete_writer(&self, result: std::io::Result<()>) {
757 self.complete_deciding(|| {
758 if Instant::now() >= self.deadline {
759 Err(CriticalPostAcceptanceError::AcknowledgementTimedOut {
760 timeout: self.timeout,
761 })
762 } else {
763 result.map_err(|error| {
764 CriticalPostAcceptanceError::DurabilityFailure(error.to_string())
765 })
766 }
767 });
768 }
769
770 fn complete_deciding(&self, decide: impl FnOnce() -> Result<(), CriticalPostAcceptanceError>) {
771 let waker = {
772 let mut state = self
773 .state
774 .lock()
775 .expect("journal async-acknowledgement mutex poisoned");
776 if state.terminal {
777 return;
778 }
779 state.terminal = true;
780 state.result = Some(decide());
781 state.waker.take()
782 };
783 if let Some(manager) = self.manager.upgrade() {
784 manager.remove(self.id);
785 }
786 if let Some(waker) = waker {
787 waker.wake();
788 }
789 }
790
791 fn cancel_preacceptance(&self) {
792 {
793 let mut state = self
794 .state
795 .lock()
796 .expect("journal async-acknowledgement mutex poisoned");
797 if state.terminal {
798 return;
799 }
800 state.terminal = true;
801 }
802 if let Some(manager) = self.manager.upgrade() {
803 manager.remove(self.id);
804 }
805 }
806}
807
808struct AsyncAcknowledgement {
809 entry: Arc<AsyncAcknowledgementEntry>,
810}
811
812impl Future for AsyncAcknowledgement {
813 type Output = Result<(), CriticalPostAcceptanceError>;
814
815 fn poll(self: Pin<&mut Self>, context: &mut Context<'_>) -> Poll<Self::Output> {
816 let mut state = self
817 .entry
818 .state
819 .lock()
820 .expect("journal async-acknowledgement mutex poisoned");
821 match state.result.take() {
822 Some(result) => Poll::Ready(result),
823 None => {
824 state.waker = Some(context.waker().clone());
825 Poll::Pending
826 }
827 }
828 }
829}
830
831struct AsyncAcknowledgementManagerState {
832 entries: HashMap<u64, Arc<AsyncAcknowledgementEntry>>,
833 next_id: u64,
834 shutting_down: bool,
835}
836
837struct AsyncAcknowledgementManagerInner {
838 capacity: usize,
839 state: Mutex<AsyncAcknowledgementManagerState>,
840 changed: Condvar,
841 #[cfg(test)]
842 expiry_barrier: Mutex<Option<AsyncAcknowledgementExpiryBarrier>>,
843}
844
845#[cfg(test)]
846#[derive(Clone)]
847struct AsyncAcknowledgementExpiryBarrier {
848 removed: Arc<std::sync::Barrier>,
849 release: Arc<std::sync::Barrier>,
850}
851
852#[cfg(test)]
853impl AsyncAcknowledgementExpiryBarrier {
854 fn new() -> Self {
855 Self {
856 removed: Arc::new(std::sync::Barrier::new(2)),
857 release: Arc::new(std::sync::Barrier::new(2)),
858 }
859 }
860
861 fn pause_after_removal(&self) {
862 self.removed.wait();
863 self.release.wait();
864 }
865
866 fn wait_until_removed(&self) {
867 self.removed.wait();
868 }
869
870 fn allow_timeout_completion(&self) {
871 self.release.wait();
872 }
873}
874
875impl AsyncAcknowledgementManagerInner {
876 fn remove(&self, id: u64) {
877 let removed = self
878 .state
879 .lock()
880 .expect("journal acknowledgement-manager mutex poisoned")
881 .entries
882 .remove(&id)
883 .is_some();
884 if removed {
885 self.changed.notify_all();
886 }
887 }
888}
889
890struct AsyncAcknowledgementManager {
891 inner: Arc<AsyncAcknowledgementManagerInner>,
892 worker: Mutex<Option<thread::JoinHandle<()>>>,
893}
894
895impl AsyncAcknowledgementManager {
896 fn new(capacity: usize) -> Self {
897 Self {
898 inner: Arc::new(AsyncAcknowledgementManagerInner {
899 capacity,
900 state: Mutex::new(AsyncAcknowledgementManagerState {
901 entries: HashMap::new(),
902 next_id: 0,
903 shutting_down: false,
904 }),
905 changed: Condvar::new(),
906 #[cfg(test)]
907 expiry_barrier: Mutex::new(None),
908 }),
909 worker: Mutex::new(None),
910 }
911 }
912
913 #[cfg(test)]
914 fn pause_next_expiry_after_removal(&self, barrier: AsyncAcknowledgementExpiryBarrier) {
915 *self
916 .inner
917 .expiry_barrier
918 .lock()
919 .expect("journal acknowledgement expiry-barrier mutex poisoned") = Some(barrier);
920 }
921
922 fn ensure_worker(&self) -> Result<(), CriticalPreAcceptanceError> {
923 let mut worker = self
924 .worker
925 .lock()
926 .expect("journal acknowledgement-worker mutex poisoned");
927 if worker.is_some() {
928 return Ok(());
929 }
930 let inner = self.inner.clone();
931 let handle = thread::Builder::new()
932 .name("car-eventlog-critical-ack".into())
933 .spawn(move || async_acknowledgement_timer_loop(inner))
934 .map_err(|error| {
935 CriticalPreAcceptanceError::CoordinatorUnavailable(error.to_string())
936 })?;
937 *worker = Some(handle);
938 Ok(())
939 }
940
941 fn reserve(
942 &self,
943 timeout: Duration,
944 ) -> Result<AsyncAcknowledgementReservation, CriticalPreAcceptanceError> {
945 if timeout.is_zero() || timeout > MAX_CRITICAL_ACKNOWLEDGEMENT_TIMEOUT {
946 return Err(CriticalPreAcceptanceError::InvalidAcknowledgementTimeout {
947 requested: timeout,
948 });
949 }
950 self.ensure_worker()?;
951 let mut state = self
952 .inner
953 .state
954 .lock()
955 .expect("journal acknowledgement-manager mutex poisoned");
956 if state.shutting_down {
957 return Err(CriticalPreAcceptanceError::CoordinatorUnavailable(
958 "coordinator is shutting down".to_string(),
959 ));
960 }
961 if state.entries.len() >= self.inner.capacity {
962 return Err(CriticalPreAcceptanceError::CapacityExhausted {
963 capacity: self.inner.capacity,
964 });
965 }
966 let id = loop {
967 let candidate = state.next_id;
968 state.next_id = state.next_id.wrapping_add(1);
969 if !state.entries.contains_key(&candidate) {
970 break candidate;
971 }
972 };
973 let entry = Arc::new(AsyncAcknowledgementEntry {
974 id,
975 deadline: Instant::now() + timeout,
976 timeout,
977 manager: Arc::downgrade(&self.inner),
978 state: Mutex::new(AsyncAcknowledgementState {
979 terminal: false,
980 result: None,
981 waker: None,
982 }),
983 });
984 state.entries.insert(id, entry.clone());
985 drop(state);
986 self.inner.changed.notify_all();
987 Ok(AsyncAcknowledgementReservation {
988 entry,
989 preaccepted: true,
990 })
991 }
992
993 fn shutdown(&self) {
994 let entries = {
995 let mut state = self
996 .inner
997 .state
998 .lock()
999 .expect("journal acknowledgement-manager mutex poisoned");
1000 state.shutting_down = true;
1001 let entries = state
1002 .entries
1003 .drain()
1004 .map(|(_, entry)| entry)
1005 .collect::<Vec<_>>();
1006 self.inner.changed.notify_all();
1007 entries
1008 };
1009 for entry in entries {
1010 entry.complete(Err(CriticalPostAcceptanceError::CoordinatorStopped));
1011 }
1012 if let Some(worker) = self
1013 .worker
1014 .lock()
1015 .expect("journal acknowledgement-worker mutex poisoned")
1016 .take()
1017 {
1018 let _ = worker.join();
1019 }
1020 }
1021}
1022
1023fn async_acknowledgement_timer_loop(inner: Arc<AsyncAcknowledgementManagerInner>) {
1024 loop {
1025 let expired = {
1026 let mut state = inner
1027 .state
1028 .lock()
1029 .expect("journal acknowledgement-manager mutex poisoned");
1030 loop {
1031 if state.shutting_down {
1032 return;
1033 }
1034 let now = Instant::now();
1035 let expired_ids: Vec<_> = state
1036 .entries
1037 .iter()
1038 .filter_map(|(id, entry)| (entry.deadline <= now).then_some(*id))
1039 .collect();
1040 if !expired_ids.is_empty() {
1041 break expired_ids
1042 .into_iter()
1043 .filter_map(|id| state.entries.remove(&id))
1044 .collect::<Vec<_>>();
1045 }
1046 if let Some(deadline) = state.entries.values().map(|entry| entry.deadline).min() {
1047 let wait = deadline.saturating_duration_since(now);
1048 let (next, _) = inner
1049 .changed
1050 .wait_timeout(state, wait)
1051 .expect("journal acknowledgement-manager mutex poisoned");
1052 state = next;
1053 } else {
1054 state = inner
1055 .changed
1056 .wait(state)
1057 .expect("journal acknowledgement-manager mutex poisoned");
1058 }
1059 }
1060 };
1061 #[cfg(test)]
1062 if !expired.is_empty() {
1063 if let Some(barrier) = inner
1064 .expiry_barrier
1065 .lock()
1066 .expect("journal acknowledgement expiry-barrier mutex poisoned")
1067 .take()
1068 {
1069 barrier.pause_after_removal();
1070 }
1071 }
1072 for entry in expired {
1073 entry.complete(Err(CriticalPostAcceptanceError::AcknowledgementTimedOut {
1074 timeout: entry.timeout,
1075 }));
1076 }
1077 }
1078}
1079
1080struct AsyncAcknowledgementReservation {
1081 entry: Arc<AsyncAcknowledgementEntry>,
1082 preaccepted: bool,
1083}
1084
1085impl AsyncAcknowledgementReservation {
1086 fn sender(&self) -> AsyncAcknowledgementSender {
1087 AsyncAcknowledgementSender {
1088 entry: self.entry.clone(),
1089 }
1090 }
1091
1092 fn into_future(mut self) -> AsyncAcknowledgement {
1093 self.preaccepted = false;
1094 AsyncAcknowledgement {
1095 entry: self.entry.clone(),
1096 }
1097 }
1098}
1099
1100impl Drop for AsyncAcknowledgementReservation {
1101 fn drop(&mut self) {
1102 if self.preaccepted {
1103 self.entry.cancel_preacceptance();
1104 }
1105 }
1106}
1107
1108struct AsyncAcknowledgementSender {
1109 entry: Arc<AsyncAcknowledgementEntry>,
1110}
1111
1112impl AsyncAcknowledgementSender {
1113 fn send(&self, result: std::io::Result<()>) {
1114 self.entry.complete_writer(result);
1115 }
1116}
1117
1118enum JournalAcknowledgement {
1119 Sync(mpsc::SyncSender<std::io::Result<()>>),
1120 Async(AsyncAcknowledgementSender),
1121}
1122
1123impl JournalAcknowledgement {
1124 fn send(&self, result: std::io::Result<()>) {
1125 match self {
1126 Self::Sync(sender) => {
1127 let _ = sender.send(result);
1128 }
1129 Self::Async(sender) => sender.send(result),
1130 }
1131 }
1132}
1133
1134impl std::fmt::Debug for JournalAcknowledgement {
1135 fn fmt(&self, formatter: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
1136 match self {
1137 Self::Sync(_) => formatter.write_str("JournalAcknowledgement::Sync"),
1138 Self::Async(_) => formatter.write_str("JournalAcknowledgement::Async"),
1139 }
1140 }
1141}
1142
1143#[derive(Debug, Clone, PartialEq, Eq)]
1147pub enum CriticalAppendError {
1148 Rejected { reason: String },
1150 DurabilityUnknown { reason: String },
1153}
1154
1155impl CriticalAppendError {
1156 pub fn is_retry_safe(&self) -> bool {
1157 matches!(self, Self::DurabilityUnknown { .. })
1158 }
1159}
1160
1161impl std::fmt::Display for CriticalAppendError {
1162 fn fmt(&self, formatter: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
1163 match self {
1164 Self::Rejected { reason } => {
1165 write!(formatter, "critical journal append rejected: {reason}")
1166 }
1167 Self::DurabilityUnknown { reason } => write!(
1168 formatter,
1169 "critical journal durability is unknown; retry the exact event safely: {reason}"
1170 ),
1171 }
1172 }
1173}
1174
1175impl std::error::Error for CriticalAppendError {}
1176
1177struct JournalWriter {
1178 tx: Option<mpsc::Sender<JournalMessage>>,
1181 handle: Option<thread::JoinHandle<()>>,
1182 acknowledgements: AsyncAcknowledgementManager,
1183}
1184
1185impl JournalWriter {
1186 fn spawn(path: PathBuf) -> Self {
1187 Self::spawn_with_injectors(path, JournalFailureInjector::default(), None)
1188 }
1189
1190 fn spawn_with_injector(path: PathBuf, failures: JournalFailureInjector) -> Self {
1191 Self::spawn_with_injectors(path, failures, None)
1192 }
1193
1194 fn spawn_with_private_path_injector(
1195 path: PathBuf,
1196 failures: car_secrets::PrivatePathDurabilityFailureInjector,
1197 ) -> Self {
1198 Self::spawn_with_injectors(path, JournalFailureInjector::default(), Some(failures))
1199 }
1200
1201 fn spawn_with_injectors(
1202 path: PathBuf,
1203 failures: JournalFailureInjector,
1204 private_path_failures: Option<car_secrets::PrivatePathDurabilityFailureInjector>,
1205 ) -> Self {
1206 Self::spawn_with_injectors_and_ack_capacity(
1207 path,
1208 failures,
1209 private_path_failures,
1210 DEFAULT_CRITICAL_ACKNOWLEDGEMENT_CAPACITY,
1211 )
1212 }
1213
1214 fn spawn_with_injectors_and_ack_capacity(
1215 path: PathBuf,
1216 failures: JournalFailureInjector,
1217 private_path_failures: Option<car_secrets::PrivatePathDurabilityFailureInjector>,
1218 acknowledgement_capacity: usize,
1219 ) -> Self {
1220 let (tx, rx) = mpsc::channel::<JournalMessage>();
1221 let acknowledgements = AsyncAcknowledgementManager::new(acknowledgement_capacity);
1222 match thread::Builder::new()
1223 .name("car-eventlog-journal".into())
1224 .spawn(move || journal_loop(path, rx, failures, private_path_failures))
1225 {
1226 Ok(handle) => Self {
1227 tx: Some(tx),
1228 handle: Some(handle),
1229 acknowledgements,
1230 },
1231 Err(e) => {
1233 tracing::warn!(error = %e, "car-eventlog: failed to spawn journal writer thread — journaling disabled for this log");
1234 Self {
1235 tx: None,
1236 handle: None,
1237 acknowledgements,
1238 }
1239 }
1240 }
1241 }
1242
1243 fn send(&self, line: String) {
1244 if let Some(tx) = &self.tx {
1245 let _ = tx.send(JournalMessage::Async(line));
1247 }
1248 }
1249
1250 fn enqueue_critical_sync(
1251 &self,
1252 line: String,
1253 known_existing: bool,
1254 ) -> Result<mpsc::Receiver<std::io::Result<()>>, CriticalPreAcceptanceError> {
1255 let tx = self
1256 .tx
1257 .as_ref()
1258 .ok_or(CriticalPreAcceptanceError::WriterUnavailable)?;
1259 let (ack_tx, ack_rx) = mpsc::sync_channel(0);
1260 tx.send(JournalMessage::Critical {
1261 line,
1262 known_existing,
1263 ack: JournalAcknowledgement::Sync(ack_tx),
1264 })
1265 .map_err(|_| CriticalPreAcceptanceError::WriterStopped)?;
1266 Ok(ack_rx)
1267 }
1268
1269 fn reserve_async_acknowledgement(
1270 &self,
1271 acknowledgement_timeout: Duration,
1272 ) -> Result<AsyncAcknowledgementReservation, CriticalPreAcceptanceError> {
1273 if self.tx.is_none() {
1274 return Err(CriticalPreAcceptanceError::WriterUnavailable);
1275 }
1276 self.acknowledgements.reserve(acknowledgement_timeout)
1277 }
1278
1279 fn enqueue_critical_async(
1280 &self,
1281 line: String,
1282 known_existing: bool,
1283 reservation: AsyncAcknowledgementReservation,
1284 ) -> Result<AsyncAcknowledgement, CriticalPreAcceptanceError> {
1285 let tx = self
1286 .tx
1287 .as_ref()
1288 .ok_or(CriticalPreAcceptanceError::WriterUnavailable)?;
1289 tx.send(JournalMessage::Critical {
1290 line,
1291 known_existing,
1292 ack: JournalAcknowledgement::Async(reservation.sender()),
1293 })
1294 .map_err(|_| CriticalPreAcceptanceError::WriterStopped)?;
1295 Ok(reservation.into_future())
1296 }
1297
1298 #[cfg(test)]
1299 fn remove_sender_for_test(&mut self) {
1300 self.tx.take();
1301 if let Some(handle) = self.handle.take() {
1302 let _ = handle.join();
1303 }
1304 }
1305
1306 #[cfg(test)]
1307 fn stop_receiver_for_test(&mut self) {
1308 if let Some(tx) = &self.tx {
1309 let _ = tx.send(JournalMessage::Shutdown);
1310 }
1311 if let Some(handle) = self.handle.take() {
1312 let _ = handle.join();
1313 }
1314 }
1315}
1316
1317impl Drop for JournalWriter {
1318 fn drop(&mut self) {
1319 self.acknowledgements.shutdown();
1320 self.tx.take();
1323 if let Some(handle) = self.handle.take() {
1324 let _ = handle.join();
1325 }
1326 }
1327}
1328
1329fn journal_loop(
1340 path: PathBuf,
1341 rx: mpsc::Receiver<JournalMessage>,
1342 failures: JournalFailureInjector,
1343 private_path_failures: Option<car_secrets::PrivatePathDurabilityFailureInjector>,
1344) {
1345 let mut writer: Option<std::fs::File> = None;
1346 let mut written_critical_lines = HashSet::new();
1347 let mut blocked_critical: Option<String> = None;
1348 let mut failed_async = VecDeque::new();
1353 let mut after_blocked_critical = VecDeque::new();
1354 while let Ok(message) = rx.recv() {
1355 let existed_before_open = path.exists();
1356 let open = || match private_path_failures.as_ref() {
1357 Some(failures) => {
1358 car_secrets::open_private_append_with_failure_injector(&path, failures)
1359 }
1360 None => open_private_append(&path),
1361 };
1362 match message {
1363 #[cfg(test)]
1364 JournalMessage::Shutdown => break,
1365 JournalMessage::Async(line) => {
1366 if blocked_critical.is_some() {
1367 after_blocked_critical.push_back(line);
1368 continue;
1369 }
1370 if !failed_async.is_empty() {
1371 failed_async.push_back(line);
1372 continue;
1373 }
1374 if writer.is_none() {
1375 writer = open().ok();
1376 }
1377 let result = match writer.as_mut() {
1378 Some(file) => append_journal_line(
1379 &path,
1380 file,
1381 &line,
1382 false,
1383 false,
1384 existed_before_open,
1385 &failures,
1386 &mut written_critical_lines,
1387 ),
1388 None => Err(std::io::Error::other("cannot open journal file")),
1389 };
1390 if let Err(error) = result {
1391 failed_async.push_back(line);
1392 tracing::warn!(path = %path.display(), %error, "car-eventlog: asynchronous journal append failed and is awaiting ordered retry");
1393 }
1394 continue;
1395 }
1396 JournalMessage::Critical {
1397 line,
1398 known_existing,
1399 ack,
1400 } => {
1401 if blocked_critical
1402 .as_deref()
1403 .is_some_and(|pending| pending != line)
1404 {
1405 ack.send(Err(std::io::Error::new(
1406 std::io::ErrorKind::WouldBlock,
1407 "another critical journal row is awaiting durability",
1408 )));
1409 continue;
1410 }
1411 if writer.is_none() {
1412 writer = open().ok();
1413 }
1414
1415 while let Some(pending) = failed_async.front() {
1420 let replay = match writer.as_mut() {
1421 Some(file) => append_journal_line(
1422 &path,
1423 file,
1424 pending,
1425 false,
1426 false,
1427 existed_before_open,
1428 &failures,
1429 &mut written_critical_lines,
1430 ),
1431 None => Err(std::io::Error::other("cannot open journal file")),
1432 };
1433 match replay {
1434 Ok(()) => {
1435 failed_async.pop_front();
1436 }
1437 Err(error) => {
1438 blocked_critical = Some(line.clone());
1439 ack.send(Err(std::io::Error::new(
1440 error.kind(),
1441 format!("prior asynchronous journal row is not durable: {error}"),
1442 )));
1443 break;
1444 }
1445 }
1446 }
1447 if !failed_async.is_empty() {
1448 continue;
1449 }
1450 let line_failures = if failures.take_critical_pass() {
1451 JournalFailureInjector::default()
1452 } else {
1453 failures.clone()
1454 };
1455 let result = match writer.as_mut() {
1456 Some(file) => append_journal_line(
1457 &path,
1458 file,
1459 &line,
1460 true,
1461 known_existing,
1462 existed_before_open,
1463 &line_failures,
1464 &mut written_critical_lines,
1465 ),
1466 None => Err(std::io::Error::other("cannot open journal file")),
1467 };
1468 match result {
1469 Ok(()) => {
1470 blocked_critical = None;
1471 while let Some(queued) = after_blocked_critical.pop_front() {
1472 if let Some(file) = writer.as_mut() {
1473 if let Err(error) = append_journal_line(
1474 &path,
1475 file,
1476 &queued,
1477 false,
1478 false,
1479 true,
1480 &failures,
1481 &mut written_critical_lines,
1482 ) {
1483 failed_async.push_back(queued);
1484 failed_async.append(&mut after_blocked_critical);
1485 tracing::warn!(path = %path.display(), %error, "car-eventlog: queued asynchronous append failed after critical recovery and is awaiting ordered retry");
1486 break;
1487 }
1488 }
1489 }
1490 if line_failures.take(JournalFailurePoint::HoldAcknowledgement) {
1491 failures.hold_acknowledgement(ack);
1492 } else {
1493 ack.send(Ok(()));
1494 }
1495 }
1496 Err(error) => {
1497 blocked_critical = Some(line);
1498 ack.send(Err(error));
1499 }
1500 }
1501 continue;
1502 }
1503 };
1504 }
1505 if let Some(mut writer) = writer {
1506 let _ = writer.flush();
1507 }
1508}
1509
1510fn append_journal_line(
1511 path: &Path,
1512 file: &mut std::fs::File,
1513 line: &str,
1514 critical: bool,
1515 known_existing: bool,
1516 existed_before_open: bool,
1517 failures: &JournalFailureInjector,
1518 written_critical_lines: &mut HashSet<String>,
1519) -> std::io::Result<()> {
1520 revalidate_private_path(path, file)?;
1521 let already_written = known_existing || written_critical_lines.contains(line);
1522 if !already_written {
1523 if (!critical && failures.take(JournalFailurePoint::AsyncWrite))
1524 || (critical && failures.take(JournalFailurePoint::Write))
1525 {
1526 return Err(std::io::Error::from_raw_os_error(28)); }
1528 let mut bytes = Vec::with_capacity(line.len() + 2);
1529 let len = file.seek(SeekFrom::End(0))?;
1530 if len > 0 {
1531 file.seek(SeekFrom::End(-1))?;
1532 let mut tail = [0u8; 1];
1533 file.read_exact(&mut tail)?;
1534 if tail[0] != b'\n' {
1535 bytes.push(b'\n');
1536 }
1537 }
1538 bytes.extend_from_slice(line.as_bytes());
1539 bytes.push(b'\n');
1540 if let Err(error) = file.write_all(&bytes) {
1541 let _ = file.set_len(len);
1545 let _ = file.seek(SeekFrom::End(0));
1546 return Err(error);
1547 }
1548 if critical {
1549 written_critical_lines.insert(line.to_string());
1550 }
1551 }
1552 if critical && failures.take(JournalFailurePoint::Flush) {
1553 return Err(std::io::Error::other("injected journal flush failure"));
1554 }
1555 file.flush()?;
1556 if critical {
1557 if failures.take(JournalFailurePoint::Fsync) {
1558 return Err(std::io::Error::other("injected journal fsync failure"));
1559 }
1560 file.sync_all()?;
1561 if !existed_before_open {
1562 sync_journal_parent(path)?;
1563 }
1564 }
1565 revalidate_private_path(path, file)
1566}
1567
1568#[cfg(not(target_os = "windows"))]
1569fn sync_journal_parent(path: &Path) -> std::io::Result<()> {
1570 if let Some(parent) = path.parent() {
1571 std::fs::File::open(parent)?.sync_all()?;
1572 }
1573 Ok(())
1574}
1575
1576#[cfg(target_os = "windows")]
1577fn sync_journal_parent(_path: &Path) -> std::io::Result<()> {
1578 Ok(())
1583}
1584
1585pub struct EventLog {
1587 events: Vec<Event>,
1588 spans: Vec<Span>,
1589 journal: Option<JournalWriter>,
1590 hash_chaining: bool,
1595 last_hash: Option<String>,
1598 retention: Option<RetentionPolicy>,
1603 journal_path: Option<PathBuf>,
1606 journal_lines: usize,
1611 trimmed_events: u64,
1617 cumulative_cost_usd: f64,
1623 active_binding: Option<EventBinding>,
1627 critical_pending: HashSet<String>,
1631}
1632
1633#[derive(Debug, Clone, PartialEq, Eq)]
1634struct EventBinding {
1635 run_id: String,
1636 client_id: String,
1637 policy_session_id: Option<String>,
1638}
1639
1640struct PreparedCriticalAppend {
1641 existing_index: Option<usize>,
1642 event: Option<Event>,
1643 line: String,
1644 known_existing: bool,
1645}
1646
1647const JOURNAL_COMPACT_MIN_EXCESS: usize = 1024;
1653
1654fn event_digest(
1666 prev_hash: &str,
1667 kind: &EventKind,
1668 run_id: Option<&str>,
1669 client_id: Option<&str>,
1670 policy_session_id: Option<&str>,
1671 action_id: Option<&str>,
1672 proposal_id: Option<&str>,
1673 data: &HashMap<String, Value>,
1674 timestamp: &DateTime<Utc>,
1675) -> String {
1676 use sha2::{Digest, Sha256};
1677 let mut sorted: Vec<(&String, &Value)> = data.iter().collect();
1678 sorted.sort_by(|a, b| a.0.cmp(b.0));
1679 let data_canon: String = sorted
1680 .iter()
1681 .map(|(k, v)| format!("{k}={}", v))
1682 .collect::<Vec<_>>()
1683 .join("\u{1f}");
1684 let kind_str = serde_json::to_string(kind).unwrap_or_default();
1685 let mut hasher = Sha256::new();
1686 hasher.update(prev_hash.as_bytes());
1687 hasher.update(b"\x1e");
1688 hasher.update(kind_str.as_bytes());
1689 if run_id.is_some() || client_id.is_some() || policy_session_id.is_some() {
1692 hasher.update(b"\x1d");
1693 hasher.update(run_id.unwrap_or("").as_bytes());
1694 hasher.update(b"\x1f");
1695 hasher.update(client_id.unwrap_or("").as_bytes());
1696 hasher.update(b"\x1f");
1697 hasher.update(policy_session_id.unwrap_or("").as_bytes());
1698 }
1699 hasher.update(b"\x1e");
1700 hasher.update(action_id.unwrap_or("").as_bytes());
1701 hasher.update(b"\x1e");
1702 hasher.update(proposal_id.unwrap_or("").as_bytes());
1703 hasher.update(b"\x1e");
1704 hasher.update(data_canon.as_bytes());
1705 hasher.update(b"\x1e");
1706 hasher.update(timestamp.to_rfc3339().as_bytes());
1707 let digest = hasher.finalize();
1708 digest.iter().map(|b| format!("{b:02x}")).collect()
1709}
1710
1711#[derive(Debug, Clone, Default, PartialEq, Serialize, Deserialize)]
1721pub struct RetentionPolicy {
1722 #[serde(default, alias = "maxEvents")]
1724 pub max_events: Option<usize>,
1725 #[serde(default, alias = "maxAgeSecs")]
1727 pub max_age_secs: Option<i64>,
1728}
1729
1730#[derive(Debug, Clone, Default, Serialize, Deserialize)]
1740pub struct EventQuery {
1741 #[serde(default)]
1743 pub kinds: Vec<EventKind>,
1744 #[serde(default, alias = "actionId")]
1746 pub action_id: Option<String>,
1747 #[serde(default, alias = "proposalId")]
1749 pub proposal_id: Option<String>,
1750 #[serde(default)]
1752 pub since: Option<DateTime<Utc>>,
1753 #[serde(default)]
1755 pub until: Option<DateTime<Utc>>,
1756 #[serde(default, alias = "dataMatches")]
1760 pub data_matches: std::collections::HashMap<String, String>,
1761 #[serde(default)]
1763 pub limit: Option<usize>,
1764}
1765
1766fn data_value_matches(v: &Value, want: &str) -> bool {
1769 match v {
1770 Value::String(s) => s == want,
1771 Value::Null => false,
1772 other => *other == want,
1773 }
1774}
1775
1776impl EventQuery {
1777 pub fn matches(&self, e: &Event) -> bool {
1779 if !self.kinds.is_empty() && !self.kinds.contains(&e.kind) {
1780 return false;
1781 }
1782 if let Some(aid) = &self.action_id {
1783 if e.action_id.as_deref() != Some(aid.as_str()) {
1784 return false;
1785 }
1786 }
1787 if let Some(pid) = &self.proposal_id {
1788 if e.proposal_id.as_deref() != Some(pid.as_str()) {
1789 return false;
1790 }
1791 }
1792 if let Some(since) = self.since {
1793 if e.timestamp < since {
1794 return false;
1795 }
1796 }
1797 if let Some(until) = self.until {
1798 if e.timestamp >= until {
1799 return false;
1800 }
1801 }
1802 for (k, want) in &self.data_matches {
1803 match e.data.get(k) {
1804 Some(v) if data_value_matches(v, want) => {}
1805 _ => return false,
1806 }
1807 }
1808 true
1809 }
1810}
1811
1812impl EventLog {
1813 pub fn new() -> Self {
1814 Self {
1815 events: Vec::new(),
1816 spans: Vec::new(),
1817 journal: None,
1818 hash_chaining: false,
1819 last_hash: None,
1820 retention: None,
1821 journal_path: None,
1822 journal_lines: 0,
1823 trimmed_events: 0,
1824 cumulative_cost_usd: 0.0,
1825 active_binding: None,
1826 critical_pending: HashSet::new(),
1827 }
1828 }
1829
1830 pub fn with_journal(path: PathBuf) -> Self {
1831 let mut log = Self::with_lazy_journal(path.clone());
1832 log.journal = Some(JournalWriter::spawn(path));
1833 log
1834 }
1835
1836 pub fn with_lazy_journal(path: PathBuf) -> Self {
1841 Self {
1842 events: Vec::new(),
1843 spans: Vec::new(),
1844 journal: None,
1845 hash_chaining: false,
1846 last_hash: None,
1847 retention: None,
1848 journal_path: Some(path),
1849 journal_lines: 0,
1850 trimmed_events: 0,
1851 cumulative_cost_usd: 0.0,
1852 active_binding: None,
1853 critical_pending: HashSet::new(),
1854 }
1855 }
1856
1857 pub fn with_journal_failure_injector(path: PathBuf, failures: JournalFailureInjector) -> Self {
1859 let mut log = Self::with_journal(path.clone());
1860 log.journal = Some(JournalWriter::spawn_with_injector(path, failures));
1861 log
1862 }
1863
1864 #[cfg(test)]
1865 fn with_journal_failure_injector_and_ack_capacity(
1866 path: PathBuf,
1867 failures: JournalFailureInjector,
1868 acknowledgement_capacity: usize,
1869 ) -> Self {
1870 let mut log = Self::with_journal(path.clone());
1871 log.journal = Some(JournalWriter::spawn_with_injectors_and_ack_capacity(
1872 path,
1873 failures,
1874 None,
1875 acknowledgement_capacity,
1876 ));
1877 log
1878 }
1879
1880 pub fn with_private_path_failure_injector(
1882 path: PathBuf,
1883 failures: car_secrets::PrivatePathDurabilityFailureInjector,
1884 ) -> Self {
1885 let mut log = Self::with_journal(path.clone());
1886 log.journal = Some(JournalWriter::spawn_with_private_path_injector(
1887 path, failures,
1888 ));
1889 log
1890 }
1891
1892 pub fn bind_run(&mut self, run_id: &str, client_id: &str) -> Result<(), String> {
1896 if run_id.is_empty() || client_id.is_empty() {
1897 return Err("active journal binding requires non-empty run_id and client_id".into());
1898 }
1899 match &self.active_binding {
1900 Some(binding) if binding.run_id == run_id && binding.client_id == client_id => Ok(()),
1901 Some(binding) => Err(format!(
1902 "journal is already bound to run_id `{}` and client_id `{}`",
1903 binding.run_id, binding.client_id
1904 )),
1905 None => {
1906 self.active_binding = Some(EventBinding {
1907 run_id: run_id.to_string(),
1908 client_id: client_id.to_string(),
1909 policy_session_id: None,
1910 });
1911 Ok(())
1912 }
1913 }
1914 }
1915
1916 pub fn bind_policy_session(&mut self, policy_session_id: &str) -> Result<(), String> {
1918 if policy_session_id.is_empty() {
1919 return Err("policy_session_id must be non-empty".into());
1920 }
1921 let binding = self
1922 .active_binding
1923 .as_mut()
1924 .ok_or_else(|| "cannot bind a policy session without an active run".to_string())?;
1925 match binding.policy_session_id.as_deref() {
1926 Some(existing) if existing != policy_session_id => Err(format!(
1927 "journal proposal is already bound to policy_session_id `{existing}`"
1928 )),
1929 _ => {
1930 binding.policy_session_id = Some(policy_session_id.to_string());
1931 Ok(())
1932 }
1933 }
1934 }
1935
1936 pub fn clear_policy_session(&mut self, policy_session_id: &str) -> Result<(), String> {
1937 let binding = self
1938 .active_binding
1939 .as_mut()
1940 .ok_or_else(|| "cannot clear a policy session without an active run".to_string())?;
1941 if binding.policy_session_id.as_deref() != Some(policy_session_id) {
1942 return Err("policy_session_id does not match the active journal binding".into());
1943 }
1944 binding.policy_session_id = None;
1945 Ok(())
1946 }
1947
1948 pub fn clear_run_binding(&mut self, run_id: &str, client_id: &str) -> Result<(), String> {
1949 let binding = self
1950 .active_binding
1951 .as_ref()
1952 .ok_or_else(|| "journal has no active run binding".to_string())?;
1953 if binding.run_id != run_id || binding.client_id != client_id {
1954 return Err("run_id/client_id does not match the active journal binding".into());
1955 }
1956 if binding.policy_session_id.is_some() {
1957 return Err(
1958 "cannot clear an active run while a proposal policy session is bound".into(),
1959 );
1960 }
1961 self.active_binding = None;
1962 Ok(())
1963 }
1964
1965 pub fn active_run_binding(&self) -> Option<(&str, &str, Option<&str>)> {
1966 self.active_binding.as_ref().map(|binding| {
1967 (
1968 binding.run_id.as_str(),
1969 binding.client_id.as_str(),
1970 binding.policy_session_id.as_deref(),
1971 )
1972 })
1973 }
1974
1975 pub fn with_hash_chaining(mut self) -> Self {
1980 self.enable_hash_chaining();
1981 self
1982 }
1983
1984 pub fn enable_hash_chaining(&mut self) {
1986 self.hash_chaining = true;
1987 if self.last_hash.is_none() {
1989 self.last_hash = self.events.last().and_then(|e| e.hash.clone());
1990 }
1991 }
1992
1993 pub fn hash_chaining_enabled(&self) -> bool {
1995 self.hash_chaining
1996 }
1997
1998 pub fn append(
1999 &mut self,
2000 kind: EventKind,
2001 action_id: Option<&str>,
2002 proposal_id: Option<&str>,
2003 data: HashMap<String, Value>,
2004 ) -> &Event {
2005 let timestamp = Utc::now();
2006 let (prev_hash, hash) = if self.hash_chaining {
2007 let prev = self.last_hash.clone().unwrap_or_default();
2008 let binding = self.active_binding.as_ref();
2009 let h = event_digest(
2010 &prev,
2011 &kind,
2012 binding.map(|b| b.run_id.as_str()),
2013 binding.map(|b| b.client_id.as_str()),
2014 binding.and_then(|b| b.policy_session_id.as_deref()),
2015 action_id,
2016 proposal_id,
2017 &data,
2018 ×tamp,
2019 );
2020 self.last_hash = Some(h.clone());
2021 (Some(prev), Some(h))
2022 } else {
2023 (None, None)
2024 };
2025 let event = Event {
2026 kind,
2027 run_id: self.active_binding.as_ref().map(|b| b.run_id.clone()),
2028 client_id: self.active_binding.as_ref().map(|b| b.client_id.clone()),
2029 policy_session_id: self
2030 .active_binding
2031 .as_ref()
2032 .and_then(|b| b.policy_session_id.clone()),
2033 action_id: action_id.map(|s| s.to_string()),
2034 proposal_id: proposal_id.map(|s| s.to_string()),
2035 data,
2036 timestamp,
2037 prev_hash,
2038 hash,
2039 };
2040
2041 if let Some(journal) = &self.journal {
2044 if let Ok(json) = serde_json::to_string(&event) {
2045 journal.send(json);
2046 self.journal_lines += 1;
2047 }
2048 }
2049
2050 if let Some(c) = event.cost_usd() {
2053 self.cumulative_cost_usd += c;
2054 }
2055
2056 self.events.push(event);
2057 if let Some(max) = self.retention.as_ref().and_then(|p| p.max_events) {
2062 if self.events.len() > max {
2063 let removed = truncate_vec_keep_last(&mut self.events, max);
2064 self.trimmed_events += removed as u64;
2065 self.maybe_compact_journal();
2068 }
2069 }
2070 self.events.last().unwrap()
2071 }
2072
2073 fn prepare_critical_append(
2074 &mut self,
2075 kind: EventKind,
2076 action_id: Option<&str>,
2077 proposal_id: Option<&str>,
2078 data: HashMap<String, Value>,
2079 ) -> Result<PreparedCriticalAppend, String> {
2080 let binding = self.active_binding.as_ref().ok_or_else(|| {
2081 "critical lifecycle event requires an authenticated run binding".to_string()
2082 })?;
2083 let existing = self.events.iter().position(|event| {
2084 event.kind == kind
2085 && event.run_id.as_deref() == Some(binding.run_id.as_str())
2086 && event.client_id.as_deref() == Some(binding.client_id.as_str())
2087 && event.policy_session_id.as_deref() == binding.policy_session_id.as_deref()
2088 && event.action_id.as_deref() == action_id
2089 && event.proposal_id.as_deref() == proposal_id
2090 && event.data == data
2091 });
2092 if existing.is_none() && !self.critical_pending.is_empty() {
2093 return Err(
2094 "another critical lifecycle event is awaiting an exact durability retry".into(),
2095 );
2096 }
2097
2098 if let Some(index) = existing {
2099 let line = serde_json::to_string(&self.events[index]).map_err(|e| e.to_string())?;
2100 return Ok(PreparedCriticalAppend {
2101 existing_index: Some(index),
2102 event: None,
2103 known_existing: !self.critical_pending.contains(&line),
2104 line,
2105 });
2106 }
2107
2108 let timestamp = Utc::now();
2109 let (prev_hash, hash) = if self.hash_chaining {
2110 let prev = self.last_hash.clone().unwrap_or_default();
2111 let hash = event_digest(
2112 &prev,
2113 &kind,
2114 Some(binding.run_id.as_str()),
2115 Some(binding.client_id.as_str()),
2116 binding.policy_session_id.as_deref(),
2117 action_id,
2118 proposal_id,
2119 &data,
2120 ×tamp,
2121 );
2122 (Some(prev), Some(hash))
2123 } else {
2124 (None, None)
2125 };
2126 let event = Event {
2127 kind,
2128 run_id: Some(binding.run_id.clone()),
2129 client_id: Some(binding.client_id.clone()),
2130 policy_session_id: binding.policy_session_id.clone(),
2131 action_id: action_id.map(str::to_string),
2132 proposal_id: proposal_id.map(str::to_string),
2133 data,
2134 timestamp,
2135 prev_hash,
2136 hash,
2137 };
2138 let line = serde_json::to_string(&event).map_err(|error| error.to_string())?;
2139 Ok(PreparedCriticalAppend {
2140 existing_index: None,
2141 event: Some(event),
2142 line,
2143 known_existing: false,
2144 })
2145 }
2146
2147 fn commit_prepared_critical(&mut self, prepared: PreparedCriticalAppend) -> (usize, String) {
2148 let index = match prepared.existing_index {
2149 Some(index) => index,
2150 None => {
2151 let event = prepared
2152 .event
2153 .expect("new critical append must carry its prepared event");
2154 if self.hash_chaining {
2155 self.last_hash = event.hash.clone();
2156 }
2157 self.events.push(event);
2158 self.journal_lines += 1;
2159 self.events.len() - 1
2160 }
2161 };
2162 (index, prepared.line)
2163 }
2164
2165 pub fn append_critical(
2176 &mut self,
2177 kind: EventKind,
2178 action_id: Option<&str>,
2179 proposal_id: Option<&str>,
2180 data: HashMap<String, Value>,
2181 ) -> Result<&Event, String> {
2182 if self.journal.is_none() {
2183 return Err("critical lifecycle event requires an enabled journal".to_string());
2184 }
2185 let prepared = self.prepare_critical_append(kind, action_id, proposal_id, data)?;
2186 let acknowledgement = self
2187 .journal
2188 .as_ref()
2189 .expect("journal presence checked above")
2190 .enqueue_critical_sync(prepared.line.clone(), prepared.known_existing)
2191 .map_err(|error| error.to_string())?;
2192 let (index, line) = self.commit_prepared_critical(prepared);
2193 self.critical_pending.insert(line.clone());
2194 let result = acknowledgement
2195 .recv()
2196 .map_err(|_| {
2197 std::io::Error::new(
2198 std::io::ErrorKind::BrokenPipe,
2199 "journal writer stopped before critical acknowledgement",
2200 )
2201 })
2202 .and_then(|result| result);
2203 match result {
2204 Ok(()) => {
2205 self.critical_pending.remove(&line);
2206 Ok(&self.events[index])
2207 }
2208 Err(error) => {
2209 self.critical_pending.insert(line);
2210 Err(format!("critical journal append was not durable: {error}"))
2211 }
2212 }
2213 }
2214
2215 pub fn append_critical_bounded(
2223 &mut self,
2224 kind: EventKind,
2225 action_id: Option<&str>,
2226 proposal_id: Option<&str>,
2227 data: HashMap<String, Value>,
2228 acknowledgement_timeout: Duration,
2229 ) -> Result<&Event, CriticalAppendError> {
2230 if acknowledgement_timeout.is_zero()
2231 || acknowledgement_timeout > MAX_CRITICAL_ACKNOWLEDGEMENT_TIMEOUT
2232 {
2233 return Err(CriticalAppendError::Rejected {
2234 reason: CriticalPreAcceptanceError::InvalidAcknowledgementTimeout {
2235 requested: acknowledgement_timeout,
2236 }
2237 .to_string(),
2238 });
2239 }
2240 let prepared = self
2241 .prepare_critical_append(kind, action_id, proposal_id, data)
2242 .map_err(|reason| CriticalAppendError::Rejected { reason })?;
2243 if prepared.known_existing && self.journal.is_none() && self.journal_path.is_some() {
2244 let (index, _) = self.commit_prepared_critical(prepared);
2245 return Ok(&self.events[index]);
2246 }
2247 if self.journal.is_none() {
2248 let path = self
2249 .journal_path
2250 .clone()
2251 .ok_or_else(|| CriticalAppendError::Rejected {
2252 reason: "critical lifecycle event requires an enabled journal".to_string(),
2253 })?;
2254 self.journal = Some(JournalWriter::spawn(path));
2255 }
2256 let acknowledgement = self
2257 .journal
2258 .as_ref()
2259 .expect("lazy journal writer installed above")
2260 .enqueue_critical_sync(prepared.line.clone(), prepared.known_existing)
2261 .map_err(|error| CriticalAppendError::Rejected {
2262 reason: error.to_string(),
2263 })?;
2264 let (index, line) = self.commit_prepared_critical(prepared);
2265 self.critical_pending.insert(line.clone());
2266 let result = match acknowledgement.recv_timeout(acknowledgement_timeout) {
2267 Ok(result) => result.map_err(|error| error.to_string()),
2268 Err(mpsc::RecvTimeoutError::Timeout) => Err(format!(
2269 "journal writer did not acknowledge within {}ms",
2270 acknowledgement_timeout.as_millis()
2271 )),
2272 Err(mpsc::RecvTimeoutError::Disconnected) => {
2273 Err("journal writer stopped before critical acknowledgement".to_string())
2274 }
2275 };
2276 match result {
2277 Ok(()) => {
2278 self.critical_pending.remove(&line);
2279 Ok(&self.events[index])
2280 }
2281 Err(reason) => Err(CriticalAppendError::DurabilityUnknown { reason }),
2282 }
2283 }
2284
2285 pub async fn append_critical_async(
2297 &mut self,
2298 kind: EventKind,
2299 action_id: Option<&str>,
2300 proposal_id: Option<&str>,
2301 data: HashMap<String, Value>,
2302 acknowledgement_timeout: Duration,
2303 ) -> Result<&Event, CriticalAppendError> {
2304 let reservation = self
2305 .journal
2306 .as_ref()
2307 .ok_or_else(|| CriticalAppendError::Rejected {
2308 reason: "critical lifecycle event requires an enabled journal".to_string(),
2309 })?
2310 .reserve_async_acknowledgement(acknowledgement_timeout)
2311 .map_err(|error| CriticalAppendError::Rejected {
2312 reason: error.to_string(),
2313 })?;
2314 let prepared = self
2315 .prepare_critical_append(kind, action_id, proposal_id, data)
2316 .map_err(|reason| CriticalAppendError::Rejected { reason })?;
2317 let acknowledgement = self
2318 .journal
2319 .as_ref()
2320 .expect("journal presence checked before reservation")
2321 .enqueue_critical_async(prepared.line.clone(), prepared.known_existing, reservation)
2322 .map_err(|error| CriticalAppendError::Rejected {
2323 reason: error.to_string(),
2324 })?;
2325 let (index, line) = self.commit_prepared_critical(prepared);
2326
2327 self.critical_pending.insert(line.clone());
2330 match acknowledgement.await {
2331 Ok(()) => {
2332 self.critical_pending.remove(&line);
2333 Ok(&self.events[index])
2334 }
2335 Err(error) => Err(CriticalAppendError::DurabilityUnknown {
2336 reason: error.to_string(),
2337 }),
2338 }
2339 }
2340
2341 pub fn verify_chain(&self) -> Result<usize, usize> {
2362 let mut prev = String::new();
2363 let mut verified = 0usize;
2364 let mut chain_started = false;
2365 for (i, ev) in self.events.iter().enumerate() {
2366 let Some(stored) = &ev.hash else {
2367 if chain_started {
2369 return Err(i);
2370 }
2371 continue;
2372 };
2373 let recorded_prev = ev.prev_hash.clone().unwrap_or_default();
2375 if chain_started && recorded_prev != prev {
2376 return Err(i);
2377 }
2378 let recomputed = event_digest(
2379 &recorded_prev,
2380 &ev.kind,
2381 ev.run_id.as_deref(),
2382 ev.client_id.as_deref(),
2383 ev.policy_session_id.as_deref(),
2384 ev.action_id.as_deref(),
2385 ev.proposal_id.as_deref(),
2386 &ev.data,
2387 &ev.timestamp,
2388 );
2389 if &recomputed != stored {
2390 return Err(i);
2391 }
2392 prev = stored.clone();
2393 chain_started = true;
2394 verified += 1;
2395 }
2396 Ok(verified)
2397 }
2398
2399 pub fn append_metered(
2406 &mut self,
2407 kind: EventKind,
2408 action_id: Option<&str>,
2409 proposal_id: Option<&str>,
2410 mut data: HashMap<String, Value>,
2411 metrics: Metrics,
2412 ) -> &Event {
2413 metrics.merge_into(&mut data);
2414 self.append(kind, action_id, proposal_id, data)
2415 }
2416
2417 pub fn metrics_totals(&self) -> MetricsTotals {
2429 metrics_totals_of(&self.events)
2430 }
2431
2432 pub fn cost_by_agent(&self) -> Vec<AgentCost> {
2434 cost_by_agent_of(&self.events)
2435 }
2436
2437 pub fn events(&self) -> &[Event] {
2438 &self.events
2439 }
2440
2441 pub fn len(&self) -> usize {
2442 self.events.len()
2443 }
2444
2445 pub fn span_len(&self) -> usize {
2446 self.spans.len()
2447 }
2448
2449 pub fn is_empty(&self) -> bool {
2450 self.events.is_empty()
2451 }
2452
2453 pub fn stats(&self) -> EventLogStats {
2454 EventLogStats {
2455 events: self.events.len(),
2456 spans: self.spans.len(),
2457 approx_event_bytes: approx_json_bytes(&self.events),
2458 approx_span_bytes: approx_json_bytes(&self.spans),
2459 }
2460 }
2461
2462 pub fn truncate_events_keep_last(&mut self, keep_last: usize) -> usize {
2463 let removed = truncate_vec_keep_last(&mut self.events, keep_last);
2464 self.trimmed_events += removed as u64;
2465 if removed > 0 {
2466 self.maybe_compact_journal();
2467 }
2468 removed
2469 }
2470
2471 pub fn truncate_spans_keep_last(&mut self, keep_last: usize) -> usize {
2472 truncate_vec_keep_last(&mut self.spans, keep_last)
2473 }
2474
2475 pub fn clear(&mut self) -> EventLogStats {
2480 let removed = self.stats();
2481 self.trimmed_events += removed.events as u64;
2482 self.events.clear();
2483 self.events.shrink_to_fit();
2484 self.spans.clear();
2485 self.spans.shrink_to_fit();
2486 removed
2487 }
2488
2489 pub fn trimmed_events(&self) -> u64 {
2495 self.trimmed_events
2496 }
2497
2498 pub fn cumulative_cost_usd(&self) -> f64 {
2505 self.cumulative_cost_usd
2506 }
2507
2508 pub fn journal_size_bytes(&self) -> Option<u64> {
2512 let path = self.journal_path.as_ref()?;
2513 fs::metadata(path).ok().map(|m| m.len())
2514 }
2515
2516 fn maybe_compact_journal(&mut self) {
2522 if self.journal_path.is_none() {
2523 return;
2524 }
2525 let excess = self.journal_lines.saturating_sub(self.events.len());
2526 if excess >= JOURNAL_COMPACT_MIN_EXCESS && excess.saturating_mul(4) >= self.journal_lines {
2527 self.compact_journal();
2528 }
2529 }
2530
2531 pub fn compact_journal(&mut self) -> bool {
2549 let Some(path) = self.journal_path.clone() else {
2550 return false;
2551 };
2552 let compacted_lines: HashSet<String> = self
2553 .events
2554 .iter()
2555 .filter_map(|event| serde_json::to_string(event).ok())
2556 .collect();
2557 self.journal = None;
2559 let file_name = path
2560 .file_name()
2561 .and_then(|name| name.to_str())
2562 .unwrap_or("journal");
2563 let tmp = path.with_file_name(format!(".{file_name}.compact-{}.tmp", Uuid::new_v4()));
2564 let rewrite = (|| -> std::io::Result<()> {
2565 let file = create_private_file(&tmp)?;
2566 let mut writer = BufWriter::new(file);
2567 for ev in &self.events {
2568 let line = serde_json::to_string(ev).map_err(std::io::Error::other)?;
2569 writeln!(writer, "{line}")?;
2570 }
2571 writer.flush()?;
2572 let file = writer.into_inner().map_err(|error| error.into_error())?;
2573 file.sync_all()?;
2574 revalidate_private_file(&file)?;
2575 drop(file);
2576 atomic_replace_private_file(&tmp, &path)
2577 })();
2578 let ok = match rewrite {
2579 Ok(()) => {
2580 self.journal_lines = self.events.len();
2581 self.critical_pending
2587 .retain(|line| !compacted_lines.contains(line));
2588 true
2589 }
2590 Err(e) => {
2591 let _ = fs::remove_file(&tmp);
2592 tracing::warn!(
2593 path = %path.display(), error = %e,
2594 "car-eventlog: journal compaction failed — journal keeps growing until the next successful compaction"
2595 );
2596 false
2597 }
2598 };
2599 self.journal = Some(JournalWriter::spawn(path));
2600 ok
2601 }
2602
2603 pub fn query(&self, query: &EventQuery) -> Vec<&Event> {
2606 let mut out: Vec<&Event> = self.events.iter().filter(|e| query.matches(e)).collect();
2607 out.reverse(); if let Some(limit) = query.limit.filter(|l| *l > 0) {
2609 out.truncate(limit);
2610 }
2611 out
2612 }
2613
2614 pub fn set_retention(&mut self, policy: Option<RetentionPolicy>) {
2618 self.retention = policy;
2619 }
2620
2621 pub fn retention(&self) -> Option<&RetentionPolicy> {
2623 self.retention.as_ref()
2624 }
2625
2626 pub fn enforce_retention(&mut self, policy: &RetentionPolicy, now: DateTime<Utc>) -> usize {
2634 let before = self.events.len();
2635 if let Some(age) = policy.max_age_secs {
2636 let cutoff = now - chrono::Duration::seconds(age);
2637 self.events.retain(|e| e.timestamp >= cutoff);
2638 }
2639 if let Some(max) = policy.max_events {
2640 truncate_vec_keep_last(&mut self.events, max);
2641 }
2642 let removed = before.saturating_sub(self.events.len());
2643 self.trimmed_events += removed as u64;
2644 if removed > 0 {
2645 self.maybe_compact_journal();
2646 }
2647 removed
2648 }
2649
2650 pub fn filter(&self, kind: Option<&EventKind>, action_id: Option<&str>) -> Vec<&Event> {
2651 self.events
2652 .iter()
2653 .filter(|e| {
2654 if let Some(k) = kind {
2655 if &e.kind != k {
2656 return false;
2657 }
2658 }
2659 if let Some(aid) = action_id {
2660 if e.action_id.as_deref() != Some(aid) {
2661 return false;
2662 }
2663 }
2664 true
2665 })
2666 .collect()
2667 }
2668
2669 pub fn begin_span(
2671 &mut self,
2672 name: &str,
2673 trace_id: &str,
2674 parent_span_id: Option<&str>,
2675 attributes: HashMap<String, Value>,
2676 ) -> String {
2677 let span_id = Uuid::new_v4().to_string();
2678 let span = Span {
2679 trace_id: trace_id.to_string(),
2680 span_id: span_id.clone(),
2681 parent_span_id: parent_span_id.map(|s| s.to_string()),
2682 name: name.to_string(),
2683 start_time: Utc::now(),
2684 end_time: None,
2685 status: SpanStatus::Unset,
2686 attributes,
2687 };
2688 self.spans.push(span);
2689 span_id
2690 }
2691
2692 pub fn end_span(&mut self, span_id: &str, status: SpanStatus) {
2694 if let Some(span) = self.spans.iter_mut().find(|s| s.span_id == span_id) {
2695 span.end_time = Some(Utc::now());
2696 span.status = status;
2697 }
2698 }
2699
2700 pub fn spans(&self) -> Vec<Span> {
2702 self.spans.clone()
2703 }
2704
2705 pub fn export_traces(&self) -> String {
2707 let mut traces: HashMap<&str, Vec<&Span>> = HashMap::new();
2709 for span in &self.spans {
2710 traces.entry(span.trace_id.as_str()).or_default().push(span);
2711 }
2712
2713 let resource_spans: Vec<Value> = traces.into_values().map(|spans| {
2714 let scope_spans = spans
2715 .iter()
2716 .map(|s| {
2717 let mut span_obj = serde_json::json!({
2718 "traceId": s.trace_id,
2719 "spanId": s.span_id,
2720 "name": s.name,
2721 "startTimeUnixNano": s.start_time.timestamp_nanos_opt().unwrap_or(0).to_string(),
2722 "status": {
2723 "code": match s.status {
2724 SpanStatus::Ok => 1,
2725 SpanStatus::Error => 2,
2726 SpanStatus::Unset => 0,
2727 }
2728 },
2729 "attributes": s.attributes.iter().map(|(k, v)| {
2730 serde_json::json!({
2731 "key": k,
2732 "value": { "stringValue": v.to_string() }
2733 })
2734 }).collect::<Vec<_>>(),
2735 });
2736
2737 if let Some(ref parent) = s.parent_span_id {
2738 span_obj.as_object_mut().unwrap().insert(
2739 "parentSpanId".to_string(),
2740 Value::from(parent.as_str()),
2741 );
2742 }
2743 if let Some(end) = s.end_time {
2744 span_obj.as_object_mut().unwrap().insert(
2745 "endTimeUnixNano".to_string(),
2746 Value::from(end.timestamp_nanos_opt().unwrap_or(0).to_string()),
2747 );
2748 }
2749
2750 span_obj
2751 })
2752 .collect::<Vec<_>>();
2753
2754 serde_json::json!({
2755 "resource": {
2756 "attributes": [
2757 { "key": "service.name", "value": { "stringValue": "car-runtime" } }
2758 ]
2759 },
2760 "scopeSpans": [{
2761 "scope": { "name": "car-eventlog" },
2762 "spans": scope_spans
2763 }]
2764 })
2765 })
2766 .collect();
2767
2768 serde_json::to_string(&serde_json::json!({
2769 "resourceSpans": resource_spans
2770 }))
2771 .unwrap_or_else(|_| "{}".to_string())
2772 }
2773
2774 pub fn load(path: &Path) -> std::io::Result<Self> {
2776 Self::load_with_writer(path, JournalWriter::spawn(path.to_path_buf()))
2777 }
2778
2779 pub fn load_for_reconciliation(path: &Path) -> std::io::Result<Self> {
2785 Self::load_from_journal(path, None, true)
2786 }
2787
2788 pub fn load_read_only(path: &Path) -> std::io::Result<Self> {
2793 Self::load_from_journal(path, None, false)
2794 }
2795
2796 #[doc(hidden)]
2799 pub fn load_with_journal_failure_injector(
2800 path: &Path,
2801 failures: JournalFailureInjector,
2802 ) -> std::io::Result<Self> {
2803 Self::load_with_writer(
2804 path,
2805 JournalWriter::spawn_with_injector(path.to_path_buf(), failures),
2806 )
2807 }
2808
2809 fn load_with_writer(path: &Path, writer: JournalWriter) -> std::io::Result<Self> {
2810 Self::load_from_journal(path, Some(writer), true)
2811 }
2812
2813 fn load_from_journal(
2814 path: &Path,
2815 writer: Option<JournalWriter>,
2816 repair_torn_tail: bool,
2817 ) -> std::io::Result<Self> {
2818 let file = fs::File::open(path)?;
2819 let mut reader = BufReader::new(file);
2820 let mut events = Vec::new();
2821 let mut event_lines = Vec::new();
2822 let mut line_bytes = Vec::new();
2823 let mut line_number = 0usize;
2824 let mut torn_tail_line = None;
2825
2826 loop {
2827 line_bytes.clear();
2828 let bytes_read = reader.read_until(b'\n', &mut line_bytes)?;
2829 if bytes_read == 0 {
2830 break;
2831 }
2832 line_number += 1;
2833 let terminated = line_bytes.ends_with(b"\n");
2834 if line_bytes.iter().all(|byte| byte.is_ascii_whitespace()) {
2835 if !terminated {
2836 torn_tail_line = Some(line_number);
2837 }
2838 continue;
2839 }
2840 match serde_json::from_slice::<Event>(&line_bytes) {
2841 Ok(event) => {
2842 events.push(event);
2843 event_lines.push(line_number);
2844 if !terminated {
2845 torn_tail_line = Some(line_number);
2846 }
2847 }
2848 Err(_) if !terminated => {
2849 torn_tail_line = Some(line_number);
2854 }
2855 Err(error) => {
2856 return Err(invalid_journal_data(path, line_number, error));
2857 }
2858 }
2859 if !terminated {
2860 break;
2861 }
2862 }
2863 drop(reader);
2864
2865 let last_hash = events.last().and_then(|e| e.hash.clone());
2871 let hash_chaining = last_hash.is_some();
2872 let cumulative_cost_usd = events.iter().filter_map(Event::cost_usd).sum();
2877 let journal_lines = events.len();
2878 let loaded = Self {
2879 events,
2880 spans: Vec::new(),
2881 journal: writer,
2884 hash_chaining,
2885 last_hash,
2886 retention: None,
2887 journal_path: repair_torn_tail.then(|| path.to_path_buf()),
2888 journal_lines,
2889 trimmed_events: 0,
2890 cumulative_cost_usd,
2891 active_binding: None,
2892 critical_pending: HashSet::new(),
2893 };
2894 if let Err(index) = loaded.verify_chain() {
2895 let source_line = event_lines.get(index).copied().unwrap_or(index + 1);
2896 return Err(invalid_journal_data(
2897 path,
2898 source_line,
2899 "hash chain integrity check failed",
2900 ));
2901 }
2902 if let Some(line_number) = torn_tail_line {
2903 if !repair_torn_tail {
2904 return Err(torn_journal_tail(path, line_number));
2905 }
2906 rewrite_loaded_journal(path, &loaded.events)?;
2907 }
2908 Ok(loaded)
2909 }
2910}
2911
2912fn torn_journal_tail(path: &Path, line_number: usize) -> std::io::Error {
2913 std::io::Error::new(
2914 std::io::ErrorKind::UnexpectedEof,
2915 format!(
2916 "event journal torn tail: path={} line={} reason=unterminated final record",
2917 path.display(),
2918 line_number
2919 ),
2920 )
2921}
2922
2923fn invalid_journal_data(
2924 path: &Path,
2925 line_number: usize,
2926 reason: impl std::fmt::Display,
2927) -> std::io::Error {
2928 std::io::Error::new(
2929 std::io::ErrorKind::InvalidData,
2930 format!(
2931 "event journal corruption: path={} line={} reason={reason}",
2932 path.display(),
2933 line_number
2934 ),
2935 )
2936}
2937
2938fn rewrite_loaded_journal(path: &Path, events: &[Event]) -> std::io::Result<()> {
2939 let file_name = path
2940 .file_name()
2941 .and_then(|name| name.to_str())
2942 .unwrap_or("journal");
2943 let temp = path.with_file_name(format!(".{file_name}.recover-{}.tmp", Uuid::new_v4()));
2944 let result = (|| {
2945 let file = create_private_file(&temp)?;
2946 let mut output = BufWriter::new(file);
2947 for event in events {
2948 let line = serde_json::to_string(event).map_err(std::io::Error::other)?;
2949 writeln!(output, "{line}")?;
2950 }
2951 output.flush()?;
2952 let file = output.into_inner().map_err(|error| error.into_error())?;
2953 file.sync_all()?;
2954 revalidate_private_file(&file)?;
2955 drop(file);
2956 atomic_replace_private_file(&temp, path)
2957 })();
2958 if result.is_err() {
2959 let _ = fs::remove_file(&temp);
2960 }
2961 result
2962}
2963
2964fn approx_json_bytes<T: Serialize>(value: &T) -> usize {
2965 serde_json::to_vec(value)
2966 .map(|bytes| bytes.len())
2967 .unwrap_or(0)
2968}
2969
2970fn truncate_vec_keep_last<T>(items: &mut Vec<T>, keep_last: usize) -> usize {
2971 let len = items.len();
2972 if len <= keep_last {
2973 return 0;
2974 }
2975 let removed = len - keep_last;
2976 items.drain(..removed);
2977 items.shrink_to_fit();
2978 removed
2979}
2980
2981impl Default for EventLog {
2982 fn default() -> Self {
2983 Self::new()
2984 }
2985}
2986
2987#[cfg(test)]
2988mod tests {
2989 use super::*;
2990
2991 struct ThreadWake(std::thread::Thread);
2992
2993 impl std::task::Wake for ThreadWake {
2994 fn wake(self: Arc<Self>) {
2995 self.0.unpark();
2996 }
2997
2998 fn wake_by_ref(self: &Arc<Self>) {
2999 self.0.unpark();
3000 }
3001 }
3002
3003 fn test_waker() -> std::task::Waker {
3004 std::task::Waker::from(Arc::new(ThreadWake(std::thread::current())))
3005 }
3006
3007 fn block_on_test_future<F: std::future::Future>(future: F) -> F::Output {
3008 let waker = test_waker();
3009 let mut context = std::task::Context::from_waker(&waker);
3010 let mut future = Box::pin(future);
3011 loop {
3012 match future.as_mut().poll(&mut context) {
3013 std::task::Poll::Ready(output) => return output,
3014 std::task::Poll::Pending => std::thread::park(),
3015 }
3016 }
3017 }
3018
3019 #[test]
3020 fn append_and_read() {
3021 let mut log = EventLog::new();
3022 log.append(
3023 EventKind::ProposalReceived,
3024 None,
3025 Some("p1"),
3026 [("source".to_string(), Value::from("test"))].into(),
3027 );
3028 assert_eq!(log.len(), 1);
3029 assert_eq!(log.events()[0].kind, EventKind::ProposalReceived);
3030 }
3031
3032 #[test]
3033 fn query_filters_by_kind_data_and_time() {
3034 let mut log = EventLog::new();
3035 log.append(
3036 EventKind::PermissionDecision,
3037 Some("a1"),
3038 None,
3039 [
3040 ("caller".to_string(), Value::from("alice")),
3041 ("tool".to_string(), Value::from("shell")),
3042 ]
3043 .into(),
3044 );
3045 log.append(
3046 EventKind::PermissionDecision,
3047 Some("a2"),
3048 None,
3049 [
3050 ("caller".to_string(), Value::from("bob")),
3051 ("tool".to_string(), Value::from("shell")),
3052 ]
3053 .into(),
3054 );
3055 log.append(
3056 EventKind::StateChanged,
3057 Some("a3"),
3058 None,
3059 Default::default(),
3060 );
3061
3062 let q = EventQuery {
3064 kinds: vec![EventKind::PermissionDecision],
3065 ..Default::default()
3066 };
3067 assert_eq!(log.query(&q).len(), 2);
3068
3069 let q = EventQuery {
3071 data_matches: [("caller".to_string(), "alice".to_string())].into(),
3072 ..Default::default()
3073 };
3074 let hits = log.query(&q);
3075 assert_eq!(hits.len(), 1);
3076 assert_eq!(hits[0].action_id.as_deref(), Some("a1"));
3077
3078 let q = EventQuery {
3080 kinds: vec![EventKind::PermissionDecision],
3081 data_matches: [("tool".to_string(), "shell".to_string())].into(),
3082 limit: Some(1),
3083 ..Default::default()
3084 };
3085 let hits = log.query(&q);
3087 assert_eq!(hits.len(), 1);
3088 assert_eq!(hits[0].action_id.as_deref(), Some("a2"));
3089 }
3090
3091 #[test]
3092 fn cost_by_agent_folds_metered_events() {
3093 let mut log = EventLog::new();
3094 log.append_metered(
3095 EventKind::InferenceMetered,
3096 None,
3097 None,
3098 [("agent".to_string(), Value::from("researcher"))].into(),
3099 Metrics {
3100 tokens_in: Some(100),
3101 tokens_out: Some(50),
3102 cost_usd: Some(2.0),
3103 ..Default::default()
3104 },
3105 );
3106 log.append_metered(
3107 EventKind::InferenceMetered,
3108 None,
3109 None,
3110 [("agent".to_string(), Value::from("researcher"))].into(),
3111 Metrics {
3112 tokens_in: Some(10),
3113 tokens_out: Some(5),
3114 cost_usd: Some(0.2),
3115 ..Default::default()
3116 },
3117 );
3118 log.append_metered(
3119 EventKind::InferenceMetered,
3120 None,
3121 None,
3122 [("agent".to_string(), Value::from("coordinator"))].into(),
3123 Metrics {
3124 cost_usd: Some(0.5),
3125 ..Default::default()
3126 },
3127 );
3128 let report = log.cost_by_agent();
3129 assert_eq!(report.len(), 2);
3130 assert_eq!(report[0].agent, "coordinator");
3132 assert_eq!(report[0].cost_usd, 0.5);
3133 assert_eq!(report[1].agent, "researcher");
3134 assert_eq!(report[1].calls, 2);
3135 assert_eq!(report[1].tokens_in, 110);
3136 assert_eq!(report[1].tokens_out, 55);
3137 assert!((report[1].cost_usd - 2.2).abs() < 1e-9);
3138 }
3139
3140 #[test]
3146 fn cost_by_agent_skips_summary_rows() {
3147 let mut log = EventLog::new();
3148 log.append_metered(
3150 EventKind::InferenceMetered,
3151 None,
3152 None,
3153 [
3154 ("agent".to_string(), Value::from("agent:bot")),
3155 ("call_id".to_string(), Value::from("call-1")),
3156 ]
3157 .into(),
3158 Metrics::inference(100, 50, Some(2.0)),
3159 );
3160 log.append_metered(
3162 EventKind::InferenceMetered,
3163 None,
3164 None,
3165 [
3166 ("agent".to_string(), Value::from("agent:bot")),
3167 ("sub_agent".to_string(), Value::from("Researcher")),
3168 (SUMMARY_OF.to_string(), Value::from("infer")),
3169 ("reported_cost_usd".to_string(), Value::from(2.0)),
3170 ]
3171 .into(),
3172 Metrics::inference(100, 50, Some(2.0)).with_duration(10.0),
3173 );
3174 log.append_metered(
3176 EventKind::InferenceMetered,
3177 None,
3178 None,
3179 [
3180 ("agent".to_string(), Value::from("agent:bot")),
3181 ("sub_agent".to_string(), Value::from("Verifier")),
3182 ("reported_cost_usd".to_string(), Value::from(0.5)),
3183 ]
3184 .into(),
3185 Metrics::inference(10, 5, Some(0.5)),
3186 );
3187 let report = log.cost_by_agent();
3188 assert_eq!(report.len(), 1, "{report:?}");
3189 let bot = &report[0];
3190 assert_eq!(bot.agent, "agent:bot");
3191 assert_eq!((bot.calls, bot.tokens_in, bot.tokens_out), (2, 110, 55));
3192 assert!((bot.cost_usd - 2.5).abs() < 1e-9, "{bot:?}");
3193 }
3194
3195 #[test]
3201 fn metrics_totals_skip_summary_rows() {
3202 let mut log = EventLog::new();
3203 log.append_metered(
3204 EventKind::InferenceMetered,
3205 None,
3206 None,
3207 [("call_id".to_string(), Value::from("call-1"))].into(),
3208 Metrics::inference(100, 50, Some(2.0)).with_duration(30.0),
3209 );
3210 log.append_metered(
3211 EventKind::InferenceMetered,
3212 None,
3213 None,
3214 [(SUMMARY_OF.to_string(), Value::from("infer"))].into(),
3215 Metrics::inference(100, 50, Some(2.0)).with_duration(45.0),
3216 );
3217 let t = log.metrics_totals();
3218 assert_eq!((t.tokens_in, t.tokens_out, t.tokens), (100, 50, 150));
3219 assert_eq!(t.cost_usd, 2.0);
3220 assert_eq!(t.duration_ms, 30.0);
3221 assert_eq!(t.metered_events, 1);
3222 assert_eq!(log.events()[1].tokens_in(), Some(100));
3224 assert_eq!(log.events()[1].cost_usd(), Some(2.0));
3225 }
3226
3227 #[test]
3228 fn auto_retention_caps_event_count() {
3229 let mut log = EventLog::new();
3230 log.set_retention(Some(RetentionPolicy {
3231 max_events: Some(3),
3232 max_age_secs: None,
3233 }));
3234 for i in 0..10 {
3235 log.append(
3236 EventKind::StateChanged,
3237 Some(&format!("a{i}")),
3238 None,
3239 Default::default(),
3240 );
3241 }
3242 assert_eq!(log.len(), 3);
3244 assert_eq!(log.events()[0].action_id.as_deref(), Some("a7"));
3245 assert_eq!(log.events()[2].action_id.as_deref(), Some("a9"));
3246 }
3247
3248 #[test]
3249 fn enforce_retention_drops_old_by_age() {
3250 let mut log = EventLog::new();
3251 log.append(
3253 EventKind::StateChanged,
3254 Some("old"),
3255 None,
3256 Default::default(),
3257 );
3258 log.events[0].timestamp = Utc::now() - chrono::Duration::seconds(3600);
3259 log.append(
3260 EventKind::StateChanged,
3261 Some("fresh"),
3262 None,
3263 Default::default(),
3264 );
3265
3266 let removed = log.enforce_retention(
3267 &RetentionPolicy {
3268 max_events: None,
3269 max_age_secs: Some(60),
3270 },
3271 Utc::now(),
3272 );
3273 assert_eq!(removed, 1);
3274 assert_eq!(log.len(), 1);
3275 assert_eq!(log.events()[0].action_id.as_deref(), Some("fresh"));
3276 }
3277
3278 #[test]
3279 fn retention_trims_are_counted() {
3280 let mut log = EventLog::new();
3281 log.set_retention(Some(RetentionPolicy {
3282 max_events: Some(2),
3283 max_age_secs: None,
3284 }));
3285 for i in 0..5 {
3286 log.append(
3287 EventKind::StateChanged,
3288 Some(&format!("a{i}")),
3289 None,
3290 Default::default(),
3291 );
3292 }
3293 assert_eq!(log.trimmed_events(), 3);
3294 assert_eq!(log.truncate_events_keep_last(1), 1);
3295 assert_eq!(log.trimmed_events(), 4);
3296 log.clear();
3297 assert_eq!(log.trimmed_events(), 5);
3298 }
3299
3300 #[test]
3301 fn cumulative_cost_is_monotonic_across_trims_and_reload() {
3302 let dir = tempfile::tempdir().unwrap();
3303 let journal = dir.path().join("cost.jsonl");
3304 {
3305 let mut log = EventLog::with_journal(journal.clone());
3306 log.set_retention(Some(RetentionPolicy {
3307 max_events: Some(1),
3308 max_age_secs: None,
3309 }));
3310 for _ in 0..4 {
3311 log.append_metered(
3312 EventKind::InferenceMetered,
3313 None,
3314 None,
3315 Default::default(),
3316 Metrics {
3317 cost_usd: Some(2.5),
3318 ..Default::default()
3319 },
3320 );
3321 }
3322 assert_eq!(log.len(), 1);
3324 assert!((log.cumulative_cost_usd() - 10.0).abs() < 1e-9);
3325 }
3326 let reloaded = EventLog::load(&journal).unwrap();
3329 assert!((reloaded.cumulative_cost_usd() - 10.0).abs() < 1e-9);
3330 }
3331
3332 #[test]
3333 fn journal_compaction_rewrites_to_retained_set() {
3334 let dir = tempfile::tempdir().unwrap();
3339 let journal = dir.path().join("compact.jsonl");
3340 let keep = 16usize;
3341 let total = keep + JOURNAL_COMPACT_MIN_EXCESS + 8;
3342 {
3343 let mut log = EventLog::with_journal(journal.clone());
3344 log.set_retention(Some(RetentionPolicy {
3345 max_events: Some(keep),
3346 max_age_secs: None,
3347 }));
3348 for i in 0..total {
3349 log.append(
3350 EventKind::ActionSucceeded,
3351 Some(&format!("a{i}")),
3352 None,
3353 HashMap::new(),
3354 );
3355 }
3356 assert_eq!(log.len(), keep);
3357 assert!(log.journal_size_bytes().unwrap_or(0) > 0);
3358 } let reloaded = EventLog::load(&journal).unwrap();
3362 assert!(
3363 reloaded.len() < total,
3364 "journal must have been compacted (got {} lines)",
3365 reloaded.len()
3366 );
3367 assert_eq!(
3369 reloaded.events().last().unwrap().action_id.as_deref(),
3370 Some(format!("a{}", total - 1).as_str())
3371 );
3372 }
3373
3374 #[test]
3375 fn compact_journal_preserves_hash_chain_of_retained_tail() {
3376 let dir = tempfile::tempdir().unwrap();
3380 let journal = dir.path().join("chained.jsonl");
3381 {
3382 let mut log = EventLog::with_journal(journal.clone()).with_hash_chaining();
3383 for i in 0..20 {
3384 log.append(
3385 EventKind::ActionSucceeded,
3386 Some(&format!("a{i}")),
3387 None,
3388 HashMap::new(),
3389 );
3390 }
3391 log.truncate_events_keep_last(5);
3393 assert!(log.compact_journal(), "compaction must succeed");
3394 log.append(
3397 EventKind::ActionSucceeded,
3398 Some("post"),
3399 None,
3400 HashMap::new(),
3401 );
3402 }
3403 let reloaded = EventLog::load(&journal).unwrap();
3404 assert_eq!(reloaded.len(), 6);
3405 assert_eq!(reloaded.verify_chain(), Ok(6), "retained tail must verify");
3406 assert_eq!(reloaded.events()[0].action_id.as_deref(), Some("a15"));
3407 assert_eq!(reloaded.events()[5].action_id.as_deref(), Some("post"));
3408 }
3409
3410 #[test]
3411 fn compact_journal_without_journal_is_noop() {
3412 let mut log = EventLog::new();
3413 log.append(EventKind::StateChanged, Some("a"), None, Default::default());
3414 assert!(!log.compact_journal());
3415 assert_eq!(log.journal_size_bytes(), None);
3416 }
3417
3418 #[test]
3419 fn chaining_off_by_default_no_hashes() {
3420 let mut log = EventLog::new();
3421 log.append(
3422 EventKind::ActionSucceeded,
3423 Some("a1"),
3424 Some("p1"),
3425 HashMap::new(),
3426 );
3427 assert!(!log.hash_chaining_enabled());
3428 assert!(log.events()[0].hash.is_none());
3429 assert!(log.events()[0].prev_hash.is_none());
3430 assert_eq!(log.verify_chain(), Ok(0));
3432 }
3433
3434 #[test]
3435 fn hash_chain_verifies_clean_log() {
3436 let mut log = EventLog::new().with_hash_chaining();
3437 for i in 0..5 {
3438 log.append(
3439 EventKind::ActionSucceeded,
3440 Some(&format!("a{i}")),
3441 Some("p"),
3442 [("i".to_string(), Value::from(i))].into(),
3443 );
3444 }
3445 assert!(log.events().iter().all(|e| e.hash.is_some()));
3447 assert_eq!(log.verify_chain(), Ok(5));
3448 assert_eq!(log.events()[0].prev_hash.as_deref(), Some(""));
3450 for w in log.events().windows(2) {
3452 assert_eq!(w[1].prev_hash, w[0].hash);
3453 }
3454 }
3455
3456 #[test]
3457 fn tampering_with_data_breaks_chain() {
3458 let mut log = EventLog::new().with_hash_chaining();
3459 for i in 0..4 {
3460 log.append(
3461 EventKind::ActionSucceeded,
3462 Some(&format!("a{i}")),
3463 Some("p"),
3464 [("v".to_string(), Value::from(i))].into(),
3465 );
3466 }
3467 assert_eq!(log.verify_chain(), Ok(4));
3468 log.events[2].data.insert("v".to_string(), Value::from(999));
3470 assert_eq!(log.verify_chain(), Err(2));
3472 }
3473
3474 #[test]
3475 fn deleting_an_event_breaks_chain() {
3476 let mut log = EventLog::new().with_hash_chaining();
3477 for i in 0..4 {
3478 log.append(
3479 EventKind::ActionSucceeded,
3480 Some(&format!("a{i}")),
3481 Some("p"),
3482 HashMap::new(),
3483 );
3484 }
3485 log.events.remove(1);
3488 assert_eq!(log.verify_chain(), Err(1));
3489 }
3490
3491 #[test]
3492 fn chain_survives_serialize_roundtrip() {
3493 let mut log = EventLog::new().with_hash_chaining();
3494 for i in 0..3 {
3495 log.append(
3496 EventKind::PermissionDecision,
3497 Some(&format!("a{i}")),
3498 Some("p"),
3499 [
3500 ("decision".to_string(), Value::from("allow")),
3501 ("nested".to_string(), serde_json::json!({"z": 1, "a": 2})),
3502 ]
3503 .into(),
3504 );
3505 }
3506 let lines: Vec<String> = log
3509 .events()
3510 .iter()
3511 .map(|e| serde_json::to_string(e).unwrap())
3512 .collect();
3513 let mut rebuilt = EventLog::new();
3514 for line in &lines {
3515 rebuilt.events.push(serde_json::from_str(line).unwrap());
3516 }
3517 assert_eq!(rebuilt.verify_chain(), Ok(3));
3518 }
3519
3520 #[test]
3521 fn chain_survives_journal_load_and_append() {
3522 let dir = tempfile::tempdir().unwrap();
3527 let journal = dir.path().join("chain.jsonl");
3528 {
3529 let mut log = EventLog::with_journal(journal.clone());
3530 log.enable_hash_chaining();
3531 log.append(EventKind::ActionSucceeded, Some("a1"), None, HashMap::new());
3532 log.append(EventKind::ActionSucceeded, Some("a2"), None, HashMap::new());
3533 } {
3536 let mut log = EventLog::load(&journal).unwrap();
3537 assert!(
3538 log.hash_chaining_enabled(),
3539 "loading a chained tail re-enables chaining"
3540 );
3541 log.append(EventKind::ActionSucceeded, Some("a3"), None, HashMap::new());
3542 assert_eq!(log.verify_chain(), Ok(3), "post-load append stays chained");
3543 }
3544
3545 let reloaded = EventLog::load(&journal).unwrap();
3547 assert_eq!(reloaded.len(), 3);
3548 assert_eq!(reloaded.verify_chain(), Ok(3));
3549
3550 let plain = dir.path().join("plain.jsonl");
3552 {
3553 let mut log = EventLog::with_journal(plain.clone());
3554 log.append(EventKind::ActionSucceeded, Some("a1"), None, HashMap::new());
3555 }
3556 let loaded = EventLog::load(&plain).unwrap();
3557 assert!(!loaded.hash_chaining_enabled(), "unchained tail stays off");
3558 }
3559
3560 #[test]
3561 fn metered_event_carries_metrics_in_data() {
3562 let mut log = EventLog::new();
3563 log.append_metered(
3564 EventKind::ActionSucceeded,
3565 Some("a1"),
3566 Some("p1"),
3567 [("tool".to_string(), Value::from("search"))].into(),
3568 Metrics::inference(120, 45, Some(0.0012)).with_duration(83.0),
3569 );
3570 let ev = &log.events()[0];
3571 assert_eq!(ev.data.get("tool").unwrap(), "search");
3573 assert_eq!(ev.duration_ms(), Some(83.0));
3574 assert_eq!(ev.tokens_in(), Some(120));
3575 assert_eq!(ev.tokens_out(), Some(45));
3576 assert_eq!(ev.cost_usd(), Some(0.0012));
3577 }
3578
3579 #[test]
3580 fn metrics_totals_sum_across_events() {
3581 let mut log = EventLog::new();
3582 log.append_metered(
3583 EventKind::ActionSucceeded,
3584 Some("a1"),
3585 None,
3586 HashMap::new(),
3587 Metrics::latency(50.0),
3588 );
3589 log.append_metered(
3590 EventKind::ActionSucceeded,
3591 Some("a2"),
3592 None,
3593 HashMap::new(),
3594 Metrics::inference(100, 20, Some(0.5)).with_duration(70.0),
3595 );
3596 log.append(EventKind::ProposalReceived, None, None, HashMap::new());
3598
3599 let t = log.metrics_totals();
3600 assert_eq!(t.duration_ms, 120.0);
3601 assert_eq!(t.tokens_in, 100);
3602 assert_eq!(t.tokens_out, 20);
3603 assert_eq!(t.tokens, 120);
3604 assert_eq!(t.cost_usd, 0.5);
3605 assert_eq!(t.metered_events, 2);
3606 }
3607
3608 #[test]
3609 fn metrics_totals_counts_raw_appended_duration_key() {
3610 let mut log = EventLog::new();
3615 log.append(
3616 EventKind::ActionSucceeded,
3617 Some("a1"),
3618 None,
3619 [(metric_keys::DURATION_MS.to_string(), Value::from(42.0))].into(),
3620 );
3621 let t = log.metrics_totals();
3622 assert_eq!(t.duration_ms, 42.0);
3623 assert_eq!(t.metered_events, 1);
3624 }
3625
3626 #[test]
3627 fn new_telemetry_event_kinds_serialize_snake_case() {
3628 let json = serde_json::to_string(&EventKind::BranchDecision).unwrap();
3630 assert_eq!(json, "\"branch_decision\"");
3631 let json = serde_json::to_string(&EventKind::AlternativeRejected).unwrap();
3632 assert_eq!(json, "\"alternative_rejected\"");
3633 let json = serde_json::to_string(&EventKind::InferenceMetered).unwrap();
3634 assert_eq!(json, "\"inference_metered\"");
3635 }
3636
3637 #[test]
3638 fn filter_by_kind() {
3639 let mut log = EventLog::new();
3640 log.append(
3641 EventKind::ProposalReceived,
3642 None,
3643 Some("p1"),
3644 HashMap::new(),
3645 );
3646 log.append(
3647 EventKind::ActionValidated,
3648 Some("a1"),
3649 Some("p1"),
3650 HashMap::new(),
3651 );
3652 log.append(
3653 EventKind::ActionSucceeded,
3654 Some("a1"),
3655 Some("p1"),
3656 HashMap::new(),
3657 );
3658
3659 let validated = log.filter(Some(&EventKind::ActionValidated), None);
3660 assert_eq!(validated.len(), 1);
3661 }
3662
3663 #[test]
3664 fn filter_by_action_id() {
3665 let mut log = EventLog::new();
3666 log.append(EventKind::ActionValidated, Some("a1"), None, HashMap::new());
3667 log.append(EventKind::ActionValidated, Some("a2"), None, HashMap::new());
3668
3669 let a1_events = log.filter(None, Some("a1"));
3670 assert_eq!(a1_events.len(), 1);
3671 }
3672
3673 #[test]
3674 fn journal_write_and_reload() {
3675 let dir = tempfile::tempdir().unwrap();
3676 let journal = dir.path().join("events.jsonl");
3677
3678 {
3679 let mut log = EventLog::with_journal(journal.clone());
3680 log.append(
3681 EventKind::ProposalReceived,
3682 None,
3683 Some("p1"),
3684 HashMap::new(),
3685 );
3686 log.append(
3687 EventKind::ActionSucceeded,
3688 Some("a1"),
3689 Some("p1"),
3690 HashMap::new(),
3691 );
3692 }
3693
3694 assert!(journal.exists());
3695
3696 let reloaded = EventLog::load(&journal).unwrap();
3697 assert_eq!(reloaded.len(), 2);
3698 assert_eq!(reloaded.events()[0].kind, EventKind::ProposalReceived);
3699 assert_eq!(reloaded.events()[1].kind, EventKind::ActionSucceeded);
3700 }
3701
3702 #[test]
3703 fn load_rejects_newline_terminated_corrupt_middle_before_later_terminal() {
3704 let dir = tempfile::tempdir().unwrap();
3705 let journal = dir.path().join("corrupt-middle.jsonl");
3706 let started = serde_json::json!({
3707 "kind": "run_started",
3708 "run_id": "run-corrupt",
3709 "client_id": "client-1",
3710 "data": {"agent_id": "daily-continuity-newsroom"},
3711 "timestamp": "2026-08-30T09:30:00Z"
3712 });
3713 let completed = serde_json::json!({
3714 "kind": "run_completed",
3715 "run_id": "run-corrupt",
3716 "client_id": "client-1",
3717 "data": {
3718 "completion_digest": "must-not-be-trusted",
3719 "termination": {"kind": "outcome", "status": "success", "outcome": {}}
3720 },
3721 "timestamp": "2026-08-30T10:00:00Z"
3722 });
3723 fs::write(
3724 &journal,
3725 format!("{started}\n{{this-is-not-json}}\n{completed}\n"),
3726 )
3727 .unwrap();
3728
3729 let error = match EventLog::load(&journal) {
3730 Ok(_) => panic!("newline-terminated middle corruption must fail closed"),
3731 Err(error) => error,
3732 };
3733 assert_eq!(error.kind(), std::io::ErrorKind::InvalidData);
3734 assert!(error.to_string().contains("line=2"), "{error}");
3735 }
3736
3737 #[test]
3738 fn load_repairs_crash_torn_final_record_before_append() {
3739 let dir = tempfile::tempdir().unwrap();
3740 let journal = dir.path().join("torn-tail.jsonl");
3741 let started = serde_json::json!({
3742 "kind": "run_started",
3743 "run_id": "run-torn",
3744 "client_id": "client-1",
3745 "data": {"agent_id": "daily-continuity-newsroom"},
3746 "timestamp": "2026-08-30T09:30:00Z"
3747 });
3748 let mut journal_file = create_private_file(&journal).unwrap();
3749 write!(journal_file, "{started}\n{{\"kind\":\"run_completed\"").unwrap();
3750 drop(journal_file);
3751
3752 {
3753 let mut loaded = EventLog::load(&journal).expect("torn final row is recoverable");
3754 assert_eq!(loaded.len(), 1);
3755 loaded.append(
3756 EventKind::ProposalReceived,
3757 None,
3758 Some("proposal-after-recovery"),
3759 HashMap::new(),
3760 );
3761 }
3762
3763 let bytes = fs::read_to_string(&journal).unwrap();
3764 assert!(!bytes.contains("{\"kind\":\"run_completed\""), "{bytes}");
3765 assert!(bytes.ends_with('\n'));
3766 let reloaded = EventLog::load(&journal).unwrap();
3767 assert_eq!(reloaded.len(), 2);
3768 assert_eq!(reloaded.events()[0].kind, EventKind::RunStarted);
3769 assert_eq!(reloaded.events()[1].kind, EventKind::ProposalReceived);
3770 }
3771
3772 #[test]
3773 fn load_read_only_rejects_a_torn_tail_without_modifying_the_journal() {
3774 let dir = tempfile::tempdir().unwrap();
3775 let journal = dir.path().join("read-only-torn-tail.jsonl");
3776 let started = serde_json::json!({
3777 "kind": "run_started",
3778 "run_id": "run-torn",
3779 "client_id": "client-1",
3780 "data": {"agent_id": "daily-continuity-newsroom"},
3781 "timestamp": "2026-08-30T09:30:00Z"
3782 });
3783 fs::write(&journal, format!("{started}\n{{\"kind\":\"run_completed\"")).unwrap();
3784 let before = fs::read(&journal).unwrap();
3785
3786 let error = match EventLog::load_read_only(&journal) {
3787 Ok(_) => panic!("read-only loading must expose a torn final row"),
3788 Err(error) => error,
3789 };
3790
3791 assert_eq!(error.kind(), std::io::ErrorKind::UnexpectedEof);
3792 assert!(error.to_string().contains("event journal torn tail"));
3793 assert!(error.to_string().contains("line=2"));
3794 assert_eq!(fs::read(&journal).unwrap(), before);
3795 }
3796
3797 #[test]
3798 fn load_rejects_existing_hash_chain_tampering() {
3799 let dir = tempfile::tempdir().unwrap();
3800 let journal = dir.path().join("tampered-chain.jsonl");
3801 {
3802 let mut log = EventLog::with_journal(journal.clone()).with_hash_chaining();
3803 log.append(
3804 EventKind::RunStarted,
3805 None,
3806 None,
3807 [(
3808 "agent_id".to_string(),
3809 Value::from("daily-continuity-newsroom"),
3810 )]
3811 .into(),
3812 );
3813 log.append(EventKind::RunCompleted, None, None, HashMap::new());
3814 }
3815 let mut rows: Vec<Value> = fs::read_to_string(&journal)
3816 .unwrap()
3817 .lines()
3818 .map(|line| serde_json::from_str(line).unwrap())
3819 .collect();
3820 rows[0]["data"]["agent_id"] = Value::from("tampered-agent");
3821 fs::write(
3822 &journal,
3823 rows.iter()
3824 .map(Value::to_string)
3825 .collect::<Vec<_>>()
3826 .join("\n")
3827 + "\n",
3828 )
3829 .unwrap();
3830
3831 let error = match EventLog::load(&journal) {
3832 Ok(_) => panic!("hash-chain tampering must fail closed during load"),
3833 Err(error) => error,
3834 };
3835 assert_eq!(error.kind(), std::io::ErrorKind::InvalidData);
3836 assert!(error.to_string().contains("hash chain"), "{error}");
3837 assert!(error.to_string().contains("line=1"), "{error}");
3838 }
3839
3840 #[cfg(unix)]
3841 fn unix_mode(path: &Path) -> u32 {
3842 use std::os::unix::fs::PermissionsExt;
3843 fs::symlink_metadata(path).unwrap().permissions().mode() & 0o777
3844 }
3845
3846 #[cfg(unix)]
3847 #[test]
3848 fn car_owned_journal_and_created_parents_are_private() {
3849 let root = tempfile::tempdir().unwrap();
3850 let parent = root.path().join("eventlogs").join("session");
3851 let journal = parent.join("events.jsonl");
3852 {
3853 let mut log = EventLog::with_journal(journal.clone());
3854 log.append(EventKind::StateChanged, Some("a1"), None, HashMap::new());
3855 }
3856
3857 assert_eq!(unix_mode(&root.path().join("eventlogs")), 0o700);
3858 assert_eq!(unix_mode(&parent), 0o700);
3859 assert_eq!(unix_mode(&journal), 0o600);
3860 }
3861
3862 #[cfg(unix)]
3863 #[test]
3864 fn append_hardens_preexisting_owned_permissive_journal() {
3865 use std::os::unix::fs::PermissionsExt;
3866
3867 let dir = tempfile::tempdir().unwrap();
3868 let journal = dir.path().join("events.jsonl");
3869 fs::write(&journal, b"").unwrap();
3870 fs::set_permissions(&journal, fs::Permissions::from_mode(0o644)).unwrap();
3871 {
3872 let mut log = EventLog::with_journal(journal.clone());
3873 log.append(EventKind::StateChanged, Some("a1"), None, HashMap::new());
3874 }
3875 assert_eq!(unix_mode(&journal), 0o600);
3876 }
3877
3878 #[cfg(unix)]
3879 #[test]
3880 fn journal_refuses_symlink_and_hardlink_destinations() {
3881 use std::os::unix::fs::symlink;
3882
3883 let dir = tempfile::tempdir().unwrap();
3884 let victim = dir.path().join("victim");
3885 fs::write(&victim, b"unchanged").unwrap();
3886
3887 for journal in [dir.path().join("symlink"), dir.path().join("hardlink")] {
3888 if journal.ends_with("symlink") {
3889 symlink(&victim, &journal).unwrap();
3890 } else {
3891 fs::hard_link(&victim, &journal).unwrap();
3892 }
3893 {
3894 let mut log = EventLog::with_journal(journal);
3895 log.append(EventKind::StateChanged, Some("a1"), None, HashMap::new());
3896 }
3897 assert_eq!(fs::read(&victim).unwrap(), b"unchanged");
3898 }
3899 }
3900
3901 #[cfg(unix)]
3902 #[test]
3903 fn journal_stops_if_the_opened_path_is_substituted() {
3904 let dir = tempfile::tempdir().unwrap();
3905 let journal = dir.path().join("events.jsonl");
3906 let moved = dir.path().join("moved.jsonl");
3907 let mut log = EventLog::with_journal(journal.clone());
3908 log.append(EventKind::StateChanged, Some("first"), None, HashMap::new());
3909
3910 let deadline = std::time::Instant::now() + std::time::Duration::from_secs(2);
3911 while fs::metadata(&journal).map_or(true, |metadata| metadata.len() == 0) {
3912 assert!(
3913 std::time::Instant::now() < deadline,
3914 "first event was not persisted"
3915 );
3916 std::thread::yield_now();
3917 }
3918 fs::rename(&journal, &moved).unwrap();
3919 let _substitute = create_private_file(&journal).unwrap();
3920 log.append(
3921 EventKind::StateChanged,
3922 Some("second"),
3923 None,
3924 HashMap::new(),
3925 );
3926 drop(log);
3927
3928 assert_eq!(EventLog::load(&moved).unwrap().len(), 1);
3929 assert_eq!(fs::metadata(&journal).unwrap().len(), 0);
3930 }
3931
3932 #[cfg(unix)]
3933 #[test]
3934 fn compaction_preserves_private_mode_and_leaves_no_temp_name() {
3935 let dir = tempfile::tempdir().unwrap();
3936 let journal = dir.path().join("events.jsonl");
3937 let mut log = EventLog::with_journal(journal.clone());
3938 for index in 0..4 {
3939 log.append(
3940 EventKind::StateChanged,
3941 Some(&format!("a{index}")),
3942 None,
3943 HashMap::new(),
3944 );
3945 }
3946 log.truncate_events_keep_last(2);
3947 assert!(log.compact_journal());
3948 drop(log);
3949
3950 assert_eq!(unix_mode(&journal), 0o600);
3951 let names: Vec<_> = fs::read_dir(dir.path())
3952 .unwrap()
3953 .map(|entry| entry.unwrap().file_name())
3954 .collect();
3955 assert_eq!(names, vec![journal.file_name().unwrap()]);
3956 }
3957
3958 #[cfg(unix)]
3959 #[test]
3960 fn historical_world_readable_journal_can_be_loaded_without_mutation() {
3961 use std::os::unix::fs::PermissionsExt;
3962
3963 let dir = tempfile::tempdir().unwrap();
3964 let journal = dir.path().join("historical.jsonl");
3965 let event = Event {
3966 kind: EventKind::StateChanged,
3967 run_id: None,
3968 client_id: None,
3969 policy_session_id: None,
3970 action_id: Some("historical".into()),
3971 proposal_id: None,
3972 data: HashMap::new(),
3973 timestamp: Utc::now(),
3974 prev_hash: None,
3975 hash: None,
3976 };
3977 fs::write(
3978 &journal,
3979 format!("{}\n", serde_json::to_string(&event).unwrap()),
3980 )
3981 .unwrap();
3982 fs::set_permissions(&journal, fs::Permissions::from_mode(0o644)).unwrap();
3983
3984 let loaded = EventLog::load(&journal).unwrap();
3985 assert_eq!(loaded.len(), 1);
3986 drop(loaded);
3987 assert_eq!(unix_mode(&journal), 0o644);
3988 }
3989
3990 #[test]
3991 fn journal_not_created_without_appends() {
3992 let dir = tempfile::tempdir().unwrap();
3996 let journal = dir.path().join("no-events.jsonl");
3997 {
3998 let _log = EventLog::with_journal(journal.clone());
3999 }
4002 assert!(
4003 !journal.exists(),
4004 "journal file must not be created when nothing is appended"
4005 );
4006 }
4007
4008 #[test]
4009 fn journal_preserves_order_and_count_under_burst() {
4010 let dir = tempfile::tempdir().unwrap();
4014 let journal = dir.path().join("burst.jsonl");
4015 {
4016 let mut log = EventLog::with_journal(journal.clone());
4017 for i in 0..500 {
4018 log.append(
4019 EventKind::ActionSucceeded,
4020 Some(&format!("a{i}")),
4021 None,
4022 HashMap::new(),
4023 );
4024 }
4025 } let reloaded = EventLog::load(&journal).unwrap();
4028 assert_eq!(reloaded.len(), 500, "no events lost");
4029 for (i, event) in reloaded.events().iter().enumerate() {
4030 assert_eq!(
4031 event.action_id.as_deref(),
4032 Some(format!("a{i}").as_str()),
4033 "order preserved at {i}"
4034 );
4035 }
4036 }
4037
4038 #[test]
4039 fn unopenable_journal_is_best_effort_not_fatal() {
4040 let dir = tempfile::tempdir().unwrap();
4044 let journal = dir.path().join("a-directory");
4045 fs::create_dir(&journal).unwrap(); let mut log = EventLog::with_journal(journal);
4048 log.append(
4049 EventKind::ProposalReceived,
4050 None,
4051 Some("p1"),
4052 HashMap::new(),
4053 );
4054 log.append(EventKind::ActionSucceeded, Some("a1"), None, HashMap::new());
4055 assert_eq!(
4056 log.len(),
4057 2,
4058 "in-memory log unaffected by an unwritable journal"
4059 );
4060 }
4062
4063 #[test]
4064 fn load_then_append_preserves_existing_and_adds() {
4065 let dir = tempfile::tempdir().unwrap();
4066 let journal = dir.path().join("resume.jsonl");
4067 {
4068 let mut log = EventLog::with_journal(journal.clone());
4069 log.append(
4070 EventKind::ProposalReceived,
4071 None,
4072 Some("p1"),
4073 HashMap::new(),
4074 );
4075 }
4076 {
4078 let mut log = EventLog::load(&journal).unwrap();
4079 assert_eq!(log.len(), 1);
4080 log.append(EventKind::ActionSucceeded, Some("a1"), None, HashMap::new());
4081 }
4082 let reloaded = EventLog::load(&journal).unwrap();
4083 assert_eq!(reloaded.len(), 2, "append-mode preserved the loaded line");
4084 assert_eq!(reloaded.events()[0].kind, EventKind::ProposalReceived);
4085 assert_eq!(reloaded.events()[1].kind, EventKind::ActionSucceeded);
4086 }
4087
4088 #[test]
4089 fn event_kind_serializes_snake_case() {
4090 assert_eq!(
4091 serde_json::to_string(&EventKind::ProposalReceived).unwrap(),
4092 "\"proposal_received\""
4093 );
4094 assert_eq!(
4095 serde_json::to_string(&EventKind::StateSnapshot).unwrap(),
4096 "\"state_snapshot\""
4097 );
4098 }
4099
4100 #[test]
4101 fn stats_truncate_and_clear_release_retained_entries() {
4102 let mut log = EventLog::new();
4103 for idx in 0..5 {
4104 log.append(
4105 EventKind::ActionSucceeded,
4106 Some(&format!("a{idx}")),
4107 Some("p1"),
4108 [("payload".to_string(), Value::from("x".repeat(16)))].into(),
4109 );
4110 log.begin_span("action.tool_call", "trace", None, HashMap::new());
4111 }
4112
4113 let stats = log.stats();
4114 assert_eq!(stats.events, 5);
4115 assert_eq!(stats.spans, 5);
4116 assert!(stats.approx_event_bytes > 0);
4117 assert!(stats.approx_span_bytes > 0);
4118
4119 assert_eq!(log.truncate_events_keep_last(2), 3);
4120 assert_eq!(log.truncate_spans_keep_last(1), 4);
4121 assert_eq!(log.len(), 2);
4122 assert_eq!(log.span_len(), 1);
4123 assert_eq!(log.events()[0].action_id.as_deref(), Some("a3"));
4124
4125 let removed = log.clear();
4126 assert_eq!(removed.events, 2);
4127 assert_eq!(removed.spans, 1);
4128 assert_eq!(log.len(), 0);
4129 assert_eq!(log.span_len(), 0);
4130 }
4131
4132 #[test]
4133 fn span_begin_end_lifecycle() {
4134 let mut log = EventLog::new();
4135 let trace_id = "trace-1".to_string();
4136
4137 let span_id = log.begin_span(
4138 "test.operation",
4139 &trace_id,
4140 None,
4141 [("key".to_string(), Value::from("value"))].into(),
4142 );
4143
4144 let spans = log.spans();
4145 assert_eq!(spans.len(), 1);
4146 assert_eq!(spans[0].name, "test.operation");
4147 assert_eq!(spans[0].trace_id, "trace-1");
4148 assert!(spans[0].parent_span_id.is_none());
4149 assert!(spans[0].end_time.is_none());
4150 assert_eq!(spans[0].status, SpanStatus::Unset);
4151
4152 log.end_span(&span_id, SpanStatus::Ok);
4153
4154 let spans = log.spans();
4155 assert!(spans[0].end_time.is_some());
4156 assert_eq!(spans[0].status, SpanStatus::Ok);
4157 }
4158
4159 #[test]
4160 fn span_parent_child_relationship() {
4161 let mut log = EventLog::new();
4162 let trace_id = "trace-2".to_string();
4163
4164 let parent_id = log.begin_span("parent.op", &trace_id, None, HashMap::new());
4165 let child_id = log.begin_span("child.op", &trace_id, Some(&parent_id), HashMap::new());
4166
4167 let spans = log.spans();
4168 assert_eq!(spans.len(), 2);
4169
4170 let child = spans.iter().find(|s| s.span_id == child_id).unwrap();
4171 assert_eq!(child.parent_span_id.as_deref(), Some(parent_id.as_str()));
4172 assert_eq!(child.trace_id, trace_id);
4173
4174 let parent = spans.iter().find(|s| s.span_id == parent_id).unwrap();
4175 assert!(parent.parent_span_id.is_none());
4176 }
4177
4178 #[test]
4179 fn export_traces_produces_valid_json() {
4180 let mut log = EventLog::new();
4181 let trace_id = "trace-3".to_string();
4182
4183 let root = log.begin_span(
4184 "proposal.execute",
4185 &trace_id,
4186 None,
4187 [("proposal_id".to_string(), Value::from("p1"))].into(),
4188 );
4189 let child = log.begin_span(
4190 "action.tool_call",
4191 &trace_id,
4192 Some(&root),
4193 [("tool".to_string(), Value::from("read_file"))].into(),
4194 );
4195 log.end_span(&child, SpanStatus::Ok);
4196 log.end_span(&root, SpanStatus::Ok);
4197
4198 let json_str = log.export_traces();
4199 let parsed: Value =
4200 serde_json::from_str(&json_str).expect("export_traces must produce valid JSON");
4201
4202 let resource_spans = parsed["resourceSpans"].as_array().unwrap();
4203 assert_eq!(resource_spans.len(), 1);
4204
4205 let scope_spans = &resource_spans[0]["scopeSpans"][0]["spans"];
4206 let spans_arr = scope_spans.as_array().unwrap();
4207 assert_eq!(spans_arr.len(), 2);
4208
4209 for span in spans_arr {
4211 assert!(span.get("traceId").is_some());
4212 assert!(span.get("spanId").is_some());
4213 assert!(span.get("name").is_some());
4214 assert!(span.get("startTimeUnixNano").is_some());
4215 assert!(span.get("endTimeUnixNano").is_some());
4216 assert!(span.get("status").is_some());
4217 }
4218
4219 let child_span = spans_arr
4221 .iter()
4222 .find(|s| s["name"] == "action.tool_call")
4223 .unwrap();
4224 assert!(child_span.get("parentSpanId").is_some());
4225 }
4226
4227 #[test]
4228 fn span_status_set_on_error() {
4229 let mut log = EventLog::new();
4230 let trace_id = "trace-4".to_string();
4231
4232 let span_id = log.begin_span("failing.op", &trace_id, None, HashMap::new());
4233 log.end_span(&span_id, SpanStatus::Error);
4234
4235 let spans = log.spans();
4236 assert_eq!(spans[0].status, SpanStatus::Error);
4237 assert!(spans[0].end_time.is_some());
4238 }
4239
4240 #[test]
4241 fn active_run_binding_stamps_every_new_event_and_rejects_conflicts() {
4242 let mut log = EventLog::new();
4243 log.bind_run("run-a", "client-a")
4244 .expect("first active run binds");
4245 log.bind_policy_session("policy-session-a")
4246 .expect("CAR-minted policy session binds inside the run");
4247
4248 log.append(
4249 EventKind::ProposalReceived,
4250 None,
4251 Some("same-proposal"),
4252 HashMap::new(),
4253 );
4254 log.append(
4255 EventKind::ActionSucceeded,
4256 Some("action-a"),
4257 Some("same-proposal"),
4258 HashMap::new(),
4259 );
4260
4261 for event in log.events() {
4262 assert_eq!(event.run_id.as_deref(), Some("run-a"));
4263 assert_eq!(event.client_id.as_deref(), Some("client-a"));
4264 assert_eq!(event.policy_session_id.as_deref(), Some("policy-session-a"));
4265 }
4266 assert!(log.bind_run("run-b", "client-a").is_err());
4267 assert!(log.bind_run("run-a", "client-b").is_err());
4268 assert!(log.clear_run_binding("run-b", "client-a").is_err());
4269 assert_eq!(
4270 log.active_run_binding(),
4271 Some(("run-a", "client-a", Some("policy-session-a")))
4272 );
4273
4274 log.clear_policy_session("policy-session-a")
4275 .expect("exact policy session clears");
4276 log.clear_run_binding("run-a", "client-a")
4277 .expect("exact active run clears");
4278 log.append(
4279 EventKind::ProposalReceived,
4280 None,
4281 Some("unbound-legacy"),
4282 HashMap::new(),
4283 );
4284 let legacy = log.events().last().unwrap();
4285 assert!(legacy.run_id.is_none());
4286 assert!(legacy.client_id.is_none());
4287 assert!(legacy.policy_session_id.is_none());
4288 }
4289
4290 #[test]
4291 fn historical_event_without_binding_fields_still_deserializes() {
4292 let historical = r#"{"kind":"proposal_received","proposal_id":"p-old","data":{},"timestamp":"2026-01-02T03:04:05Z"}"#;
4293 let event: Event = serde_json::from_str(historical).expect("historical event replays");
4294 assert!(event.run_id.is_none());
4295 assert!(event.client_id.is_none());
4296 assert!(event.policy_session_id.is_none());
4297 }
4298
4299 #[test]
4300 fn async_acknowledgement_timeout_wins_after_expiry_removal() {
4301 let manager = AsyncAcknowledgementManager::new(1);
4302 let barrier = AsyncAcknowledgementExpiryBarrier::new();
4303 manager.pause_next_expiry_after_removal(barrier.clone());
4304 let reservation = manager.reserve(Duration::from_millis(10)).unwrap();
4305 let sender = reservation.sender();
4306 let acknowledgement = reservation.into_future();
4307
4308 barrier.wait_until_removed();
4309 sender.send(Ok(()));
4310 let result = block_on_test_future(acknowledgement);
4311 barrier.allow_timeout_completion();
4312 manager.shutdown();
4313
4314 assert!(matches!(
4315 result,
4316 Err(CriticalPostAcceptanceError::AcknowledgementTimedOut { .. })
4317 ));
4318 }
4319
4320 #[test]
4321 fn async_acknowledgement_capacity_is_atomic_under_concurrent_reservation() {
4322 let manager = Arc::new(AsyncAcknowledgementManager::new(1));
4323 let barrier = Arc::new(std::sync::Barrier::new(3));
4324 let handles: Vec<_> = (0..2)
4325 .map(|_| {
4326 let manager = manager.clone();
4327 let barrier = barrier.clone();
4328 std::thread::spawn(move || {
4329 let reservation = manager.reserve(MAX_CRITICAL_ACKNOWLEDGEMENT_TIMEOUT);
4330 barrier.wait();
4331 reservation
4332 })
4333 })
4334 .collect();
4335
4336 barrier.wait();
4337 let results: Vec<_> = handles
4338 .into_iter()
4339 .map(|handle| handle.join().unwrap())
4340 .collect();
4341 assert_eq!(results.iter().filter(|result| result.is_ok()).count(), 1);
4342 assert_eq!(
4343 results
4344 .iter()
4345 .filter(|result| {
4346 matches!(
4347 result,
4348 Err(CriticalPreAcceptanceError::CapacityExhausted { capacity: 1 })
4349 )
4350 })
4351 .count(),
4352 1
4353 );
4354 drop(results);
4355 manager.shutdown();
4356 }
4357
4358 #[test]
4359 fn async_acknowledgement_completed_before_future_construction_is_observed() {
4360 let manager = AsyncAcknowledgementManager::new(1);
4361 let reservation = manager.reserve(Duration::from_secs(1)).unwrap();
4362 reservation.sender().send(Ok(()));
4363 let acknowledgement = reservation.into_future();
4364
4365 assert!(block_on_test_future(acknowledgement).is_ok());
4366 manager.shutdown();
4367 }
4368
4369 #[test]
4370 fn journal_writer_drop_completes_pending_async_acknowledgement() {
4371 let dir = tempfile::tempdir().unwrap();
4372 let failures = JournalFailureInjector::default();
4373 failures.fail_next(JournalFailurePoint::HoldAcknowledgement);
4374 let writer = JournalWriter::spawn_with_injector(
4375 dir.path().join("pending-ack-shutdown.jsonl"),
4376 failures.clone(),
4377 );
4378 let reservation = writer
4379 .reserve_async_acknowledgement(MAX_CRITICAL_ACKNOWLEDGEMENT_TIMEOUT)
4380 .unwrap();
4381 let acknowledgement = writer
4382 .enqueue_critical_async("{}".to_string(), false, reservation)
4383 .unwrap();
4384 let deadline = Instant::now() + Duration::from_secs(2);
4385 while failures.held_acknowledgement_count() == 0 {
4386 assert!(
4387 Instant::now() < deadline,
4388 "writer never retained the pending acknowledgement"
4389 );
4390 std::thread::yield_now();
4391 }
4392
4393 drop(writer);
4394 let result = block_on_test_future(acknowledgement);
4395 assert!(matches!(
4396 result,
4397 Err(CriticalPostAcceptanceError::CoordinatorStopped)
4398 ));
4399 failures.release_held_acknowledgements();
4400 }
4401
4402 #[test]
4403 fn startup_reconciliation_opens_a_writer_only_for_a_missing_row() {
4404 let dir = tempfile::tempdir().unwrap();
4405 let path = dir.path().join("startup-lazy.jsonl");
4406 let data = HashMap::from([("completion_digest".to_string(), Value::from("durable"))]);
4407 let mut original = EventLog::with_journal(path.clone());
4408 original.bind_run("run", "client").unwrap();
4409 original
4410 .append_critical_bounded(
4411 EventKind::RunCompleted,
4412 None,
4413 None,
4414 data.clone(),
4415 Duration::from_secs(1),
4416 )
4417 .unwrap();
4418 drop(original);
4419
4420 let mut resumed = EventLog::load_for_reconciliation(&path).unwrap();
4421 resumed.bind_run("run", "client").unwrap();
4422 resumed
4423 .append_critical_bounded(
4424 EventKind::RunCompleted,
4425 None,
4426 None,
4427 data,
4428 Duration::from_secs(1),
4429 )
4430 .unwrap();
4431 assert!(
4432 resumed.journal.is_none(),
4433 "a row that survived restart needs no append writer"
4434 );
4435
4436 resumed
4437 .append_critical_bounded(
4438 EventKind::ProposalCompleted,
4439 None,
4440 Some("missing"),
4441 HashMap::new(),
4442 Duration::from_secs(1),
4443 )
4444 .unwrap();
4445 assert!(
4446 resumed.journal.is_some(),
4447 "a missing row must attach a writer before acknowledging durability"
4448 );
4449 }
4450
4451 #[test]
4452 fn prepare_failure_releases_async_acknowledgement_capacity() {
4453 let dir = tempfile::tempdir().unwrap();
4454 let mut log = EventLog::with_journal_failure_injector_and_ack_capacity(
4455 dir.path().join("prepare-failure-capacity.jsonl"),
4456 JournalFailureInjector::default(),
4457 1,
4458 );
4459 let data = HashMap::from([("completion_digest".to_string(), Value::from("7".repeat(64)))]);
4460
4461 let error = block_on_test_future(log.append_critical_async(
4462 EventKind::RunCompleted,
4463 None,
4464 None,
4465 data.clone(),
4466 Duration::from_secs(1),
4467 ))
4468 .expect_err("an unbound critical event must fail during preparation");
4469 assert!(matches!(error, CriticalAppendError::Rejected { .. }));
4470
4471 log.bind_run("run-after-prepare-failure", "client-after-prepare-failure")
4472 .unwrap();
4473 block_on_test_future(log.append_critical_async(
4474 EventKind::RunCompleted,
4475 None,
4476 None,
4477 data,
4478 Duration::from_secs(1),
4479 ))
4480 .expect("the failed preparation must release the only acknowledgement slot");
4481 }
4482
4483 #[test]
4484 fn async_critical_preacceptance_failures_reject_without_fabricating_events() {
4485 let data = HashMap::from([("completion_digest".to_string(), Value::from("f".repeat(64)))]);
4486
4487 let mut no_journal = EventLog::new();
4488 no_journal
4489 .bind_run("run-no-writer", "client-no-writer")
4490 .unwrap();
4491 let error = block_on_test_future(no_journal.append_critical_async(
4492 EventKind::RunCompleted,
4493 None,
4494 None,
4495 data.clone(),
4496 Duration::from_millis(100),
4497 ))
4498 .expect_err("a missing writer must reject before acceptance");
4499 assert!(matches!(error, CriticalAppendError::Rejected { .. }));
4500 assert!(!error.is_retry_safe());
4501 assert!(no_journal.events().is_empty());
4502 assert!(no_journal.critical_pending.is_empty());
4503
4504 let dir = tempfile::tempdir().unwrap();
4505 let unavailable_path = dir.path().join("sender-missing.jsonl");
4506 let mut unavailable = EventLog::with_journal(unavailable_path.clone());
4507 unavailable
4508 .bind_run("run-sender-missing", "client-sender-missing")
4509 .unwrap();
4510 unavailable
4511 .journal
4512 .as_mut()
4513 .unwrap()
4514 .remove_sender_for_test();
4515 let error = block_on_test_future(unavailable.append_critical_async(
4516 EventKind::RunCompleted,
4517 None,
4518 None,
4519 data.clone(),
4520 Duration::from_millis(100),
4521 ))
4522 .expect_err("a missing writer sender must reject before event construction");
4523 assert!(matches!(error, CriticalAppendError::Rejected { .. }));
4524 assert!(unavailable.events().is_empty());
4525 assert!(unavailable.critical_pending.is_empty());
4526 assert!(!unavailable_path.exists());
4527
4528 let stopped_path = dir.path().join("receiver-stopped.jsonl");
4529 let mut stopped = EventLog::with_journal(stopped_path.clone());
4530 stopped
4531 .bind_run("run-receiver-stopped", "client-receiver-stopped")
4532 .unwrap();
4533 stopped.journal.as_mut().unwrap().stop_receiver_for_test();
4534 let error = block_on_test_future(stopped.append_critical_async(
4535 EventKind::RunCompleted,
4536 None,
4537 None,
4538 data,
4539 Duration::from_millis(100),
4540 ))
4541 .expect_err("a stopped writer receiver must reject a failed enqueue");
4542 assert!(matches!(error, CriticalAppendError::Rejected { .. }));
4543 assert!(stopped.events().is_empty());
4544 assert!(stopped.critical_pending.is_empty());
4545 assert!(!stopped_path.exists());
4546 }
4547
4548 #[test]
4549 fn async_critical_rejects_excessive_acknowledgement_duration_before_enqueue() {
4550 let dir = tempfile::tempdir().unwrap();
4551 let path = dir.path().join("excessive-ack-duration.jsonl");
4552 let mut log = EventLog::with_journal(path.clone());
4553 log.bind_run("run-excessive-ack", "client-excessive-ack")
4554 .unwrap();
4555
4556 let error = block_on_test_future(log.append_critical_async(
4557 EventKind::RunCompleted,
4558 None,
4559 None,
4560 HashMap::new(),
4561 MAX_CRITICAL_ACKNOWLEDGEMENT_TIMEOUT + Duration::from_millis(1),
4562 ))
4563 .expect_err("an excessive acknowledgement duration must reject");
4564
4565 assert!(matches!(error, CriticalAppendError::Rejected { .. }));
4566 assert!(log.events().is_empty());
4567 assert!(log.critical_pending.is_empty());
4568 assert!(!path.exists());
4569 }
4570
4571 #[test]
4572 fn async_critical_capacity_exhaustion_rejects_before_enqueue_and_exact_retry_unblocks() {
4573 let dir = tempfile::tempdir().unwrap();
4574 let path = dir.path().join("critical-ack-capacity.jsonl");
4575 let failures = JournalFailureInjector::default();
4576 failures.fail_next(JournalFailurePoint::HoldAcknowledgement);
4577 let mut log = EventLog::with_journal_failure_injector_and_ack_capacity(
4578 path.clone(),
4579 failures.clone(),
4580 1,
4581 );
4582 log.bind_run("run-capacity", "client-capacity").unwrap();
4583 let first_data =
4584 HashMap::from([("completion_digest".to_string(), Value::from("1".repeat(64)))]);
4585 let second_data =
4586 HashMap::from([("completion_digest".to_string(), Value::from("2".repeat(64)))]);
4587
4588 let mut first = Box::pin(log.append_critical_async(
4589 EventKind::RunCompleted,
4590 None,
4591 None,
4592 first_data.clone(),
4593 MAX_CRITICAL_ACKNOWLEDGEMENT_TIMEOUT,
4594 ));
4595 let waker = test_waker();
4596 let mut context = std::task::Context::from_waker(&waker);
4597 assert!(matches!(
4598 first.as_mut().poll(&mut context),
4599 std::task::Poll::Pending
4600 ));
4601 drop(first);
4602 assert_eq!(log.events().len(), 1);
4603 assert_eq!(log.critical_pending.len(), 1);
4604
4605 for attempt in 0..100 {
4606 let error = block_on_test_future(log.append_critical_async(
4607 EventKind::ProposalCompleted,
4608 None,
4609 Some("capacity-rejected"),
4610 second_data.clone(),
4611 Duration::from_millis(100),
4612 ))
4613 .expect_err("exhausted acknowledgement capacity must reject");
4614 let CriticalAppendError::Rejected { reason } = error else {
4615 panic!("attempt {attempt} was not a pre-enqueue rejection");
4616 };
4617 assert!(
4618 reason.contains("acknowledgement capacity is exhausted"),
4619 "attempt {attempt} bypassed capacity admission: {reason}"
4620 );
4621 assert_eq!(log.events().len(), 1);
4622 assert_eq!(log.critical_pending.len(), 1);
4623 }
4624
4625 let hold_deadline = std::time::Instant::now() + Duration::from_secs(2);
4626 while failures.held_acknowledgement_count() == 0 {
4627 assert!(
4628 std::time::Instant::now() < hold_deadline,
4629 "writer never reached the held acknowledgement"
4630 );
4631 std::thread::yield_now();
4632 }
4633 let pending_line = serde_json::to_string(&log.events()[0]).unwrap();
4634 assert_eq!(
4635 fs::read_to_string(&path).unwrap(),
4636 format!("{pending_line}\n")
4637 );
4638 failures.release_held_acknowledgements();
4639
4640 let original_timestamp = log.events()[0].timestamp;
4641 let retried = block_on_test_future(log.append_critical_async(
4642 EventKind::RunCompleted,
4643 None,
4644 None,
4645 first_data,
4646 Duration::from_millis(500),
4647 ))
4648 .expect("the exact cancelled row must reconcile pending state");
4649 assert_eq!(retried.timestamp, original_timestamp);
4650 assert!(log.critical_pending.is_empty());
4651
4652 block_on_test_future(log.append_critical_async(
4653 EventKind::ProposalCompleted,
4654 None,
4655 Some("capacity-rejected"),
4656 second_data,
4657 Duration::from_millis(500),
4658 ))
4659 .expect("a distinct row is allowed after exact reconciliation");
4660 drop(log);
4661
4662 let loaded = EventLog::load(&path).unwrap();
4663 assert_eq!(loaded.events().len(), 2);
4664 assert_eq!(loaded.events()[0].kind, EventKind::RunCompleted);
4665 assert_eq!(loaded.events()[1].kind, EventKind::ProposalCompleted);
4666 }
4667
4668 #[test]
4669 fn async_critical_never_acknowledged_row_remains_exactly_retryable() {
4670 let dir = tempfile::tempdir().unwrap();
4671 let path = dir.path().join("critical-never-acknowledged.jsonl");
4672 let failures = JournalFailureInjector::default();
4673 failures.fail_next(JournalFailurePoint::HoldAcknowledgement);
4674 let mut log = EventLog::with_journal_failure_injector(path.clone(), failures.clone());
4675 log.bind_run("run-never-ack", "client-never-ack").unwrap();
4676 let data = HashMap::from([("completion_digest".to_string(), Value::from("9".repeat(64)))]);
4677
4678 let error = block_on_test_future(log.append_critical_async(
4679 EventKind::RunCompleted,
4680 None,
4681 None,
4682 data.clone(),
4683 Duration::from_millis(20),
4684 ))
4685 .expect_err("the first acknowledgement is retained forever");
4686 assert!(matches!(
4687 error,
4688 CriticalAppendError::DurabilityUnknown { .. }
4689 ));
4690 let original = serde_json::to_string(&log.events()[0]).unwrap();
4691 assert!(log.critical_pending.contains(&original));
4692
4693 let retried = block_on_test_future(log.append_critical_async(
4694 EventKind::RunCompleted,
4695 None,
4696 None,
4697 data,
4698 Duration::from_millis(500),
4699 ))
4700 .expect("the exact row must reconcile without the first acknowledgement");
4701 assert_eq!(serde_json::to_string(retried).unwrap(), original);
4702 assert!(log.critical_pending.is_empty());
4703 assert_eq!(
4704 failures.held_acknowledgement_count(),
4705 1,
4706 "the original acknowledgement must remain unsent"
4707 );
4708 drop(log);
4709
4710 assert_eq!(fs::read_to_string(&path).unwrap(), format!("{original}\n"));
4711 assert_eq!(EventLog::load(&path).unwrap().events().len(), 1);
4712 }
4713
4714 #[test]
4715 fn bounded_sync_critical_timeout_is_exactly_retryable() {
4716 let dir = tempfile::tempdir().unwrap();
4717 let path = dir.path().join("critical-bounded-sync-timeout.jsonl");
4718 let failures = JournalFailureInjector::default();
4719 failures.fail_next(JournalFailurePoint::HoldAcknowledgement);
4720 let mut log = EventLog::with_journal_failure_injector(path.clone(), failures.clone());
4721 log.bind_run("run-bounded-sync", "client-bounded-sync")
4722 .unwrap();
4723 let data = HashMap::from([("completion_digest".to_string(), Value::from("7".repeat(64)))]);
4724
4725 let error = log
4726 .append_critical_bounded(
4727 EventKind::RunCompleted,
4728 None,
4729 None,
4730 data.clone(),
4731 Duration::from_millis(20),
4732 )
4733 .expect_err("the retained acknowledgement must hit the exact sync bound");
4734 assert_eq!(
4735 error,
4736 CriticalAppendError::DurabilityUnknown {
4737 reason: "journal writer did not acknowledge within 20ms".to_string()
4738 }
4739 );
4740 assert!(error.is_retry_safe());
4741 let pending = log
4742 .critical_pending
4743 .iter()
4744 .next()
4745 .expect("the exact timed-out row remains pending")
4746 .clone();
4747 assert_eq!(pending, serde_json::to_string(&log.events()[0]).unwrap());
4748
4749 let retried = log
4750 .append_critical_bounded(
4751 EventKind::RunCompleted,
4752 None,
4753 None,
4754 data,
4755 Duration::from_millis(500),
4756 )
4757 .expect("an exact retry must reconcile without the held acknowledgement");
4758 assert_eq!(serde_json::to_string(retried).unwrap(), pending);
4759 assert!(log.critical_pending.is_empty());
4760 assert_eq!(failures.held_acknowledgement_count(), 1);
4761 drop(log);
4762 assert_eq!(fs::read_to_string(&path).unwrap(), format!("{pending}\n"));
4763 }
4764
4765 #[test]
4766 fn async_critical_append_bounds_unknown_ack_and_preserves_exact_retry() {
4767 let dir = tempfile::tempdir().unwrap();
4768 let path = dir.path().join("critical-unknown-ack.jsonl");
4769 let failures = JournalFailureInjector::default();
4770 failures.fail_next(JournalFailurePoint::HoldAcknowledgement);
4771 let mut log = EventLog::with_journal_failure_injector(path.clone(), failures.clone());
4772 log.bind_run("run-unknown-ack", "client-unknown-ack")
4773 .unwrap();
4774 let data = HashMap::from([("completion_digest".to_string(), Value::from("e".repeat(64)))]);
4775
4776 let started = std::time::Instant::now();
4777 let error = block_on_test_future(log.append_critical_async(
4778 EventKind::RunCompleted,
4779 None,
4780 None,
4781 data.clone(),
4782 std::time::Duration::from_millis(40),
4783 ))
4784 .expect_err("a retained acknowledgement must become durability-unknown");
4785 assert!(
4786 started.elapsed() < std::time::Duration::from_millis(500),
4787 "the async acknowledgement wait exceeded its bounded allowance"
4788 );
4789 assert!(matches!(
4790 error,
4791 CriticalAppendError::DurabilityUnknown { .. }
4792 ));
4793 assert!(error.is_retry_safe());
4794 assert!(error
4795 .to_string()
4796 .contains("did not acknowledge within 40ms"));
4797
4798 let pending = log
4799 .critical_pending
4800 .iter()
4801 .next()
4802 .expect("the exact unacknowledged row remains pending")
4803 .clone();
4804 assert_eq!(log.critical_pending.len(), 1);
4805 assert_eq!(pending, serde_json::to_string(&log.events()[0]).unwrap());
4806 let disk_row = format!("{pending}\n");
4807 let writer_deadline = std::time::Instant::now() + std::time::Duration::from_secs(2);
4808 while fs::read_to_string(&path).unwrap_or_default() != disk_row {
4809 assert!(
4810 std::time::Instant::now() < writer_deadline,
4811 "the writer never durably accepted the held-acknowledgement row"
4812 );
4813 std::thread::yield_now();
4814 }
4815 while failures.held_acknowledgement_count() == 0 {
4816 assert!(
4817 std::time::Instant::now() < writer_deadline,
4818 "the writer never retained the late acknowledgement"
4819 );
4820 std::thread::yield_now();
4821 }
4822 assert_eq!(failures.held_acknowledgement_count(), 1);
4823 failures.release_held_acknowledgements();
4824 let original_timestamp = log.events()[0].timestamp;
4825
4826 let distinct_error = block_on_test_future(log.append_critical_async(
4827 EventKind::ProposalCompleted,
4828 None,
4829 Some("different-terminal"),
4830 HashMap::new(),
4831 Duration::from_millis(100),
4832 ))
4833 .expect_err("a different critical row must not bypass exact retry");
4834 assert!(matches!(
4835 distinct_error,
4836 CriticalAppendError::Rejected { .. }
4837 ));
4838 assert_eq!(log.events().len(), 1);
4839
4840 let retried = block_on_test_future(log.append_critical_async(
4841 EventKind::RunCompleted,
4842 None,
4843 None,
4844 data,
4845 std::time::Duration::from_secs(1),
4846 ))
4847 .expect("an identical retry must finish the retained row");
4848 assert_eq!(retried.timestamp, original_timestamp);
4849 assert!(log.critical_pending.is_empty());
4850
4851 block_on_test_future(log.append_critical_async(
4852 EventKind::ProposalCompleted,
4853 None,
4854 Some("different-terminal"),
4855 HashMap::new(),
4856 Duration::from_millis(500),
4857 ))
4858 .expect("a different row is allowed after exact retry reconciliation");
4859 drop(log);
4860
4861 let loaded = EventLog::load(&path).unwrap();
4862 assert_eq!(loaded.events().len(), 2);
4863 assert_eq!(serde_json::to_string(&loaded.events()[0]).unwrap(), pending);
4864 }
4865
4866 #[test]
4867 fn critical_append_failures_retry_same_row_and_fsync_prior_async_events() {
4868 for point in [
4869 JournalFailurePoint::Write,
4870 JournalFailurePoint::Flush,
4871 JournalFailurePoint::Fsync,
4872 ] {
4873 let dir = tempfile::tempdir().unwrap();
4874 let path = dir.path().join(format!("critical-{point:?}.jsonl"));
4875 let failures = JournalFailureInjector::default();
4876 failures.fail_next(point);
4877 let mut log = EventLog::with_journal_failure_injector(path.clone(), failures);
4878 log.bind_run("run-critical", "client-critical").unwrap();
4879 log.append(
4880 EventKind::ProposalReceived,
4881 None,
4882 Some("proposal-critical"),
4883 HashMap::new(),
4884 );
4885 let data =
4886 HashMap::from([("completion_digest".to_string(), Value::from("a".repeat(64)))]);
4887 assert!(
4888 log.append_critical(EventKind::RunCompleted, None, None, data.clone())
4889 .is_err(),
4890 "{point:?} failure must not acknowledge"
4891 );
4892 log.append(
4893 EventKind::ActionSucceeded,
4894 Some("after-pending-terminal"),
4895 Some("proposal-critical"),
4896 HashMap::new(),
4897 );
4898 log.append_critical(EventKind::RunCompleted, None, None, data)
4899 .expect("retry finishes the exact critical row");
4900 drop(log);
4901
4902 let loaded = EventLog::load(&path).unwrap();
4903 let events = loaded.events();
4904 assert_eq!(events[0].kind, EventKind::ProposalReceived);
4905 assert_eq!(events[1].kind, EventKind::RunCompleted);
4906 assert_eq!(events[2].kind, EventKind::ActionSucceeded);
4907 assert_eq!(
4908 events
4909 .iter()
4910 .filter(|event| event.kind == EventKind::RunCompleted)
4911 .count(),
4912 1,
4913 "{point:?} retry must not duplicate a terminal"
4914 );
4915 }
4916 }
4917
4918 #[test]
4919 fn a_critical_pass_moves_a_queued_failure_to_the_next_row() {
4920 let dir = tempfile::tempdir().unwrap();
4921 let path = dir.path().join("critical-pass.jsonl");
4922 let failures = JournalFailureInjector::default();
4923 failures.pass_next_critical(1);
4924 failures.fail_next(JournalFailurePoint::Write);
4925 let mut log = EventLog::with_journal_failure_injector(path.clone(), failures);
4926 log.bind_run("run-critical-pass", "client-critical-pass")
4927 .unwrap();
4928
4929 log.append_critical(
4930 EventKind::RunCancellationRequested,
4931 None,
4932 None,
4933 HashMap::new(),
4934 )
4935 .expect("the passed row must be written despite the queued failure");
4936 assert!(
4937 log.append_critical(EventKind::RunCancellationResult, None, None, HashMap::new())
4938 .is_err(),
4939 "the queued failure must apply to the row after the pass"
4940 );
4941 drop(log);
4942
4943 let kinds: Vec<_> = EventLog::load(&path)
4944 .unwrap()
4945 .events()
4946 .iter()
4947 .map(|event| event.kind.clone())
4948 .collect();
4949 assert_eq!(kinds, vec![EventKind::RunCancellationRequested]);
4950 }
4951
4952 #[test]
4953 fn compacting_a_failed_critical_row_makes_its_retry_idempotent() {
4954 let dir = tempfile::tempdir().unwrap();
4955 let path = dir.path().join("critical-compact-retry.jsonl");
4956 let failures = JournalFailureInjector::default();
4957 failures.fail_next(JournalFailurePoint::Fsync);
4958 let mut log =
4959 EventLog::with_journal_failure_injector(path.clone(), failures).with_hash_chaining();
4960 log.bind_run("run-critical-compact", "client-critical-compact")
4961 .unwrap();
4962 log.append(
4963 EventKind::ProposalReceived,
4964 None,
4965 Some("proposal-critical-compact"),
4966 HashMap::new(),
4967 );
4968 let data = HashMap::from([("completion_digest".to_string(), Value::from("c".repeat(64)))]);
4969
4970 assert!(
4971 log.append_critical(EventKind::RunCompleted, None, None, data.clone())
4972 .is_err(),
4973 "the injected fsync failure must leave the exact terminal pending"
4974 );
4975 assert!(
4976 log.compact_journal(),
4977 "compaction persists the in-memory pending terminal"
4978 );
4979 log.append_critical(EventKind::RunCompleted, None, None, data)
4980 .expect("identical retry recognizes the compacted terminal as durable");
4981 drop(log);
4982
4983 let loaded = EventLog::load(&path).unwrap();
4984 assert_eq!(
4985 loaded
4986 .events()
4987 .iter()
4988 .filter(|event| event.kind == EventKind::RunCompleted)
4989 .count(),
4990 1,
4991 "writer respawn must not duplicate the compacted terminal"
4992 );
4993 assert_eq!(loaded.events()[0].kind, EventKind::ProposalReceived);
4994 assert_eq!(loaded.events()[1].kind, EventKind::RunCompleted);
4995 assert_eq!(loaded.verify_chain(), Ok(2));
4996 }
4997
4998 #[test]
4999 fn critical_append_cannot_ack_until_failed_prior_async_row_is_replayed() {
5000 let dir = tempfile::tempdir().unwrap();
5001 let path = dir.path().join("prior-async-failure.jsonl");
5002 let failures = JournalFailureInjector::default();
5003 failures.fail_next(JournalFailurePoint::AsyncWrite);
5006 failures.fail_next(JournalFailurePoint::AsyncWrite);
5007 let mut log = EventLog::with_journal_failure_injector(path.clone(), failures);
5008 log.bind_run("run-ordered", "client-ordered").unwrap();
5009 log.append(
5010 EventKind::ActionSucceeded,
5011 Some("action-ordered"),
5012 Some("proposal-ordered"),
5013 HashMap::new(),
5014 );
5015 let data = HashMap::from([("completion_digest".to_string(), Value::from("b".repeat(64)))]);
5016
5017 assert!(
5018 log.append_critical(
5019 EventKind::ProposalCompleted,
5020 None,
5021 Some("proposal-ordered"),
5022 data.clone()
5023 )
5024 .is_err(),
5025 "a terminal must not acknowledge while an earlier row is still missing"
5026 );
5027 log.append_critical(
5028 EventKind::ProposalCompleted,
5029 None,
5030 Some("proposal-ordered"),
5031 data,
5032 )
5033 .expect("retry repairs the prior row before acknowledging the terminal");
5034 drop(log);
5035
5036 let loaded = EventLog::load(&path).unwrap();
5037 assert_eq!(loaded.events().len(), 2);
5038 assert_eq!(loaded.events()[0].kind, EventKind::ActionSucceeded);
5039 assert_eq!(loaded.events()[1].kind, EventKind::ProposalCompleted);
5040 }
5041
5042 #[test]
5043 fn first_use_parent_sync_failure_blocks_terminal_until_prior_async_replays() {
5044 let dir = tempfile::tempdir().unwrap();
5045 let path = dir.path().join("nested").join("first-use.jsonl");
5046 let failures = car_secrets::PrivatePathDurabilityFailureInjector::default();
5047 failures.fail_next(car_secrets::PrivatePathDurabilityFailurePoint::ParentDirectorySync);
5048 failures.fail_next(car_secrets::PrivatePathDurabilityFailurePoint::ParentDirectorySync);
5049 let mut log = EventLog::with_private_path_failure_injector(path.clone(), failures);
5050 log.bind_run("run-first-use", "client-first-use").unwrap();
5051 log.append(
5052 EventKind::ActionSucceeded,
5053 Some("action-first-use"),
5054 Some("proposal-first-use"),
5055 HashMap::new(),
5056 );
5057 let data = HashMap::from([("completion_digest".to_string(), Value::from("d".repeat(64)))]);
5058
5059 assert!(log
5060 .append_critical(
5061 EventKind::ProposalCompleted,
5062 None,
5063 Some("proposal-first-use"),
5064 data.clone(),
5065 )
5066 .is_err());
5067 log.append_critical(
5068 EventKind::ProposalCompleted,
5069 None,
5070 Some("proposal-first-use"),
5071 data,
5072 )
5073 .expect("retry durably replays async row then exact terminal");
5074 drop(log);
5075
5076 let loaded = EventLog::load(&path).unwrap();
5077 assert_eq!(loaded.events().len(), 2);
5078 assert_eq!(loaded.events()[0].kind, EventKind::ActionSucceeded);
5079 assert_eq!(loaded.events()[1].kind, EventKind::ProposalCompleted);
5080 }
5081}