Skip to content

Follow-ups from #749: the oracle watch's starvation guard, the epoll 1.2-3.9 s read stretches, the inbound #607 checks that cannot fire at CI size, and body wording #788

Description

@FumingPower3925

Round-2 review findings on #749 (the WebSocket backpressure/inbound oracle rework, lane B-2b). Both reviewers approved it. Under the two-round review cap these are follow-ups, not blockers. Evidence paths are under the maintainer's evidence root evidence/celeris-b2/b2b/.

  1. minor: The inbound oracle's new io_uring: a linked recv never starts because its chained SEND blocks on a detached WebSocket peer's closed window #607 checks (the watch and RecvLinkedArms == 0) never fired on any mutant, and at CI's size they cannot fire. The body does not say so. Its Summary says "On io_uring both oracles also assert...", and the m607 table reports "io_uring subtest FAILED 10/10" without naming the test. In fact only TestBackpressurePauseDoesNotCancelInflightSend catches m607.

    • Evidence: R-B (run 36359543720, 1ee81fc + m607), 11-fix/01-m607/tally-R-B.txt: TestBackpressureInboundSequenceIntegrity/io_uring and /io_uring/multishot_recv FAILED in 0/5 per arch, 'LINKBLOCK ... arms=0 procsArms>0=0', recvStallMax=0.000. V-B4 and V-B6 show the same. In every CI-shape run the inbound 'floodDeadlines=0 ... procs floodDeadlines>0=0', and stallmax-healthy-CIshape.txt gives 'inbound_sequence ...: subtest runs=138 max=0.00s' for all three variants. So at CI's size the inbound flood never builds the backpressure these checks look for. Fix: name the test in the m607 row, and state that the inbound oracle passed 10/10 under m607 at CI's size. A follow-up issue can give the inbound checks a mutant that exercises them.
  2. minor: On x86 the watch alone clears its 5 s limit by about 1 s, and the wsoQuiet comment's onset figure is contradicted by this head's own records. "Each check alone fails every process" holds for the sample. But the watch's x86 kill depends on the 8 s quiet with little headroom. On epoll the watch is the only io_uring: a linked recv never starts because its chained SEND blocks on a detached WebSocket peer's closed window #607-class detector, and no epoll mutant tests it.

    • Evidence: Per-process longest stretch under m607, x86: V-B4 36356482425 was 6.00-6.51 s in 11 of 20 processes. V-B6 36359217411 had 6.44/6.50/6.53 s. R-B had x86-4 6.01 s and x86-5 6.78 s, and its x86 records include 5.00 s. In R-B, stretches begin up to 2.81 s after that connection's flood end on x86. Example: x86-4 conn :59454, flood end +7.353 s, stretch +9.526 to +15.277 = 5.751 s, which ends at the end of its quiet. The wsoQuiet comment (backpressure_oracle_linux_test.go:152-158) says 'such a stretch began up to 1.6 s after the flood ended'. At 6 s of quiet (V-B-fix3 36355873107) STALL fired in only 6/10 x86 processes (stretches-V-B.txt: x86 io_uring min 4.50, >=5s:6). Fix: correct the comment to about 2.8 s, and state the margin in the body; a longer quiet would add headroom.
  3. minor: The body's healthy-margin and watch-lag claims pool runs that did not measure the lag. Both maxima come from a pre-quiet candidate. Also, the watch and the linked-recv assertion were never run with multi-worker io_uring (128 MiB memlock or the cluster).

    • Evidence: Re-running scripts/stallmax.py per run: both 2.32 s (epoll) and 1.71 s (io_uring) come from B-fix2 36354813394 (1294552: no quiet, 3 s limit, 1 s gap guard). The final watch code (580cffe onward, 128 runs) maxes at 2.15 s and 1.37 s. A-fix and B-fix2 emitted no watchResets/watchMaxLag at all (0 of 20 and 0 of 160 PauseCancel waits lines carry watchMaxLag; stallmax.py defaults them to 0). So 'watchResets 0 everywhere' and 'never lagged more than 0.73 s' cover 128 of the 218 runs, not 218. Every round-1 dispatch used memlock=8m (1 io_uring worker). Round 0's 128 MiB whole-suite run predates the watch.
  4. minor: The inbound oracle still counts a server-side read ECONNRESET (serverRST) and never judges it. PauseCancel classes the same error as a close (isCloseErr). This is the 'The WebSocket inbound oracle reports frames as lost that its own handler abandoned, and never asserts the write errors that explain them #611 class' the PR sets out to remove, and it makes the body's 'Every other error is judged' too broad.

    • Evidence: inbound_sequence_linux_test.go:189-192: 'serverRST.Add(1)' with no noteErr and no assertion anywhere. pause_cancel_linux_test.go:101-104 plus isCloseErr (inbound_sequence_linux_test.go:630-641) include ECONNRESET, so it is never noted. The body's 'Server errors' section says 'Every other error is judged'. In the healthy R-A run 36359349677 serverRST is 0 in every process, so asserting it (excused on a give-up, like the other errors) costs nothing. Suitable for a follow-up issue.
  5. nit: The 'Not in this PR' bullet has the ci: set up CodeRabbit, Codecov, CodSpeed (celeris#690) #699 direction backwards. ./middleware/websocket is already out of test-coverage.yml; ci: set up CodeRabbit, Codecov, CodSpeed (celeris#690) #699 is the merged PR that removed it, so the follow-up is putting it back.

  6. nit: The range-diff sentence mixes the old and new commit ids.

    • Evidence: The body says 'git range-diff shows all three commits as = against 13ca047/3421840/44ee852 on 698bed6'. 11-fix/06-pr/range-diff-44ee852-rebased.txt maps 46bbbf3/1a6a60f/44ee852 (on 698bed6) to 13ca047/3421840/1ee81fc. 13ca047 and 3421840 are the rebased commits, not the ones on 698bed6.
  7. nit: Two phrasings go beyond the data.

  8. minor: The watch's CPU-starvation guard only measures how long the watcher waited for its tick. It never measures how long a pass took. After a slow pass the Ticker already holds a buffered tick, so the computed lag is negative. Also, now is read after srvViewOf, so a pass slowed by starvation lengthens a stretch without any reset. The claim that the guard resets the watch whenever the process is starved (file comment and body) therefore does not hold, and a stretch stretched by starvation can reach wsoRecvStall and fail the test with no engine fault.

    • Evidence: backpressure_oracle_linux_test.go:1154-1165: lag = since - idleFrom - wsoWatchEvery, and idleFrom is set only at the end of a pass (line 1206). Lines 1174-1175: the sample time is taken after srvViewOf. Observed in 11-fix/02-dispatch/V-C4-inbound-default-race-36357012593, stress__x86__2.log, io_uring/multishot_recv: 'read nothing for 2.624s (3 samples, +1.267s to +3.891s)'. That is about 1.3 s between samples on a 250 ms cadence, while the same subtest's waits line reports watchMaxLag=280ms and watchResets=0. Fix: reset a connection's episode when the gap since that connection's previous sample exceeds wsoWatchEvery+wsoWatchGap, measured per sample and not per tick wait.
  9. minor: On a healthy build, epoll routinely meets the exact WSO-STALL condition: the handler waits idle in ReadMessage, the chanReader is empty and not paused, pendingWrite is 0, and about 93 KiB sits unread at a zero receive window for 1.2-2.3 s. At the inbound test's default size under -race this reaches 3.89 s against the 5 s limit. The body attributes it to other connections keeping the loop busy, but that is not shown. The stretches happen with the watcher unstarved, several fall inside the quiet window, and the pause counters show the chanReader never paused these connections. So either the limit is an empirical cut over an unexplained epoll behaviour with 1.1 s of margin at default size, or the watch has found an epoll read-side stall of the io_uring: a linked recv never starts because its chained SEND blocks on a detached WebSocket peer's closed window #607 class and the PR calls it healthy margin. Either way it deserves a follow-up issue, not the label healthy.

    • Evidence: This PR head's own CI (run 36359326818, job 108733213676), PauseCancel/epoll: 'read nothing for 1.744s ... onset: srv{read frames=12881 echoAgo=0.071s depth=0 spill=0 paused=false ... pauses=0 resumes=0} sock{inq=95232 outq=1520629 wnd=0/0 ...} eng{read=1623039 pendingWrite=0}', last sample echoAgo=1.814s, same inq, watchMaxLag=174ms. In the healthy runs V-A4/V-A5/V-A6/R-A, every epoll subtest's longest stretch is 1.2-1.9 s with onset inq=95232 and rcv_wnd 0 (for example 1.94 s starting 5.14 s after its own flood end, inside the 8 s quiet). stallmax-inbound-default.txt: 'epoll: subtest runs=20 max=3.89s >=3s:2'. PR body: 'On epoll the longest ones come while other connections keep the loop busy'.
  10. minor: The oracles have not run against the chanReader they will merge with. The PR is behind main: fix(websocket): never strand a chunk that spills after the handler drained the channel (celeris#705); fail the start helpers fast with Start's error (celeris#706) #730 (e673408) rewrote chanReader's blocking read (next(), promoteSpill under spillMu, and spillChunk now retrying the channel). The watch's condition and wsoShape both key on depth, spill and paused. The rig still compiles against it (every field it touches still exists), but CI's green result is for base 0e239b1 only.

  1. nit: 'RecvLinkedArms == 0, io_uring, both tests' overstates coverage. At CI's size the inbound test's linked-recv assertion is vacuous against m607: with the mutant it recorded 0 arms in every inbound io_uring subtest (default and multishot). Only PauseCancel's assertion has ever fired, so the inbound one is not a io_uring: a linked recv never starts because its chained SEND blocks on a detached WebSocket peer's closed window #607 guard at the configured size.
  • Evidence: 11-fix/01-m607 tally-R-B.txt, tally-V-B6.txt and tally-V-B4-final-m607.txt: 'LINKBLOCK TestBackpressureInboundSequenceIntegrity/io_uring: ... arms=0 procsArms>0=0' and the same for multishot_recv, against PauseCancel io_uring 'arms=249..557 procsArms>0=all'. PR body line: 'RecvLinkedArms == 0, io_uring, both tests.'
  1. nit: The PauseCancel comment says the recv witnesses read after shutdown 'are direct atomics, so nothing is stranded in a per-iteration batch'. That is not true of RecvLinkedArms, which the new assertion now judges: it goes through the worker-local linkArmBatch and is flushed once per loop iteration, so arms made in the worker's last iteration can be lost. The effect is a possible false negative only, but the comment now backs an assertion.
  • Evidence: pause_cancel_linux_test.go:137-140 (the comment) and :163 (wsoAssertNoLinkedRecv). engine/iouring/worker.go:416-420 (linkArmBatch is 'flushed ... once per event-loop iteration'), :1322-1326 (the flush) and :5226 (the increment).

Before #749 merges, it must be updated onto main containing #730 (e673408), and the websocket CI step must be re-run on the merged tree: see item 3 of the first review.

Refs #749, #633, #607, #623, #611, #783.

No activity

Activity on this issue will appear here.

Activity

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    bugSomething isn't workingmiddlewareMiddleware implementationtestingTesting infrastructure and helpers

    Type

    No type

    Projects

    No projects

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions