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