tokio-rs · hawkw · Jun 7, 2022 · Apr 27, 2022 · May 5, 2022 · May 9, 2022
@@ -32,7 +32,7 @@ futures = "0.3"
 tokio = { version = "1.1", features = ["full"] }
 
 # env-logger example
-env_logger = "0.7"
+env_logger = "0.9"
 
 # tower examples
 tower = { version = "0.4.4", features = ["full"] }

@@ -92,17 +92,9 @@ async fn echo(req: Request<Body>) -> Result<Response<Body>, hyper::Error> {
 
 #[tokio::main]
 async fn main() -> Result<(), Box<dyn std::error::Error>> {
-    use tracing_log::env_logger::BuilderExt;
-
     let subscriber = tracing_subscriber::fmt()
         .with_max_level(Level::TRACE)
         .finish();
-    let mut builder = env_logger::Builder::new();
-    builder
-        .filter(Some("hyper_echo"), log::LevelFilter::Off)
-        .filter(Some("hyper"), log::LevelFilter::Trace)
-        .emit_traces() // from `tracing_log::env_logger::BuilderExt`
-        .try_init()?;
     tracing::subscriber::set_global_default(subscriber)?;
 
     let local_addr: std::net::SocketAddr = ([127, 0, 0, 1], 3000).into();

@@ -1,3 +1,4 @@
+use opentelemetry::global;
 use std::{error::Error, thread, time::Duration};
 use tracing::{span, trace, warn};
 use tracing_attributes::instrument;
@@ -26,16 +27,20 @@ fn main() -> Result<(), Box<dyn Error + Send + Sync + 'static>> {
         .with(opentelemetry)
         .try_init()?;
 
-    let root = span!(tracing::Level::INFO, "app_start", work_units = 2);
-    let _enter = root.enter();
+    {
+        let root = span!(tracing::Level::INFO, "app_start", work_units = 2);
+        let _enter = root.enter();
 
-    let work_result = expensive_work();
+        let work_result = expensive_work();
 
-    span!(tracing::Level::INFO, "faster_work")
-        .in_scope(|| thread::sleep(Duration::from_millis(10)));
+        span!(tracing::Level::INFO, "faster_work")
+            .in_scope(|| thread::sleep(Duration::from_millis(10)));
 
-    warn!("About to exit!");
-    trace!("status: {}", work_result);
+        warn!("About to exit!");
+        trace!("status: {}", work_result);
+    }
+
+    global::shutdown_tracer_provider();
 
     Ok(())
 }
@@ -32,6 +32,12 @@ default-features = false
 features = ["fmt", "std"]
 
 [dev-dependencies]
+
+criterion = { version = "0.3", default_features = false }
 tracing = { path = "../tracing", version = "0.1" }
 time = { version = "0.3", default-features = false, features = ["formatting", "parsing"] }
 tempfile = "3"
+
+[[bench]]
+name = "bench"
+harness = false
@@ -0,0 +1,134 @@
+use criterion::{criterion_group, criterion_main, Criterion};
+use std::{
+    thread::{self, JoinHandle},
+    time::Instant,
+};
+use tracing::{event, Level};
+use tracing_appender::non_blocking;
+use tracing_subscriber::fmt::MakeWriter;
+
+// a no-op writer is used in order to measure the overhead incurred by
+// tracing-subscriber.
+#[derive(Clone)]
+struct NoOpWriter;
+
+impl NoOpWriter {
+    fn new() -> NoOpWriter {
+        NoOpWriter
+    }
+}
+
+impl<'a> MakeWriter<'a> for NoOpWriter {
+    type Writer = NoOpWriter;
+
+    fn make_writer(&self) -> Self::Writer {
+        self.clone()
+    }
+}
+
+impl std::io::Write for NoOpWriter {
+    fn write(&mut self, buf: &[u8]) -> std::io::Result<usize> {
+        Ok(buf.len())
+    }
+
+    fn flush(&mut self) -> std::io::Result<()> {
+        Ok(())
+    }
+}
+
+fn synchronous_benchmark(c: &mut Criterion) {
+    let mut group = c.benchmark_group("synchronous");
+    group.bench_function("single_thread", |b| {
+        let subscriber = tracing_subscriber::fmt().with_writer(NoOpWriter::new());
+        tracing::subscriber::with_default(subscriber.finish(), || {
+            b.iter(|| event!(Level::INFO, "event"))
+        });
+    });
+
+    group.bench_function("multiple_writers", |b| {
+        b.iter_custom(|iters| {
+            let mut handles: Vec<JoinHandle<()>> = Vec::new();
+
+            let start = Instant::now();
+
+            let make_writer = NoOpWriter::new();
+            let cloned_make_writer = make_writer.clone();
+
+            handles.push(thread::spawn(move || {
+                let subscriber = tracing_subscriber::fmt().with_writer(make_writer);
+                tracing::subscriber::with_default(subscriber.finish(), || {
+                    for _ in 0..iters {
+                        event!(Level::INFO, "event");
+                    }
+                });
+            }));
+
+            handles.push(thread::spawn(move || {
+                let subscriber = tracing_subscriber::fmt().with_writer(cloned_make_writer);
+                tracing::subscriber::with_default(subscriber.finish(), || {
+                    for _ in 0..iters {
+                        event!(Level::INFO, "event");
+                    }
+                });
+            }));
+
+            for handle in handles {
+                let _ = handle.join();
+            }
+
+            start.elapsed()
+        });
+    });
+}
+
+fn non_blocking_benchmark(c: &mut Criterion) {
+    let mut group = c.benchmark_group("non_blocking");
+
+    group.bench_function("single_thread", |b| {
+        let (non_blocking, _guard) = non_blocking(NoOpWriter::new());
+        let subscriber = tracing_subscriber::fmt().with_writer(non_blocking);
+
+        tracing::subscriber::with_default(subscriber.finish(), || {
+            b.iter(|| event!(Level::INFO, "event"))
+        });
+    });
+
+    group.bench_function("multiple_writers", |b| {
+        b.iter_custom(|iters| {
+            let (non_blocking, _guard) = non_blocking(NoOpWriter::new());
+
+            let mut handles: Vec<JoinHandle<()>> = Vec::new();
+
+            let start = Instant::now();
+
+            let cloned_make_writer = non_blocking.clone();
+
+            handles.push(thread::spawn(move || {
+                let subscriber = tracing_subscriber::fmt().with_writer(non_blocking);
+                tracing::subscriber::with_default(subscriber.finish(), || {
+                    for _ in 0..iters {
+                        event!(Level::INFO, "event");
+                    }
+                });
+            }));
+
+            handles.push(thread::spawn(move || {
+                let subscriber = tracing_subscriber::fmt().with_writer(cloned_make_writer);
+                tracing::subscriber::with_default(subscriber.finish(), || {
+                    for _ in 0..iters {
+                        event!(Level::INFO, "event");
+                    }
+                });
+            }));
+
+            for handle in handles {
+                let _ = handle.join();
+            }
+
+            start.elapsed()
+        });
+    });
+}
+
+criterion_group!(benches, synchronous_benchmark, non_blocking_benchmark);
+criterion_main!(benches);
@@ -46,7 +46,7 @@ quote = "1"
 [dev-dependencies]
 tracing = { path = "../tracing", version = "0.1" }
 tracing-mock = { path = "../tracing-mock", features = ["tokio-test"] }
-tokio-test = { version = "0.2.0" }
+tokio-test = { version = "0.3.0" }
 tracing-core = { path = "../tracing-core", version = "0.1"}
 async-trait = "0.1.44"
 

@@ -28,13 +28,13 @@ rust-version = "1.49.0"
 
 [features]
 default = ["std", "valuable/std"]
-std = ["lazy_static"]
+std = ["once_cell"]
 
 [badges]
 maintenance = { status = "actively-developed" }
 
 [dependencies]
-lazy_static = { version = "1.0.2", optional = true }
+once_cell = { version = "1.12", optional = true }
 
 [target.'cfg(tracing_unstable)'.dependencies]
 valuable = { version = "0.1.0", optional = true, default_features = false }

@@ -253,6 +253,11 @@ static CALLSITES: Callsites = Callsites {
 
 static DISPATCHERS: Dispatchers = Dispatchers::new();
 
+#[cfg(feature = "std")]
+static LOCKED_CALLSITES: once_cell::sync::Lazy<Mutex<Vec<&'static dyn Callsite>>> =
+    once_cell::sync::Lazy::new(Default::default);
+
+#[cfg(not(feature = "std"))]
 crate::lazy_static! {
     static ref LOCKED_CALLSITES: Mutex<Vec<&'static dyn Callsite>> = Mutex::new(Vec::new());
 }
@@ -510,6 +515,7 @@ mod private {
 #[cfg(feature = "std")]
 mod dispatchers {
     use crate::dispatcher;
+    use once_cell::sync::Lazy;
     use std::sync::{
         atomic::{AtomicBool, Ordering},
         RwLock, RwLockReadGuard, RwLockWriteGuard,
@@ -519,9 +525,8 @@ mod dispatchers {
         has_just_one: AtomicBool,
     }
 
-    crate::lazy_static! {
-        static ref LOCKED_DISPATCHERS: RwLock<Vec<dispatcher::Registrar>> = RwLock::new(Vec::new());
-    }
+    static LOCKED_DISPATCHERS: Lazy<RwLock<Vec<dispatcher::Registrar>>> =
+        Lazy::new(Default::default);
 
     pub(super) enum Rebuilder<'a> {
         JustOne,

@@ -254,10 +254,6 @@ macro_rules! metadata {
     };
 }
 
-// when `std` is enabled, use the `lazy_static` crate from crates.io
-#[cfg(feature = "std")]
-pub(crate) use lazy_static::lazy_static;
-
 // Facade module: `no_std` uses spinlocks, `std` uses the mutexes in the standard library
 #[cfg(not(feature = "std"))]
 #[macro_use]

@@ -221,7 +221,7 @@ pub use self::layer::ErrorLayer;
 pub mod prelude {
     //! The `tracing-error` prelude.
     //!
-    //! This brings into scope the `InstrumentError, `InstrumentResult`, and `ExtractSpanTrace`
+    //! This brings into scope the `InstrumentError`, `InstrumentResult`, and `ExtractSpanTrace`
     //! extension traits. These traits allow attaching `SpanTrace`s to errors and
     //! subsequently retrieving them from `dyn Error` trait objects.
 

@@ -28,7 +28,8 @@ smallvec = ["tracing-subscriber/smallvec"]
 [dependencies]
 tracing-subscriber = { path = "../tracing-subscriber", version = "0.3", default-features = false, features = ["registry", "fmt"] }
 tracing = { path = "../tracing", version = "0.1.12", default-features = false, features = ["std"] }
-lazy_static = "1.3.0"
+once_cell = "1.12"
+
 
 [dev-dependencies]
 tempfile = "3"
@@ -137,7 +137,7 @@
 pub use error::Error;
 
 use error::Kind;
-use lazy_static::lazy_static;
+use once_cell::sync::Lazy;
 use std::cell::Cell;
 use std::fmt;
 use std::fmt::Write as _;
@@ -158,9 +158,7 @@ use tracing_subscriber::Layer;
 
 mod error;
 
-lazy_static! {
-    static ref START: Instant = Instant::now();
-}
+static START: Lazy<Instant> = Lazy::new(Instant::now);
 
 thread_local! {
     static LAST_EVENT: Cell<Instant> = Cell::new(*START);

@@ -36,7 +36,7 @@ tokio = { version = "0.1", optional = true }
 
 [dev-dependencies]
 tokio = "0.1.22"
-tokio-test = "0.2"
+tokio-test = "0.3"
 tracing-core = { path = "../tracing-core", version = "0.1.2" }
 tracing-mock = { path = "../tracing-mock" }
 

@@ -18,9 +18,9 @@ rust-version = "1.49.0"
 [dependencies]
 libc = "0.2.107"
 tracing-core = { path = "../tracing-core", version = "0.1.10" }
-tracing-subscriber = { path = "../tracing-subscriber", version = "0.3" }
+tracing-subscriber = { path = "../tracing-subscriber", version = "0.3", default-features = false, features = ["registry"] }
 
 [dev-dependencies]
 serde_json = "1.0.68"
 serde = { version = "1.0.130", features = ["derive"] }
-tracing = { path = "../tracing", version = "0.1" }
+tracing = { path = "../tracing", version = "0.1" }
@@ -27,8 +27,8 @@ interest-cache = ["lru", "ahash"]
 [dependencies]
 tracing-core = { path = "../tracing-core", version = "0.1.17"}
 log = { version = "0.4" }
-lazy_static = "1.3.0"
-env_logger = { version = "0.7", optional = true }
+once_cell = "1.12"
+env_logger = { version = "0.8", optional = true }
 lru = { version = "0.7.0", optional = true }
 ahash = { version = "0.7.4", optional = true }
 

@@ -1,6 +1,7 @@
 use ahash::AHasher;
 use log::{Level, Metadata};
 use lru::LruCache;
+use once_cell::sync::Lazy;
 use std::cell::RefCell;
 use std::hash::Hasher;
 use std::sync::atomic::{AtomicUsize, Ordering};
@@ -140,12 +141,10 @@ static SENTINEL_METADATA: tracing_core::Metadata<'static> = tracing_core::Metada
     tracing_core::metadata::Kind::EVENT,
 );
 
-lazy_static::lazy_static! {
-    static ref CONFIG: Mutex<InterestCacheConfig> = {
-        tracing_core::callsite::register(&SENTINEL_CALLSITE);
-        Mutex::new(InterestCacheConfig::disabled())
-    };
-}
+static CONFIG: Lazy<Mutex<InterestCacheConfig>> = Lazy::new(|| {
+    tracing_core::callsite::register(&SENTINEL_CALLSITE);
+    Mutex::new(InterestCacheConfig::disabled())
+});
 
 thread_local! {
     static STATE: RefCell<State> = {
@@ -236,10 +235,7 @@ mod tests {
 
     fn lock_for_test() -> impl Drop {
         // We need to make sure only one test runs at a time.
-
-        lazy_static::lazy_static! {
-            static ref LOCK: Mutex<()> = Mutex::new(());
-        }
+        static LOCK: Lazy<Mutex<()>> = Lazy::new(Mutex::new);
 
         match LOCK.lock() {
             Ok(guard) => guard,