feat(engine): count the requests an io_uring hand-off drops, and the hand-offs made with an op in flight (celeris#657) - #676
Conversation
…ars (celeris#657) recordErr guarded the whole tally on map SIZE while its keys embedded the client's ephemeral port, so it stopped counting after ~200 connections -- repeats of a key already held included. Every figure read off it past that point was a floor, and a "0 of kind X" reading was not concludable at all. Counting is now unbounded and per class (errClass662 drops the addresses); only the verbatim exemplar set is capped, and a key already held keeps counting. dumpErrSamples prints the class census first, because it is the only complete tally. This is W3 of the celeris#657 instruments (PR-1). The hunk is ported byte-for-byte from 3a195c0 on the celeris#662 branch, so rebasing that branch onto a main that has it is a no-op for this file. Refs #657 Refs #662
…d hand-offs made with an op in flight (celeris#657) A reverse (io_uring->epoll) hand-off detaches a connection with its recv still armed. Closing the original descriptor does not end an io_uring recv, so until the cancel lands that recv keeps reading the socket epoll now owns -- and if its SQE had not reached the kernel yet, it resolves the fd NUMBER at submit time, which the next hand-off's dup may already have reused for a different connection. A recv that then completes with data has consumed a request some client is still waiting on. Its CQE carries the old (fd, generation), so staleConnCQE drops it as stale -- with no counter at all. The #624 hand-off ledger balanced exactly through every such loss. Two witnesses, observation only: * staleRecvData{Closed,Transplanted,Unattributed}: a stale recv CQE with res > 0, split by what closedOps holds for its identity -- a conn this worker closed, one it handed off, or nothing. The hand-off sites now register their identity through noteHandedOffInflight, which is noteClosedInflight plus a flag on the entry; the kernel accounting and the release gate are unchanged. The class is read BEFORE noteStaleTerminalOp, which retires the entry on the terminal CQE. * handoffInFlight: a hand-off (tryTransplant or finishAsyncTransplant) that detached a conn with recvArmed, kernelInflight != 0 or a SEND_ZC notification pending -- the precondition of every loss above. Neither is on the per-request path: the first runs only for stale CQEs, the second once per hand-off. The set is nil-safe, like the #586/#591 witnesses, and is wired to Metrics() in the next commit. Tests, one per counter and each failing if its increment is removed: the transplanted class through tryTransplant and through finishAsyncTransplant end to end on a real ring, the closed and the unattributed class, a negative control (no data, a stale SEND, a live conn's own CQE), and the in-flight witness at both hand-off sites, each predicate term on its own. Refs #657
…EngineMetrics StaleRecvDataClosed, StaleRecvDataTransplanted, StaleRecvDataUnattributed and TransplantHandoffInFlight join the #624 hand-off ledger in EngineMetrics, wired exactly like the Transplant* counters: one engine-wide set in the io_uring engine's metrics, a pointer to it handed to every worker by createWorkers, read in Metrics(), and summed over both sub-engines by the adaptive engine. The adaptive sum matters more here than for most fields: the stale CQEs of a revert's hand-offs arrive on the sub-engine that made them, which is the standby by then, so reporting only the active side would read zero through the very loss these exist to report. io_uring-only; zero on epoll and std. This is what lets the probatorium validator report the loss on both cluster arches before the fix lands. Refs #657
… (celeris#657) A unit test for W3: far more distinct error keys than errExemplarCap, as under load, must still give an exact total and exact per-class counts, a repeat of a retained exemplar must keep counting, and only the exemplar set may stop growing. It fails against the old size-guarded recordErr. Kept out of ramp_transplant_test.go so that file stays byte-identical to 3a195c0's and the celeris#662 rebase stays trivial. Refs #657
…57 flag in its padding The hand-off flag added for the stale-recv witness sat after the slice header and grew the entry from 32 to 40 bytes. It fits in the padding after inflight; an instrument should not change the layout of what it observes. Refs #657
…equest, and name the stale read none of the three counts (celeris#657)
StaleRecvDataClosed was documented as benign ("nothing a live client is
waiting on"). Two routes into it contradict that. hijackConn registers
through noteClosedInflight like the close paths, and after a hijack the
socket lives on under the hijacker's net.Conn, so a recv that completes
with data before its cancel lands has read the first bytes of a
connection its client is still using. After a close, a recv that had
not reached the kernel yet resolves the fd number when it does, and a
new connection may hold that number by then.
The three counters were also documented as if they covered every stale
read. A stale completion whose (fd, generation) equals the current
occupant's, a generation collision, takes staleConnCQE's live branch
and none of them counts it. That needs the process-wide 32-bit
generation sequence to wrap while the op is in flight, and it predates
these counters. Both the EngineMetrics doc and the handoffLossStats doc
now say so.
Comments only; no code change.
…ts own (celeris#657) TestTransplantHandoffInFlightCountsTryTransplant claimed to test each term of `recvArmed || kernelInflight != 0 || zcNotifPending` on its own, but its "recv armed" state also set kernelInflight to 1. A mutant that drops `cs.recvArmed ||` survived every test. The recv-armed state now has kernelInflight at 0. Each of the three single-term states differs from "nothing in flight" in exactly one term. A fifth state keeps the usual shape, a recv armed and counted. The predicate keeps all three terms. With consistent accounting, kernelInflight != 0 implies the other two. Every recv arm counts itself, and a SEND_ZC keeps its count until the notification CQE that clears zcNotifPending. A generation-collision misroute (staleConnCQE's KNOWN RESIDUAL) can still take kernelInflight to 0 while a recv is armed or a notification is pending. The three terms are also the condition the fix refuses a hand-off on. noteHandoffInFlight's comment now says this.
…rows from 16 to 20 on 32-bit (celeris#657) The handoff flag was said to keep closedOpsEntry at 32 bytes, "checked with unsafe.Sizeof", but nothing kept the check. On 32-bit platforms the claim was also wrong. There is no padding after inflight (an int32 plus a 12-byte slice header is 16 bytes), so the flag grows the entry from 16 to 20 bytes. TestClosedOpsEntryStaysThirtyTwoBytes, built only for linux/amd64 and linux/arm64, fails if the entry, or the same entry without the flag, is not 32 bytes. The field comment now states both sizes.
…celeris#657) The PR says a stale multishot recv counts once per data CQE, including the intermediate F_MORE completions. No test and no integration run had exercised that path. Every one of the 1024 stale recv completions the join probe recorded was terminal. TestStaleRecvDataCountsEachMultishotCompletion feeds a handed-off identity two F_MORE data completions and then a terminal one. Each must count as Transplanted, and the identity must stay registered until the terminal CQE retires it.
…#657 witness tests' skips Five of the celeris#657 witness tests can skip. Four get their ring from newTestRing, which skipped whenever NewRing failed, with no way to forbid it. TestWorkersShareTheHandoffLossWitnesses skipped on its own when it could not build an engine or its workers. In a job that runs ./engine/iouring without -v, a skip prints nothing and the package still reports ok. newTestRing and that test now skip through skipOrFail656. It still skips by default, and it fails when CELERIS_REQUIRE_IOURING_WORKERS=1, the variable the `iouring` job already uses for the celeris#656 tests. The only CI step that sets the variable today selects only the three celeris#656 tests, so none of newTestRing's other callers change in CI.
…, skipping forbidden The unit job runs ./engine/iouring without -v, so its output shows only "ok" for the package. Five of the celeris#657 hand-off loss witness tests can skip, and a skip there would pass unseen. That is how the celeris#656 leak shipped. A new unit-job step runs all eleven witness tests by name, with the interlock the `iouring` job established (celeris#664): - `-v`, and an anchored `-run` built from the name list; - CELERIS_REQUIRE_IOURING_WORKERS=1, so an environment skip is a failure; - a tally of top-level `=== RUN Name` lines and `--- PASS: Name (` lines, both of which must equal the number of names; - zero `--- SKIP` lines at any indentation. The PASS pattern ends with ` \(` because go test prints the elapsed time after the name. A pattern anchored with `$` right after the name can never match that line. memlock stays at the runner's 8 MiB, the shape the root race step runs these tests in. They need one ring, not a worker per 12 MiB.
… its test's comment (celeris#657) The field doc no longer says Closed is benign: hijackConn registers through noteClosedInflight too, and a recv that reaches the kernel after a close can read a reused fd number. The comment on TestStaleRecvDataCountsAClosedConn still said "the benign class". It now says what the test checks, a close-registered identity, and points to the field doc for the cases that are not benign. Comment only.
…mirror struct (celeris#657) golangci-lint's `unused` flagged the two fields of the local flag-less struct TestClosedOpsEntryStaysThirtyTwoBytes compared against, because they existed only for unsafe.Sizeof. The test now reads the real struct. The entry must be 32 bytes, handoff must sit right after inflight, and conns must stay at offset 8, where it is without the flag. A flag placed anywhere else still fails the test.
Review round 2: all five fixes pushed, and an answer to each of D1-D5The head is now 1aca300, a fast-forward from 6d8d822 with eight new commits and no rebase (main is still 985a386). The PR body is updated to match. Fixes
I kept all three terms of the in-flight predicate rather than simplifying to Two more fixes came out of this round. Mutation now stands at 23/23 KILLED, with the unmutated control at 11/11 and 3/3. golangci-lint 2.13.2 reports 0 issues on linux/amd64 and arm64. actionlint 1.7.12 with shellcheck and zizmor 1.30.0 are clean. D1: the behaviour gate was registered weaker than the DECISIONThat is right, and I should have said it in the PR. DECISION step 1 asks for "verdict rates within the A/A floor of the unchanged base". I registered Fisher's exact p ≥ 0.05 as the gate and kept the A/A floor only as calibration. Under the DECISION's criterion, campaign V failed The evidence against a real effect:
From reading the code, the PR adds no lock, allocation or reordering on any path:
The per-request path is untouched. D2: G2 cannot tell "count armed" from "count every"Agreed for the integration runs. The distinction is carried by:
An integration arm with quiet hand-offs cannot be built cheaply on this engine. Every hand-off here is made with an op in flight:
The first integration run that can tell the two apart is PR 2's gate. There, D3: the T4 shape and the async siteI ran this now, pre-registered: predictions and tools hashed before the build, binary pins added before the first run. Two arms (engine byte for byte, and with the J probe) × two cells × n = 6 gives 24 runs. The shape is
What stays open is the async site's
D4: #670 did not pass in all runsCorrected. D5: acknowledged
CI on 1aca300All 11 jobs passed on the first attempt (CI run 35424972675, PR run 35424970454), so nothing was re-run. From the real job logs:
|
…p comment (celeris#657) The KNOWN RESIDUAL note in staleConnCQE and cqe.go's layout history still described a 16-bit, per-connState generation. celeris#470 made it the 32-bit field drawn from the process-wide connGenSeq; both now say so. The comment at the stale-data counter said every stale recv with data consumed a request a client is still waiting on. That holds for a handed-off conn, not for every class; it now points at handoffLossStats. The witness step's comment said the tests need one ring. One builds two workers through createWorkers, which skips the Listen path's memlock ceiling; the comment now says the fit at 8 MiB is measured, and that a future ENOMEM fails the job on purpose. The step's run block is unchanged.
…can still resolve its fd (celeris#657) (#681) PR 2 of 3 for #657. PR 1 (#676) made the loss countable; this stops it. When io_uring hands a connection to epoll, tryTransplant dup'd the fd, closed the original and handed the dup over while the connection's next RECV could still be issued or completed. That recv then resolved the fd NUMBER, which a later dup may already have given to another connection, and consumed that connection's request. staleConnCQE dropped the CQE as stale, so the #624 hand-off ledger balanced while requests went missing. The rule: never hand a connection off while a read on it can still resolve its fd. - R0 gate: refuse the hand-off at both sites while recvArmed, kernelInflight != 0 or a SEND_ZC notification is pending. - REAP: cancel an armed recv first, with a reported cancel under its own tag and a per-connection count; the -ECANCELED is routed before the generic error branch, and the hand-off re-runs. A miss is retried; any other failure is counted and never retried, and never followed by a hand-off. A connection whose dup failed is not reaped again until it serves another request. - HOLD: a response served while a drain is set flushes unlinked and does not arm the next recv, through one helper for every tail. Every hold is released on every path, with a checkTimeouts rescue that must stay 0. - One owner per hand-off, and pending SQEs are submitted before a worker parks. IORING_ASYNC_CANCEL flags are 5.19+. A cached startup probe detects them; where they are missing the reap is off (counted), never retried, and no connection is handed off with a recv armed. Measured on Ubuntu 5.15.0-191, 5.19.0-50 and 6.8.0-138 under QEMU. The pre-existing cancel breakage on 5.10-5.18 is #682. EngineMetrics gains TransplantHeld, TransplantReaps, TransplantReapMisses, TransplantReapFailed, TransplantReapUnsupported, TransplantHoldRescued and TransplantClaimDeferred; TransplantDoubleClaim now counts only a real second claim, so a release gate of 0 is meaningful. Measured, one container per observation, pre-registered (304 containers, prereg 99c7e04c): - one-worker revert and flap: base FAIL 4/8 and 7/8, fix 0/8 and 0/8. - T4 (2 workers, 128 conns/ring): base FAIL 8/8 with 1,713 lost requests == the W1 counter; fix PASS 8/8. - switch-stall harness: base 18/60 stall rounds, fix 0/60 (p=1.7e-6). - W1, W2, DoubleClaim, HoldRescued and ReapFailed are 0 in all 116 fix records, while the fix still handed off every connection. - Every negative control loses: no HOLD/REAP, blind witnesses, no A6, no A5. Mutants: 85 killed, 0 survivors. - Refused dials at a revert, pre-registered on this head: no regression (base 7/104, fix 5/104, inside the A/A floor). The listener gap those dials fall into is pre-existing and is #683. - No PASS->FAIL in any package x memlock cell. CI: the witness step tallies 29 tests with skipping forbidden, a new one-worker leg requires err=0, and T4 runs with a guarded tally. Each was proven to fail on a deleted, renamed, skipped or loss-carrying tree, and a deliberate red run on the runner (35465814564) showed T4 and the err=0 leg turn red for the planted reason; its revert is green. Not in this PR: the placement half of #657 (sweep, A2w, A1) is PR 3. Tracked elsewhere: #682, #683, #684, #685. Refs #657
Summary
This is PR 1 of 3 for #657. It adds instruments only and changes no behaviour. It makes the request loss diagnosed in #657 (diagnosis comment) countable. The fix that follows in PR 2 can then be judged by these counters reading zero, and this PR first shows they are non-zero on today's engine.
Refs #657
Why these counters exist
When io_uring hands a sync connection to epoll (a revert),
tryTransplantdups the fd, closes the original and hands the dup over. The connection's next RECV can still be issued or completed after that. When it reads, it takes a request, and through a recycled fd number that request can belong to a different connection. Its CQE still carries the old (fd, generation), sostaleConnCQEdrops it as stale, and nothing counted it. The #624 hand-off ledger (TransplantDetached == TransplantAdopted) keeps balancing while requests go missing. The diagnosis comment has the measurements and the mechanism.The third instrument is the ramp test's error census. As the correction comment explains,
recordErrcapped the whole tally on map size, and its keys carry the client's ephemeral port, so it went quiet after about 200 connections. The same census is how anyone would measure the fix.What this adds
EngineMetricsfieldStaleRecvDataTransplantedstaleConnCQE: a stale recv CQE withres > 0whose (fd, gen) this worker handed offStaleRecvDataClosedHijackthe socket lives on under the hijacker'snet.Conn, and a recv that reaches the kernel after a close resolves the fd number, which a new connection may hold by then. Either way a live client's request can land here.StaleRecvDataUnattributedTransplantHandoffInFlighttryTransplantandfinishAsyncTransplant, once the hand-off is committedrecvArmed,kernelInflight != 0orzcNotifPending. This is the precondition of every loss above, and PR 2 must take it to 0.noteStaleTerminalOpretires theclosedOpsentry. Counting after the retire would turn every identity into Unattributed, and a mutant pins this ordering.staleConnCQE's live branch and none of them counts it. Generations come from one process-wide 32-bit sequence, so this needs the sequence to wrap while the op is in flight. The residual predates this PR, and the field doc now says so.noteHandedOffInflight, which isnoteClosedInflightplus ahandoffflag on theclosedOpsEntry. Kernel accounting and the release gate are unchanged. The flag sits ininflight's padding, so on 64-bit platforms the entry stays 32 bytes. This is pinned byTestClosedOpsEntryStaysThirtyTwoBytesand measured at compile time for linux/amd64 and linux/arm64. On 32-bit platforms there is no padding there, and the entry grows from 16 to 20 bytes (measured for linux/386 and linux/arm).kernelInflight != 0implies the other two, but a generation-collision misroute can takekernelInflightto 0 while a recv is still armed or a SEND_ZC notification is still pending. The three terms are also the condition PR 2 refuses a hand-off on. The unit test checks each term on its own.F_MOREdata CQE counts once per CQE. A unit test pins this. No integration run has produced one yet: 0 of 1,024 stale recv completions in the join proof, and 0 in the T4-shape campaign.adaptive.Engine.Metrics()sums both sub-engines, because by the time the stale CQEs arrive the engine that made the hand-off is the standby.adaptive/ramp_transplant_test.go):recordErrnow counts every error, in total and per port-free class. Only the verbatim exemplars are capped at 200, and a key that is already held keeps counting.dumpErrSamplesprints the class tally first.There are 13 new tests, one per counter or path, with no subtests:
engine/iouring/handoff_loss_test.gohas 8. Two of them drivetryTransplantandfinishAsyncTransplanton a ring-backed worker, then feed that identity's recv completion. One is a negative control: completions that read nothing, stale sends and a live connection's own data must not count. One feeds a multishot recv's F_MORE completions.engine/iouring/handoff_loss_metrics_test.gohas 2.engine/iouring/closed_ops_entry_size_test.gohas 1 (linux/amd64 and linux/arm64 only).adaptive/handoff_loss_metrics_test.gohas 1.adaptive/ramp_err_census_test.gohas 1.The existing
TestMetricsCarriesEveryFieldReflectivelycovers the new fields.CI interlock. The
unitjob runs./engine/iouringwithout-v, so a skip there prints nothing, and five of the elevenengine/iouringtests can skip. A new step in theunitjob re-runs all eleven by name. It uses-vandCELERIS_REQUIRE_IOURING_WORKERS=1, whichnewTestRingand the worker test now honour, so an environment skip becomes a failure. It then checks an exact tally:=== RUN Nameand--- PASS: Name (must each count 11, and there must be no--- SKIPline. The step's block was run verbatim, as GitHub runsshell: bash, against the committed tree and against copies with one test source edited:t.SkipHow it was checked
Base is
main985a386, and this branch is 1aca300 (985a386 plus 13 commits).golang:1.27,--cpus 4, one container per observation and one at a time, with-race -v.--- PASS/FAILlines are tallied, andworkers=is checked in every run.analyze_j.py,analyze_t.py,analyze_v.py,analyze_v2.py,analyze_s.pyandanalyze_mut.py.1. Join proof: each counter equals the loss it claims to count
One worker, sync site (campaign J). The cells are
TestReverseTransplantandTestBidirectionalFlapat memlock 8 MiB, which caps io_uring at one worker;workers=1held in 32/32 runs. There are two arms, n = 8 per test per arm, 32 runs in all:EngineMetricsafter the load.StaleRecvDataTransplanted== client read errorsStaleRecvDataUnattributed==StaleRecvDataClosed== 0TransplantHandoffInFlight== hand-offs the kernel confirmed as armed (a terminal stale completion arrived later for that identity, per the probe)StaleRecvDataTransplanted== stale data CQEs the probe joined to a hand-off; unjoined data CQEsTransplantHandoffInFlight==TransplantDetachedStaleRecvDataTransplantedat the end of the load == 500 ms after a wake switchTestReverseTransplant: runs with loss, lost == countedTestBidirectionalFlap: runs with loss, lost == countedTwo workers, and the async site (campaign T). This used the T4 shape:
Workers=2, 256 keep-alive connections (128 per ring) and three promote/revert cycles, at memlock 128 MiB.workers=2held in 24/24 runs. The cells were the sync test and the same shape with every route async, so connections leave io_uring throughfinishAsyncTransplant. There were two arms (engine byte for byte, and with the probe), n = 6 per arm per cell:StaleRecvDataTransplanted+Unattributed== client read errors; dial = write = 0TransplantHandoffInFlight== probe hand-offs with an op in flight == kernel-confirmed armed;TransplantDetached== probe hand-offstryTransplant)finishAsyncTransplant)StaleRecvDataTransplanted== probe-joined stale data CQEs; unjoined 0All registered predictions held. On this engine every hand-off is made with an op in flight: 0 of 2,205 probe hand-offs were quiet. So the integration runs cannot tell "count the armed hand-offs" from "count every hand-off". The unit tests' quiet arms at both sites, with mutant m21, carry that distinction until PR 2 makes quiet hand-offs the norm. The async site has not yet shown a lost request at integration level; its counter path is the sync site's (
noteHandedOffInflight), and PR 2's failing-first campaign, on main plus this PR, is where it meets non-zero loss.This is the positive control the fix needs. On an engine that behaves like main, every revert hand-off is made with its recv armed, and requests were lost in 28 of 32 one-worker runs and 12 of 12 two-worker sync runs. One instrument-check run was made before the pre-registration, on
TestReverseTransplantAsync; it is not a gate cell.2. No behaviour change
The gate was registered weaker than the design decision asked. The decision asked for "verdict rates within the A/A floor of the unchanged base". This PR registered Fisher's exact p ≥ 0.05 as the gate and kept the A/A floor only as calibration. Under the decision's criterion, campaign V failed
TestBidirectionalFlap: the rate difference was 0.188, above V's largest same-bytes A/A difference, 0.125.The pre-registered replication on identical bytes (V2) and the pooled figures:
TestReverseTransplantTestBidirectionalFlapCounts are FAILs, base (M) against this branch (B), with Fisher's exact test, two-sided. In V2 the Flap difference reversed: the branch failed more. The pooled difference is 0.031. On identical bytes the same arm moved by up to 0.25 between V and V2 (the branch's Flap went from 11/16 to 15/16), so V's 0.125 floor, taken from 8-run halves, was too small to measure the spread. That comparison is post hoc. Read from the code, the counters add no lock, no allocation and no reordering on any path. The pooled client-error census (Mann-Whitney) gave p = 0.33 and 0.42. Both tests fail on main at one worker. That failure is #657 itself, and PR 2 is its fix.
Two registered predictions missed, both on
TestBidirectionalFlap, and neither difference is significant:Full suites. The packages were
./engine/iouring,./engine/epolland./adaptive, each on base and on this branch at 6d8d822. They ran at memlock 8 MiB and at 128 MiB; the 128 MiB runs setCELERIS_REQUIRE_UPSWITCH=1andCELERIS_REQUIRE_IOURING_WORKERS=1. Each combination ran twice on identical bytes with-test.run '.', quarantined tests included, for 24 containers.TestBidirectionalFlapAsync, at both memlocks (CI skips it);TestBidirectionalFlapandTestReverseTransplant, at 8 MiB only.TestRampAutoMixedH1H2(adaptive: TestRampAutoMixedH1H2 flakes on the phase-0 migration threshold (949 of the 1024 required) behind a flat 2500 ms sleep #670) skipped at 8 MiB (4/4, the up-switch is disabled there) and passed at 128 MiB (4/4)../engine/iouringran again in full: 136 PASS and 5 environment SKIPs at 8 MiB, 141 PASS at 128 MiB, and the 11 new tests PASS at both.3. Mutation and lint
res > 0andop == udRecvconditions, and counting only terminal CQEs;closedOpsEntry;Metrics()export, the worker wiring and the adaptive sum;.golangci.yml, on linux/amd64 and linux/arm64, found 0 issues on the branch and 0 on the base. A defect planted in a copy of the branch is flagged (rc 1). actionlint 1.7.12 with shellcheck, and zizmor 1.30.0 offline, are clean on the workflow. A planted unquoted variable is flagged.go build, test-binary compile andgo vetreturn rc 0 on linux/amd64 and linux/arm64../engine/iouringbuilds and vets on linux/386 and linux/arm.What this PR does not do
This is PR 1 of 3:
TransplantHandoffInFlightandStaleRecvData{Transplanted,Unattributed}reading 0, with zero client errors.Once this lands, the probatorium validator will report these counters in "report, don't gate" mode, so the nightly shows face 2 on both cluster architectures before the fix.