From e0bca8862619dd5cb593cd78098e11cd6166ba16 Mon Sep 17 00:00:00 2001 From: Asuna Date: Sat, 23 Nov 2024 10:20:44 +0800 Subject: [PATCH] Add basic support for structured logging (KV) --- spdlog/Cargo.toml | 1 + spdlog/src/formatter/full_formatter.rs | 2 +- spdlog/src/formatter/json_formatter.rs | 5 +- spdlog/src/formatter/pattern_formatter/mod.rs | 1 + spdlog/src/helper/concrete_cow.rs | 29 +++++++ spdlog/src/helper/mod.rs | 3 + spdlog/src/kv.rs | 86 +++++++++++++++++++ spdlog/src/lib.rs | 5 +- spdlog/src/log_macros.rs | 2 +- spdlog/src/record.rs | 37 +++++++- spdlog/src/sink/rotating_file_sink.rs | 4 +- 11 files changed, 166 insertions(+), 9 deletions(-) create mode 100644 spdlog/src/helper/concrete_cow.rs create mode 100644 spdlog/src/helper/mod.rs create mode 100644 spdlog/src/kv.rs diff --git a/spdlog/Cargo.toml b/spdlog/Cargo.toml index 86ac573d..4af1ac1b 100644 --- a/spdlog/Cargo.toml +++ b/spdlog/Cargo.toml @@ -57,6 +57,7 @@ spdlog-internal = { version = "=0.1.0", path = "../spdlog-internal", optional = spdlog-macros = { version = "=0.2.0", path = "../spdlog-macros" } spin = "0.9.8" thiserror = "1.0.37" +value-bag = { version = "1.10.0", features = ["owned"] } [target.'cfg(windows)'.dependencies] winapi = { version = "0.3.9", features = ["consoleapi", "debugapi", "handleapi", "processenv", "processthreadsapi", "winbase", "wincon"] } diff --git a/spdlog/src/formatter/full_formatter.rs b/spdlog/src/formatter/full_formatter.rs index 11b6347f..c81ad4da 100644 --- a/spdlog/src/formatter/full_formatter.rs +++ b/spdlog/src/formatter/full_formatter.rs @@ -130,7 +130,7 @@ mod tests { #[test] fn format() { - let record = Record::new(Level::Warn, "test log content", None, None); + let record = Record::new(Level::Warn, "test log content", None, None, &[]); let mut buf = StringBuf::new(); let mut ctx = FormatterContext::new(); FullFormatter::new() diff --git a/spdlog/src/formatter/json_formatter.rs b/spdlog/src/formatter/json_formatter.rs index dc3f6de0..82238f07 100644 --- a/spdlog/src/formatter/json_formatter.rs +++ b/spdlog/src/formatter/json_formatter.rs @@ -199,7 +199,7 @@ mod tests { fn should_format_json() { let mut dest = StringBuf::new(); let formatter = JsonFormatter::new(); - let record = Record::new(Level::Info, "payload", None, None); + let record = Record::new(Level::Info, "payload", None, None, &[]); let mut ctx = FormatterContext::new(); formatter.format(&record, &mut dest, &mut ctx).unwrap(); @@ -222,7 +222,7 @@ mod tests { fn should_format_json_with_logger_name() { let mut dest = StringBuf::new(); let formatter = JsonFormatter::new(); - let record = Record::new(Level::Info, "payload", None, Some("my-component")); + let record = Record::new(Level::Info, "payload", None, Some("my-component"), &[]); let mut ctx = FormatterContext::new(); formatter.format(&record, &mut dest, &mut ctx).unwrap(); @@ -250,6 +250,7 @@ mod tests { "payload", Some(SourceLocation::__new("module", "file.rs", 1, 2)), None, + &[], ); let mut ctx = FormatterContext::new(); formatter.format(&record, &mut dest, &mut ctx).unwrap(); diff --git a/spdlog/src/formatter/pattern_formatter/mod.rs b/spdlog/src/formatter/pattern_formatter/mod.rs index 5cd607a0..8f69a22c 100644 --- a/spdlog/src/formatter/pattern_formatter/mod.rs +++ b/spdlog/src/formatter/pattern_formatter/mod.rs @@ -1219,6 +1219,7 @@ mod tests { "record_payload", Some(SourceLocation::__new("module", "file", 10, 20)), Some("logger_name"), + &[], ) } diff --git a/spdlog/src/helper/concrete_cow.rs b/spdlog/src/helper/concrete_cow.rs new file mode 100644 index 00000000..ad4bb25b --- /dev/null +++ b/spdlog/src/helper/concrete_cow.rs @@ -0,0 +1,29 @@ +// Workaround https://stackoverflow.com/questions/79216846 + +use std::{borrow::Borrow, ops::Deref}; + +#[derive(Debug)] +pub(crate) enum ConcreteCow<'a, B: ?Sized, O> { + Borrowed(&'a B), + Owned(O), +} + +impl Clone for ConcreteCow<'_, B, O> { + fn clone(&self) -> Self { + match self { + Self::Borrowed(b) => Self::Borrowed(b), + Self::Owned(o) => Self::Owned(o.clone()), + } + } +} + +impl> Deref for ConcreteCow<'_, B, O> { + type Target = B; + + fn deref(&self) -> &B { + match *self { + Self::Borrowed(borrowed) => borrowed, + Self::Owned(ref owned) => owned.borrow(), + } + } +} diff --git a/spdlog/src/helper/mod.rs b/spdlog/src/helper/mod.rs new file mode 100644 index 00000000..1f67b71b --- /dev/null +++ b/spdlog/src/helper/mod.rs @@ -0,0 +1,3 @@ +mod concrete_cow; + +pub(crate) use concrete_cow::*; diff --git a/spdlog/src/kv.rs b/spdlog/src/kv.rs new file mode 100644 index 00000000..b9ad6878 --- /dev/null +++ b/spdlog/src/kv.rs @@ -0,0 +1,86 @@ +use std::borrow::Cow; + +use value_bag::{OwnedValueBag, ValueBag}; + +use crate::helper::ConcreteCow; + +#[derive(Debug, Clone)] +enum KeyInner<'a> { + Str(&'a str), + StaticStr(&'static str), +} + +#[derive(Debug, Clone)] +pub struct Key<'a>(KeyInner<'a>); + +impl<'a> Key<'a> { + pub fn __from_static_str(key: &'static str) -> Self { + Key(KeyInner::StaticStr(key)) + } + + fn from_str(key: &'a str) -> Self { + Key(KeyInner::Str(key)) + } + + pub(crate) fn to_owned(&self) -> KeyOwned { + let inner = match self.0 { + KeyInner::Str(s) => KeyOwnedInner::CowStr(Cow::Owned(s.to_string())), + KeyInner::StaticStr(s) => KeyOwnedInner::CowStr(Cow::Borrowed(s)), + }; + KeyOwned(inner) + } +} + +#[derive(Debug, Clone)] +enum KeyOwnedInner { + CowStr(Cow<'static, str>), +} + +#[derive(Debug, Clone)] +pub(crate) struct KeyOwned(KeyOwnedInner); + +impl KeyOwned { + pub(crate) fn as_ref(&self) -> Key { + let inner = match &self.0 { + KeyOwnedInner::CowStr(s) => match s { + Cow::Borrowed(s) => KeyInner::StaticStr(s), + Cow::Owned(s) => KeyInner::Str(s), + }, + }; + Key(inner) + } +} + +pub type Value<'a> = ValueBag<'a>; +pub(crate) type ValueOwned = OwnedValueBag; + +pub(crate) type Pair<'a> = (Key<'a>, Value<'a>); + +#[cfg(feature = "log")] +pub(crate) struct LogCrateConverter<'a>(Vec<(Key<'a>, Value<'a>)>); + +#[cfg(feature = "log")] +impl<'a> LogCrateConverter<'a> { + pub(crate) fn new(capacity: usize) -> Self { + Self(Vec::with_capacity(capacity)) + } + + pub(crate) fn finalize(self) -> ConcreteCow<'a, [Pair<'a>], Vec>> { + ConcreteCow::Owned(self.0) + } +} + +#[cfg(feature = "log")] +impl<'a> log::kv::VisitSource<'a> for LogCrateConverter<'a> { + fn visit_pair( + &mut self, + key: log::kv::Key<'a>, + value: log::kv::Value<'a>, + ) -> Result<(), log::kv::Error> { + self.0.push(( + Key::from_str(key.as_str()), + todo!("convert `lov::kv::Value` to `Value`"), + )); + Ok(()) + } +} diff --git a/spdlog/src/lib.rs b/spdlog/src/lib.rs index 40ba5148..ed054a13 100644 --- a/spdlog/src/lib.rs +++ b/spdlog/src/lib.rs @@ -281,6 +281,8 @@ mod env_level; pub mod error; pub mod formatter; +mod helper; +pub mod kv; mod level; #[cfg(feature = "log")] mod log_crate_proxy; @@ -784,6 +786,7 @@ pub fn __log( logger: &Logger, level: Level, srcloc: Option, + kvs: &[(kv::Key, kv::Value)], fmt_args: fmt::Arguments, ) { // Use `Cow` to avoid allocation as much as we can @@ -791,7 +794,7 @@ pub fn __log( .as_str() .map(Cow::Borrowed) // No format arguments, so it is a `&'static str` .unwrap_or_else(|| Cow::Owned(fmt_args.to_string())); - let record = Record::new(level, payload, srcloc, logger.name()); + let record = Record::new(level, payload, srcloc, logger.name(), kvs); logger.log(&record); } diff --git a/spdlog/src/log_macros.rs b/spdlog/src/log_macros.rs index 0ab0f070..d8bb1371 100644 --- a/spdlog/src/log_macros.rs +++ b/spdlog/src/log_macros.rs @@ -26,7 +26,7 @@ macro_rules! log { const LEVEL: $crate::Level = $level; const SHOULD_LOG: bool = $crate::STATIC_LEVEL_FILTER.__test_const(LEVEL); if SHOULD_LOG && logger.should_log(LEVEL) { - $crate::__log(logger, LEVEL, $crate::source_location_current!(), format_args!($($arg)+)); + $crate::__log(logger, LEVEL, $crate::source_location_current!(), &[], format_args!($($arg)+)); } }); ($level:expr, $($arg:tt)+) => ($crate::log!(logger: $crate::default_logger(), $level, $($arg)+)) diff --git a/spdlog/src/record.rs b/spdlog/src/record.rs index 7fe08db0..61660ac3 100644 --- a/spdlog/src/record.rs +++ b/spdlog/src/record.rs @@ -4,7 +4,7 @@ use std::{ time::SystemTime, }; -use crate::{Level, SourceLocation}; +use crate::{helper::ConcreteCow, kv, Level, SourceLocation}; /// Represents a log record. /// @@ -24,6 +24,7 @@ use crate::{Level, SourceLocation}; pub struct Record<'a> { logger_name: Option>, payload: Cow<'a, str>, + kvs: ConcreteCow<'a, [kv::Pair<'a>], Vec>>, inner: Cow<'a, RecordInner>, } @@ -42,10 +43,12 @@ impl<'a> Record<'a> { payload: impl Into>, srcloc: Option, logger_name: Option<&'a str>, + kvs: &'a [(kv::Key<'a>, kv::Value<'a>)], ) -> Record<'a> { Record { logger_name: logger_name.map(Cow::Borrowed), payload: payload.into(), + kvs: ConcreteCow::Borrowed(kvs), inner: Cow::Owned(RecordInner { level, source_location: srcloc, @@ -61,6 +64,11 @@ impl<'a> Record<'a> { RecordOwned { logger_name: self.logger_name.clone().map(|n| n.into_owned()), payload: self.payload.to_string(), + kvs: self + .kvs + .iter() + .map(|(k, v)| (k.to_owned(), v.to_owned())) + .collect(), inner: self.inner.clone().into_owned(), } } @@ -101,6 +109,12 @@ impl<'a> Record<'a> { self.inner.tid } + #[must_use] + pub fn key_values(&self) -> impl IntoIterator { + // The 2 clones should be cheap + self.kvs.iter().map(|(k, v)| (k.clone(), v.clone())) + } + // When adding more getters, also add to `RecordOwned` #[must_use] @@ -108,6 +122,7 @@ impl<'a> Record<'a> { Self { logger_name: self.logger_name.clone(), payload: new.into(), + kvs: self.kvs.clone(), inner: Cow::Borrowed(&self.inner), } } @@ -116,7 +131,7 @@ impl<'a> Record<'a> { #[must_use] pub(crate) fn from_log_crate_record( logger: &'a crate::Logger, - record: &log::Record, + record: &'a log::Record, time: SystemTime, ) -> Self { let args = record.args(); @@ -132,6 +147,12 @@ impl<'a> Record<'a> { Some(Cow::Owned(String::from(log_target))) } }), + kvs: { + let kvs = record.key_values(); + let mut cvt = kv::LogCrateConverter::new(kvs.count()); + assert!(kvs.visit(&mut cvt).is_ok()); + cvt.finalize() + }, payload: match args.as_str() { Some(literal_str) => literal_str.into(), None => args.to_string().into(), @@ -160,6 +181,7 @@ impl<'a> Record<'a> { pub struct RecordOwned { logger_name: Option, payload: String, + kvs: Vec<(kv::KeyOwned, kv::ValueOwned)>, inner: RecordInner, } @@ -170,6 +192,12 @@ impl RecordOwned { Record { logger_name: self.logger_name.as_deref().map(Cow::Borrowed), payload: Cow::Borrowed(&self.payload), + kvs: ConcreteCow::Owned( + self.kvs + .iter() + .map(|(k, v)| (k.as_ref(), v.by_ref())) + .collect::>(), + ), inner: Cow::Borrowed(&self.inner), } } @@ -210,6 +238,11 @@ impl RecordOwned { self.inner.tid } + #[must_use] + pub fn key_values(&self) -> impl IntoIterator { + self.kvs.iter().map(|(k, v)| (k.as_ref(), v.by_ref())) + } + // When adding more getters, also add to `Record` } diff --git a/spdlog/src/sink/rotating_file_sink.rs b/spdlog/src/sink/rotating_file_sink.rs index ea7dc015..7a6f7d24 100644 --- a/spdlog/src/sink/rotating_file_sink.rs +++ b/spdlog/src/sink/rotating_file_sink.rs @@ -1220,7 +1220,7 @@ mod tests { { let logger = build(true); - let mut record = Record::new(Level::Info, "test log message", None, None); + let mut record = Record::new(Level::Info, "test log message", None, None, &[]); let initial_time = record.time(); assert_files_count("hourly", 1); @@ -1279,7 +1279,7 @@ mod tests { }; { - let mut record = Record::new(Level::Info, "test log message", None, None); + let mut record = Record::new(Level::Info, "test log message", None, None, &[]); assert_files_count(prefix, 1);