fix(store): lazy distance build — drop the reset sync.Once, fix the lock order (#149)

[dborup]

Relates to #149

Summary

The gate of the lazy distance-index build (Kpa-clawbot#1011, cmd/server/store.go) had two separate defects:

1. Crash. distLazyOnce (a sync.Once) was reassigned to a zero value by the background-load completion, and by the debounce path, while Do could be running on it. Do holds the Once's internal mutex for the whole build, so its deferred unlock hit the zeroed mutex: fatal error: sync: unlock of unlocked mutex. That error is not recoverable, and the server exits.
2. Deadlock. On the debounce path, TriggerDistanceIndexBuild took s.mu.RLock while holding distLazyMu. The background-load completion took distLazyMu while holding s.mu.Lock. With the locks taken in opposite order, both goroutines can block forever.

Commits

Commit	Content
15f17983	Tests only: reproductions and pins, red on master
8ea5583d	Fix, sync.Once guard, test refinements (listed below)
93790bb8	Review follow-up: stale re-pass and queued-build tests, debounce bookkeeping and boundary pins, lock-rule and generation-read comments (see the review-feedback comment)

Reproductions (red on master)

Tests that crash or hang a broken build run in a child process (runDistBuildChild). Every wait inside the child has a 10 s deadline and dumps all goroutines when it expires, so a regression fails instead of crashing or hanging the CI run.

Test	On master (d778bc40)
LoadCompletionDuringBuildDoesNotCrash	The child dies with fatal error: sync: unlock of unlocked mutex in sync.(*Once).doSlow. The build is held open with the existing distanceBuildHook seam while loadBackgroundChunks completes.
TriggerAndLoadCompletionDoNotDeadlock	The child times out after 10 s. The dump shows the loader parked in [sync.Mutex.Lock] (distLazyMu) inside loadBackgroundChunks, and the trigger parked in [sync.RWMutex.RLock] inside TriggerDistanceIndexBuild. The orchestration is deterministic: a held read lock queues the loader as a writer, and the trigger then parks behind it.
LoadBeforeBuildSnapshotNoExtraBuild	Same crash: the load completes while the queued build is inside Once.Do.
LoadAfterBuildSnapshotRebuildsOnce	Either the crash or a lost invalidation: the stale index is reported as built and never rebuilt. Which one depends on who wins distLazyMu; both outcomes are red.
BuildingIsSetBeforeTheBuildGoroutineRuns	distLazyBuilding is still false right after the trigger, because it was only set inside the goroutine. With GOMAXPROCS(1) the goroutine cannot run before the check.
TestDistLazyMuNeverHeldWhileTakingStoreMu	The AST guard reports store.go:4667: takes s.mu.RLock with distLazyMu held.

The pins (ConcurrentTriggersStartOneBuild, HandlerContractAndLoadInvalidation, DebounceUnchanged, DebouncedRebuildStartsOnce) pass on master without -race. Correction to the message of 15f17983: it says these pins "pass on master", but under -race three of them fail on master. The race detector reports a data race at store.go:4680 (s.distLazyOnce = sync.Once{}) against Once.doSlow's deferred store, which is the #149 race itself. ConcurrentTriggersStartOneBuild passes on master either way.

Design

• No sync.Once. The gate state lives under distLazyMu:
  • distLazyBuilding and distLazyBuilt, as before;
  • distLazyBuiltGen, new: the generation the last completed build read;
  • distLazyLastBuilt and distLazyLastObs, as before.
• Start a build. startDistanceBuildLocked, called under distLazyMu, sets distLazyBuilding = true and distLazyBuilt = false before the go statement, so concurrent triggers start at most one build.
• Generation. distDataGen is an atomic.Uint64. The background-load completion bumps it under s.mu.Lock. It no longer touches distLazyMu.
  • A build reads the generation under the same s.mu.Lock as buildDistanceIndex, so the recorded generation always matches the data the build read.
  • DistanceIndexBuilt() returns true only when built && builtGen == distDataGen.
• Rebuild only after the snapshot. runDistanceIndexBuild loops only if the generation changed after its snapshot. If the load completes before the build takes s.mu, one build is enough. If it completes after, exactly one more build follows. The loop cannot spin, because distDataGen has one writer, which runs once per background load.
• Lock rule: s.mu (Lock or RLock) is never acquired while distLazyMu is held. In the fix the two are never held together at all.
  • The debounce path reads totalObs between two distLazyMu sections.
  • Before starting a build, the second section re-checks the gate: !building, and lastBuilt unchanged.
• Behaviour kept:
  • 202 + Retry-After: 5 whenever the index is not built. That includes a debounced rebuild, as on master, because distLazyBuilt is cleared when a build starts.
  • Debounce: rebuild when Δobs ≥ 5 % or ≥ 5 min. This is the exact complement of master's suppression condition; the old comment said "> 5 %".
  • Rebuild after the background load.
• Guards:
  • TestDistLazyMuNeverHeldWhileTakingStoreMu is a flow-sensitive AST walk over the package's non-test sources. It rejects .mu.Lock/RLock, and calls to PacketStore methods that take s.mu directly or transitively, while distLazyMu may be held.
  • TestNoSyncOnceIsReassigned rejects assignments to anything declared with a type that holds a sync.Once by value: sync.Once itself, or a struct or array containing one. It also rejects assigning a composite literal of such a type.
  • Both guards have synthetic positive and negative controls.

Performance

This is not a hot path: the build runs at most once per trigger. The question here is whether the trigger and debounce path takes more locks than before.

Trigger path	master	fix
Build in flight	distLazyMu ×1	distLazyMu ×1
Not built or stale (the handler's 202 path)	distLazyMu ×1; the goroutine takes distLazyMu again to set building	distLazyMu ×1; building is set before go; no s.mu
Current, debounced	distLazyMu + s.mu.RLock nested	distLazyMu, then s.mu.RLock, not nested
Current, rebuild due	distLazyMu + nested RLock, plus distLazyMu in the goroutine	distLazyMu, RLock, distLazyMu, and none in the goroutine; same total per cycle
Load completion (under s.mu.Lock)	distLazyMu lock/unlock	one atomic add

• BenchmarkTriggerDistanceIndexBuild (-count=5 -benchtime=200000x, Apple M2 Pro, go1.26.0, 0 allocs):

  Sub-benchmark	master median	fix median
  building	7.82 ns/op	7.90 ns/op
  debounced	35.31 ns/op	35.86 ns/op

  Both differences are within noise; in one round the fix was faster on debounced.

• Contended probe (a scratch test, not committed): a writer holds s.mu for 200 ms while one trigger is parked in the debounce read, and the probe times a second request's DistanceIndexBuilt().

  • master: about 180 ms, because distLazyMu is held across the RLock wait;
  • fix: 0.4–1.3 µs.

Test results

Local runs: go1.26.0, darwin/arm64.

• New and related tests, go test -race -count=20: 16 tests × 20 = 320 PASS, 0 FAIL, 0 data races (160.7 s). The 16 are the 10 TestDistanceBuild149_* tests, the two guards and their two controls, and the three existing TestDistance* lazy-build tests.
• Whole cmd/server suite, go test -race -count=1 ./...: ok github.com/corescope/server 400.1s, exit 0, no FAIL, no data race.
• After 93790bb8:
  • #149 set with go test -race -count=20: 20 tests × 20 = 400 PASS, 0 FAIL, 0 data races (226.2 s).
  • Whole cmd/server with go test -race -count=1 ./...: ok github.com/corescope/server 440.6s, exit 0.
• gofmt / vet:
  • gofmt -l is clean on every touched file. The package has untouched files that are not gofmt-clean on master with go1.26; that is pre-existing.
  • go vet ./... in cmd/server is clean.
• Known flakes (TestIssue1008_HandlerReturns503WhileSubpathIndexLoading, TestPollerBroadcastsNewData): did not occur in the final full run; both passed.

Mutants

Each mutant was applied to the final store.go and the #149, guard and existing lazy-build tests were run against it.

Mutant	Result	Red tests
m1: reintroduce distLazyOnce, builds through Once.Do, reset in the load completion and the debounce path	red	LoadCompletionDuringBuildDoesNotCrash, LoadBeforeBuildSnapshotNoExtraBuild, LoadAfterBuildSnapshotRebuildsOnce, TestNoSyncOnceIsReassigned
m2a: read totalObs under s.mu.RLock inside distLazyMu in the trigger	red	TestDistLazyMuNeverHeldWhileTakingStoreMu
m2b: m2a, plus the load completion takes distLazyMu under s.mu (master's shape)	red	the guard and TriggerAndLoadCompletionDoNotDeadlock
m3a: drop the generation check after a build (stale := false)	red	LoadAfterBuildSnapshotRebuildsOnce
m3b: DistanceIndexBuilt() ignores the generation	red	HandlerContractAndLoadInvalidation
m4: set distLazyBuilding only inside the goroutine	red	BuildingIsSetBeforeTheBuildGoroutineRuns, ConcurrentTriggersStartOneBuild, DebouncedRebuildStartsOnce
m5: the load completion does not bump the generation	red	HandlerContractAndLoadInvalidation, LoadAfterBuildSnapshotRebuildsOnce
m6a: Δobs threshold 5 % → 10 %	red	DebounceUnchanged
m6b: age threshold 5 min → 10 min	red	DebounceUnchanged, DebouncedRebuildStartsOnce
m7a: no !building re-check before a debounced rebuild	red	DebouncedRebuildStartsOnce
m7b: no lastBuilt re-check before a debounced rebuild	red (since 93790bb8)	DebouncedTriggerSkipsWhenABuildFinishedMeanwhile
m8: the trigger ignores a build in flight	red	BuildingIsSetBeforeTheBuildGoroutineRuns, ConcurrentTriggersStartOneBuild, HandlerContractAndLoadInvalidation
m9: a debounced rebuild keeps reporting the old index as built (answers 200)	red	DebounceUnchanged
Mb: distLazyBuilding = false before the generation check (93790bb8)	red 5/5	TriggersDuringStaleRepassStartNoBuild
Mf: distDataGen read before s.mu.Lock (93790bb8)	red 5/5	LoadHoldsMuWhileBuildQueuedNoExtraBuild
Mc: record the current generation instead of the one the pass read (93790bb8)	red 3/3	TriggersDuringStaleRepassStartNoBuild
Mu: second section re-checks "current" instead of lastBuilt (93790bb8)	red 3/3	DebouncedTriggerSkipsWhenABuildFinishedMeanwhile
Mk: a build no longer records the totalObs it read (93790bb8)	red 3/3	DebounceUnchanged
Mw / Mx: >= 5 % / >= 5 min turned into > (93790bb8)	red 3/3 each	RebuildDueBoundaries
Mg: distDataGen read after s.mu.Unlock	survives	see "Not verified"

Changes to commit A's tests in commit B

• Lock-order guard:
  • It no longer flags s.distDataGen.Load(). Only calls x.m() on a plain identifier count as PacketStore method calls. The old rule was a false positive from the name clash with PacketStore.Load; the viaNamesake control still catches s.Load().
  • It now also flags a taker deferred after defer distLazyMu.Unlock().
  • New controls cover both changes.
• DebounceUnchanged also asserts that DistanceIndexBuilt() is false while a debounced rebuild runs, so the handler answers 202 as on master. This passes on master.
• New DebouncedRebuildStartsOnce: 16 triggers get past the first gate check together, and exactly one starts the rebuild. It is a pin, not red on master.
• New sync_once_reset_guard_test.go.

Not verified

• Go version. I did not run on Go 1.27.1 (CI's version); local runs are on go1.26.0. The stack-scan helpers match the runtime wait reasons ([sync.Mutex.Lock], [sync.RWMutex.RLock], [sync.RWMutex.Lock]) in the goroutine header. CI is the check for 1.27.1.
• Surviving mutant Mg. Reading distDataGen after the build's s.mu.Unlock would allow a lost invalidation, if a load completed between that Unlock and the read. Nothing blocks in that window, so the existing seams cannot produce a deterministic test. The comment at the read documents why it must stay inside the section.
• Guard blind spots. Both guards are syntactic:
  • The lock-order guard does not see s.mu taken inside a function literal run by a distLazyMu holder, in a package-level function, or through a method value. The runtime deadlock test covers the actual fix(store): lazy distance build can crash (sync.Once reset during Do) and deadlock (lock order) #149 shape.
  • The sync.Once guard does not see copies through pointers (*p = *q). go vet's copylocks would, but CI does not run go vet for cmd/server, and go test's vet subset does not include copylocks.
• Coverage. The rebuild-loop branch in runDistanceIndexBuild is exercised only in child processes, so it does not show up in the CI coverage profile.
• Reachability of the debounce path. The handler calls TriggerDistanceIndexBuild only when DistanceIndexBuilt() is false. The Δobs/5-minute debounce is therefore practically unreachable from HTTP, on master as well; it is reachable through direct calls.
• Load between the two trigger sections. If a load completes between the trigger's two sections and the debounce says "not due", that trigger starts no build. The next request sees the stale index and starts one: at most a one-retry delay.
• Real deployments. Not tested on staging or prod, or against real data. Backend only, with no UI change. The HTTP contract is covered by httptest, and there was no browser validation.

Follow-up

• fix(analytics): recompute cached snapshots after the complete startup load #145 must be synced with this fix and merged after it. fix(analytics): recompute cached snapshots after the complete startup load #145 re-runs analytics right after the startup load, which widens the crash window described here.

🤖 Generated with Claude Code

[dborup]

Review feedback addressed (commit 93790bb8)

The follow-up is one new commit on top of 8ea5583d: no amend, no force push.

1. The stale re-pass keeps distLazyBuilding set. New test: TestDistanceBuild149_TriggersDuringStaleRepassStartNoBuild.
   • Pass 1 reads the dataset, and the load completion lands behind that snapshot. When the second pass starts, DistanceIndexBuilding() is still true.
   • Eight triggers during the second pass start no build: there are exactly 2 builds.
   • Mutant Mb (set distLazyBuilding = false before the generation check) is red 5/5.
2. The build queues behind a load completion that holds s.mu. New test: TestDistanceBuild149_LoadHoldsMuWhileBuildQueuedNoExtraBuild.
   • A held read lock queues the completion as a writer, and the build queues behind it. The completion bumps the generation before the build gets the lock, and exactly 1 build runs.
   • Mutant Mf (read distDataGen before s.mu.Lock) is red 5/5.
3. Comment at gen := s.distDataGen.Load() in runDistanceIndexBuild: the read has to stay inside the build's s.mu section.
   • Read after the Unlock, a load completing in between counts as seen by an index built without it: a lost invalidation.
   • Read before the Lock, it forces a redundant rebuild.
4. The lock rule is stated as a single direction. s.mu is never acquired while distLazyMu is held; s.mu → distLazyMu is allowed. This is fixed in:
   • the gate-field comment;
   • the load-completion comment;
   • the lock-order guard's header and failure message.

Both tests are adapted from the reviewer's TestReview149_* versions:

• They are renamed to the file's TestDistanceBuild149_ convention.
• runBuildFrame became buildFrame, in the existing frame constant block.
• In the stale re-pass test, the load completion now runs in a goroutine with a bounded wait. The test also tolerates a completion that takes distLazyMu, which the rule allows, the same way LoadAfterBuildSnapshotRebuildsOnce does.

Also closed while verifying the follow-up. A second independent review and a 24-mutant hunt found three test-coverage gaps; none was a code defect.

5. Mc records the current generation instead of the one the pass read, which makes the stale first-pass index count as built during the second pass. The stale re-pass test now also asserts DistanceIndexBuilt() == false there. Red 3/3.

6. m7b and Mu drop or replace the lastBuilt re-check in the trigger's second section. The PR description called m7b "not deterministically reachable", and that was wrong. TestDistanceBuild149_DebouncedTriggerSkipsWhenABuildFinishedMeanwhile parks the trigger at its second section and records a finished build in between, which the lock rule allows. Red 3/3 each. I have updated the description.

7. Mk, Mw and Mx break the debounce bookkeeping and boundaries:

   • Mk: a build no longer records the totalObs it read.
   • Mw: >= 5 % becomes > 5 %.
   • Mx: >= 5 min becomes > 5 min.

   DebounceUnchanged now checks the recorded totalObs after each build, and the new TestDistanceBuild149_RebuildDueBoundaries pins exactly 5 minutes and exactly 5 %, which are master's boundaries. Red 3/3 each.

Verification (local, go1.26.0 darwin/arm64):

• #149 set with go test -race -count=20: 20 tests × 20 = 400 PASS, 0 FAIL, 0 data races (226.2 s).
• Whole cmd/server with go test -race -count=1 ./...: ok github.com/corescope/server 440.6s, exit 0.
• gofmt -l on the touched files: clean. go vet ./... in cmd/server: clean.
• Regression run of the earlier mutants m1–m9: all red.
• Still surviving: Mg, which reads distDataGen after s.mu.Unlock. Nothing blocks between that Unlock and the read, so the existing seams cannot produce a deterministic test. The new comment at the read documents why it must stay inside the section.

origin/master has moved on (#114 and #115 touch store.go, but not the gate or the load completion). git merge-tree against it is clean. CI runs on the merge ref.