trace: Add static level filtering (#987)

## Motivation

`tokio-trace` should have static verbosity level filtering, like the
`log` crate. The static max verbosity level should be controlled at
compile time with a set of features. It should be possible to set a
separate max level for release and debug mode builds.

## Solution

We can do this fairly similarly to how the `log` crate does it:
`tokio-trace` should export a constant whose value is set based on the
static max level feature flags. Then, we add an if statement to the
`span!` and `event!` macros which tests if that event or span's level
is enabled.

Closes #959

.cirrus.yml

@@ -32,6 +32,7 @@ task:
   test_script:
     - . $HOME/.cargo/env
     - cargo test --all --no-fail-fast
+    - (cd tokio-trace/test_static_max_level_features && cargo test)
     - cargo doc --all
   i686_test_script:
     - . $HOME/.cargo/env

azure-pipelines.yml

@@ -47,6 +47,7 @@ jobs:
       - tokio-timer
       - tokio-trace
       - tokio-trace/tokio-trace-core
+      - tokio-trace/test_static_max_level_features
 
 - template: ci/azure-cargo-check.yml
   parameters:

tokio-trace/Cargo.toml

@@ -16,6 +16,7 @@ publish = false
 
 [dependencies]
 tokio-trace-core = "0.1"
+cfg-if = "0.1.7"
 
 [dev-dependencies]
 ansi_term = "0.11"
@@ -23,6 +24,21 @@ humantime = "1.1.1"
 futures = "0.1"
 log = "0.4"
 
+[features]
+max_level_off   = []
+max_level_error = []
+max_level_warn  = []
+max_level_info  = []
+max_level_debug = []
+max_level_trace = []
+
+release_max_level_off   = []
+release_max_level_error = []
+release_max_level_warn  = []
+release_max_level_info  = []
+release_max_level_debug = []
+release_max_level_trace = []
+
 # These are used for the "basic" example from the tokio-trace-prototype repo,
 # which is currently not included as it used the `tokio-trace-log` crate, and
 # that crate is currently unstable.

tokio-trace/src/level_filters.rs

@@ -0,0 +1,88 @@
+use std::cmp::Ordering;
+use tokio_trace_core::Level;
+
+/// `LevelFilter` is used to statistically filter the logging messages based on its `Level`.
+/// Logging messages will be discarded if its `Level` is greater than `LevelFilter`.
+#[derive(Clone, Debug, Eq, PartialEq, Ord, PartialOrd)]
+pub struct LevelFilter(Option<Level>);
+
+impl LevelFilter {
+    /// The "off" level.
+    ///
+    /// Designates that logging should be to turned off.
+    pub const OFF: LevelFilter = LevelFilter(None);
+    /// The "error" level.
+    ///
+    /// Designates very serious errors.
+    pub const ERROR: LevelFilter = LevelFilter(Some(Level::ERROR));
+    /// The "warn" level.
+    ///
+    /// Designates hazardous situations.
+    pub const WARN: LevelFilter = LevelFilter(Some(Level::WARN));
+    /// The "info" level.
+    ///
+    /// Designates useful information.
+    pub const INFO: LevelFilter = LevelFilter(Some(Level::INFO));
+    /// The "debug" level.
+    ///
+    /// Designates lower priority information.
+    pub const DEBUG: LevelFilter = LevelFilter(Some(Level::DEBUG));
+    /// The "trace" level.
+    ///
+    /// Designates very low priority, often extremely verbose, information.
+    pub const TRACE: LevelFilter = LevelFilter(Some(Level::TRACE));
+}
+
+impl PartialEq<LevelFilter> for Level {
+    fn eq(&self, other: &LevelFilter) -> bool {
+        match other.0 {
+            None => false,
+            Some(ref level) => self.eq(level),
+        }
+    }
+}
+
+impl PartialOrd<LevelFilter> for Level {
+    fn partial_cmp(&self, other: &LevelFilter) -> Option<Ordering> {
+        match other.0 {
+            None => Some(Ordering::Less),
+            Some(ref level) => self.partial_cmp(level),
+        }
+    }
+}
+
+/// The statically resolved maximum trace level.
+///
+/// See the crate level documentation for information on how to configure this.
+///
+/// This value is checked by the `event` macro. Code that manually calls functions on that value
+/// should compare the level against this value.
+pub const STATIC_MAX_LEVEL: LevelFilter = MAX_LEVEL;
+
+cfg_if! {
+    if #[cfg(all(not(debug_assertions), feature = "release_max_level_off"))] {
+        const MAX_LEVEL: LevelFilter = LevelFilter::OFF;
+    } else if #[cfg(all(not(debug_assertions), feature = "release_max_level_error"))] {
+        const MAX_LEVEL: LevelFilter = LevelFilter::ERROR;
+    } else if #[cfg(all(not(debug_assertions), feature = "release_max_level_warn"))] {
+        const MAX_LEVEL: LevelFilter = LevelFilter::WARN;
+    } else if #[cfg(all(not(debug_assertions), feature = "release_max_level_info"))] {
+        const MAX_LEVEL: LevelFilter = LevelFilter::INFO;
+    } else if #[cfg(all(not(debug_assertions), feature = "release_max_level_debug"))] {
+        const MAX_LEVEL: LevelFilter = LevelFilter::DEBUG;
+    } else if #[cfg(all(not(debug_assertions), feature = "release_max_level_trace"))] {
+        const MAX_LEVEL: LevelFilter = LevelFilter::TRACE;
+    } else if #[cfg(feature = "max_level_off")] {
+        const MAX_LEVEL: LevelFilter = LevelFilter::OFF;
+    } else if #[cfg(feature = "max_level_error")] {
+        const MAX_LEVEL: LevelFilter = LevelFilter::ERROR;
+    } else if #[cfg(feature = "max_level_warn")] {
+        const MAX_LEVEL: LevelFilter = LevelFilter::WARN;
+    } else if #[cfg(feature = "max_level_info")] {
+        const MAX_LEVEL: LevelFilter = LevelFilter::INFO;
+    } else if #[cfg(feature = "max_level_debug")] {
+        const MAX_LEVEL: LevelFilter = LevelFilter::DEBUG;
+    } else {
+        const MAX_LEVEL: LevelFilter = LevelFilter::TRACE;
+    }
+}

tokio-trace/src/lib.rs

@@ -309,6 +309,8 @@
 //! [`tokio-trace-futures`]: https://github.com/tokio-rs/tokio-trace-nursery/tree/master/tokio-trace-futures
 //! [`tokio-trace-fmt`]: https://github.com/tokio-rs/tokio-trace-nursery/tree/master/tokio-trace-fmt
 //! [`tokio-trace-log`]: https://github.com/tokio-rs/tokio-trace-nursery/tree/master/tokio-trace-log
+#[macro_use]
+extern crate cfg_if;
 extern crate tokio_trace_core;
 
 // Somehow this `use` statement is necessary for us to re-export the `core`
@@ -339,6 +341,7 @@ pub use self::{
 mod macros;
 
 pub mod field;
+pub mod level_filters;
 pub mod span;
 pub mod subscriber;
 

tokio-trace/src/macros.rs

@@ -101,7 +101,7 @@ macro_rules! span {
         $name:expr,
         $($k:ident $( = $val:expr )* ),*
     ) => {
-        {
+        if $lvl <= $crate::level_filters::STATIC_MAX_LEVEL {
             use $crate::callsite;
             use $crate::callsite::Callsite;
             let callsite = callsite! {
@@ -120,6 +120,8 @@ macro_rules! span {
             } else {
                 $crate::Span::new_disabled()
             }
+        } else {
+            $crate::Span::new_disabled()
         }
     };
     (
@@ -128,7 +130,7 @@ macro_rules! span {
         $name:expr,
         $($k:ident $( = $val:expr )* ),*
     ) => {
-        {
+        if $lvl <= $crate::level_filters::STATIC_MAX_LEVEL {
             use $crate::callsite;
             use $crate::callsite::Callsite;
             let callsite = callsite! {
@@ -146,6 +148,8 @@ macro_rules! span {
             } else {
                 $crate::Span::new_disabled()
             }
+        } else {
+            $crate::Span::new_disabled()
         }
     };
     (target: $target:expr, level: $lvl:expr, parent: $parent:expr, $name:expr) => {
@@ -334,7 +338,7 @@ macro_rules! span {
 #[macro_export(local_inner_macros)]
 macro_rules! event {
     (target: $target:expr, $lvl:expr, { $( $k:ident = $val:expr ),* $(,)*} )=> ({
-        {
+        if $lvl <= $crate::level_filters::STATIC_MAX_LEVEL {
             #[allow(unused_imports)]
             use $crate::{callsite, dispatcher, Event, field::{Value, ValueSet}};
             use $crate::callsite::Callsite;

tokio-trace/test_static_max_level_features/Cargo.toml

@@ -0,0 +1,10 @@
+[workspace]
+
+[package]
+name = "test_cargo_max_level_features"
+version = "0.1.0"
+publish = false
+
+[dependencies.tokio-trace]
+path = ".."
+features = ["max_level_debug", "release_max_level_info"]

tokio-trace/test_static_max_level_features/tests/test.rs

@@ -0,0 +1,71 @@
+#[macro_use]
+extern crate tokio_trace;
+
+use std::sync::{Arc, Mutex};
+use tokio_trace::span::{Attributes, Record};
+use tokio_trace::{span, Event, Id, Level, Metadata, Subscriber};
+
+struct State {
+    last_level: Mutex<Option<Level>>,
+}
+
+struct TestSubscriber(Arc<State>);
+
+impl Subscriber for TestSubscriber {
+    fn enabled(&self, _: &Metadata) -> bool {
+        true
+    }
+
+    fn new_span(&self, _span: &Attributes) -> Id {
+        span::Id::from_u64(42)
+    }
+
+    fn record(&self, _span: &Id, _values: &Record) {}
+
+    fn record_follows_from(&self, _span: &Id, _follows: &Id) {}
+
+    fn event(&self, event: &Event) {
+        *self.0.last_level.lock().unwrap() = Some(event.metadata().level().clone());
+    }
+
+    fn enter(&self, _span: &Id) {}
+
+    fn exit(&self, _span: &Id) {}
+}
+
+#[cfg(test)]
+fn test_static_max_level_features() {
+    let me = Arc::new(State {
+        last_level: Mutex::new(None),
+    });
+    let a = me.clone();
+    tokio_trace::subscriber::with_default(TestSubscriber(me), || {
+        error!("");
+        last(&a, Some(Level::ERROR));
+        warn!("");
+        last(&a, Some(Level::WARN));
+        info!("");
+        last(&a, Some(Level::INFO));
+        debug!("");
+        last(&a, Some(Level::DEBUG));
+        trace!("");
+        last(&a, None);
+
+        span!(level: Level::ERROR, "");
+        last(&a, None);
+        span!(level: Level::WARN, "");
+        last(&a, None);
+        span!(level: Level::INFO, "");
+        last(&a, None);
+        span!(level: Level::DEBUG, "");
+        last(&a, None);
+        span!(level: Level::TRACE, "");
+        last(&a, None);
+    });
+}
+
+fn last(state: &State, expected: Option<Level>) {
+    let mut lvl = state.last_level.lock().unwrap();
+    assert_eq!(*lvl, expected);
+    *lvl = None;
+}