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

Benches for reloadable collectors #1090

Merged
merged 8 commits into from
Nov 23, 2020
Merged
Show file tree
Hide file tree
Changes from 2 commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
188 changes: 187 additions & 1 deletion tracing-subscriber/benches/filter.rs
Original file line number Diff line number Diff line change
@@ -1,7 +1,7 @@
use criterion::{criterion_group, criterion_main, Criterion};
use std::time::Duration;
use tracing::{dispatch::Dispatch, span, Event, Id, Metadata};
use tracing_subscriber::{prelude::*, EnvFilter};
use tracing_subscriber::{prelude::*, EnvFilter, reload};

mod support;
use support::MultithreadedBench;
Expand Down Expand Up @@ -54,6 +54,7 @@ fn bench_static(c: &mut Criterion) {
})
});
});

group.bench_function("single_threaded", |b| {
let filter = "static_filter=info"
.parse::<EnvFilter>()
Expand All @@ -67,6 +68,25 @@ fn bench_static(c: &mut Criterion) {
})
});
});

group.bench_function("single_threaded_reload", |b| {
let filter = "static_filter=info"
.parse::<EnvFilter>()
.expect("should parse");

let (reloadeable_filter, h) = reload::Subscriber::new(filter);
let collector = EnabledSubscriber.with(reloadeable_filter);
criterion::black_box(h);
tracing::collect::with_default(collector, || {
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::<EnvFilter>()
Expand All @@ -77,6 +97,21 @@ fn bench_static(c: &mut Criterion) {
})
});
});

group.bench_function("enabled_one_reload", |b| {
let filter = "static_filter=info"
.parse::<EnvFilter>()
.expect("should parse");
let (reloadeable_filter, h) = reload::Subscriber::new(filter);
let collector = EnabledSubscriber.with(reloadeable_filter);
criterion::black_box(h);

tracing::collect::with_default(collector, || {
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::<EnvFilter>()
Expand All @@ -87,6 +122,19 @@ fn bench_static(c: &mut Criterion) {
})
});
});
group.bench_function("enabled_many_reload", |b| {
let filter = "foo=debug,bar=trace,baz=error,quux=warn,static_filter=info"
.parse::<EnvFilter>()
.expect("should parse");
let (reloadeable_filter, h) = reload::Subscriber::new(filter);
let collector = EnabledSubscriber.with(reloadeable_filter);
criterion::black_box(h);
tracing::collect::with_default(collector, || {
b.iter(|| {
tracing::info!(target: "static_filter", "hi");
})
});
});
group.bench_function("disabled_level_one", |b| {
let filter = "static_filter=info"
.parse::<EnvFilter>()
Expand All @@ -97,6 +145,19 @@ fn bench_static(c: &mut Criterion) {
})
});
});
group.bench_function("disabled_level_one_reload", |b| {
let filter = "static_filter=info"
.parse::<EnvFilter>()
.expect("should parse");
let (reloadeable_filter, h) = reload::Subscriber::new(filter);
let collector = EnabledSubscriber.with(reloadeable_filter);
criterion::black_box(h);
tracing::collect::with_default(collector, || {
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::<EnvFilter>()
Expand All @@ -107,6 +168,19 @@ fn bench_static(c: &mut Criterion) {
})
});
});
group.bench_function("disabled_level_many_reload", |b| {
let filter = "foo=debug,bar=info,baz=error,quux=warn,static_filter=info"
.parse::<EnvFilter>()
.expect("should parse");
let (reloadeable_filter, h) = reload::Subscriber::new(filter);
let collector = EnabledSubscriber.with(reloadeable_filter);
criterion::black_box(h);
tracing::collect::with_default(collector, || {
b.iter(|| {
tracing::trace!(target: "static_filter", "hi");
})
});
});
group.bench_function("disabled_one", |b| {
let filter = "foo=info".parse::<EnvFilter>().expect("should parse");
tracing::collect::with_default(EnabledSubscriber.with(filter), || {
Expand All @@ -115,6 +189,17 @@ fn bench_static(c: &mut Criterion) {
})
});
});
group.bench_function("disabled_one_reload", |b| {
let filter = "foo=info".parse::<EnvFilter>().expect("should parse");
let (reloadeable_filter, h) = reload::Subscriber::new(filter);
let collector = EnabledSubscriber.with(reloadeable_filter);
criterion::black_box(h);
tracing::collect::with_default(collector, || {
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::<EnvFilter>()
Expand All @@ -125,6 +210,19 @@ fn bench_static(c: &mut Criterion) {
})
});
});
group.bench_function("disabled_many_reload", |b| {
let filter = "foo=debug,bar=trace,baz=error,quux=warn,whibble=info"
.parse::<EnvFilter>()
.expect("should parse");
let (reloadeable_filter, h) = reload::Subscriber::new(filter);
let collector = EnabledSubscriber.with(reloadeable_filter);
criterion::black_box(h);
tracing::collect::with_default(collector, || {
b.iter(|| {
tracing::info!(target: "static_filter", "hi");
})
});
});
group.bench_function("baseline_multithreaded", |b| {
let dispatch = Dispatch::new(EnabledSubscriber);
b.iter_custom(|iters| {
Expand Down Expand Up @@ -178,6 +276,39 @@ fn bench_static(c: &mut Criterion) {
total
});
});
group.bench_function("multithreaded_reload", |b| {
let filter = "static_filter=info"
.parse::<EnvFilter>()
.expect("should parse");

let (reloadeable_filter, h) = reload::Subscriber::new(filter);
let collector = EnabledSubscriber.with(reloadeable_filter);
criterion::black_box(h);

let dispatch = Dispatch::new(collector);
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();
}

Expand Down Expand Up @@ -213,6 +344,25 @@ fn bench_dynamic(c: &mut Criterion) {
})
});
});
group.bench_function("single_threaded_reload", |b| {
let filter = "[foo]=trace".parse::<EnvFilter>().expect("should parse");
let (reloadeable_filter, h) = reload::Subscriber::new(filter);
let collector = EnabledSubscriber.with(reloadeable_filter);
criterion::black_box(h);

tracing::collect::with_default(collector, || {
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| {
Expand Down Expand Up @@ -277,6 +427,42 @@ fn bench_dynamic(c: &mut Criterion) {
})
});

group.bench_function("multithreaded_reload", |b| {
let filter = "[foo]=trace".parse::<EnvFilter>().expect("should parse");
let (reloadeable_filter, h) = reload::Subscriber::new(filter);
let collector = EnabledSubscriber.with(reloadeable_filter);
criterion::black_box(h);
let dispatch = Dispatch::new(collector);
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();
}

Expand Down
4 changes: 2 additions & 2 deletions tracing-subscriber/src/subscribe.rs
Original file line number Diff line number Diff line change
Expand Up @@ -451,7 +451,7 @@ where
}
}

/// Composes this subscriber with the given collecto, returning a
/// Composes this subscriber with the given collector, returning a
/// `Layered` struct that implements [`Collect`].
///
/// The returned `Layered` subscriber will call the methods on this subscriber
Expand Down Expand Up @@ -517,7 +517,7 @@ where

/// Extension trait adding a `with(Subscriber)` combinator to `Collector`s.
pub trait CollectorExt: Collect + crate::sealed::Sealed {
/// Wraps `self` with the provided `layer`.
/// Wraps `self` with the provided `subscriber`.
fn with<S>(self, subscriber: S) -> Layered<S, Self>
where
S: Subscribe<Self>,
Expand Down
4 changes: 2 additions & 2 deletions tracing/src/collect.rs
Original file line number Diff line number Diff line change
Expand Up @@ -17,9 +17,9 @@ pub use tracing_core::dispatch::DefaultGuard;
/// [`Event`]: :../event/struct.Event.html
#[cfg(feature = "std")]
#[cfg_attr(docsrs, doc(cfg(feature = "std")))]
pub fn with_default<T, S>(collector: S, f: impl FnOnce() -> T) -> T
pub fn with_default<T, C>(collector: C, f: impl FnOnce() -> T) -> T
where
S: Collect + Send + Sync + 'static,
C: Collect + Send + Sync + 'static,
{
crate::dispatch::with_default(&crate::Dispatch::new(collector), f)
}
Expand Down