mirror of
https://github.com/logos-messaging/logos-delivery.git
synced 2026-07-21 12:09:29 +00:00
2a4da679f2
Records the micro + macro baseline (Apple M4, macOS 26.5, refc, Nim 2.2.4) with both scenarios' verbatim output, CSV, per-node decode/hash breakdown, and the Phase 1 acceptance verdict. Validates the analysis: receiver decodes the same proto bytes 4x, aggregate 6 decodes / 5 hashes per relayed message; micro determinism 4.03% (<5%). Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
89 lines
4.7 KiB
Markdown
89 lines
4.7 KiB
Markdown
# 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** |
|