subscriber: fix incorrect filter selection + improve filter performance

tracing-subscriber/src/filter/env/directive.rs

@@ -39,7 +39,7 @@ pub(crate) type Statics = DirectiveSet<StaticDirective>;
 #[derive(Debug, PartialEq)]
 pub(crate) struct DirectiveSet<T> {
  directives: Vec<T>,
- max_level: LevelFilter,
+ pub(crate) max_level: LevelFilter,
 }
 
 pub(crate) type CallsiteMatcher = MatchSet<field::CallsiteMatch>;
@@ -406,6 +406,7 @@ impl<T: Match + Ord> DirectiveSet<T> {
  self.directives
  .iter()
  .filter(move |d| d.cares_about(metadata))
+ .rev()
  }
 
  pub(crate) fn add(&mut self, directive: T) {
@@ -482,7 +483,10 @@ impl Dynamics {
 impl Statics {
  pub(crate) fn enabled(&self, meta: &Metadata<'_>) -> bool {
  let level = meta.level();
- self.directives_for(meta).any(|d| d.level >= *level)
+ match self.directives_for(meta).next() {
+ Some(d) => d.level >= *level,
+ None => false,
+ }
  }
 }
 

tracing-subscriber/src/filter/env/mod.rs

@@ -96,7 +96,7 @@ use tracing_core::{
 pub struct EnvFilter {
  statics: directive::Statics,
  dynamics: directive::Dynamics,
-
+ has_dynamics: bool,
  by_id: RwLock<HashMap<span::Id, directive::SpanMatcher>>,
  by_cs: RwLock<HashMap<callsite::Identifier, directive::CallsiteMatcher>>,
 }
@@ -219,21 +219,24 @@ impl EnvFilter {
  if let Some(stat) = directive.to_static() {
  self.statics.add(stat)
  } else {
+ self.has_dynamics = true;
  self.dynamics.add(directive);
  }
  self
  }
 
  fn from_directives(directives: impl IntoIterator<Item = Directive>) -> Self {
  let (dynamics, mut statics) = Directive::make_tables(directives);
+ let has_dynamics = !dynamics.is_empty();
 
- if statics.is_empty() && dynamics.is_empty() {
+ if statics.is_empty() && !has_dynamics {
  statics.add(directive::StaticDirective::default());
  }
 
  Self {
  statics,
  dynamics,
+ has_dynamics,
  by_id: RwLock::new(HashMap::new()),
  by_cs: RwLock::new(HashMap::new()),
  }
@@ -245,17 +248,17 @@ impl EnvFilter {
  }
 
  fn base_interest(&self) -> Interest {
- if self.dynamics.is_empty() {
- Interest::never()
- } else {
+ if self.has_dynamics {
  Interest::sometimes()
+ } else {
+ Interest::never()
  }
  }
 }
 
 impl<S: Subscriber> Layer<S> for EnvFilter {
  fn register_callsite(&self, metadata: &'static Metadata<'static>) -> Interest {
- if metadata.is_span() {
+ if self.has_dynamics && metadata.is_span() {
  // If this metadata describes a span, first, check if there is a
  // dynamic filter that should be constructed for it. If so, it
  // should always be enabled, since it influences filtering.
@@ -276,20 +279,35 @@ impl<S: Subscriber> Layer<S> for EnvFilter {
 
  fn enabled(&self, metadata: &Metadata<'_>, _: Context<'_, S>) -> bool {
  let level = metadata.level();
- SCOPE.with(|scope| {
- for filter in scope.borrow().iter() {
- if filter >= level {
- return true;
+
+ // is it possible for a dynamic filter directive to enable this event?
+ // if not, we can avoid the thread local access + iterating over the
+ // spans in the current scope.
+ if self.has_dynamics && self.dynamics.max_level >= *level {
+ let enabled_by_scope = SCOPE.with(|scope| {
+ for filter in scope.borrow().iter() {
+ if filter >= level {
+ return true;
+ }
  }
+ false
+ });
+ if enabled_by_scope {
+ return true;
  }
+ }
 
+ // is it possible for a static filter directive to enable this event?
+ if self.statics.max_level >= *level {
  // Otherwise, fall back to checking if the callsite is
  // statically enabled.
  // TODO(eliza): we *might* want to check this only if the `log`
  // feature is enabled, since if this is a `tracing` event with a
  // real callsite, it would already have been statically enabled...
- self.statics.enabled(metadata)
- })
+ return self.statics.enabled(metadata);
+ }
+
+ false
  }
 
  fn new_span(&self, attrs: &span::Attributes<'_>, id: &span::Id, _: Context<'_, S>) {