Markk116
a55f442315
Instrument the four suspect regions from bench/RPS: cache-lookup, cache-insert, sqlite-query, and gzip-decode, plus an asset-served progress point. New `ccc causal` subcommand runs the sweep against live traffic and prints a summary (optionally a .coz file and a ledger audit). Ran it under the same 80/20 hot-set workload as bench/RPS - see bench/CAUSAL.md for the methodology and results. Findings: - sqlite-query is the real bottleneck on a cache miss (+20.5% at a 50% speedup, roughly linear). - cache-lookup/cache-insert are noise-level (0-4%) - the O(n) recency-scan touch() bench/RPS flagged as a possible follow-up is not actually costing anything, so that's off the table. - Switched prepare() -> prepare_cached() on the query as the obvious fix; re-measured and it made no real difference (+20.0% -> +20.5%, within noise). Kept it anyway (strictly not worse), but it shows execution cost (B-tree lookup + BLOB copy) dominates over parse cost in that site. - gzip-decode barely gets exercised since real clients (and oha) negotiate gzip - not worth optimizing further. - Net conclusion: the existing CCC_CACHE_CAPACITY tuning from bench/RPS (+42-47% RPS) is the correct lever, and causal profiling explains why - every cache hit skips the one site that matters. Zero cost when the feature is off: causal_site!/progress! compile to no-ops without smarm-causal.
113 lines
5.3 KiB
Markdown
113 lines
5.3 KiB
Markdown
# 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<u8>`) 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.
|