bones_framework/
logging.rs

1//! Logging module for bones. Provides implementation of global tracing subscriber and panic hook.
2//!
3//! Enabled with feature "logging". See docs of [`setup_logging`] for details + usage.
4#![allow(clippy::needless_doctest_main)]
5
6use std::{
7    backtrace::{Backtrace, BacktraceStatus},
8    error::Error,
9    panic::PanicHookInfo,
10    path::PathBuf,
11};
12
13#[allow(unused_imports)]
14use tracing_appender::rolling::{RollingFileAppender, Rotation};
15use tracing_subscriber::{
16    filter::{FromEnvError, ParseError},
17    layer::SubscriberExt,
18    EnvFilter, Layer, Registry,
19};
20
21#[allow(unused_imports)]
22use tracing::{error, warn, Level};
23
24use bones_asset::HasSchema;
25use bones_lib::prelude::Deref;
26
27/// Logging prelude
28pub mod prelude {
29    pub use super::{
30        macros::setup_logs, setup_logging, setup_logging_default, LogFileConfig, LogFileError,
31        LogFileRotation, LogPath, LogSettings,
32    };
33}
34
35pub use macros::setup_logs;
36
37/// A boxed [`Layer`] that can be used with [`setup_logging`].
38pub type BoxedLayer = Box<dyn Layer<Registry> + Send + Sync + 'static>;
39
40/// Plugin to enable tracing. Configures global tracing subscriber.
41pub struct LogSettings {
42    /// Filters logs using the [`EnvFilter`] format
43    pub filter: String,
44
45    /// Filters out logs that are "less than" the given level.
46    /// This can be further filtered using the `filter` setting.
47    pub level: tracing::Level,
48
49    /// Optionally add an extra [`Layer`] to the tracing subscriber
50    ///
51    /// This function is only called once, when logging is initialized.
52    ///
53    /// Because [`BoxedLayer`] takes a `dyn Layer`, `Vec<Layer>` is also an acceptable return value.
54    pub custom_layer: fn() -> Option<BoxedLayer>,
55
56    /// The (qualifier, organization, application) that will be used to pick a persistent storage
57    /// location for the game.
58    ///
59    /// For example: `("org", "fishfolk", "jumpy")`
60    ///
61    /// Used to determine directory to write log files if
62    // pub app_namespace: Option<(String, String, String)>,
63
64    /// Set to write log output to file system. Not supported on wasm.
65    pub log_file: Option<LogFileConfig>,
66}
67
68impl Default for LogSettings {
69    fn default() -> Self {
70        Self {
71            filter: "wgpu=error,naga=warn".to_string(),
72            level: Level::INFO,
73            custom_layer: || None,
74            log_file: None,
75        }
76    }
77}
78
79/// How often to rotate log file.
80#[derive(Copy, Clone, Default)]
81#[allow(missing_docs)]
82pub enum LogFileRotation {
83    Minutely,
84    Hourly,
85    #[default]
86    Daily,
87    Never,
88}
89
90impl From<LogFileRotation> for tracing_appender::rolling::Rotation {
91    fn from(value: LogFileRotation) -> Self {
92        match value {
93            LogFileRotation::Minutely => Rotation::MINUTELY,
94            LogFileRotation::Hourly => Rotation::HOURLY,
95            LogFileRotation::Daily => Rotation::DAILY,
96            LogFileRotation::Never => Rotation::NEVER,
97        }
98    }
99}
100
101/// Error for file logging.
102#[derive(Debug, thiserror::Error)]
103pub enum LogFileError {
104    /// Failed to determine a log directory.
105    #[error("Could not determine log dir: {0}")]
106    LogDirFail(String),
107    /// Attempted to setup file logging on unsupported platform.
108    #[error("Logging to file system is unsupported on platform: {0}")]
109    Unsupported(String),
110}
111
112/// Path to save log files. [`LogPath::find_app_data_dir`] may be used to
113/// to automatically find OS appropriate app data path from app namespace strings, e.g. ("org", "fishfolk", "jumpy")
114#[derive(Clone, Deref)]
115pub struct LogPath(pub PathBuf);
116
117impl LogPath {
118    /// Find OS app data path for provided app namespace (e.g. ("org", "fishfolk", "jumpy"))
119    ///
120    /// Will error if failed to resole this directory for OS or on unsupported platform such as wasm.
121    ///
122    /// i.e. ~/.local/share/org.fishfolk.jumpy/logs,
123    //       C:\Users\<User>\Appdata\Roaming\org.fishfolk.jumpy\logs,
124    ///      ~/Library/Application Support/org.fishfolk.jumpy/logs
125    #[allow(unused_variables)]
126    pub fn find_app_data_dir(app_namespace: (&str, &str, &str)) -> Result<Self, LogFileError> {
127        // Don't run this during tests, as Miri CI does not support the syscall.
128        #[cfg(not(target_arch = "wasm32"))]
129        {
130            directories::ProjectDirs::from(app_namespace.0, app_namespace.1, app_namespace.2)
131                // error message from `ProjectDirs::from` docs
132                .ok_or(LogFileError::LogDirFail(
133                    "no valid home directory path could be retrieved from the operating system"
134                        .to_string(),
135                ))
136                .map(|dirs| LogPath(dirs.data_dir().join("logs")))
137        }
138
139        #[cfg(target_arch = "wasm32")]
140        {
141            Err(LogFileError::Unsupported("wasm32".to_string()))
142        }
143    }
144}
145
146/// Settings to enable writing tracing output to files.
147pub struct LogFileConfig {
148    /// Path to store log files - use [`LogPath`]'s helper function to find good default path.
149    pub log_path: LogPath,
150
151    /// How often to rotate log file.
152    pub rotation: LogFileRotation,
153
154    /// Beginning of log file name (e.g. "Jumpy.log"), timestamp will be appended to this
155    /// if using rotatig logs.
156    pub file_name_prefix: String,
157
158    /// If set, will cleanup the oldest log files in directory that match `file_name_prefix` until under max
159    /// file count. Otherwise no log files will be cleaned up.
160    pub max_log_files: Option<usize>,
161}
162
163/// Guard for file logging thread, this should be held onto for duration of app, if dropped
164/// writing to log file will stop.
165///
166/// It is recommended to hold onto this in main() to ensure all logs are flushed when app is
167/// exiting. See [`tracing_appender::non_blocking::WorkerGuard`] docs for details.
168#[derive(HasSchema)]
169#[schema(no_clone, no_default)]
170#[allow(dead_code)]
171pub struct LogFileGuard(tracing_appender::non_blocking::WorkerGuard);
172
173impl Drop for LogFileGuard {
174    fn drop(&mut self) {
175        warn!("LogFileGuard dropped - flushing buffered tracing to file, no further tracing will be written to file. If unexpected, make sure bones logging init is done in root scope of app.");
176    }
177}
178
179/// Setup the global tracing subscriber, add hook for tracing panics, and optionally enable logging to file system.
180///
181/// This function sets panic hook to call [`tracing_panic_hook`], and then call previous hook. This writes panics to
182/// tracing subscribers. This is helpful for recording panics when logging to file system.
183///
184/// if [`LogFileConfig`] was provided in settings and is supported on this platform (cannot log to file system on wasm),
185/// this function will return a [`LogFileGuard`]. This must be kept alive for duration of process to capture all logs,
186/// see [`LogFileGuard`] docs.
187///
188/// Examples below show direct usage and short-hand with [`setup_logs`] macro.
189///
190/// # Examples
191///
192/// ### Default without logging to file
193/// ```
194/// use bones_framework::logging::prelude::*;
195/// fn main() {
196///     let _log_guard = bones_framework::logging::setup_logging(LogSettings::default());
197/// }
198/// ```
199/// or
200/// ```
201/// use bones_framework::logging::prelude::*;
202/// fn main() {
203///     setup_logs!();
204/// }
205/// ```
206///
207/// ### Enable logging including logging to files:
208/// ```no_run
209/// use bones_framework::prelude::*;
210/// fn main() {
211///     let log_file =
212///         match LogPath::find_app_data_dir(("org", "fishfolk", "jumpy")) {
213///             Ok(log_path) => Some(LogFileConfig {
214///                 log_path,
215///                 rotation: LogFileRotation::Daily,
216///                 file_name_prefix: "Jumpy.log".to_string(),
217///                 max_log_files: Some(7),
218///             }),
219///             Err(err) => {
220///                 // Cannot use error! macro as logging not configured yet.
221///                 eprintln!("Failed to configure file logging: {err}");
222///                 None
223///             }
224///         };
225///
226///     // _log_guard will be dropped when main exits, remains alive for duration of program.
227///     let _log_guard = bones_framework::logging::setup_logging(LogSettings {
228///         log_file,
229///         ..default()
230///     });
231/// }
232/// ```
233/// or logging to file with defaults:
234/// ```no_run
235/// use bones_framework::logging::prelude::*;
236/// fn main() {
237///     let _log_guard = bones_framework::logging::setup_logging_default(("org", "fishfolk", "jumpy"));
238/// }
239/// ```
240/// same with [`macros::setup_logs`] macro:
241/// ```no_run
242/// use bones_framework::prelude::*;
243/// fn main() {
244///     setup_logs!("org", "fishfolk", "jumpy");
245/// }
246/// ```
247///
248///
249#[must_use]
250pub fn setup_logging(settings: LogSettings) -> Option<LogFileGuard> {
251    // Preserve current panic hook, and call `tracing_panic_hook` to send panic and possibly backtrace to
252    // tracing subscribers, and not just stderr.
253    let prev_hook = std::panic::take_hook();
254    std::panic::set_hook(Box::new(move |panic_info| {
255        tracing_panic_hook(panic_info);
256        prev_hook(panic_info);
257    }));
258
259    let finished_subscriber;
260    let subscriber = Registry::default();
261
262    // add optional layer provided by user
263    let subscriber = subscriber.with((settings.custom_layer)());
264
265    let default_filter = { format!("{},{}", settings.level, settings.filter) };
266    let filter_layer = EnvFilter::try_from_default_env()
267        .or_else(|from_env_error| {
268            _ = from_env_error
269                .source()
270                .and_then(|source| source.downcast_ref::<ParseError>())
271                .map(|parse_err| {
272                    // we cannot use the `error!` macro here because the logger is not ready yet.
273                    eprintln!(
274                        "setup_logging() failed to parse filter from env: {}",
275                        parse_err
276                    );
277                });
278
279            Ok::<EnvFilter, FromEnvError>(EnvFilter::builder().parse_lossy(&default_filter))
280        })
281        .unwrap();
282    let subscriber = subscriber.with(filter_layer);
283
284    let log_file_guard;
285    #[cfg(not(target_arch = "wasm32"))]
286    {
287        let (file_layer, file_guard) = match &settings.log_file {
288            Some(log_file) => {
289                let LogFileConfig {
290                    log_path,
291                    rotation,
292                    file_name_prefix,
293                    max_log_files,
294                } = log_file;
295
296                let file_appender = RollingFileAppender::builder()
297                    .filename_prefix(file_name_prefix)
298                    .rotation((*rotation).into());
299
300                let file_appender = match *max_log_files {
301                    Some(max) => file_appender.max_log_files(max),
302                    None => file_appender,
303                };
304
305                match file_appender.build(&**log_path) {
306                    Ok(file_appender) => {
307                        let (non_blocking, _guard) = tracing_appender::non_blocking(file_appender);
308                        let file_layer = tracing_subscriber::fmt::Layer::default()
309                            .with_ansi(false)
310                            .with_writer(non_blocking);
311                        (Some(file_layer), Some(LogFileGuard(_guard)))
312                    }
313                    Err(err) => {
314                        // we cannot use the `error!` macro here because the logger is not ready yet.
315                        eprintln!("Failed to configure tracing_appender layer for logging to file system - {err}");
316                        (None, None)
317                    }
318                }
319            }
320            None => (None, None),
321        };
322        let subscriber = subscriber.with(file_layer);
323        log_file_guard = file_guard;
324
325        #[cfg(feature = "tracing-tracy")]
326        let tracy_layer = tracing_tracy::TracyLayer::default();
327
328        // note: the implementation of `Default` reads from the env var NO_COLOR
329        // to decide whether to use ANSI color codes, which is common convention
330        // https://no-color.org/
331        let fmt_layer = tracing_subscriber::fmt::Layer::default();
332
333        // bevy_render::renderer logs a `tracy.frame_mark` event every frame
334        // at Level::INFO. Formatted logs should omit it.
335        #[cfg(feature = "tracing-tracy")]
336        let fmt_layer = fmt_layer.with_filter(tracing_subscriber::filter::FilterFn::new(|meta| {
337            meta.fields().field("tracy.frame_mark").is_none()
338        }));
339
340        let subscriber = subscriber.with(fmt_layer);
341
342        #[cfg(feature = "tracing-tracy")]
343        let subscriber = subscriber.with(tracy_layer);
344        finished_subscriber = subscriber;
345    }
346
347    #[cfg(target_arch = "wasm32")]
348    {
349        finished_subscriber = subscriber.with(tracing_wasm::WASMLayer::new(
350            tracing_wasm::WASMLayerConfig::default(),
351        ));
352        log_file_guard = None;
353    }
354
355    if let Err(err) = tracing::subscriber::set_global_default(finished_subscriber) {
356        error!("{err} - `setup_logging` was called and configures global subscriber. Game may either setup subscriber itself, or call `setup_logging` from bones, but not both.");
357    }
358
359    #[cfg(target_arch = "wasm32")]
360    {
361        if settings.log_file.is_some() {
362            // Report this warning after setting up tracing subscriber so it will show up on wasm.
363            warn!("bones_framework::setup_logging() - `LogFileConfig` provided, however logging to file system is not supported in wasm.");
364        }
365    }
366
367    log_file_guard
368}
369
370/// Helper to call [`setup_logging`] conciseably with reasonable defaults for logging to console and file system.
371///
372/// This uses default [`LogSettings`] with addition of enabling logging to files. If logging to file is not desired,
373/// you can call `setup_logging(LogSettings::default())` instead.
374///
375/// See [`setup_logging`] docs for details.
376#[must_use]
377pub fn setup_logging_default(app_namespace: (&str, &str, &str)) -> Option<LogFileGuard> {
378    let file_name_prefix = format!("{}.log", app_namespace.2);
379    let log_file =
380        match LogPath::find_app_data_dir((app_namespace.0, app_namespace.1, app_namespace.2)) {
381            Ok(log_path) => Some(LogFileConfig {
382                log_path,
383                rotation: LogFileRotation::Daily,
384                file_name_prefix,
385                max_log_files: Some(7),
386            }),
387            Err(err) => {
388                // Cannot use error! macro as logging not configured yet.
389                eprintln!("Failed to configure file logging: {err}");
390                None
391            }
392        };
393
394    // _log_guard will be dropped when main exits, remains alive for duration of program.
395    setup_logging(LogSettings {
396        log_file,
397        ..Default::default()
398    })
399}
400
401/// Logging macros
402#[macro_use]
403pub mod macros {
404
405    /// [`setup_logs`] is a macro for initializing logging in bones.
406    ///
407    /// It wraps a call to [`super::setup_logging`] (see docs for details on configuration options).
408    ///
409    /// Warning: There may be issues if not called in root scope of app (e.g. in `main()`).
410    /// Macro expands to: `let _guard = setup_logging(...);`, if `_guard` is dropped, any logging to
411    /// file system will stop (console logging unimpacted).
412    ///
413    /// Usage for log defaults (logging to file system included):
414    /// ```no_run
415    /// use bones_framework::prelude::*;
416    /// setup_logs!("org", "fishfolk", "jumpy");
417    /// ```
418    ///
419    /// Usage for log defaults (without logging to file system):
420    /// ```
421    /// use bones_framework::prelude::*;
422    /// setup_logs!();
423    /// ```
424    #[macro_export]
425    macro_rules! setup_logs {
426        // LogSettings::default() -
427        //   setup_logs!();
428        () => {
429            use bones_framework::logging::setup_logging;
430            use bones_framework::logging::LogSettings;
431            let _log_file_guard = setup_logging(LogSettings::default());
432        };
433        // With LogSettings identifier -
434        //   let settings = LogSettings::{...};
435        //   setup_logs!(settings);
436        ($settings:ident) => {
437            use bones_framework::logging::setup_logging;
438            let _log_file_guard = setup_logging($settings);
439        };
440        // setup_logging_default from app namespace -
441        //   setup_logs!(("org", "fishfolk", "jumpy"));
442        ($app_namespace:expr) => {
443            use bones_framework::logging::setup_logging_default;
444            let _log_file_guard = setup_logging_default($app_namespace);
445        };
446        // setup_logging_default from app namespace -
447        //   setup_logs!("org", "fishfolk", "jumpy");
448        ($app_ns1:expr, $app_ns2:expr, $app_ns3:expr) => {
449            use bones_framework::logging::setup_logging_default;
450            let _log_file_guard = setup_logging_default(($app_ns1, $app_ns2, $app_ns3));
451        };
452    }
453    pub use setup_logs;
454}
455
456/// Panic hook that sends panic payload to [`tracing::error`], and backtrace if available.
457///
458/// This hook is enabled in [`setup_logging`] to make sure panics are traced.
459pub fn tracing_panic_hook(panic_info: &PanicHookInfo) {
460    let payload = panic_info.payload();
461
462    let payload = if let Some(s) = payload.downcast_ref::<&str>() {
463        Some(*s)
464    } else {
465        payload.downcast_ref::<String>().map(|s| s.as_str())
466    };
467
468    let location = panic_info.location().map(|l| l.to_string());
469    let (backtrace, note) = {
470        let backtrace = Backtrace::capture();
471        let note = (backtrace.status() == BacktraceStatus::Disabled)
472            .then_some("run with RUST_BACKTRACE=1 environment variable to display a backtrace");
473        (Some(backtrace), note)
474    };
475
476    tracing::error!(
477        panic.payload = payload,
478        panic.location = location,
479        panic.backtrace = backtrace.map(tracing::field::display),
480        panic.note = note,
481        "A panic occurred",
482    );
483}