How to trace errors when using `anyhow`

Question

When using the anyhow crate errors can be conveniently bubbled up to the root of the app, where they are handled.

Sometimes, however, I want to know where the error happened and I can't find a way to do that with anyhow.

My backtrace only mentions the root:

   4: mp_parser::main
             at ./src/main.rs:37:5

And running RUST_BACKTRACE=full gives me a detailed stack of internal calls, but it doesn't show me where the error originated inside my own code.

As a result I'm often left uncommenting different parts of the code to figure out where the error actually took place.

Is there some way to get the original line where it occured?

Suborbital

use snafu or thiserror and do proper error design, anyhow is evil (IMO) – Haerr

maybe you can try activate the feature features = ["backtrace"] – Haerr

@Haerr If you develop a library, anyhow is not a (complete) solution. But for a binary, could you elaborate why you find it "evil"? – Increscent

I have just tested the features = ["backtrace"] setting RUST_BACKTRACE=full and it just works! – Metric

@Metric What exactly do you mean by "it works"? Did you manage to get the line numbers under release mode? – Increscent

@at54321: Well, in release mode it just shows the name of the functions. I've just tried setting debug = true to [profile.release] and it gives also the line numbers. As good as can be expected, I guess. – Metric

@Haerr features = ["backtrace"] worked! Want to add a reply and I'll mark it as correct? – Suborbital

Answer 1

I ran a few tests with the following app (all in release mode):

use anyhow::{ensure, Result};

fn main() -> Result<()> {
    aa()?;
    Ok(())
}

fn aa() -> Result<()> {
    bb(33)?;
    bb(77)?;
    bb(5)?;
    Ok(())
}

fn bb(p: i32) -> Result<i32> {
    ensure!(p >= 10, "param not big enough!");
    Ok(p)
}

I tested various combinations:

• On Stable (1.58) and Nightly (1.60) toolchains.
• With and without the "backtrace" feature;
• Without setting RUST_BACKTRACE and setting it to 1 or full (there was no difference between 1 and full in this test).

When running the app with RUST_BACKTRACE=1 or RUST_BACKTRACE=full, we get a backtrace like this:

Error: param not big enough!

Stack backtrace:
   0: anyhow::error::<impl anyhow::Error>::msg
   1: an::main
   2: std::sys_common::backtrace::__rust_begin_short_backtrace
   3: std::rt::lang_start::{{closure}}
   4: core::ops::function::impls::<impl core::ops::function::FnOnce<A> for &F>::call_once
             at /rustc/5e57faa78aa7661c6000204591558f6665f11abc/library/core/src/ops/function.rs:259:13
   5: std::panicking::try::do_call
             at /rustc/5e57faa78aa7661c6000204591558f6665f11abc/library/std/src/panicking.rs:485:40
   6: std::panicking::try
             at /rustc/5e57faa78aa7661c6000204591558f6665f11abc/library/std/src/panicking.rs:449:19
   7: std::panic::catch_unwind
             at /rustc/5e57faa78aa7661c6000204591558f6665f11abc/library/std/src/panic.rs:136:14
   8: std::rt::lang_start_internal::{{closure}}
             at /rustc/5e57faa78aa7661c6000204591558f6665f11abc/library/std/src/rt.rs:128:48
   9: std::panicking::try::do_call
             at /rustc/5e57faa78aa7661c6000204591558f6665f11abc/library/std/src/panicking.rs:485:40
  10: std::panicking::try
             at /rustc/5e57faa78aa7661c6000204591558f6665f11abc/library/std/src/panicking.rs:449:19
  11: std::panic::catch_unwind
             at /rustc/5e57faa78aa7661c6000204591558f6665f11abc/library/std/src/panic.rs:136:14
  12: std::rt::lang_start_internal
             at /rustc/5e57faa78aa7661c6000204591558f6665f11abc/library/std/src/rt.rs:128:20
  13: main
  14: __libc_start_main
  15: _start

I also tested with the "backtrace" feature on:

    anyhow = { version = "1.0.52", features = ["backtrace"] }

, but that didn't seem to add any valuable information to the stack trace.

The reason we only see 1: an::main is that in this simple program the other functions are inlined.

We can experiment with disabling inlining for a particular function like this:

#[inline(never)]
fn aa() -> Result<()> {...

Now we get this:

Stack backtrace:
   0: anyhow::error::<impl anyhow::Error>::msg
   1: an::aa
   2: std::sys_common::backtrace::__rust_begin_short_backtrace
   ...

That might help a bit in narrowing down the location where the error originated to a single function, but it is still far from perfect. And, obviously, it's generally not a great idea to disable inlining just for this purpose.

It seems we can do this though:

ensure!(p >= 10, "param not big enough! {}:{}", file!(), line!());

And even in release mode we can obtain info about the file & line:

Error: param not big enough! src/main.rs:18

So obviously, it is possible to build something around that, but I'm not familiar with how exactly those macros work and how much the overhead would be. Would be happy if someone could shed more light on that.

---

As suggested by Rodrigo, I also tried this:

[profile.release]
debug = true

The result looks great:

Stack backtrace:
   0: anyhow::error::<impl anyhow::Error>::msg
             at /home/xyz/.cargo/registry/src/github.com-1ecc6299db9ec823/anyhow-1.0.52/src/error.rs:79:36
   1: an::bb
             at ./src/main.rs:18:5
   2: an::aa
             at ./src/main.rs:13:2
   3: an::main
             at ./src/main.rs:6:2
   4: core::ops::function::FnOnce::call_once
             at /rustc/5e57faa78aa7661c6000204591558f6665f11abc/library/core/src/ops/function.rs:227:5
   5: std::sys_common::backtrace::__rust_begin_short_backtrace
             at /rustc/5e57faa78aa7661c6000204591558f6665f11abc/library/std/src/sys_common/backtrace.rs:123:18
   ...
   

The binary size grew up by 16% as a result of this.

Setting debug = 1 yields the same stack-trace as debug = true (which BTW is the same as debug = 2), but with only 6% bigger binary size, compared to the default debug = 0

I haven't tested if/how that setting affects performance.

Increscent

I wonder if enabling stack trace would do any great harm to performance. Maybe we should set it on by default for debug builds. – Fabien

Answer 2

We do that by overriding the error!() macro by our own version.

In this macro, we inject the file!(), line!() values to the log message (using the"kv" feature) so that it picks exactly the code location which creates the error.

Fustic