diff --git a/docs/BACKLOG.md b/docs/BACKLOG.md index 4c98d248..35520812 100644 --- a/docs/BACKLOG.md +++ b/docs/BACKLOG.md @@ -7295,3 +7295,41 @@ So `calling_ae_allowlist` **alone** satisfies a gate whose stated purpose is to **Related:** ADR 0155, `.github/workflows/dast.yml`, `scripts/security/dast_auth_sweep.py`, `scripts/security/route_gates.py`, `scripts/security/dast-policy.json`, `tests/test_dast_auth_sweep.py`, `tests/test_dast_claims.py`, [`Secure_Development_Standards`](Secure_Development_Standards.md) ยง6.1 / ยงA.6. **Source:** the empty ยง6.1 *Dynamic* tier row, filed and built 2026-07-31. + +## 320. windows-2025 MLLP ingress is ~10x slower than a healthy runner + +> ๐Ÿ“‹ **Filed 2026-08-01, not started.** Diagnosis only โ€” the CI symptom is already fixed (#115, `06fd327d`) by widening the reconcile's stranding budget. This item is the **underlying capacity fact**, which that fix does not address and deliberately did not try to. + +**Type:** CI/runner capacity โ€” not a correctness defect. No message was ever lost in any observed instance. + +**What:** the `test (windows-2025, py3.14)` leg cannot service the load smoke's offered rate. `tests/test_load_runner.py` offers **60 msg/s for 1.5s** (90 messages, `pool_size = 4`) at a listener whose ingress is **strictly serial per connection** โ€” `mllp.py:1433` is `read chunk โ†’ for each frame โ†’ await handler โ†’ next`, where the handler is the durable ingress commit the ACK depends on. Total ingress throughput is therefore `pool_size รท per-message-commit-latency`. On windows-2025 that product is under 60/s, so roughly half the offered run is never ingested inside the measurement window and strands unacknowledged at teardown. + +**Measured (2026-08-01), and one measurement RETRACTED โ€” read this before quoting a number.** + +The first write-up of this item claimed the CI signature reproduces on a healthy developer box purely by raising the offered rate, on the strength of a single 600/s run that stranded **456 of 900 (50.7%)** โ€” a near-exact match for windows-2025's 51.1%. **Four repeats of that same command on that same box then stranded 0, every time.** The outlier was taken while an unrelated test suite was running concurrently. + +So that reproduction is **withdrawn**. Stranding on a developer box is a **contention** artifact, not a clean function of offered rate, and n=1 is not a measurement โ€” which is exactly the failure mode this item is about, committed while documenting it. + +What the repeats support: + +| offered | runs | stranded | engine_read | +|---|---|---|---| +| 60/s | 1 | **0 (0.0%)** | 90 of 90 | +| 300/s | 1 | **0 (0.0%)** | 450 of 450 | +| 600/s | 5 | **0 in 4 runs**; 50.7% in the 1 contended run | ~899 of ~899 when unloaded | + +**The surviving claim is weaker and still worth acting on:** an unloaded box strands **zero** at up to 10ร— the CI profile's offered rate, while windows-2025 stranded ~51% at the profile's own **60/s** โ€” twice, on `9b03057f` and `56f7d240`, with **byte-identical** counters (90 sent / 44 acked / 46 stranded / 52 read). Byte-identical repetition is what rules out weather *on that leg*; it is not evidence about a developer box, and the earlier entry conflated the two. + +**Why it matters even though nothing is lost:** it recurs, it will recur on any profile whose offered rate approaches that leg's service rate, and it is invisible to a correctness check because delivery is complete every time (104 written, 104 received, backlog drained in 4.7s of a 30s bound). + +**Tooling:** `harness/load/ingress_probe.py` + `.github/workflows/ingress-rate-probe.yml` (dispatch-only) now sweep the rate across ubuntu / windows-2022 / windows-2025 with `--repeat`, so the next person reads a distribution instead of a lucky row. + +**Correcting the record:** `harness/load/report.py` previously justified the stranding budget with *"observed teardown stranding is ~16%, so half is ~3x the worst seen."* Both halves are wrong. **Healthy stranding at this rate is 0%**, not 16% โ€” the 16% figure was itself measured on a partially-saturated run โ€” and "half" was ~1.0x the worst seen by the time it red `main`, not 3x. + +**Not yet determined:** *why* that runner's per-message commit is ~10x slower. Disk/fsync characteristics of the hosted windows-2025 image, Defender scanning the temp SQLite DB, and CPU contention are all plausible; none has been measured, and it cannot be measured from outside the runner. + +**Adjacent finding, unverified:** at saturation `engine_read` (452) cleared the reconcile's unconditional anti-vacuity floor `read >= sent // 2` (450) by **two messages**. A breach of that floor is a hard failure no budget widening can rescue. A probe at 1200/s did *not* reproduce it, but that run is not comparable โ€” its drain timed out (`max_drain_seconds` observed `-1.0`) and it took the branch that skips the settle-poll. Untested, not disproven. + +**Related:** #115 (`06fd327d`, the budget fix), `harness/load/report.py` `_reconcile`, `harness/load/connscale/runner.py`, `harness/load/estate/runner.py`, `tests/test_load_runner.py`, `tests/test_harness_reconcile.py`, `messagefoundry/transports/mllp.py:1433`, and the sibling windows-2025 failure `test_coord_lock` (fixed in #109) โ€” a *different* mechanism on the same leg. + +**Source:** investigation of the `test_run_load_end_to_end_no_loss` failures on `main` at `9b03057f` and `56f7d240`, 2026-08-01.