From 698f8c2f01ea549d77d7dc3338a12e04c11057b9 Mon Sep 17 00:00:00 2001 From: Daniel Baumann Date: Wed, 17 Apr 2024 14:02:58 +0200 Subject: Adding upstream version 1.64.0+dfsg1. Signed-off-by: Daniel Baumann --- vendor/tracing-subscriber/benches/enter.rs | 64 +++++ vendor/tracing-subscriber/benches/filter.rs | 308 +++++++++++++++++++++ vendor/tracing-subscriber/benches/filter_log.rs | 315 +++++++++++++++++++++ vendor/tracing-subscriber/benches/fmt.rs | 331 +++++++++++++++++++++++ vendor/tracing-subscriber/benches/support/mod.rs | 49 ++++ 5 files changed, 1067 insertions(+) create mode 100644 vendor/tracing-subscriber/benches/enter.rs create mode 100644 vendor/tracing-subscriber/benches/filter.rs create mode 100644 vendor/tracing-subscriber/benches/filter_log.rs create mode 100644 vendor/tracing-subscriber/benches/fmt.rs create mode 100644 vendor/tracing-subscriber/benches/support/mod.rs (limited to 'vendor/tracing-subscriber/benches') diff --git a/vendor/tracing-subscriber/benches/enter.rs b/vendor/tracing-subscriber/benches/enter.rs new file mode 100644 index 000000000..49c6e730a --- /dev/null +++ b/vendor/tracing-subscriber/benches/enter.rs @@ -0,0 +1,64 @@ +use criterion::{criterion_group, criterion_main, Criterion}; +use tracing_subscriber::prelude::*; + +fn enter(c: &mut Criterion) { + let mut group = c.benchmark_group("enter"); + let _subscriber = tracing_subscriber::fmt() + .with_max_level(tracing::Level::INFO) + .finish() + .set_default(); + group.bench_function("enabled", |b| { + let span = tracing::info_span!("foo"); + b.iter_with_large_drop(|| span.enter()) + }); + group.bench_function("disabled", |b| { + let span = tracing::debug_span!("foo"); + b.iter_with_large_drop(|| span.enter()) + }); +} + +fn enter_exit(c: &mut Criterion) { + let mut group = c.benchmark_group("enter_exit"); + let _subscriber = tracing_subscriber::fmt() + .with_max_level(tracing::Level::INFO) + .finish() + .set_default(); + group.bench_function("enabled", |b| { + let span = tracing::info_span!("foo"); + b.iter(|| span.enter()) + }); + group.bench_function("disabled", |b| { + let span = tracing::debug_span!("foo"); + b.iter(|| span.enter()) + }); +} + +fn enter_many(c: &mut Criterion) { + let mut group = c.benchmark_group("enter_many"); + let _subscriber = tracing_subscriber::fmt() + .with_max_level(tracing::Level::INFO) + .finish() + .set_default(); + group.bench_function("enabled", |b| { + let span1 = tracing::info_span!("span1"); + let _e1 = span1.enter(); + let span2 = tracing::info_span!("span2"); + let _e2 = span2.enter(); + let span3 = tracing::info_span!("span3"); + let _e3 = span3.enter(); + let span = tracing::info_span!("foo"); + b.iter_with_large_drop(|| span.enter()) + }); + group.bench_function("disabled", |b| { + let span1 = tracing::info_span!("span1"); + let _e1 = span1.enter(); + let span2 = tracing::info_span!("span2"); + let _e2 = span2.enter(); + let span3 = tracing::info_span!("span3"); + let _e3 = span3.enter(); + let span = tracing::debug_span!("foo"); + b.iter_with_large_drop(|| span.enter()) + }); +} +criterion_group!(benches, enter, enter_exit, enter_many); +criterion_main!(benches); diff --git a/vendor/tracing-subscriber/benches/filter.rs b/vendor/tracing-subscriber/benches/filter.rs new file mode 100644 index 000000000..91ab9c91d --- /dev/null +++ b/vendor/tracing-subscriber/benches/filter.rs @@ -0,0 +1,308 @@ +use criterion::{criterion_group, criterion_main, Criterion}; +use std::time::Duration; +use tracing::{dispatcher::Dispatch, span, Event, Id, Metadata}; +use tracing_subscriber::{prelude::*, EnvFilter}; + +mod support; +use support::MultithreadedBench; + +/// A subscriber that is enabled but otherwise does nothing. +struct EnabledSubscriber; + +impl tracing::Subscriber for EnabledSubscriber { + 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 bench_static(c: &mut Criterion) { + let mut group = c.benchmark_group("static"); + + group.bench_function("baseline_single_threaded", |b| { + tracing::subscriber::with_default(EnabledSubscriber, || { + b.iter(|| { + tracing::info!(target: "static_filter", "hi"); + tracing::debug!(target: "static_filter", "hi"); + tracing::warn!(target: "static_filter", "hi"); + tracing::trace!(target: "foo", "hi"); + }) + }); + }); + group.bench_function("single_threaded", |b| { + let filter = "static_filter=info" + .parse::() + .expect("should parse"); + tracing::subscriber::with_default(EnabledSubscriber.with(filter), || { + b.iter(|| { + tracing::info!(target: "static_filter", "hi"); + tracing::debug!(target: "static_filter", "hi"); + tracing::warn!(target: "static_filter", "hi"); + tracing::trace!(target: "foo", "hi"); + }) + }); + }); + group.bench_function("enabled_one", |b| { + let filter = "static_filter=info" + .parse::() + .expect("should parse"); + tracing::subscriber::with_default(EnabledSubscriber.with(filter), || { + b.iter(|| { + tracing::info!(target: "static_filter", "hi"); + }) + }); + }); + group.bench_function("enabled_many", |b| { + let filter = "foo=debug,bar=trace,baz=error,quux=warn,static_filter=info" + .parse::() + .expect("should parse"); + tracing::subscriber::with_default(EnabledSubscriber.with(filter), || { + b.iter(|| { + tracing::info!(target: "static_filter", "hi"); + }) + }); + }); + group.bench_function("disabled_level_one", |b| { + let filter = "static_filter=info" + .parse::() + .expect("should parse"); + tracing::subscriber::with_default(EnabledSubscriber.with(filter), || { + b.iter(|| { + tracing::debug!(target: "static_filter", "hi"); + }) + }); + }); + group.bench_function("disabled_level_many", |b| { + let filter = "foo=debug,bar=info,baz=error,quux=warn,static_filter=info" + .parse::() + .expect("should parse"); + tracing::subscriber::with_default(EnabledSubscriber.with(filter), || { + b.iter(|| { + tracing::trace!(target: "static_filter", "hi"); + }) + }); + }); + group.bench_function("disabled_one", |b| { + let filter = "foo=info".parse::().expect("should parse"); + tracing::subscriber::with_default(EnabledSubscriber.with(filter), || { + b.iter(|| { + tracing::info!(target: "static_filter", "hi"); + }) + }); + }); + group.bench_function("disabled_many", |b| { + let filter = "foo=debug,bar=trace,baz=error,quux=warn,whibble=info" + .parse::() + .expect("should parse"); + tracing::subscriber::with_default(EnabledSubscriber.with(filter), || { + b.iter(|| { + tracing::info!(target: "static_filter", "hi"); + }) + }); + }); + group.bench_function("baseline_multithreaded", |b| { + let dispatch = Dispatch::new(EnabledSubscriber); + b.iter_custom(|iters| { + let mut total = Duration::from_secs(0); + for _ in 0..iters { + let bench = MultithreadedBench::new(dispatch.clone()); + let elapsed = bench + .thread(|| { + tracing::info!(target: "static_filter", "hi"); + }) + .thread(|| { + tracing::debug!(target: "static_filter", "hi"); + }) + .thread(|| { + tracing::warn!(target: "static_filter", "hi"); + }) + .thread(|| { + tracing::warn!(target: "foo", "hi"); + }) + .run(); + total += elapsed; + } + total + }) + }); + group.bench_function("multithreaded", |b| { + let filter = "static_filter=info" + .parse::() + .expect("should parse"); + let dispatch = Dispatch::new(EnabledSubscriber.with(filter)); + b.iter_custom(|iters| { + let mut total = Duration::from_secs(0); + for _ in 0..iters { + let bench = MultithreadedBench::new(dispatch.clone()); + let elapsed = bench + .thread(|| { + tracing::info!(target: "static_filter", "hi"); + }) + .thread(|| { + tracing::debug!(target: "static_filter", "hi"); + }) + .thread(|| { + tracing::warn!(target: "static_filter", "hi"); + }) + .thread(|| { + tracing::warn!(target: "foo", "hi"); + }) + .run(); + total += elapsed; + } + total + }); + }); + group.finish(); +} + +fn bench_dynamic(c: &mut Criterion) { + let mut group = c.benchmark_group("dynamic"); + + group.bench_function("baseline_single_threaded", |b| { + tracing::subscriber::with_default(EnabledSubscriber, || { + b.iter(|| { + tracing::info_span!("foo").in_scope(|| { + tracing::info!("hi"); + tracing::debug!("hi"); + }); + tracing::info_span!("bar").in_scope(|| { + tracing::warn!("hi"); + }); + tracing::trace!("hi"); + }) + }); + }); + group.bench_function("single_threaded", |b| { + let filter = "[foo]=trace".parse::().expect("should parse"); + tracing::subscriber::with_default(EnabledSubscriber.with(filter), || { + b.iter(|| { + tracing::info_span!("foo").in_scope(|| { + tracing::info!("hi"); + tracing::debug!("hi"); + }); + tracing::info_span!("bar").in_scope(|| { + tracing::warn!("hi"); + }); + tracing::trace!("hi"); + }) + }); + }); + group.bench_function("baseline_multithreaded", |b| { + let dispatch = Dispatch::new(EnabledSubscriber); + b.iter_custom(|iters| { + let mut total = Duration::from_secs(0); + for _ in 0..iters { + let bench = MultithreadedBench::new(dispatch.clone()); + let elapsed = bench + .thread(|| { + let span = tracing::info_span!("foo"); + let _ = span.enter(); + tracing::info!("hi"); + }) + .thread(|| { + let span = tracing::info_span!("foo"); + let _ = span.enter(); + tracing::debug!("hi"); + }) + .thread(|| { + let span = tracing::info_span!("bar"); + let _ = span.enter(); + tracing::debug!("hi"); + }) + .thread(|| { + tracing::trace!("hi"); + }) + .run(); + total += elapsed; + } + total + }) + }); + group.bench_function("multithreaded", |b| { + let filter = "[foo]=trace".parse::().expect("should parse"); + let dispatch = Dispatch::new(EnabledSubscriber.with(filter)); + b.iter_custom(|iters| { + let mut total = Duration::from_secs(0); + for _ in 0..iters { + let bench = MultithreadedBench::new(dispatch.clone()); + let elapsed = bench + .thread(|| { + let span = tracing::info_span!("foo"); + let _ = span.enter(); + tracing::info!("hi"); + }) + .thread(|| { + let span = tracing::info_span!("foo"); + let _ = span.enter(); + tracing::debug!("hi"); + }) + .thread(|| { + let span = tracing::info_span!("bar"); + let _ = span.enter(); + tracing::debug!("hi"); + }) + .thread(|| { + tracing::trace!("hi"); + }) + .run(); + total += elapsed; + } + total + }) + }); + + group.finish(); +} + +fn bench_mixed(c: &mut Criterion) { + let mut group = c.benchmark_group("mixed"); + group.bench_function("disabled", |b| { + let filter = "[foo]=trace,bar[quux]=debug,[{baz}]=debug,asdf=warn,wibble=info" + .parse::() + .expect("should parse"); + tracing::subscriber::with_default(EnabledSubscriber.with(filter), || { + b.iter(|| { + tracing::info!(target: "static_filter", "hi"); + }) + }); + }); + group.bench_function("disabled_by_level", |b| { + let filter = "[foo]=info,bar[quux]=debug,asdf=warn,static_filter=info" + .parse::() + .expect("should parse"); + tracing::subscriber::with_default(EnabledSubscriber.with(filter), || { + b.iter(|| { + tracing::trace!(target: "static_filter", "hi"); + }) + }); + }); +} + +criterion_group!(benches, bench_static, bench_dynamic, bench_mixed); +criterion_main!(benches); diff --git a/vendor/tracing-subscriber/benches/filter_log.rs b/vendor/tracing-subscriber/benches/filter_log.rs new file mode 100644 index 000000000..4dcf3b4ec --- /dev/null +++ b/vendor/tracing-subscriber/benches/filter_log.rs @@ -0,0 +1,315 @@ +use criterion::{criterion_group, criterion_main, Criterion}; +use std::time::Duration; +use tracing::{dispatcher::Dispatch, span, Event, Id, Metadata}; +use tracing_subscriber::{prelude::*, EnvFilter}; + +mod support; +use support::MultithreadedBench; + +/// A subscriber that is enabled but otherwise does nothing. +struct EnabledSubscriber; + +impl tracing::Subscriber for EnabledSubscriber { + 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 bench_static(c: &mut Criterion) { + let _ = tracing_log::LogTracer::init(); + + let mut group = c.benchmark_group("log/static"); + + group.bench_function("baseline_single_threaded", |b| { + tracing::subscriber::with_default(EnabledSubscriber, || { + b.iter(|| { + log::info!(target: "static_filter", "hi"); + log::debug!(target: "static_filter", "hi"); + log::warn!(target: "static_filter", "hi"); + log::trace!(target: "foo", "hi"); + }) + }); + }); + group.bench_function("single_threaded", |b| { + let filter = "static_filter=info" + .parse::() + .expect("should parse"); + tracing::subscriber::with_default(EnabledSubscriber.with(filter), || { + b.iter(|| { + log::info!(target: "static_filter", "hi"); + log::debug!(target: "static_filter", "hi"); + log::warn!(target: "static_filter", "hi"); + log::trace!(target: "foo", "hi"); + }) + }); + }); + group.bench_function("enabled_one", |b| { + let filter = "static_filter=info" + .parse::() + .expect("should parse"); + tracing::subscriber::with_default(EnabledSubscriber.with(filter), || { + b.iter(|| { + log::info!(target: "static_filter", "hi"); + }) + }); + }); + group.bench_function("enabled_many", |b| { + let filter = "foo=debug,bar=trace,baz=error,quux=warn,static_filter=info" + .parse::() + .expect("should parse"); + tracing::subscriber::with_default(EnabledSubscriber.with(filter), || { + b.iter(|| { + log::info!(target: "static_filter", "hi"); + }) + }); + }); + group.bench_function("disabled_level_one", |b| { + let filter = "static_filter=info" + .parse::() + .expect("should parse"); + tracing::subscriber::with_default(EnabledSubscriber.with(filter), || { + b.iter(|| { + log::debug!(target: "static_filter", "hi"); + }) + }); + }); + group.bench_function("disabled_level_many", |b| { + let filter = "foo=debug,bar=info,baz=error,quux=warn,static_filter=info" + .parse::() + .expect("should parse"); + tracing::subscriber::with_default(EnabledSubscriber.with(filter), || { + b.iter(|| { + log::trace!(target: "static_filter", "hi"); + }) + }); + }); + group.bench_function("disabled_one", |b| { + let filter = "foo=info".parse::().expect("should parse"); + tracing::subscriber::with_default(EnabledSubscriber.with(filter), || { + b.iter(|| { + log::info!(target: "static_filter", "hi"); + }) + }); + }); + group.bench_function("disabled_many", |b| { + let filter = "foo=debug,bar=trace,baz=error,quux=warn,whibble=info" + .parse::() + .expect("should parse"); + tracing::subscriber::with_default(EnabledSubscriber.with(filter), || { + b.iter(|| { + log::info!(target: "static_filter", "hi"); + }) + }); + }); + group.bench_function("baseline_multithreaded", |b| { + let dispatch = Dispatch::new(EnabledSubscriber); + b.iter_custom(|iters| { + let mut total = Duration::from_secs(0); + for _ in 0..iters { + let bench = MultithreadedBench::new(dispatch.clone()); + let elapsed = bench + .thread(|| { + log::info!(target: "static_filter", "hi"); + }) + .thread(|| { + log::debug!(target: "static_filter", "hi"); + }) + .thread(|| { + log::warn!(target: "static_filter", "hi"); + }) + .thread(|| { + log::warn!(target: "foo", "hi"); + }) + .run(); + total += elapsed; + } + total + }) + }); + group.bench_function("multithreaded", |b| { + let filter = "static_filter=info" + .parse::() + .expect("should parse"); + let dispatch = Dispatch::new(EnabledSubscriber.with(filter)); + b.iter_custom(|iters| { + let mut total = Duration::from_secs(0); + for _ in 0..iters { + let bench = MultithreadedBench::new(dispatch.clone()); + let elapsed = bench + .thread(|| { + log::info!(target: "static_filter", "hi"); + }) + .thread(|| { + log::debug!(target: "static_filter", "hi"); + }) + .thread(|| { + log::warn!(target: "static_filter", "hi"); + }) + .thread(|| { + log::warn!(target: "foo", "hi"); + }) + .run(); + total += elapsed; + } + total + }); + }); + group.finish(); +} + +fn bench_dynamic(c: &mut Criterion) { + let _ = tracing_log::LogTracer::init(); + + let mut group = c.benchmark_group("log/dynamic"); + + group.bench_function("baseline_single_threaded", |b| { + tracing::subscriber::with_default(EnabledSubscriber, || { + b.iter(|| { + tracing::info_span!("foo").in_scope(|| { + log::info!("hi"); + log::debug!("hi"); + }); + tracing::info_span!("bar").in_scope(|| { + log::warn!("hi"); + }); + log::trace!("hi"); + }) + }); + }); + group.bench_function("single_threaded", |b| { + let filter = "[foo]=trace".parse::().expect("should parse"); + tracing::subscriber::with_default(EnabledSubscriber.with(filter), || { + b.iter(|| { + tracing::info_span!("foo").in_scope(|| { + log::info!("hi"); + log::debug!("hi"); + }); + tracing::info_span!("bar").in_scope(|| { + log::warn!("hi"); + }); + log::trace!("hi"); + }) + }); + }); + group.bench_function("baseline_multithreaded", |b| { + let dispatch = Dispatch::new(EnabledSubscriber); + b.iter_custom(|iters| { + let mut total = Duration::from_secs(0); + for _ in 0..iters { + let bench = MultithreadedBench::new(dispatch.clone()); + let elapsed = bench + .thread(|| { + let span = tracing::info_span!("foo"); + let _ = span.enter(); + log::info!("hi"); + }) + .thread(|| { + let span = tracing::info_span!("foo"); + let _ = span.enter(); + log::debug!("hi"); + }) + .thread(|| { + let span = tracing::info_span!("bar"); + let _ = span.enter(); + log::debug!("hi"); + }) + .thread(|| { + log::trace!("hi"); + }) + .run(); + total += elapsed; + } + total + }) + }); + group.bench_function("multithreaded", |b| { + let filter = "[foo]=trace".parse::().expect("should parse"); + let dispatch = Dispatch::new(EnabledSubscriber.with(filter)); + b.iter_custom(|iters| { + let mut total = Duration::from_secs(0); + for _ in 0..iters { + let bench = MultithreadedBench::new(dispatch.clone()); + let elapsed = bench + .thread(|| { + let span = tracing::info_span!("foo"); + let _ = span.enter(); + log::info!("hi"); + }) + .thread(|| { + let span = tracing::info_span!("foo"); + let _ = span.enter(); + log::debug!("hi"); + }) + .thread(|| { + let span = tracing::info_span!("bar"); + let _ = span.enter(); + log::debug!("hi"); + }) + .thread(|| { + log::trace!("hi"); + }) + .run(); + total += elapsed; + } + total + }) + }); + + group.finish(); +} + +fn bench_mixed(c: &mut Criterion) { + let _ = tracing_log::LogTracer::init(); + + let mut group = c.benchmark_group("log/mixed"); + + group.bench_function("disabled", |b| { + let filter = "[foo]=trace,bar[quux]=debug,[{baz}]=debug,asdf=warn,wibble=info" + .parse::() + .expect("should parse"); + tracing::subscriber::with_default(EnabledSubscriber.with(filter), || { + b.iter(|| { + log::info!(target: "static_filter", "hi"); + }) + }); + }); + group.bench_function("disabled_by_level", |b| { + let filter = "[foo]=info,bar[quux]=debug,asdf=warn,static_filter=info" + .parse::() + .expect("should parse"); + tracing::subscriber::with_default(EnabledSubscriber.with(filter), || { + b.iter(|| { + log::trace!(target: "static_filter", "hi"); + }) + }); + }); +} + +criterion_group!(benches, bench_static, bench_dynamic, bench_mixed); +criterion_main!(benches); diff --git a/vendor/tracing-subscriber/benches/fmt.rs b/vendor/tracing-subscriber/benches/fmt.rs new file mode 100644 index 000000000..a039e66d4 --- /dev/null +++ b/vendor/tracing-subscriber/benches/fmt.rs @@ -0,0 +1,331 @@ +use criterion::{criterion_group, criterion_main, BenchmarkId, Criterion, Throughput}; +use std::{io, time::Duration}; + +mod support; +use support::MultithreadedBench; + +/// A fake writer that doesn't actually do anything. +/// +/// We want to measure the subscriber's overhead, *not* the performance of +/// stdout/file writers. Using a no-op Write implementation lets us only measure +/// the subscriber's overhead. +struct NoWriter; + +impl io::Write for NoWriter { + fn write(&mut self, buf: &[u8]) -> io::Result { + Ok(buf.len()) + } + + fn flush(&mut self) -> io::Result<()> { + Ok(()) + } +} + +impl NoWriter { + fn new() -> Self { + Self + } +} + +fn bench_new_span(c: &mut Criterion) { + bench_thrpt(c, "new_span", |group, i| { + group.bench_with_input(BenchmarkId::new("single_thread", i), i, |b, &i| { + tracing::dispatcher::with_default(&mk_dispatch(), || { + b.iter(|| { + for n in 0..i { + let _span = tracing::info_span!("span", n); + } + }) + }); + }); + group.bench_with_input(BenchmarkId::new("multithreaded", i), i, |b, &i| { + b.iter_custom(|iters| { + let mut total = Duration::from_secs(0); + let dispatch = mk_dispatch(); + for _ in 0..iters { + let bench = MultithreadedBench::new(dispatch.clone()); + let elapsed = bench + .thread(move || { + for n in 0..i { + let _span = tracing::info_span!("span", n); + } + }) + .thread(move || { + for n in 0..i { + let _span = tracing::info_span!("span", n); + } + }) + .thread(move || { + for n in 0..i { + let _span = tracing::info_span!("span", n); + } + }) + .thread(move || { + for n in 0..i { + let _span = tracing::info_span!("span", n); + } + }) + .run(); + total += elapsed; + } + total + }) + }); + }); +} + +type Group<'a> = criterion::BenchmarkGroup<'a, criterion::measurement::WallTime>; +fn bench_thrpt(c: &mut Criterion, name: &'static str, mut f: impl FnMut(&mut Group<'_>, &usize)) { + const N_SPANS: &[usize] = &[1, 10, 50]; + + let mut group = c.benchmark_group(name); + for spans in N_SPANS { + group.throughput(Throughput::Elements(*spans as u64)); + f(&mut group, spans); + } + group.finish(); +} + +fn mk_dispatch() -> tracing::Dispatch { + let subscriber = tracing_subscriber::FmtSubscriber::builder() + .with_writer(NoWriter::new) + .finish(); + tracing::Dispatch::new(subscriber) +} + +fn bench_event(c: &mut Criterion) { + bench_thrpt(c, "event", |group, i| { + group.bench_with_input(BenchmarkId::new("root/single_threaded", i), i, |b, &i| { + let dispatch = mk_dispatch(); + tracing::dispatcher::with_default(&dispatch, || { + b.iter(|| { + for n in 0..i { + tracing::info!(n); + } + }) + }); + }); + group.bench_with_input(BenchmarkId::new("root/multithreaded", i), i, |b, &i| { + b.iter_custom(|iters| { + let mut total = Duration::from_secs(0); + let dispatch = mk_dispatch(); + for _ in 0..iters { + let bench = MultithreadedBench::new(dispatch.clone()); + let elapsed = bench + .thread(move || { + for n in 0..i { + tracing::info!(n); + } + }) + .thread(move || { + for n in 0..i { + tracing::info!(n); + } + }) + .thread(move || { + for n in 0..i { + tracing::info!(n); + } + }) + .thread(move || { + for n in 0..i { + tracing::info!(n); + } + }) + .run(); + total += elapsed; + } + total + }) + }); + group.bench_with_input( + BenchmarkId::new("unique_parent/single_threaded", i), + i, + |b, &i| { + tracing::dispatcher::with_default(&mk_dispatch(), || { + let span = tracing::info_span!("unique_parent", foo = false); + let _guard = span.enter(); + b.iter(|| { + for n in 0..i { + tracing::info!(n); + } + }) + }); + }, + ); + group.bench_with_input( + BenchmarkId::new("unique_parent/multithreaded", i), + i, + |b, &i| { + b.iter_custom(|iters| { + let mut total = Duration::from_secs(0); + let dispatch = mk_dispatch(); + for _ in 0..iters { + let bench = MultithreadedBench::new(dispatch.clone()); + let elapsed = bench + .thread_with_setup(move |start| { + let span = tracing::info_span!("unique_parent", foo = false); + let _guard = span.enter(); + start.wait(); + for n in 0..i { + tracing::info!(n); + } + }) + .thread_with_setup(move |start| { + let span = tracing::info_span!("unique_parent", foo = false); + let _guard = span.enter(); + start.wait(); + for n in 0..i { + tracing::info!(n); + } + }) + .thread_with_setup(move |start| { + let span = tracing::info_span!("unique_parent", foo = false); + let _guard = span.enter(); + start.wait(); + for n in 0..i { + tracing::info!(n); + } + }) + .thread_with_setup(move |start| { + let span = tracing::info_span!("unique_parent", foo = false); + let _guard = span.enter(); + start.wait(); + for n in 0..i { + tracing::info!(n); + } + }) + .run(); + total += elapsed; + } + total + }) + }, + ); + group.bench_with_input( + BenchmarkId::new("shared_parent/multithreaded", i), + i, + |b, &i| { + b.iter_custom(|iters| { + let dispatch = mk_dispatch(); + let mut total = Duration::from_secs(0); + for _ in 0..iters { + let parent = tracing::dispatcher::with_default(&dispatch, || { + tracing::info_span!("shared_parent", foo = "hello world") + }); + let bench = MultithreadedBench::new(dispatch.clone()); + let parent2 = parent.clone(); + bench.thread_with_setup(move |start| { + let _guard = parent2.enter(); + start.wait(); + for n in 0..i { + tracing::info!(n); + } + }); + let parent2 = parent.clone(); + bench.thread_with_setup(move |start| { + let _guard = parent2.enter(); + start.wait(); + for n in 0..i { + tracing::info!(n); + } + }); + let parent2 = parent.clone(); + bench.thread_with_setup(move |start| { + let _guard = parent2.enter(); + start.wait(); + for n in 0..i { + tracing::info!(n); + } + }); + let parent2 = parent.clone(); + bench.thread_with_setup(move |start| { + let _guard = parent2.enter(); + start.wait(); + for n in 0..i { + tracing::info!(n); + } + }); + let elapsed = bench.run(); + total += elapsed; + } + total + }) + }, + ); + group.bench_with_input( + BenchmarkId::new("multi-parent/multithreaded", i), + i, + |b, &i| { + b.iter_custom(|iters| { + let dispatch = mk_dispatch(); + let mut total = Duration::from_secs(0); + for _ in 0..iters { + let parent = tracing::dispatcher::with_default(&dispatch, || { + tracing::info_span!("multiparent", foo = "hello world") + }); + let bench = MultithreadedBench::new(dispatch.clone()); + let parent2 = parent.clone(); + bench.thread_with_setup(move |start| { + let _guard = parent2.enter(); + start.wait(); + let mut span = tracing::info_span!("parent"); + for n in 0..i { + let s = tracing::info_span!(parent: &span, "parent2", n, i); + s.in_scope(|| { + tracing::info!(n); + }); + span = s; + } + }); + let parent2 = parent.clone(); + bench.thread_with_setup(move |start| { + let _guard = parent2.enter(); + start.wait(); + let mut span = tracing::info_span!("parent"); + for n in 0..i { + let s = tracing::info_span!(parent: &span, "parent2", n, i); + s.in_scope(|| { + tracing::info!(n); + }); + span = s; + } + }); + let parent2 = parent.clone(); + bench.thread_with_setup(move |start| { + let _guard = parent2.enter(); + start.wait(); + let mut span = tracing::info_span!("parent"); + for n in 0..i { + let s = tracing::info_span!(parent: &span, "parent2", n, i); + s.in_scope(|| { + tracing::info!(n); + }); + span = s; + } + }); + let parent2 = parent.clone(); + bench.thread_with_setup(move |start| { + let _guard = parent2.enter(); + start.wait(); + let mut span = tracing::info_span!("parent"); + for n in 0..i { + let s = tracing::info_span!(parent: &span, "parent2", n, i); + s.in_scope(|| { + tracing::info!(n); + }); + span = s; + } + }); + let elapsed = bench.run(); + total += elapsed; + } + total + }) + }, + ); + }); +} + +criterion_group!(benches, bench_new_span, bench_event); +criterion_main!(benches); diff --git a/vendor/tracing-subscriber/benches/support/mod.rs b/vendor/tracing-subscriber/benches/support/mod.rs new file mode 100644 index 000000000..25e9e7e22 --- /dev/null +++ b/vendor/tracing-subscriber/benches/support/mod.rs @@ -0,0 +1,49 @@ +use std::{ + sync::{Arc, Barrier}, + thread, + time::{Duration, Instant}, +}; +use tracing::dispatcher::Dispatch; + +#[derive(Clone)] +pub(super) struct MultithreadedBench { + start: Arc, + end: Arc, + dispatch: Dispatch, +} + +impl MultithreadedBench { + pub(super) fn new(dispatch: Dispatch) -> Self { + Self { + start: Arc::new(Barrier::new(5)), + end: Arc::new(Barrier::new(5)), + dispatch, + } + } + + pub(super) fn thread(&self, f: impl FnOnce() + Send + 'static) -> &Self { + self.thread_with_setup(|start| { + start.wait(); + f() + }) + } + + pub(super) fn thread_with_setup(&self, f: impl FnOnce(&Barrier) + Send + 'static) -> &Self { + let this = self.clone(); + thread::spawn(move || { + let dispatch = this.dispatch.clone(); + tracing::dispatcher::with_default(&dispatch, move || { + f(&*this.start); + this.end.wait(); + }) + }); + self + } + + pub(super) fn run(&self) -> Duration { + self.start.wait(); + let t0 = Instant::now(); + self.end.wait(); + t0.elapsed() + } +} -- cgit v1.2.3