Skip to main content

subc_daemon/
stderr_tail.rs

1//! Bounded per-module stderr capture.
2//!
3//! # Why this exists
4//!
5//! `last_exit_code` survives a respawn because the supervisor holds it in memory.
6//! Stderr had no such path: it went to the daemon's inherited fd, and from there
7//! to whatever rotates or evicts it. On the box this was written for, that window
8//! was about three hours; on another it was bounded by a log file reaching 908 MB
9//! with one module accounting for 98% of it. Two hosts, two mechanisms, the same
10//! outcome -- the text explaining a crash is gone by the time anyone asks.
11//!
12//! So this keeps the last few lines where `last_exit` already lives: in supervisor
13//! memory, immune to whatever happens to the log.
14//!
15//! # What it is not
16//!
17//! Not a log. The ring is deliberately small and lossy, and callers are expected
18//! to know they are reading a tail rather than a history. The daemon log keeps
19//! doing its job; this exists because that job has a time limit.
20
21use std::collections::VecDeque;
22use std::io::{self, Write};
23use std::path::{Path, PathBuf};
24use std::sync::{
25    atomic::{AtomicBool, Ordering},
26    Arc, Mutex,
27};
28
29use tokio::io::AsyncReadExt;
30
31/// Longest single line admitted to the ring before truncation.
32///
33/// A module emitting a 40 MB backtrace on one line satisfies any line-count cap
34/// while evicting everything else -- the pathological emitter wins twice, once by
35/// filling the ring and once by being unreadable itself. Truncating on the way in
36/// costs that emitter one line instead of the whole tail.
37pub const DEFAULT_MAX_LINE_BYTES: usize = 2048;
38
39/// Lines retained per module.
40pub const DEFAULT_MAX_LINES: usize = 200;
41
42/// Total bytes retained per module, across all lines.
43///
44/// Both this and [`DEFAULT_MAX_LINES`] apply; whichever binds first wins. A line
45/// cap alone is satisfied by 200 lines of 2 KB, which is not a budget worth
46/// holding for fifteen modules.
47pub const DEFAULT_MAX_BYTES: usize = 64 * 1024;
48
49/// Whether a module's stderr is being captured, and if not, why not.
50///
51/// Typed rather than nullable so `NotCaptured` has to be handled rather than
52/// defaulted past. An empty tail and an uncaptured one send an operator in
53/// opposite directions -- one says the module printed nothing before dying, the
54/// other says nobody was listening -- and rendering them alike is the defect this
55/// module exists to fix, reproduced one layer up.
56#[derive(Debug, Clone, PartialEq, Eq)]
57pub enum CaptureState {
58    /// A reader is attached, or was attached and reached clean EOF.
59    Captured,
60    /// Retained entries are valid, but capture ended before clean EOF.
61    Incomplete { reason: String },
62    /// No reader was attached. The tail says nothing about what the module wrote.
63    NotCaptured { reason: String },
64}
65
66/// One retained entry.
67///
68/// Boundaries are in-band rather than a separate field because their position
69/// relative to the lines is the whole point: "these three lines came from the
70/// process that died, those came from its replacement" is unanswerable from a
71/// count.
72#[derive(Debug, Clone, PartialEq, Eq)]
73pub enum TailEntry {
74    Line {
75        text: String,
76        /// This line was cut at the per-line cap.
77        truncated: bool,
78    },
79    /// The supervisor spawned a new process for this module. Lines after this
80    /// entry come from the new one.
81    ProcessStart,
82}
83
84impl TailEntry {
85    fn cost(&self) -> usize {
86        match self {
87            Self::Line { text, .. } => text.len(),
88            Self::ProcessStart => 0,
89        }
90    }
91}
92
93#[derive(Debug, Clone, Copy, PartialEq, Eq)]
94pub struct StderrTailConfig {
95    max_lines: usize,
96    max_bytes: usize,
97    max_line_bytes: usize,
98}
99
100impl StderrTailConfig {
101    /// Keeps every retained line within the ring's total byte budget.
102    /// Clamp rather than reject so diagnostics degrade without blocking supervisor startup.
103    pub const fn new(max_lines: usize, max_bytes: usize, max_line_bytes: usize) -> Self {
104        Self {
105            max_lines,
106            max_bytes,
107            max_line_bytes: if max_line_bytes > max_bytes {
108                max_bytes
109            } else {
110                max_line_bytes
111            },
112        }
113    }
114}
115
116impl Default for StderrTailConfig {
117    fn default() -> Self {
118        Self::new(DEFAULT_MAX_LINES, DEFAULT_MAX_BYTES, DEFAULT_MAX_LINE_BYTES)
119    }
120}
121
122/// A module's retained stderr, oldest first.
123#[derive(Debug, Clone, PartialEq, Eq)]
124pub struct StderrTailSnapshot {
125    pub capture: CaptureState,
126    pub entries: Vec<TailEntry>,
127    /// Lines evicted since the module was first supervised.
128    ///
129    /// Non-zero means the tail starts mid-stream. That is the ring working as
130    /// intended, but a reader diagnosing a crash needs to know the first retained
131    /// line is not the first line the module wrote -- otherwise an absent cause
132    /// reads as a module that never explained itself.
133    pub dropped_lines: u64,
134}
135
136impl StderrTailSnapshot {
137    /// The uncaptured case, for a module whose stderr was never piped.
138    pub fn not_captured(reason: impl Into<String>) -> Self {
139        Self {
140            capture: CaptureState::NotCaptured {
141                reason: reason.into(),
142            },
143            entries: Vec::new(),
144            dropped_lines: 0,
145        }
146    }
147}
148
149/// Bounded ring of a single module's stderr lines.
150///
151/// Survives respawn deliberately. The stderr explaining an exit is written
152/// *before* that exit, so clearing on restart would discard the lines exactly
153/// when they become the thing being asked for. [`TailEntry::ProcessStart`] keeps
154/// the generations distinguishable instead.
155#[derive(Debug)]
156pub struct StderrRing {
157    config: StderrTailConfig,
158    entries: VecDeque<TailEntry>,
159    // Count of `TailEntry::Line` entries, kept running because eviction checks
160    // it on every push and recounting would walk the whole ring under the
161    // mutex each time.
162    lines: usize,
163    bytes: usize,
164    dropped_lines: u64,
165    capture: CaptureState,
166}
167
168impl StderrRing {
169    pub fn new(config: StderrTailConfig) -> Self {
170        Self {
171            config,
172            entries: VecDeque::new(),
173            lines: 0,
174            bytes: 0,
175            dropped_lines: 0,
176            // Until a reader attaches, the honest answer is that nothing is
177            // listening -- not that the module has been quiet.
178            capture: CaptureState::NotCaptured {
179                reason: "stderr reader has not started".to_string(),
180            },
181        }
182    }
183
184    pub fn mark_captured(&mut self) {
185        if matches!(self.capture, CaptureState::NotCaptured { .. }) {
186            self.capture = CaptureState::Captured;
187        }
188    }
189
190    pub fn mark_incomplete(&mut self, reason: impl Into<String>) {
191        self.capture = CaptureState::Incomplete {
192            reason: reason.into(),
193        };
194    }
195
196    pub fn mark_not_captured(&mut self, reason: impl Into<String>) {
197        self.capture = CaptureState::NotCaptured {
198            reason: reason.into(),
199        };
200    }
201
202    /// Record that a new process was spawned for this module.
203    ///
204    /// A boundary separates output on either side of it, so one with nothing
205    /// before it separates nothing: on the FIRST spawn it would make a module
206    /// that printed nothing render as a marker rather than as empty, and the
207    /// caller then has to decide whether a one-marker tail counts as silence.
208    /// Recording it only once there is something to divide keeps "captured and
209    /// empty" literally empty.
210    pub fn push_process_start(&mut self) {
211        if self.entries.is_empty() && self.dropped_lines == 0 {
212            return;
213        }
214        if matches!(self.entries.back(), Some(TailEntry::ProcessStart)) {
215            return;
216        }
217        self.push_entry(TailEntry::ProcessStart);
218    }
219
220    /// Admit one complete line, truncating it if it exceeds the per-line cap.
221    ///
222    /// `line` must not contain a trailing newline; the reader strips it so the
223    /// stored text and the byte accounting agree.
224    pub fn push_line(&mut self, line: &str) {
225        let (text, truncated) = truncate_line(line, self.config.max_line_bytes);
226        self.push_entry(TailEntry::Line { text, truncated });
227    }
228
229    fn push_entry(&mut self, entry: TailEntry) {
230        self.bytes += entry.cost();
231        if matches!(entry, TailEntry::Line { .. }) {
232            self.lines += 1;
233        }
234        self.entries.push_back(entry);
235        self.evict_to_fit();
236    }
237
238    fn evict_to_fit(&mut self) {
239        while self.lines > self.config.max_lines
240            || (self.bytes > self.config.max_bytes && self.entries.len() > 1)
241        {
242            let Some(evicted) = self.entries.pop_front() else {
243                break;
244            };
245            self.bytes -= evicted.cost();
246            if matches!(evicted, TailEntry::Line { .. }) {
247                self.lines -= 1;
248                self.dropped_lines += 1;
249            }
250        }
251    }
252
253    /// The most recent entries, oldest first, bounded by the caller's limits.
254    ///
255    /// `max_lines`/`max_bytes` narrow the ring's own caps; they cannot widen them.
256    pub fn snapshot(
257        &self,
258        max_lines: Option<usize>,
259        max_bytes: Option<usize>,
260    ) -> StderrTailSnapshot {
261        let line_limit = max_lines.unwrap_or(self.config.max_lines);
262        let byte_limit = max_bytes.unwrap_or(self.config.max_bytes);
263
264        let mut taken: Vec<TailEntry> = Vec::new();
265        let mut bytes = 0usize;
266        let mut lines = 0usize;
267        // Walk backwards: a tail is anchored at the newest end, so a caller
268        // asking for 20 lines wants the last 20, not the first 20.
269        for entry in self.entries.iter().rev() {
270            match entry {
271                TailEntry::Line { .. } => {
272                    if lines >= line_limit {
273                        break;
274                    }
275                    let cost = entry.cost();
276                    if lines > 0 && bytes + cost > byte_limit {
277                        break;
278                    }
279                    bytes += cost;
280                    lines += 1;
281                    taken.push(entry.clone());
282                }
283                TailEntry::ProcessStart if lines > 0 => taken.push(entry.clone()),
284                TailEntry::ProcessStart => {}
285            }
286        }
287        taken.reverse();
288
289        let withheld = self
290            .entries
291            .iter()
292            .filter(|entry| matches!(entry, TailEntry::Line { .. }))
293            .count()
294            .saturating_sub(
295                taken
296                    .iter()
297                    .filter(|entry| matches!(entry, TailEntry::Line { .. }))
298                    .count(),
299            );
300
301        StderrTailSnapshot {
302            capture: self.capture.clone(),
303            entries: taken,
304            // Lines the ring evicted plus lines this request's own limits held
305            // back. Both mean the same thing to the reader -- the text above is
306            // not the beginning -- and separating them would invite treating a
307            // narrow request as evidence of a quiet module.
308            dropped_lines: self.dropped_lines + withheld as u64,
309        }
310    }
311}
312
313/// Reassembly buffer ceiling for a line with no newline in sight.
314///
315/// The ring truncates what it stores, but the READER has to hold the bytes until
316/// it finds a delimiter. A module emitting a gigabyte with no newline would grow
317/// this buffer without bound and take the daemon down with it -- a module fault
318/// escalating into a fleet fault, which is exactly what supervision exists to
319/// prevent. At this ceiling the pending bytes are flushed as a line and
320/// reassembly restarts.
321const MAX_PENDING_LINE_BYTES: usize = 1024 * 1024;
322
323/// Read a child's stderr to EOF, retaining the bounded crash tail and forwarding
324/// every complete line to the selected capture sink.
325pub async fn pump_stderr<R>(source: R, ring: Arc<Mutex<StderrRing>>)
326where
327    R: AsyncReadExt + Unpin,
328{
329    pump_stderr_into(source, ring, &mut StderrSink).await
330}
331
332/// Shared destination for a child's stdout and stderr pumps.
333///
334/// The file keeps the historical `.stderr.log` name even though it carries both
335/// streams; the stable name is part of the operator contract. Both pumps share
336/// one mutex, and cortexkit-log writes each framed line in one call, so partial
337/// lines from the two pipes cannot interleave.
338#[derive(Clone)]
339pub(crate) enum ChildOutputSink {
340    File {
341        sink: Arc<Mutex<cortexkit_log::LineSink>>,
342        path: Arc<PathBuf>,
343        failure_reported: Arc<AtomicBool>,
344    },
345    Stderr,
346}
347
348impl ChildOutputSink {
349    pub(crate) fn open(path: &Path, retention: cortexkit_log::Retention) -> io::Result<Self> {
350        Ok(Self::File {
351            sink: Arc::new(Mutex::new(cortexkit_log::LineSink::open(path, retention)?)),
352            path: Arc::new(path.to_path_buf()),
353            failure_reported: Arc::new(AtomicBool::new(false)),
354        })
355    }
356}
357
358/// Where forwarded complete lines go. It exists so tests can observe framing
359/// and so production can serialize the two child pipes through one file sink.
360pub trait OutputSink {
361    fn write_line(&mut self, line: &[u8]);
362}
363
364struct StderrSink;
365
366impl OutputSink for StderrSink {
367    fn write_line(&mut self, line: &[u8]) {
368        let stderr = std::io::stderr();
369        let mut handle = stderr.lock();
370        let _ = handle.write_all(line);
371    }
372}
373
374impl OutputSink for ChildOutputSink {
375    fn write_line(&mut self, line: &[u8]) {
376        match self {
377            Self::File {
378                sink,
379                path,
380                failure_reported,
381            } => {
382                let result = sink
383                    .lock()
384                    .unwrap_or_else(|poisoned| poisoned.into_inner())
385                    .write_line(line);
386                if let Err(error) = result {
387                    if !failure_reported.swap(true, Ordering::Relaxed) {
388                        tracing::warn!(
389                            path = %path.display(),
390                            error = %error,
391                            "child output capture write failed; later failures are suppressed"
392                        );
393                    }
394                }
395            }
396            Self::Stderr => StderrSink.write_line(line),
397        }
398    }
399}
400
401pub(crate) async fn pump_stderr_to<R>(
402    source: R,
403    ring: Arc<Mutex<StderrRing>>,
404    mut sink: ChildOutputSink,
405) where
406    R: AsyncReadExt + Unpin,
407{
408    pump_stderr_into(source, ring, &mut sink).await;
409}
410
411pub(crate) async fn pump_stdout_to<R>(source: R, mut sink: ChildOutputSink)
412where
413    R: AsyncReadExt + Unpin,
414{
415    pump_lines_into(source, None, &mut sink, "stdout").await;
416}
417
418async fn pump_stderr_into<R, S>(source: R, ring: Arc<Mutex<StderrRing>>, sink: &mut S)
419where
420    R: AsyncReadExt + Unpin,
421    S: OutputSink,
422{
423    pump_lines_into(source, Some(&ring), sink, "stderr").await;
424}
425
426async fn pump_lines_into<R, S>(
427    mut source: R,
428    ring: Option<&Arc<Mutex<StderrRing>>>,
429    sink: &mut S,
430    stream_name: &str,
431) where
432    R: AsyncReadExt + Unpin,
433    S: OutputSink,
434{
435    if let Some(ring) = ring {
436        lock_ring(ring).mark_captured();
437    }
438
439    let mut pending: Vec<u8> = Vec::new();
440    // Bytes before `scanned_upto` are already known to hold no newline; searching
441    // them again would rescan the whole buffer on every chunk -- for a line with
442    // no newline that is about 64 MiB examined per MiB of module output.
443    let mut scanned_upto = 0usize;
444    // Bytes before `cursor` were emitted as complete lines. They are removed in
445    // one compaction per chunk rather than shifting the buffer once per line.
446    let mut cursor = 0usize;
447    let mut chunk = [0u8; 8192];
448    loop {
449        let read = match source.read(&mut chunk).await {
450            Ok(0) => break,
451            Ok(n) => n,
452            Err(error) => {
453                if let Some(ring) = ring {
454                    lock_ring(ring).mark_incomplete(format!("{stream_name} read failed: {error}"));
455                } else {
456                    tracing::warn!(stream = stream_name, error = %error, "child output capture read failed");
457                }
458                return;
459            }
460        };
461        pending.extend_from_slice(&chunk[..read]);
462
463        while let Some(relative) = find_newline(&pending[scanned_upto..]) {
464            let newline = scanned_upto + relative;
465            emit_line(ring, sink, &pending[cursor..newline], true);
466            cursor = newline + 1;
467            scanned_upto = cursor;
468        }
469        scanned_upto = pending.len();
470
471        if cursor > 0 {
472            pending.drain(..cursor);
473            scanned_upto -= cursor;
474            cursor = 0;
475        }
476
477        if pending.len() >= MAX_PENDING_LINE_BYTES {
478            let line = std::mem::take(&mut pending);
479            emit_line(ring, sink, &line, false);
480            scanned_upto = 0;
481        }
482    }
483
484    if !pending.is_empty() {
485        emit_line(ring, sink, &pending, false);
486    }
487}
488
489/// Bytes examined by newline searches, summed across a pump. Tests use this to
490/// assert the reader does not rescan bytes it already knows contain no newline.
491#[cfg(test)]
492static SCANNED_BYTES: std::sync::atomic::AtomicUsize = std::sync::atomic::AtomicUsize::new(0);
493
494#[cfg(test)]
495fn take_scanned_bytes() -> usize {
496    SCANNED_BYTES.swap(0, Ordering::Relaxed)
497}
498
499/// Locate the next newline in `haystack`, counting the bytes examined so a
500/// test can observe how much of the pending buffer each search walks.
501fn find_newline(haystack: &[u8]) -> Option<usize> {
502    let found = memchr::memchr(b'\n', haystack);
503    #[cfg(test)]
504    SCANNED_BYTES.fetch_add(
505        found.map(|index| index + 1).unwrap_or(haystack.len()),
506        Ordering::Relaxed,
507    );
508    found
509}
510
511fn emit_line<S: OutputSink>(
512    ring: Option<&Arc<Mutex<StderrRing>>>,
513    sink: &mut S,
514    raw: &[u8],
515    terminated: bool,
516) {
517    if let Some(ring) = ring {
518        lock_ring(ring).push_line(&String::from_utf8_lossy(raw));
519    }
520
521    // Framed and written in ONE call. Two writes would let the other pipe land
522    // between the body and newline.
523    if terminated {
524        let mut framed = Vec::with_capacity(raw.len() + 1);
525        framed.extend_from_slice(raw);
526        framed.push(b'\n');
527        sink.write_line(&framed);
528    } else {
529        sink.write_line(raw);
530    }
531}
532
533fn lock_ring(ring: &Arc<Mutex<StderrRing>>) -> std::sync::MutexGuard<'_, StderrRing> {
534    ring.lock().unwrap_or_else(|poisoned| poisoned.into_inner())
535}
536
537/// Cut `line` to at most `max_bytes`, reporting whether it was shortened.
538///
539/// Cuts on a char boundary: slicing a multi-byte sequence would produce invalid
540/// UTF-8, and a panic while capturing a crash message is the worst possible time
541/// to discover that.
542fn truncate_line(line: &str, max_bytes: usize) -> (String, bool) {
543    if line.len() <= max_bytes {
544        return (line.to_string(), false);
545    }
546    let mut end = max_bytes;
547    while end > 0 && !line.is_char_boundary(end) {
548        end -= 1;
549    }
550    (line[..end].to_string(), true)
551}
552
553#[cfg(test)]
554mod tests {
555    use std::{
556        io,
557        pin::Pin,
558        task::{Context, Poll},
559    };
560
561    use super::*;
562    use tokio::io::{AsyncRead, ReadBuf};
563
564    fn ring(max_lines: usize, max_bytes: usize, max_line_bytes: usize) -> StderrRing {
565        StderrRing::new(StderrTailConfig::new(max_lines, max_bytes, max_line_bytes))
566    }
567
568    fn lines(snapshot: &StderrTailSnapshot) -> Vec<String> {
569        snapshot
570            .entries
571            .iter()
572            .filter_map(|entry| match entry {
573                TailEntry::Line { text, .. } => Some(text.clone()),
574                TailEntry::ProcessStart => None,
575            })
576            .collect()
577    }
578
579    #[test]
580    fn a_fresh_ring_reports_not_captured_rather_than_empty() {
581        // The distinction this whole module exists for: "nobody was listening"
582        // must not render as "the module said nothing".
583        let ring = ring(10, 1024, 128);
584        let snapshot = ring.snapshot(None, None);
585        assert!(matches!(snapshot.capture, CaptureState::NotCaptured { .. }));
586        assert!(snapshot.entries.is_empty());
587    }
588
589    #[test]
590    fn a_captured_module_that_printed_nothing_is_distinguishable_from_an_uncaptured_one() {
591        let mut captured = ring(10, 1024, 128);
592        captured.mark_captured();
593        let uncaptured = ring(10, 1024, 128);
594
595        let captured = captured.snapshot(None, None);
596        let uncaptured = uncaptured.snapshot(None, None);
597
598        // Both are empty. Only the capture state separates them, which is the
599        // point -- an assertion on emptiness alone would pass either way.
600        assert!(captured.entries.is_empty());
601        assert!(uncaptured.entries.is_empty());
602        assert_eq!(captured.capture, CaptureState::Captured);
603        assert!(matches!(
604            uncaptured.capture,
605            CaptureState::NotCaptured { .. }
606        ));
607    }
608
609    #[test]
610    fn the_line_cap_evicts_oldest_first_and_counts_what_it_dropped() {
611        let mut ring = ring(3, 10_000, 128);
612        ring.mark_captured();
613        for i in 0..6 {
614            ring.push_line(&format!("line{i}"));
615        }
616        let snapshot = ring.snapshot(None, None);
617        assert_eq!(lines(&snapshot), vec!["line3", "line4", "line5"]);
618        // Without this the tail silently becomes "the last lines that happened
619        // to survive" and reads as complete.
620        assert_eq!(snapshot.dropped_lines, 3);
621    }
622
623    #[test]
624    fn the_byte_cap_binds_before_the_line_cap_when_lines_are_large() {
625        // 100 lines allowed, but only ~30 bytes of them.
626        let mut ring = ring(100, 30, 128);
627        ring.mark_captured();
628        for i in 0..10 {
629            ring.push_line(&format!("{i}--------")); // 9 bytes each
630        }
631        let snapshot = ring.snapshot(None, None);
632        assert!(
633            snapshot.entries.len() < 10,
634            "byte cap did not bind: {} entries retained",
635            snapshot.entries.len()
636        );
637        let retained: usize = lines(&snapshot).iter().map(String::len).sum();
638        assert!(
639            retained <= 30,
640            "retained {retained} bytes over a 30 byte cap"
641        );
642        assert!(snapshot.dropped_lines > 0);
643    }
644
645    #[test]
646    fn one_enormous_line_is_truncated_rather_than_evicting_the_tail() {
647        // The pathological-emitter case: without per-line truncation this single
648        // line would evict every other line AND be unreadable itself.
649        let mut ring = ring(10, 10_000, 64);
650        ring.mark_captured();
651        ring.push_line("context line that must survive");
652        ring.push_line(&"x".repeat(40_000));
653
654        let snapshot = ring.snapshot(None, None);
655        let kept = &snapshot.entries;
656        assert!(matches!(
657            &kept[0],
658            TailEntry::Line { text, truncated: false }
659                if text == "context line that must survive"
660        ));
661        let TailEntry::Line { text, truncated } = &kept[1] else {
662            panic!("expected a truncated line");
663        };
664        assert_eq!(text, &"x".repeat(64));
665        assert!(*truncated);
666    }
667
668    #[test]
669    fn truncation_is_visible_so_a_cut_line_is_not_mistaken_for_a_short_one() {
670        let mut ring = ring(10, 10_000, 16);
671        ring.mark_captured();
672        ring.push_line("0123456789abcdefghij");
673        ring.push_line("short");
674
675        let snapshot = ring.snapshot(None, None);
676        let TailEntry::Line { truncated, .. } = &snapshot.entries[0] else {
677            panic!("expected a line");
678        };
679        assert!(truncated);
680        let TailEntry::Line { truncated, .. } = &snapshot.entries[1] else {
681            panic!("expected a line");
682        };
683        assert!(!truncated, "a short line must not be reported as truncated");
684    }
685
686    #[test]
687    fn truncation_cuts_on_a_char_boundary_rather_than_splitting_utf8() {
688        // A panic message with non-ASCII in it is not exotic, and slicing mid
689        // sequence would panic while capturing a crash.
690        let mut ring = ring(10, 10_000, 5);
691        ring.mark_captured();
692        ring.push_line("aa€€€€");
693        let snapshot = ring.snapshot(None, None);
694        let TailEntry::Line { text, truncated } = &snapshot.entries[0] else {
695            panic!("expected a line");
696        };
697        assert!(truncated);
698        assert!(text.starts_with("aa"));
699    }
700
701    #[test]
702    fn a_restart_boundary_keeps_generations_distinguishable() {
703        let mut ring = ring(10, 10_000, 128);
704        ring.mark_captured();
705        ring.push_line("before the crash");
706        ring.push_process_start();
707        ring.push_line("after the respawn");
708
709        let snapshot = ring.snapshot(None, None);
710        assert_eq!(
711            snapshot.entries,
712            vec![
713                TailEntry::Line {
714                    text: "before the crash".to_string(),
715                    truncated: false
716                },
717                TailEntry::ProcessStart,
718                TailEntry::Line {
719                    text: "after the respawn".to_string(),
720                    truncated: false
721                },
722            ]
723        );
724    }
725
726    #[test]
727    fn the_ring_survives_respawn_because_the_cause_is_written_before_the_exit() {
728        // Clearing on restart would discard the lines at the exact moment they
729        // become the thing being asked for.
730        let mut ring = ring(10, 10_000, 128);
731        ring.mark_captured();
732        ring.push_line("Error: storage section missing");
733        ring.push_process_start();
734
735        let snapshot = ring.snapshot(None, None);
736        assert!(lines(&snapshot).contains(&"Error: storage section missing".to_string()));
737    }
738
739    #[test]
740    fn a_caller_limit_returns_the_newest_lines_not_the_oldest() {
741        let mut ring = ring(100, 100_000, 128);
742        ring.mark_captured();
743        for i in 0..10 {
744            ring.push_line(&format!("line{i}"));
745        }
746        let snapshot = ring.snapshot(Some(3), None);
747        assert_eq!(lines(&snapshot), vec!["line7", "line8", "line9"]);
748    }
749
750    #[test]
751    fn a_caller_line_limit_keeps_the_boundary_before_the_selected_line() {
752        let mut ring = ring(100, 100_000, 128);
753        ring.mark_captured();
754        ring.push_line("before restart");
755        ring.push_process_start();
756        ring.push_line("after restart");
757
758        let snapshot = ring.snapshot(Some(1), None);
759        assert_eq!(
760            snapshot.entries,
761            vec![
762                TailEntry::ProcessStart,
763                TailEntry::Line {
764                    text: "after restart".to_string(),
765                    truncated: false,
766                },
767            ]
768        );
769    }
770
771    #[test]
772    fn a_caller_line_limit_omits_a_trailing_boundary_after_the_selected_line() {
773        let mut ring = ring(100, 100_000, 128);
774        ring.mark_captured();
775        ring.push_line("before restart");
776        ring.push_process_start();
777
778        let snapshot = ring.snapshot(Some(1), None);
779        assert_eq!(
780            snapshot.entries,
781            vec![TailEntry::Line {
782                text: "before restart".to_string(),
783                truncated: false,
784            }]
785        );
786    }
787
788    #[test]
789    fn a_caller_limit_reports_what_it_withheld_rather_than_looking_complete() {
790        let mut ring = ring(100, 100_000, 128);
791        ring.mark_captured();
792        for i in 0..10 {
793            ring.push_line(&format!("line{i}"));
794        }
795        // Nothing was evicted; the narrowing is the caller's own. It still has to
796        // be reported, or a 3-line request reads as a module that wrote 3 lines.
797        assert_eq!(ring.snapshot(Some(3), None).dropped_lines, 7);
798        assert_eq!(ring.snapshot(None, None).dropped_lines, 0);
799    }
800
801    #[test]
802    fn a_caller_limit_cannot_widen_the_rings_own_caps() {
803        let mut ring = ring(2, 10_000, 128);
804        ring.mark_captured();
805        for i in 0..5 {
806            ring.push_line(&format!("line{i}"));
807        }
808        let snapshot = ring.snapshot(Some(1000), Some(1_000_000));
809        assert_eq!(lines(&snapshot).len(), 2);
810    }
811
812    fn shared(max_lines: usize, max_bytes: usize, max_line_bytes: usize) -> Arc<Mutex<StderrRing>> {
813        Arc::new(Mutex::new(ring(max_lines, max_bytes, max_line_bytes)))
814    }
815
816    /// Records each forwarded write separately, so a test can tell one write of
817    /// `b"abc\n"` from two writes of `b"abc"` and `b"\n"`.
818    #[derive(Default)]
819    struct RecordingSink {
820        writes: Vec<Vec<u8>>,
821    }
822
823    impl OutputSink for RecordingSink {
824        fn write_line(&mut self, line: &[u8]) {
825            self.writes.push(line.to_vec());
826        }
827    }
828
829    /// Yields predetermined chunks, one per read, so a test controls exactly
830    /// where the byte stream is split.
831    struct ChunkedReader {
832        chunks: VecDeque<Vec<u8>>,
833    }
834
835    impl AsyncRead for ChunkedReader {
836        fn poll_read(
837            mut self: Pin<&mut Self>,
838            _cx: &mut Context<'_>,
839            buf: &mut ReadBuf<'_>,
840        ) -> Poll<io::Result<()>> {
841            match self.chunks.pop_front() {
842                None => Poll::Ready(Ok(())),
843                Some(chunk) => {
844                    buf.put_slice(&chunk);
845                    Poll::Ready(Ok(()))
846                }
847            }
848        }
849    }
850
851    struct FailingReader {
852        bytes: Vec<u8>,
853        emitted: bool,
854    }
855
856    impl AsyncRead for FailingReader {
857        fn poll_read(
858            mut self: Pin<&mut Self>,
859            _cx: &mut Context<'_>,
860            buf: &mut ReadBuf<'_>,
861        ) -> Poll<io::Result<()>> {
862            if self.emitted {
863                return Poll::Ready(Err(io::Error::other("reader failed")));
864            }
865            self.emitted = true;
866            buf.put_slice(&self.bytes);
867            Poll::Ready(Ok(()))
868        }
869    }
870
871    #[tokio::test]
872    async fn the_pump_splits_on_newlines_and_keeps_a_trailing_fragment() {
873        let ring = shared(10, 10_000, 128);
874        // No trailing newline on the last line: a crashing process routinely dies
875        // mid-line, and that fragment is often the message worth reading.
876        let source = std::io::Cursor::new(b"one\ntwo\nthree".to_vec());
877        let mut sink = RecordingSink::default();
878        pump_stderr_into(source, Arc::clone(&ring), &mut sink).await;
879
880        let snapshot = lock_ring(&ring).snapshot(None, None);
881        assert_eq!(lines(&snapshot), vec!["one", "two", "three"]);
882        assert_eq!(snapshot.capture, CaptureState::Captured);
883        assert_eq!(
884            sink.writes,
885            vec![b"one\n".to_vec(), b"two\n".to_vec(), b"three".to_vec()]
886        );
887    }
888
889    #[tokio::test]
890    async fn a_read_failure_keeps_prior_lines_and_marks_the_capture_incomplete() {
891        let ring = shared(10, 10_000, 128);
892        let source = FailingReader {
893            bytes: b"crash cause\n".to_vec(),
894            emitted: false,
895        };
896        let mut sink = RecordingSink::default();
897        pump_stderr_into(source, Arc::clone(&ring), &mut sink).await;
898
899        let snapshot = lock_ring(&ring).snapshot(None, None);
900        assert_eq!(lines(&snapshot), vec!["crash cause"]);
901        assert!(matches!(
902            snapshot.capture,
903            CaptureState::Incomplete { ref reason } if reason.contains("reader failed")
904        ));
905        assert_eq!(sink.writes, vec![b"crash cause\n".to_vec()]);
906    }
907
908    #[tokio::test]
909    async fn every_captured_line_is_also_forwarded() {
910        // Forwarding is not optional. The daemon log is overwhelmingly module
911        // output; a tap that captured without forwarding would leave it nearly
912        // empty and every existing reader would report clean on nothing.
913        let ring = shared(10, 10_000, 128);
914        let source = std::io::Cursor::new(b"alpha\nbeta\n".to_vec());
915        let mut sink = RecordingSink::default();
916        pump_stderr_into(source, Arc::clone(&ring), &mut sink).await;
917
918        assert_eq!(sink.writes, vec![b"alpha\n".to_vec(), b"beta\n".to_vec()]);
919    }
920
921    #[tokio::test]
922    async fn each_forwarded_line_is_exactly_one_write() {
923        // Inheriting the fd gave line atomicity for free. Reading a pipe and
924        // re-emitting can split a line that used to be atomic, so the framing
925        // must be one syscall per complete line -- asserted as one write per
926        // line, not merely as correct bytes.
927        let ring = shared(10, 10_000, 128);
928        let source = std::io::Cursor::new(b"first\nsecond\nthird\n".to_vec());
929        let mut sink = RecordingSink::default();
930        pump_stderr_into(source, Arc::clone(&ring), &mut sink).await;
931
932        assert_eq!(sink.writes.len(), 3);
933        for write in &sink.writes {
934            assert_eq!(
935                write.iter().filter(|byte| **byte == b'\n').count(),
936                1,
937                "a write carried something other than exactly one complete line"
938            );
939            assert_eq!(*write.last().unwrap(), b'\n');
940        }
941    }
942
943    #[test]
944    fn the_first_process_start_is_not_recorded_because_it_divides_nothing() {
945        // Otherwise a module that printed nothing renders as a lone boundary
946        // marker, and every caller has to decide whether that counts as silence.
947        let mut ring = ring(10, 10_000, 128);
948        ring.push_process_start();
949        assert!(ring.snapshot(None, None).entries.is_empty());
950
951        ring.push_line("first process said this");
952        ring.push_process_start();
953        assert!(
954            matches!(ring.entries.back(), Some(TailEntry::ProcessStart)),
955            "a boundary with output before it must be recorded"
956        );
957    }
958
959    #[test]
960    fn a_process_start_is_recorded_when_only_dropped_lines_precede_it() {
961        // The ring can be non-empty in the sense that matters -- lines were
962        // written and evicted -- while `entries` is empty. Suppressing the
963        // boundary there would attribute surviving output to the wrong process.
964        let mut ring = ring(1, 10_000, 128);
965        ring.push_line("evicted");
966        ring.push_line("also evicted");
967        // Emptying `entries` by hand must also zero the running totals kept
968        // beside it, or the ring holds counts for lines it no longer has and
969        // any later eviction decision is made against the stale numbers.
970        ring.entries.clear();
971        ring.lines = 0;
972        ring.bytes = 0;
973        ring.push_process_start();
974        assert!(matches!(
975            ring.entries.front(),
976            Some(TailEntry::ProcessStart)
977        ));
978    }
979
980    #[tokio::test]
981    async fn the_pump_marks_captured_even_when_the_module_writes_nothing() {
982        // Clean EOF with no output is a module that was quiet, not one nobody
983        // listened to -- and the two must not render alike.
984        let ring = shared(10, 10_000, 128);
985        let source = std::io::Cursor::new(Vec::new());
986        let mut sink = RecordingSink::default();
987        pump_stderr_into(source, Arc::clone(&ring), &mut sink).await;
988
989        let snapshot = lock_ring(&ring).snapshot(None, None);
990        assert!(snapshot.entries.is_empty());
991        assert_eq!(snapshot.capture, CaptureState::Captured);
992        assert!(sink.writes.is_empty());
993    }
994
995    #[tokio::test]
996    async fn a_line_with_no_newline_cannot_grow_the_reader_without_bound() {
997        // A module fault must not become a daemon fault: without the pending
998        // ceiling this buffer grows to whatever the module writes.
999        let ring = shared(10, 10_000_000, 4 * 1024 * 1024);
1000        let source = std::io::Cursor::new(vec![b'x'; MAX_PENDING_LINE_BYTES + 4096]);
1001        let mut sink = RecordingSink::default();
1002        pump_stderr_into(source, Arc::clone(&ring), &mut sink).await;
1003
1004        let snapshot = lock_ring(&ring).snapshot(None, None);
1005        assert_eq!(
1006            lines(&snapshot).len(),
1007            2,
1008            "expected a forced flush at the ceiling plus the remainder"
1009        );
1010        assert_eq!(
1011            sink.writes,
1012            vec![vec![b'x'; MAX_PENDING_LINE_BYTES], vec![b'x'; 4096],],
1013            "forced flushes and EOF fragments must not invent delimiters"
1014        );
1015    }
1016
1017    #[tokio::test]
1018    async fn boundaries_truncation_and_framing_do_not_depend_on_chunk_splits() {
1019        // The same stream split at hostile boundaries -- mid-line, between a CR
1020        // and its LF, and a line sitting exactly on the per-line cap -- must
1021        // produce the same ring entries and forwarded bytes as any other split.
1022        let ring = shared(100, 100_000, 8);
1023        let source = ChunkedReader {
1024            chunks: vec![
1025                b"fir".to_vec(),
1026                b"st\nsec".to_vec(),
1027                b"ond\ncarry\r".to_vec(),
1028                b"\nover\n".to_vec(),
1029                b"12345678\n".to_vec(),
1030                b"1234567".to_vec(),
1031                b"89\n".to_vec(),
1032                b"tail".to_vec(),
1033            ]
1034            .into_iter()
1035            .collect(),
1036        };
1037        let mut sink = RecordingSink::default();
1038        pump_stderr_into(source, Arc::clone(&ring), &mut sink).await;
1039
1040        let snapshot = lock_ring(&ring).snapshot(None, None);
1041        assert_eq!(snapshot.capture, CaptureState::Captured);
1042        assert_eq!(
1043            snapshot.entries,
1044            vec![
1045                TailEntry::Line {
1046                    text: "first".to_string(),
1047                    truncated: false
1048                },
1049                TailEntry::Line {
1050                    text: "second".to_string(),
1051                    truncated: false
1052                },
1053                // The pump delimits on '\n' alone; a CR belongs to the line body.
1054                TailEntry::Line {
1055                    text: "carry\r".to_string(),
1056                    truncated: false
1057                },
1058                TailEntry::Line {
1059                    text: "over".to_string(),
1060                    truncated: false
1061                },
1062                // Exactly at the per-line cap: kept whole.
1063                TailEntry::Line {
1064                    text: "12345678".to_string(),
1065                    truncated: false
1066                },
1067                // One byte past the cap: cut, and marked as cut.
1068                TailEntry::Line {
1069                    text: "12345678".to_string(),
1070                    truncated: true
1071                },
1072                TailEntry::Line {
1073                    text: "tail".to_string(),
1074                    truncated: false
1075                },
1076            ]
1077        );
1078        assert_eq!(
1079            sink.writes,
1080            vec![
1081                b"first\n".to_vec(),
1082                b"second\n".to_vec(),
1083                b"carry\r\n".to_vec(),
1084                b"over\n".to_vec(),
1085                b"12345678\n".to_vec(),
1086                b"123456789\n".to_vec(),
1087                b"tail".to_vec(),
1088            ]
1089        );
1090    }
1091
1092    #[tokio::test]
1093    async fn a_line_with_no_newline_is_not_rescanned_from_byte_zero_on_every_chunk() {
1094        // One 1 MiB line arrives in 8192-byte reads. Searching the whole
1095        // pending buffer for a newline on every chunk scans each byte once per
1096        // chunk that arrived after it -- about 64 MiB examined per MiB of
1097        // output. Searching only the bytes that arrived since the last search
1098        // scans each byte once.
1099        let input = vec![b'x'; MAX_PENDING_LINE_BYTES + 4096];
1100        let ring = shared(10, 10_000_000, 4 * 1024 * 1024);
1101        let source = std::io::Cursor::new(input.clone());
1102        let mut sink = RecordingSink::default();
1103
1104        take_scanned_bytes();
1105        pump_stderr_into(source, Arc::clone(&ring), &mut sink).await;
1106        let scanned = take_scanned_bytes();
1107
1108        assert!(
1109            scanned <= 2 * input.len(),
1110            "newline searches examined {scanned} bytes for {} bytes of input; \
1111             each chunk must search only newly arrived bytes",
1112            input.len()
1113        );
1114    }
1115
1116    #[test]
1117    fn a_byte_limit_smaller_than_one_line_still_returns_that_line() {
1118        // Returning nothing would be indistinguishable from a quiet module, which
1119        // is the failure this module exists to prevent.
1120        let mut ring = ring(10, 10_000, 128);
1121        ring.mark_captured();
1122        ring.push_line("a line considerably longer than the request limit");
1123        let snapshot = ring.snapshot(None, Some(4));
1124        assert_eq!(snapshot.entries.len(), 1);
1125    }
1126
1127    #[test]
1128    fn an_incoherent_config_clamps_the_line_cap_and_keeps_its_restart_boundary() {
1129        let config = StderrTailConfig::new(2, 10, 100);
1130        assert_eq!(config.max_line_bytes, config.max_bytes);
1131        let mut ring = StderrRing::new(config);
1132        ring.mark_captured();
1133        ring.push_line("old");
1134        ring.push_process_start();
1135        ring.push_line("new process line longer than the ring byte cap");
1136
1137        assert_eq!(
1138            ring.snapshot(None, None).entries,
1139            vec![
1140                TailEntry::ProcessStart,
1141                TailEntry::Line {
1142                    text: "new proces".to_string(),
1143                    truncated: true,
1144                },
1145            ]
1146        );
1147    }
1148}