test(loadharness)+docs: wire-path stream probes — R2 batching benchmark-proven at target scale

The WP-4 runs measured the stream path only up to the bounded send channel;
the probe deliberately substituted the socket hop with a controllable reader,
which is exactly where the R2 SiteStreamEventBatcher lives — so batching had
never been in any benchmark's hot path. The harness now also attaches per-site
wire probes: a real Kestrel h2c listener hosting the production
SiteStreamGrpcServer, dialed by the production SiteStreamGrpcClient with
batching negotiated, batch sizes read from the production batch_size histogram
via a MeterListener (--wire-probes-per-site, default 10; 0 restores the old
shape). Full-scale run (10x500x75, 20-min window, results doc §8 + raw JSON):
899,807 events in 12,462 frames (mean 72.2 ev/frame, p50=p99=75), wire P99
43.4 ms vs the 250 ms budget — every batch pays the full 25 ms linger since a
75-event burst never hits the 100 cap — zero drops, zero faults, offered load
100.0% of nominal with fan-out doubled. CI smoke Fact now asserts the wire
path carries traffic and observes frames.
This commit is contained in:
Joseph Doherty
2026-08-18 10:32:46 -04:00
parent d3be5f0527
commit e9e44a9ef0
14 changed files with 3400 additions and 8 deletions
@@ -191,7 +191,7 @@ Each is a deliberate, recorded trade — not an omission.
| D1 | **Sustained window shortened from 1 hour to 20 minutes** at full scale | Practicality on a single shared workstation. Memory growth is reported as a *slope* precisely so a shorter window still answers the leak question: a leak shows as a positive slope in 20 min just as in 60. The 1-hour run is a single flag — `--sustain-minutes 60` — and the exact command is recorded in the results doc. |
| D2 | **In-process, non-clustered sites** rather than 10 real two-node Akka clusters | A single box cannot host 20 clustered nodes at this scale. Cluster membership/failover is already measured on a real two-node rig (`FailoverTimingTests`, `docker/failover-drill.sh`); WP-4's question is about the hierarchy under the singleton. |
| D3 | **Simulated data source** instead of real OPC UA | No simulated adapter exists in the DCL, and 375k real monitored items would measure the OPC UA SDK. Injected at the documented `RegisterAdapter` seam, at the exact hand-off point the real adapter uses. |
| D4 | **gRPC socket replaced by a reader task** on the stream path | Required by the row-50 measurement itself: a stalled subscriber must be *held* stalled. All of `SiteStreamGrpcServer`'s per-subscription machinery above the socket is real. |
| D4 | **gRPC socket replaced by a reader task** on the stream path | Required by the row-50 measurement itself: a stalled subscriber must be *held* stalled. All of `SiteStreamGrpcServer`'s per-subscription machinery above the socket is real. **Partially retired 2026-08-18:** the harness now ALSO attaches per-site wire probes — real Kestrel h2c + real `SiteStreamGrpcClient` with R2 batching negotiated (`--wire-probes-per-site`, default 10) — so the batcher/serialization/HTTP/2 hop is measured too; the substituted-reader probes remain because the slow-subscriber scenario still needs them. Results doc §8. |
| D5 | **Instance Actors are `/user` children**, not children of a `DeploymentManagerActor` | Constructing them directly is what lets the ramp be timed in isolation and keeps the harness independent of the deploy round-trip. Visible only as `InstanceActorInitialized` dead letters, which the harness suppresses. No measured path differs. |
| D6 | **Akka logging at WARNING** | At 37,500 updates/s, INFO output would itself become a measured load. |
| D7 | `[xc-3]` site event logging volume, `[xc-4]` audit-log degradation, `[xc-5]` template flattening, `[xc-8]` UI responsiveness **not covered** | Out of scope for this harness: the first three need central MS SQL and the Template Engine (a central-cluster fixture, not a site one), and `[xc-8]` needs a browser. Recorded as residual scope in the results doc rather than silently dropped. |
@@ -275,7 +275,10 @@ Stated plainly so the evidence is not over-read:
- **Not a real-network run.** The gRPC, health-transport and S&F-to-central hops are
in-process. Serialization cost, TLS, WAN latency and socket backpressure are out of
frame; the *stream* path's backpressure was measured deliberately by substituting a
controllable reader for the socket (D4).
controllable reader for the socket (D4). **Partially superseded by §8 (2026-08-18):**
the site→central stream hop now also runs over a real loopback HTTP/2 socket with
the R2 batcher, protobuf serialization and Kestrel in the measured path. TLS and
WAN latency remain out of frame.
- **Not a real OPC UA run.** 375,000 monitored items were simulated at the adapter
callback (D3). The DCL above that callback is real and fully exercised.
- **Not 1 hour.** 20 minutes (D1). See finding F1 for the one question this leaves
@@ -323,6 +326,111 @@ dotnet test tests/ZB.MOM.WW.ScadaBridge.PerformanceTests \
`--help`-style knobs: `--sites`, `--instances-per-site`, `--tags-per-instance`,
`--tag-update-period-seconds`, `--settle-minutes`, `--sustain-minutes`,
`--sample-seconds`, `--health-interval-seconds`, `--debug-probe-interval-seconds`,
`--subscribe-settle-seconds`, `--stream-probes-per-site`, `--sf-drain-messages`,
`--slow-subscriber-events`, `--data-dir`, `--results`. An unknown key is rejected
rather than ignored, so a typo cannot silently change the measured scale.
`--subscribe-settle-seconds`, `--stream-probes-per-site`, `--wire-probes-per-site`,
`--sf-drain-messages`, `--slow-subscriber-events`, `--data-dir`, `--results`. An
unknown key is rejected rather than ignored, so a typo cannot silently change the
measured scale.
Since 2026-08-18 the default protocol also attaches 10 **wire** stream subscribers
per site (real Kestrel + real `SiteStreamGrpcClient`, §8); `--wire-probes-per-site 0`
reproduces the original in-process-only shape.
---
## 8. Wire-path run — R2 stream batching in the hot path (2026-08-18)
**Raw metrics:** `docs/plans/2026-08-18-loadharness-results-wire.json`
### 8.1 Why this run exists
Both prior runs (§2 and the §4 F1 1-hour sustain) measured the stream path only up
to the bounded send channel: `StreamSubscriberProbe` deliberately substitutes the
final socket hop with a controllable reader (deviation D4 — required by the row-50
slow-subscriber measurement). The R2 gRPC event batcher (`SiteStreamEventBatcher`,
merged `c75c79f8` on 2026-08-15, about an hour *after* the §2 run) lives exactly in
that substituted hop — so no benchmark run had ever exercised it, only R2's own
component-level measurement (worst-case P99 25.4 ms) and trickle-rate live traffic
on the rig (register row 48).
This run adds a **wire path** to the harness without touching the existing probes:
each site hosts the production `SiteStreamGrpcServer` on a real Kestrel HTTP/2 (h2c)
loopback listener (production `CommunicationOptions` defaults — batch cap 100,
window 25 ms, channel capacity 1000), and the production `SiteStreamGrpcClient`
dials in with `BatchingSupported = true`, one channel per site with 10 streams
multiplexed on it — the exact production shape and the exact production code on both
ends. Latency is recorded in the client callback, i.e. after protobuf
deserialization, batch unpacking and domain mapping. The batch-size figures are the
production `scadabridge.site.stream.batch_size` histogram itself, captured by a
`MeterListener`. Deliberately not in the path: `ControlPlaneAuthInterceptor`
(authenticates once per stream lifetime, nothing per-event) and TLS (production is
h2c too).
The 100 wire subscribers are attached **in addition to** the 100 in-process probes,
watching the same instances (same stride), so one run yields both distributions and
their difference isolates the wire hop's cost. Total hub fan-out is therefore
double that of the §2 run.
### 8.2 Environment
Identical posture to §1: same host (M4 Pro, 14 cores, 48 GB), .NET 10.0.5, server
GC, Release; the 8-node `docker/` rig stayed running throughout (D8); 20-minute
window after a 2-minute settle; harness at the state committed with this section.
### 8.3 Measured
| | in-process probes (§2 path) | **wire probes (new)** |
|---|---|---|
| Subscribers | 100 | 100 |
| Events delivered (window) | 899,807 | **899,807** |
| Events dropped / faults | 0 / — | **0 / 0** |
| Latency mean | 1.79 ms | **28.00 ms** |
| Latency P50 | 1.36 ms | **26.97 ms** |
| Latency P95 | 4.19 ms | **32.07 ms** |
| Latency P99 | 6.74 ms | **43.44 ms** |
| Latency P99.9 / max | 25.83 / 32.17 ms | **53.94 / 62.42 ms** |
Batching (production histogram, window deltas):
```
events 899,807 frames 12,462 → mean 72.20 events/frame (72x frame reduction)
batch size p50/p95/p99/max = 75/75/75/75 batched frames 11,998 single-event frames 464
server channel drops 0 stream faults 0 graceful completions 0
```
Offered load held at **37,497/s = 100.0% of nominal** with the doubled fan-out
(driver overrun 0.0 s, skipped 0). Whole-run CPU mean **66% of one core (4.7% of
the box)** vs 41% in §2 — the added ~25% of one core buys 10 Kestrel listeners, 100
live HTTP/2 streams, protobuf serialization of ~900 k events and the client-side
unpack. Working-set slope **−116 MB/min** (a large mid-window release; peak
3,413 MB), heap sawtooth with 5 gen-2 collects and endpoints 1,876→1,943 MB —
consistent with the §4 F1 resolution (row 29: not a leak).
### 8.4 Reading the numbers
- **The batcher engaged exactly as designed, at its natural batch size.** The
driver emits each instance's 75 tags contiguously within a slice, so a subscriber
receives one 75-event burst per 10 s period. 75 < the 100-event cap, so the
size cap never closes a batch early — nearly every burst becomes exactly one
75-event frame (p50 = p99 = max = 75). The 464 single-event frames are burst
stragglers that arrived after their batch's window closed.
- **The ~26 ms wire P50 is dominated by the deliberate linger, and that is the
documented trade.** Because bursts never hit the cap, every batch pays the full
25 ms `GrpcStreamBatchWindow` — this workload is the batcher's *worst-case latency
posture and best-case framing win* simultaneously. Wire P50 26.97 ms ≈ in-process
P50 1.36 ms + the 25 ms window + sub-millisecond socket/serialize cost. Against
the 250 ms P99 threshold the wire path passes with a **5.8× margin** (43.44 ms),
and the `CommunicationOptionsValidator` bound (window strictly < 250 ms) is
confirmed to compose: end-to-end latency stayed threshold-compliant with the
window fully paid on every frame.
- **Framing efficiency at scale is now measured, not extrapolated:** 899,807 events
crossed the wire in 12,462 frames. Pre-R2, the same window would have cost
899,807 frames.
- **Nothing degraded elsewhere.** The in-process path under doubled fan-out reads
P99 6.74 ms vs 4.57 ms in §2 — same order, still a 37× margin — and every §2
pass criterion that this run re-exercises (offered load, zero drops at healthy
subscribers, health reports, debug snapshots, S&F drain, slow-subscriber
isolation) repeated its pass.
**Verdict: PASS.** R2's negotiated batching is now benchmark-proven at target scale
over a real socket: 72× fewer frames, zero loss, zero faults, and worst-case-posture
latency 5.8× inside the budget.
File diff suppressed because it is too large Load Diff