Skip to main content

sloop/
run_log.rs

1//! Per-run NDJSON output capture. Agent and stage stdout/stderr are
2//! untrusted evidence: they are stored as ordered chunks, never parsed as
3//! lines and never routed through the dispatcher.
4
5use std::collections::VecDeque;
6use std::fs::{self, File, OpenOptions};
7use std::io::{self, BufRead, BufReader, Read, Seek, SeekFrom, Write};
8use std::path::Path;
9use std::sync::{Arc, Mutex};
10
11use base64::Engine;
12use base64::engine::general_purpose::STANDARD as BASE64;
13use serde::{Deserialize, Serialize};
14use time::OffsetDateTime;
15use time::format_description::well_known::Rfc3339;
16
17use crate::clock::format_timestamp;
18
19/// One socket page of records, and the window a bare `sloop logs` tails.
20pub const PAGE_LIMIT: usize = 64;
21
22/// An explicit `tail` may ask for more than one default page — that is the
23/// point of asking — but not for an unbounded slice of an untrusted log.
24pub const TAIL_LIMIT: usize = 1000;
25
26#[derive(Debug, Clone, Copy, PartialEq, Eq, Serialize, Deserialize)]
27#[serde(rename_all = "snake_case")]
28pub enum OutputSource {
29    /// A supervised agent process.
30    Agent,
31    /// A stage process the daemon ran itself.
32    Stage,
33}
34
35#[derive(Debug, Clone, Copy, PartialEq, Eq, Serialize, Deserialize)]
36#[serde(rename_all = "snake_case")]
37pub enum OutputStream {
38    Stdout,
39    Stderr,
40}
41
42/// One captured chunk. UTF-8 chunks stay readable; anything else round-trips
43/// through base64 rather than being lossily converted.
44#[derive(Debug, Clone, PartialEq, Eq, Serialize, Deserialize)]
45#[serde(tag = "encoding", rename_all = "snake_case")]
46pub enum OutputChunk {
47    Utf8 { text: String },
48    Base64 { data: String },
49}
50
51impl OutputChunk {
52    pub fn from_bytes(bytes: &[u8]) -> Self {
53        match std::str::from_utf8(bytes) {
54            Ok(text) => Self::Utf8 { text: text.into() },
55            Err(_) => Self::Base64 {
56                data: BASE64.encode(bytes),
57            },
58        }
59    }
60
61    pub fn into_bytes(self) -> Vec<u8> {
62        match self {
63            Self::Utf8 { text } => text.into_bytes(),
64            Self::Base64 { data } => BASE64.decode(data).unwrap_or_default(),
65        }
66    }
67}
68
69#[derive(Debug, Clone, PartialEq, Eq, Serialize, Deserialize)]
70pub struct OutputRecord {
71    pub sequence: u64,
72    pub timestamp: String,
73    pub source: OutputSource,
74    #[serde(default, skip_serializing_if = "Option::is_none")]
75    pub stage: Option<String>,
76    /// Which execution of `stage` produced the chunk. A backward edge re-runs
77    /// a stage, so the stage name alone no longer identifies whose output this
78    /// is. Absent on records captured before re-runs existed.
79    #[serde(default, skip_serializing_if = "Option::is_none")]
80    pub attempt: Option<u32>,
81    pub stream: OutputStream,
82    #[serde(flatten)]
83    pub chunk: OutputChunk,
84}
85
86/// Append-only writer shared by the stdout and stderr reader threads of one
87/// run. Sequence numbers are capture order across both pipes.
88#[derive(Clone)]
89pub struct RunLogWriter {
90    inner: Arc<Mutex<Inner>>,
91}
92
93struct Inner {
94    file: File,
95    next_sequence: u64,
96}
97
98impl RunLogWriter {
99    /// Opens (creating directories as needed) the run's output log and
100    /// resumes sequence numbering after any records already present, so a
101    /// restarted daemon appends instead of renumbering.
102    pub fn open(path: &Path) -> io::Result<Self> {
103        if let Some(parent) = path.parent() {
104            fs::create_dir_all(parent)?;
105        }
106        let next_sequence = last_sequence(path)?.map_or(1, |last| last + 1);
107        let mut file = OpenOptions::new().create(true).append(true).open(path)?;
108        if !ends_with_newline(path)? {
109            file.write_all(b"\n")?;
110        }
111        Ok(Self {
112            inner: Arc::new(Mutex::new(Inner {
113                file,
114                next_sequence,
115            })),
116        })
117    }
118
119    /// Appends one chunk and durably flushes it. Capture must be on disk
120    /// before exit evidence claims it is complete.
121    pub fn append(
122        &self,
123        source: OutputSource,
124        stage: Option<&str>,
125        attempt: Option<u32>,
126        stream: OutputStream,
127        bytes: &[u8],
128    ) -> io::Result<u64> {
129        let timestamp_ms = OffsetDateTime::now_utc().unix_timestamp_nanos() / 1_000_000;
130        self.append_at(
131            i64::try_from(timestamp_ms).unwrap_or(0),
132            source,
133            stage,
134            attempt,
135            stream,
136            bytes,
137        )
138    }
139
140    /// Appends a chunk with a caller-supplied clock instant. Agent output uses
141    /// the daemon clock so scheduler deadlines and persisted output agree in
142    /// tests as well as production.
143    #[allow(clippy::too_many_arguments)]
144    pub fn append_at(
145        &self,
146        timestamp_ms: i64,
147        source: OutputSource,
148        stage: Option<&str>,
149        attempt: Option<u32>,
150        stream: OutputStream,
151        bytes: &[u8],
152    ) -> io::Result<u64> {
153        let timestamp =
154            format_timestamp(timestamp_ms).unwrap_or_else(|| "1970-01-01T00:00:00Z".into());
155        let mut inner = self
156            .inner
157            .lock()
158            .map_err(|_| io::Error::other("run log lock poisoned"))?;
159        let record = OutputRecord {
160            sequence: inner.next_sequence,
161            timestamp,
162            source,
163            stage: stage.map(str::to_owned),
164            attempt,
165            stream,
166            chunk: OutputChunk::from_bytes(bytes),
167        };
168        let mut line = serde_json::to_vec(&record).map_err(io::Error::other)?;
169        line.push(b'\n');
170        let original_len = inner.file.metadata()?.len();
171        if let Err(error) = inner
172            .file
173            .write_all(&line)
174            .and_then(|()| inner.file.sync_data())
175        {
176            let _ = inner.file.set_len(original_len);
177            return Err(error);
178        }
179        inner.next_sequence += 1;
180        Ok(record.sequence)
181    }
182}
183
184/// The reusable output-silence signal for one running agent stage. The file is
185/// authoritative: reopening after daemon restart reconstructs both the last
186/// append instant and the silence episode from its final complete agent record.
187#[derive(Debug, Clone, Copy, PartialEq, Eq)]
188pub struct OutputStaleness {
189    pub last_sequence: Option<u64>,
190    pub last_output_at_ms: i64,
191    pub silent_for_ms: i64,
192    pub deadline_ms: i64,
193    pub stalled: bool,
194}
195
196/// Measures agent-output silence from the last complete record, falling back
197/// to the durable stage start when the agent has not written anything yet.
198pub fn output_staleness(
199    path: &Path,
200    started_at_ms: i64,
201    now_ms: i64,
202    report_after_ms: i64,
203) -> io::Result<OutputStaleness> {
204    let last = last_agent_output(path)?;
205    let (last_sequence, last_output_at_ms) = last
206        .map(|(sequence, at_ms)| (Some(sequence), at_ms))
207        .unwrap_or((None, started_at_ms));
208    let silent_for_ms = now_ms.saturating_sub(last_output_at_ms).max(0);
209    let deadline_ms = last_output_at_ms.saturating_add(report_after_ms);
210    Ok(OutputStaleness {
211        last_sequence,
212        last_output_at_ms,
213        silent_for_ms,
214        deadline_ms,
215        stalled: now_ms >= deadline_ms,
216    })
217}
218
219/// Reads backward so frequent scheduler recomputations cost at most the final
220/// record in the common case rather than repeatedly scanning a large run log.
221fn last_agent_output(path: &Path) -> io::Result<Option<(u64, i64)>> {
222    const BLOCK: usize = 8 * 1024;
223    let mut file = match File::open(path) {
224        Ok(file) => file,
225        Err(error) if error.kind() == io::ErrorKind::NotFound => return Ok(None),
226        Err(error) => return Err(error),
227    };
228    let mut position = file.metadata()?.len();
229    let mut suffix = Vec::new();
230    while position > 0 {
231        let start = position.saturating_sub(BLOCK as u64);
232        let mut block = vec![0; usize::try_from(position - start).unwrap_or(BLOCK)];
233        file.seek(SeekFrom::Start(start))?;
234        file.read_exact(&mut block)?;
235        block.extend_from_slice(&suffix);
236
237        let mut end = block.len();
238        while let Some(newline) = block[..end].iter().rposition(|byte| *byte == b'\n') {
239            if let Some(last) = agent_output_record(&block[newline + 1..end]) {
240                return Ok(Some(last));
241            }
242            end = newline;
243        }
244        suffix = block[..end].to_vec();
245        position = start;
246    }
247    Ok(agent_output_record(&suffix))
248}
249
250fn agent_output_record(line: &[u8]) -> Option<(u64, i64)> {
251    if line.is_empty() {
252        return None;
253    }
254    let record = serde_json::from_slice::<OutputRecord>(line).ok()?;
255    (record.source == OutputSource::Agent)
256        .then(|| parse_timestamp_ms(&record.timestamp).map(|at_ms| (record.sequence, at_ms)))?
257}
258
259fn parse_timestamp_ms(timestamp: &str) -> Option<i64> {
260    let nanos = OffsetDateTime::parse(timestamp, &Rfc3339)
261        .ok()?
262        .unix_timestamp_nanos();
263    i64::try_from(nanos / 1_000_000).ok()
264}
265
266/// True when the file is empty or its last byte is a newline, meaning the
267/// next append starts a fresh record.
268fn ends_with_newline(path: &Path) -> io::Result<bool> {
269    let mut file = match File::open(path) {
270        Ok(file) => file,
271        Err(error) if error.kind() == io::ErrorKind::NotFound => return Ok(true),
272        Err(error) => return Err(error),
273    };
274    if file.metadata()?.len() == 0 {
275        return Ok(true);
276    }
277    file.seek(SeekFrom::End(-1))?;
278    let mut last = [0u8; 1];
279    file.read_exact(&mut last)?;
280    Ok(last[0] == b'\n')
281}
282
283/// The sequence of the last complete record, ignoring a truncated tail left
284/// by a crash; earlier records stay valid evidence.
285fn last_sequence(path: &Path) -> io::Result<Option<u64>> {
286    let file = match File::open(path) {
287        Ok(file) => file,
288        Err(error) if error.kind() == io::ErrorKind::NotFound => return Ok(None),
289        Err(error) => return Err(error),
290    };
291    let mut last = None;
292    for line in BufReader::new(file).lines() {
293        if let Ok(record) = serde_json::from_str::<OutputRecord>(&line?) {
294            last = Some(record.sequence);
295        }
296    }
297    Ok(last)
298}
299
300#[derive(Debug, Clone, PartialEq, Eq)]
301pub struct OutputPage {
302    pub entries: Vec<OutputRecord>,
303    /// Sequence of the last returned entry; the cursor a future paginated
304    /// call would resume after.
305    pub next_cursor: u64,
306    /// True when the page reached the end of the captured records.
307    pub complete: bool,
308    /// Matching records a trailing window dropped off the front. `complete`
309    /// cannot carry this: a tail reads to the end, so it is always complete
310    /// however much older output it discarded.
311    pub elided: usize,
312}
313
314#[derive(Debug, Clone, Default, PartialEq, Eq)]
315pub struct AgentOutput {
316    pub stdout: Vec<u8>,
317    pub stderr: Vec<u8>,
318}
319
320/// Reassembles each agent stream from every complete captured record. Test
321/// and merge output is deliberately excluded from vendor classification.
322pub fn read_agent_output(path: &Path) -> io::Result<AgentOutput> {
323    let mut output = AgentOutput::default();
324    visit_agent_output(path, |stream, bytes| {
325        let destination = match stream {
326            OutputStream::Stdout => &mut output.stdout,
327            OutputStream::Stderr => &mut output.stderr,
328        };
329        destination.extend_from_slice(bytes);
330    })?;
331    Ok(output)
332}
333
334/// Visits decoded agent chunks in capture order without retaining the whole
335/// log. A malformed or crash-truncated record does not hide earlier evidence.
336pub fn visit_agent_output(
337    path: &Path,
338    mut visitor: impl FnMut(OutputStream, &[u8]),
339) -> io::Result<()> {
340    let file = match File::open(path) {
341        Ok(file) => file,
342        Err(error) if error.kind() == io::ErrorKind::NotFound => {
343            return Ok(());
344        }
345        Err(error) => return Err(error),
346    };
347    for line in BufReader::new(file).lines() {
348        if let Ok(record) = serde_json::from_str::<OutputRecord>(&line?)
349            && record.source == OutputSource::Agent
350        {
351            let bytes = record.chunk.into_bytes();
352            visitor(record.stream, &bytes);
353        }
354    }
355    Ok(())
356}
357
358/// The trailing `lines` lines one stage execution captured, decoded as text.
359///
360/// This is the only read that narrows to a single *execution* rather than a
361/// stage: it feeds the "previous attempt failed" block a re-entered agent
362/// stage is prompted with, and quoting a different attempt's output there
363/// would send the agent after the wrong failure. Records written before
364/// attempts were tagged carry none and are claimed by the first attempt, which
365/// is the only one such a run ever had.
366pub fn stage_output_tail(
367    path: &Path,
368    stage: &str,
369    attempt: u32,
370    lines: usize,
371) -> io::Result<String> {
372    let file = match File::open(path) {
373        Ok(file) => file,
374        Err(error) if error.kind() == io::ErrorKind::NotFound => return Ok(String::new()),
375        Err(error) => return Err(error),
376    };
377    let mut captured = Vec::new();
378    for line in BufReader::new(file).lines() {
379        let Ok(record) = serde_json::from_str::<OutputRecord>(&line?) else {
380            continue;
381        };
382        if record.stage.as_deref() != Some(stage) {
383            continue;
384        }
385        if record.attempt.unwrap_or(1) != attempt {
386            continue;
387        }
388        captured.extend_from_slice(&record.chunk.into_bytes());
389    }
390    let text = String::from_utf8_lossy(&captured);
391    let text = text.strip_suffix('\n').unwrap_or(&text);
392    if text.is_empty() {
393        return Ok(String::new());
394    }
395    let total = text.lines().count();
396    Ok(text
397        .lines()
398        .skip(total.saturating_sub(lines))
399        .collect::<Vec<_>>()
400        .join("\n"))
401}
402
403/// Selects the records belonging to one flow stage. Stage records carry
404/// their stage name; agent records captured before stages were tagged carry
405/// none, so `agent_fallback` lets the flow's agent stage claim them.
406#[derive(Debug, Clone, PartialEq, Eq)]
407pub struct StageFilter {
408    pub stage: String,
409    /// One execution of the stage, or every execution when absent. A backward
410    /// edge re-enters a stage, and past that point the name alone selects two
411    /// different runs of the same command interleaved in one page — which is
412    /// exactly the page nobody wants to read.
413    pub attempt: Option<u32>,
414    pub agent_fallback: bool,
415}
416
417impl StageFilter {
418    fn accepts(&self, record: &OutputRecord) -> bool {
419        if self
420            .attempt
421            .is_some_and(|attempt| record.attempt.unwrap_or(1) != attempt)
422        {
423            return false;
424        }
425        match record.stage.as_deref() {
426            Some(stage) => stage == self.stage,
427            None => self.agent_fallback && record.source == OutputSource::Agent,
428        }
429    }
430}
431
432/// One read of the captured log: everything after a cursor, optionally
433/// narrowed to a stage and trimmed to a trailing window.
434#[derive(Debug, Clone, Default, PartialEq, Eq)]
435pub struct PageQuery {
436    /// Only records with `sequence > after`.
437    pub after: u64,
438    /// Hard cap on returned entries; also the cap on `tail`.
439    pub limit: usize,
440    /// Only records this filter accepts.
441    pub stage: Option<StageFilter>,
442    /// Keep the last N accepted records instead of the first N. Reading runs
443    /// to the end of the file, so the page is always complete.
444    pub tail: Option<usize>,
445}
446
447/// Reads a finite page of records with `sequence > after`, in order. A
448/// missing file is an empty page: the run may exist before any output does.
449pub fn read_page(path: &Path, after: u64, limit: usize) -> io::Result<OutputPage> {
450    read_filtered_page(
451        path,
452        &PageQuery {
453            after,
454            limit,
455            ..PageQuery::default()
456        },
457    )
458}
459
460/// Reads one page under a filter. `next_cursor` advances past every record
461/// the read *consumed*, not just the ones it returned: a filtered-out record
462/// is still evidence that has been examined, so a follower resuming from the
463/// cursor neither replays it nor stalls behind it.
464pub fn read_filtered_page(path: &Path, query: &PageQuery) -> io::Result<OutputPage> {
465    let file = match File::open(path) {
466        Ok(file) => file,
467        Err(error) if error.kind() == io::ErrorKind::NotFound => {
468            return Ok(OutputPage {
469                entries: Vec::new(),
470                next_cursor: query.after,
471                complete: true,
472                elided: 0,
473            });
474        }
475        Err(error) => return Err(error),
476    };
477
478    let window = query.tail.map_or(query.limit, |tail| tail.min(query.limit));
479    let mut entries = VecDeque::new();
480    let mut next_cursor = query.after;
481    let mut complete = true;
482    let mut elided = 0;
483    for line in BufReader::new(file).lines() {
484        let Ok(record) = serde_json::from_str::<OutputRecord>(&line?) else {
485            continue;
486        };
487        if record.sequence <= query.after {
488            continue;
489        }
490        if query.tail.is_none() && entries.len() == query.limit {
491            complete = false;
492            break;
493        }
494        next_cursor = record.sequence;
495        if query.stage.as_ref().is_some_and(|f| !f.accepts(&record)) {
496            continue;
497        }
498        entries.push_back(record);
499        if entries.len() > window {
500            entries.pop_front();
501            elided += 1;
502        }
503    }
504    Ok(OutputPage {
505        entries: entries.into(),
506        next_cursor,
507        complete,
508        elided,
509    })
510}
511
512#[cfg(test)]
513mod tests {
514    use serde_json::{Value, json};
515    use tempfile::tempdir;
516
517    use super::{
518        OutputChunk, OutputSource, OutputStream, PageQuery, RunLogWriter, StageFilter,
519        output_staleness, read_agent_output, read_filtered_page, read_page,
520    };
521
522    /// Writes one record per call, so a test controls entry boundaries the
523    /// way pipe reads do at runtime.
524    fn write_records(path: &std::path::Path, records: &[(OutputSource, Option<&str>, &str)]) {
525        let writer = RunLogWriter::open(path).unwrap();
526        for (source, stage, text) in records {
527            writer
528                .append(
529                    *source,
530                    *stage,
531                    Some(1),
532                    OutputStream::Stdout,
533                    text.as_bytes(),
534                )
535                .unwrap();
536        }
537    }
538
539    fn texts(page: &super::OutputPage) -> Vec<String> {
540        page.entries
541            .iter()
542            .map(|record| String::from_utf8(record.chunk.clone().into_bytes()).unwrap())
543            .collect()
544    }
545
546    #[test]
547    fn a_stage_filter_selects_that_stage_and_leaves_the_cursor_past_what_it_skipped() {
548        let directory = tempdir().unwrap();
549        let path = directory.path().join("output.ndjson");
550        write_records(
551            &path,
552            &[
553                (OutputSource::Agent, Some("build"), "built"),
554                (OutputSource::Stage, Some("test"), "tested"),
555                (OutputSource::Stage, Some("merge"), "merged"),
556            ],
557        );
558
559        let page = read_filtered_page(
560            &path,
561            &PageQuery {
562                limit: 10,
563                stage: Some(StageFilter {
564                    stage: "test".into(),
565                    attempt: None,
566                    agent_fallback: false,
567                }),
568                ..PageQuery::default()
569            },
570        )
571        .unwrap();
572
573        assert_eq!(texts(&page), ["tested"]);
574        assert_eq!(page.next_cursor, 3);
575        assert!(page.complete);
576    }
577
578    #[test]
579    fn the_agent_fallback_claims_records_captured_before_stages_were_tagged() {
580        let directory = tempdir().unwrap();
581        let path = directory.path().join("output.ndjson");
582        write_records(
583            &path,
584            &[
585                (OutputSource::Agent, None, "legacy agent"),
586                (OutputSource::Stage, None, "legacy untagged"),
587                (OutputSource::Agent, Some("build"), "tagged agent"),
588            ],
589        );
590        let filter = |agent_fallback| PageQuery {
591            limit: 10,
592            stage: Some(StageFilter {
593                stage: "build".into(),
594                attempt: None,
595                agent_fallback,
596            }),
597            ..PageQuery::default()
598        };
599
600        let claimed = read_filtered_page(&path, &filter(true)).unwrap();
601        assert_eq!(texts(&claimed), ["legacy agent", "tagged agent"]);
602
603        let literal = read_filtered_page(&path, &filter(false)).unwrap();
604        assert_eq!(texts(&literal), ["tagged agent"]);
605    }
606
607    #[test]
608    fn a_tail_keeps_the_newest_matching_records_and_still_reaches_the_end() {
609        let directory = tempdir().unwrap();
610        let path = directory.path().join("output.ndjson");
611        let mut records = Vec::new();
612        for index in 0..6 {
613            records.push((OutputSource::Stage, Some("test"), format!("t{index}")));
614            records.push((OutputSource::Agent, Some("build"), format!("b{index}")));
615        }
616        write_records(
617            &path,
618            &records
619                .iter()
620                .map(|(source, stage, text)| (*source, *stage, text.as_str()))
621                .collect::<Vec<_>>(),
622        );
623
624        let page = read_filtered_page(
625            &path,
626            &PageQuery {
627                limit: 64,
628                stage: Some(StageFilter {
629                    stage: "test".into(),
630                    attempt: None,
631                    agent_fallback: false,
632                }),
633                tail: Some(2),
634                ..PageQuery::default()
635            },
636        )
637        .unwrap();
638
639        assert_eq!(texts(&page), ["t4", "t5"]);
640        assert!(page.complete);
641        assert_eq!(page.next_cursor, 12);
642    }
643
644    #[test]
645    fn a_tail_larger_than_the_log_returns_everything_and_never_exceeds_the_limit() {
646        let directory = tempdir().unwrap();
647        let path = directory.path().join("output.ndjson");
648        write_records(
649            &path,
650            &[
651                (OutputSource::Agent, Some("build"), "one"),
652                (OutputSource::Agent, Some("build"), "two"),
653            ],
654        );
655
656        let all = read_filtered_page(
657            &path,
658            &PageQuery {
659                limit: 64,
660                tail: Some(50),
661                ..PageQuery::default()
662            },
663        )
664        .unwrap();
665        assert_eq!(texts(&all), ["one", "two"]);
666
667        let capped = read_filtered_page(
668            &path,
669            &PageQuery {
670                limit: 1,
671                tail: Some(50),
672                ..PageQuery::default()
673            },
674        )
675        .unwrap();
676        assert_eq!(texts(&capped), ["two"]);
677    }
678
679    /// The block a re-entered stage is prompted with quotes one execution, so
680    /// the tail must never mix a stage's attempts together.
681    #[test]
682    fn a_stage_tail_selects_one_execution_and_keeps_its_last_lines() {
683        let directory = tempdir().unwrap();
684        let path = directory.path().join("output.ndjson");
685        let writer = RunLogWriter::open(&path).unwrap();
686        for attempt in 1..=2 {
687            for index in 0..4 {
688                writer
689                    .append(
690                        OutputSource::Stage,
691                        Some("test"),
692                        Some(attempt),
693                        OutputStream::Stdout,
694                        format!("a{attempt} line {index}\n").as_bytes(),
695                    )
696                    .unwrap();
697            }
698        }
699        writer
700            .append(
701                OutputSource::Agent,
702                Some("build"),
703                Some(1),
704                OutputStream::Stdout,
705                b"not the test stage\n",
706            )
707            .unwrap();
708        drop(writer);
709
710        assert_eq!(
711            super::stage_output_tail(&path, "test", 1, 2).unwrap(),
712            "a1 line 2\na1 line 3"
713        );
714        assert_eq!(
715            super::stage_output_tail(&path, "test", 2, 100).unwrap(),
716            "a2 line 0\na2 line 1\na2 line 2\na2 line 3"
717        );
718        assert_eq!(super::stage_output_tail(&path, "test", 3, 10).unwrap(), "");
719        assert_eq!(
720            super::stage_output_tail(&directory.path().join("absent.ndjson"), "test", 1, 10)
721                .unwrap(),
722            ""
723        );
724    }
725
726    /// Chunks are pipe reads, not lines: a line split across two records is
727    /// one line in the tail, and the count applies after reassembly.
728    #[test]
729    fn a_stage_tail_counts_lines_after_reassembling_chunks() {
730        let directory = tempdir().unwrap();
731        let path = directory.path().join("output.ndjson");
732        let writer = RunLogWriter::open(&path).unwrap();
733        for chunk in ["one\ntw", "o\nthr", "ee\n"] {
734            writer
735                .append(
736                    OutputSource::Stage,
737                    Some("test"),
738                    Some(1),
739                    OutputStream::Stdout,
740                    chunk.as_bytes(),
741                )
742                .unwrap();
743        }
744        drop(writer);
745
746        assert_eq!(
747            super::stage_output_tail(&path, "test", 1, 10).unwrap(),
748            "one\ntwo\nthree"
749        );
750        assert_eq!(
751            super::stage_output_tail(&path, "test", 1, 1).unwrap(),
752            "three"
753        );
754    }
755
756    /// Output captured before attempts were tagged belongs to the only
757    /// execution such a run ever had.
758    #[test]
759    fn untagged_output_is_claimed_by_the_first_attempt() {
760        let directory = tempdir().unwrap();
761        let path = directory.path().join("output.ndjson");
762        let writer = RunLogWriter::open(&path).unwrap();
763        writer
764            .append(
765                OutputSource::Stage,
766                Some("test"),
767                None,
768                OutputStream::Stdout,
769                b"legacy\n",
770            )
771            .unwrap();
772        drop(writer);
773
774        assert_eq!(
775            super::stage_output_tail(&path, "test", 1, 10).unwrap(),
776            "legacy"
777        );
778        assert_eq!(super::stage_output_tail(&path, "test", 2, 10).unwrap(), "");
779    }
780
781    #[test]
782    fn utf8_and_binary_chunks_serialize_to_the_documented_shapes() {
783        let writer_dir = tempdir().unwrap();
784        let path = writer_dir.path().join("runs/R1/output.ndjson");
785        let writer = RunLogWriter::open(&path).unwrap();
786
787        writer
788            .append(
789                OutputSource::Agent,
790                None,
791                None,
792                OutputStream::Stdout,
793                b"hello\n",
794            )
795            .unwrap();
796        writer
797            .append(
798                OutputSource::Stage,
799                Some("test"),
800                None,
801                OutputStream::Stderr,
802                &[0xff, 0x00],
803            )
804            .unwrap();
805
806        let contents = std::fs::read_to_string(&path).unwrap();
807        let records: Vec<Value> = contents
808            .lines()
809            .map(|line| serde_json::from_str(line).unwrap())
810            .collect();
811
812        assert_eq!(records[0]["sequence"], 1);
813        assert_eq!(records[0]["source"], "agent");
814        assert_eq!(records[0]["stream"], "stdout");
815        assert_eq!(records[0]["encoding"], "utf8");
816        assert_eq!(records[0]["text"], "hello\n");
817        assert_eq!(records[0].get("stage"), None);
818        assert!(records[0]["timestamp"].as_str().unwrap().ends_with('Z'));
819
820        assert_eq!(records[1]["sequence"], 2);
821        assert_eq!(records[1]["source"], "stage");
822        assert_eq!(records[1]["stage"], "test");
823        assert_eq!(records[1]["encoding"], "base64");
824        assert_eq!(records[1]["data"], "/wA=");
825    }
826
827    #[test]
828    fn binary_chunks_round_trip_without_loss() {
829        let bytes = [0xff, 0xfe, 0x00, 0x41];
830        let chunk = OutputChunk::from_bytes(&bytes);
831        assert!(matches!(chunk, OutputChunk::Base64 { .. }));
832        assert_eq!(chunk.into_bytes(), bytes);
833    }
834
835    #[test]
836    fn reopening_appends_after_existing_records() {
837        let directory = tempdir().unwrap();
838        let path = directory.path().join("output.ndjson");
839
840        let writer = RunLogWriter::open(&path).unwrap();
841        writer
842            .append(
843                OutputSource::Agent,
844                None,
845                None,
846                OutputStream::Stdout,
847                b"one",
848            )
849            .unwrap();
850        drop(writer);
851
852        let writer = RunLogWriter::open(&path).unwrap();
853        let sequence = writer
854            .append(
855                OutputSource::Agent,
856                None,
857                None,
858                OutputStream::Stdout,
859                b"two",
860            )
861            .unwrap();
862        assert_eq!(sequence, 2);
863
864        let page = read_page(&path, 0, 10).unwrap();
865        assert_eq!(page.entries.len(), 2);
866        assert_eq!(
867            page.entries[1].chunk,
868            OutputChunk::Utf8 { text: "two".into() }
869        );
870    }
871
872    #[test]
873    fn staleness_uses_the_last_complete_agent_record_across_reopen() {
874        let directory = tempdir().unwrap();
875        let path = directory.path().join("output.ndjson");
876        let writer = RunLogWriter::open(&path).unwrap();
877        writer
878            .append_at(
879                100_000,
880                OutputSource::Agent,
881                Some("build"),
882                None,
883                OutputStream::Stdout,
884                b"first",
885            )
886            .unwrap();
887        writer
888            .append_at(
889                200_000,
890                OutputSource::Stage,
891                Some("test"),
892                None,
893                OutputStream::Stdout,
894                b"ignored",
895            )
896            .unwrap();
897        drop(writer);
898
899        let stale = output_staleness(&path, 50_000, 160_000, 60_000).unwrap();
900        assert_eq!(stale.last_sequence, Some(1));
901        assert_eq!(stale.last_output_at_ms, 100_000);
902        assert_eq!(stale.silent_for_ms, 60_000);
903        assert!(stale.stalled);
904
905        let writer = RunLogWriter::open(&path).unwrap();
906        writer
907            .append_at(
908                160_000,
909                OutputSource::Agent,
910                Some("build"),
911                None,
912                OutputStream::Stdout,
913                b"resumed",
914            )
915            .unwrap();
916        drop(writer);
917        let resumed = output_staleness(&path, 50_000, 160_000, 60_000).unwrap();
918        assert_eq!(resumed.last_sequence, Some(3));
919        assert_eq!(resumed.silent_for_ms, 0);
920        assert!(!resumed.stalled);
921    }
922
923    #[test]
924    fn a_truncated_tail_hides_no_earlier_records() {
925        let directory = tempdir().unwrap();
926        let path = directory.path().join("output.ndjson");
927        let writer = RunLogWriter::open(&path).unwrap();
928        writer
929            .append(
930                OutputSource::Agent,
931                None,
932                None,
933                OutputStream::Stdout,
934                b"kept",
935            )
936            .unwrap();
937        drop(writer);
938
939        use std::io::Write;
940        let mut file = std::fs::OpenOptions::new()
941            .append(true)
942            .open(&path)
943            .unwrap();
944        file.write_all(b"{\"sequence\":2,\"timest").unwrap();
945        drop(file);
946
947        let page = read_page(&path, 0, 10).unwrap();
948        assert_eq!(page.entries.len(), 1);
949        assert!(page.complete);
950
951        let writer = RunLogWriter::open(&path).unwrap();
952        let sequence = writer
953            .append(
954                OutputSource::Agent,
955                None,
956                None,
957                OutputStream::Stdout,
958                b"next",
959            )
960            .unwrap();
961        assert_eq!(sequence, 2);
962
963        let page = read_page(&path, 0, 10).unwrap();
964        assert_eq!(page.entries.len(), 2);
965        assert_eq!(
966            page.entries[1].chunk,
967            OutputChunk::Utf8 {
968                text: "next".into()
969            }
970        );
971    }
972
973    #[test]
974    fn pagination_is_stable_across_sequence_cursors() {
975        let directory = tempdir().unwrap();
976        let path = directory.path().join("output.ndjson");
977        let writer = RunLogWriter::open(&path).unwrap();
978        for index in 0..5 {
979            writer
980                .append(
981                    OutputSource::Agent,
982                    None,
983                    None,
984                    OutputStream::Stdout,
985                    format!("chunk {index}").as_bytes(),
986                )
987                .unwrap();
988        }
989
990        let first = read_page(&path, 0, 2).unwrap();
991        assert_eq!(first.entries.len(), 2);
992        assert_eq!(first.next_cursor, 2);
993        assert!(!first.complete);
994
995        let second = read_page(&path, first.next_cursor, 10).unwrap();
996        assert_eq!(second.entries.len(), 3);
997        assert_eq!(second.next_cursor, 5);
998        assert!(second.complete);
999
1000        let missing = read_page(&directory.path().join("absent.ndjson"), 0, 10).unwrap();
1001        assert!(missing.entries.is_empty() && missing.complete);
1002    }
1003
1004    #[test]
1005    fn records_round_trip_through_serde() {
1006        let record = super::OutputRecord {
1007            sequence: 7,
1008            timestamp: "2026-07-13T20:00:01Z".into(),
1009            source: OutputSource::Stage,
1010            stage: Some("test".into()),
1011            attempt: Some(2),
1012            stream: OutputStream::Stderr,
1013            chunk: OutputChunk::Utf8 { text: "x".into() },
1014        };
1015        let encoded = serde_json::to_value(&record).unwrap();
1016        assert_eq!(
1017            encoded,
1018            json!({
1019                "sequence": 7,
1020                "timestamp": "2026-07-13T20:00:01Z",
1021                "source": "stage",
1022                "stage": "test",
1023                "attempt": 2,
1024                "stream": "stderr",
1025                "encoding": "utf8",
1026                "text": "x"
1027            })
1028        );
1029        let decoded: super::OutputRecord = serde_json::from_value(encoded).unwrap();
1030        assert_eq!(decoded, record);
1031    }
1032
1033    #[test]
1034    fn agent_streams_are_reassembled_across_utf8_and_binary_chunks() {
1035        let directory = tempdir().unwrap();
1036        let path = directory.path().join("output.ndjson");
1037        let writer = RunLogWriter::open(&path).unwrap();
1038        writer
1039            .append(
1040                OutputSource::Agent,
1041                None,
1042                None,
1043                OutputStream::Stderr,
1044                b"rate li",
1045            )
1046            .unwrap();
1047        writer
1048            .append(
1049                OutputSource::Stage,
1050                Some("test"),
1051                None,
1052                OutputStream::Stderr,
1053                b"must not match",
1054            )
1055            .unwrap();
1056        writer
1057            .append(
1058                OutputSource::Agent,
1059                None,
1060                None,
1061                OutputStream::Stdout,
1062                &[0xff, b'o', b'k'],
1063            )
1064            .unwrap();
1065        writer
1066            .append(
1067                OutputSource::Agent,
1068                None,
1069                None,
1070                OutputStream::Stderr,
1071                b"mited",
1072            )
1073            .unwrap();
1074        drop(writer);
1075
1076        use std::io::Write;
1077        let mut file = std::fs::OpenOptions::new()
1078            .append(true)
1079            .open(&path)
1080            .unwrap();
1081        file.write_all(b"{\"sequence\":99").unwrap();
1082
1083        let output = read_agent_output(&path).unwrap();
1084        assert_eq!(output.stderr, b"rate limited");
1085        assert_eq!(output.stdout, [0xff, b'o', b'k']);
1086    }
1087}