From 43872aaf50f0cf7f9ad00adc5b4ebad057a35e32 Mon Sep 17 00:00:00 2001 From: Marco Mastropaolo Date: Tue, 23 Jun 2020 10:35:32 +0200 Subject: [PATCH 1/4] Added debug support and refinements - Tests are not thread dependent anymore - Added support for domain - Added support for customized loggers - Added support for simple loggers without file/line info --- Cargo.toml | 3 ++ src/lib.rs | 115 +++++++++++++++++++++++++++++++++++++++++------------ 2 files changed, 93 insertions(+), 25 deletions(-) diff --git a/Cargo.toml b/Cargo.toml index 104bf3c..029be59 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -15,3 +15,6 @@ license = "MIT" [dependencies] log = "0.4.0" glib-sys = { version = "0.9.1", features = ["v2_44"] } + +[dev-dependencies] +serial_test = "0.4.0" diff --git a/src/lib.rs b/src/lib.rs index 90b5e4f..9c290a7 100644 --- a/src/lib.rs +++ b/src/lib.rs @@ -89,16 +89,37 @@ use log::{Level, Metadata, Record}; +#[derive(Debug, Copy, Clone)] +pub enum LoggerType { + Simple, + SimplePlain, + Structured, +} + pub struct Logger { - structured: bool, + logger_type: LoggerType, + domain: Option<&'static str>, } pub const fn simple() -> Logger { - Logger { structured: false } + Logger { + logger_type: LoggerType::Simple, + domain: None, + } } pub const fn structured() -> Logger { - Logger { structured: true } + Logger { + logger_type: LoggerType::Structured, + domain: None, + } +} + +pub const fn custom(logger_type: LoggerType, domain: Option<&'static str>) -> Logger { + Logger { + logger_type, + domain, + } } trait ToGlib { @@ -122,18 +143,27 @@ impl ToGlib for log::Level { } } -fn glib_log_structured(level: log::Level, file: &str, line: &str, func: &str, message: &str) { +fn glib_log_structured(domain: Option<&str>, level: log::Level, file: &str, line: &str, func: &str, message: &str) { use glib_sys::g_log_structured_standard; use std::ffi::CString; use std::ptr; - println!("file: {}", file); + let c_file = CString::new(file).expect("CString::new(file) failed"); let c_line = CString::new(line).expect("CString::new(line) failed"); let c_func = CString::new(func).expect("CString::new(func) failed"); let c_message = CString::new(message).expect("CString::new(message) failed"); + + let c_domain_ptr = match domain { + None => ptr::null(), + Some(s) => match CString::new(s) { + Ok(s) => s.as_ptr(), + Err(_) => ptr::null(), + }, + }; + unsafe { g_log_structured_standard( - ptr::null(), + c_domain_ptr, level.to_glib(), c_file.as_ptr(), c_line.as_ptr(), @@ -143,13 +173,24 @@ fn glib_log_structured(level: log::Level, file: &str, line: &str, func: &str, me } } -fn glib_log(level: log::Level, message: &str) { +fn glib_log(domain: Option<&str>, level: log::Level, message: &str) { use glib_sys::g_log; use std::ffi::CString; use std::ptr; let c_message = CString::new(message).expect("CString::new(message) failed"); + + let c_domain = match domain { + None => None, + Some(s) => Some(CString::new(s).expect("CString::new(domain) failed")), + }; + + let c_domain_ptr = match &c_domain { + None => ptr::null(), + Some(s) => s.as_ptr(), + }; + unsafe { - g_log(ptr::null(), level.to_glib(), c_message.as_ptr()); + g_log(c_domain_ptr, level.to_glib(), c_message.as_ptr()); } } @@ -164,19 +205,28 @@ impl log::Log for Logger { } let file = record.file().expect("no file in record"); let line = &record.line().expect("no line in record").to_string(); - if !self.structured { - let s = format!("{}:{}: {}", file, line, record.args()); - glib_log(record.level(), &s); - } else { - let s = format!("{}", record.args()); - glib_log_structured( - record.level(), - file, - line, - record.module_path().expect("no module"), - &s, - ); - } + + match self.logger_type { + LoggerType::Simple => { + let s = format!("{}:{}: {}", file, line, record.args()); + glib_log(self.domain, record.level(), &s); + }, + LoggerType::SimplePlain => { + let s = format!("{}", record.args()); + glib_log(self.domain, record.level(), &s) + }, + LoggerType::Structured => { + let s = format!("{}", record.args()); + glib_log_structured( + self.domain, + record.level(), + file, + line, + record.module_path().expect("no module"), + &s, + ); + }, + }; } fn flush(&self) {} @@ -188,6 +238,8 @@ pub static SIMPLE: Logger = simple(); // Structured logger (Experimental). pub static STRUCTURED: Logger = structured(); +pub static CUSTOM: Logger = custom(LoggerType::Structured, Some("AHAHAH")); + // Set up given logger. pub fn init(logger: &'static Logger) { log::set_logger(logger).expect("glib_logger::init failed to initialize"); @@ -197,6 +249,7 @@ pub fn init(logger: &'static Logger) { mod tests { use log::Level; use std::os::raw::c_char; + use serial_test::serial; struct LogTrace { domain: Option, @@ -219,7 +272,6 @@ mod tests { use std::ffi::c_void; use std::ptr; - // let mut trace = Box::new(LogTrace::new()); let mut trace = LogTrace::new(); let prev_handler: glib_sys::GLogFunc; @@ -255,14 +307,13 @@ mod tests { trace.domain = Some(CStr::from_ptr(domain_ptr).to_string_lossy().into_owned()); } trace.level = Some(level); - - println!("log writer"); } #[test] + #[serial] fn simple_log() { let trace = collect_log(|| { - super::glib_log(Level::Debug, "foobar"); + super::glib_log(None, Level::Debug, "foobar"); }); assert_eq!(trace.domain, None); assert_eq!(trace.message, Some("foobar".to_string())); @@ -270,9 +321,22 @@ mod tests { } #[test] + #[serial] + fn domain_log() { + let trace = collect_log(|| { + super::glib_log(Some("barbaz"), Level::Debug, "foobar"); + }); + assert_eq!(trace.domain, Some(String::from("barbaz"))); + assert_eq!(trace.message, Some("foobar".to_string())); + assert_eq!(trace.level, Some(glib_sys::G_LOG_LEVEL_DEBUG)); + } + + #[test] + #[serial] fn simple_formatted_log() { let trace = collect_log(|| { super::glib_log( + None, Level::Info, &format!("this is a test {} \"{}\" %%d", 123, "abcd"), ); @@ -288,6 +352,7 @@ mod tests { // TODO: figure out a way to install handler for structure logs #[test] + #[serial] fn via_logger() { let trace = collect_log(|| { use log::Log; From 06e1237ec5a9d33ad59fa10d8593e1d3d372f9fd Mon Sep 17 00:00:00 2001 From: Marco Mastropaolo Date: Tue, 23 Jun 2020 20:00:02 +0200 Subject: [PATCH 2/4] Amended README --- README.md | 3 ++- src/lib.rs | 2 -- 2 files changed, 2 insertions(+), 3 deletions(-) diff --git a/README.md b/README.md index 03339f1..06f461a 100644 --- a/README.md +++ b/README.md @@ -63,4 +63,5 @@ done in Glib. It is advisable to set `G_MESSAGES_DEBUG=all` environment variable Using Glib a domain can be set per file by using `#define G_LOG_DOMAIN "my-domain"` directly in C code. This functionality is not avaialble when using -`glib_logger`, all logs are emitted with a NULL domain. +`glib_logger` default loggers. To reproduce this functionality, create a custom +logger using `pub static CUSTOM: Logger = custom(LoggerType::Structured, Some("my-domain"));`. diff --git a/src/lib.rs b/src/lib.rs index 9c290a7..4df98be 100644 --- a/src/lib.rs +++ b/src/lib.rs @@ -238,8 +238,6 @@ pub static SIMPLE: Logger = simple(); // Structured logger (Experimental). pub static STRUCTURED: Logger = structured(); -pub static CUSTOM: Logger = custom(LoggerType::Structured, Some("AHAHAH")); - // Set up given logger. pub fn init(logger: &'static Logger) { log::set_logger(logger).expect("glib_logger::init failed to initialize"); From 7d79ef203dbec339a64b66bcda24eb381d9aa880 Mon Sep 17 00:00:00 2001 From: Marco Mastropaolo Date: Wed, 1 Jul 2020 19:31:51 +0200 Subject: [PATCH 3/4] Added support for target overriding domains, and unit tests using macros --- src/lib.rs | 129 +++++++++++++++++++++++++++++++++++++++++++++++++---- 1 file changed, 121 insertions(+), 8 deletions(-) diff --git a/src/lib.rs b/src/lib.rs index 4df98be..af591bc 100644 --- a/src/lib.rs +++ b/src/lib.rs @@ -87,6 +87,9 @@ //! "my-domain"` directly in C code. This functionality is not avaialble when using //! `glib_logger`, all logs are emitted with a NULL domain. +#[macro_use] +extern crate log; + use log::{Level, Metadata, Record}; #[derive(Debug, Copy, Clone)] @@ -98,27 +101,35 @@ pub enum LoggerType { pub struct Logger { logger_type: LoggerType, - domain: Option<&'static str>, + default_domain: Option<&'static str>, + target_overrides_domain: bool, } pub const fn simple() -> Logger { Logger { logger_type: LoggerType::Simple, - domain: None, + default_domain: None, + target_overrides_domain: true, } } pub const fn structured() -> Logger { Logger { logger_type: LoggerType::Structured, - domain: None, + default_domain: None, + target_overrides_domain: true, } } -pub const fn custom(logger_type: LoggerType, domain: Option<&'static str>) -> Logger { +pub const fn custom( + logger_type: LoggerType, + default_domain: Option<&'static str>, + target_overrides_domain: bool +) -> Logger { Logger { logger_type, - domain, + default_domain, + target_overrides_domain, } } @@ -206,19 +217,25 @@ impl log::Log for Logger { let file = record.file().expect("no file in record"); let line = &record.line().expect("no line in record").to_string(); + let domain = if self.target_overrides_domain && record.metadata().target() != "" { + Some(record.metadata().target()) + } else { + self.default_domain + }; + match self.logger_type { LoggerType::Simple => { let s = format!("{}:{}: {}", file, line, record.args()); - glib_log(self.domain, record.level(), &s); + glib_log(domain, record.level(), &s); }, LoggerType::SimplePlain => { let s = format!("{}", record.args()); - glib_log(self.domain, record.level(), &s) + glib_log(domain, record.level(), &s) }, LoggerType::Structured => { let s = format!("{}", record.args()); glib_log_structured( - self.domain, + domain, record.level(), file, line, @@ -243,12 +260,51 @@ pub fn init(logger: &'static Logger) { log::set_logger(logger).expect("glib_logger::init failed to initialize"); } +pub fn try_init(logger: &'static Logger) -> Result<(), log::SetLoggerError> { + log::set_logger(logger) +} + #[cfg(test)] mod tests { use log::Level; use std::os::raw::c_char; use serial_test::serial; + static TEST_LOGGER: InterchangableLoggerWrap = InterchangableLoggerWrap { + wrapped_logger: std::cell::Cell::new(None) + }; + + struct InterchangableLoggerWrap { + wrapped_logger: std::cell::Cell>, + } + + impl InterchangableLoggerWrap { + pub fn set_wrapped_logger(&self, wrapped_logger: &'static dyn log::Log) { + self.wrapped_logger.set(Some(wrapped_logger)); + } + + pub fn clear_wrapped_logger(&self) { + self.wrapped_logger.set(None); + } + } + + unsafe impl Send for InterchangableLoggerWrap {} + unsafe impl Sync for InterchangableLoggerWrap {} + + impl log::Log for InterchangableLoggerWrap { + fn enabled(&self, _metadata: &log::Metadata) -> bool { + self.wrapped_logger.get().is_some() + } + + fn log(&self, record: &log::Record) { + if let Some(logger) = self.wrapped_logger.get() { + logger.log(record); + } + } + + fn flush(&self) {} + } + struct LogTrace { domain: Option, level: Option, @@ -307,6 +363,11 @@ mod tests { trace.level = Some(level); } + fn init_test_logger() { + let _ = log::set_logger(&TEST_LOGGER); + log::set_max_level(log::LevelFilter::Debug); + } + #[test] #[serial] fn simple_log() { @@ -329,6 +390,7 @@ mod tests { assert_eq!(trace.level, Some(glib_sys::G_LOG_LEVEL_DEBUG)); } + #[test] #[serial] fn simple_formatted_log() { @@ -371,4 +433,55 @@ mod tests { ); assert_eq!(trace.level, Some(glib_sys::G_LOG_LEVEL_CRITICAL)); } + + #[test] + #[serial] + fn via_macro() { + static THIS_LOGGER: crate::Logger = crate::custom(crate::LoggerType::SimplePlain, None, false); + init_test_logger(); + TEST_LOGGER.set_wrapped_logger(&THIS_LOGGER); + + let trace = collect_log(|| { + warn!("foobar"); + }); + assert_eq!(trace.domain, None); + assert_eq!(trace.message, Some("foobar".to_string())); + assert_eq!(trace.level, Some(glib_sys::G_LOG_LEVEL_WARNING)); + + TEST_LOGGER.clear_wrapped_logger(); + } + + #[test] + #[serial] + fn via_macro_domain_default() { + static THIS_LOGGER: crate::Logger = crate::custom(crate::LoggerType::SimplePlain, Some("barbaz"), false); + init_test_logger(); + TEST_LOGGER.set_wrapped_logger(&THIS_LOGGER); + + let trace = collect_log(|| { + warn!("foobar"); + }); + assert_eq!(trace.domain, Some("barbaz".to_string())); + assert_eq!(trace.message, Some("foobar".to_string())); + assert_eq!(trace.level, Some(glib_sys::G_LOG_LEVEL_WARNING)); + + TEST_LOGGER.clear_wrapped_logger(); + } + + #[test] + #[serial] + fn via_macro_domain_override() { + static THIS_LOGGER: crate::Logger = crate::custom(crate::LoggerType::SimplePlain, Some("barbaz"), true); + init_test_logger(); + TEST_LOGGER.set_wrapped_logger(&THIS_LOGGER); + + let trace = collect_log(|| { + warn!(target: "notbarbaz", "foobar"); + }); + assert_eq!(trace.domain, Some("notbarbaz".to_string())); + assert_eq!(trace.message, Some("foobar".to_string())); + assert_eq!(trace.level, Some(glib_sys::G_LOG_LEVEL_WARNING)); + + TEST_LOGGER.clear_wrapped_logger(); + } } From 1f8b119dd5e5a77d4ca49362a879ff2e13f1791f Mon Sep 17 00:00:00 2001 From: Marco Mastropaolo Date: Thu, 2 Jul 2020 12:20:03 +0200 Subject: [PATCH 4/4] Added complete domain support, examples and docs --- Cargo.toml | 7 + README.md | 143 +++++++- examples/custom_log_function.rs | 64 ++++ examples/g_macro_domain.rs | 39 +++ examples/override_macro_domain.rs | 44 +++ examples/simple.rs | 23 ++ examples/simple_domain.rs | 28 ++ examples/target_domain.rs | 28 ++ src/domain_macros.rs | 64 ++++ src/lib.rs | 556 ++++++++++-------------------- src/logging.rs | 121 +++++++ src/redefined_log_macros.rs | 49 +++ src/tests.rs | 296 ++++++++++++++++ 13 files changed, 1080 insertions(+), 382 deletions(-) create mode 100644 examples/custom_log_function.rs create mode 100644 examples/g_macro_domain.rs create mode 100644 examples/override_macro_domain.rs create mode 100644 examples/simple.rs create mode 100644 examples/simple_domain.rs create mode 100644 examples/target_domain.rs create mode 100644 src/domain_macros.rs create mode 100644 src/logging.rs create mode 100644 src/redefined_log_macros.rs create mode 100644 src/tests.rs diff --git a/Cargo.toml b/Cargo.toml index 029be59..23db81b 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -16,5 +16,12 @@ license = "MIT" log = "0.4.0" glib-sys = { version = "0.9.1", features = ["v2_44"] } +[features] +redefine_log_macros = [] + [dev-dependencies] serial_test = "0.4.0" + +[[example]] +name = "override_macro_domain" +required-features = [ "redefine_log_macros" ] diff --git a/README.md b/README.md index 06f461a..dae15da 100644 --- a/README.md +++ b/README.md @@ -1,13 +1,15 @@ A simple logger that integrates with [glib message logging](https://developer.gnome.org/glib/unstable/glib-Message-Logging.html) mechanism. The logger is useful when one wants to integrate a piece of Rust -code into a larger application which is already using glib/gio stack. +code into a larger application which is already using the glib/gio stack, or +for Rust applications and libraries using gtk-rs or similar infrastructure. -### Example +### Simplest example ```rust use std::env; +#[macro_use] use log; fn main() { @@ -16,9 +18,9 @@ fn main() { glib_logger::init(&glib_logger::SIMPLE); log::set_max_level(log::LevelFilter::Debug); - log::info!("info message: {}", 2); - log::warn!("warning message: {}", "foobar"); - log::debug!("Hello, world!"); + info!("info message: {}", 2); + warn!("warning message: {}", "foobar"); + debug!("Hello, world!"); } ``` @@ -44,7 +46,61 @@ $ ./glib_logger_test ** (process:39403): DEBUG: 20:18:34.076: src/main.rs:15: Hello, world! ``` -### Details +### Examples + +The crate provides a series of examples in the `examples/` subdir. + +- simple.rs : The simplest usage example possible, zero customization. +- simple_domain.rs : How to use a simple, custom glib log domain. +- target_domain.rs : How to map the Rust log target to the glib log domain. +- g_macro_domain.rs : How to use macros to have the glib log domain specified + in `G_LOG_DOMAIN`. +- override_macro_domain.rs : How to use the optional feature to remap the + g_trace etc. macros over the standard log macro names +- custom_log_function.rs : How to specify a custom log function using + the `glib_sys` crate. + + +### Logger types + +The crate makes two logger types available, plus the functionality to build a +custom logger. + +The two predefined logger types are: + +- `glib_logger::SIMPLE`: a simple logger which prints the message, decorated + with file and line number, without a domain + +- `glib_logger::STRUCTURED`: an experimental logger using glib structured + logging capabilities + +Custom loggers can be defined with `glib_logger::custom`, specifying both how +the message is composed and how the logging domain is composed. + +`LoggerType` can be: + +- `LoggerType::Simple`: a simple logger which prints the message, decorated + with file and line number + +- `LoggerType::SimplePlain`: a simple logger which prints the message, without + decorating the message with file and line number + +- `LoggerType::Structured`: an experimental logger using glib structured + logging capabilities + +`LoggerDomain` can be: + +- `LoggerDomain::None`: a logger which uses an empty domain + +- `LoggerDomain::Custom(&'static str)`: a logger using a predefined domain; note + that the domain would then be the same across all Rust crates + +- `LoggerDomain::Context`: a logger using the logging context of the `log` crate + as the glib logging domain + +See the domain section for further details. + +### Log levels Due to slight differences between the meaning of respective log levels, the crate takes certain liberties. Specifically the log level mappings are: @@ -58,10 +114,75 @@ The G_LOG_LEVEL_ERROR (as produced via `g_error()` macro in C) is not mapped to any of `log::Level` enum values. The reason is that `g_error()` is fatal, while `log::error!()` is not. -The formatting is done fully in Rust. However, log filtering based on level is -done in Glib. It is advisable to set `G_MESSAGES_DEBUG=all` environment variable. +The formatting is done fully in Rust. Log filtering based on level is done in +both Glib and the Rust `log` crate. + +It is advisable to set `G_MESSAGES_DEBUG=all` environment variable if a custom +glib log handler is not used, to set the glib logger to debug level. + +Additionally log level will be filtered also by the `log` crate in Rust itself; +so to enable lower level of logs you might need to set the log level explicitely +using calls similar to `log::set_max_level(log::LevelFilter::Debug);`. + +### Domain Using Glib a domain can be set per file by using `#define G_LOG_DOMAIN -"my-domain"` directly in C code. This functionality is not avaialble when using -`glib_logger` default loggers. To reproduce this functionality, create a custom -logger using `pub static CUSTOM: Logger = custom(LoggerType::Structured, Some("my-domain"));`. +"my-domain"` directly in C code. + +This functionality is not available by default when using the predefined +`glib_logger` loggers, so a custom logger must be created using the `custom` +function. + +The closest option to get this functionality is using a custom logger with +LoggerDomain set as `LoggerDomain::Target`. + +This example shows how to use the target to set the domain using standard Rust +log functions: + +```rust +// initialize a static custom logger +static CUSTOM: Logger = custom(LoggerType::Simple, LoggerDomain::Target); +// set the logger as active +glib_logger::init(&CUSTOM); +// implicit; will use the current crate/file as domain +warn!("some log message"); +// explicit; will use the "my-domain" string as a domain +warn!(target: "my-domain", "some log message"); +``` + +Alternatively, you can use macros and `G_LOG_DOMAIN` in the same vein of glib +to support the domain functionality: + +```rust +// See the "g_macro_domain" example for a more extensive usage example. +#[macro_use] +extern crate glib_logger; +static G_LOG_DOMAIN: &str = "my-global-domain"; +static CUSTOM: Logger = custom(LoggerType::Simple, LoggerDomain::Target); +// ... +// set the logger as active +glib_logger::init(&CUSTOM); +// implicit; will use the domain in G_LOG_DOMAIN +g_warn!("some log message"); +// explicit; will use the "my-domain" string as a domain +g_warn!(target: "my-domain", "some log message"); +``` + +Finally, you can use macros in the same vein of glib ones to support the +domain functionality: + +```rust +// This requires the "redefine_log_macros" to be enabled in Cargo.toml. +// See the "override_macro_domain" example for a more extensive usage example. +#[macro_use] +extern crate glib_logger; +static G_LOG_DOMAIN: &str = "my-global-domain"; +static CUSTOM: Logger = custom(LoggerType::Simple, LoggerDomain::Target); +// ... +// set the logger as active +glib_logger::init(&CUSTOM); +// implicit; will use the domain in G_LOG_DOMAIN +warn!("some log message"); +// explicit; will use the "my-domain" string as a domain +warn!(target: "my-domain", "some log message"); +``` diff --git a/examples/custom_log_function.rs b/examples/custom_log_function.rs new file mode 100644 index 0000000..8520eea --- /dev/null +++ b/examples/custom_log_function.rs @@ -0,0 +1,64 @@ +// +// This example shows basic usage of a custom log function in glib for simple +// (non-structured) log formats. This is actually all done by the `glib_sys` +// crate, but example is included here because it's relevant to the logging +// use-case. +// +// To run this example, use: +// +// cargo run --example custom_log_function +// + +extern crate glib_logger; +use std::env; +#[macro_use] +extern crate log; +use std::os::raw::c_char; + +static DOMAIN_LOGGER: glib_logger::Logger = glib_logger::custom( + glib_logger::LoggerType::Simple, + glib_logger::LoggerDomain::Custom("mydomain") +); + +fn main() { + env::set_var("G_MESSAGES_DEBUG", "all"); + + // setup the custom log handler + unsafe { + glib_sys::g_log_set_default_handler( + Some(log_handler), // our "extern" function to perform logging + std::ptr::null_mut() // a pointer to optional "user data" + ); + } + + glib_logger::init(&DOMAIN_LOGGER); + log::set_max_level(log::LevelFilter::Debug); + + info!("info message: {}", 2); + warn!("warning message: {}", "foobar"); + debug!("Hello, world!"); +} + +unsafe extern "C" fn log_handler( + domain_ptr: *const c_char, + level: glib_sys::GLogLevelFlags, + message_ptr: *const c_char, + _data_ptr: glib_sys::gpointer, +) { + use std::ffi::CStr; + + let message = if !message_ptr.is_null() { + Some(CStr::from_ptr(message_ptr).to_string_lossy().into_owned()) + } else { + None + }; + + let domain = if !domain_ptr.is_null() { + Some(CStr::from_ptr(domain_ptr).to_string_lossy().into_owned()) + } else { + None + }; + + println!("LOG: {:?} - {:?} - {:?}", level, domain, message); +} + diff --git a/examples/g_macro_domain.rs b/examples/g_macro_domain.rs new file mode 100644 index 0000000..22c2d4c --- /dev/null +++ b/examples/g_macro_domain.rs @@ -0,0 +1,39 @@ +// +// This example shows basic usage of custom domains using a G_LOG_DOMAIN +// variable and `g_trace` .. `g_error` macros. The variable should be static, +// but it can be different for each module. +// +// To run this example, use: +// +// cargo run --example g_macro_domain +// + +#[macro_use] +extern crate glib_logger; +use std::env; + +static DOMAIN_LOGGER: glib_logger::Logger = glib_logger::custom( + glib_logger::LoggerType::Simple, + glib_logger::LoggerDomain::Target +); + +static G_LOG_DOMAIN: &str = "my-global-domain"; + +fn main() { + env::set_var("G_MESSAGES_DEBUG", "all"); + + glib_logger::init(&DOMAIN_LOGGER); + log::set_max_level(log::LevelFilter::Debug); + + g_info!("info message: {}", 2); + g_warn!(target: "my-custom-domain", "warning message: {}", "foobar"); + different_domain::log_on_different_domain(); + g_debug!("Hello, world!"); +} + +mod different_domain { + static G_LOG_DOMAIN: &str = "my-scoped-domain"; + pub fn log_on_different_domain() { + g_error!("this will be in a scoped domain"); + } +} diff --git a/examples/override_macro_domain.rs b/examples/override_macro_domain.rs new file mode 100644 index 0000000..fa93f5f --- /dev/null +++ b/examples/override_macro_domain.rs @@ -0,0 +1,44 @@ +// +// This example shows basic usage of custom domains using a G_LOG_DOMAIN +// variable while keeping, at the same time, usage of standard `log`-like +// macros. The variable should be static, but it can be different for each +// module. +// +// If you use similar code in your example, you'll need to enable the +// `redefine_log_macros` feature in `Cargo.toml`. +// +// To run this example, use: +// +// cargo run --example override_macro_domain --features="redefine_log_macros" +// + +#[macro_use] +extern crate glib_logger; + +use std::env; + +static DOMAIN_LOGGER: glib_logger::Logger = glib_logger::custom( + glib_logger::LoggerType::Simple, + glib_logger::LoggerDomain::Target +); + +static G_LOG_DOMAIN: &str = "my-global-domain"; + +fn main() { + env::set_var("G_MESSAGES_DEBUG", "all"); + + glib_logger::init(&DOMAIN_LOGGER); + log::set_max_level(log::LevelFilter::Debug); + + info!("info message: {}", 2); + warn!(target: "my-custom-domain", "warning message: {}", "foobar"); + different_domain::log_on_different_domain(); + debug!("Hello, world!"); +} + +mod different_domain { + static G_LOG_DOMAIN: &str = "my-scoped-domain"; + pub fn log_on_different_domain() { + error!("this will be in a scoped domain"); + } +} diff --git a/examples/simple.rs b/examples/simple.rs new file mode 100644 index 0000000..70ef679 --- /dev/null +++ b/examples/simple.rs @@ -0,0 +1,23 @@ +// +// This example shows basic usage of the glib logging library +// +// To run this example, use: +// +// cargo run --example simple +// + +extern crate glib_logger; +#[macro_use] +extern crate log; +use std::env; + +fn main() { + env::set_var("G_MESSAGES_DEBUG", "all"); + + glib_logger::init(&glib_logger::SIMPLE); + log::set_max_level(log::LevelFilter::Debug); + + info!("info message: {}", 2); + warn!("warning message: {}", "foobar"); + debug!("Hello, world!"); +} diff --git a/examples/simple_domain.rs b/examples/simple_domain.rs new file mode 100644 index 0000000..201131c --- /dev/null +++ b/examples/simple_domain.rs @@ -0,0 +1,28 @@ +// +// This example shows basic usage of custom, fixed domains +// +// To run this example, use: +// +// cargo run --example simple_domain +// + +extern crate glib_logger; +use std::env; +#[macro_use] +extern crate log; + +static DOMAIN_LOGGER: glib_logger::Logger = glib_logger::custom( + glib_logger::LoggerType::Simple, + glib_logger::LoggerDomain::Custom("mydomain") +); + +fn main() { + env::set_var("G_MESSAGES_DEBUG", "all"); + + glib_logger::init(&DOMAIN_LOGGER); + log::set_max_level(log::LevelFilter::Debug); + + info!("info message: {}", 2); + warn!("warning message: {}", "foobar"); + debug!("Hello, world!"); +} diff --git a/examples/target_domain.rs b/examples/target_domain.rs new file mode 100644 index 0000000..62cdeb1 --- /dev/null +++ b/examples/target_domain.rs @@ -0,0 +1,28 @@ +// +// This example shows basic usage of custom, fixed domains +// +// To run this example, use: +// +// cargo run --example target_domain +// + +extern crate glib_logger; +use std::env; +#[macro_use] +extern crate log; + +static DOMAIN_LOGGER: glib_logger::Logger = glib_logger::custom( + glib_logger::LoggerType::Simple, + glib_logger::LoggerDomain::Target +); + +fn main() { + env::set_var("G_MESSAGES_DEBUG", "all"); + + glib_logger::init(&DOMAIN_LOGGER); + log::set_max_level(log::LevelFilter::Debug); + + info!("info message: {}", 2); + warn!(target: "my-custom-domain", "warning message: {}", "foobar"); + debug!("Hello, world!"); +} diff --git a/src/domain_macros.rs b/src/domain_macros.rs new file mode 100644 index 0000000..3467cd5 --- /dev/null +++ b/src/domain_macros.rs @@ -0,0 +1,64 @@ +/// A macro which behaves exactly as `log::error!` except that it sets the +/// current log target to the contents of a `G_LOG_DOMAIN` library (and fails +/// to build if not defined). +#[macro_export] +macro_rules! g_error { + (target: $target:expr, $($arg:tt)+) => ( + log::log!(target: $target, log::Level::Error, $($arg)+); + ); + ($($arg:tt)+) => ( + log::log!(target: G_LOG_DOMAIN, log::Level::Error, $($arg)+); + ) +} + +/// A macro which behaves exactly as `log::warn!` except that it sets the +/// current log target to the contents of a `G_LOG_DOMAIN` library (and fails +/// to build if not defined). +#[macro_export] +macro_rules! g_warn { + (target: $target:expr, $($arg:tt)+) => ( + log::log!(target: $target, log::Level::Warn, $($arg)+); + ); + ($($arg:tt)+) => ( + log::log!(target: G_LOG_DOMAIN, log::Level::Warn, $($arg)+); + ) +} + +/// A macro which behaves exactly as `log::info!` except that it sets the +/// current log target to the contents of a `G_LOG_DOMAIN` library (and fails +/// to build if not defined). +#[macro_export] +macro_rules! g_info { + (target: $target:expr, $($arg:tt)+) => ( + log::log!(target: $target, log::Level::Info, $($arg)+); + ); + ($($arg:tt)+) => ( + log::log!(target: G_LOG_DOMAIN, log::Level::Info, $($arg)+); + ) +} + +/// A macro which behaves exactly as `log::debug!` except that it sets the +/// current log target to the contents of a `G_LOG_DOMAIN` library (and fails +/// to build if not defined). +#[macro_export] +macro_rules! g_debug { + (target: $target:expr, $($arg:tt)+) => ( + log::log!(target: $target, log::Level::Debug, $($arg)+); + ); + ($($arg:tt)+) => ( + log::log!(target: G_LOG_DOMAIN, log::Level::Debug, $($arg)+); + ) +} + +/// A macro which behaves exactly as `log::trace!` except that it sets the +/// current log target to the contents of a `G_LOG_DOMAIN` library (and fails +/// to build if not defined). +#[macro_export] +macro_rules! g_trace { + (target: $target:expr, $($arg:tt)+) => ( + log::log!(target: $target, log::Level::Trace, $($arg)+); + ); + ($($arg:tt)+) => ( + log::log!(target: G_LOG_DOMAIN, log::Level::Trace, $($arg)+); + ) +} diff --git a/src/lib.rs b/src/lib.rs index af591bc..c6a3f93 100644 --- a/src/lib.rs +++ b/src/lib.rs @@ -23,13 +23,15 @@ //! A simple logger that integrates with [glib message //! logging](https://developer.gnome.org/glib/unstable/glib-Message-Logging.html) //! mechanism. The logger is useful when one wants to integrate a piece of Rust -//! code into a larger application which is already using glib/gio stack. +//! code into a larger application which is already using the glib/gio stack, or +//! for Rust applications and libraries using gtk-rs or similar infrastructure. //! -//! ### Example +//! ### Simplest example //! -//! ``` +//! ```ignore //! use std::env; //! +//! #[macro_use] //! use log; //! //! fn main() { @@ -38,14 +40,14 @@ //! glib_logger::init(&glib_logger::SIMPLE); //! log::set_max_level(log::LevelFilter::Debug); //! -//! log::info!("info message: {}", 2); -//! log::warn!("warning message: {}", "foobar"); -//! log::debug!("Hello, world!"); +//! info!("info message: {}", 2); +//! warn!("warning message: {}", "foobar"); +//! debug!("Hello, world!"); //! } //! ``` //! //! Equivalent Vala code: - +//! //! ```vala //! public void main() { //! Environment.set_variable ("G_MESSAGES_DEBUG", "all", false); @@ -57,7 +59,7 @@ //! ``` //! //! Running: - +//! //! ```bash //! $ ./glib_logger_test //! ** INFO: 20:18:34.074: src/main.rs:12: info message: 2 @@ -66,7 +68,61 @@ //! ** (process:39403): DEBUG: 20:18:34.076: src/main.rs:15: Hello, world! //! ``` //! -//! ### Details +//! ### Examples +//! +//! The crate provides a series of examples in the `examples/` subdir. +//! +//! - simple.rs : The simplest usage example possible, zero customization. +//! - simple_domain.rs : How to use a simple, custom glib log domain. +//! - target_domain.rs : How to map the Rust log target to the glib log domain. +//! - g_macro_domain.rs : How to use macros to have the glib log domain specified +//! in `G_LOG_DOMAIN`. +//! - override_macro_domain.rs : How to use the optional feature to remap the +//! g_trace etc. macros over the standard log macro names +//! - custom_log_function.rs : How to specify a custom log function using +//! the `glib_sys` crate. +//! +//! +//! ### Logger types +//! +//! The crate makes two logger types available, plus the functionality to build a +//! custom logger. +//! +//! The two predefined logger types are: +//! +//! - `glib_logger::SIMPLE`: a simple logger which prints the message, decorated +//! with file and line number, without a domain +//! +//! - `glib_logger::STRUCTURED`: an experimental logger using glib structured +//! logging capabilities +//! +//! Custom loggers can be defined with `glib_logger::custom`, specifying both how +//! the message is composed and how the logging domain is composed. +//! +//! `LoggerType` can be: +//! +//! - `LoggerType::Simple`: a simple logger which prints the message, decorated +//! with file and line number +//! +//! - `LoggerType::SimplePlain`: a simple logger which prints the message, without +//! decorating the message with file and line number +//! +//! - `LoggerType::Structured`: an experimental logger using glib structured +//! logging capabilities +//! +//! `LoggerDomain` can be: +//! +//! - `LoggerDomain::None`: a logger which uses an empty domain +//! +//! - `LoggerDomain::Custom(&'static str)`: a logger using a predefined domain; note +//! that the domain would then be the same across all Rust crates +//! +//! - `LoggerDomain::Context`: a logger using the logging context of the `log` crate +//! as the glib logging domain +//! +//! See the domain section for further details. +//! +//! ### Log levels //! //! Due to slight differences between the meaning of respective log levels, the //! crate takes certain liberties. Specifically the log level mappings are: @@ -80,408 +136,166 @@ //! any of `log::Level` enum values. The reason is that `g_error()` is fatal, while //! `log::error!()` is not. //! -//! The formatting is done fully in Rust. However, log filtering based on level is -//! done in Glib. It is advisable to set `G_MESSAGES_DEBUG=all` environment variable. +//! The formatting is done fully in Rust. Log filtering based on level is done in +//! both Glib and the Rust `log` crate. +//! +//! It is advisable to set `G_MESSAGES_DEBUG=all` environment variable if a custom +//! glib log handler is not used, to set the glib logger to debug level. +//! +//! Additionally log level will be filtered also by the `log` crate in Rust itself; +//! so to enable lower level of logs you might need to set the log level explicitely +//! using calls similar to `log::set_max_level(log::LevelFilter::Debug);`. +//! +//! ### Domain //! //! Using Glib a domain can be set per file by using `#define G_LOG_DOMAIN -//! "my-domain"` directly in C code. This functionality is not avaialble when using -//! `glib_logger`, all logs are emitted with a NULL domain. +//! "my-domain"` directly in C code. +//! +//! This functionality is not available by default when using the predefined +//! `glib_logger` loggers, so a custom logger must be created using the `custom` +//! function. +//! +//! The closest option to get this functionality is using a custom logger with +//! LoggerDomain set as `LoggerDomain::Target`. +//! +//! This example shows how to use the target to set the domain using standard Rust +//! log functions: +//! +//! ```ignore +//! // initialize a static custom logger +//! static CUSTOM: Logger = custom(LoggerType::Simple, LoggerDomain::Target); +//! // set the logger as active +//! glib_logger::init(&CUSTOM); +//! // implicit; will use the current crate/file as domain +//! warn!("some log message"); +//! // explicit; will use the "my-domain" string as a domain +//! warn!(target: "my-domain", "some log message"); +//! ``` +//! +//! Alternatively, you can use macros and `G_LOG_DOMAIN` in the same vein of glib +//! to support the domain functionality: +//! +//! ```ignore +//! // See the "g_macro_domain" example for a more extensive usage example. +//! #[macro_use] +//! extern crate glib_logger; +//! static G_LOG_DOMAIN: &str = "my-global-domain"; +//! static CUSTOM: Logger = custom(LoggerType::Simple, LoggerDomain::Target); +//! // ... +//! // set the logger as active +//! glib_logger::init(&CUSTOM); +//! // implicit; will use the domain in G_LOG_DOMAIN +//! g_warn!("some log message"); +//! // explicit; will use the "my-domain" string as a domain +//! g_warn!(target: "my-domain", "some log message"); +//! ``` +//! +//! Finally, you can use macros in the same vein of glib ones to support the +//! domain functionality: +//! +//! ```ignore +//! // This requires the "redefine_log_macros" to be enabled in Cargo.toml. +//! // See the "override_macro_domain" example for a more extensive usage example. +//! #[macro_use] +//! extern crate glib_logger; +//! static G_LOG_DOMAIN: &str = "my-global-domain"; +//! static CUSTOM: Logger = custom(LoggerType::Simple, LoggerDomain::Target); +//! // ... +//! // set the logger as active +//! glib_logger::init(&CUSTOM); +//! // implicit; will use the domain in G_LOG_DOMAIN +//! warn!("some log message"); +//! // explicit; will use the "my-domain" string as a domain +//! warn!(target: "my-domain", "some log message"); +//! ``` + +mod logging; + +#[macro_use] +mod domain_macros; #[macro_use] -extern crate log; +#[cfg(any(test, feature = "redefine_log_macros"))] +mod redefined_log_macros; + +#[cfg(test)] +mod tests; -use log::{Level, Metadata, Record}; +/// The possible message composition behaviors #[derive(Debug, Copy, Clone)] pub enum LoggerType { + /// A simple logger, writing file, line and message on output Simple, + /// A simple logger, writing only message on output SimplePlain, + /// An experimental logger using glib structured logging Structured, } +/// The possible domain handling behaviors +pub enum LoggerDomain { + /// Logs will have no domain specified + None, + /// Logs will have a custom predefined domain specified + Custom(&'static str), + /// Logs will use the `target` of the log crate as a domain + Target, +} + +/// The logger object which will be used. +/// Use `init` or `try_init` to set a logger object as +/// the current logger. pub struct Logger { logger_type: LoggerType, - default_domain: Option<&'static str>, - target_overrides_domain: bool, + domain: LoggerDomain, } +/// A function returning a preinitialized simple logger. +/// Usage of the predefined `SIMPLE` static is recommended. pub const fn simple() -> Logger { Logger { logger_type: LoggerType::Simple, - default_domain: None, - target_overrides_domain: true, + domain: LoggerDomain::None, } } +/// A function returning a preinitialized structured logger. +/// Usage of the predefined `STRUCTURED` static is recommended. +/// Note: support for structured loggers is experimental. pub const fn structured() -> Logger { Logger { logger_type: LoggerType::Structured, - default_domain: None, - target_overrides_domain: true, + domain: LoggerDomain::None, } } -pub const fn custom( - logger_type: LoggerType, - default_domain: Option<&'static str>, - target_overrides_domain: bool -) -> Logger { +/// A function returning a custom logger, allowing the caller to +/// specify `LoggerType` and `LoggerDomain`. +/// The return value of this should be store in a static variable. +pub const fn custom(logger_type: LoggerType, domain: LoggerDomain) -> Logger { Logger { logger_type, - default_domain, - target_overrides_domain, + domain, } } -trait ToGlib { - type GlibType; - - fn to_glib(&self) -> Self::GlibType; -} - -impl ToGlib for log::Level { - type GlibType = glib_sys::GLogLevelFlags; - - fn to_glib(&self) -> glib_sys::GLogLevelFlags { - match *self { - Level::Debug => glib_sys::G_LOG_LEVEL_DEBUG, - Level::Info => glib_sys::G_LOG_LEVEL_INFO, - Level::Warn => glib_sys::G_LOG_LEVEL_WARNING, - Level::Trace => glib_sys::G_LOG_LEVEL_DEBUG, - // cannot use G_LOG_LEVEL_ERROR as those are always fatal - Level::Error => glib_sys::G_LOG_LEVEL_CRITICAL, - } - } -} - -fn glib_log_structured(domain: Option<&str>, level: log::Level, file: &str, line: &str, func: &str, message: &str) { - use glib_sys::g_log_structured_standard; - use std::ffi::CString; - use std::ptr; - - let c_file = CString::new(file).expect("CString::new(file) failed"); - let c_line = CString::new(line).expect("CString::new(line) failed"); - let c_func = CString::new(func).expect("CString::new(func) failed"); - let c_message = CString::new(message).expect("CString::new(message) failed"); - - let c_domain_ptr = match domain { - None => ptr::null(), - Some(s) => match CString::new(s) { - Ok(s) => s.as_ptr(), - Err(_) => ptr::null(), - }, - }; - - unsafe { - g_log_structured_standard( - c_domain_ptr, - level.to_glib(), - c_file.as_ptr(), - c_line.as_ptr(), - c_func.as_ptr(), - c_message.as_ptr(), - ); - } -} - -fn glib_log(domain: Option<&str>, level: log::Level, message: &str) { - use glib_sys::g_log; - use std::ffi::CString; - use std::ptr; - let c_message = CString::new(message).expect("CString::new(message) failed"); - - let c_domain = match domain { - None => None, - Some(s) => Some(CString::new(s).expect("CString::new(domain) failed")), - }; - - let c_domain_ptr = match &c_domain { - None => ptr::null(), - Some(s) => s.as_ptr(), - }; - - unsafe { - g_log(c_domain_ptr, level.to_glib(), c_message.as_ptr()); - } -} - -impl log::Log for Logger { - fn enabled(&self, _metadata: &Metadata) -> bool { - true - } - - fn log(&self, record: &Record) { - if !self.enabled(record.metadata()) { - return; - } - let file = record.file().expect("no file in record"); - let line = &record.line().expect("no line in record").to_string(); - - let domain = if self.target_overrides_domain && record.metadata().target() != "" { - Some(record.metadata().target()) - } else { - self.default_domain - }; - - match self.logger_type { - LoggerType::Simple => { - let s = format!("{}:{}: {}", file, line, record.args()); - glib_log(domain, record.level(), &s); - }, - LoggerType::SimplePlain => { - let s = format!("{}", record.args()); - glib_log(domain, record.level(), &s) - }, - LoggerType::Structured => { - let s = format!("{}", record.args()); - glib_log_structured( - domain, - record.level(), - file, - line, - record.module_path().expect("no module"), - &s, - ); - }, - }; - } - - fn flush(&self) {} -} - -// Simple logger. +/// A predefined static contained a preinitialized simple logger. pub static SIMPLE: Logger = simple(); -// Structured logger (Experimental). +/// A predefined static contained a preinitialized structured +/// logger +/// Note: support for structured loggers is experimental. pub static STRUCTURED: Logger = structured(); -// Set up given logger. +/// Sets up given logger as the active logger. If a logger is +/// already initialized, this will panic. pub fn init(logger: &'static Logger) { - log::set_logger(logger).expect("glib_logger::init failed to initialize"); + try_init(logger).expect("glib_logger::init failed to initialize"); } +/// Sets up given logger as the active logger. If a logger is +/// already initialized, this will return a `log::SetLoggerError`. pub fn try_init(logger: &'static Logger) -> Result<(), log::SetLoggerError> { - log::set_logger(logger) -} - -#[cfg(test)] -mod tests { - use log::Level; - use std::os::raw::c_char; - use serial_test::serial; - - static TEST_LOGGER: InterchangableLoggerWrap = InterchangableLoggerWrap { - wrapped_logger: std::cell::Cell::new(None) - }; - - struct InterchangableLoggerWrap { - wrapped_logger: std::cell::Cell>, - } - - impl InterchangableLoggerWrap { - pub fn set_wrapped_logger(&self, wrapped_logger: &'static dyn log::Log) { - self.wrapped_logger.set(Some(wrapped_logger)); - } - - pub fn clear_wrapped_logger(&self) { - self.wrapped_logger.set(None); - } - } - - unsafe impl Send for InterchangableLoggerWrap {} - unsafe impl Sync for InterchangableLoggerWrap {} - - impl log::Log for InterchangableLoggerWrap { - fn enabled(&self, _metadata: &log::Metadata) -> bool { - self.wrapped_logger.get().is_some() - } - - fn log(&self, record: &log::Record) { - if let Some(logger) = self.wrapped_logger.get() { - logger.log(record); - } - } - - fn flush(&self) {} - } - - struct LogTrace { - domain: Option, - level: Option, - message: Option, - } - - impl LogTrace { - fn new() -> LogTrace { - LogTrace { - domain: None, - level: None, - message: None, - } - } - } - - fn collect_log(test_case: fn()) -> LogTrace { - use glib_sys::g_log_set_default_handler; - use std::ffi::c_void; - use std::ptr; - - let mut trace = LogTrace::new(); - let prev_handler: glib_sys::GLogFunc; - - unsafe { - prev_handler = - g_log_set_default_handler(Some(log_writer), &mut trace as *mut _ as *mut c_void); - } - test_case(); - unsafe { - g_log_set_default_handler(prev_handler, ptr::null_mut()); - } - - trace - } - - unsafe extern "C" fn log_writer( - domain_ptr: *const c_char, - level: glib_sys::GLogLevelFlags, - message_ptr: *const c_char, - data_ptr: glib_sys::gpointer, - ) { - use std::ffi::CStr; - - if data_ptr.is_null() { - panic!("own data is NULL"); - } - let trace: &mut LogTrace = &mut *(data_ptr as *mut LogTrace); - - if !message_ptr.is_null() { - trace.message = Some(CStr::from_ptr(message_ptr).to_string_lossy().into_owned()); - } - if !domain_ptr.is_null() { - trace.domain = Some(CStr::from_ptr(domain_ptr).to_string_lossy().into_owned()); - } - trace.level = Some(level); - } - - fn init_test_logger() { - let _ = log::set_logger(&TEST_LOGGER); - log::set_max_level(log::LevelFilter::Debug); - } - - #[test] - #[serial] - fn simple_log() { - let trace = collect_log(|| { - super::glib_log(None, Level::Debug, "foobar"); - }); - assert_eq!(trace.domain, None); - assert_eq!(trace.message, Some("foobar".to_string())); - assert_eq!(trace.level, Some(glib_sys::G_LOG_LEVEL_DEBUG)); - } - - #[test] - #[serial] - fn domain_log() { - let trace = collect_log(|| { - super::glib_log(Some("barbaz"), Level::Debug, "foobar"); - }); - assert_eq!(trace.domain, Some(String::from("barbaz"))); - assert_eq!(trace.message, Some("foobar".to_string())); - assert_eq!(trace.level, Some(glib_sys::G_LOG_LEVEL_DEBUG)); - } - - - #[test] - #[serial] - fn simple_formatted_log() { - let trace = collect_log(|| { - super::glib_log( - None, - Level::Info, - &format!("this is a test {} \"{}\" %%d", 123, "abcd"), - ); - }); - assert_eq!(trace.domain, None); - assert_eq!( - trace.message, - Some("this is a test 123 \"abcd\" %d".to_string()) - ); - assert_eq!(trace.level, Some(glib_sys::G_LOG_LEVEL_INFO)); - } - - // TODO: figure out a way to install handler for structure logs - - #[test] - #[serial] - fn via_logger() { - let trace = collect_log(|| { - use log::Log; - - let l = super::simple(); - l.log(&log::Record::builder() - .level(Level::Error) - .file(Some("foo.rs")) - .line(Some(123)) - .module_path(None) - .args(format_args!("this is a test \"{}\" {}", "abcd", 12)) - .build()); - }); - assert_eq!(trace.domain, None); - assert_eq!( - trace.message, - Some("foo.rs:123: this is a test \"abcd\" 12".to_string()) - ); - assert_eq!(trace.level, Some(glib_sys::G_LOG_LEVEL_CRITICAL)); - } - - #[test] - #[serial] - fn via_macro() { - static THIS_LOGGER: crate::Logger = crate::custom(crate::LoggerType::SimplePlain, None, false); - init_test_logger(); - TEST_LOGGER.set_wrapped_logger(&THIS_LOGGER); - - let trace = collect_log(|| { - warn!("foobar"); - }); - assert_eq!(trace.domain, None); - assert_eq!(trace.message, Some("foobar".to_string())); - assert_eq!(trace.level, Some(glib_sys::G_LOG_LEVEL_WARNING)); - - TEST_LOGGER.clear_wrapped_logger(); - } - - #[test] - #[serial] - fn via_macro_domain_default() { - static THIS_LOGGER: crate::Logger = crate::custom(crate::LoggerType::SimplePlain, Some("barbaz"), false); - init_test_logger(); - TEST_LOGGER.set_wrapped_logger(&THIS_LOGGER); - - let trace = collect_log(|| { - warn!("foobar"); - }); - assert_eq!(trace.domain, Some("barbaz".to_string())); - assert_eq!(trace.message, Some("foobar".to_string())); - assert_eq!(trace.level, Some(glib_sys::G_LOG_LEVEL_WARNING)); - - TEST_LOGGER.clear_wrapped_logger(); - } - - #[test] - #[serial] - fn via_macro_domain_override() { - static THIS_LOGGER: crate::Logger = crate::custom(crate::LoggerType::SimplePlain, Some("barbaz"), true); - init_test_logger(); - TEST_LOGGER.set_wrapped_logger(&THIS_LOGGER); - - let trace = collect_log(|| { - warn!(target: "notbarbaz", "foobar"); - }); - assert_eq!(trace.domain, Some("notbarbaz".to_string())); - assert_eq!(trace.message, Some("foobar".to_string())); - assert_eq!(trace.level, Some(glib_sys::G_LOG_LEVEL_WARNING)); - - TEST_LOGGER.clear_wrapped_logger(); - } + logging::try_init(logger) } diff --git a/src/logging.rs b/src/logging.rs new file mode 100644 index 0000000..8ec09a2 --- /dev/null +++ b/src/logging.rs @@ -0,0 +1,121 @@ +use log::{Level, Metadata, Record}; +use crate::{ Logger, LoggerDomain, LoggerType }; + +trait ToGlib { + type GlibType; + fn to_glib(&self) -> Self::GlibType; +} + +impl ToGlib for log::Level { + type GlibType = glib_sys::GLogLevelFlags; + + fn to_glib(&self) -> glib_sys::GLogLevelFlags { + match *self { + Level::Debug => glib_sys::G_LOG_LEVEL_DEBUG, + Level::Info => glib_sys::G_LOG_LEVEL_INFO, + Level::Warn => glib_sys::G_LOG_LEVEL_WARNING, + Level::Trace => glib_sys::G_LOG_LEVEL_DEBUG, + // cannot use G_LOG_LEVEL_ERROR as those are always fatal + Level::Error => glib_sys::G_LOG_LEVEL_CRITICAL, + } + } +} + +fn glib_log_structured(domain: Option<&str>, level: log::Level, file: &str, line: &str, func: &str, message: &str) { + use glib_sys::g_log_structured_standard; + use std::ffi::CString; + use std::ptr; + + let c_file = CString::new(file).expect("CString::new(file) failed"); + let c_line = CString::new(line).expect("CString::new(line) failed"); + let c_func = CString::new(func).expect("CString::new(func) failed"); + let c_message = CString::new(message).expect("CString::new(message) failed"); + + let c_domain_ptr = match domain { + None => ptr::null(), + Some(s) => match CString::new(s) { + Ok(s) => s.as_ptr(), + Err(_) => ptr::null(), + }, + }; + + unsafe { + g_log_structured_standard( + c_domain_ptr, + level.to_glib(), + c_file.as_ptr(), + c_line.as_ptr(), + c_func.as_ptr(), + c_message.as_ptr(), + ); + } +} + +pub fn glib_log(domain: Option<&str>, level: log::Level, message: &str) { + use glib_sys::g_log; + use std::ffi::CString; + use std::ptr; + let c_message = CString::new(message).expect("CString::new(message) failed"); + + let c_domain = match domain { + None => None, + Some(s) => Some(CString::new(s).expect("CString::new(domain) failed")), + }; + + let c_domain_ptr = match &c_domain { + None => ptr::null(), + Some(s) => s.as_ptr(), + }; + + unsafe { + g_log(c_domain_ptr, level.to_glib(), c_message.as_ptr()); + } +} + +impl log::Log for Logger { + fn enabled(&self, _metadata: &Metadata) -> bool { + true + } + + fn log(&self, record: &Record) { + if !self.enabled(record.metadata()) { + return; + } + let file = record.file().expect("no file in record"); + let line = &record.line().expect("no line in record").to_string(); + + let domain = match self.domain { + LoggerDomain::None => None, + LoggerDomain::Custom(s) => Some(s), + LoggerDomain::Target => Some(record.metadata().target()), + }; + + match self.logger_type { + LoggerType::Simple => { + let s = format!("{}:{}: {}", file, line, record.args()); + glib_log(domain, record.level(), &s); + }, + LoggerType::SimplePlain => { + let s = format!("{}", record.args()); + glib_log(domain, record.level(), &s) + }, + LoggerType::Structured => { + let s = format!("{}", record.args()); + glib_log_structured( + domain, + record.level(), + file, + line, + record.module_path().expect("no module"), + &s, + ); + }, + }; + } + + fn flush(&self) {} +} + +pub fn try_init(logger: &'static crate::Logger) -> Result<(), log::SetLoggerError> { + log::set_logger(logger) +} diff --git a/src/redefined_log_macros.rs b/src/redefined_log_macros.rs new file mode 100644 index 0000000..726e492 --- /dev/null +++ b/src/redefined_log_macros.rs @@ -0,0 +1,49 @@ +#[macro_export] +macro_rules! error { + (target: $target:expr, $($arg:tt)+) => ( + log::log!(target: $target, log::Level::Error, $($arg)+); + ); + ($($arg:tt)+) => ( + log::log!(target: G_LOG_DOMAIN, log::Level::Error, $($arg)+); + ) +} + +#[macro_export] +macro_rules! warn { + (target: $target:expr, $($arg:tt)+) => ( + log::log!(target: $target, log::Level::Warn, $($arg)+); + ); + ($($arg:tt)+) => ( + log::log!(target: G_LOG_DOMAIN, log::Level::Warn, $($arg)+); + ) +} + +#[macro_export] +macro_rules! info { + (target: $target:expr, $($arg:tt)+) => ( + log::log!(target: $target, log::Level::Info, $($arg)+); + ); + ($($arg:tt)+) => ( + log::log!(target: G_LOG_DOMAIN, log::Level::Info, $($arg)+); + ) +} + +#[macro_export] +macro_rules! debug { + (target: $target:expr, $($arg:tt)+) => ( + log::log!(target: $target, log::Level::Debug, $($arg)+); + ); + ($($arg:tt)+) => ( + log::log!(target: G_LOG_DOMAIN, log::Level::Debug, $($arg)+); + ) +} + +#[macro_export] +macro_rules! trace { + (target: $target:expr, $($arg:tt)+) => ( + log::log!(target: $target, log::Level::Trace, $($arg)+); + ); + ($($arg:tt)+) => ( + log::log!(target: G_LOG_DOMAIN, log::Level::Trace, $($arg)+); + ) +} diff --git a/src/tests.rs b/src/tests.rs new file mode 100644 index 0000000..8dcbd66 --- /dev/null +++ b/src/tests.rs @@ -0,0 +1,296 @@ +use log::Level; +use std::os::raw::c_char; +use serial_test::serial; +use crate::*; + +static TEST_LOGGER: InterchangableLoggerWrap = InterchangableLoggerWrap { + wrapped_logger: std::cell::Cell::new(None) +}; + +struct InterchangableLoggerWrap { + wrapped_logger: std::cell::Cell>, +} + +impl InterchangableLoggerWrap { + pub fn set_wrapped_logger(&self, wrapped_logger: &'static dyn log::Log) { + self.wrapped_logger.set(Some(wrapped_logger)); + } + + pub fn clear_wrapped_logger(&self) { + self.wrapped_logger.set(None); + } +} + +unsafe impl Send for InterchangableLoggerWrap {} +unsafe impl Sync for InterchangableLoggerWrap {} + +impl log::Log for InterchangableLoggerWrap { + fn enabled(&self, _metadata: &log::Metadata) -> bool { + self.wrapped_logger.get().is_some() + } + + fn log(&self, record: &log::Record) { + if let Some(logger) = self.wrapped_logger.get() { + logger.log(record); + } + } + + fn flush(&self) {} +} + +struct LogTrace { + domain: Option, + level: Option, + message: Option, +} + +impl LogTrace { + fn new() -> LogTrace { + LogTrace { + domain: None, + level: None, + message: None, + } + } +} + +fn collect_log(test_case: fn()) -> LogTrace { + use glib_sys::g_log_set_default_handler; + use std::ffi::c_void; + use std::ptr; + + let mut trace = LogTrace::new(); + let prev_handler: glib_sys::GLogFunc; + + unsafe { + prev_handler = + g_log_set_default_handler(Some(log_writer), &mut trace as *mut _ as *mut c_void); + } + test_case(); + unsafe { + g_log_set_default_handler(prev_handler, ptr::null_mut()); + } + + trace +} + +unsafe extern "C" fn log_writer( + domain_ptr: *const c_char, + level: glib_sys::GLogLevelFlags, + message_ptr: *const c_char, + data_ptr: glib_sys::gpointer, +) { + use std::ffi::CStr; + + if data_ptr.is_null() { + panic!("own data is NULL"); + } + let trace: &mut LogTrace = &mut *(data_ptr as *mut LogTrace); + + if !message_ptr.is_null() { + trace.message = Some(CStr::from_ptr(message_ptr).to_string_lossy().into_owned()); + } + if !domain_ptr.is_null() { + trace.domain = Some(CStr::from_ptr(domain_ptr).to_string_lossy().into_owned()); + } + trace.level = Some(level); +} + +fn init_test_logger() { + let _ = log::set_logger(&TEST_LOGGER); + log::set_max_level(log::LevelFilter::Debug); +} + +#[test] +#[serial] +fn simple_log() { + let trace = collect_log(|| { + logging::glib_log(None, Level::Debug, "foobar"); + }); + assert_eq!(trace.domain, None); + assert_eq!(trace.message, Some("foobar".to_string())); + assert_eq!(trace.level, Some(glib_sys::G_LOG_LEVEL_DEBUG)); +} + +#[test] +#[serial] +fn domain_log() { + let trace = collect_log(|| { + logging::glib_log(Some("barbaz"), Level::Debug, "foobar"); + }); + assert_eq!(trace.domain, Some(String::from("barbaz"))); + assert_eq!(trace.message, Some("foobar".to_string())); + assert_eq!(trace.level, Some(glib_sys::G_LOG_LEVEL_DEBUG)); +} + + +#[test] +#[serial] +fn simple_formatted_log() { + let trace = collect_log(|| { + logging::glib_log( + None, + Level::Info, + &format!("this is a test {} \"{}\" %%d", 123, "abcd"), + ); + }); + assert_eq!(trace.domain, None); + assert_eq!( + trace.message, + Some("this is a test 123 \"abcd\" %d".to_string()) + ); + assert_eq!(trace.level, Some(glib_sys::G_LOG_LEVEL_INFO)); +} + +// TODO: figure out a way to install handler for structure logs + +#[test] +#[serial] +fn via_logger() { + let trace = collect_log(|| { + use log::Log; + + let l = super::simple(); + l.log(&log::Record::builder() + .level(Level::Error) + .file(Some("foo.rs")) + .line(Some(123)) + .module_path(None) + .args(format_args!("this is a test \"{}\" {}", "abcd", 12)) + .build()); + }); + assert_eq!(trace.domain, None); + assert_eq!( + trace.message, + Some("foo.rs:123: this is a test \"abcd\" 12".to_string()) + ); + assert_eq!(trace.level, Some(glib_sys::G_LOG_LEVEL_CRITICAL)); +} + +#[test] +#[serial] +fn via_macro() { + static THIS_LOGGER: crate::Logger = crate::custom(crate::LoggerType::SimplePlain, + crate::LoggerDomain::None); + init_test_logger(); + TEST_LOGGER.set_wrapped_logger(&THIS_LOGGER); + + let trace = collect_log(|| { + log::warn!("foobar"); + }); + assert_eq!(trace.domain, None); + assert_eq!(trace.message, Some("foobar".to_string())); + assert_eq!(trace.level, Some(glib_sys::G_LOG_LEVEL_WARNING)); + + TEST_LOGGER.clear_wrapped_logger(); +} + +#[test] +#[serial] +fn via_macro_domain_default() { + static THIS_LOGGER: crate::Logger = crate::custom(crate::LoggerType::SimplePlain, + crate::LoggerDomain::Custom("barbaz")); + init_test_logger(); + TEST_LOGGER.set_wrapped_logger(&THIS_LOGGER); + + let trace = collect_log(|| { + log::warn!("foobar"); + }); + assert_eq!(trace.domain, Some("barbaz".to_string())); + assert_eq!(trace.message, Some("foobar".to_string())); + assert_eq!(trace.level, Some(glib_sys::G_LOG_LEVEL_WARNING)); + + TEST_LOGGER.clear_wrapped_logger(); +} + +#[test] +#[serial] +fn via_macro_domain_target() { + static THIS_LOGGER: crate::Logger = crate::custom( + crate::LoggerType::SimplePlain, crate::LoggerDomain::Target); + init_test_logger(); + TEST_LOGGER.set_wrapped_logger(&THIS_LOGGER); + + let trace = collect_log(|| { + log::warn!(target: "notbarbaz", "foobar"); + }); + assert_eq!(trace.domain, Some("notbarbaz".to_string())); + assert_eq!(trace.message, Some("foobar".to_string())); + assert_eq!(trace.level, Some(glib_sys::G_LOG_LEVEL_WARNING)); + + TEST_LOGGER.clear_wrapped_logger(); +} + +#[test] +#[serial] +fn via_gmacro_domain_target() { + static THIS_LOGGER: crate::Logger = crate::custom( + crate::LoggerType::SimplePlain, crate::LoggerDomain::Target); + init_test_logger(); + TEST_LOGGER.set_wrapped_logger(&THIS_LOGGER); + + let trace = collect_log(|| { + g_warn!(target: "notbarbaz", "foobar"); + }); + assert_eq!(trace.domain, Some("notbarbaz".to_string())); + assert_eq!(trace.message, Some("foobar".to_string())); + assert_eq!(trace.level, Some(glib_sys::G_LOG_LEVEL_WARNING)); + + TEST_LOGGER.clear_wrapped_logger(); +} + +#[test] +#[serial] +fn via_gmacro_domain_localdomain() { + static THIS_LOGGER: crate::Logger = crate::custom( + crate::LoggerType::SimplePlain, crate::LoggerDomain::Target); + static G_LOG_DOMAIN: &str = "barbaz"; + init_test_logger(); + TEST_LOGGER.set_wrapped_logger(&THIS_LOGGER); + + let trace = collect_log(|| { + g_warn!("foobar"); + }); + assert_eq!(trace.domain, Some("barbaz".to_string())); + assert_eq!(trace.message, Some("foobar".to_string())); + assert_eq!(trace.level, Some(glib_sys::G_LOG_LEVEL_WARNING)); + + TEST_LOGGER.clear_wrapped_logger(); +} + +#[test] +#[serial] +fn via_alias_macro_domain_target() { + static THIS_LOGGER: crate::Logger = crate::custom( + crate::LoggerType::SimplePlain, crate::LoggerDomain::Target); + init_test_logger(); + TEST_LOGGER.set_wrapped_logger(&THIS_LOGGER); + + let trace = collect_log(|| { + warn!(target: "notbarbaz", "foobar"); + }); + assert_eq!(trace.domain, Some("notbarbaz".to_string())); + assert_eq!(trace.message, Some("foobar".to_string())); + assert_eq!(trace.level, Some(glib_sys::G_LOG_LEVEL_WARNING)); + + TEST_LOGGER.clear_wrapped_logger(); +} + +#[test] +#[serial] +fn via_alias_macro_domain_localdomain() { + static THIS_LOGGER: crate::Logger = crate::custom( + crate::LoggerType::SimplePlain, crate::LoggerDomain::Target); + static G_LOG_DOMAIN: &str = "barbaz"; + init_test_logger(); + TEST_LOGGER.set_wrapped_logger(&THIS_LOGGER); + + let trace = collect_log(|| { + warn!("foobar"); + }); + assert_eq!(trace.domain, Some("barbaz".to_string())); + assert_eq!(trace.message, Some("foobar".to_string())); + assert_eq!(trace.level, Some(glib_sys::G_LOG_LEVEL_WARNING)); + + TEST_LOGGER.clear_wrapped_logger(); +} \ No newline at end of file