Skip to main content

agent_engine/runtime/telemetry/
writer.rs

1//! Bounded, non-blocking background writer for observability persistence
2//! (Task 11, spec §6.5).
3//!
4//! One cloneable [`TelemetryWriter`] handle serves BOTH record kinds:
5//!
6//! - legacy per-request [`TelemetryRecord`]s → the existing
7//!   `~/.cache/synaps/api-log.jsonl` (format unchanged: one raw JSON object
8//!   per line, exactly what the old synchronous `write_record` produced);
9//! - metadata-only [`RequestTrace`]s (Tasks 7–10) → a private trace log at
10//!   `~/.cache/synaps/request-trace.jsonl`. Each line is the unwrapped
11//!   `synaps-request-trace/1` object, so any schema-aware reader can parse
12//!   lines directly.
13//!
14//! Design contract:
15//!
16//! - **Never blocks the request path.** Enqueue is a `try_send` on a bounded
17//!   queue; overflow increments a dropped counter (never waits). No awaits,
18//!   no hidden runtime dependency — the worker is a dedicated OS thread, so
19//!   sync contexts can enqueue too.
20//! - **Single-owner writes.** Only the worker thread touches the files, so
21//!   size-capped rotation is concurrency-safe by construction.
22//! - **Private files.** All paths use the Phase 1 `private_fs` helpers:
23//!   parent `0700`, file `0600`, `O_NOFOLLOW` (a planted symlink is refused,
24//!   never followed).
25//! - **Observable, quiet failure.** Atomic counters for
26//!   enqueued/written/dropped/serialization/I-O failures; at most one
27//!   warning per persistent failure class (queue overflow, serialization,
28//!   open/write, rotate). Warnings carry a class label only — never record
29//!   content or paths. The open/write latch re-arms after a successful
30//!   write so a *new* persistent failure warns again.
31//! - **Bounded shutdown.** [`TelemetryWriter::shutdown`] stops intake,
32//!   drains until the deadline, and returns typed stats. Dropping the last
33//!   handle simply disconnects the queue: the worker drains what is buffered
34//!   and exits detached — `Drop` can never hang.
35//!
36//! Production wiring rule (documented until Task 12 adds explicit trace
37//! config/UI): telemetry `basic`/`full` enables BOTH legacy telemetry
38//! persistence and metadata-only trace persistence through this writer;
39//! `off` disables both. The trace schema is structurally metadata-only, so
40//! this can never silently persist raw content.
41
42use super::TelemetryRecord;
43use crate::runtime::trace::{RequestTrace, TraceSink};
44use std::path::PathBuf;
45use std::sync::atomic::{AtomicBool, AtomicU64, Ordering};
46use std::sync::mpsc::{sync_channel, Receiver, SyncSender, TrySendError};
47use std::sync::{Arc, Condvar, Mutex as StdMutex};
48use std::time::{Duration, Instant};
49
50/// Default bounded queue capacity: deep enough that a briefly slow disk
51/// never drops records, small enough to bound memory (records are boxed).
52pub const DEFAULT_QUEUE_CAPACITY: usize = 1024;
53
54/// Default per-file size cap before rotation (matches the legacy writer).
55pub const DEFAULT_MAX_FILE_BYTES: u64 = 50 * 1024 * 1024;
56
57/// Default budget for the shutdown flush at process-exit epilogues
58/// (Task 11): long enough for a healthy disk to drain a full queue,
59/// short enough that a hung filesystem can never stall a clean exit.
60pub const DEFAULT_SHUTDOWN_FLUSH_TIMEOUT: Duration = Duration::from_secs(2);
61
62/// Lock a writer mutex, recovering from poison instead of panicking.
63///
64/// The request path (enqueue) and the shutdown path must never propagate a
65/// panic that happened while another thread held one of these mutexes: the
66/// protected state (an `Option<SyncSender>` / `Option<JoinHandle>` / `bool`)
67/// is always internally consistent regardless of where the poisoning panic
68/// occurred, so recovery is safe — the caller degrades to the normal
69/// enqueue/drop or drain semantics.
70fn lock_recover<T>(m: &StdMutex<T>) -> std::sync::MutexGuard<'_, T> {
71    m.lock().unwrap_or_else(std::sync::PoisonError::into_inner)
72}
73
74/// Default telemetry log path: `~/.cache/synaps/api-log.jsonl`.
75pub fn default_telemetry_log_path() -> Option<PathBuf> {
76    let home = std::env::var("HOME").ok()?;
77    Some(PathBuf::from(home).join(".cache/synaps/api-log.jsonl"))
78}
79
80/// Default trace log path: `~/.cache/synaps/request-trace.jsonl`.
81pub fn default_trace_log_path() -> Option<PathBuf> {
82    let home = std::env::var("HOME").ok()?;
83    Some(PathBuf::from(home).join(".cache/synaps/request-trace.jsonl"))
84}
85
86/// Writer configuration. `None` paths resolve to the installation defaults.
87#[derive(Debug, Clone)]
88pub struct WriterOptions {
89    pub telemetry_path: Option<PathBuf>,
90    pub trace_path: Option<PathBuf>,
91    /// Bounded queue capacity (jobs, both kinds combined).
92    pub capacity: usize,
93    /// Size cap per log file before single-generation rotation to `<path>.1`.
94    pub max_file_bytes: u64,
95    /// Test seam: artificial per-job delay inside the worker, simulating
96    /// slow storage deterministically (never set in production).
97    pub write_delay: Option<Duration>,
98}
99
100impl Default for WriterOptions {
101    fn default() -> Self {
102        Self {
103            telemetry_path: None,
104            trace_path: None,
105            capacity: DEFAULT_QUEUE_CAPACITY,
106            max_file_bytes: DEFAULT_MAX_FILE_BYTES,
107            write_delay: None,
108        }
109    }
110}
111
112/// Snapshot of the writer's atomic counters.
113#[derive(Debug, Clone, Copy, Default, PartialEq, Eq)]
114pub struct WriterStats {
115    /// Jobs accepted onto the queue.
116    pub enqueued: u64,
117    /// Records fully persisted (serialized + appended).
118    pub written: u64,
119    /// Jobs rejected: queue full or writer already shut down.
120    pub dropped: u64,
121    /// Records that failed to serialize (kept, counted, never retried).
122    pub serialization_failures: u64,
123    /// Append/open/rotate I/O failures (record lost, counted).
124    pub io_failures: u64,
125    /// Warnings actually emitted for queue overflow (warn-once latch).
126    pub overflow_warnings: u64,
127    /// Warnings actually emitted for serialization failures.
128    pub serialization_warnings: u64,
129    /// Warnings actually emitted for open/write failures.
130    pub io_warnings: u64,
131    /// Warnings actually emitted for rotation failures.
132    pub rotate_warnings: u64,
133}
134
135/// Typed result of a bounded shutdown flush.
136#[derive(Debug, Clone, Copy, PartialEq, Eq)]
137pub enum ShutdownOutcome {
138    /// Queue fully drained before the deadline.
139    Flushed(WriterStats),
140    /// Deadline hit with jobs still in flight; the worker is detached and
141    /// keeps draining in the background, but the caller stops waiting.
142    TimedOut(WriterStats),
143}
144
145impl ShutdownOutcome {
146    pub fn stats(&self) -> WriterStats {
147        match self {
148            Self::Flushed(s) | Self::TimedOut(s) => *s,
149        }
150    }
151
152    pub fn is_flushed(&self) -> bool {
153        matches!(self, Self::Flushed(_))
154    }
155}
156
157/// Cloneable handle to the bounded background writer.
158#[derive(Debug, Clone)]
159pub struct TelemetryWriter {
160    shared: Arc<Shared>,
161}
162
163/// A queued persistence job: tagged by record kind. Boxed so the queue slot
164/// stays one pointer wide regardless of record size.
165#[derive(Debug)]
166enum Job {
167    Telemetry(Box<TelemetryRecord>),
168    Trace(Box<RequestTrace>),
169}
170
171/// Atomic counters + warn-once latches. Warnings carry a class label only —
172/// never record content or filesystem paths.
173#[derive(Debug, Default)]
174struct Counters {
175    enqueued: AtomicU64,
176    written: AtomicU64,
177    dropped: AtomicU64,
178    serialization_failures: AtomicU64,
179    io_failures: AtomicU64,
180    overflow_warnings: AtomicU64,
181    serialization_warnings: AtomicU64,
182    io_warnings: AtomicU64,
183    rotate_warnings: AtomicU64,
184    /// Warn-once latches. Overflow and serialization latch once per writer;
185    /// the open/write and rotate latches re-arm after the next success so a
186    /// *new* persistent failure surfaces again.
187    overflow_warned: AtomicBool,
188    serialization_warned: AtomicBool,
189    io_warned: AtomicBool,
190    rotate_warned: AtomicBool,
191}
192
193impl Counters {
194    fn warn_once(latch: &AtomicBool, count: &AtomicU64, class: &str, msg: &str) {
195        if !latch.swap(true, Ordering::Relaxed) {
196            count.fetch_add(1, Ordering::Relaxed);
197            // Class label only — no record content, no paths.
198            tracing::warn!(class, "{msg}");
199        }
200    }
201
202    fn snapshot(&self) -> WriterStats {
203        WriterStats {
204            enqueued: self.enqueued.load(Ordering::Relaxed),
205            written: self.written.load(Ordering::Relaxed),
206            dropped: self.dropped.load(Ordering::Relaxed),
207            serialization_failures: self.serialization_failures.load(Ordering::Relaxed),
208            io_failures: self.io_failures.load(Ordering::Relaxed),
209            overflow_warnings: self.overflow_warnings.load(Ordering::Relaxed),
210            serialization_warnings: self.serialization_warnings.load(Ordering::Relaxed),
211            io_warnings: self.io_warnings.load(Ordering::Relaxed),
212            rotate_warnings: self.rotate_warnings.load(Ordering::Relaxed),
213        }
214    }
215}
216
217#[derive(Debug)]
218struct Shared {
219    /// `None` after shutdown — dropping the sender disconnects the channel,
220    /// which is the worker's drain-and-exit signal.
221    tx: StdMutex<Option<SyncSender<Job>>>,
222    latest_traces: StdMutex<std::collections::BTreeMap<String, RequestTrace>>,
223    /// Joined only on a fully-drained shutdown; otherwise the worker stays
224    /// detached (it exits on its own once the queue drains).
225    worker: StdMutex<Option<std::thread::JoinHandle<()>>>,
226    done: StdMutex<bool>,
227    done_cv: Condvar,
228    counters: Counters,
229}
230
231/// Everything the worker thread owns (single-owner writes ⇒ rotation is
232/// concurrency-safe without file locks).
233struct WorkerCfg {
234    telemetry_path: Option<PathBuf>,
235    trace_path: Option<PathBuf>,
236    max_file_bytes: u64,
237    write_delay: Option<Duration>,
238    latest_traces: Arc<Shared>,
239}
240
241impl TelemetryWriter {
242    /// Spawn the dedicated worker thread and return a cloneable handle.
243    /// `None` paths resolve to the installation defaults at spawn time.
244    pub fn new(options: WriterOptions) -> Self {
245        let (tx, rx) = sync_channel::<Job>(options.capacity.max(1));
246        let shared = Arc::new(Shared {
247            tx: StdMutex::new(Some(tx)),
248            latest_traces: StdMutex::new(std::collections::BTreeMap::new()),
249            worker: StdMutex::new(None),
250            done: StdMutex::new(false),
251            done_cv: Condvar::new(),
252            counters: Counters::default(),
253        });
254        let cfg = WorkerCfg {
255            telemetry_path: options.telemetry_path.or_else(default_telemetry_log_path),
256            trace_path: options.trace_path.or_else(default_trace_log_path),
257            max_file_bytes: options.max_file_bytes,
258            write_delay: options.write_delay,
259            latest_traces: Arc::clone(&shared),
260        };
261        let worker_shared = Arc::clone(&shared);
262        let handle = std::thread::Builder::new()
263            .name("synaps-telemetry-writer".to_string())
264            .spawn(move || worker_loop(rx, cfg, worker_shared))
265            .expect("spawning the telemetry writer thread cannot fail");
266        *lock_recover(&shared.worker) = Some(handle);
267        Self { shared }
268    }
269
270    /// Enqueue a legacy telemetry record. Non-blocking; overflow drops.
271    pub fn enqueue_telemetry(&self, record: TelemetryRecord) {
272        self.enqueue(Job::Telemetry(Box::new(record)));
273    }
274
275    /// Enqueue a metadata-only request trace. Non-blocking; overflow drops.
276    pub fn enqueue_trace(&self, record: RequestTrace) {
277        lock_recover(&self.shared.latest_traces)
278            .insert(record.request_id.as_str().to_string(), record.clone());
279        self.enqueue(Job::Trace(Box::new(record)));
280    }
281
282    pub fn enrich_trace(
283        &self,
284        request_id: &crate::runtime::trace::TraceId,
285        events: Vec<crate::runtime::trace::ToolExecutionEvent>,
286    ) {
287        if let Some(record) = lock_recover(&self.shared.latest_traces).get_mut(request_id.as_str())
288        {
289            record.execution_events = events;
290        }
291    }
292
293    pub fn trace_snapshot(
294        &self,
295        request_id: &crate::runtime::trace::TraceId,
296    ) -> Option<RequestTrace> {
297        lock_recover(&self.shared.latest_traces)
298            .get(request_id.as_str())
299            .cloned()
300    }
301
302    fn enqueue(&self, job: Job) {
303        let c = &self.shared.counters;
304        // Poison-tolerant: a panic on another thread while it held this
305        // mutex must never panic the request path — recover and degrade to
306        // normal enqueue/drop semantics (drops are counted, never silent).
307        let guard = lock_recover(&self.shared.tx);
308        let Some(tx) = guard.as_ref() else {
309            // Shut down: quiet, counted drop (records are best-effort).
310            c.dropped.fetch_add(1, Ordering::Relaxed);
311            return;
312        };
313        match tx.try_send(job) {
314            Ok(()) => {
315                c.enqueued.fetch_add(1, Ordering::Relaxed);
316            }
317            Err(TrySendError::Full(_)) => {
318                c.dropped.fetch_add(1, Ordering::Relaxed);
319                Counters::warn_once(
320                    &c.overflow_warned,
321                    &c.overflow_warnings,
322                    "queue_overflow",
323                    "telemetry writer queue full — dropping records (counted, best-effort)",
324                );
325            }
326            Err(TrySendError::Disconnected(_)) => {
327                c.dropped.fetch_add(1, Ordering::Relaxed);
328            }
329        }
330    }
331
332    /// Snapshot the counters.
333    pub fn stats(&self) -> WriterStats {
334        self.shared.counters.snapshot()
335    }
336
337    /// Stop accepting new records, drain the queue until `timeout`, and
338    /// return typed stats. On timeout the worker stays detached and keeps
339    /// draining in the background — the caller never waits past the
340    /// deadline. Safe from sync contexts; async callers should use
341    /// [`Self::shutdown_async`]. Idempotent.
342    ///
343    /// "Flushed" means every queued record was appended into the OS file
344    /// buffers (`write(2)` returned) — there is deliberately no `fsync`:
345    /// these are best-effort diagnostic logs, and surviving a kernel crash
346    /// is not part of their contract.
347    pub fn shutdown(&self, timeout: Duration) -> ShutdownOutcome {
348        // Stop intake: dropping the sender disconnects the channel; the
349        // worker drains whatever is buffered and then marks `done`.
350        drop(lock_recover(&self.shared.tx).take());
351
352        let deadline = Instant::now() + timeout;
353        let mut done = lock_recover(&self.shared.done);
354        while !*done {
355            let now = Instant::now();
356            let Some(remaining) = deadline
357                .checked_duration_since(now)
358                .filter(|d| !d.is_zero())
359            else {
360                break;
361            };
362            let (guard, _timeout) = self
363                .shared
364                .done_cv
365                .wait_timeout(done, remaining)
366                .unwrap_or_else(std::sync::PoisonError::into_inner);
367            done = guard;
368        }
369        let flushed = *done;
370        drop(done);
371
372        if flushed {
373            // Worker has drained; the join is immediate.
374            if let Some(handle) = lock_recover(&self.shared.worker).take() {
375                let _ = handle.join();
376            }
377        }
378        let stats = self.stats();
379        if flushed {
380            ShutdownOutcome::Flushed(stats)
381        } else {
382            ShutdownOutcome::TimedOut(stats)
383        }
384    }
385
386    /// Async-safe wrapper around [`Self::shutdown`] (runs on the blocking
387    /// pool so an executor thread is never parked).
388    pub async fn shutdown_async(&self, timeout: Duration) -> ShutdownOutcome {
389        let writer = self.clone();
390        tokio::task::spawn_blocking(move || writer.shutdown(timeout))
391            .await
392            .unwrap_or_else(|_| ShutdownOutcome::TimedOut(self.stats()))
393    }
394}
395
396/// Worker: drains jobs until every sender is gone, then signals `done`.
397/// This is the ONLY code that touches the log files.
398fn worker_loop(rx: Receiver<Job>, cfg: WorkerCfg, shared: Arc<Shared>) {
399    while let Ok(job) = rx.recv() {
400        if let Some(delay) = cfg.write_delay {
401            std::thread::sleep(delay);
402        }
403        process_job(job, &cfg, &shared.counters);
404    }
405    // Channel disconnected and fully drained.
406    let mut done = lock_recover(&shared.done);
407    *done = true;
408    shared.done_cv.notify_all();
409}
410
411fn process_job(job: Job, cfg: &WorkerCfg, c: &Counters) {
412    let (serialized, path) = match &job {
413        Job::Telemetry(r) => (serde_json::to_string(r), cfg.telemetry_path.as_deref()),
414        Job::Trace(r) => {
415            let latest = lock_recover(&cfg.latest_traces.latest_traces)
416                .get(r.request_id.as_str())
417                .cloned()
418                .unwrap_or_else(|| (**r).clone());
419            (serde_json::to_string(&latest), cfg.trace_path.as_deref())
420        }
421    };
422    let line = match serialized {
423        Ok(line) => line,
424        Err(_) => {
425            note_serialization_failure(c);
426            return;
427        }
428    };
429    let Some(path) = path else {
430        // No resolvable destination (e.g. HOME unset): counted I/O failure.
431        note_io_failure(c);
432        return;
433    };
434    append_private_line(path, &line, cfg.max_file_bytes, c);
435}
436
437fn note_serialization_failure(c: &Counters) {
438    c.serialization_failures.fetch_add(1, Ordering::Relaxed);
439    Counters::warn_once(
440        &c.serialization_warned,
441        &c.serialization_warnings,
442        "serialization",
443        "telemetry record failed to serialize — dropped (counted)",
444    );
445}
446
447fn note_io_failure(c: &Counters) {
448    c.io_failures.fetch_add(1, Ordering::Relaxed);
449    Counters::warn_once(
450        &c.io_warned,
451        &c.io_warnings,
452        "open_write",
453        "telemetry log unwritable — records dropped (counted); \
454         will warn again after the next successful write",
455    );
456}
457
458/// Append one line with private-fs hardening + single-generation rotation.
459/// Runs only on the worker thread — single-owner writes make the
460/// stat/rename/append sequence race-free.
461fn append_private_line(path: &std::path::Path, line: &str, max_bytes: u64, c: &Counters) {
462    if let Some(parent) = path.parent() {
463        if agent_core::core::private_fs::ensure_private_dir(parent).is_err() {
464            note_io_failure(c);
465            return;
466        }
467    }
468
469    // Size-capped rotation: at > max_bytes, rename to `<path>.1` (clobbering
470    // any old generation) before appending. One generation is enough — this
471    // is a diagnostic log, not an audit trail.
472    if let Ok(meta) = std::fs::metadata(path) {
473        if meta.len() > max_bytes {
474            let mut rotated = path.as_os_str().to_owned();
475            rotated.push(".1");
476            let rotated = PathBuf::from(rotated);
477            if std::fs::rename(path, &rotated).is_ok() {
478                // The rotated file keeps our 0600, but repair a broader mode
479                // inherited from older builds (best-effort, policy §5.4).
480                #[cfg(unix)]
481                {
482                    use std::os::unix::fs::PermissionsExt;
483                    let _ =
484                        std::fs::set_permissions(&rotated, std::fs::Permissions::from_mode(0o600));
485                }
486                c.rotate_warned.store(false, Ordering::Relaxed);
487            } else {
488                c.io_failures.fetch_add(1, Ordering::Relaxed);
489                Counters::warn_once(
490                    &c.rotate_warned,
491                    &c.rotate_warnings,
492                    "rotate",
493                    "telemetry log rotation failed — appending past the size cap",
494                );
495                // Fall through: an oversized log beats a lost record.
496            }
497        }
498    }
499
500    // Created 0600 with O_NOFOLLOW (CWE-59); pre-existing broader modes are
501    // repaired by the helper. A planted symlink is refused, never followed.
502    match agent_core::core::private_fs::open_private_append(path) {
503        Ok(mut f) => {
504            use std::io::Write;
505            if writeln!(f, "{line}").is_ok() {
506                c.written.fetch_add(1, Ordering::Relaxed);
507                // Success re-arms the open/write warn latch.
508                c.io_warned.store(false, Ordering::Relaxed);
509            } else {
510                note_io_failure(c);
511            }
512        }
513        Err(_) => note_io_failure(c),
514    }
515}
516
517/// Production [`TraceSink`]: enqueues each record onto the shared writer.
518#[derive(Debug)]
519pub struct WriterTraceSink {
520    writer: TelemetryWriter,
521}
522
523impl WriterTraceSink {
524    pub fn new(writer: TelemetryWriter) -> Self {
525        Self { writer }
526    }
527}
528
529impl TraceSink for WriterTraceSink {
530    fn emit(&self, record: RequestTrace) {
531        self.writer.enqueue_trace(record);
532    }
533
534    fn enrich_execution_events(
535        &self,
536        request_id: &crate::runtime::trace::TraceId,
537        events: Vec<crate::runtime::trace::ToolExecutionEvent>,
538    ) {
539        self.writer.enrich_trace(request_id, events);
540    }
541
542    fn snapshot_for_request(
543        &self,
544        request_id: &crate::runtime::trace::TraceId,
545    ) -> Option<RequestTrace> {
546        self.writer.trace_snapshot(request_id)
547    }
548
549    fn enabled(&self) -> bool {
550        true
551    }
552}
553
554#[cfg(test)]
555mod tests {
556    use super::*;
557    use crate::runtime::telemetry::TelemetryRecord;
558    use crate::runtime::trace::{
559        CacheMeta, EndpointMeta, RequestAnatomy, RequestTrace, TimingStages, TraceId,
560        TraceSchemaVersion, TransportKind, TransportOutcome,
561    };
562    use std::time::Instant;
563
564    const SENTINEL: &str = "RAW-CONTENT-SENTINEL-9f2c";
565
566    fn tmp_writer(
567        dir: &std::path::Path,
568        capacity: usize,
569        delay: Option<Duration>,
570    ) -> (TelemetryWriter, PathBuf, PathBuf) {
571        let telemetry = dir.join("synaps/api-log.jsonl");
572        let trace = dir.join("synaps/request-trace.jsonl");
573        let w = TelemetryWriter::new(WriterOptions {
574            telemetry_path: Some(telemetry.clone()),
575            trace_path: Some(trace.clone()),
576            capacity,
577            max_file_bytes: DEFAULT_MAX_FILE_BYTES,
578            write_delay: delay,
579        });
580        (w, telemetry, trace)
581    }
582
583    fn sample_telemetry() -> TelemetryRecord {
584        TelemetryRecord {
585            ts: 42,
586            model: "claude-sonnet-4-6".to_string(),
587            attempt: 1,
588            total_ms: 100,
589            ..Default::default()
590        }
591    }
592
593    /// Minimal schema-valid trace record. Byte lengths are *derived from* a
594    /// sentinel string but the record structurally cannot carry the string
595    /// itself — the persistence test asserts its absence on disk.
596    fn sample_trace() -> RequestTrace {
597        RequestTrace {
598            schema: TraceSchemaVersion,
599            session_id: TraceId::new("sess-w1").unwrap(),
600            turn_id: TraceId::new("turn-w1").unwrap(),
601            request_id: TraceId::new("req-w1").unwrap(),
602            execution_events: Vec::new(),
603            attempt: 1,
604            model: agent_core::prompt::QualifiedModelId::parse("anthropic/claude-sonnet-4-6")
605                .unwrap(),
606            transport: TransportKind::AnthropicMessages,
607            endpoint: EndpointMeta::new("api.anthropic.com", "/v1/messages").unwrap(),
608            anatomy: RequestAnatomy {
609                system_segment_count: 1,
610                message_count: 1,
611                block_count: SENTINEL.len() as u32 % 7,
612                tool_count: 0,
613            },
614            wire: None,
615            system_segments: vec![],
616            messages: vec![],
617            tools: vec![],
618            cache: CacheMeta::default(),
619            translation_losses: vec![],
620            outcome: TransportOutcome {
621                timings: TimingStages::default(),
622                retries: vec![],
623                provider_request_id: None,
624                http_status: Some(200),
625                stop_reason: None,
626                usage: None,
627                terminal: agent_core::TurnOutcome::Completed,
628            },
629        }
630    }
631
632    fn read_lines(path: &std::path::Path) -> Vec<String> {
633        std::fs::read_to_string(path)
634            .unwrap_or_default()
635            .lines()
636            .map(str::to_string)
637            .collect()
638    }
639
640    // ── Success path: flush writes everything, formats preserved ─────────
641
642    #[test]
643    fn flush_writes_telemetry_jsonl_in_legacy_format() {
644        let tmp = tempfile::TempDir::new().unwrap();
645        let (w, telemetry_path, _) = tmp_writer(tmp.path(), 16, None);
646        w.enqueue_telemetry(sample_telemetry());
647        let out = w.shutdown(Duration::from_secs(5));
648        assert!(out.is_flushed());
649        assert_eq!(out.stats().written, 1);
650        assert_eq!(out.stats().enqueued, 1);
651        assert_eq!(out.stats().dropped, 0);
652
653        let lines = read_lines(&telemetry_path);
654        assert_eq!(lines.len(), 1);
655        // Exact legacy format: the raw serde_json object, unwrapped.
656        let expected = serde_json::to_string(&sample_telemetry()).unwrap();
657        assert_eq!(lines[0], expected);
658        // Legacy skip-none contract intact.
659        assert!(!lines[0].contains("request_id"));
660        assert!(lines[0].contains("\"model\":\"claude-sonnet-4-6\""));
661    }
662
663    #[test]
664    fn trace_lines_are_unwrapped_schema_valid_and_content_free() {
665        let tmp = tempfile::TempDir::new().unwrap();
666        let (w, _, trace_path) = tmp_writer(tmp.path(), 16, None);
667        w.enqueue_trace(sample_trace());
668        assert!(w.shutdown(Duration::from_secs(5)).is_flushed());
669
670        let lines = read_lines(&trace_path);
671        assert_eq!(lines.len(), 1);
672        // Unwrapped: a schema-aware reader parses the line directly.
673        let parsed: RequestTrace = serde_json::from_str(&lines[0]).unwrap();
674        assert_eq!(parsed, sample_trace());
675        assert!(lines[0].contains("synaps-request-trace/1"));
676        // No raw content can appear on disk.
677        assert!(!lines[0].contains(SENTINEL));
678    }
679
680    #[test]
681    fn both_kinds_interleave_without_cross_contamination() {
682        let tmp = tempfile::TempDir::new().unwrap();
683        let (w, telemetry_path, trace_path) = tmp_writer(tmp.path(), 16, None);
684        w.enqueue_telemetry(sample_telemetry());
685        w.enqueue_trace(sample_trace());
686        w.enqueue_telemetry(sample_telemetry());
687        let out = w.shutdown(Duration::from_secs(5));
688        assert_eq!(out.stats().written, 3);
689        assert_eq!(read_lines(&telemetry_path).len(), 2);
690        assert_eq!(read_lines(&trace_path).len(), 1);
691    }
692
693    // ── Overflow: dropped counter + warn once ────────────────────────────
694
695    #[test]
696    fn overflow_increments_dropped_and_warns_once() {
697        let tmp = tempfile::TempDir::new().unwrap();
698        // Capacity 1 + slow worker: most enqueues must overflow.
699        let (w, _, _) = tmp_writer(tmp.path(), 1, Some(Duration::from_millis(200)));
700        for _ in 0..20 {
701            w.enqueue_telemetry(sample_telemetry());
702        }
703        let stats = w.stats();
704        assert!(stats.dropped > 0, "queue overflow must drop: {stats:?}");
705        assert_eq!(
706            stats.overflow_warnings, 1,
707            "exactly one overflow warning: {stats:?}"
708        );
709        assert_eq!(stats.enqueued + stats.dropped, 20);
710        w.shutdown(Duration::from_secs(5));
711    }
712
713    #[test]
714    fn enqueue_after_shutdown_counts_dropped_never_panics() {
715        let tmp = tempfile::TempDir::new().unwrap();
716        let (w, _, _) = tmp_writer(tmp.path(), 16, None);
717        assert!(w.shutdown(Duration::from_secs(5)).is_flushed());
718        w.enqueue_telemetry(sample_telemetry());
719        w.enqueue_trace(sample_trace());
720        assert_eq!(w.stats().dropped, 2);
721    }
722
723    // ── Latency: slow storage never delays the enqueue path ──────────────
724
725    #[test]
726    fn enqueue_is_fast_even_when_worker_is_slow() {
727        let tmp = tempfile::TempDir::new().unwrap();
728        let (w, _, _) = tmp_writer(tmp.path(), 1, Some(Duration::from_millis(500)));
729        let start = Instant::now();
730        for _ in 0..100 {
731            w.enqueue_telemetry(sample_telemetry());
732        }
733        assert!(
734            start.elapsed() < Duration::from_millis(250),
735            "enqueue must never block on storage: {:?}",
736            start.elapsed()
737        );
738        // Bounded even though the worker still sleeps on the queued job.
739        let out = w.shutdown(Duration::from_millis(100));
740        assert!(!out.is_flushed());
741    }
742
743    #[test]
744    fn trace_sink_emit_is_fast_with_slow_storage() {
745        let tmp = tempfile::TempDir::new().unwrap();
746        let (w, _, _) = tmp_writer(tmp.path(), 1, Some(Duration::from_millis(500)));
747        let sink = WriterTraceSink::new(w.clone());
748        assert!(sink.enabled());
749        let start = Instant::now();
750        for _ in 0..50 {
751            sink.emit(sample_trace());
752        }
753        assert!(
754            start.elapsed() < Duration::from_millis(250),
755            "sink emit must never block on storage: {:?}",
756            start.elapsed()
757        );
758        w.shutdown(Duration::from_millis(100));
759    }
760
761    // ── Broken storage: counted, warned once, request path unaffected ────
762
763    #[test]
764    fn broken_path_counts_io_failures_and_warns_once() {
765        let tmp = tempfile::TempDir::new().unwrap();
766        // Parent "dir" is a regular file → every append must fail.
767        let blocker = tmp.path().join("blocked");
768        std::fs::write(&blocker, b"not a dir").unwrap();
769        let w = TelemetryWriter::new(WriterOptions {
770            telemetry_path: Some(blocker.join("api-log.jsonl")),
771            trace_path: Some(blocker.join("request-trace.jsonl")),
772            capacity: 16,
773            max_file_bytes: DEFAULT_MAX_FILE_BYTES,
774            write_delay: None,
775        });
776        for _ in 0..3 {
777            w.enqueue_telemetry(sample_telemetry());
778        }
779        let out = w.shutdown(Duration::from_secs(5));
780        assert!(out.is_flushed(), "broken storage must not stall drain");
781        let stats = out.stats();
782        assert_eq!(stats.io_failures, 3);
783        assert_eq!(stats.io_warnings, 1, "warn once per failure class");
784        assert_eq!(stats.written, 0);
785    }
786
787    #[test]
788    fn io_warning_latch_rearms_after_success() {
789        let tmp = tempfile::TempDir::new().unwrap();
790        let good = tmp.path().join("synaps/api-log.jsonl");
791        let blocker = tmp.path().join("blocked");
792        std::fs::write(&blocker, b"not a dir").unwrap();
793        // Trace path broken, telemetry path good: fail → succeed → fail.
794        let w = TelemetryWriter::new(WriterOptions {
795            telemetry_path: Some(good.clone()),
796            trace_path: Some(blocker.join("request-trace.jsonl")),
797            capacity: 16,
798            max_file_bytes: DEFAULT_MAX_FILE_BYTES,
799            write_delay: None,
800        });
801        w.enqueue_trace(sample_trace()); // fail → warn #1
802        w.enqueue_telemetry(sample_telemetry()); // success → latch re-arms
803        w.enqueue_trace(sample_trace()); // fail → warn #2
804        let stats = w.shutdown(Duration::from_secs(5)).stats();
805        assert_eq!(stats.io_failures, 2);
806        assert_eq!(stats.io_warnings, 2);
807        assert_eq!(stats.written, 1);
808    }
809
810    #[test]
811    fn serialization_failure_counted_and_warned_once() {
812        // `TelemetryRecord`/`RequestTrace` serialization is structurally
813        // infallible (serde_json maps even non-finite floats to null), so
814        // the failure class is exercised directly on the worker's private
815        // failure path rather than via a contrived record.
816        let c = Counters::default();
817        note_serialization_failure(&c);
818        note_serialization_failure(&c);
819        let stats = c.snapshot();
820        assert_eq!(stats.serialization_failures, 2);
821        assert_eq!(stats.serialization_warnings, 1, "warn once per writer");
822    }
823
824    // ── Rotation: single worker owns writes, order preserved ─────────────
825
826    #[test]
827    fn rotation_at_cap_preserves_order_and_parseability() {
828        let tmp = tempfile::TempDir::new().unwrap();
829        let telemetry_path = tmp.path().join("synaps/api-log.jsonl");
830        let w = TelemetryWriter::new(WriterOptions {
831            telemetry_path: Some(telemetry_path.clone()),
832            trace_path: None,
833            capacity: 64,
834            max_file_bytes: 64, // one record (~90B) exceeds the cap
835            write_delay: None,
836        });
837        for ts in 0..3u64 {
838            let mut r = sample_telemetry();
839            r.ts = ts;
840            w.enqueue_telemetry(r);
841        }
842        let stats = w.shutdown(Duration::from_secs(5)).stats();
843        assert_eq!(stats.written, 3);
844
845        // One-generation rotation with a cap below one record's size keeps
846        // the last two records: `.1` holds the previous generation, the
847        // live file the newest. Every surviving line parses and order holds.
848        let rotated = tmp.path().join("synaps/api-log.jsonl.1");
849        assert!(rotated.exists(), "size cap must rotate to .1");
850        let ts_of = |lines: Vec<String>| -> Vec<u64> {
851            lines
852                .iter()
853                .map(|l| {
854                    serde_json::from_str::<serde_json::Value>(l).unwrap()["ts"]
855                        .as_u64()
856                        .unwrap()
857                })
858                .collect()
859        };
860        assert_eq!(ts_of(read_lines(&rotated)), vec![1]);
861        assert_eq!(ts_of(read_lines(&telemetry_path)), vec![2]);
862    }
863
864    // ── Bounded shutdown ─────────────────────────────────────────────────
865
866    #[test]
867    fn shutdown_is_bounded_with_slow_sink() {
868        let tmp = tempfile::TempDir::new().unwrap();
869        let (w, _, _) = tmp_writer(tmp.path(), 32, Some(Duration::from_millis(300)));
870        for _ in 0..10 {
871            w.enqueue_telemetry(sample_telemetry());
872        }
873        let start = Instant::now();
874        let out = w.shutdown(Duration::from_millis(200));
875        let elapsed = start.elapsed();
876        assert!(!out.is_flushed(), "10×300ms cannot drain in 200ms");
877        assert!(
878            elapsed < Duration::from_millis(800),
879            "shutdown must respect its deadline: {elapsed:?}"
880        );
881    }
882
883    #[test]
884    fn shutdown_is_idempotent() {
885        let tmp = tempfile::TempDir::new().unwrap();
886        let (w, _, _) = tmp_writer(tmp.path(), 16, None);
887        w.enqueue_telemetry(sample_telemetry());
888        assert!(w.shutdown(Duration::from_secs(5)).is_flushed());
889        assert!(w.shutdown(Duration::from_secs(5)).is_flushed());
890    }
891
892    #[tokio::test]
893    async fn shutdown_async_flushes_off_the_executor() {
894        let tmp = tempfile::TempDir::new().unwrap();
895        let (w, telemetry_path, _) = tmp_writer(tmp.path(), 16, None);
896        w.enqueue_telemetry(sample_telemetry());
897        let out = w.shutdown_async(Duration::from_secs(5)).await;
898        assert!(out.is_flushed());
899        assert_eq!(read_lines(&telemetry_path).len(), 1);
900    }
901
902    // ── Poisoned mutex: request path degrades, never panics ──────────────
903
904    /// A panic on another thread while it held the intake mutex must never
905    /// propagate into the request path: enqueue recovers the (always
906    /// internally consistent) state and keeps working; shutdown still
907    /// drains and the queued record is persisted.
908    #[test]
909    fn enqueue_degrades_on_poisoned_mutex_instead_of_panicking() {
910        let tmp = tempfile::TempDir::new().unwrap();
911        let (w, telemetry_path, _) = tmp_writer(tmp.path(), 16, None);
912
913        // Poison the intake mutex deliberately.
914        let w2 = w.clone();
915        let poisoner = std::thread::spawn(move || {
916            let _guard = w2.shared.tx.lock().unwrap();
917            panic!("intentional poison for the degradation test");
918        });
919        assert!(poisoner.join().is_err(), "poisoner must have panicked");
920        assert!(w.shared.tx.is_poisoned(), "mutex must be poisoned");
921
922        // Request path: no panic; the record is accepted (recovered state).
923        w.enqueue_telemetry(sample_telemetry());
924        assert_eq!(w.stats().enqueued, 1, "poison recovery keeps intake open");
925        assert_eq!(w.stats().dropped, 0);
926
927        // Shutdown path is poison-tolerant too and still drains.
928        let out = w.shutdown(Duration::from_secs(5));
929        assert!(out.is_flushed());
930        assert_eq!(out.stats().written, 1);
931        assert_eq!(read_lines(&telemetry_path).len(), 1);
932    }
933
934    // ── Fatal-outcome epilogue: failure records survive the final flush ──
935
936    /// Chat-like fatal shutdown: the last record carries a failed terminal
937    /// outcome and is enqueued just before the owner's epilogue flush (the
938    /// same call site serves the success and failure return paths). The
939    /// bounded flush must persist it.
940    #[test]
941    fn fatal_outcome_record_persisted_by_epilogue_flush() {
942        let tmp = tempfile::TempDir::new().unwrap();
943        let (w, _, trace_path) = tmp_writer(tmp.path(), 16, None);
944        let mut trace = sample_trace();
945        trace.outcome.terminal = agent_core::TurnOutcome::ProviderFailed {
946            code: "api_error".to_string(),
947            correlation_id: "corr-fatal-1".to_string(),
948        };
949        trace.outcome.http_status = Some(500);
950        w.enqueue_trace(trace);
951
952        let out = w.shutdown(DEFAULT_SHUTDOWN_FLUSH_TIMEOUT);
953        assert!(out.is_flushed());
954        let lines = read_lines(&trace_path);
955        assert_eq!(lines.len(), 1);
956        let parsed: RequestTrace = serde_json::from_str(&lines[0]).unwrap();
957        assert!(matches!(
958            parsed.outcome.terminal,
959            agent_core::TurnOutcome::ProviderFailed { .. }
960        ));
961    }
962
963    // ── Private-mode hardening (spec §5.4) ───────────────────────────────
964
965    #[cfg(unix)]
966    mod private_modes {
967        use super::*;
968        use serial_test::serial;
969        use std::os::unix::fs::PermissionsExt;
970
971        struct UmaskGuard {
972            old: libc::mode_t,
973        }
974        impl UmaskGuard {
975            fn set(mask: libc::mode_t) -> Self {
976                Self {
977                    old: unsafe { libc::umask(mask) },
978                }
979            }
980        }
981        impl Drop for UmaskGuard {
982            fn drop(&mut self) {
983                unsafe {
984                    libc::umask(self.old);
985                }
986            }
987        }
988
989        fn mode_of(path: &std::path::Path) -> u32 {
990            std::fs::metadata(path).unwrap().permissions().mode() & 0o777
991        }
992
993        #[test]
994        #[serial(umask)]
995        fn writer_creates_0600_files_and_0700_dir_under_permissive_umask() {
996            let _umask = UmaskGuard::set(0);
997            let tmp = tempfile::TempDir::new().unwrap();
998            let (w, telemetry_path, trace_path) = tmp_writer(tmp.path(), 16, None);
999            w.enqueue_telemetry(sample_telemetry());
1000            w.enqueue_trace(sample_trace());
1001            assert!(w.shutdown(Duration::from_secs(5)).is_flushed());
1002            assert_eq!(mode_of(telemetry_path.parent().unwrap()), 0o700);
1003            assert_eq!(mode_of(&telemetry_path), 0o600);
1004            assert_eq!(mode_of(&trace_path), 0o600);
1005        }
1006
1007        #[test]
1008        fn writer_refuses_symlink_targets() {
1009            let tmp = tempfile::TempDir::new().unwrap();
1010            let dir = tmp.path().join("synaps");
1011            std::fs::create_dir_all(&dir).unwrap();
1012            let victim = tmp.path().join("victim.jsonl");
1013            std::fs::write(&victim, "").unwrap();
1014            std::os::unix::fs::symlink(&victim, dir.join("api-log.jsonl")).unwrap();
1015            std::os::unix::fs::symlink(&victim, dir.join("request-trace.jsonl")).unwrap();
1016            let (w, _, _) = tmp_writer(tmp.path(), 16, None);
1017            w.enqueue_telemetry(sample_telemetry());
1018            w.enqueue_trace(sample_trace());
1019            let stats = w.shutdown(Duration::from_secs(5)).stats();
1020            assert_eq!(
1021                std::fs::read_to_string(&victim).unwrap(),
1022                "",
1023                "no bytes may be written through a planted symlink"
1024            );
1025            assert_eq!(stats.io_failures, 2);
1026            assert_eq!(stats.written, 0);
1027        }
1028    }
1029}