Skip to content

Commit

Permalink
Implement JsonFormatter (#69)
Browse files Browse the repository at this point in the history
  • Loading branch information
NotEvenANeko authored Aug 5, 2024
1 parent 084b75d commit 4bc900b
Show file tree
Hide file tree
Showing 8 changed files with 306 additions and 2 deletions.
4 changes: 2 additions & 2 deletions .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 serde_json']
cfg_feature: ['', 'flexible-string', 'source-location']
runs-on: ${{ matrix.os }}
steps:
Expand Down Expand Up @@ -212,7 +212,7 @@ jobs:
- name: Restore cargo caches
uses: Swatinem/rust-cache@v2
- name: Run benchmark
run: cargo +nightly bench --features "multi-thread,runtime-pattern" --bench spdlog_rs --bench spdlog_rs_pattern | tee bench-results.txt
run: cargo +nightly bench --features "multi-thread,runtime-pattern,serde_json" --bench spdlog_rs --bench spdlog_rs_pattern | tee bench-results.txt
- name: Discard irrelevant changes
run: git checkout -- spdlog/Cargo.toml
- name: Process results
Expand Down
4 changes: 4 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"]
serde_json = ["serde", "dep:serde_json"]

[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 Expand Up @@ -106,6 +109,7 @@ harness = false
[[bench]]
name = "spdlog_rs_pattern"
path = "benches/spdlog-rs/pattern.rs"
required-features = ["runtime-pattern", "serde_json"]
[[bench]]
name = "fast_log"
path = "benches/fast_log/main.rs"
Expand Down
8 changes: 8 additions & 0 deletions spdlog/benches/spdlog-rs/pattern.rs
Original file line number Diff line number Diff line change
Expand Up @@ -5,6 +5,8 @@ extern crate test;
use std::{cell::RefCell, sync::Arc};

use paste::paste;
#[cfg(feature = "serde_json")]
use spdlog::formatter::JsonFormatter;
use spdlog::{
formatter::{pattern, Formatter, FullFormatter, Pattern, PatternFormatter},
prelude::*,
Expand Down Expand Up @@ -104,6 +106,12 @@ fn bench_1_full_formatter(bencher: &mut Bencher) {
bench_formatter(bencher, FullFormatter::new())
}

#[cfg(feature = "serde_json")]
#[bench]
fn bench_1_json_formatter(bencher: &mut Bencher) {
bench_formatter(bencher, JsonFormatter::new())
}

#[bench]
fn bench_2_full_pattern_ct(bencher: &mut Bencher) {
bench_full_pattern(
Expand Down
7 changes: 7 additions & 0 deletions spdlog/src/error.rs
Original file line number Diff line number Diff line change
Expand Up @@ -98,6 +98,13 @@ pub enum Error {
#[error("failed to build pattern at runtime: {0}")]
BuildPattern(BuildPatternError),

/// Returned by [`Formatter`]s when an error occurs in serializing a log.
///
/// [`Formatter`]: crate::formatter::Formatter
#[cfg(feature = "serde")]
#[error("failed to serialize log: {0}")]
SerializeRecord(io::Error),

/// Returned when multiple errors occurred.
#[error("{0:?}")]
Multiple(Vec<Error>),
Expand Down
258 changes: 258 additions & 0 deletions spdlog/src/formatter/json_formatter.rs
Original file line number Diff line number Diff line change
@@ -0,0 +1,258 @@
use std::{
fmt::{self, Write},
marker::PhantomData,
time::SystemTime,
};

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

use crate::{
formatter::{FmtExtraInfo, Formatter},
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())?;
record.serialize_field(
"timestamp",
&self
.0
.time()
.duration_since(SystemTime::UNIX_EPOCH)
.ok()
// https://github.com/SpriteOvO/spdlog-rs/pull/69#discussion_r1694063293
.and_then(|dur| u64::try_from(dur.as_millis()).ok())
.expect("invalid timestamp"),
)?;
record.serialize_field("payload", self.0.payload())?;
if let Some(logger_name) = self.0.logger_name() {
record.serialize_field("logger", logger_name)?;
}
record.serialize_field("tid", &self.0.tid())?;
if let Some(src_loc) = src_loc {
record.serialize_field("source", src_loc)?;
}

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::SerializeRecord(e.into()),
}
}
}

#[rustfmt::skip]
/// JSON logs formatter.
///
/// Each log will be serialized into a single line of JSON object with the following schema.
///
/// ## Schema
///
/// | Field | Type | Description |
/// |-------------|--------------|--------------------------------------------------------------------------------------------------------------------------------|
/// | `level` | String | The level of the log. Same as the return of [`Level::as_str`]. |
/// | `timestamp` | Integer(u64) | The timestamp when the log was generated, in milliseconds since January 1, 1970 00:00:00 UTC. |
/// | `payload` | String | The contents of the log. |
/// | `logger` | String/Null | The name of the logger. Null if the logger has no name. |
/// | `tid` | Integer(u64) | The thread ID when the log was generated. |
/// | `source` | Object/Null | The source location of the log. See [`SourceLocation`] for its schema. Null if crate feature `source-location` is not enabled. |
///
/// <div class="warning">
///
/// - If the type of a field is Null, the field will not be present or be `null`.
///
/// - The order of the fields is not guaranteed.
///
/// </div>
///
/// ---
///
/// ## Examples
///
/// - Default:
///
/// ```json
/// {"level":"Info","timestamp":1722817424798,"payload":"hello, world!","tid":3472525}
/// {"level":"Error","timestamp":1722817424798,"payload":"something went wrong","tid":3472525}
/// ```
///
/// - If the logger has a name:
///
/// ```json
/// {"level":"Info","timestamp":1722817541459,"payload":"hello, world!","logger":"app-component","tid":3478045}
/// {"level":"Error","timestamp":1722817541459,"payload":"something went wrong","logger":"app-component","tid":3478045}
/// ```
///
/// - If crate feature `source-location` is enabled:
///
/// ```json
/// {"level":"Info","timestamp":1722817572709,"payload":"hello, world!","tid":3479856,"source":{"module_path":"my_app::say_hi","file":"src/say_hi.rs","line":4,"column":5}}
/// {"level":"Error","timestamp":1722817572709,"payload":"something went wrong","tid":3479856,"source":{"module_path":"my_app::say_hi","file":"src/say_hi.rs","line":5,"column":5}}
/// ```
///
/// [`Level::as_str`]: crate::Level::as_str
/// [`SourceLocation`]: crate::SourceLocation
#[derive(Clone)]
pub struct JsonFormatter(PhantomData<()>);

impl JsonFormatter {
/// Constructs a `JsonFormatter`.
#[must_use]
pub fn new() -> JsonFormatter {
JsonFormatter(PhantomData)
}

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

let json_record: JsonRecord = record.into();

// TODO: https://github.com/serde-rs/json/issues/863
//
// The performance can be significantly optimized here if the issue can be
// solved.
dest.write_str(&serde_json::to_string(&json_record)?)?;

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","timestamp":{},"payload":"{}","tid":{}}}{}"#,
local_time.timestamp_millis(),
"payload",
record.tid(),
__EOL
)
);
}

#[test]
fn should_format_json_with_logger_name() {
let mut dest = StringBuf::new();
let formatter = JsonFormatter::new();
let record = Record::builder(Level::Info, "payload")
.logger_name("my-component")
.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","timestamp":{},"payload":"{}","logger":"my-component","tid":{}}}{}"#,
local_time.timestamp_millis(),
"payload",
record.tid(),
__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","timestamp":{},"payload":"{}","tid":{},"source":{{"module_path":"module","file":"file.rs","line":1,"column":2}}}}{}"#,
local_time.timestamp_millis(),
"payload",
record.tid(),
__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 = "serde_json")]
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 = "serde_json")]
pub use json_formatter::*;
pub(crate) use local_time_cacher::*;
pub use pattern_formatter::*;

Expand Down
10 changes: 10 additions & 0 deletions spdlog/src/level.rs
Original file line number Diff line number Diff line change
Expand Up @@ -67,6 +67,16 @@ pub enum Level {
Trace,
}

#[cfg(feature = "serde")]
impl serde::Serialize for Level {
fn serialize<S>(&self, serializer: S) -> Result<S::Ok, S::Error>
where
S: serde::Serializer,
{
serializer.serialize_str(self.as_str())
}
}

cfg_if! {
if #[cfg(test)] {
crate::utils::const_assert!(atomic::Atomic::<Level>::is_lock_free());
Expand Down
13 changes: 13 additions & 0 deletions spdlog/src/source_location.rs
Original file line number Diff line number Diff line change
Expand Up @@ -5,8 +5,21 @@ use std::path;
/// Usually users don't need to construct it manually, but if you do, use macro
/// [`source_location_current`].
///
/// ## Schema
///
/// This struct is implemented [`serde::Serialize`] if crate feature `serde` is
/// enabled.
///
/// | Field | Type |
/// |---------------|--------|
/// | `module_path` | String |
/// | `file` | String |
/// | `line` | u32 |
/// | `column` | u32 |
///
/// [`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

0 comments on commit 4bc900b

Please sign in to comment.