JSON formatter

[pimeys]

Motivation

A formatter for JSON output.

Solution

Enable json feature from tracing-subscriber crate. Instantiate a new formatter with JSON output:

let subscriber = FmtSubscriber::builder()
    .json()
    .with_env_filter(EnvFilter::from_default_env())
    .finish();

subscriber::set_global_default(subscriber)?;

[pimeys]

Oh and I just started today with the tracing codebase, so I might not know every detail how this code should be formed. :)

[davidbarsky]

Eugh, sorry about the duplicate comments. Computers!

[pimeys]

Understood how the Serialize structs work now. Planning to add one for times so we can skip the trimming part in the JSON output. Tomorrow!

[hawkw]

Thanks for making the changes I requested! I left some notes on the structure of the serialized output.

[hawkw]

this will only serialize the name of the immediate parent span. it seems like it might be good to serialize the span's fields as well — note that if we don't also serialize fields, the JSON formatter will output strictly less information than the text formatter, which does include the parent span's fields.

[pimeys]

The current Span implementation in tracing-subscriber formats fields in a format suitable for plain test logs, but looks kind of bad in JSON. See the test example here:

pimeys@b143824#diff-12298a6463a49769f9b40d8e8b01e754R817

I couldn't really track where and why do we stringify the fields in this way. Would be nicer to have a struct that implements Display and AsSerde to the both formats.

[hawkw]

The fields are formatted by a type implementing the FormatFields trait:

tracing/tracing-subscriber/src/fmt/format.rs

Lines 49 to 64 in 06daa95

	/// A type that can format a [set of fields] to a `fmt::Write`.
	///
	/// `FormatFields` is primarily used in the context of [`FmtSubscriber`]. Each
	/// time a span or event with fields is recorded, the subscriber will format
	/// those fields with its associated `FormatFields` implementation.
	///
	/// [set of fields]: ../field/trait.RecordFields.html
	/// [`FmtSubscriber`]: ../fmt/struct.Subscriber.html
	pub trait FormatFields<'writer> {
	/// Format the provided `fields` to the provided `writer`, returning a result.
	fn format_fields<R: RecordFields>(
	&self,
	writer: &'writer mut dyn fmt::Write,
	fields: R,
	) -> fmt::Result;
	}

The FormatFields implementation used can be set by the Builder here:

tracing/tracing-subscriber/src/fmt/mod.rs

Lines 402 to 433 in 06daa95

	/// Sets the Visitor that the subscriber being built will use to record
	/// fields.
	///
	/// For example:
	/// ```rust
	/// use tracing_subscriber::fmt::{Subscriber, format};
	/// use tracing_subscriber::prelude::*;
	///
	/// let formatter =
	/// // Construct a custom formatter for `Debug` fields
	/// format::debug_fn(|writer, field, value| write!(writer, "{}: {:?}", field, value))
	/// // Use the `tracing_subscriber::MakeFmtExt` trait to wrap the
	/// // formatter so that a delimiter is added between fields.
	/// .delimited(", ");
	///
	/// let subscriber = Subscriber::builder()
	/// .fmt_fields(formatter)
	/// .finish();
	/// # drop(subscriber)
	/// ```
	pub fn fmt_fields<N2>(self, fmt_fields: N2) -> Builder<N2, E, F, W>
	where
	N2: for<'writer> FormatFields<'writer> + 'static,
	{
	Builder {
	fmt_fields: fmt_fields.into(),
	fmt_event: self.fmt_event,
	filter: self.filter,
	settings: self.settings,
	make_writer: self.make_writer,
	}
	}

FormatFields is also implemented for any MakeVisitor implementation:

tracing/tracing-subscriber/src/fmt/format.rs

Lines 285 to 299 in 06daa95

	impl<'writer, M> FormatFields<'writer> for M
	where
	M: MakeOutput<&'writer mut dyn fmt::Write, fmt::Result>,
	M::Visitor: VisitFmt + VisitOutput<fmt::Result>,
	{
	fn format_fields<R: RecordFields>(
	&self,
	writer: &'writer mut dyn fmt::Write,
	fields: R,
	) -> fmt::Result {
	let mut v = self.make_visitor(writer);
	fields.record(&mut v);
	v.finish()
	}
	}

So, we could override the default field formatter to record the fields using a Serde visitor. Although the formatted representation would be stored as a string, we could then interpolate that string into the output, and the fields would be formatted as JSON.

[pimeys]

<3

[pimeys]

This is done now but rendering the fields in an escaped form due to serde not really helping us here. We decided in Discord to leave it how it is for now and come back later to fix the architecture to make field formatting better for different formats.

pimeys@53e3394

[hawkw]

We'll need to publish a tracing-serde release to crates.io before we can publish the changes in this branch — we can't publish a crate that depends on an unpublished crate.

[pimeys]

True. Do you have a plan when we want this to happen?

[hawkw]

When these changes land, I can take care of that.

[hawkw]

This looks really close. Beyond moving the WriteAdaptor type out of tracing-serde, I'd be happy to merge this as-is; most of my comments are for follow-up work.

When this merges, it would be good to open new issues to track those follow-ups.

[hawkw]

This serializes only the current span in which the event occurred, rather than the span and all its parents (the way the Format<Full, ...> formatter does. We might want to have separate "full" and "compact" JSON formatters as well (though I'm fine with adding that in a follow-up).

[hawkw]

I would still really like it if all of this was factored out of main into a separate function, but it's not a blocker. It would be fine if that function called set_global_default so that we don't have to handle return type issues...

[hawkw]

This looks good to me! Thanks @pimeys for all your hard work — I know this took a while to get through.

We can ignore the nightly CI failure for now; it's due to a nightly change that broke our CI scripts and is unrelated. I'm going to go ahead and merge this when the other builds are done, and open tickets for some of the follow-up work we discussed.

[davidbarsky]

@hawkw's review is a more fine-grained superset of mine; I'm happy merging as is!