302d4a92df
## Motivation The docs state that using the `reload` module inflicts a performance penalty but there was no further data about how big the penalty is. This PR adds `_reload` variants to the filter benchmarks. Results are a bit inconclusive but the tl;dr is "yes, there is a performance impact and yes, in some cases it's significant. Generally the more complex the collector the less it matters.". The benchmarks after this PR are a bit noisy; happy to rework this but wasn't sure what the preferred way was. There's already a fair bit of duplication in the benchmarks but this PR isn't helping with that.
308 lines
13 KiB
Rust
308 lines
13 KiB
Rust
use criterion::{criterion_group, criterion_main, BenchmarkId, Criterion, Throughput};
|
|
use std::time::Duration;
|
|
|
|
mod support;
|
|
use support::{MultithreadedBench, NoWriter};
|
|
|
|
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::dispatch::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 collector = tracing_subscriber::fmt::Collector::builder()
|
|
.with_writer(NoWriter::new)
|
|
.finish();
|
|
tracing::Dispatch::new(collector)
|
|
}
|
|
|
|
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::dispatch::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::dispatch::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::dispatch::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::dispatch::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);
|