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
14 changes: 14 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,19 @@ 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.
hawkw marked this conversation as resolved.
Show resolved Hide resolved
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
22 changes: 22 additions & 0 deletions tracing-subscriber/src/subscribe/mod.rs
Expand Up @@ -1475,6 +1475,26 @@ 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 --- 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.
hawkw marked this conversation as resolved.
Show resolved Hide resolved
subscriber.downcast_raw(TypeId::of::<NoneLayerMarker>())
}
.is_some()
}

impl<S, C> Subscribe<C> for Option<S>
where
S: Subscribe<C>,
Expand Down Expand Up @@ -1589,6 +1609,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