Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

feat(spdlog): impl JsonFormatter #69

Merged
merged 20 commits into from
Aug 5, 2024
Merged
Show file tree
Hide file tree
Changes from 3 commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 1 addition & 1 deletion .github/workflows/ci.yml
Original file line number Diff line number Diff line change
Expand Up @@ -49,7 +49,7 @@ jobs:
fail-fast: false
matrix:
os: ['ubuntu-latest', 'windows-latest', 'macos-latest']
fn_features: ['', 'log native libsystemd multi-thread runtime-pattern']
fn_features: ['', 'log native libsystemd multi-thread runtime-pattern json-formatter']
cfg_feature: ['', 'flexible-string', 'source-location']
runs-on: ${{ matrix.os }}
steps:
Expand Down
3 changes: 3 additions & 0 deletions spdlog/Cargo.toml
Original file line number Diff line number Diff line change
Expand Up @@ -37,6 +37,7 @@ native = []
libsystemd = ["libsystemd-sys"]
multi-thread = ["crossbeam"]
runtime-pattern = ["spdlog-internal"]
json-formatter = ["serde", "serde_json"]
Copy link
Owner

@SpriteOvO SpriteOvO Jul 25, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I've been thinking about this gate these days. Perhaps we can enable JsonFormatter when feature serde is enabled and feature serde implies dependencies serde and serde_json, then feature json-formatter is no longer needed.

The benefit of it is that we have ability to add other serialization crates in the future, so users can choose the "backend" of JsonFormatter by enabling just one feature.

What do you think?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It might add lots of dependencies for a single feature as new formatters are introduced.

Or we can just make a SerdeFormatter as @Lancern said to decouple the serializer from the formatter. So user can choose any serializer instead of the serde_json.

Copy link
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It might add lots of dependencies for a single feature as new formatters are introduced.

Hmm, makes sense. What about enable JsonFormatter when feature serde_json is enabled, so serde_json implies serde?

Or we can just make a SerdeFormatter as @Lancern said to decouple the serializer from the formatter. So user can choose any serializer instead of the serde_json.

SerdeFormatter is fine, but we are in no hurry to implement it in this PR.

What I meant by my comment was that JsonFormatter should not be limited to only using serde as a backend. Semantically, JSON is a format and serde is an implementation. It seems more correct that the implementation implies the format, rather than the format implying the implementation. So that if now or in the future, there are any json crates that aren't serde-based, we could easily add it without breaking anything.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

serde_json implies serde sounds more reasonable.

Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

So that if now or in the future, there are any json crates that aren't serde-based, we could easily add it without breaking anything.

Is this really implementable? serde is the de-facto standard and we already rely on the critical abstractions it provides. The "critical abstractions" I'm talking about here is the Serialize trait which is provided by serde. I cannot work out a way to bypass it and still implement a usable JsonFormatter.

Copy link
Owner

@SpriteOvO SpriteOvO Jul 26, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Is this really implementable? serde is the de-facto standard [...] I cannot work out a way to bypass it and still implement a usable JsonFormatter.

It is. For now, there are crates rkyv, miniserde, nanoserde, etc., they each have their own advantages and are not serde-based. If we can harmlessly preserve the maximum possibilities, why not do so?

[...] and we already rely on the critical abstractions it provides. The "critical abstractions" I'm talking about here is the Serialize trait which is provided by serde.

If you are talking about deriving serde::Serialize macro for types of spdlog-rs, this can be unforced. Considering the following psuode-code:

#[cfg(and(feature = "serde", feature = "rkyv"))
compile_error!("you can select only one serialization backend");

#[cfg_attr(feature = "serde", derive(serde::Serialize))]
#[cfg_attr(feature = "rkyv", derive(rkyv::Serialize))]
pub enum Level {
    // ...
}

Then implement JsonFormatter:

// In fact, we'll apply this condition on `mod json_formatter` and `pub use json_formatter::JsonFormatter`.
#[cfg(any(feature = "serde_json", feature = "rkyv"))
pub struct JsonFormatter(PhantomData);

impl Formatter for JsonFormatter {
    fn format(&self, record: &Record, dest: &mut StringBuf) -> crate::Result<FmtExtraInfo> {
        #[cfg(feature = "serde_json")]
        {
            // using `serde_json`
        }
        #[cfg(feature = "rkyv")]
        {
            // using `rkyv`
        }
    }
}

Also, we are not in a hurry to implement these other crate supports in this PR right now.

Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@SpriteOvO OK this makes sense. I thought you mean we completely abandon any dependencies on serialization libraries and let the users choose what suits them. So we're still depending on a bunch of pre-selected serialization libraries (even if they're just optional) and let the user choose one among them.


[dependencies]
arc-swap = "1.5.1"
Expand All @@ -50,6 +51,8 @@ if_chain = "1.0.2"
is-terminal = "0.4"
log = { version = "0.4.8", optional = true }
once_cell = "1.16.0"
serde = { version = "1.0.163", optional = true, features = ["derive"] }
serde_json = { version = "1.0.120", optional = true }
spdlog-internal = { version = "=0.1.0", path = "../spdlog-internal", optional = true }
spdlog-macros = { version = "0.1.0", path = "../spdlog-macros" }
spin = "0.9.8"
Expand Down
5 changes: 5 additions & 0 deletions spdlog/src/error.rs
Original file line number Diff line number Diff line change
Expand Up @@ -102,6 +102,11 @@ pub enum Error {
#[error("{0:?}")]
Multiple(Vec<Error>),

/// Returned by [`Formatter`]s when an error occurs in serializing a log.
#[cfg(feature = "serde")]
#[error("failed to serialize log: {0}")]
Serialization(io::Error),
SpriteOvO marked this conversation as resolved.
Show resolved Hide resolved

#[cfg(test)]
#[error("{0}")]
__ForInternalTestsUseOnly(i32),
Expand Down
184 changes: 184 additions & 0 deletions spdlog/src/formatter/json_formatter.rs
Original file line number Diff line number Diff line change
@@ -0,0 +1,184 @@
use std::fmt::{self, Write};

use cfg_if::cfg_if;
use serde::{ser::SerializeStruct, Serialize};

use crate::{
formatter::{FmtExtraInfo, Formatter, LOCAL_TIME_CACHER},
Error, Record, StringBuf, __EOL,
};

struct JsonRecord<'a>(&'a Record<'a>);

impl<'a> Serialize for JsonRecord<'a> {
fn serialize<S>(&self, serializer: S) -> Result<S::Ok, S::Error>
where
S: serde::Serializer,
{
let src_loc = self.0.source_location();

let mut record =
serializer.serialize_struct("JsonRecord", if src_loc.is_none() { 4 } else { 5 })?;

record.serialize_field("level", &self.0.level())?;
{
let mut local_time_cacher = LOCAL_TIME_CACHER.lock();
record.serialize_field::<str>(
"time",
local_time_cacher
.get(self.0.time())
.full_second_str()
.as_ref(),
)?;
Copy link
Owner

@SpriteOvO SpriteOvO Jul 22, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think for the machine format JSON, a timestamp number is more friendly. How about we rename the field to timestamp and then get the unix timestamp from the cacher?

UPDATE: Seems that the cacher is not needed, just get the timestamp from field time in Record should be fine.

}
record.serialize_field("tid", &self.0.tid())?;
record.serialize_field("payload", self.0.payload())?;

if let Some(src_loc) = src_loc {
record.serialize_field("source_location", src_loc)?;
SpriteOvO marked this conversation as resolved.
Show resolved Hide resolved
}

record.end()
}
}

impl<'a> From<&'a Record<'a>> for JsonRecord<'a> {
fn from(value: &'a Record<'a>) -> Self {
JsonRecord(value)
}
}

enum JsonFormatterError {
Fmt(fmt::Error),
Serialization(serde_json::Error),
}

impl From<fmt::Error> for JsonFormatterError {
fn from(value: fmt::Error) -> Self {
JsonFormatterError::Fmt(value)
}
}

impl From<serde_json::Error> for JsonFormatterError {
fn from(value: serde_json::Error) -> Self {
JsonFormatterError::Serialization(value)
}
}

impl From<JsonFormatterError> for crate::Error {
fn from(value: JsonFormatterError) -> Self {
match value {
JsonFormatterError::Fmt(e) => Error::FormatRecord(e),
JsonFormatterError::Serialization(e) => Error::Serialization(e.into()),
}
}
}

/// JSON logs formatter
Copy link
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
/// JSON logs formatter
#[rustfmt::skip]
/// JSON logs formatter

The doc formatting seems to be broken by Rustfmt, try adding a #[rustfmt::skip] on it.

///
/// Output format:
///
/// ```json
/// {"level":"info","time":"2024-01-01
/// 12:00:00","tid":123456,"payload":"test"}
///
/// // with source location
/// {"level":"info","time":"2024-01-01
/// 12:00:00","tid":123456,"payload":"test","source_location":{"module_path":"
/// module","file":"file.rs","line":42}}
/// ```
#[derive(Clone)]
pub struct JsonFormatter;
SpriteOvO marked this conversation as resolved.
Show resolved Hide resolved

impl JsonFormatter {
/// Create a `JsonFormatter`
pub fn new() -> JsonFormatter {
SpriteOvO marked this conversation as resolved.
Show resolved Hide resolved
JsonFormatter
}

fn format_impl(
&self,
record: &Record,
dest: &mut StringBuf,
) -> Result<FmtExtraInfo, JsonFormatterError> {
cfg_if! {
if #[cfg(not(feature = "flexible-string"))] {
dest.reserve(RESERVE_SIZE);
}
}

let json_record: JsonRecord = record.into();

dest.write_str(&serde_json::to_string(&json_record)?)?;
Copy link
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Leaving this comment as a note.

test bench_1_full_formatter       ... bench:          90.39 ns/iter (+/- 9.58)
test bench_1_json_formatter       ... bench:         121.27 ns/iter (+/- 9.10)

I benchmarked JsonFormatter and I was expecting it to be faster than that (close to FullFormatter). After a quick check, the String returned by serde::to_string will do unnecessary allocation and should be optimized out.

Unfortunately, due to the serde_json API limitation (serde-rs/json#863), this is currently not possible (at least not without using unsafe).


dest.write_str(__EOL)?;

Ok(FmtExtraInfo { style_range: None })
}
}

impl Formatter for JsonFormatter {
fn format(&self, record: &Record, dest: &mut StringBuf) -> crate::Result<FmtExtraInfo> {
self.format_impl(record, dest).map_err(Into::into)
}
}

impl Default for JsonFormatter {
fn default() -> Self {
JsonFormatter::new()
}
}

#[cfg(test)]
mod tests {
use chrono::prelude::*;

use super::*;
use crate::{Level, SourceLocation, __EOL};

#[test]
fn should_format_json() {
let mut dest = StringBuf::new();
let formatter = JsonFormatter::new();
let record = Record::builder(Level::Info, "payload").build();
let extra_info = formatter.format(&record, &mut dest).unwrap();

let local_time: DateTime<Local> = record.time().into();

assert_eq!(extra_info.style_range, None);
assert_eq!(
dest.to_string(),
format!(
r#"{{"level":"Info","time":"{}","tid":{},"payload":"{}"}}{}"#,
local_time.format("%Y-%m-%d %H:%M:%S"),
record.tid(),
"payload",
__EOL
)
);
}

#[test]
fn should_format_json_with_src_loc() {
let mut dest = StringBuf::new();
let formatter = JsonFormatter::new();
let record = Record::builder(Level::Info, "payload")
.source_location(Some(SourceLocation::__new("module", "file.rs", 1, 2)))
.build();
let extra_info = formatter.format(&record, &mut dest).unwrap();

let local_time: DateTime<Local> = record.time().into();

assert_eq!(extra_info.style_range, None);
assert_eq!(
dest.to_string(),
format!(
r#"{{"level":"Info","time":"{}","tid":{},"payload":"{}","source_location":{{"module_path":"module","file":"file.rs","line":1,"column":2}}}}{}"#,
local_time.format("%Y-%m-%d %H:%M:%S"),
record.tid(),
"payload",
__EOL
)
);
}
}
4 changes: 4 additions & 0 deletions spdlog/src/formatter/mod.rs
Original file line number Diff line number Diff line change
Expand Up @@ -54,6 +54,8 @@ mod full_formatter;
all(doc, not(doctest))
))]
mod journald_formatter;
#[cfg(feature = "json-formatter")]
mod json_formatter;
mod local_time_cacher;
mod pattern_formatter;

Expand All @@ -66,6 +68,8 @@ pub use full_formatter::*;
all(doc, not(doctest))
))]
pub(crate) use journald_formatter::*;
#[cfg(feature = "json-formatter")]
pub use json_formatter::*;
pub(crate) use local_time_cacher::*;
pub use pattern_formatter::*;

Expand Down
1 change: 1 addition & 0 deletions spdlog/src/level.rs
Original file line number Diff line number Diff line change
Expand Up @@ -52,6 +52,7 @@ const LOG_LEVEL_SHORT_NAMES: [&str; Level::count()] = ["C", "E", "W", "I", "D",
/// [`log!`]: crate::log!
#[repr(u16)]
#[derive(Copy, Clone, Eq, PartialEq, Hash, Debug)]
#[cfg_attr(feature = "serde", derive(serde::Serialize))]
pub enum Level {
/// Designates critical errors.
Critical = 0,
Expand Down
2 changes: 2 additions & 0 deletions spdlog/src/record.rs
Original file line number Diff line number Diff line change
Expand Up @@ -21,13 +21,15 @@ use crate::{Level, SourceLocation};
// FIXME: `Record` still owns some data and not just a reference, I'm not sure this is necessary and
// possible to correct.
#[derive(Clone, Debug)]
#[cfg_attr(feature = "serde", derive(serde::Serialize))]
pub struct Record<'a> {
logger_name: Option<Cow<'a, str>>,
payload: Cow<'a, str>,
inner: Cow<'a, RecordInner>,
}

#[derive(Clone, Debug)]
#[cfg_attr(feature = "serde", derive(serde::Serialize))]
struct RecordInner {
level: Level,
source_location: Option<SourceLocation>,
Expand Down
1 change: 1 addition & 0 deletions spdlog/src/source_location.rs
Original file line number Diff line number Diff line change
Expand Up @@ -7,6 +7,7 @@ use std::path;
///
/// [`source_location_current`]: crate::source_location_current
#[derive(Clone, Hash, Debug)]
#[cfg_attr(feature = "serde", derive(serde::Serialize))]
pub struct SourceLocation {
module_path: &'static str,
file: &'static str,
Expand Down
Loading