From 18ac1259973bfb690a3891693417ab8c64b31ae0 Mon Sep 17 00:00:00 2001 From: Jos Feenstra Date: Tue, 5 Dec 2023 02:56:40 +0100 Subject: [PATCH] Add helper macro's for logging only once (#10808) # Objective Fixes #10291 This adds a way to easily log messages once within system which are called every frame. ## Solution Opted for a macro-based approach. The fact that the 'once' call is tracked per call site makes the `log_once!()` macro very versatile and easy-to-use. I suspect it will be very handy for all of us, but especially beginners, to get some initial feedback from systems without spamming up the place! I've made the macro's return its internal `has_fired` state, for situations in which that might be useful to know (trigger something else alongside the log, for example). Please let me know if I placed the macro's in the right location, and if you would like me to do something more clever with the macro's themselves, since its looking quite copy-pastey at the moment. I've tried ways to replace 5 with 1 macro's, but no success yet. One downside of this approach is: Say you wish to warn the user if a resource is invalid. In this situation, the `resource.is_valid()` check would still be performed every frame: ```rust fn my_system(my_res: Res) { if !my_res.is_valid() { warn_once!("resource is invalid!"); } } ``` If you want to prevent that, you would still need to introduce a local boolean. I don't think this is a very big deal, as expensive checks shouldn't be called every frame in any case. ## Changelog Added: `trace_once!()`, `debug_once!()`, `info_once!()`, `warn_once!()`, and `error_once!()` log macros which fire only once per call site. --- crates/bevy_log/src/lib.rs | 4 +++ crates/bevy_log/src/once.rs | 62 +++++++++++++++++++++++++++++++++++++ examples/app/logs.rs | 28 +++++++++++++++++ 3 files changed, 94 insertions(+) create mode 100644 crates/bevy_log/src/once.rs diff --git a/crates/bevy_log/src/lib.rs b/crates/bevy_log/src/lib.rs index cc8d3e7a47100..bab058535e4c2 100644 --- a/crates/bevy_log/src/lib.rs +++ b/crates/bevy_log/src/lib.rs @@ -11,6 +11,8 @@ //! For more fine-tuned control over logging behavior, set up the [`LogPlugin`] or //! `DefaultPlugins` during app initialization. +mod once; + #[cfg(feature = "trace")] use std::panic; @@ -28,6 +30,8 @@ pub mod prelude { pub use bevy_utils::tracing::{ debug, debug_span, error, error_span, info, info_span, trace, trace_span, warn, warn_span, }; + + pub use crate::{debug_once, error_once, info_once, trace_once, warn_once}; } pub use bevy_utils::tracing::{ diff --git a/crates/bevy_log/src/once.rs b/crates/bevy_log/src/once.rs new file mode 100644 index 0000000000000..9cac9f22e121b --- /dev/null +++ b/crates/bevy_log/src/once.rs @@ -0,0 +1,62 @@ +/// Call some expression only once per call site. +#[macro_export] +macro_rules! once { + ($expression:expr) => {{ + use ::std::sync::atomic::{AtomicBool, Ordering}; + + static SHOULD_FIRE: AtomicBool = AtomicBool::new(true); + if SHOULD_FIRE.swap(false, Ordering::Relaxed) { + $expression; + } + }}; +} + +/// Call [`trace!`](crate::trace) once per call site. +/// +/// Useful for logging within systems which are called every frame. +#[macro_export] +macro_rules! trace_once { + ($($arg:tt)+) => ({ + $crate::once!($crate::trace!($($arg)+)) + }); +} + +/// Call [`debug!`](crate::debug) once per call site. +/// +/// Useful for logging within systems which are called every frame. +#[macro_export] +macro_rules! debug_once { + ($($arg:tt)+) => ({ + $crate::once!($crate::debug!($($arg)+)) + }); +} + +/// Call [`info!`](crate::info) once per call site. +/// +/// Useful for logging within systems which are called every frame. +#[macro_export] +macro_rules! info_once { + ($($arg:tt)+) => ({ + $crate::once!($crate::info!($($arg)+)) + }); +} + +/// Call [`warn!`](crate::warn) once per call site. +/// +/// Useful for logging within systems which are called every frame. +#[macro_export] +macro_rules! warn_once { + ($($arg:tt)+) => ({ + $crate::once!($crate::warn!($($arg)+)) + }); +} + +/// Call [`error!`](crate::error) once per call site. +/// +/// Useful for logging within systems which are called every frame. +#[macro_export] +macro_rules! error_once { + ($($arg:tt)+) => ({ + $crate::once!($crate::error!($($arg)+)) + }); +} diff --git a/examples/app/logs.rs b/examples/app/logs.rs index 17fd51dfda46e..797fd85fc121b 100644 --- a/examples/app/logs.rs +++ b/examples/app/logs.rs @@ -1,5 +1,6 @@ //! This example illustrates how to use logs in bevy. +use bevy::log::once; use bevy::prelude::*; fn main() { @@ -11,6 +12,7 @@ fn main() { ..default() })) .add_systems(Update, log_system) + .add_systems(Update, log_once_system) .run(); } @@ -30,3 +32,29 @@ fn log_system() { // the format used here is super flexible. check out this documentation for more info: // https://docs.rs/tracing-subscriber/*/tracing_subscriber/filter/struct.EnvFilter.html } + +fn log_once_system() { + // The 'once' variants of each log level are useful when a system is called every frame, + // but we still wish to inform the user only once. In other words, use these to prevent spam :) + + trace_once!("one time noisy message"); + debug_once!("one time debug message"); + info_once!("some info which is printed only once"); + warn_once!("some warning we wish to call out only once"); + error_once!("some error we wish to report only once"); + + for i in 0..10 { + info_once!("logs once per call site, so this works just fine: {}", i); + } + + // you can also use the 'once!' macro directly, in situations you want do do + // something expensive only once within the context of a continous system. + once!({ + info!("doing expensive things"); + let mut a: u64 = 0; + for i in 0..100000000 { + a += i; + } + info!("result of some expensive one time calculation: {}", a); + }); +}