fixed logger multi init

the logger test sometimes crashed due to multithreading problems in combination with a Logger module panicing when the INITIALIZED AtomicBool was false due to cargo tests multithreading
This commit is contained in:
Christoph J. Scherr 2023-07-08 14:43:11 +02:00
parent 4fc6ac7e0a
commit d36b7c0d04
Signed by: PlexSheep
GPG Key ID: 25B4ACF7D88186CC
8 changed files with 178 additions and 102 deletions

View File

@ -13,6 +13,9 @@ So what? I don't care. Besides, there is not enough names to name everything uni
# compiling
TBD
# installing
TBD
# Documentation
TBD

View File

@ -1,12 +0,0 @@
"""
# libpt python bindings
`libpt` is originally implemented in rust, but offers a python module too.
"""
from . import logger
def is_loaded() -> bool:
"""
returns true if `libpt` has been loaded
"""
...

61
src/common/macros.rs Normal file
View File

@ -0,0 +1,61 @@
//! # common macros for `libpt`
//!
//! This module implements macros for use with `libpt`.
//// ATTRIBUTES ////////////////////////////////////////////////////////////////////////////////////
// we want docs
#![warn(missing_docs)]
#![warn(rustdoc::missing_crate_level_docs)]
////////////////////////////////////////////////////////////////////////////////////////////////////
// we want Debug everywhere.
#![warn(missing_debug_implementations)]
////////////////////////////////////////////////////////////////////////////////////////////////////
// enable clippy's extra lints, the pedantic version
#![warn(clippy::pedantic)]
//// IMPORTS ///////////////////////////////////////////////////////////////////////////////////////
pub use crate::get_stdout_for;
//// CONSTANTS /////////////////////////////////////////////////////////////////////////////////////
//// STATICS ///////////////////////////////////////////////////////////////////////////////////////
//// MACROS ////////////////////////////////////////////////////////////////////////////////////////
/// ## catches what the expression would write to the `stdout`
///
/// This macro takes an expression, executes it, and catches what it would write to the stdout.
/// The buffer of the stdout will then be returned for further use.
///
/// This is especially useful when testing loggers or other frontend CLI functions.
///
/// Inspiration: [users.rust-lang.org](https://users.rust-lang.org/t/how-to-test-functions-that-use-
/// println/67188/5)
#[macro_export]
macro_rules! get_stdout_for {
($test:expr) => {{
use gag::BufferRedirect;
use std::io::Read;
let mut buf = BufferRedirect::stdout().unwrap();
$test;
let mut output = String::new();
buf.read_to_string(&mut output).unwrap();
drop(buf);
output
}};
}
//// ENUMS /////////////////////////////////////////////////////////////////////////////////////////
//// STRUCTS ///////////////////////////////////////////////////////////////////////////////////////
//// IMPLEMENTATION ////////////////////////////////////////////////////////////////////////////////
//// PUBLIC FUNCTIONS //////////////////////////////////////////////////////////////////////////////
//// PRIVATE FUNCTIONS /////////////////////////////////////////////////////////////////////////////

34
src/common/mod.rs Normal file
View File

@ -0,0 +1,34 @@
//! # common functionalities
//!
//! This module implements common functionality useful for many use cases, such as macros,
//! Formatting functions and more.
//// ATTRIBUTES ////////////////////////////////////////////////////////////////////////////////////
// we want docs
#![warn(missing_docs)]
#![warn(rustdoc::missing_crate_level_docs)]
////////////////////////////////////////////////////////////////////////////////////////////////////
// we want Debug everywhere.
#![warn(missing_debug_implementations)]
////////////////////////////////////////////////////////////////////////////////////////////////////
// enable clippy's extra lints, the pedantic version
#![warn(clippy::pedantic)]
//// IMPORTS ///////////////////////////////////////////////////////////////////////////////////////
pub mod macros;
//// CONSTANTS /////////////////////////////////////////////////////////////////////////////////////
//// STATICS ///////////////////////////////////////////////////////////////////////////////////////
//// ENUMS /////////////////////////////////////////////////////////////////////////////////////////
//// STRUCTS ///////////////////////////////////////////////////////////////////////////////////////
//// IMPLEMENTATION ////////////////////////////////////////////////////////////////////////////////
//// PUBLIC FUNCTIONS //////////////////////////////////////////////////////////////////////////////
//// PRIVATE FUNCTIONS /////////////////////////////////////////////////////////////////////////////

View File

@ -22,6 +22,8 @@
#![warn(clippy::pedantic)]
//// IMPORTS ///////////////////////////////////////////////////////////////////////////////////////
/// contains useful code, such as macros, for general use
pub mod common;
/// contains code specific to the executable
pub mod bin;
/// logger used by libpt

View File

@ -18,9 +18,7 @@ use std::{
sync::atomic::{AtomicBool, Ordering},
};
use env_logger::{
Env, Target, WriteStyle,
};
use env_logger::{Env, Target, WriteStyle};
use log::{debug, error, info, trace, warn, Level};
use pyo3::prelude::*;
@ -41,7 +39,7 @@ static INITIALIZED: AtomicBool = AtomicBool::new(false);
///
/// ### Setting a [`Level`](log::Level)
///
/// To set a [`Level`](log::Level), you need to set the environment variable `LIBPT_LOGLEVEL`
/// To set a [`Level`](log::Level), you need to set the environment variable `LIBPT_LOGLEVEL`
/// to either of:
///
/// - `Trace`
@ -72,7 +70,11 @@ impl Logger {
return;
} else {
let env = Env::default().filter_or(LOGGER_ENV_KEY, DEFAULT_LOG_LEVEL.to_string());
env_logger::init_from_env(env);
let res = env_logger::Builder::from_env(env)
.try_init();
if res.is_err() {
eprintln!("could not init logger: {}", res.unwrap_err());
}
INITIALIZED.store(true, Ordering::Relaxed);
}
}
@ -83,11 +85,11 @@ impl Logger {
pub fn init_specialized(test: bool, color: bool, target: Target) {
// only init if no init has been performed yet
if INITIALIZED.load(Ordering::Relaxed) {
warn!("trying to reinitialize the logger, ignoring");
eprintln!("trying to reinitialize the logger, ignoring");
return;
} else {
let env = Env::default().filter_or(LOGGER_ENV_KEY, DEFAULT_LOG_LEVEL.to_string());
env_logger::Builder::from_env(env)
let res = env_logger::Builder::from_env(env)
.is_test(test)
.target(target)
.write_style(if color {
@ -95,7 +97,10 @@ impl Logger {
} else {
WriteStyle::Never
})
.init();
.try_init();
if res.is_err() {
eprintln!("could not init logger: {}", res.unwrap_err());
}
INITIALIZED.store(true, Ordering::Relaxed);
}
}

View File

@ -27,6 +27,8 @@
//// STATICS ///////////////////////////////////////////////////////////////////////////////////////
//// MACROS ////////////////////////////////////////////////////////////////////////////////////////
//// ENUMS /////////////////////////////////////////////////////////////////////////////////////////
//// STRUCTS ///////////////////////////////////////////////////////////////////////////////////////

View File

@ -1,92 +1,73 @@
//! # Tests for libpt::logger::Logger
//!
//! Note: the module uses a global variable to store if the thread has
//// IMPORTS ///////////////////////////////////////////////////////////////////////////////////////
/// ## Tests for basic logging functionality
use libpt::logger::*;
use libpt::common::macros::get_stdout_for;
use regex::Regex;
//// HELPERS ///////////////////////////////////////////////////////////////////////////////////////
/// ## checks if the expected thing was printed to stdout
///
/// Source: [users.rust-lang.org](https://users.rust-lang.org/t/how-to-test-functions-that-use-
/// println/67188/5)
macro_rules! get_stdout_for {
($test:expr) => {{
use gag::BufferRedirect;
use std::io::Read;
let mut buf = BufferRedirect::stdout().unwrap();
$test;
let mut output = String::new();
buf.read_to_string(&mut output).unwrap();
drop(buf);
output
}};
// only initialize once
/// ## setup that's needed before testing the logger struct
fn setup() {
// we don't want to log messages during our tests!
std::env::set_var(LOGGER_ENV_KEY, "Trace");
Logger::init_specialized(false, false, env_logger::Target::Stdout);
println!()
}
//// IMPLEMENTATION ////////////////////////////////////////////////////////////////////////////////
/// ## Tests for basic logging functionality
mod test_logger_struct {
use libpt::logger::*;
/// ## Tests for basic logging
///
/// This test tests if the loggers basic logging functionality works, that is it's methods:
///
/// - [`Logger::trace`]
/// - [`Logger::debug`]
/// - [`Logger::info`]
/// - [`Logger::warn`]
/// - [`Logger::error`]
///
/// After those methods have Successfully been executed, their outputs gets stored in a single
/// [`String`] and a [`Regex`] checks if we have five correctly formatted messages.
#[test]
fn test_log_basic() {
setup();
let l = Logger::new();
let trace_out = get_stdout_for!(l.trace("MSG"));
let debug_out = get_stdout_for!(l.debug("MSG"));
let info_out = get_stdout_for!(l.info("MSG"));
let warn_out = get_stdout_for!(l.warn("MSG"));
let error_out = get_stdout_for!(l.error("MSG"));
let combined = format!(
"{}{}{}{}{}",
trace_out, debug_out, info_out, warn_out, error_out
);
print!("{}", combined);
use regex::Regex;
// too long, so i split into two lines.
// this matches the format of the env_logger perfectly, but make sure that color is off,
// else the ANSI escape sequences break this test
let regex = Regex::new(concat!(
r"(?m)\[\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}Z ",
r"(TRACE|DEBUG|INFO|WARN|ERROR) +libpt::logger\] MSG"
))
.unwrap();
/// ## setup that's needed before testing the logger struct
fn setup() {
// we don't want to log messages during our tests!
Logger::init_specialized(false, false, env_logger::Target::Stdout);
println!()
}
/// ## Tests for basic logging
///
/// This test tests if the loggers basic logging functionality works, that is it's methods:
///
/// - [`Logger::trace`]
/// - [`Logger::debug`]
/// - [`Logger::info`]
/// - [`Logger::warn`]
/// - [`Logger::error`]
///
/// After those methods have Successfully been executed, their outputs gets stored in a single
/// [`String`] and a [`Regex`] checks if we have five correctly formatted messages.
#[test]
fn test_log_basic() {
std::env::set_var(LOGGER_ENV_KEY, "Trace");
setup();
let l = Logger::new();
let trace_out = get_stdout_for!(l.trace("MSG"));
let debug_out = get_stdout_for!(l.debug("MSG"));
let info_out = get_stdout_for!(l.info("MSG"));
let warn_out = get_stdout_for!(l.warn("MSG"));
let error_out = get_stdout_for!(l.error("MSG"));
let combined = format!(
"{}{}{}{}{}",
trace_out, debug_out, info_out, warn_out, error_out
);
print!("{}", combined);
// too long, so i split into two lines.
// this matches the format of the env_logger perfectly, but make sure that color is off,
// else the ANSI escape sequences break this test
let regex = Regex::new(concat!(
r"(?m)\[\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}Z ",
r"(TRACE|DEBUG|INFO|WARN|ERROR) +libpt::logger\] MSG"
))
.unwrap();
// we have 5 log levels, therefore we should have 5 captures
assert_eq!(regex.captures_iter(&combined).count(), 5);
}
#[test]
fn test_multi_initialize() {
setup();
let l = Logger::new();
// these should be ignored due to the global flag
Logger::init();
Logger::init();
Logger::init();
Logger::init();
l.info("Successfully ignored extra init");
}
// we have 5 log levels, therefore we should have 5 captures
assert_eq!(regex.captures_iter(&combined).count(), 5);
}
#[test]
fn test_multi_initialize() {
setup();
let l = Logger::new();
// these should be ignored due to the global flag
Logger::init();
Logger::init();
Logger::init();
Logger::init();
l.info("Successfully ignored extra init");
}