subscriber: fix None subscribers setting the max level to OFF (#2321

)

## Motivation

Currently, when using the `Subscribe` impl for `Option<S:
Subscribe<...>>`, the `Subscribe::max_level_hint` returns
`Some(LevelFilter::OFF)`. This was intended to allow totally disabling
output in the case where a collector is composed entirely of `None`
subscribers. However, when other subscribers *do* exist but return
`None` from their `max_level_hint` implementations to indicate that they
don't care what the max level is, the presence of a single `None` layer
will globally disable everything, which is not the wanted behavior.

Fixes #2265

## Solution

This branch introduces a special downcast marker that can be used to
detect when a `Subscribe` in a `Layered` is `None`. This allows the
`pick_level_hint` method to short-circuit when a `Subscribe`
implementation which is `None` returns `Some(LevelFilter::OFF)` from its
`max_level_hint` if the other half of the `Layered` is not `None`. The
tests I added should be pretty thorough!

Additionally, the downcast marker is special-cased in the `reload`
subscriber. Normally, this subscriber doesn't support downcasting, but
it can in the case of the special marker value.

Co-authored-by: Eliza Weisman <eliza@buoyant.io>

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,25 @@ where
     fn max_level_hint(&self) -> Option<LevelFilter> {
         try_lock!(self.inner.read(), else return None).max_level_hint()
     }
+
+    #[doc(hidden)]
+    unsafe fn downcast_raw(&self, id: TypeId) -> Option<NonNull<()>> {
+        // 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::<subscribe::NoneLayerMarker>() {
+            return try_lock!(self.inner.read(), else return None).downcast_raw(id);
+        }
+
+        None
+    }
 }
 
 #[cfg(all(feature = "registry", feature = "std"))]

tracing-subscriber/src/subscribe/layered.rs

@@ -119,6 +119,7 @@ where
         self.pick_level_hint(
             self.subscriber.max_level_hint(),
             self.inner.max_level_hint(),
+            super::collector_is_none(&self.inner),
         )
     }
 
@@ -274,6 +275,7 @@ where
         self.pick_level_hint(
             self.subscriber.max_level_hint(),
             self.inner.max_level_hint(),
+            super::subscriber_is_none(&self.inner),
         )
     }
 
@@ -477,6 +479,7 @@ where
         &self,
         outer_hint: Option<LevelFilter>,
         inner_hint: Option<LevelFilter>,
+        inner_is_none: bool,
     ) -> Option<LevelFilter> {
         if self.inner_is_registry {
             return outer_hint;
@@ -494,6 +497,31 @@ 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?));
+        }
+
+        // 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)
     }
 }

tracing-subscriber/src/subscribe/mod.rs

@@ -1492,6 +1492,47 @@ pub struct Identity {
 
 // === impl Subscribe ===
 
+#[derive(Clone, Copy)]
+pub(crate) struct NoneLayerMarker(());
+static NONE_LAYER_MARKER: NoneLayerMarker = NoneLayerMarker(());
+
+/// Is a type implementing `Subscriber` `Option::<_>::None`?
+pub(crate) fn subscriber_is_none<S, C>(subscriber: &S) -> bool
+where
+    S: Subscribe<C>,
+    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.
+        subscriber.downcast_raw(TypeId::of::<NoneLayerMarker>())
+    }
+    .is_some()
+}
+
+/// Is a type implementing `Collect` `Option::<_>::None`?
+pub(crate) fn collector_is_none<C>(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::<NoneLayerMarker>())
+    }
+    .is_some()
+}
+
 impl<S, C> Subscribe<C> for Option<S>
 where
     S: Subscribe<C>,
@@ -1606,6 +1647,8 @@ where
     unsafe fn downcast_raw(&self, id: TypeId) -> Option<NonNull<()>> {
         if id == TypeId::of::<Self>() {
             Some(NonNull::from(self).cast())
+        } else if id == TypeId::of::<NoneLayerMarker>() && self.is_none() {
+            Some(NonNull::from(&NONE_LAYER_MARKER).cast())
         } else {
             self.as_ref().and_then(|inner| inner.downcast_raw(id))
         }

tracing-subscriber/tests/option.rs

@@ -1,7 +1,23 @@
 #![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`
+#[derive(Debug)]
+struct BasicLayer(Option<LevelFilter>);
+impl<C: Collect> tracing_subscriber::Subscribe<C> 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<LevelFilter> {
+        self.0
+    }
+}
 
 // This test is just used to compare to the tests below
 #[test]
@@ -39,3 +55,209 @@ fn just_option_none_subscriber() {
     let collector = tracing_subscriber::registry().with(Some(LevelFilter::ERROR));
     assert_eq!(collector.max_level_hint(), Some(LevelFilter::ERROR));
 }
+
+// Test that the `None` max level hint only applies if its the only layer
+#[test]
+fn none_outside_doesnt_override_max_level() {
+    // None means the other layer takes control
+    let subscriber = tracing_subscriber::registry()
+        .with(BasicLayer(None))
+        .with(None::<LevelFilter>);
+    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),
+        "\n stack: {:#?}",
+        subscriber
+    );
+
+    // Check that we aren't doing anything truly wrong
+    let subscriber = tracing_subscriber::registry()
+        .with(BasicLayer(Some(LevelFilter::DEBUG)))
+        .with(None::<LevelFilter>);
+    assert_eq!(
+        subscriber.max_level_hint(),
+        Some(LevelFilter::DEBUG),
+        "\n stack: {:#?}",
+        subscriber
+    );
+
+    // 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::<LevelFilter>.with_filter(LevelFilter::DEBUG));
+    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::<LevelFilter>.with_filter(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::<LevelFilter>);
+    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::<LevelFilter>);
+    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::<LevelFilter>);
+    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
+#[test]
+fn none_inside_doesnt_override_max_level() {
+    // None means the other layer takes control
+    let subscriber = tracing_subscriber::registry()
+        .with(None::<LevelFilter>)
+        .with(BasicLayer(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),
+        "\n stack: {:#?}",
+        subscriber
+    );
+
+    // Check that we aren't doing anything truly wrong
+    let subscriber = tracing_subscriber::registry()
+        .with(None::<LevelFilter>)
+        .with(BasicLayer(Some(LevelFilter::DEBUG)));
+    assert_eq!(
+        subscriber.max_level_hint(),
+        Some(LevelFilter::DEBUG),
+        "\n stack: {:#?}",
+        subscriber
+    );
+
+    // Test that per-subscriber filters aren't affected
+
+    // One layer is None so it "wins"
+    let subscriber = tracing_subscriber::registry()
+        .with(None::<LevelFilter>.with_filter(LevelFilter::DEBUG))
+        .with(BasicLayer(None));
+    assert_eq!(
+        subscriber.max_level_hint(),
+        None,
+        "\n stack: {:#?}",
+        subscriber
+    );
+
+    // The max-levels wins
+    let subscriber = tracing_subscriber::registry()
+        .with(None::<LevelFilter>.with_filter(LevelFilter::DEBUG))
+        .with(BasicLayer(Some(LevelFilter::INFO)));
+    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::<LevelFilter>)
+        .with(BasicLayer(Some(LevelFilter::INFO)).with_filter(LevelFilter::DEBUG));
+    assert_eq!(
+        subscriber.max_level_hint(),
+        Some(LevelFilter::DEBUG),
+        "\n stack: {:#?}",
+        subscriber
+    );
+    let subscriber = tracing_subscriber::registry()
+        .with(None::<LevelFilter>)
+        .with(BasicLayer(None).with_filter(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::<LevelFilter>)
+        .with(BasicLayer(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
+#[test]
+fn reload_works_with_none() {
+    let (subscriber1, handle1) = tracing_subscriber::reload::Subscriber::new(None::<BasicLayer>);
+    let (subscriber2, _handle2) = tracing_subscriber::reload::Subscriber::new(None::<BasicLayer>);
+
+    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));
+}