From e59795355798958cf025a6a6eb5ea38cd2e207cf Mon Sep 17 00:00:00 2001 From: Eliza Weisman Date: Fri, 17 Sep 2021 14:25:57 -0700 Subject: [PATCH] subscriber: fix missing `on_layer` for `Box`/`Arc` layer impls (#1576) The `Layer::on_layer` method on `Layer` was added in PR #1523. PR #1536, which added `Layer` implementations to `Box + ...>` and `Arc + ...>`, merged prior to #1523. However, when merging #1523, I didn't think to update the `Layer` impl for `Box`ed and `Arc`ed layers to forward `on_layer` to the inner `Layer`. This means that when a `Layer` is wrapped in an `Arc` or a `Box`, the `on_layer` method never gets called. When per-layer filters are in use, the `on_layer` method is necessary to ensure the filter is registered with the inner subscriber and has a valid ID. This bug means that when per-layer filters are wrapped in a `Box` or `Arc`, they won't be registered, and per-layer filtering breaks. This PR fixes the bug by adding `on_layer` implementations to the `Layer` impls for `Arc`ed and `Box`ed layers. I also added some tests --- thanks to @Noah-Kennedy for the original repro that these were based on (https://github.com/tokio-rs/tracing/issues/1563#issuecomment-922014777). I also added a nicer debug assertion to `Filtered` for cases where `Layer` impls don't call `on_layer`, so that this fails less confusingly in the future. Signed-off-by: Eliza Weisman --- .../src/filter/layer_filters.rs | 9 +++ tracing-subscriber/src/layer/mod.rs | 32 +++++++- .../tests/layer_filters/boxed.rs | 73 +++++++++++++++++++ .../tests/layer_filters/main.rs | 1 + 4 files changed, 114 insertions(+), 1 deletion(-) create mode 100644 tracing-subscriber/tests/layer_filters/boxed.rs diff --git a/tracing-subscriber/src/filter/layer_filters.rs b/tracing-subscriber/src/filter/layer_filters.rs index bc59125a9e..e3492ffefe 100644 --- a/tracing-subscriber/src/filter/layer_filters.rs +++ b/tracing-subscriber/src/filter/layer_filters.rs @@ -236,6 +236,11 @@ impl Filtered { #[inline(always)] fn id(&self) -> FilterId { + debug_assert!( + !self.id.0.is_disabled(), + "a `Filtered` layer was used, but it had no `FilterId`; \ + was it registered with the subscriber?" + ); self.id.0 } @@ -504,6 +509,10 @@ impl FilterId { Self(self.0 | other) } + + fn is_disabled(self) -> bool { + self.0 == Self::disabled().0 + } } impl fmt::Debug for FilterId { diff --git a/tracing-subscriber/src/layer/mod.rs b/tracing-subscriber/src/layer/mod.rs index f3a87898e0..5ba89575b4 100644 --- a/tracing-subscriber/src/layer/mod.rs +++ b/tracing-subscriber/src/layer/mod.rs @@ -414,7 +414,11 @@ //! [`LevelFilter`]: crate::filter::LevelFilter //! [feat]: crate#feature-flags use crate::filter; -use std::{any::TypeId, ops::Deref, sync::Arc}; +use std::{ + any::TypeId, + ops::{Deref, DerefMut}, + sync::Arc, +}; use tracing_core::{ metadata::Metadata, span, @@ -1160,6 +1164,15 @@ where L: Layer, S: Subscriber, { + fn on_layer(&mut self, subscriber: &mut S) { + if let Some(inner) = Arc::get_mut(self) { + // XXX(eliza): this may behave weird if another `Arc` clone of this + // layer is layered onto a _different_ subscriber...but there's no + // good solution for that... + inner.on_layer(subscriber); + } + } + layer_impl_body! {} } @@ -1167,6 +1180,15 @@ impl Layer for Arc + Send + Sync> where S: Subscriber, { + fn on_layer(&mut self, subscriber: &mut S) { + if let Some(inner) = Arc::get_mut(self) { + // XXX(eliza): this may behave weird if another `Arc` clone of this + // layer is layered onto a _different_ subscriber...but there's no + // good solution for that... + inner.on_layer(subscriber); + } + } + layer_impl_body! {} } @@ -1175,6 +1197,10 @@ where L: Layer, S: Subscriber, { + fn on_layer(&mut self, subscriber: &mut S) { + self.deref_mut().on_layer(subscriber); + } + layer_impl_body! {} } @@ -1182,6 +1208,10 @@ impl Layer for Box + Send + Sync> where S: Subscriber, { + fn on_layer(&mut self, subscriber: &mut S) { + self.deref_mut().on_layer(subscriber); + } + layer_impl_body! {} } diff --git a/tracing-subscriber/tests/layer_filters/boxed.rs b/tracing-subscriber/tests/layer_filters/boxed.rs new file mode 100644 index 0000000000..4788490a80 --- /dev/null +++ b/tracing-subscriber/tests/layer_filters/boxed.rs @@ -0,0 +1,73 @@ +use super::*; +use std::sync::Arc; +use tracing_subscriber::{filter, prelude::*, Layer}; + +fn layer() -> (ExpectLayer, subscriber::MockHandle) { + layer::mock().done().run_with_handle() +} + +fn filter() -> 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) +} + +/// reproduces https://github.com/tokio-rs/tracing/issues/1563#issuecomment-921363629 +#[test] +fn box_works() { + let (layer, handle) = layer(); + let layer = Box::new(layer.with_filter(filter())); + + let _guard = tracing_subscriber::registry().with(layer).set_default(); + + for i in 0..2 { + tracing::info!(i); + } + + handle.assert_finished(); +} + +/// the same as `box_works` but with a type-erased `Box`. +#[test] +fn dyn_box_works() { + let (layer, handle) = layer(); + let layer: Box + Send + Sync + 'static> = Box::new(layer.with_filter(filter())); + + let _guard = tracing_subscriber::registry().with(layer).set_default(); + + for i in 0..2 { + tracing::info!(i); + } + + handle.assert_finished(); +} + +/// the same as `box_works` but with an `Arc`. +#[test] +fn arc_works() { + let (layer, handle) = layer(); + let layer = Box::new(layer.with_filter(filter())); + + let _guard = tracing_subscriber::registry().with(layer).set_default(); + + for i in 0..2 { + tracing::info!(i); + } + + handle.assert_finished(); +} + +/// the same as `box_works` but with a type-erased `Arc`. +#[test] +fn dyn_arc_works() { + let (layer, handle) = layer(); + let layer: Arc + Send + Sync + 'static> = Arc::new(layer.with_filter(filter())); + + let _guard = tracing_subscriber::registry().with(layer).set_default(); + + for i in 0..2 { + tracing::info!(i); + } + + handle.assert_finished(); +} diff --git a/tracing-subscriber/tests/layer_filters/main.rs b/tracing-subscriber/tests/layer_filters/main.rs index ccc4ef2679..dfe3309c62 100644 --- a/tracing-subscriber/tests/layer_filters/main.rs +++ b/tracing-subscriber/tests/layer_filters/main.rs @@ -2,6 +2,7 @@ #[path = "../support.rs"] mod support; use self::support::*; +mod boxed; mod filter_scopes; mod targets; mod trees;