From 62d57a62c327e387a7bb91d3f503be6162b81db3 Mon Sep 17 00:00:00 2001 From: Jeremy Fitzhardinge Date: Thu, 28 Sep 2023 16:57:49 -0700 Subject: [PATCH] subscriber: Implement subscribe::Filter for Option (#2407) ## Motivation It's currently awkward to have an optional per-subscriber filter. ## Solution Implement `Filter` for `Option where F: Filter`, following the example of `Subscribe`. 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/subscriber_filters/mod.rs | 99 ++++++++++++ tracing-subscriber/src/subscribe/mod.rs | 24 ++- .../tests/option_filter_interest_caching.rs | 53 +++++++ .../tests/subscriber_filters/main.rs | 1 + .../tests/subscriber_filters/option.rs | 149 ++++++++++++++++++ 5 files changed, 323 insertions(+), 3 deletions(-) create mode 100644 tracing-subscriber/tests/option_filter_interest_caching.rs create mode 100644 tracing-subscriber/tests/subscriber_filters/option.rs diff --git a/tracing-subscriber/src/filter/subscriber_filters/mod.rs b/tracing-subscriber/src/filter/subscriber_filters/mod.rs index c7837ec927..d519aa4d7c 100644 --- a/tracing-subscriber/src/filter/subscriber_filters/mod.rs +++ b/tracing-subscriber/src/filter/subscriber_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 subscribe::Filter for Box + Send + Sync + 's filter_impl_body!(); } +// Implement Filter for Option where None => allow +#[cfg(feature = "registry")] +#[cfg_attr(docsrs, doc(cfg(feature = "registry")))] +impl subscribe::Filter for Option +where + F: subscribe::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/subscribe/mod.rs b/tracing-subscriber/src/subscribe/mod.rs index 6f375654a9..61a2e4b080 100644 --- a/tracing-subscriber/src/subscribe/mod.rs +++ b/tracing-subscriber/src/subscribe/mod.rs @@ -464,12 +464,30 @@ //! //! This crate's [`filter`] module provides a number of types which implement //! the [`Filter`] trait, such as [`LevelFilter`], [`Targets`], and -//! [`FilterFn`]. These [`Filter`]s provide ready-made implementations of -//! common forms of filtering. For custom filtering policies, the [`FilterFn`] -//! and [`DynFilterFn`] types allow implementing a [`Filter`] with a closure or +//! [`FilterFn`]. These [`Filter`]s provide ready-made implementations of common +//! forms of filtering. For custom filtering policies, the [`FilterFn`] and +//! [`DynFilterFn`] types allow implementing a [`Filter`] with a closure or //! 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, Subscribe}; +//! # use tracing_core::{Metadata, collect::Collect}; +//! # struct MySubscriber(std::marker::PhantomData); +//! # impl MySubscriber { fn new() -> Self { Self(std::marker::PhantomData)} } +//! # impl Subscribe for MySubscriber {} +//! # fn my_filter(_: &str) -> impl Fn(&Metadata) -> bool { |_| true } +//! fn setup_tracing(filter_config: Option<&str>) { +//! let layer = MySubscriber::::new() +//! .with_filter(filter_config.map(|config| filter_fn(my_filter(config)))); +//! //... +//! } +//! ``` +//! //!
//! 
 //!     Warning: Currently, the 
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..5853d65718
--- /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, subscriber};
+use tracing_subscriber::{filter, prelude::*, Subscribe};
+
+/// 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 (subscribe_none, handle_none) = subscriber::mock()
+        .event(expect::event())
+        .event(expect::event())
+        .only()
+        .run_with_handle();
+    let subscribe_none = subscribe_none.with_filter(None::>);
+
+    let times_filtered = Arc::new(AtomicUsize::new(0));
+    let (subscribe_filter_fn, handle_filter_fn) = subscriber::mock()
+        .event(expect::event())
+        .event(expect::event())
+        .only()
+        .run_with_handle();
+    let subscribe_filter_fn = subscribe_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(subscribe_none)
+        .with(subscribe_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();
+}
diff --git a/tracing-subscriber/tests/subscriber_filters/main.rs b/tracing-subscriber/tests/subscriber_filters/main.rs
index 0ec43b67e1..79aacbfca2 100644
--- a/tracing-subscriber/tests/subscriber_filters/main.rs
+++ b/tracing-subscriber/tests/subscriber_filters/main.rs
@@ -1,5 +1,6 @@
 #![cfg(feature = "registry")]
 mod filter_scopes;
+mod option;
 mod per_event;
 mod targets;
 mod trees;
diff --git a/tracing-subscriber/tests/subscriber_filters/option.rs b/tracing-subscriber/tests/subscriber_filters/option.rs
new file mode 100644
index 0000000000..0bdf356d33
--- /dev/null
+++ b/tracing-subscriber/tests/subscriber_filters/option.rs
@@ -0,0 +1,149 @@
+use super::*;
+use tracing::Collect;
+use tracing_subscriber::{
+    filter::{self, LevelFilter},
+    prelude::*,
+    Subscribe,
+};
+
+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 (subscribe, handle) = subscriber::mock().only().run_with_handle();
+    let subscribe = subscribe.with_filter(Some(filter_out_everything()));
+
+    let _guard = tracing_subscriber::registry().with(subscribe).set_default();
+
+    for i in 0..2 {
+        tracing::info!(i);
+    }
+
+    handle.assert_finished();
+}
+
+#[test]
+fn option_none() {
+    let (subscribe, handle) = subscriber::mock()
+        .event(expect::event())
+        .event(expect::event())
+        .only()
+        .run_with_handle();
+    let subscribe = subscribe.with_filter(None::>);
+
+    let _guard = tracing_subscriber::registry().with(subscribe).set_default();
+
+    for i in 0..2 {
+        tracing::info!(i);
+    }
+
+    handle.assert_finished();
+}
+
+#[test]
+fn option_mixed() {
+    let (subscribe, handle) = subscriber::mock()
+        .event(expect::event())
+        .only()
+        .run_with_handle();
+    let subscribe = subscribe
+        .with_filter(filter::dynamic_filter_fn(|meta, _ctx| {
+            meta.target() == "interesting"
+        }))
+        .with_filter(None::>);
+
+    let _guard = tracing_subscriber::registry().with(subscribe).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 (subscribe_none, handle_none) = subscriber::mock()
+        .event(expect::event())
+        .event(expect::event())
+        .only()
+        .run_with_handle();
+    let subscribe_none = subscribe_none.with_filter(None::>);
+    assert!(subscribe_none.max_level_hint().is_none());
+
+    let (subscribe_filter_fn, handle_filter_fn) = subscriber::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 (subscribe_some, handle_some) = subscriber::mock()
+        .event(expect::event())
+        .event(expect::event())
+        .only()
+        .run_with_handle();
+    let subscribe_some = subscribe_some.with_filter(Some(
+        filter::dynamic_filter_fn(move |meta, _| return meta.level() <= &Level::DEBUG)
+            .with_max_level_hint(Level::DEBUG),
+    ));
+    assert_eq!(subscribe_some.max_level_hint(), Some(LevelFilter::DEBUG));
+
+    let (subscribe_filter_fn, handle_filter_fn) = subscriber::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(subscribe_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();
+}