shepmaster / snafu

Easily assign underlying errors into domain-specific errors while adding context
https://docs.rs/snafu/
Apache License 2.0
1.35k stars 60 forks source link

Make backtrace output more end-user friendly #307

Open hellow554 opened 2 years ago

hellow554 commented 2 years ago

Currently, if I compare the output of backtrace-rs and snafu, they differ in readability and verbosity:

Backtrace-rs:

   0: rusty_blazer::solver::GameState::region
             at src/solver.rs:72:34
   1: rusty_blazer::solver::Solve::check_dependency
             at src/solver.rs:176:30
   2: rusty_blazer::solver::Solve::reachable_states::{{closure}}
             at src/solver.rs:119:24
   3: petgraph::visit::dfsvisit::dfs_visitor
             at /home/marcel/.cargo/registry/src/github.com-1ecc6299db9ec823/petgraph-0.6.0/src/visit/dfsvisit.rs:289:30
   4: petgraph::visit::dfsvisit::dfs_visitor
             at /home/marcel/.cargo/registry/src/github.com-1ecc6299db9ec823/petgraph-0.6.0/src/visit/dfsvisit.rs:291:21
   5: petgraph::visit::dfsvisit::dfs_visitor
             at /home/marcel/.cargo/registry/src/github.com-1ecc6299db9ec823/petgraph-0.6.0/src/visit/dfsvisit.rs:291:21
   6: petgraph::visit::dfsvisit::dfs_visitor
             at /home/marcel/.cargo/registry/src/github.com-1ecc6299db9ec823/petgraph-0.6.0/src/visit/dfsvisit.rs:291:21
   7: petgraph::visit::dfsvisit::depth_first_search
             at /home/marcel/.cargo/registry/src/github.com-1ecc6299db9ec823/petgraph-0.6.0/src/visit/dfsvisit.rs:260:13
   8: rusty_blazer::solver::Solve::reachable_states
             at src/solver.rs:102:13
   9: rusty_blazer::solver::find_path
             at src/solver.rs:223:21
  10: rusty_blazer::run
             at src/main.rs:89:5
  11: rusty_blazer::main
             at src/main.rs:95:21
  12: core::ops::function::FnOnce::call_once
             at /rustc/ac2d9fc509e36d1b32513744adf58c34bcc4f43c/library/core/src/ops/function.rs:227:5
  13: std::sys_common::backtrace::__rust_begin_short_backtrace
             at /rustc/ac2d9fc509e36d1b32513744adf58c34bcc4f43c/library/std/src/sys_common/backtrace.rs:125:18
  14: std::rt::lang_start::{{closure}}
             at /rustc/ac2d9fc509e36d1b32513744adf58c34bcc4f43c/library/std/src/rt.rs:64:18
  15: core::ops::function::impls::<impl core::ops::function::FnOnce<A> for &F>::call_once
             at /rustc/ac2d9fc509e36d1b32513744adf58c34bcc4f43c/library/core/src/ops/function.rs:259:13
      std::panicking::try::do_call
             at /rustc/ac2d9fc509e36d1b32513744adf58c34bcc4f43c/library/std/src/panicking.rs:403:40
      std::panicking::try
             at /rustc/ac2d9fc509e36d1b32513744adf58c34bcc4f43c/library/std/src/panicking.rs:367:19
      std::panic::catch_unwind
             at /rustc/ac2d9fc509e36d1b32513744adf58c34bcc4f43c/library/std/src/panic.rs:133:14
      std::rt::lang_start_internal::{{closure}}
             at /rustc/ac2d9fc509e36d1b32513744adf58c34bcc4f43c/library/std/src/rt.rs:46:48
      std::panicking::try::do_call
             at /rustc/ac2d9fc509e36d1b32513744adf58c34bcc4f43c/library/std/src/panicking.rs:403:40
      std::panicking::try
             at /rustc/ac2d9fc509e36d1b32513744adf58c34bcc4f43c/library/std/src/panicking.rs:367:19
      std::panic::catch_unwind
             at /rustc/ac2d9fc509e36d1b32513744adf58c34bcc4f43c/library/std/src/panic.rs:133:14
      std::rt::lang_start_internal
             at /rustc/ac2d9fc509e36d1b32513744adf58c34bcc4f43c/library/std/src/rt.rs:46:20
  16: std::rt::lang_start
             at /rustc/ac2d9fc509e36d1b32513744adf58c34bcc4f43c/library/std/src/rt.rs:63:17
  17: main
  18: __libc_start_main
  19: _start

Snafu:

 0 <snafu::backtrace_shim::Backtrace as snafu::GenerateBacktrace>::generate::h032e01463a593a88
   /home/marcel/.cargo/registry/src/github.com-1ecc6299db9ec823/snafu-0.7.0-beta.0/src/backtrace_shim.rs:15
   rusty_blazer::error::Logic::build::hcacf101af6f9f11e
   /home/marcel/projects/rusty_blazer/src/error.rs:6
 1 rusty_blazer::error::Logic::fail::ha1297597d0dbddb3
   /home/marcel/projects/rusty_blazer/src/error.rs:6
 2 rusty_blazer::solver::GameState::region::hed3d271bf2887e58
   /home/marcel/projects/rusty_blazer/src/solver.rs:73
 3 rusty_blazer::solver::Solve::check_dependency::h49d65a992b02ba0b
   /home/marcel/projects/rusty_blazer/src/solver.rs:176
 4 rusty_blazer::solver::Solve::reachable_states::{{closure}}::h7011f0ac07c01dd6
   /home/marcel/projects/rusty_blazer/src/solver.rs:119
 5 petgraph::visit::dfsvisit::dfs_visitor::he1f0317ac202544e
   /home/marcel/.cargo/registry/src/github.com-1ecc6299db9ec823/petgraph-0.6.0/src/visit/dfsvisit.rs:289
 6 petgraph::visit::dfsvisit::dfs_visitor::he1f0317ac202544e
   /home/marcel/.cargo/registry/src/github.com-1ecc6299db9ec823/petgraph-0.6.0/src/visit/dfsvisit.rs:291
 7 petgraph::visit::dfsvisit::dfs_visitor::he1f0317ac202544e
   /home/marcel/.cargo/registry/src/github.com-1ecc6299db9ec823/petgraph-0.6.0/src/visit/dfsvisit.rs:291
 8 petgraph::visit::dfsvisit::dfs_visitor::he1f0317ac202544e
   /home/marcel/.cargo/registry/src/github.com-1ecc6299db9ec823/petgraph-0.6.0/src/visit/dfsvisit.rs:291
 9 petgraph::visit::dfsvisit::depth_first_search::h1ec41680ec0cb3df
   /home/marcel/.cargo/registry/src/github.com-1ecc6299db9ec823/petgraph-0.6.0/src/visit/dfsvisit.rs:260
10 rusty_blazer::solver::Solve::reachable_states::hb25c860fdb3aacc8
   /home/marcel/projects/rusty_blazer/src/solver.rs:102
11 rusty_blazer::solver::find_path::h091e86bcbbb17cec
   /home/marcel/projects/rusty_blazer/src/solver.rs:223
12 rusty_blazer::run::hb178675bbcd21152
   /home/marcel/projects/rusty_blazer/src/main.rs:89
13 rusty_blazer::main::h3f3e17287947491a
   /home/marcel/projects/rusty_blazer/src/main.rs:95
14 core::ops::function::FnOnce::call_once::h66b2ae16b2a7cfd7
   /rustc/ac2d9fc509e36d1b32513744adf58c34bcc4f43c/library/core/src/ops/function.rs:227
15 std::sys_common::backtrace::__rust_begin_short_backtrace::hbb68dab704ddc512
   /rustc/ac2d9fc509e36d1b32513744adf58c34bcc4f43c/library/std/src/sys_common/backtrace.rs:125
16 std::rt::lang_start::{{closure}}::h7c7e68b49978a565
   /rustc/ac2d9fc509e36d1b32513744adf58c34bcc4f43c/library/std/src/rt.rs:64
17 core::ops::function::impls::<impl core::ops::function::FnOnce<A> for &F>::call_once::hab43eb8ec758341e
   /rustc/ac2d9fc509e36d1b32513744adf58c34bcc4f43c/library/core/src/ops/function.rs:259
   std::panicking::try::do_call::hb667fefd650e964d
   /rustc/ac2d9fc509e36d1b32513744adf58c34bcc4f43c/library/std/src/panicking.rs:403
   std::panicking::try::hc279775c9409768d
   /rustc/ac2d9fc509e36d1b32513744adf58c34bcc4f43c/library/std/src/panicking.rs:367
   std::panic::catch_unwind::hbe8b6ecc84f73073
   /rustc/ac2d9fc509e36d1b32513744adf58c34bcc4f43c/library/std/src/panic.rs:133
   std::rt::lang_start_internal::{{closure}}::hb04fdaef496a162b
   /rustc/ac2d9fc509e36d1b32513744adf58c34bcc4f43c/library/std/src/rt.rs:46
   std::panicking::try::do_call::habca359de051411d
   /rustc/ac2d9fc509e36d1b32513744adf58c34bcc4f43c/library/std/src/panicking.rs:403
   std::panicking::try::h24c556a6948e0937
   /rustc/ac2d9fc509e36d1b32513744adf58c34bcc4f43c/library/std/src/panicking.rs:367
   std::panic::catch_unwind::h58075d47f5a308d8
   /rustc/ac2d9fc509e36d1b32513744adf58c34bcc4f43c/library/std/src/panic.rs:133
   std::rt::lang_start_internal::h3d20dc1537d76758
   /rustc/ac2d9fc509e36d1b32513744adf58c34bcc4f43c/library/std/src/rt.rs:46
18 std::rt::lang_start::ha001032d5bf6d738
   /rustc/ac2d9fc509e36d1b32513744adf58c34bcc4f43c/library/std/src/rt.rs:63
19 main
20 __libc_start_main
21 _start

What I precisly want to change is that after the function should be removed and the paths should be relative to project root, not the filesystem:

currently:

11 rusty_blazer::solver::find_path::h58373568c6eed383
   /home/marcel/projects/rusty_blazer/src/solver.rs:223

wanted:

   9: rusty_blazer::solver::find_path
             at src/solver.rs:223:21

Since you're using the backtrace backend I don't see why it behaves like it does, but maybe you could shine a light on this.

In addition (but I doubt that will happen soon) is to reduce the backtrace to the relevant part, e.g. I don't want first two frames to appear (and maybe the last few, that are part of _start_lang)

Enet4 commented 2 years ago

Could this be related to @shepmaster's recent changes in #306? To the best of my knowledge, SNAFU does not take advantage of #[track_caller] yet, and I imagine that there could be some more tricks in this pull request.

shepmaster commented 1 year ago

Hmm, I don't have a great answer to the why, but the good news is that soon this will become moot:

use snafu::prelude::*;

#[derive(Debug, Snafu)]
struct NeatError {
    backtrace: snafu::Backtrace,
}

fn main() {
    println!("{}", NeatSnafu.build().backtrace);
}

features = ["backtraces"]

 0 backtrace::backtrace::libunwind::trace::hccd7e83906acb689
   /Users/shep/.cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.66/src/backtrace/libunwind.rs:93
   backtrace::backtrace::trace_unsynchronized::h32cdfaf0744a9709
   /Users/shep/.cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.66/src/backtrace/mod.rs:66
 1 backtrace::backtrace::trace::h0f26207a195201cc
   /Users/shep/.cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.66/src/backtrace/mod.rs:53
 2 backtrace::capture::Backtrace::create::hb02d7ef832adfdad
   /Users/shep/.cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.66/src/capture.rs:176
 3 backtrace::capture::Backtrace::new::hb97f424b0533f138
   /Users/shep/.cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.66/src/capture.rs:140
 4 <snafu::backtrace_shim::Backtrace as snafu::GenerateImplicitData>::generate::hdd9a23f449cedb9a
   /Users/shep/Projects/snafu/src/backtrace_shim.rs:15
   bt_example::NeatSnafu::build::hbea4ca5e0aafdd0a
   /private/tmp/bt-example/src/main.rs:3
 5 bt_example::main::hacce18dfcbd76c8a
   /private/tmp/bt-example/src/main.rs:9
 6 core::ops::function::FnOnce::call_once::h74f7fb924d26a014
   /rustc/a55dd71d5fb0ec5a6a3a9e8c27b2127ba491ce52/library/core/src/ops/function.rs:248
 7 std::sys_common::backtrace::__rust_begin_short_backtrace::he57537c4ce6a66de
   /rustc/a55dd71d5fb0ec5a6a3a9e8c27b2127ba491ce52/library/std/src/sys_common/backtrace.rs:122
 8 std::rt::lang_start::{{closure}}::ha4bb6f22b59e222f
   /rustc/a55dd71d5fb0ec5a6a3a9e8c27b2127ba491ce52/library/std/src/rt.rs:145
 9 core::ops::function::impls::<impl core::ops::function::FnOnce<A> for &F>::call_once::h7cd8ae72620b0d1f
   /rustc/a55dd71d5fb0ec5a6a3a9e8c27b2127ba491ce52/library/core/src/ops/function.rs:280
   std::panicking::try::do_call::h0bbb0f423dd9d86c
   /rustc/a55dd71d5fb0ec5a6a3a9e8c27b2127ba491ce52/library/std/src/panicking.rs:492
   std::panicking::try::hdaabe7e5908702af
   /rustc/a55dd71d5fb0ec5a6a3a9e8c27b2127ba491ce52/library/std/src/panicking.rs:456
   std::panic::catch_unwind::h7ee653eae81d0a43
   /rustc/a55dd71d5fb0ec5a6a3a9e8c27b2127ba491ce52/library/std/src/panic.rs:137
   std::rt::lang_start_internal::{{closure}}::he727754da11a45c1
   /rustc/a55dd71d5fb0ec5a6a3a9e8c27b2127ba491ce52/library/std/src/rt.rs:128
   std::panicking::try::do_call::h0171064c04d908b7
   /rustc/a55dd71d5fb0ec5a6a3a9e8c27b2127ba491ce52/library/std/src/panicking.rs:492
   std::panicking::try::h9c521838fe914345
   /rustc/a55dd71d5fb0ec5a6a3a9e8c27b2127ba491ce52/library/std/src/panicking.rs:456
   std::panic::catch_unwind::hac847f960377a9be
   /rustc/a55dd71d5fb0ec5a6a3a9e8c27b2127ba491ce52/library/std/src/panic.rs:137
   std::rt::lang_start_internal::hef2161f9571a51d7
   /rustc/a55dd71d5fb0ec5a6a3a9e8c27b2127ba491ce52/library/std/src/rt.rs:128
10 std::rt::lang_start::hade2d0e3fc9aeef5
   /rustc/a55dd71d5fb0ec5a6a3a9e8c27b2127ba491ce52/library/std/src/rt.rs:144
11 _main

features = ["backtraces", "backtraces-impl-std"] (with Rust 1.65)

   0: std::backtrace_rs::backtrace::libunwind::trace
             at /rustc/2a65764f21cf10b7e03c645f1ad0946e42758e0a/library/std/src/../../backtrace/src/backtrace/mod.rs:66:5
   1: std::backtrace_rs::backtrace::trace_unsynchronized
             at /rustc/2a65764f21cf10b7e03c645f1ad0946e42758e0a/library/std/src/../../backtrace/src/backtrace/mod.rs:66:5
   2: std::backtrace::Backtrace::create
             at /rustc/2a65764f21cf10b7e03c645f1ad0946e42758e0a/library/std/src/backtrace.rs:333:13
   3: <std::backtrace::Backtrace as snafu::GenerateImplicitData>::generate
             at /Users/shep/Projects/snafu/src/lib.rs:1256:9
   4: bt_example::NeatSnafu::build
             at ./src/main.rs:3:17
   5: bt_example::main
             at ./src/main.rs:9:20
   6: core::ops::function::FnOnce::call_once
             at /rustc/2a65764f21cf10b7e03c645f1ad0946e42758e0a/library/core/src/ops/function.rs:248:5
   7: std::sys_common::backtrace::__rust_begin_short_backtrace
             at /rustc/2a65764f21cf10b7e03c645f1ad0946e42758e0a/library/std/src/sys_common/backtrace.rs:122:18
   8: std::rt::lang_start::{{closure}}
             at /rustc/2a65764f21cf10b7e03c645f1ad0946e42758e0a/library/std/src/rt.rs:166:18
   9: core::ops::function::impls::<impl core::ops::function::FnOnce<A> for &F>::call_once
             at /rustc/2a65764f21cf10b7e03c645f1ad0946e42758e0a/library/core/src/ops/function.rs:283:13
  10: std::panicking::try::do_call
             at /rustc/2a65764f21cf10b7e03c645f1ad0946e42758e0a/library/std/src/panicking.rs:492:40
  11: std::panicking::try
             at /rustc/2a65764f21cf10b7e03c645f1ad0946e42758e0a/library/std/src/panicking.rs:456:19
  12: std::panic::catch_unwind
             at /rustc/2a65764f21cf10b7e03c645f1ad0946e42758e0a/library/std/src/panic.rs:137:14
  13: std::rt::lang_start_internal::{{closure}}
             at /rustc/2a65764f21cf10b7e03c645f1ad0946e42758e0a/library/std/src/rt.rs:148:48
  14: std::panicking::try::do_call
             at /rustc/2a65764f21cf10b7e03c645f1ad0946e42758e0a/library/std/src/panicking.rs:492:40
  15: std::panicking::try
             at /rustc/2a65764f21cf10b7e03c645f1ad0946e42758e0a/library/std/src/panicking.rs:456:19
  16: std::panic::catch_unwind
             at /rustc/2a65764f21cf10b7e03c645f1ad0946e42758e0a/library/std/src/panic.rs:137:14
  17: std::rt::lang_start_internal
             at /rustc/2a65764f21cf10b7e03c645f1ad0946e42758e0a/library/std/src/rt.rs:148:20
  18: std::rt::lang_start
             at /rustc/2a65764f21cf10b7e03c645f1ad0946e42758e0a/library/std/src/rt.rs:165:17
  19: _main