Skip to main content

sloop/
run_log.rs

1//! Per-run NDJSON output capture. Agent and aftercare 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, 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
17#[derive(Debug, Clone, Copy, PartialEq, Eq, Serialize, Deserialize)]
18#[serde(rename_all = "snake_case")]
19pub enum OutputSource {
20    Agent,
21    Aftercare,
22}
23
24#[derive(Debug, Clone, Copy, PartialEq, Eq, Serialize, Deserialize)]
25#[serde(rename_all = "snake_case")]
26pub enum OutputStream {
27    Stdout,
28    Stderr,
29}
30
31/// One captured chunk. UTF-8 chunks stay readable; anything else round-trips
32/// through base64 rather than being lossily converted.
33#[derive(Debug, Clone, PartialEq, Eq, Serialize, Deserialize)]
34#[serde(tag = "encoding", rename_all = "snake_case")]
35pub enum OutputChunk {
36    Utf8 { text: String },
37    Base64 { data: String },
38}
39
40impl OutputChunk {
41    pub fn from_bytes(bytes: &[u8]) -> Self {
42        match std::str::from_utf8(bytes) {
43            Ok(text) => Self::Utf8 { text: text.into() },
44            Err(_) => Self::Base64 {
45                data: BASE64.encode(bytes),
46            },
47        }
48    }
49
50    pub fn into_bytes(self) -> Vec<u8> {
51        match self {
52            Self::Utf8 { text } => text.into_bytes(),
53            Self::Base64 { data } => BASE64.decode(data).unwrap_or_default(),
54        }
55    }
56}
57
58#[derive(Debug, Clone, PartialEq, Eq, Serialize, Deserialize)]
59pub struct OutputRecord {
60    pub sequence: u64,
61    pub timestamp: String,
62    pub source: OutputSource,
63    #[serde(default, skip_serializing_if = "Option::is_none")]
64    pub stage: Option<String>,
65    pub stream: OutputStream,
66    #[serde(flatten)]
67    pub chunk: OutputChunk,
68}
69
70/// Append-only writer shared by the stdout and stderr reader threads of one
71/// run. Sequence numbers are capture order across both pipes.
72#[derive(Clone)]
73pub struct RunLogWriter {
74    inner: Arc<Mutex<Inner>>,
75}
76
77struct Inner {
78    file: File,
79    next_sequence: u64,
80}
81
82impl RunLogWriter {
83    /// Opens (creating directories as needed) the run's output log and
84    /// resumes sequence numbering after any records already present, so a
85    /// restarted daemon appends instead of renumbering.
86    pub fn open(path: &Path) -> io::Result<Self> {
87        if let Some(parent) = path.parent() {
88            fs::create_dir_all(parent)?;
89        }
90        let next_sequence = last_sequence(path)?.map_or(1, |last| last + 1);
91        let mut file = OpenOptions::new().create(true).append(true).open(path)?;
92        // A crash can leave a partial record with no trailing newline; the
93        // next record must start on its own line or it would be corrupted too.
94        if !ends_with_newline(path)? {
95            file.write_all(b"\n")?;
96        }
97        Ok(Self {
98            inner: Arc::new(Mutex::new(Inner {
99                file,
100                next_sequence,
101            })),
102        })
103    }
104
105    /// Appends one chunk and durably flushes it. Capture must be on disk
106    /// before exit evidence claims it is complete.
107    pub fn append(
108        &self,
109        source: OutputSource,
110        stage: Option<&str>,
111        stream: OutputStream,
112        bytes: &[u8],
113    ) -> io::Result<u64> {
114        let timestamp = OffsetDateTime::now_utc()
115            .format(&Rfc3339)
116            .unwrap_or_else(|_| "1970-01-01T00:00:00Z".into());
117        let mut inner = self
118            .inner
119            .lock()
120            .map_err(|_| io::Error::other("run log lock poisoned"))?;
121        let record = OutputRecord {
122            sequence: inner.next_sequence,
123            timestamp,
124            source,
125            stage: stage.map(str::to_owned),
126            stream,
127            chunk: OutputChunk::from_bytes(bytes),
128        };
129        let mut line = serde_json::to_vec(&record).map_err(io::Error::other)?;
130        line.push(b'\n');
131        let original_len = inner.file.metadata()?.len();
132        if let Err(error) = inner
133            .file
134            .write_all(&line)
135            .and_then(|()| inner.file.sync_data())
136        {
137            // Keep the previous complete-record boundary after a short write,
138            // especially ENOSPC, so future appends cannot join corrupt JSON.
139            let _ = inner.file.set_len(original_len);
140            return Err(error);
141        }
142        inner.next_sequence += 1;
143        Ok(record.sequence)
144    }
145}
146
147/// True when the file is empty or its last byte is a newline, meaning the
148/// next append starts a fresh record.
149fn ends_with_newline(path: &Path) -> io::Result<bool> {
150    use std::io::{Read, Seek, SeekFrom};
151    let mut file = match File::open(path) {
152        Ok(file) => file,
153        Err(error) if error.kind() == io::ErrorKind::NotFound => return Ok(true),
154        Err(error) => return Err(error),
155    };
156    if file.metadata()?.len() == 0 {
157        return Ok(true);
158    }
159    file.seek(SeekFrom::End(-1))?;
160    let mut last = [0u8; 1];
161    file.read_exact(&mut last)?;
162    Ok(last[0] == b'\n')
163}
164
165/// The sequence of the last complete record, ignoring a truncated tail left
166/// by a crash; earlier records stay valid evidence.
167fn last_sequence(path: &Path) -> io::Result<Option<u64>> {
168    let file = match File::open(path) {
169        Ok(file) => file,
170        Err(error) if error.kind() == io::ErrorKind::NotFound => return Ok(None),
171        Err(error) => return Err(error),
172    };
173    let mut last = None;
174    for line in BufReader::new(file).lines() {
175        if let Ok(record) = serde_json::from_str::<OutputRecord>(&line?) {
176            last = Some(record.sequence);
177        }
178    }
179    Ok(last)
180}
181
182#[derive(Debug, Clone, PartialEq, Eq)]
183pub struct OutputPage {
184    pub entries: Vec<OutputRecord>,
185    /// Sequence of the last returned entry; the cursor a future paginated
186    /// call would resume after.
187    pub next_cursor: u64,
188    /// True when the page reached the end of the captured records.
189    pub complete: bool,
190}
191
192#[derive(Debug, Clone, Default, PartialEq, Eq)]
193pub struct AgentOutput {
194    pub stdout: Vec<u8>,
195    pub stderr: Vec<u8>,
196}
197
198/// Reassembles each agent stream from every complete captured record. Test
199/// and merge output is deliberately excluded from vendor classification.
200pub fn read_agent_output(path: &Path) -> io::Result<AgentOutput> {
201    let mut output = AgentOutput::default();
202    visit_agent_output(path, |stream, bytes| {
203        let destination = match stream {
204            OutputStream::Stdout => &mut output.stdout,
205            OutputStream::Stderr => &mut output.stderr,
206        };
207        destination.extend_from_slice(bytes);
208    })?;
209    Ok(output)
210}
211
212/// Visits decoded agent chunks in capture order without retaining the whole
213/// log. A malformed or crash-truncated record does not hide earlier evidence.
214pub fn visit_agent_output(
215    path: &Path,
216    mut visitor: impl FnMut(OutputStream, &[u8]),
217) -> io::Result<()> {
218    let file = match File::open(path) {
219        Ok(file) => file,
220        Err(error) if error.kind() == io::ErrorKind::NotFound => {
221            return Ok(());
222        }
223        Err(error) => return Err(error),
224    };
225    for line in BufReader::new(file).lines() {
226        if let Ok(record) = serde_json::from_str::<OutputRecord>(&line?)
227            && record.source == OutputSource::Agent
228        {
229            let bytes = record.chunk.into_bytes();
230            visitor(record.stream, &bytes);
231        }
232    }
233    Ok(())
234}
235
236/// Selects the records belonging to one flow stage. Aftercare records carry
237/// their stage name; agent records captured before stages were tagged carry
238/// none, so `agent_fallback` lets the flow's agent stage claim them.
239#[derive(Debug, Clone, PartialEq, Eq)]
240pub struct StageFilter {
241    pub stage: String,
242    pub agent_fallback: bool,
243}
244
245impl StageFilter {
246    fn accepts(&self, record: &OutputRecord) -> bool {
247        match record.stage.as_deref() {
248            Some(stage) => stage == self.stage,
249            None => self.agent_fallback && record.source == OutputSource::Agent,
250        }
251    }
252}
253
254/// One read of the captured log: everything after a cursor, optionally
255/// narrowed to a stage and trimmed to a trailing window.
256#[derive(Debug, Clone, Default, PartialEq, Eq)]
257pub struct PageQuery {
258    /// Only records with `sequence > after`.
259    pub after: u64,
260    /// Hard cap on returned entries; also the cap on `tail`.
261    pub limit: usize,
262    /// Only records this filter accepts.
263    pub stage: Option<StageFilter>,
264    /// Keep the last N accepted records instead of the first N. Reading runs
265    /// to the end of the file, so the page is always complete.
266    pub tail: Option<usize>,
267}
268
269/// Reads a finite page of records with `sequence > after`, in order. A
270/// missing file is an empty page: the run may exist before any output does.
271pub fn read_page(path: &Path, after: u64, limit: usize) -> io::Result<OutputPage> {
272    read_filtered_page(
273        path,
274        &PageQuery {
275            after,
276            limit,
277            ..PageQuery::default()
278        },
279    )
280}
281
282/// Reads one page under a filter. `next_cursor` advances past every record
283/// the read *consumed*, not just the ones it returned: a filtered-out record
284/// is still evidence that has been examined, so a follower resuming from the
285/// cursor neither replays it nor stalls behind it.
286pub fn read_filtered_page(path: &Path, query: &PageQuery) -> io::Result<OutputPage> {
287    let file = match File::open(path) {
288        Ok(file) => file,
289        Err(error) if error.kind() == io::ErrorKind::NotFound => {
290            return Ok(OutputPage {
291                entries: Vec::new(),
292                next_cursor: query.after,
293                complete: true,
294            });
295        }
296        Err(error) => return Err(error),
297    };
298
299    // A tail keeps the newest accepted records, so it must read to the end;
300    // the trailing window is bounded by the caller's limit either way.
301    let window = query.tail.map_or(query.limit, |tail| tail.min(query.limit));
302    let mut entries = VecDeque::new();
303    let mut next_cursor = query.after;
304    let mut complete = true;
305    for line in BufReader::new(file).lines() {
306        // An unparsable line is an incomplete tail, not corruption of the
307        // records before it.
308        let Ok(record) = serde_json::from_str::<OutputRecord>(&line?) else {
309            continue;
310        };
311        if record.sequence <= query.after {
312            continue;
313        }
314        if query.tail.is_none() && entries.len() == query.limit {
315            complete = false;
316            break;
317        }
318        next_cursor = record.sequence;
319        if query.stage.as_ref().is_some_and(|f| !f.accepts(&record)) {
320            continue;
321        }
322        entries.push_back(record);
323        if entries.len() > window {
324            entries.pop_front();
325        }
326    }
327    Ok(OutputPage {
328        entries: entries.into(),
329        next_cursor,
330        complete,
331    })
332}
333
334#[cfg(test)]
335mod tests {
336    use serde_json::{Value, json};
337    use tempfile::tempdir;
338
339    use super::{
340        OutputChunk, OutputSource, OutputStream, PageQuery, RunLogWriter, StageFilter,
341        read_agent_output, read_filtered_page, read_page,
342    };
343
344    /// Writes one record per call, so a test controls entry boundaries the
345    /// way pipe reads do at runtime.
346    fn write_records(path: &std::path::Path, records: &[(OutputSource, Option<&str>, &str)]) {
347        let writer = RunLogWriter::open(path).unwrap();
348        for (source, stage, text) in records {
349            writer
350                .append(*source, *stage, OutputStream::Stdout, text.as_bytes())
351                .unwrap();
352        }
353    }
354
355    fn texts(page: &super::OutputPage) -> Vec<String> {
356        page.entries
357            .iter()
358            .map(|record| String::from_utf8(record.chunk.clone().into_bytes()).unwrap())
359            .collect()
360    }
361
362    #[test]
363    fn a_stage_filter_selects_that_stage_and_leaves_the_cursor_past_what_it_skipped() {
364        let directory = tempdir().unwrap();
365        let path = directory.path().join("output.ndjson");
366        write_records(
367            &path,
368            &[
369                (OutputSource::Agent, Some("build"), "built"),
370                (OutputSource::Aftercare, Some("test"), "tested"),
371                (OutputSource::Aftercare, Some("merge"), "merged"),
372            ],
373        );
374
375        let page = read_filtered_page(
376            &path,
377            &PageQuery {
378                limit: 10,
379                stage: Some(StageFilter {
380                    stage: "test".into(),
381                    agent_fallback: false,
382                }),
383                ..PageQuery::default()
384            },
385        )
386        .unwrap();
387
388        assert_eq!(texts(&page), ["tested"]);
389        // Records 3 was examined and rejected, so a follower resuming here
390        // neither replays it nor re-reads it on every poll.
391        assert_eq!(page.next_cursor, 3);
392        assert!(page.complete);
393    }
394
395    #[test]
396    fn the_agent_fallback_claims_records_captured_before_stages_were_tagged() {
397        let directory = tempdir().unwrap();
398        let path = directory.path().join("output.ndjson");
399        write_records(
400            &path,
401            &[
402                (OutputSource::Agent, None, "legacy agent"),
403                (OutputSource::Aftercare, None, "legacy aftercare"),
404                (OutputSource::Agent, Some("build"), "tagged agent"),
405            ],
406        );
407        let filter = |agent_fallback| PageQuery {
408            limit: 10,
409            stage: Some(StageFilter {
410                stage: "build".into(),
411                agent_fallback,
412            }),
413            ..PageQuery::default()
414        };
415
416        let claimed = read_filtered_page(&path, &filter(true)).unwrap();
417        assert_eq!(texts(&claimed), ["legacy agent", "tagged agent"]);
418
419        // Without the fallback only the tagged record matches: an untagged
420        // record names no stage and must not be invented into one.
421        let literal = read_filtered_page(&path, &filter(false)).unwrap();
422        assert_eq!(texts(&literal), ["tagged agent"]);
423    }
424
425    #[test]
426    fn a_tail_keeps_the_newest_matching_records_and_still_reaches_the_end() {
427        let directory = tempdir().unwrap();
428        let path = directory.path().join("output.ndjson");
429        let mut records = Vec::new();
430        for index in 0..6 {
431            records.push((OutputSource::Aftercare, Some("test"), format!("t{index}")));
432            records.push((OutputSource::Agent, Some("build"), format!("b{index}")));
433        }
434        write_records(
435            &path,
436            &records
437                .iter()
438                .map(|(source, stage, text)| (*source, *stage, text.as_str()))
439                .collect::<Vec<_>>(),
440        );
441
442        let page = read_filtered_page(
443            &path,
444            &PageQuery {
445                limit: 64,
446                stage: Some(StageFilter {
447                    stage: "test".into(),
448                    agent_fallback: false,
449                }),
450                tail: Some(2),
451                ..PageQuery::default()
452            },
453        )
454        .unwrap();
455
456        assert_eq!(texts(&page), ["t4", "t5"]);
457        // A tail reads to the end of the file, so the page is complete and
458        // the cursor is past every record — including the ones it dropped.
459        assert!(page.complete);
460        assert_eq!(page.next_cursor, 12);
461    }
462
463    #[test]
464    fn a_tail_larger_than_the_log_returns_everything_and_never_exceeds_the_limit() {
465        let directory = tempdir().unwrap();
466        let path = directory.path().join("output.ndjson");
467        write_records(
468            &path,
469            &[
470                (OutputSource::Agent, Some("build"), "one"),
471                (OutputSource::Agent, Some("build"), "two"),
472            ],
473        );
474
475        let all = read_filtered_page(
476            &path,
477            &PageQuery {
478                limit: 64,
479                tail: Some(50),
480                ..PageQuery::default()
481            },
482        )
483        .unwrap();
484        assert_eq!(texts(&all), ["one", "two"]);
485
486        // The limit outranks the tail; a caller cannot page past it.
487        let capped = read_filtered_page(
488            &path,
489            &PageQuery {
490                limit: 1,
491                tail: Some(50),
492                ..PageQuery::default()
493            },
494        )
495        .unwrap();
496        assert_eq!(texts(&capped), ["two"]);
497    }
498
499    #[test]
500    fn utf8_and_binary_chunks_serialize_to_the_documented_shapes() {
501        let writer_dir = tempdir().unwrap();
502        let path = writer_dir.path().join("runs/R1/output.ndjson");
503        let writer = RunLogWriter::open(&path).unwrap();
504
505        writer
506            .append(OutputSource::Agent, None, OutputStream::Stdout, b"hello\n")
507            .unwrap();
508        writer
509            .append(
510                OutputSource::Aftercare,
511                Some("test"),
512                OutputStream::Stderr,
513                &[0xff, 0x00],
514            )
515            .unwrap();
516
517        let contents = std::fs::read_to_string(&path).unwrap();
518        let records: Vec<Value> = contents
519            .lines()
520            .map(|line| serde_json::from_str(line).unwrap())
521            .collect();
522
523        assert_eq!(records[0]["sequence"], 1);
524        assert_eq!(records[0]["source"], "agent");
525        assert_eq!(records[0]["stream"], "stdout");
526        assert_eq!(records[0]["encoding"], "utf8");
527        assert_eq!(records[0]["text"], "hello\n");
528        assert_eq!(records[0].get("stage"), None);
529        assert!(records[0]["timestamp"].as_str().unwrap().ends_with('Z'));
530
531        assert_eq!(records[1]["sequence"], 2);
532        assert_eq!(records[1]["source"], "aftercare");
533        assert_eq!(records[1]["stage"], "test");
534        assert_eq!(records[1]["encoding"], "base64");
535        assert_eq!(records[1]["data"], "/wA=");
536    }
537
538    #[test]
539    fn binary_chunks_round_trip_without_loss() {
540        let bytes = [0xff, 0xfe, 0x00, 0x41];
541        let chunk = OutputChunk::from_bytes(&bytes);
542        assert!(matches!(chunk, OutputChunk::Base64 { .. }));
543        assert_eq!(chunk.into_bytes(), bytes);
544    }
545
546    #[test]
547    fn reopening_appends_after_existing_records() {
548        let directory = tempdir().unwrap();
549        let path = directory.path().join("output.ndjson");
550
551        let writer = RunLogWriter::open(&path).unwrap();
552        writer
553            .append(OutputSource::Agent, None, OutputStream::Stdout, b"one")
554            .unwrap();
555        drop(writer);
556
557        let writer = RunLogWriter::open(&path).unwrap();
558        let sequence = writer
559            .append(OutputSource::Agent, None, OutputStream::Stdout, b"two")
560            .unwrap();
561        assert_eq!(sequence, 2);
562
563        let page = read_page(&path, 0, 10).unwrap();
564        assert_eq!(page.entries.len(), 2);
565        assert_eq!(
566            page.entries[1].chunk,
567            OutputChunk::Utf8 { text: "two".into() }
568        );
569    }
570
571    #[test]
572    fn a_truncated_tail_hides_no_earlier_records() {
573        let directory = tempdir().unwrap();
574        let path = directory.path().join("output.ndjson");
575        let writer = RunLogWriter::open(&path).unwrap();
576        writer
577            .append(OutputSource::Agent, None, OutputStream::Stdout, b"kept")
578            .unwrap();
579        drop(writer);
580
581        use std::io::Write;
582        let mut file = std::fs::OpenOptions::new()
583            .append(true)
584            .open(&path)
585            .unwrap();
586        file.write_all(b"{\"sequence\":2,\"timest").unwrap();
587        drop(file);
588
589        let page = read_page(&path, 0, 10).unwrap();
590        assert_eq!(page.entries.len(), 1);
591        assert!(page.complete);
592
593        // The partial record was never complete, so its sequence is free to
594        // reuse, and the new record must land on its own line.
595        let writer = RunLogWriter::open(&path).unwrap();
596        let sequence = writer
597            .append(OutputSource::Agent, None, OutputStream::Stdout, b"next")
598            .unwrap();
599        assert_eq!(sequence, 2);
600
601        let page = read_page(&path, 0, 10).unwrap();
602        assert_eq!(page.entries.len(), 2);
603        assert_eq!(
604            page.entries[1].chunk,
605            OutputChunk::Utf8 {
606                text: "next".into()
607            }
608        );
609    }
610
611    #[test]
612    fn pagination_is_stable_across_sequence_cursors() {
613        let directory = tempdir().unwrap();
614        let path = directory.path().join("output.ndjson");
615        let writer = RunLogWriter::open(&path).unwrap();
616        for index in 0..5 {
617            writer
618                .append(
619                    OutputSource::Agent,
620                    None,
621                    OutputStream::Stdout,
622                    format!("chunk {index}").as_bytes(),
623                )
624                .unwrap();
625        }
626
627        let first = read_page(&path, 0, 2).unwrap();
628        assert_eq!(first.entries.len(), 2);
629        assert_eq!(first.next_cursor, 2);
630        assert!(!first.complete);
631
632        let second = read_page(&path, first.next_cursor, 10).unwrap();
633        assert_eq!(second.entries.len(), 3);
634        assert_eq!(second.next_cursor, 5);
635        assert!(second.complete);
636
637        let missing = read_page(&directory.path().join("absent.ndjson"), 0, 10).unwrap();
638        assert!(missing.entries.is_empty() && missing.complete);
639    }
640
641    #[test]
642    fn records_round_trip_through_serde() {
643        let record = super::OutputRecord {
644            sequence: 7,
645            timestamp: "2026-07-13T20:00:01Z".into(),
646            source: OutputSource::Aftercare,
647            stage: Some("test".into()),
648            stream: OutputStream::Stderr,
649            chunk: OutputChunk::Utf8 { text: "x".into() },
650        };
651        let encoded = serde_json::to_value(&record).unwrap();
652        assert_eq!(
653            encoded,
654            json!({
655                "sequence": 7,
656                "timestamp": "2026-07-13T20:00:01Z",
657                "source": "aftercare",
658                "stage": "test",
659                "stream": "stderr",
660                "encoding": "utf8",
661                "text": "x"
662            })
663        );
664        let decoded: super::OutputRecord = serde_json::from_value(encoded).unwrap();
665        assert_eq!(decoded, record);
666    }
667
668    #[test]
669    fn agent_streams_are_reassembled_across_utf8_and_binary_chunks() {
670        let directory = tempdir().unwrap();
671        let path = directory.path().join("output.ndjson");
672        let writer = RunLogWriter::open(&path).unwrap();
673        writer
674            .append(OutputSource::Agent, None, OutputStream::Stderr, b"rate li")
675            .unwrap();
676        writer
677            .append(
678                OutputSource::Aftercare,
679                Some("test"),
680                OutputStream::Stderr,
681                b"must not match",
682            )
683            .unwrap();
684        writer
685            .append(
686                OutputSource::Agent,
687                None,
688                OutputStream::Stdout,
689                &[0xff, b'o', b'k'],
690            )
691            .unwrap();
692        writer
693            .append(OutputSource::Agent, None, OutputStream::Stderr, b"mited")
694            .unwrap();
695        drop(writer);
696
697        use std::io::Write;
698        let mut file = std::fs::OpenOptions::new()
699            .append(true)
700            .open(&path)
701            .unwrap();
702        file.write_all(b"{\"sequence\":99").unwrap();
703
704        let output = read_agent_output(&path).unwrap();
705        assert_eq!(output.stderr, b"rate limited");
706        assert_eq!(output.stdout, [0xff, b'o', b'k']);
707    }
708}