Pick one: Error location or error context

[epage]

In updating cobalt.rs to 0.4, I found that with the new API, I could either do .unwrap() which shows why it fails but shows the error location as within assert_cli (setting traceback would probably help) or to .execute(); assert!(result.is_ok()); which will get me the error location but lose the information on why it failed.

See https://github.com/cobalt-org/cobalt.rs/blob/master/tests/cli.rs

[killercup]

Oh, great to see you using assert_cli! :)

What does .execute().unwrap() with RUST_BACKTRACE=full give you? I have not that much experience with it, but erro-chain does have some backtrace features IIRC.

[epage]

Looks like RUST_BACKTRACE doesn't help

When I do unwrap:
Assert::main_binary().with_args(&["--nonexistent-argument"]).succeeds().unwrap(); leads to

---- invalid_calls stdout ----
 Binary: "P:\\_OTHER\\git\\cobalt.rs\\target/debug/cobalt"
thread 'invalid_calls' panicked at 'Assert CLI failure:
Command "cargo run -- --nonexistent-argument" failed but expected it to succeed', C:\Users\epage.AMER\.cargo\registry\src\github.com-1ecc6299db9ec823\assert_cli-0.4.0\src\lib.rs:378

Just in case, I verified that I correctly set RUST_BACKTRACE
assert!(false); led to :

---- invalid_calls stdout ----
 Binary: "P:\\_OTHER\\git\\cobalt.rs\\target/debug/cobalt"
thread 'invalid_calls' panicked at 'assertion failed: false', tests\cli.rs:39
stack backtrace:
 0: 0x7ff6ca775798 - std::panicking::default_hook::{{closure}}
 at C:\bot\slave\nightly-dist-rustc-win-msvc-64\build\src\libstd\panicking.rs:356
 1: 0x7ff6ca774c22 - std::panicking::default_hook
 at C:\bot\slave\nightly-dist-rustc-win-msvc-64\build\src\libstd\panicking.rs:361
 2: 0x7ff6ca77865d - std::panicking::rust_panic_with_hook
 at C:\bot\slave\nightly-dist-rustc-win-msvc-64\build\src\libstd\panicking.rs:545
 3: 0x7ff6ca721fe7 - std::panicking::begin_panic<&str>
 at C:\bot\slave\nightly-dist-rustc-win-msvc-64\build\src\libstd\panicking.rs:507
 4: 0x7ff6ca723b92 - cli::invalid_calls
 at P:\_OTHER\git\cobalt.rs\tests\cli.rs:39
 5: 0x7ff6ca734a1a - test::{{impl}}::call_box<(),closure>
 at C:\bot\slave\nightly-dist-rustc-win-msvc-64\build\src\libtest\lib.rs:140
 6: 0x7ff6ca779491 - panic_unwind::__rust_maybe_catch_panic
 at C:\bot\slave\nightly-dist-rustc-win-msvc-64\build\src\libpanic_unwind\lib.rs:98
 7: 0x7ff6ca726a9b - std::panicking::try::do_call<std::panic::AssertUnwindSafe<closure>,()>
 at C:\bot\slave\nightly-dist-rustc-win-msvc-64\build\src\libstd\panicking.rs:446
 8: 0x7ff6ca779491 - panic_unwind::__rust_maybe_catch_panic
 at C:\bot\slave\nightly-dist-rustc-win-msvc-64\build\src\libpanic_unwind\lib.rs:98
 9: 0x7ff6ca72f3cc - alloc::boxed::{{impl}}::call_box<(),closure>
 at C:\bot\slave\nightly-dist-rustc-win-msvc-64\build\src\liballoc\boxed.rs:630
 10: 0x7ff6ca7739ae - std::sys::imp::thread::{{impl}}::new::thread_start
 at C:\bot\slave\nightly-dist-rustc-win-msvc-64\build\src\libstd\sys\windows\thread.rs:50
 11: 0x7ffee5338363 - BaseThreadInitThunk

[killercup]

Interesting. Just for comparison, for

extern crate assert_cli;
use assert_cli::Assert;

fn main() {
 Assert::command(&["echo", "goo"]).fails().unwrap();
}

I get

$ env RUST_BACKTRACE=full cargo run
 Compiling assert_cli_demo v0.1.0 (file:///Users/pascal/Projekte/_resolved/assert_cli_demo)
 Finished dev [unoptimized + debuginfo] target(s) in 0.49 secs
 Running `target/debug/assert_cli_demo`
thread 'main' panicked at 'Assert CLI failure:
Command "echo goo" succeed but expected it to failed', /Users/pascal/.cargo/registry/src/github.com-1ecc6299db9ec823/assert_cli-0.4.0/src/lib.rs:378
stack backtrace:
 0: 0x1058b08d3 - std::sys::imp::backtrace::tracing::imp::unwind_backtrace::h7b906ec435ded35c
 1: 0x1058b34e4 - std::panicking::default_hook::{{closure}}::h44d92332f38028b9
 2: 0x1058b30fd - std::panicking::default_hook::ha8486ead32221b33
 3: 0x1058b5b87 - std::panicking::rust_panic_with_hook::hdbc3bba6a9dc0bb9
 4: 0x1058b5a24 - std::panicking::begin_panic::ha249c774b9bf96e1
 5: 0x1058b5992 - std::panicking::begin_panic_fmt::ha197daaf02a649ab
 6: 0x105884d1b - assert_cli::Assert::unwrap::h4c3eab01a606e0e5
 7: 0x10586d5fd - assert_cli_demo::main::h10163101c8169415
 8: 0x1058b58b5 - std::panicking::try::do_call::h24a2756282b9a31c
 9: 0x1058b67ba - __rust_maybe_catch_panic
 10: 0x1058b5e30 - std::rt::lang_start::hd19f94db0c6a490e
 11: 0x10586d669 - main

I agree this is not a good backtrace, but it at least contains the relevant call site (7).

But: If you change the code to:

extern crate assert_cli;
use assert_cli::Assert;

fn main() {
 Assert::command(&["echo", "goo"]).fails().execute().unwrap();
}

you get (at least on macOS) a pretty detailed output (as Debug impl from error-chain seem to be much better than my simple panic!):

$ env RUST_BACKTRACE=full cargo run17
 Compiling assert_cli_demo v0.1.0 (file:///Users/pascal/Projekte/_resolved/assert_cli_demo)
 Finished dev [unoptimized + debuginfo] target(s) in 1.15 secs
 Running `target/debug/assert_cli_demo`
thread 'main' panicked at 'called `Result::unwrap()` on an `Err` value: Error(StatusMismatch(["echo", "goo"], false), State { next_error: None, backtrace: Some(stack backtrace:
 0: 0x10d614021 - backtrace::backtrace::trace::h6b0e5620771482fc
 1: 0x10d615473 - backtrace::capture::Backtrace::new::h8ca3ad60a3bf61a1
 2: 0x10d60adcc - error_chain::make_backtrace::hf8ec40e83a179f27
 3: 0x10d60ae87 - _$LT$error_chain..State$u20$as$u20$core..default..Default$GT$::default::h134e8cac5637e9a6
 4: 0x10d5f07cf - assert_cli::errors::Error::from_kind::hd4f14ad6d930bc3f
 5: 0x10d5f0a46 - _$LT$assert_cli..errors..Error$u20$as$u20$core..convert..From$LT$assert_cli..errors..ErrorKind$GT$$GT$::from::h9c287f0377047c1a
 6: 0x10d5e56f6 - _$LT$T$u20$as$u20$core..convert..Into$LT$U$GT$$GT$::into::hcbf3f403e6ea2079
 7: 0x10d5ef34b - assert_cli::Assert::execute::h3eee93ff511f7d96
 8: 0x10d5da3a8 - assert_cli_demo::main::h10163101c8169415
 9: 0x10d626355 - std::panicking::try::do_call::h24a2756282b9a31c
 10: 0x10d62725a - __rust_maybe_catch_panic
 11: 0x10d6268d0 - std::rt::lang_start::hd19f94db0c6a490e
 12: 0x10d5da459 - main) })', src/libcore/result.rs:860
stack backtrace:
 0: 0x10d621373 - std::sys::imp::backtrace::tracing::imp::unwind_backtrace::h7b906ec435ded35c
 1: 0x10d623f84 - std::panicking::default_hook::{{closure}}::h44d92332f38028b9
 2: 0x10d623b9d - std::panicking::default_hook::ha8486ead32221b33
 3: 0x10d626627 - std::panicking::rust_panic_with_hook::hdbc3bba6a9dc0bb9
 4: 0x10d6264c4 - std::panicking::begin_panic::ha249c774b9bf96e1
 5: 0x10d626432 - std::panicking::begin_panic_fmt::ha197daaf02a649ab
 6: 0x10d626397 - rust_begin_unwind
 7: 0x10d647760 - core::panicking::panic_fmt::h7414cb5ce71ea361
 8: 0x10d5d911f - core::result::unwrap_failed::h8ab7ade0bc19fe42
 9: 0x10d5d87a2 - <core::result::Result<T, E>>::unwrap::hc021ad1203fd1c6c
 10: 0x10d5da3c6 - assert_cli_demo::main::h10163101c8169415
 11: 0x10d626355 - std::panicking::try::do_call::h24a2756282b9a31c
 12: 0x10d62725a - __rust_maybe_catch_panic
 13: 0x10d6268d0 - std::rt::lang_start::hd19f94db0c6a490e
 14: 0x10d5da459 - main

From what I understand of the error-chain code, it only collects its internal backtrace when RUST_BACKTRACE is set.

Now I'm wondering: Do you think it'd be a good idea to replace my unwrap impl with just a call to this underlying error-chain unwrap?

[colin-kiegel]

@killercup You could try

 pub fn unwrap(self) {
 self.execute().unwrap();
 }

instead of

 pub fn unwrap(self) {
 if let Err(err) = self.execute() {
 panic!("{}", err);
 }
 }

It's also shorter :-)

[killercup]

Yeah, that's what I meant at the end, @colin-kiegel. I'm wondering if we may be able to inspect the backtrace to give a slightly more helpful error message, though.

[colin-kiegel]

Ok, perhaps give panic!("{:?}", err) a quick shot then?

[epage]

Trying this out with the latest version with BACKTRACE=1

 thread 'experiment' panicked at 'CLI assertion failed: (command `cargo run -- --nonexistent-argument` expected to succeed) (command failed)', /home/epage/.cargo/registry/src/github.com-1ecc6299db9ec823/assert_cli-0.5.1/src/assert.rs:281:12
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
stack backtrace:
 0: std::sys::imp::backtrace::tracing::imp::unwind_backtrace
 at /checkout/src/libstd/sys/unix/backtrace/tracing/gcc_s.rs:49
 1: std::sys_common::backtrace::_print
 at /checkout/src/libstd/sys_common/backtrace.rs:71
 2: std::panicking::default_hook::{{closure}}
 at /checkout/src/libstd/sys_common/backtrace.rs:60
 at /checkout/src/libstd/panicking.rs:380
 3: std::panicking::default_hook
 at /checkout/src/libstd/panicking.rs:390
 4: std::panicking::rust_panic_with_hook
 at /checkout/src/libstd/panicking.rs:611
 5: std::panicking::begin_panic_new
 at /checkout/src/libstd/panicking.rs:553
 6: std::panicking::begin_panic_fmt
 at /checkout/src/libstd/panicking.rs:521
 7: assert_cli::assert::Assert::unwrap
 at /home/epage/.cargo/registry/src/github.com-1ecc6299db9ec823/assert_cli-0.5.1/src/assert.rs:281
 8: cli::experiment
 at tests/cli.rs:200
 9: <F as test::FnBox<T>>::call_box
 at /checkout/src/libtest/lib.rs:1477
 at /checkout/src/libcore/ops/function.rs:143
 at /checkout/src/libtest/lib.rs:138
 10: __rust_maybe_catch_panic
 at /checkout/src/libpanic_unwind/lib.rs:98

with self.execute().unwrap()

 thread 'experiment' panicked at 'called `Result::unwrap()` on an `Err` value: Error(StatusMismatch(["cargo", "run", "--", "--nonexistent-argument"], true), State { next_error: None, backtrace: Some(stack backtrace:
 0: 0x7f8fc4e6fd84 - backtrace::backtrace::libunwind::trace
 at /home/epage/.cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.3/src/backtrace/libunwind.rs:53
 - backtrace::backtrace::trace<closure>
 at /home/epage/.cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.3/src/backtrace/mod.rs:42
 1: 0x7f8fc4e701ef - backtrace::capture::{{impl}}::new_unresolved
 at /home/epage/.cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.3/src/capture.rs:88
 2: 0x7f8fc4e7014e - backtrace::capture::{{impl}}::new
 at /home/epage/.cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.3/src/capture.rs:63
 3: 0x7f8fc4e63224 - error_chain::make_backtrace
 at /home/epage/.cargo/registry/src/github.com-1ecc6299db9ec823/error-chain-0.11.0/src/lib.rs:616
 4: 0x7f8fc4e6329f - error_chain::{{impl}}::default
 at /home/epage/.cargo/registry/src/github.com-1ecc6299db9ec823/error-chain-0.11.0/src/lib.rs:710
 5: 0x7f8fc4e3cfc8 - assert_cli::errors::{{impl}}::from_kind
 at /home/epage/git/cobalt.rs/<impl_error_chain_processed macros>:53
 6: 0x7f8fc4e3d192 - assert_cli::errors::{{impl}}::from
 at /home/epage/git/assert_cli/src/errors.rs:3
 7: 0x7f8fc4e2dc32 - core::convert::{{impl}}::into<assert_cli::errors::ErrorKind,assert_cli::errors::Error>
 at /checkout/src/libcore/convert.rs:398
 8: 0x7f8fc4e3c5f5 - assert_cli::assert::{{impl}}::execute
 at /home/epage/git/assert_cli/src/assert.rs:250
 9: 0x7f8fc4e3cda3 - assert_cli::assert::{{impl}}::unwrap
 at /home/epage/git/assert_cli/src/assert.rs:280
 10: 0x7f8fc4e1be98 - cli::experiment
 at tests/cli.rs:200
 11: 0x7f8fc4e4e091 - test::run_test::{{closure}}
 at /checkout/src/libtest/lib.rs:1477
 - core::ops::function::FnOnce::call_once<closure,(())>
 at /checkout/src/libcore/ops/function.rs:143
 - test::{{impl}}::call_box<(),closure>
 at /checkout/src/libtest/lib.rs:138
 12: 0x7f8fc4ef067c - panic_unwind::__rust_maybe_catch_panic
 at /checkout/src/libpanic_unwind/lib.rs:98
 13: 0x7f8fc4e3f05a - std::panicking::try<(),std::panic::AssertUnwindSafe<closure>>
 at /checkout/src/libstd/panicking.rs:458
 - std::panic::catch_unwind<std::panic::AssertUnwindSafe<closure>,()>
 at /checkout/src/libstd/panic.rs:361
 - test::run_test::run_test_inner::{{closure}}
 at /checkout/src/libtest/lib.rs:1416
 - std::sys_common::backtrace::__rust_begin_short_backtrace<closure,()>
 at /checkout/src/libstd/sys_common/backtrace.rs:136
 14: 0x7f8fc4e3fda2 - std::thread::{{impl}}::spawn::{{closure}}::{{closure}}<closure,()>
 at /checkout/src/libstd/thread/mod.rs:364
 - std::panic::{{impl}}::call_once<(),closure>
 at /checkout/src/libstd/panic.rs:296
 - std::panicking::try::do_call<std::panic::AssertUnwindSafe<closure>,()>
 at /checkout/src/libstd/panicking.rs:479
 15: 0x7f8fc4ef067c - panic_unwind::__rust_maybe_catch_panic
 at /checkout/src/libpanic_unwind/lib.rs:98
 16: 0x7f8fc4e478d2 - std::panicking::try<(),std::panic::AssertUnwindSafe<closure>>
 at /checkout/src/libstd/panicking.rs:458
 - std::panic::catch_unwind<std::panic::AssertUnwindSafe<closure>,()>
 at /checkout/src/libstd/panic.rs:361
 - std::thread::{{impl}}::spawn::{{closure}}<closure,()>
 at /checkout/src/libstd/thread/mod.rs:363
 - alloc::boxed::{{impl}}::call_box<(),closure>
 at /checkout/src/liballoc/boxed.rs:651
 17: 0x7f8fc4ee862b - alloc::boxed::{{impl}}::call_once<(),()>
 at /checkout/src/liballoc/boxed.rs:661
 - std::sys_common::thread::start_thread
 at /checkout/src/libstd/sys_common/thread.rs:21
 - std::sys::imp::thread::{{impl}}::new::thread_start
 at /checkout/src/libstd/sys/unix/thread.rs:84
 18: 0x7f8fc43c76b9 - start_thread
 19: 0x7f8fc3ed73dc - clone
 20: 0x0 - <unknown>) })', /checkout/src/libcore/result.rs:860:4
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
stack backtrace:
 0: std::sys::imp::backtrace::tracing::imp::unwind_backtrace
 at /checkout/src/libstd/sys/unix/backtrace/tracing/gcc_s.rs:49
 1: std::sys_common::backtrace::_print
 at /checkout/src/libstd/sys_common/backtrace.rs:71
 2: std::panicking::default_hook::{{closure}}
 at /checkout/src/libstd/sys_common/backtrace.rs:60
 at /checkout/src/libstd/panicking.rs:380
 3: std::panicking::default_hook
 at /checkout/src/libstd/panicking.rs:390
 4: std::panicking::rust_panic_with_hook
 at /checkout/src/libstd/panicking.rs:611
 5: std::panicking::begin_panic_new
 at /checkout/src/libstd/panicking.rs:553
 6: std::panicking::begin_panic_fmt
 at /checkout/src/libstd/panicking.rs:521
 7: rust_begin_unwind
 at /checkout/src/libstd/panicking.rs:497
 8: core::panicking::panic_fmt
 at /checkout/src/libcore/panicking.rs:92
 9: core::result::unwrap_failed
 at /checkout/src/libcore/macros.rs:41
 10: <core::result::Result<T, E>>::unwrap
 at /checkout/src/libcore/result.rs:738
 11: assert_cli::assert::Assert::unwrap
 at /home/epage/git/assert_cli/src/assert.rs:280
 12: cli::experiment
 at tests/cli.rs:200
 13: <F as test::FnBox<T>>::call_box
 at /checkout/src/libtest/lib.rs:1477
 at /checkout/src/libcore/ops/function.rs:143
 at /checkout/src/libtest/lib.rs:138
 14: __rust_maybe_catch_panic
 at /checkout/src/libpanic_unwind/lib.rs:98

and panic!("{:?}", err) produces the same thing

[epage]

So I'll admit, I'm a little confused about my own issue. Not sure how much of it is confusion at the time, my confusing myself, or changes in assert_cli.

In updating cobalt.rs to 0.4, I found that with the new API, I could either do .unwrap() which shows why it fails but shows the error location as within assert_cli (setting traceback would probably help) or to .execute(); assert!(result.is_ok()); which will get me the error location but lose the information on why it failed.

The crux of the issue seems to be my preferring macro-based solutions because the non-traceback message gives a lot of information.

But then I claim traceback didn't help

Looks like RUST_BACKTRACE doesn't help

and I have no clue why.

As a consumer of the crate, its macro solutions are really nice but not required. I'm going to close this.