Repository navigation
test(server): fix the reach-rank expired-snapshot round deadline flake (#237) - #269
Conversation
…efresh TestReachRank_ExpiredSnapshotAlwaysRefreshes hammers an expired snapshot from 16 goroutines with no pause between requests. On a loaded host those 16 take every available P from the one goroutine the round is waiting for, the single singleflight refresh, and the delay lands inside loadDegreeSnapshot. A round then misses its 3 s deadline with nothing wrong in production (#237). Each caller now pauses 100 us between requests. Every round still has 16 concurrent callers hitting the stale snapshot continuously; the test just stops issuing ~530k requests per process. The deadline is unchanged. Also takes the test-hardening item from the #234 review that belongs to this test: awaitDegreeRefresh moves into t.Cleanup, so the join also runs when a round assertion fails and a failing run cannot leave a stray refresh behind for the next test. Cleanup is LIFO, so it runs before resetReachState's. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Rapport — CS-Macmini PR#269 #237 — head cfa4e0aStatus: Cause named and measured, fixed in the test, acceptance met 3/3 under load (master reproduces 1/200 twice), both mutants killed, CI green on every job. Cause [T] [A]The test hammers an expired snapshot from 16 goroutines with no pause between So the round is starved, but by the test itself. The two alternatives the issue
Evidence, from an instrumented scratch copy (per-round duration, per-round refresh
This is scheduling starvation, so by the issue's own rule a raised deadline would FixTest-only, two hunks in
The 3 s per-round deadline, the 300 rounds and the 16 callers are unchanged. Measurements before and after [T]
Master: 2 failures in 600 at load ~40. Branch: 0 in 600, two of three runs at 6× A 1/200 rate is a poor instrument, so the same comparison was also run with the 3 s
Mutants
CI per job [K]Run 37344078852, all green, nothing re-run:
The known flaky Hash Stats sort test (#256) did not fire, so no job needed a retry. Local checks [T]
RemainingThe other two #234 review items are in
Worth one follow-up issue; not filed from here. Also observed, not changed: the stale-while-revalidate path in |
Review — CS-pve-agent3 PR#269 — head cfa4e0aDom: APPROVE with nits Evidence tags: [T] = I ran it myself in this review · [A] = read/analysed from code or diff · [K] = taken from the author's report or CI, not re-run by me. Independent, read-only review. The diff is test-only: one function plus one new constant in Findings
No blocking findings. Answers to the review points1. Cause — named with evidence? Starvation or a leftover singleflight flight? Yes. It is starvation, and it comes from the test's own 16 spinning callers. I repeated the key measurement with an instrumented scratch copy: per-round total, expire→load-start, load duration, loads per round, and
2. Fix — in the test or in production? Is the deadline raised? Does 3. Load test — the literal
4. Mutant: reintroduce the cause, test goes red under load. See M1 below: killed. Mutants (all own, [T])
Acceptance criteria of the issue vs red/green:
Tests on the merged treeMerged tree
Invariants
Not verified
|
3 participants
Relates to #237
Cause
TestReachRank_ExpiredSnapshotAlwaysRefresheshammers an expired snapshot from16 goroutines with no pause between requests. On a loaded host those 16
runnable goroutines take every available P from the one goroutine the round is
actually waiting for — the single singleflight refresh — and the delay lands
inside
loadDegreeSnapshot. A round then misses its 3 s deadline with nothingwrong in production.
To answer the question the issue asks directly: the round is starved, but
it is starved by the test itself, not by the scheduler in general and not by a
leftover singleflight flight from the previous round.
Evidence
Instrumented scratch copy (per-round duration, per-round refresh count,
singleflight path counters, goroutine dump when a round runs long),
-race,GOMAXPROCS=2, loaded host.The round waits on exactly one load, and that load is what runs long.
Slowest round captured: 276 ms, of which 272 ms inside
loadDegreeSnapshot. [T]Goroutine dump at that moment [A]: all 16 hammer goroutines parked in
singleflight.(*Group).DoChanon the group mutex; the single refreshgoroutine parked inside the sqlite driver mid-query
(
newRows→columnCount,semacquire), reached throughrefreshDegreeSnapshot.func1→loadDegreeSnapshot→scanRankRows.A leftover flight is real but cheap. A round sees 1–8 flights, of which
at most one loads; the rest return the already-fresh snapshot and exit. A
caller that joins a leftover loses one loop iteration out of the ~1000 it
runs per round, not a round. [T]
The retry backoff is never involved.
degreeFailAtis the zero time anddegreeFailErris nil at every slow round, so the 15 sreachDegreeRetryBackoffpath is not what suppresses the refresh. [T]Volume of the hammer: ~490k–640k
refreshDegreeSnapshotcalls per testprocess, up to ~30k in a single round, each appending a singleflight result
channel that nobody ever reads. [T]
The round-duration tail scales with how hot the hammer is. Same host,
same load, interleaved runs, 300 rounds each: [T]
This is scheduling starvation, so by the issue's own rule a raised deadline
would have been allowed — but the starvation is the test's own doing, so the
deadline stays at 3 s and the hammer is fixed instead.
Fix
Test-only, both hunks in
TestReachRank_ExpiredSnapshotAlwaysRefreshes.degreeHammerPause(100 µs) between requests. Everyround still has 16 concurrent callers hitting the stale snapshot
continuously, ~30k requests per process and over 100 per round; the test
just stops competing with the refresh for the last free P. 100 µs was
picked from the table above: it has the best tail and still issues 4× the
requests of a 1 ms pause.
awaitDegreeRefreshmoves intot.Cleanup— the test(server): deflake reach_rank hook race and the #1008 not-ready window (#224, #227) #234 review item thatbelongs to this test. A
t.Fatalfin the round loop skipped the tail call,so a failing run could leave a stray refresh behind and add a misleading
race report to the next test. Cleanup is LIFO, so it runs before
resetReachState's cleanup, while the snapshot is still there.No production change. The 3 s per-round deadline, the 300 rounds and the 16
callers are unchanged.
Measurements
go test -race -count=200 -run TestReachRank_ExpiredSnapshotAlwaysRefreshes ./...in
cmd/server, with threecmd/server-racesuite loops plus eight CPUburners alongside. The reported symptom reproduces on master. [T]
round 150: expired snapshot never refreshed(3.63 s)round 128: expired snapshot never refreshed(3.62 s)Master fails 2/600 at load ~40; the branch is clean 0/600, and two of its three
runs ran at 6× that load. The literal acceptance command was then run three
more times at default
GOMAXPROCSwith the same load setup: 0/200, 0/200,0/200 (162 s, 182 s, 172 s), the last two at load 235–331. [T]
Because a 1/200 rate is a poor measuring instrument, the same comparison was
also run with the 3 s budget scaled down 100× to 30 ms, which turns the
rare tail event into a rate, 20 processes per cell, interleaved: [T]
Mutants
awaitDegreeRefreshback as a tail call instead oft.Cleanup, with a round assertion forced to fail while one extra refresh is in flight (the condition the item protects against), run together withTestReachRank_RefreshHonoursBackoffAfterQueuedFailure, 20 processes per cell-racereports and 1/20 "2 loads inside the backoff window", fixed 0/20 and 0/20 [K]t.Cleanupjoin is now defence in depth rather than something an unforced mutant can distinguish. Noted, not hidden. [T]Checks
cd cmd/server && go test -race -count=1 -timeout 40m ./...(whole package,once, unloaded):
ok486.069 s, 0 race reports. [T]go vet ./...clean.gofmt -l reach_rank_test.goclean.cmd/serverstays read-only — the change is one test function. No newmap[string]interface{}. Fork guards unchanged: 9 indeploy.yml, 1 inrelease-fast-path.yml.Remaining
The other two #234 review items are in
index_ready_1008*and belong to adifferent test, so they are not folded in here:
TestIssue1008_PathHopIndexReadyFalseImmediatelyAfterLoadhas the test: TestIssue1008_HandlerReturns503WhileSubpathIndexLoading races the background index build under load (-race flake) #227 raceclass (asserts "not ready" right after
Load(); the path-hop builder canwin). It needs a gate like
subpathBuildGatefor the path-hop builder.store.subpathBuildGate = func() { close(building); <-release }closesbuildingunguarded, so a secondLoad()on the same store would panic.It wants a
sync.Once.Worth one follow-up issue; not filed from here.
Also observed but not changed: the stale-while-revalidate path in
getDegreeSnapshotcallsrefreshDegreeSnapshot(ctx)and discards thechannel, so every request arriving during a refresh allocates a singleflight
result channel that nobody reads and that the finishing flight must still send
to while holding the group mutex. The test made that pathological (up to ~30k
per round); at real request rates it is negligible, which is why production is
left alone here.
🤖 Generated with Claude Code