nextest_runner/reporter/structured/
libtest.rs

1// Copyright (c) The nextest Contributors
2// SPDX-License-Identifier: MIT OR Apache-2.0
3
4//! libtest compatible output support
5//!
6//! Before 1.70.0 it was possible to send `--format json` to test executables and
7//! they would print out a JSON line to stdout for various events. This format
8//! was however not intended to be stabilized, so 1.70.0 made it nightly only as
9//! intended. However, machine readable output is immensely useful to other
10//! tooling that can much more easily consume it than parsing the output meant
11//! for humans.
12//!
13//! Since there already existed tooling using the libtest output format, this
14//! event aggregator replicates that format so that projects can seamlessly
15//! integrate cargo-nextest into their project, as well as get the benefit of
16//! running their tests on stable instead of being forced to use nightly.
17//!
18//! This implementation will attempt to follow the libtest format as it changes,
19//! but the rate of changes is quite low (see <https://github.com/rust-lang/rust/blob/master/library/test/src/formatters/json.rs>)
20//! so this should not be a big issue to users, however, if the format is changed,
21//! the changes will be replicated in this file with a new minor version allowing
22//! users to move to the new format or stick to the format version(s) they were
23//! using before
24
25use crate::{
26    config::elements::{LeakTimeoutResult, SlowTimeoutResult},
27    errors::{DisplayErrorChain, FormatVersionError, FormatVersionErrorInner, WriteEventError},
28    list::{RustTestSuite, TestList},
29    reporter::events::{
30        ChildExecutionOutputDescription, ChildOutputDescription, ExecutionResultDescription,
31        StressIndex, TestEvent, TestEventKind,
32    },
33    test_output::ChildSingleOutput,
34};
35use bstr::ByteSlice;
36use iddqd::{IdOrdItem, IdOrdMap, id_ord_map, id_upcast};
37use nextest_metadata::{MismatchReason, RustBinaryId, TestCaseName};
38use std::fmt::Write as _;
39
40/// To support pinning the version of the output, we just use this simple enum
41/// to document changes as libtest output changes
42#[derive(Copy, Clone)]
43#[repr(u8)]
44enum FormatMinorVersion {
45    /// The libtest output as of `rustc 1.75.0-nightly (aa1a71e9e 2023-10-26)` with `--format json --report-time`
46    ///
47    /// * `{ "type": "suite", "event": "started", "test_count": <u32> }` - Start of a test binary run, always printed
48    ///   * `{ "type": "test", "event": "started", "name": "<name>" }` - Start of a single test, always printed
49    ///   * `{ "type": "test", "name": "<name>", "event": "ignored" }` - Printed if a test is ignored
50    ///     * Will have an additional `"message" = "<message>"` field if the there is a message in the ignore attribute eg. `#[ignore = "not yet implemented"]`
51    ///   * `{ "type": "test", "name": "<name>", "event": "ok", "exec_time": <f32> }` - Printed if a test runs successfully
52    ///   * `{ "type": "test", "name": "<name>", "event": "failed", "exec_time": <f32>, "stdout": "<escaped output collected during test execution>" }` - Printed if a test fails, note the stdout field actually contains both stdout and stderr despite the name
53    ///     * If `--ensure-time` is passed, libtest will add `"reason": "time limit exceeded"` if the test passes, but exceeds the time limit.
54    ///     * If `#[should_panic = "<expected message>"]` is used and message doesn't match, an additional `"message": "panic did not contain expected string\n<panic message>"` field is added
55    /// * `{ "type": "suite", "event": "<overall_status>", "passed": <u32>, "failed": <u32>, "ignored": <u32>, "measured": <u32>, "filtered_out": <u32>, "exec_time": <f32> }`
56    ///   * `event` will be `"ok"` if no failures occurred, or `"failed"` if `"failed" > 0`
57    ///   * `ignored` will be > 0 if there are `#[ignore]` tests and `--ignored` was not passed
58    ///   * `filtered_out` with be > 0 if there were tests not marked `#[ignore]` and `--ignored` was passed OR a test filter was passed and 1 or more tests were not executed
59    ///   * `measured` is only > 0 if running benchmarks
60    First = 1,
61    #[doc(hidden)]
62    _Max,
63}
64
65/// If libtest output is ever stabilized, this would most likely become the single
66/// version and we could get rid of the minor version, but who knows if that
67/// will ever happen
68#[derive(Copy, Clone)]
69#[repr(u8)]
70enum FormatMajorVersion {
71    /// The libtest output is unstable
72    Unstable = 0,
73    #[doc(hidden)]
74    _Max,
75}
76
77/// The accumulated stats for a single test binary
78struct LibtestSuite<'cfg> {
79    /// The number of tests that failed
80    failed: usize,
81    /// The number of tests that succeeded
82    succeeded: usize,
83    /// The number of tests that were ignored
84    ignored: usize,
85    /// The number of tests that were not executed due to filters
86    filtered: usize,
87    /// The number of tests in this suite that are still running
88    running: usize,
89
90    stress_index: Option<StressIndex>,
91    meta: &'cfg RustTestSuite<'cfg>,
92    /// The accumulated duration of every test that has been executed
93    total: std::time::Duration,
94    /// Libtest outputs outputs a `started` event for every test that isn't
95    /// filtered, including ignored tests, then outputs `ignored` events after
96    /// all the started events, so we just mimic that with a temporary buffer
97    ignore_block: Option<bytes::BytesMut>,
98    /// The single block of output accumulated for all tests executed in the binary,
99    /// this needs to be emitted as a single block to emulate how cargo test works,
100    /// executing each test binary serially and outputting a json line for each
101    /// event, as otherwise consumers would not be able to associate a single test
102    /// with its parent suite
103    output_block: bytes::BytesMut,
104}
105
106impl IdOrdItem for LibtestSuite<'_> {
107    type Key<'a>
108        = &'a RustBinaryId
109    where
110        Self: 'a;
111
112    fn key(&self) -> Self::Key<'_> {
113        &self.meta.binary_id
114    }
115
116    id_upcast!();
117}
118
119/// Determines whether the `nextest` subobject is added with additional metadata
120/// to events
121#[derive(Copy, Clone, Debug)]
122pub enum EmitNextestObject {
123    /// The `nextest` subobject is added
124    Yes,
125    /// The `nextest` subobject is not added
126    No,
127}
128
129const KIND_TEST: &str = "test";
130const KIND_SUITE: &str = "suite";
131
132const EVENT_STARTED: &str = "started";
133const EVENT_IGNORED: &str = "ignored";
134const EVENT_OK: &str = "ok";
135const EVENT_FAILED: &str = "failed";
136
137#[inline]
138fn fmt_err(err: std::fmt::Error) -> WriteEventError {
139    WriteEventError::Io(std::io::Error::new(std::io::ErrorKind::OutOfMemory, err))
140}
141
142/// A reporter that reports test runs in the same line-by-line JSON format as
143/// libtest itself
144pub struct LibtestReporter<'cfg> {
145    _minor: FormatMinorVersion,
146    _major: FormatMajorVersion,
147    test_list: Option<&'cfg TestList<'cfg>>,
148    test_suites: IdOrdMap<LibtestSuite<'cfg>>,
149    /// If true, we emit a `nextest` subobject with additional metadata in it
150    /// that consumers can use for easier integration if they wish
151    emit_nextest_obj: bool,
152}
153
154impl<'cfg> LibtestReporter<'cfg> {
155    /// Creates a new libtest reporter
156    ///
157    /// The version string is used to allow the reporter to evolve along with
158    /// libtest, but still be able to output a stable format for consumers. If
159    /// it is not specified the latest version of the format will be produced.
160    ///
161    /// If [`EmitNextestObject::Yes`] is passed, an additional `nextest` subobject
162    /// will be added to some events that includes additional metadata not produced
163    /// by libtest, but most consumers should still be able to consume them as
164    /// the base format itself is not changed
165    pub fn new(
166        version: Option<&str>,
167        emit_nextest_obj: EmitNextestObject,
168    ) -> Result<Self, FormatVersionError> {
169        let emit_nextest_obj = matches!(emit_nextest_obj, EmitNextestObject::Yes);
170
171        let Some(version) = version else {
172            return Ok(Self {
173                _minor: FormatMinorVersion::First,
174                _major: FormatMajorVersion::Unstable,
175                test_list: None,
176                test_suites: IdOrdMap::new(),
177                emit_nextest_obj,
178            });
179        };
180        let Some((major, minor)) = version.split_once('.') else {
181            return Err(FormatVersionError {
182                input: version.into(),
183                error: FormatVersionErrorInner::InvalidFormat {
184                    expected: "<major>.<minor>",
185                },
186            });
187        };
188
189        let major: u8 = major.parse().map_err(|err| FormatVersionError {
190            input: version.into(),
191            error: FormatVersionErrorInner::InvalidInteger {
192                which: "major",
193                err,
194            },
195        })?;
196
197        let minor: u8 = minor.parse().map_err(|err| FormatVersionError {
198            input: version.into(),
199            error: FormatVersionErrorInner::InvalidInteger {
200                which: "minor",
201                err,
202            },
203        })?;
204
205        let major = match major {
206            0 => FormatMajorVersion::Unstable,
207            o => {
208                return Err(FormatVersionError {
209                    input: version.into(),
210                    error: FormatVersionErrorInner::InvalidValue {
211                        which: "major",
212                        value: o,
213                        range: (FormatMajorVersion::Unstable as u8)
214                            ..(FormatMajorVersion::_Max as u8),
215                    },
216                });
217            }
218        };
219
220        let minor = match minor {
221            1 => FormatMinorVersion::First,
222            o => {
223                return Err(FormatVersionError {
224                    input: version.into(),
225                    error: FormatVersionErrorInner::InvalidValue {
226                        which: "minor",
227                        value: o,
228                        range: (FormatMinorVersion::First as u8)..(FormatMinorVersion::_Max as u8),
229                    },
230                });
231            }
232        };
233
234        Ok(Self {
235            _major: major,
236            _minor: minor,
237            test_list: None,
238            test_suites: IdOrdMap::new(),
239            emit_nextest_obj,
240        })
241    }
242
243    pub(crate) fn write_event(&mut self, event: &TestEvent<'cfg>) -> Result<(), WriteEventError> {
244        let mut retries = None;
245
246        // Write the pieces of data that are the same across all events
247        let (kind, eve, stress_index, test_instance) = match &event.kind {
248            TestEventKind::TestStarted {
249                stress_index,
250                test_instance,
251                ..
252            } => (KIND_TEST, EVENT_STARTED, stress_index, test_instance),
253            TestEventKind::TestSkipped {
254                stress_index,
255                test_instance,
256                reason: MismatchReason::Ignored,
257            } => {
258                // Note: unfortunately, libtest does not expose the message test in `#[ignore = "<message>"]`
259                // so we can't replicate the behavior of libtest exactly by emitting
260                // that message as additional metadata
261                (KIND_TEST, EVENT_STARTED, stress_index, test_instance)
262            }
263            TestEventKind::TestFinished {
264                stress_index,
265                test_instance,
266                run_statuses,
267                ..
268            } => {
269                if run_statuses.len() > 1 {
270                    retries = Some(run_statuses.len());
271                }
272
273                (
274                    KIND_TEST,
275                    match &run_statuses.last_status().result {
276                        ExecutionResultDescription::Pass
277                        | ExecutionResultDescription::Timeout {
278                            result: SlowTimeoutResult::Pass,
279                        }
280                        | ExecutionResultDescription::Leak {
281                            result: LeakTimeoutResult::Pass,
282                        } => EVENT_OK,
283                        ExecutionResultDescription::Leak {
284                            result: LeakTimeoutResult::Fail,
285                        }
286                        | ExecutionResultDescription::Fail { .. }
287                        | ExecutionResultDescription::ExecFail
288                        | ExecutionResultDescription::Timeout {
289                            result: SlowTimeoutResult::Fail,
290                        } => EVENT_FAILED,
291                    },
292                    stress_index,
293                    test_instance,
294                )
295            }
296            TestEventKind::RunStarted { test_list, .. } => {
297                self.test_list = Some(*test_list);
298                return Ok(());
299            }
300            TestEventKind::StressSubRunFinished { .. } | TestEventKind::RunFinished { .. } => {
301                for test_suite in std::mem::take(&mut self.test_suites) {
302                    self.finalize(test_suite)?;
303                }
304
305                return Ok(());
306            }
307            _ => return Ok(()),
308        };
309
310        // Look up the suite info from the test list.
311        let test_list = self
312            .test_list
313            .expect("test_list should be set by RunStarted before any test events");
314        let suite_info = test_list
315            .get_suite(test_instance.binary_id)
316            .expect("suite should exist in test list");
317        let crate_name = suite_info.package.name();
318        let binary_name = &suite_info.binary_name;
319
320        // Emit the suite start if this is the first test of the suite
321        let mut test_suite = match self.test_suites.entry(&suite_info.binary_id) {
322            id_ord_map::Entry::Vacant(e) => {
323                let (running, ignored, filtered) =
324                    suite_info.status.test_cases().fold((0, 0, 0), |acc, case| {
325                        if case.test_info.ignored {
326                            (acc.0, acc.1 + 1, acc.2)
327                        } else if case.test_info.filter_match.is_match() {
328                            (acc.0 + 1, acc.1, acc.2)
329                        } else {
330                            (acc.0, acc.1, acc.2 + 1)
331                        }
332                    });
333
334                let mut out = bytes::BytesMut::with_capacity(1024);
335                write!(
336                    &mut out,
337                    r#"{{"type":"{KIND_SUITE}","event":"{EVENT_STARTED}","test_count":{}"#,
338                    running + ignored,
339                )
340                .map_err(fmt_err)?;
341
342                if self.emit_nextest_obj {
343                    write!(
344                        out,
345                        r#","nextest":{{"crate":"{crate_name}","test_binary":"{binary_name}","kind":"{}""#,
346                        suite_info.kind,
347                    )
348                    .map_err(fmt_err)?;
349
350                    if let Some(stress_index) = stress_index {
351                        write!(out, r#","stress_index":{}"#, stress_index.current)
352                            .map_err(fmt_err)?;
353                        if let Some(total) = stress_index.total {
354                            write!(out, r#","stress_total":{total}"#).map_err(fmt_err)?;
355                        }
356                    }
357
358                    write!(out, "}}").map_err(fmt_err)?;
359                }
360
361                out.extend_from_slice(b"}\n");
362
363                e.insert(LibtestSuite {
364                    running,
365                    failed: 0,
366                    succeeded: 0,
367                    ignored,
368                    filtered,
369                    stress_index: *stress_index,
370                    meta: suite_info,
371                    total: std::time::Duration::new(0, 0),
372                    ignore_block: None,
373                    output_block: out,
374                })
375            }
376            id_ord_map::Entry::Occupied(e) => e.into_mut(),
377        };
378
379        let test_suite_mut = &mut *test_suite;
380        let out = &mut test_suite_mut.output_block;
381
382        // After all the tests have been started or ignored, put the block of
383        // tests that were ignored just as libtest does
384        if matches!(event.kind, TestEventKind::TestFinished { .. })
385            && let Some(ib) = test_suite_mut.ignore_block.take()
386        {
387            out.extend_from_slice(&ib);
388        }
389
390        // This is one place where we deviate from the behavior of libtest, by
391        // always prefixing the test name with both the crate and the binary name,
392        // as this information is quite important to distinguish tests from each
393        // other when testing inside a large workspace with hundreds or thousands
394        // of tests
395        //
396        // Additionally, a `#<n>` is used as a suffix if the test was retried,
397        // as libtest does not support that functionality
398        write!(
399            out,
400            r#"{{"type":"{kind}","event":"{eve}","name":"{}::{}"#,
401            suite_info.package.name(),
402            suite_info.binary_name,
403        )
404        .map_err(fmt_err)?;
405
406        if let Some(stress_index) = stress_index {
407            write!(out, "@stress-{}", stress_index.current).map_err(fmt_err)?;
408        }
409        write!(out, "${}", test_instance.test_name).map_err(fmt_err)?;
410        if let Some(retry_count) = retries {
411            write!(out, "#{retry_count}\"").map_err(fmt_err)?;
412        } else {
413            out.extend_from_slice(b"\"");
414        }
415
416        match &event.kind {
417            TestEventKind::TestFinished { run_statuses, .. } => {
418                let last_status = run_statuses.last_status();
419
420                test_suite_mut.total += last_status.time_taken;
421                test_suite_mut.running -= 1;
422
423                // libtest actually requires an additional `--report-time` flag to be
424                // passed for the exec_time information to be written. This doesn't
425                // really make sense when outputting structured output so we emit it
426                // unconditionally
427                write!(
428                    out,
429                    r#","exec_time":{}"#,
430                    last_status.time_taken.as_secs_f64()
431                )
432                .map_err(fmt_err)?;
433
434                match &last_status.result {
435                    ExecutionResultDescription::Fail { .. }
436                    | ExecutionResultDescription::ExecFail => {
437                        test_suite_mut.failed += 1;
438
439                        // Write the output from the test into the `stdout` (even
440                        // though it could contain stderr output as well).
441                        write!(out, r#","stdout":""#).map_err(fmt_err)?;
442
443                        strip_human_output_from_failed_test(
444                            &last_status.output,
445                            out,
446                            test_instance.test_name,
447                        )?;
448                        out.extend_from_slice(b"\"");
449                    }
450                    ExecutionResultDescription::Timeout {
451                        result: SlowTimeoutResult::Fail,
452                    } => {
453                        test_suite_mut.failed += 1;
454                        out.extend_from_slice(br#","reason":"time limit exceeded""#);
455                    }
456                    _ => {
457                        test_suite_mut.succeeded += 1;
458                    }
459                }
460            }
461            TestEventKind::TestSkipped { .. } => {
462                test_suite_mut.running -= 1;
463
464                if test_suite_mut.ignore_block.is_none() {
465                    test_suite_mut.ignore_block = Some(bytes::BytesMut::with_capacity(1024));
466                }
467
468                let ib = test_suite_mut
469                    .ignore_block
470                    .get_or_insert_with(|| bytes::BytesMut::with_capacity(1024));
471
472                writeln!(
473                    ib,
474                    r#"{{"type":"{kind}","event":"{EVENT_IGNORED}","name":"{}::{}${}"}}"#,
475                    suite_info.package.name(),
476                    suite_info.binary_name,
477                    test_instance.test_name,
478                )
479                .map_err(fmt_err)?;
480            }
481            _ => {}
482        };
483
484        out.extend_from_slice(b"}\n");
485
486        if self.emit_nextest_obj {
487            {
488                use std::io::Write as _;
489
490                let mut stdout = std::io::stdout().lock();
491                stdout.write_all(out).map_err(WriteEventError::Io)?;
492                stdout.flush().map_err(WriteEventError::Io)?;
493                out.clear();
494            }
495
496            if test_suite_mut.running == 0 {
497                std::mem::drop(test_suite);
498
499                if let Some(test_suite) = self.test_suites.remove(&suite_info.binary_id) {
500                    self.finalize(test_suite)?;
501                }
502            }
503        } else {
504            // If this is the last test of the suite, emit the test suite summary
505            // before emitting the entire block
506            if test_suite_mut.running > 0 {
507                return Ok(());
508            }
509
510            std::mem::drop(test_suite);
511
512            if let Some(test_suite) = self.test_suites.remove(&suite_info.binary_id) {
513                self.finalize(test_suite)?;
514            }
515        }
516
517        Ok(())
518    }
519
520    fn finalize(&self, mut test_suite: LibtestSuite) -> Result<(), WriteEventError> {
521        let event = if test_suite.failed > 0 {
522            EVENT_FAILED
523        } else {
524            EVENT_OK
525        };
526
527        let out = &mut test_suite.output_block;
528        let suite_info = test_suite.meta;
529
530        // It's possible that a test failure etc has cancelled the run, in which
531        // case we might still have tests that are "running", even ones that are
532        // actually skipped, so we just add those to the filtered list
533        if test_suite.running > 0 {
534            test_suite.filtered += test_suite.running;
535        }
536
537        write!(
538            out,
539            r#"{{"type":"{KIND_SUITE}","event":"{event}","passed":{},"failed":{},"ignored":{},"measured":0,"filtered_out":{},"exec_time":{}"#,
540            test_suite.succeeded,
541            test_suite.failed,
542            test_suite.ignored,
543            test_suite.filtered,
544            test_suite.total.as_secs_f64(),
545        )
546        .map_err(fmt_err)?;
547
548        if self.emit_nextest_obj {
549            let crate_name = suite_info.package.name();
550            let binary_name = &suite_info.binary_name;
551            write!(
552                out,
553                r#","nextest":{{"crate":"{crate_name}","test_binary":"{binary_name}","kind":"{}""#,
554                suite_info.kind,
555            )
556            .map_err(fmt_err)?;
557
558            if let Some(stress_index) = test_suite.stress_index {
559                write!(out, r#","stress_index":{}"#, stress_index.current).map_err(fmt_err)?;
560                if let Some(total) = stress_index.total {
561                    write!(out, r#","stress_total":{total}"#).map_err(fmt_err)?;
562                }
563            }
564
565            write!(out, "}}").map_err(fmt_err)?;
566        }
567
568        out.extend_from_slice(b"}\n");
569
570        {
571            use std::io::Write as _;
572
573            let mut stdout = std::io::stdout().lock();
574            stdout.write_all(out).map_err(WriteEventError::Io)?;
575            stdout.flush().map_err(WriteEventError::Io)?;
576        }
577
578        Ok(())
579    }
580}
581
582/// Unfortunately, to replicate the libtest json output, we need to do our own
583/// filtering of the output to strip out the data emitted by libtest in the
584/// human format.
585///
586/// This function relies on the fact that nextest runs every individual test in
587/// isolation.
588fn strip_human_output_from_failed_test(
589    output: &ChildExecutionOutputDescription<ChildSingleOutput>,
590    out: &mut bytes::BytesMut,
591    test_name: &TestCaseName,
592) -> Result<(), WriteEventError> {
593    match output {
594        ChildExecutionOutputDescription::Output {
595            result: _,
596            output,
597            errors,
598        } => {
599            match output {
600                ChildOutputDescription::Combined { output } => {
601                    strip_human_stdout_or_combined(output, out, test_name)?;
602                }
603                ChildOutputDescription::Split { stdout, stderr } => {
604                    // This is not a case that we hit because we always set CaptureStrategy to Combined. But
605                    // handle it in a reasonable fashion. (We do have a unit test for this case, so gate the
606                    // assertion with cfg(not(test)).)
607                    #[cfg(not(test))]
608                    {
609                        debug_assert!(false, "libtest output requires CaptureStrategy::Combined");
610                    }
611                    if let Some(stdout) = stdout {
612                        if !stdout.is_empty() {
613                            write!(out, "--- STDOUT ---\\n").map_err(fmt_err)?;
614                            strip_human_stdout_or_combined(stdout, out, test_name)?;
615                        }
616                    } else {
617                        write!(out, "(stdout not captured)").map_err(fmt_err)?;
618                    }
619                    // If stderr is not empty, just write all of it in.
620                    if let Some(stderr) = stderr {
621                        if !stderr.is_empty() {
622                            write!(out, "\\n--- STDERR ---\\n").map_err(fmt_err)?;
623                            write!(out, "{}", EscapedString(stderr.as_str_lossy()))
624                                .map_err(fmt_err)?;
625                        }
626                    } else {
627                        writeln!(out, "\\n(stderr not captured)").map_err(fmt_err)?;
628                    }
629                }
630            }
631
632            if let Some(errors) = errors {
633                write!(out, "\\n--- EXECUTION ERRORS ---\\n").map_err(fmt_err)?;
634                write!(
635                    out,
636                    "{}",
637                    EscapedString(&DisplayErrorChain::new(errors).to_string())
638                )
639                .map_err(fmt_err)?;
640            }
641        }
642        ChildExecutionOutputDescription::StartError(error) => {
643            write!(out, "--- EXECUTION ERROR ---\\n").map_err(fmt_err)?;
644            write!(
645                out,
646                "{}",
647                EscapedString(&DisplayErrorChain::new(error).to_string())
648            )
649            .map_err(fmt_err)?;
650        }
651    }
652    Ok(())
653}
654
655fn strip_human_stdout_or_combined(
656    output: &ChildSingleOutput,
657    out: &mut bytes::BytesMut,
658    test_name: &TestCaseName,
659) -> Result<(), WriteEventError> {
660    if output.buf.contains_str("running 1 test\n") {
661        // This is most likely the default test harness.
662        let lines = output
663            .lines()
664            .skip_while(|line| line != b"running 1 test")
665            .skip(1)
666            .take_while(|line| {
667                if let Some(name) = line
668                    .strip_prefix(b"test ")
669                    .and_then(|np| np.strip_suffix(b" ... FAILED"))
670                    && test_name.as_bytes() == name
671                {
672                    return false;
673                }
674
675                true
676            })
677            .map(|line| line.to_str_lossy());
678
679        for line in lines {
680            // This will never fail unless we are OOM
681            write!(out, "{}\\n", EscapedString(&line)).map_err(fmt_err)?;
682        }
683    } else {
684        // This is most likely a custom test harness. Just write out the entire
685        // output.
686        write!(out, "{}", EscapedString(output.as_str_lossy())).map_err(fmt_err)?;
687    }
688
689    Ok(())
690}
691
692/// Copy of the same string escaper used in libtest
693///
694/// <https://github.com/rust-lang/rust/blob/f440b5f0ea042cb2087a36631b20878f9847ee28/library/test/src/formatters/json.rs#L222-L285>
695struct EscapedString<'s>(&'s str);
696
697impl std::fmt::Display for EscapedString<'_> {
698    fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> ::std::fmt::Result {
699        let mut start = 0;
700        let s = self.0;
701
702        for (i, byte) in s.bytes().enumerate() {
703            let escaped = match byte {
704                b'"' => "\\\"",
705                b'\\' => "\\\\",
706                b'\x00' => "\\u0000",
707                b'\x01' => "\\u0001",
708                b'\x02' => "\\u0002",
709                b'\x03' => "\\u0003",
710                b'\x04' => "\\u0004",
711                b'\x05' => "\\u0005",
712                b'\x06' => "\\u0006",
713                b'\x07' => "\\u0007",
714                b'\x08' => "\\b",
715                b'\t' => "\\t",
716                b'\n' => "\\n",
717                b'\x0b' => "\\u000b",
718                b'\x0c' => "\\f",
719                b'\r' => "\\r",
720                b'\x0e' => "\\u000e",
721                b'\x0f' => "\\u000f",
722                b'\x10' => "\\u0010",
723                b'\x11' => "\\u0011",
724                b'\x12' => "\\u0012",
725                b'\x13' => "\\u0013",
726                b'\x14' => "\\u0014",
727                b'\x15' => "\\u0015",
728                b'\x16' => "\\u0016",
729                b'\x17' => "\\u0017",
730                b'\x18' => "\\u0018",
731                b'\x19' => "\\u0019",
732                b'\x1a' => "\\u001a",
733                b'\x1b' => "\\u001b",
734                b'\x1c' => "\\u001c",
735                b'\x1d' => "\\u001d",
736                b'\x1e' => "\\u001e",
737                b'\x1f' => "\\u001f",
738                b'\x7f' => "\\u007f",
739                _ => {
740                    continue;
741                }
742            };
743
744            if start < i {
745                f.write_str(&s[start..i])?;
746            }
747
748            f.write_str(escaped)?;
749
750            start = i + 1;
751        }
752
753        if start != self.0.len() {
754            f.write_str(&s[start..])?;
755        }
756
757        Ok(())
758    }
759}
760
761#[cfg(test)]
762mod test {
763    use crate::{
764        errors::ChildStartError,
765        reporter::{
766            events::ChildExecutionOutputDescription,
767            structured::libtest::strip_human_output_from_failed_test,
768        },
769        test_output::{ChildExecutionOutput, ChildOutput, ChildSplitOutput},
770    };
771    use bytes::BytesMut;
772    use color_eyre::eyre::eyre;
773    use nextest_metadata::TestCaseName;
774    use std::{io, sync::Arc};
775
776    /// Validates that the human output portion from a failed test is stripped
777    /// out when writing a JSON string, as it is not part of the output when
778    /// libtest itself outputs the JSON, so we have 100% identical output to libtest
779    #[test]
780    fn strips_human_output() {
781        const TEST_OUTPUT: &[&str] = &[
782            "\n",
783            "running 1 test\n",
784            "[src/index.rs:185] \"boop\" = \"boop\"\n",
785            "this is stdout\n",
786            "this i stderr\nok?\n",
787            "thread 'index::test::download_url_crates_io'",
788            r" panicked at src/index.rs:206:9:
789oh no
790stack backtrace:
791    0: rust_begin_unwind
792                at /rustc/a28077b28a02b92985b3a3faecf92813155f1ea1/library/std/src/panicking.rs:597:5
793    1: core::panicking::panic_fmt
794                at /rustc/a28077b28a02b92985b3a3faecf92813155f1ea1/library/core/src/panicking.rs:72:14
795    2: tame_index::index::test::download_url_crates_io
796                at ./src/index.rs:206:9
797    3: tame_index::index::test::download_url_crates_io::{{closure}}
798                at ./src/index.rs:179:33
799    4: core::ops::function::FnOnce::call_once
800                at /rustc/a28077b28a02b92985b3a3faecf92813155f1ea1/library/core/src/ops/function.rs:250:5
801    5: core::ops::function::FnOnce::call_once
802                at /rustc/a28077b28a02b92985b3a3faecf92813155f1ea1/library/core/src/ops/function.rs:250:5
803note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
804",
805            "test index::test::download_url_crates_io ... FAILED\n",
806            "\n\nfailures:\n\nfailures:\n    index::test::download_url_crates_io\n\ntest result: FAILED. 0 passed; 1 failed; 0 ignored; 0 measured; 13 filtered out; finished in 0.01s\n",
807        ];
808
809        let output = {
810            let mut acc = BytesMut::new();
811            for line in TEST_OUTPUT {
812                acc.extend_from_slice(line.as_bytes());
813            }
814
815            ChildOutput::Combined {
816                output: acc.freeze().into(),
817            }
818        };
819
820        let mut actual = bytes::BytesMut::new();
821        let output_desc: ChildExecutionOutputDescription<_> = ChildExecutionOutput::Output {
822            result: None,
823            output,
824            errors: None,
825        }
826        .into();
827        strip_human_output_from_failed_test(
828            &output_desc,
829            &mut actual,
830            &TestCaseName::new("index::test::download_url_crates_io"),
831        )
832        .unwrap();
833
834        insta::assert_snapshot!(std::str::from_utf8(&actual).unwrap());
835    }
836
837    #[test]
838    fn strips_human_output_custom_test_harness() {
839        // For a custom test harness, we don't strip the human output at all.
840        const TEST_OUTPUT: &[&str] = &["\n", "this is a custom test harness!!!\n", "1 test passed"];
841
842        let output = {
843            let mut acc = BytesMut::new();
844            for line in TEST_OUTPUT {
845                acc.extend_from_slice(line.as_bytes());
846            }
847
848            ChildOutput::Combined {
849                output: acc.freeze().into(),
850            }
851        };
852
853        let mut actual = bytes::BytesMut::new();
854        let output_desc: ChildExecutionOutputDescription<_> = ChildExecutionOutput::Output {
855            result: None,
856            output,
857            errors: None,
858        }
859        .into();
860        strip_human_output_from_failed_test(
861            &output_desc,
862            &mut actual,
863            &TestCaseName::new("non-existent"),
864        )
865        .unwrap();
866
867        insta::assert_snapshot!(std::str::from_utf8(&actual).unwrap());
868    }
869
870    #[test]
871    fn strips_human_output_start_error() {
872        let inner_error = eyre!("inner error");
873        let error = io::Error::other(inner_error);
874
875        let output: ChildExecutionOutputDescription<_> =
876            ChildExecutionOutput::StartError(ChildStartError::Spawn(Arc::new(error))).into();
877
878        let mut actual = bytes::BytesMut::new();
879        strip_human_output_from_failed_test(
880            &output,
881            &mut actual,
882            &TestCaseName::new("non-existent"),
883        )
884        .unwrap();
885
886        insta::assert_snapshot!(std::str::from_utf8(&actual).unwrap());
887    }
888
889    #[test]
890    fn strips_human_output_none() {
891        let mut actual = bytes::BytesMut::new();
892        let output_desc: ChildExecutionOutputDescription<_> = ChildExecutionOutput::Output {
893            result: None,
894            output: ChildOutput::Split(ChildSplitOutput {
895                stdout: None,
896                stderr: None,
897            }),
898            errors: None,
899        }
900        .into();
901        strip_human_output_from_failed_test(
902            &output_desc,
903            &mut actual,
904            &TestCaseName::new("non-existent"),
905        )
906        .unwrap();
907
908        insta::assert_snapshot!(std::str::from_utf8(&actual).unwrap());
909    }
910}