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