From 97fc247474ca49af541b05e598a0c1abd941ecd9 Mon Sep 17 00:00:00 2001 From: Eliza Weisman Date: Fri, 24 Jun 2022 12:53:35 -0700 Subject: [PATCH] tracing: reorganize benchmarks for comparability Currently, `tracing`'s benchmark suite benchmarks the same behaviors (e.g. creating a span, recording an event, etc) across a handful of cases: with no default dispatcher, with a global default, and with a scoped (thread-local) default. We use criterion's `benchmark_group` to represent each kind of dispatcher, and `bench_function` for each behavior being measured. This is actually kind of backwards relative to how Criterion is _supposed_ to be used. `bench_function` is intended for comparing different implementations of the *same* thing, with the `benchmark_group` representing what's being compared. If we inverted the structure of these benchmarks, Criterion would give us nicer plots that would allow comparing the performance of each dispatch type on the same task. This PR reorganizes the benchmarks so that each behavior being tested (such as entering a span or recording an event) is a `benchmark_group`, and each dispatch type (none, global, or scoped) is a `bench_function` within that group. Now, Criterion will generate plots for each group comparing the performance of each dispatch type in that benchmark. Unfortunately, this required splitting each benchmark type out into its own file. This is because, once we set the global default dispatcher within one benchmark group, it would remain set for the entire lifetime of the process --- there would be no way to test something else with no global default. But, I think this is fine, even though it means we now have a bunch of tiny files: it also allows us to run an individual benchmark against every combination of dispatch types, without having to run unrelated benches. This is potentially useful if (for example) someone is changing only the code for recording events, and not spans. --- tracing/Cargo.toml | 30 +++- tracing/benches/baseline.rs | 24 +++ tracing/benches/dispatch_get_clone.rs | 15 ++ tracing/benches/dispatch_get_ref.rs | 16 ++ tracing/benches/empty_span.rs | 43 ++++++ tracing/benches/enter_span.rs | 16 ++ tracing/benches/event.rs | 12 ++ tracing/benches/global_subscriber.rs | 141 ----------------- tracing/benches/no_subscriber.rs | 101 ------------- tracing/benches/shared.rs | 168 +++++++++++++++++++++ tracing/benches/span_fields.rs | 23 +++ tracing/benches/span_no_fields.rs | 13 ++ tracing/benches/span_repeated.rs | 20 +++ tracing/benches/subscriber.rs | 209 -------------------------- 14 files changed, 377 insertions(+), 454 deletions(-) create mode 100644 tracing/benches/baseline.rs create mode 100644 tracing/benches/dispatch_get_clone.rs create mode 100644 tracing/benches/dispatch_get_ref.rs create mode 100644 tracing/benches/empty_span.rs create mode 100644 tracing/benches/enter_span.rs create mode 100644 tracing/benches/event.rs delete mode 100644 tracing/benches/global_subscriber.rs delete mode 100644 tracing/benches/no_subscriber.rs create mode 100644 tracing/benches/shared.rs create mode 100644 tracing/benches/span_fields.rs create mode 100644 tracing/benches/span_no_fields.rs create mode 100644 tracing/benches/span_repeated.rs delete mode 100644 tracing/benches/subscriber.rs diff --git a/tracing/Cargo.toml b/tracing/Cargo.toml index 66419e31e9..4c1f6d89b9 100644 --- a/tracing/Cargo.toml +++ b/tracing/Cargo.toml @@ -68,15 +68,39 @@ log-always = ["log"] attributes = ["tracing-attributes"] [[bench]] -name = "subscriber" +name = "baseline" harness = false [[bench]] -name = "no_subscriber" +name = "dispatch_get_clone" harness = false [[bench]] -name = "global_subscriber" +name = "dispatch_get_ref" +harness = false + +[[bench]] +name = "empty_span" +harness = false + +[[bench]] +name = "enter_span" +harness = false + +[[bench]] +name = "event" +harness = false + +[[bench]] +name = "span_fields" +harness = false + +[[bench]] +name = "span_no_fields" +harness = false + +[[bench]] +name = "span_repeated" harness = false [badges] diff --git a/tracing/benches/baseline.rs b/tracing/benches/baseline.rs new file mode 100644 index 0000000000..93c14f422c --- /dev/null +++ b/tracing/benches/baseline.rs @@ -0,0 +1,24 @@ +use criterion::{black_box, criterion_group, criterion_main, Criterion}; + +fn bench(c: &mut Criterion) { + use std::sync::atomic::{AtomicUsize, Ordering}; + + let mut group = c.benchmark_group("comparison"); + group.bench_function("relaxed_load", |b| { + let foo = AtomicUsize::new(1); + b.iter(|| black_box(foo.load(Ordering::Relaxed))); + }); + group.bench_function("acquire_load", |b| { + let foo = AtomicUsize::new(1); + b.iter(|| black_box(foo.load(Ordering::Acquire))) + }); + group.bench_function("log", |b| { + b.iter(|| { + log::log!(log::Level::Info, "log"); + }) + }); + group.finish(); +} + +criterion_group!(benches, bench); +criterion_main!(benches); diff --git a/tracing/benches/dispatch_get_clone.rs b/tracing/benches/dispatch_get_clone.rs new file mode 100644 index 0000000000..5474074ff7 --- /dev/null +++ b/tracing/benches/dispatch_get_clone.rs @@ -0,0 +1,15 @@ +use criterion::{black_box, criterion_group, criterion_main, Criterion}; + +mod shared; + +fn bench(c: &mut Criterion) { + shared::for_all_dispatches(&mut c.benchmark_group("Dispatch::get_clone"), |b| { + b.iter(|| { + let current = tracing::dispatch::get_default(|current| current.clone()); + black_box(current); + }) + }); +} + +criterion_group!(benches, bench); +criterion_main!(benches); diff --git a/tracing/benches/dispatch_get_ref.rs b/tracing/benches/dispatch_get_ref.rs new file mode 100644 index 0000000000..f369da31dc --- /dev/null +++ b/tracing/benches/dispatch_get_ref.rs @@ -0,0 +1,16 @@ +use criterion::{black_box, criterion_group, criterion_main, Criterion}; + +mod shared; + +fn bench(c: &mut Criterion) { + shared::for_all_dispatches(&mut c.benchmark_group("Dispatch::get_ref"), |b| { + b.iter(|| { + tracing::dispatch::get_default(|current| { + black_box(¤t); + }) + }) + }); +} + +criterion_group!(benches, bench); +criterion_main!(benches); diff --git a/tracing/benches/empty_span.rs b/tracing/benches/empty_span.rs new file mode 100644 index 0000000000..fb38b08e15 --- /dev/null +++ b/tracing/benches/empty_span.rs @@ -0,0 +1,43 @@ +use criterion::{black_box, criterion_group, criterion_main, Criterion}; + +mod shared; + +fn bench(c: &mut Criterion) { + let mut group = c.benchmark_group("empty_span"); + shared::for_all_dispatches(&mut group, |b| { + b.iter(|| { + let span = tracing::span::Span::none(); + black_box(&span); + }) + }); + group.bench_function("baseline_struct", |b| { + b.iter(|| { + let span = FakeEmptySpan::new(); + black_box(&span); + }) + }); +} + +struct FakeEmptySpan { + inner: Option<(usize, std::sync::Arc<()>)>, + meta: Option<&'static ()>, +} + +impl FakeEmptySpan { + fn new() -> Self { + Self { + inner: None, + meta: None, + } + } +} + +impl Drop for FakeEmptySpan { + fn drop(&mut self) { + black_box(&self.inner); + black_box(&self.meta); + } +} + +criterion_group!(benches, bench); +criterion_main!(benches); diff --git a/tracing/benches/enter_span.rs b/tracing/benches/enter_span.rs new file mode 100644 index 0000000000..757350a539 --- /dev/null +++ b/tracing/benches/enter_span.rs @@ -0,0 +1,16 @@ +use criterion::{criterion_group, criterion_main, Criterion}; +use tracing::{span, Level}; + +mod shared; + +fn bench(c: &mut Criterion) { + shared::for_all_dispatches(&mut c.benchmark_group("enter_span"), |b| { + let span = span!(Level::TRACE, "span"); + b.iter(|| { + let _span = span.enter(); + }) + }); +} + +criterion_group!(benches, bench); +criterion_main!(benches); diff --git a/tracing/benches/event.rs b/tracing/benches/event.rs new file mode 100644 index 0000000000..1649325482 --- /dev/null +++ b/tracing/benches/event.rs @@ -0,0 +1,12 @@ +use criterion::{criterion_group, criterion_main, Criterion}; + +mod shared; + +fn bench(c: &mut Criterion) { + shared::for_all_recording(&mut c.benchmark_group("event"), |b| { + b.iter(|| tracing::info!("hello world!")) + }); +} + +criterion_group!(benches, bench); +criterion_main!(benches); diff --git a/tracing/benches/global_subscriber.rs b/tracing/benches/global_subscriber.rs deleted file mode 100644 index 6558bd9021..0000000000 --- a/tracing/benches/global_subscriber.rs +++ /dev/null @@ -1,141 +0,0 @@ -use std::fmt::Write; - -use criterion::{black_box, criterion_group, criterion_main, Criterion}; -use tracing::Level; - -use tracing::{span, Event, Id, Metadata}; -use tracing_core::span::Current; - -/// A collector that is enabled but otherwise does nothing. -struct EnabledCollector; - -impl tracing::Collect for EnabledCollector { - fn new_span(&self, span: &span::Attributes<'_>) -> Id { - let _ = span; - Id::from_u64(0xDEAD_FACE) - } - - fn event(&self, event: &Event<'_>) { - let _ = event; - } - - fn record(&self, span: &Id, values: &span::Record<'_>) { - let _ = (span, values); - } - - fn record_follows_from(&self, span: &Id, follows: &Id) { - let _ = (span, follows); - } - - fn enabled(&self, metadata: &Metadata<'_>) -> bool { - let _ = metadata; - true - } - - fn enter(&self, span: &Id) { - let _ = span; - } - - fn exit(&self, span: &Id) { - let _ = span; - } - - fn current_span(&self) -> Current { - Current::unknown() - } -} - -const NOP_LOGGER: NopLogger = NopLogger; - -struct NopLogger; - -impl log::Log for NopLogger { - fn enabled(&self, _metadata: &log::Metadata) -> bool { - true - } - - fn log(&self, record: &log::Record) { - if self.enabled(record.metadata()) { - let mut this = self; - let _ = write!(this, "{}", record.args()); - } - } - - fn flush(&self) {} -} - -impl Write for &NopLogger { - fn write_str(&mut self, s: &str) -> std::fmt::Result { - black_box(s); - Ok(()) - } -} - -const N_SPANS: usize = 100; - -fn criterion_benchmark(c: &mut Criterion) { - let mut c = c.benchmark_group("global/collector"); - let _ = tracing::collect::set_global_default(EnabledCollector); - let _ = log::set_logger(&NOP_LOGGER); - log::set_max_level(log::LevelFilter::Trace); - c.bench_function("span_no_fields", |b| b.iter(|| span!(Level::TRACE, "span"))); - - c.bench_function("event", |b| { - b.iter(|| { - tracing::event!(Level::TRACE, "hello"); - }) - }); - - c.bench_function("enter_span", |b| { - let span = span!(Level::TRACE, "span"); - #[allow(clippy::unit_arg)] - b.iter(|| black_box(span.in_scope(|| {}))) - }); - - c.bench_function("span_repeatedly", |b| { - #[inline] - fn mk_span(i: u64) -> tracing::Span { - span!(Level::TRACE, "span", i = i) - } - - let n = black_box(N_SPANS); - b.iter(|| (0..n).fold(mk_span(0), |_, i| mk_span(i as u64))) - }); - - c.bench_function("span_with_fields", |b| { - b.iter(|| { - span!( - Level::TRACE, - "span", - foo = "foo", - bar = "bar", - baz = 3, - quuux = tracing::field::debug(0.99) - ) - }); - }); -} - -fn bench_dispatch(c: &mut Criterion) { - let mut group = c.benchmark_group("global/dispatch"); - let _ = tracing::collect::set_global_default(EnabledCollector); - let _ = log::set_logger(&NOP_LOGGER); - log::set_max_level(log::LevelFilter::Trace); - group.bench_function("get_ref", |b| { - b.iter(|| { - tracing::dispatch::get_default(|current| { - black_box(¤t); - }) - }) - }); - group.bench_function("get_clone", |b| { - b.iter(|| { - let current = tracing::dispatch::get_default(|current| current.clone()); - black_box(current); - }) - }); - group.finish(); -} - -criterion_group!(benches, criterion_benchmark, bench_dispatch); -criterion_main!(benches); diff --git a/tracing/benches/no_subscriber.rs b/tracing/benches/no_subscriber.rs deleted file mode 100644 index e0f82b56a0..0000000000 --- a/tracing/benches/no_subscriber.rs +++ /dev/null @@ -1,101 +0,0 @@ -use criterion::{black_box, criterion_group, criterion_main, Criterion}; -use tracing::Level; - -struct FakeEmptySpan { - inner: Option<(usize, std::sync::Arc<()>)>, - meta: Option<&'static ()>, -} - -impl FakeEmptySpan { - fn new() -> Self { - Self { - inner: None, - meta: None, - } - } -} - -impl Drop for FakeEmptySpan { - fn drop(&mut self) { - black_box(&self.inner); - black_box(&self.meta); - } -} - -fn bench_no_subscriber(c: &mut Criterion) { - use std::sync::atomic::{AtomicUsize, Ordering}; - - let mut group = c.benchmark_group("no_subscriber"); - - group.bench_function("span", |b| { - b.iter(|| { - let span = tracing::span!(Level::TRACE, "span"); - black_box(&span); - }) - }); - group.bench_function("span_enter", |b| { - b.iter(|| { - let span = tracing::span!(Level::TRACE, "span"); - let _e = span.enter(); - }) - }); - group.bench_function("empty_span", |b| { - b.iter(|| { - let span = tracing::span::Span::none(); - black_box(&span); - }); - }); - group.bench_function("empty_struct", |b| { - b.iter(|| { - let span = FakeEmptySpan::new(); - black_box(&span); - }) - }); - group.bench_function("event", |b| { - b.iter(|| { - tracing::event!(Level::TRACE, "hello"); - }) - }); - group.bench_function("relaxed_load", |b| { - let foo = AtomicUsize::new(1); - b.iter(|| black_box(foo.load(Ordering::Relaxed))); - }); - group.bench_function("acquire_load", |b| { - let foo = AtomicUsize::new(1); - b.iter(|| black_box(foo.load(Ordering::Acquire))) - }); - group.bench_function("log", |b| { - b.iter(|| { - log::log!(log::Level::Info, "log"); - }) - }); - group.finish(); -} - -fn bench_fields(c: &mut Criterion) { - let mut group = c.benchmark_group("no_subscriber_field"); - group.bench_function("span", |b| { - b.iter(|| { - black_box(tracing::span!( - Level::TRACE, - "span", - foo = tracing::field::display(format!("bar {:?}", 2)) - )); - }) - }); - group.bench_function("event", |b| { - b.iter(|| { - tracing::event!( - Level::TRACE, - foo = tracing::field::display(format!("bar {:?}", 2)) - ); - }) - }); - group.bench_function("log", |b| { - b.iter(|| log::log!(log::Level::Trace, "{}", format!("bar {:?}", 2))) - }); - group.finish(); -} - -criterion_group!(benches, bench_no_subscriber, bench_fields); -criterion_main!(benches); diff --git a/tracing/benches/shared.rs b/tracing/benches/shared.rs new file mode 100644 index 0000000000..d0cdbb8ed1 --- /dev/null +++ b/tracing/benches/shared.rs @@ -0,0 +1,168 @@ +#![allow(dead_code)] +use criterion::{black_box, measurement::WallTime, Bencher}; +use tracing::{field, span, Event, Id, Metadata}; +use tracing_core::span::Current; + +use std::{ + fmt::{self, Write}, + sync::{Mutex, MutexGuard}, +}; + +pub fn for_all_recording( + group: &mut criterion::BenchmarkGroup<'_, WallTime>, + mut iter: impl FnMut(&mut Bencher<'_, WallTime>), +) { + // first, run benchmarks with no collector + group.bench_function("none", &mut iter); + + // then, run benchmarks with a scoped default collector + tracing::collect::with_default(EnabledCollector, || { + group.bench_function("scoped", &mut iter) + }); + + let collector = VisitingCollector(Mutex::new(String::from(""))); + tracing::collect::with_default(collector, || { + group.bench_function("scoped_recording", &mut iter); + }); + + // finally, set a global default collector, and run the benchmarks again. + tracing::collect::set_global_default(EnabledCollector) + .expect("global default should not have already been set!"); + let _ = log::set_logger(&NOP_LOGGER); + log::set_max_level(log::LevelFilter::Trace); + group.bench_function("global", &mut iter); +} + +pub fn for_all_dispatches( + group: &mut criterion::BenchmarkGroup<'_, WallTime>, + mut iter: impl FnMut(&mut Bencher<'_, WallTime>), +) { + // first, run benchmarks with no collector + group.bench_function("none", &mut iter); + + // then, run benchmarks with a scoped default collector + tracing::collect::with_default(EnabledCollector, || { + group.bench_function("scoped", &mut iter) + }); + + // finally, set a global default collector, and run the benchmarks again. + tracing::collect::set_global_default(EnabledCollector) + .expect("global default should not have already been set!"); + let _ = log::set_logger(&NOP_LOGGER); + log::set_max_level(log::LevelFilter::Trace); + group.bench_function("global", &mut iter); +} + +const NOP_LOGGER: NopLogger = NopLogger; + +struct NopLogger; + +impl log::Log for NopLogger { + fn enabled(&self, _metadata: &log::Metadata) -> bool { + true + } + + fn log(&self, record: &log::Record) { + if self.enabled(record.metadata()) { + let mut this = self; + let _ = write!(this, "{}", record.args()); + } + } + + fn flush(&self) {} +} + +impl Write for &NopLogger { + fn write_str(&mut self, s: &str) -> std::fmt::Result { + black_box(s); + Ok(()) + } +} + +/// Simulates a collector that records span data. +struct VisitingCollector(Mutex); + +struct Visitor<'a>(MutexGuard<'a, String>); + +impl<'a> field::Visit for Visitor<'a> { + fn record_debug(&mut self, _field: &field::Field, value: &dyn fmt::Debug) { + let _ = write!(&mut *self.0, "{:?}", value); + } +} + +impl tracing::Collect for VisitingCollector { + fn new_span(&self, span: &span::Attributes<'_>) -> Id { + let mut visitor = Visitor(self.0.lock().unwrap()); + span.record(&mut visitor); + Id::from_u64(0xDEAD_FACE) + } + + fn record(&self, _span: &Id, values: &span::Record<'_>) { + let mut visitor = Visitor(self.0.lock().unwrap()); + values.record(&mut visitor); + } + + fn event(&self, event: &Event<'_>) { + let mut visitor = Visitor(self.0.lock().unwrap()); + event.record(&mut visitor); + } + + fn record_follows_from(&self, span: &Id, follows: &Id) { + let _ = (span, follows); + } + + fn enabled(&self, metadata: &Metadata<'_>) -> bool { + let _ = metadata; + true + } + + fn enter(&self, span: &Id) { + let _ = span; + } + + fn exit(&self, span: &Id) { + let _ = span; + } + + fn current_span(&self) -> Current { + Current::unknown() + } +} + +/// A collector that is enabled but otherwise does nothing. +struct EnabledCollector; + +impl tracing::Collect for EnabledCollector { + fn new_span(&self, span: &span::Attributes<'_>) -> Id { + let _ = span; + Id::from_u64(0xDEAD_FACE) + } + + fn event(&self, event: &Event<'_>) { + let _ = event; + } + + fn record(&self, span: &Id, values: &span::Record<'_>) { + let _ = (span, values); + } + + fn record_follows_from(&self, span: &Id, follows: &Id) { + let _ = (span, follows); + } + + fn enabled(&self, metadata: &Metadata<'_>) -> bool { + let _ = metadata; + true + } + + fn enter(&self, span: &Id) { + let _ = span; + } + + fn exit(&self, span: &Id) { + let _ = span; + } + fn current_span(&self) -> Current { + Current::unknown() + } +} diff --git a/tracing/benches/span_fields.rs b/tracing/benches/span_fields.rs new file mode 100644 index 0000000000..5ad8289826 --- /dev/null +++ b/tracing/benches/span_fields.rs @@ -0,0 +1,23 @@ +use criterion::{criterion_group, criterion_main, Criterion}; +use tracing::{span, Level}; + +mod shared; + +fn bench(c: &mut Criterion) { + shared::for_all_recording(&mut c.benchmark_group("span_fields"), |b| { + b.iter(|| { + let span = span!( + Level::TRACE, + "span", + foo = "foo", + bar = "bar", + baz = 3, + quuux = tracing::field::debug(0.99) + ); + criterion::black_box(span) + }) + }); +} + +criterion_group!(benches, bench); +criterion_main!(benches); diff --git a/tracing/benches/span_no_fields.rs b/tracing/benches/span_no_fields.rs new file mode 100644 index 0000000000..8a1ff6e041 --- /dev/null +++ b/tracing/benches/span_no_fields.rs @@ -0,0 +1,13 @@ +use criterion::{criterion_group, criterion_main, Criterion}; +use tracing::{span, Level}; + +mod shared; + +fn bench(c: &mut Criterion) { + shared::for_all_recording(&mut c.benchmark_group("span_no_fields"), |b| { + b.iter(|| span!(Level::TRACE, "span")) + }); +} + +criterion_group!(benches, bench); +criterion_main!(benches); diff --git a/tracing/benches/span_repeated.rs b/tracing/benches/span_repeated.rs new file mode 100644 index 0000000000..4c6ac409d8 --- /dev/null +++ b/tracing/benches/span_repeated.rs @@ -0,0 +1,20 @@ +use criterion::{black_box, criterion_group, criterion_main, Criterion}; +use tracing::{span, Level}; + +mod shared; + +fn bench(c: &mut Criterion) { + shared::for_all_recording(&mut c.benchmark_group("span_repeated"), |b| { + let n = black_box(N_SPANS); + b.iter(|| (0..n).fold(mk_span(0), |_, i| mk_span(i as u64))) + }); +} + +#[inline] +fn mk_span(i: u64) -> tracing::Span { + span!(Level::TRACE, "span", i = i) +} + +const N_SPANS: usize = 100; +criterion_group!(benches, bench); +criterion_main!(benches); diff --git a/tracing/benches/subscriber.rs b/tracing/benches/subscriber.rs deleted file mode 100644 index 3fda5283e0..0000000000 --- a/tracing/benches/subscriber.rs +++ /dev/null @@ -1,209 +0,0 @@ -use criterion::{black_box, criterion_group, criterion_main, Criterion}; -use tracing::Level; - -use std::{ - fmt, - sync::{Mutex, MutexGuard}, -}; -use tracing::{field, span, Event, Id, Metadata}; -use tracing_core::span::Current; - -/// A collector that is enabled but otherwise does nothing. -struct EnabledCollector; - -impl tracing::Collect for EnabledCollector { - fn new_span(&self, span: &span::Attributes<'_>) -> Id { - let _ = span; - Id::from_u64(0xDEAD_FACE) - } - - fn event(&self, event: &Event<'_>) { - let _ = event; - } - - fn record(&self, span: &Id, values: &span::Record<'_>) { - let _ = (span, values); - } - - fn record_follows_from(&self, span: &Id, follows: &Id) { - let _ = (span, follows); - } - - fn enabled(&self, metadata: &Metadata<'_>) -> bool { - let _ = metadata; - true - } - - fn enter(&self, span: &Id) { - let _ = span; - } - - fn exit(&self, span: &Id) { - let _ = span; - } - fn current_span(&self) -> Current { - Current::unknown() - } -} - -/// Simulates a collector that records span data. -struct VisitingCollector(Mutex); - -struct Visitor<'a>(MutexGuard<'a, String>); - -impl<'a> field::Visit for Visitor<'a> { - fn record_debug(&mut self, _field: &field::Field, value: &dyn fmt::Debug) { - use std::fmt::Write; - let _ = write!(&mut *self.0, "{:?}", value); - } -} - -impl tracing::Collect for VisitingCollector { - fn new_span(&self, span: &span::Attributes<'_>) -> Id { - let mut visitor = Visitor(self.0.lock().unwrap()); - span.record(&mut visitor); - Id::from_u64(0xDEAD_FACE) - } - - fn record(&self, _span: &Id, values: &span::Record<'_>) { - let mut visitor = Visitor(self.0.lock().unwrap()); - values.record(&mut visitor); - } - - fn event(&self, event: &Event<'_>) { - let mut visitor = Visitor(self.0.lock().unwrap()); - event.record(&mut visitor); - } - - fn record_follows_from(&self, span: &Id, follows: &Id) { - let _ = (span, follows); - } - - fn enabled(&self, metadata: &Metadata<'_>) -> bool { - let _ = metadata; - true - } - - fn enter(&self, span: &Id) { - let _ = span; - } - - fn exit(&self, span: &Id) { - let _ = span; - } - - fn current_span(&self) -> Current { - Current::unknown() - } -} - -const N_SPANS: usize = 100; - -fn criterion_benchmark(c: &mut Criterion) { - let mut c = c.benchmark_group("scoped/subscriber"); - c.bench_function("span_no_fields", |b| { - tracing::collect::with_default(EnabledCollector, || b.iter(|| span!(Level::TRACE, "span"))); - }); - - c.bench_function("enter_span", |b| { - tracing::collect::with_default(EnabledCollector, || { - let span = span!(Level::TRACE, "span"); - #[allow(clippy::unit_arg)] - b.iter(|| black_box(span.in_scope(|| {}))) - }); - }); - - c.bench_function("event", |b| { - tracing::collect::with_default(EnabledCollector, || { - b.iter(|| { - tracing::event!(Level::TRACE, "hello"); - }); - }); - }); - - c.bench_function("span_repeatedly", |b| { - #[inline] - fn mk_span(i: u64) -> tracing::Span { - span!(Level::TRACE, "span", i = i) - } - - let n = black_box(N_SPANS); - tracing::collect::with_default(EnabledCollector, || { - b.iter(|| (0..n).fold(mk_span(0), |_, i| mk_span(i as u64))) - }); - }); - - c.bench_function("span_with_fields", |b| { - tracing::collect::with_default(EnabledCollector, || { - b.iter(|| { - span!( - Level::TRACE, - "span", - foo = "foo", - bar = "bar", - baz = 3, - quuux = tracing::field::debug(0.99) - ) - }) - }); - }); - - c.bench_function("span_with_fields_record", |b| { - let subscriber = VisitingCollector(Mutex::new(String::from(""))); - tracing::collect::with_default(subscriber, || { - b.iter(|| { - span!( - Level::TRACE, - "span", - foo = "foo", - bar = "bar", - baz = 3, - quuux = tracing::field::debug(0.99) - ) - }) - }); - }); - - c.finish(); -} - -fn bench_dispatch(c: &mut Criterion) { - let mut group = c.benchmark_group("no/dispatch"); - group.bench_function("get_ref", |b| { - b.iter(|| { - tracing::dispatch::get_default(|current| { - black_box(¤t); - }) - }) - }); - group.bench_function("get_clone", |b| { - b.iter(|| { - let current = tracing::dispatch::get_default(|current| current.clone()); - black_box(current); - }) - }); - group.finish(); - - let mut group = c.benchmark_group("scoped/dispatch"); - group.bench_function("get_ref", |b| { - tracing::collect::with_default(EnabledCollector, || { - b.iter(|| { - tracing::dispatch::get_default(|current| { - black_box(¤t); - }) - }) - }) - }); - group.bench_function("get_clone", |b| { - tracing::collect::with_default(EnabledCollector, || { - b.iter(|| { - let current = tracing::dispatch::get_default(|current| current.clone()); - black_box(current); - }) - }) - }); - group.finish(); -} - -criterion_group!(benches, criterion_benchmark, bench_dispatch); -criterion_main!(benches);