From dd71569a259bedc0b23f0b6d6def664da028cfb5 Mon Sep 17 00:00:00 2001 From: DaveWK <13626476+DaveWK@users.noreply.github.com> Date: Sat, 3 Sep 2022 04:05:15 -0400 Subject: [PATCH 1/2] Add builder_from_env to use custom env var This adds a wrapper to Builder::from_env so a variable other than RUST_LOG can be used This also updates the log crate to the latest, where the feature has been changed to "kv_unstable_std", as well as updates env_logger to 0.9 --- Cargo.toml | 4 ++-- src/lib.rs | 56 ++++++++++++++++++++++++++++++++++++++++++++++++++++++ 2 files changed, 58 insertions(+), 2 deletions(-) diff --git a/Cargo.toml b/Cargo.toml index 272cc04..a393e3a 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -18,8 +18,8 @@ readme = "README.md" kv-log-macro = "1.0" backtrace = { version = "0.3", optional = true } chrono = { version = "0.4", optional = true } -env_logger = { version = "0.7", default_features = false } -log = { version = "0.4", features = ["kv_unstable", "std"] } +env_logger = { version = "0.9", default_features = false } +log = { version = "0.4.7", features = ["kv_unstable_std"] } serde_json = "1.0" [features] diff --git a/src/lib.rs b/src/lib.rs index eb3d236..cad31ab 100644 --- a/src/lib.rs +++ b/src/lib.rs @@ -124,6 +124,16 @@ pub fn builder() -> Builder { builder } +/// Use a custom environment variable instead of RUST_LOG +pub fn builder_from_env<'a, E>(env_var_name: E) -> Builder +where + E: Into>, +{ + let mut builder = Builder::from_env(env_var_name); + builder.format(write); + builder +} + fn write( f: &mut F, record: &log::Record, @@ -210,4 +220,50 @@ mod tests { assert_eq!("\"\\\"\\n\\t\"", std::str::from_utf8(&buf)?); Ok(()) } + + // Adapter for testing output from logger + struct WriteAdapter { + sender: std::sync::mpsc::Sender, + } + + impl io::Write for WriteAdapter { + // On write we forward each u8 of the buffer to the sender and return the length of the buffer + fn write( + &mut self, + buf: &[u8], + ) -> io::Result { + for chr in buf { + self.sender.send(*chr).unwrap(); + } + Ok(buf.len()) + } + + fn flush(&mut self) -> io::Result<()> { + Ok(()) + } + } + + #[test] + fn use_custom_env_var() -> Result<(), Box> { + // USE FOO_LOG instead of RUST_LOG for env var. Sets level to info + std::env::set_var("FOO_LOG", "info"); + // create rx/tx channels to captue log output + let (rx, tx) = std::sync::mpsc::channel(); + builder_from_env("FOO_LOG") + .target(env_logger::Target::Pipe(Box::new(WriteAdapter { + sender: rx, + }))) + .init(); + // log level is info. should be parseable json + log::info!("Hello"); + let hello_info_log = String::from_utf8(tx.try_iter().collect::>()).unwrap(); + let hello_log_parsed: serde_json::Value = serde_json::from_str(hello_info_log.as_str())?; + println!("Msg: {}", hello_log_parsed["msg"]); + assert!(hello_log_parsed["msg"] == "Hello"); + // should not print debug level logs due to FOO_LOG value + log::debug!("Hidden"); + let hidden_debug_log = String::from_utf8(tx.try_iter().collect::>()).unwrap(); + assert!(hidden_debug_log.len() == 0); + Ok(()) + } } From 2c87b467d2bb957d745ba2ec7099de7cfbb61c73 Mon Sep 17 00:00:00 2001 From: DaveWK <13626476+DaveWK@users.noreply.github.com> Date: Sat, 3 Sep 2022 06:15:25 -0400 Subject: [PATCH 2/2] Add ability to swap logger config after it has been initialized, add mutex to avoid format changes impacting other tests --- Cargo.toml | 4 +++ src/lib.rs | 96 ++++++++++++++++++++++++++++++++++++++++-------------- 2 files changed, 75 insertions(+), 25 deletions(-) diff --git a/Cargo.toml b/Cargo.toml index a393e3a..2e94629 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -22,6 +22,10 @@ env_logger = { version = "0.9", default_features = false } log = { version = "0.4.7", features = ["kv_unstable_std"] } serde_json = "1.0" +[dev-dependencies] +serial_test = "0.9.0" +lazy_static = "1.4.0" + [features] default = [] iso-timestamps = ["chrono"] diff --git a/src/lib.rs b/src/lib.rs index cad31ab..3eb9dde 100644 --- a/src/lib.rs +++ b/src/lib.rs @@ -195,30 +195,41 @@ fn write_json_str( #[cfg(test)] mod tests { use super::*; - use std::error::Error; + use lazy_static::lazy_static; + use serial_test::serial; + use std::{ + error::Error, + sync::{Arc, RwLock}, + }; - #[test] - fn writes_records_as_json() -> Result<(), Box> { - let record = log::Record::builder() - .args(format_args!("hello")) - .level(log::Level::Info) - .build(); - let mut buf = Vec::new(); - write(&mut buf, &record)?; - let output = std::str::from_utf8(&buf)?; - assert!(serde_json::from_str::(&output).is_ok()); - Ok(()) + // enables swapping loggers after it has been initialized + lazy_static! { + static ref LOGGER: Arc> = + Arc::new(RwLock::new(env_logger::Logger::from_default_env())); } + struct LoggerShim {} + impl log::Log for LoggerShim { + fn enabled( + &self, + metadata: &log::Metadata, + ) -> bool { + LOGGER.read().unwrap().enabled(metadata) + } - #[test] - fn escapes_json_strings() -> Result<(), Box> { - let mut buf = Vec::new(); - write_json_str( - &mut buf, r#"" - "#, - )?; - assert_eq!("\"\\\"\\n\\t\"", std::str::from_utf8(&buf)?); - Ok(()) + fn log( + &self, + record: &log::Record, + ) { + LOGGER.read().unwrap().log(record); + } + + fn flush(&self) {} + } + + fn replace_logger(logger: env_logger::Logger) { + log::set_max_level(logger.filter()); + *LOGGER.write().unwrap() = logger; + let _ = log::set_boxed_logger(Box::new(LoggerShim {})); } // Adapter for testing output from logger @@ -244,26 +255,61 @@ mod tests { } #[test] + #[serial] + fn writes_records_as_json() -> Result<(), Box> { + let (rx, tx) = std::sync::mpsc::channel(); + let json_logger = builder() + .filter_level(log::LevelFilter::Info) + .target(env_logger::Target::Pipe(Box::new(WriteAdapter { + sender: rx, + }))) + .build(); + replace_logger(json_logger); + log::info!("hello"); + let hello_info_log = String::from_utf8(tx.try_iter().collect::>()).unwrap(); + let hello_log_parsed: serde_json::Value = serde_json::from_str(hello_info_log.as_str())?; + println!("Full json log: {}", hello_info_log); + assert!(hello_log_parsed["msg"] == "hello"); + Ok(()) + } + + #[test] + fn escapes_json_strings() -> Result<(), Box> { + let mut buf = Vec::new(); + write_json_str( + &mut buf, r#"" + "#, + )?; + println!("{}", std::str::from_utf8(&buf)?); + assert_eq!("\"\\\"\\n\\t\"", std::str::from_utf8(&buf)?); + Ok(()) + } + + #[test] + #[serial] fn use_custom_env_var() -> Result<(), Box> { // USE FOO_LOG instead of RUST_LOG for env var. Sets level to info std::env::set_var("FOO_LOG", "info"); // create rx/tx channels to captue log output let (rx, tx) = std::sync::mpsc::channel(); - builder_from_env("FOO_LOG") + let custom_env_logger = builder_from_env("FOO_LOG") .target(env_logger::Target::Pipe(Box::new(WriteAdapter { sender: rx, }))) - .init(); + .build(); + + replace_logger(custom_env_logger); // log level is info. should be parseable json log::info!("Hello"); let hello_info_log = String::from_utf8(tx.try_iter().collect::>()).unwrap(); let hello_log_parsed: serde_json::Value = serde_json::from_str(hello_info_log.as_str())?; - println!("Msg: {}", hello_log_parsed["msg"]); + println!("Parsed json message: {}", hello_log_parsed); assert!(hello_log_parsed["msg"] == "Hello"); // should not print debug level logs due to FOO_LOG value log::debug!("Hidden"); let hidden_debug_log = String::from_utf8(tx.try_iter().collect::>()).unwrap(); - assert!(hidden_debug_log.len() == 0); + println!("Hidden Log: {}", hidden_debug_log); + assert!(hidden_debug_log.is_empty()); Ok(()) } }