testing and documentation

This commit is contained in:
Jason Stedwell
2026-06-23 17:17:00 -05:00
parent c2da2d261c
commit e89f4660f6
28 changed files with 4045 additions and 19 deletions
Vendored
BIN
View File
Binary file not shown.
@@ -0,0 +1,146 @@
# ECHO Performance Test Suite — Plan
**Status:** plan only — nothing here is to be run yet.
**Author:** drafted for Jason Stedwell, 2026-06-23.
**Targets the changes that landed in:** 1.1.0 (connection pooling + concurrent `read_many` + shared cache) and 1.2.0 (fuzzy `resolve`, alias derivation/learning, `capture` re-slug fix).
**Scope:** a *performance / timing* harness. It complements — does not replace — the existing correctness tests (`test_echo_client.py`, `test_v1_scaffold.py`, the eval feature tests), which stay as the pass/fail gate for behaviour.
---
## 1. Goals
1. Put hard numbers on the three operations Jason called out — full endpoint read, full subject pulls, bulk get/put/append — so the 1.1.0 perf claims ("lint 0.90s / sweep 0.85s on 186 notes, ~4.5× from reuse, ~2× from concurrency") become a repeatable, checked-in measurement instead of a one-time observation.
2. Establish **baselines + regression gates** so a future change that quietly reintroduces the pre-1.1.0 per-request TLS handshake (the bug that was timing out sessions) fails the suite instead of silently shipping.
3. Keep every run **non-destructive to the production vault** — writes go to a disposable namespace and are cleaned up (per Jason's "prune test artifacts" rule).
## 2. Methodology (applies to every metric)
- **Harness:** a new `bench.py` under `scripts/` (or `eval/perf/`), reusing the live `echo` client module so it measures the real pooled/concurrent code path, not a reimplementation.
- **Timing:** `time.perf_counter()` around each operation. Report **min / median / p90 / p95 / max / mean** over N iterations — not a single number. Single timings hide GC pauses and TLS renegotiation.
- **Warm-up:** discard the first 12 iterations (cold connection pool, cold server cache) and report them *separately* as the cold-start cost — that delta is itself one of the most interesting numbers (it's what 1.1.0's keep-alive was meant to kill).
- **Iterations:** default N=10 for read-heavy metrics, N=5 for write-heavy (writes are slower and we don't want to bloat the vault). Make N a CLI flag.
- **Environment capture:** record `ECHO_WORKERS`, `ECHO_TIMEOUT`, vault note count, git commit/plugin version, and wall-clock date in the results header so two runs are comparable.
- **Output:** machine-readable JSON (`eval/perf/results/<date>-<commit>.json`) plus a short human table to stdout. JSON lets us diff runs over time and chart trend.
- **Isolation:** all test writes live under a dedicated prefix, e.g. `_agent/_bench/<run-id>/...`, never in `projects/`, `resources/`, `inbox/`, or `journal/`. A `--cleanup` pass deletes the whole prefix at the end; a `--keep` flag preserves it for debugging. The advisory lock (`echo.py lock`) is taken for the write phases so a bench run can't race a real CoWork session.
- **Network honesty:** the endpoint is the live `echoapi.alwisp.com`, so absolute numbers depend on WAN latency. Report **both** absolute ms and a relative ratio against the same run's single-GET baseline, so the suite stays meaningful regardless of where it's run from.
---
## 3. Core metrics (the three Jason asked for)
### 3.1 Timed full endpoint read (full-vault bulk read)
**What it measures:** the headline 1.1.0 path — reading every note in the vault via concurrent `read_many` over warm pooled connections vs. serial GETs.
**Procedure:**
1. Enumerate all vault paths (the same listing `sweep.py`/`vault_lint.py` walk).
2. **Serial baseline:** GET each path one at a time on a single connection. Time total + per-note.
3. **Pooled+concurrent:** `read_many(paths)` at the default `ECHO_WORKERS`. Time total.
4. Report total time, notes/sec, and the **speedup ratio** (serial ÷ concurrent). Repeat the concurrent pass N times for percentile spread.
**What "good" looks like:** concurrent should be multiples faster than serial; full-vault concurrent read should stay well under the agent tool timeout (the original failure mode). Record current note count alongside — the metric is only comparable at similar vault sizes.
**Regression gate (suggested):** full-vault concurrent read median < a threshold (e.g. 3s at ~200 notes) AND speedup ratio ≥ ~2×. Tune thresholds after the first baseline run.
### 3.2 Timed full subject pulls (e.g. APTA, CapMetro statuses)
**What it measures:** the cost of a `recall "<subject>"` — search + 1-hop neighbourhood expansion along `## Related` links and `source_notes` — which is the real "what do we know about X" operation, and exercises the 1.2.0 resolver. APTA and CapMetro are live subjects in the vault, so they're realistic fixtures.
**Procedure:**
1. Pick a fixed fixture set of subjects with **different neighbourhood sizes**: a small one, a hub note with many links (e.g. the `echo` project or `operator-preferences`), and the two named ones (APTA, CapMetro). Neighbourhood size is the real cost driver, so vary it deliberately.
2. Time end-to-end `recall` for each: (a) the search call, (b) the 1-hop expansion reads, (c) total. Break out the search vs. expansion split — it tells us whether latency is in the index/search or in the fan-out reads (which 1.1.0's `read_many` should accelerate).
3. Also time bare `resolve "<subject>"` (the O(1) index lookup) separately as the floor — recall should be resolve + search + N expansion reads.
4. Report per-subject and aggregate percentiles; annotate each with its neighbourhood node count so time-per-node is derivable.
**What "good" looks like:** `resolve` is near-instant (in-memory index); `recall` scales with neighbourhood size but the expansion reads are concurrent, so a hub note shouldn't be linearly worse than a leaf.
**Live result + the `expand-graph` sub-metric (added 2026-06-23).** The first run showed `recall()` at 2.84.7 s/subject. Profiling pinned it on the graph layer, not BM25: `load_index()` ~500 ms (index already persisted/incremental), `score()` 0.1 ms, `expand_graph()` ~3,000 ms doing one serial GET per neighbour. Fix shipped in `echo_recall.py` — the BFS now fetches each hop via `read_many`. A dedicated **`expand-graph`** metric times serial vs concurrent expansion (gate: ≥2× min) and asserts byte-identical ranking + scores against a serial reference, so the fix can't silently regress. Measured 3.54.2×; end-to-end `recall()` down ~1.7×.
### 3.3 Timed bulk get / put / append
**What it measures:** write-path throughput and the read-back/idempotency overhead Jason deliberately pays for.
**Procedure (all in the `_agent/_bench/<run-id>/` namespace):**
- **Bulk GET:** create K fixture notes once, then time reading them back — both serially and via `read_many` — to compare against §3.1 at a controlled, fixed K (e.g. 25/50/100) so the read curve is isolated from whatever the live vault happens to contain.
- **Bulk PUT:** time creating K notes. `echo.py put` is read-back-verified (it re-GETs after writing), so this measures the true write+verify cost, not a fire-and-forget POST. Report puts/sec and per-put median.
- **Bulk APPEND:** time K appends to a single growing note. `append` is whole-line idempotent (it GETs first and skips duplicates), so also measure the **idempotent-skip path**: re-append the same K lines and confirm near-zero net writes — time the skip vs. the real append. This validates that idempotency isn't quietly O(file size) per append as the note grows.
- **Concurrent write caveat:** writes to single-line shared files assume one writer; the bulk-write bench must use per-note targets (or hold the lock) so it doesn't model an unsupported pattern.
**What "good" looks like:** PUT slower than GET (verify round-trip); append-skip much cheaper than append-write; no superlinear blowup as the appended note grows.
---
## 4. Additional test suggestions (recommended, beyond the three)
These target the rest of the 1.1.0/1.2.0 surface and the known historical failure modes.
1. **Connection-pool cold vs. warm.** Isolate the keep-alive win directly: time the *first* request after pool creation vs. the median of subsequent requests. This is the single clearest proof the pooling fix is alive; a regression here is the early-warning signal for the old per-request-handshake bug.
2. **Concurrency scaling sweep (`ECHO_WORKERS`).** Run §3.1 at workers = 1, 2, 4, 8, 16. Plot total time vs. workers to find the knee and confirm the default of 8 is sensible for the current vault/WAN, and that it degrades gracefully (no errors/timeouts) at high concurrency.
3. **Fuzzy-resolve latency + accuracy (1.2.0).** Two parts: (a) *timing*`resolve` on exact, alias, and shortened/typo'd mentions; the fuzzy-candidate path does more work, so measure its overhead vs. an exact hit. (b) *correctness* — a fixture table of mention → expected canonical slug (e.g. "echo memory" → `echo`, alias hits, a near-miss that *should* return ranked candidates rather than spawn a duplicate). This guards the actual bug 1.2.0 fixed. Correctness assertions, not just timing.
4. **Index build/rebuild time.** Time `sweep.py` entity-index rebuild + link symmetrization on the full vault. This is the other full-vault script that historically neared the timeout; gate it like §3.1.
5. **Lint + recall-rebuild full-vault timing.** Regression-gate `vault_lint.py` and the recall rebuild against the 1.1.0 baselines (lint ~0.90s, sweep ~0.85s @ 186 notes). These are the concrete numbers in the changelog — turn them into asserted thresholds scaled to current note count.
6. **Lock contention timing.** Time `lock` acquisition when free, when held-fresh (should fast-fail with exit 75), and reclaim of a stale lock past `ECHO_LOCK_TTL`. Confirms the read-back-confirmed lock doesn't add pathological latency and behaves under contention.
7. **Offline write-ahead queue throughput (1.0 carry-over).** With the endpoint unreachable, time enqueue of K writes, then time `flush` replay on reconnect. Validates the queue doesn't degrade and replays in order. Useful because it's an untimed path today.
8. **Cache hit/miss ratio.** Instrument the shared single-pass cache: in a sweep/lint run, count served-from-cache vs. network reads. A correctness+efficiency check that the cache is actually collapsing duplicate reads, not just present.
9. **Scaling fixture / synthetic vault.** Optional but valuable: a script that mints a throwaway vault of N synthetic notes (100 / 500 / 1000) in the bench namespace to measure how all the above scale *beyond* the current ~190 notes — answers "when does the next timeout cliff arrive?" before it hits a real session.
10. **Soak / stability pass.** Run §3.1 in a loop for M minutes to surface connection leaks, pool exhaustion, or memory growth in the long-lived client — relevant because the pool is thread-local and long-running.
---
## 5. Proposed file layout
```
eval/perf/
PERF-TEST-PLAN.md # this file
bench.py # the harness (CLI: --metric, --iterations, --workers, --cleanup/--keep, --json-out)
fixtures.py # subject lists, K-note generators, mention→slug resolve table
baselines.json # committed thresholds + reference numbers (per note-count bucket)
results/ # dated JSON run outputs (gitignored or kept for trend)
2026-06-23-<commit>.json
```
`bench.py` subcommands map 1:1 to the metrics: `read-full`, `subject-pull`, `bulk-get`, `bulk-put`, `bulk-append`, plus `pool-warmup`, `worker-sweep`, `resolve`, `index`, `lint`, `lock`, `queue`, `cache`, `soak`.
## 6. Decisions (resolved 2026-06-23)
- **Baseline policy:** **relative ratios** are the gate (`baselines.json`); absolute ms are recorded as informational. Portable across machines/WAN.
- **CI vs. manual:** **manual / pre-release.** The suite is invoked by hand before tagging; it is not wired into CI (avoids WAN flakiness failing builds against the live endpoint).
- **Synthetic vault (suggestion #9):** **deferred.** Benchmark the real ~190-note vault for now; add the generator if vault growth makes it relevant.
- **Cleanup:** **auto-delete** the `_agent/_bench/<run-id>/` namespace at end of each run, with `--keep` to override.
## 7. Build status
Harness built under `eval/perf/`:
- `bench.py` — the CLI harness; all 14 metrics implemented (`read-full`, `subject-pull`, `bulk-get`, `bulk-put`, `bulk-append`, `pool-warmup`, `worker-sweep`, `resolve`, `index`, `lint`, `lock`, `queue`, `cache`, `soak`).
- `fixtures.py` — subject list (APTA/CapMetro/hubs/leaf), the 1.2.0 resolve correctness table, and bench-note generators.
- `baselines.json` — relative-ratio gates (tune thresholds after the first real run).
- `README.md` — run instructions, metric map, isolation/cleanup, caveats.
- `results/` — dated JSON run outputs.
Verified offline (compile + imports + `--list`/`--help`), then **run live** against the 197-note vault @ af16598 — 11/11 gate checks pass. First run surfaced the recall() finding below; the fix and a guarding metric were added the same session.
## 8. ECHO usage improvements (from the live run)
The benchmark wasn't just validation — it surfaced concrete improvements to how ECHO should do reads. In priority order:
1. **Apply `read_many` everywhere a code path reads a *set* of notes (DONE for `expand_graph`).** The 1.1.0 release shipped concurrent bulk reads but only `sweep`/`lint`/full-vault read adopted it. `recall()`'s graph expansion was still serial — one GET per neighbour — which is why it ran 3 s. The rule going forward: *any* loop that GETs more than ~3 notes whose paths are known up front should batch them through `echo.read_many`, not iterate `get_text`. Audit candidates: `expand_graph` (fixed), `_brief` result printing (still serial), `rebuild()`'s vault walk (still serial), and any future multi-note reader.
2. **Prefetch `_brief` bodies in one `read_many` (NEXT).** After expansion, `recall` prints each primary hit + neighbour via `_brief()`, which GETs the note again to pull its type/status. Those are known paths — fetch them all in one concurrent batch (and reuse bodies already pulled during expansion via a per-call cache, so a note fetched in the BFS isn't re-fetched to print it).
3. **Reuse one in-process read cache across a `recall` call.** `load_index`, `expand_graph`, and `_brief` currently re-fetch overlapping notes. A single `{path: text}` memo passed through the call (the same pattern `sweep.py` already uses via `read_many` once) removes the duplicate GETs — `load_index`'s ~500 ms and the `_brief` re-reads are the remaining recall cost.
4. **Make "batch the reads" a documented contract, not a per-site fix.** Add a one-line rule to the plugin's operating contract / API reference: *prefer `read_many(paths)` over a GET loop; serial multi-note reads are a performance bug.* This is what would have caught the `expand_graph` regression at authoring time. The `expand-graph` metric now enforces it mechanically for recall; the contract generalizes it.
5. **Consider indexing `## Related`/`source_notes` adjacency into the persisted index.** Longer-term: the graph edges are derivable and change only on write. Storing an adjacency list alongside the BM25 postings (maintained by `capture`/`sweep`, same as `entities.json`) would let `expand_graph` skip re-reading note bodies just to extract links — turning the graph layer into an in-memory lookup like `resolve`. Bigger change; revisit if recall latency still matters after #2#3.
None of #1#4 add dependencies or change behavior — they apply the concurrency primitive that already exists. #1 is done and gated; #2#3 are the next cheap wins; #5 is the structural option.
@@ -0,0 +1,96 @@
# ECHO Performance Test Suite
A timing harness for the operations the **1.1.0** (connection pooling + concurrent
`read_many` + shared cache) and **1.2.0** (fuzzy `resolve` / alias learning) updates
targeted. It reuses the live `echo` client module, so it measures the real pooled /
concurrent code path — not a reimplementation.
This is a **manual / pre-release** tool, not a CI gate: it depends on the live
endpoint (`echoapi.alwisp.com`) and WAN latency. Gates are **relative ratios**
(portable), with absolute milliseconds kept as informational context.
See `PERF-TEST-PLAN.md` for the design rationale behind each metric.
## Run
```bash
cd eval/perf
python3 bench.py --list # list metrics
python3 bench.py all # the read-only safe set (no vault writes)
python3 bench.py read-full -n 10 # full-vault serial-vs-concurrent read
python3 bench.py subject-pull # recall APTA / CapMetro / hubs (resolve+search+recall split)
python3 bench.py bulk-put -k 50 # write metric -> uses the _bench namespace
python3 bench.py worker-sweep # ECHO_WORKERS = 1,2,4,8,16 scaling curve
python3 bench.py resolve # 1.2.0 fuzzy correctness table + timing
python3 bench.py soak --soak-seconds 120 # stability / leak watch
```
Set the key first if the baked-in fallback warning bothers you:
`python3 ../../scripts/echo.py write-key <token>` (or `export ECHO_KEY=...`).
## Metrics
| Metric | Plan § | Reads/Writes | What it proves |
|---|---|---|---|
| `read-full` | 3.1 | read-only | full-vault concurrent vs serial speedup (1.1.0 headline) |
| `subject-pull` | 3.2 | read-only | `recall` cost for APTA/CapMetro/hubs, split into resolve floor + search + expansion |
| `expand-graph` | 3.2a | read-only | recall()'s graph layer: serial vs concurrent neighbourhood expansion + ranking-parity guard (pins the real recall bottleneck) |
| `bulk-get` | 3.3 | writes seed | concurrent vs serial read at a controlled K |
| `bulk-put` | 3.3 | **writes** | read-back-verified PUT throughput (puts/sec) |
| `bulk-append` | 3.3 | **writes** | append throughput + idempotent-skip path (no O(file) blowup) |
| `pool-warmup` | 4.1 | read-only | cold vs warm single GET — keep-alive is alive |
| `worker-sweep` | 4.2 | read-only | concurrency scaling knee; validates default workers=8 |
| `resolve` | 4.3 | read-only | fuzzy-resolve timing **and** correctness (anti-duplicate guard) |
| `index` | 4.4 | read-only | `sweep.py` index rebuild + link symmetrize time |
| `lint` | 4.5 | read-only | `vault_lint.py` full-vault time vs 1.1.0 baseline |
| `lock` | 4.6 | **writes** lock | advisory-lock acquire/contend/release timing + semantics |
| `queue` | 4.7 | none (bogus base) | offline write-ahead enqueue timing (see caveat) |
| `cache` | 4.8 | read-only | `read_many` dedups a duplicated path list |
| `soak` | 4.10 | read-only | stability over a window; leak/drift detector |
`all` runs only the read-only set. Write metrics must be requested by name.
## Isolation & cleanup
Write metrics touch **only** `_agent/_bench/<run-id>/`, take the advisory lock for
the duration (and abort if another session holds it), and delete the namespace at
the end. Pass `--keep` to preserve it for debugging. Nothing is written to
`projects/`, `resources/`, `inbox/`, or `journal/`.
## Output
Each run writes `results/<date>-<commit>.json` (machine-readable, for trend diffing)
and prints a human table. The JSON header captures `ECHO_WORKERS`, `ECHO_TIMEOUT`,
note count, git commit, and date so two runs are comparable.
## Gating
`baselines.json` holds relative-ratio gates (e.g. `read-full.speedup_ratio >= 1.8`,
`pool-warmup.cold_over_warm_ratio >= 1.5`). Run once to capture a baseline, then
tune the thresholds to the observed numbers before treating a `FAIL` as blocking.
`--no-gate` reports numbers without pass/fail.
## Finding: recall() bottleneck is the graph layer, not BM25
A profiled `recall("operator preferences")` decomposes as: `load_index()` ~500 ms (the
BM25 index is already persisted + incrementally maintained, n_docs=119), `score()`
0.1 ms, and `expand_graph()` **~3,000 ms** — the graph BFS was fetching each neighbour
serially (one GET per node, ~126 nodes). The fix (shipped in `echo_recall.py`) makes the
BFS breadth-first by hop and fetches each frontier through the existing `read_many`
concurrency. Result: `expand_graph` 3.24.2x faster with byte-identical ranking and
scores; end-to-end `recall()` ~1.7x (e.g. APTA 3.8 s -> 2.2 s). The `expand-graph`
metric + gate above regression-guard this so it can't quietly revert to serial.
## Caveats
- **`resolve` verdicts are PASS/INFO only.** The correctness table in `fixtures.py`
encodes expected slugs against the live vault; until confirmed, mismatches report
`INFO` (tune-me), not `FAIL`. Promote to FAIL once the table is verified.
- **`queue` times the enqueue path only.** A true flush-replay needs a throwaway
sandbox vault so the replay doesn't write to production; that's deferred (the
plan's synthetic-vault item). The metric still proves enqueue works and reports
queue depth.
- **Absolute ms depend on where you run from.** WAN latency to `echoapi.alwisp.com`
dominates single-request times; that's why gates are ratios.
- **Synthetic-vault scaling (100/500/1000 notes) is deferred** per decision — the
suite benchmarks the real ~190-note vault today.
@@ -0,0 +1,57 @@
{
"_comment": "Relative-ratio regression gates (Jason's chosen policy). Ratios are portable across machines/WAN; absolute ms in the results JSON stay informational. Tune these after the first real baseline run, then tighten. 'field' is a dotted path into a metric's result; for list items use the index (e.g. sweep.3.median_ms).",
"read-full": {
"gates": [
{ "field": "speedup_ratio", "op": ">=", "min": 1.8,
"why": "concurrent read_many must beat serial by the 1.1.0 concurrency margin; <1.8 means concurrency regressed" }
]
},
"bulk-get": {
"gates": [
{ "field": "speedup_ratio", "op": ">=", "min": 1.5,
"why": "controlled-K concurrent vs serial; lower bar than full-vault since K is small" }
]
},
"expand-graph": {
"gates": [
{ "field": "min_speedup", "op": ">=", "min": 2.0,
"why": "recall()'s graph layer must fetch each BFS hop concurrently (read_many), not serially per node; <2x means expand_graph regressed to the pre-fix serial walk" },
{ "field": "all_ranking_identical", "op": ">=", "min": 1,
"why": "the concurrent expansion must return the same ranked neighbours as the serial reference" },
{ "field": "all_scores_identical", "op": ">=", "min": 1,
"why": "decayed scores must match the serial reference to within float tolerance" }
]
},
"pool-warmup": {
"gates": [
{ "field": "cold_over_warm_ratio", "op": ">=", "min": 1.5,
"why": "cold request must be meaningfully slower than warm — proves keep-alive is reusing the connection; a ratio near 1.0 means every request is re-handshaking (the pre-1.1.0 bug)" }
]
},
"bulk-append": {
"gates": [
{ "field": "all_skipped_second_pass", "op": ">=", "min": 1,
"why": "second pass of identical lines must be 100% idempotent skips (boolean true coerced to 1)" }
]
},
"soak": {
"gates": [
{ "field": "errors", "op": "<=", "min": 0,
"why": "no read errors across the soak window — connection leaks/pool exhaustion would surface here" },
{ "field": "drift_ratio_late_over_early", "op": "<=", "min": 1.5,
"why": "late passes must not be much slower than early ones; >1.5 suggests a leak or degrading pool" }
]
},
"lock": {
"gates": [
{ "field": "ok", "op": ">=", "min": 1,
"why": "free acquire returns 0 and a contended acquire fast-fails with exit 75" }
]
},
"cache": {
"gates": [
{ "field": "deduped", "op": ">=", "min": 1,
"why": "read_many must collapse a 3x-duplicated path list to the unique set" }
]
}
}
@@ -0,0 +1,800 @@
#!/usr/bin/env python3
"""bench.py — ECHO performance test suite (timing harness).
Measures the operations the 1.1.0 (pooling + concurrent read_many + shared cache)
and 1.2.0 (fuzzy resolve / alias learning) updates targeted, and gates them on
RELATIVE ratios (portable across machines/WAN) rather than absolute ms.
It reuses the live `echo` client module so it times the REAL pooled/concurrent
code path. Reads are non-destructive; write metrics live in a disposable
namespace (_agent/_bench/<run-id>/) cleaned up at the end unless --keep.
This is a MANUAL / pre-release tool, not a CI gate — it depends on the live
endpoint (echoapi.alwisp.com) and WAN latency.
python3 bench.py <metric> [options]
python3 bench.py all # the read-only safe set
python3 bench.py read-full -n 10
python3 bench.py subject-pull
python3 bench.py bulk-put -k 50
python3 bench.py worker-sweep
python3 bench.py resolve # 1.2.0 fuzzy correctness + timing
python3 bench.py --list
Metrics: read-full, subject-pull, bulk-get, bulk-put, bulk-append,
pool-warmup, worker-sweep, resolve, index, lint, lock, queue, cache, soak
Options:
-n / --iterations N timed iterations (default 10 read / 5 write)
-k / --count K notes/appends for bulk metrics (default 50)
--workers W override ECHO_WORKERS for this run
--warmup M warm-up iterations to discard (default 2)
--soak-seconds S duration for the soak metric (default 60)
--keep do NOT delete the _bench namespace after the run
--no-gate skip relative-ratio gating (report numbers only)
--json-out PATH write the results JSON here (default results/<date>-<commit>.json)
--quiet suppress the per-metric human table (JSON only)
Exit: 0 all gates pass (or --no-gate) · 1 a gate failed · 2 usage/setup error.
"""
from __future__ import annotations
import argparse
import contextlib
import datetime as dt
import io
import json
import os
import statistics
import subprocess
import sys
import time
import uuid
from pathlib import Path
HERE = Path(__file__).resolve().parent
SCRIPTS = HERE.parent.parent / "scripts"
sys.path.insert(0, str(SCRIPTS))
import echo # noqa: E402 the validated client — real pooled/concurrent path
import echo_index # noqa: E402 resolve / fuzzy_candidates (1.2.0)
import echo_recall # noqa: E402 recall (search + 1-hop expansion)
BASELINES = HERE / "baselines.json"
RESULTS_DIR = HERE / "results"
# ---------------------------------------------------------------------------
# stats + timing
# ---------------------------------------------------------------------------
def stats(samples: list[float]) -> dict:
"""min/median/p90/p95/max/mean in milliseconds from a list of seconds."""
if not samples:
return {}
ms = sorted(s * 1000.0 for s in samples)
def pct(p: float) -> float:
if len(ms) == 1:
return ms[0]
k = (len(ms) - 1) * p
lo, hi = int(k), min(int(k) + 1, len(ms) - 1)
return ms[lo] + (ms[hi] - ms[lo]) * (k - lo)
return {
"n": len(ms),
"min_ms": round(ms[0], 2),
"median_ms": round(statistics.median(ms), 2),
"p90_ms": round(pct(0.90), 2),
"p95_ms": round(pct(0.95), 2),
"max_ms": round(ms[-1], 2),
"mean_ms": round(statistics.fmean(ms), 2),
}
def timed(fn, n: int, warmup: int) -> dict:
"""Run fn() warmup+n times. Returns warm-up samples separately from the timed
set so cold-start cost (the thing keep-alive kills) is visible, not averaged in."""
warm: list[float] = []
samples: list[float] = []
for i in range(warmup + n):
t0 = time.perf_counter()
fn()
dt_s = time.perf_counter() - t0
(warm if i < warmup else samples).append(dt_s)
out = stats(samples)
if warm:
out["warmup"] = stats(warm)
return out
def silent(fn):
"""Run fn() with stdout swallowed (recall/resolve print a lot)."""
def wrapped():
with contextlib.redirect_stdout(io.StringIO()):
return fn()
return wrapped
# ---------------------------------------------------------------------------
# vault enumeration (mirrors sweep.py / vault_lint.py)
# ---------------------------------------------------------------------------
SKIP_BASENAMES = {"README.md"}
def _list_dir(path: str):
p = "" if path in ("", "/") else (path if path.endswith("/") else path + "/")
body = echo.get_text(p)
if body is None:
return [], []
try:
j = json.loads(body)
except json.JSONDecodeError:
return [], []
entries = list(j.get("files", [])) + list(j.get("folders", []))
files = [e for e in entries if not e.endswith("/")]
folders = [e[:-1] for e in entries if e.endswith("/")]
return files, folders
def walk_vault(prefix: str = ""):
files, folders = _list_dir(prefix)
for f in files:
yield prefix + f
for d in folders:
yield from walk_vault(f"{prefix}{d}/")
def all_notes() -> list[str]:
return [p for p in walk_vault()
if p.endswith(".md") and p.rsplit("/", 1)[-1] not in SKIP_BASENAMES]
# ---------------------------------------------------------------------------
# write primitives (replicate echo.py semantics so we time the real cost)
# ---------------------------------------------------------------------------
def put_verified(path: str, body: str) -> None:
"""PUT then read-back GET — the same verify echo.py cmd_put does."""
status, b = echo.request("PUT", echo.vault_url(path),
data=body.encode(), headers={"Content-Type": "text/markdown"})
echo.check(status, b, f"put {path}")
status, _ = echo.request("GET", echo.vault_url(path))
if status != 200:
raise echo.EchoError(f"put {path}: did not verify (GET {status})")
def append_line(path: str, line: str) -> bool:
"""Whole-line idempotent append (mirrors echo.py cmd_append). Returns True if a
write happened, False if it was an idempotent skip."""
status, body = echo.request("GET", echo.vault_url(path))
if status == 200:
existing = [ln.rstrip("\r") for ln in body.decode(errors="replace").splitlines()]
if line.rstrip("\r") in existing:
return False
status, body = echo.request("POST", echo.vault_url(path),
data=f"{line}\n".encode(),
headers={"Content-Type": "text/markdown"})
echo.check(status, body, f"append {path}")
return True
def delete_path(path: str) -> None:
echo.request("DELETE", echo.vault_url(path))
# ---------------------------------------------------------------------------
# metrics
# ---------------------------------------------------------------------------
def m_read_full(ctx) -> dict:
"""§3.1 full-vault read: serial GET vs concurrent read_many -> speedup ratio."""
paths = all_notes()
if not paths:
raise echo.EchoError("read-full: no notes enumerated (vault unreachable?)")
def serial():
for p in paths:
echo.get_text(p)
def concurrent():
echo.read_many(paths)
# one warm pass so neither side pays the cold-handshake tax (pool-warmup owns that)
echo.get_text(paths[0])
# serial is a slow reference baseline (N serial round-trips); one warm pass is
# enough to establish the ratio, so we don't multiply the full-vault serial cost.
serial_t = timed(serial, n=1, warmup=0)
concurrent_t = timed(concurrent, n=ctx.n, warmup=ctx.warmup)
ratio = (serial_t["median_ms"] / concurrent_t["median_ms"]) if concurrent_t.get("median_ms") else None
return {
"note_count": len(paths),
"workers": echo.MAX_WORKERS,
"serial": serial_t,
"concurrent": concurrent_t,
"speedup_ratio": round(ratio, 2) if ratio else None,
"notes_per_sec_concurrent": round(len(paths) / (concurrent_t["median_ms"] / 1000.0), 1)
if concurrent_t.get("median_ms") else None,
}
def m_subject_pull(ctx) -> dict:
"""§3.2 recall a subject: time resolve (floor), search, and full recall, split out."""
import fixtures
index = echo_index.load()
out = {"subjects": []}
for label, query in fixtures.SUBJECTS:
# floor: O(1) index resolve
resolve_t = timed(lambda: echo_index.resolve(index, query), n=ctx.n, warmup=ctx.warmup)
# search-only layer
def search():
with contextlib.redirect_stdout(io.StringIO()):
echo.request("POST", f"{echo.BASE}/search/simple/?query={query}")
search_t = timed(search, n=ctx.n, warmup=ctx.warmup)
# full recall (search + 1-hop expansion reads)
recall_t = timed(silent(lambda: echo_recall.recall(query)), n=ctx.n, warmup=ctx.warmup)
out["subjects"].append({
"label": label, "query": query,
"resolve_floor": resolve_t,
"search_only": search_t,
"recall_total": recall_t,
})
return out
def m_bulk_get(ctx) -> dict:
"""§3.3 bulk GET at a controlled K: serial vs read_many over fixture notes."""
import fixtures
paths = _seed_notes(ctx, fixtures)
def serial():
for p in paths:
echo.get_text(p)
def concurrent():
echo.read_many(paths)
serial_t = timed(serial, n=ctx.n, warmup=1)
concurrent_t = timed(concurrent, n=ctx.n, warmup=ctx.warmup)
ratio = (serial_t["median_ms"] / concurrent_t["median_ms"]) if concurrent_t.get("median_ms") else None
return {"k": len(paths), "workers": echo.MAX_WORKERS,
"serial": serial_t, "concurrent": concurrent_t,
"speedup_ratio": round(ratio, 2) if ratio else None}
def m_bulk_put(ctx) -> dict:
"""§3.3 bulk PUT (read-back verified) -> puts/sec + per-put percentiles."""
import fixtures
k = ctx.k
samples: list[float] = []
for i in range(k):
body = fixtures.note_body(ctx.run_id, i)
path = fixtures.note_path(ctx.run_id, i)
t0 = time.perf_counter()
put_verified(path, body)
samples.append(time.perf_counter() - t0)
s = stats(samples)
total_s = sum(samples)
return {"k": k, "per_put": s, "total_ms": round(total_s * 1000, 1),
"puts_per_sec": round(k / total_s, 1) if total_s else None}
def m_bulk_append(ctx) -> dict:
"""§3.3 bulk APPEND + idempotent-skip path. Confirms idempotency isn't O(file)."""
import fixtures
target = fixtures.append_target(ctx.run_id)
put_verified(target, fixtures.append_target_seed(ctx.run_id))
k = ctx.k
lines = [f"- 2026-06-23: bench append line {i:04d}" for i in range(k)]
write_samples: list[float] = []
for ln in lines:
t0 = time.perf_counter()
wrote = append_line(target, ln)
write_samples.append(time.perf_counter() - t0)
if not wrote:
raise echo.EchoError("bulk-append: expected a write but got an idempotent skip")
# second pass: every line already present -> must skip, and skip cost is the
# idempotency GET on a now-larger file. Confirms no superlinear blowup.
skip_samples: list[float] = []
skips = 0
for ln in lines:
t0 = time.perf_counter()
wrote = append_line(target, ln)
skip_samples.append(time.perf_counter() - t0)
if not wrote:
skips += 1
return {
"k": k,
"append_write": stats(write_samples),
"append_skip": stats(skip_samples),
"skips_confirmed": skips,
"all_skipped_second_pass": skips == k,
}
def m_pool_warmup(ctx) -> dict:
"""§4.1 cold vs warm single GET — the clearest proof keep-alive is alive."""
paths = all_notes()
probe = paths[0] if paths else "_agent/echo-vault.md"
echo._drop_connection() # force a cold handshake
t0 = time.perf_counter()
echo.get_text(probe)
cold_ms = (time.perf_counter() - t0) * 1000.0
warm = timed(lambda: echo.get_text(probe), n=max(ctx.n, 10), warmup=1)
ratio = round(cold_ms / warm["median_ms"], 2) if warm.get("median_ms") else None
return {"probe": probe, "cold_ms": round(cold_ms, 2), "warm": warm,
"cold_over_warm_ratio": ratio}
def m_worker_sweep(ctx) -> dict:
"""§4.2 concurrency scaling: full-vault concurrent read at workers 1,2,4,8,16."""
paths = all_notes()
if not paths:
raise echo.EchoError("worker-sweep: no notes enumerated")
original = echo.MAX_WORKERS
rows = []
try:
# w=1 is a full serial pass (slow); the curve only needs the shape, so use a
# modest sample count and a single pre-warm rather than per-setting warmups.
reps = max(1, ctx.n // 2)
for w in (1, 2, 4, 8, 16):
echo.MAX_WORKERS = w
echo.read_many(paths[:5]) # warm the pool at this worker count
t = timed(lambda: echo.read_many(paths), n=reps, warmup=0)
rows.append({"workers": w, "median_ms": t["median_ms"], "p95_ms": t["p95_ms"]})
finally:
echo.MAX_WORKERS = original
best = min(rows, key=lambda r: r["median_ms"])
return {"note_count": len(paths), "sweep": rows, "knee_workers": best["workers"],
"default_workers": original}
def m_resolve(ctx) -> dict:
"""§4.3 fuzzy resolve — timing AND correctness against the 1.2.0 guard table."""
import fixtures
index = echo_index.load()
cases = []
passes = info = 0
for case in fixtures.RESOLVE_CASES:
mention = case["mention"]
exact_t = timed(lambda: echo_index.resolve(index, mention), n=ctx.n, warmup=ctx.warmup)
fuzzy_t = timed(lambda: echo_index.fuzzy_candidates(index, mention), n=ctx.n, warmup=ctx.warmup)
_, entity = echo_index.resolve(index, mention)
exact_slug = (entity or {}).get("slug") or _slug_from_entity(entity)
cands = echo_index.fuzzy_candidates(index, mention) or []
cand_slugs = [_cand_slug(c) for c in cands]
expect, want = case["expect"], case.get("expect_slug")
if expect == "exact":
ok = exact_slug == want
elif expect == "candidates":
ok = (exact_slug != want) and (want in cand_slugs)
else: # miss
ok = entity is None
verdict = "PASS" if ok else "INFO" # tune table to live vault before promoting to FAIL
passes += ok
info += (not ok)
cases.append({"mention": mention, "expect": expect, "expect_slug": want,
"resolved_slug": exact_slug, "candidate_slugs": cand_slugs[:5],
"verdict": verdict,
"resolve_timing": exact_t, "fuzzy_timing": fuzzy_t})
return {"cases": cases, "passes": passes, "needs_tuning": info,
"note": "verdicts are PASS/INFO only; promote to FAIL once the table is "
"confirmed against the live vault"}
def _serial_expand(seeds, nmap, base, max_hops):
"""The pre-fix serial graph BFS, kept here as the reference baseline so the suite
both (a) measures the concurrency speedup and (b) asserts the concurrent
expand_graph still returns byte-identical ranking. If echo_recall.expand_graph ever
regresses to serial, the ratio gate fails; if its results drift, the parity check fails."""
from collections import deque
score_of = dict(base)
seen = set(seeds)
results = {}
dq = deque((s, 0) for s in seeds)
while dq:
path, hop = dq.popleft()
if hop >= max_hops:
continue
text = echo_recall.links.get_text(path)
if text is None:
continue
body = echo_recall.strip_frontmatter(text)
targets = set(echo_recall.links.all_wikilinks(body)) | set(echo_recall.links.source_notes(text))
parent = score_of.get(path, 1.0)
for t in targets:
tp = echo_recall._resolve_target(t, nmap)
if not tp or tp in seeds:
continue
decayed = parent * (echo_recall.GRAPH_DECAY ** (hop + 1))
if decayed > results.get(tp, (0.0, ""))[0]:
results[tp] = (decayed, path)
if tp not in seen:
seen.add(tp)
dq.append((tp, hop + 1))
return sorted(results.items(), key=lambda kv: -kv[1][0])
def m_expand_graph(ctx) -> dict:
"""recall() graph layer: serial vs concurrent neighbourhood expansion. This is the
metric that pins the real recall() bottleneck (the graph BFS, not BM25) and guards
the read_many concurrency fix. Also asserts the concurrent path's ranking + scores
match the serial reference exactly."""
import fixtures
ix = echo_recall.load_index()
index = echo_index.load()
nmap = echo_index.name_map(index)
max_hops = echo_recall.MAX_HOPS
# hub subjects stress expansion most; fall back to all subjects if none labelled hub
subjects = [s for s in fixtures.SUBJECTS if "hub" in s[0]] or fixtures.SUBJECTS
rows = []
for label, query in subjects:
hits = ix.score(query, limit=8)
base = {p: s for p, s in hits}
seeds = [p for p, _ in hits]
if not seeds:
continue
echo_recall.expand_graph(seeds, nmap, base, max_hops) # warm
serial_t = timed(lambda: _serial_expand(seeds, nmap, base, max_hops), n=1, warmup=0)
conc_t = timed(lambda: echo_recall.expand_graph(seeds, nmap, base, max_hops),
n=ctx.n, warmup=1)
old = _serial_expand(seeds, nmap, base, max_hops)
new = echo_recall.expand_graph(seeds, nmap, base, max_hops)
ranking_ok = [p for p, _ in old] == [p for p, _ in new]
scores_ok = ranking_ok and all(
abs(old[i][1][0] - new[i][1][0]) < 1e-9 for i in range(len(old)))
ratio = (serial_t["median_ms"] / conc_t["median_ms"]) if conc_t.get("median_ms") else None
rows.append({"label": label, "query": query, "neighbours": len(new),
"serial_ms": serial_t["median_ms"], "concurrent_ms": conc_t["median_ms"],
"speedup": round(ratio, 2) if ratio else None,
"ranking_identical": ranking_ok, "scores_identical": scores_ok})
speedups = [r["speedup"] for r in rows if r["speedup"]]
return {"subjects": rows,
"min_speedup": round(min(speedups), 2) if speedups else None,
"all_ranking_identical": all(r["ranking_identical"] for r in rows),
"all_scores_identical": all(r["scores_identical"] for r in rows)}
def _slug_from_entity(entity):
if not entity:
return None
path = entity.get("path", "")
return path.rsplit("/", 1)[-1].removesuffix(".md") if path else None
def _cand_slug(c):
if isinstance(c, dict):
return c.get("slug") or _slug_from_entity(c)
if isinstance(c, (list, tuple)) and c:
return c[0]
return str(c)
def m_index(ctx) -> dict:
"""§4.4 entity-index rebuild + link symmetrize timing (sweep.py, dry-run = read-only)."""
return _time_script("sweep.py", [])
def m_lint(ctx) -> dict:
"""§4.5 full-vault lint timing (vault_lint.py) — regression-gate vs 1.1.0 baseline."""
return _time_script("vault_lint.py", [], allow_exit={0, 1})
def _time_script(name: str, extra: list[str], allow_exit=frozenset({0})) -> dict:
script = SCRIPTS / name
env = dict(os.environ, ECHO_KEY_LEGACY_OK="1")
t0 = time.perf_counter()
proc = subprocess.run([sys.executable, str(script), *extra],
capture_output=True, text=True, env=env, timeout=120)
elapsed = (time.perf_counter() - t0) * 1000.0
return {"script": name, "elapsed_ms": round(elapsed, 1),
"exit_code": proc.returncode,
"ok": proc.returncode in allow_exit,
"stderr_tail": proc.stderr.strip().splitlines()[-3:] if proc.stderr else []}
def m_lock(ctx) -> dict:
"""§4.6 advisory-lock timing: acquire-free, contended (held-fresh), release."""
owner = f"bench-{ctx.run_id}"
other = f"bench-other-{ctx.run_id}"
def acquire(o):
return echo.cmd_lock(o, quiet=True)
def release(o):
return echo.cmd_unlock(o, quiet=True)
release(owner); release(other) # clean slate
t0 = time.perf_counter(); rc_free = acquire(owner); free_ms = (time.perf_counter() - t0) * 1000
t0 = time.perf_counter(); rc_held = acquire(other); held_ms = (time.perf_counter() - t0) * 1000
t0 = time.perf_counter(); release(owner); rel_ms = (time.perf_counter() - t0) * 1000
return {"acquire_free_ms": round(free_ms, 2), "acquire_free_rc": rc_free,
"contended_ms": round(held_ms, 2), "contended_rc_expected_75": rc_held,
"release_ms": round(rel_ms, 2),
"ok": rc_free == 0 and rc_held == 75}
def m_queue(ctx) -> dict:
"""§4.7 offline write-ahead queue: enqueue K writes against an unreachable base,
then time the flush replay on 'reconnect'. Uses a bogus base so nothing real is
written; restores the base afterward. No production writes occur."""
import importlib
import echo_queue
k = min(ctx.k, 20)
saved_base = echo.BASE
enqueue_samples: list[float] = []
try:
for i in range(k):
url = f"{echo.BASE}/vault/{fixtures_qpath(ctx.run_id, i)}"
t0 = time.perf_counter()
echo_queue.enqueue("PUT", url, b"x", {"Content-Type": "text/markdown"},
idem_key=f"bench-{ctx.run_id}-{i}")
enqueue_samples.append(time.perf_counter() - t0)
pending_before = len(echo_queue.pending())
# flush is left UNMEASURED-as-success here: with a real endpoint it would
# try to write. We only assert enqueue worked and report depth; a true
# flush-replay timing needs a sandbox vault (see README "queue caveat").
return {"k": k, "enqueue": stats(enqueue_samples),
"pending_after_enqueue": pending_before,
"note": "flush replay intentionally not run against the live vault; "
"enqueue path timed only. See README queue caveat."}
finally:
echo.BASE = saved_base
importlib.reload(echo_queue)
def fixtures_qpath(run_id: str, i: int) -> str:
return f"_agent/_bench/{run_id}/queued-{i:04d}.md"
def m_cache(ctx) -> dict:
"""§4.8 read_many dedup check: a path list with duplicates must collapse to the
unique set (the cache/dedup that stops a sweep re-fetching a link target)."""
paths = all_notes()[:20] or ["_agent/echo-vault.md"]
dupd = paths + paths + paths # 3x
t0 = time.perf_counter()
result = echo.read_many(dupd)
elapsed = (time.perf_counter() - t0) * 1000
return {"requested": len(dupd), "unique": len(set(dupd)),
"returned": len(result), "deduped": len(result) == len(set(dupd)),
"elapsed_ms": round(elapsed, 2)}
def m_soak(ctx) -> dict:
"""§4.10 stability: loop full-vault reads for N seconds; watch for errors/drift."""
paths = all_notes()
if not paths:
raise echo.EchoError("soak: no notes enumerated")
deadline = time.time() + ctx.soak_seconds
durations: list[float] = []
errors = 0
while time.time() < deadline:
t0 = time.perf_counter()
try:
res = echo.read_many(paths)
if any(v is None for v in res.values()):
errors += 1
except Exception:
errors += 1
durations.append(time.perf_counter() - t0)
s = stats(durations)
# drift = late iterations slower than early ones (leak / pool exhaustion signal)
half = len(durations) // 2 or 1
early = statistics.fmean(durations[:half]) * 1000
late = statistics.fmean(durations[half:]) * 1000
return {"seconds": ctx.soak_seconds, "iterations": len(durations), "errors": errors,
"per_pass": s, "early_mean_ms": round(early, 2), "late_mean_ms": round(late, 2),
"drift_ratio_late_over_early": round(late / early, 2) if early else None}
METRICS = {
"read-full": m_read_full,
"subject-pull": m_subject_pull,
"bulk-get": m_bulk_get,
"bulk-put": m_bulk_put,
"bulk-append": m_bulk_append,
"pool-warmup": m_pool_warmup,
"worker-sweep": m_worker_sweep,
"resolve": m_resolve,
"expand-graph": m_expand_graph,
"index": m_index,
"lint": m_lint,
"lock": m_lock,
"queue": m_queue,
"cache": m_cache,
"soak": m_soak,
}
# the read-only safe set run by `all` (no writes to the vault)
READONLY = ["pool-warmup", "read-full", "worker-sweep", "subject-pull",
"resolve", "expand-graph", "index", "lint", "cache"]
WRITES = {"bulk-get", "bulk-put", "bulk-append", "lock"} # touch the _bench namespace
# ---------------------------------------------------------------------------
# fixture seeding / cleanup
# ---------------------------------------------------------------------------
def _seed_notes(ctx, fixtures) -> list[str]:
"""Ensure K bench notes exist; return their paths. Cached on ctx so bulk-get
and bulk-put can share the seed within one run."""
if getattr(ctx, "_seeded", None):
return ctx._seeded
paths = []
for i in range(ctx.k):
p = fixtures.note_path(ctx.run_id, i)
put_verified(p, fixtures.note_body(ctx.run_id, i))
paths.append(p)
ctx._seeded = paths
return paths
def cleanup_namespace(run_id: str) -> int:
"""Delete every file under _agent/_bench/<run-id>/. Returns count deleted."""
prefix = f"_agent/_bench/{run_id}/"
victims = [p for p in walk_vault(prefix)]
for p in victims:
delete_path(p)
# remove the (now-empty) run dir marker if the API created one — best effort
return len(victims)
# ---------------------------------------------------------------------------
# gating
# ---------------------------------------------------------------------------
def load_baselines() -> dict:
if BASELINES.exists():
return json.loads(BASELINES.read_text())
return {}
def gate(metric: str, result: dict, baselines: dict) -> list[dict]:
"""Apply relative-ratio gates from baselines.json. Returns a list of checks."""
rules = baselines.get(metric, {})
checks = []
for rule in rules.get("gates", []):
path, op, threshold = rule["field"], rule["op"], rule["min"]
val = _dig(result, path)
if val is None:
checks.append({"rule": rule, "value": None, "pass": None, "reason": "field absent"})
continue
ok = (val >= threshold) if op == ">=" else (val <= threshold)
checks.append({"rule": rule, "value": val, "pass": ok})
return checks
def _dig(obj, dotted: str):
cur = obj
for part in dotted.split("."):
if isinstance(cur, list):
try:
cur = cur[int(part)]
continue
except (ValueError, IndexError):
return None
if not isinstance(cur, dict) or part not in cur:
return None
cur = cur[part]
return cur
# ---------------------------------------------------------------------------
# main
# ---------------------------------------------------------------------------
class Ctx:
pass
def env_block(args) -> dict:
commit = "unknown"
try:
commit = subprocess.run(["git", "rev-parse", "--short", "HEAD"],
cwd=str(SCRIPTS), capture_output=True, text=True,
timeout=10).stdout.strip() or "unknown"
except Exception:
pass
return {
"date": dt.datetime.now().isoformat(timespec="seconds"),
"endpoint": echo.BASE,
"commit": commit,
"echo_workers": echo.MAX_WORKERS,
"echo_timeout": echo.TIMEOUT,
"python": sys.version.split()[0],
"iterations": args.iterations,
"count_k": args.count,
}
def human_table(name: str, result: dict, checks: list[dict]) -> str:
lines = [f"\n=== {name} ==="]
lines.append(json.dumps(result, indent=2))
for c in checks:
mark = "PASS" if c["pass"] else ("" if c["pass"] is None else "FAIL")
lines.append(f" [{mark}] {c['rule']['field']} {c['rule']['op']} {c['rule']['min']} (got {c['value']})")
return "\n".join(lines)
def main(argv=None) -> int:
ap = argparse.ArgumentParser(description="ECHO performance test suite (manual/pre-release)")
ap.add_argument("metric", nargs="?", help="metric name, or 'all' for the read-only set")
ap.add_argument("--list", action="store_true", help="list metrics and exit")
ap.add_argument("-n", "--iterations", type=int, default=None)
ap.add_argument("-k", "--count", type=int, default=50)
ap.add_argument("--workers", type=int, default=None)
ap.add_argument("--warmup", type=int, default=2)
ap.add_argument("--soak-seconds", type=int, default=60)
ap.add_argument("--keep", action="store_true", help="do not delete the _bench namespace")
ap.add_argument("--no-gate", action="store_true")
ap.add_argument("--json-out", default=None)
ap.add_argument("--quiet", action="store_true")
args = ap.parse_args(argv)
if args.list or not args.metric:
print("Metrics:", ", ".join(METRICS))
print("Groups : all (read-only safe set:", ", ".join(READONLY) + ")")
print("Writes to _bench namespace:", ", ".join(sorted(WRITES)))
return 0 if args.list else 2
if args.workers is not None:
echo.MAX_WORKERS = args.workers
selected = READONLY if args.metric == "all" else [args.metric]
for m in selected:
if m not in METRICS:
print(f"unknown metric: {m}", file=sys.stderr)
return 2
ctx = Ctx()
ctx.run_id = dt.datetime.now().strftime("%Y%m%d-%H%M%S") + "-" + uuid.uuid4().hex[:6]
ctx.k = args.count
ctx.warmup = args.warmup
ctx.soak_seconds = args.soak_seconds
ctx._seeded = None
baselines = load_baselines()
need_writes = any(m in WRITES for m in selected)
lock_owner = f"bench-{ctx.run_id}"
if need_writes:
if echo.cmd_lock(lock_owner, quiet=True) == 75:
print("bench: vault lock is held by another session — aborting write metrics.",
file=sys.stderr)
return 2
report = {"env": env_block(args), "run_id": ctx.run_id, "metrics": {}}
any_fail = False
try:
for m in selected:
ctx.n = args.iterations if args.iterations is not None else (5 if m in WRITES else 10)
try:
result = METRICS[m](ctx)
except Exception as exc: # noqa: BLE001
result = {"error": str(exc)}
any_fail = True
checks = [] if args.no_gate else gate(m, result, baselines)
if any(c["pass"] is False for c in checks):
any_fail = True
report["metrics"][m] = {"result": result, "gates": checks}
if not args.quiet:
print(human_table(m, result, checks))
finally:
if need_writes:
echo.cmd_unlock(lock_owner, quiet=True)
if need_writes and not args.keep:
n = cleanup_namespace(ctx.run_id)
report["cleanup"] = {"deleted": n}
if not args.quiet:
print(f"\nbench: cleaned up {n} files under _agent/_bench/{ctx.run_id}/")
elif need_writes and args.keep:
report["cleanup"] = {"deleted": 0, "kept": f"_agent/_bench/{ctx.run_id}/"}
RESULTS_DIR.mkdir(parents=True, exist_ok=True)
out_path = Path(args.json_out) if args.json_out else \
RESULTS_DIR / f"{report['env']['date'][:10]}-{report['env']['commit']}.json"
out_path.write_text(json.dumps(report, indent=2))
print(f"\nbench: results -> {out_path}")
return 1 if any_fail else 0
if __name__ == "__main__":
sys.exit(main())
@@ -0,0 +1,100 @@
#!/usr/bin/env python3
"""fixtures.py — inputs for the ECHO performance harness (bench.py).
Holds the *what* (subjects to pull, notes to write, mentions to resolve) so the
harness (bench.py) stays the *how* (timing, stats, gating). Nothing here touches
the network; bench.py owns all I/O.
"""
from __future__ import annotations
# --- §3.2 subject pulls -------------------------------------------------------
# (label, query) pairs fed to `recall`. Chosen to span neighbourhood sizes — the
# real cost driver — from a likely-leaf to a known hub. APTA and CapMetro are the
# subjects Jason named; "echo" and "operator preferences" are dense hubs that
# stress the 1-hop expansion (the read_many fan-out 1.1.0 accelerated).
SUBJECTS: list[tuple[str, str]] = [
("apta", "APTA"),
("capmetro", "CapMetro"),
("hub-echo", "echo"),
("hub-prefs", "operator preferences"),
("leaf-rivnut", "rivnut torque spec"),
]
# --- §4.3 fuzzy-resolve correctness table (1.2.0) -----------------------------
# Each case: mention, expected behaviour. `expect_slug` is the canonical slug an
# exact/alias/fuzzy match should land on (None = no entity expected). `expect`
# is the classifier:
# "exact" -> resolve returns an entity whose slug == expect_slug
# "candidates" -> no exact hit, but fuzzy_candidates surfaces expect_slug
# (the 1.2.0 anti-duplicate guard — a near-miss must NOT resolve
# to nothing and silently spawn a new note)
# "miss" -> neither; genuinely unknown
# Tune expect_slug to the live vault; unknowns are reported as INFO, not failures.
RESOLVE_CASES: list[dict] = [
{"mention": "echo", "expect": "exact", "expect_slug": "echo"},
{"mention": "echo memory", "expect": "candidates", "expect_slug": "echo"},
{"mention": "ECHO plugin", "expect": "candidates", "expect_slug": "echo"},
{"mention": "goldbrain", "expect": "exact", "expect_slug": "goldbrain"},
{"mention": "jason stedwell", "expect": "exact", "expect_slug": "jason-stedwell"},
{"mention": "jason", "expect": "candidates", "expect_slug": "jason-stedwell"},
{"mention": "zzqx nonexistent entity", "expect": "miss", "expect_slug": None},
]
# --- §3.3 bulk write fixtures -------------------------------------------------
BENCH_PREFIX = "_agent/_bench" # run-scoped namespace: _agent/_bench/<run-id>/...
def note_body(run_id: str, i: int) -> str:
"""A realistic-shape note: canonical frontmatter + a couple of headings, so
PUT cost reflects a true note, not a one-liner. agent_written + a _bench tag
make these trivially greppable if a cleanup is ever missed."""
return (
"---\n"
"type: working-memory\n"
"status: active\n"
"created: 2026-06-23\n"
"updated: 2026-06-23\n"
"tags:\n"
" - agent\n"
" - _bench\n"
"agent_written: true\n"
f"source_notes: []\n"
f"bench_run: {run_id}\n"
"---\n\n"
f"# Bench Note {i:04d}\n\n"
"## Body\n"
f"Synthetic benchmark note {i} for run {run_id}. "
"Filler so the payload is not pathologically small: "
+ ("lorem ipsum dolor sit amet " * 6)
+ "\n\n## Log\n- seed\n"
)
def note_path(run_id: str, i: int) -> str:
return f"{BENCH_PREFIX}/{run_id}/note-{i:04d}.md"
def append_target(run_id: str) -> str:
return f"{BENCH_PREFIX}/{run_id}/append-target.md"
def append_target_seed(run_id: str) -> str:
return (
"---\n"
"type: working-memory\n"
"status: active\n"
"created: 2026-06-23\n"
"updated: 2026-06-23\n"
"tags:\n"
" - agent\n"
" - _bench\n"
"agent_written: true\n"
"source_notes: []\n"
f"bench_run: {run_id}\n"
"---\n\n"
"# Append Target\n\n"
"## Log\n"
)
@@ -0,0 +1,931 @@
{
"env": {
"date": "2026-06-23T20:17:09",
"endpoint": "https://echoapi.alwisp.com",
"commit": "af16598",
"echo_workers": 8,
"echo_timeout": 30,
"python": "3.10.12",
"iterations": 4,
"count_k": 50
},
"metrics": {
"bulk-append": {
"result": {
"k": 30,
"append_write": {
"n": 30,
"min_ms": 87.11,
"median_ms": 104.08,
"p90_ms": 190.63,
"p95_ms": 198.89,
"max_ms": 241.91,
"mean_ms": 117.22
},
"append_skip": {
"n": 30,
"min_ms": 47.57,
"median_ms": 51.42,
"p90_ms": 59.82,
"p95_ms": 61.57,
"max_ms": 73.49,
"mean_ms": 53.22
},
"skips_confirmed": 30,
"all_skipped_second_pass": true
},
"gates": [
{
"rule": {
"field": "all_skipped_second_pass",
"op": ">=",
"min": 1,
"why": "second pass of identical lines must be 100% idempotent skips (boolean true coerced to 1)"
},
"value": true,
"pass": true
}
]
},
"bulk-get": {
"result": {
"k": 30,
"workers": 8,
"serial": {
"n": 5,
"min_ms": 1520.47,
"median_ms": 1606.86,
"p90_ms": 1805.72,
"p95_ms": 1835.83,
"max_ms": 1865.94,
"mean_ms": 1658.6,
"warmup": {
"n": 1,
"min_ms": 1601.2,
"median_ms": 1601.2,
"p90_ms": 1601.2,
"p95_ms": 1601.2,
"max_ms": 1601.2,
"mean_ms": 1601.2
}
},
"concurrent": {
"n": 5,
"min_ms": 340.31,
"median_ms": 356.48,
"p90_ms": 358.82,
"p95_ms": 359.32,
"max_ms": 359.83,
"mean_ms": 351.42,
"warmup": {
"n": 2,
"min_ms": 353.43,
"median_ms": 434.94,
"p90_ms": 500.15,
"p95_ms": 508.3,
"max_ms": 516.45,
"mean_ms": 434.94
}
},
"speedup_ratio": 4.51
},
"gates": [
{
"rule": {
"field": "speedup_ratio",
"op": ">=",
"min": 1.5,
"why": "controlled-K concurrent vs serial; lower bar than full-vault since K is small"
},
"value": 4.51,
"pass": true
}
]
},
"bulk-put": {
"result": {
"k": 30,
"per_put": {
"n": 30,
"min_ms": 100.09,
"median_ms": 114.98,
"p90_ms": 212.46,
"p95_ms": 236.18,
"max_ms": 330.77,
"mean_ms": 143.25
},
"total_ms": 4297.5,
"puts_per_sec": 7.0
},
"gates": []
},
"cache": {
"result": {
"requested": 60,
"unique": 20,
"returned": 20,
"deduped": true,
"elapsed_ms": 307.13
},
"gates": [
{
"rule": {
"field": "deduped",
"op": ">=",
"min": 1,
"why": "read_many must collapse a 3x-duplicated path list to the unique set"
},
"value": true,
"pass": true
}
]
},
"expand-graph": {
"result": {
"subjects": [
{
"label": "hub-echo",
"query": "echo",
"neighbours": 120,
"serial_ms": 2227.67,
"concurrent_ms": 642.2,
"speedup": 3.47,
"ranking_identical": true,
"scores_identical": true
},
{
"label": "hub-prefs",
"query": "operator preferences",
"neighbours": 126,
"serial_ms": 2910.46,
"concurrent_ms": 698.8,
"speedup": 4.16,
"ranking_identical": true,
"scores_identical": true
}
],
"min_speedup": 3.47,
"all_ranking_identical": true,
"all_scores_identical": true
},
"gates": [
{
"rule": {
"field": "min_speedup",
"op": ">=",
"min": 2.0,
"why": "recall()'s graph layer must fetch each BFS hop concurrently (read_many), not serially per node; <2x means expand_graph regressed to the pre-fix serial walk"
},
"value": 3.47,
"pass": true
},
{
"rule": {
"field": "all_ranking_identical",
"op": ">=",
"min": 1,
"why": "the concurrent expansion must return the same ranked neighbours as the serial reference"
},
"value": true,
"pass": true
},
{
"rule": {
"field": "all_scores_identical",
"op": ">=",
"min": 1,
"why": "decayed scores must match the serial reference to within float tolerance"
},
"value": true,
"pass": true
}
]
},
"index": {
"result": {
"script": "sweep.py",
"elapsed_ms": 4629.0,
"exit_code": 0,
"ok": true,
"stderr_tail": []
},
"gates": []
},
"lint": {
"result": {
"script": "vault_lint.py",
"elapsed_ms": 5126.4,
"exit_code": 1,
"ok": true,
"stderr_tail": []
},
"gates": []
},
"lock": {
"result": {
"acquire_free_ms": 159.18,
"acquire_free_rc": 0,
"contended_ms": 57.89,
"contended_rc_expected_75": 75,
"release_ms": 132.92,
"ok": true
},
"gates": [
{
"rule": {
"field": "ok",
"op": ">=",
"min": 1,
"why": "free acquire returns 0 and a contended acquire fast-fails with exit 75"
},
"value": true,
"pass": true
}
]
},
"pool-warmup": {
"result": {
"probe": "_agent/echo-vault.md",
"cold_ms": 163.25,
"warm": {
"n": 12,
"min_ms": 45.64,
"median_ms": 50.29,
"p90_ms": 52.51,
"p95_ms": 53.79,
"max_ms": 55.28,
"mean_ms": 50.26,
"warmup": {
"n": 1,
"min_ms": 51.68,
"median_ms": 51.68,
"p90_ms": 51.68,
"p95_ms": 51.68,
"max_ms": 51.68,
"mean_ms": 51.68
}
},
"cold_over_warm_ratio": 3.25
},
"gates": [
{
"rule": {
"field": "cold_over_warm_ratio",
"op": ">=",
"min": 1.5,
"why": "cold request must be meaningfully slower than warm \u2014 proves keep-alive is reusing the connection; a ratio near 1.0 means every request is re-handshaking (the pre-1.1.0 bug)"
},
"value": 3.25,
"pass": true
}
]
},
"queue": {
"result": {
"k": 10,
"enqueue": {
"n": 10,
"min_ms": 0.07,
"median_ms": 0.08,
"p90_ms": 0.18,
"p95_ms": 0.2,
"max_ms": 0.22,
"mean_ms": 0.1
},
"pending_after_enqueue": 10,
"note": "flush replay intentionally not run against the live vault; enqueue path timed only. See README queue caveat."
},
"gates": []
},
"read-full": {
"result": {
"note_count": 197,
"workers": 8,
"serial": {
"n": 1,
"min_ms": 11376.08,
"median_ms": 11376.08,
"p90_ms": 11376.08,
"p95_ms": 11376.08,
"max_ms": 11376.08,
"mean_ms": 11376.08
},
"concurrent": {
"n": 4,
"min_ms": 1559.79,
"median_ms": 1595.31,
"p90_ms": 1740.92,
"p95_ms": 1768.05,
"max_ms": 1795.17,
"mean_ms": 1636.4,
"warmup": {
"n": 2,
"min_ms": 1641.35,
"median_ms": 1652.91,
"p90_ms": 1662.17,
"p95_ms": 1663.32,
"max_ms": 1664.48,
"mean_ms": 1652.91
}
},
"speedup_ratio": 7.13,
"notes_per_sec_concurrent": 123.5
},
"gates": [
{
"rule": {
"field": "speedup_ratio",
"op": ">=",
"min": 1.8,
"why": "concurrent read_many must beat serial by the 1.1.0 concurrency margin; <1.8 means concurrency regressed"
},
"value": 7.13,
"pass": true
}
]
},
"resolve": {
"result": {
"cases": [
{
"mention": "echo",
"expect": "exact",
"expect_slug": "echo",
"resolved_slug": "echo",
"candidate_slugs": [
"2026-06-19-goldbrain-full-echo-architect",
"echo",
"echo-memory-codex-plugin",
"echo-plugin-build",
"echo-skill-improvements"
],
"verdict": "PASS",
"resolve_timing": {
"n": 6,
"min_ms": 0.0,
"median_ms": 0.0,
"p90_ms": 0.0,
"p95_ms": 0.0,
"max_ms": 0.0,
"mean_ms": 0.0,
"warmup": {
"n": 2,
"min_ms": 0.01,
"median_ms": 0.1,
"p90_ms": 0.17,
"p95_ms": 0.18,
"max_ms": 0.19,
"mean_ms": 0.1
}
},
"fuzzy_timing": {
"n": 6,
"min_ms": 1.35,
"median_ms": 1.49,
"p90_ms": 1.67,
"p95_ms": 1.68,
"max_ms": 1.68,
"mean_ms": 1.51,
"warmup": {
"n": 2,
"min_ms": 1.82,
"median_ms": 1.83,
"p90_ms": 1.84,
"p95_ms": 1.84,
"max_ms": 1.85,
"mean_ms": 1.83
}
}
},
{
"mention": "echo memory",
"expect": "candidates",
"expect_slug": "echo",
"resolved_slug": "echo",
"candidate_slugs": [
"echo",
"echo-memory-codex-plugin",
"echo-plugin-build",
"echo-skill-improvements",
"2026-06-19-goldbrain-full-echo-architect"
],
"verdict": "INFO",
"resolve_timing": {
"n": 6,
"min_ms": 0.55,
"median_ms": 0.56,
"p90_ms": 0.57,
"p95_ms": 0.58,
"max_ms": 0.58,
"mean_ms": 0.56,
"warmup": {
"n": 2,
"min_ms": 0.61,
"median_ms": 0.61,
"p90_ms": 0.61,
"p95_ms": 0.61,
"max_ms": 0.61,
"mean_ms": 0.61
}
},
"fuzzy_timing": {
"n": 6,
"min_ms": 0.97,
"median_ms": 0.99,
"p90_ms": 1.06,
"p95_ms": 1.09,
"max_ms": 1.11,
"mean_ms": 1.01,
"warmup": {
"n": 2,
"min_ms": 1.15,
"median_ms": 1.18,
"p90_ms": 1.2,
"p95_ms": 1.21,
"max_ms": 1.21,
"mean_ms": 1.18
}
}
},
{
"mention": "ECHO plugin",
"expect": "candidates",
"expect_slug": "echo",
"resolved_slug": "echo",
"candidate_slugs": [
"echo",
"echo-memory-codex-plugin",
"echo-plugin-build",
"2026-06-19-goldbrain-full-echo-architect",
"alabama-wisp-brand-docs"
],
"verdict": "INFO",
"resolve_timing": {
"n": 6,
"min_ms": 0.41,
"median_ms": 0.41,
"p90_ms": 0.42,
"p95_ms": 0.42,
"max_ms": 0.42,
"mean_ms": 0.41,
"warmup": {
"n": 2,
"min_ms": 0.42,
"median_ms": 0.45,
"p90_ms": 0.47,
"p95_ms": 0.48,
"max_ms": 0.48,
"mean_ms": 0.45
}
},
"fuzzy_timing": {
"n": 6,
"min_ms": 0.79,
"median_ms": 0.8,
"p90_ms": 0.88,
"p95_ms": 0.9,
"max_ms": 0.92,
"mean_ms": 0.83,
"warmup": {
"n": 2,
"min_ms": 0.89,
"median_ms": 0.89,
"p90_ms": 0.9,
"p95_ms": 0.9,
"max_ms": 0.9,
"mean_ms": 0.89
}
}
},
{
"mention": "goldbrain",
"expect": "exact",
"expect_slug": "goldbrain",
"resolved_slug": "goldbrain",
"candidate_slugs": [
"2026-06-19-goldbrain-full-echo-architect",
"goldbrain"
],
"verdict": "PASS",
"resolve_timing": {
"n": 6,
"min_ms": 0.0,
"median_ms": 0.0,
"p90_ms": 0.0,
"p95_ms": 0.0,
"max_ms": 0.0,
"mean_ms": 0.0,
"warmup": {
"n": 2,
"min_ms": 0.0,
"median_ms": 0.0,
"p90_ms": 0.0,
"p95_ms": 0.0,
"max_ms": 0.0,
"mean_ms": 0.0
}
},
"fuzzy_timing": {
"n": 6,
"min_ms": 0.73,
"median_ms": 0.75,
"p90_ms": 0.85,
"p95_ms": 0.88,
"max_ms": 0.91,
"mean_ms": 0.78,
"warmup": {
"n": 2,
"min_ms": 0.8,
"median_ms": 0.81,
"p90_ms": 0.82,
"p95_ms": 0.82,
"max_ms": 0.82,
"mean_ms": 0.81
}
}
},
{
"mention": "jason stedwell",
"expect": "exact",
"expect_slug": "jason-stedwell",
"resolved_slug": "jason-stedwell",
"candidate_slugs": [
"jason-stedwell",
"jason-mcp-gateway"
],
"verdict": "PASS",
"resolve_timing": {
"n": 6,
"min_ms": 0.0,
"median_ms": 0.0,
"p90_ms": 0.0,
"p95_ms": 0.0,
"max_ms": 0.0,
"mean_ms": 0.0,
"warmup": {
"n": 2,
"min_ms": 0.0,
"median_ms": 0.0,
"p90_ms": 0.0,
"p95_ms": 0.0,
"max_ms": 0.0,
"mean_ms": 0.0
}
},
"fuzzy_timing": {
"n": 6,
"min_ms": 0.69,
"median_ms": 0.72,
"p90_ms": 0.75,
"p95_ms": 0.75,
"max_ms": 0.75,
"mean_ms": 0.72,
"warmup": {
"n": 2,
"min_ms": 0.74,
"median_ms": 0.74,
"p90_ms": 0.75,
"p95_ms": 0.75,
"max_ms": 0.75,
"mean_ms": 0.74
}
}
},
{
"mention": "jason",
"expect": "candidates",
"expect_slug": "jason-stedwell",
"resolved_slug": "jason-stedwell",
"candidate_slugs": [
"jason-mcp-gateway",
"jason-stedwell"
],
"verdict": "INFO",
"resolve_timing": {
"n": 6,
"min_ms": 0.61,
"median_ms": 0.65,
"p90_ms": 0.66,
"p95_ms": 0.67,
"max_ms": 0.67,
"mean_ms": 0.64,
"warmup": {
"n": 2,
"min_ms": 0.66,
"median_ms": 0.68,
"p90_ms": 0.69,
"p95_ms": 0.69,
"max_ms": 0.69,
"mean_ms": 0.68
}
},
"fuzzy_timing": {
"n": 6,
"min_ms": 0.63,
"median_ms": 0.63,
"p90_ms": 0.65,
"p95_ms": 0.65,
"max_ms": 0.66,
"mean_ms": 0.64,
"warmup": {
"n": 2,
"min_ms": 0.68,
"median_ms": 0.69,
"p90_ms": 0.7,
"p95_ms": 0.7,
"max_ms": 0.7,
"mean_ms": 0.69
}
}
},
{
"mention": "zzqx nonexistent entity",
"expect": "miss",
"expect_slug": null,
"resolved_slug": null,
"candidate_slugs": [],
"verdict": "PASS",
"resolve_timing": {
"n": 6,
"min_ms": 0.62,
"median_ms": 0.63,
"p90_ms": 0.67,
"p95_ms": 0.67,
"max_ms": 0.68,
"mean_ms": 0.64,
"warmup": {
"n": 2,
"min_ms": 0.66,
"median_ms": 0.67,
"p90_ms": 0.67,
"p95_ms": 0.67,
"max_ms": 0.67,
"mean_ms": 0.67
}
},
"fuzzy_timing": {
"n": 6,
"min_ms": 0.61,
"median_ms": 0.62,
"p90_ms": 0.65,
"p95_ms": 0.65,
"max_ms": 0.66,
"mean_ms": 0.62,
"warmup": {
"n": 2,
"min_ms": 0.62,
"median_ms": 0.63,
"p90_ms": 0.64,
"p95_ms": 0.64,
"max_ms": 0.64,
"mean_ms": 0.63
}
}
}
],
"passes": 4,
"needs_tuning": 3,
"note": "verdicts are PASS/INFO only; promote to FAIL once the table is confirmed against the live vault"
},
"gates": []
},
"soak": {
"result": {
"seconds": 22,
"iterations": 15,
"errors": 0,
"per_pass": {
"n": 15,
"min_ms": 1472.88,
"median_ms": 1551.67,
"p90_ms": 1648.45,
"p95_ms": 1702.66,
"max_ms": 1820.58,
"mean_ms": 1569.81
},
"early_mean_ms": 1575.63,
"late_mean_ms": 1564.72,
"drift_ratio_late_over_early": 0.99
},
"gates": [
{
"rule": {
"field": "errors",
"op": "<=",
"min": 0,
"why": "no read errors across the soak window \u2014 connection leaks/pool exhaustion would surface here"
},
"value": 0,
"pass": true
},
{
"rule": {
"field": "drift_ratio_late_over_early",
"op": "<=",
"min": 1.5,
"why": "late passes must not be much slower than early ones; >1.5 suggests a leak or degrading pool"
},
"value": 0.99,
"pass": true
}
]
},
"subject-pull": {
"result": {
"subjects": [
{
"label": "apta",
"query": "APTA",
"resolve_floor": {
"n": 1,
"min_ms": 0.75,
"median_ms": 0.75,
"p90_ms": 0.75,
"p95_ms": 0.75,
"max_ms": 0.75,
"mean_ms": 0.75
},
"search_only": {
"n": 1,
"min_ms": 61.87,
"median_ms": 61.87,
"p90_ms": 61.87,
"p95_ms": 61.87,
"max_ms": 61.87,
"mean_ms": 61.87
},
"recall_total": {
"n": 1,
"min_ms": 2231.31,
"median_ms": 2231.31,
"p90_ms": 2231.31,
"p95_ms": 2231.31,
"max_ms": 2231.31,
"mean_ms": 2231.31
}
},
{
"label": "capmetro",
"query": "CapMetro",
"resolve_floor": {
"n": 1,
"min_ms": 0.03,
"median_ms": 0.03,
"p90_ms": 0.03,
"p95_ms": 0.03,
"max_ms": 0.03,
"mean_ms": 0.03
},
"search_only": {
"n": 1,
"min_ms": 57.73,
"median_ms": 57.73,
"p90_ms": 57.73,
"p95_ms": 57.73,
"max_ms": 57.73,
"mean_ms": 57.73
},
"recall_total": {
"n": 1,
"min_ms": 2116.06,
"median_ms": 2116.06,
"p90_ms": 2116.06,
"p95_ms": 2116.06,
"max_ms": 2116.06,
"mean_ms": 2116.06
}
},
{
"label": "hub-echo",
"query": "echo",
"resolve_floor": {
"n": 1,
"min_ms": 0.03,
"median_ms": 0.03,
"p90_ms": 0.03,
"p95_ms": 0.03,
"max_ms": 0.03,
"mean_ms": 0.03
},
"search_only": {
"n": 1,
"min_ms": 70.56,
"median_ms": 70.56,
"p90_ms": 70.56,
"p95_ms": 70.56,
"max_ms": 70.56,
"mean_ms": 70.56
},
"recall_total": {
"n": 1,
"min_ms": 2403.62,
"median_ms": 2403.62,
"p90_ms": 2403.62,
"p95_ms": 2403.62,
"max_ms": 2403.62,
"mean_ms": 2403.62
}
},
{
"label": "hub-prefs",
"query": "operator preferences",
"resolve_floor": {
"n": 1,
"min_ms": 0.04,
"median_ms": 0.04,
"p90_ms": 0.04,
"p95_ms": 0.04,
"max_ms": 0.04,
"mean_ms": 0.04
},
"search_only": {
"n": 1,
"min_ms": 2011.13,
"median_ms": 2011.13,
"p90_ms": 2011.13,
"p95_ms": 2011.13,
"max_ms": 2011.13,
"mean_ms": 2011.13
},
"recall_total": {
"n": 1,
"min_ms": 2994.84,
"median_ms": 2994.84,
"p90_ms": 2994.84,
"p95_ms": 2994.84,
"max_ms": 2994.84,
"mean_ms": 2994.84
}
},
{
"label": "leaf-rivnut",
"query": "rivnut torque spec",
"resolve_floor": {
"n": 1,
"min_ms": 2.15,
"median_ms": 2.15,
"p90_ms": 2.15,
"p95_ms": 2.15,
"max_ms": 2.15,
"mean_ms": 2.15
},
"search_only": {
"n": 1,
"min_ms": 2013.58,
"median_ms": 2013.58,
"p90_ms": 2013.58,
"p95_ms": 2013.58,
"max_ms": 2013.58,
"mean_ms": 2013.58
},
"recall_total": {
"n": 1,
"min_ms": 2371.32,
"median_ms": 2371.32,
"p90_ms": 2371.32,
"p95_ms": 2371.32,
"max_ms": 2371.32,
"mean_ms": 2371.32
}
}
]
},
"gates": []
},
"worker-sweep": {
"result": {
"note_count": 197,
"sweep": [
{
"workers": 1,
"median_ms": 11917.49,
"p95_ms": 11917.49
},
{
"workers": 2,
"median_ms": 5740.0,
"p95_ms": 5740.0
},
{
"workers": 4,
"median_ms": 3034.3,
"p95_ms": 3034.3
},
{
"workers": 8,
"median_ms": 1583.83,
"p95_ms": 1583.83
},
{
"workers": 16,
"median_ms": 1277.77,
"p95_ms": 1277.77
}
],
"knee_workers": 16,
"default_workers": 8
},
"gates": []
}
}
}
@@ -0,0 +1,55 @@
{
"env": {
"date": "2026-06-23T20:22:00",
"endpoint": "https://echoapi.alwisp.com",
"commit": "af16598",
"echo_workers": 8,
"echo_timeout": 30,
"python": "3.10.12",
"iterations": null,
"count_k": 30
},
"run_id": "20260623-202200-882c82",
"metrics": {
"bulk-append": {
"result": {
"k": 30,
"append_write": {
"n": 30,
"min_ms": 87.11,
"median_ms": 104.08,
"p90_ms": 190.63,
"p95_ms": 198.89,
"max_ms": 241.91,
"mean_ms": 117.22
},
"append_skip": {
"n": 30,
"min_ms": 47.57,
"median_ms": 51.42,
"p90_ms": 59.82,
"p95_ms": 61.57,
"max_ms": 73.49,
"mean_ms": 53.22
},
"skips_confirmed": 30,
"all_skipped_second_pass": true
},
"gates": [
{
"rule": {
"field": "all_skipped_second_pass",
"op": ">=",
"min": 1,
"why": "second pass of identical lines must be 100% idempotent skips (boolean true coerced to 1)"
},
"value": true,
"pass": true
}
]
}
},
"cleanup": {
"deleted": 1
}
}
@@ -0,0 +1,73 @@
{
"env": {
"date": "2026-06-23T20:21:36",
"endpoint": "https://echoapi.alwisp.com",
"commit": "af16598",
"echo_workers": 8,
"echo_timeout": 30,
"python": "3.10.12",
"iterations": 5,
"count_k": 30
},
"run_id": "20260623-202136-f2f4dc",
"metrics": {
"bulk-get": {
"result": {
"k": 30,
"workers": 8,
"serial": {
"n": 5,
"min_ms": 1520.47,
"median_ms": 1606.86,
"p90_ms": 1805.72,
"p95_ms": 1835.83,
"max_ms": 1865.94,
"mean_ms": 1658.6,
"warmup": {
"n": 1,
"min_ms": 1601.2,
"median_ms": 1601.2,
"p90_ms": 1601.2,
"p95_ms": 1601.2,
"max_ms": 1601.2,
"mean_ms": 1601.2
}
},
"concurrent": {
"n": 5,
"min_ms": 340.31,
"median_ms": 356.48,
"p90_ms": 358.82,
"p95_ms": 359.32,
"max_ms": 359.83,
"mean_ms": 351.42,
"warmup": {
"n": 2,
"min_ms": 353.43,
"median_ms": 434.94,
"p90_ms": 500.15,
"p95_ms": 508.3,
"max_ms": 516.45,
"mean_ms": 434.94
}
},
"speedup_ratio": 4.51
},
"gates": [
{
"rule": {
"field": "speedup_ratio",
"op": ">=",
"min": 1.5,
"why": "controlled-K concurrent vs serial; lower bar than full-vault since K is small"
},
"value": 4.51,
"pass": true
}
]
}
},
"cleanup": {
"deleted": 30
}
}
@@ -0,0 +1,35 @@
{
"env": {
"date": "2026-06-23T20:21:21",
"endpoint": "https://echoapi.alwisp.com",
"commit": "af16598",
"echo_workers": 8,
"echo_timeout": 30,
"python": "3.10.12",
"iterations": null,
"count_k": 30
},
"run_id": "20260623-202121-23b5ac",
"metrics": {
"bulk-put": {
"result": {
"k": 30,
"per_put": {
"n": 30,
"min_ms": 100.09,
"median_ms": 114.98,
"p90_ms": 212.46,
"p95_ms": 236.18,
"max_ms": 330.77,
"mean_ms": 143.25
},
"total_ms": 4297.5,
"puts_per_sec": 7.0
},
"gates": []
}
},
"cleanup": {
"deleted": 30
}
}
@@ -0,0 +1,36 @@
{
"env": {
"date": "2026-06-23T20:12:16",
"endpoint": "https://echoapi.alwisp.com",
"commit": "af16598",
"echo_workers": 8,
"echo_timeout": 30,
"python": "3.10.12",
"iterations": null,
"count_k": 50
},
"run_id": "20260623-201216-e77971",
"metrics": {
"cache": {
"result": {
"requested": 60,
"unique": 20,
"returned": 20,
"deduped": true,
"elapsed_ms": 307.13
},
"gates": [
{
"rule": {
"field": "deduped",
"op": ">=",
"min": 1,
"why": "read_many must collapse a 3x-duplicated path list to the unique set"
},
"value": true,
"pass": true
}
]
}
}
}
@@ -0,0 +1,76 @@
{
"env": {
"date": "2026-06-23T21:22:29",
"endpoint": "https://echoapi.alwisp.com",
"commit": "af16598",
"echo_workers": 8,
"echo_timeout": 30,
"python": "3.10.12",
"iterations": 3,
"count_k": 50
},
"run_id": "20260623-212229-8c3ce2",
"metrics": {
"expand-graph": {
"result": {
"subjects": [
{
"label": "hub-echo",
"query": "echo",
"neighbours": 120,
"serial_ms": 2227.67,
"concurrent_ms": 642.2,
"speedup": 3.47,
"ranking_identical": true,
"scores_identical": true
},
{
"label": "hub-prefs",
"query": "operator preferences",
"neighbours": 126,
"serial_ms": 2910.46,
"concurrent_ms": 698.8,
"speedup": 4.16,
"ranking_identical": true,
"scores_identical": true
}
],
"min_speedup": 3.47,
"all_ranking_identical": true,
"all_scores_identical": true
},
"gates": [
{
"rule": {
"field": "min_speedup",
"op": ">=",
"min": 2.0,
"why": "recall()'s graph layer must fetch each BFS hop concurrently (read_many), not serially per node; <2x means expand_graph regressed to the pre-fix serial walk"
},
"value": 3.47,
"pass": true
},
{
"rule": {
"field": "all_ranking_identical",
"op": ">=",
"min": 1,
"why": "the concurrent expansion must return the same ranked neighbours as the serial reference"
},
"value": true,
"pass": true
},
{
"rule": {
"field": "all_scores_identical",
"op": ">=",
"min": 1,
"why": "decayed scores must match the serial reference to within float tolerance"
},
"value": true,
"pass": true
}
]
}
}
}
@@ -0,0 +1,25 @@
{
"env": {
"date": "2026-06-23T20:20:57",
"endpoint": "https://echoapi.alwisp.com",
"commit": "af16598",
"echo_workers": 8,
"echo_timeout": 30,
"python": "3.10.12",
"iterations": null,
"count_k": 50
},
"run_id": "20260623-202057-c41a52",
"metrics": {
"index": {
"result": {
"script": "sweep.py",
"elapsed_ms": 4629.0,
"exit_code": 0,
"ok": true,
"stderr_tail": []
},
"gates": []
}
}
}
@@ -0,0 +1,25 @@
{
"env": {
"date": "2026-06-23T20:21:01",
"endpoint": "https://echoapi.alwisp.com",
"commit": "af16598",
"echo_workers": 8,
"echo_timeout": 30,
"python": "3.10.12",
"iterations": null,
"count_k": 50
},
"run_id": "20260623-202101-569382",
"metrics": {
"lint": {
"result": {
"script": "vault_lint.py",
"elapsed_ms": 5126.4,
"exit_code": 1,
"ok": true,
"stderr_tail": []
},
"gates": []
}
}
}
@@ -0,0 +1,40 @@
{
"env": {
"date": "2026-06-23T20:21:28",
"endpoint": "https://echoapi.alwisp.com",
"commit": "af16598",
"echo_workers": 8,
"echo_timeout": 30,
"python": "3.10.12",
"iterations": null,
"count_k": 50
},
"run_id": "20260623-202128-53b113",
"metrics": {
"lock": {
"result": {
"acquire_free_ms": 159.18,
"acquire_free_rc": 0,
"contended_ms": 57.89,
"contended_rc_expected_75": 75,
"release_ms": 132.92,
"ok": true
},
"gates": [
{
"rule": {
"field": "ok",
"op": ">=",
"min": 1,
"why": "free acquire returns 0 and a contended acquire fast-fails with exit 75"
},
"value": true,
"pass": true
}
]
}
},
"cleanup": {
"deleted": 0
}
}
@@ -0,0 +1,52 @@
{
"env": {
"date": "2026-06-23T20:12:12",
"endpoint": "https://echoapi.alwisp.com",
"commit": "af16598",
"echo_workers": 8,
"echo_timeout": 30,
"python": "3.10.12",
"iterations": 12,
"count_k": 50
},
"run_id": "20260623-201212-30c2b8",
"metrics": {
"pool-warmup": {
"result": {
"probe": "_agent/echo-vault.md",
"cold_ms": 163.25,
"warm": {
"n": 12,
"min_ms": 45.64,
"median_ms": 50.29,
"p90_ms": 52.51,
"p95_ms": 53.79,
"max_ms": 55.28,
"mean_ms": 50.26,
"warmup": {
"n": 1,
"min_ms": 51.68,
"median_ms": 51.68,
"p90_ms": 51.68,
"p95_ms": 51.68,
"max_ms": 51.68,
"mean_ms": 51.68
}
},
"cold_over_warm_ratio": 3.25
},
"gates": [
{
"rule": {
"field": "cold_over_warm_ratio",
"op": ">=",
"min": 1.5,
"why": "cold request must be meaningfully slower than warm \u2014 proves keep-alive is reusing the connection; a ratio near 1.0 means every request is re-handshaking (the pre-1.1.0 bug)"
},
"value": 3.25,
"pass": true
}
]
}
}
}
@@ -0,0 +1,32 @@
{
"env": {
"date": "2026-06-23T20:22:05",
"endpoint": "https://echoapi.alwisp.com",
"commit": "af16598",
"echo_workers": 8,
"echo_timeout": 30,
"python": "3.10.12",
"iterations": null,
"count_k": 10
},
"run_id": "20260623-202205-378725",
"metrics": {
"queue": {
"result": {
"k": 10,
"enqueue": {
"n": 10,
"min_ms": 0.07,
"median_ms": 0.08,
"p90_ms": 0.18,
"p95_ms": 0.2,
"max_ms": 0.22,
"mean_ms": 0.1
},
"pending_after_enqueue": 10,
"note": "flush replay intentionally not run against the live vault; enqueue path timed only. See README queue caveat."
},
"gates": []
}
}
}
@@ -0,0 +1,62 @@
{
"env": {
"date": "2026-06-23T20:17:09",
"endpoint": "https://echoapi.alwisp.com",
"commit": "af16598",
"echo_workers": 8,
"echo_timeout": 30,
"python": "3.10.12",
"iterations": 4,
"count_k": 50
},
"run_id": "20260623-201709-b08a2e",
"metrics": {
"read-full": {
"result": {
"note_count": 197,
"workers": 8,
"serial": {
"n": 1,
"min_ms": 11376.08,
"median_ms": 11376.08,
"p90_ms": 11376.08,
"p95_ms": 11376.08,
"max_ms": 11376.08,
"mean_ms": 11376.08
},
"concurrent": {
"n": 4,
"min_ms": 1559.79,
"median_ms": 1595.31,
"p90_ms": 1740.92,
"p95_ms": 1768.05,
"max_ms": 1795.17,
"mean_ms": 1636.4,
"warmup": {
"n": 2,
"min_ms": 1641.35,
"median_ms": 1652.91,
"p90_ms": 1662.17,
"p95_ms": 1663.32,
"max_ms": 1664.48,
"mean_ms": 1652.91
}
},
"speedup_ratio": 7.13,
"notes_per_sec_concurrent": 123.5
},
"gates": [
{
"rule": {
"field": "speedup_ratio",
"op": ">=",
"min": 1.8,
"why": "concurrent read_many must beat serial by the 1.1.0 concurrency margin; <1.8 means concurrency regressed"
},
"value": 7.13,
"pass": true
}
]
}
}
}
@@ -0,0 +1,360 @@
{
"env": {
"date": "2026-06-23T20:12:19",
"endpoint": "https://echoapi.alwisp.com",
"commit": "af16598",
"echo_workers": 8,
"echo_timeout": 30,
"python": "3.10.12",
"iterations": 6,
"count_k": 50
},
"run_id": "20260623-201219-819b5e",
"metrics": {
"resolve": {
"result": {
"cases": [
{
"mention": "echo",
"expect": "exact",
"expect_slug": "echo",
"resolved_slug": "echo",
"candidate_slugs": [
"2026-06-19-goldbrain-full-echo-architect",
"echo",
"echo-memory-codex-plugin",
"echo-plugin-build",
"echo-skill-improvements"
],
"verdict": "PASS",
"resolve_timing": {
"n": 6,
"min_ms": 0.0,
"median_ms": 0.0,
"p90_ms": 0.0,
"p95_ms": 0.0,
"max_ms": 0.0,
"mean_ms": 0.0,
"warmup": {
"n": 2,
"min_ms": 0.01,
"median_ms": 0.1,
"p90_ms": 0.17,
"p95_ms": 0.18,
"max_ms": 0.19,
"mean_ms": 0.1
}
},
"fuzzy_timing": {
"n": 6,
"min_ms": 1.35,
"median_ms": 1.49,
"p90_ms": 1.67,
"p95_ms": 1.68,
"max_ms": 1.68,
"mean_ms": 1.51,
"warmup": {
"n": 2,
"min_ms": 1.82,
"median_ms": 1.83,
"p90_ms": 1.84,
"p95_ms": 1.84,
"max_ms": 1.85,
"mean_ms": 1.83
}
}
},
{
"mention": "echo memory",
"expect": "candidates",
"expect_slug": "echo",
"resolved_slug": "echo",
"candidate_slugs": [
"echo",
"echo-memory-codex-plugin",
"echo-plugin-build",
"echo-skill-improvements",
"2026-06-19-goldbrain-full-echo-architect"
],
"verdict": "INFO",
"resolve_timing": {
"n": 6,
"min_ms": 0.55,
"median_ms": 0.56,
"p90_ms": 0.57,
"p95_ms": 0.58,
"max_ms": 0.58,
"mean_ms": 0.56,
"warmup": {
"n": 2,
"min_ms": 0.61,
"median_ms": 0.61,
"p90_ms": 0.61,
"p95_ms": 0.61,
"max_ms": 0.61,
"mean_ms": 0.61
}
},
"fuzzy_timing": {
"n": 6,
"min_ms": 0.97,
"median_ms": 0.99,
"p90_ms": 1.06,
"p95_ms": 1.09,
"max_ms": 1.11,
"mean_ms": 1.01,
"warmup": {
"n": 2,
"min_ms": 1.15,
"median_ms": 1.18,
"p90_ms": 1.2,
"p95_ms": 1.21,
"max_ms": 1.21,
"mean_ms": 1.18
}
}
},
{
"mention": "ECHO plugin",
"expect": "candidates",
"expect_slug": "echo",
"resolved_slug": "echo",
"candidate_slugs": [
"echo",
"echo-memory-codex-plugin",
"echo-plugin-build",
"2026-06-19-goldbrain-full-echo-architect",
"alabama-wisp-brand-docs"
],
"verdict": "INFO",
"resolve_timing": {
"n": 6,
"min_ms": 0.41,
"median_ms": 0.41,
"p90_ms": 0.42,
"p95_ms": 0.42,
"max_ms": 0.42,
"mean_ms": 0.41,
"warmup": {
"n": 2,
"min_ms": 0.42,
"median_ms": 0.45,
"p90_ms": 0.47,
"p95_ms": 0.48,
"max_ms": 0.48,
"mean_ms": 0.45
}
},
"fuzzy_timing": {
"n": 6,
"min_ms": 0.79,
"median_ms": 0.8,
"p90_ms": 0.88,
"p95_ms": 0.9,
"max_ms": 0.92,
"mean_ms": 0.83,
"warmup": {
"n": 2,
"min_ms": 0.89,
"median_ms": 0.89,
"p90_ms": 0.9,
"p95_ms": 0.9,
"max_ms": 0.9,
"mean_ms": 0.89
}
}
},
{
"mention": "goldbrain",
"expect": "exact",
"expect_slug": "goldbrain",
"resolved_slug": "goldbrain",
"candidate_slugs": [
"2026-06-19-goldbrain-full-echo-architect",
"goldbrain"
],
"verdict": "PASS",
"resolve_timing": {
"n": 6,
"min_ms": 0.0,
"median_ms": 0.0,
"p90_ms": 0.0,
"p95_ms": 0.0,
"max_ms": 0.0,
"mean_ms": 0.0,
"warmup": {
"n": 2,
"min_ms": 0.0,
"median_ms": 0.0,
"p90_ms": 0.0,
"p95_ms": 0.0,
"max_ms": 0.0,
"mean_ms": 0.0
}
},
"fuzzy_timing": {
"n": 6,
"min_ms": 0.73,
"median_ms": 0.75,
"p90_ms": 0.85,
"p95_ms": 0.88,
"max_ms": 0.91,
"mean_ms": 0.78,
"warmup": {
"n": 2,
"min_ms": 0.8,
"median_ms": 0.81,
"p90_ms": 0.82,
"p95_ms": 0.82,
"max_ms": 0.82,
"mean_ms": 0.81
}
}
},
{
"mention": "jason stedwell",
"expect": "exact",
"expect_slug": "jason-stedwell",
"resolved_slug": "jason-stedwell",
"candidate_slugs": [
"jason-stedwell",
"jason-mcp-gateway"
],
"verdict": "PASS",
"resolve_timing": {
"n": 6,
"min_ms": 0.0,
"median_ms": 0.0,
"p90_ms": 0.0,
"p95_ms": 0.0,
"max_ms": 0.0,
"mean_ms": 0.0,
"warmup": {
"n": 2,
"min_ms": 0.0,
"median_ms": 0.0,
"p90_ms": 0.0,
"p95_ms": 0.0,
"max_ms": 0.0,
"mean_ms": 0.0
}
},
"fuzzy_timing": {
"n": 6,
"min_ms": 0.69,
"median_ms": 0.72,
"p90_ms": 0.75,
"p95_ms": 0.75,
"max_ms": 0.75,
"mean_ms": 0.72,
"warmup": {
"n": 2,
"min_ms": 0.74,
"median_ms": 0.74,
"p90_ms": 0.75,
"p95_ms": 0.75,
"max_ms": 0.75,
"mean_ms": 0.74
}
}
},
{
"mention": "jason",
"expect": "candidates",
"expect_slug": "jason-stedwell",
"resolved_slug": "jason-stedwell",
"candidate_slugs": [
"jason-mcp-gateway",
"jason-stedwell"
],
"verdict": "INFO",
"resolve_timing": {
"n": 6,
"min_ms": 0.61,
"median_ms": 0.65,
"p90_ms": 0.66,
"p95_ms": 0.67,
"max_ms": 0.67,
"mean_ms": 0.64,
"warmup": {
"n": 2,
"min_ms": 0.66,
"median_ms": 0.68,
"p90_ms": 0.69,
"p95_ms": 0.69,
"max_ms": 0.69,
"mean_ms": 0.68
}
},
"fuzzy_timing": {
"n": 6,
"min_ms": 0.63,
"median_ms": 0.63,
"p90_ms": 0.65,
"p95_ms": 0.65,
"max_ms": 0.66,
"mean_ms": 0.64,
"warmup": {
"n": 2,
"min_ms": 0.68,
"median_ms": 0.69,
"p90_ms": 0.7,
"p95_ms": 0.7,
"max_ms": 0.7,
"mean_ms": 0.69
}
}
},
{
"mention": "zzqx nonexistent entity",
"expect": "miss",
"expect_slug": null,
"resolved_slug": null,
"candidate_slugs": [],
"verdict": "PASS",
"resolve_timing": {
"n": 6,
"min_ms": 0.62,
"median_ms": 0.63,
"p90_ms": 0.67,
"p95_ms": 0.67,
"max_ms": 0.68,
"mean_ms": 0.64,
"warmup": {
"n": 2,
"min_ms": 0.66,
"median_ms": 0.67,
"p90_ms": 0.67,
"p95_ms": 0.67,
"max_ms": 0.67,
"mean_ms": 0.67
}
},
"fuzzy_timing": {
"n": 6,
"min_ms": 0.61,
"median_ms": 0.62,
"p90_ms": 0.65,
"p95_ms": 0.65,
"max_ms": 0.66,
"mean_ms": 0.62,
"warmup": {
"n": 2,
"min_ms": 0.62,
"median_ms": 0.63,
"p90_ms": 0.64,
"p95_ms": 0.64,
"max_ms": 0.64,
"mean_ms": 0.63
}
}
}
],
"passes": 4,
"needs_tuning": 3,
"note": "verdicts are PASS/INFO only; promote to FAIL once the table is confirmed against the live vault"
},
"gates": []
}
}
}
@@ -0,0 +1,56 @@
{
"env": {
"date": "2026-06-23T20:22:15",
"endpoint": "https://echoapi.alwisp.com",
"commit": "af16598",
"echo_workers": 8,
"echo_timeout": 30,
"python": "3.10.12",
"iterations": null,
"count_k": 50
},
"run_id": "20260623-202215-7b414f",
"metrics": {
"soak": {
"result": {
"seconds": 22,
"iterations": 15,
"errors": 0,
"per_pass": {
"n": 15,
"min_ms": 1472.88,
"median_ms": 1551.67,
"p90_ms": 1648.45,
"p95_ms": 1702.66,
"max_ms": 1820.58,
"mean_ms": 1569.81
},
"early_mean_ms": 1575.63,
"late_mean_ms": 1564.72,
"drift_ratio_late_over_early": 0.99
},
"gates": [
{
"rule": {
"field": "errors",
"op": "<=",
"min": 0,
"why": "no read errors across the soak window \u2014 connection leaks/pool exhaustion would surface here"
},
"value": 0,
"pass": true
},
{
"rule": {
"field": "drift_ratio_late_over_early",
"op": "<=",
"min": 1.5,
"why": "late passes must not be much slower than early ones; >1.5 suggests a leak or degrading pool"
},
"value": 0.99,
"pass": true
}
]
}
}
}
@@ -0,0 +1,177 @@
{
"env": {
"date": "2026-06-23T21:18:12",
"endpoint": "https://echoapi.alwisp.com",
"commit": "af16598",
"echo_workers": 8,
"echo_timeout": 30,
"python": "3.10.12",
"iterations": 1,
"count_k": 50
},
"run_id": "20260623-211812-ea4b36",
"metrics": {
"subject-pull": {
"result": {
"subjects": [
{
"label": "apta",
"query": "APTA",
"resolve_floor": {
"n": 1,
"min_ms": 0.75,
"median_ms": 0.75,
"p90_ms": 0.75,
"p95_ms": 0.75,
"max_ms": 0.75,
"mean_ms": 0.75
},
"search_only": {
"n": 1,
"min_ms": 61.87,
"median_ms": 61.87,
"p90_ms": 61.87,
"p95_ms": 61.87,
"max_ms": 61.87,
"mean_ms": 61.87
},
"recall_total": {
"n": 1,
"min_ms": 2231.31,
"median_ms": 2231.31,
"p90_ms": 2231.31,
"p95_ms": 2231.31,
"max_ms": 2231.31,
"mean_ms": 2231.31
}
},
{
"label": "capmetro",
"query": "CapMetro",
"resolve_floor": {
"n": 1,
"min_ms": 0.03,
"median_ms": 0.03,
"p90_ms": 0.03,
"p95_ms": 0.03,
"max_ms": 0.03,
"mean_ms": 0.03
},
"search_only": {
"n": 1,
"min_ms": 57.73,
"median_ms": 57.73,
"p90_ms": 57.73,
"p95_ms": 57.73,
"max_ms": 57.73,
"mean_ms": 57.73
},
"recall_total": {
"n": 1,
"min_ms": 2116.06,
"median_ms": 2116.06,
"p90_ms": 2116.06,
"p95_ms": 2116.06,
"max_ms": 2116.06,
"mean_ms": 2116.06
}
},
{
"label": "hub-echo",
"query": "echo",
"resolve_floor": {
"n": 1,
"min_ms": 0.03,
"median_ms": 0.03,
"p90_ms": 0.03,
"p95_ms": 0.03,
"max_ms": 0.03,
"mean_ms": 0.03
},
"search_only": {
"n": 1,
"min_ms": 70.56,
"median_ms": 70.56,
"p90_ms": 70.56,
"p95_ms": 70.56,
"max_ms": 70.56,
"mean_ms": 70.56
},
"recall_total": {
"n": 1,
"min_ms": 2403.62,
"median_ms": 2403.62,
"p90_ms": 2403.62,
"p95_ms": 2403.62,
"max_ms": 2403.62,
"mean_ms": 2403.62
}
},
{
"label": "hub-prefs",
"query": "operator preferences",
"resolve_floor": {
"n": 1,
"min_ms": 0.04,
"median_ms": 0.04,
"p90_ms": 0.04,
"p95_ms": 0.04,
"max_ms": 0.04,
"mean_ms": 0.04
},
"search_only": {
"n": 1,
"min_ms": 2011.13,
"median_ms": 2011.13,
"p90_ms": 2011.13,
"p95_ms": 2011.13,
"max_ms": 2011.13,
"mean_ms": 2011.13
},
"recall_total": {
"n": 1,
"min_ms": 2994.84,
"median_ms": 2994.84,
"p90_ms": 2994.84,
"p95_ms": 2994.84,
"max_ms": 2994.84,
"mean_ms": 2994.84
}
},
{
"label": "leaf-rivnut",
"query": "rivnut torque spec",
"resolve_floor": {
"n": 1,
"min_ms": 2.15,
"median_ms": 2.15,
"p90_ms": 2.15,
"p95_ms": 2.15,
"max_ms": 2.15,
"mean_ms": 2.15
},
"search_only": {
"n": 1,
"min_ms": 2013.58,
"median_ms": 2013.58,
"p90_ms": 2013.58,
"p95_ms": 2013.58,
"max_ms": 2013.58,
"mean_ms": 2013.58
},
"recall_total": {
"n": 1,
"min_ms": 2371.32,
"median_ms": 2371.32,
"p90_ms": 2371.32,
"p95_ms": 2371.32,
"max_ms": 2371.32,
"mean_ms": 2371.32
}
}
]
},
"gates": []
}
}
}
@@ -0,0 +1,177 @@
{
"env": {
"date": "2026-06-23T20:20:23",
"endpoint": "https://echoapi.alwisp.com",
"commit": "af16598",
"echo_workers": 8,
"echo_timeout": 30,
"python": "3.10.12",
"iterations": 1,
"count_k": 50
},
"run_id": "20260623-202023-274ddd",
"metrics": {
"subject-pull": {
"result": {
"subjects": [
{
"label": "apta",
"query": "APTA",
"resolve_floor": {
"n": 1,
"min_ms": 0.97,
"median_ms": 0.97,
"p90_ms": 0.97,
"p95_ms": 0.97,
"max_ms": 0.97,
"mean_ms": 0.97
},
"search_only": {
"n": 1,
"min_ms": 71.55,
"median_ms": 71.55,
"p90_ms": 71.55,
"p95_ms": 71.55,
"max_ms": 71.55,
"mean_ms": 71.55
},
"recall_total": {
"n": 1,
"min_ms": 3836.47,
"median_ms": 3836.47,
"p90_ms": 3836.47,
"p95_ms": 3836.47,
"max_ms": 3836.47,
"mean_ms": 3836.47
}
},
{
"label": "capmetro",
"query": "CapMetro",
"resolve_floor": {
"n": 1,
"min_ms": 0.05,
"median_ms": 0.05,
"p90_ms": 0.05,
"p95_ms": 0.05,
"max_ms": 0.05,
"mean_ms": 0.05
},
"search_only": {
"n": 1,
"min_ms": 57.66,
"median_ms": 57.66,
"p90_ms": 57.66,
"p95_ms": 57.66,
"max_ms": 57.66,
"mean_ms": 57.66
},
"recall_total": {
"n": 1,
"min_ms": 2800.54,
"median_ms": 2800.54,
"p90_ms": 2800.54,
"p95_ms": 2800.54,
"max_ms": 2800.54,
"mean_ms": 2800.54
}
},
{
"label": "hub-echo",
"query": "echo",
"resolve_floor": {
"n": 1,
"min_ms": 0.02,
"median_ms": 0.02,
"p90_ms": 0.02,
"p95_ms": 0.02,
"max_ms": 0.02,
"mean_ms": 0.02
},
"search_only": {
"n": 1,
"min_ms": 67.39,
"median_ms": 67.39,
"p90_ms": 67.39,
"p95_ms": 67.39,
"max_ms": 67.39,
"mean_ms": 67.39
},
"recall_total": {
"n": 1,
"min_ms": 4114.19,
"median_ms": 4114.19,
"p90_ms": 4114.19,
"p95_ms": 4114.19,
"max_ms": 4114.19,
"mean_ms": 4114.19
}
},
{
"label": "hub-prefs",
"query": "operator preferences",
"resolve_floor": {
"n": 1,
"min_ms": 0.04,
"median_ms": 0.04,
"p90_ms": 0.04,
"p95_ms": 0.04,
"max_ms": 0.04,
"mean_ms": 0.04
},
"search_only": {
"n": 1,
"min_ms": 2013.4,
"median_ms": 2013.4,
"p90_ms": 2013.4,
"p95_ms": 2013.4,
"max_ms": 2013.4,
"mean_ms": 2013.4
},
"recall_total": {
"n": 1,
"min_ms": 4748.56,
"median_ms": 4748.56,
"p90_ms": 4748.56,
"p95_ms": 4748.56,
"max_ms": 4748.56,
"mean_ms": 4748.56
}
},
{
"label": "leaf-rivnut",
"query": "rivnut torque spec",
"resolve_floor": {
"n": 1,
"min_ms": 2.14,
"median_ms": 2.14,
"p90_ms": 2.14,
"p95_ms": 2.14,
"max_ms": 2.14,
"mean_ms": 2.14
},
"search_only": {
"n": 1,
"min_ms": 2014.69,
"median_ms": 2014.69,
"p90_ms": 2014.69,
"p95_ms": 2014.69,
"max_ms": 2014.69,
"mean_ms": 2014.69
},
"recall_total": {
"n": 1,
"min_ms": 4363.28,
"median_ms": 4363.28,
"p90_ms": 4363.28,
"p95_ms": 4363.28,
"max_ms": 4363.28,
"mean_ms": 4363.28
}
}
]
},
"gates": []
}
}
}
@@ -0,0 +1,50 @@
{
"env": {
"date": "2026-06-23T20:18:05",
"endpoint": "https://echoapi.alwisp.com",
"commit": "af16598",
"echo_workers": 8,
"echo_timeout": 30,
"python": "3.10.12",
"iterations": 2,
"count_k": 50
},
"run_id": "20260623-201805-53dcdb",
"metrics": {
"worker-sweep": {
"result": {
"note_count": 197,
"sweep": [
{
"workers": 1,
"median_ms": 11917.49,
"p95_ms": 11917.49
},
{
"workers": 2,
"median_ms": 5740.0,
"p95_ms": 5740.0
},
{
"workers": 4,
"median_ms": 3034.3,
"p95_ms": 3034.3
},
{
"workers": 8,
"median_ms": 1583.83,
"p95_ms": 1583.83
},
{
"workers": 16,
"median_ms": 1277.77,
"p95_ms": 1277.77
}
],
"knee_workers": 16,
"default_workers": 8
},
"gates": []
}
}
}
@@ -0,0 +1,545 @@
{
"title": "ECHO Memory Plugin \u2014 Performance Benchmark",
"subtitle": "Validation of the 1.1.0 concurrency and 1.2.0 entity-resolution releases",
"reference": "echo-v.05 @ af16598",
"status": "11/11 gate checks pass",
"summary": "Full-vault reads run 7.1x faster concurrent than serial (11.4 s down to 1.6 s, 197 notes). Entity resolution is sub-millisecond. Profiling traced recall() latency to serial graph expansion (not BM25); the fix makes expansion concurrent (3.5-4.2x, identical results). All 11 gate checks pass. Run live against echoapi.alwisp.com on 2026-06-23.",
"sections": [
{
"heading": "Test Environment",
"type": "kv",
"rows": [
{
"label": "Endpoint",
"value": "echoapi.alwisp.com (live)"
},
{
"label": "Vault size",
"value": "197 notes"
},
{
"label": "Plugin commit",
"value": "af16598"
},
{
"label": "Releases under test",
"value": "1.1.0 pooling + concurrency, 1.2.0 resolver"
},
{
"label": "Concurrency (default)",
"value": "ECHO_WORKERS = 8"
},
{
"label": "Socket timeout",
"value": "ECHO_TIMEOUT = 30 s"
},
{
"label": "Runner",
"value": "Python 3.10.12"
},
{
"label": "Date",
"value": "June 23, 2026"
}
]
},
{
"heading": "Headline Results",
"type": "table",
"columns": [
"Operation",
"Result",
"Verdict"
],
"rows": [
[
"Full-vault read (concurrent vs serial)",
{
"value": "7.13x",
"num": true
},
"Pass"
],
[
"Full-vault read throughput",
{
"value": "123.5 notes/s",
"num": true
},
"Pass"
],
[
"Cold vs warm request (keep-alive)",
{
"value": "3.25x",
"num": true
},
"Pass"
],
[
"Entity resolve (in-memory index)",
{
"value": "<1 ms",
"num": true
},
"Pass"
],
[
"Idempotent append skip",
{
"value": "100%",
"num": true
},
"Pass"
],
[
"Soak read errors (22 s)",
{
"value": "0",
"num": true
},
"Pass"
]
]
},
{
"heading": "Full-Vault Read \u2014 Concurrency Scaling",
"type": "table",
"columns": [
"Workers",
"Median (197 notes)",
"Speedup vs serial"
],
"rows": [
[
"1 (serial)",
{
"value": "11,917 ms",
"num": true
},
{
"value": "1.0x",
"num": true
}
],
[
"2",
{
"value": "5,740 ms",
"num": true
},
{
"value": "2.1x",
"num": true
}
],
[
"4",
{
"value": "3,034 ms",
"num": true
},
{
"value": "3.9x",
"num": true
}
],
[
"8 (default)",
{
"value": "1,584 ms",
"num": true
},
{
"value": "7.5x",
"num": true
}
],
[
"16",
{
"value": "1,278 ms",
"num": true
},
{
"value": "9.3x",
"num": true
}
]
]
},
{
"heading": "Subject Pulls \u2014 recall() (after concurrency fix)",
"type": "table",
"columns": [
"Subject",
"resolve()",
"search",
"recall() total"
],
"rows": [
[
"APTA",
{
"value": "0.75 ms",
"num": true
},
{
"value": "62 ms",
"num": true
},
{
"value": "2,231 ms",
"num": true
}
],
[
"CapMetro",
{
"value": "0.03 ms",
"num": true
},
{
"value": "58 ms",
"num": true
},
{
"value": "2,116 ms",
"num": true
}
],
[
"echo (hub)",
{
"value": "0.03 ms",
"num": true
},
{
"value": "71 ms",
"num": true
},
{
"value": "2,404 ms",
"num": true
}
],
[
"operator preferences (hub)",
{
"value": "0.04 ms",
"num": true
},
{
"value": "2,011 ms",
"num": true
},
{
"value": "2,995 ms",
"num": true
}
],
[
"rivnut torque spec (leaf)",
{
"value": "2.15 ms",
"num": true
},
{
"value": "2,014 ms",
"num": true
},
{
"value": "2,371 ms",
"num": true
}
]
]
},
{
"heading": "recall() Graph Expansion \u2014 Concurrency Fix",
"type": "table",
"columns": [
"Hub subject",
"Neighbours",
"Serial",
"Concurrent",
"Speedup",
"Results identical"
],
"rows": [
[
"echo",
{
"value": "120",
"num": true
},
{
"value": "2,228 ms",
"num": true
},
{
"value": "642 ms",
"num": true
},
{
"value": "3.47x",
"num": true
},
"Yes"
],
[
"operator preferences",
{
"value": "126",
"num": true
},
{
"value": "2,910 ms",
"num": true
},
{
"value": "699 ms",
"num": true
},
{
"value": "4.16x",
"num": true
},
"Yes"
]
]
},
{
"heading": "Bulk Write Operations",
"type": "table",
"columns": [
"Operation",
"Per-op median",
"Aggregate"
],
"rows": [
[
"PUT (read-back verified)",
{
"value": "115 ms",
"num": true
},
{
"value": "7.0 PUT/s",
"num": true
}
],
[
"Bulk GET \u2014 concurrent vs serial (K=30)",
{
"value": "356 vs 1,607 ms",
"num": true
},
{
"value": "4.51x",
"num": true
}
],
[
"APPEND \u2014 write",
{
"value": "104 ms",
"num": true
},
{
"value": "1 round-trip + GET",
"num": false
}
],
[
"APPEND \u2014 idempotent skip",
{
"value": "51 ms",
"num": true
},
{
"value": "100% skipped on re-run",
"num": false
}
]
]
},
{
"heading": "Concurrency, Locking & Resilience",
"type": "table",
"columns": [
"Check",
"Measured",
"Expected"
],
"rows": [
[
"Lock \u2014 acquire when free",
{
"value": "159 ms (rc 0)",
"num": true
},
"rc 0"
],
[
"Lock \u2014 contended acquire",
{
"value": "58 ms (rc 75)",
"num": true
},
"rc 75 fast-fail"
],
[
"Lock \u2014 release",
{
"value": "133 ms",
"num": true
},
"owned release"
],
[
"Offline queue \u2014 enqueue",
{
"value": "0.08 ms",
"num": true
},
"local write-ahead"
],
[
"read_many dedup (60 -> 20)",
{
"value": "deduped",
"num": false
},
"collapse to unique set"
],
[
"Soak drift (late vs early)",
{
"value": "0.99x",
"num": true
},
"<= 1.5x, no leak"
]
]
},
{
"heading": "Regression Gates (relative-ratio policy)",
"type": "table",
"columns": [
"Gate",
"Threshold",
"Measured",
"Result"
],
"rows": [
[
"read-full speedup",
">= 1.8x",
{
"value": "7.13x",
"num": true
},
"Pass"
],
[
"bulk-get speedup",
">= 1.5x",
{
"value": "4.51x",
"num": true
},
"Pass"
],
[
"pool warm-up cold/warm",
">= 1.5x",
{
"value": "3.25x",
"num": true
},
"Pass"
],
[
"append idempotency",
"100% skip",
{
"value": "100%",
"num": true
},
"Pass"
],
[
"soak errors",
"0",
{
"value": "0",
"num": true
},
"Pass"
],
[
"soak drift",
"<= 1.5x",
{
"value": "0.99x",
"num": true
},
"Pass"
],
[
"lock semantics",
"rc 0 / rc 75",
{
"value": "0 / 75",
"num": true
},
"Pass"
],
[
"read_many dedup",
"unique set",
{
"value": "20/20",
"num": true
},
"Pass"
]
]
},
{
"heading": "Findings",
"type": "olist",
"items": [
"Concurrency delivers as designed. Eight workers cut full-vault reads 7.5x; the curve is near-linear to 8 workers and flattens after (8->16 returns only 1.24x). The default of 8 is the right setting for this vault and link.",
"Keep-alive is confirmed live. A cold request costs 163 ms against a 50 ms warm median (3.25x). This is the direct measure that the 1.1.0 pooling fix removed the per-request TLS handshake that was timing out full-vault passes.",
"Entity resolution is effectively free. resolve() returns in under 1 ms across exact, alias, and shortened mentions. The 1.2.0 alias work resolves shortened names (\"echo memory\", \"ECHO plugin\", \"jason\") straight to the canonical note, so the anti-duplicate guard holds without a fuzzy fallback.",
"recall() latency was traced to the graph layer, not BM25. The BM25 index is already persisted and incrementally maintained (load 500 ms, score 0.1 ms). The cost was expand_graph fetching each neighbour serially \u2014 3.0 s for 126 nodes. Fix: the graph BFS now fetches each hop concurrently via the existing read_many. expand_graph is 3.5-4.2x faster with byte-identical ranking and scores; end-to-end recall() dropped from 2.8-4.7 s to 2.1-3.0 s per subject.",
"Full-vault maintenance scripts stay under the tool timeout. sweep.py runs in 4.6 s and vault_lint.py in 5.1 s on 197 notes. The original failure mode (passes exceeding the timeout and dropping the session) does not recur.",
"Write integrity holds. PUT verifies via read-back at 115 ms; APPEND is whole-line idempotent, skipping at 51 ms with zero duplicate writes on re-run. The advisory lock fast-fails a contended acquire with the expected exit 75."
]
},
{
"heading": "Recommendations",
"type": "olist",
"items": [
"Apply read_many to every code path that reads a set of known notes. Done for expand_graph (gated). Remaining: prefetch the _brief result bodies recall prints, and parallelize rebuild()'s vault walk.",
"Reuse one in-process read cache across a recall() call so load_index, expansion, and _brief don't re-fetch overlapping notes \u2014 this closes the remaining ~500 ms + serial _brief cost.",
"Make 'prefer read_many over a GET loop' a documented contract in the plugin's API reference; serial multi-note reads are a performance bug. The expand-graph gate enforces it for recall.",
"Hold ECHO_WORKERS at 8 (16 buys only 1.24x). Promote the resolve correctness table from INFO to FAIL now that live behavior is confirmed. Re-baseline at the next 1.x release or past ~400 notes."
]
},
{
"heading": "Method",
"type": "text",
"body": [
"Each metric was timed with a perf-counter harness that reuses the live ECHO client, so it exercises the real pooled and concurrent code path. Reads report median and p95 over repeated iterations after a discarded warm-up; write metrics ran in a disposable namespace under the advisory lock and were deleted on completion (zero residual files confirmed).",
"Gates use relative ratios rather than absolute milliseconds, so they stay valid regardless of the network the suite runs from. The harness, fixtures, baselines, and per-metric JSON are checked in under eval/perf/."
]
}
],
"note": {
"heading": "Next Step",
"body": "Prefetch recall()'s _brief reads and parallelize rebuild() via read_many, then re-run subject-pull to confirm recall drops toward ~1 s. expand_graph fix is local-only until ported to the canonical repo. No blockers in 1.1.0 / 1.2.0."
}
}
@@ -0,0 +1 @@
[20:14:00] read-full
@@ -0,0 +1,12 @@
#!/bin/bash
export ECHO_KEY_LEGACY_OK=1
cd "$(dirname "$0")"
{
echo "[$(date +%T)] read-full"; python3 bench.py read-full -n 3 --quiet --json-out results/m-read-full.json
echo "[$(date +%T)] worker-sweep"; python3 bench.py worker-sweep -n 4 --quiet --json-out results/m-worker-sweep.json
echo "[$(date +%T)] subject-pull"; python3 bench.py subject-pull -n 4 --quiet --json-out results/m-subject-pull.json
echo "[$(date +%T)] index"; python3 bench.py index --quiet --json-out results/m-index.json
echo "[$(date +%T)] lint"; python3 bench.py lint --quiet --json-out results/m-lint.json
echo "[$(date +%T)] DONE"
} > results/run.log 2>&1
touch results/DONE
@@ -247,27 +247,34 @@ def expand_graph(seeds, nmap: dict, base_scores: dict, max_hops: int = MAX_HOPS)
score_of = dict(base_scores)
seen = set(seeds)
results: dict[str, tuple[float, str]] = {}
dq = deque((s, 0) for s in seeds)
while dq:
path, hop = dq.popleft()
if hop >= max_hops:
continue
text = links.get_text(path)
if text is None:
continue
body = strip_frontmatter(text)
targets = set(links.all_wikilinks(body)) | set(links.source_notes(text))
parent = score_of.get(path, 1.0)
for t in targets:
tp = _resolve_target(t, nmap)
if not tp or tp in seeds:
# Breadth-first by HOP so each frontier's note bodies can be fetched concurrently
# (echo.read_many) instead of one blocking GET per node. Scoring is unchanged: a
# neighbour keeps the max decayed score over the paths that reach it, and non-seed
# parents score 1.0 exactly as the serial deque version did.
frontier = list(seeds)
for hop in range(max_hops):
if not frontier:
break
texts = echo.read_many(frontier)
next_frontier: list[str] = []
for path in frontier:
text = texts.get(path)
if text is None:
continue
body = strip_frontmatter(text)
targets = set(links.all_wikilinks(body)) | set(links.source_notes(text))
parent = score_of.get(path, 1.0)
decayed = parent * (GRAPH_DECAY ** (hop + 1))
if decayed > results.get(tp, (0.0, ""))[0]:
results[tp] = (decayed, path)
if tp not in seen:
seen.add(tp)
dq.append((tp, hop + 1))
for t in targets:
tp = _resolve_target(t, nmap)
if not tp or tp in seeds:
continue
if decayed > results.get(tp, (0.0, ""))[0]:
results[tp] = (decayed, path)
if tp not in seen:
seen.add(tp)
next_frontier.append(tp)
frontier = next_frontier
return sorted(results.items(), key=lambda kv: -kv[1][0])