diff --git a/Cargo.lock b/Cargo.lock index 79339485..1d21c170 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -427,6 +427,7 @@ dependencies = [ "tokio", "toml", "tracing", + "tracing-appender", "vk-shader-macros", "webpki", "winit", @@ -624,6 +625,15 @@ dependencies = [ "itertools 0.13.0", ] +[[package]] +name = "crossbeam-channel" +version = "0.5.15" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "82b8f8f868b36967f9606790d1903570de9ceaf870a7bf9fbbd3016d636a2cb2" +dependencies = [ + "crossbeam-utils", +] + [[package]] name = "crossbeam-deque" version = "0.8.6" @@ -3102,6 +3112,18 @@ dependencies = [ "tracing-core", ] +[[package]] +name = "tracing-appender" +version = "0.2.4" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "786d480bce6247ab75f005b14ae1624ad978d3029d9113f0a22fa1ac773faeaf" +dependencies = [ + "crossbeam-channel", + "thiserror 2.0.18", + "time", + "tracing-subscriber", +] + [[package]] name = "tracing-attributes" version = "0.1.31" diff --git a/client/Cargo.toml b/client/Cargo.toml index 03d9c9aa..deaa4249 100644 --- a/client/Cargo.toml +++ b/client/Cargo.toml @@ -12,6 +12,7 @@ license = "Apache-2.0 OR Zlib" common = { path = "../common" } server = { path = "../server" } tracing = "0.1.10" +tracing-appender = "0.2.4" ash = { version = "0.38.0", default-features = false, features = ["loaded", "debug", "std"] } lahar = { git = "https://github.com/Ralith/lahar", rev = "7963ae5750ea61fa0a894dbb73d3be0ac77255d2" } yakui = "0.3.0" diff --git a/client/src/lib.rs b/client/src/lib.rs index 75d3a940..ffe23824 100644 --- a/client/src/lib.rs +++ b/client/src/lib.rs @@ -16,6 +16,7 @@ pub mod graphics; mod lahar_deprecated; mod loader; mod local_character_controller; +pub mod logfile; pub mod metrics; pub mod net; mod prediction; diff --git a/client/src/logfile.rs b/client/src/logfile.rs new file mode 100644 index 00000000..1f7057ed --- /dev/null +++ b/client/src/logfile.rs @@ -0,0 +1,81 @@ +use std::{ + fs::{self, File, OpenOptions}, + io, + path::{Path, PathBuf}, +}; + +use common::Anonymize; + +// Currently, the "tracing" crate does not have an implementation for logging to a file that has all the +// properties we want: Creating a fresh file per run of the game. Because of this, we use a custom +// logging implementation instead. +pub struct Logfile { + path: PathBuf, + file: Option, + has_error: bool, +} + +impl Logfile { + pub fn new(path: impl AsRef) -> Self { + Self { + path: path.as_ref().to_path_buf(), + file: None, + has_error: false, + } + } +} + +impl io::Write for Logfile { + fn write(&mut self, buf: &[u8]) -> io::Result { + let file = match self.file { + Some(ref mut file) => file, + None => loop { + if self.has_error { + // If we are in the error state, don't keep attempting to create or rename a file. + return Ok(buf.len()); + } + match OpenOptions::new() + .write(true) + .create_new(true) + .open(&self.path) + { + Ok(file) => { + tracing::info!("Created log file: {}", self.path.anonymize().display()); + break self.file.insert(file); + } + Err(ref e) if e.kind() == io::ErrorKind::AlreadyExists => { + fs::rename(&self.path, self.path.with_added_extension("old")).inspect_err( + |e| { + self.has_error = true; + tracing::error!("Failed to rename old log file: {}", e) + }, + )?; + } + Err(e) => { + return Err(e).inspect_err(|e| { + self.has_error = true; + tracing::error!("Failed to create new log file: {}", e); + }); + } + } + }, + }; + file.write(buf).inspect_err(|e| { + // If we already have the file open, we should keep attempting to write to it even + // if some writes fail. However, if an error occurs, we should only report it once + // to avoid spamming the logs (especially since using "tracing" to report errors in + // "tracing" can result in a feedback loop if we are not careful). + if !self.has_error { + self.has_error = true; + tracing::error!("Failed to write to log file: {}", e); + } + }) + } + + fn flush(&mut self) -> io::Result<()> { + if let Some(ref mut file) = self.file { + file.flush()?; + } + Ok(()) + } +} diff --git a/client/src/main.rs b/client/src/main.rs index 3817e67f..754dcd5c 100644 --- a/client/src/main.rs +++ b/client/src/main.rs @@ -1,6 +1,6 @@ use std::{sync::Arc, thread}; -use client::{Config, graphics, metrics, net}; +use client::{Config, graphics, logfile::Logfile, metrics, net}; use common::{Anonymize, proto}; use save::Save; @@ -13,11 +13,30 @@ use winit::{ }; fn main() { + let dirs = directories::ProjectDirs::from("", "", "hypermine").unwrap(); + // Set up logging - common::init_tracing(); + let (non_blocking, _tracing_guard) = tracing_appender::non_blocking(Logfile::new( + dirs.data_local_dir().join("logs").join("hypermine.log"), + )); + common::init_tracing_with_logfiles(non_blocking); + + // Set up panic handler to log errors with "tracing" crate. + let default_panic_behavior = std::panic::take_hook(); + std::panic::set_hook(Box::new(move |panic_hook_info| { + // Although it's redundant, we take advantage of the default panic behavior to + // allow debugging to still work even if there's an issue with our custom logic + default_panic_behavior(panic_hook_info); + + // Afterwards, we print the panic message and line number by taking advantage of the `Display` trait of `PanicHookInfo` + tracing::error!("{}", panic_hook_info); + + // Finally, we capture a backtrace regardless of whether there is an environment variable enabling said backtrace. + tracing::error!("Backtrace:\n{}", std::backtrace::Backtrace::force_capture()); + })); + let metrics = crate::metrics::init(); - let dirs = directories::ProjectDirs::from("", "", "hypermine").unwrap(); let config = Arc::new(Config::load(&dirs)); let net = match config.server { diff --git a/common/src/lib.rs b/common/src/lib.rs index 6e3cf06e..87c43c05 100644 --- a/common/src/lib.rs +++ b/common/src/lib.rs @@ -99,7 +99,23 @@ pub fn init_tracing() { tracing_subscriber().init(); } -fn tracing_subscriber() -> impl tracing::Subscriber { +pub fn init_tracing_with_logfiles( + writer: impl for<'a> tracing_subscriber::fmt::MakeWriter<'a> + Send + Sync + 'static, +) { + use tracing_subscriber::{layer::SubscriberExt, util::SubscriberInitExt}; + + tracing_subscriber() + .with( + tracing_subscriber::fmt::layer() + .with_target(false) + .with_ansi(false) + .with_writer(writer), + ) + .init(); +} + +fn tracing_subscriber() +-> impl tracing::Subscriber + for<'a> tracing_subscriber::registry::LookupSpan<'a> { use tracing_subscriber::{filter, fmt, layer::SubscriberExt, registry}; registry()