Add a file output for "tracing" and ensure that panics are included

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"

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;

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<File>,
+    has_error: bool,
+}
+
+impl Logfile {
+    pub fn new(path: impl AsRef<Path>) -> 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<usize> {
+        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(())
+    }
+}

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 {

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()