Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

ensure the None-layer doesn't override the max-level erroneously #2321

Merged
merged 12 commits into from Sep 27, 2022
20 changes: 20 additions & 0 deletions tracing-subscriber/src/reload.rs
Expand Up @@ -23,6 +23,7 @@
use crate::subscribe;
use crate::sync::RwLock;

use core::{any::TypeId, ptr::NonNull};
use std::{
error, fmt,
sync::{Arc, Weak},
Expand Down Expand Up @@ -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"))]
Expand Down
19 changes: 19 additions & 0 deletions tracing-subscriber/src/subscribe/layered.rs
Expand Up @@ -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)
}
}
Expand Down
25 changes: 25 additions & 0 deletions tracing-subscriber/src/subscribe/mod.rs
Expand Up @@ -1492,6 +1492,29 @@ pub struct Identity {

// === impl Subscribe ===

#[derive(Clone, Copy)]
pub(crate) struct NoneLayerMarker(());
pub(crate) static NONE_LAYER_MARKER: NoneLayerMarker = NoneLayerMarker(());
hawkw marked this conversation as resolved.
Show resolved Hide resolved

/// 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()
}

impl<S, C> Subscribe<C> for Option<S>
where
S: Subscribe<C>,
Expand Down Expand Up @@ -1606,6 +1629,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))
}
Expand Down
95 changes: 92 additions & 3 deletions 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<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]
Expand Down Expand Up @@ -39,3 +54,77 @@ 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 doesnt_override_none() {
// 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);

// 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::<LevelFilter>);
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::<LevelFilter>.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::<LevelFilter>.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::<LevelFilter>);
assert_eq!(subscriber.max_level_hint(), Some(LevelFilter::DEBUG));
let subscriber = tracing_subscriber::registry()
.with(BasicLayer(None).with_filter(LevelFilter::DEBUG))
.with(None::<LevelFilter>);
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::<LevelFilter>);
assert_eq!(subscriber.max_level_hint(), Some(LevelFilter::INFO));
}
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

i notice all these tests order the layers so that we have another layer, and then a None. we should probably also have tests that the same cases work when the None layer is on the inside (e.g., Registry, None, BasicLayer instead of Registry, BasicLayer, None)?

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

added tests for this in abd1030 and it turns out we weren't handling that case nicely, so i fixed it in 870ba11. i'm not super happy with the code, but it does at least do the right thing now...


/// 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));
}
hawkw marked this conversation as resolved.
Show resolved Hide resolved