relux_runtime/observe/structured/
builder.rs

1//! Concurrent accumulator for `StructuredLog`.
2//!
3//! `StructuredLogBuilder` is the writer end of the structured-event stream.
4//! It is cheap to `Clone` (storage is `Arc<Mutex<_>>`-shared) and is threaded
5//! through `RuntimeContext`; every emission site forwards through it.
6//!
7//! The per-event-kind emitters live in concern-grouped submodules
8//! (`lifecycle`, `io`, `matching`, `values`, `diagnostics`) - each one
9//! adds an `impl StructuredLogBuilder` block. This file owns the core:
10//! the struct itself, the `SpanGuard` RAII handle, helper resolvers
11//! (`now`, `resolve_location`, `timeout_value`, `push_progress`), the
12//! two raw push entry points (`push_event`, `push_buffer_event`), and
13//! the final `build()` assembly.
14
15mod diagnostics;
16mod io;
17mod lifecycle;
18mod matching;
19mod values;
20
21use std::collections::HashMap;
22use std::path::Path;
23use std::sync::Arc;
24use std::sync::Mutex;
25use std::time::Duration;
26use std::time::Instant;
27
28use relux_core::diagnostics::IrSpan;
29use relux_core::table::SourceTable;
30use relux_ir::IrTimeout;
31
32use super::ArtifactEntry;
33use super::EnvInfo;
34use super::SourceLocation;
35use super::StructuredLog;
36use super::TestInfo;
37use super::TestOutcome;
38use super::buffer::BufferEvent;
39use super::buffer::BufferEventKind;
40use super::event::Event;
41use super::event::EventKind;
42use super::event::EventSeq;
43use super::event::TimeoutValue;
44use super::span::Span;
45use super::span::SpanId;
46use crate::observe::progress::ProgressEvent;
47use crate::observe::progress::ProgressTx;
48
49/// Concurrent accumulator for `StructuredLog`. Cheap to `Clone` (the storage
50/// is `Arc`-shared); the runtime threads it through `RuntimeContext` and
51/// every emission site forwards through it.
52#[derive(Clone)]
53pub struct StructuredLogBuilder {
54    pub(super) inner: Arc<Mutex<BuilderInner>>,
55    pub(super) test_start: Instant,
56    pub(super) sources: SourceTable,
57    pub(super) project_root: Arc<Path>,
58    pub(super) progress_tx: ProgressTx,
59}
60
61/// RAII handle for a span. `Drop` calls `close_span_inner` on the underlying
62/// builder, so `?` early-returns are safe - the span always gets an `end_ts`.
63/// Use `id()` to obtain the `SpanId` for emissions and as a parent of
64/// child spans. Use `close()` to close explicitly (gives a tighter `end_ts`
65/// than waiting for drop, useful right before `build()`).
66pub struct SpanGuard {
67    id: Option<SpanId>,
68    log: StructuredLogBuilder,
69}
70
71impl SpanGuard {
72    pub(super) fn new(id: SpanId, log: StructuredLogBuilder) -> Self {
73        Self { id: Some(id), log }
74    }
75
76    pub fn id(&self) -> SpanId {
77        self.id.expect("span guard already closed")
78    }
79
80    pub fn close(mut self) {
81        if let Some(id) = self.id.take() {
82            self.log.close_span_inner(id);
83        }
84    }
85}
86
87impl Drop for SpanGuard {
88    fn drop(&mut self) {
89        if let Some(id) = self.id.take() {
90            self.log.close_span_inner(id);
91        }
92    }
93}
94
95pub(super) struct BuilderInner {
96    pub(super) next_seq: EventSeq,
97    pub(super) next_span_id: SpanId,
98    pub(super) spans: HashMap<SpanId, Span>,
99    pub(super) events: Vec<Event>,
100    pub(super) buffer_events: Vec<BufferEvent>,
101    pub(super) shells: HashMap<String, super::shell::ShellRecord>,
102}
103
104impl StructuredLogBuilder {
105    pub fn new(
106        progress_tx: ProgressTx,
107        test_start: Instant,
108        sources: SourceTable,
109        project_root: Arc<Path>,
110    ) -> Self {
111        Self {
112            inner: Arc::new(Mutex::new(BuilderInner {
113                next_seq: 0,
114                next_span_id: 0,
115                spans: HashMap::new(),
116                events: Vec::new(),
117                buffer_events: Vec::new(),
118                shells: HashMap::new(),
119            })),
120            test_start,
121            sources,
122            project_root,
123            progress_tx,
124        }
125    }
126
127    pub(super) fn now(&self) -> Duration {
128        self.test_start.elapsed()
129    }
130
131    pub(crate) fn resolve_location(&self, span: &IrSpan) -> Option<SourceLocation> {
132        let file_id = span.file();
133        let source_file = self.sources.get(file_id)?;
134        let line = source_file.line_at(span.span().start());
135        let rel_path = source_file
136            .path
137            .strip_prefix(&*self.project_root)
138            .unwrap_or(&source_file.path);
139        Some(SourceLocation {
140            file: rel_path.display().to_string(),
141            line,
142            start: span.span().start(),
143            end: span.span().end(),
144        })
145    }
146
147    pub(super) fn timeout_value(&self, t: &IrTimeout) -> TimeoutValue {
148        match t {
149            IrTimeout::Tolerance {
150                duration,
151                multiplier,
152                span,
153            } => TimeoutValue::Tolerance {
154                duration: humantime::format_duration(*duration).to_string(),
155                multiplier: format_multiplier(*multiplier),
156                total_duration: humantime::format_duration(t.adjusted_duration()).to_string(),
157                source: self.resolve_location(span),
158            },
159            IrTimeout::Assertion { duration, span } => TimeoutValue::Assertion {
160                duration: humantime::format_duration(*duration).to_string(),
161                source: self.resolve_location(span),
162            },
163        }
164    }
165
166    pub(super) fn push_progress(&self, event: ProgressEvent) {
167        let _ = self.progress_tx.send(event);
168    }
169
170    /// Latest emitted seq, or `0` if no event has fired yet. Failures use
171    /// this to point the structured-log artifact at the most recent event
172    /// (typically a `Timeout` or `FailPatternTriggered`).
173    pub fn current_seq(&self) -> EventSeq {
174        let inner = self.inner.lock().unwrap();
175        inner.next_seq.saturating_sub(1)
176    }
177
178    /// Test-only: a snapshot of the accumulated buffer events, in the
179    /// order they were pushed.
180    #[cfg(test)]
181    pub(crate) fn buffer_events_for_tests(&self) -> Vec<BufferEvent> {
182        self.inner.lock().unwrap().buffer_events.clone()
183    }
184
185    #[cfg(test)]
186    pub(crate) fn sources_for_tests(&self) -> &relux_core::table::SourceTable {
187        &self.sources
188    }
189
190    #[cfg(test)]
191    pub(crate) fn resolve_location_for_tests(&self, span: &IrSpan) -> Option<SourceLocation> {
192        self.resolve_location(span)
193    }
194
195    pub fn push_event(
196        &self,
197        span: SpanId,
198        shell: Option<&str>,
199        shell_marker: Option<&str>,
200        location: Option<&IrSpan>,
201        kind: EventKind,
202    ) -> EventSeq {
203        let source = location.and_then(|s| self.resolve_location(s));
204        let ts = self.now();
205        let mut inner = self.inner.lock().unwrap();
206        let seq = inner.next_seq;
207        inner.next_seq += 1;
208        inner.events.push(Event {
209            seq,
210            ts,
211            span,
212            shell: shell.map(String::from),
213            shell_marker: shell_marker.map(String::from),
214            source,
215            kind,
216        });
217        seq
218    }
219
220    pub fn push_buffer_event(
221        &self,
222        shell: &str,
223        shell_marker: &str,
224        kind: BufferEventKind,
225    ) -> EventSeq {
226        let ts = self.now();
227        let mut inner = self.inner.lock().unwrap();
228        let seq = inner.next_seq;
229        inner.next_seq += 1;
230        inner.buffer_events.push(BufferEvent {
231            seq,
232            ts,
233            shell: shell.to_string(),
234            shell_marker: shell_marker.to_string(),
235            kind,
236        });
237        seq
238    }
239
240    pub fn build(
241        self,
242        info: TestInfo,
243        env: EnvInfo,
244        outcome: TestOutcome,
245        artifacts: Vec<ArtifactEntry>,
246    ) -> StructuredLog {
247        let inner = match Arc::try_unwrap(self.inner) {
248            Ok(mutex) => mutex.into_inner().unwrap(),
249            Err(arc) => {
250                let mut guard = arc.lock().unwrap();
251                BuilderInner {
252                    next_seq: guard.next_seq,
253                    next_span_id: guard.next_span_id,
254                    spans: std::mem::take(&mut guard.spans),
255                    events: std::mem::take(&mut guard.events),
256                    buffer_events: std::mem::take(&mut guard.buffer_events),
257                    shells: std::mem::take(&mut guard.shells),
258                }
259            }
260        };
261
262        let mut referenced: std::collections::HashSet<String> = std::collections::HashSet::new();
263        for span in inner.spans.values() {
264            if let Some(loc) = &span.location {
265                referenced.insert(loc.file.clone());
266            }
267        }
268        for ev in &inner.events {
269            if let Some(loc) = &ev.source {
270                referenced.insert(loc.file.clone());
271            }
272        }
273
274        let mut sources: HashMap<String, String> = HashMap::new();
275        for (_, source_file) in self.sources.as_vec() {
276            let rel = source_file
277                .path
278                .strip_prefix(&*self.project_root)
279                .unwrap_or(&source_file.path)
280                .display()
281                .to_string();
282            if referenced.contains(&rel) {
283                sources.insert(rel, source_file.source.clone());
284            }
285        }
286
287        StructuredLog {
288            schema_version: super::SCHEMA_VERSION,
289            info,
290            outcome,
291            env,
292            shells: inner.shells,
293            spans: inner.spans,
294            events: inner.events,
295            buffer_events: inner.buffer_events,
296            sources,
297            artifacts,
298        }
299    }
300}
301
302/// Format a tolerance multiplier as a stable string. Whole numbers keep one
303/// decimal place (`1.0`, `2.0`), fractional values use default float
304/// formatting (`1.5`, `1.25`).
305fn format_multiplier(m: f64) -> String {
306    if m.fract() == 0.0 {
307        format!("{m:.1}")
308    } else {
309        format!("{m}")
310    }
311}
312
313#[cfg(test)]
314mod tests {
315    use std::path::PathBuf;
316
317    use super::super::span::FnCallKind;
318    use super::super::span::SpanKind;
319    use super::*;
320    use crate::observe::progress;
321
322    fn make_builder() -> (
323        StructuredLogBuilder,
324        tokio::sync::mpsc::UnboundedReceiver<ProgressEvent>,
325    ) {
326        let (tx, rx) = progress::channel();
327        let sources = relux_core::table::SharedTable::new();
328        let builder = StructuredLogBuilder::new(
329            tx,
330            Instant::now(),
331            sources,
332            Arc::from(PathBuf::from("/project").as_path()),
333        );
334        (builder, rx)
335    }
336
337    #[test]
338    fn seq_is_monotonic_across_event_and_buffer_pushes() {
339        let (b, _rx) = make_builder();
340        let test_span = b.open_span(SpanKind::Test { name: "t".into() }, None, None);
341        let id = test_span.id();
342        let s1 = b.push_event(
343            id,
344            Some("sh"),
345            Some("m"),
346            None,
347            EventKind::Send { data: "a".into() },
348        );
349        let s2 = b.push_buffer_event("sh", "m", BufferEventKind::Grew { data: "b".into() });
350        let s3 = b.push_event(
351            id,
352            Some("sh"),
353            Some("m"),
354            None,
355            EventKind::Recv { data: "c".into() },
356        );
357        assert_eq!(s1, 0);
358        assert_eq!(s2, 1);
359        assert_eq!(s3, 2);
360    }
361
362    #[test]
363    fn open_close_span_round_trips() {
364        let (b, _rx) = make_builder();
365        let span = b.open_span(SpanKind::Test { name: "t".into() }, None, None);
366        let id = span.id();
367        span.close();
368        let inner = b.inner.lock().unwrap();
369        let stored = inner.spans.get(&id).unwrap();
370        assert!(stored.end_ts.is_some());
371        assert!(stored.parent.is_none());
372    }
373
374    #[test]
375    fn span_guard_closes_on_drop() {
376        let (b, _rx) = make_builder();
377        let id = {
378            let span = b.open_span(SpanKind::Test { name: "t".into() }, None, None);
379            span.id()
380            // span drops at end of this block
381        };
382        let inner = b.inner.lock().unwrap();
383        assert!(inner.spans.get(&id).unwrap().end_ts.is_some());
384    }
385
386    #[test]
387    fn span_guard_explicit_close_then_drop_is_noop() {
388        let (b, _rx) = make_builder();
389        let span = b.open_span(SpanKind::Test { name: "t".into() }, None, None);
390        let id = span.id();
391        span.close();
392        let end_after_close = b.inner.lock().unwrap().spans.get(&id).unwrap().end_ts;
393        assert!(end_after_close.is_some());
394        // Drop happened inside `close()` (Option taken). A subsequent peek
395        // should show the same end_ts - the guard's drop didn't re-touch it
396        // because there's no guard left.
397        let end_later = b.inner.lock().unwrap().spans.get(&id).unwrap().end_ts;
398        assert_eq!(end_after_close, end_later);
399    }
400
401    #[test]
402    fn span_ids_are_unique_and_parent_preserved() {
403        let (b, _rx) = make_builder();
404        let parent = b.open_span(SpanKind::Test { name: "t".into() }, None, None);
405        let parent_id = parent.id();
406        let child = b.open_span(
407            SpanKind::ShellBlock { shell: "sh".into() },
408            Some(parent_id),
409            None,
410        );
411        let child_id = child.id();
412        assert_ne!(parent_id, child_id);
413        let inner = b.inner.lock().unwrap();
414        assert_eq!(inner.spans.get(&child_id).unwrap().parent, Some(parent_id));
415    }
416
417    #[test]
418    fn shell_glossary_records_spawn_and_terminate() {
419        let (b, _rx) = make_builder();
420        b.record_shell_spawn("test-marker-0000", "default", "/bin/bash");
421        b.record_shell_terminate("test-marker-0000");
422        let inner = b.inner.lock().unwrap();
423        let rec = inner.shells.get("test-marker-0000").unwrap();
424        assert_eq!(rec.name, "default");
425        assert_eq!(rec.command, "/bin/bash");
426        assert!(rec.terminate_ts.is_some());
427    }
428
429    #[test]
430    fn clone_shares_storage() {
431        let (b, _rx) = make_builder();
432        let b2 = b.clone();
433        let span = b.open_span(SpanKind::Test { name: "t".into() }, None, None);
434        b2.push_event(
435            span.id(),
436            Some("sh"),
437            Some("m"),
438            None,
439            EventKind::Send { data: "x".into() },
440        );
441        let inner = b.inner.lock().unwrap();
442        assert_eq!(inner.events.len(), 1);
443    }
444
445    #[test]
446    fn build_consumes_builder_and_yields_log() {
447        let (b, _rx) = make_builder();
448        let span = b.open_span(SpanKind::Test { name: "t".into() }, None, None);
449        let id = span.id();
450        b.push_event(
451            id,
452            Some("sh"),
453            Some("m"),
454            None,
455            EventKind::Send { data: "x".into() },
456        );
457        b.push_buffer_event("sh", "m", BufferEventKind::Grew { data: "y".into() });
458        span.close();
459        let log = b.build(
460            TestInfo {
461                name: "t".into(),
462                path: "t.relux".into(),
463                duration_ms: 1,
464            },
465            EnvInfo::default(),
466            TestOutcome::Pass,
467            Vec::new(),
468        );
469        assert_eq!(log.events.len(), 1);
470        assert_eq!(log.buffer_events.len(), 1);
471        assert_eq!(log.spans.len(), 1);
472        assert!(matches!(log.outcome, TestOutcome::Pass));
473    }
474
475    #[test]
476    fn emit_send_pushes_event_and_progress() {
477        let (b, mut rx) = make_builder();
478        let span = b.open_span(SpanKind::Test { name: "t".into() }, None, None);
479        b.emit_send(span.id(), "sh", "m", "hello", None);
480        let inner = b.inner.lock().unwrap();
481        assert!(matches!(
482            &inner.events.last().unwrap().kind,
483            EventKind::Send { data } if data == "hello"
484        ));
485        drop(inner);
486        assert!(matches!(rx.try_recv(), Ok(ProgressEvent::Send)));
487    }
488
489    #[test]
490    fn emit_match_done_record_pushes_event_with_supplied_buffer_seq() {
491        let (b, _rx) = make_builder();
492        let span = b.open_span(SpanKind::Test { name: "t".into() }, None, None);
493        // Simulate the buffer event that `OutputBuffer::consume_*` would
494        // have pushed atomically with the consume operation.
495        let buffer_seq = b.push_buffer_event(
496            "sh",
497            "m",
498            BufferEventKind::Matched {
499                before: "before".into(),
500                matched: "ok".into(),
501                after: "after".into(),
502            },
503        );
504        b.emit_match_done_record(
505            span.id(),
506            "sh",
507            "m",
508            "ok",
509            Duration::from_millis(5),
510            None,
511            buffer_seq,
512            None,
513        );
514        let inner = b.inner.lock().unwrap();
515        assert_eq!(inner.buffer_events.len(), 1);
516        let last = inner.events.last().unwrap();
517        match &last.kind {
518            EventKind::MatchDone {
519                buffer_seq: ev_seq, ..
520            } => assert_eq!(*ev_seq, buffer_seq),
521            _ => panic!("expected MatchDone"),
522        }
523    }
524
525    #[test]
526    fn resolve_stack_walks_parent_chain_root_to_leaf() {
527        let (b, _rx) = make_builder();
528        let test_span = b.open_span(SpanKind::Test { name: "t".into() }, None, None);
529        let test_id = test_span.id();
530        let block_span = b.open_span(
531            SpanKind::ShellBlock { shell: "sh".into() },
532            Some(test_id),
533            None,
534        );
535        let block_id = block_span.id();
536        let fn_span = b.open_span(
537            SpanKind::FnCall {
538                name: "do_thing".into(),
539                args: vec![("x".into(), "1".into())],
540                result: None,
541                callee_kind: FnCallKind::User,
542                is_pure: false,
543            },
544            Some(block_id),
545            None,
546        );
547        let fn_id = fn_span.id();
548
549        let frames = b.resolve_stack(fn_id);
550        assert_eq!(frames.len(), 3);
551        assert_eq!(frames[0].span, test_id);
552        assert_eq!(frames[0].kind, "test");
553        assert_eq!(frames[0].name.as_deref(), Some("t"));
554        assert_eq!(frames[1].span, block_id);
555        assert_eq!(frames[1].kind, "shell-block");
556        assert_eq!(frames[1].name.as_deref(), Some("sh"));
557        assert_eq!(frames[2].span, fn_id);
558        assert_eq!(frames[2].kind, "fn-call");
559        assert_eq!(frames[2].name.as_deref(), Some("do_thing"));
560        assert_eq!(frames[2].args, vec![("x".into(), "1".into())]);
561    }
562
563    #[test]
564    fn resolve_stack_renders_nested_pure_fn_chain_top_down() {
565        // A pure-match failure reached through nested pure fns resolves
566        // its call chain from the innermost still-open pure-fn span. The
567        // frames must be outermost-first with kind `pure-fn-call` for
568        // every pure-fn frame; the impure shell frame keeps `shell-block`.
569        let (b, _rx) = make_builder();
570        let test_span = b.open_span(SpanKind::Test { name: "t".into() }, None, None);
571        let test_id = test_span.id();
572        let block_span = b.open_span(
573            SpanKind::ShellBlock { shell: "s".into() },
574            Some(test_id),
575            None,
576        );
577        let block_id = block_span.id();
578        let outer = b.open_span(
579            SpanKind::FnCall {
580                name: "outer".into(),
581                args: vec![("s".into(), "actual".into())],
582                result: None,
583                callee_kind: FnCallKind::User,
584                is_pure: true,
585            },
586            Some(block_id),
587            None,
588        );
589        let outer_id = outer.id();
590        let inner = b.open_span(
591            SpanKind::FnCall {
592                name: "inner".into(),
593                args: vec![("s".into(), "actual".into())],
594                result: None,
595                callee_kind: FnCallKind::User,
596                is_pure: true,
597            },
598            Some(outer_id),
599            None,
600        );
601        let inner_id = inner.id();
602
603        // Resolve from the innermost (deepest) open pure-fn span.
604        let frames = b.resolve_stack(inner_id);
605        let rendered: Vec<(&str, Option<&str>)> = frames
606            .iter()
607            .map(|f| (f.kind.as_str(), f.name.as_deref()))
608            .collect();
609        assert_eq!(
610            rendered,
611            vec![
612                ("test", Some("t")),
613                ("shell-block", Some("s")),
614                ("pure-fn-call", Some("outer")),
615                ("pure-fn-call", Some("inner")),
616            ]
617        );
618        assert_eq!(frames[2].span, outer_id);
619        assert_eq!(frames[3].span, inner_id);
620    }
621
622    #[test]
623    fn fn_call_round_trips_callee_kind_and_is_pure() {
624        let (b, _rx) = make_builder();
625        let test_span = b.open_span(SpanKind::Test { name: "t".into() }, None, None);
626        let test_id = test_span.id();
627        let fn_span = b.open_span(
628            SpanKind::FnCall {
629                name: "trim".into(),
630                args: vec![("$0".into(), "hi".into())],
631                result: None,
632                callee_kind: FnCallKind::Bif,
633                is_pure: true,
634            },
635            Some(test_id),
636            None,
637        );
638        let fn_id = fn_span.id();
639        fn_span.close();
640        test_span.close();
641
642        let inner = b.inner.lock().unwrap();
643        let stored = inner.spans.get(&fn_id).unwrap();
644        match &stored.kind {
645            SpanKind::FnCall {
646                callee_kind,
647                is_pure,
648                ..
649            } => {
650                assert_eq!(*callee_kind, FnCallKind::Bif);
651                assert!(*is_pure);
652            }
653            _ => panic!("expected FnCall"),
654        }
655    }
656
657    #[test]
658    fn current_seq_reflects_latest_emission() {
659        let (b, _rx) = make_builder();
660        assert_eq!(b.current_seq(), 0);
661        let span = b.open_span(SpanKind::Test { name: "t".into() }, None, None);
662        b.push_event(
663            span.id(),
664            Some("sh"),
665            Some("m"),
666            None,
667            EventKind::Send { data: "a".into() },
668        );
669        assert_eq!(b.current_seq(), 0);
670        b.push_buffer_event("sh", "m", BufferEventKind::Grew { data: "b".into() });
671        assert_eq!(b.current_seq(), 1);
672    }
673
674    #[test]
675    fn round_trip_serde_json() {
676        let (b, _rx) = make_builder();
677        let span = b.open_span(SpanKind::Test { name: "t".into() }, None, None);
678        let buffer_seq = b.push_buffer_event(
679            "sh",
680            "m",
681            BufferEventKind::Matched {
682                before: "".into(),
683                matched: "ok".into(),
684                after: "".into(),
685            },
686        );
687        b.emit_match_done_record(
688            span.id(),
689            "sh",
690            "m",
691            "ok",
692            Duration::from_millis(1),
693            None,
694            buffer_seq,
695            None,
696        );
697        span.close();
698        let log = b.build(
699            TestInfo {
700                name: "t".into(),
701                path: "t.relux".into(),
702                duration_ms: 1,
703            },
704            EnvInfo::default(),
705            TestOutcome::Pass,
706            Vec::new(),
707        );
708        let json = serde_json::to_string(&log).unwrap();
709        let back: StructuredLog = serde_json::from_str(&json).unwrap();
710        assert_eq!(back.events.len(), log.events.len());
711        assert_eq!(back.buffer_events.len(), log.buffer_events.len());
712        assert_eq!(back.spans.len(), log.spans.len());
713    }
714
715    #[test]
716    fn push_event_records_source_when_irspan_provided() {
717        use relux_core::Span as CoreSpan;
718        use relux_core::diagnostics::IrSpan;
719        use relux_core::table::FileId;
720
721        let (builder, _rx) = make_builder();
722        let path = PathBuf::from("/project/t.relux");
723        let file_id = FileId::new(path.clone());
724        let src = relux_core::table::SourceFile::new(path, "abcdef\n".into());
725        builder.sources_for_tests().insert(file_id.clone(), src);
726
727        let span_guard = builder.open_span(SpanKind::Test { name: "t".into() }, None, None);
728        let ir = IrSpan::new(file_id, CoreSpan::new(1, 4));
729        builder.push_event(
730            span_guard.id(),
731            None,
732            None,
733            Some(&ir),
734            EventKind::Annotate { text: "hi".into() },
735        );
736        drop(span_guard);
737
738        let log = builder.build(
739            TestInfo {
740                name: "t".into(),
741                path: "t".into(),
742                duration_ms: 0,
743            },
744            EnvInfo::default(),
745            TestOutcome::Pass,
746            Vec::new(),
747        );
748        let ev = log
749            .events
750            .iter()
751            .find(|e| matches!(e.kind, EventKind::Annotate { .. }))
752            .unwrap();
753        let src = ev.source.as_ref().expect("source present");
754        assert_eq!(src.start, 1);
755        assert_eq!(src.end, 4);
756    }
757
758    #[test]
759    fn build_populates_sources_for_referenced_files_only() {
760        use relux_core::Span as CoreSpan;
761        use relux_core::diagnostics::IrSpan;
762        use relux_core::table::FileId;
763
764        let (builder, _rx) = make_builder();
765        let path_used = PathBuf::from("/project/used.relux");
766        let path_unused = PathBuf::from("/project/unused.relux");
767        let fid_used = FileId::new(path_used.clone());
768        let fid_unused = FileId::new(path_unused.clone());
769        builder.sources_for_tests().insert(
770            fid_used.clone(),
771            relux_core::table::SourceFile::new(path_used, "u-content\n".into()),
772        );
773        builder.sources_for_tests().insert(
774            fid_unused,
775            relux_core::table::SourceFile::new(path_unused, "x-content\n".into()),
776        );
777
778        let test_span = builder.open_span(SpanKind::Test { name: "t".into() }, None, None);
779        let ir = IrSpan::new(fid_used, CoreSpan::new(0, 1));
780        builder.emit_annotate(test_span.id(), "sh", "m", "a", Some(&ir));
781        drop(test_span);
782
783        let log = builder.build(
784            TestInfo {
785                name: "t".into(),
786                path: "t".into(),
787                duration_ms: 0,
788            },
789            EnvInfo::default(),
790            TestOutcome::Pass,
791            Vec::new(),
792        );
793
794        assert_eq!(log.sources.len(), 1, "only referenced files in sources");
795        assert_eq!(
796            log.sources.get("used.relux"),
797            Some(&"u-content\n".to_string())
798        );
799        assert!(!log.sources.contains_key("unused.relux"));
800    }
801
802    #[test]
803    fn emit_send_records_source_from_irspan() {
804        use relux_core::Span as CoreSpan;
805        use relux_core::diagnostics::IrSpan;
806        use relux_core::table::FileId;
807
808        let (builder, _rx) = make_builder();
809        let path = PathBuf::from("/project/t.relux");
810        let file_id = FileId::new(path.clone());
811        let src = relux_core::table::SourceFile::new(path, "send hello\n".into());
812        builder.sources_for_tests().insert(file_id.clone(), src);
813
814        let test_span = builder.open_span(SpanKind::Test { name: "t".into() }, None, None);
815        let ir = IrSpan::new(file_id, CoreSpan::new(0, 4));
816        builder.emit_send(test_span.id(), "sh", "m", "hello", Some(&ir));
817        drop(test_span);
818
819        let log = builder.build(
820            TestInfo {
821                name: "t".into(),
822                path: "t".into(),
823                duration_ms: 0,
824            },
825            EnvInfo::default(),
826            TestOutcome::Pass,
827            Vec::new(),
828        );
829        let ev = log
830            .events
831            .iter()
832            .find(|e| matches!(e.kind, EventKind::Send { .. }))
833            .unwrap();
834        let s = ev.source.as_ref().expect("source set");
835        assert_eq!(s.start, 0);
836        assert_eq!(s.end, 4);
837    }
838
839    #[test]
840    fn source_location_carries_byte_range() {
841        use relux_core::Span as CoreSpan;
842        use relux_core::diagnostics::IrSpan;
843        use relux_core::table::FileId;
844
845        let (builder, _rx) = make_builder();
846        let path = PathBuf::from("/project/lib/x.relux");
847        let file_id = FileId::new(path.clone());
848        let src = relux_core::table::SourceFile::new(path, "line 1\nline 2\nline 3\n".into());
849        builder.sources_for_tests().insert(file_id.clone(), src);
850
851        let ir = IrSpan::new(file_id, CoreSpan::new(7, 13));
852        let loc = builder.resolve_location_for_tests(&ir).expect("resolve");
853        assert_eq!(loc.file, "lib/x.relux");
854        assert_eq!(loc.line, 2);
855        assert_eq!(loc.start, 7);
856        assert_eq!(loc.end, 13);
857    }
858
859    #[test]
860    fn test_outcome_skip_serde_round_trip() {
861        use super::super::skip::SkipRecord;
862        use super::super::span::MarkerEvalDetail;
863        use super::super::span::MarkerEvalKind;
864
865        let original = TestOutcome::Skip(SkipRecord {
866            span: 42u64,
867            event_seq: 7u64,
868            marker_kind: MarkerEvalKind::Skip,
869            evaluation: MarkerEvalDetail::Unconditional,
870            location: None,
871        });
872        let json = serde_json::to_string(&original).unwrap();
873        assert!(
874            json.contains("\"kind\":\"skip\""),
875            "expected `\"kind\":\"skip\"` in JSON, got: {json}"
876        );
877        let parsed: TestOutcome = serde_json::from_str(&json).unwrap();
878        match parsed {
879            TestOutcome::Skip(rec) => {
880                assert_eq!(rec.span, 42u64);
881                assert_eq!(rec.event_seq, 7u64);
882            }
883            other => panic!("expected TestOutcome::Skip, got {other:?}"),
884        }
885    }
886
887    #[test]
888    fn open_multimatch_span_attaches_to_parent_and_uses_shell() {
889        let (b, _rx) = make_builder();
890        let parent = b.open_span(SpanKind::Test { name: "t".into() }, None, None);
891        let parent_id = parent.id();
892        let mm = b.open_multimatch_span(parent_id, "default", None);
893        let mm_id = mm.id();
894        let inner = b.inner.lock().unwrap();
895        let stored = inner.spans.get(&mm_id).unwrap();
896        assert_eq!(stored.parent, Some(parent_id));
897        match &stored.kind {
898            SpanKind::MultiMatch { shell } => assert_eq!(shell, "default"),
899            _ => panic!("expected MultiMatch span"),
900        }
901    }
902
903    #[test]
904    fn emit_multimatch_start_pushes_event_with_patterns_and_effective() {
905        use crate::observe::structured::event::MultiMatchPattern;
906        use relux_ir::IrTimeout;
907        let (b, _rx) = make_builder();
908        let span = b.open_span(SpanKind::Test { name: "t".into() }, None, None);
909        let effective = IrTimeout::tolerance(Duration::from_secs(5));
910        let patterns = vec![
911            MultiMatchPattern {
912                pattern: "^ok$".into(),
913                is_regex: true,
914            },
915            MultiMatchPattern {
916                pattern: "done".into(),
917                is_regex: false,
918            },
919        ];
920        b.emit_multimatch_start(span.id(), "sh", "m", &patterns, &effective, None);
921        let inner = b.inner.lock().unwrap();
922        match &inner.events.last().unwrap().kind {
923            EventKind::MultiMatchStart { patterns: p, .. } => {
924                assert_eq!(p.len(), 2);
925                assert_eq!(p[0].pattern, "^ok$");
926                assert!(p[0].is_regex);
927                assert!(!p[1].is_regex);
928            }
929            other => panic!("expected MultiMatchStart, got {other:?}"),
930        }
931    }
932
933    #[test]
934    fn emit_multimatch_pattern_done_records_index_elapsed_and_buffer_seq() {
935        let (b, _rx) = make_builder();
936        let span = b.open_span(SpanKind::Test { name: "t".into() }, None, None);
937        let buffer_seq = b.push_buffer_event(
938            "sh",
939            "m",
940            BufferEventKind::Matched {
941                before: "".into(),
942                matched: "ok".into(),
943                after: "".into(),
944            },
945        );
946        b.emit_multimatch_pattern_done(
947            span.id(),
948            "sh",
949            "m",
950            1,
951            Duration::from_millis(7),
952            buffer_seq,
953            None,
954        );
955        let inner = b.inner.lock().unwrap();
956        match &inner.events.last().unwrap().kind {
957            EventKind::MultiMatchPatternDone {
958                index,
959                buffer_seq: ev_seq,
960                ..
961            } => {
962                assert_eq!(*index, 1);
963                assert_eq!(*ev_seq, buffer_seq);
964            }
965            other => panic!("expected MultiMatchPatternDone, got {other:?}"),
966        }
967    }
968
969    #[test]
970    fn emit_multimatch_done_records_advance_to_seq() {
971        let (b, _rx) = make_builder();
972        let span = b.open_span(SpanKind::Test { name: "t".into() }, None, None);
973        let buffer_seq = b.push_buffer_event(
974            "sh",
975            "m",
976            BufferEventKind::Matched {
977                before: "".into(),
978                matched: "longest".into(),
979                after: "".into(),
980            },
981        );
982        b.emit_multimatch_done(span.id(), "sh", "m", buffer_seq, None);
983        let inner = b.inner.lock().unwrap();
984        match &inner.events.last().unwrap().kind {
985            EventKind::MultiMatchDone { advance_to } => assert_eq!(*advance_to, buffer_seq),
986            other => panic!("expected MultiMatchDone, got {other:?}"),
987        }
988    }
989
990    #[test]
991    fn emit_multimatch_timeout_records_unmatched_indices() {
992        let (b, _rx) = make_builder();
993        let span = b.open_span(SpanKind::Test { name: "t".into() }, None, None);
994        b.emit_multimatch_timeout(span.id(), "sh", "m", &[0, 2], None);
995        let inner = b.inner.lock().unwrap();
996        match &inner.events.last().unwrap().kind {
997            EventKind::MultiMatchTimeout { unmatched } => {
998                assert_eq!(unmatched, &vec![0usize, 2]);
999            }
1000            other => panic!("expected MultiMatchTimeout, got {other:?}"),
1001        }
1002    }
1003
1004    #[test]
1005    fn failure_record_translates_multimatch() {
1006        use crate::observe::structured::event::MultiMatchPattern;
1007        use crate::observe::structured::failure::FailureRecord;
1008        use crate::report::result::Failure;
1009        use crate::report::result::FailureContext;
1010        use relux_core::diagnostics::IrSpan;
1011        use relux_ir::IrTimeout;
1012
1013        let (b, _rx) = make_builder();
1014        let f = Failure::MultiMatch {
1015            shell: "default".into(),
1016            patterns: vec![
1017                MultiMatchPattern {
1018                    pattern: "^a$".into(),
1019                    is_regex: true,
1020                },
1021                MultiMatchPattern {
1022                    pattern: "b".into(),
1023                    is_regex: false,
1024                },
1025            ],
1026            matched: vec![1],
1027            span: IrSpan::synthetic(),
1028            effective: Box::new(IrTimeout::tolerance(Duration::from_secs(5))),
1029            context: FailureContext::pre_vm(),
1030        };
1031        let rec = b.failure_record(&f);
1032        match rec {
1033            FailureRecord::MultiMatch {
1034                shell,
1035                patterns,
1036                matched,
1037                ..
1038            } => {
1039                assert_eq!(shell, "default");
1040                assert_eq!(patterns.len(), 2);
1041                assert_eq!(matched, vec![1]);
1042            }
1043            other => panic!("expected MultiMatch, got {other:?}"),
1044        }
1045    }
1046}
relux_runtime/observe/structured/builder.rs

relux_runtime/observe/structured/
builder.rs
