test(perf): add ingest-ceiling harness for the audit write path - #6479
Draft
odedlaz wants to merge 4 commits into
Draft
test(perf): add ingest-ceiling harness for the audit write path#6479odedlaz wants to merge 4 commits into
odedlaz wants to merge 4 commits into
Conversation
The backend perf findings predict a hard ingest ceiling from the six sequential round trips in the audit log write, and nothing in this repo could measure it: there are no criterion benches, and perf/ only covers the Redis fan-out boundary. Three pieces. scripts/start-perf-ingest-rig.sh stands up one relay serving two communities resolved by Host, on the isolated buzz-harness stack. ingest_load drives them at independently settable rates. relay_ingest_ ceiling.py owns the experiment and exits non-zero on a violated contract, following relay_bus_scaling.py. Two measurement choices are load-bearing. The generator paces on a fixed schedule and reports latency from the intended slot as well as the actual send: a self-correcting timer measured from the send silently redefines the offered rate downward under saturation and keeps the queueing delay out of the percentiles. And the rig raises the admission limits, because at defaults one identity is capped at 50 events per 5s and a rejected EVENT gets a NOTICE with no OK, so a sweep would measure the limiter and draw a knee at a plausible-looking rate; the runner invalidates any run where the quota-rejection counter moves. Signed-off-by: Oded Lazar <olazar@neo.ai> Co-authored-by: Oded Lazar <olazar@neo.ai>
Two review panels found that the harness could report a ceiling from evidence that did not support one. The pass predicate was the load-bearing problem: it derived a threshold from the spread of repeated runs, which is ~0 where the metric is pinned at 1.0 and is the system-under-test's own throughput variability where it is not. Either placement makes it meaningless. The contract is now that the two arms separate: repeats give each arm an interval, and the verdict asks whether the difference between audit-off and audit-on excludes zero at some rate. Nothing gates on the knee, which is a grid point rather than a measurement, and no comparison treats overlapping intervals as evidence of equality. Also closed, all of them paths by which a run could pass without establishing anything: a single-arm dataset returning ok with attribution never tested, and reporting an audit-off null indistinguishable from a control that never ran; --combine accepting halves from different durations, rate grids, limiter settings or revisions; only quota rejections invalidating a cell, when unavailable rejections take the same NOTICE-without-OK path and are load-correlated, so they can forge a knee that survives repeats; and the generator dying with its error context captured into an exception. The bounded audit channel lends a cell up to its full depth in accepted events before backpressure -- measured as exactly +1000 from an empty start and 0 from a full one. That is a bias, identical across repeats, so more repeats converge on a wrong number. Cells now carry outstanding-work and busy-fraction readings, and the worker-rate estimate is drawn only from cells where the worker was demonstrably busy in steady state. Accepted throughput stays the arm-separation quantity, because the audit-off arm has no worker and therefore no completion series at all. Trailer order corrected here rather than by amending the pushed commit, which would need a force-push. Co-authored-by: Oded Lazar <olazar@neo.ai> Signed-off-by: Oded Lazar <olazar@neo.ai>
The steady-state gate made every genuine saturating dataset fail its own contract. Three of the harness's own parts composed into it: a cell is not steady if outstanding audit work moves by more than a fraction of the channel's depth, any non-steady cell failed the run, and a saturating cell starting with that channel empty banks its whole depth in accepted events. The first repeat of the first saturating rate always starts empty, because the unsaturated rates before it never filled the channel, so it always banked and always failed. A rate just above the drain rate is worse: it accumulates over several repeats, and that is the transition region where the bracket is decided. A cell that cannot be evidence is now dropped from the arm intervals and the worker-rate estimate and listed with its reason. That also removes the bias rather than only the failure -- the banked credit lands in accepted, inflating that cell's accepted/offered, so it did not belong in the interval either. A rate needs two surviving repeats per arm to yield a difference interval, and the run fails when no rate clears that, so exclusion cannot become a way to pass by discarding almost everything. An audit *enqueue* failure stays fatal: send errors only when the receiver is dropped, so the worker is gone and later cells are suspect too. The suite had been green because the model set every cell steady, including at a rate above its own ceiling. It now runs the queue forward across repeats and reproduces the fill, so the green path is tested against the physics. Also: two-community cells carry problem and steady annotations, since they are report-only and an unannotated contaminated cell is how a bad number gets quoted later; and the script header no longer documents the unguarded kill the code stopped performing. Co-authored-by: Oded Lazar <olazar@neo.ai> Signed-off-by: Oded Lazar <olazar@neo.ai>
Two review panels found paths by which the harness could be internally precise and still answer the wrong experiment. The three that could flip the verdict: The control was never required to be positive. Audit-off only had to beat audit-on, so two collapsed arms separated cleanly and passed -- which does not show that removing the audit path restores ingest. It now has to hold its offer at the primary contrast, and its audit series has to stay flat, because the rig JSON claiming audit is off is a claim about how the relay was started and under --skip-relay nobody verified it. The pass ran an unadjusted interval at every rate and accepted any positive one. Measured against this module with identical populations, five rates and n=5, that passes 9.8% of the time rather than 5%. There is now one predeclared primary contrast at the highest comparable rate; a reverse separation anywhere contradicts the hypothesis instead of being ignored. Counter deltas were read around the whole subprocess while every rate divided by the post-connect window, so backlog draining during setup landed in the delta but not the divisor -- overstating completions, allowing a busy fraction above 1.0, and feeding the exclusion decision. The generator now samples the relay's counters at its own window edges over a plain TCP GET, needing no new dependency, and a cell without aligned samples is not evidence. The default grid also never reached saturation. Its top rate was set before any drain measurement existed and sat at 81-102% utilisation, so the only informative cell was a coin flip and a miss printed "the audit path is not shown to limit ingest" -- a false negative phrased as a conclusion. The grid now spans the measured band, and more importantly a run that never reaches a busy worker reports inconclusive rather than exonerating the audit path, so the next stale constant cannot be read as a finding. Also: combine validates the cell payload against the identity it claims rather than only comparing identities; the identity carries a working-tree digest and whether the database was reset, so two dirty trees at one commit are two builds and a pair where only one arm was reset is not one experiment; worker rates are reported per rate instead of pooling load regimes; the sparse t-table rounds to the conservative side; a generator that misses its scheduled slots disqualifies its cell; and the pid guard matches this rig's exact binary path. Co-authored-by: Oded Lazar <olazar@neo.ai> Signed-off-by: Oded Lazar <olazar@neo.ai>
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
The backend perf deep-dive predicts a hard ingest ceiling from the six sequential round trips in
AuditService::log, which sits on the OK path. Nothing in this repo could measure it: there are no criterion benches, andperf/deliberately covers only the Redis fan-out boundary. This adds the missing instrument. No production code changes.Three pieces:
scripts/start-perf-ingest-rig.sh— one relay process serving two communities resolved byHost(a.localhost/b.localhostboth reach 127.0.0.1, so the URL host is the header), on the isolatedbuzz-harnessCompose project.--skip-relayattaches to a relay someone else supervises.crates/buzz-test-client/src/bin/ingest_load.rs— paced generator driving those communities at independently settable rates from one clock.perf/relay_ingest_ceiling.py— owns the experiment and the verdict, exits non-zero on a violated contract,--mode modelfor review without services. Followsrelay_bus_scaling.py.Two measurement choices that carry the result
Pacing. The generator advances a fixed schedule and never rebases it on the response, and it reports latency from the intended slot as well as from the actual send. A generator that paces with a self-correcting timer and times from the send — the shape
wamp_bench.rsuses — silently redefines its own offered rate downward when the relay slows, caps throughput atconnections / latency, and keeps the queueing delay out of its percentiles. That hides the damage exactly when the damage is the measurement.Admission limits. The rig raises them, and this is not incidental. At defaults one identity is capped at 50 events per 5s (
human_ws_events_per_sec= 10, widened byws_admission_budgetinto a 5s window), and a rejected EVENT gets aNOTICE, which carries no event id — so a NIP-01 client waiting forOKblocks for its whole publish timeout instead of learning it was rejected. Measured here: 50 events land in 2.4s, the next send stalls 30s, the run self-truncates, and the surviving numbers read as a textbook saturation knee at ~1.5/s. A sweep at defaults measures the limiter. The runner therefore invalidates any run wherebuzz_admission_rejections_total{reason="quota"}moves, and prints the configured limits in the run metadata.What it measured, and what has since been withdrawn
Standing: the arm separation. With the audit log enabled, delivered/offered collapses
to 0.62 at 800/s and 0.25 at 1600/s. With
BUZZ_AUDIT_ENABLED=false, the same ratesdeliver 1.0000, and
audit_logstayed flat at 63,723 rows through that sweep, so thecontrol is verified positive rather than assumed. Round 1 also recorded zero quota
rejections, zero admission-
unavailablewarnings across 302,531 relay log lines, andzero rejected events or transport errors across all 20 runs. Splitting the same offer
across two communities did not raise the combined ceiling.
Withdrawn: every absolute ceiling figure, including the "~400–494/s plateau" and the
round-trip time back-solved from it. Review found that an initially-empty 1000-slot audit
queue lends up to
1000/durationfree accepts to every fixed-duration run — +100/s at10s — so the numbers are biased upward by an unmeasured amount, consistently, in a way no
number of repeats corrects. The repeats were also run back-to-back inside the queue's
drain window, so they inherited each other's backlog rather than being independent draws.
That was a defect in this harness, and it is fixed in
ac64b0bf0along with the rest of two review panels' findings.What changed after review
The pass predicate was the load-bearing problem. It derived a threshold from the spread of repeated runs, which is ~0 in the region where accepted/offered is pinned at 1.0 and is the system's own throughput variability in the region where it is not — so no placement of that control made it mean anything. The contract is now that the two arms separate: repeats give each arm an interval and the verdict asks whether the difference between audit-off and audit-on excludes zero at some rate. Nothing gates on the knee, and no comparison reads overlapping intervals as evidence of equality.
Also closed, each of them a route to passing without establishing anything:
--combineaccepting halves from different durations, rate grids, limiter settings or source revisions;unavailablerejections take the same NOTICE-without-OK path and cost Redis round trips against the rig the sweep is loading, so they are load-correlated and can forge a knee that survives repeats;Cells now carry
outstanding_deltaandaudit_busy_fraction, and the worker-rate estimate is drawn only from cells where the worker was demonstrably busy in steady state. The steady-state criterion is stability, not emptiness — a saturating cell settles with the channel full, and a gate demanding an empty queue would have made every cell that matters unmeasurable.Scope and limits, stated in the doc
The harness characterizes the mechanism, not deployability at scale — a raised-limit sweep cannot show that a real community reaches these rates, since production defaults would need hundreds of concurrent identities each paying its own admission round trip. Sensitivity to round-trip latency is unmeasured; a sweep of injected delays should predeclare six added exchange delays plus a durability intercept, since disabling
synchronous_commitremoves the flush wait but not the COMMIT exchange. And the per-community lock ceiling is structurally blind in this round: the worker ceiling is lower and masks it, so a passing run is not evidence the lock is fine.Verification
cargo clippy --workspace --all-targets -- -D warningsandcargo fmt --all --checkclean;cargo test -p buzz-test-clientgreen;python3 -m unittest discover -s perf -p 'test_*.py'51 tests green;shellcheckclean. The unit tests pair every passing case with a mutant that must fail — a lone dip that must not count as a knee, a control that did not run, an arm separation in the wrong direction, a cell that banked the whole channel, a--combineacross mismatched durations — because a contract that cannot go red is decoration.Larger than the usual single-pass PR, and I'd rather not split it: the generator, the rig, and the verdict logic are not independently useful, and the doc and the mutant tests are the parts that make the numbers trustworthy.