From 51afb3525de95b723c292ec35f660e6c205cba2c Mon Sep 17 00:00:00 2001 From: Gus Wynn Date: Fri, 23 Sep 2022 10:50:06 -0700 Subject: [PATCH 01/10] ensure the None-layer doesn't override the max-level erroneously --- tracing-subscriber/src/subscribe/layered.rs | 19 +++++++ tracing-subscriber/src/subscribe/mod.rs | 22 +++++++ tracing-subscriber/tests/option.rs | 63 ++++++++++++++++++++- 3 files changed, 101 insertions(+), 3 deletions(-) diff --git a/tracing-subscriber/src/subscribe/layered.rs b/tracing-subscriber/src/subscribe/layered.rs index 787472dea7..c2279aeb89 100644 --- a/tracing-subscriber/src/subscribe/layered.rs +++ b/tracing-subscriber/src/subscribe/layered.rs @@ -494,6 +494,25 @@ where return None; } + // If the subscriber is `Option::None`, then we + // want to short-circuit the layer underneath, if it + // returns `None`, to override the `None` layer returning + // `Some(OFF)`, which should ONLY apply when there are + // no other layers that return `None`. Note this + // `None` does not == `Some(TRACE)`, it means + // something more like: "whatever all the other + // layers agree on, default to `TRACE` if none + // have an opinion". We also choose do this AFTER + // we check for per-subscriber filters, which + // have their own logic. + // + // Also note that this does come at some perf cost, but + // this function is only called on initialization and + // subscriber reloading. + if super::subscriber_is_none(&self.subscriber) { + return cmp::max(outer_hint, Some(inner_hint?)); + } + cmp::max(outer_hint, inner_hint) } } diff --git a/tracing-subscriber/src/subscribe/mod.rs b/tracing-subscriber/src/subscribe/mod.rs index f2b1ec7cbb..96a695309a 100644 --- a/tracing-subscriber/src/subscribe/mod.rs +++ b/tracing-subscriber/src/subscribe/mod.rs @@ -1475,6 +1475,26 @@ pub struct Identity { // === impl Subscribe === +#[derive(Clone, Copy)] +pub(crate) struct NoneLayerMarker; +pub(crate) static NONE_LAYER_MARKER: NoneLayerMarker = NoneLayerMarker; + +/// Does a type implementing `Subscriber` contain any per-subscriber filters? +pub(crate) fn subscriber_is_none(subscriber: &S) -> bool +where + S: Subscribe, + C: Collect, +{ + unsafe { + // Safety: we're not actually *doing* anything with this pointer --- we + // only care about the `Option`, which we're turning into a `bool`. So + // even if the subscriber decides to be evil and give us some kind of invalid + // pointer, we don't ever dereference it, so this is always safe. + subscriber.downcast_raw(TypeId::of::()) + } + .is_some() +} + impl Subscribe for Option where S: Subscribe, @@ -1589,6 +1609,8 @@ where unsafe fn downcast_raw(&self, id: TypeId) -> Option> { if id == TypeId::of::() { Some(NonNull::from(self).cast()) + } else if id == TypeId::of::() && self.is_none() { + Some(NonNull::from(&NONE_LAYER_MARKER).cast()) } else { self.as_ref().and_then(|inner| inner.downcast_raw(id)) } diff --git a/tracing-subscriber/tests/option.rs b/tracing-subscriber/tests/option.rs index a0f127e286..106e2f71e9 100644 --- a/tracing-subscriber/tests/option.rs +++ b/tracing-subscriber/tests/option.rs @@ -1,7 +1,22 @@ #![cfg(feature = "registry")] -use tracing::level_filters::LevelFilter; -use tracing::Collect; -use tracing_subscriber::prelude::*; +use tracing_core::{collect::Interest, Collect, LevelFilter, Metadata}; +use tracing_subscriber::{prelude::*, subscribe}; + +// A basic layer that returns its inner for `max_level_hint` +struct BasicLayer(Option); +impl tracing_subscriber::Subscribe for BasicLayer { + fn register_callsite(&self, _m: &Metadata<'_>) -> Interest { + Interest::sometimes() + } + + fn enabled(&self, _m: &Metadata<'_>, _: subscribe::Context<'_, C>) -> bool { + true + } + + fn max_level_hint(&self) -> Option { + self.0 + } +} // This test is just used to compare to the tests below #[test] @@ -39,3 +54,45 @@ fn just_option_none_subscriber() { let collector = tracing_subscriber::registry().with(Some(LevelFilter::ERROR)); assert_eq!(collector.max_level_hint(), Some(LevelFilter::ERROR)); } + +/// lalal +#[test] +fn doesnt_override_none() { + // None means the other layer takes control + let subscriber = tracing_subscriber::registry() + .with(BasicLayer(None)) + .with(None::); + assert_eq!(subscriber.max_level_hint(), None); + + // The `None`-returning layer still wins + let subscriber = tracing_subscriber::registry() + .with(BasicLayer(None)) + .with(Some(LevelFilter::ERROR)); + assert_eq!(subscriber.max_level_hint(), Some(LevelFilter::ERROR)); + + // Check that we aren't doing anything truly wrong + let subscriber = tracing_subscriber::registry() + .with(BasicLayer(Some(LevelFilter::DEBUG))) + .with(None::); + assert_eq!(subscriber.max_level_hint(), Some(LevelFilter::DEBUG)); + + // Test that per-subscriber filters aren't affected + + // One layer is None so it "wins" + let subscriber = tracing_subscriber::registry() + .with(BasicLayer(None)) + .with(None::.with_filter(LevelFilter::DEBUG)); + assert_eq!(subscriber.max_level_hint(), None); + + // The max-levels wins + let subscriber = tracing_subscriber::registry() + .with(BasicLayer(Some(LevelFilter::INFO))) + .with(None::.with_filter(LevelFilter::DEBUG)); + assert_eq!(subscriber.max_level_hint(), Some(LevelFilter::DEBUG)); + + // The `OFF` from `None` over overridden. + let subscriber = tracing_subscriber::registry() + .with(BasicLayer(Some(LevelFilter::INFO))) + .with(None::); + assert_eq!(subscriber.max_level_hint(), Some(LevelFilter::INFO)); +} From aed92ac011a9fbc9a0bb9d6ddc124e65427eaa0a Mon Sep 17 00:00:00 2001 From: Gus Wynn Date: Fri, 23 Sep 2022 11:05:56 -0700 Subject: [PATCH 02/10] allow the none-downcast works through the reload subscriber --- tracing-subscriber/src/reload.rs | 14 ++++++++++++++ tracing-subscriber/tests/option.rs | 22 ++++++++++++++++++++++ 2 files changed, 36 insertions(+) diff --git a/tracing-subscriber/src/reload.rs b/tracing-subscriber/src/reload.rs index f1fa0f1f76..33514a9497 100644 --- a/tracing-subscriber/src/reload.rs +++ b/tracing-subscriber/src/reload.rs @@ -23,6 +23,7 @@ use crate::subscribe; use crate::sync::RwLock; +use core::{any::TypeId, ptr::NonNull}; use std::{ error, fmt, sync::{Arc, Weak}, @@ -144,6 +145,19 @@ where fn max_level_hint(&self) -> Option { try_lock!(self.inner.read(), else return None).max_level_hint() } + + #[doc(hidden)] + unsafe fn downcast_raw(&self, id: TypeId) -> Option> { + // It is generally unsafe to downcast through a reload, because + // the pointer can be invalidated after the lock is dropped. + // `NoneLayerMarker` is a special case because it + // is never dereferenced. + if id == TypeId::of::() { + return try_lock!(self.inner.read(), else return None).downcast_raw(id); + } + + None + } } #[cfg(all(feature = "registry", feature = "std"))] diff --git a/tracing-subscriber/tests/option.rs b/tracing-subscriber/tests/option.rs index 106e2f71e9..1c603172f0 100644 --- a/tracing-subscriber/tests/option.rs +++ b/tracing-subscriber/tests/option.rs @@ -96,3 +96,25 @@ fn doesnt_override_none() { .with(None::); assert_eq!(subscriber.max_level_hint(), Some(LevelFilter::INFO)); } + +/// lalal +#[test] +fn reload_works_with_none() { + let (subscriber1, handle1) = tracing_subscriber::reload::Subscriber::new(None::); + let (subscriber2, _handle2) = tracing_subscriber::reload::Subscriber::new(None::); + + let subscriber = tracing_subscriber::registry() + .with(subscriber1) + .with(subscriber2); + assert_eq!(subscriber.max_level_hint(), Some(LevelFilter::OFF)); + + // reloading one should pass through correctly. + handle1.reload(Some(BasicLayer(None))).unwrap(); + assert_eq!(subscriber.max_level_hint(), None); + + // Check pass-through of an actual level as well + handle1 + .reload(Some(BasicLayer(Some(LevelFilter::DEBUG)))) + .unwrap(); + assert_eq!(subscriber.max_level_hint(), Some(LevelFilter::DEBUG)); +} From 56749e326b9f1848f448a856b33292f559ac21af Mon Sep 17 00:00:00 2001 From: Gus Wynn Date: Fri, 23 Sep 2022 16:05:08 -0700 Subject: [PATCH 03/10] fix nits and comments --- tracing-subscriber/src/reload.rs | 2 +- tracing-subscriber/src/subscribe/mod.rs | 2 +- tracing-subscriber/tests/option.rs | 4 ++-- 3 files changed, 4 insertions(+), 4 deletions(-) diff --git a/tracing-subscriber/src/reload.rs b/tracing-subscriber/src/reload.rs index 33514a9497..f447a5f494 100644 --- a/tracing-subscriber/src/reload.rs +++ b/tracing-subscriber/src/reload.rs @@ -148,7 +148,7 @@ where #[doc(hidden)] unsafe fn downcast_raw(&self, id: TypeId) -> Option> { - // It is generally unsafe to downcast through a reload, because + // Safety: It is generally unsafe to downcast through a reload, because // the pointer can be invalidated after the lock is dropped. // `NoneLayerMarker` is a special case because it // is never dereferenced. diff --git a/tracing-subscriber/src/subscribe/mod.rs b/tracing-subscriber/src/subscribe/mod.rs index 96a695309a..7e2ef3e0c9 100644 --- a/tracing-subscriber/src/subscribe/mod.rs +++ b/tracing-subscriber/src/subscribe/mod.rs @@ -1479,7 +1479,7 @@ pub struct Identity { pub(crate) struct NoneLayerMarker; pub(crate) static NONE_LAYER_MARKER: NoneLayerMarker = NoneLayerMarker; -/// Does a type implementing `Subscriber` contain any per-subscriber filters? +/// Is a type implementing `Subscriber` `Option::<_>::None`? pub(crate) fn subscriber_is_none(subscriber: &S) -> bool where S: Subscribe, diff --git a/tracing-subscriber/tests/option.rs b/tracing-subscriber/tests/option.rs index 1c603172f0..8cdf79496b 100644 --- a/tracing-subscriber/tests/option.rs +++ b/tracing-subscriber/tests/option.rs @@ -55,7 +55,7 @@ fn just_option_none_subscriber() { assert_eq!(collector.max_level_hint(), Some(LevelFilter::ERROR)); } -/// lalal +/// Test that the `None` max level hint only applies if its the only layer #[test] fn doesnt_override_none() { // None means the other layer takes control @@ -97,7 +97,7 @@ fn doesnt_override_none() { assert_eq!(subscriber.max_level_hint(), Some(LevelFilter::INFO)); } -/// lalal +/// Tests that the logic tested in `doesnt_override_none` works through the reload subscriber #[test] fn reload_works_with_none() { let (subscriber1, handle1) = tracing_subscriber::reload::Subscriber::new(None::); From 8c90a4f2544939ec7d282d4eda77b9250fd82d7e Mon Sep 17 00:00:00 2001 From: Gus Wynn Date: Fri, 23 Sep 2022 16:11:04 -0700 Subject: [PATCH 04/10] add 2 more tests --- tracing-subscriber/tests/option.rs | 10 ++++++++++ 1 file changed, 10 insertions(+) diff --git a/tracing-subscriber/tests/option.rs b/tracing-subscriber/tests/option.rs index 8cdf79496b..7be122e729 100644 --- a/tracing-subscriber/tests/option.rs +++ b/tracing-subscriber/tests/option.rs @@ -90,6 +90,16 @@ fn doesnt_override_none() { .with(None::.with_filter(LevelFilter::DEBUG)); assert_eq!(subscriber.max_level_hint(), Some(LevelFilter::DEBUG)); + // Test filter on the other layer + let subscriber = tracing_subscriber::registry() + .with(BasicLayer(Some(LevelFilter::INFO)).with_filter(LevelFilter::DEBUG)) + .with(None::); + assert_eq!(subscriber.max_level_hint(), Some(LevelFilter::DEBUG)); + let subscriber = tracing_subscriber::registry() + .with(BasicLayer(None).with_filter(LevelFilter::DEBUG)) + .with(None::); + assert_eq!(subscriber.max_level_hint(), Some(LevelFilter::DEBUG)); + // The `OFF` from `None` over overridden. let subscriber = tracing_subscriber::registry() .with(BasicLayer(Some(LevelFilter::INFO))) From 3b9a32e1eafeea5332a367d3cf3db208aa6fe1f9 Mon Sep 17 00:00:00 2001 From: Eliza Weisman Date: Mon, 26 Sep 2022 10:39:44 -0700 Subject: [PATCH 05/10] Apply suggestions from code review --- tracing-subscriber/src/reload.rs | 8 +++++++- tracing-subscriber/src/subscribe/mod.rs | 15 +++++++++------ 2 files changed, 16 insertions(+), 7 deletions(-) diff --git a/tracing-subscriber/src/reload.rs b/tracing-subscriber/src/reload.rs index f447a5f494..22370cc45d 100644 --- a/tracing-subscriber/src/reload.rs +++ b/tracing-subscriber/src/reload.rs @@ -148,10 +148,16 @@ where #[doc(hidden)] unsafe fn downcast_raw(&self, id: TypeId) -> Option> { - // Safety: It is generally unsafe to downcast through a reload, because + // Safety: it is generally unsafe to downcast through a reload, because // the pointer can be invalidated after the lock is dropped. // `NoneLayerMarker` is a special case because it // is never dereferenced. + // + // Additionally, even if the marker type *is* dereferenced (which it + // never will be), the pointer should be valid even if the subscriber + // is reloaded, because all `NoneLayerMarker` pointers that we return + // actually point to the global static singleton `NoneLayerMarker`, + // rather than to a field inside the lock. if id == TypeId::of::() { return try_lock!(self.inner.read(), else return None).downcast_raw(id); } diff --git a/tracing-subscriber/src/subscribe/mod.rs b/tracing-subscriber/src/subscribe/mod.rs index e40e65a397..5041459866 100644 --- a/tracing-subscriber/src/subscribe/mod.rs +++ b/tracing-subscriber/src/subscribe/mod.rs @@ -1493,8 +1493,8 @@ pub struct Identity { // === impl Subscribe === #[derive(Clone, Copy)] -pub(crate) struct NoneLayerMarker; -pub(crate) static NONE_LAYER_MARKER: NoneLayerMarker = NoneLayerMarker; +pub(crate) struct NoneLayerMarker(()); +pub(crate) static NONE_LAYER_MARKER: NoneLayerMarker = NoneLayerMarker(()); /// Is a type implementing `Subscriber` `Option::<_>::None`? pub(crate) fn subscriber_is_none(subscriber: &S) -> bool @@ -1503,10 +1503,13 @@ where C: Collect, { unsafe { - // Safety: we're not actually *doing* anything with this pointer --- we - // only care about the `Option`, which we're turning into a `bool`. So - // even if the subscriber decides to be evil and give us some kind of invalid - // pointer, we don't ever dereference it, so this is always safe. + // Safety: we're not actually *doing* anything with this pointer --- + // this only care about the `Option`, which is essentially being used + // as a bool. We can rely on the pointer being valid, because it is + // a crate-private type, and is only returned by the `Subscribe` impl + // for `Option`s. However, even if the subscriber *does* decide to be + // evil and give us an invalid pointer here, that's fine, because we'll + // never actually dereference it. subscriber.downcast_raw(TypeId::of::()) } .is_some() From 582f3e96240308109cd65e397eae7cf909c8c2f6 Mon Sep 17 00:00:00 2001 From: Eliza Weisman Date: Mon, 26 Sep 2022 10:42:50 -0700 Subject: [PATCH 06/10] Update tracing-subscriber/src/subscribe/mod.rs --- 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 5041459866..c0cf7d8dfc 100644 --- a/tracing-subscriber/src/subscribe/mod.rs +++ b/tracing-subscriber/src/subscribe/mod.rs @@ -1494,7 +1494,7 @@ pub struct Identity { #[derive(Clone, Copy)] pub(crate) struct NoneLayerMarker(()); -pub(crate) static NONE_LAYER_MARKER: NoneLayerMarker = NoneLayerMarker(()); +static NONE_LAYER_MARKER: NoneLayerMarker = NoneLayerMarker(()); /// Is a type implementing `Subscriber` `Option::<_>::None`? pub(crate) fn subscriber_is_none(subscriber: &S) -> bool From abd1030951ead86a517116d9b5d87da8b4512d30 Mon Sep 17 00:00:00 2001 From: Eliza Weisman Date: Mon, 26 Sep 2022 10:49:04 -0700 Subject: [PATCH 07/10] add tests with the `None` before the layer --- tracing-subscriber/tests/option.rs | 56 ++++++++++++++++++++++++++++-- 1 file changed, 54 insertions(+), 2 deletions(-) diff --git a/tracing-subscriber/tests/option.rs b/tracing-subscriber/tests/option.rs index 7be122e729..31936e0237 100644 --- a/tracing-subscriber/tests/option.rs +++ b/tracing-subscriber/tests/option.rs @@ -55,9 +55,9 @@ fn just_option_none_subscriber() { assert_eq!(collector.max_level_hint(), Some(LevelFilter::ERROR)); } -/// Test that the `None` max level hint only applies if its the only layer +// Test that the `None` max level hint only applies if its the only layer #[test] -fn doesnt_override_none() { +fn none_outside_doesnt_override_max_level() { // None means the other layer takes control let subscriber = tracing_subscriber::registry() .with(BasicLayer(None)) @@ -107,6 +107,58 @@ fn doesnt_override_none() { assert_eq!(subscriber.max_level_hint(), Some(LevelFilter::INFO)); } +// Test that the `None` max level hint only applies if its the only layer +#[test] +fn none_inside_doesnt_override_max_level() { + // None means the other layer takes control + let subscriber = tracing_subscriber::registry() + .with(None::) + .with(BasicLayer(None)); + assert_eq!(subscriber.max_level_hint(), None); + + // The `None`-returning layer still wins + let subscriber = tracing_subscriber::registry() + .with(Some(LevelFilter::ERROR)) + .with(BasicLayer(None)); + assert_eq!(subscriber.max_level_hint(), Some(LevelFilter::ERROR)); + + // Check that we aren't doing anything truly wrong + let subscriber = tracing_subscriber::registry() + .with(None::) + .with(BasicLayer(Some(LevelFilter::DEBUG))); + assert_eq!(subscriber.max_level_hint(), Some(LevelFilter::DEBUG)); + + // Test that per-subscriber filters aren't affected + + // One layer is None so it "wins" + let subscriber = tracing_subscriber::registry() + .with(None::.with_filter(LevelFilter::DEBUG)) + .with(BasicLayer(None)); + assert_eq!(subscriber.max_level_hint(), None); + + // The max-levels wins + let subscriber = tracing_subscriber::registry() + .with(None::.with_filter(LevelFilter::DEBUG)) + .with(BasicLayer(Some(LevelFilter::INFO))); + assert_eq!(subscriber.max_level_hint(), Some(LevelFilter::DEBUG)); + + // Test filter on the other layer + let subscriber = tracing_subscriber::registry() + .with(None::) + .with(BasicLayer(Some(LevelFilter::INFO)).with_filter(LevelFilter::DEBUG)); + assert_eq!(subscriber.max_level_hint(), Some(LevelFilter::DEBUG)); + let subscriber = tracing_subscriber::registry() + .with(None::) + .with(BasicLayer(None).with_filter(LevelFilter::DEBUG)); + assert_eq!(subscriber.max_level_hint(), Some(LevelFilter::DEBUG)); + + // The `OFF` from `None` over overridden. + let subscriber = tracing_subscriber::registry() + .with(None::) + .with(BasicLayer(Some(LevelFilter::INFO))); + assert_eq!(subscriber.max_level_hint(), Some(LevelFilter::INFO)); +} + /// Tests that the logic tested in `doesnt_override_none` works through the reload subscriber #[test] fn reload_works_with_none() { From c6926701c6f7f1c316c1424b1058b2d2c0861649 Mon Sep 17 00:00:00 2001 From: Eliza Weisman Date: Mon, 26 Sep 2022 10:54:13 -0700 Subject: [PATCH 08/10] have the tests actually print the failing subscriber this should make these a little easier to debug --- tracing-subscriber/tests/option.rs | 113 +++++++++++++++++++++++++---- 1 file changed, 97 insertions(+), 16 deletions(-) diff --git a/tracing-subscriber/tests/option.rs b/tracing-subscriber/tests/option.rs index 31936e0237..92585e700b 100644 --- a/tracing-subscriber/tests/option.rs +++ b/tracing-subscriber/tests/option.rs @@ -3,6 +3,7 @@ use tracing_core::{collect::Interest, Collect, LevelFilter, Metadata}; use tracing_subscriber::{prelude::*, subscribe}; // A basic layer that returns its inner for `max_level_hint` +#[derive(Debug)] struct BasicLayer(Option); impl tracing_subscriber::Subscribe for BasicLayer { fn register_callsite(&self, _m: &Metadata<'_>) -> Interest { @@ -62,19 +63,34 @@ fn none_outside_doesnt_override_max_level() { let subscriber = tracing_subscriber::registry() .with(BasicLayer(None)) .with(None::); - assert_eq!(subscriber.max_level_hint(), None); + assert_eq!( + subscriber.max_level_hint(), + None, + "\n stack: {:#?}", + subscriber + ); // The `None`-returning layer still wins let subscriber = tracing_subscriber::registry() .with(BasicLayer(None)) .with(Some(LevelFilter::ERROR)); - assert_eq!(subscriber.max_level_hint(), Some(LevelFilter::ERROR)); + assert_eq!( + subscriber.max_level_hint(), + Some(LevelFilter::ERROR), + "\n stack: {:#?}", + subscriber + ); // Check that we aren't doing anything truly wrong let subscriber = tracing_subscriber::registry() .with(BasicLayer(Some(LevelFilter::DEBUG))) .with(None::); - assert_eq!(subscriber.max_level_hint(), Some(LevelFilter::DEBUG)); + assert_eq!( + subscriber.max_level_hint(), + Some(LevelFilter::DEBUG), + "\n stack: {:#?}", + subscriber + ); // Test that per-subscriber filters aren't affected @@ -82,29 +98,54 @@ fn none_outside_doesnt_override_max_level() { let subscriber = tracing_subscriber::registry() .with(BasicLayer(None)) .with(None::.with_filter(LevelFilter::DEBUG)); - assert_eq!(subscriber.max_level_hint(), None); + assert_eq!( + subscriber.max_level_hint(), + None, + "\n stack: {:#?}", + subscriber + ); // The max-levels wins let subscriber = tracing_subscriber::registry() .with(BasicLayer(Some(LevelFilter::INFO))) .with(None::.with_filter(LevelFilter::DEBUG)); - assert_eq!(subscriber.max_level_hint(), Some(LevelFilter::DEBUG)); + assert_eq!( + subscriber.max_level_hint(), + Some(LevelFilter::DEBUG), + "\n stack: {:#?}", + subscriber + ); // Test filter on the other layer let subscriber = tracing_subscriber::registry() .with(BasicLayer(Some(LevelFilter::INFO)).with_filter(LevelFilter::DEBUG)) .with(None::); - assert_eq!(subscriber.max_level_hint(), Some(LevelFilter::DEBUG)); + assert_eq!( + subscriber.max_level_hint(), + Some(LevelFilter::DEBUG), + "\n stack: {:#?}", + subscriber + ); let subscriber = tracing_subscriber::registry() .with(BasicLayer(None).with_filter(LevelFilter::DEBUG)) .with(None::); - assert_eq!(subscriber.max_level_hint(), Some(LevelFilter::DEBUG)); + assert_eq!( + subscriber.max_level_hint(), + Some(LevelFilter::DEBUG), + "\n stack: {:#?}", + subscriber + ); // The `OFF` from `None` over overridden. let subscriber = tracing_subscriber::registry() .with(BasicLayer(Some(LevelFilter::INFO))) .with(None::); - assert_eq!(subscriber.max_level_hint(), Some(LevelFilter::INFO)); + assert_eq!( + subscriber.max_level_hint(), + Some(LevelFilter::INFO), + "\n stack: {:#?}", + subscriber + ); } // Test that the `None` max level hint only applies if its the only layer @@ -114,19 +155,34 @@ fn none_inside_doesnt_override_max_level() { let subscriber = tracing_subscriber::registry() .with(None::) .with(BasicLayer(None)); - assert_eq!(subscriber.max_level_hint(), None); + assert_eq!( + subscriber.max_level_hint(), + None, + "\n stack: {:#?}", + subscriber + ); // The `None`-returning layer still wins let subscriber = tracing_subscriber::registry() .with(Some(LevelFilter::ERROR)) .with(BasicLayer(None)); - assert_eq!(subscriber.max_level_hint(), Some(LevelFilter::ERROR)); + assert_eq!( + subscriber.max_level_hint(), + Some(LevelFilter::ERROR), + "\n stack: {:#?}", + subscriber + ); // Check that we aren't doing anything truly wrong let subscriber = tracing_subscriber::registry() .with(None::) .with(BasicLayer(Some(LevelFilter::DEBUG))); - assert_eq!(subscriber.max_level_hint(), Some(LevelFilter::DEBUG)); + assert_eq!( + subscriber.max_level_hint(), + Some(LevelFilter::DEBUG), + "\n stack: {:#?}", + subscriber + ); // Test that per-subscriber filters aren't affected @@ -134,29 +190,54 @@ fn none_inside_doesnt_override_max_level() { let subscriber = tracing_subscriber::registry() .with(None::.with_filter(LevelFilter::DEBUG)) .with(BasicLayer(None)); - assert_eq!(subscriber.max_level_hint(), None); + assert_eq!( + subscriber.max_level_hint(), + None, + "\n stack: {:#?}", + subscriber + ); // The max-levels wins let subscriber = tracing_subscriber::registry() .with(None::.with_filter(LevelFilter::DEBUG)) .with(BasicLayer(Some(LevelFilter::INFO))); - assert_eq!(subscriber.max_level_hint(), Some(LevelFilter::DEBUG)); + assert_eq!( + subscriber.max_level_hint(), + Some(LevelFilter::DEBUG), + "\n stack: {:#?}", + subscriber + ); // Test filter on the other layer let subscriber = tracing_subscriber::registry() .with(None::) .with(BasicLayer(Some(LevelFilter::INFO)).with_filter(LevelFilter::DEBUG)); - assert_eq!(subscriber.max_level_hint(), Some(LevelFilter::DEBUG)); + assert_eq!( + subscriber.max_level_hint(), + Some(LevelFilter::DEBUG), + "\n stack: {:#?}", + subscriber + ); let subscriber = tracing_subscriber::registry() .with(None::) .with(BasicLayer(None).with_filter(LevelFilter::DEBUG)); - assert_eq!(subscriber.max_level_hint(), Some(LevelFilter::DEBUG)); + assert_eq!( + subscriber.max_level_hint(), + Some(LevelFilter::DEBUG), + "\n stack: {:#?}", + subscriber + ); // The `OFF` from `None` over overridden. let subscriber = tracing_subscriber::registry() .with(None::) .with(BasicLayer(Some(LevelFilter::INFO))); - assert_eq!(subscriber.max_level_hint(), Some(LevelFilter::INFO)); + assert_eq!( + subscriber.max_level_hint(), + Some(LevelFilter::INFO), + "\n stack: {:#?}", + subscriber + ); } /// Tests that the logic tested in `doesnt_override_none` works through the reload subscriber From 870ba11ec3dd91b0fd4ffe2a3fe1c96e82f88944 Mon Sep 17 00:00:00 2001 From: Eliza Weisman Date: Mon, 26 Sep 2022 11:04:08 -0700 Subject: [PATCH 09/10] fix off hints still overriding when `None` is inside --- tracing-subscriber/src/subscribe/layered.rs | 20 +++++++++++++++----- tracing-subscriber/src/subscribe/mod.rs | 18 ++++++++++++++++++ 2 files changed, 33 insertions(+), 5 deletions(-) diff --git a/tracing-subscriber/src/subscribe/layered.rs b/tracing-subscriber/src/subscribe/layered.rs index c2279aeb89..dd72fbf4fb 100644 --- a/tracing-subscriber/src/subscribe/layered.rs +++ b/tracing-subscriber/src/subscribe/layered.rs @@ -18,6 +18,8 @@ use core::{ ptr::NonNull, }; +use super::subscriber_is_none; + /// A [collector] composed of a [collector] wrapped by one or more /// [subscriber]s. /// @@ -119,6 +121,7 @@ where self.pick_level_hint( self.subscriber.max_level_hint(), self.inner.max_level_hint(), + super::collector_is_none(&self.inner), ) } @@ -274,6 +277,7 @@ where self.pick_level_hint( self.subscriber.max_level_hint(), self.inner.max_level_hint(), + super::subscriber_is_none(&self.inner), ) } @@ -374,10 +378,9 @@ where .and(self.inner.downcast_raw(id)), // Otherwise, try to downcast both branches normally... - _ => self - .subscriber - .downcast_raw(id) - .or_else(|| self.inner.downcast_raw(id)), + _ => { + dbg!(self.subscriber.downcast_raw(id)).or_else(|| dbg!(self.inner.downcast_raw(id))) + } } } } @@ -477,6 +480,7 @@ where &self, outer_hint: Option, inner_hint: Option, + inner_is_none: bool, ) -> Option { if self.inner_is_registry { return outer_hint; @@ -509,10 +513,16 @@ where // Also note that this does come at some perf cost, but // this function is only called on initialization and // subscriber reloading. - if super::subscriber_is_none(&self.subscriber) { + if dbg!(super::subscriber_is_none(&self.subscriber)) { return cmp::max(outer_hint, Some(inner_hint?)); } + // Similarly, if the layer on the inside is `None` and it returned an + // `Off` hint, we want to override that with the outer hint. + if inner_is_none && inner_hint == Some(LevelFilter::OFF) { + return outer_hint; + } + cmp::max(outer_hint, inner_hint) } } diff --git a/tracing-subscriber/src/subscribe/mod.rs b/tracing-subscriber/src/subscribe/mod.rs index c0cf7d8dfc..a18d95fc5a 100644 --- a/tracing-subscriber/src/subscribe/mod.rs +++ b/tracing-subscriber/src/subscribe/mod.rs @@ -1515,6 +1515,24 @@ where .is_some() } +/// Is a type implementing `Collect` `Option::<_>::None`? +pub(crate) fn collector_is_none(collector: &C) -> bool +where + C: Collect, +{ + unsafe { + // Safety: we're not actually *doing* anything with this pointer --- + // this only care about the `Option`, which is essentially being used + // as a bool. We can rely on the pointer being valid, because it is + // a crate-private type, and is only returned by the `Subscribe` impl + // for `Option`s. However, even if the subscriber *does* decide to be + // evil and give us an invalid pointer here, that's fine, because we'll + // never actually dereference it. + collector.downcast_raw(TypeId::of::()) + } + .is_some() +} + impl Subscribe for Option where S: Subscribe, From 64774e5c3df41d73335a674f739a6a52ffb65b70 Mon Sep 17 00:00:00 2001 From: Eliza Weisman Date: Mon, 26 Sep 2022 11:08:09 -0700 Subject: [PATCH 10/10] fixup --- tracing-subscriber/src/subscribe/layered.rs | 11 +++++------ 1 file changed, 5 insertions(+), 6 deletions(-) diff --git a/tracing-subscriber/src/subscribe/layered.rs b/tracing-subscriber/src/subscribe/layered.rs index dd72fbf4fb..bc67cc10af 100644 --- a/tracing-subscriber/src/subscribe/layered.rs +++ b/tracing-subscriber/src/subscribe/layered.rs @@ -18,8 +18,6 @@ use core::{ ptr::NonNull, }; -use super::subscriber_is_none; - /// A [collector] composed of a [collector] wrapped by one or more /// [subscriber]s. /// @@ -378,9 +376,10 @@ where .and(self.inner.downcast_raw(id)), // Otherwise, try to downcast both branches normally... - _ => { - dbg!(self.subscriber.downcast_raw(id)).or_else(|| dbg!(self.inner.downcast_raw(id))) - } + _ => self + .subscriber + .downcast_raw(id) + .or_else(|| self.inner.downcast_raw(id)), } } } @@ -513,7 +512,7 @@ where // Also note that this does come at some perf cost, but // this function is only called on initialization and // subscriber reloading. - if dbg!(super::subscriber_is_none(&self.subscriber)) { + if super::subscriber_is_none(&self.subscriber) { return cmp::max(outer_hint, Some(inner_hint?)); }