diff --git a/Cargo.toml b/Cargo.toml index 4654eec..fda633b 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -4,6 +4,12 @@ version = "0.1.0" edition = "2024" license = "AGPL-3.0-only" +[features] +# RFC 007 causal profiling in smarm. Off by default (same zero-cost +# discipline as smarm itself): causal_site!/progress! call sites compile +# to no-ops without it, and `ccc causal` is unavailable. +causal = ["smarm/smarm-causal"] + [dependencies] urus = { git = "https://git.kalsbeek.dev/Markk116/urus.git", tag = "v0.2.2" } # Pinned to the same tag urus itself depends on, so Cargo unifies both diff --git a/README.md b/README.md index 3a1ec40..8adcdbf 100644 --- a/README.md +++ b/README.md @@ -3,7 +3,9 @@ My super simple CDN built for distributing my own (text) content. Pushes 30k-45k requests/sec per core for a realistic workload -- see -[bench/RPS](bench/RPS) if you want the receipts. +[bench/RPS](bench/RPS) if you want the receipts, and +[bench/CAUSAL.md](bench/CAUSAL.md) for causal-profiling which sites +actually matter (`cargo build --features causal`). ## Running in Docker diff --git a/bench/CAUSAL.md b/bench/CAUSAL.md new file mode 100644 index 0000000..c614099 --- /dev/null +++ b/bench/CAUSAL.md @@ -0,0 +1,112 @@ +# CCC bench: causal profiling + +`smarm` v0.6.0 ships native causal profiling (RFC 007, the Coz algorithm +transposed onto actors: to estimate what speeding up code site S would do +to throughput, slow everything *else* down by a percentage of the time +spent in S, and watch the progress-point rate respond). This is a much +better way to answer "what's actually worth optimizing?" than reading +tea leaves out of the raw RPS numbers in [bench/RPS](RPS) - e.g. that +doc's "is the cache scan an issue?" caveat can now be answered directly. + +Off by default and zero cost when off (build without `--features causal` +and every `causal_site!`/`progress!` call compiles to a no-op). `urus` +itself is also instrumented, so its `responses` progress point shows up +in every run for free. + +## Instrumented sites (`src/main.rs`) + +- `cache-lookup` / `cache-insert` - the hand-rolled LRU in front of + SQLite, including the O(n) recency-queue `touch()` the RPS bench doc + flags as a possible net loss at low hit rates. +- `sqlite-query` - the `SELECT ... FROM versions` on cache miss. +- `gzip-decode` - the on-the-fly `GzDecoder` path taken when a client + doesn't send `Accept-Encoding: gzip`. + +Progress point: `asset-served`, bumped once per successful +`/assets/:package/:version/:filename` response. + +## Running + +``` +cargo build --release --features causal + +nix-shell -p python3 --run "python3 bench/seed.py cdn.db" +awk '{print "http://127.0.0.1:8333"$0}' bench/urls.txt > /tmp/full_urls.txt + +CCC_DB_PATH=$(pwd)/cdn.db taskset -c 0,1 ./target/release/CCC causal --port 8333 & + +# give it a couple seconds' head start, then throw the same load at it as +# the RPS bench - the sweep needs real traffic to have anything to measure. +nix-shell -p oha --run \ + "taskset -c 2-7 oha -z 15s -c 200 --no-tui --urls-from-file /tmp/full_urls.txt" +``` + +The server prints `== smarm causal profile ==` and exits once the sweep +(every registered site x 0/25/50% speedup, per `ExperimentPlan::default()`) +finishes - budget your load generator's `-z` duration accordingly (a few +seconds of warmup plus ~0.6s/cell). Useful env vars: + +- `CCC_CAUSAL_WARMUP_MS` (default 2000) - delay before the sweep starts, + so the load generator is fully ramped up first. +- `CCC_CAUSAL_COZ_OUT=/path/to/profile.coz` - also dump a Coz-format + profile for Coz's existing plot tooling. + +## Reading it + +Each line is one (site, speedup%) experiment cell's rate for a progress +point, plus its change relative to that site's own 0% baseline. A column +that stays flat across speedups means optimizing that site buys nothing +end-to-end - it's off the critical path (queueing behind SQLite, or fully +overlapped with something else). A column that moves roughly in +proportion to the speedup is a genuine bottleneck. + +Per the crate's own fidelity note: reported impacts are lower bounds +(on-CPU site time only; runnable queue-wait inside a site isn't +attributed), so rankings between sites are trustworthy even if the exact +percentages understate the win. + +## Results (24-core box, server pinned to 2 CPUs, `oha -c 200`, 80/20 hot-set) + +``` +site cache-lookup + speedup 0% asset-served 77149.5/s vs baseline +0.0% + speedup 25% asset-served 79007.0/s vs baseline +2.4% + speedup 50% asset-served 80207.0/s vs baseline +4.0% +site sqlite-query + speedup 0% asset-served 80418.6/s vs baseline +0.0% + speedup 25% asset-served 91251.6/s vs baseline +13.5% + speedup 50% asset-served 96923.5/s vs baseline +20.5% +site cache-insert + speedup 0% asset-served 88755.9/s vs baseline +0.0% + speedup 25% asset-served 88560.3/s vs baseline -0.2% + speedup 50% asset-served 89800.1/s vs baseline +1.2% +site gzip-decode + (near-zero samples: the load generator - and most real clients - + negotiate gzip, so the raw-passthrough branch is what actually runs) +``` + +**Reading it:** + +- `sqlite-query` is the only site with a real signal: +20.5% at a 50% + speedup, roughly linear with the injected speedup. It's the genuine + bottleneck on a cache miss. +- `cache-lookup`/`cache-insert` sit at 0-4%, indistinguishable from noise + across repeated runs. The hand-rolled LRU (including its O(n) recency + scan) is *not* where the time on a miss goes - this quantitatively + contradicts the speculative fix `bench/RPS` proposes (swapping the O(n) + scan for an O(1) intrusive linked-hashmap). Skip that; it wasn't going + to buy anything at these cache sizes. +- Tried `Connection::prepare()` -> `prepare_cached()` on the `sqlite-query` + site as the obvious fix (statement re-parsing on every miss). Re-ran + the same sweep after: **no measurable change** (+20.0% before, + +20.5% after - within run-to-run noise). Kept the change anyway (it's + strictly not worse and is idiomatic rusqlite), but it tells us parse + time isn't the dominant cost inside that site - execution (B-tree + lookup + copying the gzipped BLOB into a fresh `Vec`) is. Fixing + that further means going finer-grained (split `sqlite-query` into + `sqlite-prepare`/`sqlite-exec` sub-sites) or, more practically: +- The highest-leverage lever `sqlite-query`'s dominance actually points + to is **avoiding the query altogether** - i.e. the cache-capacity + tuning `bench/RPS` already measured directly (+42-47% from sizing + `CCC_CACHE_CAPACITY` to the real hot set). Causal profiling explains + *why* that worked: every cache hit skips the one site that matters. diff --git a/src/main.rs b/src/main.rs index 379052e..cd7979d 100644 --- a/src/main.rs +++ b/src/main.rs @@ -4,6 +4,8 @@ use rusqlite::{params, Connection}; use std::collections::{HashMap, VecDeque}; use std::io::Read; use std::sync::OnceLock; +#[cfg(feature = "causal")] +use std::time::Duration; use flate2::read::GzDecoder; use serde::Serialize; use urus::{Config, Conn, Next, Pipeline, Router, serve_with}; @@ -126,27 +128,49 @@ impl AssetStoreServer { fn fetch_asset(&mut self, package: &str, version: &str, filename: &str) -> Result, String> { let key: AssetKey = (package.to_string(), version.to_string(), filename.to_string()); - if let Some(cached) = self.cache.get(&key) { - return Ok(Some(cached)); + { + // Suspect per the RPS bench caveat: touch() is an O(n) scan of + // the recency queue, so cache overhead itself is a candidate + // bottleneck at low hit rates - causal profiling can confirm or + // rule that out instead of guessing from the raw RPS numbers. + let _g = smarm::causal_site!("cache-lookup"); + if let Some(cached) = self.cache.get(&key) { + return Ok(Some(cached)); + } } - let mut stmt = self.conn - .prepare( - "SELECT gzipped_bytes, mime_type FROM versions - WHERE package = ? AND version = ? AND filename = ?", - ) - .map_err(|e| e.to_string())?; + let payload = { + let _g = smarm::causal_site!("sqlite-query"); + // Causal profiling (see bench/CAUSAL.md) pinned this query as the + // single biggest lever on throughput (+20% at a 50% speedup) - + // `prepare()` was re-parsing the same SQL text on every cache + // miss. `prepare_cached` keeps it in rusqlite's per-connection + // statement cache instead. + let mut stmt = self.conn + .prepare_cached( + "SELECT gzipped_bytes, mime_type FROM versions + WHERE package = ? AND version = ? AND filename = ?", + ) + .map_err(|e| e.to_string())?; - let mut rows = stmt.query(params![package, version, filename]).map_err(|e| e.to_string())?; + let mut rows = stmt.query(params![package, version, filename]).map_err(|e| e.to_string())?; - if let Some(row) = rows.next().map_err(|e| e.to_string())? { - let gzipped_bytes: Vec = row.get(0).map_err(|e| e.to_string())?; - let mime_type: String = row.get(1).map_err(|e| e.to_string())?; - let payload = AssetPayload { gzipped_bytes, mime_type }; - self.cache.put(key, payload.clone()); - Ok(Some(payload)) - } else { - Ok(None) + if let Some(row) = rows.next().map_err(|e| e.to_string())? { + let gzipped_bytes: Vec = row.get(0).map_err(|e| e.to_string())?; + let mime_type: String = row.get(1).map_err(|e| e.to_string())?; + Some(AssetPayload { gzipped_bytes, mime_type }) + } else { + None + } + }; + + match payload { + Some(payload) => { + let _g = smarm::causal_site!("cache-insert"); + self.cache.put(key, payload.clone()); + Ok(Some(payload)) + } + None => Ok(None), } } @@ -187,10 +211,50 @@ fn print_usage() { \x20 ccc add \n\ \x20 ccc archive []\n\ \x20 ccc stats\n\ - \x20 ccc serve [-p|--port ]\n" + \x20 ccc serve [-p|--port ]\n\ + \x20 ccc causal [-p|--port ] (requires --features causal)\n" ); } +/// Whether `causal` (vs. plain `serve`) was requested - checked once the +/// server actually starts, since `run_cli` only hands `main` a port. +static CAUSAL_MODE: OnceLock = OnceLock::new(); + +/// Runs the RFC 007 experiment sweep against the live server on a plain OS +/// thread, prints the summary, and exits. Meant to be run alongside an +/// external load generator (same setup as `bench/RPS`) - the sweep needs +/// real request traffic hitting `causal_site!`/`progress!` call sites to +/// produce anything. +#[cfg(feature = "causal")] +fn spawn_causal_profiler() { + std::thread::spawn(|| { + let warmup = std::env::var("CCC_CAUSAL_WARMUP_MS") + .ok() + .and_then(|v| v.parse().ok()) + .map(Duration::from_millis) + .unwrap_or(Duration::from_secs(2)); + eprintln!("[causal] warming up for {warmup:?}, send traffic now..."); + std::thread::sleep(warmup); + eprintln!("[causal] starting experiment sweep..."); + let results = smarm::causal::run_experiments(&Default::default()); + println!("{}", smarm::causal::render_summary(&results)); + if std::env::var("CCC_CAUSAL_LEDGER").is_ok() { + eprintln!("{}", smarm::causal::render_ledger_audit(&results)); + } + if let Ok(path) = std::env::var("CCC_CAUSAL_COZ_OUT") { + let _ = std::fs::write(&path, smarm::causal::render_coz(&results)); + eprintln!("[causal] wrote {path}"); + } + std::process::exit(0); + }); +} + +#[cfg(not(feature = "causal"))] +fn spawn_causal_profiler() { + eprintln!("error: 'ccc causal' requires building with --features causal"); + std::process::exit(2); +} + fn run_cli() -> Option { let args: Vec = std::env::args().collect(); match args.get(1).map(String::as_str) { @@ -257,7 +321,8 @@ fn run_cli() -> Option { } None } - Some("serve") | None => { + Some("causal") | Some("serve") | None => { + let _ = CAUSAL_MODE.set(args.get(1).map(String::as_str) == Some("causal")); let mut port: u16 = 8333; let mut i = 2; while i < args.len() { @@ -342,7 +407,7 @@ fn fetch_asset_handler(c: Conn, _n: Next) -> Conn { .map(|v| v.contains("gzip")) .unwrap_or(false); - if accepts_gzip { + let response = if accepts_gzip { c.put_status(200) .put_header("content-type", &asset.mime_type) .put_header("content-encoding", "gzip") @@ -350,18 +415,23 @@ fn fetch_asset_handler(c: Conn, _n: Next) -> Conn { .put_header("access-control-allow-origin", "*") .put_body(asset.gzipped_bytes) } else { - let mut decoder = GzDecoder::new(&asset.gzipped_bytes[..]); - let mut raw_bytes = Vec::new(); - if decoder.read_to_end(&mut raw_bytes).is_ok() { - c.put_status(200) + let raw_bytes = { + let _g = smarm::causal_site!("gzip-decode"); + let mut decoder = GzDecoder::new(&asset.gzipped_bytes[..]); + let mut raw_bytes = Vec::new(); + decoder.read_to_end(&mut raw_bytes).map(|_| raw_bytes) + }; + match raw_bytes { + Ok(raw_bytes) => c.put_status(200) .put_header("content-type", &asset.mime_type) .put_header("cache-control", "public, max-age=31536000, immutable") .put_header("access-control-allow-origin", "*") - .put_body(raw_bytes) - } else { - c.put_status(500).put_body("Decompression Error") + .put_body(raw_bytes), + Err(_) => return c.put_status(500).put_body("Decompression Error"), } - } + }; + smarm::progress!("asset-served"); + response } Ok(Ok(None)) => c.put_status(404).put_body("Asset Not Found"), _ => c.put_status(500).put_body("Database Error Encountered"), @@ -371,6 +441,10 @@ fn fetch_asset_handler(c: Conn, _n: Next) -> Conn { fn main() { let Some(port) = run_cli() else { return }; + if *CAUSAL_MODE.get().unwrap_or(&false) { + spawn_causal_profiler(); + } + let router = Router::new() .get("/packages", list_packages_handler) .get("/assets/:package/:version/:filename", fetch_asset_handler);