fix(iouring): an async handler's direct write waits for a ring SEND of the conn's earlier bytes (celeris#751) - #800
Conversation
…f the conn's earlier bytes (celeris#751) The dispatch goroutine wrote each response straight to the socket without asking whether a ring SEND of the previous response's tail (a short direct write the worker finished with a SEND) was still in flight, so a pipelined response went out in the middle of the previous one. The h2c-upgrade exit's direct write of the 101 had the same gap. Both now leave writeBuf to the worker while a SEND or its notification is outstanding or sendBuf/bodyBuf hold bytes (the condition the detached conns' guarded writeFn has always tested, read under the detachMu the goroutine already holds); completeSend sends it after that SEND, in order.
FumingPower3925
added
bug
|
Navigate logical layers of code changes, visualize relationships, and explore their blast radius. No actionable comments were generated in the recent review. 🎉 ℹ️ Recent review info⚙️ Run configurationConfiguration used: Repository: goceleris/celeris/.coderabbit.yaml Review profile: CHILL Plan: Advanced Run ID: 📒 Files selected for processing (1)
Included review availability: This review used your included allowance. Your plan provides up to 10 included reviews per hour; 6 remain after this review. 📝 WalkthroughWalkthroughThe async response paths defer direct writes when earlier ring output remains outstanding. A Linux-only test checks response ordering for pipelined requests with a normal response and an h2c upgrade. ChangesAsync response ordering
Priority: ➖ Normal Estimated code review effort: 3 (Moderate) | ~20 minutes Change: Bug fix · Severity of issue fixed: Medium Merge Risk: ⚪ Minimal · up to Later response bytes remain queued until earlier output completes, including for h2c upgrades. No actionable merge-blocking risk is established. Architecture SummaryArchitecture risk: 🟡 Medium · up to The change affects 1 system. Changed systems: Architecture concerns Review detailsSystems and components
Before / after behavior
Reliability and maintainability
🚥 Pre-merge checks | ✅ 3 | ❌ 1❌ Failed checks (1 warning)
✅ Passed checks (3 passed)
Full details: Linked Issues checkExplanation Issue
Comment |
Codecov Report✅ All modified and coverable lines are covered by tests. 📢 Thoughts on this report? Let us know! |
1 participant
Summary
With
AsyncHandlerson io_uring, the dispatch goroutine writes each response straight to the socket (unix.Write(cs.fd, cs.writeBuf)at the end of arunAsyncHandleriteration). It did so without asking whether a ring SEND of the conn's earlier bytes was still in flight. Those bytes are the rest of the previous response: its own direct write was short, the goroutine left the remainder inwriteBuf, and the worker moved it tosendBufand submitted a SEND. A pipelined request answered while that SEND is outstanding went out ahead of it, in the middle of the previous response, and the client parses garbage. The h2c-upgrade exit's direct write of the 101 had the same gap.The detached conns' guarded
writeFnhas always refused the raw write in that state (!cs.sending && !cs.zcNotifPending && len(cs.sendBuf) == 0 && len(cs.bodyBuf) == 0). epoll is not affected: its pending bytes stay inwriteBuf, which the goroutine's own flush writes first.Fixes #751
Failing-first
End to end, on current main. The issue's probe (lane EP-1's
zz_probe_send_stall_linux_test.go, added by-overlay) re-run on main dfd044f, m8,-race -count=5: a client with a 4 KiBSO_RCVBUFpipelines/big(3 MiB) and, 150 ms later,/slow. In 5/5 runs/bigarrived with the right length and the wrong bytes, and/slow's response failed to parse (malformed HTTP response "789abcdef0123456789abcdef…": the rest of/bigarrived after/slow's head). Logmain/logs/probe-sendstall-dfd044f-m8.log, scriptmain/probe.sh.The regression test is deterministic.
TestAsyncResponseWaitsForAnInFlightRingSendplays the kernel and the client on one promoted async conn of anfdlFixture:/big, 1 MiB): the goroutine's direct write fills the socketpair (219,264 bytes), and the worker submits the other 829,419 as a ring SEND. The test captures that SEND and keeps it in flight.responseisGET /small, armh2c_upgradeis an h2c upgrade (its 101).sendBufto the socket) and completes it, and then any SEND the worker submits after it.The client must then parse response 1 whole, byte for byte, and then the answer to request 2. No timing is involved: the window is an input.
main dfd044f with the test added by
-overlay(byte-identical to this PR's, sha256b7aa7fd7…,751/logs/ff-test.sha256),-race -v -count=3, Docker linux/arm64, 4 CPUs; m8 is CI's shape (8 MiB memlock, one io_uring worker), unl has unlimited memlock:-count=10)-count=10)responseh2c_upgrade0 data races in all four logs. On main, in every run, 103 bytes (
response) or 143 bytes (h2c_upgrade) of the answer to request 2 reached the client while the SEND was in flight, and response 1's body differs at byte 219,157, whereHTTP/1.1 200 OK\r\ndate: …orHTTP/1.1 101 Switching Protocols\r\n…begins. With the fix, 0 bytes arrive early, and the worker sends them in a second SEND after the first completes (sends=2). Logs751/logs/{ff-dfd044f,fix-b340cbe-new}-{m8,unl}.log.The fix
ringSendOutstanding(cs)is the guardedwriteFn's condition: a SEND or its SEND_ZC notification is outstanding, orsendBuf/bodyBufhold bytes the worker has taken fromwriteBufand not yet sent. The worker mutates all four undercs.detachMu, which the goroutine holds here, so no SEND can start while it looks.writeBufand the goroutine enqueues the conn (partial = true), as for a full socket buffer. The worker'scompleteSendsendswriteBufafter that SEND, in order.writeBuf, and the exit'sasyncH2Promotedentry puts the conn on the dirty list, wherecompleteSendfinds them.The guarded
writeFnkeeps its own copy of the condition; this PR does not touch it.Controls
Run by
751/suite.sh(stagectl), m8,-race, each an-overlayof the fix head'sworker.go(the tree is never edited). NEG is main'sworker.go, copied from the pristine main worktree.response,h2c_upgraderesponseonlyh2c_upgradeonlyLog:
751/logs/controls-m8.log.Suites
Docker linux/arm64, 4 CPUs,
seccomp=unconfined, at this head (b340cbe); logs751/logs/../engine/iouring-race -v./engine/iouring-race -v./adaptive/...-race -v-race -vEvery skip is the environment's: at m8 the three
TestListenCloses…init-failure tests need two workers' memlock; in both shapes the twoTestPauseAccept…SynackRetriesZerotests neednet.ipv4.tcp_synack_retries=0(the VM reads 5); in the root package the three io_uringTestAdaptiveSettledRouteRetime592subtests skip at 8 MiB (#709), andTestRouteAdaptive_SettleReopenCostis opt-in.amd64:
go vetand the new tests under--platform linux/amd64(qemu). They SKIP there (io_uring_setup: function not implementedunder emulation), so this is a compile-and-vet check only, and the SKIPs count as absent, not as passes (751/logs/amd64-new-m8.log). The amd64 verdicts are CI's: the Unit job'sengine/iouringstep runs the package with-vnatively on ubuntu-latest.Static:
go build ./...,go vet ./engine/... .,go test -c ./engine/iouring/andgolangci-lint run ./engine/...(the repo's.golangci.yml),GOOS=linuxfor amd64 and arm64: all clean, 0 issues (751/logs/lint-b340cbe.txt).CI at
b340cbe: 17/17 checks green on the first attempt. The Unit job's native amd64engine/iouringstep ran the new test: 3--- PASSlines, and bothceleris751 ORDERlines readhead=219264 tail=829419 early=0 sends=2, as on the laptop.Combined with the lane's other two PRs and with main. fix(iouring): leave a conn whose dispatch goroutine exited to close it, or upgraded it to h2c, to its queued exit (celeris#780) #799 (a83e045), fix(iouring): an async handler's direct write waits for a ring SEND of the conn's earlier bytes (celeris#751) #800 (b340cbe) and fix(iouring): stop a ring SEND completion parking the worker on a running async handler's detachMu (celeris#750) #801 (f8f51fd) merge cleanly onto main 3e7abba, which has fix(iouring): never release a descriptor number while an op can still resolve it: close paths, hijack, shutdown (celeris#685) #793 (io_uring close paths close the fd while a linked RECV can still resolve its number (the #657 fd-lifetime rule, not yet applied to close/hijack/shutdown) #685's close paths); the merged tree is 1b82782 (
combined/logs/merge-1b82782.txt). On that tree,-race -count=3:listed_passes=0/3, and bothceleris751 ORDERarms readtail=829419 early=0 sends=2. With io_uring: a ring SEND completing while an async handler holds cs.detachMu parks the worker (handleSend/completeSend, a fifth #704 site) #750 and io_uring: an async handler's direct write goes out while a ring SEND of the previous response is still in flight, interleaving pipelined responses #751 both in, every e2e run readsbig_ok=true slow_body="slow"(/bigintact, then/slow), and the fast conn's worst request is 2.0 to 8.8 ms../engine/iouringpackage,-count=1, unl: 387 PASS, 0 FAIL, 2 SKIP (the twoSynackRetriesZerotests) and 0 races.Script
combined/run.sh(HEAD=1b82782 PKG=1); logscombined/logs/{new,pkg-iouring}-1b82782-*.log. The round-1 merge (4c5a0cc, on main 67fdb78) is incombined/logs/new-4c5a0cc-*.log.Cost
Measured under the laptop's timing lock (no other container running:
containers_at_start=[]andcontainers_at_end=[]in the log), linux/arm64,-count=10,benchstat -col /impl(bench.sh; the benchmark is751/bench/zz_bench_direct_write_gate_linux_test.go, added by-overlay, not committed):impl=main/dev/nullimpl=fixringSendOutstanding, then the same writeimpl=gate0 B/op and 0 allocs/op in all three.
/dev/nullis the cheapestwrite(2)there is, and a socket write costs more, so the check is at most about 1.1% of the path it guards, and below the noise of that path. No lock and no atomic are added: the four fields are read under thedetachMuthe goroutine already holds. The end-to-end bound is a perf-checkpoint row in the cluster queue, the io_uring async columns: PASS iff no RPS or CPU/req regression beyond the detectable floor, both arches. Logsbench-logs/751-gate.log,bench-logs/benchstat-751.txt.Cluster
Queued, not dispatched (
evidence/_queue/cluster.tsv, lane EP-3): the ordering test on bare metal, both arches,-race -count=20; PASS iff both arms PASS 20x per arch with 0 FAIL/SKIP/race and everyceleris751 ORDERline readsearly=0 sends=2with the window entered (tail>0). And the perf-checkpoint row for the io_uring async columns (see Cost).Related: #811
A response left behind an outstanding SEND puts the conn on the worker's dirty list, where main already puts it when the socket buffer is full, and a listed conn whose SEND waits for a stalled client makes the worker busy-poll. Measured with a stalled client and a pipelined second request: 368 to 374 ms CPU per second on main, 371 to 376 ms on this head, so this PR does not change it. That pre-existing defect is #811.
Relation to #750
#750 (a SEND completion parks the worker on a running handler's
detachMu) is fixed separately in #801. The two are independent diffs. With both, a completion held for the goroutine keepscs.sendingset, so this check keeps the next response inwriteBufuntil the completion is applied.Follow-ups
The review's minor findings and nits are in #815:
ringSendOutstanding'ssendBufclause (an SQ-full arm) and itszcNotifPendingclause;writeFn;Reproduce
Every number above comes from
evidence/lanes-20260927/EP-3/751/suite.sh(stagesff fix ctl pkg amd64),751/make_mutants.sh,main/probe.sh,bench.shandtools/in the probatorium evidence tree.