backlog: file #320 — windows-2025 MLLP ingress is ~10x slower than a healthy runner - #117
Merged
Conversation
…healthy runner Diagnosis only; no code change. The CI symptom was fixed in #115 (06fd327) by widening the reconcile's stranding budget. This files the capacity fact that fix deliberately did not address. The load smoke offers 60 msg/s at a listener whose ingress is strictly serial per connection (mllp.py:1433 awaits the durable commit per frame), so total ingress is pool_size / commit-latency. On windows-2025 that is under 60/s. Reproduced the signature on a healthy box by raising the offered rate alone: 0% stranding at 60/s and at 300/s, then 50.7% at 600/s with engine_read 452 of 900 -- the same shape as windows-2025's 51.1% and 52 of 90 at 60/s. So that leg hits at 60/s what a healthy box hits at 600/s. Also corrects report.py's stated justification for the old budget: healthy stranding at this rate is 0%, not the "~16% worst seen" it cited, and "half" was ~1.0x that worst by the time it red main, not 3x. Records one adjacent unverified finding: at saturation engine_read cleared the unconditional `read >= sent // 2` floor by two messages, and a floor breach is a hard failure no budget widening can rescue. A 1200/s probe did not reproduce it but is not comparable (drain timed out, different code path). Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
The first write-up claimed the windows-2025 signature reproduces on a healthy developer box by raising the offered rate alone, citing one 600/s run that stranded 456 of 900 (50.7%). Four repeats of the same command on the same box stranded 0, every time; the outlier was taken while an unrelated test suite ran concurrently. Withdrawn. Stranding on a developer box is a CONTENTION artifact, not a clean function of offered rate -- and drawing a conclusion from one run is the exact failure mode this item documents, committed while documenting it. The surviving claim is weaker and still actionable: an unloaded box strands ZERO at up to 10x the CI profile's rate, while windows-2025 stranded ~51% at the profile's own 60/s twice (9b03057, 56f7d24) with byte-identical counters. Byte-identical repetition rules out weather ON THAT LEG; it says nothing about a developer box, and the retracted entry conflated the two. Also points at the probe + dispatch-only workflow now on ingress-rate-probe, whose --repeat exists so the next reader gets a distribution rather than a lucky row. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
wshallwshall
added a commit
that referenced
this pull request
Aug 1, 2026
test_backlog_status_check::test_the_real_backlog_satisfies_the_invariant fails on origin/main at ea05525 itself. #320 (filed in #117) opened with a `📋 Filed …` banner, which is not one of the five the invariant accepts (SHIPPED / DECLINED / RETIRED / Re-scored / Status). An invented emoji instead of the defined vocabulary. It fails in 0.6s inside every required test leg, so it red every PR that compiles the suite -- already blocking auto-merge on #119 and would have blocked #118. Corrected to `🚧 Status: OPEN INVESTIGATION …`, which is what the item is. The banner now also carries the two facts a reader needs: measurement tooling landed in #118, and the decisive experiment is blocked on an unregistered self-hosted WS2025 runner. Coverage hole recorded, not fixed here: #117 was docs-only, and ci.yml's `changes` job short-circuits that case (code == 'false' skips install/lint/type/test), so the guard that polices BACKLOG.md does not run on a PR that only changes BACKLOG.md. The one class of change the invariant exists to catch is the class that skips it. Follow-up: either count docs/BACKLOG.md as `code` for the short-circuit, or run the ledger/backlog guards in a cheap always-on leg.
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.
Diagnosis only. One file, one new BACKLOG entry, no code change.
The CI symptom was already fixed in #115 (
06fd327d) by widening the reconcile's stranding budget. That fix was correct — a saturated-but-lossless run is not a correctness failure — but it deliberately did not address why the runner saturates. This files that.The finding
tests/test_load_runner.pyoffers 60 msg/s for 1.5s (90 messages,pool_size = 4) at a listener whose ingress is strictly serial per connection —mllp.py:1433isread chunk → for each frame → await handler → next, and the handler is the durable commit the ACK depends on. Total ingress =pool_size ÷ per-message-commit-latency. On windows-2025 that product is under 60/s.Reproduced by raising the rate alone
Same profile, same code, same
run_loadpath, on a healthy developer box:windows-2025 at 60/s: 90 sent, 44 acked, 46 stranded (51.1%), read 52. That is the 600/s row at one tenth the offered rate.
windows-2025 hits at 60/s what a healthy box hits at 600/s.
Why file it when nothing was lost
The same counters recurred byte-identically on two different commits —
9b03057fand56f7d240, both 90/44/46/52. That is deterministic queueing, not runner weather, so 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 was complete every time: 104 written, 104 received, backlog drained in 4.7s of a 30s bound.It also corrects the record
harness/load/report.pyjustified the old 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% (the 16% was itself measured on a partially-saturated run), and "half" was ~1.0x the worst seen by the time it redmain, not 3x.Stated as unknown rather than guessed
Not determined: why that runner's per-message commit is ~10x slower. Disk/fsync on the hosted image, Defender scanning the temp SQLite DB, CPU contention — all plausible, none measured, and not measurable from outside the runner.
Adjacent, unverified: at saturation
engine_read(452) cleared the unconditional anti-vacuity floorread >= sent // 2(450) by two messages. A floor breach is a hard failure no budget widening can rescue. A 1200/s probe did not reproduce it, but that run is not comparable — its drain timed out (max_drain_seconds=-1.0) and it took the branch that skips the settle-poll. Recorded as untested, not disproven.Ledger
Number allocated atomically via
scripts/coord/alloc.ps1(not hand-picked).ledger_check.py --ciexits 0. #107's#1000floor is not yet onmain, so #320 is below it and will be grandfathered once merged — same sequencing as #318/#319.