Experiment benchmarks dev small observation run 01 - kmosoti/FabricO11y GitHub Wiki
Historical report imported 2026-10-10 from
docs/experiments/benchmarks/dev-small-observation-run-01.md. Original SHA-256:3e2dd81821fbffb787df86a5cb204e1a5c14b8868bf583ec20979561a3bb9df1. Measurements and outcomes retain their stated revisions. Links and local environment labels are normalized;$FABRIC_DATAis the mounted experiment drive. See evidence policy.
Development and small ingestion/consumer observation, run 01
Local native observations on 2026-10-04 under the
profile protocol (local checkout reference docs/experiments/benchmarks/dev-small-observation-protocol.md; not present at origin/main), using the current bounded
binary-spill sealer. Development and small are sequential finite workloads,
not independently qualified deployment products or minimum hardware claims.
The earlier results used another host/revision and
cannot establish a causal speedup here.
Both profiles met the registered finite criteria: all 3,000 / 300,000 source logs recovered exactly, all 183 / 3,640 Batches matched their ACK hashes, no delivery retries, no collection gaps, and no HTTP errors. Six final query chains matched the independent oracle, and all 5,313 distinct live returned log rows matched independent decoding. Negative controls rejected altered or missing query rows and altered rate, CPU and query-latency summaries.
Profile design
| Setting | Development | Small |
|---|---|---|
| Native Spindles | 1 | 20 |
| Ordinary / burst logs/s | 10 / 30 | 1,000 / 3,000 |
| Source volume | 3,000 logs | 300,000 logs |
| Load phases | 60 s ordinary, 60 s burst, 60 s recovery | same |
| Server / client CPU placement | 2 / 2 separate logical CPUs | same |
| Seal workers, journal file | 1, 64 MiB | same |
| Journal / retained Segment trial ceilings | 512 / 512 MiB | same |
| Each Spool ceiling | 256 MiB | same |
| Concurrent consumers | serial query mix plus tagged-record visibility poller | same |
These are workload/configuration profiles on an Intel i7-10750H host, using the mounted ext4 data drive. The overall cgroup enforces memory high 16 GiB, max 20 GiB, zero swap and 30 minutes. The server additionally has a 4 GiB address-space limit; each node 512 MiB. CPU placement does not reserve cores. The trial's short retained corpus does not test a 24-hour retention budget.
The query mix uses default Scan: recent logs, absent text, and CPU metric history, one request/second rotating shapes. A second client polls a unique source tag every five seconds, rotating nodes, at 250 ms intervals until seen. All source bodies are 900 bytes plus newline, with native metrics every 15 s. Successful Spool batch rate and successful log rate are separate: native batching adapts to how much source data each collection pass reads.
Results
| Observation | Development | Small |
|---|---|---|
| Server peak RSS, kernel high-water mark | 30.59 MiB | 484.51 MiB |
| Largest Spindle peak RSS | 5.57 MiB | 6.44 MiB |
| Aggregate Spindle sampled RSS peak | 5.57 MiB | 120.80 MiB |
| Cgroup peak reached by end of timed sampling | 70.86 MiB | 1.39 GiB |
| Server mean CPU, whole monitored window | 0.0078 cores | 0.3138 cores |
| All Spindles mean CPU | 0.0009 cores | 0.0315 cores |
| Producer/client/observer mean CPU | 0.0065 cores | 0.0741 cores |
| Largest sampled server CPU interval | 0.040 cores | 1.711 cores |
| Collection → server receive p99 | 22.69 ms | 38.25 ms |
| Collection → server ACK observation p99 | 27.81 ms | 54.20 ms |
| Source write → server receive p99 | 924.88 ms | 999.87 ms |
| Recent-log query p99, 67 requests | 17.11 ms | 278.98 ms |
| Absent-text query p99, 67 requests | 20.13 ms | 725.04 ms |
| CPU metric query p99, 66 requests | 11.47 ms | 229.60 ms |
| Sampled source → visible maximum, 36 tags | 280.78 ms | 1,894.23 ms |
| Sampled Spool observation → visible maximum | 263.63 ms | 914.02 ms |
| Sampled ACK observation → visible maximum | 254.00 ms | 906.50 ms |
| Published Segments | 0 | 5 |
| Maximum sampled pending sealed files | 0 | 1 |
CPU core equivalents are CPU-seconds/wall-second; 1.0 means one fully busy logical CPU. CPU windows use their actual sample span, approximately 59 seconds inside each 60-second source phase. Process readings are not atomic across processes or between RSS and CPU snapshots. Cgroup peak covers the entire service up to that sample, including startup and page cache. The whole small service, including subsequent recovery/oracle analysis, peaked at 1.9 GiB; that is different from the timed 1.39 GiB peak. Both used zero swap and recorded no memory high/max/OOM events. At small's highest current-memory sample, about 638 MiB was anonymous memory and 752 MiB file cache; this includes the clients and producer, not just the server.
| Phase | Dev Spool batches/s | Small Spool batches/s | Small committed logs/s | Small encoded Spool MiB/s | Small ACKs/s | Dev server CPU cores | Small server CPU cores |
|---|---|---|---|---|---|---|---|
| Ordinary | 1.00 | 19.97 | 998.33 | 1.094 | 19.95 | 0.0030 | 0.1740 |
| Burst | 1.00 | 20.00 | 2,996.67 | 3.270 | 19.97 | 0.0081 | 0.3782 |
| Recovery | 1.00 | 20.00 | 1,003.33 | 1.103 | 20.03 | 0.0122 | 0.4470 |
Batch count stayed almost constant while burst batch payload grew. Phase-edge differences are collection/delivery lag: all source data caught up by the end. Every observed delivery attempt returned an ACK. Small's maximum sampled committed-but-unacknowledged count was six across twenty nodes; final pending counts were zero. Reported post-collection unread source backlog was zero, which does not exclude lines waiting between collection polls. Small's source generator lateness p99 was 0.91 ms. Its Spool files peaked at about 161 MiB in aggregate; this includes retained acknowledged frames awaiting file reclaim.
Small accepted 328.25 MiB of exact encoded Batches. The server's whole-window
/proc counters recorded about 19.53 GiB logical bytes read and 882.82 MiB
logical bytes written; read_bytes was zero and write_bytes 897.06 MiB, with
334.05 MiB separately reported as cancelled writes. These counters are not
equivalent to device traffic; raw cgroup IO records both device-mapper and
underlying-device views, which must not be added together. This newly written,
cache-resident workload is not a cold-disk benchmark. Timed logical trial disk
footprint peaked at about 750.54 MiB.
Interpretation and remaining experiments
The bounded sealer coexisted with intake and two query clients on these finite loads. Small's process RSS was still about 485 MiB; the earlier 97% result was incremental builder heap, not a process-wide memory reduction. Development never sealed, so its low RSS cannot establish lifetime demand.
The most useful next comparison is consumer work over growing history. Small's server CPU rose from 0.174 cores in ordinary load to 0.447 during recovery, despite the source rate returning to 1,000/s; absent-text queries had the largest observed tail. Default Scan reading an increasing corpus is a plausible contributor. These observations do not isolate query CPU from sealing or prove the cause. Compare Scan/Walk and a query-off control with the same input and retained corpus before changing defaults or adding workers.
Still unrun: repeated trials/confidence estimates, jittered visibility sampling covering all collector phases, a development run through its first seal, longer retention/soak, cold storage, stricter deployment cgroup budgets, Spool-full/backpressure/outage tests, mixed trace/cardinality workloads and remote forwarding. These two samples neither find maximum sustainable rate nor complete bounded-sealer acceptance. The 512 MiB trial retention ceiling is not a recommendation for 24-hour production history.
Evidence and measurement boundaries
Raw development evidence (local evidence omitted from stage) and small evidence (local evidence omitted from stage) contain source and Batch hashes, per-record delivery clocks, complete native event streams, one-second rates, process/cgroup samples, query requests/answers, visibility targets, oracle verdicts, source snapshots and cleanup receipts.
summary.json contains phase CPU seconds/core equivalents, per-process user
and system CPU, peak sampled intervals, RSS, logical/physical IO deltas,
acceptance rates, latency distributions, errors and backlog. resources.json
retains cgroup anon/file/kernel memory, IO/CPU/memory pressure, swap and events.
Application metrics exclude the Python producer/clients, which have their own
process accounting. Whole cgroup memory includes both and the file cache.
Fresh-process recovery and oracle grading occur after timed resource sampling.
Spool cycle stdout is observed after successful append; ACK stdout is observed after the server response and before local ACK-cursor persistence. The exact recovered bytes supply encoded sizes. The ACK/attempt ratio has a denominator; a Spool append acceptance percentage does not, because cycle output records successful commits only. Native stderr and exits retain collection failures.
Visibility measures the first exact HTTP response for 36 sampled tags per profile. These tags recur at fixed five-second phases and may align with the one-second collector poll. Their distribution cannot stand in for all-record freshness p99. Preserve both collection-to-receive and source-to-receive populations, along with the sampled source/Spool/ACK-to-visible clocks. The 30-second threshold is experimental headroom, not an intentional delay or a new availability contract. HTTP elapsed time includes connection/TLS/JSON cost; response byte counts are reserialized JSON size, not network wire bytes.
Accounting counterexample
The independent accounting check initially failed on development: converting epoch nanoseconds to floating point excluded second zero from the normal-load summary. The counterexample (local evidence omitted from stage) retains the original summary and failed verdict. The fix classifies each raw event with integer timestamps, also respecting the final partial drain window. Development accounting was recomputed from intact archived events; its timed workload was not rerun. The independent check then exited 0 and rejected deliberately changed rate, CPU and query-p99 summaries. Small started with that correction. No oracle, expected answer or acceptance threshold changed.
Verification, interruption and cleanup
Release build, observer controls, both native trials, both final accounting
checks and the corrected development reanalysis exited 0. The initial
development accounting check exited 1 and remains preserved. The fast profile
completed all 17 checks with exit 0 under
fabric-work-d1571108988e4613b693f8cfdf0947b1; its service took 2 min 28.488 s,
used 4 min 56.287 s CPU and peaked at 260.7 MiB with zero swap. The subsequent
internet/power interruption was reported after both workload artifacts and
cleanup receipts existed; reconnecting retrieved the fast command's successful
completion. This was not a controlled power-loss experiment and supports no
additional recovery claim.
The manual documentation command
python3 tools/resource_group.py -- /tmp/fabric-bun-runtime/bun-linux-x64/bun tools/docs/check.mjs
exited 0, and git diff --check exited 0. The completed fast and resource
receipts are archived under
verification (local evidence omitted from stage). The fast
launcher's wall-clock receipt spans about 57 min 38 s across the interruption;
the service's reported execution runtime was 2 min 28.488 s. Preserve both
boundaries rather than treating disconnected wall time as measured CPU work.
A subsequent combined archive/validation command was not run: the launcher
exited 2 creating data-drive scratch with Read-only file system. findmnt
showed the drive as ro in this session. That observation does not distinguish
the session filesystem restrictions from a host-side remount; no filesystem
repair or uncapped fallback was attempted. Existing receipts and scripts were
copied into repository evidence with ordinary file operations. Read-only
inspection confirmed that both workload scratch directories and the completed
fast-check scratch directory were absent. The final explanatory documentation
addition was not rechecked after this new launcher failure.
Development and small cleanup receipts record removal of 12,244,731 and 530,040,784 bytes of remaining owned scratch, respectively. These are bytes present at cleanup, not peak disk footprint or total bytes ever created; the large recovered JSON stream had already been removed after grading. Native children exited cleanly. Source/Batch hashes, clocks, queries, failures and source snapshots remain in the evidence directory; shared build caches remain on the data drive. No remote hosts were used.
Reproduction and policy limitation
All commands use the resource launcher:
python3 tools/resource_group.py -- cargo build --offline --locked --release -p fabric_o11y --bin fabric-node -p fabric-server --bin fabric-server --example server_dump
python3 tools/resource_group.py -- python3 -B tools/bench/observe_dev_small.py --controls
python3 tools/resource_group.py -- python3 -B tools/bench/observe_dev_small.py --tier development
python3 tools/resource_group.py -- python3 -B tools/bench/recompute_profile_accounting.py docs/experiments/benchmarks/data/dev-small-observation-run-01/development
python3 tools/resource_group.py -- python3 -B tools/bench/check_dev_small_observations.py docs/experiments/benchmarks/data/dev-small-observation-run-01/development
python3 tools/resource_group.py -- python3 -B tools/bench/observe_dev_small.py --tier small
python3 tools/resource_group.py -- python3 -B tools/bench/check_dev_small_observations.py docs/experiments/benchmarks/data/dev-small-observation-run-01/small
Runners refuse existing evidence directories. A repeat needs a new run
destination and record, preserving these results. Runtime source and binaries
are frozen by hashes/snapshots; no production behavior changed for observation.
The observer, lifecycle harness and independent accounting checker are in
tools/bench. The only inter-trial harness edits corrected
accounting and changed the archived protocol's extension to .txt so relative
documentation links are not interpreted from the evidence directory.
The protocol content was frozen before either trial and copied with its hash
into both records. The requested separate policy commit is not made:
git add exited 128 because this session mounts .git read-only. This is an
unresolved repository-policy limitation, not a claimed successful commit.
Keep the protocol isolated when committing the prepared working-tree changes.