Skip to content

Commit

Permalink
Write key values at end of log message
Browse files Browse the repository at this point in the history 
And support two formats: inline and multiline
  • Loading branch information
@tmccombs
tmccombs committed May 4, 2023
1 parent 05a4dc1 commit a47d1d9
Show file tree
Hide file tree
Showing 2 changed files with 138 additions and 46 deletions.
178 changes: 135 additions & 43 deletions src/fmt/mod.rs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -27,7 +27,8 @@
//! # Key Value arguments
//!
//! If the `kv_unstable` feature is enabled, then the default format will include key values from
//! the log by default, but this can be disabled with the [`Builder::format_key_values`] method.
//! the log by default, but this can be disabled by calling [`Builder::format_key_value_style`]
//! with [`KVStyle::Hidden`].
//!
//! ```
//! use log::info;
Expand All @@ -42,7 +43,8 @@
//! [`Style`]: struct.Style.html
//! [`Builder::format`]: ../struct.Builder.html#method.format
//! [`Write`]: https://doc.rust-lang.org/stable/std/io/trait.Write.html
//! [`Builder::format_key_values`]: ../struct.Builder.html#method.format_key_values
//! [`Builder::format_key_value_style`]: ../struct.Builder.html#method.format_key_value_style
//! [`KVStyle::Hidden`]: ../enum.KVStyle.html#variant.Hidden

use std::cell::RefCell;
use std::fmt::Display;
Expand Down Expand Up @@ -83,6 +85,38 @@ pub enum TimestampPrecision {
Nanos,
}

/// Style for displaying key/value structured data
///
/// This determines how key/value pairs are displayed in the log output.
/// The values can be suppressed, included in a trailer at the end of the line, or
/// included as multiple lines after the message.
#[derive(Copy, Clone, Debug, PartialEq, Eq)]
pub enum KVStyle {
/// Key/value pairs are not included in the output
Hidden,
/// Display the KV values at the end of the line
///
/// After the message, any KV data is printed within curly braces on the same line. An "="
/// is used to delimite the key from a value.
///
/// For example:
/// ```txt
/// [INFO] log message { a=1 b=2 }
/// ```
Inline,
/// Display the KV values on additional lines
///
/// Each key/value pair is printed on its own line, with key and value delimited by ": ".
///
/// For example:
/// ```txt
/// [INFO] log message
/// a: 1
/// b: 2
/// ```
Multiline,
}

/// The default timestamp precision is seconds.
impl Default for TimestampPrecision {
fn default() -> Self {
Expand Down Expand Up @@ -161,9 +195,9 @@ pub(crate) struct Builder {
pub format_target: bool,
pub format_level: bool,
pub format_indent: Option<usize>,
pub format_key_values: bool,
pub custom_format: Option<FormatFn>,
pub format_suffix: &'static str,
pub key_value_style: KVStyle,
built: bool,
}

Expand All @@ -175,9 +209,9 @@ impl Default for Builder {
format_target: true,
format_level: true,
format_indent: Some(4),
format_key_values: true,
custom_format: None,
format_suffix: "\n",
key_value_style: KVStyle::Multiline,
built: false,
}
}
Expand Down Expand Up @@ -209,10 +243,10 @@ impl Builder {
module_path: built.format_module_path,
target: built.format_target,
level: built.format_level,
key_values: built.format_key_values,
written_header_value: false,
indent: built.format_indent,
suffix: built.format_suffix,
key_value_style: built.key_value_style,
buf,
};

Expand All @@ -237,9 +271,9 @@ struct DefaultFormat<'a> {
level: bool,
written_header_value: bool,
indent: Option<usize>,
key_values: bool,
buf: &'a mut Formatter,
suffix: &'a str,
key_value_style: KVStyle,
}

impl<'a> DefaultFormat<'a> {
Expand All @@ -248,10 +282,11 @@ impl<'a> DefaultFormat<'a> {
self.write_level(record)?;
self.write_module_path(record)?;
self.write_target(record)?;
self.write_kv(record)?;
self.finish_header()?;

self.write_args(record)
self.write_args(record)?;
self.write_kv(record)?;
write!(self.buf, "{}", self.suffix)
}

fn subtle_style(&self, text: &'static str) -> SubtleStyle {
Expand Down Expand Up @@ -361,7 +396,7 @@ impl<'a> DefaultFormat<'a> {
fn write_args(&mut self, record: &Record) -> io::Result<()> {
match self.indent {
// Fast path for no indentation
None => write!(self.buf, "{}{}", record.args(), self.suffix),
None => write!(self.buf, "{}", record.args()),

Some(indent_count) => {
// Create a wrapper around the buffer only if we have to actually indent the message
Expand Down Expand Up @@ -405,8 +440,6 @@ impl<'a> DefaultFormat<'a> {
write!(wrapper, "{}", record.args())?;
}

write!(self.buf, "{}", self.suffix)?;

Ok(())
}
}
Expand All @@ -415,38 +448,66 @@ impl<'a> DefaultFormat<'a> {
fn write_kv(&mut self, record: &Record) -> io::Result<()> {
#[cfg(feature = "kv_unstable")]
{
if !self.key_values {
return Ok(());
}
let kvs = record.key_values();
if !self.written_header_value && kvs.count() > 0 {
self.written_header_value = true;
let open_brace = self.subtle_style("[");
write!(self.buf, "{}", open_brace)?;
match self.key_value_style {
KVStyle::Hidden => Ok(()),
KVStyle::Multiline => record
.key_values()
.visit(&mut KVMultilineVisitor(self))
.map_err(|e| io::Error::new(io::ErrorKind::Other, e)),
KVStyle::Inline => {
let kvs = record.key_values();
if kvs.count() > 0 {
write!(self.buf, " {}", self.subtle_style("{"))?;

kvs.visit(&mut KVInlineVisitor(self.buf))
.map_err(|e| io::Error::new(io::ErrorKind::Other, e))?;
write!(self.buf, "{}", self.subtle_style(" }"))?;
}
Ok(())
}
}
kvs.visit(&mut KeyValueVisitor(self.buf))
.map_err(|e| io::Error::new(io::ErrorKind::Other, e))
}
#[cfg(not(feature = "kv_unstable"))]
{
// avoid dead code lints
let _ = record;
let _ = self.key_values;
let _ = self.key_value_style;
Ok(())
}
}
}

#[cfg(feature = "kv_unstable")]
struct KeyValueVisitor<'a>(&'a mut Formatter);
struct KVInlineVisitor<'a>(&'a mut Formatter);

#[cfg(feature = "kv_unstable")]
impl<'a, 'kvs> kv::Visitor<'kvs> for KeyValueVisitor<'a> {
impl<'a, 'kvs> kv::Visitor<'kvs> for KVInlineVisitor<'a> {
fn visit_pair(&mut self, key: kv::Key<'kvs>, value: kv::Value<'kvs>) -> Result<(), kv::Error> {
write!(self.0, " {}={}", key, value).map_err(|e| e.into())
}
}

#[cfg(feature = "kv_unstable")]
struct KVMultilineVisitor<'a, 'fmt>(&'a mut DefaultFormat<'fmt>);

#[cfg(feature = "kv_unstable")]
impl<'a, 'kvs, 'fmt> kv::Visitor<'kvs> for KVMultilineVisitor<'a, 'fmt> {
fn visit_pair(&mut self, key: kv::Key<'kvs>, value: kv::Value<'kvs>) -> Result<(), kv::Error> {
let suffix = self.0.suffix;
let indent = self.0.indent.unwrap_or(0);
write!(
self.0.buf,
"{}{:width$}{}: {}",
"",
suffix,
key,
value,
width = indent
)?;
Ok(())
}
}

#[cfg(test)]
mod tests {
use super::*;
Expand Down Expand Up @@ -497,7 +558,7 @@ mod tests {
module_path: true,
target: false,
level: true,
key_values: false,
key_value_style: KVStyle::Hidden,
written_header_value: false,
indent: None,
suffix: "\n",
Expand All @@ -516,7 +577,7 @@ mod tests {
module_path: false,
target: false,
level: false,
key_values: false,
key_value_style: KVStyle::Hidden,
written_header_value: false,
indent: None,
suffix: "\n",
Expand All @@ -535,7 +596,7 @@ mod tests {
module_path: true,
target: false,
level: true,
key_values: false,
key_value_style: KVStyle::Hidden,
written_header_value: false,
indent: Some(4),
suffix: "\n",
Expand All @@ -554,7 +615,7 @@ mod tests {
module_path: true,
target: false,
level: true,
key_values: false,
key_value_style: KVStyle::Hidden,
written_header_value: false,
indent: Some(0),
suffix: "\n",
Expand All @@ -573,7 +634,7 @@ mod tests {
module_path: false,
target: false,
level: false,
key_values: false,
key_value_style: KVStyle::Hidden,
written_header_value: false,
indent: Some(4),
suffix: "\n",
Expand All @@ -592,7 +653,7 @@ mod tests {
module_path: false,
target: false,
level: false,
key_values: false,
key_value_style: KVStyle::Hidden,
written_header_value: false,
indent: None,
suffix: "\n\n",
Expand All @@ -611,7 +672,7 @@ mod tests {
module_path: false,
target: false,
level: false,
key_values: false,
key_value_style: KVStyle::Hidden,
written_header_value: false,
indent: Some(4),
suffix: "\n\n",
Expand All @@ -632,7 +693,7 @@ mod tests {
module_path: true,
target: true,
level: true,
key_values: false,
key_value_style: KVStyle::Hidden,
written_header_value: false,
indent: None,
suffix: "\n",
Expand All @@ -652,7 +713,7 @@ mod tests {
module_path: true,
target: true,
level: true,
key_values: false,
key_value_style: KVStyle::Hidden,
written_header_value: false,
indent: None,
suffix: "\n",
Expand All @@ -673,7 +734,7 @@ mod tests {
module_path: true,
target: false,
level: true,
key_values: false,
key_value_style: KVStyle::Hidden,
written_header_value: false,
indent: None,
suffix: "\n",
Expand All @@ -686,11 +747,11 @@ mod tests {

#[cfg(feature = "kv_unstable")]
#[test]
fn format_kv() {
fn format_kv_trailer() {
let kvs = &[("a", 1u32), ("b", 2u32)][..];
let mut f = formatter();
let record = Record::builder()
.args(format_args!("log\nmessage"))
.args(format_args!("log message"))
.level(Level::Info)
.module_path(Some("test::path"))
.key_values(&kvs)
Expand All @@ -703,21 +764,20 @@ mod tests {
module_path: false,
target: false,
level: true,
key_values: true,
key_value_style: KVStyle::Inline,
written_header_value: false,
indent: None,
suffix: "\n",
buf: &mut f,
},
);

#[cfg(feature = "kv_unstable")]
assert_eq!("[INFO a=1 b=2] log\nmessage\n", written);
assert_eq!("[INFO ] log message { a=1 b=2 }\n", written);
}

#[cfg(feature = "kv_unstable")]
#[test]
fn format_kv_full() {
fn format_kv_trailer_full() {
let kvs = &[("a", 1u32), ("b", 2u32)][..];
let mut f = formatter();
let record = Record::builder()
Expand All @@ -737,15 +797,47 @@ mod tests {
module_path: true,
target: true,
level: true,
key_values: true,
key_value_style: KVStyle::Inline,
written_header_value: false,
indent: None,
suffix: "\n",
buf: &mut f,
},
);

#[cfg(feature = "kv_unstable")]
assert_eq!("[INFO test::path target a=1 b=2] log\nmessage\n", written);
assert_eq!(
"[INFO test::path target] log\nmessage { a=1 b=2 }\n",
written
);
}

#[cfg(feature = "kv_unstable")]
#[test]
fn format_kv_multiline() {
let kvs = &[("a", 1u32), ("b", 2u32)][..];
let mut f = formatter();
let record = Record::builder()
.args(format_args!("log\nmessage"))
.level(Level::Info)
.module_path(Some("test::path"))
.key_values(&kvs)
.build();

let written = write_record(
record,
DefaultFormat {
timestamp: None,
module_path: false,
target: false,
level: true,
key_value_style: KVStyle::Multiline,
written_header_value: false,
indent: None,
suffix: "\n",
buf: &mut f,
},
);

assert_eq!("[INFO ] log\nmessage\na: 1\nb: 2\n", written);
}
}

0 comments on commit a47d1d9

Please sign in to comment.