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