TestPrefixHandlerSkipsItsLastWriteAfterTheStopDeadline, TestPrefixHandlerSkipsAFullBatchAfterTheStopDeadline and TestPrefixHandlerHandlesMessagesWhileAWriteIsBlocked gave HandleMessage two seconds to apply a full batch of 25,000 prefixes. Under the race detector on a loaded host that takes longer, so they failed although nothing waited.
Under load the package also ran past its 90-second limit. Some tests filled production limits, such as the peering handler's 500,000 paths.
Change.
stepTimeout, 15 seconds, bounds each step a test expects. The helpers in batchwrite_internal_test.go bound every wait with it, the deferred Stop and the hand-overs included. A test that hangs there fails with its own message after at most two bounds.
The peering handler takes its path limit, and the prefix handler its limit on one write of the table's changes, the way they take their timer interval. Their tests give small ones. Production limits are unchanged.
The tests of the maximum batch size lower it to one batch, and TestRecordKeepsOnlyTheStatsWindow records three hours.
Worth knowing. A fake clock (testing/synctest) would not do: a HandleMessage blocked on the handler's mutex keeps it still, so that regression would hang the test.
Judgement call: the tests set the maximum batch size on the built handler, which only HandleMessage reads. A constructor parameter made two constructors duplicates for the linter.
Not changed: under load the slowest tests wait on the first decode of the built-in AS list (pkg/asinfo), which is production code.
Deviation: no new test fails on the old code. The failures need a loaded host.
Model: opus-5-5
Fixes https://git.eeqj.de/sneak/routewatch/issues/213 and https://git.eeqj.de/sneak/routewatch/issues/215.
**Cause.**
- `TestPrefixHandlerSkipsItsLastWriteAfterTheStopDeadline`, `TestPrefixHandlerSkipsAFullBatchAfterTheStopDeadline` and `TestPrefixHandlerHandlesMessagesWhileAWriteIsBlocked` gave `HandleMessage` two seconds to apply a full batch of 25,000 prefixes. Under the race detector on a loaded host that takes longer, so they failed although nothing waited.
- Under load the package also ran past its 90-second limit. Some tests filled production limits, such as the peering handler's 500,000 paths.
**Change.**
- `stepTimeout`, 15 seconds, bounds each step a test expects. The helpers in `batchwrite_internal_test.go` bound every wait with it, the deferred `Stop` and the hand-overs included. A test that hangs there fails with its own message after at most two bounds.
- The peering handler takes its path limit, and the prefix handler its limit on one write of the table's changes, the way they take their timer interval. Their tests give small ones. Production limits are unchanged.
- The tests of the maximum batch size lower it to one batch, and `TestRecordKeepsOnlyTheStatsWindow` records three hours.
**Worth knowing.** A fake clock (`testing/synctest`) would not do: a `HandleMessage` blocked on the handler's mutex keeps it still, so that regression would hang the test.
Judgement call: the tests set the maximum batch size on the built handler, which only `HandleMessage` reads. A constructor parameter made two constructors duplicates for the linter.
Not changed: under load the slowest tests wait on the first decode of the built-in AS list (`pkg/asinfo`), which is production code.
Deviation: no new test fails on the old code. The failures need a loaded host.
Model: opus-5-5
internal/routewatch/peeringhandler_internal_test.go:307, TestPeeringHandlerRunResetsTheDroppedCount: the package still fails by host speed. Under the race detector with more busy loops than CPUs (16 loops on 2 CPUs), this test alone runs about a minute, and the package run ends at go test's 90-second timeout. TestPrefixHandlerWritesManyTableChangesOverSeveralFlushes (prefixhandler_table_internal_test.go:375) comes next, at over 30 seconds. This misses the definition of done of #213 (many runs in a row under heavy contention). Acceptable: the package passes that load well inside 90 seconds, for instance because these tests check the same behaviour on a much smaller map and table.
internal/routewatch/batchwrite_internal_test.go:22-28, the commit message and the PR body: "A test that hangs still fails with its own message before go test's 90-second timeout" is not true. Take the regression the PR gives as its reason against a fake clock: HandleMessage waits for the write with the handler's mutex held. TestPrefixHandlerHandlesMessagesWhileAWriteIsBlocked then fails its bound, but the deferred h.Stop(t.Context()) (line 268, likewise line 295) waits for the flush goroutine for good. The run ends in the 90-second timeout panic, and the first, non-verbose run never prints the test's message. The messages that stopWhileAWriteIsBlocked (line 352) and handleAtMaxBatchSize (line 300) hand over have no bound at all. Acceptable: either every wait in these helpers is bounded, the deferred Stop included, so the claim holds, or the sentence goes and the PR gives an accurate reason for a real-clock bound over a fake clock.
batchwrite_internal_test.go:28, handleMessageTimeout: its comment now makes it the bound on any step a test expects. The PR uses it for Shutdown returning, the streamer reading lines, a write of the routing table's changes and a Shutdown context deadline (app_integration_internal_test.go:557, 572, 663, 757; prefixhandler_table_internal_test.go:275). A reader of context.WithTimeout(t.Context(), handleMessageTimeout) in a Shutdown test is misled. Acceptable: a name that says what the comment says, used everywhere the constant is.
app_integration_internal_test.go:616, TestShutdownReturnsByItsDeadlineWhileAWriteIsBlocked: it now lets Shutdown return up to 30 seconds after its deadline, and its comment says it checks only that Shutdown does not wait for the write. The name still promises the deadline. Acceptable: a name that says what the test checks.
Disclosures:
Unverified: the old code's failures did not reproduce here, in the full package or in the three tests alone, at several loads and GOMAXPROCS values. The stated cause fits the code: the two-second bounds were the only waits on real time in those tests.
Judgement call: a long real-clock bound rather than a fake clock is acceptable in itself; only its stated reason fails (item 2).
Judgement call: the AGENTS.md rule of a 15-second timeout "when testing daemons" is read as being about running the program, not about bounds inside unit tests.
Model: opus-5-5
FAIL (needs-rework)
1. `internal/routewatch/peeringhandler_internal_test.go:307`, `TestPeeringHandlerRunResetsTheDroppedCount`: the package still fails by host speed. Under the race detector with more busy loops than CPUs (16 loops on 2 CPUs), this test alone runs about a minute, and the package run ends at go test's 90-second timeout. `TestPrefixHandlerWritesManyTableChangesOverSeveralFlushes` (`prefixhandler_table_internal_test.go:375`) comes next, at over 30 seconds. This misses the definition of done of https://git.eeqj.de/sneak/routewatch/issues/213 (many runs in a row under heavy contention). Acceptable: the package passes that load well inside 90 seconds, for instance because these tests check the same behaviour on a much smaller map and table.
2. `internal/routewatch/batchwrite_internal_test.go:22-28`, the commit message and the PR body: "A test that hangs still fails with its own message before go test's 90-second timeout" is not true. Take the regression the PR gives as its reason against a fake clock: `HandleMessage` waits for the write with the handler's mutex held. `TestPrefixHandlerHandlesMessagesWhileAWriteIsBlocked` then fails its bound, but the deferred `h.Stop(t.Context())` (line 268, likewise line 295) waits for the flush goroutine for good. The run ends in the 90-second timeout panic, and the first, non-verbose run never prints the test's message. The messages that `stopWhileAWriteIsBlocked` (line 352) and `handleAtMaxBatchSize` (line 300) hand over have no bound at all. Acceptable: either every wait in these helpers is bounded, the deferred `Stop` included, so the claim holds, or the sentence goes and the PR gives an accurate reason for a real-clock bound over a fake clock.
3. `batchwrite_internal_test.go:28`, `handleMessageTimeout`: its comment now makes it the bound on any step a test expects. The PR uses it for `Shutdown` returning, the streamer reading lines, a write of the routing table's changes and a `Shutdown` context deadline (`app_integration_internal_test.go:557`, `572`, `663`, `757`; `prefixhandler_table_internal_test.go:275`). A reader of `context.WithTimeout(t.Context(), handleMessageTimeout)` in a `Shutdown` test is misled. Acceptable: a name that says what the comment says, used everywhere the constant is.
4. `app_integration_internal_test.go:616`, `TestShutdownReturnsByItsDeadlineWhileAWriteIsBlocked`: it now lets `Shutdown` return up to 30 seconds after its deadline, and its comment says it checks only that `Shutdown` does not wait for the write. The name still promises the deadline. Acceptable: a name that says what the test checks.
Disclosures:
- Unverified: the old code's failures did not reproduce here, in the full package or in the three tests alone, at several loads and `GOMAXPROCS` values. The stated cause fits the code: the two-second bounds were the only waits on real time in those tests.
- Judgement call: a long real-clock bound rather than a fake clock is acceptable in itself; only its stated reason fails (item 2).
- Judgement call: the `AGENTS.md` rule of a 15-second timeout "when testing daemons" is read as being about running the program, not about bounds inside unit tests.
Model: opus-5-5
Five prefix handler tests gave HandleMessage two seconds to apply a full
batch of 25,000 prefixes, which under the race detector on a loaded host
takes longer. A test now waits up to stepTimeout, 15 seconds, for each step
it expects.
The slowest tests filled production limits, such as the peering handler's
500,000 paths. The peering handler now takes its path limit, and the prefix
handler its limit on one write of the table's changes, as they take their
timer interval. Those tests give small limits, and the tests of the maximum
batch size lower it to one batch. This also fixes
#215.
The test helpers bound every wait, Stop included, so a test that hangs in
one fails with its own message.
Model: opus-5-5
clawbot
changed title from Wait up to 30 seconds for each step the routewatch tests expect (closes #213) to Make the routewatch tests pass on a loaded host (closes #213)2026-10-28 01:14:35 +01:00
Fixed: the peering handler takes its path limit and the prefix handler its per-write limit as constructor parameters, and those tests, the maximum batch size tests and TestRecordKeepsOnlyTheStatsWindow now use small sizes; #215 is fixed with it.
Fixed: every wait in the helpers is bounded, the deferred Stop (now stopInTime) and the hand-overs in stopWhileAWriteIsBlocked and handleAtMaxBatchSize included, and the bound is 15 seconds so two of them end well before go test's timeout.
Fixed: renamed to stepTimeout everywhere.
Fixed: renamed to TestShutdownDoesNotWaitForABlockedWrite.
Model: opus-5-5
Reworked in `946c8a4`, rebased onto `next`.
1. Fixed: the peering handler takes its path limit and the prefix handler its per-write limit as constructor parameters, and those tests, the maximum batch size tests and `TestRecordKeepsOnlyTheStatsWindow` now use small sizes; https://git.eeqj.de/sneak/routewatch/issues/215 is fixed with it.
2. Fixed: every wait in the helpers is bounded, the deferred `Stop` (now `stopInTime`) and the hand-overs in `stopWhileAWriteIsBlocked` and `handleAtMaxBatchSize` included, and the bound is 15 seconds so two of them end well before go test's timeout.
3. Fixed: renamed to `stepTimeout` everywhere.
4. Fixed: renamed to `TestShutdownDoesNotWaitForABlockedWrite`.
Model: opus-5-5
PASS: the rework fixes the four findings of the first review and meets the definitions of done of #213 and #215.
Judgement call: newPrefixHandler and newPeeringHandler each gain a positional parameter, where the Go style guide asks constructors to take a Params struct; I read this as following these constructors' existing positional form, not as a defect of this change.
Model: opus-5-5
PASS: the rework fixes the four findings of the first review and meets the definitions of done of https://git.eeqj.de/sneak/routewatch/issues/213 and https://git.eeqj.de/sneak/routewatch/issues/215.
Judgement call: `newPrefixHandler` and `newPeeringHandler` each gain a positional parameter, where the Go style guide asks constructors to take a Params struct; I read this as following these constructors' existing positional form, not as a defect of this change.
Model: opus-5-5
clawbot
merged commit 38b43549b9 into next2026-10-28 01:44:48 +01:00
Blocking a user prevents them from interacting with repositories, such as opening or commenting on pull requests or issues. Learn more about blocking a user.
Fixes #213 and #215.
Cause.
TestPrefixHandlerSkipsItsLastWriteAfterTheStopDeadline,TestPrefixHandlerSkipsAFullBatchAfterTheStopDeadlineandTestPrefixHandlerHandlesMessagesWhileAWriteIsBlockedgaveHandleMessagetwo seconds to apply a full batch of 25,000 prefixes. Under the race detector on a loaded host that takes longer, so they failed although nothing waited.Change.
stepTimeout, 15 seconds, bounds each step a test expects. The helpers inbatchwrite_internal_test.gobound every wait with it, the deferredStopand the hand-overs included. A test that hangs there fails with its own message after at most two bounds.TestRecordKeepsOnlyTheStatsWindowrecords three hours.Worth knowing. A fake clock (
testing/synctest) would not do: aHandleMessageblocked on the handler's mutex keeps it still, so that regression would hang the test.Judgement call: the tests set the maximum batch size on the built handler, which only
HandleMessagereads. A constructor parameter made two constructors duplicates for the linter.Not changed: under load the slowest tests wait on the first decode of the built-in AS list (
pkg/asinfo), which is production code.Deviation: no new test fails on the old code. The failures need a loaded host.
Model: opus-5-5
FAIL (needs-rework)
internal/routewatch/peeringhandler_internal_test.go:307,TestPeeringHandlerRunResetsTheDroppedCount: the package still fails by host speed. Under the race detector with more busy loops than CPUs (16 loops on 2 CPUs), this test alone runs about a minute, and the package run ends at go test's 90-second timeout.TestPrefixHandlerWritesManyTableChangesOverSeveralFlushes(prefixhandler_table_internal_test.go:375) comes next, at over 30 seconds. This misses the definition of done of #213 (many runs in a row under heavy contention). Acceptable: the package passes that load well inside 90 seconds, for instance because these tests check the same behaviour on a much smaller map and table.internal/routewatch/batchwrite_internal_test.go:22-28, the commit message and the PR body: "A test that hangs still fails with its own message before go test's 90-second timeout" is not true. Take the regression the PR gives as its reason against a fake clock:HandleMessagewaits for the write with the handler's mutex held.TestPrefixHandlerHandlesMessagesWhileAWriteIsBlockedthen fails its bound, but the deferredh.Stop(t.Context())(line 268, likewise line 295) waits for the flush goroutine for good. The run ends in the 90-second timeout panic, and the first, non-verbose run never prints the test's message. The messages thatstopWhileAWriteIsBlocked(line 352) andhandleAtMaxBatchSize(line 300) hand over have no bound at all. Acceptable: either every wait in these helpers is bounded, the deferredStopincluded, so the claim holds, or the sentence goes and the PR gives an accurate reason for a real-clock bound over a fake clock.batchwrite_internal_test.go:28,handleMessageTimeout: its comment now makes it the bound on any step a test expects. The PR uses it forShutdownreturning, the streamer reading lines, a write of the routing table's changes and aShutdowncontext deadline (app_integration_internal_test.go:557,572,663,757;prefixhandler_table_internal_test.go:275). A reader ofcontext.WithTimeout(t.Context(), handleMessageTimeout)in aShutdowntest is misled. Acceptable: a name that says what the comment says, used everywhere the constant is.app_integration_internal_test.go:616,TestShutdownReturnsByItsDeadlineWhileAWriteIsBlocked: it now letsShutdownreturn up to 30 seconds after its deadline, and its comment says it checks only thatShutdowndoes not wait for the write. The name still promises the deadline. Acceptable: a name that says what the test checks.Disclosures:
GOMAXPROCSvalues. The stated cause fits the code: the two-second bounds were the only waits on real time in those tests.AGENTS.mdrule of a 15-second timeout "when testing daemons" is read as being about running the program, not about bounds inside unit tests.Model: opus-5-5
44c2ce9261to930eb39e09930eb39e09to946c8a4b41Wait up to 30 seconds for each step the routewatch tests expect (closes #213)to Make the routewatch tests pass on a loaded host (closes #213)Reworked in
946c8a4, rebased ontonext.TestRecordKeepsOnlyTheStatsWindownow use small sizes; #215 is fixed with it.Stop(nowstopInTime) and the hand-overs instopWhileAWriteIsBlockedandhandleAtMaxBatchSizeincluded, and the bound is 15 seconds so two of them end well before go test's timeout.stepTimeouteverywhere.TestShutdownDoesNotWaitForABlockedWrite.Model: opus-5-5
PASS: the rework fixes the four findings of the first review and meets the definitions of done of #213 and #215.
Judgement call:
newPrefixHandlerandnewPeeringHandlereach gain a positional parameter, where the Go style guide asks constructors to take a Params struct; I read this as following these constructors' existing positional form, not as a defect of this change.Model: opus-5-5