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

forward-port Filter impl for EnvFilter #2031

Merged
merged 3 commits into from
Mar 29, 2022
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Jump to
Jump to file
Failed to load files.
Diff view
Diff view
7 changes: 7 additions & 0 deletions tracing-mock/src/span.rs
Original file line number Diff line number Diff line change
Expand Up @@ -24,6 +24,13 @@ pub fn mock() -> MockSpan {
}
}

pub fn named<I>(name: I) -> MockSpan
where
I: Into<String>,
{
mock().named(name)
}

impl MockSpan {
pub fn named<I>(self, name: I) -> Self
where
Expand Down
2 changes: 1 addition & 1 deletion tracing-subscriber/Cargo.toml
Original file line number Diff line number Diff line change
Expand Up @@ -27,7 +27,7 @@ rust-version = "1.49.0"
default = ["smallvec", "fmt", "ansi", "tracing-log", "std"]
alloc = []
std = ["alloc", "tracing-core/std"]
env-filter = ["matchers", "regex", "lazy_static", "tracing", "std"]
env-filter = ["matchers", "regex", "lazy_static", "tracing", "std", "thread_local"]
fmt = ["registry", "std"]
ansi = ["fmt", "ansi_term"]
registry = ["sharded-slab", "thread_local", "std"]
Expand Down
219 changes: 178 additions & 41 deletions tracing-subscriber/src/filter/env/mod.rs
Original file line number Diff line number Diff line change
Expand Up @@ -10,11 +10,12 @@ mod field;

use crate::{
filter::LevelFilter,
subscribe::{Context, Subscribe},
subscribe::{self, Context, Subscribe},
sync::RwLock,
};
use directive::ParseError;
use std::{cell::RefCell, collections::HashMap, env, error::Error, fmt, str::FromStr};
use thread_local::ThreadLocal;
use tracing_core::{
callsite,
collect::{Collect, Interest},
Expand All @@ -25,6 +26,16 @@ use tracing_core::{
/// A [`Subscriber`] which filters spans and events based on a set of filter
/// directives.
///
/// `EnvFilter` implements both the [`Subscribe`](#impl-Subscribe<C>) and
/// [`Filter`] traits, so it may be used for both [global filtering][global] and
/// [per-subscriber filtering][psf], respectively. See [the documentation on
/// filtering with `Subscriber`s][filtering] for details.
///
/// The [`Targets`] type implements a similar form of filtering, but without the
/// ability to dynamically enable events based on the current span context, and
/// without filtering on field values. When these features are not required,
/// [`Targets`] provides a lighter-weight alternative to [`EnvFilter`].
///
/// # Directives
///
/// A filter consists of one or more comma-separated directives which match on [`Span`]s and [`Event`]s.
Expand Down Expand Up @@ -71,7 +82,7 @@ use tracing_core::{
/// - A dash in a target will only appear when being specified explicitly:
/// `tracing::info!(target: "target-name", ...);`
///
/// ## Examples
/// ## Example Syntax
///
/// - `tokio::net=info` will enable all spans or events that:
/// - have the `tokio::net` target,
Expand All @@ -88,10 +99,54 @@ use tracing_core::{
/// - which has a field named `name` with value `bob`,
/// - at _any_ level.
///
/// The [`Targets`] type implements a similar form of filtering, but without the
/// ability to dynamically enable events based on the current span context, and
/// without filtering on field values. When these features are not required,
/// [`Targets`] provides a lighter-weight alternative to [`EnvFilter`].
/// # Examples
///
/// Parsing an `EnvFilter` from the [default environment
/// variable](EnvFilter::from_default_env) (`RUST_LOG`):
///
/// ```
/// use tracing_subscriber::{EnvFilter, fmt, prelude::*};
///
/// tracing_subscriber::registry()
/// .with(fmt::subscriber())
/// .with(EnvFilter::from_default_env())
/// .init();
/// ```
///
/// Parsing an `EnvFilter` [from a user-provided environment
/// variable](EnvFilter::from_env):
///
/// ```
/// use tracing_subscriber::{EnvFilter, fmt, prelude::*};
///
/// tracing_subscriber::registry()
/// .with(fmt::subscriber())
/// .with(EnvFilter::from_env("MYAPP_LOG"))
/// .init();
/// ```
///
/// Using `EnvFilter` as a [per-subscriber filter][psf] to filter only a single
/// [subscriber](crate::subscribe::Subscribe):
///
/// ```
/// use tracing_subscriber::{EnvFilter, fmt, prelude::*};
///
/// // Parse an `EnvFilter` configuration from the `RUST_LOG`
/// // environment variable.
/// let filter = EnvFilter::from_default_env();
///
/// // Apply the filter to this subscriber *only*.
/// let filtered_subscriber = fmt::subscriber().with_filter(filter);
///
/// // Some other subscriber, whose output we don't want to filter.
/// let unfiltered_subscriber = // ...
/// # fmt::subscriber();
///
/// tracing_subscriber::registry()
/// .with(filtered_subscriber)
/// .with(unfiltered_subscriber)
/// .init();
/// ```
///
/// [`Subscriber`]: Subscribe
/// [`env_logger`]: https://docs.rs/env_logger/0.7.1/env_logger/#enabling-logging
Expand All @@ -101,6 +156,10 @@ use tracing_core::{
/// [`level`]: tracing_core::Level
/// [`Metadata`]: tracing_core::Metadata
/// [`Targets`]: crate::filter::Targets
/// [`Filter`]: #impl-Filter<C>
/// [global]: crate::subscribe#global-filtering
/// [psf]: crate::subscribe#per-subscriber-filtering
/// [filtering]: crate::subscribe#filtering-with-subscribers
#[cfg_attr(docsrs, doc(cfg(all(feature = "env-filter", feature = "std"))))]
#[derive(Debug)]
pub struct EnvFilter {
Expand All @@ -109,10 +168,7 @@ pub struct EnvFilter {
has_dynamics: bool,
by_id: RwLock<HashMap<span::Id, directive::SpanMatcher>>,
by_cs: RwLock<HashMap<callsite::Identifier, directive::CallsiteMatcher>>,
}

thread_local! {
static SCOPE: RefCell<Vec<LevelFilter>> = RefCell::new(Vec::new());
scope: ThreadLocal<RefCell<Vec<LevelFilter>>>,
}

type FieldMap<T> = HashMap<Field, T>;
Expand Down Expand Up @@ -347,6 +403,10 @@ impl EnvFilter {
has_dynamics,
by_id: RwLock::new(HashMap::new()),
by_cs: RwLock::new(HashMap::new()),
// TODO(eliza): maybe worth allocating capacity for `num_cpus`
// threads or something (assuming we're running in Tokio)? or
// `num_cpus * 2` or something?
scope: ThreadLocal::new(),
}
}

Expand All @@ -362,9 +422,7 @@ impl EnvFilter {
Interest::never()
}
}
}

impl<C: Collect> Subscribe<C> for EnvFilter {
fn register_callsite(&self, metadata: &'static Metadata<'static>) -> Interest {
if self.has_dynamics && metadata.is_span() {
// If this metadata describes a span, first, check if there is a
Expand All @@ -385,20 +443,7 @@ impl<C: Collect> Subscribe<C> for EnvFilter {
}
}

fn max_level_hint(&self) -> Option<LevelFilter> {
if self.dynamics.has_value_filters() {
// If we perform any filtering on span field *values*, we will
// enable *all* spans, because their field values are not known
// until recording.
return Some(LevelFilter::TRACE);
}
std::cmp::max(
self.statics.max_level.into(),
self.dynamics.max_level.into(),
)
}

fn enabled(&self, metadata: &Metadata<'_>, _: Context<'_, C>) -> bool {
fn enabled(&self, metadata: &Metadata<'_>) -> bool {
let level = metadata.level();

// is it possible for a dynamic filter directive to enable this event?
Expand All @@ -418,14 +463,15 @@ impl<C: Collect> Subscribe<C> for EnvFilter {
}
}

let enabled_by_scope = SCOPE.with(|scope| {
for filter in scope.borrow().iter() {
let enabled_by_scope = {
let scope = self.scope.get_or_default().borrow();
for filter in &*scope {
if filter >= level {
return true;
}
}
false
});
};
if enabled_by_scope {
return true;
}
Expand All @@ -441,36 +487,43 @@ impl<C: Collect> Subscribe<C> for EnvFilter {
false
}

fn on_new_span(&self, attrs: &span::Attributes<'_>, id: &span::Id, _: Context<'_, C>) {
fn max_level_hint(&self) -> Option<LevelFilter> {
if self.dynamics.has_value_filters() {
// If we perform any filtering on span field *values*, we will
// enable *all* spans, because their field values are not known
// until recording.
return Some(LevelFilter::TRACE);
}
std::cmp::max(
self.statics.max_level.into(),
self.dynamics.max_level.into(),
)
}

fn on_new_span(&self, attrs: &span::Attributes<'_>, id: &span::Id) {
let by_cs = try_lock!(self.by_cs.read());
if let Some(cs) = by_cs.get(&attrs.metadata().callsite()) {
let span = cs.to_span_match(attrs);
try_lock!(self.by_id.write()).insert(id.clone(), span);
}
}

fn on_record(&self, id: &span::Id, values: &span::Record<'_>, _: Context<'_, C>) {
if let Some(span) = try_lock!(self.by_id.read()).get(id) {
span.record_update(values);
}
}

fn on_enter(&self, id: &span::Id, _: Context<'_, C>) {
fn on_enter(&self, id: &span::Id) {
// XXX: This is where _we_ could push IDs to the stack instead, and use
// that to allow changing the filter while a span is already entered.
// But that might be much less efficient...
if let Some(span) = try_lock!(self.by_id.read()).get(id) {
SCOPE.with(|scope| scope.borrow_mut().push(span.level()));
self.scope.get_or_default().borrow_mut().push(span.level());
}
}

fn on_exit(&self, id: &span::Id, _: Context<'_, C>) {
fn on_exit(&self, id: &span::Id) {
if self.cares_about_span(id) {
SCOPE.with(|scope| scope.borrow_mut().pop());
self.scope.get_or_default().borrow_mut().pop();
}
}

fn on_close(&self, id: span::Id, _: Context<'_, C>) {
fn on_close(&self, id: span::Id) {
// If we don't need to acquire a write lock, avoid doing so.
if !self.cares_about_span(&id) {
return;
Expand All @@ -481,6 +534,90 @@ impl<C: Collect> Subscribe<C> for EnvFilter {
}
}

impl<C: Collect> Subscribe<C> for EnvFilter {
#[inline]
fn register_callsite(&self, metadata: &'static Metadata<'static>) -> Interest {
EnvFilter::register_callsite(self, metadata)
}

#[inline]
fn max_level_hint(&self) -> Option<LevelFilter> {
EnvFilter::max_level_hint(self)
}

#[inline]
fn enabled(&self, metadata: &Metadata<'_>, _: Context<'_, C>) -> bool {
self.enabled(metadata)
}

#[inline]
fn on_new_span(&self, attrs: &span::Attributes<'_>, id: &span::Id, _: Context<'_, C>) {
self.on_new_span(attrs, id)
}

fn on_record(&self, id: &span::Id, values: &span::Record<'_>, _: Context<'_, C>) {
if let Some(span) = try_lock!(self.by_id.read()).get(id) {
span.record_update(values);
}
}

#[inline]
fn on_enter(&self, id: &span::Id, _: Context<'_, C>) {
self.on_enter(id);
}

#[inline]
fn on_exit(&self, id: &span::Id, _: Context<'_, C>) {
self.on_exit(id);
}

#[inline]
fn on_close(&self, id: span::Id, _: Context<'_, C>) {
self.on_close(id);
}
}

feature! {
#![all(feature = "registry", feature = "std")]

impl<C> subscribe::Filter<C> for EnvFilter {
#[inline]
fn enabled(&self, meta: &Metadata<'_>, _: &Context<'_, C>) -> bool {
self.enabled(meta)
}

#[inline]
fn callsite_enabled(&self, meta: &'static Metadata<'static>) -> Interest {
self.register_callsite(meta)
}

#[inline]
fn max_level_hint(&self) -> Option<LevelFilter> {
EnvFilter::max_level_hint(self)
}

#[inline]
fn on_new_span(&self, attrs: &span::Attributes<'_>, id: &span::Id, _: Context<'_, C>) {
self.on_new_span(attrs, id)
}

#[inline]
fn on_enter(&self, id: &span::Id, _: Context<'_, C>) {
self.on_enter(id);
}

#[inline]
fn on_exit(&self, id: &span::Id, _: Context<'_, C>) {
self.on_exit(id);
}

#[inline]
fn on_close(&self, id: span::Id, _: Context<'_, C>) {
self.on_close(id);
}
}
}

impl FromStr for EnvFilter {
type Err = directive::ParseError;

Expand Down