Skip to main content

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