Custom JSON Format for Rust tracing

Cargo.toml

tracing-log = "0.1"
tracing-subscriber = { version = "0.3", features = ["env-filter", "json"] }
tracing-serde = "0.1"
chrono = { version = "0.4", default-features = false, features = ["clock"] }

custom_json_format.rs

use chrono::Utc;
use serde::{ser::SerializeMap, Serializer};
use std::{fmt, io};
use tracing::{log, Event, Level, Subscriber};
use tracing_log::AsLog;
use tracing_subscriber::{fmt::FormattedFields, registry::LookupSpan};
use tracing_subscriber::{
    fmt::{
        format::{self, FormatEvent, FormatFields},
        FmtContext,
    },
    registry,
};

pub struct CustomJsonFormat;

// non pub struct copied from tracing-subsriber
// needed to bridge from fmt:Writer to serde_json
pub struct WriteAdaptor<'a> {
    fmt_write: &'a mut dyn fmt::Write,
}

impl<'a> WriteAdaptor<'a> {
    pub fn new(fmt_write: &'a mut dyn fmt::Write) -> Self {
        Self { fmt_write }
    }
}

impl<'a> io::Write for WriteAdaptor<'a> {
    fn write(&mut self, buf: &[u8]) -> io::Result<usize> {
        let s =
            std::str::from_utf8(buf).map_err(|e| io::Error::new(io::ErrorKind::InvalidData, e))?;

        self.fmt_write
            .write_str(s)
            .map_err(|e| io::Error::new(io::ErrorKind::Other, e))?;

        Ok(s.as_bytes().len())
    }

    fn flush(&mut self) -> io::Result<()> {
        Ok(())
    }
}

impl<'a> fmt::Debug for WriteAdaptor<'a> {
    fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
        f.pad("WriteAdaptor { .. }")
    }
}

// non pub struct copied from tracing-subsriber json
// needed to look into the span data fields
struct SerializableSpan<'a, 'b, Span, N>(
    &'b registry::SpanRef<'a, Span>,
    std::marker::PhantomData<N>,
)
where
    Span: for<'lookup> registry::LookupSpan<'lookup>,
    N: for<'writer> FormatFields<'writer> + 'static;

/// Convert log level to [syslog severity level](https://en.wikipedia.org/wiki/Syslog#Severity_level)
fn to_severity_level(level: &Level) -> &str {
    match level.as_log() {
        log::Level::Error => "err",
        log::Level::Warn => "warning",
        log::Level::Info => "info",
        log::Level::Debug | log::Level::Trace => "debug",
    }
}

/*  adapted from impl<S, N, T> FormatEvent<S, N> for Format<Json, T> in json.rs

    let subscriber = tracing_subscriber::fmt()
        .with_span_events(FmtSpan::CLOSE)
        .with_env_filter(EnvFilter::try_from_default_env().expect("unable to create log filter"))
        .json()
        .event_format(CustomJsonFormat);

    tracing::subscriber::set_global_default(subscriber.finish()).expect("should work");

    let span = span!(Level::INFO, "my_span", "user_id" = "foo");
    let _guard = span.enter();
    tracing::info!("span_test");
    tracing::event!(Level::INFO, message = "event_test", user_id = "foo");
    ...

    {"timestamp":1677499869,"severity":"info","message":"span_test","threadName":"main","user_id":"foo","threadId":"ThreadId(1)"}
    {"timestamp":1677499869,"severity":"info","message":"event_test","user_id":"foo","threadName":"main","user_id":"foo","threadId":"ThreadId(1)"}
*/
impl<S, N> FormatEvent<S, N> for CustomJsonFormat
where
    S: Subscriber + for<'a> LookupSpan<'a>,
    N: for<'a> FormatFields<'a> + 'static,
{
    fn format_event(
        &self,
        ctx: &FmtContext<'_, S, N>,
        mut writer: format::Writer<'_>,
        event: &Event<'_>,
    ) -> fmt::Result {
        let timestamp = Utc::now().timestamp();
        let meta = event.metadata();

        let mut visit = || {
            let mut serializer = serde_json::Serializer::new(WriteAdaptor::new(&mut writer));
            let mut serializer = serializer.serialize_map(None)?;

            serializer.serialize_entry("timestamp", &timestamp)?;
            serializer.serialize_entry("severity", to_severity_level(&meta.level()))?;

            // flatten fields into log record
            // includes the "message" field
            let mut visitor = tracing_serde::SerdeMapVisitor::new(serializer);
            event.record(&mut visitor);
            serializer = visitor.take_serializer()?;

            let current_thread = std::thread::current();
            match current_thread.name() {
                Some(name) => {
                    serializer.serialize_entry("threadName", name)?;
                }
                _ => {}
            }

            let current_span = event
                .parent()
                .and_then(|id| ctx.span(id))
                .or_else(|| ctx.lookup_current());

            if let Some(ref span) = current_span {
                let format_field_marker: std::marker::PhantomData<N> = std::marker::PhantomData;
                let serializable_span = &SerializableSpan(span, format_field_marker);

                let ext = serializable_span.0.extensions();
                let data = ext
                    .get::<FormattedFields<N>>()
                    .expect("illegal state: unable to find FormattedFields in extensions");

                match serde_json::from_str::<serde_json::Value>(data) {
                    Ok(serde_json::Value::Object(fields)) => {
                        for field in fields {
                            serializer.serialize_entry(&field.0, &field.1)?;
                        }
                    }
                    _ => serializer.serialize_entry(
                        "field_error",
                        &format!("not a valid span data value: {}", data),
                    )?,
                }
            }

            serializer
                .serialize_entry("threadId", &format!("{:?}", std::thread::current().id()))?;

            serializer.end()
        };

        visit().map_err(|_| fmt::Error)?;
        writeln!(writer)
    }
}