fix(analytics): recompute cached snapshots after the complete startup load - #145
Conversation
A one-shot StartupLoadDone signal on every RunStartupLoad exit path (success, hot window off, retention off, empty DB, LoadChunked error, background-fill failure) with backgroundLoadDone/Failed unchanged, and still open while the background fill runs after LoadComplete(); the signal drops the hash-size, clock-skew and region TTL caches; RecomputeNow runs on the loop and resets the ticker; a pass started before the signal never opens the warm-up gate; every recomputer runs once after the signal (gated three first, roles after nodes-clock-skew); end to end, RF stays 503 through the background fill and then serves the full store while ungated endpoints keep 200; a forced-open snapshot is replaced; the distance snapshot refreshes before the lazy index reports built. Does not compile on master. Relates to #116 Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_019TcZHooUiiknVWbECVWzk8
… load (#116) - StartupLoadDone(): one-shot channel closed (deferred) when RunStartupLoad returns, on every path. Separate from LoadComplete() (end of the hot window) and from backgroundLoadDone/Failed, whose health/coverage meaning is unchanged. Before closing it drops the hash-size info cache, the clock-skew recompute throttle and the region/window analytics TTL caches computed on the partial store. - analyticsRecomputer.RecomputeNow(): a pass on the recomputer's own loop goroutine that restarts its ticker (no immediate duplicate). - StartAnalyticsRecomputers recomputes all nine default-shape recomputers once, sequentially, after the signal: rf, topology, channels first; roles after nodes-clock-skew (it reads that snapshot). - Warm-up gate (Kpa-clawbot#1659) is the startup-load signal, sampled before each compute, so a pass that began on partial data never opens it; 503 + Retry-After and the force timeout are unchanged, and a forced-open snapshot is replaced by the post-load pass. Ungated endpoints keep their availability. - The lazy distance build clears the distance TTL cache and refreshes the distance recomputer before reporting the index built. - TestAnalyticsRF_AfterFirstPassReturns200 models "loaded" with the new signal instead of LoadComplete(). Relates to #116 Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_019TcZHooUiiknVWbECVWzk8
Independent review of
|
| Criterion | Result |
|---|---|
| One-shot terminal signal fires exactly once on every startup-load exit path | Met [F]. defer s.signalStartupLoadDone() at chunked_load.go:210 is the first defer, so it runs last. The CompareAndSwap guard makes it one-shot. TestStartupLoadDoneFiresOnEveryPath_116 covers 6 paths plus a second call. Mutants M1 (defer removed) and M12 (signal before the fill) are caught. |
| Every current default-shape analytics recomputer runs once after that signal | Met for the nine in StartAnalyticsRecomputers [F]: recomputeWhenLoaded runs them in order rf, topology, channels, distance, hash-collisions, hash-sizes, observers-clock-skew, nodes-clock-skew, roles. Live log on the 51 K copy: recomputed 9 snapshots in 726ms. The /api/analytics/neighbor-graph response cache (Kpa-clawbot#1481) is not included; it reads s.graph from persisted neighbor_edges, not from the packet load, so it is unaffected in the normal case [A]. See nit 6 for the double pass. |
| Manual recompute runs on the loop and resets its ticker (no immediate duplicate) | Mostly met [F]. It runs on the loop goroutine, never overlaps, and resets the ticker. But a tick that comes due during the pass still triggers an immediate duplicate under go 1.22 timer semantics (finding 2). |
| Gated endpoints cannot open on a pass that began before the signal; force-open results replaced promptly | Met [F]. The gate is sampled before compute (analytics_recomputer.go:136), and the gate is now the startup signal instead of LoadComplete. Live, on the 51 K copy: RF 503 + Retry-After: 5 until the fill ended, then 200 with totalTransmissions: 51307. Master served 212 (hot window) as final and would keep doing so until the next 5 min tick. Mutants M2, M5 and M4 are caught. |
| Ungated endpoints keep their availability; no new 503 | Met [F]. hash-sizes stayed 200 throughout the live startup poll. The test checks hash-sizes, hash-collisions and roles. |
| Dependent caches and throttles invalidated before recompute | Met [F]. The hash-size info cache, the clock-skew throttle (new ClockSkewEngine.Invalidate, clock_skew.go:225) and the region/window TTL caches are dropped before close. Mutants M6 and M9 are caught. The clock_skew.go change is in scope: Recompute returns early when the last run is under 30 s old (clock_skew.go:238), so without it the post-load nodes/observers-clock-skew pass could return the partial result. |
| Distance snapshot refreshed before the index reports ready | Met [F]. Live: distance 202 → 200. Mutant M7 is caught. See finding 1 for the widened pre-existing race in the same block. |
| Background-load health/coverage semantics unchanged | Met [F]. The table test asserts backgroundLoadDone/Failed per path, including a failed fill (done=false, failed=true, with the signal still fired). The existing RunStartupLoad, Kpa-clawbot#1690 and Kpa-clawbot#1809 tests pass. |
Test-first and mutants
- Commit A adds only
analytics_after_startup_load_116_test.go, and it does not compile on master [T];go testof commit A fails to build [F]. The test file is byte-identical between A and the head [F]. - The only change to an existing test is
analytics_warmup_1659_test.go:loadComplete.Store(true)becomessignalStartupLoadDone(). That is justified, because the meaning of the gate changed. - Red on master behaviour [F]: I took the head, kept the new API, and reverted the fix (29 lines across 4 files). 8 of the 9 new tests go red:
RF during the background fill: 200, want 503hash-sizes did not recompute after the startup load finishedthe distance index reported built before the distance snapshot was refreshed- and others.
TestStartupLoadDoneWaitsForBackgroundFill_116passes vacuously on the revert, because the signal never fires. It is a guard against signalling too early and does catch M12.- The same 9 tests with
-race -count=10:okin 31 s [F].
All mutants were run against the head with -run '_116|Warmup|1659|RunStartupLoad|Distance'. After each run the file was restored, and shasum matched git show 0a463524:<path> for all 4 files [F].
| # | Mutant | Result |
|---|---|---|
| M1 | remove defer s.signalStartupLoadDone() |
caught (FiresOnEveryPath ×6, GatedRF) |
| M2 | sample the warm-up gate after compute (old behaviour) | caught (WarmupGateIgnoresPassStartedBeforeLoad) |
| M3 | remove t.Reset(r.interval) |
caught (RecomputeNowRunsOnLoopAndResetsTicker) |
| M4 | do not start the post-load pass | caught (EveryRecomputerRunsOnce, GatedRF, ForcedOpenReplaced) |
| M5 | gate back on s.LoadComplete |
caught (GatedRF, ForcedOpenReplaced) |
| M6 | drop clockSkew.Invalidate() |
caught (DropsDependentCaches) |
| M7 | drop rc.RecomputeNow() in the lazy distance build |
caught (DistanceSnapshotRefreshedBeforeReady) |
| M8 | drop the distCache clear in the lazy distance build |
survived; almost equivalent (nit 4) |
| M9 | drop invalidateCachesFor(eviction) at the signal |
caught (DropsDependentCaches) |
| M10 | roles before nodes-clock-skew | caught (EveryRecomputerRunsOnce) |
| M11 | stop closure does not wait on postLoadDone |
survived; test gap (nit 4) |
| M12 | signal before the background fill instead of deferred | caught (WaitsForBackgroundFill, GatedRF) |
Suites run locally
| Suite | Head | Master |
|---|---|---|
cmd/server go test -race -count=1 -timeout 60m ./... |
ok 896.3s (2002 tests listed) [F] |
ok 758.1s (1993 tests listed) [F] |
Read-only invariant tests (TestServerSourceHasNoCachedRWCalls, TestServerDBHasNoWriteMethods, TestServerDBConnIsReadOnly, TestPacketStoreHasNoMultibytePersistMethods) |
PASS [F] | n/a |
go vet . |
clean [F] | n/a |
gofmt -l on touched files |
4 files flagged, including store.go [F] |
3 files flagged; store.go clean [F] |
- The known flake
TestIssue1008_HandlerReturns503WhileSubpathIndexLoadingdid not fire in either run [F]. - The PR reports
ok 1632sfor the full race suite [T]; my run gaveok 896s. The difference is machine timing only. - No JS or E2E suites were run: no frontend files changed, and the master drift since the base is frontend-only and does not touch
cmd/.
Browser
Not applicable: there is no UI change. I checked the server side live with e2e-up.sh (head on 13780, master on 13781; both killed afterwards):
- Default config (hot window off), fixture: head and master both return 200 for all gated and ungated endpoints,
totalTransmissions: 500, and distance 202 → 200. retentionHours=720, hotStartupHours=1, 51,409-transmission copy of the fixture (100 time-shifted replicas; 213 in the hot hour), poll every ~0.1 s from launch:- head:
t=1.2s rf=503 Retry-After: 5, topology=503, hash-sizes=200→t=6.3s rf=200 total=51307→t=6.5s topology=200. The fill completed at +6 s. - master:
t=0.37s rf=200 total=212for the whole poll. After the fill, master still servedrf totalTransmissions=212,hash-sizes total=159,channels activeChannels=15; the head served 51307, 40299 and 19.
- head:
Performance and security
Performance [F].
-
On the 51 K copy the post-load round took 726 ms in total, run sequentially:
Recomputer Time rf 33 ms topology 350 ms channels 59 ms distance 0 ms hash-collisions 27 ms hash-sizes 204 ms observers-clock-skew 14 ms nodes-clock-skew 38 ms roles 0 ms -
The PR's own measurement covers 499 rows (34 ms) only [T].
-
This is one extra round per process start. Because the passes run sequentially, a writer waits for at most one compute's read-lock hold at a time.
-
Production scale (~1.6 M observations) is not measured, by the PR or by me. The PR's "Not verified" section says so.
-
Cache drops are map resets, O(1).
Locking and deadlocks [F by reading].
signalStartupLoadDonetakeshashSizeInfoMu,clockSkew.muandcacheMu→channelsCacheMuone after another, and never holds one acrossclose. That order matches the existinginvalidateCachesFor.TriggerDistanceIndexBuildreleasescacheMuandanalyticsRecomputerMubeforeRecomputeNow.RecomputeNowholds no lock while it waits, and it returns onr.stop.- The stop closure closes
stopPostLoad, stops each recomputer (eachRecomputeNowwait unblocks throughr.stop), then waits for the post-load goroutine. I found no cycle.
Goroutines and timers [F]. One post-load goroutine per StartAnalyticsRecomputers; it exits on the signal or on stop. RecomputeNow blocks until Start if the recomputer has not started yet. The only external caller that could see an unstarted recomputer is the distance build, and it only waits briefly while StartAnalyticsRecomputers is still starting them.
Other checks [F]. No new map[string]interface{} outside one test assertion. No DB writes, and the read-only invariant tests pass. No DOM or HTML surface.
Not verified
- Timings at production size (100 K+ transmissions, ~1.6 M observations), and how long the 503 window lasts there compared with the frontend's ~30 s retry budget (finding 3) [K].
- Staging startup with a real hot/background split [K]. No ssh by brief.
- How often the widened distance race (finding 1) is hit in practice. I only reproduced it deterministically with hooks.
- Frontend behaviour during a warm-up longer than 30 s. It was not exercised in a browser; this is based on reading
public/app.js[A]. - Reviewer probe tests were kept locally only; nothing was committed.
Brings in #151 (fix #149, distance build lock order). #145's hunk that clears distCache and recomputes the distance snapshot lands inside the new runDistanceIndexBuild loop, after s.mu.Unlock and before the distLazyMu section, so it holds neither lock. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
…lts (#116) A region- or area-keyed distance result cached from the index as it was before a build must not be served once the build reports the index built. Red without the distCache reset in runDistanceIndexBuild. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
|
Review feedback addressed (commit
Local runs on
Not changed here: finding 2 (ticker tick buffered during |
Relates to #116
Plan and design
The user asked for autonomous work, so the plan is written here instead of waiting for sign-off (AGENTS.md rule 5).
Commits:
1a668004: tests. They do not compile on master (noStartupLoadDone,RecomputeNow,LastStartAtorClockSkewEngine.Invalidate).0a463524: the fix.9996e08f: merge oforigin/master(e829d1ea), which brings in fix(store): lazy distance build — drop the reset sync.Once, fix the lock order (#149) #151 (the fix(store): lazy distance build can crash (sync.Once reset during Do) and deadlock (lock order) #149 distance build lock fix). See "Sync with master" below.6d608a7a: gofmt of thestartupLoadDonefield block instore.go(review nit 5).9729a9be: test that a distance build drops region/area TTL results (review nit 4, mutant M8).Sync with master (after #151)
origin/mastere829d1eawas merged in with a merge commit; there were no conflicts. #151 replaced thesync.Oncein the lazy distance build with thedistLazyBuilding/distLazyBuiltstate underdistLazyMu, and moved the build intorunDistanceIndexBuild, a loop that builds once more when the background load completed during a build.Git placed this PR's hunk (clear
distCache, thenRecomputeNow()on the distance recomputer) inside that loop, afters.mu.Unlock()and before thedistLazyMusection that setsdistLazyBuilt = true. That is the right place:s.munordistLazyMu.computeAnalyticsDistancetakess.mu.RLock, ands.mumust never be taken whiledistLazyMuis held (fix(store): lazy distance build can crash (sync.Once reset during Do) and deadlock (lock order) #149). The lock-order guard does not follow calls intoRecomputeNow, so this was checked by reading, and the fix(store): lazy distance build can crash (sync.Once reset during Do) and deadlock (lock order) #149 tests pass with-race -count=10.Review finding 1 (P2,
sync.Oncereset whileDoruns) is fixed on master by #151 and no longer applies to this branch.Claims in the issue, verified against master
main.gostarts the recomputers right afterFirstChunkReady.Start()computes on the partial store, and the next pass comes one interval (5 min) later.LoadComplete(), which flips at the end of the hot window, beforeloadBackgroundChunksfills the retention window.retentionHours=720,hotStartupHours=1), afterbackground load complete: 499/499:/api/analytics/rfreturns 200 withtotalTransmissions: 213(the hot-window snapshot), until the next 5-minute tick;Change
One-shot terminal signal.
StartupLoadDone()(chunked_load.go) is closed by a deferredsignalStartupLoadDone()whenRunStartupLoadreturns, on every path:hotStartupHours=0LoadChunkederrorIt is separate from
LoadComplete()(end of the hot window) and frombackgroundLoadDone/Failed. Those keep their health/coverage meaning: after a failed fillbackgroundLoadDonestays false, but the signal still fires.Dependent caches dropped before the signal closes:
ClockSkewEngine.Invalidate)RecomputeNow()(analytics_recomputer.go). Runs a pass on the recomputer's own loop goroutine, so it never overlaps a periodic pass, and resets the ticker, so no periodic pass follows right behind it.Post-load pass.
StartAnalyticsRecomputersrecomputes all nine current default-shape recomputers once, sequentially, after the signal:One log line reports the per-recomputer durations.
Warm-up gate (Kpa-clawbot#1659). The gate is now the startup-load signal, sampled before each compute, so a pass that began on partial data never opens it. 503 +
Retry-Afterand the 60 s force timeout are unchanged. A forced-open partial snapshot is replaced by the post-load pass.Ungated endpoints. Their availability is unchanged (no new 503s); their snapshots are replaced right after the load.
Distance. Each pass of the lazy build (
runDistanceIndexBuild) clears the distance TTL cache and refreshes the distance recomputer before reporting the index built, so the handler never goes from 202 to an older snapshot or to a region/area result computed from the older index.How this differs from upstream
Kpa-clawbot/CoreScope#2025Upstream is read as a reference only; nothing was cherry-picked.
rfCache,topoCache,hashCache,collisionCache,chanCache,distCache,subpathCache, channels list) are also dropped at the signal. Upstream listed them as "not verified".LastStartAt()exposes when a pass started, which the tests use to prove that passes start after the signal and run in the required order.Acceptance criteria
TestStartupLoadDoneFiresOnEveryPath_116(6 paths; a second signal is a no-op),TestStartupLoadDoneWaitsForBackgroundFill_116TestEveryRecomputerRunsOnceAfterLoad_116(all nine, exactly +1, started after the signal, gated first, roles after nodes-clock-skew)TestRecomputeNowRunsOnLoopAndResetsTicker_116(no overlap, no immediate periodic pass, loop continues, returns on a stopped recomputer)TestWarmupGateIgnoresPassStartedBeforeLoad_116,TestForcedOpenSnapshotReplacedAfterLoad_116, end to end inTestGatedRFWaitsForBackgroundFill_116TestGatedRFWaitsForBackgroundFill_116: hash-sizes, hash-collisions and roles return 200 during the loadTestStartupLoadDoneDropsDependentCaches_116TestDistanceSnapshotRefreshedBeforeReady_116TestDistanceBuildDropsRegionAreaCache_116TestStartupLoadDoneFiresOnEveryPath_116assertsbackgroundLoadDone/Failedper path; existingRunStartupLoad/Kpa-clawbot#1690/Kpa-clawbot#1809 tests passTests
analytics_after_startup_load_116_test.go: 10 test functions (one a table test with 6 paths). They do not compile on master; on this branch all pass, including 10× under-race.TestDistanceBuildDropsRegionAreaCache_116. It holds the lazy build before it reads the dataset (the fix(store): lazy distance build can crash (sync.Once reset during Do) and deadlock (lock order) #149distanceBuildHookgate) and cachesSJC|,|BAYandSJC|BAYdistance results from the index as it was before the build (0 hops). This models a request that passed theDistanceIndexBuilt()check just before an invalidation and cached its result after the startup signal had dropped the cache. After the build reports built, each key must return a fresh result equal tocomputeAnalyticsDistanceon the built index (3 hops), not the cached map. Without thedistCachereset inrunDistanceIndexBuildit fails for all three keys (served the result cached from the pre-build index after the index reported built);TestDistanceSnapshotRefreshedBeforeReady_116alone lets that mutant survive.LoadCompleteTestAnalyticsRF_AfterFirstPassReturns200now models "loaded" withsignalStartupLoadDone()instead of settingloadComplete, because the gate's meaning changed as the issue requires.TestWarmup_GateBlockedUntilLoadCompleteis unchanged; it passes its own gate function.go test -run "_116|Warmup|1659|RunStartupLoad|Recomputer|Distance|ClockSkew|StartupLoad|Chunked|1690|1809": ok.-racesuite (cd cmd/server && go test -race -count=1 ./...):ok github.com/corescope/server 1632.212s.sync.Onceguards and the Analytics cards show post-restart slice with 'All data' selected until multiple manual refreshes Kpa-clawbot/CoreScope#1659 warm-up tests with-race -count=10: ok. Full server suite with-race: see the latest follow-up comment.go vetis clean.store.gois gofmt-clean again.analytics_recomputer.go,analytics_warmup_1659.goandclock_skew.gowere already not gofmt-clean on master; this PR's lines in them follow the surrounding style, and CI does not run gofmt.Local run on a database copy
test-fixtures/e2e-fixture.db, freshened, withlast_seenderived fromfirst_seen; 499 transmissions, 214 in the last hour. Config:retentionHours=720,hotStartupHours=1./api/analytics/rf→ 200,totalTransmissions: 499. The master binary on the same copy gives 213.Perf
Not verified
Overlap with other open PRs
cmd/server/store.go: this PR changesrunDistanceIndexBuild(one block) and one struct field. fix(store): preserve first_seen ordering when merging background chunks #137 (fix(store): preserve first_seen ordering when merging background chunks #114), fix(store): remove evicted transmissions from resolved byPathHop entries #144 (fix(store): remove evicted transmissions from resolved byPathHop entries #115) and fix(store): lazy distance build — drop the reset sync.Once, fix the lock order (#149) #151 (fix(store): lazy distance build can crash (sync.Once reset during Do) and deadlock (lock order) #149) are merged into master and included through the sync.cmd/server/chunked_load.gois changed only by this PR.origin/mastere829d1ea.Open review findings
RecomputeNowpass can still start a periodic pass right after it, becausego.modisgo 1.22andt.Resetdoes not draint.C. Not changed here.<-postLoadDone) and nit 6 (extra post-load pass when the load finishes before the recomputers start): not changed here.🤖 Generated with Claude Code
https://claude.ai/code/session_019TcZHooUiiknVWbECVWzk8
Generated by Claude Code