From 44c2ce92614f71d9e931c7b8e093496f003f2161 Mon Sep 17 00:00:00 2001 From: clawbot <35+clawbot@noreply.example.org> Date: Tue, 27 Oct 2026 22:22:01 +0000 Subject: [PATCH] Wait up to 30 seconds for each step the routewatch tests expect (closes #213) 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 --- TODO.md | 4 +++ .../app_integration_internal_test.go | 31 +++++++------------ .../routewatch/batchwrite_internal_test.go | 10 ++++-- .../prefixhandler_table_internal_test.go | 8 ++--- 4 files changed, 24 insertions(+), 29 deletions(-) diff --git a/TODO.md b/TODO.md index d581f10..92ba5c4 100644 --- a/TODO.md +++ b/TODO.md @@ -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) diff --git a/internal/routewatch/app_integration_internal_test.go b/internal/routewatch/app_integration_internal_test.go index 15b3b61..e21e788 100644 --- a/internal/routewatch/app_integration_internal_test.go +++ b/internal/routewatch/app_integration_internal_test.go @@ -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) diff --git a/internal/routewatch/batchwrite_internal_test.go b/internal/routewatch/batchwrite_internal_test.go index e196fb9..34597de 100644 --- a/internal/routewatch/batchwrite_internal_test.go +++ b/internal/routewatch/batchwrite_internal_test.go @@ -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. diff --git a/internal/routewatch/prefixhandler_table_internal_test.go b/internal/routewatch/prefixhandler_table_internal_test.go index b4b894f..0935e47 100644 --- a/internal/routewatch/prefixhandler_table_internal_test.go +++ b/internal/routewatch/prefixhandler_table_internal_test.go @@ -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) } } }