use std::{error::Error, io};
use tracing::{Dispatch, Subscriber};
use tracing_core::LevelFilter;
use tracing_subscriber::{
fmt::{
time::{FormatTime, SystemTime},
MakeWriter,
TestWriter,
},
layer::{Layered, SubscriberExt},
registry::LookupSpan,
reload,
Layer,
Registry,
};
use super::names::{
CURRENT_SPAN,
FIELDS,
FILENAME,
LEVEL,
LINE_NUMBER,
SPAN_LIST,
TARGET,
THREAD_ID,
THREAD_NAME,
TIMESTAMP,
};
use crate::layer::JsonLayer;
pub struct SubscriberBuilder<W = fn() -> io::Stdout, T = SystemTime, F = LevelFilter> {
make_writer: W,
timer: T,
filter: F,
log_internal_errors: bool,
display_timestamp: bool,
display_target: bool,
display_level: bool,
display_thread_id: bool,
display_thread_name: bool,
display_filename: bool,
display_line_number: bool,
flatten_event: bool,
display_current_span: bool,
display_span_list: bool,
#[cfg(feature = "opentelemetry")]
display_opentelemetry_ids: bool,
}
impl Default for SubscriberBuilder {
fn default() -> Self {
Self {
make_writer: io::stdout,
filter: LevelFilter::INFO,
timer: SystemTime,
log_internal_errors: false,
display_timestamp: true,
display_target: true,
display_level: true,
display_thread_id: false,
display_thread_name: false,
display_filename: false,
display_line_number: false,
flatten_event: false,
display_current_span: true,
display_span_list: true,
#[cfg(feature = "opentelemetry")]
display_opentelemetry_ids: false,
}
}
}
impl<W, T, F> SubscriberBuilder<W, T, F>
where
W: for<'writer> MakeWriter<'writer> + Send + Sync + 'static,
T: FormatTime + Send + Sync + 'static,
F: Layer<Layered<JsonLayer<Registry, W>, Registry>> + 'static,
Layered<F, Layered<JsonLayer<Registry, W>, Registry>>:
tracing_core::Subscriber + Into<Dispatch>,
{
pub(crate) fn layers<S>(self) -> (JsonLayer<S, W>, F)
where
S: Subscriber + for<'lookup> LookupSpan<'lookup>,
{
let mut layer = JsonLayer::<S>::new(self.make_writer);
if self.display_timestamp {
layer.with_timer(TIMESTAMP, self.timer);
}
if self.display_level {
layer.with_level(LEVEL);
}
if self.display_target {
layer.with_target(TARGET);
}
if self.display_filename {
layer.with_file(FILENAME);
}
if self.display_line_number {
layer.with_line_number(LINE_NUMBER);
}
if self.display_thread_name {
layer.with_thread_names(THREAD_NAME);
}
if self.display_thread_id {
layer.with_thread_ids(THREAD_ID);
}
if self.flatten_event {
layer.with_flattened_event();
} else {
layer.with_event(FIELDS);
}
if self.display_current_span {
layer.with_current_span(CURRENT_SPAN);
}
if self.display_span_list {
layer.with_span_list(SPAN_LIST);
}
(layer, self.filter)
}
pub fn finish(self) -> Layered<F, Layered<JsonLayer<Registry, W>, Registry>> {
let (json_layer, filter_layer) = self.layers();
tracing_subscriber::registry()
.with(json_layer)
.with(filter_layer)
}
pub fn try_init(self) -> Result<(), Box<dyn Error + Send + Sync + 'static>> {
use tracing_subscriber::util::SubscriberInitExt;
self.finish().try_init()?;
Ok(())
}
pub fn init(self) {
self.try_init()
.expect("Unable to install global subscriber");
}
}
impl<W, T, F> SubscriberBuilder<W, T, F> {
#[deprecated(note = "Calling `json()` does nothing.")]
#[must_use]
pub fn json(self) -> Self {
self
}
#[deprecated(note = "Calling `with_ansi()` does nothing.")]
#[must_use]
pub fn with_ansi(self, _ansi: bool) -> Self {
self
}
pub fn with_writer<W2>(self, make_writer: W2) -> SubscriberBuilder<W2, T, F>
where
W2: for<'writer> MakeWriter<'writer> + 'static,
{
SubscriberBuilder {
make_writer,
timer: self.timer,
filter: self.filter,
log_internal_errors: self.log_internal_errors,
display_timestamp: self.display_timestamp,
display_target: self.display_target,
display_level: self.display_level,
display_thread_id: self.display_thread_id,
display_thread_name: self.display_thread_name,
display_filename: self.display_filename,
display_line_number: self.display_line_number,
flatten_event: self.flatten_event,
display_current_span: self.display_current_span,
display_span_list: self.display_span_list,
#[cfg(feature = "opentelemetry")]
display_opentelemetry_ids: self.display_opentelemetry_ids,
}
}
pub fn writer(&self) -> &W {
&self.make_writer
}
pub fn writer_mut(&mut self) -> &mut W {
&mut self.make_writer
}
pub fn with_test_writer(self) -> SubscriberBuilder<TestWriter, T, F> {
SubscriberBuilder {
make_writer: TestWriter::default(),
timer: self.timer,
filter: self.filter,
log_internal_errors: self.log_internal_errors,
display_timestamp: self.display_timestamp,
display_target: self.display_target,
display_level: self.display_level,
display_thread_id: self.display_thread_id,
display_thread_name: self.display_thread_name,
display_filename: self.display_filename,
display_line_number: self.display_line_number,
flatten_event: self.flatten_event,
display_current_span: self.display_current_span,
display_span_list: self.display_span_list,
#[cfg(feature = "opentelemetry")]
display_opentelemetry_ids: self.display_opentelemetry_ids,
}
}
#[must_use]
pub fn log_internal_errors(self, log_internal_errors: bool) -> Self {
Self {
log_internal_errors,
..self
}
}
pub fn map_writer<W2>(self, f: impl FnOnce(W) -> W2) -> SubscriberBuilder<W2, T, F>
where
W2: for<'writer> MakeWriter<'writer> + 'static,
{
SubscriberBuilder {
make_writer: f(self.make_writer),
timer: self.timer,
filter: self.filter,
log_internal_errors: self.log_internal_errors,
display_timestamp: self.display_timestamp,
display_target: self.display_target,
display_level: self.display_level,
display_thread_id: self.display_thread_id,
display_thread_name: self.display_thread_name,
display_filename: self.display_filename,
display_line_number: self.display_line_number,
flatten_event: self.flatten_event,
display_current_span: self.display_current_span,
display_span_list: self.display_span_list,
#[cfg(feature = "opentelemetry")]
display_opentelemetry_ids: self.display_opentelemetry_ids,
}
}
#[must_use]
pub fn flatten_event(self, flatten_event: bool) -> SubscriberBuilder<W, T, F> {
SubscriberBuilder {
flatten_event,
..self
}
}
#[must_use]
pub fn with_current_span(self, display_current_span: bool) -> SubscriberBuilder<W, T, F> {
SubscriberBuilder {
display_current_span,
..self
}
}
#[must_use]
pub fn with_span_list(self, display_span_list: bool) -> SubscriberBuilder<W, T, F> {
SubscriberBuilder {
display_span_list,
..self
}
}
pub fn with_timer<T2>(self, timer: T2) -> SubscriberBuilder<W, T2, F> {
SubscriberBuilder {
make_writer: self.make_writer,
timer,
filter: self.filter,
log_internal_errors: self.log_internal_errors,
display_timestamp: self.display_timestamp,
display_target: self.display_target,
display_level: self.display_level,
display_thread_id: self.display_thread_id,
display_thread_name: self.display_thread_name,
display_filename: self.display_filename,
display_line_number: self.display_line_number,
flatten_event: self.flatten_event,
display_current_span: self.display_current_span,
display_span_list: self.display_span_list,
#[cfg(feature = "opentelemetry")]
display_opentelemetry_ids: self.display_opentelemetry_ids,
}
}
pub fn without_time(self) -> SubscriberBuilder<W, (), F> {
SubscriberBuilder {
make_writer: self.make_writer,
timer: (),
filter: self.filter,
log_internal_errors: self.log_internal_errors,
display_timestamp: self.display_timestamp,
display_target: self.display_target,
display_level: self.display_level,
display_thread_id: self.display_thread_id,
display_thread_name: self.display_thread_name,
display_filename: self.display_filename,
display_line_number: self.display_line_number,
flatten_event: self.flatten_event,
display_current_span: self.display_current_span,
display_span_list: self.display_span_list,
#[cfg(feature = "opentelemetry")]
display_opentelemetry_ids: self.display_opentelemetry_ids,
}
}
#[must_use]
pub fn with_target(self, display_target: bool) -> SubscriberBuilder<W, T, F> {
SubscriberBuilder {
display_target,
..self
}
}
#[must_use]
pub fn with_file(self, display_filename: bool) -> SubscriberBuilder<W, T, F> {
SubscriberBuilder {
display_filename,
..self
}
}
#[must_use]
pub fn with_line_number(self, display_line_number: bool) -> SubscriberBuilder<W, T, F> {
SubscriberBuilder {
display_line_number,
..self
}
}
#[must_use]
pub fn with_level(self, display_level: bool) -> SubscriberBuilder<W, T, F> {
SubscriberBuilder {
display_level,
..self
}
}
#[must_use]
pub fn with_thread_names(self, display_thread_name: bool) -> SubscriberBuilder<W, T, F> {
SubscriberBuilder {
display_thread_name,
..self
}
}
#[must_use]
pub fn with_thread_ids(self, display_thread_id: bool) -> SubscriberBuilder<W, T, F> {
SubscriberBuilder {
display_thread_id,
..self
}
}
#[cfg(feature = "opentelemetry")]
#[cfg_attr(docsrs, doc(cfg(feature = "opentelemetry")))]
#[must_use]
pub fn with_opentelemetry_ids(self, display_opentelemetry_ids: bool) -> Self {
SubscriberBuilder {
display_opentelemetry_ids,
..self
}
}
#[cfg(feature = "env-filter")]
#[cfg_attr(docsrs, doc(cfg(feature = "env-filter")))]
pub fn with_env_filter(
self,
filter: impl Into<tracing_subscriber::EnvFilter>,
) -> SubscriberBuilder<W, T, tracing_subscriber::EnvFilter> {
SubscriberBuilder {
make_writer: self.make_writer,
timer: self.timer,
filter: filter.into(),
log_internal_errors: self.log_internal_errors,
display_timestamp: self.display_timestamp,
display_target: self.display_target,
display_level: self.display_level,
display_thread_id: self.display_thread_id,
display_thread_name: self.display_thread_name,
display_filename: self.display_filename,
display_line_number: self.display_line_number,
flatten_event: self.flatten_event,
display_current_span: self.display_current_span,
display_span_list: self.display_span_list,
#[cfg(feature = "opentelemetry")]
display_opentelemetry_ids: self.display_opentelemetry_ids,
}
}
pub fn with_max_level(
self,
filter: impl Into<LevelFilter>,
) -> SubscriberBuilder<W, T, LevelFilter> {
SubscriberBuilder {
make_writer: self.make_writer,
timer: self.timer,
filter: filter.into(),
log_internal_errors: self.log_internal_errors,
display_timestamp: self.display_timestamp,
display_target: self.display_target,
display_level: self.display_level,
display_thread_id: self.display_thread_id,
display_thread_name: self.display_thread_name,
display_filename: self.display_filename,
display_line_number: self.display_line_number,
flatten_event: self.flatten_event,
display_current_span: self.display_current_span,
display_span_list: self.display_span_list,
#[cfg(feature = "opentelemetry")]
display_opentelemetry_ids: self.display_opentelemetry_ids,
}
}
#[cfg(feature = "env-filter")]
#[cfg_attr(docsrs, doc(cfg(feature = "env-filter")))]
pub fn with_filter_reloading<S>(self) -> SubscriberBuilder<W, T, reload::Layer<F, S>> {
let (filter, _) = reload::Layer::new(self.filter);
SubscriberBuilder {
make_writer: self.make_writer,
timer: self.timer,
filter,
log_internal_errors: self.log_internal_errors,
display_timestamp: self.display_timestamp,
display_target: self.display_target,
display_level: self.display_level,
display_thread_id: self.display_thread_id,
display_thread_name: self.display_thread_name,
display_filename: self.display_filename,
display_line_number: self.display_line_number,
flatten_event: self.flatten_event,
display_current_span: self.display_current_span,
display_span_list: self.display_span_list,
#[cfg(feature = "opentelemetry")]
display_opentelemetry_ids: self.display_opentelemetry_ids,
}
}
}
impl<W, T, F, S> SubscriberBuilder<W, T, reload::Layer<F, S>> {
pub fn reload_handle(&self) -> reload::Handle<F, S> {
self.filter.handle()
}
}
#[cfg(test)]
mod tests {
use std::path::Path;
use tracing::subscriber::with_default;
use tracing_core::Dispatch;
use tracing_subscriber::{filter::LevelFilter, registry::LookupSpan, Registry};
use super::SubscriberBuilder;
use crate::{
layer::JsonLayer,
tests::{MockMakeWriter, MockTime},
};
fn subscriber() -> SubscriberBuilder {
SubscriberBuilder::default()
}
#[rustfmt::skip]
#[test]
fn json_filename() {
let current_path = Path::new("src")
.join("fmt")
.join("builder.rs")
.to_str()
.expect("path must be valid unicode")
.replace('\\', "\\\\");
#[rustfmt::skip]
let expected = &format!("{}{}{}",
"{\"timestamp\":\"fake time\",\"level\":\"INFO\",\"span\":{\"answer\":42,\"name\":\"json_span\",\"number\":3},\"spans\":[{\"answer\":42,\"name\":\"json_span\",\"number\":3}],\"target\":\"json_subscriber::fmt::builder::tests\",\"filename\":\"",
current_path,
"\",\"fields\":{\"message\":\"some json test\"}}\n"
);
let collector = subscriber()
.flatten_event(false)
.with_current_span(true)
.with_file(true)
.with_span_list(true);
test_json(expected, collector, || {
let span = tracing::span!(tracing::Level::INFO, "json_span", answer = 42, number = 3);
let _guard = span.enter();
tracing::info!("some json test");
});
}
#[test]
fn json_line_number() {
#[rustfmt::skip]
let expected = "{\"timestamp\":\"fake time\",\"level\":\"INFO\",\"span\":{\"answer\":42,\"name\":\"json_span\",\"number\":3},\"spans\":[{\"answer\":42,\"name\":\"json_span\",\"number\":3}],\"target\":\"json_subscriber::fmt::builder::tests\",\"line_number\":42,\"fields\":{\"message\":\"some json test\"}}\n";
let collector = subscriber()
.flatten_event(false)
.with_current_span(true)
.with_line_number(true)
.with_span_list(true);
test_json_with_line_number(expected, collector, || {
let span = tracing::span!(tracing::Level::INFO, "json_span", answer = 42, number = 3);
let _guard = span.enter();
tracing::info!("some json test");
});
}
#[test]
fn json_flattened_event() {
#[rustfmt::skip]
let expected = "{\"timestamp\":\"fake time\",\"level\":\"INFO\",\"span\":{\"answer\":42,\"name\":\"json_span\",\"number\":3},\"spans\":[{\"answer\":42,\"name\":\"json_span\",\"number\":3}],\"target\":\"json_subscriber::fmt::builder::tests\",\"message\":\"some json test\"}\n";
let collector = subscriber()
.flatten_event(true)
.with_current_span(true)
.with_span_list(true);
test_json(expected, collector, || {
let span = tracing::span!(tracing::Level::INFO, "json_span", answer = 42, number = 3);
let _guard = span.enter();
tracing::info!("some json test");
});
}
#[test]
fn json_disabled_current_span_event() {
#[rustfmt::skip]
let expected = "{\"timestamp\":\"fake time\",\"level\":\"INFO\",\"spans\":[{\"answer\":42,\"name\":\"json_span\",\"number\":3}],\"target\":\"json_subscriber::fmt::builder::tests\",\"fields\":{\"message\":\"some json test\"}}\n";
let collector = subscriber()
.flatten_event(false)
.with_current_span(false)
.with_span_list(true);
test_json(expected, collector, || {
let span = tracing::span!(tracing::Level::INFO, "json_span", answer = 42, number = 3);
let _guard = span.enter();
tracing::info!("some json test");
});
}
#[test]
fn json_disabled_span_list_event() {
#[rustfmt::skip]
let expected = "{\"timestamp\":\"fake time\",\"level\":\"INFO\",\"span\":{\"answer\":42,\"name\":\"json_span\",\"number\":3},\"target\":\"json_subscriber::fmt::builder::tests\",\"fields\":{\"message\":\"some json test\"}}\n";
let collector = subscriber()
.flatten_event(false)
.with_current_span(true)
.with_span_list(false);
test_json(expected, collector, || {
let span = tracing::span!(tracing::Level::INFO, "json_span", answer = 42, number = 3);
let _guard = span.enter();
tracing::info!("some json test");
});
}
#[test]
fn json_nested_span() {
#[rustfmt::skip]
let expected = "{\"timestamp\":\"fake time\",\"level\":\"INFO\",\"span\":{\"answer\":43,\"name\":\"nested_json_span\",\"number\":4},\"spans\":[{\"answer\":42,\"name\":\"json_span\",\"number\":3},{\"answer\":43,\"name\":\"nested_json_span\",\"number\":4}],\"target\":\"json_subscriber::fmt::builder::tests\",\"fields\":{\"message\":\"some json test\"}}\n";
let collector = subscriber()
.flatten_event(false)
.with_current_span(true)
.with_span_list(true);
test_json(expected, collector, || {
let span = tracing::span!(tracing::Level::INFO, "json_span", answer = 42, number = 3);
let _guard = span.enter();
let span = tracing::span!(
tracing::Level::INFO,
"nested_json_span",
answer = 43,
number = 4
);
let _guard = span.enter();
tracing::info!("some json test");
});
}
#[test]
fn json_explicit_span() {
#[rustfmt::skip]
let expected = "{\"timestamp\":\"fake time\",\"level\":\"INFO\",\"span\":{\"answer\":43,\"name\":\"nested_json_span\",\"number\":4},\"spans\":[{\"answer\":42,\"name\":\"json_span\",\"number\":3},{\"answer\":43,\"name\":\"nested_json_span\",\"number\":4}],\"target\":\"json_subscriber::fmt::builder::tests\",\"fields\":{\"message\":\"some json test\"}}\n";
let collector = subscriber()
.flatten_event(false)
.with_current_span(true)
.with_span_list(true);
test_json(expected, collector, || {
let span = tracing::span!(tracing::Level::INFO, "json_span", answer = 42, number = 3);
let span = tracing::span!(
parent: &span,
tracing::Level::INFO,
"nested_json_span",
answer = 43,
number = 4
);
tracing::info!(parent: &span, "some json test");
});
}
#[test]
fn json_explicit_no_span() {
#[rustfmt::skip]
let expected = "{\"timestamp\":\"fake time\",\"level\":\"INFO\",\"target\":\"json_subscriber::fmt::builder::tests\",\"fields\":{\"message\":\"some json test\"}}\n";
let collector = subscriber()
.flatten_event(false)
.with_current_span(true)
.with_span_list(true);
test_json(expected, collector, || {
let span = tracing::span!(tracing::Level::INFO, "json_span", answer = 42, number = 3);
let _guard = span.enter();
let span = tracing::span!(
tracing::Level::INFO,
"nested_json_span",
answer = 43,
number = 4
);
let _guard = span.enter();
tracing::info!(parent: None, "some json test");
});
}
#[test]
fn json_no_span() {
#[rustfmt::skip]
let expected = "{\"timestamp\":\"fake time\",\"level\":\"INFO\",\"target\":\"json_subscriber::fmt::builder::tests\",\"fields\":{\"message\":\"some json test\"}}\n";
let collector = subscriber()
.flatten_event(false)
.with_current_span(true)
.with_span_list(true);
test_json(expected, collector, || {
tracing::info!("some json test");
});
}
#[test]
fn record_works() {
let buffer = MockMakeWriter::default();
let subscriber = SubscriberBuilder::default()
.with_writer(buffer.clone())
.finish();
with_default(subscriber, || {
tracing::info!("an event outside the root span");
assert_eq!(
parse_as_json(&buffer)["fields"]["message"],
"an event outside the root span"
);
let span = tracing::info_span!("the span", na = tracing::field::Empty);
span.record("na", "value");
let _enter = span.enter();
tracing::info!("an event inside the root span");
assert_eq!(
parse_as_json(&buffer)["fields"]["message"],
"an event inside the root span"
);
});
}
fn parse_as_json(buffer: &MockMakeWriter) -> serde_json::Value {
let buf = String::from_utf8(buffer.buf().to_vec()).unwrap();
let json = buf
.lines()
.last()
.expect("expected at least one line to be written!");
match serde_json::from_str(json) {
Ok(v) => v,
Err(e) => {
panic!(
"assertion failed: JSON shouldn't be malformed\n error: {e}\n json: {json}"
)
},
}
}
fn test_json<T>(expected: &str, builder: SubscriberBuilder, producer: impl FnOnce() -> T) {
let make_writer = MockMakeWriter::default();
let collector = builder
.with_writer(make_writer.clone())
.with_timer(MockTime)
.finish();
with_default(collector, producer);
let buf = make_writer.buf();
let actual = dbg!(std::str::from_utf8(&buf[..]).unwrap());
assert_eq!(
serde_json::from_str::<std::collections::HashMap<&str, serde_json::Value>>(expected)
.unwrap(),
serde_json::from_str(actual).unwrap()
);
}
fn test_json_with_line_number<T>(
expected: &str,
builder: SubscriberBuilder,
producer: impl FnOnce() -> T,
) {
let make_writer = MockMakeWriter::default();
let collector = builder
.with_writer(make_writer.clone())
.with_timer(MockTime)
.finish();
with_default(collector, producer);
let buf = make_writer.buf();
let actual = std::str::from_utf8(&buf[..]).unwrap();
let mut expected =
serde_json::from_str::<std::collections::HashMap<&str, serde_json::Value>>(expected)
.unwrap();
let expect_line_number = expected.remove("line_number").is_some();
let mut actual: std::collections::HashMap<&str, serde_json::Value> =
serde_json::from_str(actual).unwrap();
let line_number = actual.remove("line_number");
if expect_line_number {
assert_eq!(line_number.map(|x| x.is_number()), Some(true));
} else {
assert!(line_number.is_none());
}
assert_eq!(actual, expected);
}
#[test]
fn subscriber_downcasts() {
let subscriber = SubscriberBuilder::default().finish();
let dispatch = Dispatch::new(subscriber);
assert!(dispatch.downcast_ref::<Registry>().is_some());
}
#[test]
fn subscriber_downcasts_to_parts() {
let subscriber = SubscriberBuilder::default().finish();
let dispatch = Dispatch::new(subscriber);
assert!(dispatch.downcast_ref::<JsonLayer>().is_some());
assert!(dispatch.downcast_ref::<LevelFilter>().is_some());
}
#[test]
fn is_lookup_span() {
fn assert_lookup_span<T: for<'a> LookupSpan<'a>>(_: T) {}
let subscriber = SubscriberBuilder::default().finish();
assert_lookup_span(subscriber);
}
#[test]
#[cfg(feature = "env-filter")]
fn reload_filter_works() {
use tracing::Level;
use tracing_subscriber::util::SubscriberInitExt;
let builder = SubscriberBuilder::default()
.with_max_level(Level::INFO)
.with_filter_reloading();
let handle = builder.reload_handle();
builder.finish().init();
tracing::debug!("this is not recorded!");
handle
.reload(Level::DEBUG)
.expect("the collector should still exist");
tracing::debug!("this is recorded!");
}
}