Skip to content

Commit

Permalink
subscriber: fix incorrect filtering for tracing-log events (#344)
Browse files Browse the repository at this point in the history
## Motivation

Currently, the `tracing-subscriber` `EnvFilter` does not properly enable
events that originate from the `tracing-log` `LogTracer` adapter. This
is because those events are supposed to be filtered only by `enabled`,
and will not generate proper `register_callsite` metadata. `EnvFilter`'s
`enabled` method will assume that an event was not enabled statically,
since `enabled` wouldn't have been called if the callsite was given the
`Always` interest. However, this doesn't take `tracing-log` into
account.

## Solution

I've changed `EnvFilter` to always check against static filters in
`enabled` if the dynamic filters don't enable a given metadata. This
fixes the filtering of `tracing-log` events. I've also added tests that
fail against the current master. 

This fixes the regression reported by @samscott89.


Signed-off-by: Eliza Weisman <eliza@buoyant.io>
  • Loading branch information
hawkw committed Sep 12, 2019
1 parent d58b80a commit 520e4eb
Show file tree
Hide file tree
Showing 3 changed files with 44 additions and 4 deletions.
2 changes: 2 additions & 0 deletions tracing-subscriber/Cargo.toml
Expand Up @@ -47,6 +47,8 @@ chrono = { version = "0.4", optional = true }

[dev-dependencies]
tracing = "0.1"
log = "0.4"
tracing-log = "0.1"

[badges]
azure-devops = { project = "tracing/tracing", pipeline = "tokio-rs.tracing", build = "1" }
Expand Down
11 changes: 7 additions & 4 deletions tracing-subscriber/src/filter/env/mod.rs
Expand Up @@ -231,11 +231,14 @@ impl<S: Subscriber> Layer<S> for EnvFilter {
}
}

// TODO: other filters...

false
// Otherwise, fall back to checking if the callsite is
// statically enabled.
// TODO(eliza): we *might* want to check this only if the `log`
// feature is enabled, since if this is a `tracing` event with a
// real callsite, it would already have been statically enabled...
self.statics.enabled(metadata)
})
.unwrap_or(false)
.unwrap_or_else(|| self.statics.enabled(metadata))
}

fn new_span(&self, attrs: &span::Attributes<'_>, id: &span::Id, _: Context<'_, S>) {
Expand Down
35 changes: 35 additions & 0 deletions tracing-subscriber/tests/filter_log.rs
@@ -0,0 +1,35 @@
mod support;
use self::support::*;
use tracing::{self, subscriber::with_default, Level};
use tracing_subscriber::{filter::EnvFilter, prelude::*};

#[test]
fn log_is_enabled() {
mod my_module {
pub(crate) fn do_test() {
log::trace!("this should be disabled");
log::info!("this shouldn't be");
log::debug!("this should be disabled");
log::warn!("this should be enabled");
log::warn!(target: "something else", "this shouldn't be enabled");
log::error!("this should be enabled too");
}
}
tracing_log::LogTracer::init().expect("logger should be unset");
let filter: EnvFilter = "filter_log::my_module=info"
.parse()
.expect("filter should parse");
let (subscriber, finished) = subscriber::mock()
.event(event::mock().at_level(Level::INFO))
.event(event::mock().at_level(Level::WARN))
.event(event::mock().at_level(Level::ERROR))
.done()
.run_with_handle();
let subscriber = subscriber.with(filter);

with_default(subscriber, || {
my_module::do_test();
});

finished.assert_finished();
}

0 comments on commit 520e4eb

Please sign in to comment.