From fa8f61576f49dc529cac5a0fe3319da28b2d4ffc Mon Sep 17 00:00:00 2001 From: Leigh McCulloch <351529+leighmcculloch@users.noreply.github.com> Date: Wed, 18 Sep 2024 10:38:53 +1000 Subject: [PATCH] Remove backtrace (#1464) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit ### 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::::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::::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::::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::::error at /Users/leighmcculloch/.cargo/git/checkouts/rs-soroban-env-230c62c6b1f3d3f1/75b7821/soroban-env-host/src/host/error.rs:267:9 12: ::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::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: ::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: ::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::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: ::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: ::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::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: ::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! 🎉 --- soroban-env-host/Cargo.toml | 3 ++- soroban-env-host/src/host/error.rs | 15 +++++++++------ 2 files changed, 11 insertions(+), 7 deletions(-) diff --git a/soroban-env-host/Cargo.toml b/soroban-env-host/Cargo.toml index 66c3a6167..c6275bcf1 100644 --- a/soroban-env-host/Cargo.toml +++ b/soroban-env-host/Cargo.toml @@ -105,7 +105,8 @@ default-features = false features = ["arbitrary"] [features] -testutils = ["soroban-env-common/testutils", "recording_mode", "dep:backtrace"] +testutils = ["soroban-env-common/testutils", "recording_mode"] +backtrace = ["dep:backtrace"] next = ["soroban-env-common/next", "stellar-xdr/next"] tracy = ["dep:tracy-client", "soroban-env-common/tracy"] recording_mode = [] diff --git a/soroban-env-host/src/host/error.rs b/soroban-env-host/src/host/error.rs index d2bfcfca4..6110b1b35 100644 --- a/soroban-env-host/src/host/error.rs +++ b/soroban-env-host/src/host/error.rs @@ -5,7 +5,7 @@ use crate::{ ConversionError, EnvBase, Error, Host, TryFromVal, U32Val, Val, }; -#[cfg(any(test, feature = "testutils"))] +#[cfg(any(test, feature = "backtrace"))] use backtrace::{Backtrace, BacktraceFrame}; use core::fmt::Debug; use std::{ @@ -18,7 +18,7 @@ use super::metered_clone::MeteredClone; #[derive(Clone)] pub(crate) struct DebugInfo { events: Events, - #[cfg(any(test, feature = "testutils"))] + #[cfg(any(test, feature = "backtrace"))] backtrace: Backtrace, } @@ -67,12 +67,12 @@ impl DebugInfo { Ok(()) } - #[cfg(not(any(test, feature = "testutils")))] + #[cfg(not(any(test, feature = "backtrace")))] fn write_backtrace(&self, _f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result { Ok(()) } - #[cfg(any(test, feature = "testutils"))] + #[cfg(any(test, feature = "backtrace"))] fn write_backtrace(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result { // We do a little trimming here, skipping the first two frames (which // are always into, from, and one or more Host::err_foo calls) and all @@ -296,8 +296,11 @@ impl Host { self.with_debug_mode(|| { if let Ok(events_ref) = self.0.events.try_borrow() { let events = events_ref.externalize(self)?; - let backtrace = Backtrace::new_unresolved(); - res = Some(Box::new(DebugInfo { backtrace, events })); + res = Some(Box::new(DebugInfo { + #[cfg(any(test, feature = "backtrace"))] + backtrace: Backtrace::new_unresolved(), + events, + })); } Ok(()) });