Skip to content

Commit

Permalink
subscriber: fix None layers setting the max level to OFF (tokio-r…
Browse files Browse the repository at this point in the history
…s#2321)

## Motivation

Currently, when using the `Layer` impl for `Option<S: Layer<...>>`, the
`Layer::max_level_hint` returns  `Some(LevelFilter::OFF)`. This was
intended to allow totally disabling output in the case where a
`Subscriber` is composed entirely of `None` `Layer`s. However, when
other `Layer`s *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 tokio-rs#2265

## Solution

This branch introduces a special downcast marker that can be used to
detect when a `Layer` in a `Layered` is `None`. This allows the
`pick_level_hint` method to short-circuit when a `Layer` 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`
`Layer`. Normally, this `Layer` doesn't support downcasting, but it can
in the case of the special marker value.

Co-authored-by: Eliza Weisman <eliza@buoyant.io>
  • Loading branch information
2 people authored and kaffarell committed May 22, 2024
1 parent 5a00f7b commit d7f72fc
Show file tree
Hide file tree
Showing 3 changed files with 284 additions and 2 deletions.
38 changes: 36 additions & 2 deletions tracing-subscriber/src/layer/layered.rs
Original file line number Diff line number Diff line change
Expand Up @@ -115,7 +115,11 @@ where
}

fn max_level_hint(&self) -> Option<LevelFilter> {
self.pick_level_hint(self.layer.max_level_hint(), self.inner.max_level_hint())
self.pick_level_hint(
self.layer.max_level_hint(),
self.inner.max_level_hint(),
super::subscriber_is_none(&self.inner),
)
}

fn new_span(&self, span: &span::Attributes<'_>) -> span::Id {
Expand Down Expand Up @@ -267,7 +271,11 @@ where
}

fn max_level_hint(&self) -> Option<LevelFilter> {
self.pick_level_hint(self.layer.max_level_hint(), self.inner.max_level_hint())
self.pick_level_hint(
self.layer.max_level_hint(),
self.inner.max_level_hint(),
super::layer_is_none(&self.inner),
)
}

#[inline]
Expand Down Expand Up @@ -470,6 +478,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;
Expand All @@ -487,6 +496,31 @@ where
return None;
}

// If the layer 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-layer 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::layer_is_none(&self.layer) {
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)
}
}
Expand Down
43 changes: 43 additions & 0 deletions tracing-subscriber/src/layer/mod.rs
Original file line number Diff line number Diff line change
Expand Up @@ -1497,6 +1497,47 @@ pub struct Identity {

// === impl Layer ===

#[derive(Clone, Copy)]
pub(crate) struct NoneLayerMarker(());
static NONE_LAYER_MARKER: NoneLayerMarker = NoneLayerMarker(());

/// Is a type implementing `Layer` `Option::<_>::None`?
pub(crate) fn layer_is_none<L, S>(layer: &L) -> bool
where
L: Layer<S>,
S: Subscriber,
{
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 `Layer` impl
// for `Option`s. However, even if the layer *does* decide to be
// evil and give us an invalid pointer here, that's fine, because we'll
// never actually dereference it.
layer.downcast_raw(TypeId::of::<NoneLayerMarker>())
}
.is_some()
}

/// Is a type implementing `Subscriber` `Option::<_>::None`?
pub(crate) fn subscriber_is_none<S>(subscriber: &S) -> bool
where
S: Subscriber,
{
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 `Layer` 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<L, S> Layer<S> for Option<L>
where
L: Layer<S>,
Expand Down Expand Up @@ -1605,6 +1646,8 @@ where
unsafe fn downcast_raw(&self, id: TypeId) -> Option<*const ()> {
if id == TypeId::of::<Self>() {
Some(self as *const _ as *const ())
} else if id == TypeId::of::<NoneLayerMarker>() && self.is_none() {
Some(&NONE_LAYER_MARKER as *const _ as *const ())
} else {
self.as_ref().and_then(|inner| inner.downcast_raw(id))
}
Expand Down
205 changes: 205 additions & 0 deletions tracing-subscriber/tests/option.rs
Original file line number Diff line number Diff line change
Expand Up @@ -50,6 +50,7 @@ fn just_option_some_subscriber() {
assert_eq!(collector.max_level_hint(), Some(LevelFilter::OFF));
}

/// Tests that the logic tested in `doesnt_override_none` works through the reload subscriber
#[test]
fn just_option_none_subscriber() {
let collector = tracing_subscriber::registry().with(Some(LevelFilter::ERROR));
Expand Down Expand Up @@ -261,3 +262,207 @@ fn reload_works_with_none() {
.unwrap();
assert_eq!(subscriber.max_level_hint(), Some(LevelFilter::DEBUG));
}

// 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 layer
#[test]
fn reload_works_with_none() {
let (layer1, handle1) = tracing_subscriber::reload::Layer::new(None::<BasicLayer>);
let (layer2, _handle2) = tracing_subscriber::reload::Layer::new(None::<BasicLayer>);

let subscriber = tracing_subscriber::registry().with(layer1).with(layer2);
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));
}

0 comments on commit d7f72fc

Please sign in to comment.