From 46bc7960c19c1ced410ab12769082fdb5e4c1e50 Mon Sep 17 00:00:00 2001 From: Kristofers Solo Date: Wed, 4 Feb 2026 15:11:26 +0200 Subject: [PATCH] feat(server): add structured logging with tracing --- Cargo.lock | 3 +++ docs/TODO.md | 2 +- justfile | 5 +++- runner/src/main.rs | 18 ++++--------- server/Cargo.toml | 3 +++ server/build.rs | 16 +++++++++++ server/src/main.rs | 67 +++++++++++++++++++++++++--------------------- 7 files changed, 68 insertions(+), 46 deletions(-) create mode 100644 server/build.rs diff --git a/Cargo.lock b/Cargo.lock index a5b0a8c..3aec39c 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -882,6 +882,9 @@ dependencies = [ "rustls", "tokio", "tokio-rustls", + "tracing", + "tracing-subscriber", + "uuid", ] [[package]] diff --git a/docs/TODO.md b/docs/TODO.md index 8948c57..f5d1b09 100644 --- a/docs/TODO.md +++ b/docs/TODO.md @@ -29,7 +29,7 @@ ## Milestone 4 -- Concurrency & runner [MUST] - [x] tokio-based runner -- [ ] concurrency control and warmup +- [X] concurrency control and warmup - [ ] matrix runner over (mode, payload, concurrency) ## Milestone 5 -- HTTP/1.1 mode (hyper) \[OPTIONAL\] diff --git a/justfile b/justfile index 0630076..d41ee8b 100644 --- a/justfile +++ b/justfile @@ -1,7 +1,11 @@ +export RUSTC_WRAPPER := "sccache" +set shell := ["bash", "-cu"] + # Default recipe default: @just --list +alias c := check # Run all checks (fmt, clippy, docs, test) check: fmt clippy docs test @@ -47,7 +51,6 @@ runner server mode="x25519" payload="1024" iters="100" warmup="10": --iters {{iters}} \ --warmup {{warmup}} -alias c := clean # Clean build artifacts clean: cargo clean diff --git a/runner/src/main.rs b/runner/src/main.rs index 21e3f59..4c461bf 100644 --- a/runner/src/main.rs +++ b/runner/src/main.rs @@ -130,7 +130,6 @@ impl ServerCertVerifier for NoVerifier { /// Build TLS client config for the given key exchange mode. fn build_tls_config(mode: KeyExchangeMode) -> miette::Result> { - // Select crypto provider with appropriate key exchange groups let mut provider = aws_lc_rs::default_provider(); provider.kx_groups = match mode { KeyExchangeMode::X25519 => vec![X25519], @@ -157,12 +156,10 @@ async fn run_iteration( ) -> miette::Result { let start = Instant::now(); - // TCP connect let stream = TcpStream::connect(server) .await .map_err(|e| miette!("TCP connection failed: {e}"))?; - // TLS handshake let mut tls_stream = tls_connector .connect(server_name.clone(), stream) .await @@ -170,12 +167,10 @@ 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}"))?; - // Read response read_payload(&mut tls_stream, u64::from(payload_bytes)) .await .map_err(|e| miette!("read payload failed: {e}"))?; @@ -193,7 +188,6 @@ async fn run_benchmark( tls_connector: TlsConnector, server_name: ServerName<'static>, ) -> miette::Result<()> { - // Open output file or use stdout let mut output: Box = match &args.out { Some(path) => { let file = @@ -316,11 +310,11 @@ async fn main() -> miette::Result<()> { .init(); info!( - run_id=%run_id, - rust_version=env!("RUSTC_VERSION"), - on=env::consts::OS, - arch=env::consts::ARCH, - command=env::args().collect::>().join(" "), + run_id = %run_id, + rust_version = env!("RUSTC_VERSION"), + os = env::consts::OS, + arch = env::consts::ARCH, + command = env::args().collect::>().join(" "), "benchmark started" ); @@ -336,11 +330,9 @@ async fn main() -> miette::Result<()> { "runner configuration" ); - // Build TLS config (skips certificate verification for benchmarking) let tls_config = build_tls_config(args.mode)?; let tls_connector = TlsConnector::from(tls_config); - // Server name for TLS (use "localhost" for local testing) let server_name = ServerName::try_from("localhost".to_string()) .map_err(|e| miette!("invalid server name: {e}"))?; diff --git a/server/Cargo.toml b/server/Cargo.toml index 993fb12..64a6517 100644 --- a/server/Cargo.toml +++ b/server/Cargo.toml @@ -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 diff --git a/server/build.rs b/server/build.rs new file mode 100644 index 0000000..1218380 --- /dev/null +++ b/server/build.rs @@ -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}"); +} diff --git a/server/src/main.rs b/server/src/main.rs index 9741029..b8b9011 100644 --- a/server/src/main.rs +++ b/server/src/main.rs @@ -21,12 +21,14 @@ use rustls::{ server::Acceptor, version::TLS13, }; -use std::{fmt::Write, io::ErrorKind, net::SocketAddr, sync::Arc}; +use std::{env, fmt::Write, io::ErrorKind, net::SocketAddr, sync::Arc}; use tokio::{ io::AsyncWriteExt, net::{TcpListener, TcpStream}, }; use tokio_rustls::LazyConfigAcceptor; +use tracing::{debug, error, info, warn}; +use tracing_subscriber::EnvFilter; /// TLS benchmark server. #[derive(Debug, Parser)] @@ -46,21 +48,18 @@ fn build_tls_config( mode: KeyExchangeMode, server_cert: &ServerCertificate, ) -> miette::Result> { - // Select crypto provider with appropriate key exchange groups let mut provider = aws_lc_rs::default_provider(); provider.kx_groups = match mode { KeyExchangeMode::X25519 => vec![X25519], KeyExchangeMode::X25519Mlkem768 => vec![X25519MLKEM768], }; - // Convert certificate chain - let certs: Vec> = server_cert + let certs = server_cert .cert_chain_der .iter() .map(|der| CertificateDer::from(der.clone())) - .collect(); + .collect::>(); - // Convert private key let key = PrivateKeyDer::try_from(server_cert.private_key_der.clone()) .map_err(|e| miette!("invalid private key: {e}"))?; @@ -75,12 +74,11 @@ fn build_tls_config( } async fn handle_connection(stream: TcpStream, peer: SocketAddr, tls_config: Arc) { - // Perform TLS handshake let acceptor = LazyConfigAcceptor::new(Acceptor::default(), stream); let start_handshake = match acceptor.await { Ok(sh) => sh, Err(e) => { - eprintln!("[{peer}] TLS accept error: {e}"); + warn!(peer = %peer, error = %e, "TLS accept error"); return; } }; @@ -88,32 +86,32 @@ async fn handle_connection(stream: TcpStream, peer: SocketAddr, tls_config: Arc< let mut tls_stream = match start_handshake.into_stream(tls_config).await { Ok(s) => s, Err(e) => { - eprintln!("[{peer}] TLS handshake error: {e}"); + warn!(peer = %peer, error = %e, "TLS handshake error"); return; } }; - // Handle protocol loop { let payload_size = match read_request(&mut tls_stream).await { Ok(size) => size, Err(e) if e.kind() == ErrorKind::UnexpectedEof => { + debug!(peer = %peer, "client disconnected"); break; } Err(e) => { - eprintln!("[{peer}] read error: {e}"); + warn!(peer = %peer, error = %e, "connection error"); break; } }; if let Err(e) = write_payload(&mut tls_stream, payload_size).await { - eprintln!("[{peer}] write error: {e}"); + warn!(peer = %peer, error = %e, "write error"); break; } // Flush to ensure data is sent if let Err(e) = tls_stream.flush().await { - eprintln!("[{peer}] flush error: {e}"); + warn!(peer = %peer, error = %e, "flush error"); break; } } @@ -124,16 +122,13 @@ async fn run_server(args: Args, tls_config: Arc) -> miette::Result .await .map_err(|e| miette!("failed to bind to {}: {e}", args.listen))?; - eprintln!( - "Listening on {} (TLS 1.3, mode: {})", - args.listen, args.mode - ); + info!(listen = %args.listen, mode = %args.mode, "listening"); loop { let (stream, peer) = match listener.accept().await { Ok(conn) => conn, Err(e) => { - eprintln!("accept error: {e}"); + error!(error = %e, "accept error"); continue; } }; @@ -145,27 +140,38 @@ async fn run_server(args: Args, tls_config: Arc) -> miette::Result #[tokio::main] async fn main() -> miette::Result<()> { + tracing_subscriber::fmt() + .with_env_filter(EnvFilter::from_default_env()) + .with_target(false) + .init(); + let args = Args::parse(); - eprintln!("server configuration:"); - eprintln!(" mode: {}", args.mode); - eprintln!(" listen: {}", args.listen); - eprintln!(); + info!( + rust_version = env!("RUSTC_VERSION"), + os = env::consts::OS, + arch = env::consts::ARCH, + command = env::args().collect::>().join(" "), + listen = %args.listen, + mode = %args.mode, + "server started" + ); - // Generate certificates - eprintln!("Generating self-signed certificates..."); + info!("Generating self-signed certificates..."); let ca = CaCertificate::generate().map_err(|e| miette!("failed to generate CA: {e}"))?; let server_cert = ca .sign_server_cert("localhost") .map_err(|e| miette!("failed to generate server cert: {e}"))?; - // Build TLS config let tls_config = build_tls_config(args.mode, &server_cert)?; - // Print CA certificate for client configuration - eprintln!("CA certificate (base64 DER):"); - eprintln!("{}", base64_encode(&ca.cert_der)); - eprintln!(); + info!( + ca_cert_base64 = base64_encode(&ca.cert_der) + .lines() + .take(3) + .collect::(), + "CA cert (truncated)" + ); run_server(args, tls_config).await } @@ -176,7 +182,7 @@ fn base64_encode(data: &[u8]) -> String { let mut result = String::new(); for chunk in data.chunks(3) { - let mut n = 0u32; + let mut n = 0; for (i, &byte) in chunk.iter().enumerate() { n |= u32::from(byte) << (16 - 8 * i); } @@ -191,7 +197,6 @@ fn base64_encode(data: &[u8]) -> String { } } - // Wrap at 76 characters let mut wrapped = String::new(); for (i, c) in result.chars().enumerate() { if i > 0 && i % 76 == 0 {