From 48cb92b5e39c383764ec94077522eef1998fb2c6 Mon Sep 17 00:00:00 2001 From: Esper Thomson Date: Mon, 30 Sep 2024 16:47:34 -0400 Subject: [PATCH 1/5] Fix unnecessary unsafe code usage in `logging.rs`. --- astro_modloader/src/logging.rs | 69 +++++++++++++++------------------- 1 file changed, 30 insertions(+), 39 deletions(-) diff --git a/astro_modloader/src/logging.rs b/astro_modloader/src/logging.rs index 21701bf..831287a 100644 --- a/astro_modloader/src/logging.rs +++ b/astro_modloader/src/logging.rs @@ -1,11 +1,14 @@ use std::fs; use std::io::prelude::*; +use std::sync::OnceLock; use colored::*; use log::{Level, LevelFilter, Metadata, Record, SetLoggerError}; #[derive(Debug)] -struct SimpleLogger; +struct SimpleLogger { + file: fs::File, +} impl log::Log for SimpleLogger { fn enabled(&self, metadata: &Metadata) -> bool { @@ -34,58 +37,46 @@ impl log::Log for SimpleLogger { }; println!( - "{}{:<5} {}:{}{} {}", + "{}{level:<5} {file_path}:{}{} {}", "[".truecolor(100, 100, 100), - level, - file_path, record.line().unwrap_or(0), "]".truecolor(100, 100, 100), record.args() ); } - // we need unsafe to write to a global variable - unsafe { - let level = match record.level() { - Level::Error => "ERROR", - Level::Warn => "WARN", - Level::Info => "INFO", - Level::Debug => "DEBUG", - Level::Trace => "TRACE", - }; + let level = match record.level() { + Level::Error => "ERROR", + Level::Warn => "WARN", + Level::Info => "INFO", + Level::Debug => "DEBUG", + Level::Trace => "TRACE", + }; - writeln!( - LOG_FILE.as_ref().unwrap(), - "[{:<5} {}:{}] {}", - level, - file_path, - record.line().unwrap_or(0), - record.args() - ) - .unwrap(); - } + writeln!( + &self.file, + "[{level:<5} {file_path}:{}] {}", + record.line().unwrap_or(0), + record.args() + ) + .unwrap(); } } fn flush(&self) {} } -static LOGGER: SimpleLogger = SimpleLogger; -static mut LOG_FILE: Option = None; - pub fn init() -> Result<(), SetLoggerError> { - // open file - // unsafe because I'm too lazy to properly handle the file - unsafe { - LOG_FILE = Some( - fs::OpenOptions::new() - .write(true) - .create(true) - .truncate(true) - .open("modloader_log.txt") - .unwrap(), - ); - } + static LOGGER: OnceLock = OnceLock::new(); + let logger = LOGGER.get_or_init(|| SimpleLogger { + // open file + file: fs::OpenOptions::new() + .write(true) + .create(true) + .truncate(true) + .open("modloader_log.txt") + .unwrap(), + }); - log::set_logger(&LOGGER).map(|()| log::set_max_level(LevelFilter::Trace)) + log::set_logger(logger).map(|()| log::set_max_level(LevelFilter::Trace)) } From effbe57b30345aa3f62c5f066e18142455f94cd7 Mon Sep 17 00:00:00 2001 From: Esper Thomson Date: Mon, 30 Sep 2024 17:02:23 -0400 Subject: [PATCH 2/5] Flush logger on shutdown. --- astro_modloader/src/logging.rs | 22 +++++++++++++++------- astro_modloader/src/main.rs | 2 ++ 2 files changed, 17 insertions(+), 7 deletions(-) diff --git a/astro_modloader/src/logging.rs b/astro_modloader/src/logging.rs index 831287a..16ece28 100644 --- a/astro_modloader/src/logging.rs +++ b/astro_modloader/src/logging.rs @@ -3,14 +3,14 @@ use std::io::prelude::*; use std::sync::OnceLock; use colored::*; -use log::{Level, LevelFilter, Metadata, Record, SetLoggerError}; +use log::{Level, LevelFilter, Log, Metadata, Record, SetLoggerError}; #[derive(Debug)] struct SimpleLogger { file: fs::File, } -impl log::Log for SimpleLogger { +impl Log for SimpleLogger { fn enabled(&self, metadata: &Metadata) -> bool { metadata.level() <= Level::Trace } @@ -63,12 +63,14 @@ impl log::Log for SimpleLogger { } } - fn flush(&self) {} + fn flush(&self) { + (&self.file).flush().unwrap() + } } -pub fn init() -> Result<(), SetLoggerError> { +fn get_logger() -> &'static SimpleLogger { static LOGGER: OnceLock = OnceLock::new(); - let logger = LOGGER.get_or_init(|| SimpleLogger { + LOGGER.get_or_init(|| SimpleLogger { // open file file: fs::OpenOptions::new() .write(true) @@ -76,7 +78,13 @@ pub fn init() -> Result<(), SetLoggerError> { .truncate(true) .open("modloader_log.txt") .unwrap(), - }); + }) +} + +pub fn init() -> Result<(), SetLoggerError> { + log::set_logger(get_logger()).map(|()| log::set_max_level(LevelFilter::Trace)) +} - log::set_logger(logger).map(|()| log::set_max_level(LevelFilter::Trace)) +pub fn flush() { + get_logger().flush() } diff --git a/astro_modloader/src/main.rs b/astro_modloader/src/main.rs index 761555d..f6703d1 100644 --- a/astro_modloader/src/main.rs +++ b/astro_modloader/src/main.rs @@ -246,4 +246,6 @@ fn main() { let config = AstroGameConfig; unreal_mod_manager::run(config); + + logging::flush(); } From 3618c2fbc14a2d66d269e6026630527f128aaa41 Mon Sep 17 00:00:00 2001 From: Esper Thomson Date: Mon, 30 Sep 2024 17:23:58 -0400 Subject: [PATCH 3/5] Fix log interleaving when logging from multiple threads. --- astro_modloader/src/logging.rs | 45 ++++++++++++++++++++++------------ 1 file changed, 30 insertions(+), 15 deletions(-) diff --git a/astro_modloader/src/logging.rs b/astro_modloader/src/logging.rs index 16ece28..892269e 100644 --- a/astro_modloader/src/logging.rs +++ b/astro_modloader/src/logging.rs @@ -1,13 +1,24 @@ use std::fs; use std::io::prelude::*; -use std::sync::OnceLock; +use std::sync::{Mutex, OnceLock}; use colored::*; use log::{Level, LevelFilter, Log, Metadata, Record, SetLoggerError}; #[derive(Debug)] struct SimpleLogger { - file: fs::File, + file: Mutex, +} + +impl SimpleLogger { + fn lock(&self, f: impl FnOnce(&mut fs::File) -> T) -> T { + let mut guard = match self.file.lock() { + Ok(guard) => guard, + Err(err) => err.into_inner(), + }; + + f(&mut guard) + } } impl Log for SimpleLogger { @@ -53,18 +64,20 @@ impl Log for SimpleLogger { Level::Trace => "TRACE", }; - writeln!( - &self.file, - "[{level:<5} {file_path}:{}] {}", - record.line().unwrap_or(0), - record.args() - ) + self.lock(|file| { + writeln!( + file, + "[{level:<5} {file_path}:{}] {}", + record.line().unwrap_or(0), + record.args() + ) + }) .unwrap(); } } fn flush(&self) { - (&self.file).flush().unwrap() + self.lock(|file| file.flush()).unwrap() } } @@ -72,12 +85,14 @@ fn get_logger() -> &'static SimpleLogger { static LOGGER: OnceLock = OnceLock::new(); LOGGER.get_or_init(|| SimpleLogger { // open file - file: fs::OpenOptions::new() - .write(true) - .create(true) - .truncate(true) - .open("modloader_log.txt") - .unwrap(), + file: Mutex::new( + fs::OpenOptions::new() + .write(true) + .create(true) + .truncate(true) + .open("modloader_log.txt") + .unwrap(), + ), }) } From 00e1bea43942dd8f16533982f8f68aa0939307ec Mon Sep 17 00:00:00 2001 From: Esper Thomson Date: Mon, 30 Sep 2024 17:51:54 -0400 Subject: [PATCH 4/5] Add `BufWriter` wrapper for performance. --- astro_modloader/src/logging.rs | 19 ++++++++++++------- 1 file changed, 12 insertions(+), 7 deletions(-) diff --git a/astro_modloader/src/logging.rs b/astro_modloader/src/logging.rs index 892269e..f27f288 100644 --- a/astro_modloader/src/logging.rs +++ b/astro_modloader/src/logging.rs @@ -1,5 +1,5 @@ use std::fs; -use std::io::prelude::*; +use std::io::{prelude::*, BufWriter}; use std::sync::{Mutex, OnceLock}; use colored::*; @@ -7,11 +7,17 @@ use log::{Level, LevelFilter, Log, Metadata, Record, SetLoggerError}; #[derive(Debug)] struct SimpleLogger { - file: Mutex, + file: Mutex>, } impl SimpleLogger { - fn lock(&self, f: impl FnOnce(&mut fs::File) -> T) -> T { + fn new(file: fs::File) -> Self { + SimpleLogger { + file: Mutex::new(BufWriter::new(file)), + } + } + + fn lock(&self, f: impl FnOnce(&mut BufWriter) -> T) -> T { let mut guard = match self.file.lock() { Ok(guard) => guard, Err(err) => err.into_inner(), @@ -83,16 +89,15 @@ impl Log for SimpleLogger { fn get_logger() -> &'static SimpleLogger { static LOGGER: OnceLock = OnceLock::new(); - LOGGER.get_or_init(|| SimpleLogger { - // open file - file: Mutex::new( + LOGGER.get_or_init(|| { + SimpleLogger::new( fs::OpenOptions::new() .write(true) .create(true) .truncate(true) .open("modloader_log.txt") .unwrap(), - ), + ) }) } From a599b19370957a952c22997c0aa19b565bba6f02 Mon Sep 17 00:00:00 2001 From: Esper Thomson Date: Thu, 3 Oct 2024 04:08:37 -0400 Subject: [PATCH 5/5] Add comments. --- astro_modloader/src/logging.rs | 3 +++ 1 file changed, 3 insertions(+) diff --git a/astro_modloader/src/logging.rs b/astro_modloader/src/logging.rs index f27f288..e72349b 100644 --- a/astro_modloader/src/logging.rs +++ b/astro_modloader/src/logging.rs @@ -7,6 +7,7 @@ use log::{Level, LevelFilter, Log, Metadata, Record, SetLoggerError}; #[derive(Debug)] struct SimpleLogger { + // Synchronize log entries file: Mutex>, } @@ -18,6 +19,7 @@ impl SimpleLogger { } fn lock(&self, f: impl FnOnce(&mut BufWriter) -> T) -> T { + // Ignore log mutex poison let mut guard = match self.file.lock() { Ok(guard) => guard, Err(err) => err.into_inner(), @@ -91,6 +93,7 @@ fn get_logger() -> &'static SimpleLogger { static LOGGER: OnceLock = OnceLock::new(); LOGGER.get_or_init(|| { SimpleLogger::new( + // Open file fs::OpenOptions::new() .write(true) .create(true)