1use super::{RecordStamp, TelemetryRecord};
51use crate::runtime::trace::{RequestTrace, TraceSink};
52use std::path::PathBuf;
53use std::sync::atomic::{AtomicBool, AtomicU64, Ordering};
54use std::sync::mpsc::{sync_channel, Receiver, SyncSender, TrySendError};
55use std::sync::{Arc, Condvar, Mutex as StdMutex};
56use std::time::{Duration, Instant};
57
58pub const DEFAULT_QUEUE_CAPACITY: usize = 1024;
61
62pub const DEFAULT_MAX_FILE_BYTES: u64 = 50 * 1024 * 1024;
64
65pub const DEFAULT_MAX_GENERATIONS: u32 = 1;
68
69pub const ROTATE_LOCK_WAIT: Duration = Duration::from_secs(2);
72
73const MAX_GENERATIONS: u32 = agent_core::config::MAX_TELEMETRY_LOG_GENERATIONS;
77
78pub const DEFAULT_SHUTDOWN_FLUSH_TIMEOUT: Duration = Duration::from_secs(2);
82
83fn lock_recover<T>(m: &StdMutex<T>) -> std::sync::MutexGuard<'_, T> {
92 m.lock().unwrap_or_else(std::sync::PoisonError::into_inner)
93}
94
95pub fn default_telemetry_log_path() -> Option<PathBuf> {
97 let home = std::env::var("HOME").ok()?;
98 Some(PathBuf::from(home).join(".cache/synaps/api-log.jsonl"))
99}
100
101pub fn default_trace_log_path() -> Option<PathBuf> {
103 let home = std::env::var("HOME").ok()?;
104 Some(PathBuf::from(home).join(".cache/synaps/request-trace.jsonl"))
105}
106
107#[derive(Debug, Clone)]
109pub struct WriterOptions {
110 pub telemetry_path: Option<PathBuf>,
111 pub trace_path: Option<PathBuf>,
112 pub capacity: usize,
114 pub max_file_bytes: u64,
116 pub max_generations: u32,
119 pub write_delay: Option<Duration>,
122 pub write_gate: Option<WriteGate>,
126}
127
128#[derive(Debug, Clone, Default)]
131pub struct WriteGate(Arc<(StdMutex<bool>, Condvar)>);
132
133impl WriteGate {
134 pub fn closed() -> Self {
136 Self::default()
137 }
138
139 pub fn open(&self) {
141 let (open, cv) = &*self.0;
142 *lock_recover(open) = true;
143 cv.notify_all();
144 }
145
146 fn wait(&self) {
147 let (open, cv) = &*self.0;
148 let mut guard = lock_recover(open);
149 while !*guard {
150 guard = cv.wait(guard).unwrap_or_else(|e| e.into_inner());
151 }
152 }
153}
154
155impl Default for WriterOptions {
156 fn default() -> Self {
157 Self {
158 telemetry_path: None,
159 trace_path: None,
160 capacity: DEFAULT_QUEUE_CAPACITY,
161 max_file_bytes: DEFAULT_MAX_FILE_BYTES,
162 max_generations: DEFAULT_MAX_GENERATIONS,
163 write_delay: None,
164 write_gate: None,
165 }
166 }
167}
168
169#[derive(Debug, Clone, Copy, Default, PartialEq, Eq)]
171pub struct WriterStats {
172 pub enqueued: u64,
174 pub written: u64,
176 pub dropped: u64,
178 pub serialization_failures: u64,
180 pub io_failures: u64,
182 pub overflow_warnings: u64,
184 pub serialization_warnings: u64,
186 pub io_warnings: u64,
188 pub rotate_warnings: u64,
190}
191
192#[derive(Debug, Clone, Copy, PartialEq, Eq)]
194pub enum ShutdownOutcome {
195 Flushed(WriterStats),
197 TimedOut(WriterStats),
200}
201
202impl ShutdownOutcome {
203 pub fn stats(&self) -> WriterStats {
204 match self {
205 Self::Flushed(s) | Self::TimedOut(s) => *s,
206 }
207 }
208
209 pub fn is_flushed(&self) -> bool {
210 matches!(self, Self::Flushed(_))
211 }
212}
213
214#[derive(Debug, Clone)]
216pub struct TelemetryWriter {
217 shared: Arc<Shared>,
218 stamp: Option<Arc<RecordStamp>>,
222}
223
224#[derive(Debug)]
227enum Job {
228 Telemetry(Box<TelemetryRecord>),
229 Trace(Box<RequestTrace>),
230}
231
232#[derive(Debug, Default)]
235struct Counters {
236 enqueued: AtomicU64,
237 written: AtomicU64,
238 dropped: AtomicU64,
239 serialization_failures: AtomicU64,
240 io_failures: AtomicU64,
241 overflow_warnings: AtomicU64,
242 serialization_warnings: AtomicU64,
243 io_warnings: AtomicU64,
244 rotate_warnings: AtomicU64,
245 overflow_warned: AtomicBool,
249 serialization_warned: AtomicBool,
250 io_warned: AtomicBool,
251 rotate_warned: AtomicBool,
252}
253
254impl Counters {
255 fn warn_once(latch: &AtomicBool, count: &AtomicU64, class: &str, msg: &str) {
256 if !latch.swap(true, Ordering::Relaxed) {
257 count.fetch_add(1, Ordering::Relaxed);
258 tracing::warn!(class, "{msg}");
260 }
261 }
262
263 fn snapshot(&self) -> WriterStats {
264 WriterStats {
265 enqueued: self.enqueued.load(Ordering::Relaxed),
266 written: self.written.load(Ordering::Relaxed),
267 dropped: self.dropped.load(Ordering::Relaxed),
268 serialization_failures: self.serialization_failures.load(Ordering::Relaxed),
269 io_failures: self.io_failures.load(Ordering::Relaxed),
270 overflow_warnings: self.overflow_warnings.load(Ordering::Relaxed),
271 serialization_warnings: self.serialization_warnings.load(Ordering::Relaxed),
272 io_warnings: self.io_warnings.load(Ordering::Relaxed),
273 rotate_warnings: self.rotate_warnings.load(Ordering::Relaxed),
274 }
275 }
276}
277
278#[derive(Debug)]
279struct Shared {
280 tx: StdMutex<Option<SyncSender<Job>>>,
283 latest_traces: StdMutex<std::collections::BTreeMap<String, RequestTrace>>,
284 worker: StdMutex<Option<std::thread::JoinHandle<()>>>,
287 done: StdMutex<bool>,
288 done_cv: Condvar,
289 counters: Counters,
290}
291
292struct WorkerCfg {
295 telemetry_path: Option<PathBuf>,
296 trace_path: Option<PathBuf>,
297 max_file_bytes: u64,
298 max_generations: u32,
299 write_delay: Option<Duration>,
300 write_gate: Option<WriteGate>,
301 latest_traces: Arc<Shared>,
302}
303
304impl TelemetryWriter {
305 pub fn new(options: WriterOptions) -> Self {
308 let (tx, rx) = sync_channel::<Job>(options.capacity.max(1));
309 let shared = Arc::new(Shared {
310 tx: StdMutex::new(Some(tx)),
311 latest_traces: StdMutex::new(std::collections::BTreeMap::new()),
312 worker: StdMutex::new(None),
313 done: StdMutex::new(false),
314 done_cv: Condvar::new(),
315 counters: Counters::default(),
316 });
317 let cfg = WorkerCfg {
318 telemetry_path: options.telemetry_path.or_else(default_telemetry_log_path),
319 trace_path: options.trace_path.or_else(default_trace_log_path),
320 max_file_bytes: options.max_file_bytes,
321 max_generations: options.max_generations.max(1),
322 write_delay: options.write_delay,
323 write_gate: options.write_gate,
324 latest_traces: Arc::clone(&shared),
325 };
326 let worker_shared = Arc::clone(&shared);
327 let handle = std::thread::Builder::new()
328 .name("synaps-telemetry-writer".to_string())
329 .spawn(move || worker_loop(rx, cfg, worker_shared))
330 .expect("spawning the telemetry writer thread cannot fail");
331 *lock_recover(&shared.worker) = Some(handle);
332 Self {
333 shared,
334 stamp: None,
335 }
336 }
337
338 pub fn with_stamp(&self, stamp: RecordStamp) -> Self {
341 Self {
342 shared: Arc::clone(&self.shared),
343 stamp: Some(Arc::new(stamp)),
344 }
345 }
346
347 pub fn with_session(&self, session_id: Option<String>) -> Self {
350 let mut stamp = self.stamp.as_deref().cloned().unwrap_or_default();
351 stamp.session_id = session_id;
352 self.with_stamp(stamp)
353 }
354
355 pub fn enqueue_telemetry(&self, mut record: TelemetryRecord) {
357 if let Some(stamp) = &self.stamp {
358 stamp.apply(&mut record);
359 }
360 self.enqueue(Job::Telemetry(Box::new(record)));
361 }
362
363 pub fn enqueue_trace(&self, record: RequestTrace) {
365 lock_recover(&self.shared.latest_traces)
366 .insert(record.request_id.as_str().to_string(), record.clone());
367 self.enqueue(Job::Trace(Box::new(record)));
368 }
369
370 pub fn enrich_trace(
371 &self,
372 request_id: &crate::runtime::trace::TraceId,
373 events: Vec<crate::runtime::trace::ToolExecutionEvent>,
374 ) {
375 if let Some(record) = lock_recover(&self.shared.latest_traces).get_mut(request_id.as_str())
376 {
377 record.execution_events = events;
378 }
379 }
380
381 pub fn trace_snapshot(
382 &self,
383 request_id: &crate::runtime::trace::TraceId,
384 ) -> Option<RequestTrace> {
385 lock_recover(&self.shared.latest_traces)
386 .get(request_id.as_str())
387 .cloned()
388 }
389
390 fn enqueue(&self, job: Job) {
391 let c = &self.shared.counters;
392 let guard = lock_recover(&self.shared.tx);
396 let Some(tx) = guard.as_ref() else {
397 c.dropped.fetch_add(1, Ordering::Relaxed);
399 return;
400 };
401 match tx.try_send(job) {
402 Ok(()) => {
403 c.enqueued.fetch_add(1, Ordering::Relaxed);
404 }
405 Err(TrySendError::Full(_)) => {
406 c.dropped.fetch_add(1, Ordering::Relaxed);
407 Counters::warn_once(
408 &c.overflow_warned,
409 &c.overflow_warnings,
410 "queue_overflow",
411 "telemetry writer queue full — dropping records (counted, best-effort)",
412 );
413 }
414 Err(TrySendError::Disconnected(_)) => {
415 c.dropped.fetch_add(1, Ordering::Relaxed);
416 }
417 }
418 }
419
420 pub fn stats(&self) -> WriterStats {
422 self.shared.counters.snapshot()
423 }
424
425 pub fn shutdown(&self, timeout: Duration) -> ShutdownOutcome {
436 drop(lock_recover(&self.shared.tx).take());
439
440 let deadline = Instant::now() + timeout;
441 let mut done = lock_recover(&self.shared.done);
442 while !*done {
443 let now = Instant::now();
444 let Some(remaining) = deadline
445 .checked_duration_since(now)
446 .filter(|d| !d.is_zero())
447 else {
448 break;
449 };
450 let (guard, _timeout) = self
451 .shared
452 .done_cv
453 .wait_timeout(done, remaining)
454 .unwrap_or_else(std::sync::PoisonError::into_inner);
455 done = guard;
456 }
457 let flushed = *done;
458 drop(done);
459
460 if flushed {
461 if let Some(handle) = lock_recover(&self.shared.worker).take() {
463 let _ = handle.join();
464 }
465 }
466 let stats = self.stats();
467 if flushed {
468 ShutdownOutcome::Flushed(stats)
469 } else {
470 ShutdownOutcome::TimedOut(stats)
471 }
472 }
473
474 pub async fn shutdown_async(&self, timeout: Duration) -> ShutdownOutcome {
477 let writer = self.clone();
478 tokio::task::spawn_blocking(move || writer.shutdown(timeout))
479 .await
480 .unwrap_or_else(|_| ShutdownOutcome::TimedOut(self.stats()))
481 }
482}
483
484fn worker_loop(rx: Receiver<Job>, cfg: WorkerCfg, shared: Arc<Shared>) {
487 while let Ok(job) = rx.recv() {
488 if let Some(gate) = &cfg.write_gate {
489 gate.wait();
490 }
491 if let Some(delay) = cfg.write_delay {
492 std::thread::sleep(delay);
493 }
494 process_job(job, &cfg, &shared.counters);
495 }
496 let mut done = lock_recover(&shared.done);
498 *done = true;
499 shared.done_cv.notify_all();
500}
501
502fn process_job(job: Job, cfg: &WorkerCfg, c: &Counters) {
503 let (serialized, path) = match &job {
504 Job::Telemetry(r) => (serde_json::to_string(r), cfg.telemetry_path.as_deref()),
505 Job::Trace(r) => {
506 let latest = lock_recover(&cfg.latest_traces.latest_traces)
507 .get(r.request_id.as_str())
508 .cloned()
509 .unwrap_or_else(|| (**r).clone());
510 (serde_json::to_string(&latest), cfg.trace_path.as_deref())
511 }
512 };
513 let line = match serialized {
514 Ok(line) => line,
515 Err(_) => {
516 note_serialization_failure(c);
517 return;
518 }
519 };
520 let Some(path) = path else {
521 note_io_failure(c);
523 return;
524 };
525 append_private_line(path, &line, cfg.max_file_bytes, cfg.max_generations, c);
526}
527
528fn note_serialization_failure(c: &Counters) {
529 c.serialization_failures.fetch_add(1, Ordering::Relaxed);
530 Counters::warn_once(
531 &c.serialization_warned,
532 &c.serialization_warnings,
533 "serialization",
534 "telemetry record failed to serialize — dropped (counted)",
535 );
536}
537
538fn note_io_failure(c: &Counters) {
539 c.io_failures.fetch_add(1, Ordering::Relaxed);
540 Counters::warn_once(
541 &c.io_warned,
542 &c.io_warnings,
543 "open_write",
544 "telemetry log unwritable — records dropped (counted); \
545 will warn again after the next successful write",
546 );
547}
548
549fn generation_path(path: &std::path::Path, n: u32) -> PathBuf {
551 let mut p = path.as_os_str().to_owned();
552 p.push(format!(".{n}"));
553 PathBuf::from(p)
554}
555
556fn append_private_line(
559 path: &std::path::Path,
560 line: &str,
561 max_bytes: u64,
562 generations: u32,
563 c: &Counters,
564) {
565 if let Some(parent) = path.parent() {
566 if agent_core::core::private_fs::ensure_private_dir(parent).is_err() {
567 note_io_failure(c);
568 return;
569 }
570 }
571
572 rotate_if_over(path, max_bytes, generations, c);
573
574 match agent_core::core::private_fs::open_private_append(path) {
577 Ok(mut f) => {
578 use std::io::Write;
579 if writeln!(f, "{line}").is_ok() {
580 c.written.fetch_add(1, Ordering::Relaxed);
581 c.io_warned.store(false, Ordering::Relaxed);
583 } else {
584 note_io_failure(c);
585 }
586 }
587 Err(_) => note_io_failure(c),
588 }
589}
590
591fn over_cap(path: &std::path::Path, max_bytes: u64) -> bool {
592 std::fs::metadata(path).is_ok_and(|m| m.len() > max_bytes)
593}
594
595fn note_rotate_failure(c: &Counters, msg: &str) {
596 c.io_failures.fetch_add(1, Ordering::Relaxed);
597 Counters::warn_once(&c.rotate_warned, &c.rotate_warnings, "rotate", msg);
598}
599
600fn chmod_private(path: &std::path::Path) {
603 #[cfg(unix)]
604 {
605 use std::os::unix::fs::PermissionsExt;
606 let _ = std::fs::set_permissions(path, std::fs::Permissions::from_mode(0o600));
607 }
608 #[cfg(not(unix))]
609 let _ = path;
610}
611
612fn lock_rotation(path: &std::path::Path) -> Option<std::fs::File> {
615 use fs4::fs_std::FileExt;
616 let mut lock_path = path.as_os_str().to_owned();
617 lock_path.push(".lock");
618 let file = agent_core::core::private_fs::open_private_append(std::path::Path::new(&lock_path)).ok()?;
619 let deadline = Instant::now() + ROTATE_LOCK_WAIT;
620 loop {
621 match FileExt::try_lock_exclusive(&file) {
622 Ok(true) => return Some(file),
623 Ok(false) if Instant::now() < deadline => std::thread::sleep(Duration::from_millis(5)),
624 _ => return None,
625 }
626 }
627}
628
629fn rotate_if_over(path: &std::path::Path, max_bytes: u64, generations: u32, c: &Counters) {
636 if !over_cap(path, max_bytes) {
637 return;
638 }
639 let Some(_lock) = lock_rotation(path) else {
640 note_rotate_failure(c, "telemetry log rotation lock unavailable — appending past the size cap");
641 return;
642 };
643 if !over_cap(path, max_bytes) {
644 return; }
646 let n = generations.clamp(1, MAX_GENERATIONS);
647 for k in (1..n).rev() {
648 let from = generation_path(path, k);
649 if std::fs::symlink_metadata(&from).is_err() {
650 continue;
651 }
652 let to = generation_path(path, k + 1);
653 match std::fs::rename(&from, &to) {
654 Ok(()) => chmod_private(&to),
655 Err(_) => note_rotate_failure(c, "telemetry log generation shift failed — a generation may be lost"),
656 }
657 }
658 let rotated = generation_path(path, 1);
659 if std::fs::rename(path, &rotated).is_ok() {
660 chmod_private(&rotated);
661 c.rotate_warned.store(false, Ordering::Relaxed);
662 } else {
663 note_rotate_failure(c, "telemetry log rotation failed — appending past the size cap");
665 }
666 for k in n + 1..=MAX_GENERATIONS {
669 let stale = generation_path(path, k);
670 if std::fs::symlink_metadata(&stale).is_ok() {
671 let _ = std::fs::remove_file(&stale);
672 }
673 }
674}
675
676#[derive(Debug)]
678pub struct WriterTraceSink {
679 writer: TelemetryWriter,
680}
681
682impl WriterTraceSink {
683 pub fn new(writer: TelemetryWriter) -> Self {
684 Self { writer }
685 }
686}
687
688impl TraceSink for WriterTraceSink {
689 fn emit(&self, record: RequestTrace) {
690 self.writer.enqueue_trace(record);
691 }
692
693 fn enrich_execution_events(
694 &self,
695 request_id: &crate::runtime::trace::TraceId,
696 events: Vec<crate::runtime::trace::ToolExecutionEvent>,
697 ) {
698 self.writer.enrich_trace(request_id, events);
699 }
700
701 fn snapshot_for_request(
702 &self,
703 request_id: &crate::runtime::trace::TraceId,
704 ) -> Option<RequestTrace> {
705 self.writer.trace_snapshot(request_id)
706 }
707
708 fn enabled(&self) -> bool {
709 true
710 }
711}
712
713#[cfg(test)]
714mod tests {
715 use super::*;
716 use crate::runtime::telemetry::TelemetryRecord;
717 use crate::runtime::trace::{
718 CacheMeta, EndpointMeta, RequestAnatomy, RequestTrace, TimingStages, TraceId,
719 TraceSchemaVersion, TransportKind, TransportOutcome,
720 };
721 use std::time::Instant;
722
723 const SENTINEL: &str = "RAW-CONTENT-SENTINEL-9f2c";
724
725 fn tmp_writer(
726 dir: &std::path::Path,
727 capacity: usize,
728 delay: Option<Duration>,
729 ) -> (TelemetryWriter, PathBuf, PathBuf) {
730 let telemetry = dir.join("synaps/api-log.jsonl");
731 let trace = dir.join("synaps/request-trace.jsonl");
732 let w = TelemetryWriter::new(WriterOptions {
733 telemetry_path: Some(telemetry.clone()),
734 trace_path: Some(trace.clone()),
735 capacity,
736 max_file_bytes: DEFAULT_MAX_FILE_BYTES,
737 max_generations: DEFAULT_MAX_GENERATIONS,
738 write_delay: delay,
739 write_gate: None,
740 });
741 (w, telemetry, trace)
742 }
743
744 fn sample_telemetry() -> TelemetryRecord {
745 TelemetryRecord {
746 ts: 42,
747 model: "claude-sonnet-4-6".to_string(),
748 attempt: 1,
749 total_ms: 100,
750 ..Default::default()
751 }
752 }
753
754 fn sample_trace() -> RequestTrace {
758 RequestTrace {
759 schema: TraceSchemaVersion,
760 session_id: TraceId::new("sess-w1").unwrap(),
761 turn_id: TraceId::new("turn-w1").unwrap(),
762 request_id: TraceId::new("req-w1").unwrap(),
763 execution_events: Vec::new(),
764 attempt: 1,
765 model: agent_core::prompt::QualifiedModelId::parse("anthropic/claude-sonnet-4-6")
766 .unwrap(),
767 transport: TransportKind::AnthropicMessages,
768 endpoint: EndpointMeta::new("api.anthropic.com", "/v1/messages").unwrap(),
769 anatomy: RequestAnatomy {
770 system_segment_count: 1,
771 message_count: 1,
772 block_count: SENTINEL.len() as u32 % 7,
773 tool_count: 0,
774 },
775 wire: None,
776 system_segments: vec![],
777 messages: vec![],
778 tools: vec![],
779 cache: CacheMeta::default(),
780 translation_losses: vec![],
781 outcome: TransportOutcome {
782 timings: TimingStages::default(),
783 retries: vec![],
784 provider_request_id: None,
785 http_status: Some(200),
786 stop_reason: None,
787 usage: None,
788 terminal: agent_core::TurnOutcome::Completed,
789 },
790 }
791 }
792
793 fn read_lines(path: &std::path::Path) -> Vec<String> {
794 std::fs::read_to_string(path)
795 .unwrap_or_default()
796 .lines()
797 .map(str::to_string)
798 .collect()
799 }
800
801 #[test]
804 fn flush_writes_telemetry_jsonl_in_legacy_format() {
805 let tmp = tempfile::TempDir::new().unwrap();
806 let (w, telemetry_path, _) = tmp_writer(tmp.path(), 16, None);
807 w.enqueue_telemetry(sample_telemetry());
808 let out = w.shutdown(Duration::from_secs(5));
809 assert!(out.is_flushed());
810 assert_eq!(out.stats().written, 1);
811 assert_eq!(out.stats().enqueued, 1);
812 assert_eq!(out.stats().dropped, 0);
813
814 let lines = read_lines(&telemetry_path);
815 assert_eq!(lines.len(), 1);
816 let expected = serde_json::to_string(&sample_telemetry()).unwrap();
818 assert_eq!(lines[0], expected);
819 assert!(!lines[0].contains("request_id"));
821 assert!(lines[0].contains("\"model\":\"claude-sonnet-4-6\""));
822 }
823
824 #[test]
825 fn trace_lines_are_unwrapped_schema_valid_and_content_free() {
826 let tmp = tempfile::TempDir::new().unwrap();
827 let (w, _, trace_path) = tmp_writer(tmp.path(), 16, None);
828 w.enqueue_trace(sample_trace());
829 assert!(w.shutdown(Duration::from_secs(5)).is_flushed());
830
831 let lines = read_lines(&trace_path);
832 assert_eq!(lines.len(), 1);
833 let parsed: RequestTrace = serde_json::from_str(&lines[0]).unwrap();
835 assert_eq!(parsed, sample_trace());
836 assert!(lines[0].contains("synaps-request-trace/1"));
837 assert!(!lines[0].contains(SENTINEL));
839 }
840
841 #[test]
842 fn both_kinds_interleave_without_cross_contamination() {
843 let tmp = tempfile::TempDir::new().unwrap();
844 let (w, telemetry_path, trace_path) = tmp_writer(tmp.path(), 16, None);
845 w.enqueue_telemetry(sample_telemetry());
846 w.enqueue_trace(sample_trace());
847 w.enqueue_telemetry(sample_telemetry());
848 let out = w.shutdown(Duration::from_secs(5));
849 assert_eq!(out.stats().written, 3);
850 assert_eq!(read_lines(&telemetry_path).len(), 2);
851 assert_eq!(read_lines(&trace_path).len(), 1);
852 }
853
854 #[test]
857 fn overflow_increments_dropped_and_warns_once() {
858 let tmp = tempfile::TempDir::new().unwrap();
859 let (w, _, _) = tmp_writer(tmp.path(), 1, Some(Duration::from_millis(200)));
861 for _ in 0..20 {
862 w.enqueue_telemetry(sample_telemetry());
863 }
864 let stats = w.stats();
865 assert!(stats.dropped > 0, "queue overflow must drop: {stats:?}");
866 assert_eq!(
867 stats.overflow_warnings, 1,
868 "exactly one overflow warning: {stats:?}"
869 );
870 assert_eq!(stats.enqueued + stats.dropped, 20);
871 w.shutdown(Duration::from_secs(5));
872 }
873
874 #[test]
875 fn enqueue_after_shutdown_counts_dropped_never_panics() {
876 let tmp = tempfile::TempDir::new().unwrap();
877 let (w, _, _) = tmp_writer(tmp.path(), 16, None);
878 assert!(w.shutdown(Duration::from_secs(5)).is_flushed());
879 w.enqueue_telemetry(sample_telemetry());
880 w.enqueue_trace(sample_trace());
881 assert_eq!(w.stats().dropped, 2);
882 }
883
884 #[test]
887 fn enqueue_is_fast_even_when_worker_is_slow() {
888 let tmp = tempfile::TempDir::new().unwrap();
889 let (w, _, _) = tmp_writer(tmp.path(), 1, Some(Duration::from_millis(500)));
890 let start = Instant::now();
891 for _ in 0..100 {
892 w.enqueue_telemetry(sample_telemetry());
893 }
894 assert!(
895 start.elapsed() < Duration::from_millis(250),
896 "enqueue must never block on storage: {:?}",
897 start.elapsed()
898 );
899 let out = w.shutdown(Duration::from_millis(100));
901 assert!(!out.is_flushed());
902 }
903
904 #[test]
905 fn trace_sink_emit_is_fast_with_slow_storage() {
906 let tmp = tempfile::TempDir::new().unwrap();
907 let (w, _, _) = tmp_writer(tmp.path(), 1, Some(Duration::from_millis(500)));
908 let sink = WriterTraceSink::new(w.clone());
909 assert!(sink.enabled());
910 let start = Instant::now();
911 for _ in 0..50 {
912 sink.emit(sample_trace());
913 }
914 assert!(
915 start.elapsed() < Duration::from_millis(250),
916 "sink emit must never block on storage: {:?}",
917 start.elapsed()
918 );
919 w.shutdown(Duration::from_millis(100));
920 }
921
922 #[test]
925 fn broken_path_counts_io_failures_and_warns_once() {
926 let tmp = tempfile::TempDir::new().unwrap();
927 let blocker = tmp.path().join("blocked");
929 std::fs::write(&blocker, b"not a dir").unwrap();
930 let w = TelemetryWriter::new(WriterOptions {
931 telemetry_path: Some(blocker.join("api-log.jsonl")),
932 trace_path: Some(blocker.join("request-trace.jsonl")),
933 capacity: 16,
934 max_file_bytes: DEFAULT_MAX_FILE_BYTES,
935 max_generations: 1,
936 write_delay: None,
937 write_gate: None,
938 });
939 for _ in 0..3 {
940 w.enqueue_telemetry(sample_telemetry());
941 }
942 let out = w.shutdown(Duration::from_secs(5));
943 assert!(out.is_flushed(), "broken storage must not stall drain");
944 let stats = out.stats();
945 assert_eq!(stats.io_failures, 3);
946 assert_eq!(stats.io_warnings, 1, "warn once per failure class");
947 assert_eq!(stats.written, 0);
948 }
949
950 #[test]
951 fn io_warning_latch_rearms_after_success() {
952 let tmp = tempfile::TempDir::new().unwrap();
953 let good = tmp.path().join("synaps/api-log.jsonl");
954 let blocker = tmp.path().join("blocked");
955 std::fs::write(&blocker, b"not a dir").unwrap();
956 let w = TelemetryWriter::new(WriterOptions {
958 telemetry_path: Some(good.clone()),
959 trace_path: Some(blocker.join("request-trace.jsonl")),
960 capacity: 16,
961 max_file_bytes: DEFAULT_MAX_FILE_BYTES,
962 max_generations: 1,
963 write_delay: None,
964 write_gate: None,
965 });
966 w.enqueue_trace(sample_trace()); w.enqueue_telemetry(sample_telemetry()); w.enqueue_trace(sample_trace()); let stats = w.shutdown(Duration::from_secs(5)).stats();
970 assert_eq!(stats.io_failures, 2);
971 assert_eq!(stats.io_warnings, 2);
972 assert_eq!(stats.written, 1);
973 }
974
975 #[test]
976 fn serialization_failure_counted_and_warned_once() {
977 let c = Counters::default();
982 note_serialization_failure(&c);
983 note_serialization_failure(&c);
984 let stats = c.snapshot();
985 assert_eq!(stats.serialization_failures, 2);
986 assert_eq!(stats.serialization_warnings, 1, "warn once per writer");
987 }
988
989 #[test]
992 fn rotation_at_cap_preserves_order_and_parseability() {
993 let tmp = tempfile::TempDir::new().unwrap();
994 let telemetry_path = tmp.path().join("synaps/api-log.jsonl");
995 let w = TelemetryWriter::new(WriterOptions {
996 telemetry_path: Some(telemetry_path.clone()),
997 trace_path: None,
998 capacity: 64,
999 max_file_bytes: 64, max_generations: 1,
1001 write_delay: None,
1002 write_gate: None,
1003 });
1004 for ts in 0..3u64 {
1005 let mut r = sample_telemetry();
1006 r.ts = ts;
1007 w.enqueue_telemetry(r);
1008 }
1009 let stats = w.shutdown(Duration::from_secs(5)).stats();
1010 assert_eq!(stats.written, 3);
1011
1012 let rotated = tmp.path().join("synaps/api-log.jsonl.1");
1016 assert!(rotated.exists(), "size cap must rotate to .1");
1017 let ts_of = |lines: Vec<String>| -> Vec<u64> {
1018 lines
1019 .iter()
1020 .map(|l| {
1021 serde_json::from_str::<serde_json::Value>(l).unwrap()["ts"]
1022 .as_u64()
1023 .unwrap()
1024 })
1025 .collect()
1026 };
1027 assert_eq!(ts_of(read_lines(&rotated)), vec![1]);
1028 assert_eq!(ts_of(read_lines(&telemetry_path)), vec![2]);
1029 assert!(
1030 !tmp.path().join("synaps/api-log.jsonl.2").exists(),
1031 "the default keeps exactly one generation"
1032 );
1033 }
1034
1035 fn rotating_writer(telemetry_path: &std::path::Path, generations: u32) -> TelemetryWriter {
1036 TelemetryWriter::new(WriterOptions {
1037 telemetry_path: Some(telemetry_path.to_path_buf()),
1038 trace_path: None,
1039 capacity: 1024,
1040 max_file_bytes: 64, max_generations: generations,
1042 write_delay: None,
1043 write_gate: None,
1044 })
1045 }
1046
1047 fn write_n(w: &TelemetryWriter, from: u64, count: u64) {
1048 for ts in from..from + count {
1049 let mut r = sample_telemetry();
1050 r.ts = ts;
1051 w.enqueue_telemetry(r);
1052 }
1053 }
1054
1055 #[test]
1059 fn rotation_prunes_generations_beyond_n_including_after_n_is_lowered() {
1060 let tmp = tempfile::TempDir::new().unwrap();
1061 let path = tmp.path().join("synaps/api-log.jsonl");
1062 let w = rotating_writer(&path, 5);
1063 write_n(&w, 0, 7);
1064 assert!(w.shutdown(Duration::from_secs(5)).is_flushed());
1065 for k in 1..=5 {
1066 assert!(generation_path(&path, k).exists(), ".{k} kept at N=5");
1067 }
1068 std::fs::write(generation_path(&path, 42), b"{\"ts\":999}\n").unwrap();
1070
1071 let w = rotating_writer(&path, 2);
1073 write_n(&w, 100, 1);
1074 let stats = w.shutdown(Duration::from_secs(5)).stats();
1075 assert_eq!((stats.written, stats.io_failures), (1, 0));
1076 assert!(generation_path(&path, 1).exists());
1077 assert!(generation_path(&path, 2).exists());
1078 for k in [3, 4, 5, 6, 42] {
1079 assert!(!generation_path(&path, k).exists(), ".{k} pruned at N=2");
1080 }
1081 }
1082
1083 #[cfg(unix)]
1086 #[test]
1087 fn shifted_generations_are_repaired_to_0600() {
1088 use std::os::unix::fs::PermissionsExt;
1089 let tmp = tempfile::TempDir::new().unwrap();
1090 let path = tmp.path().join("synaps/api-log.jsonl");
1091 std::fs::create_dir_all(path.parent().unwrap()).unwrap();
1092 let old = generation_path(&path, 1);
1093 std::fs::write(&old, b"{\"ts\":1}\n").unwrap();
1094 std::fs::set_permissions(&old, std::fs::Permissions::from_mode(0o644)).unwrap();
1095 let w = rotating_writer(&path, 3);
1096 write_n(&w, 10, 2);
1097 assert!(w.shutdown(Duration::from_secs(5)).is_flushed());
1098 for k in 1..=2 {
1099 let mode = std::fs::metadata(generation_path(&path, k)).unwrap().permissions().mode();
1100 assert_eq!(mode & 0o777, 0o600, ".{k}");
1101 }
1102 }
1103
1104 #[test]
1110 fn concurrent_writers_on_one_log_never_double_rotate() {
1111 let tmp = tempfile::TempDir::new().unwrap();
1112 let path = tmp.path().join("synaps/api-log.jsonl");
1113 const WRITERS: u64 = 4;
1114 const EACH: u64 = 20; let writers: Vec<_> = (0..WRITERS).map(|_| rotating_writer(&path, MAX_GENERATIONS)).collect();
1116 let threads: Vec<_> = writers
1117 .iter()
1118 .enumerate()
1119 .map(|(i, w)| {
1120 let w = w.clone();
1121 std::thread::spawn(move || write_n(&w, i as u64 * 1000, EACH))
1122 })
1123 .collect();
1124 for t in threads {
1125 t.join().unwrap();
1126 }
1127 for w in &writers {
1128 assert!(w.shutdown(Duration::from_secs(10)).is_flushed());
1129 }
1130 let total_written: u64 = writers.iter().map(|w| w.stats().written).sum();
1131 assert_eq!(total_written, WRITERS * EACH);
1132
1133 let mut on_disk = read_lines(&path).len() as u64;
1134 let mut k = 1;
1135 while generation_path(&path, k).exists() {
1136 let n = read_lines(&generation_path(&path, k)).len();
1137 assert!(n > 0, ".{k} is empty: a double rotation");
1138 on_disk += n as u64;
1139 k += 1;
1140 }
1141 let highest = (1..=MAX_GENERATIONS).filter(|k| generation_path(&path, *k).exists()).max().unwrap_or(0);
1142 assert_eq!(highest, k - 1, "generations are contiguous (no gap from a double shift)");
1143 assert_eq!(on_disk, WRITERS * EACH, "no record lost to a double rotation");
1144 }
1145
1146 #[test]
1149 fn rotation_keeps_n_generations_for_both_logs() {
1150 let tmp = tempfile::TempDir::new().unwrap();
1151 let telemetry_path = tmp.path().join("synaps/api-log.jsonl");
1152 let trace_path = tmp.path().join("synaps/request-trace.jsonl");
1153 let w = TelemetryWriter::new(WriterOptions {
1154 telemetry_path: Some(telemetry_path.clone()),
1155 trace_path: Some(trace_path.clone()),
1156 capacity: 64,
1157 max_file_bytes: 64, max_generations: 3,
1159 write_delay: None,
1160 write_gate: None,
1161 });
1162 for ts in 0..6u64 {
1163 let mut r = sample_telemetry();
1164 r.ts = ts;
1165 w.enqueue_telemetry(r);
1166 w.enqueue_trace(sample_trace());
1167 }
1168 let stats = w.shutdown(Duration::from_secs(5)).stats();
1169 assert_eq!(stats.written, 12);
1170 assert_eq!(stats.io_failures, 0);
1171
1172 let ts = |path: PathBuf| -> Vec<u64> {
1173 read_lines(&path)
1174 .iter()
1175 .map(|l| {
1176 serde_json::from_str::<serde_json::Value>(l).unwrap()["ts"]
1177 .as_u64()
1178 .unwrap()
1179 })
1180 .collect()
1181 };
1182 assert_eq!(ts(telemetry_path.clone()), vec![5]);
1183 assert_eq!(ts(generation_path(&telemetry_path, 1)), vec![4]);
1184 assert_eq!(ts(generation_path(&telemetry_path, 2)), vec![3]);
1185 assert_eq!(ts(generation_path(&telemetry_path, 3)), vec![2]);
1186 assert!(!generation_path(&telemetry_path, 4).exists());
1187 for n in 1..=3 {
1188 assert_eq!(read_lines(&generation_path(&trace_path, n)).len(), 1);
1189 }
1190 assert!(!generation_path(&trace_path, 4).exists());
1191 #[cfg(unix)]
1192 {
1193 use std::os::unix::fs::PermissionsExt;
1194 for n in 1..=3 {
1195 let mode = std::fs::metadata(generation_path(&telemetry_path, n))
1196 .unwrap()
1197 .permissions()
1198 .mode();
1199 assert_eq!(mode & 0o777, 0o600, "generation {n} stays private");
1200 }
1201 }
1202 }
1203
1204 #[test]
1207 fn shutdown_is_bounded_with_slow_sink() {
1208 let tmp = tempfile::TempDir::new().unwrap();
1209 let (w, _, _) = tmp_writer(tmp.path(), 32, Some(Duration::from_millis(300)));
1210 for _ in 0..10 {
1211 w.enqueue_telemetry(sample_telemetry());
1212 }
1213 let start = Instant::now();
1214 let out = w.shutdown(Duration::from_millis(200));
1215 let elapsed = start.elapsed();
1216 assert!(!out.is_flushed(), "10×300ms cannot drain in 200ms");
1217 assert!(
1218 elapsed < Duration::from_millis(800),
1219 "shutdown must respect its deadline: {elapsed:?}"
1220 );
1221 }
1222
1223 #[test]
1224 fn shutdown_is_idempotent() {
1225 let tmp = tempfile::TempDir::new().unwrap();
1226 let (w, _, _) = tmp_writer(tmp.path(), 16, None);
1227 w.enqueue_telemetry(sample_telemetry());
1228 assert!(w.shutdown(Duration::from_secs(5)).is_flushed());
1229 assert!(w.shutdown(Duration::from_secs(5)).is_flushed());
1230 }
1231
1232 #[tokio::test]
1233 async fn shutdown_async_flushes_off_the_executor() {
1234 let tmp = tempfile::TempDir::new().unwrap();
1235 let (w, telemetry_path, _) = tmp_writer(tmp.path(), 16, None);
1236 w.enqueue_telemetry(sample_telemetry());
1237 let out = w.shutdown_async(Duration::from_secs(5)).await;
1238 assert!(out.is_flushed());
1239 assert_eq!(read_lines(&telemetry_path).len(), 1);
1240 }
1241
1242 #[test]
1249 fn enqueue_degrades_on_poisoned_mutex_instead_of_panicking() {
1250 let tmp = tempfile::TempDir::new().unwrap();
1251 let (w, telemetry_path, _) = tmp_writer(tmp.path(), 16, None);
1252
1253 let w2 = w.clone();
1255 let poisoner = std::thread::spawn(move || {
1256 let _guard = w2.shared.tx.lock().unwrap();
1257 panic!("intentional poison for the degradation test");
1258 });
1259 assert!(poisoner.join().is_err(), "poisoner must have panicked");
1260 assert!(w.shared.tx.is_poisoned(), "mutex must be poisoned");
1261
1262 w.enqueue_telemetry(sample_telemetry());
1264 assert_eq!(w.stats().enqueued, 1, "poison recovery keeps intake open");
1265 assert_eq!(w.stats().dropped, 0);
1266
1267 let out = w.shutdown(Duration::from_secs(5));
1269 assert!(out.is_flushed());
1270 assert_eq!(out.stats().written, 1);
1271 assert_eq!(read_lines(&telemetry_path).len(), 1);
1272 }
1273
1274 #[test]
1281 fn fatal_outcome_record_persisted_by_epilogue_flush() {
1282 let tmp = tempfile::TempDir::new().unwrap();
1283 let (w, _, trace_path) = tmp_writer(tmp.path(), 16, None);
1284 let mut trace = sample_trace();
1285 trace.outcome.terminal = agent_core::TurnOutcome::ProviderFailed {
1286 code: "api_error".to_string(),
1287 correlation_id: "corr-fatal-1".to_string(),
1288 };
1289 trace.outcome.http_status = Some(500);
1290 w.enqueue_trace(trace);
1291
1292 let out = w.shutdown(DEFAULT_SHUTDOWN_FLUSH_TIMEOUT);
1293 assert!(out.is_flushed());
1294 let lines = read_lines(&trace_path);
1295 assert_eq!(lines.len(), 1);
1296 let parsed: RequestTrace = serde_json::from_str(&lines[0]).unwrap();
1297 assert!(matches!(
1298 parsed.outcome.terminal,
1299 agent_core::TurnOutcome::ProviderFailed { .. }
1300 ));
1301 }
1302
1303 #[cfg(unix)]
1306 mod private_modes {
1307 use super::*;
1308 use serial_test::serial;
1309 use std::os::unix::fs::PermissionsExt;
1310
1311 struct UmaskGuard {
1312 old: libc::mode_t,
1313 }
1314 impl UmaskGuard {
1315 fn set(mask: libc::mode_t) -> Self {
1316 Self {
1317 old: unsafe { libc::umask(mask) },
1318 }
1319 }
1320 }
1321 impl Drop for UmaskGuard {
1322 fn drop(&mut self) {
1323 unsafe {
1324 libc::umask(self.old);
1325 }
1326 }
1327 }
1328
1329 fn mode_of(path: &std::path::Path) -> u32 {
1330 std::fs::metadata(path).unwrap().permissions().mode() & 0o777
1331 }
1332
1333 #[test]
1334 #[serial(umask)]
1335 fn writer_creates_0600_files_and_0700_dir_under_permissive_umask() {
1336 let _umask = UmaskGuard::set(0);
1337 let tmp = tempfile::TempDir::new().unwrap();
1338 let (w, telemetry_path, trace_path) = tmp_writer(tmp.path(), 16, None);
1339 w.enqueue_telemetry(sample_telemetry());
1340 w.enqueue_trace(sample_trace());
1341 assert!(w.shutdown(Duration::from_secs(5)).is_flushed());
1342 assert_eq!(mode_of(telemetry_path.parent().unwrap()), 0o700);
1343 assert_eq!(mode_of(&telemetry_path), 0o600);
1344 assert_eq!(mode_of(&trace_path), 0o600);
1345 }
1346
1347 #[test]
1348 fn writer_refuses_symlink_targets() {
1349 let tmp = tempfile::TempDir::new().unwrap();
1350 let dir = tmp.path().join("synaps");
1351 std::fs::create_dir_all(&dir).unwrap();
1352 let victim = tmp.path().join("victim.jsonl");
1353 std::fs::write(&victim, "").unwrap();
1354 std::os::unix::fs::symlink(&victim, dir.join("api-log.jsonl")).unwrap();
1355 std::os::unix::fs::symlink(&victim, dir.join("request-trace.jsonl")).unwrap();
1356 let (w, _, _) = tmp_writer(tmp.path(), 16, None);
1357 w.enqueue_telemetry(sample_telemetry());
1358 w.enqueue_trace(sample_trace());
1359 let stats = w.shutdown(Duration::from_secs(5)).stats();
1360 assert_eq!(
1361 std::fs::read_to_string(&victim).unwrap(),
1362 "",
1363 "no bytes may be written through a planted symlink"
1364 );
1365 assert_eq!(stats.io_failures, 2);
1366 assert_eq!(stats.written, 0);
1367 }
1368 }
1369}