Skip to content

fix(server): bound resolved-path LRU entry age for /paths confirmation (#277) - #316

Merged
dborup merged 8 commits into
masterfrom
codex/issue-277-paths-lru-followups
Oct 7, 2026
Merged

dborup merged 8 commits into
masterfrom
codex/issue-277-paths-lru-followups

Conversation

@dborup-agent

Copy link
Copy Markdown
Collaborator

Relates to #277

Follow-ups from the review of #246. All three points are addressed; only point 1 changes server behaviour.

Plan

# Issue point Decision Tests
1 Stale resolved-path LRU in /paths / /hop_analytics Bound the entry age: 60 s TTL (poll-loop invalidation is not possible without new SQL, see below). Clock read once per request. Red-first reproduction plus guards
2 Rejected candidates cached Measured first. Keep caching (0 rejected candidates per call on realistic data) Guard test pinning why they stay rare
3 #246 tests pass trivially / only via query counts Rename, comment, and add behavioural assertions Strengthened tests, red against the "before" mutants

No config or customizer implications. The TTL is an internal cache bound, not a user-facing value. No frontend change.

1. Stale LRU: bounded entry age

Why not invalidate in the poll loop. The ingestor's observation upsert (ON CONFLICT … resolved_path = COALESCE(excluded.resolved_path, resolved_path)) rewrites the row in place and keeps its id. The server's poll loop only reads new ids (IngestNewObservations: WHERE o.id > ?), so no existing poll query ever sees the change. Invalidating there would need a new ingestor-side change log (as route_mask_changes does for #89), a schema change, and at least one more query per poll tick. That is more than the issue's "no extra SQL per poll" bar allows.

What this does instead.

  • Each apiResolvedPathLRU entry records when it was stored. An entry older than resolvedPathLRUTTL (60 s) is a miss. The next read refreshes it in place and keeps its FIFO slot, so lruOrder gets no duplicates.
  • The clock is monotonic (time.Since of a package epoch). Wall-clock steps can therefore neither extend nor cut an entry's life.
  • /paths and /hop_analytics read the clock once per request (fetchResolvedPathForTxBestAt). A cache hit with a per-hit time.Now() measured 80 ns against 15 ns on this kvm-clock VM, and /paths does one hit per candidate.
  • The poll path is untouched. Nothing on it reaches the LRU.
  • The packets page and node health use the same LRU, so they converge too.

Trade-off. For up to 60 s after a rewrite, the old path can still be served. Each requested entry costs one primary-key read per 60 s (measured below as the "after 62 s" pass).

Not covered. A rewrite that adds the target to a path does not reach the in-memory hash index until restart. That is a pre-existing limitation, documented in cmd/ingestor/resolved_path_backfill.go. This change only stops the endpoints from answering from an old path.

2. Rejected candidates: measured, kept

Method: load the store, then for every node clear the LRU, call the endpoint, and classify every LRU entry the call created. An entry is either accepted, rejected by the canonical path, or rejected where the old SQL check would also have rejected it. That last class is the cost #246 added.

Dataset hop-index candidates (max/call) canonical fetches (max/call) rejected after fetch only-SQL-rejected (max/call)
CI-prepared fixture (533 tx / 536 obs, 204 nodes) 2,872 (207) 2,147 (207) 0 0
20× copy (10,014 tx / 76,384 obs) 57,421 (4,140) 42,940 (4,140) 0 0
20× copy, 5 % of resolved_path rows rewritten after load (synthetic stale index) 57,421 (4,140) 42,940 (4,140) 2,345 (233) 135 (13)

/hop_analytics gives identical counts.

Prefix collisions are the common reason a candidate does not belong to the node. They are dropped by the hash-index check before any fetch. Only 64-bit FNV collisions and stale index entries reach the fetch. Even with an unrealistically high 5 % rewrite rate, that is at most 13 entries per call in a 10,000-entry LRU (0.13 %). Not caching them would make every repeat call re-read them. So caching stays, and TestNodePaths_PrefixCollisionsExcludedBeforeCanonicalFetch pins the ordering that keeps them rare.

3. Test clarity

  • TestPathLenFast_MatchesReference / _RandomisedAgainstReference are renamed to TestPathLen_EquivalenceGuard_Corpus / _Randomised. Both now compare pathLenFast directly and require it to serve inputs: the corpus's well-formed entries, and at least one non-empty random array. A build without a fast path now fails both.
  • TestNodePaths_StaleIndexEntryStillExcluded is renamed to …_StaleIndexEntryExcludedWithoutSQLConfirm. It also asserts that the tx was decided from its canonical path. The pre-perf(server): remove per-candidate SQL and JSON parsing from /paths and /hop_analytics #246 SQL pre-filter dropped it unread, so the test now fails on the old code without relying on the query counter.
  • TestNodePaths_NoCanonicalPathStillConfirmedBySQL is renamed to …_NoCanonicalPathConfirmedBySQLExactlyOnce. The comment states that the query count is the only observable difference from the old code (the response is identical by design).

Commits

  1. test(server): reproduce the stale LRU. Red on its own: both endpoints keep the tx an hour after its stored path stopped containing the target.
  2. fix(server): 60 s entry age.
  3. test(server): guard for point 2.
  4. test(server): point 3 renames and assertions.
  5. perf(server): one LRU clock read per request, and a monotonic clock.

Perf proof

Master c713e32a vs this branch, same machine (4 vCPU VM, kvm-clock), same DB copies. Each server ran alone on its own copy.

In-process, warm, all 204 nodes per op (benchstat, n=10, interleaved, 20× copy):

master branch
/paths 152.9 ms ± 5 % 154.5 ms ± 9 % ~ (p=0.63)
/hop_analytics 72.2 ms ± 10 % 73.7 ms ± 6 % ~ (p=0.44)
poll tick, idle 880 µs ± 2 % 907 µs ± 4 % ~ (p=0.11), code unchanged
poll tick, 50 new observations 1.94 ms ± 7 % 1.93 ms ± 4 % ~ (p=0.68)
1,000 LRU hits as a request does them 15.29 µs 15.27 µs ~ (p=0.74)
single fetchResolvedPathForObs hit (packet detail, health) 15.2 ns 55.9 ns one monotonic clock read

HTTP, sequential curl, all 204 nodes (mean / p95 ms; two runs each, run 2 in brackets):

Dataset Pass master branch
fixture /paths cold 0.65 / 1.13 (0.79 / 1.24) 0.70 / 1.23 (0.65 / 1.14)
fixture /paths warm ×3 0.65 / 1.09 (0.65 / 1.06) 0.60 / 1.01 (0.57 / 0.98)
fixture /hop_analytics ×3 0.53 / 0.74 (0.52 / 0.71) 0.50 / 0.69 (0.42 / 0.56)
20× /paths cold 1.76 / 4.03 (1.75 / 4.09) 1.82 / 4.03 (1.67 / 4.11)
20× /paths warm ×3 1.26 / 3.15 (1.37 / 3.35) 1.25 / 3.14 (1.33 / 3.33)
20× /hop_analytics ×3 0.87 / 1.80 (0.90 / 1.86) 0.87 / 1.81 (0.86 / 1.84)
20× /paths 62 s later 1.34 / 3.49 (1.28 / 3.06) 2.06 / 4.72 (1.79 / 4.33)

The last row is the price of the fix. After the TTL, the first call per node re-reads its entries and costs about as much as a cold call. Calls within the window are unchanged.

Complexity. O(1) extra per cache lookup (one subtraction). One clock read per /paths / /hop_analytics request. No extra SQL on the poll path. The LRU stays bounded at 10,000 entries; each entry is 8 bytes larger.

Checks

  • cmd/server stays read-only. No new SQL; readonly_invariant_test.go passes.
  • No new map[string]interface{}.
  • No frontend files, so no colours. scripts/check-xss-sinks.sh --diff origin/master is clean.
  • No .github/ change. Fork guards: 9 in deploy.yml, 1 in release-fast-path.yml.

🤖 Generated with Claude Code

dborup and others added 5 commits October 6, 2026 08:53
…RU entry (#277)

The ingestor's observation upsert can replace a stored resolved_path in
place. /paths and /hop_analytics read the canonical path through
apiResolvedPathLRU, which is never invalidated, so they keep attributing
the tx to a node its stored path no longer contains.

Adds a clock hook on the LRU (unused here) so the test can move time
forward. Red on this commit; the next commit fixes it.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
/paths, /hop_analytics and the packets page read the canonical
resolved_path through apiResolvedPathLRU. The ingestor's upsert can
replace a stored path in place (same row id), and the poll loop only
reads new ids, so it cannot invalidate the entry; detecting the change
would need a new ingestor change log and another query per poll tick.

Bound the entry age instead: an entry older than resolvedPathLRUTTL
(60 s) is a miss and is refreshed in place by the next read, keeping its
FIFO slot. An entry stored after the lookup's clock (wall clock stepped
back) is treated as expired. Nothing changes on the poll path.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
…th fetch (#277)

Since #246 a hash-index candidate costs a canonical-path fetch and an LRU
entry even when its stored path does not contain the target. Measured on
the CI-prepared fixture and a 20x copy, no candidate is rejected after
that fetch: prefix collisions, the usual non-member candidates, are
dropped by the index check first. Rejected candidates therefore stay
cached; this test pins the order that keeps them rare, for /paths and
/hop_analytics. Numbers are in the PR description.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
- TestPathLenFast_MatchesReference / _RandomisedAgainstReference become
  TestPathLen_EquivalenceGuard_Corpus / _Randomised. Comparing pathLen
  with the reference also passes without a fast path, so both now check
  pathLenFast directly and require it to serve the well-formed inputs.
- TestNodePaths_StaleIndexEntryStillExcluded becomes
  ..._StaleIndexEntryExcludedWithoutSQLConfirm and also asserts the tx
  was decided from its canonical path (the pre-#246 pre-filter dropped it
  unread), so it fails on the old code without relying on the counter.
- TestNodePaths_NoCanonicalPathStillConfirmedBySQL becomes
  ..._NoCanonicalPathConfirmedBySQLExactlyOnce; its comment says the
  query count is the only observable difference from the old code.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
…equest (#277)

Giving LRU entries an age added a time.Now() to every cache hit. On a
kvm-clock VM that is ~65 ns against a 15 ns hit, and /paths does one hit
per candidate (up to ~4k per request on a 20x fixture copy).

- The LRU clock is monotonic (time.Since of a package epoch): one clock
  read, and wall-clock steps cannot stretch or cut an entry's life, so
  the "stored in the future" guard is gone. An entry stored after a
  request's clock read is fresh.
- fetchResolvedPathForTxBestAt / fetchResolvedPathForObsAt take the clock
  from the caller; /paths and /hop_analytics read it once per request.

1000 warm hits per request: 15.29 us on master, 15.27 us here (benchstat,
n=10, p=0.74). A single-lookup call (packet detail, health) pays one
clock read, ~40 ns. Tests pin one clock read per warm request and a
minimum useful entry life.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
@dborup-agent

Copy link
Copy Markdown
Collaborator Author

Rapport — CS-pve-agent2 PR#316 #277 — head 34e68c1

Status: All three points addressed. Every requirement has a test and caught mutants. CI is green on all jobs with no reruns. The PR is still a draft; nothing merged, readied or closed.

Evidence tags: [T] = test, benchmark or command run for this PR; [A] = code reading or analysis; [K] = taken from the issue, #246 or its review, not re-checked.

Point 1 — stale resolved-path LRU

Requirement Test Red before / green after Mutants (all caught)
Reproduce: a stored resolved_path changes and /paths / /hop_analytics answer from the stale LRU entry TestNodePaths_RewrittenResolvedPathNotServedFromStaleLRU Red at e4950b85 (test-only commit): both endpoints still list the tx an hour after the rewrite. Green from c084b015 [T] M1a: lookup ignores age
The cache still serves within the TTL (trade-off pinned; entry must live ≥ 30 s) TestNodePaths_ResolvedPathLRUServesCachedEntryWithinTTL Green before and after (guard) [T] M1a; M1d: TTL = 0; M1d2: TTL = 10 s; M1f: lookup bypasses LRU; M1j: …At ignores caller's clock
Expired entry refreshed in place, no duplicate FIFO slot; entry stored after the request's clock read is fresh TestResolvedPathLRU_ExpiryAndInPlaceRefresh Green after [T] M1b: no refresh on re-put; M1c: "future" entry expired; M1e: duplicate lruOrder slot
Clock is monotonic TestResolvedPathLRU_DefaultClockIsMonotonic Green after [T] M1g: wall clock (time.Now().UnixNano())
Clock read once per warm request (perf characteristic) TestNodePaths_WarmRequestReadsLRUClockOnce Green after [T] M1h: /paths reads per candidate; M1i: /hop_analytics reads per candidate; M1f

Choice and justification.

  • I chose a bounded entry age (60 s) instead of poll-loop invalidation. The server's poll loop only reads new observation ids (IngestNewObservations: WHERE o.id > ?). The ingestor's upsert rewrites resolved_path in place under the same id. So no existing poll query sees the change [A].
  • Invalidating on change would need a new ingestor change log, a schema change and an extra query per poll tick. That fails the "no extra SQL per poll" condition [A].
  • Nothing on the poll path reaches the LRU (IngestNewFromDB/IngestNewObservations do not call the fetchers) [A].

Poll-path cost [T] (benchstat, n=10, interleaved, 20× fixture copy). Code is unchanged; measured anyway:

Poll tick master branch
idle 880 µs 907 µs ~ (p=0.11)
50 new observations 1.94 ms 1.93 ms ~ (p=0.68)

cmd/server stays read-only: no new SQL, and readonly_invariant_test.go is in the green suite [T].

Found while measuring. The first version read time.Now() on every cache hit: 15 → 80 ns on this kvm-clock VM, about 1.5 % of a full warm /paths sweep [T]. Fixed in 34e68c18: monotonic clock, read once per request. Per request with 1,000 hits: 15.29 µs on master vs 15.27 µs on the branch (p=0.74) [T].

Point 2 — caching rejected candidates

Requirement Test Red before / green after Mutants (all caught)
Measure rejected candidates per call on realistic data Probe run on the CI-prepared fixture, a 20× copy, and the 20× copy with 5 % of rows rewritten (numbers in the PR description) n/a (measurement) [T] n/a
Prefix collisions are excluded before the canonical fetch (the reason the count is ~0) TestNodePaths_PrefixCollisionsExcludedBeforeCanonicalFetch Green before and after: no code change for this point, so no red-before. It is red against M2a/M2b, which every pre-existing test misses [T] M2a: /paths keeps non-indexed candidates; M2b: same in /hop_analytics

Numbers per call:

Dataset Rejected after canonical fetch Only-SQL-rejected
fixture 0 0
20× copy 0 0
20× copy, 5 % rows rewritten max 233 max 13 (vs up to 4,140 fetches; 0.13 % of the 10k LRU)

/hop_analytics gives identical counts [T]. Decision: keep caching. It doesn't matter at this scale, and not caching would re-read the same stale entries on every call [A].

Point 3 — test clarity

Requirement Test Red before / green after Mutants (all caught)
TestPathLenFast_* passed trivially without a fast path Renamed TestPathLen_EquivalenceGuard_Corpus / _Randomised; both now check pathLenFast directly and require it to serve inputs Master's versions pass under M3a. The new versions fail under M3a and M3b [T] M3a: no fast path (always falls back); M3b: fast path serves only []
Stale-index test failed on old code only via the query count Renamed TestNodePaths_StaleIndexEntryExcludedWithoutSQLConfirm, plus a behavioural assertion (the tx is decided from its canonical path) Under M3c, master's version fails only on the counter. The new version also fails on excluded the stale-index tx without reading its canonical resolved_path [T] M3c: pre-#246 SQL pre-filter restored in /paths; M3d: same in /hop_analytics
No-canonical-path test passed on old code except for the count Renamed TestNodePaths_NoCanonicalPathConfirmedBySQLExactlyOnce; comment says the count is the only observable difference No behavioural difference exists by design: #246 claimed identical output [A][K] Covered by #246's B4 mutant [K]

Perf: /paths and /hop_analytics before and after (same data)

In-process, warm, all 204 nodes per op (benchstat, n=10, interleaved, 20× copy) [T]:

master branch
/paths 152.9 ms 154.5 ms ~ (p=0.63)
/hop_analytics 72.2 ms 73.7 ms ~ (p=0.44)

HTTP, sequential curl, all 204 nodes, two runs each, on the CI-prepared fixture and the 20× copy: cold /paths, warm /paths and /hop_analytics are equal within run-to-run noise. The full table is in the PR description [T].

The one intended cost is the first /paths per node after 62 s on the 20× copy: 1.79–2.06 ms mean on the branch vs 1.28–1.34 ms on master. That is a cold-equivalent re-read once per TTL [T].

Rules

  • No new map[string]interface{} (0 added outside tests) [T].
  • No frontend files changed, so no hardcoded colours. scripts/check-xss-sinks.sh --diff origin/master reports nothing to scan [T].
  • Fork guards: 9 in deploy.yml and 1 in release-fast-path.yml. No .github/ change [T].
  • 5 commits, each authored and committed by dborup <kontakt@meshview.dk>. No rebase, amend or force-push [T].

Local test runs

Run Result
cmd/server go test -count=1 ./... ok (490 s) [T]
Touched tests, -race -count=3 ok [T]
cmd/ingestor go test ./... ok (1,161 s) with CI's -timeout 20m. The first run with Go's default 10 m timeout timed out; the package needs more than 10 min here [T]
sh test-all.sh 222 passed, 0 failed [T]
node test-frontend-helpers.js 709 passed, 0 failed [T]

E2E against a local branch server on a CI-prepared e2e-fixture.db (stopped by pid) [T]:

Suite Result
test-e2e-playwright.js 132/135, 3 fixture skips
test-issue-1146-path-link-contrast-e2e.js 11/11
test-issue-1281-location-row-e2e.js 6/6
test-issue-1206-resize-observer-leak-e2e.js 28/28
test-path-inspector-e2e.js 6/6

CI (run 37449209012, head 34e68c18)

Job Result
Go Build & Test pass (23m36s)
Playwright E2E Tests pass (23m42s)
Build & Publish Docker Image pass (56s)
Release Artifacts / Deploy / Publish Badges skipped (not a push to the main repo)

No reruns. The known flaky test (#271) did not fail [T].

Remaining

  1. Pre-existing flake, not fixed here. Several /paths handler tests call store.Load() without WaitIndexesReady, so they race the background path-hop index build and sometimes get 503 index loading. Seen in 1 of 8 grouped local runs on the branch (…_HopName_CanonicalPathShowsTarget_1144) and in 2 of 25 on origin/master (…_SortByRecency_1145, …_SortCountTiebreaker_1145) [T]. Worth its own issue.
  2. Hash-index staleness is out of scope. A rewrite that adds a node to a stored path still only reaches the in-memory hash index on restart (documented in resolved_path_backfill.go) [A].
  3. Dead fallback cache (follow-up). In fetchResolvedPathForTxBest, the fallback caches the result under the sibling's obs id, but the next call looks up the longest obs id first. So the multi-row fallback query repeats on every call for those txs [A]. Not measured; separate from Follow-ups to #246: stale resolved-path LRU in /paths confirmation, rejected-candidate caching, test clarity #277.
  4. Not measured: production-sized data, a multi-GB DB file, and concurrent /paths load. All timings are from the fixture and a synthetic 20× copy on one VM [A].

@dborup-agent

Copy link
Copy Markdown
Collaborator Author

Review — CS-pve-agent1 PR#316 — head 34e68c1

Dom: APPROVE med nits. F1 is a one-line test fix and I recommend applying it before merge.

Evidence tags: [T] = test, benchmark or command I ran myself; [A] = my own code reading or analysis; [K] = taken from the PR or the author's report, not re-checked.

Trees used: head 34e68c18 (merge-base c713e32a). Merged with origin/master 30c7de46 (tree 5ea72bac), and again with de6e83b4 (tree 313e99aa), because master moved during the review. Both merges are clean. The remote head was 34e68c18 before and after.

Findings

# Severity Finding Evidence
F1 Medium (test gap) The production clock's unit is not pinned by any test. Every staleness test installs lruClock (wall UnixNano), so the default branch of lruNow() (int64(time.Since(lruEpoch))) is only checked by TestResolvedPathLRU_DefaultClockIsMonotonic, which asserts b > a and b ≤ 1 h. Changing the default clock to .Milliseconds() or .Microseconds() passes all 12 touched tests and 299 related cmd/server tests (-run 'LRU|Resolved|Paths|Hop|Health|Detail'). In production that would make the TTL about 694 days (ms) or 16.7 h (µs): the fix becomes a silent no-op while CI stays green. Suggested fix, verified to kill both mutants and pass on head: in DefaultClockIsMonotonic, after the 1 ms sleep, assert store.lruNow()-a >= int64(time.Millisecond). [T]
F2 Nit The lruClock hook and the default clock use different time domains, and one field comment is wrong. store.go: lruClock … // nil = time.Now, but nil means a monotonic offset from lruEpoch. The hook returns wall UnixNano (about 1.8e18), the default a small offset. Installing the hook after entries exist would age every existing entry wrongly. Tests are safe today because they install it right after Load(), before the LRU is populated. Fix the comment; optionally make the hook func() int64 in the same domain as the default. That would also let F1's staleness tests exercise the production conversion. [A]
F3 Nit / doc The worst-case staleness is slightly more than 60 s. now is read once at the start of the request and storedAt is taken after the SQL read. So the worst case is resolvedPathLRUTTL + the request's duration + the read-to-put gap: in practice 60 s plus milliseconds. "Up to 60 s" in the PR body is fine in practice. A word in the resolvedPathLRUTTL comment would make it exact. [A]
F4 Info The shared LRU also changes behaviour elsewhere. Packet detail and node health (store.go, three call sites of fetchResolvedPathForObs / fetchResolvedPathForTxBest) now also re-read after 60 s and pay one clock read per hit (15 → 56 ns per the author). The PR describes this as intended convergence. I agree it is within the purpose of #277, since it is the same stale-data bug. [A], cost [K]
F5 Info The point-2 probe is not checked in, so the rejected-candidate table can't be re-run from the repo. I did not reproduce the numbers. [K]
F6 Info (pre-existing) The 503 index loading race appeared once in my runs (TestHandleNodePaths_FallbackPreconfirmed_1352, in a mutant run, not on unmodified code). This matches the author's "Remaining 1": several /paths tests don't call WaitIndexesReady. The new tests do wait, via reloadConfirmStore. Not caused by this PR. [T]

Answers to the review points

1. The choice (bounded entry age vs invalidation).

  • I agree with the reasoning [A]:
    • The ingestor's observation upsert (cmd/ingestor/db.go, ON CONFLICT(transmission_id, observer_idx, COALESCE(path_json,'')) DO UPDATE … resolved_path = COALESCE(excluded.resolved_path, resolved_path)) rewrites the row and keeps its id.
    • The server's only observation poll is WHERE o.id > ? ORDER BY o.id, so the server never sees the change.
    • A cheaper-looking alternative, evicting a tx's entries when a new observation for that tx arrives, doesn't help: the conflict path creates no new id.
    • So invalidation needs an ingestor-side change log, which means a schema change and more SQL per poll tick. A bounded age is the only option without new SQL.
  • Other writers don't create stale entries [A]. The backfill only writes NULL → value (… AND resolved_path IS NULL), and a NULL row is never cached (!rpJSON.Valid returns before lruPut).
  • The multi-row sibling fallback in fetchResolvedPathForTxBestAt is never served from the cache: it is stored under the sibling's id but looked up under the longest obs id. That path is therefore always fresh. As the author notes, the cache there is dead weight.
  • Worst case: /paths and /hop_analytics can serve a rewritten resolved_path for about 60 s (see F3). That is acceptable for an analytics view.
  • Documented: yes, in the resolvedPathLRUTTL comment and the PR body, including the remaining limitation that a rewrite which adds the target only reaches the hash index on restart (pre-existing).

2. Repro test red on master, green on head.

  • TestNodePaths_RewrittenResolvedPathNotServedFromStaleLRU, on origin/master 30c7de46 with only the one-line lruClock field added (as in e4950b85): FAIL for both endpoints ("tx still attributed to the target an hour after…") [T].
  • Green on head, on merged 30c7de46 and on merged de6e83b4 [T].
  • Mutants, all mine, run against the 12 touched tests on the merged tree [T]:
Mutant Result
A: age check removed from lruGet caught (RewrittenResolvedPath, ServesCachedEntryWithinTTL, ExpiryAndInPlaceRefresh)
B: default clock in ms (time.Since(lruEpoch).Milliseconds()) survives (see F1)
B2: default clock in µs survives (see F1)
C: hook clock in seconds (lruClock().Unix()) caught (3 tests)
D: TTL compared in seconds (resolvedPathLRUTTL/time.Second) caught (WithinTTL)
E: refresh updates storedAt but keeps the old value caught (RewrittenResolvedPath, ExpiryAndInPlaceRefresh)
F: wall clock as default (time.Now().UnixNano()) caught (DefaultClockIsMonotonic)
G: pathLen bypasses the fast path caught (WellFormedPathsStayOnFastPath)
H: pathLenFast declines everything caught (both EquivalenceGuard tests + WellFormed)

With the F1 assertion added, B and B2 are caught and the unmutated code still passes [T].

3. Clock and races.

  • go test -race -count=10 over the 12 touched tests on merged 30c7de46: ok, no races (36.7 s). On merged de6e83b4, -race -count=3: ok [T].
  • The clock is injectable without a global: lruClock is a per-PacketStore field. lruEpoch is a package var set once at init and only read [A].
  • Setting lruClock after Load() is safe in the tests: reloadConfirmStore waits for WaitIndexesReady first, and nothing on the load or poll path calls lruNow. The fetchers are only reached from request handlers [A]. See F2 for the domain mismatch.

4. Issue points 2 and 3.

  • Point 2: the PR reports a per-call measurement (0 rejected-after-fetch on the fixture and on the 20× copy; at most 13 only-SQL-rejected per call with 5 % synthetic rewrites) [K]. The decision to keep caching follows from those numbers. TestNodePaths_PrefixCollisionsExcludedBeforeCanonicalFetch pins the reason, and it is green [T]. The probe itself is not in the repo (F5).
  • Point 3: tests are renamed as the issue asks (TestPathLen_EquivalenceGuard_*, …_StaleIndexEntryExcludedWithoutSQLConfirm, …_NoCanonicalPathConfirmedBySQLExactlyOnce). Comments state what each one distinguishes. Behavioural assertions are added where a difference exists (lruHasTx: the canonical path was read) [A].
  • My mutant H (no fast path) fails both EquivalenceGuard tests, which the issue said passed trivially before [T].
  • I did not re-run the author's M3c (pre-perf(server): remove per-candidate SQL and JSON parsing from /paths and /hop_analytics #246 SQL pre-filter restored) [K].

5. Perf.

  • In-process benchmark (review-only, not committed): warm /paths and /hop_analytics for every node, master 30c7de46 vs merged 30c7de46. Same machine, separate DB copies, 10 interleaved rounds, benchstat [T]:
Data Endpoint master merged
CI-prepared fixture (533 tx / 536 obs, 204 nodes) /paths 34.07 ms ± 24 % 33.92 ms ± 29 % ~ (p=0.97)
same /hop_analytics 12.03 ms ± 17 % 11.52 ms ± 10 % ~ (p=0.19)
20× tx copy (10,033 tx / 10,093 obs) /paths 136.8 ms ± 3 % 140.6 ms ± 5 % ~ (p=0.19)
same /hop_analytics 48.18 ms ± 7 % 48.53 ms ± 11 % ~ (p=0.97)
  • No significant change. The geomean is −0.3 %. Each benchmark process stays inside the 60 s TTL, so this measures the warm path.
  • I did not measure the post-TTL refresh cost myself; the author reports a cold-equivalent first call per node after 62 s [K].
  • No extra SQL within the TTL: a hit is still a map lookup plus one subtraction [A]. After the TTL, there is one primary-key SELECT per expired entry, by design [A]. The poll path is unchanged [A].
  • cmd/server stays read-only: the diff adds no SQL at all, and readonly_invariant_test.go is in the green suite [T].

Rules

  • No new map[string]interface{} (0 added lines) [T].
  • No frontend or .github/ files changed, so no colours. scripts/check-xss-sinks.sh --diff origin/master on head: clean, exit 0 [T].
  • Fork guards: github.repository == 'Kpa-clawbot/CoreScope' appears 9 times in deploy.yml and once (as an if:) in release-fast-path.yml, both unchanged [T].
  • No closing keywords in the PR body ("Relates to Follow-ups to #246: stale resolved-path LRU in /paths confirmation, rejected-candidate caching, test clarity #277") or in any of the 5 commit messages [T].
  • All 5 commits have author and committer dborup <kontakt@meshview.dk> [T].
  • Commit split: the test-only commit e4950b85 adds only the lruClock field to non-test code [T].

Tests I ran

Run Tree Result
cmd/server go test -count=1 ./... merged 30c7de46 ok (851 s) [T]
cmd/server go test -count=1 ./... merged de6e83b4 ok (674 s) [T]
cmd/ingestor go test -count=1 -timeout 25m ./... merged 30c7de46 (PR doesn't touch the ingestor) ok (1,408 s) [T]
sh test-all.sh merged 30c7de46 / de6e83b4 224/224 · 225/225 passed [T]
node test-frontend-helpers.js merged 30c7de46 / de6e83b4 709 passed, 0 failed (both) [T]
Touched tests -race -count=10 / -count=3 merged 30c7de46 / de6e83b4 ok, no races [T]

E2E against a local Go server built from merged 30c7de46, on e2e-fixture.db prepared as in CI: freshen, Kpa-clawbot#1486/Kpa-clawbot#1791 seed SQL, corescope-migrate, seeds 2073, 199 and 245. Servers were stopped by port [T].

Suite Result
test-issue-1146-path-link-contrast-e2e.js 11/11
test-issue-1281-location-row-e2e.js 6/6
test-issue-1206-resize-observer-leak-e2e.js 28/28
test-path-inspector-e2e.js 6/6
test-e2e-playwright.js Fails fail-fast at "Version info lives on Perf dashboard" (#navStats wait timeout). Identical against a master-only server and a head-only server, so it comes from my environment, not this PR. With a scratch copy of the harness that has fail-fast removed: merged 131/135, 3 skipped, 1 failed (that same test); master gives the identical result.

The PR has no E2E of its own, since there is no frontend change. The four suites above are the ones that hit /paths / /hop_analytics.

CI, run 37449209012 on 34e68c18, attempt 1: Go Build & Test pass, Playwright E2E pass, Docker build pass; Release / Deploy / Badges skipped (fork). Known flakes #256 / #267 were not involved [T].

Not verified

  • The point-2 rejected-candidate numbers and the author's HTTP curl timings and 1,000-hit micro-benchmark [K].
  • The post-TTL refresh cost [K].
  • The author's M3c/M3d mutants [K].
  • Production-sized data, concurrent /paths load, and the ingestor-plus-server interaction (a real upsert rewrite end-to-end rather than the test's direct UPDATE).
  • cmd/ingestor on merged de6e83b4; it is untouched by this PR.
  • No staging or production access was used.

dborup and others added 3 commits October 6, 2026 13:57
…#277)

F1: the default branch of lruNow() was only checked for monotonicity, so
a clock in ms or µs (TTL stretched to days/hours) passed every test.
Assert it advances by nanoseconds across a 1 ms sleep.

F2: the lruClock hook returns wall UnixNano while the default clock is a
small offset from lruEpoch, so installing the hook while entries exist
expires them all. Red until lruNow puts both in the same domain.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
… clock (#277)

The hook stands in for time.Now, but lruNow returned its UnixNano (about
1.8e18) while the default clock returns nanoseconds since lruEpoch.
Installing the hook while entries existed therefore expired them all.
lruNow now returns lruClock().Sub(lruEpoch), the same domain as
time.Since(lruEpoch). The production branch is unchanged. The field
comment no longer says nil = time.Now.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
@dborup-agent

Copy link
Copy Markdown
Collaborator Author

Rapport — CS-pve-agent3 PR#316 runde 2 — head 1fdff0f

Review feedback addressed (commit 1fdff0f6)

  1. F1: the production clock's unit is now pinned. The test is in 239b9da7. TestResolvedPathLRU_DefaultClockIsMonotonic is renamed …_DefaultClockIsMonotonicNanoseconds. Across a 1 ms sleep, lruNow() must now advance at least time.Millisecond and at most the outer interval measured on the same monotonic clock. So it fails both on too small a unit (ms, µs) and on too large a unit (ns × 1000). No production code change for F1: the default branch was already correct, and the finding was a test gap. So "red" here means red against the mutants (see below) [T].
  2. F2: one time domain for the hook and the default clock, and the comment is fixed. The fix is cheap, so I applied it instead of documenting the limit. Test in 239b9da7, fix in 1fdff0f6.
    • lruNow()'s hook branch now returns int64(s.lruClock().Sub(lruEpoch)) instead of s.lruClock().UnixNano(). The hook stands in for time.Now and is measured from lruEpoch, exactly like the default time.Since(lruEpoch). Installing it while entries exist no longer re-ages them [A][T].
    • The production branch is unchanged: still int64(time.Since(lruEpoch)), one monotonic read, no new cost [A].
    • The lruClock field comment (store.go) now reads test hook standing in for time.Now in lruNow; nil = time.Since(lruEpoch), monotonic. The lruNow doc comment states the shared epoch [A].
    • New test TestResolvedPathLRU_ClockHookSharesDefaultClockDomain: an entry stored on the default clock must still be served after lruClock = time.Now is installed, and must expire once the hook moves past resolvedPathLRUTTL. Red on the test-only commit 239b9da7 ("entry stored on the default clock expired once lruClock = time.Now was installed"), green on 1fdff0f6 [T].
    • The existing hooked tests (fakeLRUClock, WarmRequestReadsLRUClockOnce) needed no change. A shared-conversion mutant (C, below) is still caught by the staleness tests [T].

No other behaviour change. F3–F6 were out of scope for this round, as instructed.

Evidence tags: [T] = test or command I ran for this round; [A] = my own code reading; [K] = taken from the review or the earlier report, not re-checked.

Commits this round

Commit Content
54091721 Merge origin/master b0b9843c (clean; master had touched cmd/server/store.go)
239b9da7 test only: F1 + F2 tests (paths_lru_staleness_test.go)
1fdff0f6 fix: hook measured from lruEpoch; field and function comments

Author and committer are dborup <kontakt@meshview.dk> on all three. No rebase, amend or force-push (34e68c18..1fdff0f6 fast-forward) [T].

Mutants (all run by me, on the merged tree, against the 12 touched tests)

Mutant Where Result
B: default clock time.Since(lruEpoch).Milliseconds() default branch caught: DefaultClockIsMonotonicNanoseconds ("advanced 1 across a 1 ms sleep") [T]
B2: default clock .Microseconds() default branch caught: same test ("advanced 1063") [T]
B3: default clock int64(time.Since(lruEpoch)) * 1000 default branch caught: DefaultClockIsMonotonicNanoseconds + ClockHookSharesDefaultClockDomain [T]
F2m: hook back to s.lruClock().UnixNano() (pre-fix domain) hook branch caught: ClockHookSharesDefaultClockDomain [T]
F2m2: hook measured from time.Time{} instead of lruEpoch hook branch caught: 4 tests (RewrittenResolvedPath, WithinTTL, ExpiryAndInPlaceRefresh, ClockHookShares…) [T]
C: hook in seconds (…Sub(lruEpoch) / time.Second) hook branch caught: the same 4 tests [T]
Unmutated 12/12 pass [T]

The review showed that B and B2 survived the previous version of the test [K]. I ran B and B2 against the new test before writing the F2 fix: both fail [T].

The 12 touched tests pass with -race -count=10 (34 s). The two clock tests pass with -count=500: no flakes from the 1 ms sleep [T].

Local test runs (merged tree, head 1fdff0f6)

Run Result
cmd/server go test -count=1 ./... 1st run: FAIL, one test, TestHandleAnalyticsSubpathsWithStore (expected 200, got 503). 2nd run: ok (608 s) [T]
cmd/ingestor go test -count=1 -timeout 30m ./... ok (1,303 s) [T]
sh test-all.sh 225 passed, 0 failed [T]
node test-frontend-helpers.js 709 passed, 0 failed [T]

About the one failure. It is the pre-existing 503 index loading race: the test calls store.Load() without WaitIndexesReady and races the background subpath index build. It is the same class as "Remaining 1" in the earlier report and F6 in the review. It is not #271 or #301. Neither the test nor the subpath code is touched by this PR. Repeated alone (-count=2000, run sequentially), it fails 4/2000 on the branch and 2/2000 on origin/master b0b9843c. A small sample beforehand (-count=300) gave 2/300 on the branch and 0/300 on master. So it reproduces on master and is not caused by this PR [T]. Still worth its own issue.

E2E against a local Go server built from 1fdff0f6, on a copy of e2e-fixture.db prepared as in CI: freshen-fixture.sh, the Kpa-clawbot#1486/Kpa-clawbot#1791 seed SQL taken from deploy.yml, corescope-migrate, then seeds 2073, 199 and 245. The server was stopped by pid [T]:

Suite Result
test-e2e-playwright.js 132/135, 3 fixture skips
test-issue-1146-path-link-contrast-e2e.js 11/11
test-issue-1281-location-row-e2e.js 6/6
test-issue-1206-resize-observer-leak-e2e.js 28/28
test-path-inspector-e2e.js 6/6

Rules

  • No new map[string]interface{} (0 in the round-2 diff) [T].
  • No frontend changes. scripts/check-xss-sinks.sh --diff origin/master reports nothing to scan (exit 0) [T].
  • No .github/ change. Fork guards unchanged: 9 in deploy.yml, 1 in release-fast-path.yml [T].
  • gofmt: the three touched files are clean [T].

CI (run 37478466487, head 1fdff0f6, attempt 1)

Job Result
Go Build & Test pass (23m50s)
Playwright E2E Tests pass (24m23s)
Build & Publish Docker Image pass (53s)
Release Artifacts / Deploy Staging / Publish Badges & Summary skipped (not a push to the main repo)

No reruns. The known flaky tests #271 and #301 did not fail [T].

Not done / not verified

  • F3 (worst-case staleness wording), F4, F5 (probe not checked in) and F6 were out of scope for round 2 and are unchanged.
  • The pre-existing 503 index loading test race is documented, not fixed.
  • The PR stays a draft. Nothing merged, readied or closed. No staging or production access was used.

@dborup-agent

Copy link
Copy Markdown
Collaborator Author

Review — CS-pve-agent1 PR#316 — head 1fdff0f

Dom: APPROVE med nits. F1 and F2 from round 1 are fixed and verified. The remaining nits are documentation or report wording and don't block merge.

Evidence tags: [T] = test, mutant or command I ran myself; [A] = my own code reading or analysis; [K] = taken from the PR or the author's report, not re-checked.

Trees used:

  • head 1fdff0f6;
  • the test-only commit 239b9da7;
  • head merged with origin/master bf3151a4 (git merge-tree --write-tree, clean, tree c5c7e564).

The PR's own merge commit 54091721 is a clean merge: its tree equals git merge-tree 34e68c18 b0b9843c (f70d8717) [T]. The remote head was 1fdff0f6 before and after the review [T].

Findings

# Severity Finding Evidence
R2-1 Nit (comment precision, test-only) The new lruNow comment holds for all hooks in use today, but only exactly for hooks that carry a monotonic reading. Sub(lruEpoch) uses the monotonic reading when both times have one (time.Now, time.Now().Add(…), the constant base := time.Now()). fakeLRUClock returns time.Unix(0, n), which has none, so Sub falls back to wall time. That only differs from the default clock if the wall clock steps between process start and the install. That is test-only and harmless, but "measured from the same epoch, so installing it while entries exist keeps their ages" is not exact for a wall-only hook. A half-sentence would make it exact. No production impact: the hook is nil in production. [A], [T] (review-only test below)
R2-2 Info (report wording) The round-2 report says "the 12 touched tests" and "12/12". With …_ClockHookSharesDefaultClockDomain added there are now 13 (paths_lru_staleness_test.go 6, pathlen_fast_test.go 3, paths_confirm_deferred_test.go 4). All 13 pass. [T]
R2-3 Info (report wording) The report names #271 and #301 as the known flakes. The ones relevant to this pipeline are #256 (Hash Stats sort) and #267 (backfill write-hold). Neither failed in CI run 37478466487: the #226 Hash Stats adopters-sort E2E shows all ✓, and the Go job is ok. [T]
F3 (r1) Nit / doc, still open Worst-case staleness is resolvedPathLRUTTL + request duration + read-to-put gap, slightly over 60 s. It is unchanged and was out of scope for round 2. Still worth a word in the resolvedPathLRUTTL comment, in this PR or later. [A]
F4–F6 (r1) Info, unchanged Shared-LRU convergence for packet detail and health (F4); point-2 probe not checked in (F5); pre-existing 503 index loading test race (F6). F6 did not show up in my runs this round. [A] / [K]

Answers to the review points

1. F1: the production clock's unit is now pinned.

  • TestResolvedPathLRU_DefaultClockIsMonotonicNanoseconds requires a ≤ b and 1 ms ≤ b − a ≤ outer, where outer is measured around a and b on the same monotonic clock. The upper bound is deterministic, because [a, b] ⊆ [start, start+outer] on one clock. The lower bound follows from time.Sleep(time.Millisecond) [A].
  • My mutants, on the merged tree, against all 13 touched tests [T]:
Mutant Change Result
M1 (round 1's B) default clock time.Since(lruEpoch).Milliseconds() caught: DefaultClockIsMonotonicNanoseconds ("advanced 1 across a 1 ms sleep")
M2 (round 1's B2) default clock .Microseconds() caught: same test ("advanced 1098")
M3 default clock × 2 caught: same test (2,168,152 > outer 1,084,208)
M4 default clock / 2 caught: same test (559,153 < 1 ms)
M8 both branches in ms (consistent unit change) caught: 5 tests, incl. the stale-LRU repro for both endpoints
Unmutated 13/13 pass
  • Red before / green after: on 239b9da7 (test-only) with M1 applied, the new test fails. Unmutated, it passes [T]. In round 1 I showed that the previous version of the test let M1 and M2 survive [T, round 1]. As the author notes, F1 needs no production change: the default branch was already correct.
  • Flake check: both clock tests -count=1000, ok [T].

2. F2: the comment is correct, and late hook installation doesn't age entries wrongly.

  • Production diff for F2 [T]: resolved_index.go hook branch s.lruClock().UnixNano() → int64(s.lruClock().Sub(lruEpoch)), plus the lruNow doc comment. In store.go, the lruClock field comment is now nil = time.Since(lruEpoch), monotonic, which is correct. The default branch is unchanged.
  • TestResolvedPathLRU_ClockHookSharesDefaultClockDomain is red on 239b9da7 ("entry stored on the default clock expired once lruClock = time.Now was installed") and green on head and on the merged tree [T].
  • Extra mutants on the hook branch [T]:
Mutant Change Result
M5 hook back to s.lruClock().UnixNano() (pre-fix) caught: ClockHookSharesDefaultClockDomain
M6 hook ignored (int64(time.Since(lruEpoch))) caught: 5 tests
M7 hook measured from time.Now() instead of lruEpoch caught: ExpiryAndInPlaceRefresh
  • Review-only test (not committed) [T]: two entries are stored on the default clock, one about 50 ms old. Then each hook kind used in the suite is installed afterwards (time.Now-based, fakeLRUClock, constant base). For all three:

    • ages are preserved (about 50 ms and about 10 µs);
    • both entries are still served;
    • entry 2 is still served at TTL − 200 ms;
    • both expire at TTL + 0.8 s.

    With M5 applied, every hook kind sees ages of about 497,597 h and expires everything at once, which is the round-1 F2 bug. See R2-1 for the wall-only nuance.

3. Production behaviour: only what F1/F2 require.

  • git diff 34e68c18 1fdff0f6 -- ':!*_test.go' also contains master's changes through the merge 54091721. That merge is clean (tree identical to git merge-tree), so I compared the PR's own round-2 commits: git diff 54091721 1fdff0f6 -- ':!*_test.go' [T].
  • That diff is exactly:
    • one changed line in lruNow (hook branch);
    • comment lines in resolved_index.go;
    • one comment line in store.go.
  • 239b9da7 is test-only (paths_lru_staleness_test.go, +35/−2) [T].
  • No new SQL, no change to the default clock, lruGet/lruPut, or callers. cmd/server stays read-only [A].

4. CI per job (run 37478466487 on 1fdff0f6, attempt 1, pull_request) [T]:

Job Result
Go Build & Test pass (23m50s); cmd/server ok at 90.5 % coverage, cmd/ingestor ok
Playwright E2E Tests pass (24m23s)
Build & Publish Docker Image pass (53s)
Release Artifacts / Deploy Staging / Publish Badges & Summary skipped (not a push to the main repo)

No --- FAIL lines in the log. The known flakes #256 and #267 were not involved.

Rules

  • Every acceptance criterion of Follow-ups to #246: stale resolved-path LRU in /paths confirmation, rejected-candidate caching, test clarity #277 has a test that is red before and green after:

    • point 1: the stale-LRU repro (round 1);
    • point 3: the renamed tests, killed by the round-1 mutants G and H;
    • F1/F2: as above.

    Point 2 is a measured decision, pinned by TestNodePaths_PrefixCollisionsExcludedBeforeCanonicalFetch [T].

  • No new map[string]interface{}: 0 added lines across the PR's own diff vs origin/master [T].

  • No frontend or .github/ files in the PR's diff, so no colours. bash scripts/check-xss-sinks.sh --diff origin/master on head: "no public/**/*.{js,html} changes to scan", exit 0 [T].

  • Fork guards: github.repository == 'Kpa-clawbot/CoreScope' appears 9 times in deploy.yml and once in release-fast-path.yml, on head and on the merged tree [T].

  • No closing keywords in the PR body or in any commit message in origin/master..1fdff0f6 [T].

  • All PR commits, including the merge, have author and committer dborup <kontakt@meshview.dk> [T].

  • gofmt -l on the 3 touched files: clean. go vet on cmd/server (merged): clean [T].

Tests I ran

Run Tree Result
cmd/server go test -count=1 ./... merged bf3151a4 ok (1,403 s) [T]
cmd/ingestor go test -count=1 ./... merged bf3151a4 (byte-identical to master; the PR doesn't touch it) 1st run with -timeout 30m: hit the time limit, with 0 --- FAIL (running TestInsertTransmission_RouteMaskUnderParallelIngest, 9 s in) on this I/O-bound VM. Re-run with -timeout 60m: ok (989 s) [T]
sh test-all.sh merged 225 passed, 0 failed [T]
node test-frontend-helpers.js merged 709 passed, 0 failed [T]
13 touched tests -race -count=10 merged 130/130 pass, no races [T]
Clock tests -count=1000 merged ok [T]
Mutants M1–M8 + review-only late-hook test merged / 239b9da7 see above [T]

E2E against a local Go server built from the merged tree, on e2e-fixture.db prepared as in CI [T]:

The server was stopped by port (fuser -k 13581/tcp).

Suite Result
test-issue-1146-path-link-contrast-e2e.js 11/11
test-issue-1281-location-row-e2e.js 6/6
test-issue-1206-resize-observer-leak-e2e.js 28/28
test-path-inspector-e2e.js 6/6
test-e2e-playwright.js Stops at "Version info lives on Perf dashboard" (#navStats wait timeout), as in round 1. With a scratch copy of the harness that has fail-fast removed: merged 130/135, 4 skipped, 1 failed (that same test). A master-only server (bf3151a4, its own public/) on the same DB gives identical per-test outcomes. So the failure comes from my environment, not this PR; CI's E2E job passes.

These are the suites that hit /paths / /hop_analytics. The PR has no E2E of its own (no frontend change).

Not verified

  • Production-sized data, concurrent /paths load, and a real ingestor upsert rewrite end-to-end (the tests use a direct UPDATE).
  • The post-TTL refresh cost, the point-2 probe numbers and the author's micro-benchmarks [K]. I did not re-run perf this round, because the production change is one line on the test-hook branch only.
  • Why #navStats doesn't fill in my local Playwright run. It is identical on master, so I didn't dig further.
  • No staging or production access was used.

@dborup
dborup marked this pull request as ready for review October 7, 2026 07:14
@dborup
dborup merged commit c8b5d1a into master Oct 7, 2026
6 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants