Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

phd: include error cause chain in failure output #606

Merged
merged 1 commit into from
Jan 16, 2024
Merged

Conversation

hawkw
Copy link
Member

@hawkw hawkw commented Jan 16, 2024

Currently, when phd tests fail by returning an anyhow::Error, the code for formatting the error message only includes the top-level error. When an error has a complex cause chain --- as most of the internal framework errors in phd do, due to use of anyhow::Context --- this means that most of the error information is discarded in the test output. For example, a test failure might currently look like this:

2024-01-16T21:07:12.693405Z  INFO phd_runner::execute: 117: test phd_tests::migrate::can_migrate_from_head ... FAILED: Failed to spawn migration source VM
    error backtrace: disabled backtrace

failures:
    phd_tests::migrate::can_migrate_from_head

test result: FAILED. 0 passed; 1 failed; 0 skipped; 0 not run; finished in 3.36s

This branch changes the error output to use the default fmt::Debug implementation for anyhow::Error, which includes the top-level error, the entire cause chain if the error has a cause, and the backtrace, if one was captured.

Now, the output for the same test failing looks like this:

2024-01-16T21:07:55.858780Z  INFO phd_runner::execute: 117: test phd_tests::migrate::can_migrate_from_head ... FAILED: Failed to spawn migration source VM

Caused by:
    0: constructing test VM
    1: building environment for new VM
    2: setting up VM execution environment
    3: Failed to extract file 'propolis-server' from tarball '/tmp/phd-propolis/ab0f89332b9ef2e21a1f4b41401b9d944ea2e6159f7c0c85143dd1c0f7e0c338/propolis-server.tar.gz'
    4: No file named 'propolis-server' found in tarball

failures:
    phd_tests::migrate::can_migrate_from_head

test result: FAILED. 0 passed; 1 failed; 0 skipped; 0 not run; finished in 3.36s

Or, if RUST_BACKTRACE=1 is set, like this:

2024-01-16T21:13:25.663321Z  INFO phd_runner::execute: 117: test phd_tests::migrate::can_migrate_from_head ... FAILED: Failed to spawn migration source VM

Caused by:
    0: constructing test VM
    1: building environment for new VM
    2: setting up VM execution environment
    3: Failed to extract file 'propolis-server' from tarball '/tmp/phd-propolis/ab0f89332b9ef2e21a1f4b41401b9d944ea2e6159f7c0c85143dd1c0f7e0c338/propolis-server.tar.gz'
    4: No file named 'propolis-server' found in tarball

Stack backtrace:
   0: anyhow::__private::format_err
             at /home/eliza/.cargo/registry/src/index.crates.io-6f17d22bba15001f/anyhow-1.0.75/src/lib.rs:678:13
   1: phd_framework::artifacts::store::extract_tarball
             at ./framework/src/artifacts/store.rs:537:9
   2: phd_framework::artifacts::store::extract_tar_gz::{{closure}}
             at ./framework/src/artifacts/store.rs:487:20
   3: phd_framework::artifacts::store::extract_tar_gz
             at ./framework/src/artifacts/store.rs:479:5

    < .. BACKTRACE SNIPPED FOR BREVITY ... >

  28: std::rt::lang_start
             at /rustc/82e1608dfa6e0b5569232559e3d385fea5a93112/library/std/src/rt.rs:166:17
  29: main
  30: _start_crt
  31: _start

failures:
    phd_tests::migrate::can_migrate_from_head

test result: FAILED. 0 passed; 1 failed; 0 skipped; 0 not run; finished in 3.99s

The additional information from the error's cause chain should come in handy while debugging test failures.

Currently, when `phd` tests fail by returning an `anyhow::Error`, the
code for formatting the error message only includes the top-level error.
When an error has a complex cause chain --- as most of the internal
framework errors in `phd` do, due to use of `anyhow::Context` --- this
means that most of the error information is discarded in the test
output. For example, a test failure might currently look like this:

```
2024-01-16T21:07:12.693405Z  INFO phd_runner::execute: 117: test phd_tests::migrate::can_migrate_from_head ... FAILED: Failed to spawn migration source VM
    error backtrace: disabled backtrace

failures:
    phd_tests::migrate::can_migrate_from_head

test result: FAILED. 0 passed; 1 failed; 0 skipped; 0 not run; finished in 3.36s
```

This branch changes the error output to use [the default `fmt::Debug`
implementation for `anyhow::Error`][default-debug], which includes the
top-level error, the entire cause chain if the error has a cause, and
the backtrace, if one was captured.

Now, the output for the same test failing looks like this:

```
2024-01-16T21:07:55.858780Z  INFO phd_runner::execute: 117: test phd_tests::migrate::can_migrate_from_head ... FAILED: Failed to spawn migration source VM

Caused by:
    0: constructing test VM
    1: building environment for new VM
    2: setting up VM execution environment
    3: Failed to extract file 'propolis-server' from tarball '/tmp/phd-propolis/ab0f89332b9ef2e21a1f4b41401b9d944ea2e6159f7c0c85143dd1c0f7e0c338/propolis-server.tar.gz'
    4: No file named 'propolis-server' found in tarball

failures:
    phd_tests::migrate::can_migrate_from_head

test result: FAILED. 0 passed; 1 failed; 0 skipped; 0 not run; finished in 3.36s
```

Or, if `RUST_BACKTRACE=1` is set, like this:

```
2024-01-16T21:13:25.663321Z  INFO phd_runner::execute: 117: test phd_tests::migrate::can_migrate_from_head ... FAILED: Failed to spawn migration source VM

Caused by:
    0: constructing test VM
    1: building environment for new VM
    2: setting up VM execution environment
    3: Failed to extract file 'propolis-server' from tarball '/tmp/phd-propolis/ab0f89332b9ef2e21a1f4b41401b9d944ea2e6159f7c0c85143dd1c0f7e0c338/propolis-server.tar.gz'
    4: No file named 'propolis-server' found in tarball

Stack backtrace:
   0: anyhow::__private::format_err
             at /home/eliza/.cargo/registry/src/index.crates.io-6f17d22bba15001f/anyhow-1.0.75/src/lib.rs:678:13
   1: phd_framework::artifacts::store::extract_tarball
             at ./framework/src/artifacts/store.rs:537:9
   2: phd_framework::artifacts::store::extract_tar_gz::{{closure}}
             at ./framework/src/artifacts/store.rs:487:20
   3: phd_framework::artifacts::store::extract_tar_gz
             at ./framework/src/artifacts/store.rs:479:5

    < .. BACKTRACE SNIPPED FOR BREVITY ... >

  28: std::rt::lang_start
             at /rustc/82e1608dfa6e0b5569232559e3d385fea5a93112/library/std/src/rt.rs:166:17
  29: main
  30: _start_crt
  31: _start

failures:
    phd_tests::migrate::can_migrate_from_head

test result: FAILED. 0 passed; 1 failed; 0 skipped; 0 not run; finished in 3.99s
```

The additional information from the error's cause chain should come in
handy while debugging test failures.

[default-debug]: https://docs.rs/anyhow/latest/anyhow/struct.Error.html#display-representations
@hawkw hawkw requested a review from gjcolombo January 16, 2024 21:15
@hawkw hawkw marked this pull request as ready for review January 16, 2024 21:15
@hawkw hawkw added the testing Related to testing and/or the PHD test framework. label Jan 16, 2024
@hawkw hawkw merged commit 390ccd8 into master Jan 16, 2024
10 checks passed
@hawkw hawkw deleted the eliza/phd-cause branch January 16, 2024 23:22
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
testing Related to testing and/or the PHD test framework.
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants