Improving failure messages in Rust tests returning a Result

Posted on Sun 08 January 2023

Rust tests can return a Result value so that we can use the ? operator in test code. The flipside is that test failure messages become basically useless. Let's see the problem and how we can improve that…

I was recently writing a test for a side project (more on that in a future post), which looked like this:

#[test]
fn test_render_index_page() -> anyhow::Result<()> {

    let json = std::fs::read_to_string("tests/data/gdoc/index.json")?;
    let doc = serde_json::from_str(&json)?;
    let html = gdocs2hugo::gdoc_to_html::render(&doc)?;

    insta::assert_snapshot!("convert_test", html);

    Ok(())
}

The test returns an anyhow::Result that can capture the various error types returned by any of the first 3 lines.

Now what happens if one of those lines returns a failed result? For example when index.json doesn’t exist:

Error: No such file or directory (os error 2)
test test_render_index_page ... FAILED

failures:

---- test_render_index_page stdout ----
thread 'test_render_index_page' panicked at 'assertion failed: `(left == right)`
  left: `1`,
 right: `0`: the test returned a termination value with a non-zero status code (1) which indicates a failure', /rustc/897e37553bba8b42751c67658967889d11ecd120/library/test/src/lib.rs:184:5
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace

We know that some file wasn’t found, causing the test_render_index_page test to fail. In this simple example we only have one line that can cause this error, but in more complex tests we may open several files and the test result will not be helpful to determine which is the faulty one.

Also the panic message is about a failed assertion and not about our missing file. That error is output to stdout, which is output early in the test output and is easy to miss when you have lots of tests.

Side note: I wish Rust included the file name in this error, which would make it much more useful. I assume the reason is that it would require allocating a string to copy the path so that it’s owned by the Error object. We certainly don’t want to allocate memory every time we test if a file exists!

Let’s see if RUST_BACKTRACE=1 is more helpful:

Error: No such file or directory (os error 2)
test test_render_index_page ... FAILED

failures:

---- test_render_index_page stdout ----
thread 'test_render_index_page' panicked at 'assertion failed: `(left == right)`
  left: `1`,
 right: `0`: the test returned a termination value with a non-zero status code (1) which indicates a failure', /rustc/897e37553bba8b42751c67658967889d11ecd120/library/test/src/lib.rs:184:5
stack backtrace:
   0: rust_begin_unwind
             at /rustc/897e37553bba8b42751c67658967889d11ecd120/library/std/src/panicking.rs:584:5
   1: core::panicking::panic_fmt
             at /rustc/897e37553bba8b42751c67658967889d11ecd120/library/core/src/panicking.rs:142:14
   2: core::panicking::assert_failed_inner
             at /rustc/897e37553bba8b42751c67658967889d11ecd120/library/core/src/panicking.rs:218:23
   3: core::panicking::assert_failed
             at /rustc/897e37553bba8b42751c67658967889d11ecd120/library/core/src/panicking.rs:181:5
   4: test::assert_test_result
             at /rustc/897e37553bba8b42751c67658967889d11ecd120/library/test/src/lib.rs:184:5
   5: publish_test::test_render_index_page::{{closure}}
             at ./tests/publish_test.rs:2:1
   6: core::ops::function::FnOnce::call_once
             at /rustc/897e37553bba8b42751c67658967889d11ecd120/library/core/src/ops/function.rs:248:5
   7: core::ops::function::FnOnce::call_once
             at /rustc/897e37553bba8b42751c67658967889d11ecd120/library/core/src/ops/function.rs:248:5
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.

The only line in our code is ./tests/publish_test.rs:2:1 which is the function declaration. But we knew that already…

We could replace every ? operator with unwrap() to panic early and have a meaningful location in the panic message, but that’s a lot of additional typing and it obscures the code. Also a good practice is to avoid unwrap() unless the result can never be an error to avoid panics, so we don’t want to introduce the cognitive dissonance of avoiding unwrap() in regular code while expecting its use in tests.

TestError: an error type that panics early

To make the stack trace more informative, we can use a little trick by panicking not in the test runner, but at the location where a ? causes the test to exist with an error. To achieve that we should remember that the ? operator is syntactic sugar for:

if let Error(err) = result { return Result::Err(From::from(err)) }

From above will resolve to the error variant of the test function return value. If the call to From::from panics, we will have an informative stacktrace.

So let’s replace anyhow::Result<()> with TestResult defined as follows:

#[derive(Debug)]
enum TestError {}

impl <Err: std::fmt::Display> From<Err> for TestError {
    #[track_caller]
    fn from(err: Err) -> Self {
        panic!("error: {}: {}", std::any::type_name::<Err>(), err);
    }
}

type TestResult = Result<(), TestError>;

If a ? operator is run with an error, TestError::from will panic. The track_caller attribute makes sure the panic will output the location of the caller (our test code) instead of the location of TestError::from which isn’t informative.

We can now use it as the result of our test function:

#[test]
fn test_render_index_page() -> TestResult {

    let json = std::fs::read_to_string("tests/data/gdoc/index.json")?;
    let doc = serde_json::from_str(&json)?;
    let html = gdocs2hugo::gdoc_to_html::render(&doc)?;

    return Result::Err(From::from(std::io::Error::last_os_error()));
    insta::assert_snapshot!("index_page", html);

    Ok(())
}

This results in the following output:

test test_render_index_page ... FAILED

failures:

---- test_render_index_page stdout ----
thread 'test_render_index_page' panicked at 'error: std::io::error::Error - No such file or directory (os error 2)', tests/publish_test.rs:4:16
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace

Yay 🎉! That’s a lot better! The panic message gives us the error type, its message, and the exact location where it happened in the test code! And we no more have this split output where the real error message is away from the panic message. And we don't even need to add RUST_BACKTRACE=1.

Publishing TestError on crates.io

Although TestResult is very small, it’s pretty useful and deserves to be published on crates.io. We should prefer small crates, after all! Looking at how to name the crate, I discovered that… there was already a crate for that 😮! It even has the exact same TestResult type! I should have looked there first 😕

However my version is a bit more elaborate:

  • it accepts any kind of error, even those not implementing std::error::Error (anyhow::Error is one of them!),
  • the use of track_caller provides a more useful panic message,
  • the panic message also contains the error type,
  • TestError being an empty enum, it cannot be instantiated, so this prevents its use for anything else than implicit error conversion.

So I ended up packaging these changes as a PR for the existing crate, which its maintainer promptly reviewed and released. So just cargo add testresult to use it!

Happy testing!



Go: the Good, the Bad and the Ugly

Home