Skip to content

tests: deflake pre-existing flaky Go and E2E tests - #571

Merged
dborup merged 12 commits into
masterfrom
test/567-deflake-preexisting
Oct 24, 2026
Merged

dborup merged 12 commits into
masterfrom
test/567-deflake-preexisting

Conversation

@dborup-agent

@dborup-agent dborup-agent commented Oct 24, 2026 •

Copy link
Copy Markdown
Collaborator

Relates to #567

Makes the pre-existing flaky tests from #567 deterministic. For each one I found the root cause first. One of them is a real product race and is fixed in the product. The others are test races, fixed by waiting for a real readiness signal or by removing a wall-clock/cwd dependency. No assertion is weakened, and no sleep or retry is added. The #556 API-count flake (test-issue-531-region-url-e2e.js) is handled in #570 and is not touched here.

Plan and root causes

# Test Root cause Kind Fix
1 TestRepeaterRelayInfoMap_ConcurrentIngestAndEviction The oracle called collectRelayEntriesLocked(key) without a metadata snapshot, so it read the node cache, which is nil until the first bulk reader warms it. The round-0 oracle therefore credited no relay, while every bulk read credited 100 per relay. A reader that finished before round 1 "matched no store state". test Snapshot node metadata once (snapshotPathNodes), the way GetRepeaterRelayInfo does, and assert that the round-0 oracle carries relay evidence.
2 TestHandleNodePaths_SortByRecency_1145, TestHandleNodePaths_PrefixCollision_1352_FallbackBranch (+ same-shaped siblings) Load() builds the path-hop index in the background and /paths answers 503 until it is ready (Kpa-clawbot#1008, by design). The tests queried right after Load(). test New loadStoreIndexed helper (Load + WaitIndexesReady, which wakes on the ready channel). Used by every /paths test that loaded without waiting; AnchorBias_1278's 10 ms poll loop becomes the same helper.
3 TestServerProcess_NormalStartDoesNotWait main called signal.Notify inside the shutdown goroutine, so /api/healthz could answer before that goroutine ran. A SIGTERM in that window took Go's default action: exit -1, no graceful shutdown. product Register SIGINT/SIGTERM synchronously before the goroutine starts and before ListenAndServe. Guarded by an AST test.
4 "Version info lives on Perf dashboard" (test-e2e-playwright.js) Without ldflags, .git-commit or a git cwd, /api/health reports "unknown", and renderVersionCard deliberately hides the card. The test treated "unknown" as present (!!"unknown") and waited for a card that never comes. test Route /api/health through the real response, overriding only version/commit plus a sentinel uptimeHuman. The sentinel shows up in the Uptime card and proves which response was rendered. Both branches are asserted (hidden for unknown/unknown, exact text otherwise). The route is always removed.
5 observer-IATA mobile (test-observer-iata-1188-e2e.js) At 375px a saved window above 3 h is capped back to 15 min (#340, intentional), so the list had rows only while the freshened fixture was under 15 min old. Under load two more test races showed up. The list re-renders rows after data-loaded, so a held row handle could be detached at click time, and $eval could read a detached <td>, whose computed display is "", so it counted as "visible". test Pin a single-observation packet from an IATA-tagged observer and open #/packets?hash=…, which suppresses the time window by contract. Click via a locator, and read cells and the badge in one evaluate. Also stronger: require ≥1 observer cell (the old .catch(() => false) let "no cell" pass) and require that the detail badge equals the observer's IATA.
6 "a very narrow tile wraps between stats" and "360x800: both tile stats stay inside the tile" (test-issue-497-rx-airtime-e2e.js) locator.evaluate resolves the tile and runs the function on the handle in a second round trip. RF Health rebuilds the grid with innerHTML on every theme-refresh and region/area change, so a rebuild in between measured a detached tile. A detached element has a zero rect and an empty computed style, which reads exactly as the CI failures did: {"nowrap":false,"inside":true,"oneLine":false}. Late CSS is ruled out, because style.css is a head <link> that scripts wait for and the RF Health gotos are same-document hash navigations. Really missing CSS reads oneLine:true, not false. test measureTile finds and measures the tile in one waitForFunction task and waits until the tile exists. The assertions are unchanged.
7 TestTrackedBytes_MixedSequenceDoesNotDrift_113 (SQLITE_BUSY) The acct113 fixture asked for WAL with ?_journal_mode=WAL, a DSN parameter that modernc.org/sqlite ignores. The file stayed in the rollback journal, and no fixture connection had a busy timeout. The loaded store's schema healer re-probes this schema every 2 s, because the fixture lacks optional columns. A fixture commit that met that read failed at once. test acct113OpenWriter opens the fixture the way cmd/ingestor/db.go opens the real database (_pragma=journal_mode(WAL) + _pragma=busy_timeout(5000)) and reads both pragmas back. Every writer of the fixture uses it. New TestAcct113Fixture_ServerReadDoesNotBlockWriter_567 holds a server read open while the fixture writes.

Tests and evidence

CPU load means 2×nproc busy loops on a 4-core linux/amd64 host.

# Red before Green after Mutants (all killed)
1 New round-0 assertion: 30/30 red; original flake 4/150 150/150 under load, 150/150 under load with -race Bulk key traversal after RUnlock: DATA RACE under -race; 2 mismatches + 1 panic in 150 without it
2 Under load on master: 50/100 and 54/100 return 503 150/150 under load, 30/30 with -race; all 11 /paths tests 30/30 under load Helper without the wait (29/60 red under load); recency sort removed (SortByRecency red); uniquePrefix := true (FallbackBranch red)
3 New AST guard red on master; a 2 s delay before the goroutine's Notify reproduces the CI signature 3/3 (exit -1, no "received" line) 150/150 under load with -race; the same 2 s delay before the now-synchronous Notify: 3/3 pass Notify back in the goroutine (master); go signal.Notify(…); guard controls cover goroutine / go statement / SIGINT-only
4 Server without a resolvable commit: timeout Green against a no-git and a git cwd; 30/30 under load (no-git) Card shown for unknown/unknown; commit dropped; no card
5 Fixture aged 40 min: 5/5 red 30/30 under load (aged fixture); green on a fixture aged 1 day Detail row without the IATA badge; fixed IATA in the detail; observer column made tier-1 (visible on mobile)
6 Forced re-render (theme-refresh every 15 ms on the 360 px tests): 15/15 red with the PR's CI signature. The handle measured after a rebuild gives the master CI JSON byte for byte 30/30 under load; 30/30 under the forced re-render white-space: nowrap removed from .rf-cell-stats > span; flex-wrap removed; measureTile without the null guard (5/5 red under re-render)
7 New writer-during-read test: red every run. Original test 24/150 under load with -race; healer forced to a 1 ms tick: 10/10 150/150 each (mixed sequence + new test) under load with -race, 0 data races; 1 ms tick: 0/60 Old DSN (_journal_mode=WAL, _busy_timeout=5000): read-back red; rollback journal + busy timeout: writer-during-read test red; WAL without busy timeout: 1 ms tick 3/30 and 10/60 red

Suites: cmd/server and cmd/ingestor go test ./..., sh test-all.sh, node test-frontend-helpers.js, and all three changed E2E files against a local Go server on e2e-fixture.db, prepared as in CI. Results are in the report comment.

Notes

  • Round 2 merges origin/master (273c2162). cmd/server stays read-only. No new map[string]interface{}, no frontend or CSS change, no .github change. Fork guards are unchanged (9 in deploy.yml, 1 in release-fast-path.yml).
  • The product change (fix(map): sync Important Links with Byte Size filter #3) only moves two lines. A SIGTERM during start-up before the listener binds still takes the default action after the schema wait. That is unchanged behaviour and not this flake.
  • Items 6 and 7 change only test code. cmd/server/db.go OpenDB also passes _journal_mode=WAL&_busy_timeout=5000, which modernc ignores, so the server's read connections have no busy timeout. That is a product question and is not changed here (see the report).
  • The comment in public/packets.js (fix(#1692): parallelize loadObservers + loadPackets in /packets init() Kpa-clawbot/CoreScope#1693) attributes the earlier mobile flake to the MutationObserver debounce. The detached-element read described above is what remained. Product code is unchanged.

🤖 Generated with Claude Code

dborup and others added 8 commits October 24, 2026 13:24
TestRepeaterRelayInfoMap_ConcurrentIngestAndEviction builds its oracle with
collectRelayEntriesLocked(key) and no metadata snapshot, which falls back to
the node cache. That cache is cold until the first bulk reader warms it, so
the round-0 oracle credits no relay while the bulk reader (which loads the
cache) credits 100 per relay. A reader that finishes before round 1 then
"matches no store state" — the flake (4/150 linux/amd64, 66/150
darwin/arm64).

This assertion makes the mismatch deterministic: red 30/30.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
The oracle called collectRelayEntriesLocked(key) without a metadata
snapshot, so it read the node cache, which is nil until the first bulk
reader warms it. Round 0 was therefore published without relay identities
while every bulk read resolved them. Snapshot the metadata once, the way
GetRepeaterRelayInfo does, so every round describes the evidence the bulk
reader sees. Test-only: the product bulk/single paths already agree.

150/150 green under 2x-nproc CPU load, with and without -race. The lock
mutant (bulk key traversal after RUnlock) is still killed: DATA RACE under
-race, and mismatches/panic without it.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Load() builds the path-hop index in a background goroutine and
/api/nodes/{pk}/paths answers 503 "index loading" until it is ready (Kpa-clawbot#1008,
by design). Several /paths tests queried right after Load(), so under CPU
load they raced the build: SortByRecency_1145 failed 50/100 and
PrefixCollision_1352_FallbackBranch 54/100 on master with 2x-nproc load.

Add loadStoreIndexed (Load + WaitIndexesReady, which wakes on the ready
channel) and use it in every /paths test that loaded without waiting:
SortByRecency/SortCountTiebreaker_1145, the Kpa-clawbot#1352 collision scenario,
FallbackUniquePrefix_1352, HopName_1144 and PrefixCollisionExclusion.
AnchorBias_1278's 10 ms poll loop becomes the same helper.

After: 150/150 green under load for both named tests, 30/30 with -race.
Mutants: helper without the wait (29/60 red under load); no recency sort
(SortByRecency red); uniquePrefix always true (FallbackBranch red).

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

main calls signal.Notify inside the shutdown goroutine, so /api/healthz can
answer before that goroutine runs; a SIGTERM in that window takes Go's
default action (exit -1, no "[server] received" line), the CI failure of
TestServerProcess_NormalStartDoesNotWait. This guard parses main.go and
requires the SIGTERM registration as a statement of main before
httpServer.ListenAndServe. Red on master (Notify is in a func literal);
the controls show it rejects a goroutine/go-statement/SIGINT-only
registration and accepts the fixed order.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
signal.Notify for SIGINT/SIGTERM ran inside the shutdown goroutine, while
main went on to ListenAndServe. /api/healthz could answer before that
goroutine was scheduled, and a SIGTERM in that window took Go's default
action: exit -1 with no graceful shutdown (CI Go Server Tests 3/3 on #555,
TestServerProcess_NormalStartDoesNotWait). Register synchronously before
the goroutine starts, so healthz 200 implies the handler is installed.

Probe on master (2 s before the goroutine's Notify): 3/3 exit -1. Same
probe after the fix (before the now-synchronous Notify): 3/3 pass.

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

At 375px the packets page caps a saved time window above 3 h back to 15 min
(#340, intentional), so the test's localStorage window of a year was
ignored and the list had rows only while the freshened fixture's newest
packet was under 15 min old. After ~30 min it showed "No packets found"
and the wait for a row timed out.

Pick a single-observation packet from an IATA-tagged observer via
/api/packets and open #/packets?hash=<hash>, which suppresses the time
window by contract (buildPacketsParams). The detail badge must now also
show that observer's IATA.

Red before: fixture aged 40 min, the mobile case times out. After: green on
fixtures aged 40 min and 1 day. Mutants: detail Observer row without the
badge, and a fixed IATA in the detail — both red.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
…567)

The server resolves version/commit from ldflags, .git-commit or
`git rev-parse` in its cwd. Without them both read "unknown", and
renderVersionCard deliberately hides the card. The test treated "unknown" as
present (!!"unknown"), so it waited for a card that never comes whenever the
server could not resolve a commit: green in CI, red locally.

Route /api/health through the real response, overriding only version,
commit and a sentinel uptimeHuman (the Uptime card shows it, which marks the
render the assertions read). Both branches are now asserted: unknown/unknown
hides the card, and a known pair renders "v9.9.9-e2e · 01234567". The route
is always removed afterwards.

Red before: no-git server, timeout. After: green from a no-git and a git
cwd; 30/30 under 2x-nproc load. Mutants: card shown for unknown, commit
dropped, no card — all red.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Under CPU load the pinned mobile case still failed 6/30. The packets list
re-renders its rows after data-loaded (hop/observer decoration, ~10 ms and
~250 ms later), so:
- the held row handle was detached by click time ("Element is not
  attached to the DOM"), and
- $eval resolves the cell and reads its style in two round trips; a cell
  detached in between has computed display "" and read as "visible"
  (verified: an attached hidden td reads "none", the same td detached
  reads "").

Tap through a locator on the pinned row and read the observer cells and the
detail badge in single evaluates. The column check now also requires at
least one observer cell (the old .catch(() => false) passed with none).
Product code is unchanged: the column is always hidden at task boundaries
(0/30 runs with per-task polling).

30/30 green under 2x-nproc load on a 40-min-aged fixture. Mutants: detail
row without the badge, a fixed IATA in the detail, observer column made
tier-1 — all red.

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

Copy link
Copy Markdown
Collaborator Author

Rapport — CS-pve-agent1 PR#571 #567 — head 48d33d8

Status: All five #567 items are fixed and locally green (N≥30 under CPU load, -race on the Go tests). CI is green except Playwright E2E (3/3), which hit a pre-existing, unrelated layout flake in test-issue-497-rx-airtime-e2e.js. The same file also failed on master at the base commit b3fc76da. It is not #271, so the job was not re-run. The PR is still a draft.

Evidence: [T] test or command run, with its result · [A] analysis by the author · [K] source code reference

CPU load = 2×nproc busy loops on a 4-core linux/amd64 host.

Requirements

# Test Root cause Fix Red before Green after Mutants (killed)
1 TestRepeaterRelayInfoMap_ConcurrentIngestAndEviction Test. The oracle called collectRelayEntriesLocked(key) without a metadata snapshot and fell back to the node cache, which is nil until the first bulk reader warms it. Round 0 credited 0 relays, while the bulk reader credited 100 per relay. Every failure started at round 0 [T] [K] repeater_liveness.go collectRelayEntriesLocked, store.go pathNodeSnapshotLocked Snapshot metadata once (snapshotPathNodes), like GetRepeaterRelayInfo, and assert that the round-0 oracle carries relay evidence [T] New assertion red 30/30; original flake 4/150 on master [T] 150/150 under load; 150/150 under load with -race [T] Bulk key traversal after RUnlock: DATA RACE under -race (5/5); without -race 2 mismatches + 1 panic in 150
2 TestHandleNodePaths_SortByRecency_1145, …_PrefixCollision_1352_FallbackBranch (+ 9 same-shaped /paths tests) Test. Load() builds the path-hop index in the background and /paths answers 503 until it is ready (Kpa-clawbot#1008, by design). The tests queried right after Load() [K] index_ready_1008.go, routes.go handleNodePaths loadStoreIndexed = Load + WaitIndexesReady (channel-based readiness, no polling); AnchorBias_1278's 10 ms poll loop becomes the same helper [T] Master under load: 50/100 and 54/100 return 503 [T] 150/150 each under load; 30/30 with -race under load; all 11 /paths tests 30/30 under load [T] Helper without the wait: 29/60 red under load; recency sort removed: SortByRecency red; uniquePrefix := true: FallbackBranch red
3 TestServerProcess_NormalStartDoesNotWait Product. main called signal.Notify inside the shutdown goroutine; /api/healthz could answer before that goroutine ran, and a SIGTERM in that window took Go's default action (exit -1) [K] main.go shutdown goroutine Register SIGINT/SIGTERM synchronously before the goroutine and before ListenAndServe (moves 2 lines). New AST guard TestMainRegistersShutdownSignalsBeforeListening_567 plus guard controls [T] Guard red on master. A 2 s delay before the goroutine's Notify on master reproduces the CI signature 3/3 (exit -1, no "received" line) [T] 150/150 under load with -race (guard, controls and process test); the same 2 s delay before the now-synchronous Notify: 3/3 pass [T] Notify back inside the goroutine (master): red; go signal.Notify(…): red; controls reject goroutine / go-statement / SIGINT-only
4 "Version info lives on Perf dashboard" Test. Without ldflags, .git-commit or a git cwd, /api/health reports "unknown", which renderVersionCard deliberately hides. The test treated "unknown" as present [K] main.go resolveCommit, public/perf.js renderVersionCard Route /api/health through the real response, overriding version/commit and a sentinel uptimeHuman (rendered in the Uptime card = readiness signal). Both branches asserted, route always removed [T] Server started from a non-git cwd: timeout [T] Green from a non-git and a git cwd; 30/30 under load (non-git) [T] Card shown for unknown/unknown; commit dropped; no card — all red
5 observer-IATA mobile E2E Test. At 375px a saved window above 3 h is capped to 15 min (#340, intentional), so rows existed only while the freshened fixture was under 15 min old [K] public/packets.js isMobile && savedTimeWindowMin > 180. Under load, 6/30 more failures had two causes. Rows re-render after data-loaded, so the held row handle could be detached. And $eval read a detached <td>, whose computed display is "" (verified in Chromium: attached none, detached ""), so it counted as visible [T] Pin a single-observation packet from an IATA-tagged observer via #/packets?hash=… (suppresses the time window by contract [K] buildPacketsParams); click via a locator; read cells and badge in one evaluate. Stronger: ≥1 observer cell required, detail badge must equal the observer's IATA [T] Fixture aged 40 min: 5/5 red [T] 30/30 under load (aged fixture); green on a fixture aged 1 day [T] Detail row without the badge; fixed IATA in the detail; observer column tier-1 (visible on mobile) — all red

[A] Product code is unchanged for #5. With per-task polling from page start, the observer cell was never visible at a task boundary (0/30 under load). The earlier "visible" readings were the detached-element read.

Suites (local)

  • [T] cd cmd/server && go vet ./... && go test ./...: ok. cd cmd/ingestor && go test ./...: ok.
  • [T] -race -count=3 over every touched Go test (TestHandleNodePaths_*, relay, _567, TestServerProcess_*, TestMainGo_*, TestIssue1008_*): ok.
  • [T] sh test-all.sh: 267 passed, 0 failed. node test-frontend-helpers.js: 719 passed, 0 failed.
  • [T] E2E against a local Go server on e2e-fixture.db prepared as in CI (freshen, inline seed SQL, corescope-migrate, seeds 2073/199/245/122), with the server started from a non-git cwd (commit unknown): test-e2e-playwright.js 154/157 (3 built-in skips, 0 failed); test-observer-iata-1188-e2e.js 3/3. Servers were stopped by pid and port.
  • [T] test-issue-497-rx-airtime-e2e.js on this branch locally: 5/5 green.

CI per job (run 40102051732, head 48d33d8c, attempt 1)

Job Result
Go Build & Test pass
Go Server Tests (1/3, 2/3, 3/3) pass
Go Ingestor Tests pass
Go Libraries & CLI pass
Verify Go Test Assignments pass
JavaScript Unit Tests & Lint pass
Script & Container Unit Checks pass
Validate Docker Image pass
Playwright E2E Tests (1/3), (2/3) pass
Playwright E2E Tests (3/3) fail: test-issue-497-rx-airtime-e2e.js "360x800: both tile stats stay inside the tile, each on one line" (oneLine:false)
Verify E2E Shards & Coverage fail (needs E2E 3/3)
Build & Publish Docker Image fail (needs the aggregate)
Publish Badges, Release Artifacts, Deploy Staging skipped

Failure analysis:

Hygiene

Remainders

  1. test-issue-497-rx-airtime-e2e.js narrow-tile layout flake (master and this PR, CI only; 5/5 local). It deserves its own issue. Not filed (outside this mandate).
  2. [A] A SIGTERM during start-up before the listener binds (between the schema wait and the shutdown registration) still takes the default action. That is unchanged behaviour and not this flake. Deferring termination during a long load would be a behaviour change, so it is left as is.
  3. [A] The comment in public/packets.js (fix(#1692): parallelize loadObservers + loadPackets in /packets init() Kpa-clawbot/CoreScope#1693) attributes the earlier mobile flake to the MutationObserver debounce. The remaining cause was the detached-element read in the test. The comment was not edited, since this PR makes no frontend change.
  4. [K] Only linux/amd64 was measured. The relay flake was reported at 66/150 on darwin/arm64. Its root cause (a cold node cache in the oracle) is platform-independent, but arm64 was not re-measured here.

dborup and others added 4 commits October 24, 2026 15:21
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
…r read (#567)

TestTrackedBytes_MixedSequenceDoesNotDrift_113 failed on master 273c216
with "database is locked (5) (SQLITE_BUSY)" on a fixture INSERT. The
fixture asks for WAL with "?_journal_mode=WAL", which modernc.org/sqlite
ignores (it applies only _pragma, _time_format and _txlock), so the file
is in the rollback journal (PRAGMA journal_mode = delete) and neither
connection has a busy timeout. The loaded store's schema healer re-probes
this schema every 2 s for its missing optional columns; a commit that
meets that SHARED lock fails at once.

The new test holds a read open on the server's connection and writes
through a fixture connection: red, SQLITE_BUSY, every run.

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

The acct113 fixture asked for WAL with "?_journal_mode=WAL", a DSN
parameter modernc.org/sqlite ignores. The file stayed in the rollback
journal, and no fixture connection had a busy timeout. Tests write to
the fixture while a loaded store reads it. The store's schema healer
re-probes this schema every 2 s, because the fixture lacks optional
columns. A commit that met one of those reads failed with SQLITE_BUSY.
That was 24/150 under 2x-nproc load with -race on the parent commit,
and with the healer forced to a 1 ms tick it was 10/10.

acct113OpenWriter opens the fixture the way cmd/ingestor/db.go opens
the real database: _pragma=journal_mode(WAL) and _pragma=busy_timeout
(5000). It reads both pragmas back, because a parameter that is silently
dropped is exactly what broke here. WAL alone is not enough. A reader
still holds a WAL lock for a moment during the wal-index header check,
so with the forced 1 ms tick WAL without a busy timeout was still red
(3/30, 10/60). With both it was 0/60.

Every writer of this fixture uses the helper: create, the mixed
sequence, leak202Insert, the two ingest benchmarks and hm215Create.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
"a very narrow tile wraps between stats" failed in CI (master b3fc76d)
with {"tid":"avg: -111.0","nowrap":false,"inside":true,"oneLine":false},
and the 360x800 tile check failed on #571 with {"inside":true,
"oneLine":false}. That is the reading of a detached tile: the rect is 0
(so inside), and the computed style is empty, so whiteSpace is "" and
fontSize is NaN (so oneLine is false). An attached tile reads nowrap:true.

locator.evaluate resolves the tile (waitForSelector, attached) and runs
the function on the handle in a second round trip. RF Health rebuilds
the grid with innerHTML on every theme-refresh and region/area change,
so a rebuild in between measured the old, detached tile.

Late CSS is ruled out. style.css is a head <link> that scripts wait for,
and the RF Health gotos are same-document hash navigations, so the sheet
was applied long before. Holding style.css back 3 s kept the file green.

measureTile finds and measures the tile in one waitForFunction task and
waits until the tile exists. The assertions are unchanged.

Forced re-render (theme-refresh every 15 ms on the 360 px tests):
before 5/5 red with the CI signature, after 8/8 green. 30/30 green
under 2x-nproc CPU load.

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

Copy link
Copy Markdown
Collaborator Author

Rapport — CS-pve-agent1 PR#571 runde-2 — head d176af1

Review feedback addressed (commit d176af18)

  1. test-issue-497-rx-airtime-e2e.js "a very narrow tile wraps between stats" (and the 360x800 tile check that failed on this PR's first CI run): fixed in d176af18. The root cause was the test measuring a detached tile. Late CSS was not the cause. Test-only change; the assertions are unchanged.
  2. TestTrackedBytes_MixedSequenceDoesNotDrift_113 SQLITE_BUSY: red test in 1c69b026, fix in 525f1daa. The lock holder is the loaded store's schema healer. Its reads collided with a fixture that was never really in WAL and had no busy timeout. Test-only change.
  3. origin/master (273c2162) merged with a merge commit (02d33f88), with no conflicts. PR description updated (items 6 and 7 in both tables, plus notes). The PR is still a draft.

Evidence: [T] test or command run, with its result · [A] analysis by the author · [K] source code reference

CPU load = 2×nproc busy loops on a 4-core linux/amd64 host.

1. RX-airtime narrow tile (E2E)

Root cause.

  • [T] The CI failure on master b3fc76da (run 40097467456, attempt 1) was {"tid":"avg: -111.0","nowrap":false,"inside":true,"oneLine":false}. On this PR (run 40102051732) it was rf-cell-airtime: {"inside":true,"oneLine":false}. Both are the first stat of the tile.
  • [K] locator.evaluate (playwright-core 1.58.2, client/locator.js _withElement) first runs waitForSelector(state: attached), then handle.evaluate in a second round trip.
  • [K] RF Health rebuilds #rfHealthGrid with innerHTML on every renderTab (theme-refresh handler, RegionFilter/AreaFilter onChange → reloadForFilters), see public/analytics.js. A rebuild between the two round trips hands the function the old, detached tile.
  • [T] A detached element has a zero rect and an empty computed style. That gives inside:true, fontSize NaN → oneLine:false, and whiteSpace "" → nowrap:false. A standalone repro took a tile handle, fired one theme-refresh, waited for !isConnected and ran the test's own measurement. It printed {"tid":"avg: -111.0","nowrap":false,"inside":true,"oneLine":false}, the master CI JSON byte for byte. The same tile while attached printed nowrap:true, inside:true, oneLine:true.

The stylesheet hypothesis is ruled out.

  • [K] style.css is a <head> <link> before every script, so the tile cannot render before the rule applies.
  • [T] All RF Health page.goto calls in this file are same-document hash navigations. A route that holds style.css back 3 s fired only on the four real page loads, and the file stayed green.
  • [T] Really missing CSS (mutant M1 below) reads oneLine:**true** for that stat, not false. Only the detached reading matches CI.

Fix. measureTile runs one page.waitForFunction that finds the tile by data-observer and measures it in the same task. It returns null until the tile exists. Both layout tests use it, and the comment above them explains why text reads may keep locator.evaluate and layout reads may not.

Result
Red before [T] Forced re-render (preload harness: theme-refresh every 15 ms on RF Health at 360 px): original file 15/15 red, every run with this PR's CI signature rf-cell-airtime: {"inside":true,"oneLine":false}
Green after [T] 30/30 under CPU load; 30/30 under the forced re-render; a normal run is green
Mutants (all killed) [T] M1 white-space: nowrap removed from .rf-cell-stats > span: red (nowrap:false). M2 flex-wrap removed: red (12 samples … inside:false). M3 measureTile without the if (!cell) return null guard: 5/5 red under re-render (TypeError on an empty grid)

[A] Locally the grid was not rebuilt between the gotos (trace: one rebuild, caused by the test's own theme-refresh). The CI-side trigger is therefore one of the rebuild paths above landing in the window, and it was not pinned down further. The fix does not depend on which path it is.

2. TestTrackedBytes_MixedSequenceDoesNotDrift_113 — SQLITE_BUSY

Who holds the lock.

  • [K] modernc.org/sqlite v1.34.5 applyQueryParams applies only _pragma, _time_format and _txlock. The fixture's ?_journal_mode=WAL was silently ignored.
  • [T] The fixture reads back journal_mode=delete. The fixture writer and the server connection both have busy_timeout=0.
  • [K] [T] OpenDB starts healSchemaFlags. The fixture lacks optional columns (isV3, scope_name, last_seen flags are false), so the healer re-runs detectSchema (several reads) every 2 s for the whole test.
  • [A] In the rollback journal, a fixture commit that meets that SHARED lock fails at once with SQLITE_BUSY.

No other test shares the DB: each test uses its own t.TempDir() file.

Repro.

  • [T] With the healer tick forced to 1 ms (a temporary edit, not committed), the original test went 10/10 red with the CI message.
  • [T] The new TestAcct113Fixture_ServerReadDoesNotBlockWriter_567 holds a read open on the server's own connection and writes through the fixture. It was red on every run (1c69b026).

Fix. acct113OpenWriter opens the fixture exactly as cmd/ingestor/db.go:153 opens the real DB: _pragma=busy_timeout(5000)&_pragma=journal_mode(WAL). It reads both pragmas back, because a silently dropped parameter is what broke here. Every writer of this fixture uses it: create, the mixed sequence, leak202Insert, the two ingest benchmarks and hm215Create.

[T] WAL alone is not enough. Under the 1 ms tick, WAL without a busy timeout was still red (3/30, and 10/60 with the pool's idle closes ruled out). [A] A WAL reader can briefly hold a WAL lock during the wal-index header check. [T] With WAL and the busy timeout it was 0/60.

[A] The busy timeout is not a test sleep or retry. It is the production writer's own setting, and without it the fixture is not the database it stands in for.

Result
Red before [T] Original test 24/150 red under load with -race (all SQLITE_BUSY at the three INSERT sites, including master's line 448); 1 ms tick 10/10; new test red every run
Green after [T] 150/150 for the mixed sequence and 150/150 for the new test, under load with -race, 0 DATA RACE (26 min); 1 ms tick 0/60
Mutants (all killed) [T] G1 old DSN ?_journal_mode=WAL&_busy_timeout=5000: read-back red (journal_mode = "delete"). G2 _pragma=journal_mode(WAL)&_busy_timeout=5000: read-back red (busy_timeout = 0). G3 rollback journal + busy timeout, read-back disabled: the new test is red (writer blocked 5 s, then BUSY). G4 WAL without busy timeout, read-back disabled: 1 ms tick 3/30 and 10/60 red

Suites (local, head d176af18)

  • [T] cd cmd/server && go vet ./... && go test ./...: ok. cd cmd/ingestor && go test ./...: ok.
  • [T] The 59 acct113/202/215/490 tests: ok. -bench TrackedBytes -benchtime 1x: all four benchmarks run.
  • [T] sh test-all.sh: 267 passed, 0 failed. node test-frontend-helpers.js: 719 passed, 0 failed.
  • [T] E2E against a local Go server on e2e-fixture.db prepared as in CI (freshen, inline seed SQL, corescope-migrate, seeds 2073/199/245/122):
    • test-issue-497-rx-airtime-e2e.js: 16/16.
    • test-observer-iata-1188-e2e.js: 3/3.
    • test-e2e-playwright.js: 154/157 (3 built-in skips, 0 failed).

CI per job (run 40110929120, head d176af18, attempt 1, no re-runs)

Job Result
Go Build & Test pass
Go Server Tests (1/3, 2/3, 3/3) pass (3/3 ran MixedSequenceDoesNotDrift_113 and ServerReadDoesNotBlockWriter_567, both pass)
Go Ingestor Tests pass
Go Libraries & CLI pass
Verify Go Test Assignments pass
JavaScript Unit Tests & Lint pass
Script & Container Unit Checks pass
Validate Docker Image pass
Playwright E2E Tests (1/3), (2/3), (3/3) pass (3/3: both #497 tile tests ✅, "All #497 … passed")
Verify E2E Shards & Coverage pass
Build & Publish Docker Image pass
Release Artifacts, Deploy Staging, Publish Badges & Summary skipped (branch run)

#271 and #301 did not fail, so no job was re-run.

Hygiene

  • [T] Commits are 02d33f88 (merge), 1c69b026, 525f1daa and d176af18. All 12 commits on the branch are authored and committed by dborup <kontakt@meshview.dk>.
  • [T] No rebase, amend or force-push; the push was a fast-forward 48d33d8c..d176af18. No closing keywords.
  • [T] Round 2 changes only test files: 5 Go _test.go files and the feat(observers): show RX 1h airtime (channel load) next to TX 1h, and both on the observer detail page #497 E2E. No public/ or .github diff. check-xss-sinks.sh --diff: nothing to scan. map[string]interface{} added in non-test Go: 0. Fork guards unchanged (9 in deploy.yml).
  • No staging or production access. No API key used. No upstream writes.

Remainders

  1. [K] The same ignored-parameter pattern exists in product code. cmd/server/db.go OpenDB (mode=ro&_journal_mode=WAL&_busy_timeout=5000), cmd/server/ping_score_history.go:451 and cmd/ingestor/admin_delete_client_rx.go:104 pass mattn-style parameters that modernc ignores. [T] The server's read connections therefore run with busy_timeout=0. [A] In production the ingestor keeps the DB in WAL, so readers are rarely blocked, but a transient WAL lock still fails a server read at once instead of waiting. This is a product change and is left out of this test-only round. It deserves its own issue (not filed).
  2. [K] 27 other cmd/server test files still open SQLite with ?_journal_mode=WAL. [A] Any of them that writes while a loaded store reads carries the same latent hazard. They were not measured or changed here, to keep the scope on the reported flake. acct113OpenWriter is the pattern to reuse.
  3. [A] For item 1, the exact CI-side rebuild trigger (theme-refresh, region or area change) was not identified. The fix holds for any rebuild.
  4. Only linux/amd64 was measured.

@dborup

dborup commented Oct 24, 2026

Copy link
Copy Markdown
Owner

Review — CS-Minimax PR#571 — head d176af1

Dom: APPROVE med nits

Evidence: [T] test or command I ran, with its result · [A] my analysis · [K] source code reference

All 7 items have a proven root cause and a red-before / green-after test. No assertion is weakened (items 4 and 5 are stricter now), and no sleep or retry was added. The one product change (signal registration order) is minimal and correct. The nits below are not blocking. One follow-up issue is recommended (finding 3).

Local platform: darwin/arm64, 12 cores, Go 1.26.0. "Under load" means 12 busy loops (1×nproc). The head was unchanged before and after the review (git ls-remote). During the review, origin/master moved from 273c2162 to cd52387e (#570, public/region-filter.js + the #531 tests). The merge with the new master is clean (e2dccf62), and the JS/E2E suites were re-run on that tree.

Findings

# Severity Where Finding
1 Nit shutdown_signal_order_567_test.go The AST guard only requires a signal.Notify(…, syscall.SIGTERM) statement in main before ListenAndServe. It accepts a SIGTERM-only registration (dropping SIGINT passes), and it does not tie the channel to the one the shutdown goroutine reads. That is good enough to stop the regression it targets, which [T] it does (see mutants), but it is not a full shape check.
2 Nit / info repeater_relay_concurrency_test.go [T] A mutant that keeps store.snapshotPathNodes() but does not pass metadata to collectRelayEntriesLocked survives 30/30. The cache-warming side effect of the snapshot call is what fixes round 0. Passing the snapshot is still right (it mirrors GetRepeaterRelayInfo), and the round-0 assertion pins the observable. Only the comment slightly overstates what the argument does.
3 Follow-up (product, recommend an issue) cmd/server/db.go:211, cmd/server/ping_score_history.go:451, cmd/ingestor/admin_delete_client_rx.go:104 mattn-style _journal_mode / _busy_timeout DSN params are silently ignored by modernc.org/sqlite v1.34.5 [K] (applyQueryParams handles only _pragma, _time_format, _txlock). [T] OpenDB on a WAL file reads back busy_timeout=0, journal_mode=wal. See the answer on item 7 for the production impact.
4 Info (pre-existing, unchanged) cmd/server/main.go end of main main returns as soon as ListenAndServe returns ErrServerClosed, which happens at the start of httpServer.Shutdown. It does not wait for the shutdown goroutine, so the drain and dbClose race process exit. The deferred stopPingScoreHistory happens to buy time. [T] Locally the full sequence was logged (received terminated → all clients disconnected → WAL checkpoint complete → shutdown complete). This PR does not change it. Worth a separate look.
5 Nit test-e2e-playwright.js Version card The test now covers only the frontend rendering contract (the route overrides version/commit). The server's own version resolution is no longer exercised end-to-end here. The old test skipped that case anyway, so nothing is lost relative to master.

Answers to the review points

Item 1, relay oracle (test).

  • [T] Master test under load: 69/150 red.
  • [T] Head under load with -race and -count=150: 150/150 green, 0 DATA RACE.
  • [T] Mutant with the snapshot call removed: the new round-0 assertion is red 30/30.
  • Root cause confirmed [K]: pathNodeSnapshotLocked falls back to cachedNodesAndPM() when no snapshot is passed. See finding 2.

Item 2, /paths 503 (test).

  • [T] Master under load: 6/200 red (SortByRecency_1145 2, FallbackBranch 4).
  • [T] Head under load with -race: 100/100 green.
  • [T] Mutant loadStoreIndexed without WaitIndexesReady: 5/120 red under load.
  • [K] WaitIndexesReady is channel-based. The 30 s value only bounds a hung build, so no polling is added. The AnchorBias 10 ms poll loop that was removed is a net improvement.

Item 3, signal.Notify before ListenAndServe (product).

  • [T] The guard is red on master's main.go and red on a go signal.Notify(…) mutant.
  • [T] Probe (2 s delay before the goroutine's Notify) on master: TestServerProcess_NormalStartDoesNotWait failed 3/3 with exit code -1 after SIGTERM. The same delay before the now-synchronous Notify on head: 3/3 green.
  • [T] Guard, controls and process test under load with -race: 30/30 green.
  • [K] Shutdown behaviour is otherwise identical: same buffered channel and the same signals, and the goroutine body is unchanged (poller stop → analytics recomputers → 15 s HTTP drain → WS hub → ping-score history → dbClose).
  • [A] If a SIGTERM lands between Notify and the bind, Shutdown runs first and ListenAndServe returns ErrServerClosed, so main exits normally. This is the same outcome as on master when the goroutine had already run.
  • [K] The schema-wait NotifyContext is stopped before the new registration, so nothing is registered twice. The comment at main.go:205 still holds.
  • [A] Supervisor/Caddy: nothing changes for a SIGTERM after healthz. A SIGTERM before healthz, in the narrow window between the schema wait and the registration, still takes the default action, as the author notes. Unchanged.
  • [T] SIGTERM on a real head binary logged the full graceful sequence (see finding 4).

Item 4, Version card (test).

  • [T] Master test against a server started from a non-git cwd (commit: "unknown"): red (timeout). Head: green.
  • [T] Own mutant (remove if (!ver && !sha) return '' in renderVersionCard): red with Version card must be hidden when version and commit are unknown, got "".

Item 5, observer IATA on mobile (test).

  • [T] Master test on a fixture aged more than 15 minutes: red (waitForSelector timeout on the mobile case). Head on the same aged fixture: 10/10 green under load.
  • [K] ?hash= suppressing the time window is the documented contract. Requiring ≥1 observer cell and an exact IATA match is stricter than before.

Item 6, narrow tile / detached tile (test).

  • [K] The fix is in the right place. locator.evaluate uses two round trips, and RF Health rebuilding #rfHealthGrid via innerHTML on theme-refresh/filter changes is known behaviour (already described in the comment above the tests). Measuring in one waitForFunction task removes the window without changing any assertion.
  • [T] Own mutant (remove .rf-cell-stats > span { white-space: nowrap; }): red with {"nowrap":false,"inside":true,"oneLine":true}. Missing CSS gives oneLine:true, not the CI oneLine:false, which supports the author's ruling-out of late CSS.
  • [T] Head under load: 10/10 green.
  • I did not rebuild the forced re-render harness, so the detached-tile reproduction itself is the author's [T], not mine.
  • [A] A product debounce of the rebuild would be a separate UX question, not needed for this flake.

Item 7, SQLITE_BUSY in the acct113 fixture (test) and production exposure.

  • [T] Old DSN: the read-back check is red (journal_mode = "delete"). Old DSN with the read-back disabled: the new TestAcct113Fixture_ServerReadDoesNotBlockWriter_567 is red 5/5 (database is locked (5) (SQLITE_BUSY)). Head under load with -race: the mixed sequence plus the new test pass 30/30.
  • [T] I could not reproduce the original flake on master locally: MixedSequenceDoesNotDrift_113 under load with -race passed 0/60 red on darwin.
  • [T] WAL without a busy timeout was green 10/10 here (no 1 ms healer tick). The need for busy_timeout rests on the author's 1 ms-tick evidence, which I did not re-run. Using the ingestor's own pragmas is the right model either way.
  • The fix is in the right place: the fixture now opens the DB as cmd/ingestor/db.go:153 does.
  • Production: the exact healer-vs-writer collision should not happen in prod. [K] The ingestor opens with _pragma=journal_mode(WAL), and WAL is persistent, so a server read never blocks the ingestor's commit. [K] healSchemaFlags exits once all optional-column flags are true, which is the normal case on a migrated DB.
  • [T] However, the server's read connections run with busy_timeout=0. [A] A read that meets a transient WAL lock (e.g. checkpoint or WAL recovery) fails immediately instead of waiting 5 s as the DSN intends. The ping-score history writer (ping_score_history.go:451) is also not actually in WAL. Recommend an issue to convert these DSNs to _pragma= form, with a read-back test (finding 3).

Always-checks

Tests run

  • [T] On head (tree identical to the merge with 273c2162):
    • cmd/server go vet + go test ./...: ok.
    • cmd/ingestor go test ./...: ok.
    • sh test-all.sh: 267 passed, 0 failed.
    • node test-frontend-helpers.js: 719 passed, 0 failed.
  • [T] On the merge with the new master cd52387e (tree e2dccf62; no Go change on master):
    • sh test-all.sh: 267/0.
    • test-frontend-helpers.js: 719/0.
  • [T] E2E against a local Go server (non-git cwd) on e2e-fixture.db, prepared as in CI (freshen, inline seed SQL, corescope-migrate, seeds 2073/199/245/122). I served public/ uninstrumented.
    • Head: test-e2e-playwright.js 154/157 (3 built-in skips, 0 failed), test-observer-iata-1188-e2e.js 3/3, test-issue-497-rx-airtime-e2e.js all passed.
    • Merged with the new master: the same three, plus test-issue-531-region-url-e2e.js 31/0.
    • Servers were stopped by port.
  • [T] Stress under load with -race:
    • relay -count=150: 150/150;
    • the two named /paths tests: 100/100;
    • acct113 pair: 60/60;
    • signal guard + controls + process test: 90/90;
    • 0 DATA RACE.

Not verified

  • linux/amd64 rates, and the author's 2×nproc load level (I used 1×nproc on darwin/arm64).
  • The forced re-render harness for item 6, and the 1 ms healer tick for item 7 (author's [T]).
  • The original acct113 flake on master (0/60 here).
  • E2E with the Istanbul-instrumented frontend.
  • Go 1.27.1 (CI) vs the local 1.26.0.
  • Real Caddy/supervisor shutdown (only the process test and a local SIGTERM).

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