tracing-subscriber: Consider adding flattening option for spans

[dahlbaek]

Feature Request

Crates

tracing-subscriber

Motivation

Many GCP services come with an out-of-process agent that will ingest logs written in a specific json format described here https://cloud.google.com/logging/docs/structured-logging. An example would be

{"time":"2023-08-03T08:13:03.159Z","severity":"INFO","logging.googleapis.com/trace":"trace-id","message":"My log message."}

Here, the trace id is scoped to a request and should be included in all messages logged in relation to a given request. It therefore makes sense to put it in a span rather than adding it to all events. However, in the out-of-the-box json format produced by tracing-subscriber, such fields are nested inside span or spans fields. Example:

{"timestamp":"2023-08-03T08:19:14.224093Z","level":"INFO","fields":{"message":"My log message."},"target":"root","span":{"logging.googleapis.com/trace":"trace-id","name":"root"},"spans":[{"logging.googleapis.com/trace":"trace-id","name":"root"}]}

tracing-subscriber already supports flattening the fields, but I was not able to find an equivalent feature for span or spans.

Proposal

Add flatten_span and flatten_spans configuration knobs to SubscriberBuilder to allow flattening span items directly into the top level. In combination with valuable support, this seems like a very flexible configuration allowing one to write logs in a very custom format. Possibly it should be possible to retain the span and spans fields while also flattening into the top level, since some keys may be overwritten during flattening (I suppose that is also the case for flatten_event).

Alternatives

Currently I implement a custom FormatEvent

struct CloudRunEventFormat;

impl CloudRunEventFormat {
    fn new() -> CloudRunEventFormat {
        CloudRunEventFormat
    }
}

impl<S, N> FormatEvent<S, N> for CloudRunEventFormat
where
    S: Subscriber + for<'lookup> LookupSpan<'lookup>,
    N: for<'writer> FormatFields<'writer> + 'static,
{
    fn format_event(
        &self,
        ctx: &FmtContext<'_, S, N>,
        mut writer: Writer<'_>,
        event: &Event<'_>,
    ) -> std::fmt::Result
    where
        S: Subscriber + for<'a> LookupSpan<'a>,
    {
        let meta = event.metadata();

        let mut s = Vec::<u8>::new();
        let mut serializer = serde_json::Serializer::new(&mut s);
        let mut serializer_map = serializer.serialize_map(None).unwrap();

        let timestamp = chrono::Utc::now().to_rfc3339_opts(chrono::SecondsFormat::Millis, true);
        serializer_map.serialize_entry("time", &timestamp).unwrap();
        serializer_map
            .serialize_entry("severity", &meta.level().as_serde())
            .unwrap();

        if let Some(leaf_span) = ctx.lookup_current() {
            for span in leaf_span.scope().from_root() {
                let ext = span.extensions();
                let data = ext
                    .get::<FormattedFields<N>>()
                    .expect("Unable to find FormattedFields in extensions; this is a bug");

                let serde_json::Value::Object(fields) =
                    serde_json::from_str::<serde_json::Value>(data).unwrap() else {panic!()};
                for field in fields {
                    serializer_map.serialize_entry(&field.0, &field.1).unwrap();
                }
            }
        }

        let mut visitor = tracing_serde::SerdeMapVisitor::new(serializer_map);
        event.record(&mut visitor);

        visitor.take_serializer().unwrap().end().unwrap();

        writer.write_str(std::str::from_utf8(&s).unwrap()).unwrap();
        writeln!(writer)
    }
}

This custom implementation also renames some fields (level -> severity and timestamp -> time), for which I created a separate feature request: #2671. This direction seems to imply that one would commonly need to implement a custom FormatEvent in order to interact with log ingestion agents, in which case implementing such a custom FormatEvent could probably be made more ergonomic.

[dahlbaek]

Looks very related to https://users.rust-lang.org/t/global-fields-to-always-log-on-any-event-in-tracing-subscriber/81649

[dahlbaek]

Looks also related to #1531