1use crate::language_model_message::LanguageModelPrompt;
18use crate::options::CallOptions;
19use serde::{Deserialize, Serialize};
20use std::collections::{HashMap, HashSet, VecDeque};
21use std::io::{BufWriter, Write};
22use std::path::PathBuf;
23use std::sync::atomic::{AtomicU32, AtomicU64, Ordering};
24use std::sync::mpsc::{Receiver, SyncSender, sync_channel};
25use std::sync::{Arc, Mutex, RwLock};
26use std::time::{Duration, SystemTime, UNIX_EPOCH};
27use ts_rs::TS;
28
29pub const RECORDING_SCHEMA: u32 = 2;
33
34#[derive(Debug, Clone, Serialize, Deserialize, TS)]
36#[ts(export)]
37pub struct Recording {
38 pub schema: u32,
40 pub call_id: String,
42 pub recorded_at: String,
44
45 pub input: InputRecord,
47
48 pub provider: ProviderRecord,
50
51 pub exchanges: Vec<HttpExchange>,
53
54 pub outcome: OutcomeRecord,
56
57 #[serde(default)]
59 pub complete: bool,
60 #[serde(default)]
63 pub transport_closed: bool,
64
65 #[serde(default, skip_serializing_if = "Option::is_none")]
69 pub session_id: Option<String>,
70 #[serde(default, skip_serializing_if = "Option::is_none")]
72 pub step: Option<u32>,
73}
74
75impl Recording {
76 #[must_use]
78 pub fn new(call_id: &str, input: InputRecord, provider: ProviderRecord) -> Self {
79 Self {
80 schema: RECORDING_SCHEMA,
81 call_id: call_id.to_string(),
82 recorded_at: iso8601_now(),
83 input,
84 provider,
85 exchanges: Vec::new(),
86 outcome: OutcomeRecord::default(),
87 complete: false,
88 transport_closed: false,
89 session_id: None,
90 step: None,
91 }
92 }
93
94 fn ready(&self) -> bool {
104 self.transport_closed
105 && self.outcome.status != OutcomeStatus::Pending
106 && !self.input.prompt.is_empty()
107 && self.exchanges.iter().all(|e| e.finalized)
108 }
109}
110
111#[derive(Debug, Clone, Serialize, Deserialize, TS)]
113#[ts(export)]
114pub struct InputRecord {
115 pub prompt: LanguageModelPrompt,
117 pub options: serde_json::Value,
120}
121
122impl InputRecord {
123 #[must_use]
125 pub fn from_call_options(options: &CallOptions) -> Self {
126 let value = serde_json::to_value(options).unwrap_or(serde_json::Value::Null);
127 Self {
128 prompt: options.prompt.clone(),
129 options: redact_json(value),
130 }
131 }
132}
133
134#[derive(Debug, Clone, Serialize, Deserialize, TS)]
136#[ts(export)]
137pub struct ProviderRecord {
138 pub provider: String,
140 pub model_id: String,
142 pub base_url: Option<String>,
144 pub api_key_source: String,
146 pub profile: Option<serde_json::Value>,
148 pub provider_options: Option<serde_json::Value>,
150}
151
152impl ProviderRecord {
153 #[must_use]
155 pub fn minimal(provider: &str, model_id: &str) -> Self {
156 Self {
157 provider: provider.to_string(),
158 model_id: model_id.to_string(),
159 base_url: None,
160 api_key_source: "unknown".to_string(),
161 profile: None,
162 provider_options: None,
163 }
164 }
165}
166
167#[derive(Debug, Clone, Serialize, Deserialize, TS)]
169#[ts(export)]
170pub struct HttpExchange {
171 #[serde(default, skip_serializing_if = "Option::is_none")]
174 pub step: Option<String>,
175 pub attempt: u32,
179 #[serde(default)]
181 pub exchange_index: u32,
182 pub request: HttpRecord,
183 pub response: Option<ResponseRecord>,
185 pub timing: TimingRecord,
186 pub error: Option<String>,
187 #[serde(default = "default_finalized")]
189 pub finalized: bool,
190}
191
192fn default_finalized() -> bool {
193 true
194}
195
196#[derive(Debug, Clone, Serialize, Deserialize, TS)]
197#[ts(export)]
198pub struct HttpRecord {
199 pub method: String,
200 pub url: String,
201 pub headers: Vec<(String, String)>,
203 pub body: Option<String>,
205}
206
207#[derive(Debug, Clone, Serialize, Deserialize, TS)]
208#[ts(export)]
209pub struct ResponseRecord {
210 pub status: u16,
211 pub headers: Vec<(String, String)>,
212 pub body: Option<String>,
214 pub stream_chunks: Option<usize>,
215 #[serde(default, skip_serializing_if = "Option::is_none")]
217 #[ts(type = "number | null")]
218 pub ttfb_ms: Option<u64>,
219}
220
221#[derive(Debug, Clone, Serialize, Deserialize, TS)]
222#[ts(export)]
223pub struct TimingRecord {
224 #[ts(type = "number")]
226 pub latency_ms: u64,
227 #[ts(type = "number | null")]
228 pub ttfb_ms: Option<u64>,
229}
230
231#[derive(Debug, Clone, Copy, PartialEq, Eq, Default, Serialize, Deserialize, TS)]
233#[serde(rename_all = "snake_case")]
234#[ts(export)]
235pub enum OutcomeStatus {
236 #[default]
238 Pending,
239 Success,
240 Error,
242 Incomplete,
244 Cancelled,
246}
247
248#[derive(Debug, Clone, Default, Serialize, Deserialize, TS)]
250#[ts(export)]
251pub struct OutcomeRecord {
252 pub status: OutcomeStatus,
253 pub finish_reason: Option<String>,
254 pub error: Option<String>,
255 #[serde(default)]
258 pub error_value: Option<serde_json::Value>,
259 pub usage: Option<serde_json::Value>,
261}
262
263impl OutcomeRecord {
264 #[must_use]
266 pub fn from_generate_result(r: &crate::result::GenerateResult) -> Self {
267 Self {
268 status: OutcomeStatus::Success,
269 finish_reason: serde_json::to_value(r.finish_reason.unified)
270 .ok()
271 .and_then(|v| v.as_str().map(std::string::ToString::to_string)),
272 error: None,
273 error_value: None,
274 usage: serde_json::to_value(&r.usage).ok(),
275 }
276 }
277
278 #[must_use]
280 pub fn from_error(e: &crate::error::AiMuxError) -> Self {
281 Self {
282 status: OutcomeStatus::Error,
283 finish_reason: None,
284 error: Some(e.to_string()),
285 error_value: serde_json::to_value(e).ok(),
286 usage: None,
287 }
288 }
289}
290
291#[derive(Debug, thiserror::Error)]
298pub enum RecordingError {
299 #[error("recording init failed for {path}: {source}")]
301 Init {
302 path: PathBuf,
303 #[source]
304 source: std::io::Error,
305 },
306 #[error("failed to open recording file {path}: {source}")]
308 OpenFile {
309 path: PathBuf,
310 #[source]
311 source: std::io::Error,
312 },
313 #[error("failed to spawn recording writer thread: {source}")]
315 Spawn {
316 #[source]
317 source: std::io::Error,
318 },
319 #[error("recording writer thread unavailable")]
321 WriterGone,
322 #[error("recording flush timed out")]
324 FlushTimeout,
325 #[error("recording write failed: {0}")]
328 Write(String),
329}
330
331pub trait Recorder: Send + Sync {
333 fn record_input(&self, call_id: &str, options: &CallOptions, provider: &str, model_id: &str);
335 fn record_session(&self, _call_id: &str, _session_id: &str, _step: u32) {}
340 fn record_provider(&self, call_id: &str, snapshot: &ProviderRecord);
342 fn record_exchange(&self, call_id: &str, exchange: &HttpExchange);
344 fn record_exchange_update(
347 &self,
348 call_id: &str,
349 attempt: u32,
350 exchange_index: u32,
351 response: &ResponseRecord,
352 error: Option<String>,
353 );
354 fn record_outcome(&self, call_id: &str, outcome: &OutcomeRecord);
356 fn record_transport_closed(&self, call_id: &str) {
358 let _ = call_id;
359 }
360 fn flush(&self);
365 fn try_flush(&self) -> Result<(), RecordingError> {
374 Ok(())
375 }
376}
377
378static RECORDER: RwLock<Option<Arc<dyn Recorder>>> = RwLock::new(None);
381
382#[derive(Clone)]
385pub struct RecordingContext {
386 pub call_id: String,
387 pub recorder: Arc<dyn Recorder>,
388 attempt_allocator: Arc<AtomicU32>,
389 current_attempt: Arc<AtomicU32>,
390 exchange_index: Arc<AtomicU32>,
391 step: Option<Arc<str>>,
392}
393
394impl RecordingContext {
395 #[must_use]
396 pub fn new(call_id: impl Into<String>, recorder: Arc<dyn Recorder>) -> Self {
397 Self {
398 call_id: call_id.into(),
399 recorder,
400 attempt_allocator: Arc::new(AtomicU32::new(0)),
401 current_attempt: Arc::new(AtomicU32::new(0)),
402 exchange_index: Arc::new(AtomicU32::new(0)),
403 step: None,
404 }
405 }
406
407 #[must_use]
413 pub fn child(&self, step: impl Into<String>) -> Self {
414 Self {
415 call_id: self.call_id.clone(),
416 recorder: self.recorder.clone(),
417 attempt_allocator: self.attempt_allocator.clone(),
418 current_attempt: Arc::new(AtomicU32::new(0)),
419 exchange_index: Arc::new(AtomicU32::new(0)),
420 step: Some(Arc::from(step.into())),
421 }
422 }
423
424 #[must_use]
426 pub fn step(&self) -> Option<String> {
427 self.step.as_deref().map(str::to_owned)
428 }
429
430 #[must_use]
432 pub fn start_attempt(&self) -> u32 {
433 let attempt = self.attempt_allocator.fetch_add(1, Ordering::AcqRel) + 1;
434 self.current_attempt.store(attempt, Ordering::Release);
435 self.exchange_index.store(0, Ordering::Release);
436 attempt
437 }
438
439 #[must_use]
442 pub fn next_exchange(&self) -> (u32, u32) {
443 let attempt = self.current_attempt.load(Ordering::Acquire).max(1);
444 let exchange_index = self.exchange_index.fetch_add(1, Ordering::AcqRel) + 1;
445 (attempt, exchange_index)
446 }
447}
448
449impl std::fmt::Debug for RecordingContext {
450 fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
451 f.debug_struct("RecordingContext")
452 .field("call_id", &self.call_id)
453 .field("recorder", &"..")
454 .finish()
455 }
456}
457
458pub fn init_recording(recorder: Option<Arc<dyn Recorder>>) {
460 if let Ok(mut g) = RECORDER.write() {
461 *g = recorder;
462 }
463}
464
465#[must_use]
468pub fn init_recording_from_env() -> bool {
469 if std::env::var("AIMUX_RECORD").as_deref() != Ok("1") {
470 return false;
471 }
472 let dir = std::env::var("AIMUX_RECORD_DIR").unwrap_or_else(|_| "./recordings".to_string());
473 init_recording(Some(Arc::new(JsonlRecorder::new(dir))));
474 true
475}
476
477pub fn context(call_id: impl Into<String>) -> Option<RecordingContext> {
480 recorder().map(|recorder| RecordingContext::new(call_id, recorder))
481}
482
483pub fn recorder() -> Option<Arc<dyn Recorder>> {
488 RECORDER.read().ok()?.clone()
489}
490
491static CALL_SEQ: AtomicU64 = AtomicU64::new(0);
494
495pub fn new_call_id() -> String {
497 let ns = SystemTime::now()
498 .duration_since(UNIX_EPOCH)
499 .map(|d| d.as_nanos())
500 .unwrap_or(0);
501 format!("call-{ns}-{}", CALL_SEQ.fetch_add(1, Ordering::Relaxed))
502}
503
504#[must_use]
521pub fn is_sensitive_key(name: &str) -> bool {
522 let n = name.to_ascii_lowercase();
523 let squashed: String = n.chars().filter(|c| *c != '-' && *c != '_').collect();
528 n == "cookie"
529 || n == "set-cookie"
530 || n == "key"
531 || squashed.ends_with("token")
532 || n.contains("authorization")
533 || squashed.contains("apikey")
534}
535
536pub(crate) fn redact_json(value: serde_json::Value) -> serde_json::Value {
539 match value {
540 serde_json::Value::Object(map) => {
541 let mut out = serde_json::Map::with_capacity(map.len());
542 for (k, v) in map {
543 if is_sensitive_key(&k) {
544 out.insert(k, serde_json::Value::String("[REDACTED]".into()));
545 } else {
546 out.insert(k, redact_json(v));
547 }
548 }
549 serde_json::Value::Object(out)
550 }
551 serde_json::Value::Array(items) => {
552 serde_json::Value::Array(items.into_iter().map(redact_json).collect())
553 }
554 other => other,
555 }
556}
557
558enum RecordEvent {
562 Input {
563 call_id: String,
564 input: InputRecord,
565 provider: ProviderRecord,
566 },
567 Session {
569 call_id: String,
570 session_id: String,
571 step: u32,
572 },
573 Provider {
574 call_id: String,
575 provider: ProviderRecord,
576 },
577 Exchange {
578 call_id: String,
579 exchange: HttpExchange,
580 },
581 ExchangeUpdate {
582 call_id: String,
583 attempt: u32,
584 exchange_index: u32,
585 response: ResponseRecord,
586 error: Option<String>,
587 },
588 Outcome {
589 call_id: String,
590 outcome: OutcomeRecord,
591 },
592 TransportClosed { call_id: String },
594 Flush {
598 ack: SyncSender<Result<(), RecordingError>>,
599 },
600}
601
602const JSONL_CHANNEL_CAPACITY: usize = 1024;
607
608pub struct JsonlRecorder {
611 tx: Option<SyncSender<RecordEvent>>,
612 dir: PathBuf,
613 thread: Option<std::thread::JoinHandle<()>>,
614 dropped: AtomicU64,
616 inconsistent: Arc<Mutex<HashSet<String>>>,
620 write_error: Arc<Mutex<Option<String>>>,
623}
624
625impl JsonlRecorder {
626 pub fn try_new(dir: impl Into<PathBuf>) -> Result<Self, RecordingError> {
635 let dir = dir.into();
636 std::fs::create_dir_all(&dir).map_err(|source| RecordingError::Init {
637 path: dir.clone(),
638 source,
639 })?;
640 let path = dir.join("recordings.jsonl");
641 let file = std::fs::OpenOptions::new()
642 .create(true)
643 .append(true)
644 .open(&path)
645 .map_err(|source| RecordingError::OpenFile {
646 path: path.clone(),
647 source,
648 })?;
649 let w = BufWriter::new(file);
650 let (tx, rx) = sync_channel::<RecordEvent>(JSONL_CHANNEL_CAPACITY);
651 let inconsistent = Arc::new(Mutex::new(HashSet::new()));
652 let writer_inconsistent = inconsistent.clone();
653 let write_error = Arc::new(Mutex::new(None));
654 let writer_write_error = write_error.clone();
655 let handle = std::thread::Builder::new()
656 .name("aimux-recording".into())
657 .spawn(move || writer_loop(rx, w, writer_inconsistent, writer_write_error))
658 .map_err(|source| RecordingError::Spawn { source })?;
659 Ok(Self {
660 tx: Some(tx),
661 dir,
662 thread: Some(handle),
663 dropped: AtomicU64::new(0),
664 inconsistent,
665 write_error,
666 })
667 }
668
669 pub fn new(dir: impl Into<PathBuf>) -> Self {
674 let dir = dir.into();
675 Self::try_new(dir.clone()).unwrap_or_else(|_| Self::disabled(dir))
676 }
677
678 fn disabled(dir: PathBuf) -> Self {
680 Self {
681 tx: None,
682 dir,
683 thread: None,
684 dropped: AtomicU64::new(0),
685 inconsistent: Arc::new(Mutex::new(HashSet::new())),
686 write_error: Arc::new(Mutex::new(None)),
687 }
688 }
689
690 fn send_ev(&self, ev: RecordEvent) {
692 if let Some(tx) = &self.tx {
693 send_or_drop(tx, ev, &self.dropped);
694 }
695 }
696
697 pub fn dropped_count(&self) -> u64 {
699 self.dropped.load(Ordering::Relaxed)
700 }
701
702 pub fn inconsistent_call_ids(&self) -> Vec<String> {
704 let mut v: Vec<String> = self.inconsistent.lock().unwrap().iter().cloned().collect();
705 v.sort();
706 v
707 }
708
709 pub fn try_flush(&self) -> Result<(), RecordingError> {
719 let Some(tx) = &self.tx else {
720 return Err(self.write_error.lock().unwrap().as_ref().map_or_else(
724 || RecordingError::WriterGone,
725 |msg| RecordingError::Write(msg.clone()),
726 ));
727 };
728 let (ack_tx, ack_rx) = sync_channel::<Result<(), RecordingError>>(0);
729 tx.send(RecordEvent::Flush { ack: ack_tx })
732 .map_err(|_| RecordingError::WriterGone)?;
733 match ack_rx.recv_timeout(Duration::from_secs(30)) {
734 Ok(status) => status,
735 Err(_) => Err(RecordingError::FlushTimeout),
736 }
737 }
738
739 pub fn last_write_error(&self) -> Option<String> {
742 self.write_error.lock().unwrap().clone()
743 }
744
745 pub fn path(&self) -> PathBuf {
747 self.dir.join("recordings.jsonl")
748 }
749}
750
751impl Drop for JsonlRecorder {
752 fn drop(&mut self) {
753 if let Some(tx) = self.tx.take() {
756 drop(tx);
757 }
758 if let Some(handle) = self.thread.take() {
759 let _ = handle.join();
760 }
761 }
762}
763
764impl Recorder for JsonlRecorder {
765 fn record_input(&self, call_id: &str, options: &CallOptions, provider: &str, model_id: &str) {
766 self.send_ev(RecordEvent::Input {
767 call_id: call_id.to_string(),
768 input: InputRecord::from_call_options(options),
769 provider: ProviderRecord::minimal(provider, model_id),
770 });
771 }
772
773 fn record_session(&self, call_id: &str, session_id: &str, step: u32) {
774 self.send_ev(RecordEvent::Session {
775 call_id: call_id.to_string(),
776 session_id: session_id.to_string(),
777 step,
778 });
779 }
780
781 fn record_provider(&self, call_id: &str, snapshot: &ProviderRecord) {
782 let mut snap = snapshot.clone();
785 snap.provider_options = snap.provider_options.take().map(redact_json);
786 snap.profile = snap.profile.take().map(redact_json);
787 self.send_ev(RecordEvent::Provider {
788 call_id: call_id.to_string(),
789 provider: snap,
790 });
791 }
792
793 fn record_exchange(&self, call_id: &str, exchange: &HttpExchange) {
794 self.send_ev(RecordEvent::Exchange {
795 call_id: call_id.to_string(),
796 exchange: exchange.clone(),
797 });
798 }
799
800 fn record_exchange_update(
801 &self,
802 call_id: &str,
803 attempt: u32,
804 exchange_index: u32,
805 response: &ResponseRecord,
806 error: Option<String>,
807 ) {
808 self.send_ev(RecordEvent::ExchangeUpdate {
809 call_id: call_id.to_string(),
810 attempt,
811 exchange_index,
812 response: response.clone(),
813 error,
814 });
815 }
816
817 fn record_outcome(&self, call_id: &str, outcome: &OutcomeRecord) {
818 self.send_ev(RecordEvent::Outcome {
819 call_id: call_id.to_string(),
820 outcome: outcome.clone(),
821 });
822 }
823
824 fn record_transport_closed(&self, call_id: &str) {
825 self.send_ev(RecordEvent::TransportClosed {
826 call_id: call_id.to_string(),
827 });
828 }
829
830 fn flush(&self) {
833 let _ = JsonlRecorder::try_flush(self);
834 }
835
836 fn try_flush(&self) -> Result<(), RecordingError> {
837 JsonlRecorder::try_flush(self)
838 }
839}
840
841fn entry_or_init<'a>(
843 pending: &'a mut HashMap<String, Recording>,
844 call_id: &str,
845) -> &'a mut Recording {
846 pending.entry(call_id.to_string()).or_insert_with(|| {
847 Recording::new(
848 call_id,
849 InputRecord {
850 prompt: Vec::new(),
851 options: serde_json::Value::Null,
852 },
853 ProviderRecord::minimal("", ""),
854 )
855 })
856}
857
858fn writer_loop(
864 rx: Receiver<RecordEvent>,
865 mut w: impl Write,
866 inconsistent: Arc<Mutex<HashSet<String>>>,
867 write_error: Arc<Mutex<Option<String>>>,
868) {
869 let mut pending: HashMap<String, Recording> = HashMap::new();
870
871 while let Ok(ev) = rx.recv() {
872 match ev {
873 RecordEvent::Input {
874 call_id,
875 input,
876 provider,
877 } => {
878 let rec = pending
881 .entry(call_id.clone())
882 .or_insert_with(|| Recording::new(&call_id, input.clone(), provider.clone()));
883 rec.input = input;
884 if rec.provider.provider.is_empty() {
885 rec.provider = provider;
886 }
887 }
888 RecordEvent::Session {
889 call_id,
890 session_id,
891 step,
892 } => {
893 let rec = entry_or_init(&mut pending, &call_id);
894 rec.session_id = Some(session_id);
895 rec.step = Some(step);
896 try_finalize(&mut w, &mut pending, &call_id, &write_error);
897 }
898 RecordEvent::Provider { call_id, provider } => {
901 entry_or_init(&mut pending, &call_id).provider = provider;
902 }
903 RecordEvent::Exchange { call_id, exchange } => {
904 let rec = entry_or_init(&mut pending, &call_id);
906 if insert_exchange(rec, exchange) {
907 mark_inconsistent(&inconsistent, &call_id);
908 }
909 try_finalize(&mut w, &mut pending, &call_id, &write_error);
910 }
911 RecordEvent::ExchangeUpdate {
912 call_id,
913 attempt,
914 exchange_index,
915 response,
916 error,
917 } => {
918 let rec = entry_or_init(&mut pending, &call_id);
921 if !matches!(
922 apply_exchange_update(rec, attempt, exchange_index, response, error),
923 UpdateMatch::Patched
924 ) {
925 mark_inconsistent(&inconsistent, &call_id);
926 }
927 try_finalize(&mut w, &mut pending, &call_id, &write_error);
928 }
929 RecordEvent::TransportClosed { call_id } => {
930 entry_or_init(&mut pending, &call_id).transport_closed = true;
931 try_finalize(&mut w, &mut pending, &call_id, &write_error);
932 }
933 RecordEvent::Outcome { call_id, outcome } => {
934 entry_or_init(&mut pending, &call_id).outcome = outcome;
935 try_finalize(&mut w, &mut pending, &call_id, &write_error);
936 }
937 RecordEvent::Flush { ack } => {
938 write_ready_all(&mut w, &mut pending, &write_error);
939 if let Err(e) = w.flush() {
940 note_write_error(&write_error, &e);
941 }
942 let status = match write_error.lock().unwrap().as_ref() {
945 Some(msg) => Err(RecordingError::Write(msg.clone())),
946 None => Ok(()),
947 };
948 let _ = ack.send(status);
949 }
950 }
951 }
952
953 for (_, rec) in pending.drain() {
955 let mut rec = rec;
956 rec.complete = false;
957 if rec.outcome.status == OutcomeStatus::Pending {
958 rec.outcome.status = OutcomeStatus::Incomplete;
959 }
960 write_line(&mut w, rec, &write_error);
961 }
962 if let Err(e) = w.flush() {
963 note_write_error(&write_error, &e);
964 }
965}
966
967fn try_finalize(
969 w: &mut impl Write,
970 pending: &mut HashMap<String, Recording>,
971 call_id: &str,
972 write_error: &Mutex<Option<String>>,
973) {
974 if pending.get(call_id).map(Recording::ready).unwrap_or(false)
975 && let Some(mut rec) = pending.remove(call_id)
976 {
977 if !rec.exchanges.is_empty() || rec.transport_closed {
978 rec.complete = true;
979 }
980 write_line(w, rec, write_error);
981 }
982}
983
984fn write_ready_all(
985 w: &mut impl Write,
986 pending: &mut HashMap<String, Recording>,
987 write_error: &Mutex<Option<String>>,
988) {
989 let ids: Vec<String> = pending
990 .iter()
991 .filter(|(_, r)| r.ready())
992 .map(|(id, _)| id.clone())
993 .collect();
994 for id in ids {
995 if let Some(mut rec) = pending.remove(&id) {
996 rec.complete = true;
997 write_line(w, rec, write_error);
998 }
999 }
1000}
1001
1002fn write_line(w: &mut impl Write, rec: Recording, write_error: &Mutex<Option<String>>) {
1003 match serde_json::to_string(&rec) {
1004 Ok(line) => {
1005 if let Err(e) = writeln!(w, "{line}").and_then(|()| w.flush()) {
1008 note_write_error(write_error, &e);
1009 }
1010 }
1011 Err(e) => note_write_error(write_error, &e),
1012 }
1013}
1014
1015fn note_write_error(slot: &Mutex<Option<String>>, e: &impl std::fmt::Display) {
1017 let mut guard = slot.lock().unwrap();
1018 if guard.is_none() {
1019 *guard = Some(e.to_string());
1020 }
1021}
1022
1023#[derive(Debug, Clone, Copy, PartialEq, Eq)]
1027enum UpdateMatch {
1028 Patched,
1030 NotFound,
1032 Ambiguous,
1034}
1035
1036fn insert_exchange(rec: &mut Recording, exchange: HttpExchange) -> bool {
1040 if let Some(existing) = rec
1041 .exchanges
1042 .iter_mut()
1043 .find(|e| e.attempt == exchange.attempt && e.exchange_index == exchange.exchange_index)
1044 {
1045 merge_exchange(existing, &exchange);
1046 true
1047 } else {
1048 rec.exchanges.push(exchange);
1049 false
1050 }
1051}
1052
1053fn merge_exchange(existing: &mut HttpExchange, new: &HttpExchange) {
1054 existing.request = new.request.clone();
1055 existing.timing = new.timing.clone();
1056 if new.response.is_some() {
1057 existing.response = new.response.clone();
1058 }
1059 if new.error.is_some() {
1060 existing.error = new.error.clone();
1061 }
1062 if new.finalized {
1064 existing.finalized = true;
1065 }
1066}
1067
1068fn apply_exchange_update(
1071 rec: &mut Recording,
1072 attempt: u32,
1073 exchange_index: u32,
1074 response: ResponseRecord,
1075 error: Option<String>,
1076) -> UpdateMatch {
1077 let matches: Vec<usize> = rec
1078 .exchanges
1079 .iter()
1080 .enumerate()
1081 .filter(|(_, e)| e.attempt == attempt && e.exchange_index == exchange_index)
1082 .map(|(i, _)| i)
1083 .collect();
1084 match matches.len() {
1085 0 => UpdateMatch::NotFound,
1086 1 => {
1087 let ex = &mut rec.exchanges[matches[0]];
1088 ex.response = Some(response);
1089 if let Some(err) = error {
1090 ex.error = Some(err);
1091 }
1092 ex.finalized = true;
1093 UpdateMatch::Patched
1094 }
1095 _ => UpdateMatch::Ambiguous,
1096 }
1097}
1098
1099fn mark_inconsistent(set: &Mutex<HashSet<String>>, call_id: &str) {
1101 if let Ok(mut g) = set.lock() {
1102 g.insert(call_id.to_string());
1103 }
1104}
1105
1106fn send_or_drop(tx: &SyncSender<RecordEvent>, ev: RecordEvent, dropped: &AtomicU64) {
1111 if let Err(err) = tx.try_send(ev) {
1112 drop(err);
1114 dropped.fetch_add(1, Ordering::Relaxed);
1115 }
1116}
1117
1118fn iso8601_now() -> String {
1122 let d = SystemTime::now()
1123 .duration_since(UNIX_EPOCH)
1124 .unwrap_or_default();
1125 format_rfc3339_utc(d)
1126}
1127
1128fn format_rfc3339_utc(d: Duration) -> String {
1134 let secs = d.as_secs() as i64;
1135 let millis = d.subsec_millis();
1136 let (year, month, day) = civil_from_days(secs.div_euclid(86_400));
1137 let hms = secs.rem_euclid(86_400);
1138 format!(
1139 "{year:04}-{month:02}-{day:02}T{:02}:{:02}:{:02}.{millis:03}Z",
1140 hms / 3600,
1141 (hms % 3600) / 60,
1142 hms % 60,
1143 )
1144}
1145
1146fn civil_from_days(z: i64) -> (i64, u32, u32) {
1148 let z = z + 719_468;
1149 let era = (if z >= 0 { z } else { z - 146_096 }) / 146_097;
1150 let doe = (z - era * 146_097) as u64;
1151 let yoe = (doe - doe / 1460 + doe / 36_524 - doe / 146_096) / 365;
1152 let y = yoe as i64 + era * 400;
1153 let doy = doe - (365 * yoe + yoe / 4 - yoe / 100);
1154 let mp = (5 * doy + 2) / 153;
1155 let d = (doy - (153 * mp + 2) / 5 + 1) as u32;
1156 let m = if mp < 10 { mp + 3 } else { mp - 9 } as u32;
1157 (if m <= 2 { y + 1 } else { y }, m, d)
1158}
1159
1160pub const DEFAULT_RING_CAPACITY: usize = 2048;
1164
1165pub struct RingRecorder {
1172 inner: Mutex<RingInner>,
1173}
1174
1175fn ring_pending_max(cap: usize) -> usize {
1178 cap.saturating_mul(2).max(2)
1179}
1180
1181struct RingInner {
1182 cap: usize,
1183 pending_max: usize,
1185 pending_order: VecDeque<String>,
1187 pending: HashMap<String, Recording>,
1189 completed: VecDeque<Recording>,
1191 dropped: u64,
1193 pending_evicted: u64,
1195 inconsistent: HashSet<String>,
1197}
1198
1199impl RingRecorder {
1200 #[must_use]
1202 pub fn new() -> Self {
1203 Self::with_capacity(DEFAULT_RING_CAPACITY)
1204 }
1205
1206 #[must_use]
1207 pub fn with_capacity(cap: usize) -> Self {
1208 assert!(cap > 0, "RingRecorder capacity must be > 0");
1209 Self {
1210 inner: Mutex::new(RingInner {
1211 cap,
1212 pending_max: ring_pending_max(cap),
1213 pending_order: VecDeque::new(),
1214 pending: HashMap::new(),
1215 completed: VecDeque::with_capacity(cap),
1216 dropped: 0,
1217 pending_evicted: 0,
1218 inconsistent: HashSet::new(),
1219 }),
1220 }
1221 }
1222
1223 pub fn len(&self) -> usize {
1225 self.inner.lock().unwrap().completed.len()
1226 }
1227
1228 pub fn is_empty(&self) -> bool {
1229 self.len() == 0
1230 }
1231
1232 pub fn pending_count(&self) -> usize {
1234 self.inner.lock().unwrap().pending.len()
1235 }
1236
1237 pub fn dropped_count(&self) -> u64 {
1239 self.inner.lock().unwrap().dropped
1240 }
1241
1242 pub fn pending_evicted_count(&self) -> u64 {
1244 self.inner.lock().unwrap().pending_evicted
1245 }
1246
1247 pub fn inconsistent_call_ids(&self) -> Vec<String> {
1249 let mut v: Vec<String> = self
1250 .inner
1251 .lock()
1252 .unwrap()
1253 .inconsistent
1254 .iter()
1255 .cloned()
1256 .collect();
1257 v.sort();
1258 v
1259 }
1260
1261 pub fn clear(&self) {
1262 let mut inner = self.inner.lock().unwrap();
1263 inner.pending.clear();
1264 inner.pending_order.clear();
1265 inner.completed.clear();
1266 inner.inconsistent.clear();
1267 inner.dropped = 0;
1268 inner.pending_evicted = 0;
1269 }
1270
1271 pub fn export_jsonl(&self, w: &mut impl Write) -> std::io::Result<()> {
1279 let inner = self.inner.lock().unwrap();
1280 for rec in &inner.completed {
1281 let line = serde_json::to_string(rec).map_err(std::io::Error::other)?;
1282 writeln!(w, "{line}")?;
1283 }
1284 Ok(())
1285 }
1286
1287 pub fn completed(&self) -> Vec<Recording> {
1289 self.inner
1290 .lock()
1291 .unwrap()
1292 .completed
1293 .iter()
1294 .cloned()
1295 .collect()
1296 }
1297
1298 pub fn get(&self, call_id: &str) -> Option<Recording> {
1300 self.inner
1301 .lock()
1302 .unwrap()
1303 .completed
1304 .iter()
1305 .find(|r| r.call_id == call_id)
1306 .cloned()
1307 }
1308}
1309
1310impl RingInner {
1311 fn entry_or_init_bounded(&mut self, call_id: &str) -> &mut Recording {
1313 if !self.pending.contains_key(call_id) {
1314 self.evict_pending_if_needed();
1315 self.pending_order.push_back(call_id.to_string());
1316 self.pending.insert(
1317 call_id.to_string(),
1318 Recording::new(
1319 call_id,
1320 InputRecord {
1321 prompt: Vec::new(),
1322 options: serde_json::Value::Null,
1323 },
1324 ProviderRecord::minimal("", ""),
1325 ),
1326 );
1327 }
1328 self.pending
1329 .get_mut(call_id)
1330 .expect("just inserted or present")
1331 }
1332
1333 fn evict_pending_if_needed(&mut self) {
1336 while self
1337 .pending_order
1338 .front()
1339 .is_some_and(|id| !self.pending.contains_key(id))
1340 {
1341 self.pending_order.pop_front();
1342 }
1343 while self.pending.len() >= self.pending_max {
1344 let Some(old) = self.pending_order.pop_front() else {
1345 break;
1346 };
1347 if let Some(mut rec) = self.pending.remove(&old) {
1348 rec.complete = false;
1349 if rec.outcome.status == OutcomeStatus::Pending {
1350 rec.outcome.status = OutcomeStatus::Incomplete;
1351 }
1352 self.pending_evicted += 1;
1353 self.push(rec);
1354 }
1355 }
1356 }
1357
1358 fn finalize(&mut self, call_id: &str) {
1360 if self.pending.get(call_id).is_some_and(Recording::ready)
1361 && let Some(mut rec) = self.pending.remove(call_id)
1362 {
1363 if !rec.exchanges.is_empty() || rec.transport_closed {
1364 rec.complete = true;
1365 }
1366 self.push(rec);
1367 }
1368 }
1369
1370 fn push(&mut self, rec: Recording) {
1372 if self.completed.len() >= self.cap {
1373 self.completed.pop_front();
1374 self.dropped += 1;
1375 }
1376 self.completed.push_back(rec);
1377 }
1378
1379 fn mark_inconsistent(&mut self, call_id: &str) {
1380 self.inconsistent.insert(call_id.to_string());
1381 }
1382}
1383
1384impl Default for RingRecorder {
1385 fn default() -> Self {
1386 Self::new()
1387 }
1388}
1389
1390impl Recorder for RingRecorder {
1391 fn record_input(&self, call_id: &str, options: &CallOptions, provider: &str, model_id: &str) {
1392 let mut inner = self.inner.lock().unwrap();
1393 let rec = inner.entry_or_init_bounded(call_id);
1396 rec.input = InputRecord::from_call_options(options);
1397 if rec.provider.provider.is_empty() {
1398 rec.provider = ProviderRecord::minimal(provider, model_id);
1399 }
1400 }
1401
1402 fn record_session(&self, call_id: &str, session_id: &str, step: u32) {
1405 let mut inner = self.inner.lock().unwrap();
1406 let rec = inner.entry_or_init_bounded(call_id);
1407 rec.session_id = Some(session_id.to_string());
1408 rec.step = Some(step);
1409 }
1410
1411 fn record_provider(&self, call_id: &str, snapshot: &ProviderRecord) {
1412 let mut snap = snapshot.clone();
1414 snap.provider_options = snap.provider_options.take().map(redact_json);
1415 snap.profile = snap.profile.take().map(redact_json);
1416 let mut inner = self.inner.lock().unwrap();
1417 inner.entry_or_init_bounded(call_id).provider = snap;
1419 }
1420
1421 fn record_exchange(&self, call_id: &str, exchange: &HttpExchange) {
1422 let mut inner = self.inner.lock().unwrap();
1423 let rec = inner.entry_or_init_bounded(call_id);
1425 if insert_exchange(rec, exchange.clone()) {
1426 inner.mark_inconsistent(call_id);
1427 }
1428 inner.finalize(call_id);
1429 }
1430
1431 fn record_exchange_update(
1432 &self,
1433 call_id: &str,
1434 attempt: u32,
1435 exchange_index: u32,
1436 response: &ResponseRecord,
1437 error: Option<String>,
1438 ) {
1439 let mut inner = self.inner.lock().unwrap();
1440 let rec = inner.entry_or_init_bounded(call_id);
1442 if !matches!(
1443 apply_exchange_update(rec, attempt, exchange_index, response.clone(), error),
1444 UpdateMatch::Patched
1445 ) {
1446 inner.mark_inconsistent(call_id);
1447 }
1448 inner.finalize(call_id);
1449 }
1450
1451 fn record_outcome(&self, call_id: &str, outcome: &OutcomeRecord) {
1452 let mut inner = self.inner.lock().unwrap();
1453 inner.entry_or_init_bounded(call_id).outcome = outcome.clone();
1454 inner.finalize(call_id);
1455 }
1456
1457 fn record_transport_closed(&self, call_id: &str) {
1458 let mut inner = self.inner.lock().unwrap();
1459 inner.entry_or_init_bounded(call_id).transport_closed = true;
1460 inner.finalize(call_id);
1461 }
1462
1463 fn flush(&self) {
1466 let mut inner = self.inner.lock().unwrap();
1467 let ids: Vec<String> = inner
1468 .pending
1469 .iter()
1470 .filter(|(_, r)| r.ready())
1471 .map(|(id, _)| id.clone())
1472 .collect();
1473 for id in ids {
1474 if let Some(mut rec) = inner.pending.remove(&id) {
1475 rec.complete = true;
1476 inner.push(rec);
1477 }
1478 }
1479 }
1480
1481 fn try_flush(&self) -> Result<(), RecordingError> {
1483 RingRecorder::flush(self);
1484 Ok(())
1485 }
1486}
1487
1488pub struct RecordingOutcomeStream<S> {
1501 inner: S,
1502 recorder: Option<Arc<dyn Recorder>>,
1503 call_id: String,
1504 recorded: bool,
1506 pending: Option<OutcomeRecord>,
1509}
1510
1511impl<S> RecordingOutcomeStream<S> {
1512 pub fn new(inner: S, recorder: Option<Arc<dyn Recorder>>, call_id: impl Into<String>) -> Self {
1514 Self {
1515 inner,
1516 recorder,
1517 call_id: call_id.into(),
1518 recorded: false,
1519 pending: None,
1520 }
1521 }
1522
1523 fn flush_pending(&mut self) -> bool {
1525 if let Some(pending) = self.pending.take() {
1526 self.record(&pending);
1527 true
1528 } else {
1529 false
1530 }
1531 }
1532
1533 fn record(&mut self, outcome: &OutcomeRecord) {
1534 if !self.recorded {
1535 self.recorded = true;
1536 if let Some(rec) = &self.recorder {
1537 rec.record_outcome(&self.call_id, outcome);
1538 rec.record_transport_closed(&self.call_id);
1540 }
1541 }
1542 }
1543}
1544
1545impl<S> futures::Stream for RecordingOutcomeStream<S>
1546where
1547 S: futures::Stream<Item = Result<crate::stream_part::StreamPart, crate::AiMuxError>> + Unpin,
1548{
1549 type Item = Result<crate::stream_part::StreamPart, crate::AiMuxError>;
1550
1551 fn poll_next(
1552 mut self: std::pin::Pin<&mut Self>,
1553 cx: &mut std::task::Context<'_>,
1554 ) -> std::task::Poll<Option<Self::Item>> {
1555 let this = self.as_mut().get_mut();
1556 let inner = std::pin::Pin::new(&mut this.inner);
1557 match inner.poll_next(cx) {
1558 std::task::Poll::Ready(Some(Ok(part))) => {
1559 match &part {
1560 crate::stream_part::StreamPart::Finish {
1561 finish_reason,
1562 usage,
1563 ..
1564 } => {
1565 let this = self.as_mut().get_mut();
1566 if let Some(mut pending) = this.pending.take() {
1567 pending.usage = serde_json::to_value(usage).ok();
1569 this.record(&pending);
1570 } else {
1571 let outcome = OutcomeRecord {
1572 status: OutcomeStatus::Success,
1573 finish_reason: serde_json::to_value(finish_reason.unified)
1574 .ok()
1575 .and_then(|v| v.as_str().map(std::string::ToString::to_string)),
1576 error: None,
1577 error_value: None,
1578 usage: serde_json::to_value(usage).ok(),
1579 };
1580 this.record(&outcome);
1581 }
1582 }
1583 crate::stream_part::StreamPart::Error { error } => {
1584 let this = self.as_mut().get_mut();
1585 if !this.recorded && this.pending.is_none() {
1586 this.pending = Some(OutcomeRecord {
1587 status: OutcomeStatus::Error,
1588 finish_reason: None,
1589 error: Some(error.to_string()),
1590 error_value: serde_json::to_value(error).ok(),
1591 usage: None,
1592 });
1593 }
1594 }
1595 _ => {}
1596 }
1597 std::task::Poll::Ready(Some(Ok(part)))
1598 }
1599 std::task::Poll::Ready(Some(Err(e))) => {
1600 if e.is_recoverable_stream_error() {
1601 if !this.recorded && this.pending.is_none() {
1602 this.pending = Some(OutcomeRecord {
1603 status: OutcomeStatus::Error,
1604 finish_reason: None,
1605 error: Some(e.to_string()),
1606 error_value: serde_json::to_value(&e).ok(),
1607 usage: None,
1608 });
1609 }
1610 return std::task::Poll::Ready(Some(Err(e)));
1611 }
1612 if !this.flush_pending() {
1614 let outcome = OutcomeRecord {
1615 status: OutcomeStatus::Error,
1616 finish_reason: None,
1617 error: Some(e.to_string()),
1618 error_value: serde_json::to_value(&e).ok(),
1619 usage: None,
1620 };
1621 this.record(&outcome);
1622 }
1623 std::task::Poll::Ready(Some(Err(e)))
1624 }
1625 std::task::Poll::Ready(None) => {
1626 if !this.flush_pending() {
1627 let outcome = OutcomeRecord {
1628 status: OutcomeStatus::Incomplete,
1629 finish_reason: None,
1630 error: None,
1631 error_value: None,
1632 usage: None,
1633 };
1634 this.record(&outcome);
1635 }
1636 std::task::Poll::Ready(None)
1637 }
1638 std::task::Poll::Pending => std::task::Poll::Pending,
1639 }
1640 }
1641}
1642
1643impl<S> Drop for RecordingOutcomeStream<S> {
1644 fn drop(&mut self) {
1645 if !self.recorded && !self.flush_pending() {
1646 let outcome = OutcomeRecord {
1647 status: OutcomeStatus::Cancelled,
1648 finish_reason: None,
1649 error: None,
1650 error_value: None,
1651 usage: None,
1652 };
1653 self.record(&outcome);
1654 }
1655 }
1656}
1657
1658#[cfg(test)]
1661mod tests {
1662 use super::*;
1663 use crate::generate::GenerateTextOptions;
1664
1665 struct CaptureRecorder(std::sync::Mutex<Vec<OutcomeRecord>>);
1666
1667 impl Recorder for CaptureRecorder {
1668 fn record_input(&self, _: &str, _: &CallOptions, _: &str, _: &str) {}
1669 fn record_provider(&self, _: &str, _: &ProviderRecord) {}
1670 fn record_exchange(&self, _: &str, _: &HttpExchange) {}
1671 fn record_exchange_update(
1672 &self,
1673 _: &str,
1674 _: u32,
1675 _: u32,
1676 _: &ResponseRecord,
1677 _: Option<String>,
1678 ) {
1679 }
1680 fn record_outcome(&self, _: &str, outcome: &OutcomeRecord) {
1681 self.0.lock().unwrap().push(outcome.clone());
1682 }
1683 fn flush(&self) {}
1684 }
1685
1686 type PartResult = Result<crate::stream_part::StreamPart, crate::AiMuxError>;
1687 type CapturedStream = RecordingOutcomeStream<
1688 futures::stream::Chain<
1689 futures::stream::Iter<std::vec::IntoIter<PartResult>>,
1690 futures::stream::Pending<PartResult>,
1691 >,
1692 >;
1693
1694 fn capture_stream(parts: Vec<PartResult>, recorder: &Arc<CaptureRecorder>) -> CapturedStream {
1695 use futures::StreamExt as _;
1696 let dyn_recorder: Arc<dyn Recorder> = recorder.clone();
1697 RecordingOutcomeStream::new(
1698 futures::stream::iter(parts).chain(futures::stream::pending()),
1699 Some(dyn_recorder),
1700 "call-1",
1701 )
1702 }
1703
1704 fn provider_error_part() -> Result<crate::stream_part::StreamPart, crate::AiMuxError> {
1705 Ok(crate::stream_part::StreamPart::Error {
1706 error: crate::AiMuxError::Other("provider error".into()),
1707 })
1708 }
1709
1710 #[tokio::test]
1711 async fn provider_error_outcome_keeps_usage_from_trailing_finish() {
1712 use futures::StreamExt as _;
1713
1714 let recorder = Arc::new(CaptureRecorder(std::sync::Mutex::new(Vec::new())));
1715 let finish = Ok(crate::stream_part::StreamPart::Finish {
1716 finish_reason: crate::types::FinishReason {
1717 unified: crate::types::FinishReasonUnified::Error,
1718 raw: None,
1719 },
1720 usage: crate::types::Usage::default(),
1721 provider_metadata: None,
1722 });
1723 let mut stream = capture_stream(vec![provider_error_part(), finish], &recorder);
1724 let _ = stream.next().await;
1725 let _ = stream.next().await;
1726 drop(stream);
1727
1728 let outcomes = recorder.0.lock().unwrap();
1729 assert_eq!(outcomes.len(), 1);
1730 assert_eq!(outcomes[0].status, OutcomeStatus::Error);
1731 assert_eq!(outcomes[0].error.as_deref(), Some("provider error"));
1732 assert!(outcomes[0].usage.is_some(), "trailing Finish usage kept");
1733 }
1734
1735 #[tokio::test]
1736 async fn provider_error_outcome_is_flushed_when_the_stream_is_dropped_early() {
1737 use futures::StreamExt as _;
1738
1739 let recorder = Arc::new(CaptureRecorder(std::sync::Mutex::new(Vec::new())));
1740 let mut stream = capture_stream(vec![provider_error_part()], &recorder);
1741 let _ = stream.next().await;
1742 drop(stream);
1743
1744 let outcomes = recorder.0.lock().unwrap();
1745 assert_eq!(outcomes.len(), 1);
1746 assert_eq!(outcomes[0].status, OutcomeStatus::Error);
1747 assert_eq!(outcomes[0].error.as_deref(), Some("provider error"));
1748 }
1749
1750 #[tokio::test]
1751 async fn recoverable_frame_error_waits_for_the_trailing_finish() {
1752 use futures::StreamExt as _;
1753
1754 let recorder = Arc::new(CaptureRecorder(std::sync::Mutex::new(Vec::new())));
1755 let finish = Ok(crate::stream_part::StreamPart::Finish {
1756 finish_reason: crate::types::FinishReason {
1757 unified: crate::types::FinishReasonUnified::Stop,
1758 raw: Some("stop".into()),
1759 },
1760 usage: crate::types::Usage::default(),
1761 provider_metadata: None,
1762 });
1763 let mut stream = capture_stream(
1764 vec![
1765 Err(crate::AiMuxError::JsonParse("bad frame".into())),
1766 finish,
1767 ],
1768 &recorder,
1769 );
1770
1771 assert!(matches!(
1772 stream.next().await,
1773 Some(Err(crate::AiMuxError::JsonParse(_)))
1774 ));
1775 assert!(recorder.0.lock().unwrap().is_empty());
1776 assert!(matches!(
1777 stream.next().await,
1778 Some(Ok(crate::stream_part::StreamPart::Finish { .. }))
1779 ));
1780
1781 let outcomes = recorder.0.lock().unwrap();
1782 assert_eq!(outcomes.len(), 1);
1783 assert_eq!(outcomes[0].status, OutcomeStatus::Error);
1784 assert!(outcomes[0].usage.is_some());
1785 }
1786
1787 fn sample_options() -> CallOptions {
1788 GenerateTextOptions {
1789 temperature: Some(0.7),
1790 ..Default::default()
1791 }
1792 .into_call_options(
1793 crate::language_model_message::convert_to_language_model_prompt(
1794 &[crate::message::ModelMessage::user("ping")],
1795 None,
1796 ),
1797 )
1798 }
1799
1800 #[test]
1801 fn gate_is_off_by_default() {
1802 assert!(recorder().is_none());
1803 }
1804
1805 #[test]
1806 fn call_id_is_unique() {
1807 let a = new_call_id();
1808 let b = new_call_id();
1809 assert_ne!(a, b);
1810 assert!(a.starts_with("call-"));
1811 }
1812
1813 #[test]
1814 fn input_record_serializes_options_without_internal_fields() {
1815 let mut opts = sample_options();
1816 opts.call_id = Some("call-test".into());
1817 opts.abort_signal = None;
1818 let rec = InputRecord::from_call_options(&opts);
1819 let v = &rec.options;
1820 assert!(v.get("call_id").is_none());
1821 assert!(v.get("abort_signal").is_none());
1822 }
1823
1824 #[test]
1825 fn sensitive_key_matching_is_separator_and_case_insensitive() {
1826 for key in [
1827 "token",
1828 "access_token",
1829 "accessToken",
1830 "access-token",
1831 "x-access-token",
1832 "refreshToken",
1833 "id_token",
1834 "x-amz-security-token",
1835 "Authorization",
1836 "x-api-key",
1837 "apiKey",
1838 ] {
1839 assert!(is_sensitive_key(key), "{key} must be redacted");
1840 }
1841 for key in ["max_tokens", "input_tokens", "output_tokens", "model"] {
1843 assert!(!is_sensitive_key(key), "{key} must stay visible");
1844 }
1845 }
1846
1847 #[test]
1848 fn redact_json_hides_sensitive_values_everywhere() {
1849 let v = serde_json::json!({
1850 "headers": {
1851 "Authorization": "Bearer sk-abc",
1852 "X-Key": "ok",
1853 "x-goog-api-key": "gkey",
1854 "x-amz-security-token": "sts-tok"
1855 },
1856 "provider_options": { "headers": { "Cookie": "s=1" } },
1857 "body_overrides": {
1858 "api_key": "sk-secret",
1859 "token": "bearer-secret",
1860 "access_token": "oauth-secret"
1861 },
1862 "usage": {
1864 "max_output_tokens": 4096,
1865 "prompt_tokens": 10,
1866 "completion_tokens": 20
1867 },
1868 "temperature": 0.5,
1869 });
1870 let r = redact_json(v);
1871 assert_eq!(r["headers"]["Authorization"], "[REDACTED]");
1872 assert_eq!(r["headers"]["x-goog-api-key"], "[REDACTED]");
1873 assert_eq!(r["headers"]["x-amz-security-token"], "[REDACTED]");
1874 assert_eq!(r["headers"]["X-Key"], "ok");
1875 assert_eq!(r["provider_options"]["headers"]["Cookie"], "[REDACTED]");
1876 assert_eq!(r["body_overrides"]["api_key"], "[REDACTED]");
1877 assert_eq!(r["body_overrides"]["token"], "[REDACTED]");
1878 assert_eq!(r["body_overrides"]["access_token"], "[REDACTED]");
1879 assert_eq!(r["usage"]["max_output_tokens"], 4096);
1881 assert_eq!(r["usage"]["prompt_tokens"], 10);
1882 assert_eq!(r["usage"]["completion_tokens"], 20);
1883 assert_eq!(r["temperature"], 0.5);
1884 }
1885
1886 #[test]
1887 fn recording_round_trips() {
1888 let rec = Recording::new(
1889 "call-1",
1890 InputRecord::from_call_options(&sample_options()),
1891 ProviderRecord::minimal("openai", "gpt-4o"),
1892 );
1893 let json = serde_json::to_string(&rec).unwrap();
1894 let back: Recording = serde_json::from_str(&json).unwrap();
1895 assert_eq!(back.call_id, "call-1");
1896 assert_eq!(back.schema, RECORDING_SCHEMA);
1897 assert_eq!(back.provider.provider, "openai");
1898 }
1899
1900 #[test]
1901 fn jsonl_flush_writes_complete_line_blocking() {
1902 let dir = std::env::temp_dir().join(format!("aimux-rec-test-{}", std::process::id()));
1903 let _ = std::fs::remove_dir_all(&dir);
1904 let rec = JsonlRecorder::new(&dir);
1905
1906 rec.record_input("call-flush-1", &sample_options(), "openai", "gpt-4o");
1907 rec.record_outcome(
1908 "call-flush-1",
1909 &OutcomeRecord {
1910 status: OutcomeStatus::Success,
1911 finish_reason: Some("stop".into()),
1912 error: None,
1913 error_value: None,
1914 usage: None,
1915 },
1916 );
1917 rec.record_transport_closed("call-flush-1");
1919 rec.flush();
1921 let content = std::fs::read_to_string(rec.path()).unwrap();
1922 let parsed: Recording = serde_json::from_str(content.trim()).unwrap();
1923 assert_eq!(parsed.call_id, "call-flush-1");
1924 assert_eq!(parsed.outcome.status, OutcomeStatus::Success);
1925 assert!(parsed.exchanges.is_empty()); let _ = std::fs::remove_dir_all(&dir);
1928 }
1929
1930 #[test]
1933 fn barrier_requires_input_record() {
1934 let mut rec = Recording::new(
1937 "call-x",
1938 InputRecord {
1939 prompt: Vec::new(),
1940 options: serde_json::Value::Null,
1941 },
1942 ProviderRecord::minimal("openai", "gpt-4o"),
1943 );
1944 rec.transport_closed = true;
1945 rec.outcome = OutcomeRecord {
1946 status: OutcomeStatus::Success,
1947 finish_reason: Some("stop".into()),
1948 error: None,
1949 error_value: None,
1950 usage: None,
1951 };
1952 assert!(!rec.ready(), "empty-prompt placeholder must not finalize");
1953 rec.input = InputRecord::from_call_options(&sample_options());
1954 assert!(rec.ready(), "real input satisfies the barrier");
1955 }
1956
1957 #[test]
1958 fn missing_input_writes_incomplete_on_shutdown() {
1959 let dir = std::env::temp_dir().join(format!("aimux-rec-noinput-{}", std::process::id()));
1960 let _ = std::fs::remove_dir_all(&dir);
1961 let rec = JsonlRecorder::new(&dir);
1962
1963 rec.record_outcome(
1965 "call-noinput",
1966 &OutcomeRecord {
1967 status: OutcomeStatus::Success,
1968 finish_reason: Some("stop".into()),
1969 error: None,
1970 error_value: None,
1971 usage: None,
1972 },
1973 );
1974 rec.record_transport_closed("call-noinput");
1975 rec.flush();
1976 drop(rec);
1978 let content = std::fs::read_to_string(dir.join("recordings.jsonl")).unwrap();
1979 let parsed: Recording = serde_json::from_str(content.trim()).unwrap();
1980 assert!(
1981 !parsed.complete,
1982 "must not be marked complete without input"
1983 );
1984 assert!(parsed.input.prompt.is_empty());
1985 assert_eq!(parsed.outcome.status, OutcomeStatus::Success);
1986
1987 let _ = std::fs::remove_dir_all(&dir);
1988 }
1989
1990 struct FailingWriter;
1992
1993 impl std::io::Write for FailingWriter {
1994 fn write(&mut self, _buf: &[u8]) -> std::io::Result<usize> {
1995 Err(std::io::Error::other("simulated disk full"))
1996 }
1997 fn flush(&mut self) -> std::io::Result<()> {
1998 Err(std::io::Error::other("simulated disk full"))
1999 }
2000 }
2001
2002 #[test]
2003 fn try_flush_reports_writer_io_error() {
2004 let (tx, rx) = sync_channel(16);
2005 let write_error = Arc::new(Mutex::new(None));
2006 let handle = {
2007 let inconsistent = Arc::new(Mutex::new(HashSet::new()));
2008 let w_err = write_error.clone();
2009 std::thread::spawn(move || writer_loop(rx, FailingWriter, inconsistent, w_err))
2010 };
2011
2012 tx.send(RecordEvent::Input {
2013 call_id: "c1".into(),
2014 input: InputRecord::from_call_options(&sample_options()),
2015 provider: ProviderRecord::minimal("openai", "gpt-4o"),
2016 })
2017 .unwrap();
2018 tx.send(RecordEvent::TransportClosed {
2019 call_id: "c1".into(),
2020 })
2021 .unwrap();
2022 tx.send(RecordEvent::Outcome {
2023 call_id: "c1".into(),
2024 outcome: OutcomeRecord {
2025 status: OutcomeStatus::Success,
2026 finish_reason: Some("stop".into()),
2027 error: None,
2028 error_value: None,
2029 usage: None,
2030 },
2031 })
2032 .unwrap();
2033
2034 let (ack_tx, ack_rx) = sync_channel(0);
2035 tx.send(RecordEvent::Flush { ack: ack_tx }).unwrap();
2036 let status = ack_rx
2037 .recv_timeout(Duration::from_secs(5))
2038 .expect("flush ack within timeout");
2039 assert!(
2040 matches!(&status, Err(RecordingError::Write(m)) if m.contains("disk full")),
2041 "expected Err(Write) carrying the io error, got {status:?}"
2042 );
2043
2044 drop(tx);
2045 handle.join().unwrap();
2046 assert!(write_error.lock().unwrap().is_some());
2048 }
2049
2050 #[test]
2053 fn record_session_writes_session_fields_to_jsonl() {
2054 let dir = std::env::temp_dir().join(format!("aimux-rec-sess-{}", std::process::id()));
2055 let _ = std::fs::remove_dir_all(&dir);
2056 let rec = JsonlRecorder::new(&dir);
2057
2058 rec.record_input("call-sess-1", &sample_options(), "openai", "gpt-4o");
2059 rec.record_session("call-sess-1", "sess-abc", 3);
2061 rec.record_outcome(
2062 "call-sess-1",
2063 &OutcomeRecord {
2064 status: OutcomeStatus::Success,
2065 finish_reason: Some("stop".into()),
2066 error: None,
2067 error_value: None,
2068 usage: None,
2069 },
2070 );
2071 rec.record_transport_closed("call-sess-1");
2072 rec.flush();
2073
2074 let content = std::fs::read_to_string(rec.path()).unwrap();
2075 let parsed: Recording = serde_json::from_str(content.trim()).unwrap();
2076 assert_eq!(parsed.session_id.as_deref(), Some("sess-abc"));
2077 assert_eq!(parsed.step, Some(3));
2078 assert!(content.contains("\"session_id\":\"sess-abc\""));
2080 assert!(content.contains("\"step\":3"));
2081 }
2082
2083 #[test]
2084 fn ungrouped_recording_omits_session_fields_and_old_jsonl_parses() {
2085 let rec = Recording::new(
2087 "call-1",
2088 InputRecord::from_call_options(&sample_options()),
2089 ProviderRecord::minimal("openai", "gpt-4o"),
2090 );
2091 let json = serde_json::to_string(&rec).unwrap();
2092 assert!(!json.contains("session_id"), "ungrouped must omit: {json}");
2093 assert!(!json.contains("\"step\""), "ungrouped must omit: {json}");
2094
2095 let old_json = serde_json::to_string(&{
2097 let mut r = serde_json::to_value(&rec).unwrap();
2098 r.as_object_mut()
2099 .unwrap()
2100 .insert("transport_closed".into(), serde_json::json!(true));
2101 r
2102 })
2103 .unwrap();
2104 let back: Recording = serde_json::from_str(&old_json).unwrap();
2105 assert_eq!(back.session_id, None);
2106 assert_eq!(back.step, None);
2107 }
2108
2109 #[test]
2110 fn exchange_update_is_attached_to_correct_attempt() {
2111 let dir = std::env::temp_dir().join(format!("aimux-rec-test2-{}", std::process::id()));
2112 let _ = std::fs::remove_dir_all(&dir);
2113 let rec = JsonlRecorder::new(&dir);
2114
2115 rec.record_input("call-x2", &sample_options(), "openai", "gpt-4o");
2116 rec.record_exchange(
2118 "call-x2",
2119 &HttpExchange {
2120 step: None,
2121 attempt: 0,
2122 exchange_index: 0,
2123 request: HttpRecord {
2124 method: "post".into(),
2125 url: "u".into(),
2126 headers: vec![("authorization".into(), "[REDACTED]".into())],
2127 body: Some("{}".into()),
2128 },
2129 response: None,
2130 timing: TimingRecord {
2131 latency_ms: 1,
2132 ttfb_ms: None,
2133 },
2134 error: None,
2135 finalized: false,
2136 },
2137 );
2138 rec.record_exchange_update(
2139 "call-x2",
2140 0,
2141 0,
2142 &ResponseRecord {
2143 status: 200,
2144 headers: vec![],
2145 body: Some("{\"ok\":true}".into()),
2146 stream_chunks: Some(1),
2147 ttfb_ms: None,
2148 },
2149 None,
2150 );
2151 rec.record_outcome(
2152 "call-x2",
2153 &OutcomeRecord {
2154 status: OutcomeStatus::Success,
2155 finish_reason: None,
2156 error: None,
2157 error_value: None,
2158 usage: None,
2159 },
2160 );
2161 rec.record_transport_closed("call-x2");
2162 rec.flush();
2163
2164 let content = std::fs::read_to_string(rec.path()).unwrap();
2165 let parsed: Recording = serde_json::from_str(content.trim()).unwrap();
2166 assert_eq!(parsed.exchanges.len(), 1);
2167 assert_eq!(parsed.exchanges[0].response.as_ref().unwrap().status, 200);
2168 assert!(parsed.exchanges[0].finalized);
2169
2170 let _ = std::fs::remove_dir_all(&dir);
2171 }
2172
2173 #[test]
2174 fn error_patches_existing_exchange_not_duplicate() {
2175 let dir = std::env::temp_dir().join(format!("aimux-rec-errpatch-{}", std::process::id()));
2176 let _ = std::fs::remove_dir_all(&dir);
2177 let rec = JsonlRecorder::new(&dir);
2178 rec.record_input("call-errp", &sample_options(), "openai", "gpt-4o");
2179 rec.record_exchange(
2180 "call-errp",
2181 &HttpExchange {
2182 step: None,
2183 attempt: 3,
2184 exchange_index: 0,
2185 request: HttpRecord {
2186 method: "post".into(),
2187 url: "u".into(),
2188 headers: vec![],
2189 body: Some("{}".into()),
2190 },
2191 response: Some(ResponseRecord {
2192 status: 200,
2193 headers: vec![],
2194 body: None,
2195 stream_chunks: None,
2196 ttfb_ms: None,
2197 }),
2198 timing: TimingRecord {
2199 latency_ms: 1,
2200 ttfb_ms: None,
2201 },
2202 error: None,
2203 finalized: false,
2204 },
2205 );
2206 rec.record_exchange_update(
2208 "call-errp",
2209 3,
2210 0,
2211 &ResponseRecord {
2212 status: 200,
2213 headers: vec![],
2214 body: Some(r#"{"partial":true}"#.into()),
2215 stream_chunks: Some(1),
2216 ttfb_ms: Some(12),
2217 },
2218 Some("mid-stream error".to_string()),
2219 );
2220 rec.record_transport_closed("call-errp");
2221 rec.record_outcome(
2222 "call-errp",
2223 &OutcomeRecord {
2224 status: OutcomeStatus::Error,
2225 finish_reason: None,
2226 error: Some("mid-stream".into()),
2227 error_value: None,
2228 usage: None,
2229 },
2230 );
2231 rec.flush();
2232 let content = std::fs::read_to_string(rec.path()).unwrap();
2233 let parsed: Recording = serde_json::from_str(content.trim()).unwrap();
2234 assert_eq!(
2236 parsed.exchanges.len(),
2237 1,
2238 "error must patch same attempt, not duplicate"
2239 );
2240 assert_eq!(parsed.exchanges[0].attempt, 3);
2241 let ex = &parsed.exchanges[0];
2242 assert!(ex.finalized);
2243 assert_eq!(ex.error.as_deref(), Some("mid-stream error"));
2244 assert!(
2246 ex.response
2247 .as_ref()
2248 .unwrap()
2249 .body
2250 .as_deref()
2251 .unwrap()
2252 .contains("partial")
2253 );
2254 assert_eq!(ex.response.as_ref().unwrap().ttfb_ms, Some(12));
2255 assert!(parsed.complete, "finalized exchange + closed -> complete");
2257 let _ = std::fs::remove_dir_all(&dir);
2258 }
2259
2260 #[test]
2261 fn barrier_waits_for_transport_closed_and_marks_complete() {
2262 let dir = std::env::temp_dir().join(format!("aimux-rec-btc-{}", std::process::id()));
2263 let _ = std::fs::remove_dir_all(&dir);
2264 let rec = JsonlRecorder::new(&dir);
2265
2266 rec.record_input("call-btc-1", &sample_options(), "openai", "gpt-4o");
2267 rec.record_outcome(
2268 "call-btc-1",
2269 &OutcomeRecord {
2270 status: OutcomeStatus::Success,
2271 finish_reason: None,
2272 error: None,
2273 error_value: None,
2274 usage: None,
2275 },
2276 );
2277 rec.flush();
2279 let content = std::fs::read_to_string(rec.path()).unwrap();
2280 assert!(
2281 content.trim().is_empty(),
2282 "must not write before transport closed"
2283 );
2284
2285 rec.record_transport_closed("call-btc-1");
2287 rec.flush();
2288 let content = std::fs::read_to_string(rec.path()).unwrap();
2289 let parsed: Recording = serde_json::from_str(content.trim()).unwrap();
2290 assert_eq!(parsed.call_id, "call-btc-1");
2291 assert!(
2292 parsed.complete,
2293 "fully-finalized recording must be complete"
2294 );
2295
2296 let _ = std::fs::remove_dir_all(&dir);
2297 }
2298
2299 #[test]
2300 fn incomplete_outcome_flushes_on_shutdown() {
2301 let dir = std::env::temp_dir().join(format!("aimux-rec-test3-{}", std::process::id()));
2302 let _ = std::fs::remove_dir_all(&dir);
2303 {
2304 let rec = JsonlRecorder::new(&dir);
2305 rec.record_input("call-orphan", &sample_options(), "openai", "gpt-4o");
2306 }
2308 let content = std::fs::read_to_string(dir.join("recordings.jsonl"))
2309 .expect("disconnected fallback must write the incomplete line");
2310 let parsed: Recording = serde_json::from_str(content.trim()).unwrap();
2311 assert_eq!(parsed.outcome.status, OutcomeStatus::Incomplete);
2312 assert!(
2313 !parsed.complete,
2314 "fallback line must not be marked complete"
2315 );
2316 let _ = std::fs::remove_dir_all(&dir);
2317 }
2318
2319 fn sample_exchange() -> HttpExchange {
2322 HttpExchange {
2323 step: None,
2324 attempt: 0,
2325 exchange_index: 0,
2326 request: HttpRecord {
2327 method: "post".into(),
2328 url: "https://api.openai.com/v1/chat/completions".into(),
2329 headers: vec![],
2330 body: Some("{}".into()),
2331 },
2332 response: Some(ResponseRecord {
2333 status: 200,
2334 headers: vec![],
2335 body: Some("{\"ok\":true}".into()),
2336 stream_chunks: None,
2337 ttfb_ms: None,
2338 }),
2339 timing: TimingRecord {
2340 latency_ms: 1,
2341 ttfb_ms: None,
2342 },
2343 error: None,
2344 finalized: true,
2345 }
2346 }
2347
2348 fn success_outcome() -> OutcomeRecord {
2349 OutcomeRecord {
2350 status: OutcomeStatus::Success,
2351 finish_reason: Some("stop".into()),
2352 error: None,
2353 error_value: None,
2354 usage: None,
2355 }
2356 }
2357
2358 fn drive_full_call(rec: &RingRecorder, call_id: &str) {
2360 rec.record_input(call_id, &sample_options(), "openai", "gpt-4o");
2361 rec.record_exchange(call_id, &sample_exchange());
2362 rec.record_outcome(call_id, &success_outcome());
2363 rec.record_transport_closed(call_id);
2364 }
2365
2366 #[test]
2367 fn ring_merges_shards_and_finalizes_on_barrier() {
2368 let ring = RingRecorder::new();
2369 drive_full_call(&ring, "call-a");
2370 assert_eq!(ring.len(), 1);
2371 assert_eq!(ring.pending_count(), 0);
2372
2373 let mut buf = Vec::new();
2374 ring.export_jsonl(&mut buf).unwrap();
2375 let parsed: Recording =
2376 serde_json::from_str(std::str::from_utf8(&buf).unwrap().trim()).unwrap();
2377 assert_eq!(parsed.call_id, "call-a");
2378 assert_eq!(parsed.exchanges.len(), 1);
2379 assert_eq!(parsed.outcome.status, OutcomeStatus::Success);
2380 assert!(parsed.complete);
2381 }
2382
2383 #[test]
2384 fn ring_records_session_fields_and_get_by_call_id() {
2385 let ring = RingRecorder::new();
2386 ring.record_input("call-s", &sample_options(), "openai", "gpt-4o");
2387 ring.record_session("call-s", "sess-1", 3);
2388 ring.record_outcome("call-s", &success_outcome());
2389 ring.record_transport_closed("call-s");
2390 ring.flush();
2391
2392 let rec = ring
2393 .get("call-s")
2394 .expect("recording retrievable by call_id");
2395 assert_eq!(rec.session_id.as_deref(), Some("sess-1"));
2396 assert_eq!(rec.step, Some(3));
2397
2398 let all = ring.completed();
2399 assert_eq!(all.len(), 1);
2400 assert_eq!(all[0].call_id, "call-s");
2401 assert!(ring.get("missing").is_none());
2402 }
2403
2404 #[test]
2405 fn ring_keeps_incomplete_in_pending_until_closed() {
2406 let ring = RingRecorder::new();
2407 ring.record_input("call-x", &sample_options(), "openai", "gpt-4o");
2408 ring.record_outcome("call-x", &success_outcome());
2409 ring.flush();
2411 assert_eq!(ring.len(), 0);
2412 assert_eq!(ring.pending_count(), 1);
2413
2414 ring.record_transport_closed("call-x");
2415 ring.flush();
2416 assert_eq!(ring.len(), 1);
2417 assert_eq!(ring.pending_count(), 0);
2418 }
2419
2420 #[test]
2421 fn ring_evicts_oldest_and_counts_drops() {
2422 let ring = RingRecorder::with_capacity(2);
2423 drive_full_call(&ring, "call-1");
2424 drive_full_call(&ring, "call-2");
2425 drive_full_call(&ring, "call-3");
2426 assert_eq!(ring.len(), 2, "ring is bounded");
2427 assert_eq!(ring.dropped_count(), 1, "oldest evicted and counted");
2428
2429 let mut buf = Vec::new();
2431 ring.export_jsonl(&mut buf).unwrap();
2432 let lines: Vec<&str> = std::str::from_utf8(&buf)
2433 .unwrap()
2434 .lines()
2435 .filter(|l| !l.trim().is_empty())
2436 .collect();
2437 assert_eq!(lines.len(), 2);
2438 assert!(lines[0].contains("call-2"));
2439 assert!(lines[1].contains("call-3"));
2440 }
2441
2442 #[test]
2443 fn ring_flush_finalizes_ready_pending() {
2444 let ring = RingRecorder::new();
2445 ring.record_input("call-f", &sample_options(), "openai", "gpt-4o");
2446 ring.record_outcome("call-f", &success_outcome());
2447 ring.record_transport_closed("call-f");
2448 ring.flush();
2451 ring.flush();
2452 assert_eq!(ring.len(), 1);
2453 }
2454
2455 #[test]
2456 fn ring_clear_resets_everything() {
2457 let ring = RingRecorder::with_capacity(2);
2458 drive_full_call(&ring, "call-1");
2459 ring.record_input("call-p", &sample_options(), "openai", "gpt-4o"); assert_eq!(ring.len(), 1);
2461 assert_eq!(ring.pending_count(), 1);
2462
2463 ring.clear();
2464 assert_eq!(ring.len(), 0);
2465 assert_eq!(ring.pending_count(), 0);
2466 assert_eq!(ring.dropped_count(), 0);
2467 }
2468
2469 fn days_from_civil(y: i64, m: u32, d: u32) -> i64 {
2473 let y = if m <= 2 { y - 1 } else { y };
2474 let era = (if y >= 0 { y } else { y - 399 }) / 400;
2475 let yoe = (y - era * 400) as u64;
2476 let mp = if m > 2 { m - 3 } else { m + 9 } as u64;
2477 let doy = (153 * mp + 2) / 5 + d as u64 - 1;
2478 let doe = yoe * 365 + yoe / 4 - yoe / 100 + doy;
2479 era * 146_097 + doe as i64 - 719_468
2480 }
2481
2482 fn parse_rfc3339_secs(s: &str) -> Option<(i64, u32)> {
2484 let b = s.as_bytes();
2485 if s.len() < 24
2486 || b[4] != b'-'
2487 || b[7] != b'-'
2488 || b[10] != b'T'
2489 || b[13] != b':'
2490 || b[16] != b':'
2491 || b[19] != b'.'
2492 || !s.ends_with('Z')
2493 {
2494 return None;
2495 }
2496 let year: i64 = s[0..4].parse().ok()?;
2497 let month: u32 = s[5..7].parse().ok()?;
2498 let day: u32 = s[8..10].parse().ok()?;
2499 let hour: u64 = s[11..13].parse().ok()?;
2500 let min: u64 = s[14..16].parse().ok()?;
2501 let sec: u64 = s[17..19].parse().ok()?;
2502 let millis: u32 = s[20..s.len() - 1].parse().ok()?;
2503 let total =
2504 days_from_civil(year, month, day) * 86_400 + (hour * 3600 + min * 60 + sec) as i64;
2505 Some((total, millis))
2506 }
2507
2508 #[test]
2509 fn format_rfc3339_utc_is_valid_rfc3339() {
2510 assert_eq!(
2512 format_rfc3339_utc(Duration::ZERO),
2513 "1970-01-01T00:00:00.000Z"
2514 );
2515 let d = Duration::from_secs(1_700_000_000);
2517 let s = format_rfc3339_utc(d);
2518 assert_eq!(s.len(), 24);
2519 assert!(s.ends_with('Z'));
2520 let (secs, millis) = parse_rfc3339_secs(&s).expect("must parse");
2521 assert_eq!(secs, 1_700_000_000);
2522 assert_eq!(millis, 0);
2523 let (s2, m2) =
2525 parse_rfc3339_secs(&format_rfc3339_utc(Duration::from_millis(12_345))).unwrap();
2526 assert_eq!((s2, m2), (12, 345));
2527 let now = iso8601_now();
2529 assert!(parse_rfc3339_secs(&now).is_some(), "now not rfc3339: {now}");
2530 }
2531
2532 #[test]
2535 fn send_or_drop_counts_overflow() {
2536 let (tx, rx) = sync_channel::<RecordEvent>(1);
2538 let dropped = AtomicU64::new(0);
2539 let ev = || RecordEvent::TransportClosed {
2540 call_id: "c".into(),
2541 };
2542 send_or_drop(&tx, ev(), &dropped);
2543 send_or_drop(&tx, ev(), &dropped);
2544 send_or_drop(&tx, ev(), &dropped);
2545 assert_eq!(dropped.load(Ordering::Relaxed), 2);
2546 assert!(rx.try_recv().is_ok()); assert!(rx.try_recv().is_err()); }
2549
2550 #[test]
2551 fn jsonl_dropped_count_starts_zero() {
2552 let dir = std::env::temp_dir().join(format!("aimux-rec-drop-{}", std::process::id()));
2553 let _ = std::fs::remove_dir_all(&dir);
2554 let rec = JsonlRecorder::new(&dir);
2555 assert_eq!(rec.dropped_count(), 0);
2556 let _ = std::fs::remove_dir_all(&dir);
2557 }
2558
2559 #[test]
2562 fn jsonl_try_new_fails_on_invalid_dir() {
2563 let blocker =
2564 std::env::temp_dir().join(format!("aimux-rec-blocker-{}", std::process::id()));
2565 let _ = std::fs::remove_file(&blocker);
2566 std::fs::write(&blocker, b"x").unwrap();
2567 let res = JsonlRecorder::try_new(blocker.join("sub"));
2569 assert!(
2570 matches!(res, Err(RecordingError::Init { .. })),
2571 "expected Init, got {:?}",
2572 res.as_ref().err()
2573 );
2574 let _ = std::fs::remove_file(&blocker);
2575 }
2576
2577 #[test]
2578 fn jsonl_try_flush_ok_and_disabled_err() {
2579 let dir = std::env::temp_dir().join(format!("aimux-rec-tf-{}", std::process::id()));
2580 let _ = std::fs::remove_dir_all(&dir);
2581 let rec = JsonlRecorder::new(&dir);
2582 rec.record_input("c", &sample_options(), "openai", "gpt-4o");
2583 rec.record_outcome("c", &success_outcome());
2584 rec.record_transport_closed("c");
2585 assert!(rec.try_flush().is_ok());
2586 let content = std::fs::read_to_string(rec.path()).unwrap();
2587 assert!(content.contains("\"call_id\":\"c\""));
2588 let _ = std::fs::remove_dir_all(&dir);
2589
2590 let blocker =
2592 std::env::temp_dir().join(format!("aimux-rec-blocker2-{}", std::process::id()));
2593 let _ = std::fs::remove_file(&blocker);
2594 std::fs::write(&blocker, b"x").unwrap();
2595 let disabled = JsonlRecorder::new(blocker.join("sub"));
2596 assert!(matches!(
2597 disabled.try_flush(),
2598 Err(RecordingError::WriterGone)
2599 ));
2600 let _ = std::fs::remove_file(&blocker);
2601 }
2602
2603 #[test]
2606 fn ring_pending_evicts_oldest_when_bounded() {
2607 let ring = RingRecorder::with_capacity(2); for i in 1..=5u32 {
2609 ring.record_input(&format!("call-{i}"), &sample_options(), "openai", "gpt-4o");
2610 }
2611 assert_eq!(ring.pending_count(), 4, "pending bounded to 4");
2612 assert_eq!(ring.len(), 1, "oldest evicted into ring as incomplete");
2613 assert_eq!(ring.pending_evicted_count(), 1);
2614
2615 let mut buf = Vec::new();
2616 ring.export_jsonl(&mut buf).unwrap();
2617 let parsed: Recording =
2618 serde_json::from_str(std::str::from_utf8(&buf).unwrap().trim()).unwrap();
2619 assert_eq!(parsed.call_id, "call-1", "oldest (call-1) evicted");
2620 assert!(!parsed.complete, "evicted pending → incomplete");
2621 assert_eq!(parsed.outcome.status, OutcomeStatus::Incomplete);
2622 }
2623
2624 fn full_provider() -> ProviderRecord {
2627 ProviderRecord {
2628 provider: "openai".into(),
2629 model_id: "gpt-4o".into(),
2630 base_url: Some("https://api.openai.com".into()),
2631 api_key_source: "env:OPENAI_API_KEY".into(),
2632 profile: None,
2633 provider_options: None,
2634 }
2635 }
2636
2637 #[test]
2638 fn ring_provider_before_input_preserved() {
2639 let ring = RingRecorder::new();
2640 ring.record_provider("c", &full_provider()); ring.record_input("c", &sample_options(), "minimal", "minimal-model");
2642 ring.record_outcome("c", &success_outcome());
2643 ring.record_transport_closed("c");
2644
2645 let mut buf = Vec::new();
2646 ring.export_jsonl(&mut buf).unwrap();
2647 let parsed: Recording =
2648 serde_json::from_str(std::str::from_utf8(&buf).unwrap().trim()).unwrap();
2649 assert_eq!(parsed.provider.provider, "openai");
2650 assert_eq!(
2651 parsed.provider.base_url.as_deref(),
2652 Some("https://api.openai.com"),
2653 "full snapshot preserved, not overwritten by minimal"
2654 );
2655 assert_eq!(parsed.provider.model_id, "gpt-4o");
2656 }
2657
2658 #[test]
2659 fn jsonl_provider_before_input_preserved() {
2660 let dir = std::env::temp_dir().join(format!("aimux-rec-pbi-{}", std::process::id()));
2661 let _ = std::fs::remove_dir_all(&dir);
2662 let rec = JsonlRecorder::new(&dir);
2663 rec.record_provider("c", &full_provider()); rec.record_input("c", &sample_options(), "minimal", "minimal-model");
2665 rec.record_outcome("c", &success_outcome());
2666 rec.record_transport_closed("c");
2667 rec.flush();
2668 let content = std::fs::read_to_string(rec.path()).unwrap();
2669 let parsed: Recording = serde_json::from_str(content.trim()).unwrap();
2670 assert_eq!(
2671 parsed.provider.base_url.as_deref(),
2672 Some("https://api.openai.com")
2673 );
2674 assert_eq!(parsed.provider.provider, "openai");
2675 let _ = std::fs::remove_dir_all(&dir);
2676 }
2677
2678 fn resp_status(status: u16) -> ResponseRecord {
2681 ResponseRecord {
2682 status,
2683 headers: vec![],
2684 body: None,
2685 stream_chunks: None,
2686 ttfb_ms: None,
2687 }
2688 }
2689
2690 fn skeleton_at(attempt: u32) -> HttpExchange {
2691 HttpExchange {
2692 step: None,
2693 attempt,
2694 exchange_index: 1,
2695 request: HttpRecord {
2696 method: "post".into(),
2697 url: "u".into(),
2698 headers: vec![],
2699 body: None,
2700 },
2701 response: None,
2702 timing: TimingRecord {
2703 latency_ms: 1,
2704 ttfb_ms: None,
2705 },
2706 error: None,
2707 finalized: false,
2708 }
2709 }
2710
2711 fn empty_recording(call_id: &str) -> Recording {
2712 Recording::new(
2713 call_id,
2714 InputRecord {
2715 prompt: Vec::new(),
2716 options: serde_json::Value::Null,
2717 },
2718 ProviderRecord::minimal("", ""),
2719 )
2720 }
2721
2722 #[test]
2723 fn interleaved_child_attempts_keep_local_attempt_and_exchange_counters() {
2724 let recorder: Arc<dyn Recorder> =
2725 Arc::new(CaptureRecorder(std::sync::Mutex::new(Vec::new())));
2726 let root = RecordingContext::new("call-1", recorder);
2727 let _ = root.start_attempt(); let a = root.child("router[0]:mock/a");
2730 let b = root.child("router[1]:mock/b");
2731 assert_eq!(a.step().as_deref(), Some("router[0]:mock/a"));
2732 assert_eq!(root.step(), None);
2733
2734 let a1 = a.start_attempt();
2738 let b1 = b.start_attempt();
2739 let mut attempts = vec![a1, b1];
2740 attempts.sort_unstable();
2741 attempts.dedup();
2742 assert_eq!(attempts.len(), 2);
2743
2744 assert_eq!(a.next_exchange(), (a1, 1));
2746 assert_eq!(b.next_exchange(), (b1, 1));
2747 assert_eq!(root.next_exchange(), (1, 1));
2748
2749 let a2 = a.start_attempt(); assert_eq!(a.next_exchange(), (a2, 1));
2753 assert_eq!(b.next_exchange(), (b1, 2));
2754 }
2755
2756 #[test]
2757 fn insert_exchange_and_apply_update_match_semantics() {
2758 let mut rec = empty_recording("c");
2759
2760 assert!(!insert_exchange(&mut rec, skeleton_at(0)));
2762 assert!(!insert_exchange(&mut rec, skeleton_at(1)));
2763 assert_eq!(rec.exchanges.len(), 2);
2764
2765 let mut dup = skeleton_at(0);
2767 dup.response = Some(resp_status(500));
2768 dup.error = Some("dup".into());
2769 dup.finalized = true;
2770 assert!(insert_exchange(&mut rec, dup));
2771 assert_eq!(rec.exchanges.len(), 2);
2772 let e0 = rec.exchanges.iter().find(|e| e.attempt == 0).unwrap();
2773 assert_eq!(e0.response.as_ref().unwrap().status, 500);
2774 assert!(e0.finalized);
2775 assert_eq!(e0.error.as_deref(), Some("dup"));
2776
2777 assert_eq!(
2779 apply_exchange_update(&mut rec, 1, 1, resp_status(200), None),
2780 UpdateMatch::Patched
2781 );
2782 assert_eq!(
2783 rec.exchanges
2784 .iter()
2785 .find(|e| e.attempt == 1)
2786 .unwrap()
2787 .response
2788 .as_ref()
2789 .unwrap()
2790 .status,
2791 200
2792 );
2793
2794 assert_eq!(
2796 apply_exchange_update(&mut rec, 9, 0, resp_status(200), None),
2797 UpdateMatch::NotFound
2798 );
2799
2800 rec.exchanges.push(skeleton_at(1));
2802 assert_eq!(
2803 apply_exchange_update(&mut rec, 1, 1, resp_status(503), Some("amb".into())),
2804 UpdateMatch::Ambiguous
2805 );
2806 assert!(
2807 rec.exchanges
2808 .iter()
2809 .filter(|e| e.attempt == 1)
2810 .all(|e| e.response.as_ref().is_none_or(|r| r.status != 503))
2811 );
2812 }
2813
2814 #[test]
2815 fn ring_duplicate_attempt_marks_inconsistent_and_merges() {
2816 let ring = RingRecorder::new();
2817 ring.record_input("c", &sample_options(), "openai", "gpt-4o");
2818 ring.record_exchange("c", &sample_exchange()); ring.record_exchange("c", &sample_exchange()); assert!(ring.inconsistent_call_ids().contains(&"c".to_string()));
2821
2822 ring.record_outcome("c", &success_outcome());
2824 ring.record_transport_closed("c");
2825 let mut buf = Vec::new();
2826 ring.export_jsonl(&mut buf).unwrap();
2827 let parsed: Recording =
2828 serde_json::from_str(std::str::from_utf8(&buf).unwrap().trim()).unwrap();
2829 assert_eq!(parsed.exchanges.len(), 1, "duplicate merged, not appended");
2830 assert_eq!(parsed.exchanges[0].attempt, 0);
2831 }
2832
2833 #[test]
2834 fn ring_update_not_found_marks_inconsistent() {
2835 let ring = RingRecorder::new();
2836 ring.record_input("c", &sample_options(), "openai", "gpt-4o");
2837 ring.record_exchange_update("c", 0, 0, &resp_status(200), None);
2839 assert!(ring.inconsistent_call_ids().contains(&"c".to_string()));
2840 assert_eq!(
2841 ring.pending_count(),
2842 1,
2843 "call still pending, no exchange created"
2844 );
2845 }
2846
2847 #[test]
2848 fn jsonl_duplicate_attempt_marks_inconsistent() {
2849 let dir = std::env::temp_dir().join(format!("aimux-rec-dup-{}", std::process::id()));
2850 let _ = std::fs::remove_dir_all(&dir);
2851 let rec = JsonlRecorder::new(&dir);
2852 rec.record_input("c", &sample_options(), "openai", "gpt-4o");
2853 rec.record_exchange("c", &sample_exchange());
2854 rec.record_exchange("c", &sample_exchange()); rec.flush();
2856 assert!(rec.inconsistent_call_ids().contains(&"c".to_string()));
2857 let _ = std::fs::remove_dir_all(&dir);
2858 }
2859}