diff options
Diffstat (limited to 'vendor/tracing-subscriber/tests')
29 files changed, 3423 insertions, 0 deletions
diff --git a/vendor/tracing-subscriber/tests/cached_layer_filters_dont_break_other_layers.rs b/vendor/tracing-subscriber/tests/cached_layer_filters_dont_break_other_layers.rs new file mode 100644 index 000000000..00e98a994 --- /dev/null +++ b/vendor/tracing-subscriber/tests/cached_layer_filters_dont_break_other_layers.rs @@ -0,0 +1,123 @@ +#![cfg(feature = "registry")] +mod support; +use self::support::*; +use tracing::Level; +use tracing_subscriber::{filter::LevelFilter, prelude::*}; + +#[test] +fn layer_filters() { + let (unfiltered, unfiltered_handle) = unfiltered("unfiltered"); + let (filtered, filtered_handle) = filtered("filtered"); + + let _subscriber = tracing_subscriber::registry() + .with(unfiltered) + .with(filtered.with_filter(filter())) + .set_default(); + + events(); + + unfiltered_handle.assert_finished(); + filtered_handle.assert_finished(); +} + +#[test] +fn layered_layer_filters() { + let (unfiltered1, unfiltered1_handle) = unfiltered("unfiltered_1"); + let (unfiltered2, unfiltered2_handle) = unfiltered("unfiltered_2"); + let unfiltered = unfiltered1.and_then(unfiltered2); + + let (filtered1, filtered1_handle) = filtered("filtered_1"); + let (filtered2, filtered2_handle) = filtered("filtered_2"); + let filtered = filtered1 + .with_filter(filter()) + .and_then(filtered2.with_filter(filter())); + + let _subscriber = tracing_subscriber::registry() + .with(unfiltered) + .with(filtered) + .set_default(); + + events(); + + unfiltered1_handle.assert_finished(); + unfiltered2_handle.assert_finished(); + filtered1_handle.assert_finished(); + filtered2_handle.assert_finished(); +} + +#[test] +fn out_of_order() { + let (unfiltered1, unfiltered1_handle) = unfiltered("unfiltered_1"); + let (unfiltered2, unfiltered2_handle) = unfiltered("unfiltered_2"); + + let (filtered1, filtered1_handle) = filtered("filtered_1"); + let (filtered2, filtered2_handle) = filtered("filtered_2"); + + let _subscriber = tracing_subscriber::registry() + .with(unfiltered1) + .with(filtered1.with_filter(filter())) + .with(unfiltered2) + .with(filtered2.with_filter(filter())) + .set_default(); + events(); + + unfiltered1_handle.assert_finished(); + unfiltered2_handle.assert_finished(); + filtered1_handle.assert_finished(); + filtered2_handle.assert_finished(); +} + +#[test] +fn mixed_layered() { + let (unfiltered1, unfiltered1_handle) = unfiltered("unfiltered_1"); + let (unfiltered2, unfiltered2_handle) = unfiltered("unfiltered_2"); + let (filtered1, filtered1_handle) = filtered("filtered_1"); + let (filtered2, filtered2_handle) = filtered("filtered_2"); + + let layered1 = filtered1.with_filter(filter()).and_then(unfiltered1); + let layered2 = unfiltered2.and_then(filtered2.with_filter(filter())); + + let _subscriber = tracing_subscriber::registry() + .with(layered1) + .with(layered2) + .set_default(); + + events(); + + unfiltered1_handle.assert_finished(); + unfiltered2_handle.assert_finished(); + filtered1_handle.assert_finished(); + filtered2_handle.assert_finished(); +} + +fn events() { + tracing::trace!("hello trace"); + tracing::debug!("hello debug"); + tracing::info!("hello info"); + tracing::warn!("hello warn"); + tracing::error!("hello error"); +} + +fn filter() -> LevelFilter { + LevelFilter::INFO +} + +fn unfiltered(name: &str) -> (ExpectLayer, subscriber::MockHandle) { + layer::named(name) + .event(event::mock().at_level(Level::TRACE)) + .event(event::mock().at_level(Level::DEBUG)) + .event(event::mock().at_level(Level::INFO)) + .event(event::mock().at_level(Level::WARN)) + .event(event::mock().at_level(Level::ERROR)) + .done() + .run_with_handle() +} + +fn filtered(name: &str) -> (ExpectLayer, subscriber::MockHandle) { + layer::named(name) + .event(event::mock().at_level(Level::INFO)) + .event(event::mock().at_level(Level::WARN)) + .event(event::mock().at_level(Level::ERROR)) + .done() + .run_with_handle() +} diff --git a/vendor/tracing-subscriber/tests/duplicate_spans.rs b/vendor/tracing-subscriber/tests/duplicate_spans.rs new file mode 100644 index 000000000..5d4dc6a85 --- /dev/null +++ b/vendor/tracing-subscriber/tests/duplicate_spans.rs @@ -0,0 +1,47 @@ +#![cfg(all(feature = "env-filter", feature = "fmt"))] +use tracing::{self, subscriber::with_default, Span}; +use tracing_subscriber::{filter::EnvFilter, FmtSubscriber}; + +#[test] +fn duplicate_spans() { + let subscriber = FmtSubscriber::builder() + .with_env_filter(EnvFilter::new("[root]=debug")) + .finish(); + + with_default(subscriber, || { + let root = tracing::debug_span!("root"); + root.in_scope(|| { + // root: + assert_eq!(root, Span::current(), "Current span must be 'root'"); + let leaf = tracing::debug_span!("leaf"); + leaf.in_scope(|| { + // root:leaf: + assert_eq!(leaf, Span::current(), "Current span must be 'leaf'"); + root.in_scope(|| { + // root:leaf: + assert_eq!( + leaf, + Span::current(), + "Current span must be 'leaf' after entering twice the 'root' span" + ); + }) + }); + // root: + assert_eq!( + root, + Span::current(), + "Current span must be root ('leaf' exited, nested 'root' exited)" + ); + + root.in_scope(|| { + assert_eq!(root, Span::current(), "Current span must be root"); + }); + // root: + assert_eq!( + root, + Span::current(), + "Current span must still be root after exiting nested 'root'" + ); + }); + }); +} diff --git a/vendor/tracing-subscriber/tests/env_filter/main.rs b/vendor/tracing-subscriber/tests/env_filter/main.rs new file mode 100644 index 000000000..3c3d4868b --- /dev/null +++ b/vendor/tracing-subscriber/tests/env_filter/main.rs @@ -0,0 +1,547 @@ +#![cfg(feature = "env-filter")] + +#[path = "../support.rs"] +mod support; +use self::support::*; + +mod per_layer; + +use tracing::{self, subscriber::with_default, Level}; +use tracing_subscriber::{ + filter::{EnvFilter, LevelFilter}, + prelude::*, +}; + +#[test] +fn level_filter_event() { + let filter: EnvFilter = "info".parse().expect("filter should parse"); + let (subscriber, finished) = subscriber::mock() + .event(event::mock().at_level(Level::INFO)) + .event(event::mock().at_level(Level::WARN)) + .event(event::mock().at_level(Level::ERROR)) + .done() + .run_with_handle(); + let subscriber = subscriber.with(filter); + + with_default(subscriber, || { + tracing::trace!("this should be disabled"); + tracing::info!("this shouldn't be"); + tracing::debug!(target: "foo", "this should also be disabled"); + tracing::warn!(target: "foo", "this should be enabled"); + tracing::error!("this should be enabled too"); + }); + + finished.assert_finished(); +} + +#[test] +fn same_name_spans() { + let filter: EnvFilter = "[foo{bar}]=trace,[foo{baz}]=trace" + .parse() + .expect("filter should parse"); + let (subscriber, finished) = subscriber::mock() + .new_span( + span::mock() + .named("foo") + .at_level(Level::TRACE) + .with_field(field::mock("bar")), + ) + .new_span( + span::mock() + .named("foo") + .at_level(Level::TRACE) + .with_field(field::mock("baz")), + ) + .done() + .run_with_handle(); + let subscriber = subscriber.with(filter); + with_default(subscriber, || { + tracing::trace_span!("foo", bar = 1); + tracing::trace_span!("foo", baz = 1); + }); + + finished.assert_finished(); +} + +#[test] +fn level_filter_event_with_target() { + let filter: EnvFilter = "info,stuff=debug".parse().expect("filter should parse"); + let (subscriber, finished) = subscriber::mock() + .event(event::mock().at_level(Level::INFO)) + .event(event::mock().at_level(Level::DEBUG).with_target("stuff")) + .event(event::mock().at_level(Level::WARN).with_target("stuff")) + .event(event::mock().at_level(Level::ERROR)) + .event(event::mock().at_level(Level::ERROR).with_target("stuff")) + .done() + .run_with_handle(); + let subscriber = subscriber.with(filter); + + with_default(subscriber, || { + tracing::trace!("this should be disabled"); + tracing::info!("this shouldn't be"); + tracing::debug!(target: "stuff", "this should be enabled"); + tracing::debug!("but this shouldn't"); + tracing::trace!(target: "stuff", "and neither should this"); + tracing::warn!(target: "stuff", "this should be enabled"); + tracing::error!("this should be enabled too"); + tracing::error!(target: "stuff", "this should be enabled also"); + }); + + finished.assert_finished(); +} + +#[test] +fn level_filter_event_with_target_and_span_global() { + let filter: EnvFilter = "info,stuff[cool_span]=debug" + .parse() + .expect("filter should parse"); + + let cool_span = span::named("cool_span"); + let uncool_span = span::named("uncool_span"); + let (subscriber, handle) = subscriber::mock() + .enter(cool_span.clone()) + .event( + event::mock() + .at_level(Level::DEBUG) + .in_scope(vec![cool_span.clone()]), + ) + .exit(cool_span) + .enter(uncool_span.clone()) + .exit(uncool_span) + .done() + .run_with_handle(); + + let subscriber = subscriber.with(filter); + + with_default(subscriber, || { + { + let _span = tracing::info_span!(target: "stuff", "cool_span").entered(); + tracing::debug!("this should be enabled"); + } + + tracing::debug!("should also be disabled"); + + { + let _span = tracing::info_span!("uncool_span").entered(); + tracing::debug!("this should be disabled"); + } + }); + + handle.assert_finished(); +} + +#[test] +fn not_order_dependent() { + // this test reproduces tokio-rs/tracing#623 + + let filter: EnvFilter = "stuff=debug,info".parse().expect("filter should parse"); + let (subscriber, finished) = subscriber::mock() + .event(event::mock().at_level(Level::INFO)) + .event(event::mock().at_level(Level::DEBUG).with_target("stuff")) + .event(event::mock().at_level(Level::WARN).with_target("stuff")) + .event(event::mock().at_level(Level::ERROR)) + .event(event::mock().at_level(Level::ERROR).with_target("stuff")) + .done() + .run_with_handle(); + let subscriber = subscriber.with(filter); + + with_default(subscriber, || { + tracing::trace!("this should be disabled"); + tracing::info!("this shouldn't be"); + tracing::debug!(target: "stuff", "this should be enabled"); + tracing::debug!("but this shouldn't"); + tracing::trace!(target: "stuff", "and neither should this"); + tracing::warn!(target: "stuff", "this should be enabled"); + tracing::error!("this should be enabled too"); + tracing::error!(target: "stuff", "this should be enabled also"); + }); + + finished.assert_finished(); +} + +#[test] +fn add_directive_enables_event() { + // this test reproduces tokio-rs/tracing#591 + + // by default, use info level + let mut filter = EnvFilter::new(LevelFilter::INFO.to_string()); + + // overwrite with a more specific directive + filter = filter.add_directive("hello=trace".parse().expect("directive should parse")); + + let (subscriber, finished) = subscriber::mock() + .event(event::mock().at_level(Level::INFO).with_target("hello")) + .event(event::mock().at_level(Level::TRACE).with_target("hello")) + .done() + .run_with_handle(); + let subscriber = subscriber.with(filter); + + with_default(subscriber, || { + tracing::info!(target: "hello", "hello info"); + tracing::trace!(target: "hello", "hello trace"); + }); + + finished.assert_finished(); +} + +#[test] +fn span_name_filter_is_dynamic() { + let filter: EnvFilter = "info,[cool_span]=debug" + .parse() + .expect("filter should parse"); + let (subscriber, finished) = subscriber::mock() + .event(event::mock().at_level(Level::INFO)) + .enter(span::named("cool_span")) + .event(event::mock().at_level(Level::DEBUG)) + .enter(span::named("uncool_span")) + .event(event::mock().at_level(Level::WARN)) + .event(event::mock().at_level(Level::DEBUG)) + .exit(span::named("uncool_span")) + .exit(span::named("cool_span")) + .enter(span::named("uncool_span")) + .event(event::mock().at_level(Level::WARN)) + .event(event::mock().at_level(Level::ERROR)) + .exit(span::named("uncool_span")) + .done() + .run_with_handle(); + let subscriber = subscriber.with(filter); + + with_default(subscriber, || { + tracing::trace!("this should be disabled"); + tracing::info!("this shouldn't be"); + let cool_span = tracing::info_span!("cool_span"); + let uncool_span = tracing::info_span!("uncool_span"); + + { + let _enter = cool_span.enter(); + tracing::debug!("i'm a cool event"); + tracing::trace!("i'm cool, but not cool enough"); + let _enter2 = uncool_span.enter(); + tracing::warn!("warning: extremely cool!"); + tracing::debug!("i'm still cool"); + } + + let _enter = uncool_span.enter(); + tracing::warn!("warning: not that cool"); + tracing::trace!("im not cool enough"); + tracing::error!("uncool error"); + }); + + finished.assert_finished(); +} + +#[test] +fn method_name_resolution() { + #[allow(unused_imports)] + use tracing_subscriber::layer::{Filter, Layer}; + + let filter = EnvFilter::new("hello_world=info"); + filter.max_level_hint(); +} + +// contains the same tests as the first half of this file +// but using EnvFilter as a `Filter`, not as a `Layer` +mod per_layer_filter { + use super::*; + + #[test] + fn level_filter_event() { + let filter: EnvFilter = "info".parse().expect("filter should parse"); + let (layer, handle) = layer::mock() + .event(event::mock().at_level(Level::INFO)) + .event(event::mock().at_level(Level::WARN)) + .event(event::mock().at_level(Level::ERROR)) + .done() + .run_with_handle(); + + let _subscriber = tracing_subscriber::registry() + .with(layer.with_filter(filter)) + .set_default(); + + tracing::trace!("this should be disabled"); + tracing::info!("this shouldn't be"); + tracing::debug!(target: "foo", "this should also be disabled"); + tracing::warn!(target: "foo", "this should be enabled"); + tracing::error!("this should be enabled too"); + + handle.assert_finished(); + } + + #[test] + fn same_name_spans() { + let filter: EnvFilter = "[foo{bar}]=trace,[foo{baz}]=trace" + .parse() + .expect("filter should parse"); + let (layer, handle) = layer::mock() + .new_span( + span::mock() + .named("foo") + .at_level(Level::TRACE) + .with_field(field::mock("bar")), + ) + .new_span( + span::mock() + .named("foo") + .at_level(Level::TRACE) + .with_field(field::mock("baz")), + ) + .done() + .run_with_handle(); + + let _subscriber = tracing_subscriber::registry() + .with(layer.with_filter(filter)) + .set_default(); + + tracing::trace_span!("foo", bar = 1); + tracing::trace_span!("foo", baz = 1); + + handle.assert_finished(); + } + + #[test] + fn level_filter_event_with_target() { + let filter: EnvFilter = "info,stuff=debug".parse().expect("filter should parse"); + let (layer, handle) = layer::mock() + .event(event::mock().at_level(Level::INFO)) + .event(event::mock().at_level(Level::DEBUG).with_target("stuff")) + .event(event::mock().at_level(Level::WARN).with_target("stuff")) + .event(event::mock().at_level(Level::ERROR)) + .event(event::mock().at_level(Level::ERROR).with_target("stuff")) + .done() + .run_with_handle(); + + let _subscriber = tracing_subscriber::registry() + .with(layer.with_filter(filter)) + .set_default(); + + tracing::trace!("this should be disabled"); + tracing::info!("this shouldn't be"); + tracing::debug!(target: "stuff", "this should be enabled"); + tracing::debug!("but this shouldn't"); + tracing::trace!(target: "stuff", "and neither should this"); + tracing::warn!(target: "stuff", "this should be enabled"); + tracing::error!("this should be enabled too"); + tracing::error!(target: "stuff", "this should be enabled also"); + + handle.assert_finished(); + } + + #[test] + fn level_filter_event_with_target_and_span() { + let filter: EnvFilter = "stuff[cool_span]=debug" + .parse() + .expect("filter should parse"); + + let cool_span = span::named("cool_span"); + let (layer, handle) = layer::mock() + .enter(cool_span.clone()) + .event( + event::mock() + .at_level(Level::DEBUG) + .in_scope(vec![cool_span.clone()]), + ) + .exit(cool_span) + .done() + .run_with_handle(); + + let _subscriber = tracing_subscriber::registry() + .with(layer.with_filter(filter)) + .set_default(); + + { + let _span = tracing::info_span!(target: "stuff", "cool_span").entered(); + tracing::debug!("this should be enabled"); + } + + tracing::debug!("should also be disabled"); + + { + let _span = tracing::info_span!("uncool_span").entered(); + tracing::debug!("this should be disabled"); + } + + handle.assert_finished(); + } + + #[test] + fn not_order_dependent() { + // this test reproduces tokio-rs/tracing#623 + + let filter: EnvFilter = "stuff=debug,info".parse().expect("filter should parse"); + let (layer, finished) = layer::mock() + .event(event::mock().at_level(Level::INFO)) + .event(event::mock().at_level(Level::DEBUG).with_target("stuff")) + .event(event::mock().at_level(Level::WARN).with_target("stuff")) + .event(event::mock().at_level(Level::ERROR)) + .event(event::mock().at_level(Level::ERROR).with_target("stuff")) + .done() + .run_with_handle(); + + let _subscriber = tracing_subscriber::registry() + .with(layer.with_filter(filter)) + .set_default(); + + tracing::trace!("this should be disabled"); + tracing::info!("this shouldn't be"); + tracing::debug!(target: "stuff", "this should be enabled"); + tracing::debug!("but this shouldn't"); + tracing::trace!(target: "stuff", "and neither should this"); + tracing::warn!(target: "stuff", "this should be enabled"); + tracing::error!("this should be enabled too"); + tracing::error!(target: "stuff", "this should be enabled also"); + + finished.assert_finished(); + } + + #[test] + fn add_directive_enables_event() { + // this test reproduces tokio-rs/tracing#591 + + // by default, use info level + let mut filter = EnvFilter::new(LevelFilter::INFO.to_string()); + + // overwrite with a more specific directive + filter = filter.add_directive("hello=trace".parse().expect("directive should parse")); + + let (layer, finished) = layer::mock() + .event(event::mock().at_level(Level::INFO).with_target("hello")) + .event(event::mock().at_level(Level::TRACE).with_target("hello")) + .done() + .run_with_handle(); + + let _subscriber = tracing_subscriber::registry() + .with(layer.with_filter(filter)) + .set_default(); + + tracing::info!(target: "hello", "hello info"); + tracing::trace!(target: "hello", "hello trace"); + + finished.assert_finished(); + } + + #[test] + fn span_name_filter_is_dynamic() { + let filter: EnvFilter = "info,[cool_span]=debug" + .parse() + .expect("filter should parse"); + let cool_span = span::named("cool_span"); + let uncool_span = span::named("uncool_span"); + let (layer, finished) = layer::mock() + .event(event::mock().at_level(Level::INFO)) + .enter(cool_span.clone()) + .event( + event::mock() + .at_level(Level::DEBUG) + .in_scope(vec![cool_span.clone()]), + ) + .enter(uncool_span.clone()) + .event( + event::mock() + .at_level(Level::WARN) + .in_scope(vec![uncool_span.clone()]), + ) + .event( + event::mock() + .at_level(Level::DEBUG) + .in_scope(vec![uncool_span.clone()]), + ) + .exit(uncool_span.clone()) + .exit(cool_span) + .enter(uncool_span.clone()) + .event( + event::mock() + .at_level(Level::WARN) + .in_scope(vec![uncool_span.clone()]), + ) + .event( + event::mock() + .at_level(Level::ERROR) + .in_scope(vec![uncool_span.clone()]), + ) + .exit(uncool_span) + .done() + .run_with_handle(); + + let _subscriber = tracing_subscriber::registry() + .with(layer.with_filter(filter)) + .set_default(); + + tracing::trace!("this should be disabled"); + tracing::info!("this shouldn't be"); + let cool_span = tracing::info_span!("cool_span"); + let uncool_span = tracing::info_span!("uncool_span"); + + { + let _enter = cool_span.enter(); + tracing::debug!("i'm a cool event"); + tracing::trace!("i'm cool, but not cool enough"); + let _enter2 = uncool_span.enter(); + tracing::warn!("warning: extremely cool!"); + tracing::debug!("i'm still cool"); + } + + { + let _enter = uncool_span.enter(); + tracing::warn!("warning: not that cool"); + tracing::trace!("im not cool enough"); + tracing::error!("uncool error"); + } + + finished.assert_finished(); + } + + #[test] + fn multiple_dynamic_filters() { + // Test that multiple dynamic (span) filters only apply to the layers + // they're attached to. + let (layer1, handle1) = { + let span = span::named("span1"); + let filter: EnvFilter = "[span1]=debug".parse().expect("filter 1 should parse"); + let (layer, handle) = layer::named("layer1") + .enter(span.clone()) + .event( + event::mock() + .at_level(Level::DEBUG) + .in_scope(vec![span.clone()]), + ) + .exit(span) + .done() + .run_with_handle(); + (layer.with_filter(filter), handle) + }; + + let (layer2, handle2) = { + let span = span::named("span2"); + let filter: EnvFilter = "[span2]=info".parse().expect("filter 2 should parse"); + let (layer, handle) = layer::named("layer2") + .enter(span.clone()) + .event( + event::mock() + .at_level(Level::INFO) + .in_scope(vec![span.clone()]), + ) + .exit(span) + .done() + .run_with_handle(); + (layer.with_filter(filter), handle) + }; + + let _subscriber = tracing_subscriber::registry() + .with(layer1) + .with(layer2) + .set_default(); + + tracing::info_span!("span1").in_scope(|| { + tracing::debug!("hello from span 1"); + tracing::trace!("not enabled"); + }); + + tracing::info_span!("span2").in_scope(|| { + tracing::info!("hello from span 2"); + tracing::debug!("not enabled"); + }); + + handle1.assert_finished(); + handle2.assert_finished(); + } +} diff --git a/vendor/tracing-subscriber/tests/env_filter/per_layer.rs b/vendor/tracing-subscriber/tests/env_filter/per_layer.rs new file mode 100644 index 000000000..8bf5698a4 --- /dev/null +++ b/vendor/tracing-subscriber/tests/env_filter/per_layer.rs @@ -0,0 +1,305 @@ +//! Tests for using `EnvFilter` as a per-layer filter (rather than a global +//! `Layer` filter). +#![cfg(feature = "registry")] +use super::*; + +#[test] +fn level_filter_event() { + let filter: EnvFilter = "info".parse().expect("filter should parse"); + let (layer, handle) = layer::mock() + .event(event::mock().at_level(Level::INFO)) + .event(event::mock().at_level(Level::WARN)) + .event(event::mock().at_level(Level::ERROR)) + .done() + .run_with_handle(); + + let _subscriber = tracing_subscriber::registry() + .with(layer.with_filter(filter)) + .set_default(); + + tracing::trace!("this should be disabled"); + tracing::info!("this shouldn't be"); + tracing::debug!(target: "foo", "this should also be disabled"); + tracing::warn!(target: "foo", "this should be enabled"); + tracing::error!("this should be enabled too"); + + handle.assert_finished(); +} + +#[test] +fn same_name_spans() { + let filter: EnvFilter = "[foo{bar}]=trace,[foo{baz}]=trace" + .parse() + .expect("filter should parse"); + let (layer, handle) = layer::mock() + .new_span( + span::mock() + .named("foo") + .at_level(Level::TRACE) + .with_field(field::mock("bar")), + ) + .new_span( + span::mock() + .named("foo") + .at_level(Level::TRACE) + .with_field(field::mock("baz")), + ) + .done() + .run_with_handle(); + + let _subscriber = tracing_subscriber::registry() + .with(layer.with_filter(filter)) + .set_default(); + + tracing::trace_span!("foo", bar = 1); + tracing::trace_span!("foo", baz = 1); + + handle.assert_finished(); +} + +#[test] +fn level_filter_event_with_target() { + let filter: EnvFilter = "info,stuff=debug".parse().expect("filter should parse"); + let (layer, handle) = layer::mock() + .event(event::mock().at_level(Level::INFO)) + .event(event::mock().at_level(Level::DEBUG).with_target("stuff")) + .event(event::mock().at_level(Level::WARN).with_target("stuff")) + .event(event::mock().at_level(Level::ERROR)) + .event(event::mock().at_level(Level::ERROR).with_target("stuff")) + .done() + .run_with_handle(); + + let _subscriber = tracing_subscriber::registry() + .with(layer.with_filter(filter)) + .set_default(); + + tracing::trace!("this should be disabled"); + tracing::info!("this shouldn't be"); + tracing::debug!(target: "stuff", "this should be enabled"); + tracing::debug!("but this shouldn't"); + tracing::trace!(target: "stuff", "and neither should this"); + tracing::warn!(target: "stuff", "this should be enabled"); + tracing::error!("this should be enabled too"); + tracing::error!(target: "stuff", "this should be enabled also"); + + handle.assert_finished(); +} + +#[test] +fn level_filter_event_with_target_and_span() { + let filter: EnvFilter = "stuff[cool_span]=debug" + .parse() + .expect("filter should parse"); + + let cool_span = span::named("cool_span"); + let (layer, handle) = layer::mock() + .enter(cool_span.clone()) + .event( + event::mock() + .at_level(Level::DEBUG) + .in_scope(vec![cool_span.clone()]), + ) + .exit(cool_span) + .done() + .run_with_handle(); + + let _subscriber = tracing_subscriber::registry() + .with(layer.with_filter(filter)) + .set_default(); + + { + let _span = tracing::info_span!(target: "stuff", "cool_span").entered(); + tracing::debug!("this should be enabled"); + } + + tracing::debug!("should also be disabled"); + + { + let _span = tracing::info_span!("uncool_span").entered(); + tracing::debug!("this should be disabled"); + } + + handle.assert_finished(); +} + +#[test] +fn not_order_dependent() { + // this test reproduces tokio-rs/tracing#623 + + let filter: EnvFilter = "stuff=debug,info".parse().expect("filter should parse"); + let (layer, finished) = layer::mock() + .event(event::mock().at_level(Level::INFO)) + .event(event::mock().at_level(Level::DEBUG).with_target("stuff")) + .event(event::mock().at_level(Level::WARN).with_target("stuff")) + .event(event::mock().at_level(Level::ERROR)) + .event(event::mock().at_level(Level::ERROR).with_target("stuff")) + .done() + .run_with_handle(); + + let _subscriber = tracing_subscriber::registry() + .with(layer.with_filter(filter)) + .set_default(); + + tracing::trace!("this should be disabled"); + tracing::info!("this shouldn't be"); + tracing::debug!(target: "stuff", "this should be enabled"); + tracing::debug!("but this shouldn't"); + tracing::trace!(target: "stuff", "and neither should this"); + tracing::warn!(target: "stuff", "this should be enabled"); + tracing::error!("this should be enabled too"); + tracing::error!(target: "stuff", "this should be enabled also"); + + finished.assert_finished(); +} + +#[test] +fn add_directive_enables_event() { + // this test reproduces tokio-rs/tracing#591 + + // by default, use info level + let mut filter = EnvFilter::new(LevelFilter::INFO.to_string()); + + // overwrite with a more specific directive + filter = filter.add_directive("hello=trace".parse().expect("directive should parse")); + + let (layer, finished) = layer::mock() + .event(event::mock().at_level(Level::INFO).with_target("hello")) + .event(event::mock().at_level(Level::TRACE).with_target("hello")) + .done() + .run_with_handle(); + + let _subscriber = tracing_subscriber::registry() + .with(layer.with_filter(filter)) + .set_default(); + + tracing::info!(target: "hello", "hello info"); + tracing::trace!(target: "hello", "hello trace"); + + finished.assert_finished(); +} + +#[test] +fn span_name_filter_is_dynamic() { + let filter: EnvFilter = "info,[cool_span]=debug" + .parse() + .expect("filter should parse"); + let cool_span = span::named("cool_span"); + let uncool_span = span::named("uncool_span"); + let (layer, finished) = layer::mock() + .event(event::mock().at_level(Level::INFO)) + .enter(cool_span.clone()) + .event( + event::mock() + .at_level(Level::DEBUG) + .in_scope(vec![cool_span.clone()]), + ) + .enter(uncool_span.clone()) + .event( + event::mock() + .at_level(Level::WARN) + .in_scope(vec![uncool_span.clone()]), + ) + .event( + event::mock() + .at_level(Level::DEBUG) + .in_scope(vec![uncool_span.clone()]), + ) + .exit(uncool_span.clone()) + .exit(cool_span) + .enter(uncool_span.clone()) + .event( + event::mock() + .at_level(Level::WARN) + .in_scope(vec![uncool_span.clone()]), + ) + .event( + event::mock() + .at_level(Level::ERROR) + .in_scope(vec![uncool_span.clone()]), + ) + .exit(uncool_span) + .done() + .run_with_handle(); + + let _subscriber = tracing_subscriber::registry() + .with(layer.with_filter(filter)) + .set_default(); + + tracing::trace!("this should be disabled"); + tracing::info!("this shouldn't be"); + let cool_span = tracing::info_span!("cool_span"); + let uncool_span = tracing::info_span!("uncool_span"); + + { + let _enter = cool_span.enter(); + tracing::debug!("i'm a cool event"); + tracing::trace!("i'm cool, but not cool enough"); + let _enter2 = uncool_span.enter(); + tracing::warn!("warning: extremely cool!"); + tracing::debug!("i'm still cool"); + } + + { + let _enter = uncool_span.enter(); + tracing::warn!("warning: not that cool"); + tracing::trace!("im not cool enough"); + tracing::error!("uncool error"); + } + + finished.assert_finished(); +} + +#[test] +fn multiple_dynamic_filters() { + // Test that multiple dynamic (span) filters only apply to the layers + // they're attached to. + let (layer1, handle1) = { + let span = span::named("span1"); + let filter: EnvFilter = "[span1]=debug".parse().expect("filter 1 should parse"); + let (layer, handle) = layer::named("layer1") + .enter(span.clone()) + .event( + event::mock() + .at_level(Level::DEBUG) + .in_scope(vec![span.clone()]), + ) + .exit(span) + .done() + .run_with_handle(); + (layer.with_filter(filter), handle) + }; + + let (layer2, handle2) = { + let span = span::named("span2"); + let filter: EnvFilter = "[span2]=info".parse().expect("filter 2 should parse"); + let (layer, handle) = layer::named("layer2") + .enter(span.clone()) + .event( + event::mock() + .at_level(Level::INFO) + .in_scope(vec![span.clone()]), + ) + .exit(span) + .done() + .run_with_handle(); + (layer.with_filter(filter), handle) + }; + + let _subscriber = tracing_subscriber::registry() + .with(layer1) + .with(layer2) + .set_default(); + + tracing::info_span!("span1").in_scope(|| { + tracing::debug!("hello from span 1"); + tracing::trace!("not enabled"); + }); + + tracing::info_span!("span2").in_scope(|| { + tracing::info!("hello from span 2"); + tracing::debug!("not enabled"); + }); + + handle1.assert_finished(); + handle2.assert_finished(); +} diff --git a/vendor/tracing-subscriber/tests/event_enabling.rs b/vendor/tracing-subscriber/tests/event_enabling.rs new file mode 100644 index 000000000..8f67cfcba --- /dev/null +++ b/vendor/tracing-subscriber/tests/event_enabling.rs @@ -0,0 +1,81 @@ +#![cfg(feature = "registry")] + +use std::sync::{Arc, Mutex}; +use tracing::{subscriber::with_default, Event, Metadata, Subscriber}; +use tracing_subscriber::{layer::Context, prelude::*, registry, Layer}; + +struct TrackingLayer { + enabled: bool, + event_enabled_count: Arc<Mutex<usize>>, + event_enabled: bool, + on_event_count: Arc<Mutex<usize>>, +} + +impl<C> Layer<C> for TrackingLayer +where + C: Subscriber + Send + Sync + 'static, +{ + fn enabled(&self, _metadata: &Metadata<'_>, _ctx: Context<'_, C>) -> bool { + self.enabled + } + + fn event_enabled(&self, _event: &Event<'_>, _ctx: Context<'_, C>) -> bool { + *self.event_enabled_count.lock().unwrap() += 1; + self.event_enabled + } + + fn on_event(&self, _event: &Event<'_>, _ctx: Context<'_, C>) { + *self.on_event_count.lock().unwrap() += 1; + } +} + +#[test] +fn event_enabled_is_only_called_once() { + let event_enabled_count = Arc::new(Mutex::default()); + let count = event_enabled_count.clone(); + let subscriber = registry().with(TrackingLayer { + enabled: true, + event_enabled_count, + event_enabled: true, + on_event_count: Arc::new(Mutex::default()), + }); + with_default(subscriber, || { + tracing::error!("hiya!"); + }); + + assert_eq!(1, *count.lock().unwrap()); +} + +#[test] +fn event_enabled_not_called_when_not_enabled() { + let event_enabled_count = Arc::new(Mutex::default()); + let count = event_enabled_count.clone(); + let subscriber = registry().with(TrackingLayer { + enabled: false, + event_enabled_count, + event_enabled: true, + on_event_count: Arc::new(Mutex::default()), + }); + with_default(subscriber, || { + tracing::error!("hiya!"); + }); + + assert_eq!(0, *count.lock().unwrap()); +} + +#[test] +fn event_disabled_does_disable_event() { + let on_event_count = Arc::new(Mutex::default()); + let count = on_event_count.clone(); + let subscriber = registry().with(TrackingLayer { + enabled: true, + event_enabled_count: Arc::new(Mutex::default()), + event_enabled: false, + on_event_count, + }); + with_default(subscriber, || { + tracing::error!("hiya!"); + }); + + assert_eq!(0, *count.lock().unwrap()); +} diff --git a/vendor/tracing-subscriber/tests/field_filter.rs b/vendor/tracing-subscriber/tests/field_filter.rs new file mode 100644 index 000000000..f14a0626d --- /dev/null +++ b/vendor/tracing-subscriber/tests/field_filter.rs @@ -0,0 +1,115 @@ +#![cfg(feature = "env-filter")] + +use tracing::{self, subscriber::with_default, Level}; +use tracing_mock::*; +use tracing_subscriber::{filter::EnvFilter, prelude::*}; + +#[test] +#[cfg_attr(not(flaky_tests), ignore)] +fn field_filter_events() { + let filter: EnvFilter = "[{thing}]=debug".parse().expect("filter should parse"); + let (subscriber, finished) = subscriber::mock() + .event( + event::mock() + .at_level(Level::INFO) + .with_fields(field::mock("thing")), + ) + .event( + event::mock() + .at_level(Level::DEBUG) + .with_fields(field::mock("thing")), + ) + .done() + .run_with_handle(); + let subscriber = subscriber.with(filter); + + with_default(subscriber, || { + tracing::trace!(disabled = true); + tracing::info!("also disabled"); + tracing::info!(thing = 1); + tracing::debug!(thing = 2); + tracing::trace!(thing = 3); + }); + + finished.assert_finished(); +} + +#[test] +#[cfg_attr(not(flaky_tests), ignore)] +fn field_filter_spans() { + let filter: EnvFilter = "[{enabled=true}]=debug" + .parse() + .expect("filter should parse"); + let (subscriber, finished) = subscriber::mock() + .enter(span::mock().named("span1")) + .event( + event::mock() + .at_level(Level::INFO) + .with_fields(field::mock("something")), + ) + .exit(span::mock().named("span1")) + .enter(span::mock().named("span2")) + .exit(span::mock().named("span2")) + .enter(span::mock().named("span3")) + .event( + event::mock() + .at_level(Level::DEBUG) + .with_fields(field::mock("something")), + ) + .exit(span::mock().named("span3")) + .done() + .run_with_handle(); + let subscriber = subscriber.with(filter); + + with_default(subscriber, || { + tracing::trace!("disabled"); + tracing::info!("also disabled"); + tracing::info_span!("span1", enabled = true).in_scope(|| { + tracing::info!(something = 1); + }); + tracing::debug_span!("span2", enabled = false, foo = "hi").in_scope(|| { + tracing::warn!(something = 2); + }); + tracing::trace_span!("span3", enabled = true, answer = 42).in_scope(|| { + tracing::debug!(something = 2); + }); + }); + + finished.assert_finished(); +} + +#[test] +fn record_after_created() { + let filter: EnvFilter = "[{enabled=true}]=debug" + .parse() + .expect("filter should parse"); + let (subscriber, finished) = subscriber::mock() + .enter(span::mock().named("span")) + .exit(span::mock().named("span")) + .record( + span::mock().named("span"), + field::mock("enabled").with_value(&true), + ) + .enter(span::mock().named("span")) + .event(event::mock().at_level(Level::DEBUG)) + .exit(span::mock().named("span")) + .done() + .run_with_handle(); + let subscriber = subscriber.with(filter); + + with_default(subscriber, || { + let span = tracing::info_span!("span", enabled = false); + span.in_scope(|| { + tracing::debug!("i'm disabled!"); + }); + + span.record("enabled", &true); + span.in_scope(|| { + tracing::debug!("i'm enabled!"); + }); + + tracing::debug!("i'm also disabled"); + }); + + finished.assert_finished(); +} diff --git a/vendor/tracing-subscriber/tests/filter_log.rs b/vendor/tracing-subscriber/tests/filter_log.rs new file mode 100644 index 000000000..8d57ed600 --- /dev/null +++ b/vendor/tracing-subscriber/tests/filter_log.rs @@ -0,0 +1,63 @@ +#![cfg(all(feature = "env-filter", feature = "tracing-log"))] + +use tracing::{self, Level}; +use tracing_mock::*; +use tracing_subscriber::{filter::EnvFilter, prelude::*}; + +mod my_module { + pub(crate) fn test_records() { + log::trace!("this should be disabled"); + log::info!("this shouldn't be"); + log::debug!("this should be disabled"); + log::warn!("this should be enabled"); + log::warn!(target: "something else", "this shouldn't be enabled"); + log::error!("this should be enabled too"); + } + + pub(crate) fn test_log_enabled() { + assert!( + log::log_enabled!(log::Level::Info), + "info should be enabled inside `my_module`" + ); + assert!( + !log::log_enabled!(log::Level::Debug), + "debug should not be enabled inside `my_module`" + ); + assert!( + log::log_enabled!(log::Level::Warn), + "warn should be enabled inside `my_module`" + ); + } +} + +#[test] +fn log_is_enabled() { + let filter: EnvFilter = "filter_log::my_module=info" + .parse() + .expect("filter should parse"); + let (subscriber, finished) = subscriber::mock() + .event(event::mock().at_level(Level::INFO)) + .event(event::mock().at_level(Level::WARN)) + .event(event::mock().at_level(Level::ERROR)) + .done() + .run_with_handle(); + + // Note: we have to set the global default in order to set the `log` max + // level, which can only be set once. + subscriber.with(filter).init(); + + my_module::test_records(); + log::info!("this is disabled"); + + my_module::test_log_enabled(); + assert!( + !log::log_enabled!(log::Level::Info), + "info should not be enabled outside `my_module`" + ); + assert!( + !log::log_enabled!(log::Level::Warn), + "warn should not be enabled outside `my_module`" + ); + + finished.assert_finished(); +} diff --git a/vendor/tracing-subscriber/tests/fmt_max_level_hint.rs b/vendor/tracing-subscriber/tests/fmt_max_level_hint.rs new file mode 100644 index 000000000..57a0f6e3f --- /dev/null +++ b/vendor/tracing-subscriber/tests/fmt_max_level_hint.rs @@ -0,0 +1,10 @@ +#![cfg(feature = "fmt")] +use tracing_subscriber::filter::LevelFilter; + +#[test] +fn fmt_sets_max_level_hint() { + tracing_subscriber::fmt() + .with_max_level(LevelFilter::DEBUG) + .init(); + assert_eq!(LevelFilter::current(), LevelFilter::DEBUG); +} diff --git a/vendor/tracing-subscriber/tests/hinted_layer_filters_dont_break_other_layers.rs b/vendor/tracing-subscriber/tests/hinted_layer_filters_dont_break_other_layers.rs new file mode 100644 index 000000000..897dae282 --- /dev/null +++ b/vendor/tracing-subscriber/tests/hinted_layer_filters_dont_break_other_layers.rs @@ -0,0 +1,131 @@ +#![cfg(feature = "registry")] +mod support; +use self::support::*; +use tracing::{Level, Metadata, Subscriber}; +use tracing_subscriber::{filter::DynFilterFn, layer::Context, prelude::*}; + +#[test] +fn layer_filters() { + let (unfiltered, unfiltered_handle) = unfiltered("unfiltered"); + let (filtered, filtered_handle) = filtered("filtered"); + + let subscriber = tracing_subscriber::registry() + .with(unfiltered) + .with(filtered.with_filter(filter())); + assert_eq!(subscriber.max_level_hint(), None); + let _subscriber = subscriber.set_default(); + + events(); + + unfiltered_handle.assert_finished(); + filtered_handle.assert_finished(); +} + +#[test] +fn layered_layer_filters() { + let (unfiltered1, unfiltered1_handle) = unfiltered("unfiltered_1"); + let (unfiltered2, unfiltered2_handle) = unfiltered("unfiltered_2"); + let unfiltered = unfiltered1.and_then(unfiltered2); + + let (filtered1, filtered1_handle) = filtered("filtered_1"); + let (filtered2, filtered2_handle) = filtered("filtered_2"); + let filtered = filtered1 + .with_filter(filter()) + .and_then(filtered2.with_filter(filter())); + + let subscriber = tracing_subscriber::registry() + .with(unfiltered) + .with(filtered); + assert_eq!(subscriber.max_level_hint(), None); + let _subscriber = subscriber.set_default(); + + events(); + + unfiltered1_handle.assert_finished(); + unfiltered2_handle.assert_finished(); + filtered1_handle.assert_finished(); + filtered2_handle.assert_finished(); +} + +#[test] +fn out_of_order() { + let (unfiltered1, unfiltered1_handle) = unfiltered("unfiltered_1"); + let (unfiltered2, unfiltered2_handle) = unfiltered("unfiltered_2"); + + let (filtered1, filtered1_handle) = filtered("filtered_1"); + let (filtered2, filtered2_handle) = filtered("filtered_2"); + + let subscriber = tracing_subscriber::registry() + .with(unfiltered1) + .with(filtered1.with_filter(filter())) + .with(unfiltered2) + .with(filtered2.with_filter(filter())); + assert_eq!(subscriber.max_level_hint(), None); + let _subscriber = subscriber.set_default(); + + events(); + + unfiltered1_handle.assert_finished(); + unfiltered2_handle.assert_finished(); + filtered1_handle.assert_finished(); + filtered2_handle.assert_finished(); +} + +#[test] +fn mixed_layered() { + let (unfiltered1, unfiltered1_handle) = unfiltered("unfiltered_1"); + let (unfiltered2, unfiltered2_handle) = unfiltered("unfiltered_2"); + let (filtered1, filtered1_handle) = filtered("filtered_1"); + let (filtered2, filtered2_handle) = filtered("filtered_2"); + + let layered1 = filtered1.with_filter(filter()).and_then(unfiltered1); + let layered2 = unfiltered2.and_then(filtered2.with_filter(filter())); + + let subscriber = tracing_subscriber::registry().with(layered1).with(layered2); + assert_eq!(subscriber.max_level_hint(), None); + let _subscriber = subscriber.set_default(); + + events(); + + unfiltered1_handle.assert_finished(); + unfiltered2_handle.assert_finished(); + filtered1_handle.assert_finished(); + filtered2_handle.assert_finished(); +} + +fn events() { + tracing::trace!("hello trace"); + tracing::debug!("hello debug"); + tracing::info!("hello info"); + tracing::warn!("hello warn"); + tracing::error!("hello error"); +} + +fn filter<S>() -> DynFilterFn<S> { + DynFilterFn::new( + (|metadata: &Metadata<'_>, _: &tracing_subscriber::layer::Context<'_, S>| { + metadata.level() <= &Level::INFO + }) as fn(&Metadata<'_>, &Context<'_, S>) -> bool, + ) + .with_max_level_hint(Level::INFO) +} + +fn unfiltered(name: &str) -> (ExpectLayer, subscriber::MockHandle) { + layer::named(name) + .event(event::mock().at_level(Level::TRACE)) + .event(event::mock().at_level(Level::DEBUG)) + .event(event::mock().at_level(Level::INFO)) + .event(event::mock().at_level(Level::WARN)) + .event(event::mock().at_level(Level::ERROR)) + .done() + .run_with_handle() +} + +fn filtered(name: &str) -> (ExpectLayer, subscriber::MockHandle) { + layer::named(name) + .event(event::mock().at_level(Level::INFO)) + .event(event::mock().at_level(Level::WARN)) + .event(event::mock().at_level(Level::ERROR)) + .done() + .run_with_handle() +} diff --git a/vendor/tracing-subscriber/tests/layer_filter_interests_are_cached.rs b/vendor/tracing-subscriber/tests/layer_filter_interests_are_cached.rs new file mode 100644 index 000000000..d89d3bf17 --- /dev/null +++ b/vendor/tracing-subscriber/tests/layer_filter_interests_are_cached.rs @@ -0,0 +1,69 @@ +#![cfg(feature = "registry")] +mod support; +use self::support::*; + +use std::{ + collections::HashMap, + sync::{Arc, Mutex}, +}; +use tracing::{Level, Subscriber}; +use tracing_subscriber::{filter, prelude::*}; + +#[test] +fn layer_filter_interests_are_cached() { + let seen = Arc::new(Mutex::new(HashMap::new())); + let seen2 = seen.clone(); + let filter = filter::filter_fn(move |meta| { + *seen + .lock() + .unwrap() + .entry(meta.callsite()) + .or_insert(0usize) += 1; + meta.level() == &Level::INFO + }); + + let (expect, handle) = layer::mock() + .event(event::mock().at_level(Level::INFO)) + .event(event::mock().at_level(Level::INFO)) + .done() + .run_with_handle(); + + let subscriber = tracing_subscriber::registry().with(expect.with_filter(filter)); + assert!(subscriber.max_level_hint().is_none()); + + let _subscriber = subscriber.set_default(); + + fn events() { + tracing::trace!("hello trace"); + tracing::debug!("hello debug"); + tracing::info!("hello info"); + tracing::warn!("hello warn"); + tracing::error!("hello error"); + } + + events(); + { + let lock = seen2.lock().unwrap(); + for (callsite, &count) in lock.iter() { + assert_eq!( + count, 1, + "callsite {:?} should have been seen 1 time (after first set of events)", + callsite + ); + } + } + + events(); + { + let lock = seen2.lock().unwrap(); + for (callsite, &count) in lock.iter() { + assert_eq!( + count, 1, + "callsite {:?} should have been seen 1 time (after second set of events)", + callsite + ); + } + } + + handle.assert_finished(); +} diff --git a/vendor/tracing-subscriber/tests/layer_filters/boxed.rs b/vendor/tracing-subscriber/tests/layer_filters/boxed.rs new file mode 100644 index 000000000..0fe37188e --- /dev/null +++ b/vendor/tracing-subscriber/tests/layer_filters/boxed.rs @@ -0,0 +1,42 @@ +use super::*; +use tracing_subscriber::{filter, prelude::*, Layer}; + +fn layer() -> (ExpectLayer, subscriber::MockHandle) { + layer::mock().done().run_with_handle() +} + +fn filter<S>() -> filter::DynFilterFn<S> { + // Use dynamic filter fn to disable interest caching and max-level hints, + // allowing us to put all of these tests in the same file. + filter::dynamic_filter_fn(|_, _| false) +} + +/// reproduces https://github.com/tokio-rs/tracing/issues/1563#issuecomment-921363629 +#[test] +fn box_works() { + let (layer, handle) = layer(); + let layer = Box::new(layer.with_filter(filter())); + + let _guard = tracing_subscriber::registry().with(layer).set_default(); + + for i in 0..2 { + tracing::info!(i); + } + + handle.assert_finished(); +} + +/// the same as `box_works` but with a type-erased `Box`. +#[test] +fn dyn_box_works() { + let (layer, handle) = layer(); + let layer: Box<dyn Layer<_> + Send + Sync + 'static> = Box::new(layer.with_filter(filter())); + + let _guard = tracing_subscriber::registry().with(layer).set_default(); + + for i in 0..2 { + tracing::info!(i); + } + + handle.assert_finished(); +} diff --git a/vendor/tracing-subscriber/tests/layer_filters/combinators.rs b/vendor/tracing-subscriber/tests/layer_filters/combinators.rs new file mode 100644 index 000000000..6052a2d00 --- /dev/null +++ b/vendor/tracing-subscriber/tests/layer_filters/combinators.rs @@ -0,0 +1,42 @@ +use super::*; +use tracing_subscriber::{ + filter::{filter_fn, FilterExt, LevelFilter}, + prelude::*, +}; + +#[test] +fn and() { + let (layer, handle) = layer::mock() + .event( + event::msg("a very interesting event") + .at_level(tracing::Level::INFO) + .with_target("interesting_target"), + ) + .done() + .run_with_handle(); + + // Enables spans and events with targets starting with `interesting_target`: + let target_filter = filter::filter_fn(|meta| meta.target().starts_with("interesting_target")); + + // Enables spans and events with levels `INFO` and below: + let level_filter = LevelFilter::INFO; + + // Combine the two filters together, returning a filter that only enables + // spans and events that *both* filters will enable: + let filter = target_filter.and(level_filter); + + let _subscriber = tracing_subscriber::registry() + .with(layer.with_filter(filter)) + .set_default(); + + // This event will *not* be enabled: + tracing::info!("an event with an uninteresting target"); + + // This event *will* be enabled: + tracing::info!(target: "interesting_target", "a very interesting event"); + + // This event will *not* be enabled: + tracing::debug!(target: "interesting_target", "interesting debug event..."); + + handle.assert_finished(); +} diff --git a/vendor/tracing-subscriber/tests/layer_filters/downcast_raw.rs b/vendor/tracing-subscriber/tests/layer_filters/downcast_raw.rs new file mode 100644 index 000000000..b5f7e35ce --- /dev/null +++ b/vendor/tracing-subscriber/tests/layer_filters/downcast_raw.rs @@ -0,0 +1,68 @@ +use tracing::Subscriber; +use tracing_subscriber::filter::Targets; +use tracing_subscriber::prelude::*; +use tracing_subscriber::Layer; + +#[test] +fn downcast_ref_to_inner_layer_and_filter() { + // Test that a filtered layer gives downcast_ref access to + // both the layer and the filter. + + struct WrappedLayer; + + impl<S> Layer<S> for WrappedLayer + where + S: Subscriber, + S: for<'lookup> tracing_subscriber::registry::LookupSpan<'lookup>, + { + } + + let layer = WrappedLayer; + let filter = Targets::new().with_default(tracing::Level::INFO); + let registry = tracing_subscriber::registry().with(layer.with_filter(filter)); + let dispatch = tracing::dispatcher::Dispatch::new(registry); + + // The filter is available + assert!(dispatch.downcast_ref::<Targets>().is_some()); + // The wrapped layer is available + assert!(dispatch.downcast_ref::<WrappedLayer>().is_some()); +} + +#[test] +fn forward_downcast_raw_to_layer() { + // Test that a filtered layer still gives its wrapped layer a chance to + // return a custom struct from downcast_raw. + // https://github.com/tokio-rs/tracing/issues/1618 + + struct WrappedLayer { + with_context: WithContext, + } + + struct WithContext; + + impl<S> Layer<S> for WrappedLayer + where + S: Subscriber, + S: for<'lookup> tracing_subscriber::registry::LookupSpan<'lookup>, + { + unsafe fn downcast_raw(&self, id: std::any::TypeId) -> Option<*const ()> { + match id { + id if id == std::any::TypeId::of::<Self>() => Some(self as *const _ as *const ()), + id if id == std::any::TypeId::of::<WithContext>() => { + Some(&self.with_context as *const _ as *const ()) + } + _ => None, + } + } + } + + let layer = WrappedLayer { + with_context: WithContext, + }; + let filter = Targets::new().with_default(tracing::Level::INFO); + let registry = tracing_subscriber::registry().with(layer.with_filter(filter)); + let dispatch = tracing::dispatcher::Dispatch::new(registry); + + // Types from a custom implementation of `downcast_raw` are available + assert!(dispatch.downcast_ref::<WithContext>().is_some()); +} diff --git a/vendor/tracing-subscriber/tests/layer_filters/filter_scopes.rs b/vendor/tracing-subscriber/tests/layer_filters/filter_scopes.rs new file mode 100644 index 000000000..7fd7d843b --- /dev/null +++ b/vendor/tracing-subscriber/tests/layer_filters/filter_scopes.rs @@ -0,0 +1,131 @@ +use super::*; + +#[test] +fn filters_span_scopes() { + let (debug_layer, debug_handle) = layer::named("debug") + .enter(span::mock().at_level(Level::DEBUG)) + .enter(span::mock().at_level(Level::INFO)) + .enter(span::mock().at_level(Level::WARN)) + .enter(span::mock().at_level(Level::ERROR)) + .event(event::msg("hello world").in_scope(vec![ + span::mock().at_level(Level::ERROR), + span::mock().at_level(Level::WARN), + span::mock().at_level(Level::INFO), + span::mock().at_level(Level::DEBUG), + ])) + .exit(span::mock().at_level(Level::ERROR)) + .exit(span::mock().at_level(Level::WARN)) + .exit(span::mock().at_level(Level::INFO)) + .exit(span::mock().at_level(Level::DEBUG)) + .done() + .run_with_handle(); + let (info_layer, info_handle) = layer::named("info") + .enter(span::mock().at_level(Level::INFO)) + .enter(span::mock().at_level(Level::WARN)) + .enter(span::mock().at_level(Level::ERROR)) + .event(event::msg("hello world").in_scope(vec![ + span::mock().at_level(Level::ERROR), + span::mock().at_level(Level::WARN), + span::mock().at_level(Level::INFO), + ])) + .exit(span::mock().at_level(Level::ERROR)) + .exit(span::mock().at_level(Level::WARN)) + .exit(span::mock().at_level(Level::INFO)) + .done() + .run_with_handle(); + let (warn_layer, warn_handle) = layer::named("warn") + .enter(span::mock().at_level(Level::WARN)) + .enter(span::mock().at_level(Level::ERROR)) + .event(event::msg("hello world").in_scope(vec![ + span::mock().at_level(Level::ERROR), + span::mock().at_level(Level::WARN), + ])) + .exit(span::mock().at_level(Level::ERROR)) + .exit(span::mock().at_level(Level::WARN)) + .done() + .run_with_handle(); + + let _subscriber = tracing_subscriber::registry() + .with(debug_layer.with_filter(LevelFilter::DEBUG)) + .with(info_layer.with_filter(LevelFilter::INFO)) + .with(warn_layer.with_filter(LevelFilter::WARN)) + .set_default(); + + { + let _trace = tracing::trace_span!("my_span").entered(); + let _debug = tracing::debug_span!("my_span").entered(); + let _info = tracing::info_span!("my_span").entered(); + let _warn = tracing::warn_span!("my_span").entered(); + let _error = tracing::error_span!("my_span").entered(); + tracing::error!("hello world"); + } + + debug_handle.assert_finished(); + info_handle.assert_finished(); + warn_handle.assert_finished(); +} + +#[test] +fn filters_interleaved_span_scopes() { + fn target_layer(target: &'static str) -> (ExpectLayer, subscriber::MockHandle) { + layer::named(format!("target_{}", target)) + .enter(span::mock().with_target(target)) + .enter(span::mock().with_target(target)) + .event(event::msg("hello world").in_scope(vec![ + span::mock().with_target(target), + span::mock().with_target(target), + ])) + .event( + event::msg("hello to my target") + .in_scope(vec![ + span::mock().with_target(target), + span::mock().with_target(target), + ]) + .with_target(target), + ) + .exit(span::mock().with_target(target)) + .exit(span::mock().with_target(target)) + .done() + .run_with_handle() + } + + let (a_layer, a_handle) = target_layer("a"); + let (b_layer, b_handle) = target_layer("b"); + let (all_layer, all_handle) = layer::named("all") + .enter(span::mock().with_target("b")) + .enter(span::mock().with_target("a")) + .event(event::msg("hello world").in_scope(vec![ + span::mock().with_target("a"), + span::mock().with_target("b"), + ])) + .exit(span::mock().with_target("a")) + .exit(span::mock().with_target("b")) + .done() + .run_with_handle(); + + let _subscriber = tracing_subscriber::registry() + .with(all_layer.with_filter(LevelFilter::INFO)) + .with(a_layer.with_filter(filter::filter_fn(|meta| { + let target = meta.target(); + target == "a" || target == module_path!() + }))) + .with(b_layer.with_filter(filter::filter_fn(|meta| { + let target = meta.target(); + target == "b" || target == module_path!() + }))) + .set_default(); + + { + let _a1 = tracing::trace_span!(target: "a", "a/trace").entered(); + let _b1 = tracing::info_span!(target: "b", "b/info").entered(); + let _a2 = tracing::info_span!(target: "a", "a/info").entered(); + let _b2 = tracing::trace_span!(target: "b", "b/trace").entered(); + tracing::info!("hello world"); + tracing::debug!(target: "a", "hello to my target"); + tracing::debug!(target: "b", "hello to my target"); + } + + a_handle.assert_finished(); + b_handle.assert_finished(); + all_handle.assert_finished(); +} diff --git a/vendor/tracing-subscriber/tests/layer_filters/main.rs b/vendor/tracing-subscriber/tests/layer_filters/main.rs new file mode 100644 index 000000000..0233f063b --- /dev/null +++ b/vendor/tracing-subscriber/tests/layer_filters/main.rs @@ -0,0 +1,189 @@ +#![cfg(feature = "registry")] +#[path = "../support.rs"] +mod support; +use self::support::*; +mod boxed; +mod downcast_raw; +mod filter_scopes; +mod targets; +mod trees; +mod vec; + +use tracing::{level_filters::LevelFilter, Level}; +use tracing_subscriber::{filter, prelude::*, Layer}; + +#[test] +fn basic_layer_filters() { + let (trace_layer, trace_handle) = layer::named("trace") + .event(event::mock().at_level(Level::TRACE)) + .event(event::mock().at_level(Level::DEBUG)) + .event(event::mock().at_level(Level::INFO)) + .done() + .run_with_handle(); + + let (debug_layer, debug_handle) = layer::named("debug") + .event(event::mock().at_level(Level::DEBUG)) + .event(event::mock().at_level(Level::INFO)) + .done() + .run_with_handle(); + + let (info_layer, info_handle) = layer::named("info") + .event(event::mock().at_level(Level::INFO)) + .done() + .run_with_handle(); + + let _subscriber = tracing_subscriber::registry() + .with(trace_layer.with_filter(LevelFilter::TRACE)) + .with(debug_layer.with_filter(LevelFilter::DEBUG)) + .with(info_layer.with_filter(LevelFilter::INFO)) + .set_default(); + + tracing::trace!("hello trace"); + tracing::debug!("hello debug"); + tracing::info!("hello info"); + + trace_handle.assert_finished(); + debug_handle.assert_finished(); + info_handle.assert_finished(); +} + +#[test] +fn basic_layer_filters_spans() { + let (trace_layer, trace_handle) = layer::named("trace") + .new_span(span::mock().at_level(Level::TRACE)) + .new_span(span::mock().at_level(Level::DEBUG)) + .new_span(span::mock().at_level(Level::INFO)) + .done() + .run_with_handle(); + + let (debug_layer, debug_handle) = layer::named("debug") + .new_span(span::mock().at_level(Level::DEBUG)) + .new_span(span::mock().at_level(Level::INFO)) + .done() + .run_with_handle(); + + let (info_layer, info_handle) = layer::named("info") + .new_span(span::mock().at_level(Level::INFO)) + .done() + .run_with_handle(); + + let _subscriber = tracing_subscriber::registry() + .with(trace_layer.with_filter(LevelFilter::TRACE)) + .with(debug_layer.with_filter(LevelFilter::DEBUG)) + .with(info_layer.with_filter(LevelFilter::INFO)) + .set_default(); + + tracing::trace_span!("hello trace"); + tracing::debug_span!("hello debug"); + tracing::info_span!("hello info"); + + trace_handle.assert_finished(); + debug_handle.assert_finished(); + info_handle.assert_finished(); +} + +#[test] +fn global_filters_layers_still_work() { + let (expect, handle) = layer::mock() + .event(event::mock().at_level(Level::INFO)) + .event(event::mock().at_level(Level::WARN)) + .event(event::mock().at_level(Level::ERROR)) + .done() + .run_with_handle(); + + let _subscriber = tracing_subscriber::registry() + .with(expect) + .with(LevelFilter::INFO) + .set_default(); + + tracing::trace!("hello trace"); + tracing::debug!("hello debug"); + tracing::info!("hello info"); + tracing::warn!("hello warn"); + tracing::error!("hello error"); + + handle.assert_finished(); +} + +#[test] +fn global_filter_interests_are_cached() { + let (expect, handle) = layer::mock() + .event(event::mock().at_level(Level::WARN)) + .event(event::mock().at_level(Level::ERROR)) + .done() + .run_with_handle(); + + let _subscriber = tracing_subscriber::registry() + .with(expect.with_filter(filter::filter_fn(|meta| { + assert!( + meta.level() <= &Level::INFO, + "enabled should not be called for callsites disabled by the global filter" + ); + meta.level() <= &Level::WARN + }))) + .with(LevelFilter::INFO) + .set_default(); + + tracing::trace!("hello trace"); + tracing::debug!("hello debug"); + tracing::info!("hello info"); + tracing::warn!("hello warn"); + tracing::error!("hello error"); + + handle.assert_finished(); +} + +#[test] +fn global_filters_affect_layer_filters() { + let (expect, handle) = layer::named("debug") + .event(event::mock().at_level(Level::INFO)) + .event(event::mock().at_level(Level::WARN)) + .event(event::mock().at_level(Level::ERROR)) + .done() + .run_with_handle(); + + let _subscriber = tracing_subscriber::registry() + .with(expect.with_filter(LevelFilter::DEBUG)) + .with(LevelFilter::INFO) + .set_default(); + + tracing::trace!("hello trace"); + tracing::debug!("hello debug"); + tracing::info!("hello info"); + tracing::warn!("hello warn"); + tracing::error!("hello error"); + + handle.assert_finished(); +} + +#[test] +fn filter_fn() { + let (all, all_handle) = layer::named("all_targets") + .event(event::msg("hello foo")) + .event(event::msg("hello bar")) + .done() + .run_with_handle(); + + let (foo, foo_handle) = layer::named("foo_target") + .event(event::msg("hello foo")) + .done() + .run_with_handle(); + + let (bar, bar_handle) = layer::named("bar_target") + .event(event::msg("hello bar")) + .done() + .run_with_handle(); + + let _subscriber = tracing_subscriber::registry() + .with(all) + .with(foo.with_filter(filter::filter_fn(|meta| meta.target().starts_with("foo")))) + .with(bar.with_filter(filter::filter_fn(|meta| meta.target().starts_with("bar")))) + .set_default(); + + tracing::trace!(target: "foo", "hello foo"); + tracing::trace!(target: "bar", "hello bar"); + + foo_handle.assert_finished(); + bar_handle.assert_finished(); + all_handle.assert_finished(); +} diff --git a/vendor/tracing-subscriber/tests/layer_filters/targets.rs b/vendor/tracing-subscriber/tests/layer_filters/targets.rs new file mode 100644 index 000000000..c8133044b --- /dev/null +++ b/vendor/tracing-subscriber/tests/layer_filters/targets.rs @@ -0,0 +1,59 @@ +use super::*; +use tracing_subscriber::{ + filter::{filter_fn, Targets}, + prelude::*, +}; + +#[test] +#[cfg_attr(not(feature = "tracing-log"), ignore)] +fn log_events() { + // Reproduces https://github.com/tokio-rs/tracing/issues/1563 + mod inner { + pub(super) const MODULE_PATH: &str = module_path!(); + + #[tracing::instrument] + pub(super) fn logs() { + log::debug!("inner"); + } + } + + let filter = Targets::new() + .with_default(LevelFilter::DEBUG) + .with_target(inner::MODULE_PATH, LevelFilter::WARN); + + let layer = + tracing_subscriber::layer::Identity::new().with_filter(filter_fn(move |_meta| true)); + + let _guard = tracing_subscriber::registry() + .with(filter) + .with(layer) + .set_default(); + + inner::logs(); +} + +#[test] +fn inner_layer_short_circuits() { + // This test ensures that when a global filter short-circuits `Interest` + // evaluation, we aren't left with a "dirty" per-layer filter state. + + let (layer, handle) = layer::mock() + .event(event::msg("hello world")) + .done() + .run_with_handle(); + + let filter = Targets::new().with_target("magic_target", LevelFilter::DEBUG); + + let _guard = tracing_subscriber::registry() + // Note: we don't just use a `LevelFilter` for the global filter here, + // because it will just return a max level filter, and the chain of + // `register_callsite` calls that would trigger the bug never happens... + .with(filter::filter_fn(|meta| meta.level() <= &Level::INFO)) + .with(layer.with_filter(filter)) + .set_default(); + + tracing::debug!("skip me please!"); + tracing::info!(target: "magic_target", "hello world"); + + handle.assert_finished(); +} diff --git a/vendor/tracing-subscriber/tests/layer_filters/trees.rs b/vendor/tracing-subscriber/tests/layer_filters/trees.rs new file mode 100644 index 000000000..18cdd8ccc --- /dev/null +++ b/vendor/tracing-subscriber/tests/layer_filters/trees.rs @@ -0,0 +1,146 @@ +use super::*; + +#[test] +fn basic_trees() { + let (with_target, with_target_handle) = layer::named("info_with_target") + .event(event::mock().at_level(Level::INFO).with_target("my_target")) + .done() + .run_with_handle(); + + let (info, info_handle) = layer::named("info") + .event( + event::mock() + .at_level(Level::INFO) + .with_target(module_path!()), + ) + .event(event::mock().at_level(Level::INFO).with_target("my_target")) + .done() + .run_with_handle(); + + let (all, all_handle) = layer::named("all") + .event( + event::mock() + .at_level(Level::INFO) + .with_target(module_path!()), + ) + .event(event::mock().at_level(Level::TRACE)) + .event(event::mock().at_level(Level::INFO).with_target("my_target")) + .event( + event::mock() + .at_level(Level::TRACE) + .with_target("my_target"), + ) + .done() + .run_with_handle(); + + let info_tree = info + .and_then( + with_target.with_filter(filter::filter_fn(|meta| dbg!(meta.target()) == "my_target")), + ) + .with_filter(LevelFilter::INFO); + + let subscriber = tracing_subscriber::registry().with(info_tree).with(all); + let _guard = dbg!(subscriber).set_default(); + + tracing::info!("hello world"); + tracing::trace!("hello trace"); + tracing::info!(target: "my_target", "hi to my target"); + tracing::trace!(target: "my_target", "hi to my target at trace"); + + all_handle.assert_finished(); + info_handle.assert_finished(); + with_target_handle.assert_finished(); +} + +#[test] +fn filter_span_scopes() { + fn target_layer(target: &'static str) -> (ExpectLayer, subscriber::MockHandle) { + layer::named(format!("target_{}", target)) + .enter(span::mock().with_target(target).at_level(Level::INFO)) + .event( + event::msg("hello world") + .in_scope(vec![span::mock().with_target(target).at_level(Level::INFO)]), + ) + .exit(span::mock().with_target(target).at_level(Level::INFO)) + .done() + .run_with_handle() + } + + let (a_layer, a_handle) = target_layer("a"); + let (b_layer, b_handle) = target_layer("b"); + let (info_layer, info_handle) = layer::named("info") + .enter(span::mock().with_target("b").at_level(Level::INFO)) + .enter(span::mock().with_target("a").at_level(Level::INFO)) + .event(event::msg("hello world").in_scope(vec![ + span::mock().with_target("a").at_level(Level::INFO), + span::mock().with_target("b").at_level(Level::INFO), + ])) + .exit(span::mock().with_target("a").at_level(Level::INFO)) + .exit(span::mock().with_target("b").at_level(Level::INFO)) + .done() + .run_with_handle(); + + let full_scope = vec![ + span::mock().with_target("b").at_level(Level::TRACE), + span::mock().with_target("a").at_level(Level::INFO), + span::mock().with_target("b").at_level(Level::INFO), + span::mock().with_target("a").at_level(Level::TRACE), + ]; + let (all_layer, all_handle) = layer::named("all") + .enter(span::mock().with_target("a").at_level(Level::TRACE)) + .enter(span::mock().with_target("b").at_level(Level::INFO)) + .enter(span::mock().with_target("a").at_level(Level::INFO)) + .enter(span::mock().with_target("b").at_level(Level::TRACE)) + .event(event::msg("hello world").in_scope(full_scope.clone())) + .event( + event::msg("hello to my target") + .with_target("a") + .in_scope(full_scope.clone()), + ) + .event( + event::msg("hello to my target") + .with_target("b") + .in_scope(full_scope), + ) + .exit(span::mock().with_target("b").at_level(Level::TRACE)) + .exit(span::mock().with_target("a").at_level(Level::INFO)) + .exit(span::mock().with_target("b").at_level(Level::INFO)) + .exit(span::mock().with_target("a").at_level(Level::TRACE)) + .done() + .run_with_handle(); + + let a_layer = a_layer.with_filter(filter::filter_fn(|meta| { + let target = meta.target(); + target == "a" || target == module_path!() + })); + + let b_layer = b_layer.with_filter(filter::filter_fn(|meta| { + let target = meta.target(); + target == "b" || target == module_path!() + })); + + let info_tree = info_layer + .and_then(a_layer) + .and_then(b_layer) + .with_filter(LevelFilter::INFO); + + let subscriber = tracing_subscriber::registry() + .with(info_tree) + .with(all_layer); + let _guard = dbg!(subscriber).set_default(); + + { + let _a1 = tracing::trace_span!(target: "a", "a/trace").entered(); + let _b1 = tracing::info_span!(target: "b", "b/info").entered(); + let _a2 = tracing::info_span!(target: "a", "a/info").entered(); + let _b2 = tracing::trace_span!(target: "b", "b/trace").entered(); + tracing::info!("hello world"); + tracing::debug!(target: "a", "hello to my target"); + tracing::debug!(target: "b", "hello to my target"); + } + + all_handle.assert_finished(); + info_handle.assert_finished(); + a_handle.assert_finished(); + b_handle.assert_finished(); +} diff --git a/vendor/tracing-subscriber/tests/layer_filters/vec.rs b/vendor/tracing-subscriber/tests/layer_filters/vec.rs new file mode 100644 index 000000000..87244e4ab --- /dev/null +++ b/vendor/tracing-subscriber/tests/layer_filters/vec.rs @@ -0,0 +1,120 @@ +use super::*; +use tracing::Subscriber; + +#[test] +fn with_filters_unboxed() { + let (trace_layer, trace_handle) = layer::named("trace") + .event(event::mock().at_level(Level::TRACE)) + .event(event::mock().at_level(Level::DEBUG)) + .event(event::mock().at_level(Level::INFO)) + .done() + .run_with_handle(); + let trace_layer = trace_layer.with_filter(LevelFilter::TRACE); + + let (debug_layer, debug_handle) = layer::named("debug") + .event(event::mock().at_level(Level::DEBUG)) + .event(event::mock().at_level(Level::INFO)) + .done() + .run_with_handle(); + let debug_layer = debug_layer.with_filter(LevelFilter::DEBUG); + + let (info_layer, info_handle) = layer::named("info") + .event(event::mock().at_level(Level::INFO)) + .done() + .run_with_handle(); + let info_layer = info_layer.with_filter(LevelFilter::INFO); + + let _subscriber = tracing_subscriber::registry() + .with(vec![trace_layer, debug_layer, info_layer]) + .set_default(); + + tracing::trace!("hello trace"); + tracing::debug!("hello debug"); + tracing::info!("hello info"); + + trace_handle.assert_finished(); + debug_handle.assert_finished(); + info_handle.assert_finished(); +} + +#[test] +fn with_filters_boxed() { + let (unfiltered_layer, unfiltered_handle) = layer::named("unfiltered") + .event(event::mock().at_level(Level::TRACE)) + .event(event::mock().at_level(Level::DEBUG)) + .event(event::mock().at_level(Level::INFO)) + .done() + .run_with_handle(); + let unfiltered_layer = unfiltered_layer.boxed(); + + let (debug_layer, debug_handle) = layer::named("debug") + .event(event::mock().at_level(Level::DEBUG)) + .event(event::mock().at_level(Level::INFO)) + .done() + .run_with_handle(); + let debug_layer = debug_layer.with_filter(LevelFilter::DEBUG).boxed(); + + let (target_layer, target_handle) = layer::named("target") + .event(event::mock().at_level(Level::INFO)) + .done() + .run_with_handle(); + let target_layer = target_layer + .with_filter(filter::filter_fn(|meta| meta.target() == "my_target")) + .boxed(); + + let _subscriber = tracing_subscriber::registry() + .with(vec![unfiltered_layer, debug_layer, target_layer]) + .set_default(); + + tracing::trace!("hello trace"); + tracing::debug!("hello debug"); + tracing::info!(target: "my_target", "hello my target"); + + unfiltered_handle.assert_finished(); + debug_handle.assert_finished(); + target_handle.assert_finished(); +} + +#[test] +fn mixed_max_level_hint() { + let unfiltered = layer::named("unfiltered").run().boxed(); + let info = layer::named("info") + .run() + .with_filter(LevelFilter::INFO) + .boxed(); + let debug = layer::named("debug") + .run() + .with_filter(LevelFilter::DEBUG) + .boxed(); + + let subscriber = tracing_subscriber::registry().with(vec![unfiltered, info, debug]); + + assert_eq!(subscriber.max_level_hint(), None); +} + +#[test] +fn all_filtered_max_level_hint() { + let warn = layer::named("warn") + .run() + .with_filter(LevelFilter::WARN) + .boxed(); + let info = layer::named("info") + .run() + .with_filter(LevelFilter::INFO) + .boxed(); + let debug = layer::named("debug") + .run() + .with_filter(LevelFilter::DEBUG) + .boxed(); + + let subscriber = tracing_subscriber::registry().with(vec![warn, info, debug]); + + assert_eq!(subscriber.max_level_hint(), Some(LevelFilter::DEBUG)); +} + +#[test] +fn empty_vec() { + // Just a None means everything is off + let subscriber = tracing_subscriber::registry().with(Vec::<ExpectLayer>::new()); + assert_eq!(subscriber.max_level_hint(), Some(LevelFilter::OFF)); +} diff --git a/vendor/tracing-subscriber/tests/multiple_layer_filter_interests_cached.rs b/vendor/tracing-subscriber/tests/multiple_layer_filter_interests_cached.rs new file mode 100644 index 000000000..5c25e7f03 --- /dev/null +++ b/vendor/tracing-subscriber/tests/multiple_layer_filter_interests_cached.rs @@ -0,0 +1,131 @@ +#![cfg(feature = "registry")] +mod support; +use self::support::*; + +use std::{ + collections::HashMap, + sync::{Arc, Mutex}, +}; +use tracing::{Level, Subscriber}; +use tracing_subscriber::{filter, prelude::*}; + +#[test] +fn multiple_layer_filter_interests_are_cached() { + // This layer will return Interest::always for INFO and lower. + let seen_info = Arc::new(Mutex::new(HashMap::new())); + let seen_info2 = seen_info.clone(); + let filter = filter::filter_fn(move |meta| { + *seen_info + .lock() + .unwrap() + .entry(*meta.level()) + .or_insert(0usize) += 1; + meta.level() <= &Level::INFO + }); + let seen_info = seen_info2; + + let (info_layer, info_handle) = layer::named("info") + .event(event::mock().at_level(Level::INFO)) + .event(event::mock().at_level(Level::WARN)) + .event(event::mock().at_level(Level::ERROR)) + .event(event::mock().at_level(Level::INFO)) + .event(event::mock().at_level(Level::WARN)) + .event(event::mock().at_level(Level::ERROR)) + .done() + .run_with_handle(); + let info_layer = info_layer.with_filter(filter); + + // This layer will return Interest::always for WARN and lower. + let seen_warn = Arc::new(Mutex::new(HashMap::new())); + let seen_warn2 = seen_warn.clone(); + let filter = filter::filter_fn(move |meta| { + *seen_warn + .lock() + .unwrap() + .entry(*meta.level()) + .or_insert(0usize) += 1; + meta.level() <= &Level::WARN + }); + let seen_warn = seen_warn2; + + let (warn_layer, warn_handle) = layer::named("warn") + .event(event::mock().at_level(Level::WARN)) + .event(event::mock().at_level(Level::ERROR)) + .event(event::mock().at_level(Level::WARN)) + .event(event::mock().at_level(Level::ERROR)) + .done() + .run_with_handle(); + let warn_layer = warn_layer.with_filter(filter); + + let subscriber = tracing_subscriber::registry() + .with(warn_layer) + .with(info_layer); + assert!(subscriber.max_level_hint().is_none()); + + let _subscriber = subscriber.set_default(); + + fn events() { + tracing::trace!("hello trace"); + tracing::debug!("hello debug"); + tracing::info!("hello info"); + tracing::warn!("hello warn"); + tracing::error!("hello error"); + } + + events(); + { + let lock = seen_info.lock().unwrap(); + for (&level, &count) in lock.iter() { + if level == Level::INFO { + continue; + } + assert_eq!( + count, 1, + "level {:?} should have been seen 1 time by the INFO layer (after first set of events)", + level + ); + } + + let lock = seen_warn.lock().unwrap(); + for (&level, &count) in lock.iter() { + if level == Level::INFO { + continue; + } + assert_eq!( + count, 1, + "level {:?} should have been seen 1 time by the WARN layer (after first set of events)", + level + ); + } + } + + events(); + { + let lock = seen_info.lock().unwrap(); + for (&level, &count) in lock.iter() { + if level == Level::INFO { + continue; + } + assert_eq!( + count, 1, + "level {:?} should have been seen 1 time by the INFO layer (after second set of events)", + level + ); + } + + let lock = seen_warn.lock().unwrap(); + for (&level, &count) in lock.iter() { + if level == Level::INFO { + continue; + } + assert_eq!( + count, 1, + "level {:?} should have been seen 1 time by the WARN layer (after second set of events)", + level + ); + } + } + + info_handle.assert_finished(); + warn_handle.assert_finished(); +} diff --git a/vendor/tracing-subscriber/tests/option.rs b/vendor/tracing-subscriber/tests/option.rs new file mode 100644 index 000000000..738cc0a6c --- /dev/null +++ b/vendor/tracing-subscriber/tests/option.rs @@ -0,0 +1,41 @@ +#![cfg(feature = "registry")] +use tracing::level_filters::LevelFilter; +use tracing::Subscriber; +use tracing_subscriber::prelude::*; + +// This test is just used to compare to the tests below +#[test] +fn just_layer() { + let subscriber = tracing_subscriber::registry().with(LevelFilter::INFO); + assert_eq!(subscriber.max_level_hint(), Some(LevelFilter::INFO)); +} + +#[test] +fn subscriber_and_option_some_layer() { + let subscriber = tracing_subscriber::registry() + .with(LevelFilter::INFO) + .with(Some(LevelFilter::DEBUG)); + assert_eq!(subscriber.max_level_hint(), Some(LevelFilter::DEBUG)); +} + +#[test] +fn subscriber_and_option_none_layer() { + // None means the other layer takes control + let subscriber = tracing_subscriber::registry() + .with(LevelFilter::ERROR) + .with(None::<LevelFilter>); + assert_eq!(subscriber.max_level_hint(), Some(LevelFilter::ERROR)); +} + +#[test] +fn just_option_some_layer() { + // Just a None means everything is off + let subscriber = tracing_subscriber::registry().with(None::<LevelFilter>); + assert_eq!(subscriber.max_level_hint(), Some(LevelFilter::OFF)); +} + +#[test] +fn just_option_none_layer() { + let subscriber = tracing_subscriber::registry().with(Some(LevelFilter::ERROR)); + assert_eq!(subscriber.max_level_hint(), Some(LevelFilter::ERROR)); +} diff --git a/vendor/tracing-subscriber/tests/registry_max_level_hint.rs b/vendor/tracing-subscriber/tests/registry_max_level_hint.rs new file mode 100644 index 000000000..f94c8a1fb --- /dev/null +++ b/vendor/tracing-subscriber/tests/registry_max_level_hint.rs @@ -0,0 +1,11 @@ +#![cfg(all(feature = "registry", feature = "fmt"))] +use tracing_subscriber::{filter::LevelFilter, prelude::*}; + +#[test] +fn registry_sets_max_level_hint() { + tracing_subscriber::registry() + .with(tracing_subscriber::fmt::layer()) + .with(LevelFilter::DEBUG) + .init(); + assert_eq!(LevelFilter::current(), LevelFilter::DEBUG); +} diff --git a/vendor/tracing-subscriber/tests/registry_with_subscriber.rs b/vendor/tracing-subscriber/tests/registry_with_subscriber.rs new file mode 100644 index 000000000..50d2f551d --- /dev/null +++ b/vendor/tracing-subscriber/tests/registry_with_subscriber.rs @@ -0,0 +1,25 @@ +#![cfg(feature = "registry")] +use tracing_futures::{Instrument, WithSubscriber}; +use tracing_subscriber::prelude::*; + +#[tokio::test] +async fn future_with_subscriber() { + tracing_subscriber::registry().init(); + let span = tracing::info_span!("foo"); + let _e = span.enter(); + let span = tracing::info_span!("bar"); + let _e = span.enter(); + tokio::spawn( + async { + async { + let span = tracing::Span::current(); + println!("{:?}", span); + } + .instrument(tracing::info_span!("hi")) + .await + } + .with_subscriber(tracing_subscriber::registry()), + ) + .await + .unwrap(); +} diff --git a/vendor/tracing-subscriber/tests/reload.rs b/vendor/tracing-subscriber/tests/reload.rs new file mode 100644 index 000000000..b8b6c2b46 --- /dev/null +++ b/vendor/tracing-subscriber/tests/reload.rs @@ -0,0 +1,141 @@ +#![cfg(feature = "std")] +use std::sync::atomic::{AtomicUsize, Ordering}; +use tracing_core::{ + span::{Attributes, Id, Record}, + subscriber::Interest, + Event, Metadata, Subscriber, +}; +use tracing_subscriber::{layer, prelude::*, reload::*}; + +pub struct NopSubscriber; + +impl Subscriber for NopSubscriber { + fn register_callsite(&self, _: &'static Metadata<'static>) -> Interest { + Interest::never() + } + + fn enabled(&self, _: &Metadata<'_>) -> bool { + false + } + + fn new_span(&self, _: &Attributes<'_>) -> Id { + Id::from_u64(1) + } + + fn record(&self, _: &Id, _: &Record<'_>) {} + fn record_follows_from(&self, _: &Id, _: &Id) {} + fn event(&self, _: &Event<'_>) {} + fn enter(&self, _: &Id) {} + fn exit(&self, _: &Id) {} +} + +#[test] +fn reload_handle() { + static FILTER1_CALLS: AtomicUsize = AtomicUsize::new(0); + static FILTER2_CALLS: AtomicUsize = AtomicUsize::new(0); + + enum Filter { + One, + Two, + } + + impl<S: Subscriber> tracing_subscriber::Layer<S> for Filter { + fn register_callsite(&self, m: &Metadata<'_>) -> Interest { + println!("REGISTER: {:?}", m); + Interest::sometimes() + } + + fn enabled(&self, m: &Metadata<'_>, _: layer::Context<'_, S>) -> bool { + println!("ENABLED: {:?}", m); + match self { + Filter::One => FILTER1_CALLS.fetch_add(1, Ordering::SeqCst), + Filter::Two => FILTER2_CALLS.fetch_add(1, Ordering::SeqCst), + }; + true + } + } + fn event() { + tracing::trace!("my event"); + } + + let (layer, handle) = Layer::new(Filter::One); + + let subscriber = tracing_core::dispatcher::Dispatch::new(layer.with_subscriber(NopSubscriber)); + + tracing_core::dispatcher::with_default(&subscriber, || { + assert_eq!(FILTER1_CALLS.load(Ordering::SeqCst), 0); + assert_eq!(FILTER2_CALLS.load(Ordering::SeqCst), 0); + + event(); + + assert_eq!(FILTER1_CALLS.load(Ordering::SeqCst), 1); + assert_eq!(FILTER2_CALLS.load(Ordering::SeqCst), 0); + + handle.reload(Filter::Two).expect("should reload"); + + event(); + + assert_eq!(FILTER1_CALLS.load(Ordering::SeqCst), 1); + assert_eq!(FILTER2_CALLS.load(Ordering::SeqCst), 1); + }) +} + +#[test] +#[cfg(feature = "registry")] +fn reload_filter() { + struct NopLayer; + impl<S: Subscriber> tracing_subscriber::Layer<S> for NopLayer { + fn register_callsite(&self, _m: &Metadata<'_>) -> Interest { + Interest::sometimes() + } + + fn enabled(&self, _m: &Metadata<'_>, _: layer::Context<'_, S>) -> bool { + true + } + } + + static FILTER1_CALLS: AtomicUsize = AtomicUsize::new(0); + static FILTER2_CALLS: AtomicUsize = AtomicUsize::new(0); + + enum Filter { + One, + Two, + } + + impl<S: Subscriber> tracing_subscriber::layer::Filter<S> for Filter { + fn enabled(&self, m: &Metadata<'_>, _: &layer::Context<'_, S>) -> bool { + println!("ENABLED: {:?}", m); + match self { + Filter::One => FILTER1_CALLS.fetch_add(1, Ordering::SeqCst), + Filter::Two => FILTER2_CALLS.fetch_add(1, Ordering::SeqCst), + }; + true + } + } + fn event() { + tracing::trace!("my event"); + } + + let (filter, handle) = Layer::new(Filter::One); + + let dispatcher = tracing_core::Dispatch::new( + tracing_subscriber::registry().with(NopLayer.with_filter(filter)), + ); + + tracing_core::dispatcher::with_default(&dispatcher, || { + assert_eq!(FILTER1_CALLS.load(Ordering::SeqCst), 0); + assert_eq!(FILTER2_CALLS.load(Ordering::SeqCst), 0); + + event(); + + assert_eq!(FILTER1_CALLS.load(Ordering::SeqCst), 1); + assert_eq!(FILTER2_CALLS.load(Ordering::SeqCst), 0); + + handle.reload(Filter::Two).expect("should reload"); + + event(); + + assert_eq!(FILTER1_CALLS.load(Ordering::SeqCst), 1); + assert_eq!(FILTER2_CALLS.load(Ordering::SeqCst), 1); + }) +} diff --git a/vendor/tracing-subscriber/tests/same_len_filters.rs b/vendor/tracing-subscriber/tests/same_len_filters.rs new file mode 100644 index 000000000..879e578d7 --- /dev/null +++ b/vendor/tracing-subscriber/tests/same_len_filters.rs @@ -0,0 +1,81 @@ +// These tests include field filters with no targets, so they have to go in a +// separate file. +#![cfg(feature = "env-filter")] + +use tracing::{self, subscriber::with_default, Level}; +use tracing_mock::*; +use tracing_subscriber::{filter::EnvFilter, prelude::*}; + +#[test] +fn same_length_targets() { + let filter: EnvFilter = "foo=trace,bar=trace".parse().expect("filter should parse"); + let (subscriber, finished) = subscriber::mock() + .event(event::mock().at_level(Level::TRACE)) + .event(event::mock().at_level(Level::TRACE)) + .done() + .run_with_handle(); + let subscriber = subscriber.with(filter); + + with_default(subscriber, || { + tracing::trace!(target: "foo", "foo"); + tracing::trace!(target: "bar", "bar"); + }); + + finished.assert_finished(); +} + +#[test] +fn same_num_fields_event() { + let filter: EnvFilter = "[{foo}]=trace,[{bar}]=trace" + .parse() + .expect("filter should parse"); + let (subscriber, finished) = subscriber::mock() + .event( + event::mock() + .at_level(Level::TRACE) + .with_fields(field::mock("foo")), + ) + .event( + event::mock() + .at_level(Level::TRACE) + .with_fields(field::mock("bar")), + ) + .done() + .run_with_handle(); + let subscriber = subscriber.with(filter); + with_default(subscriber, || { + tracing::trace!(foo = 1); + tracing::trace!(bar = 3); + }); + + finished.assert_finished(); +} + +#[test] +fn same_num_fields_and_name_len() { + let filter: EnvFilter = "[foo{bar=1}]=trace,[baz{boz=1}]=trace" + .parse() + .expect("filter should parse"); + let (subscriber, finished) = subscriber::mock() + .new_span( + span::mock() + .named("foo") + .at_level(Level::TRACE) + .with_field(field::mock("bar")), + ) + .new_span( + span::mock() + .named("baz") + .at_level(Level::TRACE) + .with_field(field::mock("boz")), + ) + .done() + .run_with_handle(); + let subscriber = subscriber.with(filter); + with_default(subscriber, || { + tracing::trace_span!("foo", bar = 1); + tracing::trace_span!("baz", boz = 1); + }); + + finished.assert_finished(); +} diff --git a/vendor/tracing-subscriber/tests/support.rs b/vendor/tracing-subscriber/tests/support.rs new file mode 100644 index 000000000..50e0e6669 --- /dev/null +++ b/vendor/tracing-subscriber/tests/support.rs @@ -0,0 +1,407 @@ +#![allow(missing_docs, dead_code)] +pub use tracing_mock::{event, field, span, subscriber}; + +use tracing_core::{ + span::{Attributes, Id, Record}, + Event, Subscriber, +}; +use tracing_mock::{ + event::MockEvent, + span::{MockSpan, NewSpan}, + subscriber::{Expect, MockHandle}, +}; +use tracing_subscriber::{ + layer::{Context, Layer}, + registry::{LookupSpan, SpanRef}, +}; + +use std::{ + collections::VecDeque, + fmt, + sync::{Arc, Mutex}, +}; + +pub mod layer { + use super::ExpectLayerBuilder; + + pub fn mock() -> ExpectLayerBuilder { + ExpectLayerBuilder { + expected: Default::default(), + name: std::thread::current() + .name() + .map(String::from) + .unwrap_or_default(), + } + } + + pub fn named(name: impl std::fmt::Display) -> ExpectLayerBuilder { + mock().named(name) + } +} + +pub struct ExpectLayerBuilder { + expected: VecDeque<Expect>, + name: String, +} + +pub struct ExpectLayer { + expected: Arc<Mutex<VecDeque<Expect>>>, + current: Mutex<Vec<Id>>, + name: String, +} + +impl ExpectLayerBuilder { + /// Overrides the name printed by the mock subscriber's debugging output. + /// + /// The debugging output is displayed if the test panics, or if the test is + /// run with `--nocapture`. + /// + /// By default, the mock subscriber's name is the name of the test + /// (*technically*, the name of the thread where it was created, which is + /// the name of the test unless tests are run with `--test-threads=1`). + /// When a test has only one mock subscriber, this is sufficient. However, + /// some tests may include multiple subscribers, in order to test + /// interactions between multiple subscribers. In that case, it can be + /// helpful to give each subscriber a separate name to distinguish where the + /// debugging output comes from. + pub fn named(mut self, name: impl fmt::Display) -> Self { + use std::fmt::Write; + if !self.name.is_empty() { + write!(&mut self.name, "::{}", name).unwrap(); + } else { + self.name = name.to_string(); + } + self + } + + pub fn enter(mut self, span: MockSpan) -> Self { + self.expected.push_back(Expect::Enter(span)); + self + } + + pub fn event(mut self, event: MockEvent) -> Self { + self.expected.push_back(Expect::Event(event)); + self + } + + pub fn exit(mut self, span: MockSpan) -> Self { + self.expected.push_back(Expect::Exit(span)); + self + } + + pub fn done(mut self) -> Self { + self.expected.push_back(Expect::Nothing); + self + } + + pub fn record<I>(mut self, span: MockSpan, fields: I) -> Self + where + I: Into<field::Expect>, + { + self.expected.push_back(Expect::Visit(span, fields.into())); + self + } + + pub fn new_span<I>(mut self, new_span: I) -> Self + where + I: Into<NewSpan>, + { + self.expected.push_back(Expect::NewSpan(new_span.into())); + self + } + + pub fn run(self) -> ExpectLayer { + ExpectLayer { + expected: Arc::new(Mutex::new(self.expected)), + name: self.name, + current: Mutex::new(Vec::new()), + } + } + + pub fn run_with_handle(self) -> (ExpectLayer, MockHandle) { + let expected = Arc::new(Mutex::new(self.expected)); + let handle = MockHandle::new(expected.clone(), self.name.clone()); + let layer = ExpectLayer { + expected, + name: self.name, + current: Mutex::new(Vec::new()), + }; + (layer, handle) + } +} + +impl ExpectLayer { + fn check_span_ref<'spans, S>( + &self, + expected: &MockSpan, + actual: &SpanRef<'spans, S>, + what_happened: impl fmt::Display, + ) where + S: LookupSpan<'spans>, + { + if let Some(exp_name) = expected.name() { + assert_eq!( + actual.name(), + exp_name, + "\n[{}] expected {} a span named {:?}\n\ + [{}] but it was named {:?} instead (span {} {:?})", + self.name, + what_happened, + exp_name, + self.name, + actual.name(), + actual.name(), + actual.id() + ); + } + + if let Some(exp_level) = expected.level() { + let actual_level = actual.metadata().level(); + assert_eq!( + actual_level, + &exp_level, + "\n[{}] expected {} a span at {:?}\n\ + [{}] but it was at {:?} instead (span {} {:?})", + self.name, + what_happened, + exp_level, + self.name, + actual_level, + actual.name(), + actual.id(), + ); + } + + if let Some(exp_target) = expected.target() { + let actual_target = actual.metadata().target(); + assert_eq!( + actual_target, + exp_target, + "\n[{}] expected {} a span with target {:?}\n\ + [{}] but it had the target {:?} instead (span {} {:?})", + self.name, + what_happened, + exp_target, + self.name, + actual_target, + actual.name(), + actual.id(), + ); + } + } +} + +impl<S> Layer<S> for ExpectLayer +where + S: Subscriber + for<'a> LookupSpan<'a>, +{ + fn register_callsite( + &self, + metadata: &'static tracing::Metadata<'static>, + ) -> tracing_core::Interest { + println!("[{}] register_callsite {:#?}", self.name, metadata); + tracing_core::Interest::always() + } + + fn on_record(&self, _: &Id, _: &Record<'_>, _: Context<'_, S>) { + unimplemented!( + "so far, we don't have any tests that need an `on_record` \ + implementation.\nif you just wrote one that does, feel free to \ + implement it!" + ); + } + + fn on_event(&self, event: &Event<'_>, cx: Context<'_, S>) { + let name = event.metadata().name(); + println!( + "[{}] event: {}; level: {}; target: {}", + self.name, + name, + event.metadata().level(), + event.metadata().target(), + ); + match self.expected.lock().unwrap().pop_front() { + None => {} + Some(Expect::Event(mut expected)) => { + let get_parent_name = || cx.event_span(event).map(|span| span.name().to_string()); + expected.check(event, get_parent_name, &self.name); + let mut current_scope = cx.event_scope(event).into_iter().flatten(); + let expected_scope = expected.scope_mut(); + let mut i = 0; + for (expected, actual) in expected_scope.iter_mut().zip(&mut current_scope) { + println!( + "[{}] event_scope[{}] actual={} ({:?}); expected={}", + self.name, + i, + actual.name(), + actual.id(), + expected + ); + self.check_span_ref( + expected, + &actual, + format_args!("the {}th span in the event's scope to be", i), + ); + i += 1; + } + let remaining_expected = &expected_scope[i..]; + assert!( + remaining_expected.is_empty(), + "\n[{}] did not observe all expected spans in event scope!\n[{}] missing: {:#?}", + self.name, + self.name, + remaining_expected, + ); + assert!( + current_scope.next().is_none(), + "\n[{}] did not expect all spans in the actual event scope!", + self.name, + ); + } + Some(ex) => ex.bad(&self.name, format_args!("observed event {:#?}", event)), + } + } + + fn on_follows_from(&self, _span: &Id, _follows: &Id, _: Context<'_, S>) { + // TODO: it should be possible to expect spans to follow from other spans + } + + fn on_new_span(&self, span: &Attributes<'_>, id: &Id, cx: Context<'_, S>) { + let meta = span.metadata(); + println!( + "[{}] new_span: name={:?}; target={:?}; id={:?};", + self.name, + meta.name(), + meta.target(), + id + ); + let mut expected = self.expected.lock().unwrap(); + let was_expected = matches!(expected.front(), Some(Expect::NewSpan(_))); + if was_expected { + if let Expect::NewSpan(mut expected) = expected.pop_front().unwrap() { + let get_parent_name = || { + span.parent() + .and_then(|id| cx.span(id)) + .or_else(|| cx.lookup_current()) + .map(|span| span.name().to_string()) + }; + expected.check(span, get_parent_name, &self.name); + } + } + } + + fn on_enter(&self, id: &Id, cx: Context<'_, S>) { + let span = cx + .span(id) + .unwrap_or_else(|| panic!("[{}] no span for ID {:?}", self.name, id)); + println!("[{}] enter: {}; id={:?};", self.name, span.name(), id); + match self.expected.lock().unwrap().pop_front() { + None => {} + Some(Expect::Enter(ref expected_span)) => { + self.check_span_ref(expected_span, &span, "to enter"); + } + Some(ex) => ex.bad(&self.name, format_args!("entered span {:?}", span.name())), + } + self.current.lock().unwrap().push(id.clone()); + } + + fn on_exit(&self, id: &Id, cx: Context<'_, S>) { + if std::thread::panicking() { + // `exit()` can be called in `drop` impls, so we must guard against + // double panics. + println!("[{}] exit {:?} while panicking", self.name, id); + return; + } + let span = cx + .span(id) + .unwrap_or_else(|| panic!("[{}] no span for ID {:?}", self.name, id)); + println!("[{}] exit: {}; id={:?};", self.name, span.name(), id); + match self.expected.lock().unwrap().pop_front() { + None => {} + Some(Expect::Exit(ref expected_span)) => { + self.check_span_ref(expected_span, &span, "to exit"); + let curr = self.current.lock().unwrap().pop(); + assert_eq!( + Some(id), + curr.as_ref(), + "[{}] exited span {:?}, but the current span was {:?}", + self.name, + span.name(), + curr.as_ref().and_then(|id| cx.span(id)).map(|s| s.name()) + ); + } + Some(ex) => ex.bad(&self.name, format_args!("exited span {:?}", span.name())), + }; + } + + fn on_close(&self, id: Id, cx: Context<'_, S>) { + if std::thread::panicking() { + // `try_close` can be called in `drop` impls, so we must guard against + // double panics. + println!("[{}] close {:?} while panicking", self.name, id); + return; + } + let span = cx.span(&id); + let name = span.as_ref().map(|span| { + println!("[{}] close_span: {}; id={:?};", self.name, span.name(), id,); + span.name() + }); + if name.is_none() { + println!("[{}] drop_span: id={:?}", self.name, id); + } + if let Ok(mut expected) = self.expected.try_lock() { + let was_expected = match expected.front() { + Some(Expect::DropSpan(ref expected_span)) => { + // Don't assert if this function was called while panicking, + // as failing the assertion can cause a double panic. + if !::std::thread::panicking() { + if let Some(ref span) = span { + self.check_span_ref(expected_span, span, "to close"); + } + } + true + } + Some(Expect::Event(_)) => { + if !::std::thread::panicking() { + panic!( + "[{}] expected an event, but dropped span {} (id={:?}) instead", + self.name, + name.unwrap_or("<unknown name>"), + id + ); + } + true + } + _ => false, + }; + if was_expected { + expected.pop_front(); + } + } + } + + fn on_id_change(&self, _old: &Id, _new: &Id, _ctx: Context<'_, S>) { + panic!("well-behaved subscribers should never do this to us, lol"); + } +} + +impl fmt::Debug for ExpectLayer { + fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { + let mut s = f.debug_struct("ExpectLayer"); + s.field("name", &self.name); + + if let Ok(expected) = self.expected.try_lock() { + s.field("expected", &expected); + } else { + s.field("expected", &format_args!("<locked>")); + } + + if let Ok(current) = self.current.try_lock() { + s.field("current", &format_args!("{:?}", ¤t)); + } else { + s.field("current", &format_args!("<locked>")); + } + + s.finish() + } +} diff --git a/vendor/tracing-subscriber/tests/unhinted_layer_filters_dont_break_other_layers.rs b/vendor/tracing-subscriber/tests/unhinted_layer_filters_dont_break_other_layers.rs new file mode 100644 index 000000000..9fa5c6bd4 --- /dev/null +++ b/vendor/tracing-subscriber/tests/unhinted_layer_filters_dont_break_other_layers.rs @@ -0,0 +1,123 @@ +#![cfg(feature = "registry")] +mod support; +use self::support::*; +use tracing::Level; +use tracing_subscriber::{filter::DynFilterFn, prelude::*}; + +#[test] +fn layer_filters() { + let (unfiltered, unfiltered_handle) = unfiltered("unfiltered"); + let (filtered, filtered_handle) = filtered("filtered"); + + let _subscriber = tracing_subscriber::registry() + .with(unfiltered) + .with(filtered.with_filter(filter())) + .set_default(); + + events(); + + unfiltered_handle.assert_finished(); + filtered_handle.assert_finished(); +} + +#[test] +fn layered_layer_filters() { + let (unfiltered1, unfiltered1_handle) = unfiltered("unfiltered_1"); + let (unfiltered2, unfiltered2_handle) = unfiltered("unfiltered_2"); + let unfiltered = unfiltered1.and_then(unfiltered2); + + let (filtered1, filtered1_handle) = filtered("filtered_1"); + let (filtered2, filtered2_handle) = filtered("filtered_2"); + let filtered = filtered1 + .with_filter(filter()) + .and_then(filtered2.with_filter(filter())); + + let _subscriber = tracing_subscriber::registry() + .with(unfiltered) + .with(filtered) + .set_default(); + + events(); + + unfiltered1_handle.assert_finished(); + unfiltered2_handle.assert_finished(); + filtered1_handle.assert_finished(); + filtered2_handle.assert_finished(); +} + +#[test] +fn out_of_order() { + let (unfiltered1, unfiltered1_handle) = unfiltered("unfiltered_1"); + let (unfiltered2, unfiltered2_handle) = unfiltered("unfiltered_2"); + + let (filtered1, filtered1_handle) = filtered("filtered_1"); + let (filtered2, filtered2_handle) = filtered("filtered_2"); + + let _subscriber = tracing_subscriber::registry() + .with(unfiltered1) + .with(filtered1.with_filter(filter())) + .with(unfiltered2) + .with(filtered2.with_filter(filter())) + .set_default(); + events(); + + unfiltered1_handle.assert_finished(); + unfiltered2_handle.assert_finished(); + filtered1_handle.assert_finished(); + filtered2_handle.assert_finished(); +} + +#[test] +fn mixed_layered() { + let (unfiltered1, unfiltered1_handle) = unfiltered("unfiltered_1"); + let (unfiltered2, unfiltered2_handle) = unfiltered("unfiltered_2"); + let (filtered1, filtered1_handle) = filtered("filtered_1"); + let (filtered2, filtered2_handle) = filtered("filtered_2"); + + let layered1 = filtered1.with_filter(filter()).and_then(unfiltered1); + let layered2 = unfiltered2.and_then(filtered2.with_filter(filter())); + + let _subscriber = tracing_subscriber::registry() + .with(layered1) + .with(layered2) + .set_default(); + + events(); + + unfiltered1_handle.assert_finished(); + unfiltered2_handle.assert_finished(); + filtered1_handle.assert_finished(); + filtered2_handle.assert_finished(); +} + +fn events() { + tracing::trace!("hello trace"); + tracing::debug!("hello debug"); + tracing::info!("hello info"); + tracing::warn!("hello warn"); + tracing::error!("hello error"); +} + +fn filter<S>() -> DynFilterFn<S> { + DynFilterFn::new(|metadata, _| metadata.level() <= &Level::INFO) +} + +fn unfiltered(name: &str) -> (ExpectLayer, subscriber::MockHandle) { + layer::named(name) + .event(event::mock().at_level(Level::TRACE)) + .event(event::mock().at_level(Level::DEBUG)) + .event(event::mock().at_level(Level::INFO)) + .event(event::mock().at_level(Level::WARN)) + .event(event::mock().at_level(Level::ERROR)) + .done() + .run_with_handle() +} + +fn filtered(name: &str) -> (ExpectLayer, subscriber::MockHandle) { + layer::named(name) + .event(event::mock().at_level(Level::INFO)) + .event(event::mock().at_level(Level::WARN)) + .event(event::mock().at_level(Level::ERROR)) + .done() + .run_with_handle() +} diff --git a/vendor/tracing-subscriber/tests/utils.rs b/vendor/tracing-subscriber/tests/utils.rs new file mode 100644 index 000000000..e95868d5e --- /dev/null +++ b/vendor/tracing-subscriber/tests/utils.rs @@ -0,0 +1,39 @@ +#![cfg(feature = "std")] + +use tracing_mock::*; +use tracing_subscriber::prelude::*; + +#[test] +fn init_ext_works() { + let (subscriber, finished) = subscriber::mock() + .event( + event::mock() + .at_level(tracing::Level::INFO) + .with_target("init_works"), + ) + .done() + .run_with_handle(); + + let _guard = subscriber.set_default(); + tracing::info!(target: "init_works", "it worked!"); + finished.assert_finished(); +} + +#[test] +#[cfg(feature = "fmt")] +fn builders_are_init_ext() { + tracing_subscriber::fmt().set_default(); + let _ = tracing_subscriber::fmt() + .with_target(false) + .compact() + .try_init(); +} + +#[test] +#[cfg(all(feature = "fmt", feature = "env-filter"))] +fn layered_is_init_ext() { + tracing_subscriber::registry() + .with(tracing_subscriber::fmt::layer()) + .with(tracing_subscriber::EnvFilter::new("foo=info")) + .set_default(); +} diff --git a/vendor/tracing-subscriber/tests/vec.rs b/vendor/tracing-subscriber/tests/vec.rs new file mode 100644 index 000000000..92abf0bff --- /dev/null +++ b/vendor/tracing-subscriber/tests/vec.rs @@ -0,0 +1,19 @@ +#![cfg(feature = "registry")] +use tracing::level_filters::LevelFilter; +use tracing::Subscriber; +use tracing_subscriber::prelude::*; + +#[test] +fn just_empty_vec() { + // Just a None means everything is off + let subscriber = tracing_subscriber::registry().with(Vec::<LevelFilter>::new()); + assert_eq!(subscriber.max_level_hint(), Some(LevelFilter::OFF)); +} + +#[test] +fn layer_and_empty_vec() { + let subscriber = tracing_subscriber::registry() + .with(LevelFilter::INFO) + .with(Vec::<LevelFilter>::new()); + assert_eq!(subscriber.max_level_hint(), Some(LevelFilter::INFO)); +} diff --git a/vendor/tracing-subscriber/tests/vec_subscriber_filter_interests_cached.rs b/vendor/tracing-subscriber/tests/vec_subscriber_filter_interests_cached.rs new file mode 100644 index 000000000..10467cb7d --- /dev/null +++ b/vendor/tracing-subscriber/tests/vec_subscriber_filter_interests_cached.rs @@ -0,0 +1,117 @@ +#![cfg(feature = "registry")] +mod support; +use self::support::*; + +use std::{ + collections::HashMap, + sync::{Arc, Mutex}, +}; +use tracing::{Level, Subscriber}; +use tracing_subscriber::{filter, prelude::*}; + +#[test] +fn vec_layer_filter_interests_are_cached() { + let mk_filtered = |level: Level, subscriber: ExpectLayer| { + let seen = Arc::new(Mutex::new(HashMap::new())); + let filter = filter::filter_fn({ + let seen = seen.clone(); + move |meta| { + *seen.lock().unwrap().entry(*meta.level()).or_insert(0usize) += 1; + meta.level() <= &level + } + }); + (subscriber.with_filter(filter).boxed(), seen) + }; + + // This layer will return Interest::always for INFO and lower. + let (info_layer, info_handle) = layer::named("info") + .event(event::mock().at_level(Level::INFO)) + .event(event::mock().at_level(Level::WARN)) + .event(event::mock().at_level(Level::ERROR)) + .event(event::mock().at_level(Level::INFO)) + .event(event::mock().at_level(Level::WARN)) + .event(event::mock().at_level(Level::ERROR)) + .done() + .run_with_handle(); + let (info_layer, seen_info) = mk_filtered(Level::INFO, info_layer); + + // This layer will return Interest::always for WARN and lower. + let (warn_layer, warn_handle) = layer::named("warn") + .event(event::mock().at_level(Level::WARN)) + .event(event::mock().at_level(Level::ERROR)) + .event(event::mock().at_level(Level::WARN)) + .event(event::mock().at_level(Level::ERROR)) + .done() + .run_with_handle(); + let (warn_layer, seen_warn) = mk_filtered(Level::WARN, warn_layer); + + let subscriber = tracing_subscriber::registry().with(vec![warn_layer, info_layer]); + assert!(subscriber.max_level_hint().is_none()); + + let _subscriber = subscriber.set_default(); + + fn events() { + tracing::trace!("hello trace"); + tracing::debug!("hello debug"); + tracing::info!("hello info"); + tracing::warn!("hello warn"); + tracing::error!("hello error"); + } + + events(); + { + let lock = seen_info.lock().unwrap(); + for (&level, &count) in lock.iter() { + if level == Level::INFO { + continue; + } + assert_eq!( + count, 1, + "level {:?} should have been seen 1 time by the INFO subscriber (after first set of events)", + level + ); + } + + let lock = seen_warn.lock().unwrap(); + for (&level, &count) in lock.iter() { + if level == Level::INFO { + continue; + } + assert_eq!( + count, 1, + "level {:?} should have been seen 1 time by the WARN subscriber (after first set of events)", + level + ); + } + } + + events(); + { + let lock = seen_info.lock().unwrap(); + for (&level, &count) in lock.iter() { + if level == Level::INFO { + continue; + } + assert_eq!( + count, 1, + "level {:?} should have been seen 1 time by the INFO subscriber (after second set of events)", + level + ); + } + + let lock = seen_warn.lock().unwrap(); + for (&level, &count) in lock.iter() { + if level == Level::INFO { + continue; + } + assert_eq!( + count, 1, + "level {:?} should have been seen 1 time by the WARN subscriber (after second set of events)", + level + ); + } + } + + info_handle.assert_finished(); + warn_handle.assert_finished(); +} |