Skip to content

Commit

Permalink
Benchmark common tracing operations (spans, events)
Browse files Browse the repository at this point in the history
As documented in the `Tracy` manual, unsurprisingly, gathering stack
frames takes a long time. These changes effectively just add some
benchmarks to demonstrate that, as well as the overhead of the
tracing-tracy implementation.
  • Loading branch information
nagisa committed Jun 11, 2022
1 parent 54ebfa9 commit a4cb0d1
Show file tree
Hide file tree
Showing 6 changed files with 121 additions and 25 deletions.
2 changes: 2 additions & 0 deletions tracing-tracy/Cargo.toml
Original file line number Diff line number Diff line change
Expand Up @@ -14,6 +14,7 @@ Inspect tracing-enabled Rust applications with Tracy

[lib]
harness = false
bench = true

[dependencies]
tracing-core = { version = "0.1", default-features = false, features = ["std"] }
Expand All @@ -26,6 +27,7 @@ tokio = { version = "1", features = ["full"] }
tracing-attributes = { version = "0.1"}
tracing-futures = { version = "0.2" }
futures = "0.3"
criterion = "0.3"

[features]
# Refer to `tracy-client-sys` for documentation on features.
Expand Down
6 changes: 5 additions & 1 deletion tracing-tracy/src/lib.rs
Original file line number Diff line number Diff line change
Expand Up @@ -279,5 +279,9 @@ impl Visit for TracyEventFieldVisitor {
mod tests;
#[cfg(test)]
fn main() {
tests::main();
if std::env::args_os().any(|p| p == std::ffi::OsStr::new("--bench")) {
tests::bench();
} else {
tests::test();
}
}
53 changes: 52 additions & 1 deletion tracing-tracy/src/tests.rs
Original file line number Diff line number Diff line change
@@ -1,3 +1,4 @@
use criterion::Criterion;
use futures::future::join_all;
use tracing::{debug, event, info, info_span, span, Level};
use tracing_attributes::instrument;
Expand Down Expand Up @@ -98,7 +99,7 @@ fn span_with_fields() {
let _enter = span.enter();
}

pub(crate) fn main() {
pub(crate) fn test() {
tracing::subscriber::set_global_default(
tracing_subscriber::registry().with(super::TracyLayer::new()),
)
Expand All @@ -117,3 +118,53 @@ pub(crate) fn main() {
.expect("tokio runtime");
runtime.block_on(async_futures());
}

fn benchmark_span(c: &mut Criterion) {
c.bench_function("span/callstack", |bencher| {
let layer =
tracing_subscriber::registry().with(super::TracyLayer::new().with_stackdepth(100));
tracing::subscriber::with_default(layer, || {
bencher.iter(|| {
let _span = tracing::error_span!("message").entered();
});
})
});

c.bench_function("span/no_callstack", |bencher| {
let layer =
tracing_subscriber::registry().with(super::TracyLayer::new().with_stackdepth(0));
tracing::subscriber::with_default(layer, || {
bencher.iter(|| {
let _span = tracing::error_span!("message").entered();
});
})
});
}

fn benchmark_message(c: &mut Criterion) {
c.bench_function("event/callstack", |bencher| {
let layer =
tracing_subscriber::registry().with(super::TracyLayer::new().with_stackdepth(100));
tracing::subscriber::with_default(layer, || {
bencher.iter(|| {
tracing::error!("message");
});
})
});

c.bench_function("event/no_callstack", |bencher| {
let layer =
tracing_subscriber::registry().with(super::TracyLayer::new().with_stackdepth(0));
tracing::subscriber::with_default(layer, || {
bencher.iter(|| {
tracing::error!("message");
});
})
});
}

pub(crate) fn bench() {
criterion::criterion_group!(benches, benchmark_span, benchmark_message);
benches();
Criterion::default().configure_from_args().final_summary();
}
4 changes: 2 additions & 2 deletions tracy-client/Cargo.toml
Original file line number Diff line number Diff line change
Expand Up @@ -23,8 +23,8 @@ path = "tests/loom.rs"
harness = false

[[bench]]
name = "state"
path = "benches/state.rs"
name = "client"
path = "benches/client.rs"
harness = false

[dev-dependencies]
Expand Down
60 changes: 60 additions & 0 deletions tracy-client/benches/client.rs
Original file line number Diff line number Diff line change
@@ -0,0 +1,60 @@
use criterion::{criterion_group, criterion_main, Criterion};
use tracy_client::Client;

fn client_start(c: &mut Criterion) {
let mut clients = Vec::<Client>::with_capacity(1_000_000_000);
c.bench_function("start", |b| b.iter(|| clients.push(Client::start())));
}

fn client_clone(c: &mut Criterion) {
let mut clients = Vec::<Client>::with_capacity(1_000_000_000);
let client = Client::start();
c.bench_function("clone", |b| b.iter(|| clients.push(client.clone())));
}

fn client_running(c: &mut Criterion) {
let _client = Client::start();
c.bench_function("running", |b| b.iter(|| Client::running()));
}

fn ops_alloc(c: &mut Criterion) {
let _client = tracy_client::Client::start();
c.bench_function("span_alloc_callstack/0", |bencher| {
bencher.iter(|| {
Client::running()
.unwrap()
.span_alloc("hello", "function", "file", 42, 0);
});
});
c.bench_function("span_alloc_callstack/100", |bencher| {
bencher.iter(|| {
Client::running()
.unwrap()
.span_alloc("hello", "function", "file", 42, 100);
});
});
}

fn ops_static(c: &mut Criterion) {
let client = tracy_client::Client::start();
c.bench_function("span_callstack/0", |bencher| {
bencher.iter(|| {
tracy_client::span!("some_name", 0);
});
});
c.bench_function("span_callstack/100", |bencher| {
bencher.iter(|| {
tracy_client::span!("some_name", 100);
});
});
}

criterion_group!(
benches,
client_start,
client_clone,
client_running,
ops_alloc,
ops_static
);
criterion_main!(benches);
21 changes: 0 additions & 21 deletions tracy-client/benches/state.rs

This file was deleted.

0 comments on commit a4cb0d1

Please sign in to comment.