Skip to main content

llm_browser_testkit/
reporting.rs

1//! Report sinks: console, NDJSON, JUnit XML, GitHub annotations, Perfetto trace.
2//!
3//! The [`Reporter`] is the single place test-run output flows through. The
4//! runner emits [`TestEvent`]s; the reporter fans them out to every enabled
5//! sink:
6//!
7//! - **Console** — level-filtered, optionally colorized, ASCII-safe lines so
8//!   output renders in CI logs and dumb terminals. Failures always show full
9//!   diagnostics; debug events (LLM calls, selector resolution) are hidden
10//!   unless `-v`/`-vv` is passed.
11//! - **NDJSON** (`--log-file`) — one JSON object per event, each with a `ts`
12//!   epoch-millisecond field and a `type` discriminator. Machine-readable
13//!   and lossless apart from configured/observed secret redaction:
14//!   `jq '. | select(.type == "step_finished" and
15//!   .status == "failed")' run.jsonl` works out of the box.
16//! - **JUnit XML** (`--junit`) — one `<testcase>` per test with `<failure>`
17//!   entries per failed step, for Jenkins/GitLab/Azure/TeamCity.
18//! - **GitHub** — `::error::` workflow commands on failed steps plus a
19//!   `GITHUB_STEP_SUMMARY` markdown file, when running in Actions.
20//! - **Perfetto trace** (`--trace`) — a Chrome Trace Event Format file with
21//!   test/step/LLM-call spans, openable in `ui.perfetto.dev`.
22
23use std::fs::File;
24use std::io::{self, BufWriter, IsTerminal, Write};
25use std::path::{Path, PathBuf};
26use std::sync::Mutex;
27use std::time::{Instant, SystemTime, UNIX_EPOCH};
28
29use serde_json::json;
30
31use crate::costs::UsageSnapshot;
32use crate::events::{StepStatus, TestEvent};
33use crate::redact::Redactor;
34
35/// Console verbosity level. Higher = more output.
36#[derive(Debug, Clone, Copy, PartialEq, Eq, PartialOrd, Ord)]
37pub enum Level {
38    /// Only failures.
39    Error = 0,
40    /// Failures, warnings, and the run summary.
41    Warn = 1,
42    /// Default: plus test and step results.
43    Info = 2,
44    /// Plus LLM call details and step starts.
45    Debug = 3,
46    /// Everything.
47    Trace = 4,
48}
49
50impl Level {
51    /// Maps `-q`/`-v` flag counts to a level. Quiet wins over verbose.
52    #[must_use]
53    pub const fn from_flags(quiet: u8, verbose: u8) -> Self {
54        match (quiet, verbose) {
55            (0, 0) => Self::Info,
56            (0, 1) => Self::Debug,
57            (0, _) => Self::Trace,
58            (1, _) => Self::Warn,
59            _ => Self::Error,
60        }
61    }
62
63    fn shows(self, level: Self) -> bool {
64        self >= level
65    }
66}
67
68#[allow(clippy::derivable_impls)]
69impl Default for Level {
70    fn default() -> Self {
71        Self::Info
72    }
73}
74
75/// Color output mode for the console sink.
76#[derive(Debug, Clone, Copy, Default, PartialEq, Eq)]
77pub enum ColorMode {
78    /// Use colors when stderr is a TTY and `NO_COLOR` is unset.
79    #[default]
80    Auto,
81    /// Always emit ANSI colors.
82    Always,
83    /// Never emit ANSI colors.
84    Never,
85}
86
87/// Decides whether the console sink should emit ANSI codes.
88#[must_use]
89pub fn detect_color(mode: ColorMode) -> bool {
90    match mode {
91        ColorMode::Always => true,
92        ColorMode::Never => false,
93        ColorMode::Auto => std::env::var_os("NO_COLOR").is_none() && io::stderr().is_terminal(),
94    }
95}
96
97/// Minimal ANSI palette; every method degrades to plain text when disabled.
98#[derive(Clone, Copy)]
99struct Palette {
100    enabled: bool,
101}
102
103impl Palette {
104    fn paint(self, s: &str, code: &str) -> String {
105        if self.enabled {
106            format!("\x1b[{code}m{s}\x1b[0m")
107        } else {
108            s.to_owned()
109        }
110    }
111
112    fn green(self, s: &str) -> String {
113        self.paint(s, "32")
114    }
115
116    fn red(self, s: &str) -> String {
117        self.paint(s, "31")
118    }
119
120    fn yellow(self, s: &str) -> String {
121        self.paint(s, "33")
122    }
123
124    fn cyan(self, s: &str) -> String {
125        self.paint(s, "36")
126    }
127
128    fn dim(self, s: &str) -> String {
129        self.paint(s, "2")
130    }
131}
132
133/// Aggregated run counts captured from the final `RunFinished` event.
134#[derive(Clone)]
135struct RunSummary {
136    tests_passed: u32,
137    tests_failed: u32,
138    steps_passed: u32,
139    steps_failed: u32,
140    steps_skipped: u32,
141    total_cost: f64,
142    total_tokens: u64,
143    total_input_tokens: u64,
144    total_output_tokens: u64,
145    total_cached_input_tokens: u64,
146    total_cache_creation_input_tokens: u64,
147    models: Vec<String>,
148    total_calls: u64,
149}
150
151/// One test's `JUnit` result, accumulated while events stream in.
152struct JunitCase {
153    name: String,
154    duration_ms: u64,
155    failures: Vec<String>,
156    skipped: u32,
157}
158
159impl JunitCase {
160    const fn new(name: String) -> Self {
161        Self {
162            name,
163            duration_ms: 0,
164            failures: Vec::new(),
165            skipped: 0,
166        }
167    }
168}
169
170/// An open (unfinished) span in the Perfetto trace.
171struct OpenSpan {
172    kind: u8,
173    name: String,
174    start: Instant,
175}
176
177/// Mutable reporter state, serialized behind a mutex so the reporter can be
178/// shared between the runner and the CLI.
179struct ReporterState {
180    jsonl: Option<BufWriter<File>>,
181    junit_path: Option<PathBuf>,
182    junit_cases: Vec<JunitCase>,
183    trace_path: Option<PathBuf>,
184    trace_events: Vec<serde_json::Value>,
185    trace_open: Vec<OpenSpan>,
186    trace_base: Option<Instant>,
187}
188
189/// Locks a mutex, recovering from a poisoned state instead of panicking.
190fn lock<T>(mutex: &Mutex<T>) -> std::sync::MutexGuard<'_, T> {
191    mutex
192        .lock()
193        .unwrap_or_else(std::sync::PoisonError::into_inner)
194}
195
196/// Fans run events out to every enabled sink.
197pub struct Reporter {
198    level: Level,
199    palette: Palette,
200    github_annotations: bool,
201    github_summary: Mutex<Option<RunSummary>>,
202    redactor: Mutex<Redactor>,
203    state: Mutex<ReporterState>,
204}
205
206impl Default for Reporter {
207    fn default() -> Self {
208        Self::new(Level::Info, ColorMode::Auto, None, None, None, false)
209            .expect("default reporter has no files to open")
210    }
211}
212
213impl Reporter {
214    /// Creates a reporter with the given console settings and optional
215    /// output files. Fails if a log/JUnit/trace file cannot be opened.
216    ///
217    /// # Errors
218    ///
219    /// Returns an io error when any configured output file cannot be created.
220    #[allow(clippy::too_many_arguments)]
221    pub fn new(
222        level: Level,
223        color: ColorMode,
224        log_file: Option<&Path>,
225        junit_file: Option<&Path>,
226        trace_file: Option<&Path>,
227        github_annotations: bool,
228    ) -> io::Result<Self> {
229        let jsonl = match log_file {
230            Some(path) => Some(BufWriter::new(File::create(path)?)),
231            None => None,
232        };
233        Ok(Self {
234            level,
235            palette: Palette {
236                enabled: detect_color(color),
237            },
238            github_annotations,
239            github_summary: Mutex::new(None),
240            redactor: Mutex::new(Redactor::new()),
241            state: Mutex::new(ReporterState {
242                jsonl,
243                junit_path: junit_file.map(Path::to_path_buf),
244                junit_cases: Vec::new(),
245                trace_path: trace_file.map(Path::to_path_buf),
246                trace_events: Vec::new(),
247                trace_open: Vec::new(),
248                trace_base: None,
249            }),
250        })
251    }
252
253    /// Emits one event to every enabled sink. The event is cloned and
254    /// redacted (configured + runtime-observed secrets) before any sink
255    /// sees it.
256    ///
257    /// # Errors
258    ///
259    /// Returns an io error when writing the NDJSON log file fails.
260    pub fn emit(&self, event: &TestEvent) -> io::Result<()> {
261        let event = lock(&self.redactor).redact_event(event);
262        let (level, text) = format_event(&event, self.palette);
263        if self.level.shows(level) {
264            let _ = writeln!(io::stderr().lock(), "{text}");
265        }
266        self.write_jsonl(&event)?;
267        self.track_trace(&event);
268        self.track_junit(&event);
269        self.track_github(&event);
270        Ok(())
271    }
272
273    /// Registers a literal value redacted from every report sink. Explicit
274    /// extras always apply, regardless of length. Append-only: config-
275    /// derived secrets registered later coexist with these.
276    pub fn add_redaction_secret(&self, value: &str) {
277        lock(&self.redactor).add_secret(value, 0);
278    }
279
280    /// Registers config-derived secrets (with the default minimum length)
281    /// redacted from every report sink.
282    pub fn add_redaction_secrets(&self, values: impl IntoIterator<Item = String>) {
283        lock(&self.redactor).add_secret_values(values);
284    }
285
286    /// Writes a plain informational line if the current level allows it.
287    pub fn info(&self, msg: impl AsRef<str>) {
288        self.line(Level::Info, msg.as_ref());
289    }
290
291    /// Writes a debug line if `-v` (or higher) was passed.
292    pub fn debug(&self, msg: impl AsRef<str>) {
293        self.line(Level::Debug, msg.as_ref());
294    }
295
296    /// Writes a warning line; always shown unless `-qq` was passed.
297    pub fn warn(&self, msg: impl AsRef<str>) {
298        self.line(Level::Warn, &format!("  ! {}", msg.as_ref()));
299    }
300
301    /// Writes an error line; always shown.
302    pub fn error(&self, msg: impl AsRef<str>) {
303        let text = self.palette.red(&format!("  ✗ {}", msg.as_ref()));
304        self.line(Level::Error, &text);
305    }
306
307    fn line(&self, level: Level, text: &str) {
308        if self.level.shows(level) {
309            let text = lock(&self.redactor).redact(text);
310            let _ = writeln!(io::stderr().lock(), "{text}");
311        }
312    }
313
314    /// Flushes the `NDJSON` log and writes `JUnit`, trace, and `GitHub`
315    /// summary files. Call once after the run finishes.
316    ///
317    /// # Errors
318    ///
319    /// Returns an io error when flushing the log or writing any report file
320    /// fails.
321    #[allow(clippy::significant_drop_tightening)]
322    pub fn finish(&self) -> io::Result<()> {
323        let mut state = lock(&self.state);
324        if let Some(writer) = state.jsonl.as_mut() {
325            writer.flush()?;
326        }
327        Self::write_junit(&state)?;
328        Self::write_trace(&state)?;
329        self.write_github_summary();
330        Ok(())
331    }
332
333    #[allow(clippy::significant_drop_tightening)]
334    fn write_jsonl(&self, event: &TestEvent) -> io::Result<()> {
335        let mut state = lock(&self.state);
336        let Some(writer) = state.jsonl.as_mut() else {
337            return Ok(());
338        };
339        let mut value = serde_json::to_value(event).map_err(io::Error::other)?;
340        if let Some(obj) = value.as_object_mut() {
341            obj.insert("ts".to_owned(), json!(now_ms()));
342        }
343        serde_json::to_writer(&mut *writer, &value).map_err(io::Error::other)?;
344        writer.write_all(b"\n")?;
345        Ok(())
346    }
347
348    // ── Perfetto trace sink ──────────────────────────────────────────────
349
350    #[allow(clippy::significant_drop_tightening)]
351    fn track_trace(&self, event: &TestEvent) {
352        let mut state = lock(&self.state);
353        if state.trace_path.is_none() {
354            return;
355        }
356        state.trace_base.get_or_insert_with(Instant::now);
357        match event {
358            TestEvent::TestStarted { test } => {
359                state.trace_open.push(OpenSpan {
360                    kind: 0,
361                    name: test.clone(),
362                    start: Instant::now(),
363                });
364            }
365            TestEvent::StepStarted { label, .. } => {
366                state.trace_open.push(OpenSpan {
367                    kind: 1,
368                    name: label.clone(),
369                    start: Instant::now(),
370                });
371            }
372            TestEvent::LlmCallStarted {
373                endpoint,
374                model,
375                purpose,
376                ..
377            } => {
378                state.trace_open.push(OpenSpan {
379                    kind: 2,
380                    name: format!("llm {purpose}: {endpoint} ({model})"),
381                    start: Instant::now(),
382                });
383            }
384            TestEvent::TestFinished {
385                test,
386                passed,
387                failed,
388                skipped,
389                ..
390            } => {
391                close_span(
392                    &mut state,
393                    0,
394                    &json!({"test": test, "passed": passed, "failed": failed, "skipped": skipped}),
395                );
396            }
397            TestEvent::StepFinished { status, .. } => {
398                close_span(&mut state, 1, &json!({"status": status}));
399            }
400            TestEvent::LlmCallFinished {
401                ok,
402                input_tokens,
403                output_tokens,
404                cost,
405                error,
406                ..
407            } => {
408                let args = json!({"ok": ok, "in_tokens": input_tokens, "out_tokens": output_tokens, "cost": cost, "error": error});
409                close_span(&mut state, 2, &args);
410            }
411            _ => {}
412        }
413    }
414
415    fn write_trace(state: &ReporterState) -> io::Result<()> {
416        let Some(path) = state.trace_path.as_deref() else {
417            return Ok(());
418        };
419        let doc = json!({
420            "traceEvents": state.trace_events,
421            "displayTimeUnit": "ms",
422        });
423        let mut writer = BufWriter::new(File::create(path)?);
424        serde_json::to_writer_pretty(&mut writer, &doc).map_err(io::Error::other)?;
425        writer.write_all(b"\n")?;
426        writer.flush()
427    }
428
429    // ── JUnit sink ───────────────────────────────────────────────────────
430
431    #[allow(clippy::significant_drop_tightening)]
432    fn track_junit(&self, event: &TestEvent) {
433        let mut state = lock(&self.state);
434        if state.junit_path.is_none() {
435            return;
436        }
437        match event {
438            TestEvent::StepFinished {
439                test,
440                label,
441                status,
442                message,
443                diagnostics,
444                screenshot,
445                ..
446            } => {
447                let case = locate_case(&mut state, test);
448                match status {
449                    StepStatus::Failed => {
450                        let mut text = format!("{label}: {message}");
451                        if let Some(diag) = diagnostics {
452                            text.push('\n');
453                            text.push_str(diag);
454                        }
455                        if let Some(shot) = screenshot {
456                            use std::fmt::Write as _;
457                            let _ = write!(text, "\nscreenshot: {shot}");
458                        }
459                        case.failures.push(text);
460                    }
461                    StepStatus::Skipped => case.skipped += 1,
462                    StepStatus::Passed => {}
463                }
464            }
465            TestEvent::TestFinished {
466                test, duration_ms, ..
467            } => {
468                let case = locate_case(&mut state, test);
469                case.duration_ms = *duration_ms;
470            }
471            _ => {}
472        }
473    }
474
475    fn write_junit(state: &ReporterState) -> io::Result<()> {
476        let Some(path) = state.junit_path.as_deref() else {
477            return Ok(());
478        };
479        write_junit_xml(&state.junit_cases, "llm-browser-testkit", path)
480    }
481
482    // ── GitHub sink ──────────────────────────────────────────────────────
483
484    fn track_github(&self, event: &TestEvent) {
485        if !self.github_annotations {
486            return;
487        }
488        match event {
489            TestEvent::StepFinished {
490                test,
491                label,
492                status,
493                message,
494                screenshot,
495                ..
496            } => {
497                if *status == StepStatus::Failed {
498                    let mut props = Vec::new();
499                    if let Some(shot) = screenshot {
500                        props.push(format!("file={}", escape_property(shot)));
501                    }
502                    props.push(format!(
503                        "title={}:{}",
504                        escape_property(test),
505                        escape_property(label)
506                    ));
507                    let _ = writeln!(
508                        io::stdout().lock(),
509                        "::error {}::{}",
510                        props.join(","),
511                        escape_data(message)
512                    );
513                }
514            }
515            TestEvent::RunFinished {
516                tests_passed,
517                tests_failed,
518                steps_passed,
519                steps_failed,
520                steps_skipped,
521                total_cost,
522                total_tokens,
523                total_input_tokens,
524                total_output_tokens,
525                total_cached_input_tokens,
526                total_cache_creation_input_tokens,
527                models,
528                total_calls,
529            } => {
530                *lock(&self.github_summary) = Some(RunSummary {
531                    tests_passed: *tests_passed,
532                    tests_failed: *tests_failed,
533                    steps_passed: *steps_passed,
534                    steps_failed: *steps_failed,
535                    steps_skipped: *steps_skipped,
536                    total_cost: *total_cost,
537                    total_tokens: *total_tokens,
538                    total_input_tokens: *total_input_tokens,
539                    total_output_tokens: *total_output_tokens,
540                    total_cached_input_tokens: *total_cached_input_tokens,
541                    total_cache_creation_input_tokens: *total_cache_creation_input_tokens,
542                    models: models.clone(),
543                    total_calls: *total_calls,
544                });
545            }
546            _ => {}
547        }
548    }
549
550    #[allow(clippy::significant_drop_tightening)]
551    fn write_github_summary(&self) {
552        let summary = lock(&self.github_summary);
553        let Some(summary) = summary.as_ref() else {
554            return;
555        };
556        let Some(path) = std::env::var_os("GITHUB_STEP_SUMMARY") else {
557            return;
558        };
559        let Ok(mut file) = File::options().append(true).open(path) else {
560            return;
561        };
562        let verdict = if summary.tests_failed == 0 {
563            "✅ all tests passed"
564        } else {
565            "❌ some tests failed"
566        };
567        let _ = writeln!(file, "## llm-browser-testkit run: {verdict}\n");
568        let _ = writeln!(
569            file,
570            "- tests: {} passed, {} failed",
571            summary.tests_passed, summary.tests_failed
572        );
573        let _ = writeln!(
574            file,
575            "- steps: {} passed, {} failed, {} skipped",
576            summary.steps_passed, summary.steps_failed, summary.steps_skipped
577        );
578        let _ = writeln!(
579            file,
580            "- cost: ${:.4} | tokens: {} ({} in / {} out, {} cached, {} cache write) | calls: {}",
581            summary.total_cost,
582            summary.total_tokens,
583            summary.total_input_tokens,
584            summary.total_output_tokens,
585            summary.total_cached_input_tokens,
586            summary.total_cache_creation_input_tokens,
587            summary.total_calls
588        );
589        if !summary.models.is_empty() {
590            let _ = writeln!(file, "- models: {}", summary.models.join(", "));
591        }
592    }
593}
594
595/// Finds the `JUnit` case for a test, creating it on first sight.
596fn locate_case<'a>(state: &'a mut ReporterState, test: &str) -> &'a mut JunitCase {
597    let idx = state
598        .junit_cases
599        .iter()
600        .rposition(|c| c.name == test)
601        .unwrap_or_else(|| {
602            state.junit_cases.push(JunitCase::new(test.to_owned()));
603            state.junit_cases.len() - 1
604        });
605    &mut state.junit_cases[idx]
606}
607
608/// Closes the most recent open span of the given kind into a complete trace
609/// event (`ph: "X"`).
610#[allow(clippy::cast_possible_truncation)]
611fn close_span(state: &mut ReporterState, kind: u8, args: &serde_json::Value) {
612    let Some(idx) = state.trace_open.iter().rposition(|s| s.kind == kind) else {
613        return;
614    };
615    let span = state.trace_open.remove(idx);
616    let base = state
617        .trace_base
618        .expect("trace base set before any span opens");
619    let start_ts = if span.start >= base {
620        span.start.duration_since(base).as_micros() as u64
621    } else {
622        0
623    };
624    let dur_us = span.start.elapsed().as_micros() as u64;
625    let cat = match kind {
626        0 => "test",
627        1 => "step",
628        _ => "llm",
629    };
630    state.trace_events.push(json!({
631        "name": span.name,
632        "ph": "X",
633        "ts": start_ts,
634        "dur": dur_us,
635        "pid": 1,
636        "tid": 1,
637        "cat": cat,
638        "args": args,
639    }));
640}
641
642/// Serializes one event into its console text and required level.
643#[must_use]
644#[allow(clippy::too_many_lines)]
645fn format_event(event: &TestEvent, palette: Palette) -> (Level, String) {
646    match event {
647        TestEvent::RunStarted { total_tests } => {
648            (Level::Debug, format!("run started: {total_tests} test(s)"))
649        }
650        TestEvent::TestStarted { test } => (Level::Info, palette.cyan(&format!("Test: {test}"))),
651        TestEvent::StepStarted { label, .. } => (Level::Debug, format!("  - {label}")),
652        TestEvent::StepFinished {
653            label,
654            message,
655            duration_ms,
656            status,
657            diagnostics,
658            screenshot,
659            ..
660        } => {
661            let level = match status {
662                StepStatus::Failed => Level::Error,
663                StepStatus::Skipped => Level::Warn,
664                StepStatus::Passed => Level::Info,
665            };
666            let icon = match status {
667                StepStatus::Passed => palette.green("✓"),
668                StepStatus::Failed => palette.red("✗"),
669                StepStatus::Skipped => palette.yellow("–"),
670            };
671            let dur = palette.dim(&format_duration(*duration_ms));
672            let mut lines = vec![format!("  {icon} {label} — {message} ({dur})")];
673            if let Some(diag) = diagnostics {
674                lines.push(diag.clone());
675            }
676            if let Some(shot) = screenshot {
677                lines.push(format!("      screenshot: {shot}"));
678            }
679            (level, lines.join("\n"))
680        }
681        TestEvent::LlmCallStarted {
682            endpoint,
683            model,
684            purpose,
685            ..
686        } => (
687            Level::Debug,
688            format!("      llm({purpose}): {endpoint} ({model}) ..."),
689        ),
690        TestEvent::LlmCallFinished {
691            endpoint,
692            model,
693            purpose,
694            ok,
695            duration_ms,
696            input_tokens,
697            output_tokens,
698            cached_input_tokens,
699            cache_creation_input_tokens,
700            cost,
701            error,
702            ..
703        } => {
704            let status = if *ok {
705                palette.green("ok")
706            } else {
707                palette.red("failed")
708            };
709            let dur = palette.dim(&format_duration(*duration_ms));
710            let mut line = format!(
711                "      llm({purpose}): {endpoint} ({model}) {status} {dur} | \
712                 {input_tokens} in / {output_tokens} out \
713                 ({cached_input_tokens} cached, {cache_creation_input_tokens} cache write) | \
714                 ${cost:.4}"
715            );
716            if let Some(err) = error {
717                use std::fmt::Write as _;
718                let _ = write!(line, " — {err}");
719            }
720            let level = if *ok { Level::Debug } else { Level::Warn };
721            (level, line)
722        }
723        TestEvent::TestFinished {
724            test,
725            passed,
726            failed,
727            skipped,
728            duration_ms,
729            cost,
730            tokens,
731            input_tokens,
732            output_tokens,
733            cached_input_tokens,
734            cache_creation_input_tokens,
735            models,
736            calls,
737        } => {
738            let verdict = if *failed == 0 && *passed > 0 {
739                palette.green("passed")
740            } else {
741                palette.red("failed")
742            };
743            let dur = palette.dim(&format_duration(*duration_ms));
744            let mut line = format!(
745                "Test: {test} — {verdict} ({dur}, ${cost:.4}, {tokens} tokens \
746                 ({input_tokens} in / {output_tokens} out, {cached_input_tokens} cached, \
747                 {cache_creation_input_tokens} cache write), \
748                 {calls} calls, {passed}+{failed}+{skipped} steps)"
749            );
750            if !models.is_empty() {
751                use std::fmt::Write as _;
752                let _ = write!(line, " | models: {}", models.join(", "));
753            }
754            (Level::Info, line)
755        }
756        TestEvent::RunFinished {
757            tests_passed,
758            tests_failed,
759            steps_passed,
760            steps_failed,
761            steps_skipped,
762            total_cost,
763            total_tokens,
764            total_input_tokens,
765            total_output_tokens,
766            total_cached_input_tokens,
767            total_cache_creation_input_tokens,
768            models,
769            total_calls,
770        } => {
771            let verdict = if *tests_failed == 0 {
772                palette.green("passed")
773            } else {
774                palette.red("failed")
775            };
776            let mut line = format!(
777                "run {verdict}: tests {tests_passed} passed, {tests_failed} failed | \
778                 steps {steps_passed} passed, {steps_failed} failed, \
779                 {steps_skipped} skipped | ${total_cost:.4} | {total_tokens} tokens \
780                 ({total_input_tokens} in / {total_output_tokens} out, \
781                 {total_cached_input_tokens} cached, {total_cache_creation_input_tokens} cache write) \
782                 | {total_calls} calls"
783            );
784            if !models.is_empty() {
785                use std::fmt::Write as _;
786                let _ = write!(line, " | models: {}", models.join(", "));
787            }
788            (Level::Warn, line)
789        }
790        TestEvent::Warning { message } => (Level::Warn, palette.yellow(&format!("  ! {message}"))),
791    }
792}
793
794/// Human-friendly duration: `431ms` or `1.2s`.
795fn format_duration(ms: u64) -> String {
796    if ms < 1000 {
797        format!("{ms}ms")
798    } else {
799        #[allow(clippy::cast_precision_loss)]
800        let secs = ms as f64 / 1000.0;
801        format!("{secs:.1}s")
802    }
803}
804
805/// Epoch milliseconds, for the NDJSON `ts` field.
806#[allow(clippy::cast_possible_truncation)]
807fn now_ms() -> u64 {
808    SystemTime::now()
809        .duration_since(UNIX_EPOCH)
810        .unwrap_or_default()
811        .as_millis() as u64
812}
813
814/// Escapes a string for the data section of a GitHub workflow command.
815#[must_use]
816fn escape_data(s: &str) -> String {
817    s.replace('%', "%25")
818        .replace('\r', "%0D")
819        .replace('\n', "%0A")
820}
821
822/// Escapes a string for the property section of a GitHub workflow command.
823#[must_use]
824fn escape_property(s: &str) -> String {
825    s.replace('%', "%25")
826        .replace('\r', "%0D")
827        .replace('\n', "%0A")
828        .replace(':', "%3A")
829        .replace(',', "%2C")
830}
831
832/// Escapes a string for use in an XML attribute value.
833#[must_use]
834fn esc_attr(s: &str) -> String {
835    s.replace('&', "&amp;")
836        .replace('<', "&lt;")
837        .replace('>', "&gt;")
838        .replace('"', "&quot;")
839        .replace('\'', "&apos;")
840}
841
842/// Writes the accumulated cases as a `JUnit` XML document.
843fn write_junit_xml(cases: &[JunitCase], classname: &str, path: &Path) -> io::Result<()> {
844    let tests = cases.len();
845    let failures: usize = cases.iter().map(|c| c.failures.len()).sum();
846    let skipped: u32 = cases.iter().map(|c| c.skipped).sum();
847    #[allow(clippy::cast_precision_loss)]
848    let time: f64 = cases.iter().map(|c| c.duration_ms as f64 / 1000.0).sum();
849
850    let mut writer = BufWriter::new(File::create(path)?);
851    writer.write_all(b"<?xml version=\"1.0\" encoding=\"UTF-8\"?>\n")?;
852    writeln!(
853        writer,
854        "<testsuites tests=\"{tests}\" failures=\"{failures}\" skipped=\"{skipped}\" \
855         time=\"{time:.3}\">"
856    )?;
857    for case in cases {
858        let name = esc_attr(&case.name);
859        #[allow(clippy::cast_precision_loss)]
860        let case_time = case.duration_ms as f64 / 1000.0;
861        if case.failures.is_empty() && case.skipped == 0 {
862            writeln!(
863                writer,
864                "  <testcase classname=\"{classname}\" name=\"{name}\" time=\"{case_time:.3}\"/>"
865            )?;
866        } else {
867            writeln!(
868                writer,
869                "  <testcase classname=\"{classname}\" name=\"{name}\" time=\"{case_time:.3}\">"
870            )?;
871            for _ in 0..case.skipped {
872                writeln!(writer, "    <skipped/>")?;
873            }
874            for failure in &case.failures {
875                write!(writer, "    <failure message=\"{}\">", esc_attr(failure))?;
876                writer.write_all(b"<![CDATA[")?;
877                writer.write_all(failure.replace("]]>", "]]]]><![CDATA[>").as_bytes())?;
878                writer.write_all(b"]]></failure>\n")?;
879            }
880            writeln!(writer, "  </testcase>")?;
881        }
882    }
883    writeln!(writer, "</testsuites>")?;
884    writer.flush()
885}
886
887/// Prints a cost report to stderr after all tests complete.
888pub fn print_report(per_test: &[(String, UsageSnapshot)], global: &UsageSnapshot) {
889    if per_test.is_empty() {
890        return;
891    }
892
893    eprintln!();
894    eprintln!("-------------------------------");
895    eprintln!("  COST REPORT");
896    eprintln!("-------------------------------");
897
898    for (test_name, snapshot) in per_test {
899        eprintln!(
900            "  Test: \"{test_name}\" — ${cost:.4} | {tokens} tokens \
901             ({input} in / {output} out, {cached} cached, {write} cache write) | {calls} calls",
902            cost = snapshot.total_cost,
903            tokens = snapshot.total_tokens,
904            input = snapshot.total_input_tokens,
905            output = snapshot.total_output_tokens,
906            cached = snapshot.total_cached_input_tokens,
907            write = snapshot.total_cache_creation_input_tokens,
908            calls = snapshot.total_calls,
909        );
910        if !snapshot.models.is_empty() {
911            eprintln!("    models: {}", snapshot.models.join(", "));
912        }
913        for (ep_name, ep_usage) in &snapshot.endpoints {
914            if ep_usage.calls == 0 {
915                continue;
916            }
917            eprintln!(
918                "    endpoint.{ep_name}:   {calls:>3} calls, {input:>7} in / {output:>7} out \
919                 ({cached} cached, {write} cache write), {tokens:>7} tokens, ${cost:.4}",
920                calls = ep_usage.calls,
921                input = ep_usage.input_tokens,
922                output = ep_usage.output_tokens,
923                cached = ep_usage.cached_input_tokens,
924                write = ep_usage.cache_creation_input_tokens,
925                tokens = ep_usage.input_tokens + ep_usage.output_tokens,
926                cost = ep_usage.cost,
927            );
928            if !ep_usage.models.is_empty() {
929                eprintln!(
930                    "      models: {}",
931                    ep_usage
932                        .models
933                        .iter()
934                        .cloned()
935                        .collect::<Vec<_>>()
936                        .join(", ")
937                );
938            }
939        }
940    }
941
942    eprintln!("-------------------------------");
943    eprintln!("  GLOBAL SUMMARY");
944    eprintln!(
945        "    Total cost:         ${cost:.4}",
946        cost = global.total_cost
947    );
948    eprintln!(
949        "    Total tokens:       {tokens}",
950        tokens = global.total_tokens
951    );
952    eprintln!(
953        "    Total input:        {input}",
954        input = global.total_input_tokens
955    );
956    eprintln!(
957        "    Total output:       {output}",
958        output = global.total_output_tokens
959    );
960    eprintln!(
961        "    Total cached input: {cached}",
962        cached = global.total_cached_input_tokens
963    );
964    eprintln!(
965        "    Total cache write:  {write}",
966        write = global.total_cache_creation_input_tokens
967    );
968    eprintln!(
969        "    Total calls:        {calls}",
970        calls = global.total_calls
971    );
972    eprintln!(
973        "    Models used:        {models}",
974        models = if global.models.is_empty() {
975            "-".to_owned()
976        } else {
977            global.models.join(", ")
978        }
979    );
980    eprintln!("-------------------------------");
981}
982
983/// Prints a budget exceeded warning to stderr.
984pub fn print_budget_warning(message: &str) {
985    eprintln!("  ! BUDGET WARNING: {message}");
986}
987
988/// Prints a budget exceeded hard error to stderr.
989pub fn print_budget_error(message: &str) {
990    eprintln!("  ✗ BUDGET EXCEEDED: {message}");
991}
992
993#[cfg(test)]
994mod tests {
995    use std::io::Read;
996    use std::path::PathBuf;
997
998    use super::{
999        escape_data, escape_property, format_duration, format_event, print_report, ColorMode,
1000        Level, Palette, Reporter,
1001    };
1002    use crate::costs::{EndpointUsage, UsageSnapshot};
1003    use crate::events::{StepStatus, TestEvent};
1004    use std::collections::HashMap;
1005
1006    fn palette() -> Palette {
1007        Palette { enabled: false }
1008    }
1009
1010    fn temp_file(name: &str) -> PathBuf {
1011        let dir = std::env::temp_dir().join(format!("lbt-report-{}", std::process::id()));
1012        std::fs::create_dir_all(&dir).expect("temp dir");
1013        dir.join(name)
1014    }
1015
1016    fn read_file(path: &PathBuf) -> String {
1017        let mut s = String::new();
1018        let mut f = std::fs::File::open(path).expect("open report file");
1019        f.read_to_string(&mut s).expect("read report file");
1020        s
1021    }
1022
1023    fn step_event(status: StepStatus) -> TestEvent {
1024        TestEvent::StepFinished {
1025            test: "login".into(),
1026            index: 0,
1027            label: "[click] sign in".into(),
1028            status,
1029            duration_ms: 1200,
1030            message: if status == StepStatus::Failed {
1031                "element #btn not found".into()
1032            } else {
1033                "clicked #btn".into()
1034            },
1035            diagnostics: (status == StepStatus::Failed).then(|| "    | url: http://x".into()),
1036            screenshot: (status == StepStatus::Failed).then(|| "artifacts/login.png".into()),
1037        }
1038    }
1039
1040    #[test]
1041    fn test_level_from_flags() {
1042        assert_eq!(Level::from_flags(0, 0), Level::Info);
1043        assert_eq!(Level::from_flags(0, 1), Level::Debug);
1044        assert_eq!(Level::from_flags(0, 2), Level::Trace);
1045        assert_eq!(Level::from_flags(0, 9), Level::Trace);
1046        assert_eq!(Level::from_flags(1, 0), Level::Warn);
1047        assert_eq!(Level::from_flags(1, 5), Level::Warn, "quiet wins");
1048        assert_eq!(Level::from_flags(2, 0), Level::Error);
1049        assert_eq!(Level::from_flags(3, 0), Level::Error);
1050    }
1051
1052    #[test]
1053    fn test_format_step_finished_failed_includes_diagnostics() {
1054        let (level, text) = format_event(&step_event(StepStatus::Failed), palette());
1055        assert_eq!(level, Level::Error);
1056        assert!(text.contains("[click] sign in"));
1057        assert!(text.contains("element #btn not found"));
1058        assert!(text.contains("1.2s"));
1059        assert!(text.contains("| url: http://x"));
1060        assert!(text.contains("screenshot: artifacts/login.png"));
1061        assert!(!text.contains("\x1b["), "no ANSI codes when color disabled");
1062    }
1063
1064    #[test]
1065    fn test_format_step_finished_passed_level_info() {
1066        let (level, text) = format_event(&step_event(StepStatus::Passed), palette());
1067        assert_eq!(level, Level::Info);
1068        assert!(text.contains("clicked #btn"));
1069        assert!(!text.contains("screenshot:"));
1070    }
1071
1072    #[test]
1073    fn test_format_test_finished_verdict() {
1074        let ok = format_event(
1075            &TestEvent::TestFinished {
1076                test: "t1".into(),
1077                passed: 3,
1078                failed: 0,
1079                skipped: 0,
1080                duration_ms: 6100,
1081                cost: 0.0123,
1082                tokens: 1234,
1083                input_tokens: 800,
1084                output_tokens: 434,
1085                cached_input_tokens: 200,
1086                cache_creation_input_tokens: 50,
1087                models: vec!["deepseek".into()],
1088                calls: 4,
1089            },
1090            palette(),
1091        );
1092        assert_eq!(ok.0, Level::Info);
1093        assert!(ok.1.contains("passed"));
1094        assert!(ok.1.contains("800 in / 434 out"));
1095        assert!(ok.1.contains("50 cache write"));
1096        assert!(ok.1.contains("models: deepseek"));
1097
1098        let bad = format_event(
1099            &TestEvent::TestFinished {
1100                test: "t2".into(),
1101                passed: 1,
1102                failed: 1,
1103                skipped: 2,
1104                duration_ms: 6100,
1105                cost: 0.0123,
1106                tokens: 1234,
1107                input_tokens: 800,
1108                output_tokens: 434,
1109                cached_input_tokens: 0,
1110                cache_creation_input_tokens: 0,
1111                models: Vec::new(),
1112                calls: 4,
1113            },
1114            palette(),
1115        );
1116        assert!(bad.1.contains("failed"));
1117    }
1118
1119    #[test]
1120    fn test_format_llm_call_lines() {
1121        let started = format_event(
1122            &TestEvent::LlmCallStarted {
1123                test: "t".into(),
1124                index: 0,
1125                endpoint: "default".into(),
1126                model: "deepseek".into(),
1127                purpose: "targeting".into(),
1128            },
1129            palette(),
1130        );
1131        assert_eq!(started.0, Level::Debug);
1132        assert!(started.1.contains("llm(targeting): default (deepseek)"));
1133
1134        let failed = format_event(
1135            &TestEvent::LlmCallFinished {
1136                test: "t".into(),
1137                index: 0,
1138                endpoint: "default".into(),
1139                model: "deepseek".into(),
1140                purpose: "targeting".into(),
1141                ok: false,
1142                duration_ms: 900,
1143                input_tokens: 100,
1144                output_tokens: 0,
1145                cached_input_tokens: 30,
1146                cache_creation_input_tokens: 12,
1147                cost: 0.0012,
1148                error: Some("HTTP 429: slow down".into()),
1149            },
1150            palette(),
1151        );
1152        assert_eq!(failed.0, Level::Warn);
1153        assert!(failed.1.contains("failed"));
1154        assert!(failed.1.contains("30 cached"));
1155        assert!(failed.1.contains("12 cache write"));
1156        assert!(failed.1.contains("HTTP 429"));
1157    }
1158
1159    #[test]
1160    fn test_format_run_started_is_debug() {
1161        let (level, text) = format_event(&TestEvent::RunStarted { total_tests: 3 }, palette());
1162        assert_eq!(level, Level::Debug);
1163        assert!(text.contains("3 test(s)"));
1164    }
1165
1166    #[test]
1167    fn test_format_duration() {
1168        assert_eq!(format_duration(0), "0ms");
1169        assert_eq!(format_duration(431), "431ms");
1170        assert_eq!(format_duration(1000), "1.0s");
1171        assert_eq!(format_duration(1234), "1.2s");
1172    }
1173
1174    #[test]
1175    fn test_github_escaping() {
1176        assert_eq!(escape_data("a% b\nc\rd"), "a%25 b%0Ac%0Dd");
1177        assert_eq!(escape_property("a:b,c\n%d"), "a%3Ab%2Cc%0A%25d");
1178    }
1179
1180    #[test]
1181    fn test_reporter_jsonl_emits_typed_timestamped_lines() {
1182        let path = temp_file("run.jsonl");
1183        let reporter = Reporter::new(
1184            Level::Debug,
1185            ColorMode::Never,
1186            Some(&path),
1187            None,
1188            None,
1189            false,
1190        )
1191        .expect("open jsonl");
1192        reporter
1193            .emit(&TestEvent::RunStarted { total_tests: 1 })
1194            .expect("emit");
1195        reporter
1196            .emit(&TestEvent::StepStarted {
1197                test: "login".into(),
1198                index: 0,
1199                label: "[click] sign in".into(),
1200            })
1201            .expect("emit");
1202        reporter
1203            .emit(&step_event(StepStatus::Passed))
1204            .expect("emit");
1205        reporter
1206            .emit(&TestEvent::TestFinished {
1207                test: "login".into(),
1208                passed: 1,
1209                failed: 0,
1210                skipped: 0,
1211                duration_ms: 1200,
1212                cost: 0.001,
1213                tokens: 100,
1214                input_tokens: 70,
1215                output_tokens: 30,
1216                cached_input_tokens: 10,
1217                cache_creation_input_tokens: 4,
1218                models: vec!["deepseek".into()],
1219                calls: 1,
1220            })
1221            .expect("emit");
1222        reporter
1223            .emit(&TestEvent::RunFinished {
1224                tests_passed: 1,
1225                tests_failed: 0,
1226                steps_passed: 1,
1227                steps_failed: 0,
1228                steps_skipped: 0,
1229                total_cost: 0.001,
1230                total_tokens: 100,
1231                total_input_tokens: 70,
1232                total_output_tokens: 30,
1233                total_cached_input_tokens: 10,
1234                total_cache_creation_input_tokens: 4,
1235                models: vec!["deepseek".into()],
1236                total_calls: 1,
1237            })
1238            .expect("emit");
1239        reporter.finish().expect("finish");
1240
1241        let content = read_file(&path);
1242        let lines: Vec<&str> = content.lines().collect();
1243        assert_eq!(lines.len(), 5);
1244        let first: serde_json::Value = serde_json::from_str(lines[0]).expect("json line");
1245        assert_eq!(first["type"], "run_started");
1246        assert!(first["ts"].as_u64().expect("ts") > 0);
1247        let step: serde_json::Value = serde_json::from_str(lines[2]).expect("json line");
1248        assert_eq!(step["type"], "step_finished");
1249        assert_eq!(step["status"], "passed");
1250        assert_eq!(step["test"], "login");
1251        let finished: serde_json::Value = serde_json::from_str(lines[4]).expect("json line");
1252        assert_eq!(finished["type"], "run_finished");
1253        assert_eq!(finished["tests_passed"], 1);
1254    }
1255
1256    #[test]
1257    fn test_reporter_junit_creates_failure_elements() {
1258        let path = temp_file("report.xml");
1259        let reporter = Reporter::new(
1260            Level::Info,
1261            ColorMode::Never,
1262            None,
1263            Some(&path),
1264            None,
1265            false,
1266        )
1267        .expect("open junit");
1268        reporter
1269            .emit(&step_event(StepStatus::Failed))
1270            .expect("emit");
1271        reporter
1272            .emit(&step_event(StepStatus::Skipped))
1273            .expect("emit");
1274        reporter
1275            .emit(&TestEvent::TestFinished {
1276                test: "login".into(),
1277                passed: 0,
1278                failed: 1,
1279                skipped: 1,
1280                duration_ms: 5000,
1281                cost: 0.0,
1282                tokens: 0,
1283                input_tokens: 0,
1284                output_tokens: 0,
1285                cached_input_tokens: 0,
1286                cache_creation_input_tokens: 0,
1287                models: Vec::new(),
1288                calls: 0,
1289            })
1290            .expect("emit");
1291        reporter.finish().expect("finish");
1292
1293        let xml = read_file(&path);
1294        assert!(xml.starts_with("<?xml version=\"1.0\""));
1295        assert!(xml.contains("<testsuites tests=\"1\" failures=\"1\" skipped=\"1\""));
1296        assert!(xml.contains("name=\"login\""));
1297        assert!(xml.contains("<skipped/>"));
1298        assert!(xml.contains("<failure"));
1299        assert!(xml.contains("element #btn not found"));
1300        assert!(xml.contains("screenshot: artifacts/login.png"));
1301        // XML safety: a failure message with angle brackets must be escaped
1302        let weird = TestEvent::StepFinished {
1303            test: "weird".into(),
1304            index: 0,
1305            label: "[wait] <weird>".into(),
1306            status: StepStatus::Failed,
1307            duration_ms: 10,
1308            message: "boom <tag> & \"quote\"".into(),
1309            diagnostics: None,
1310            screenshot: None,
1311        };
1312        reporter.emit(&weird).expect("emit");
1313        reporter
1314            .emit(&TestEvent::TestFinished {
1315                test: "weird".into(),
1316                passed: 0,
1317                failed: 1,
1318                skipped: 0,
1319                duration_ms: 10,
1320                cost: 0.0,
1321                tokens: 0,
1322                input_tokens: 0,
1323                output_tokens: 0,
1324                cached_input_tokens: 0,
1325                cache_creation_input_tokens: 0,
1326                models: Vec::new(),
1327                calls: 0,
1328            })
1329            .expect("emit");
1330        reporter.finish().expect("finish");
1331        let xml2 = read_file(&path);
1332        // Attribute copies are XML-escaped...
1333        assert!(xml2.contains("&lt;weird&gt;") && xml2.contains("&amp; &quot;quote&quot;"));
1334        // ...while the CDATA body keeps the raw text.
1335        assert!(xml2.contains("[wait] <weird>: boom <tag> & \"quote\""));
1336    }
1337
1338    #[test]
1339    fn test_reporter_trace_emits_complete_spans() {
1340        let path = temp_file("trace.json");
1341        let reporter = Reporter::new(
1342            Level::Info,
1343            ColorMode::Never,
1344            None,
1345            None,
1346            Some(&path),
1347            false,
1348        )
1349        .expect("open trace");
1350        reporter
1351            .emit(&TestEvent::TestStarted {
1352                test: "login".into(),
1353            })
1354            .expect("emit");
1355        reporter
1356            .emit(&TestEvent::StepStarted {
1357                test: "login".into(),
1358                index: 0,
1359                label: "[click] sign in".into(),
1360            })
1361            .expect("emit");
1362        reporter
1363            .emit(&step_event(StepStatus::Passed))
1364            .expect("emit");
1365        reporter
1366            .emit(&TestEvent::TestFinished {
1367                test: "login".into(),
1368                passed: 1,
1369                failed: 0,
1370                skipped: 0,
1371                duration_ms: 1200,
1372                cost: 0.0,
1373                tokens: 0,
1374                input_tokens: 0,
1375                output_tokens: 0,
1376                cached_input_tokens: 0,
1377                cache_creation_input_tokens: 0,
1378                models: Vec::new(),
1379                calls: 0,
1380            })
1381            .expect("emit");
1382        reporter.finish().expect("finish");
1383
1384        let content = read_file(&path);
1385        let doc: serde_json::Value = serde_json::from_str(&content).expect("trace json");
1386        let events = doc["traceEvents"].as_array().expect("traceEvents array");
1387        assert_eq!(events.len(), 2);
1388        // Spans close inner-first, so the array starts with the step.
1389        let step = &events[0];
1390        assert_eq!(step["name"], "[click] sign in");
1391        assert_eq!(step["ph"], "X");
1392        assert_eq!(step["cat"], "step");
1393        assert_eq!(events[1]["name"], "login");
1394        assert_eq!(events[1]["cat"], "test");
1395        assert!(step["ts"].as_u64().expect("ts") > 0);
1396        assert_eq!(doc["displayTimeUnit"], "ms");
1397    }
1398
1399    #[test]
1400    fn test_print_report_empty() {
1401        // Should return early, no panic
1402        print_report(&[], &UsageSnapshot::default());
1403    }
1404
1405    #[test]
1406    fn test_print_report_single_test() {
1407        let per_test = vec![("test1".to_owned(), make_snapshot(0.05, 500, 3))];
1408        // Should not panic
1409        print_report(&per_test, &make_snapshot(0.05, 500, 3));
1410    }
1411
1412    fn make_snapshot(cost: f64, tokens: u64, calls: u64) -> UsageSnapshot {
1413        let mut eps = HashMap::new();
1414        eps.insert(
1415            "default".to_owned(),
1416            EndpointUsage {
1417                calls,
1418                input_tokens: tokens / 2,
1419                output_tokens: tokens / 2,
1420                cached_input_tokens: tokens / 4,
1421                cache_creation_input_tokens: tokens / 8,
1422                cost,
1423                models: std::iter::once("deepseek".to_owned()).collect(),
1424            },
1425        );
1426        UsageSnapshot::from_endpoints(&eps)
1427    }
1428}