Wait up to 30 seconds for each step the routewatch tests expect (closes #213)
check / check (push) Canceled after 0s

Five prefix handler tests 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. Among them were
TestPrefixHandlerSkipsItsLastWriteAfterTheStopDeadline,
TestPrefixHandlerSkipsAFullBatchAfterTheStopDeadline and
TestPrefixHandlerHandlesMessagesWhileAWriteIsBlocked.

handleMessageTimeout is now 30 seconds, and every bound a test in the
package puts on a step it expects uses it. Only a step that never comes
reaches it. A test that hangs still fails with its own message before go
test's 90-second timeout.

Model: opus-5-5
This commit is contained in:
2026-10-27 22:22:01 +00:00
parent 5ea1bb17fe
commit 44c2ce9261
4 changed files with 24 additions and 29 deletions
+4
View File
@@ -35,6 +35,10 @@ tested.
# Completed Steps
- 2026-10-27: the tests of `internal/routewatch` no longer fail on a loaded
host. Five of them gave `HandleMessage` two seconds to apply a full prefix
batch, which under the race detector can take longer. A test now waits up to
30 seconds for each step it expects (closes #213)
- 2026-10-27: the server works out the home page's cards every minute until it
stops. It used to work them out only once, at startup: the end of the context
that `Start` is given stopped the refreshes (closes #211)
@@ -509,8 +509,6 @@ func announcementFeed(prefixes []string) string {
func TestShutdownWritesTheUpdatesQueuedInTheStreamer(t *testing.T) {
t.Parallel()
const maxWait = 10 * time.Second
prefixes := []string{"192.0.2.0/24", "198.51.100.0/24", "203.0.113.0/24"}
feed := announcementFeed(prefixes)
@@ -556,9 +554,9 @@ func TestShutdownWritesTheUpdatesQueuedInTheStreamer(t *testing.T) {
for range cap(linesSeen) {
select {
case <-linesSeen:
case <-time.After(maxWait):
case <-time.After(handleMessageTimeout):
t.Fatalf("the streamer did not read %d lines within %s",
cap(linesSeen), maxWait)
cap(linesSeen), handleMessageTimeout)
}
}
@@ -571,8 +569,8 @@ func TestShutdownWritesTheUpdatesQueuedInTheStreamer(t *testing.T) {
select {
case <-shutDown:
case <-time.After(maxWait):
t.Fatalf("Shutdown did not return within %s", maxWait)
case <-time.After(handleMessageTimeout):
t.Fatalf("Shutdown did not return within %s", handleMessageTimeout)
}
store.mu.Lock()
@@ -611,19 +609,14 @@ func freePort(t *testing.T) int {
// TestShutdownReturnsByItsDeadlineWhileAWriteIsBlocked starts the HTTP server
// and has the AS handler start a write that the store holds until the test
// ends, past Shutdown's deadline. Shutdown must return within its deadline
// plus a small margin, with the HTTP server stopped, and must neither
// checkpoint nor close the database: the real one would wait for the write.
// ends, past Shutdown's deadline. Shutdown must return without waiting for the
// write, with the HTTP server stopped, and must neither checkpoint nor close
// the database: the real one would wait for the write.
// Before the fix Shutdown waited for the write.
func TestShutdownReturnsByItsDeadlineWhileAWriteIsBlocked(t *testing.T) {
t.Parallel()
const (
deadline = 100 * time.Millisecond
// margin is how long Shutdown may take after its deadline, to stop
// the HTTP server.
margin = 2 * time.Second
)
const deadline = 100 * time.Millisecond
blocking := newBlockingStore()
defer blocking.releaseWrites()
@@ -667,9 +660,9 @@ func TestShutdownReturnsByItsDeadlineWhileAWriteIsBlocked(t *testing.T) {
select {
case <-shutDown:
case <-time.After(deadline + margin):
case <-time.After(deadline + handleMessageTimeout):
t.Fatalf("Shutdown did not return within %s of its deadline while "+
"a write was blocked", margin)
"a write was blocked", handleMessageTimeout)
}
var dialer net.Dialer
@@ -744,8 +737,6 @@ func (s *closeOrderStore) record(call string) {
func TestShutdownCheckpointsAndClosesTheDatabaseLast(t *testing.T) {
t.Parallel()
const deadline = 10 * time.Second
store := &closeOrderStore{Store: newMockStore()}
log := logger.New()
cfg := &config.Config{}
@@ -763,7 +754,7 @@ func TestShutdownCheckpointsAndClosesTheDatabaseLast(t *testing.T) {
Path: ristypes.ASPath{Sequence: []int{testASNA}},
})
ctx, cancel := context.WithTimeout(t.Context(), deadline)
ctx, cancel := context.WithTimeout(t.Context(), handleMessageTimeout)
defer cancel()
rw.Shutdown(ctx)
@@ -19,9 +19,13 @@ import (
)
const (
// handleMessageTimeout is how long a test waits for HandleMessage to
// return, or for a write to start, before it fails.
handleMessageTimeout = 2 * time.Second
// handleMessageTimeout is how long a test waits for a step it expects,
// such as HandleMessage returning or a write starting, before it fails.
// Only a step that never comes should reach it. On a loaded host, under
// the race detector, HandleMessage takes seconds to apply a full prefix
// batch. A test that hangs still fails with its own message before go
// test's 90-second timeout.
handleMessageTimeout = 30 * time.Second
// stillWaitingAfter is how long a test watches a HandleMessage that must
// wait. One that does not wait returns well within it.
@@ -32,10 +32,6 @@ const (
firstManyPrefix = "10.0.0.0/32"
)
// tableWriteTimeout is how long a test waits for the flush timer to write the
// routing table's changes: a few ticks of it.
const tableWriteTimeout = 5 * prefixBatchTimeout
// tableCase is one test of the routing table in memory: the messages handed to
// the prefix handler, and for each prefix the peers that carry it with each
// origin AS after them.
@@ -276,9 +272,9 @@ func TestPrefixHandlerWritesTheTableChangesEachSecond(t *testing.T) {
t.Fatalf("wrote %+v, want the pair of %s and AS%d with "+
"removed %t", changes, prefix, testASNB, step.wantRemoved)
}
case <-time.After(tableWriteTimeout):
case <-time.After(handleMessageTimeout):
t.Fatalf("the routing table's change was not written within %s",
tableWriteTimeout)
handleMessageTimeout)
}
}
}