Remove backtrace

[leighmcculloch]

What

Moved backtrace in the Host's DebugInfo behind a new feature.

Why

The backtrace output is included in the Debug formatting of errors when testutils are enabled, but the trace has not turned out to be that useful in contract tests written with the SDK.

When an error occurs in a contract test the output includes two long stack traces. The first is the one provided by backtrace. The second is one provided by the Rust test harness. Both are very similar and contain approximately the same information. The Rust test harness' trace is actually a little easier to read because it's not quite so verbose.

Here's a before and after of what a test failing looks like before and after this change:

Before

HostError: Error(Auth, InvalidAction)

Event log (newest first):
   0: [Diagnostic Event] topics:[error, Error(Auth, InvalidAction)], data:"escalating error to panic"
   1: [Diagnostic Event] topics:[error, Error(Auth, InvalidAction)], data:["contract call failed", exec, [CAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAFCT4]]
   2: [Failed Diagnostic Event (not emitted)] contract:CAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAHK3M, topics:[error, Error(Auth, InvalidAction)], data:"caught error from function"
   3: [Failed Diagnostic Event (not emitted)] contract:CAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAHK3M, topics:[error, Error(Auth, InvalidAction)], data:"escalating error to panic"
   4: [Failed Diagnostic Event (not emitted)] contract:CAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAHK3M, topics:[error, Error(Auth, InvalidAction)], data:["Unauthorized function call for address", CAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAFCT4]
   5: [Diagnostic Event] topics:[fn_call, Bytes(0000000000000000000000000000000000000000000000000000000000000003), exec], data:CAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAFCT4
   6: [Diagnostic Event] topics:[fn_call, Bytes(0000000000000000000000000000000000000000000000000000000000000005), __constructor], data:Void
   7: [Diagnostic Event] topics:[fn_call, Bytes(0000000000000000000000000000000000000000000000000000000000000004), __constructor], data:Void
   8: [Diagnostic Event] topics:[log], data:["holder_2", CAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAK3IM]
   9: [Diagnostic Event] topics:[log], data:["holder_1", CAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAITA4]
   10: [Diagnostic Event] topics:[log], data:["test_id", CAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAHK3M]
   11: [Diagnostic Event] topics:[fn_call, Bytes(0000000000000000000000000000000000000000000000000000000000000003), __constructor], data:Void
   12: [Diagnostic Event] topics:[log], data:["auth_id", CAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAFCT4]
   13: [Diagnostic Event] contract:CAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAFCT4, topics:[fn_return, init], data:Void
   14: [Diagnostic Event] topics:[fn_call, Bytes(0000000000000000000000000000000000000000000000000000000000000002), init], data:[CAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAD2KM, 2]
   15: [Diagnostic Event] topics:[fn_call, Bytes(0000000000000000000000000000000000000000000000000000000000000002), __constructor], data:Void
   16: [Diagnostic Event] topics:[fn_call, Bytes(0000000000000000000000000000000000000000000000000000000000000001), __constructor], data:Void

Backtrace (newest first):
   0: backtrace::backtrace::libunwind::trace
             at /Users/leighmcculloch/.cargo/registry/src/index.crates.io-6f17d22bba15001f/backtrace-0.3.74/src/backtrace/libunwind.rs:116:5
      backtrace::backtrace::trace_unsynchronized
             at /Users/leighmcculloch/.cargo/registry/src/index.crates.io-6f17d22bba15001f/backtrace-0.3.74/src/backtrace/mod.rs:66:5
   1: backtrace::backtrace::trace
             at /Users/leighmcculloch/.cargo/registry/src/index.crates.io-6f17d22bba15001f/backtrace-0.3.74/src/backtrace/mod.rs:53:14
   2: backtrace::capture::Backtrace::create
             at /Users/leighmcculloch/.cargo/registry/src/index.crates.io-6f17d22bba15001f/backtrace-0.3.74/src/capture.rs:292:9
   3: backtrace::capture::Backtrace::new_unresolved
             at /Users/leighmcculloch/.cargo/registry/src/index.crates.io-6f17d22bba15001f/backtrace-0.3.74/src/capture.rs:287:9
   4: soroban_env_host::host::error::<impl soroban_env_host::host::Host>::maybe_get_debug_info::{{closure}}
             at /Users/leighmcculloch/.cargo/git/checkouts/rs-soroban-env-230c62c6b1f3d3f1/75b7821/soroban-env-host/src/host/error.rs:299:37
   5: soroban_env_host::budget::Budget::with_shadow_mode
             at /Users/leighmcculloch/.cargo/git/checkouts/rs-soroban-env-230c62c6b1f3d3f1/75b7821/soroban-env-host/src/budget.rs:1039:21
   6: soroban_env_host::host::Host::with_debug_mode
             at /Users/leighmcculloch/.cargo/git/checkouts/rs-soroban-env-230c62c6b1f3d3f1/75b7821/soroban-env-host/src/host.rs:650:24
   7: soroban_env_host::host::error::<impl soroban_env_host::host::Host>::maybe_get_debug_info
             at /Users/leighmcculloch/.cargo/git/checkouts/rs-soroban-env-230c62c6b1f3d3f1/75b7821/soroban-env-host/src/host/error.rs:296:13
   8: soroban_env_host::host::error::<impl soroban_env_host::host::Host>::error::{{closure}}
             at /Users/leighmcculloch/.cargo/git/checkouts/rs-soroban-env-230c62c6b1f3d3f1/75b7821/soroban-env-host/src/host/error.rs:280:23
   9: soroban_env_host::budget::Budget::with_shadow_mode
             at /Users/leighmcculloch/.cargo/git/checkouts/rs-soroban-env-230c62c6b1f3d3f1/75b7821/soroban-env-host/src/budget.rs:1039:21
  10: soroban_env_host::host::Host::with_debug_mode
             at /Users/leighmcculloch/.cargo/git/checkouts/rs-soroban-env-230c62c6b1f3d3f1/75b7821/soroban-env-host/src/host.rs:650:24
  11: soroban_env_host::host::error::<impl soroban_env_host::host::Host>::error
             at /Users/leighmcculloch/.cargo/git/checkouts/rs-soroban-env-230c62c6b1f3d3f1/75b7821/soroban-env-host/src/host/error.rs:267:9
  12: <soroban_env_host::host::Host as soroban_env_common::env::EnvBase>::escalate_error_to_panic
             at /Users/leighmcculloch/.cargo/git/checkouts/rs-soroban-env-230c62c6b1f3d3f1/75b7821/soroban-env-host/src/host.rs:838:26
  13: soroban_sdk::env::internal::reject_err::{{closure}}
             at /Users/leighmcculloch/.cargo/git/checkouts/rs-soroban-sdk-0ab58a716c671239/a101940/soroban-sdk/src/env.rs:52:23
  14: core::result::Result<T,E>::map_err
             at /rustc/eeb90cda1969383f56a2637cbd3037bdf598841c/library/core/src/result.rs:854:27
  15: soroban_sdk::env::internal::reject_err
             at /Users/leighmcculloch/.cargo/git/checkouts/rs-soroban-sdk-0ab58a716c671239/a101940/soroban-sdk/src/env.rs:52:9
  16: <soroban_sdk::env::Env as soroban_env_common::env::Env>::call
             at /Users/leighmcculloch/.cargo/git/checkouts/rs-soroban-sdk-0ab58a716c671239/a101940/soroban-sdk/src/env.rs:1796:13
  17: soroban_sdk::env::Env::invoke_contract
             at /Users/leighmcculloch/.cargo/git/checkouts/rs-soroban-sdk-0ab58a716c671239/a101940/soroban-sdk/src/env.rs:379:18
  18: auth::tests::TestContractClient::exec
             at /Users/leighmcculloch/Code/talk-stellar-meridian24-testing/auth/src/tests.rs:17:1
  19: auth::tests::unit_test
             at /Users/leighmcculloch/Code/talk-stellar-meridian24-testing/auth/src/tests.rs:61:5
  20: auth::tests::unit_test::{{closure}}
             at /Users/leighmcculloch/Code/talk-stellar-meridian24-testing/auth/src/tests.rs:35:15
  21: core::ops::function::FnOnce::call_once
             at /rustc/eeb90cda1969383f56a2637cbd3037bdf598841c/library/core/src/ops/function.rs:250:5

stack backtrace:
   0: rust_begin_unwind
             at /rustc/eeb90cda1969383f56a2637cbd3037bdf598841c/library/std/src/panicking.rs:665:5
   1: core::panicking::panic_fmt
             at /rustc/eeb90cda1969383f56a2637cbd3037bdf598841c/library/core/src/panicking.rs:74:14
   2: <soroban_env_host::host::Host as soroban_env_common::env::EnvBase>::escalate_error_to_panic
             at /Users/leighmcculloch/.cargo/git/checkouts/rs-soroban-env-230c62c6b1f3d3f1/75b7821/soroban-env-host/src/host.rs:839:9
   3: soroban_sdk::env::internal::reject_err::{{closure}}
             at /Users/leighmcculloch/.cargo/git/checkouts/rs-soroban-sdk-0ab58a716c671239/a101940/soroban-sdk/src/env.rs:52:23
   4: core::result::Result<T,E>::map_err
             at /rustc/eeb90cda1969383f56a2637cbd3037bdf598841c/library/core/src/result.rs:854:27
   5: soroban_sdk::env::internal::reject_err
             at /Users/leighmcculloch/.cargo/git/checkouts/rs-soroban-sdk-0ab58a716c671239/a101940/soroban-sdk/src/env.rs:52:9
   6: <soroban_sdk::env::Env as soroban_env_common::env::Env>::call
             at /Users/leighmcculloch/.cargo/git/checkouts/rs-soroban-sdk-0ab58a716c671239/a101940/soroban-sdk/src/env.rs:1796:13
   7: soroban_sdk::env::Env::invoke_contract
             at /Users/leighmcculloch/.cargo/git/checkouts/rs-soroban-sdk-0ab58a716c671239/a101940/soroban-sdk/src/env.rs:379:18
   8: auth::tests::TestContractClient::exec
             at ./src/tests.rs:17:1
   9: auth::tests::unit_test
             at ./src/tests.rs:61:5
  10: auth::tests::unit_test::{{closure}}
             at ./src/tests.rs:35:15
  11: core::ops::function::FnOnce::call_once
             at /rustc/eeb90cda1969383f56a2637cbd3037bdf598841c/library/core/src/ops/function.rs:250:5
  12: core::ops::function::FnOnce::call_once
             at /rustc/eeb90cda1969383f56a2637cbd3037bdf598841c/library/core/src/ops/function.rs:250:5

After

HostError: Error(Auth, InvalidAction)

Event log (newest first):
   0: [Diagnostic Event] topics:[error, Error(Auth, InvalidAction)], data:"escalating error to panic"
   1: [Diagnostic Event] topics:[error, Error(Auth, InvalidAction)], data:["contract call failed", exec, [CAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAFCT4]]
   2: [Failed Diagnostic Event (not emitted)] contract:CAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAHK3M, topics:[error, Error(Auth, InvalidAction)], data:"caught error from function"
   3: [Failed Diagnostic Event (not emitted)] contract:CAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAHK3M, topics:[error, Error(Auth, InvalidAction)], data:"escalating error to panic"
   4: [Failed Diagnostic Event (not emitted)] contract:CAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAHK3M, topics:[error, Error(Auth, InvalidAction)], data:["Unauthorized function call for address", CAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAFCT4]
   5: [Diagnostic Event] topics:[fn_call, Bytes(0000000000000000000000000000000000000000000000000000000000000003), exec], data:CAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAFCT4
   6: [Diagnostic Event] topics:[fn_call, Bytes(0000000000000000000000000000000000000000000000000000000000000005), __constructor], data:Void
   7: [Diagnostic Event] topics:[fn_call, Bytes(0000000000000000000000000000000000000000000000000000000000000004), __constructor], data:Void
   8: [Diagnostic Event] topics:[log], data:["holder_2", CAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAK3IM]
   9: [Diagnostic Event] topics:[log], data:["holder_1", CAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAITA4]
   10: [Diagnostic Event] topics:[log], data:["test_id", CAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAHK3M]
   11: [Diagnostic Event] topics:[fn_call, Bytes(0000000000000000000000000000000000000000000000000000000000000003), __constructor], data:Void
   12: [Diagnostic Event] topics:[log], data:["auth_id", CAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAFCT4]
   13: [Diagnostic Event] contract:CAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAFCT4, topics:[fn_return, init], data:Void
   14: [Diagnostic Event] topics:[fn_call, Bytes(0000000000000000000000000000000000000000000000000000000000000002), init], data:[CAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAD2KM, 2]
   15: [Diagnostic Event] topics:[fn_call, Bytes(0000000000000000000000000000000000000000000000000000000000000002), __constructor], data:Void
   16: [Diagnostic Event] topics:[fn_call, Bytes(0000000000000000000000000000000000000000000000000000000000000001), __constructor], data:Void

stack backtrace:
   0: rust_begin_unwind
             at /rustc/eeb90cda1969383f56a2637cbd3037bdf598841c/library/std/src/panicking.rs:665:5
   1: core::panicking::panic_fmt
             at /rustc/eeb90cda1969383f56a2637cbd3037bdf598841c/library/core/src/panicking.rs:74:14
   2: <soroban_env_host::host::Host as soroban_env_common::env::EnvBase>::escalate_error_to_panic
             at /Users/leighmcculloch/Code/rs-soroban-env/soroban-env-host/src/host.rs:839:9
   3: soroban_sdk::env::internal::reject_err::{{closure}}
             at /Users/leighmcculloch/.cargo/git/checkouts/rs-soroban-sdk-0ab58a716c671239/a101940/soroban-sdk/src/env.rs:52:23
   4: core::result::Result<T,E>::map_err
             at /rustc/eeb90cda1969383f56a2637cbd3037bdf598841c/library/core/src/result.rs:854:27
   5: soroban_sdk::env::internal::reject_err
             at /Users/leighmcculloch/.cargo/git/checkouts/rs-soroban-sdk-0ab58a716c671239/a101940/soroban-sdk/src/env.rs:52:9
   6: <soroban_sdk::env::Env as soroban_env_common::env::Env>::call
             at /Users/leighmcculloch/.cargo/git/checkouts/rs-soroban-sdk-0ab58a716c671239/a101940/soroban-sdk/src/env.rs:1796:13
   7: soroban_sdk::env::Env::invoke_contract
             at /Users/leighmcculloch/.cargo/git/checkouts/rs-soroban-sdk-0ab58a716c671239/a101940/soroban-sdk/src/env.rs:379:18
   8: auth::tests::TestContractClient::exec
             at ./src/tests.rs:17:1
   9: auth::tests::unit_test
             at ./src/tests.rs:61:5
  10: auth::tests::unit_test::{{closure}}
             at ./src/tests.rs:35:15
  11: core::ops::function::FnOnce::call_once
             at /rustc/eeb90cda1969383f56a2637cbd3037bdf598841c/library/core/src/ops/function.rs:250:5
  12: core::ops::function::FnOnce::call_once
             at /rustc/eeb90cda1969383f56a2637cbd3037bdf598841c/library/core/src/ops/function.rs:250:5

Note

I'm not attached to this change if we need back traces for something, but if we need to keep them, I'm interested in how we can silence them for errors in contract tests.

Bonuses

As a bonus, this removes 7 deps from the dep graph for contract developers! 🎉

[graydon]

Hmm, I think I would like to keep them but it's only a mild preference. I think I mostly only see/use them when debugging test failures in the soroban host, and even then I fairly often want to look around, so set breakpoints in the IDE debugger. I won't block this if you both feel like they're not pulling their weight (and especially if users never get any value out of them, I'm certain we added them primarily for user benefit). Are you sure all/most scenarios users get a test-runner panic it'll have sufficient user-contract context in it?

[leighmcculloch]

As far as I can tell I haven't seen a case where I didn't otherwise have a backtrace available. Iirc we built the back tracing first, and then later added really good error handling and propogation to panics, (I think you did both! Thanks!!!), and so it's possible we just made the existing back tracing redundant.

Another way I could change this proposal is keep the backtrace, and only output it in the debug fmt if an env var is set, such as SOROBAN_BACKTRACE=1, or put it behind another feature? Wdyt?

[graydon]

I think I would prefer that, yes. Again, not a super-duper preference but, for example, in core we've repeatedly spent person-months to try to even get backtraces reliably reporting (the C++ library often fights with them amazingly) to debug field issues, I'd like to keep the ability close-ish at hand if it's not a huge burden.

[leighmcculloch]

I've pushed an update putting backtrace behind a new feature flag. I think this has the best tradeoffs because of the dep graph, as it'll remove the dep graph from contract developers.