feat(runner): add structured logging with tracing

- Add tracing, tracing-subscriber, uuid dependencies
- Replace eprintln! with info! for structured logs
- Add run_id, rust_version, os, arch to benchmark start log
This commit is contained in:
2026-02-04 11:53:40 +02:00
parent 0da83f231b
commit 2972163055
5 changed files with 283 additions and 29 deletions

216
Cargo.lock generated
View File

@@ -17,6 +17,15 @@ version = "2.0.1"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "320119579fcad9c21884f5c4861d16174d0e06250625266f50fe6898340abefa"
[[package]]
name = "aho-corasick"
version = "1.1.4"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "ddd31a130427c27518df266943a5308ed92d4b226cc639f5a8f1002816174301"
dependencies = [
"memchr",
]
[[package]]
name = "anstream"
version = "0.6.21"
@@ -170,6 +179,12 @@ version = "2.10.0"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "812e12b5285cc515a9c72a5c1d3b6d46a19dac5acfef5265968c166106e31dd3"
[[package]]
name = "bumpalo"
version = "3.19.1"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "5dd9dc738b7a8311c7ade152424974d8115f2cdad61e8dab8dac9f2362298510"
[[package]]
name = "bytes"
version = "1.11.0"
@@ -398,6 +413,16 @@ dependencies = [
"libc",
]
[[package]]
name = "js-sys"
version = "0.3.85"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "8c942ebf8e95485ca0d52d97da7c5a2c387d0e7f0ba4c35e93bfcaee045955b3"
dependencies = [
"once_cell",
"wasm-bindgen",
]
[[package]]
name = "lazy_static"
version = "1.5.0"
@@ -425,6 +450,21 @@ dependencies = [
"scopeguard",
]
[[package]]
name = "log"
version = "0.4.29"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "5e5032e24019045c762d3c0f28f5b6b8bbf38563a65908389bf7978758920897"
[[package]]
name = "matchers"
version = "0.2.0"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "d1525a2a28c7f4fa0fc98bb91ae755d1e2d1505079e05539e35bc876b5d65ae9"
dependencies = [
"regex-automata",
]
[[package]]
name = "memchr"
version = "2.7.6"
@@ -497,6 +537,15 @@ dependencies = [
"minimal-lexical",
]
[[package]]
name = "nu-ansi-term"
version = "0.50.3"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "7957b9740744892f114936ab4a57b3f487491bbeafaf8083688b16841a4240e5"
dependencies = [
"windows-sys 0.61.2",
]
[[package]]
name = "num-bigint"
version = "0.4.6"
@@ -659,6 +708,23 @@ dependencies = [
"bitflags",
]
[[package]]
name = "regex-automata"
version = "0.4.13"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "5276caf25ac86c8d810222b3dbb938e512c55c6831a10f3e6ed1c93b84041f1c"
dependencies = [
"aho-corasick",
"memchr",
"regex-syntax",
]
[[package]]
name = "regex-syntax"
version = "0.8.8"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "7a2d987857b319362043e95f5353c0535c1f58eec5336fdfcf626430af7def58"
[[package]]
name = "ring"
version = "0.17.14"
@@ -683,6 +749,9 @@ dependencies = [
"rustls",
"tokio",
"tokio-rustls",
"tracing",
"tracing-subscriber",
"uuid",
]
[[package]]
@@ -748,6 +817,12 @@ dependencies = [
"untrusted",
]
[[package]]
name = "rustversion"
version = "1.0.22"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "b39cdef0fa800fc44525c84ccb54a029961a8215f9619753635a9c0d2538d46d"
[[package]]
name = "scopeguard"
version = "1.2.0"
@@ -809,6 +884,15 @@ dependencies = [
"tokio-rustls",
]
[[package]]
name = "sharded-slab"
version = "0.1.7"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "f40ca3c46823713e0d4209592e8d6e826aa57e928f09752619fc696c499637f6"
dependencies = [
"lazy_static",
]
[[package]]
name = "shlex"
version = "1.3.0"
@@ -957,6 +1041,15 @@ dependencies = [
"syn",
]
[[package]]
name = "thread_local"
version = "1.1.9"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "f60246a4944f24f6e018aa17cdeffb7818b76356965d03b07d6a9886e8962185"
dependencies = [
"cfg-if",
]
[[package]]
name = "time"
version = "0.3.46"
@@ -1026,6 +1119,67 @@ dependencies = [
"tokio",
]
[[package]]
name = "tracing"
version = "0.1.44"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "63e71662fa4b2a2c3a26f570f037eb95bb1f85397f3cd8076caed2f026a6d100"
dependencies = [
"pin-project-lite",
"tracing-attributes",
"tracing-core",
]
[[package]]
name = "tracing-attributes"
version = "0.1.31"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "7490cfa5ec963746568740651ac6781f701c9c5ea257c58e057f3ba8cf69e8da"
dependencies = [
"proc-macro2",
"quote",
"syn",
]
[[package]]
name = "tracing-core"
version = "0.1.36"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "db97caf9d906fbde555dd62fa95ddba9eecfd14cb388e4f491a66d74cd5fb79a"
dependencies = [
"once_cell",
"valuable",
]
[[package]]
name = "tracing-log"
version = "0.2.0"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "ee855f1f400bd0e5c02d150ae5de3840039a3f54b025156404e34c23c03f47c3"
dependencies = [
"log",
"once_cell",
"tracing-core",
]
[[package]]
name = "tracing-subscriber"
version = "0.3.22"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "2f30143827ddab0d256fd843b7a66d164e9f271cfa0dde49142c5ca0ca291f1e"
dependencies = [
"matchers",
"nu-ansi-term",
"once_cell",
"regex-automata",
"sharded-slab",
"smallvec",
"thread_local",
"tracing",
"tracing-core",
"tracing-log",
]
[[package]]
name = "unicode-ident"
version = "1.0.22"
@@ -1062,6 +1216,23 @@ version = "0.2.2"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "06abde3611657adf66d383f00b093d7faecc7fa57071cce2578660c9f1010821"
[[package]]
name = "uuid"
version = "1.20.0"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "ee48d38b119b0cd71fe4141b30f5ba9c7c5d9f4e7a3a8b4a674e4b6ef789976f"
dependencies = [
"getrandom 0.3.4",
"js-sys",
"wasm-bindgen",
]
[[package]]
name = "valuable"
version = "0.1.1"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "ba73ea9cf16a25df0c8caa16c51acb937d5712a8429db78a3ee29d5dcacd3a65"
[[package]]
name = "wasi"
version = "0.11.1+wasi-snapshot-preview1"
@@ -1077,6 +1248,51 @@ dependencies = [
"wit-bindgen",
]
[[package]]
name = "wasm-bindgen"
version = "0.2.108"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "64024a30ec1e37399cf85a7ffefebdb72205ca1c972291c51512360d90bd8566"
dependencies = [
"cfg-if",
"once_cell",
"rustversion",
"wasm-bindgen-macro",
"wasm-bindgen-shared",
]
[[package]]
name = "wasm-bindgen-macro"
version = "0.2.108"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "008b239d9c740232e71bd39e8ef6429d27097518b6b30bdf9086833bd5b6d608"
dependencies = [
"quote",
"wasm-bindgen-macro-support",
]
[[package]]
name = "wasm-bindgen-macro-support"
version = "0.2.108"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "5256bae2d58f54820e6490f9839c49780dff84c65aeab9e772f15d5f0e913a55"
dependencies = [
"bumpalo",
"proc-macro2",
"quote",
"syn",
"wasm-bindgen-shared",
]
[[package]]
name = "wasm-bindgen-shared"
version = "0.2.108"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "1f01b580c9ac74c8d8f0c0e4afb04eeef2acf145458e52c03845ee9cd23e3d12"
dependencies = [
"unicode-ident",
]
[[package]]
name = "windows-link"
version = "0.2.1"

View File

@@ -32,6 +32,9 @@ tokio = { version = "1", features = ["full"] }
tokio-rustls = { version = "0.26", default-features = false, features = [
"tls12",
] }
tracing = "0.1"
tracing-subscriber = { version = "0.3", features = ["env-filter", "fmt"] }
uuid = { version = "1", features = ["v4"] }
[workspace.lints.clippy]
nursery = "warn"

View File

@@ -11,6 +11,9 @@ miette.workspace = true
rustls.workspace = true
tokio-rustls.workspace = true
tokio.workspace = true
tracing.workspace = true
tracing-subscriber.workspace = true
uuid.workspace = true
[lints]
workspace = true

16
runner/build.rs Normal file
View File

@@ -0,0 +1,16 @@
use std::{env, process::Command};
fn main() {
let rustc_version = env::var("RUSTC_VERSION").unwrap_or_else(|_| {
Command::new("rustc")
.arg("--version")
.output()
.ok()
.and_then(|output| String::from_utf8(output.stdout).ok())
.unwrap_or_else(|| "unknown".to_string())
.trim()
.to_string()
});
println!("cargo:rustc-env=RUSTC_VERSION={rustc_version}");
}

View File

@@ -23,6 +23,8 @@ use rustls::{
version::TLS13,
};
use std::{
env,
fmt::Debug,
fs::File,
io::{BufWriter, Write, stdout},
net::SocketAddr,
@@ -32,6 +34,9 @@ use std::{
};
use tokio::{net::TcpStream, sync::Semaphore, task::JoinHandle};
use tokio_rustls::TlsConnector;
use tracing::info;
use tracing_subscriber::EnvFilter;
use uuid::Uuid;
/// TLS benchmark runner.
#[derive(Debug, Parser)]
@@ -165,15 +170,15 @@ async fn run_iteration(
let handshake_ns = start.elapsed().as_nanos() as u64;
// Send request
write_request(&mut tls_stream, u64::from(payload_bytes))
.await
.map_err(|e| miette!("write request failed: {e}"))?;
// Send request
write_request(&mut tls_stream, u64::from(payload_bytes))
.await
.map_err(|e| miette!("write request failed: {e}"))?;
// Read response
read_payload(&mut tls_stream, u64::from(payload_bytes))
.await
.map_err(|e| miette!("read payload failed: {e}"))?;
// Read response
read_payload(&mut tls_stream, u64::from(payload_bytes))
.await
.map_err(|e| miette!("read payload failed: {e}"))?;
let ttlb_ns = start.elapsed().as_nanos() as u64;
@@ -198,11 +203,12 @@ async fn run_benchmark(
None => Box::new(stdout()),
};
eprintln!(
"Running {} warmup + {} measured iterations (concurrency: {}, TLS 1.3)",
args.warmup, args.iters, args.concurrency
info!(
warmup = args.warmup,
iters = args.iters,
concurrency = args.concurrency,
"runnning benchmark iterations"
);
eprintln!();
for _ in 0..args.warmup {
run_iteration(
@@ -213,7 +219,7 @@ async fn run_benchmark(
)
.await?;
}
eprintln!("Warmup complete.");
info!("warmup complete");
#[allow(clippy::cast_possible_truncation)] // concurrency is limited to reasonable values
let semaphore = Arc::new(Semaphore::new(args.concurrency as usize));
@@ -225,7 +231,7 @@ async fn run_benchmark(
.flush()
.map_err(|e| miette!("failed to flush output: {e}"))?;
eprintln!("Benchmark complete.");
info!("benchmark complete");
Ok(())
}
@@ -256,7 +262,6 @@ fn spawn_benchmark_tasks(
.collect()
}
#[allow(clippy::too_many_arguments)]
fn spawn_single_iteration(
i: u32,
payload_bytes: u32,
@@ -303,22 +308,33 @@ async fn write_results(
#[tokio::main]
async fn main() -> miette::Result<()> {
let args = Args::parse();
let run_id = Uuid::new_v4();
tracing_subscriber::fmt()
.with_writer(std::io::stderr)
.with_env_filter(EnvFilter::from_default_env())
.with_target(false)
.init();
eprintln!("runner configuration:");
eprintln!(" mode: {}", args.mode);
eprintln!(" server: {}", args.server);
eprintln!(" payload_bytes: {}", args.payload_bytes);
eprintln!(" iters: {}", args.iters);
eprintln!(" warmup: {}", args.warmup);
eprintln!(" concurrency: {}", args.concurrency);
eprintln!(
" out: {}",
args.out
.as_ref()
.map_or_else(|| "stdout".to_string(), |p| p.display().to_string())
info!(
run_id=%run_id,
rust_version=env!("RUSTC_VERSION"),
on=env::consts::OS,
arch=env::consts::ARCH,
command=env::args().collect::<Vec<_>>().join(" "),
"benchmark started"
);
let args = Args::parse();
info!(
mode=%args.mode,
server=%args.server,
payload_bytes=%args.payload_bytes,
iters=%args.iters,
warmup=%args.warmup,
concurrency=%args.concurrency,
out=%args.out.as_ref().map_or("stdout", |p| p.to_str().unwrap_or("invalid")),
"runner configuration"
);
eprintln!();
// Build TLS config (skips certificate verification for benchmarking)
let tls_config = build_tls_config(args.mode)?;