Logging #26

Open
leon wants to merge 33 commits from Logging into main
3 changed files with 212 additions and 201 deletions
Showing only changes of commit 9110c16256 - Show all commits

View File

@ -81,16 +81,14 @@ impl Config {
/// Getter for [`Self::log_path`]. /// Getter for [`Self::log_path`].
#[must_use] #[must_use]
pub fn log_path(&self) -> Option<&Path> pub fn log_path(&self) -> Option<&Path> {
{ self.log_path.as_deref()
self.log_path.as_deref() }
}
/// Setter for [`Self::log_path`]. /// Setter for [`Self::log_path`].
pub fn set_log_path(&mut self, log_path: impl Into<Option<PathBuf>>) pub fn set_log_path(&mut self, log_path: impl Into<Option<PathBuf>>) {
{ self.log_path = log_path.into();
self.log_path = log_path.into(); }
}
} }
/// See [`DEFAULTS`]. /// See [`DEFAULTS`].

View File

@ -9,8 +9,8 @@ use std::fmt::Display;
use std::fs::OpenOptions; use std::fs::OpenOptions;
use std::io::Write; use std::io::Write;
use config::LogVerbosity;
use config::Config; use config::Config;
use config::LogVerbosity;
use chrono::Utc; use chrono::Utc;
@ -30,8 +30,7 @@ use LogMessageType::GenericWarn;
* or if another error occurs, such as a full disk. * or if another error occurs, such as a full disk.
*/ */
pub fn log_message(msg: &LogMessage, conf: &Config, file: &str, line: u32, column: u32) { pub fn log_message(msg: &LogMessage, conf: &Config, file: &str, line: u32, column: u32) {
let Some(log_line) = log_to_str(msg, conf, file, line, column) else { return };
let Some(log_line) = log_to_str(msg, conf, file, line, column) else { return };
// May panic if file cannot be opened or written to. // May panic if file cannot be opened or written to.
conf.log_path().as_ref().map_or_else( conf.log_path().as_ref().map_or_else(
@ -40,13 +39,9 @@ pub fn log_message(msg: &LogMessage, conf: &Config, file: &str, line: u32, colum
let mut file = OpenOptions::new() let mut file = OpenOptions::new()
.write(true) .write(true)
.append(true) .append(true)
.create(true) .create(true)
.open(path) .open(path)
.unwrap_or_else(|_| { .unwrap_or_else(|_| panic!("Could not open log file: {path:#?}"));
panic!(
"Could not open log file: {path:#?}"
)
});
writeln!(file, "{log_line}") writeln!(file, "{log_line}")
.unwrap_or_else(|_| panic!("Could not write log to file: {path:#?}")); .unwrap_or_else(|_| panic!("Could not write log to file: {path:#?}"));
}, },
@ -68,8 +63,13 @@ pub fn log_message(msg: &LogMessage, conf: &Config, file: &str, line: u32, colum
* or if another error occurs, such as a full disk. * or if another error occurs, such as a full disk.
*/ */
#[must_use] #[must_use]
pub fn log_to_str(msg: &LogMessage, conf: &Config, file: &str, line: u32, column: u32) -> Option<String> pub fn log_to_str(
{ msg: &LogMessage,
conf: &Config,
file: &str,
line: u32,
column: u32,
) -> Option<String> {
if conf.log_verbosity() < &msg.1 { if conf.log_verbosity() < &msg.1 {
return None; return None;
} }
@ -86,21 +86,21 @@ pub fn log_to_str(msg: &LogMessage, conf: &Config, file: &str, line: u32, column
log_line += &format!("{file}:{line},{column} "); log_line += &format!("{file}:{line},{column} ");
} }
Some(log_line + &msg.to_string()) Some(log_line + &msg.to_string())
} }
/** /**
* Shorthand version for [`log_message`], which does not require information about the [`config::Config::log_location`]. * Shorthand version for [`log_message`], which does not require information about the [`config::Config::log_location`].
*/ */
#[macro_export] #[macro_export]
macro_rules! log{ macro_rules! log {
($msg:expr) => { ($msg:expr) => {
let conf = config::CONFIG.read().unwrap_or_else(|_| { let conf = config::CONFIG
panic!("Failed aqcuire read lock on config!") .read()
}); .unwrap_or_else(|_| panic!("Failed aqcuire read lock on config!"));
log_message($msg, &*conf, file!(), line!(), column!()); log_message($msg, &*conf, file!(), line!(), column!());
drop(conf); drop(conf);
} };
} }
/** /**

View File

@ -3,7 +3,13 @@
* This test suite uses uuid to easily avoid race conditions when writing to the same log file. * This test suite uses uuid to easily avoid race conditions when writing to the same log file.
*/ */
use std::{collections::HashSet, env, fs::{create_dir_all, read_to_string}, mem::take, path::PathBuf}; use std::{
collections::HashSet,
env,
fs::{create_dir_all, read_to_string},
mem::take,
path::PathBuf,
};
use futures::{executor::block_on, future::join_all}; use futures::{executor::block_on, future::join_all};
use once_cell::sync::Lazy; use once_cell::sync::Lazy;
@ -14,130 +20,131 @@ use super::*;
const CONCURRENT_MESSAGE_COUNT: usize = 99999; const CONCURRENT_MESSAGE_COUNT: usize = 99999;
static LOG_DIR: Lazy<String> = Lazy::new(|| static LOG_DIR: Lazy<String> = Lazy::new(|| {
if cfg!(unix) if cfg!(unix) {
{ String::from("/tmp/WANessa/unit-tests/logging")
String::from("/tmp/WANessa/unit-tests/logging") } else if cfg!(windows) {
} let tmp_path = env::var("TMP").unwrap_or_else(|_| {
else if cfg !(windows) { env::var("TEMP").expect(
let tmp_path = env::var("TMP").unwrap_or_else(|_| env::var("TEMP").expect("Windows should have both TMP and TEMP, but you have neither, what did you do?")); "Windows should have both TMP and TEMP, but you have neither, what did you do?",
format!("{tmp_path}/WANessa/unit-tests/logging") )
} });
else { String::new() } format!("{tmp_path}/WANessa/unit-tests/logging")
); } else {
String::new()
}
});
/// Tests if [`log_message`] to file correctly. /// Tests if [`log_message`] to file correctly.
#[test] #[test]
pub fn log_msg_file() pub fn log_msg_file() {
{ let log_path = &format!("{}/{}", *LOG_DIR, Uuid::new_v4());
let log_path = &format!("{}/{}", *LOG_DIR, Uuid::new_v4()); println!("Log Path: {log_path}");
println!("Log Path: {log_path}"); let message = LogMessageType::GenericWarn(String::from("Test Log")).log_message();
let message = LogMessageType::GenericWarn(String::from("Test Log")).log_message(); let mut config = config::DEFAULTS;
let mut config = config::DEFAULTS; config.set_log_path(PathBuf::from(log_path));
config.set_log_path(PathBuf::from(log_path));
create_dir_all(PathBuf::from(LOG_DIR.as_str())) create_dir_all(PathBuf::from(LOG_DIR.as_str()))
.unwrap_or_else(|_| panic!("Could not create directory: {}", *LOG_DIR)); .unwrap_or_else(|_| panic!("Could not create directory: {}", *LOG_DIR));
log_message(&message, &config, file!(), line!(), column!()); log_message(&message, &config, file!(), line!(), column!());
let log_file = read_to_string(PathBuf::from(log_path)) let log_file = read_to_string(PathBuf::from(log_path))
.unwrap_or_else(|_| panic!("Could not read file: {log_path}")); .unwrap_or_else(|_| panic!("Could not read file: {log_path}"));
assert_eq!(message.to_string() + "\n", log_file); assert_eq!(message.to_string() + "\n", log_file);
} }
/// Tests if [`log_message`] does not modify output from [`log_to_str`], when logging to file. /// Tests if [`log_message`] does not modify output from [`log_to_str`], when logging to file.
#[test] #[test]
pub fn log_str() pub fn log_str() {
{ let log_path = &format!("{}/{}", *LOG_DIR, Uuid::new_v4());
let log_path = &format!("{}/{}", *LOG_DIR, Uuid::new_v4()); println!("Log Path: {log_path}");
println!("Log Path: {log_path}"); let message = LogMessageType::GenericWarn(String::from("Test Log")).log_message();
let message = LogMessageType::GenericWarn(String::from("Test Log")).log_message(); let mut config = config::DEFAULTS;
let mut config = config::DEFAULTS; config.set_log_path(PathBuf::from(log_path));
config.set_log_path(PathBuf::from(log_path));
create_dir_all(PathBuf::from(LOG_DIR.as_str())) create_dir_all(PathBuf::from(LOG_DIR.as_str()))
.unwrap_or_else(|_| panic!("Could not create directory: {}", *LOG_DIR)); .unwrap_or_else(|_| panic!("Could not create directory: {}", *LOG_DIR));
let log_line = log_to_str(&message, &config, file!(), line!(), column!()).expect("There should be a log line.") + "\n"; let log_line = log_to_str(&message, &config, file!(), line!(), column!())
.expect("There should be a log line.")
+ "\n";
log_message(&message, &config, file!(), line!(), column!()); log_message(&message, &config, file!(), line!(), column!());
let log_file = read_to_string(PathBuf::from(log_path)) let log_file = read_to_string(PathBuf::from(log_path))
.unwrap_or_else(|_| panic!("Could not read file: {log_path}")); .unwrap_or_else(|_| panic!("Could not read file: {log_path}"));
assert_eq!(log_line, log_file); assert_eq!(log_line, log_file);
} }
/// Tests if no messages are unintentionally filtered due to their verboisity. /// Tests if no messages are unintentionally filtered due to their verboisity.
#[test] #[test]
pub fn verbosity_no_filter() pub fn verbosity_no_filter() {
{ let log_path = &format!("{}/{}", *LOG_DIR, Uuid::new_v4());
let log_path = &format!("{}/{}", *LOG_DIR, Uuid::new_v4()); println!("Log Path: {log_path}");
println!("Log Path: {log_path}"); let messages = vec![
let messages = vec![ LogMessageType::GenericErr(String::from("Test Err")).log_message(),
LogMessageType::GenericErr(String::from("Test Err")).log_message(), LogMessageType::GenericWarn(String::from("Test Warn")).log_message(),
LogMessageType::GenericWarn(String::from("Test Warn")).log_message(), LogMessageType::GenericInfo(String::from("Test Info")).log_message(),
LogMessageType::GenericInfo(String::from("Test Info")).log_message(), LogMessageType::GenericDebug(String::from("Test Debug")).log_message(),
LogMessageType::GenericDebug(String::from("Test Debug")).log_message(), ];
]; let mut config = config::DEFAULTS;
let mut config = config::DEFAULTS; config.set_log_path(PathBuf::from(log_path));
config.set_log_path(PathBuf::from(log_path)); config.set_log_verbosity(LogVerbosity::Error);
config.set_log_verbosity(LogVerbosity::Error);
create_dir_all(PathBuf::from(LOG_DIR.as_str())) create_dir_all(PathBuf::from(LOG_DIR.as_str()))
.unwrap_or_else(|_| panic!("Could not create directory: {}", *LOG_DIR)); .unwrap_or_else(|_| panic!("Could not create directory: {}", *LOG_DIR));
let log_line = log_to_str(&messages[0], &config, file!(), line!(), column!()).expect("There should be a log line.") + "\n"; let log_line = log_to_str(&messages[0], &config, file!(), line!(), column!())
.expect("There should be a log line.")
+ "\n";
for msg in messages for msg in messages {
{ log_message(&msg, &config, file!(), line!(), column!());
log_message(&msg, &config, file!(), line!(), column!()); }
}
let log_file = read_to_string(PathBuf::from(log_path)) let log_file = read_to_string(PathBuf::from(log_path))
.unwrap_or_else(|_| panic!("Could not read file: {log_path}")); .unwrap_or_else(|_| panic!("Could not read file: {log_path}"));
assert_eq!(log_file, log_line); assert_eq!(log_file, log_line);
} }
/// Tests if messages are properly filtered according to their verbosity. /// Tests if messages are properly filtered according to their verbosity.
#[test] #[test]
pub fn verbosity_filter() pub fn verbosity_filter() {
{ let log_path = &format!("{}/{}", *LOG_DIR, Uuid::new_v4());
let log_path = &format!("{}/{}", *LOG_DIR, Uuid::new_v4()); println!("Log Path: {log_path}");
println!("Log Path: {log_path}"); let messages = vec![
let messages = vec![ LogMessageType::GenericErr(String::from("Test Err")).log_message(),
LogMessageType::GenericErr(String::from("Test Err")).log_message(), LogMessageType::GenericWarn(String::from("Test Warn")).log_message(),
LogMessageType::GenericWarn(String::from("Test Warn")).log_message(), LogMessageType::GenericInfo(String::from("Test Info")).log_message(),
LogMessageType::GenericInfo(String::from("Test Info")).log_message(), LogMessageType::GenericDebug(String::from("Test Debug")).log_message(),
LogMessageType::GenericDebug(String::from("Test Debug")).log_message(), ];
]; let mut config = config::DEFAULTS;
let mut config = config::DEFAULTS; config.set_log_path(PathBuf::from(log_path));
config.set_log_path(PathBuf::from(log_path));
create_dir_all(PathBuf::from(LOG_DIR.as_str())) create_dir_all(PathBuf::from(LOG_DIR.as_str()))
.unwrap_or_else(|_| panic!("Could not create directory: {}", *LOG_DIR)); .unwrap_or_else(|_| panic!("Could not create directory: {}", *LOG_DIR));
let mut log_line = log_to_str(&messages[0], &config, file!(), line!(), column!()).expect("There should be a log line.") + "\n"; let mut log_line = log_to_str(&messages[0], &config, file!(), line!(), column!())
log_line += &(log_to_str(&messages[1], &config, file!(), line!(), column!()).expect("There should be a log line.") + "\n"); .expect("There should be a log line.")
+ "\n";
log_line += &(log_to_str(&messages[1], &config, file!(), line!(), column!())
.expect("There should be a log line.")
+ "\n");
for msg in messages for msg in messages {
{ log_message(&msg, &config, file!(), line!(), column!());
log_message(&msg, &config, file!(), line!(), column!()); }
}
let log_file = read_to_string(PathBuf::from(log_path)) let log_file = read_to_string(PathBuf::from(log_path))
.unwrap_or_else(|_| panic!("Could not read file: {log_path}")); .unwrap_or_else(|_| panic!("Could not read file: {log_path}"));
assert_eq!(log_file, log_line); assert_eq!(log_file, log_line);
} }
/** /**
* All testing concurrency in a controlled manner. * All testing concurrency in a controlled manner.
* *
@ -145,118 +152,124 @@ pub fn verbosity_filter()
* it might read the result from the changed config. * it might read the result from the changed config.
*/ */
#[test] #[test]
pub fn concurrency_tests() pub fn concurrency_tests() {
{ log_macro_file();
log_macro_file(); log_concurrently_any_order();
log_concurrently_any_order(); log_concurrently_correct_order();
log_concurrently_correct_order();
} }
/** /**
* Tests if log macro logs to file correctly. * Tests if log macro logs to file correctly.
* [`config::CONFIG`] * [`config::CONFIG`]
*/ */
fn log_macro_file() fn log_macro_file() {
{ let log_path = &format!("{}/{}", *LOG_DIR, Uuid::new_v4());
let log_path = &format!("{}/{}", *LOG_DIR, Uuid::new_v4()); println!("Log Path: {log_path}");
println!("Log Path: {log_path}"); let message = LogMessageType::GenericWarn(String::from("Test Log")).log_message();
let message = LogMessageType::GenericWarn(String::from("Test Log")).log_message(); let mut config = config::CONFIG
let mut config = config::CONFIG.write().expect("Could not acquire write lock on config!"); .write()
take(&mut *config); .expect("Could not acquire write lock on config!");
config.set_log_path(PathBuf::from(log_path)); take(&mut *config);
drop(config); config.set_log_path(PathBuf::from(log_path));
drop(config);
create_dir_all(PathBuf::from(LOG_DIR.as_str())) create_dir_all(PathBuf::from(LOG_DIR.as_str()))
.unwrap_or_else(|_| panic!("Could not create directory: {}", *LOG_DIR)); .unwrap_or_else(|_| panic!("Could not create directory: {}", *LOG_DIR));
log!(&message); log!(&message);
let log_file = read_to_string(PathBuf::from(log_path)) let log_file = read_to_string(PathBuf::from(log_path))
.unwrap_or_else(|_| panic!("Could not read file: {log_path}")); .unwrap_or_else(|_| panic!("Could not read file: {log_path}"));
assert_eq!(message.to_string()+"\n", log_file); assert_eq!(message.to_string() + "\n", log_file);
} }
/** /**
* Tests concurrent logging. Log lines may be in any order. * Tests concurrent logging. Log lines may be in any order.
*/ */
fn log_concurrently_any_order() fn log_concurrently_any_order() {
{ let log_path = &format!("{}/{}", *LOG_DIR, Uuid::new_v4());
let log_path = &format!("{}/{}", *LOG_DIR, Uuid::new_v4()); println!("Log Path: {log_path}");
println!("Log Path: {log_path}"); let mut config = config::CONFIG
let mut config = config::CONFIG.write().expect("Could not acquire write lock on config!"); .write()
take(&mut *config); .expect("Could not acquire write lock on config!");
let mut messages = Vec::with_capacity(CONCURRENT_MESSAGE_COUNT); take(&mut *config);
config.set_log_path(PathBuf::from(log_path)); let mut messages = Vec::with_capacity(CONCURRENT_MESSAGE_COUNT);
drop(config); config.set_log_path(PathBuf::from(log_path));
drop(config);
for i in 0..CONCURRENT_MESSAGE_COUNT for i in 0..CONCURRENT_MESSAGE_COUNT {
{ let msg = i.to_string();
let msg = i.to_string(); messages.push(async {
messages.push( log!(&LogMessageType::GenericWarn(msg).log_message());
async { });
log!(&LogMessageType::GenericWarn(msg).log_message()); }
}
);
}
block_on(join_all(messages)); block_on(join_all(messages));
let mut num_set = HashSet::with_capacity(CONCURRENT_MESSAGE_COUNT); let mut num_set = HashSet::with_capacity(CONCURRENT_MESSAGE_COUNT);
for i in 0..CONCURRENT_MESSAGE_COUNT for i in 0..CONCURRENT_MESSAGE_COUNT {
{ num_set.insert(i);
num_set.insert(i); }
}
for line in read_to_string(PathBuf::from(log_path)).unwrap_or_else(|_| panic!("Could not read file: {log_path}")).lines() for line in read_to_string(PathBuf::from(log_path))
{ .unwrap_or_else(|_| panic!("Could not read file: {log_path}"))
let num_str = line.split_whitespace().last().unwrap_or_else(|| panic!("Could not get message number from line: {line}")); .lines()
let num = usize::from_str_radix(num_str, 10).unwrap_or_else(|_| panic!("Could not parse number: {num_str}")); {
assert!(num_set.remove(&num)); let num_str = line
} .split_whitespace()
.last()
.unwrap_or_else(|| panic!("Could not get message number from line: {line}"));
let num = usize::from_str_radix(num_str, 10)
.unwrap_or_else(|_| panic!("Could not parse number: {num_str}"));
assert!(num_set.remove(&num));
}
assert_eq!(num_set.len(), 0); assert_eq!(num_set.len(), 0);
} }
/** /**
* Tests concurrent logging. Log lines must be in order. * Tests concurrent logging. Log lines must be in order.
*/ */
fn log_concurrently_correct_order() fn log_concurrently_correct_order() {
{ let log_path = &format!("{}/{}", *LOG_DIR, Uuid::new_v4());
let log_path = &format!("{}/{}", *LOG_DIR, Uuid::new_v4()); println!("Log Path: {log_path}");
println!("Log Path: {log_path}"); let mut config = config::CONFIG
let mut config = config::CONFIG.write().expect("Could not acquire write lock on config!"); .write()
take(&mut *config); .expect("Could not acquire write lock on config!");
let mut messages = Vec::with_capacity(CONCURRENT_MESSAGE_COUNT); take(&mut *config);
config.set_log_path(PathBuf::from(log_path)); let mut messages = Vec::with_capacity(CONCURRENT_MESSAGE_COUNT);
drop(config); config.set_log_path(PathBuf::from(log_path));
drop(config);
for i in 0..CONCURRENT_MESSAGE_COUNT for i in 0..CONCURRENT_MESSAGE_COUNT {
{ let msg = i.to_string();
let msg = i.to_string(); messages.push(async {
messages.push( log!(&LogMessageType::GenericWarn(msg).log_message());
async { });
log!(&LogMessageType::GenericWarn(msg).log_message()); }
}
);
}
block_on(join_all(messages)); block_on(join_all(messages));
let mut num_set = HashSet::with_capacity(CONCURRENT_MESSAGE_COUNT); let mut num_set = HashSet::with_capacity(CONCURRENT_MESSAGE_COUNT);
for i in 0..CONCURRENT_MESSAGE_COUNT for i in 0..CONCURRENT_MESSAGE_COUNT {
{ num_set.insert(i);
num_set.insert(i); }
}
for (i, line) in read_to_string(PathBuf::from(log_path)).unwrap_or_else(|_| panic!("Could not read file: {log_path}")).lines().enumerate() for (i, line) in read_to_string(PathBuf::from(log_path))
{ .unwrap_or_else(|_| panic!("Could not read file: {log_path}"))
let num_str = line.split_whitespace().last().unwrap_or_else(|| panic!("Could not get message number from line: {line}")); .lines()
let num = usize::from_str_radix(num_str, 10).unwrap_or_else(|_| panic!("Could not parse number: {num_str}")); .enumerate()
assert!(num_set.remove(&num)); {
assert_eq!(i, num); let num_str = line
} .split_whitespace()
.last()
assert_eq!(num_set.len(), 0); .unwrap_or_else(|| panic!("Could not get message number from line: {line}"));
let num = usize::from_str_radix(num_str, 10)
.unwrap_or_else(|_| panic!("Could not parse number: {num_str}"));
assert!(num_set.remove(&num));
assert_eq!(i, num);
}
assert_eq!(num_set.len(), 0);
} }