Skip to content

Commit b8d6b03

Browse files
author
Vineeth Rao Kanaparthi
committed
subscriber: skip RwLock in EnvFilter span callbacks when no dynamic directives
EnvFilter maintains `by_id: RwLock<HashMap<Id, SpanMatcher>>` and `by_cs: RwLock<HashMap<Identifier, CallsiteMatcher>>` for tracking per-span field-level match state. These maps are only populated when `has_dynamics` is true (i.e., when the filter has span/field-level directives like `my_crate[span_name]=debug`). However, the span lifecycle callbacks (`on_new_span`, `on_enter`, `on_exit`, `on_close`, `on_record`) unconditionally acquire the `by_id` read lock (or write lock for `on_close`) on every call. When `has_dynamics` is false — which is the common case for pure target=level configurations like `RUST_LOG=info,hyper=warn` — these maps are always empty, and the lock acquisition is wasted work. Under high concurrency this becomes a bottleneck: a GDB backtrace of a Tokio-based HTTP server under load showed ~25 worker threads contending on these RwLock acquisitions, with threads in `read_contended` blocked by `on_close`'s write lock. The contention scales with the number of EnvFilter instances in the subscriber layer stack (one per layer when using per-layer filtering). This commit adds an early `if !self.has_dynamics { return; }` guard to each of the five span lifecycle methods. This is a pure no-op when dynamic directives are present (the existing code path runs unchanged), and completely eliminates the lock traffic for the common static-only configuration.
1 parent 44696e3 commit b8d6b03

File tree

1 file changed

+15
-0
lines changed
  • tracing-subscriber/src/filter/env

1 file changed

+15
-0
lines changed

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

Lines changed: 15 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -546,6 +546,9 @@ impl EnvFilter {
546546
/// [`Filter::on_new_span`] methods on `EnvFilter`'s implementations of those
547547
/// traits, but it does not require the trait to be in scope.
548548
pub fn on_new_span<S>(&self, attrs: &span::Attributes<'_>, id: &span::Id, _: Context<'_, S>) {
549+
if !self.has_dynamics {
550+
return;
551+
}
549552
let by_cs = try_lock!(self.by_cs.read());
550553
if let Some(cs) = by_cs.get(&attrs.metadata().callsite()) {
551554
let span = cs.to_span_match(attrs);
@@ -559,6 +562,9 @@ impl EnvFilter {
559562
/// [`Filter::on_enter`] methods on `EnvFilter`'s implementations of those
560563
/// traits, but it does not require the trait to be in scope.
561564
pub fn on_enter<S>(&self, id: &span::Id, _: Context<'_, S>) {
565+
if !self.has_dynamics {
566+
return;
567+
}
562568
// XXX: This is where _we_ could push IDs to the stack instead, and use
563569
// that to allow changing the filter while a span is already entered.
564570
// But that might be much less efficient...
@@ -573,6 +579,9 @@ impl EnvFilter {
573579
/// [`Filter::on_exit`] methods on `EnvFilter`'s implementations of those
574580
/// traits, but it does not require the trait to be in scope.
575581
pub fn on_exit<S>(&self, id: &span::Id, _: Context<'_, S>) {
582+
if !self.has_dynamics {
583+
return;
584+
}
576585
if self.cares_about_span(id) {
577586
self.scope.get_or_default().borrow_mut().pop();
578587
}
@@ -584,6 +593,9 @@ impl EnvFilter {
584593
/// [`Filter::on_close`] methods on `EnvFilter`'s implementations of those
585594
/// traits, but it does not require the trait to be in scope.
586595
pub fn on_close<S>(&self, id: span::Id, _: Context<'_, S>) {
596+
if !self.has_dynamics {
597+
return;
598+
}
587599
// If we don't need to acquire a write lock, avoid doing so.
588600
if !self.cares_about_span(&id) {
589601
return;
@@ -600,6 +612,9 @@ impl EnvFilter {
600612
/// [`Filter::on_record`] methods on `EnvFilter`'s implementations of those
601613
/// traits, but it does not require the trait to be in scope
602614
pub fn on_record<S>(&self, id: &span::Id, values: &span::Record<'_>, _: Context<'_, S>) {
615+
if !self.has_dynamics {
616+
return;
617+
}
603618
if let Some(span) = try_lock!(self.by_id.read()).get(id) {
604619
span.record_update(values);
605620
}

0 commit comments

Comments
 (0)