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