From 7987a8a1d3b5787d0d8f7ce0bf0125c85dc3a98b Mon Sep 17 00:00:00 2001 From: Jeremy Fitzhardinge Date: Thu, 28 Sep 2023 16:57:49 -0700 Subject: [PATCH] subscriber: Implement layer::Filter for Option (#2407) It's currently awkward to have an optional per-layer filter. Implement `Filter` for `Option where F: Filter`, following the example of `Layer`. A `None` filter passes everything through. Also, it looks like Filter for Arc/Box doesn't pass through all the methods, so extend the `filter_impl_body` macro to include them. This also adds a couple of tests and updates the docs. --------- Co-authored-by: David Barsky Co-authored-by: Ryan Johnson Co-authored-by: Eliza Weisman --- .../src/filter/layer_filters/mod.rs | 99 ++++++++++++ tracing-subscriber/src/layer/mod.rs | 18 +++ .../tests/layer_filters/main.rs | 1 + .../tests/layer_filters/option.rs | 149 ++++++++++++++++++ .../tests/option_filter_interest_caching.rs | 53 +++++++ 5 files changed, 320 insertions(+) create mode 100644 tracing-subscriber/tests/layer_filters/option.rs create mode 100644 tracing-subscriber/tests/option_filter_interest_caching.rs diff --git a/tracing-subscriber/src/filter/layer_filters/mod.rs b/tracing-subscriber/src/filter/layer_filters/mod.rs index e50ee6f007..a3835fcc41 100644 --- a/tracing-subscriber/src/filter/layer_filters/mod.rs +++ b/tracing-subscriber/src/filter/layer_filters/mod.rs @@ -478,6 +478,36 @@ macro_rules! filter_impl_body { fn max_level_hint(&self) -> Option { self.deref().max_level_hint() } + + #[inline] + fn event_enabled(&self, event: &Event<'_>, cx: &Context<'_, S>) -> bool { + self.deref().event_enabled(event, cx) + } + + #[inline] + fn on_new_span(&self, attrs: &span::Attributes<'_>, id: &span::Id, ctx: Context<'_, S>) { + self.deref().on_new_span(attrs, id, ctx) + } + + #[inline] + fn on_record(&self, id: &span::Id, values: &span::Record<'_>, ctx: Context<'_, S>) { + self.deref().on_record(id, values, ctx) + } + + #[inline] + fn on_enter(&self, id: &span::Id, ctx: Context<'_, S>) { + self.deref().on_enter(id, ctx) + } + + #[inline] + fn on_exit(&self, id: &span::Id, ctx: Context<'_, S>) { + self.deref().on_exit(id, ctx) + } + + #[inline] + fn on_close(&self, id: span::Id, ctx: Context<'_, S>) { + self.deref().on_close(id, ctx) + } }; } @@ -493,6 +523,75 @@ impl layer::Filter for Box + Send + Sync + 'static> { filter_impl_body!(); } +// Implement Filter for Option where None => allow +#[cfg(feature = "registry")] +#[cfg_attr(docsrs, doc(cfg(feature = "registry")))] +impl layer::Filter for Option +where + F: layer::Filter, +{ + #[inline] + fn enabled(&self, meta: &Metadata<'_>, ctx: &Context<'_, S>) -> bool { + self.as_ref() + .map(|inner| inner.enabled(meta, ctx)) + .unwrap_or(true) + } + + #[inline] + fn callsite_enabled(&self, meta: &'static Metadata<'static>) -> Interest { + self.as_ref() + .map(|inner| inner.callsite_enabled(meta)) + .unwrap_or_else(Interest::always) + } + + #[inline] + fn max_level_hint(&self) -> Option { + self.as_ref().and_then(|inner| inner.max_level_hint()) + } + + #[inline] + fn event_enabled(&self, event: &Event<'_>, ctx: &Context<'_, S>) -> bool { + self.as_ref() + .map(|inner| inner.event_enabled(event, ctx)) + .unwrap_or(true) + } + + #[inline] + fn on_new_span(&self, attrs: &span::Attributes<'_>, id: &span::Id, ctx: Context<'_, S>) { + if let Some(inner) = self { + inner.on_new_span(attrs, id, ctx) + } + } + + #[inline] + fn on_record(&self, id: &span::Id, values: &span::Record<'_>, ctx: Context<'_, S>) { + if let Some(inner) = self { + inner.on_record(id, values, ctx) + } + } + + #[inline] + fn on_enter(&self, id: &span::Id, ctx: Context<'_, S>) { + if let Some(inner) = self { + inner.on_enter(id, ctx) + } + } + + #[inline] + fn on_exit(&self, id: &span::Id, ctx: Context<'_, S>) { + if let Some(inner) = self { + inner.on_exit(id, ctx) + } + } + + #[inline] + fn on_close(&self, id: span::Id, ctx: Context<'_, S>) { + if let Some(inner) = self { + inner.on_close(id, ctx) + } + } +} + // === impl Filtered === impl Filtered { diff --git a/tracing-subscriber/src/layer/mod.rs b/tracing-subscriber/src/layer/mod.rs index bdc154301a..97302ed017 100644 --- a/tracing-subscriber/src/layer/mod.rs +++ b/tracing-subscriber/src/layer/mod.rs @@ -468,6 +468,24 @@ //! function pointer. In addition, when more control is required, the [`Filter`] //! trait may also be implemented for user-defined types. //! +//! //! [`Option`] also implements [`Filter`], which allows for an optional +//! filter. [`None`](Option::None) filters out _nothing_ (that is, allows +//! everything through). For example: +//! +//! ```rust +//! # use tracing_subscriber::{filter::filter_fn, Layer}; +//! # use tracing_core::{Metadata, subscriber::Subscriber}; +//! # struct Layer(std::marker::PhantomData); +//! # impl MyLayer { fn new() -> Self { Self(std::marker::PhantomData)} } +//! # impl Layer for MyLayer {} +//! # fn my_filter(_: &str) -> impl Fn(&Metadata) -> bool { |_| true } +//! fn setup_tracing(filter_config: Option<&str>) { +//! let layer = Layer::::new() +//! .with_filter(filter_config.map(|config| filter_fn(my_filter(config)))); +//! //... +//! } +//! ``` +//! //! 
 //!     Warning: Currently, the 
 //!     Registry type defined in this crate is the only root
diff --git a/tracing-subscriber/tests/layer_filters/main.rs b/tracing-subscriber/tests/layer_filters/main.rs
index 170074e8b3..9576f39a6c 100644
--- a/tracing-subscriber/tests/layer_filters/main.rs
+++ b/tracing-subscriber/tests/layer_filters/main.rs
@@ -2,6 +2,7 @@
 mod boxed;
 mod downcast_raw;
 mod filter_scopes;
+mod option;
 mod per_event;
 mod targets;
 mod trees;
diff --git a/tracing-subscriber/tests/layer_filters/option.rs b/tracing-subscriber/tests/layer_filters/option.rs
new file mode 100644
index 0000000000..58a3012503
--- /dev/null
+++ b/tracing-subscriber/tests/layer_filters/option.rs
@@ -0,0 +1,149 @@
+use super::*;
+use tracing::Subscriber;
+use tracing_subscriber::{
+    filter::{self, LevelFilter},
+    prelude::*,
+    Layer,
+};
+
+fn filter_out_everything() -> filter::DynFilterFn {
+    // 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)
+}
+
+#[test]
+fn option_some() {
+    let (layer, handle) = layer::mock().only().run_with_handle();
+    let layer = layer.with_filter(Some(filter_out_everything()));
+
+    let _guard = tracing_subscriber::registry().with(layer).set_default();
+
+    for i in 0..2 {
+        tracing::info!(i);
+    }
+
+    handle.assert_finished();
+}
+
+#[test]
+fn option_none() {
+    let (layer, handle) = layer::mock()
+        .event(expect::event())
+        .event(expect::event())
+        .only()
+        .run_with_handle();
+    let layer = layer.with_filter(None::>);
+
+    let _guard = tracing_subscriber::registry().with(layer).set_default();
+
+    for i in 0..2 {
+        tracing::info!(i);
+    }
+
+    handle.assert_finished();
+}
+
+#[test]
+fn option_mixed() {
+    let (layer, handle) = layer::mock()
+        .event(expect::event())
+        .only()
+        .run_with_handle();
+    let layer = layer
+        .with_filter(filter::dynamic_filter_fn(|meta, _ctx| {
+            meta.target() == "interesting"
+        }))
+        .with_filter(None::>);
+
+    let _guard = tracing_subscriber::registry().with(layer).set_default();
+
+    tracing::info!(target: "interesting", x="foo");
+    tracing::info!(target: "boring", x="bar");
+
+    handle.assert_finished();
+}
+
+/// The lack of a max level hint from a `None` filter should result in no max
+/// level hint when combined with other filters/subscribers.
+#[test]
+fn none_max_level_hint() {
+    let (layer_some, handle_none) = layer::mock()
+        .event(expect::event())
+        .event(expect::event())
+        .only()
+        .run_with_handle();
+    let subscribe_none = layer_some.with_filter(None::>);
+    assert!(subscribe_none.max_level_hint().is_none());
+
+    let (subscribe_filter_fn, handle_filter_fn) = layer::mock()
+        .event(expect::event())
+        .only()
+        .run_with_handle();
+    let max_level = Level::INFO;
+    let subscribe_filter_fn = subscribe_filter_fn.with_filter(
+        filter::dynamic_filter_fn(move |meta, _| return meta.level() <= &max_level)
+            .with_max_level_hint(max_level),
+    );
+    assert_eq!(
+        subscribe_filter_fn.max_level_hint(),
+        Some(LevelFilter::INFO)
+    );
+
+    let subscriber = tracing_subscriber::registry()
+        .with(subscribe_none)
+        .with(subscribe_filter_fn);
+    // The absence of a hint from the `None` filter upgrades the `INFO` hint
+    // from the filter fn subscriber.
+    assert!(subscriber.max_level_hint().is_none());
+
+    let _guard = subscriber.set_default();
+    tracing::info!(target: "interesting", x="foo");
+    tracing::debug!(target: "sometimes_interesting", x="bar");
+
+    handle_none.assert_finished();
+    handle_filter_fn.assert_finished();
+}
+
+/// The max level hint from inside a `Some(filter)` filter should be propagated
+/// and combined with other filters/subscribers.
+#[test]
+fn some_max_level_hint() {
+    let (layer_some, handle_some) = layer::mock()
+        .event(expect::event())
+        .event(expect::event())
+        .only()
+        .run_with_handle();
+    let layer_some = layer_some.with_filter(Some(
+        filter::dynamic_filter_fn(move |meta, _| return meta.level() <= &Level::DEBUG)
+            .with_max_level_hint(Level::DEBUG),
+    ));
+    assert_eq!(layer_some.max_level_hint(), Some(LevelFilter::DEBUG));
+
+    let (subscribe_filter_fn, handle_filter_fn) = layer::mock()
+        .event(expect::event())
+        .only()
+        .run_with_handle();
+    let subscribe_filter_fn = subscribe_filter_fn.with_filter(
+        filter::dynamic_filter_fn(move |meta, _| return meta.level() <= &Level::INFO)
+            .with_max_level_hint(Level::INFO),
+    );
+    assert_eq!(
+        subscribe_filter_fn.max_level_hint(),
+        Some(LevelFilter::INFO)
+    );
+
+    let subscriber = tracing_subscriber::registry()
+        .with(layer_some)
+        .with(subscribe_filter_fn);
+    // The `DEBUG` hint from the `Some` filter upgrades the `INFO` hint from the
+    // filter fn subscriber.
+    assert_eq!(subscriber.max_level_hint(), Some(LevelFilter::DEBUG));
+
+    let _guard = subscriber.set_default();
+    tracing::info!(target: "interesting", x="foo");
+    tracing::debug!(target: "sometimes_interesting", x="bar");
+
+    handle_some.assert_finished();
+    handle_filter_fn.assert_finished();
+}
diff --git a/tracing-subscriber/tests/option_filter_interest_caching.rs b/tracing-subscriber/tests/option_filter_interest_caching.rs
new file mode 100644
index 0000000000..609007cceb
--- /dev/null
+++ b/tracing-subscriber/tests/option_filter_interest_caching.rs
@@ -0,0 +1,53 @@
+// A separate test crate for `Option` for isolation from other tests
+// that may influence the interest cache.
+
+use std::sync::{
+    atomic::{AtomicUsize, Ordering},
+    Arc,
+};
+use tracing_mock::{expect, layer};
+use tracing_subscriber::{filter, prelude::*, Layer};
+
+/// A `None` filter should always be interested in events, and it should not
+/// needlessly degrade the caching of other filters.
+#[test]
+fn none_interest_cache() {
+    let (layer_none, handle_none) = layer::mock()
+        .event(expect::event())
+        .event(expect::event())
+        .only()
+        .run_with_handle();
+    let layer_none = layer_none.with_filter(None::>);
+
+    let times_filtered = Arc::new(AtomicUsize::new(0));
+    let (layer_filter_fn, handle_filter_fn) = layer::mock()
+        .event(expect::event())
+        .event(expect::event())
+        .only()
+        .run_with_handle();
+    let layer_filter_fn = layer_filter_fn.with_filter(filter::filter_fn({
+        let times_filtered = Arc::clone(×_filtered);
+        move |_| {
+            times_filtered.fetch_add(1, Ordering::Relaxed);
+            true
+        }
+    }));
+
+    let subscriber = tracing_subscriber::registry()
+        .with(layer_none)
+        .with(layer_filter_fn);
+
+    let _guard = subscriber.set_default();
+    for _ in 0..2 {
+        tracing::debug!(target: "always_interesting", x="bar");
+    }
+
+    // The `None` filter is unchanging and performs no filtering, so it should
+    // be cacheable and always be interested in events. The filter fn is a
+    // non-dynamic filter fn, which means the result can be cached per callsite.
+    // The filter fn should only need to be called once, and the `Option` filter
+    // should not interfere in the caching of that result.
+    assert_eq!(times_filtered.load(Ordering::Relaxed), 1);
+    handle_none.assert_finished();
+    handle_filter_fn.assert_finished();
+}