Make the tests pass on a busy host #242

Merged
clawbot merged 1 commits from issue-240-test-time-allowances into next 2026-11-10 12:48:07 +01:00
Collaborator

Closes #240.

Test code only.

Named on the issue

  • TestKeepHomeCardsFreshWorksThemOutEveryInterval and TestStartedServerWorksOutTheCards: maxWait is 15 seconds.
  • TestStreamNotDroppedWhileLinesArrive: a fake RoundTripper on the testing/synctest fake clock, which httptest network I/O would stop.

Moved to synctest.Test: a short server limit bounds their requests, or they count seconds

  • TestJSONAnswersCarryMeta
  • TestJSONRoutesDoNotSendErrorDetails
  • TestRoutesAnswerHEAD, with the fake resolver: nothing limits a real DNS lookup on the fake clock
  • TestStatsHandlersAnswerFromMemory
  • TestStatsAnswerCarriesChurnPerMinute
  • TestStatsAnswerGivesHowManyMessagesAHandlerHoldsBack
  • TestStatsAnswersGiveUnitsInFieldNames
  • TestStatsAnswerGivesConnectionDurationInSeconds
  • TestHomePageCardsShowTheTableFigures
  • TestStreamDurationsCountSeconds

Moved to synctest.Test with a fake transport: a stall could reorder their requests

  • TestReconnectWhenStreamGoesIdle
  • TestReconnectWhenServerNeverAnswers
  • TestReconnectWhenStreamEnds, which shares checkReconnect

Others changed, each to 15 seconds

  • TestStopReturnsByItsDeadline
  • TestStopClosesTheConnectionOfARequestStillRunning
  • parseTimeLimit in cmd/asinfo-gen
  • waitForGoroutines in internal/streamer and internal/server
  • TestRestartLoadsCopiesFromDisk
  • TestIPLookupKeepsRouteWhenPTRLookupDoesNotAnswer: the PTR limit plus 15 seconds.
  • TestCheckpointDoesNotWaitForReader and TestCheckpointEmptiesWALOnceNoReadIsOpen: with a 30-second busy timeout, because a limit above the real 5-second one could not catch a checkpoint that waits.

Judgement call: the 5-second maxWait in three internal/streamer tests also became 15 seconds. That is outside "shorter than a few seconds", but the reported 5.5-second stall exceeds it. The 10-second wait in internal/iplist stays. TestPagesShowAgesInWords stays on the real clock, because it allows 30 seconds.

Shown to fail when broken: removing idleTimer.Reset failed the stream test, removing the refreshHomeCards call failed both home tests, a TRUNCATE checkpoint without the lowered busy timeout failed both checkpoint tests, and breaking the idle timer, the reconnect or SetConnected(false) failed the reconnect tests.

Model: opus-5-5

Closes https://git.eeqj.de/sneak/routewatch/issues/240. Test code only. **Named on the issue** - `TestKeepHomeCardsFreshWorksThemOutEveryInterval` and `TestStartedServerWorksOutTheCards`: `maxWait` is 15 seconds. - `TestStreamNotDroppedWhileLinesArrive`: a fake `RoundTripper` on the `testing/synctest` fake clock, which `httptest` network I/O would stop. **Moved to `synctest.Test`: a short server limit bounds their requests, or they count seconds** - `TestJSONAnswersCarryMeta` - `TestJSONRoutesDoNotSendErrorDetails` - `TestRoutesAnswerHEAD`, with the fake resolver: nothing limits a real DNS lookup on the fake clock - `TestStatsHandlersAnswerFromMemory` - `TestStatsAnswerCarriesChurnPerMinute` - `TestStatsAnswerGivesHowManyMessagesAHandlerHoldsBack` - `TestStatsAnswersGiveUnitsInFieldNames` - `TestStatsAnswerGivesConnectionDurationInSeconds` - `TestHomePageCardsShowTheTableFigures` - `TestStreamDurationsCountSeconds` **Moved to `synctest.Test` with a fake transport: a stall could reorder their requests** - `TestReconnectWhenStreamGoesIdle` - `TestReconnectWhenServerNeverAnswers` - `TestReconnectWhenStreamEnds`, which shares `checkReconnect` **Others changed, each to 15 seconds** - `TestStopReturnsByItsDeadline` - `TestStopClosesTheConnectionOfARequestStillRunning` - `parseTimeLimit` in `cmd/asinfo-gen` - `waitForGoroutines` in `internal/streamer` and `internal/server` - `TestRestartLoadsCopiesFromDisk` - `TestIPLookupKeepsRouteWhenPTRLookupDoesNotAnswer`: the PTR limit plus 15 seconds. - `TestCheckpointDoesNotWaitForReader` and `TestCheckpointEmptiesWALOnceNoReadIsOpen`: with a 30-second busy timeout, because a limit above the real 5-second one could not catch a checkpoint that waits. **Judgement call:** the 5-second `maxWait` in three `internal/streamer` tests also became 15 seconds. That is outside "shorter than a few seconds", but the reported 5.5-second stall exceeds it. The 10-second wait in `internal/iplist` stays. `TestPagesShowAgesInWords` stays on the real clock, because it allows 30 seconds. **Shown to fail when broken:** removing `idleTimer.Reset` failed the stream test, removing the `refreshHomeCards` call failed both home tests, a TRUNCATE checkpoint without the lowered busy timeout failed both checkpoint tests, and breaking the idle timer, the reconnect or `SetConnected(false)` failed the reconnect tests. Model: opus-5-5
clawbot self-assigned this 2026-11-10 10:28:58 +01:00
clawbot added the needs-review label 2026-11-10 10:28:58 +01:00
Author
Collaborator

FAIL (needs-rework)

  1. Tests still fail when a 2-second or 4-second limit runs out on a slow host. This is the third point of #240.

    • internal/server/middleware_internal_test.go:191: TestJSONAnswersCarryMeta expects 200 from the health check, which pings the real database under healthCheckTimeout, 2 seconds. A stall over 2 seconds answers 503 and fails the test.
    • statsContextTimeout, 4 seconds, bounds every test that expects an answer other than 504 from /status.json or /api/v1/stats, such as TestStatsHandlersAnswerFromMemory, TestRoutesAnswerHEAD and TestJSONRoutesDoNotSendErrorDetails.
    • homeCardsDatabaseTimeout, 4 seconds, bounds the Newest Updated AS and Oldest Updated AS cards in TestHomePageCardsShowTheTableFigures.
    • The PR raised the 5-second waits because the reported stall was 5.5 seconds, so the 4-second limits are in scope by the same reasoning.

    Acceptable: make these requests inside synctest.Test, with the server built outside it, as TestStreamNotDroppedWhileLinesArrive now does, so a stall uses none of the limit and no production code changes. Add them to the PR's list.

  2. A failure of TestStreamNotDroppedWhileLinesArrive ends the whole internal/streamer test binary. internal/streamer/streamer_internal_test.go:656-663. When a line does not restart the idle timer, s.stream returns while the goroutine that writes the lines is still in time.Sleep. synctest.Test then panics because a goroutine is still blocked after the test function has returned, and the package's remaining tests never report. Acceptable: pass write the request's context and wait on it and the line interval in place of time.Sleep, so the goroutine ends with the stream and the test reports an ordinary failure.

  3. TODO.md, the new entry.

    • "A wait for something that should happen is now 15 seconds." is false: the 10-second maxWait in internal/blocklist stays, as the PR says. Acceptable: "Most such waits are now 15 seconds."
    • "The test that lines keep a stream up runs on a fake clock" cannot be parsed on first reading. Acceptable: "The test of the stream's idle timeout runs on a fake clock."

Not checked: the image build step of script/cibuild.

Model: opus-5-5

**FAIL** (`needs-rework`) 1. **Tests still fail when a 2-second or 4-second limit runs out on a slow host.** This is the third point of https://git.eeqj.de/sneak/routewatch/issues/240. - `internal/server/middleware_internal_test.go:191`: `TestJSONAnswersCarryMeta` expects 200 from the health check, which pings the real database under `healthCheckTimeout`, 2 seconds. A stall over 2 seconds answers 503 and fails the test. - `statsContextTimeout`, 4 seconds, bounds every test that expects an answer other than 504 from `/status.json` or `/api/v1/stats`, such as `TestStatsHandlersAnswerFromMemory`, `TestRoutesAnswerHEAD` and `TestJSONRoutesDoNotSendErrorDetails`. - `homeCardsDatabaseTimeout`, 4 seconds, bounds the `Newest Updated AS` and `Oldest Updated AS` cards in `TestHomePageCardsShowTheTableFigures`. - The PR raised the 5-second waits because the reported stall was 5.5 seconds, so the 4-second limits are in scope by the same reasoning. Acceptable: make these requests inside `synctest.Test`, with the server built outside it, as `TestStreamNotDroppedWhileLinesArrive` now does, so a stall uses none of the limit and no production code changes. Add them to the PR's list. 2. **A failure of `TestStreamNotDroppedWhileLinesArrive` ends the whole `internal/streamer` test binary.** `internal/streamer/streamer_internal_test.go:656-663`. When a line does not restart the idle timer, `s.stream` returns while the goroutine that writes the lines is still in `time.Sleep`. `synctest.Test` then panics because a goroutine is still blocked after the test function has returned, and the package's remaining tests never report. Acceptable: pass `write` the request's context and wait on it and the line interval in place of `time.Sleep`, so the goroutine ends with the stream and the test reports an ordinary failure. 3. **`TODO.md`, the new entry.** - "A wait for something that should happen is now 15 seconds." is false: the 10-second `maxWait` in `internal/blocklist` stays, as the PR says. Acceptable: "Most such waits are now 15 seconds." - "The test that lines keep a stream up runs on a fake clock" cannot be parsed on first reading. Acceptable: "The test of the stream's idle timeout runs on a fake clock." Not checked: the image build step of `script/cibuild`. Model: opus-5-5
clawbot added needs-rework and removed needs-review labels 2026-11-10 10:48:37 +01:00
Author
Collaborator

For the reworker: make the three changes in #242 (comment), each as its "Acceptable" says, and nothing else. Rebase onto current next first; the rename landed there. Each test moved under synctest.Test goes in the PR body's list. If a test cannot run under synctest (its real database call blocks the fake clock), say so on the PR and give it a limit a stall cannot exceed instead.

Model: opus-5-5

For the reworker: make the three changes in https://git.eeqj.de/sneak/routewatch/pulls/242#issuecomment-173855, each as its "Acceptable" says, and nothing else. Rebase onto current `next` first; the rename landed there. Each test moved under `synctest.Test` goes in the PR body's list. If a test cannot run under `synctest` (its real database call blocks the fake clock), say so on the PR and give it a limit a stall cannot exceed instead. Model: opus-5-5
clawbot force-pushed issue-240-test-time-allowances from 4a9b39c7b7 to cf30c7460c 2026-11-10 11:05:55 +01:00 Compare
Author
Collaborator
  1. Done: the requests of the nine tests in the PR body's new list now run under synctest.Test, and none needed a longer limit instead. TestJSONAnswersPutNoUnitInAString and TestResponsesCarrySecurityHeaders also request these routes but pass on a 504, so they stay.
  2. Done: write gets the request's context and waits on it and the line interval.
  3. Done, in the wording given.

Rebased onto current next.

Disclosure: TestRoutesAnswerHEAD now uses the fake resolver, because nothing limits a real DNS lookup on the fake clock.

Model: opus-5-5

1. Done: the requests of the nine tests in the PR body's new list now run under `synctest.Test`, and none needed a longer limit instead. `TestJSONAnswersPutNoUnitInAString` and `TestResponsesCarrySecurityHeaders` also request these routes but pass on a 504, so they stay. 2. Done: `write` gets the request's context and waits on it and the line interval. 3. Done, in the wording given. Rebased onto current `next`. Disclosure: `TestRoutesAnswerHEAD` now uses the fake resolver, because nothing limits a real DNS lookup on the fake clock. Model: opus-5-5
clawbot added needs-review and removed needs-rework labels 2026-11-10 11:13:54 +01:00
Author
Collaborator

FAIL (needs-rework)

  1. TestStreamDurationsCountSeconds still fails on a stall of one second. internal/server/handlers_internal_test.go:498. This is the third point of #240.

    • The test sets connectedSince 90 seconds back on the real clock, then expects uptimeSeconds and connectionDurationSeconds to give exactly 90. A stall of a second or more anywhere in the test makes them give 91 or more.
    • TestStatsAnswerGivesConnectionDurationInSeconds, beside it, has the same flaw and the PR moved it to the fake clock.

    Acceptable: put the body of the test inside synctest.Test, so that time.Now and time.Since read the fake clock, and add the test to the PR body's list of tests moved to synctest.Test.

Model: opus-5-5

**FAIL** (`needs-rework`) 1. **`TestStreamDurationsCountSeconds` still fails on a stall of one second.** `internal/server/handlers_internal_test.go:498`. This is the third point of https://git.eeqj.de/sneak/routewatch/issues/240. - The test sets `connectedSince` 90 seconds back on the real clock, then expects `uptimeSeconds` and `connectionDurationSeconds` to give exactly 90. A stall of a second or more anywhere in the test makes them give 91 or more. - `TestStatsAnswerGivesConnectionDurationInSeconds`, beside it, has the same flaw and the PR moved it to the fake clock. Acceptable: put the body of the test inside `synctest.Test`, so that `time.Now` and `time.Since` read the fake clock, and add the test to the PR body's list of tests moved to `synctest.Test`. Model: opus-5-5
Author
Collaborator

For the reworker: make the one change in #242 (comment), as its "Acceptable" says, and nothing else. Before pushing, check that no other test in the PR's scope reads the real clock across a request the same way; a test with this flaw goes under synctest.Test too, and in the PR body's list. Rebase onto current next first.

Model: opus-5-5

For the reworker: make the one change in https://git.eeqj.de/sneak/routewatch/pulls/242#issuecomment-173935, as its "Acceptable" says, and nothing else. Before pushing, check that no other test in the PR's scope reads the real clock across a request the same way; a test with this flaw goes under `synctest.Test` too, and in the PR body's list. Rebase onto current `next` first. Model: opus-5-5
clawbot added needs-rework and removed needs-review labels 2026-11-10 11:31:05 +01:00
clawbot force-pushed issue-240-test-time-allowances from cf30c7460c to 48e80cce65 2026-11-10 11:38:15 +01:00 Compare
Author
Collaborator
  1. Done: the body of TestStreamDurationsCountSeconds is inside synctest.Test, and the test is in the PR body's list.
  2. Checked: no other test has this flaw. TestPagesShowAgesInWords also reads the real clock across requests, but it allows 30 seconds, so it stays.
  3. The branch was already on current next, so no rebase was needed.

Model: opus-5-5

1. Done: the body of `TestStreamDurationsCountSeconds` is inside `synctest.Test`, and the test is in the PR body's list. 2. Checked: no other test has this flaw. `TestPagesShowAgesInWords` also reads the real clock across requests, but it allows 30 seconds, so it stays. 3. The branch was already on current `next`, so no rebase was needed. Model: opus-5-5
clawbot added needs-review and removed needs-rework labels 2026-11-10 11:48:01 +01:00
Author
Collaborator

FAIL (needs-rebase)

  1. TODO.md conflicts with current next. This PR and the change for #234 each add an entry at the top of # Completed Steps. Acceptable: rebase onto current next and keep both entries.
  2. The PR body is about 280 words, over the limit of about 250. Acceptable: cut the former values, such as "was 2 seconds", until it is about 250 words. Keep the list of tests changed, the judgement call and the line on how the tests were shown to fail.

Not checked: the image build step of script/cibuild, which would replace the host's shared routewatch:latest image.

Model: opus-5-5

**FAIL** (`needs-rebase`) 1. **`TODO.md` conflicts with current `next`.** This PR and the change for https://git.eeqj.de/sneak/routewatch/issues/234 each add an entry at the top of `# Completed Steps`. Acceptable: rebase onto current `next` and keep both entries. 2. **The PR body is about 280 words, over the limit of about 250.** Acceptable: cut the former values, such as "was 2 seconds", until it is about 250 words. Keep the list of tests changed, the judgement call and the line on how the tests were shown to fail. Not checked: the image build step of `script/cibuild`, which would replace the host's shared `routewatch:latest` image. Model: opus-5-5
Author
Collaborator

Third failed review (#242 (comment), #242 (comment), #242 (comment)). This ends the loop.

For the reworker: exactly these three things.

  1. Rebase onto current next. In TODO.md keep both entries.
  2. Cut the PR body to about 250 words: drop the former values such as "was 2 seconds". Keep the list of tests changed, the judgement call and the line on how the tests were shown to fail.
  3. Make TestReconnectWhenStreamGoesIdle and TestReconnectWhenServerNeverAnswers hold on a busy host. On a load average of about 90 the first failed with "streamer was still marked connected when it came back for a second response". The likely cause is in the test: checkReconnect counts requests in arrival order at the server, and a stall can run the cancelled first request's handler after the second's, so it counts the wrong one. Move checkReconnect under synctest.Test with a fake transport like pipeTransport, as TestStreamNotDroppedWhileLinesArrive does, so there is no real connection to reorder. Add both tests to the PR body's list. If you find instead that the streamer can really be marked connected while it reconnects, change no test: post that on this PR and stop.

Leave everything else alone.

The next review checks only: these three changes; that each test still fails when the code it guards is broken; and make check. Any other test with a similar flaw goes in a new issue, not this PR.

Model: opus-5-5

Third failed review (https://git.eeqj.de/sneak/routewatch/pulls/242#issuecomment-173855, https://git.eeqj.de/sneak/routewatch/pulls/242#issuecomment-173935, https://git.eeqj.de/sneak/routewatch/pulls/242#issuecomment-173994). This ends the loop. For the reworker: exactly these three things. 1. Rebase onto current `next`. In `TODO.md` keep both entries. 2. Cut the PR body to about 250 words: drop the former values such as "was 2 seconds". Keep the list of tests changed, the judgement call and the line on how the tests were shown to fail. 3. Make `TestReconnectWhenStreamGoesIdle` and `TestReconnectWhenServerNeverAnswers` hold on a busy host. On a load average of about 90 the first failed with "streamer was still marked connected when it came back for a second response". The likely cause is in the test: `checkReconnect` counts requests in arrival order at the server, and a stall can run the cancelled first request's handler after the second's, so it counts the wrong one. Move `checkReconnect` under `synctest.Test` with a fake transport like `pipeTransport`, as `TestStreamNotDroppedWhileLinesArrive` does, so there is no real connection to reorder. Add both tests to the PR body's list. If you find instead that the streamer can really be marked connected while it reconnects, change no test: post that on this PR and stop. Leave everything else alone. The next review checks only: these three changes; that each test still fails when the code it guards is broken; and `make check`. Any other test with a similar flaw goes in a new issue, not this PR. Model: opus-5-5
clawbot added needs-rework and removed needs-review labels 2026-11-10 12:15:37 +01:00
clawbot added 1 commit 2026-11-10 12:25:30 +01:00
Make the tests pass on a busy host (closes #240)
check / check (push) Successful in 3m21s
368fca9955
Tests that waited a few seconds for something to happen now wait 15 seconds.
The wait ends as soon as the condition holds, so a passing run takes no longer.

TestStreamNotDroppedWhileLinesArrive, the reconnect tests, the tests whose
requests pass a 2- or 4-second limit in the server, and
TestStreamDurationsCountSeconds run on a fake clock, so a stall on the host
cannot change their result. The reconnect tests also use a fake transport, so
a stall cannot reorder their requests.

The checkpoint tests give the writing connection a 30-second busy timeout, so
their limit can be 15 seconds and a checkpoint that waits for a read still
fails them.

Model: opus-5-5
clawbot force-pushed issue-240-test-time-allowances from 48e80cce65 to 368fca9955 2026-11-10 12:25:30 +01:00 Compare
Author
Collaborator
  1. Done: rebased onto current next, with every TODO.md entry kept.
  2. Done: the PR body is cut to about 250 words.
  3. Done: checkReconnect runs under synctest.Test with a fake transport. The streamer was not at fault: streamWithReconnect calls SetConnected(false) before each reconnect, and stream calls SetConnected(true) only after that reconnect's request is answered.

Disclosure: TestReconnectWhenStreamEnds also goes through checkReconnect, so it moved too and is in the PR body's list.

Model: opus-5-5

1. Done: rebased onto current `next`, with every `TODO.md` entry kept. 2. Done: the PR body is cut to about 250 words. 3. Done: `checkReconnect` runs under `synctest.Test` with a fake transport. The streamer was not at fault: `streamWithReconnect` calls `SetConnected(false)` before each reconnect, and `stream` calls `SetConnected(true)` only after that reconnect's request is answered. Disclosure: `TestReconnectWhenStreamEnds` also goes through `checkReconnect`, so it moved too and is in the PR body's list. Model: opus-5-5
clawbot added needs-review and removed needs-rework labels 2026-11-10 12:30:59 +01:00
Author
Collaborator

PASS: the tests now hold on a busy host, as #240 requires.

Model: opus-5-5

**PASS**: the tests now hold on a busy host, as https://git.eeqj.de/sneak/routewatch/issues/240 requires. Model: opus-5-5
clawbot merged commit 641798bb22 into next 2026-11-10 12:48:07 +01:00
Sign in to join this conversation.
No Reviewers
1 Participants
Notifications
Due Date
No due date set.
Dependencies

No dependencies set.

Reference: sneak/routewatch#242