From 029be0eda80add6f7b6b49233ddffcdfd5106e5c Mon Sep 17 00:00:00 2001 From: CAD97 Date: Wed, 23 Mar 2022 17:31:53 -0500 Subject: [PATCH 01/10] Let Subscribe disable specific events --- tracing-subscriber/src/reload.rs | 5 +++++ tracing-subscriber/src/subscribe/mod.rs | 24 ++++++++++++++++++++++++ 2 files changed, 29 insertions(+) diff --git a/tracing-subscriber/src/reload.rs b/tracing-subscriber/src/reload.rs index f2c577b32f..5e8209beca 100644 --- a/tracing-subscriber/src/reload.rs +++ b/tracing-subscriber/src/reload.rs @@ -93,6 +93,11 @@ where try_lock!(self.inner.read()).on_follows_from(span, follows, ctx) } + #[inline] + fn event_enabled(&self, event: &Event<'_>, ctx: subscribe::Context<'_, C>) -> bool { + try_lock!(self.inner.read(), else return false).event_enabled(event, ctx) + } + #[inline] fn on_event(&self, event: &Event<'_>, ctx: subscribe::Context<'_, C>) { try_lock!(self.inner.read()).on_event(event, ctx) diff --git a/tracing-subscriber/src/subscribe/mod.rs b/tracing-subscriber/src/subscribe/mod.rs index f8d3edf52f..32ab902235 100644 --- a/tracing-subscriber/src/subscribe/mod.rs +++ b/tracing-subscriber/src/subscribe/mod.rs @@ -827,6 +827,30 @@ where // seems like a good future-proofing measure as it may grow other methods later... fn on_follows_from(&self, _span: &span::Id, _follows: &span::Id, _ctx: Context<'_, C>) {} + /// Called before `on_event`, to determine if `on_event` should be called. + /// + ///
+ ///
+    ///
+    /// **Note**: This method determines whether an event is globally enabled,
+    /// *not* whether the individual subscriber will be notified about the
+    /// event. This is intended to be used by layers that implement filtering
+    /// for the entire stack. Layers which do not wish to be notified about
+    /// certain events but do not wish to globally disable them should ignore
+    /// those events in their [on_event][Self::on_event].
+    ///
+    /// 
+ /// + /// See [the trait-level documentation] for more information on filtering + /// with `Subscriber`s. + /// + /// [`Interest`]: tracing_core::Interest + /// [the trait-level documentation]: #filtering-with-subscribers + #[inline] // collapse this to a constant please mrs optimizer + fn event_enabled(&self, _event: &Event<'_>, _ctx: Context<'_, C>) -> bool { + true + } + /// Notifies this subscriber that an event has occurred. fn on_event(&self, _event: &Event<'_>, _ctx: Context<'_, C>) {} From 2f699431cacfb4f26c83bcded6197cec5d00e96e Mon Sep 17 00:00:00 2001 From: CAD97 Date: Thu, 31 Mar 2022 17:00:15 -0500 Subject: [PATCH 02/10] Explain how various interest enablers work together --- tracing-subscriber/src/subscribe/mod.rs | 27 ++++++++++++++++++++++++- 1 file changed, 26 insertions(+), 1 deletion(-) diff --git a/tracing-subscriber/src/subscribe/mod.rs b/tracing-subscriber/src/subscribe/mod.rs index 32ab902235..71127fe10c 100644 --- a/tracing-subscriber/src/subscribe/mod.rs +++ b/tracing-subscriber/src/subscribe/mod.rs @@ -686,7 +686,31 @@ pub(crate) mod tests; /// be composed together with other subscribers to build a [collector]. See the /// [module-level documentation](crate::subscribe) for details. /// +/// # Enabling interest +/// +/// Whenever an tracing event (or span) is emitted, it goes through a number of +/// steps to determine how and how much it should be processed. The earlier an +/// event is disabled, the less work has to be done to process the event, so +/// subscribers should attempt to provide accurate information as early as +/// possible. Note that this determines **global** interest for the entire stack +/// of subscribers; a subscriber that wants to ignore certain events/spans +/// should just ignore them in the notifications. In order, each event checks: +/// +/// - [`register_callsite`], once per callsite (roughly: once per time that +/// `event!` or `span!` is written in the source code; this is cached at the +/// callsite). See [`Collect::register_callsite`] for how this behaves. +/// - [`enabled`], once per emitted event (or span). This is the main point to +/// (globally) filter events based on their [`Metadata`]. If an event can be +/// disabled by just its structure, it should be, as this allows construction +/// of the actual `Event`/`Span` to be skipped. +/// - For events only (and not spans), [`event_enabled`] is called just before +/// processing the event. This gives subscribers one last chance to say that +/// an event should be filtered out, now that the event's fields are known. +/// /// [collector]: tracing_core::Collect +/// [`enabled`]: Self::enabled +/// [`event_enabled`]: Self::event_enabled +/// [`register_callsite`]: Self::register_callsite #[cfg_attr(docsrs, doc(notable_trait))] pub trait Subscribe where @@ -827,7 +851,7 @@ where // seems like a good future-proofing measure as it may grow other methods later... fn on_follows_from(&self, _span: &span::Id, _follows: &span::Id, _ctx: Context<'_, C>) {} - /// Called before `on_event`, to determine if `on_event` should be called. + /// Called before [`on_event`], to determine if `on_event` should be called. /// ///
///
@@ -844,6 +868,7 @@ where
     /// See [the trait-level documentation] for more information on filtering
     /// with `Subscriber`s.
     ///
+    /// [`on_event`]: Self::on_event
     /// [`Interest`]: tracing_core::Interest
     /// [the trait-level documentation]: #filtering-with-subscribers
     #[inline] // collapse this to a constant please mrs optimizer

From 30f06449883fe21b8bf34a192bb4bae68e456d5e Mon Sep 17 00:00:00 2001
From: CAD97 
Date: Thu, 31 Mar 2022 17:05:24 -0500
Subject: [PATCH 03/10] Rescue event_enabled impls from the rebase wastes

---
 tracing-subscriber/src/subscribe/layered.rs | 17 +++++++++++++++--
 tracing-subscriber/src/subscribe/mod.rs     | 13 +++++++++++++
 2 files changed, 28 insertions(+), 2 deletions(-)

diff --git a/tracing-subscriber/src/subscribe/layered.rs b/tracing-subscriber/src/subscribe/layered.rs
index 813bafebba..329e5bf31c 100644
--- a/tracing-subscriber/src/subscribe/layered.rs
+++ b/tracing-subscriber/src/subscribe/layered.rs
@@ -139,8 +139,10 @@ where
     }
 
     fn event(&self, event: &Event<'_>) {
-        self.inner.event(event);
-        self.subscriber.on_event(event, self.ctx());
+        if self.subscriber.event_enabled(event, self.ctx()) {
+            self.inner.event(event);
+            self.subscriber.on_event(event, self.ctx());
+        }
     }
 
     fn enter(&self, span: &span::Id) {
@@ -280,6 +282,17 @@ where
         self.subscriber.on_follows_from(span, follows, ctx);
     }
 
+    #[inline]
+    fn event_enabled(&self, event: &Event<'_>, ctx: Context<'_, C>) -> bool {
+        if self.subscriber.event_enabled(event, ctx.clone()) {
+            // if the outer subscriber enables the event, ask the inner subscriber.
+            self.inner.event_enabled(event, ctx)
+        } else {
+            // otherwise, the callsite is disabled by this subscriber
+            false
+        }
+    }
+
     #[inline]
     fn on_event(&self, event: &Event<'_>, ctx: Context<'_, C>) {
         self.inner.on_event(event, ctx.clone());
diff --git a/tracing-subscriber/src/subscribe/mod.rs b/tracing-subscriber/src/subscribe/mod.rs
index 71127fe10c..0822fd06f2 100644
--- a/tracing-subscriber/src/subscribe/mod.rs
+++ b/tracing-subscriber/src/subscribe/mod.rs
@@ -1504,6 +1504,14 @@ where
         }
     }
 
+    #[inline]
+    fn event_enabled(&self, event: &Event<'_>, ctx: Context<'_, C>) -> bool {
+        match self {
+            Some(ref inner) => inner.event_enabled(event, ctx),
+            None => false,
+        }
+    }
+
     #[inline]
     fn on_event(&self, event: &Event<'_>, ctx: Context<'_, C>) {
         if let Some(ref inner) = self {
@@ -1583,6 +1591,11 @@ macro_rules! subscriber_impl_body {
             self.deref().on_follows_from(span, follows, ctx)
         }
 
+        #[inline]
+        fn event_enabled(&self, event: &Event<'_>, ctx: Context<'_, C>) -> bool {
+            self.deref().event_enabled(event, ctx)
+        }
+
         #[inline]
         fn on_event(&self, event: &Event<'_>, ctx: Context<'_, C>) {
             self.deref().on_event(event, ctx)

From ce016e1139d1e693fb35261cc0d3035853c681f9 Mon Sep 17 00:00:00 2001
From: CAD97 
Date: Mon, 11 Apr 2022 17:55:16 -0500
Subject: [PATCH 04/10] Improve event_enabled order independence

---
 tracing-core/src/collect.rs                 | 16 ++++++++++++++++
 tracing-subscriber/src/subscribe/layered.rs | 18 +++++++++++++-----
 2 files changed, 29 insertions(+), 5 deletions(-)

diff --git a/tracing-core/src/collect.rs b/tracing-core/src/collect.rs
index a939ef1be2..78cec2ea12 100644
--- a/tracing-core/src/collect.rs
+++ b/tracing-core/src/collect.rs
@@ -57,6 +57,9 @@ use core::ptr::NonNull;
 ///   See also the [documentation on the callsite registry][cs-reg] for details
 ///   on [`register_callsite`].
 ///
+/// - [`event_enabled`] is called once before every [`event`] is recorded. This
+///   can be used to implement filtering on events once their field values are
+///   known but before any processing is done in `event`.
 /// - [`clone_span`] is called every time a span ID is cloned, and [`try_close`]
 ///   is called when a span ID is dropped. By default, these functions do
 ///   nothing. However, they can be used to implement reference counting for
@@ -72,6 +75,8 @@ use core::ptr::NonNull;
 /// [`clone_span`]: Collect::clone_span
 /// [`try_close`]: Collect::try_close
 /// [cs-reg]: crate::callsite#registering-callsites
+/// [`event`]: Collect::event
+/// [`event_enabled`]: Collect::event_enabled
 pub trait Collect: 'static {
     // === Span registry methods ==============================================
 
@@ -288,6 +293,17 @@ pub trait Collect: 'static {
     /// follow from _b_), it may silently do nothing.
     fn record_follows_from(&self, span: &span::Id, follows: &span::Id);
 
+    /// Determine if an [`Event`] should be recorded.
+    ///
+    /// By default, this returns `true` and collectors can filter events in
+    /// [`event`][Self::event] without any penalty. However, when `event` is
+    /// more complicated, this can be used to determine if `event` should be
+    /// called at all, separating out the decision from the processing.
+    fn event_enabled(&self, event: &Event<'_>) -> bool {
+        let _ = event;
+        true
+    }
+
     /// Records that an [`Event`] has occurred.
     ///
     /// This method will be invoked when an Event is constructed by
diff --git a/tracing-subscriber/src/subscribe/layered.rs b/tracing-subscriber/src/subscribe/layered.rs
index 329e5bf31c..c601996b9e 100644
--- a/tracing-subscriber/src/subscribe/layered.rs
+++ b/tracing-subscriber/src/subscribe/layered.rs
@@ -138,13 +138,21 @@ where
         self.subscriber.on_follows_from(span, follows, self.ctx());
     }
 
-    fn event(&self, event: &Event<'_>) {
+    fn event_enabled(&self, event: &Event<'_>) -> bool {
         if self.subscriber.event_enabled(event, self.ctx()) {
-            self.inner.event(event);
-            self.subscriber.on_event(event, self.ctx());
+            // if the outer subscriber enables the event, ask the inner collector.
+            self.inner.event_enabled(event)
+        } else {
+            // otherwise, the event is disabled by this subscriber
+            false
         }
     }
 
+    fn event(&self, event: &Event<'_>) {
+        self.inner.event(event);
+        self.subscriber.on_event(event, self.ctx());
+    }
+
     fn enter(&self, span: &span::Id) {
         self.inner.enter(span);
         self.subscriber.on_enter(span, self.ctx());
@@ -285,10 +293,10 @@ where
     #[inline]
     fn event_enabled(&self, event: &Event<'_>, ctx: Context<'_, C>) -> bool {
         if self.subscriber.event_enabled(event, ctx.clone()) {
-            // if the outer subscriber enables the event, ask the inner subscriber.
+            // if the outer subscriber enables the event, ask the inner collector.
             self.inner.event_enabled(event, ctx)
         } else {
-            // otherwise, the callsite is disabled by this subscriber
+            // otherwise, the event is disabled by this subscriber
             false
         }
     }

From 53ed1dcf9221333714ba666c35c6dd1840702f5f Mon Sep 17 00:00:00 2001
From: CAD97 
Date: Mon, 11 Apr 2022 18:09:01 -0500
Subject: [PATCH 05/10] Properly call Collect::event_enabled in more places

---
 tracing-core/src/collect.rs       | 10 ++++++++++
 tracing-core/src/dispatch.rs      |  5 ++++-
 tracing-subscriber/src/fmt/mod.rs |  5 +++++
 3 files changed, 19 insertions(+), 1 deletion(-)

diff --git a/tracing-core/src/collect.rs b/tracing-core/src/collect.rs
index 78cec2ea12..80c3c12d2d 100644
--- a/tracing-core/src/collect.rs
+++ b/tracing-core/src/collect.rs
@@ -701,6 +701,11 @@ impl Collect for alloc::boxed::Box {
         self.as_ref().record_follows_from(span, follows)
     }
 
+    #[inline]
+    fn event_enabled(&self, event: &Event<'_>) -> bool {
+        self.as_ref().event_enabled(event)
+    }
+
     #[inline]
     fn event(&self, event: &Event<'_>) {
         self.as_ref().event(event)
@@ -772,6 +777,11 @@ impl Collect for alloc::sync::Arc {
         self.as_ref().record_follows_from(span, follows)
     }
 
+    #[inline]
+    fn event_enabled(&self, event: &Event<'_>) -> bool {
+        self.as_ref().event_enabled(event)
+    }
+
     #[inline]
     fn event(&self, event: &Event<'_>) {
         self.as_ref().event(event)
diff --git a/tracing-core/src/dispatch.rs b/tracing-core/src/dispatch.rs
index 5b85dcde35..e95969037b 100644
--- a/tracing-core/src/dispatch.rs
+++ b/tracing-core/src/dispatch.rs
@@ -682,7 +682,10 @@ impl Dispatch {
     /// [`event`]: super::collect::Collect::event
     #[inline]
     pub fn event(&self, event: &Event<'_>) {
-        self.collector().event(event)
+        let collector = self.collector();
+        if collector.event_enabled(event) {
+            collector.event(event);
+        }
     }
 
     /// Records that a span has been can_enter.
diff --git a/tracing-subscriber/src/fmt/mod.rs b/tracing-subscriber/src/fmt/mod.rs
index 34fd7ed497..d7abce1635 100644
--- a/tracing-subscriber/src/fmt/mod.rs
+++ b/tracing-subscriber/src/fmt/mod.rs
@@ -393,6 +393,11 @@ where
         self.inner.record_follows_from(span, follows)
     }
 
+    #[inline]
+    fn event_enabled(&self, event: &Event<'_>) -> bool {
+        self.inner.event_enabled(event)
+    }
+
     #[inline]
     fn event(&self, event: &Event<'_>) {
         self.inner.event(event);

From f5f1758be2b5ac0e6f0fc1a1d2cc74e54617c438 Mon Sep 17 00:00:00 2001
From: Christopher Durham 
Date: Tue, 14 Jun 2022 20:32:03 -0400
Subject: [PATCH 06/10] Apply code review documentation improvements

Co-authored-by: Eliza Weisman 
---
 tracing-core/src/collect.rs             |  6 +--
 tracing-subscriber/src/subscribe/mod.rs | 55 ++++++++++++-------------
 2 files changed, 30 insertions(+), 31 deletions(-)

diff --git a/tracing-core/src/collect.rs b/tracing-core/src/collect.rs
index 80c3c12d2d..96f4906e6e 100644
--- a/tracing-core/src/collect.rs
+++ b/tracing-core/src/collect.rs
@@ -57,9 +57,9 @@ use core::ptr::NonNull;
 ///   See also the [documentation on the callsite registry][cs-reg] for details
 ///   on [`register_callsite`].
 ///
-/// - [`event_enabled`] is called once before every [`event`] is recorded. This
-///   can be used to implement filtering on events once their field values are
-///   known but before any processing is done in `event`.
+/// - [`event_enabled`] is called once before every call to the [`event`]
+///   method. This can be used to implement filtering on events once their field
+///   values are known, but before any processing is done in the `event` method.
 /// - [`clone_span`] is called every time a span ID is cloned, and [`try_close`]
 ///   is called when a span ID is dropped. By default, these functions do
 ///   nothing. However, they can be used to implement reference counting for
diff --git a/tracing-subscriber/src/subscribe/mod.rs b/tracing-subscriber/src/subscribe/mod.rs
index 0822fd06f2..fa7cc039c3 100644
--- a/tracing-subscriber/src/subscribe/mod.rs
+++ b/tracing-subscriber/src/subscribe/mod.rs
@@ -417,6 +417,28 @@
 //! [`Interest::never()`] from its [`register_callsite`] method, filter
 //! evaluation will short-circuit and the span or event will be disabled.
 //!
+//! ### Enabling interest
+//!
+//! Whenever an tracing event (or span) is emitted, it goes through a number of
+//! steps to determine how and how much it should be processed. The earlier an
+//! event is disabled, the less work has to be done to process the event, so
+//! subscribers that implement filtering should attempt to disable unwanted
+//! events as early as possible. In order, each event checks:
+//!
+//! - [`register_callsite`], once per callsite (roughly: once per time that
+//!   `event!` or `span!` is written in the source code; this is cached at the
+//!   callsite). See [`Collect::register_callsite`] and
+//!   [`tracing_core::callsite`] for a summary of how this behaves.
+//! - [`enabled`], once per emitted event (roughly: once per time that `event!`
+//!   or `span!` is *executed*), and only if `register_callsite` regesters an
+//!   [`Interest::sometimes`]. This is the main customization point to globally
+//!   filter events based on their [`Metadata`]. If an event can be disabled
+//!   based only on [`Metadata`], it should be, as this allows the construction
+//!   of the actual `Event`/`Span` to be skipped.
+//! - For events only (and not spans), [`event_enabled`] is called just before
+//!   processing the event. This gives subscribers one last chance to say that
+//!   an event should be filtered out, now that the event's fields are known.
+//!
 //! ## Per-Subscriber Filtering
 //!
 //! **Note**: per-subscriber filtering APIs currently require the [`"registry"` crate
@@ -639,6 +661,7 @@
 //! [the current span]: Context::current_span
 //! [`register_callsite`]: Subscribe::register_callsite
 //! [`enabled`]: Subscribe::enabled
+//! [`event_enabled`]: Subscribe::event_enabled
 //! [`on_enter`]: Subscribe::on_enter
 //! [`Subscribe::register_callsite`]: Subscribe::register_callsite
 //! [`Subscribe::enabled`]: Subscribe::enabled
@@ -686,31 +709,7 @@ pub(crate) mod tests;
 /// be composed together with other subscribers to build a [collector]. See the
 /// [module-level documentation](crate::subscribe) for details.
 ///
-/// # Enabling interest
-///
-/// Whenever an tracing event (or span) is emitted, it goes through a number of
-/// steps to determine how and how much it should be processed. The earlier an
-/// event is disabled, the less work has to be done to process the event, so
-/// subscribers should attempt to provide accurate information as early as
-/// possible. Note that this determines **global** interest for the entire stack
-/// of subscribers; a subscriber that wants to ignore certain events/spans
-/// should just ignore them in the notifications. In order, each event checks:
-///
-/// - [`register_callsite`], once per callsite (roughly: once per time that
-///   `event!` or `span!` is written in the source code; this is cached at the
-///   callsite). See [`Collect::register_callsite`] for how this behaves.
-/// - [`enabled`], once per emitted event (or span). This is the main point to
-///   (globally) filter events based on their [`Metadata`]. If an event can be
-///   disabled by just its structure, it should be, as this allows construction
-///   of the actual `Event`/`Span` to be skipped.
-/// - For events only (and not spans), [`event_enabled`] is called just before
-///   processing the event. This gives subscribers one last chance to say that
-///   an event should be filtered out, now that the event's fields are known.
-///
 /// [collector]: tracing_core::Collect
-/// [`enabled`]: Self::enabled
-/// [`event_enabled`]: Self::event_enabled
-/// [`register_callsite`]: Self::register_callsite
 #[cfg_attr(docsrs, doc(notable_trait))]
 pub trait Subscribe
 where
@@ -858,10 +857,10 @@ where
     ///
     /// **Note**: This method determines whether an event is globally enabled,
     /// *not* whether the individual subscriber will be notified about the
-    /// event. This is intended to be used by layers that implement filtering
-    /// for the entire stack. Layers which do not wish to be notified about
-    /// certain events but do not wish to globally disable them should ignore
-    /// those events in their [on_event][Self::on_event].
+    /// event. This is intended to be used by subscibers that implement
+    /// filtering for the entire stack. Subscribers which do not wish to be
+    /// notified about certain events but do not wish to globally disable them
+    /// should ignore those events in their [on_event][Self::on_event].
     ///
     /// 
/// From 952538f0af8b81a427ecb6a3e286db7c1b042180 Mon Sep 17 00:00:00 2001 From: Christopher Durham Date: Tue, 14 Jun 2022 20:45:39 -0400 Subject: [PATCH 07/10] Ensure event_enabled is not called extra times --- tracing-subscriber/tests/event_enabling.rs | 35 ++++++++++++++++++++++ 1 file changed, 35 insertions(+) create mode 100644 tracing-subscriber/tests/event_enabling.rs diff --git a/tracing-subscriber/tests/event_enabling.rs b/tracing-subscriber/tests/event_enabling.rs new file mode 100644 index 0000000000..0c21e2fb94 --- /dev/null +++ b/tracing-subscriber/tests/event_enabling.rs @@ -0,0 +1,35 @@ +use std::sync::{Arc, Mutex}; +use tracing::{collect::with_default, Collect}; +use tracing_subscriber::{prelude::*, registry, Subscribe}; + +struct TrackingLayer { + event_enabled_count: Arc>, +} + +impl Subscribe for TrackingLayer +where + C: Collect + Send + Sync + 'static, +{ + fn event_enabled( + &self, + _event: &tracing::Event<'_>, + _ctx: tracing_subscriber::subscribe::Context<'_, C>, + ) -> bool { + *self.event_enabled_count.lock().unwrap() += 1; + true + } +} + +#[test] +fn event_enabled_is_only_called_once() { + let event_enabled_count = Arc::new(Mutex::default()); + let count = event_enabled_count.clone(); + let collector = registry().with(TrackingLayer { + event_enabled_count, + }); + with_default(collector, || { + tracing::error!("hiya!"); + }); + + assert_eq!(1, *count.lock().unwrap()); +} From d400cf6c7284fed572cfb71e1889fa31f07e6fe2 Mon Sep 17 00:00:00 2001 From: Christopher Durham Date: Tue, 14 Jun 2022 20:53:56 -0400 Subject: [PATCH 08/10] Gate event_enabling test for registry presence --- tracing-subscriber/tests/event_enabling.rs | 2 ++ 1 file changed, 2 insertions(+) diff --git a/tracing-subscriber/tests/event_enabling.rs b/tracing-subscriber/tests/event_enabling.rs index 0c21e2fb94..aa98546bdc 100644 --- a/tracing-subscriber/tests/event_enabling.rs +++ b/tracing-subscriber/tests/event_enabling.rs @@ -1,3 +1,5 @@ +#![cfg(feature = "registry")] + use std::sync::{Arc, Mutex}; use tracing::{collect::with_default, Collect}; use tracing_subscriber::{prelude::*, registry, Subscribe}; From 57e2a4715beda69b136c6f892cb5d8010f232cac Mon Sep 17 00:00:00 2001 From: Christopher Durham Date: Fri, 17 Jun 2022 16:27:36 -0400 Subject: [PATCH 09/10] Update tracing-subscriber/src/subscribe/mod.rs Co-authored-by: Eliza Weisman --- tracing-subscriber/src/subscribe/mod.rs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/tracing-subscriber/src/subscribe/mod.rs b/tracing-subscriber/src/subscribe/mod.rs index fa7cc039c3..1715437028 100644 --- a/tracing-subscriber/src/subscribe/mod.rs +++ b/tracing-subscriber/src/subscribe/mod.rs @@ -417,7 +417,7 @@ //! [`Interest::never()`] from its [`register_callsite`] method, filter //! evaluation will short-circuit and the span or event will be disabled. //! -//! ### Enabling interest +//! ### Enabling Interest //! //! Whenever an tracing event (or span) is emitted, it goes through a number of //! steps to determine how and how much it should be processed. The earlier an From 536ed442324e8afb88263d3012267a2c825286b5 Mon Sep 17 00:00:00 2001 From: Christopher Durham Date: Fri, 17 Jun 2022 16:33:02 -0400 Subject: [PATCH 10/10] More event_enabled tests --- tracing-subscriber/tests/event_enabling.rs | 60 +++++++++++++++++++--- 1 file changed, 52 insertions(+), 8 deletions(-) diff --git a/tracing-subscriber/tests/event_enabling.rs b/tracing-subscriber/tests/event_enabling.rs index aa98546bdc..bb01a79f86 100644 --- a/tracing-subscriber/tests/event_enabling.rs +++ b/tracing-subscriber/tests/event_enabling.rs @@ -1,24 +1,31 @@ #![cfg(feature = "registry")] use std::sync::{Arc, Mutex}; -use tracing::{collect::with_default, Collect}; -use tracing_subscriber::{prelude::*, registry, Subscribe}; +use tracing::{collect::with_default, Collect, Event, Metadata}; +use tracing_subscriber::{prelude::*, registry, subscribe::Context, Subscribe}; struct TrackingLayer { + enabled: bool, event_enabled_count: Arc>, + event_enabled: bool, + on_event_count: Arc>, } impl Subscribe for TrackingLayer where C: Collect + Send + Sync + 'static, { - fn event_enabled( - &self, - _event: &tracing::Event<'_>, - _ctx: tracing_subscriber::subscribe::Context<'_, C>, - ) -> bool { + 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; - true + self.event_enabled + } + + fn on_event(&self, _event: &Event<'_>, _ctx: Context<'_, C>) { + *self.on_event_count.lock().unwrap() += 1; } } @@ -27,7 +34,10 @@ fn event_enabled_is_only_called_once() { let event_enabled_count = Arc::new(Mutex::default()); let count = event_enabled_count.clone(); let collector = registry().with(TrackingLayer { + enabled: true, event_enabled_count, + event_enabled: true, + on_event_count: Arc::new(Mutex::default()), }); with_default(collector, || { tracing::error!("hiya!"); @@ -35,3 +45,37 @@ fn event_enabled_is_only_called_once() { 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 collector = registry().with(TrackingLayer { + enabled: false, + event_enabled_count, + event_enabled: true, + on_event_count: Arc::new(Mutex::default()), + }); + with_default(collector, || { + 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 collector = registry().with(TrackingLayer { + enabled: true, + event_enabled_count: Arc::new(Mutex::default()), + event_enabled: false, + on_event_count, + }); + with_default(collector, || { + tracing::error!("hiya!"); + }); + + assert_eq!(0, *count.lock().unwrap()); +}