diff --git a/docs/analysis/bench_baseline.md b/docs/analysis/bench_baseline.md new file mode 100644 index 000000000..c1b3b7704 --- /dev/null +++ b/docs/analysis/bench_baseline.md @@ -0,0 +1,88 @@ +# Message-path benchmark — Phase 1 baseline + +Baseline capture on the **current branch before Phases 2/3**, produced by +`apps/benchmarks/message_path_bench.nim` (see +[plan_phase1_bench.md](plan_phase1_bench.md)). Re-run after each phase and diff +against these numbers. + +## Environment + +| Item | Value | +|---|---| +| Commit (harness) | `cf8502eb4975ae6bc8a5667a5d179cd154e8e1d1` | +| Branch | `experimental/chore-nocopy-e2e-perf-harness` | +| Machine | Apple M4 | +| OS | macOS 26.5 (arm64) | +| Nim | 2.2.4, `--mm:refc` | +| Build | `-d:msgPathCounters -d:chronicles_log_level=ERROR`, `--passL:librln_v2.0.2.a` | +| Run | `nimble benchMessagePath` (or `./build/message_path_bench`) | +| Workload | seed 42, payload mix 10/50/150 kB @ 25/50/25 %, N=1000 + 100 warmup | + +## Results (CSV) + +``` +scenario,msgs,payload_profile,wall_ms,msg_per_s,ns_per_msg_p50,ns_per_msg_p99,decodes_per_msg,hashes_per_msg,hashed_MB,decoded_MB,occupied_mem_delta_MB,gc_collections +micro_run1,1000,10/50/150kB@25/50/25,828.591,1206.9,641375,1925042,2.000,2.000,130.00,130.11,1.54,7 +micro_run2,1000,10/50/150kB@25/50/25,795.166,1257.6,619167,1810625,2.000,2.000,130.00,130.11,1.51,8 +macro,1000,10/50/150kB@25/50/25,4367.314,229.0,3510750,10701375,6.000,5.000,325.00,390.33,141.58,10 +``` + +| Scenario | msg/s | decodes/msg | hashes/msg | decoded_MB | hashed_MB | occ_mem_delta_MB | +|---|---|---|---|---|---|---| +| micro run1 | 1206.9 | 2.000 | 2.000 | 130.11 | 130.00 | 1.54 | +| micro run2 | 1257.6 | 2.000 | 2.000 | 130.11 | 130.00 | 1.51 | +| macro | 229.0 | 6.000 | 5.000 | 390.33 | 325.00 | 141.58 | + +Micro determinism: run1=1206.9 msg/s, run2=1257.6 msg/s → **variance 4.03 %** +(< 5 % target; two earlier back-to-back runs were 1.90 % and 3.12 %). The +decode/hash *counts* are byte-exact reproducible across every run. + +## Interpretation vs. the analysis + +**Decode / hash counts validate [async_copy_analysis.md](async_copy_analysis.md).** + +The counter is a single process-global (both in-process nodes share it), so the +macro per-message numbers are the aggregate of publisher (node A) + receiver +(node B). Breakdown of the macro **6 decodes / 5 hashes** per message: + +| Counter | Node A (publish) | Node B (receive) | Total | +|---|---|---|---| +| `WakuMessage.decode` | 1 (`onSend` observer) | 4 (ordered validator, `onRecv`, `onValidated`, subscribe topicHandler) | **6** | +| `computeMessageHash` | 2 (`publish` :686, `onSend`→`logMessageInfo`) | 3 (`onValidated`→`logMessageInfo`, archive, store-sync) | **5** | + +- The **inbound-decode claim (≥4 decodes on a relayed message)** is confirmed: + node B alone decodes the same proto bytes **4×** + (`waku_relay/protocol.nim` validator :543, `onRecv` :271, `onValidated` :326, + topicHandler :603). +- The micro scenario isolates the non-observer path and shows the **2 decodes / + 2 hashes** it exercises (validator + topicHandler decode; archive + store-sync + hash) — the observers only fire under real libp2p dispatch, which the macro + scenario adds. + +### Caveats + +1. **Log level elides some hash sites.** Built at `chronicles_log_level=ERROR`, + `computeMessageHash` calls that appear *only* as disabled log arguments are + not evaluated (chronicles skips disabled-sink args) — notably the + `node.publish` `notice` at `waku_node/relay.nim:148`. Sites bound to a `let` + (archive :101, store-sync :78, `logMessageInfo` :217, `publish` :686) run + regardless of level and are the ones counted here. +2. **Filter not mounted.** Per the plan, node B has archive + store-sync but not + filter. The analysis's "4–6 hashes" upper end assumes an active filter + (`waku_filter_v2` adds ~2 more receiver-side `computeMessageHash` passes, + :195 + :246). With filter mounted the receiver-side hash count would rise + from 3 toward the analysis's upper bound. +3. **`occupied_mem_delta`** is a coarse `getOccupiedMem()` before/after delta on + the refc heap, not a per-message allocation trace; use it for order-of- + magnitude trend, not exact bytes. `decoded_MB` / `hashed_MB` (exact byte + totals fed to decode/hash) are the reliable volume metrics. + +## Acceptance gate (Phase 1) + +| # | Criterion | Verdict | +|---|---|---| +| 1 | Representative tests green (production untouched except no-op templates) | **PASS** — `tests/waku_core/test_message_digest` 5/5, `tests/waku_relay/test_protocol` 20/20 | +| 2 | Production build without `-d:msgPathCounters` compiles (templates vanish) | **PASS** — `nim check apps/wakunode2` clean; relay test built without the define | +| 3 | Two consecutive micro runs < 5 % msg/s variance | **PASS** — 4.03 % (and 1.90 % / 3.12 % on earlier runs) | +| 4 | Macro `decodes_per_msg ≥ 4` and `hashes_per_msg` in 4–6 | **PASS** — decodes 6.0, hashes 5.0 (process aggregate; receiver-side decodes = 4) | +| 5 | This baseline doc committed | **PASS** |