From 258f49535278a524ed8e6d82fd1721703fb26287 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Fran=C3=A7ois?= Date: Mon, 28 Feb 2022 22:27:20 +0000 Subject: [PATCH] log spans on panic when trace is enabled (#3848) # Objective - Help debug panics ## Solution - Insert a custom panic hook when trace is enabled that will log spans example when running a command on a despawned entity before: ``` thread 'main' panicked at 'Could not add a component (of type `panic::Marker`) to entity 1v0 because it doesn't exist in this World. If this command was added to a newly spawned entity, ensure that you have not despawned that entity within the same stage. This may have occurred due to system order ambiguity, or if the spawning system has multiple command buffers', /bevy/crates/bevy_ecs/src/system/commands/mod.rs:664:13 note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace ``` after: ``` 0: bevy_ecs::schedule::stage::system_commands with name="panic::my_bad_system" at crates/bevy_ecs/src/schedule/stage.rs:871 1: bevy_ecs::schedule::stage with name=Update at crates/bevy_ecs/src/schedule/mod.rs:340 2: bevy_app::app::frame at crates/bevy_app/src/app.rs:111 3: bevy_app::app::bevy_app at crates/bevy_app/src/app.rs:126 thread 'main' panicked at 'Could not add a component (of type `panic::Marker`) to entity 1v0 because it doesn't exist in this World. If this command was added to a newly spawned entity, ensure that you have not despawned that entity within the same stage. This may have occurred due to system order ambiguity, or if the spawning system has multiple command buffers', /bevy/crates/bevy_ecs/src/system/commands/mod.rs:664:13 note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace ``` --- crates/bevy_internal/Cargo.toml | 2 +- crates/bevy_log/Cargo.toml | 4 ++++ crates/bevy_log/src/lib.rs | 16 ++++++++++++++++ 3 files changed, 21 insertions(+), 1 deletion(-) diff --git a/crates/bevy_internal/Cargo.toml b/crates/bevy_internal/Cargo.toml index 6153c0c612d98..e69427a799b1c 100644 --- a/crates/bevy_internal/Cargo.toml +++ b/crates/bevy_internal/Cargo.toml @@ -10,7 +10,7 @@ keywords = ["game", "engine", "gamedev", "graphics", "bevy"] categories = ["game-engines", "graphics", "gui", "rendering"] [features] -trace = [ "bevy_app/trace", "bevy_ecs/trace", "bevy_render/trace" ] +trace = [ "bevy_app/trace", "bevy_ecs/trace", "bevy_log/trace", "bevy_render/trace" ] trace_chrome = [ "bevy_log/tracing-chrome" ] trace_tracy = [ "bevy_log/tracing-tracy" ] wgpu_trace = ["bevy_render/wgpu_trace"] diff --git a/crates/bevy_log/Cargo.toml b/crates/bevy_log/Cargo.toml index 3bbbc3ce275fd..4a109ddfc7f8b 100644 --- a/crates/bevy_log/Cargo.toml +++ b/crates/bevy_log/Cargo.toml @@ -8,6 +8,9 @@ repository = "https://github.com/bevyengine/bevy" license = "MIT OR Apache-2.0" keywords = ["bevy"] +[features] +trace = [ "tracing-error" ] + [dependencies] bevy_app = { path = "../bevy_app", version = "0.6.0" } bevy_utils = { path = "../bevy_utils", version = "0.6.0" } @@ -16,6 +19,7 @@ tracing-subscriber = {version = "0.3.1", features = ["registry", "env-filter"]} tracing-chrome = { version = "0.4.0", optional = true } tracing-tracy = { version = "0.8.0", optional = true } tracing-log = "0.1.2" +tracing-error = { version = "0.2.0", optional = true } [target.'cfg(target_os = "android")'.dependencies] android_log-sys = "0.2.0" diff --git a/crates/bevy_log/src/lib.rs b/crates/bevy_log/src/lib.rs index 8318880970788..7c7f07f36d51b 100644 --- a/crates/bevy_log/src/lib.rs +++ b/crates/bevy_log/src/lib.rs @@ -11,6 +11,9 @@ //! For more fine-tuned control over logging behavior, insert a [`LogSettings`] resource before //! adding [`LogPlugin`] or `DefaultPlugins` during app initialization. +#[cfg(feature = "trace")] +use std::panic; + #[cfg(target_os = "android")] mod android_tracing; @@ -21,6 +24,7 @@ pub mod prelude { debug, debug_span, error, error_span, info, info_span, trace, trace_span, warn, warn_span, }; } + pub use bevy_utils::tracing::{ debug, debug_span, error, error_span, info, info_span, trace, trace_span, warn, warn_span, Level, @@ -105,6 +109,15 @@ impl Default for LogSettings { impl Plugin for LogPlugin { fn build(&self, app: &mut App) { + #[cfg(feature = "trace")] + { + let old_handler = panic::take_hook(); + panic::set_hook(Box::new(move |infos| { + println!("{}", tracing_error::SpanTrace::capture()); + old_handler(infos); + })); + } + let default_filter = { let settings = app.world.get_resource_or_insert_with(LogSettings::default); format!("{},{}", settings.level, settings.filter) @@ -115,6 +128,9 @@ impl Plugin for LogPlugin { .unwrap(); let subscriber = Registry::default().with(filter_layer); + #[cfg(feature = "trace")] + let subscriber = subscriber.with(tracing_error::ErrorLayer::default()); + #[cfg(all(not(target_arch = "wasm32"), not(target_os = "android")))] { #[cfg(feature = "tracing-chrome")]