I have a Rust application I am instrumenting, and I would like to be able to set the log filtering level dynamically for a given span tree. Note that I don’t want to change the log level for the whole application by doing something like reloading the filter layer with a new level – I want to set the filter level for a specific execution of a given code path.
I was able to implement this behavior by adding a meta-field always-log
to the parent span, propagating that field to child spans through it’s extensions and then filtering conditionally on the presence of either the field or the extension:
use tracing::span::Attributes;
use tracing::{span, Level, Subscriber};
use tracing_core::{Interest, Metadata};
use tracing_subscriber::fmt;
use tracing_subscriber::layer::{Context, Layer, SubscriberExt};
use tracing_subscriber::registry::LookupSpan;
struct PropagateExtensionLayer;
struct AlwaysLog;
impl<S> Layer<S> for PropagateExtensionLayer
where
S: Subscriber + for<'lookup> LookupSpan<'lookup>,
{
fn on_new_span(
&self,
_attrs: &Attributes<'_>,
id: &tracing_core::span::Id,
ctx: Context<'_, S>,
) {
let span = ctx.span(id).unwrap();
let should_propagate_field = span
.fields()
.iter()
.any(|field| field.name() == "always_log")
|| span.parent().map_or(false, |parent| {
parent.extensions().get::<AlwaysLog>().is_some()
});
if should_propagate_field {
span.extensions_mut().insert(AlwaysLog);
}
}
fn register_callsite(&self, metadata: &'static Metadata<'static>) -> Interest {
if metadata
.fields()
.iter()
.any(|field| field.name() == "always_log")
{
Interest::always()
} else {
Interest::sometimes()
}
}
}
pub struct FilterLayer;
impl<S> Layer<S> for FilterLayer
where
S: tracing::Subscriber + for<'lookup> LookupSpan<'lookup>,
{
fn enabled(&self, metadata: &tracing::Metadata<'_>, ctx: Context<'_, S>) -> bool {
let always_log = metadata
.fields()
.iter()
.any(|field| field.name() == "always_log")
|| ctx
.lookup_current()
.map_or(false, |span| span.extensions().get::<AlwaysLog>().is_some());
always_log || metadata.level() <= &Level::ERROR
}
}
fn main() {
let subscriber = tracing_subscriber::registry()
.with(FilterLayer)
.with(PropagateExtensionLayer)
.with(fmt::Layer::default());
tracing::subscriber::set_global_default(subscriber).expect("Failed to set subscriber");
let parent_span = span!(Level::INFO, "parent", always_log = true, key1 = "value1");
parent_span.in_scope(|| {
let child_span = span!(Level::INFO, "child", key2 = "value2");
child_span.in_scope(|| {
tracing::info!("This should be logged and parent spans activated");
});
});
let parent_span = span!(Level::INFO, "parent", key1 = "value1");
parent_span.in_scope(|| {
let child_span = span!(Level::INFO, "child", key2 = "value2");
child_span.in_scope(|| {
tracing::info!("This should not be logged");
tracing::error!("This should also be logged but parent spans deactivated");
});
});
}
However, I am not sure this is the best way of doing this. Although it is simple to drop this meta-field later, I would rather add the extension directly to the first span, but I can’t figure out how or if it is at all possible, since on_new_span
is only called for spans the subscriber has an interest in, and that comes from register_callsite
which only sees the span metadata.
I am also unsure if this is the best approach for doing this, as I suspect with all the stuff in the tracing
ecosystem, there might be a better way. However, given that the real application is reasonably complex with the same call moving around many threads, I would like to avoid messing too much with creating new subscribers with new filters (unless, of course, there is a sensible way to do that and keep track of them for an operation that jumps all over)
So my questions are:
- Is there a way to create a
span
directly with an extension and also force it to be enabled, conditionally? - Is there a simpler, better or more canonical way to achieve this conditional filtering behavior, either improving this solution or with a different approach?
- Why is the child span in the first example being enabled? In my understanding, it shouldn’t be (although I’m glad it is) – no subscribers are declaring an interest in it, so it wouldn’t make it to
on_new_span
, causing it to be rejected by the filter layer, disabling it like the two spans in the second example.