Make the tests pass on a busy host (closes #240)

Tests that wait on the real clock failed when the host stalled for a few seconds, although the code was right. Waits for something that should happen are now mostly 15 seconds. Tests whose result depends on a short idle timeout or a production request limit run under `synctest.Test`, on a fake clock, with a fake transport where a real connection would stop that clock. Test code only.

Judgement call: the 5-second waits in three `internal/streamer` tests also became 15 seconds.

Model: opus-5-5

internal/server/handlers_internal_test.go

@@ -17,6 +17,7 @@ import (
 	"strings"
 	"sync/atomic"
 	"testing"
+	"testing/synctest"
 	"time"
 
 	"git.eeqj.de/sneak/routewatch/internal/config"
@@ -173,6 +174,9 @@ type tableStats struct {
 // carried 203.0.113.0/24, the two with kept routes withdrew it, so its origin
 // keeps no route. The oldest and newest routes are those of the other two
 // prefixes.
+//
+// The requests run in a synctest bubble, whose clock is fake, so a stall on
+// the host does not use up the handlers' 4-second limit.
 func TestStatsHandlersAnswerFromMemory(t *testing.T) {
 	t.Parallel()
 
@@ -218,7 +222,11 @@ func TestStatsHandlersAnswerFromMemory(t *testing.T) {
 
 	for name, handler := range handlers {
 		rec := httptest.NewRecorder()
-		handler(rec, httptest.NewRequestWithContext(t.Context(), http.MethodGet, "/", nil))
+
+		synctest.Test(t, func(t *testing.T) {
+			handler(rec,
+				httptest.NewRequestWithContext(t.Context(), http.MethodGet, "/", nil))
+		})
 
 		if rec.Code != http.StatusOK {
 			t.Errorf("%s: status %d, want %d; body %s",
@@ -253,15 +261,20 @@ func TestStatsHandlersAnswerFromMemory(t *testing.T) {
 // TestStatsAnswerCarriesChurnPerMinute checks that the stream object of the
 // /api/v1/stats answer holds route_churn_per_min as a whole number, and no
 // longer route_churn_per_sec, the moving average it replaces
-// (https://git.eeqj.de/sneak/routewatch/issues/160).
+// (https://git.eeqj.de/sneak/routewatch/issues/160). The request runs in a
+// synctest bubble, whose clock is fake, so a stall on the host does not use up
+// the handler's 4-second limit.
 func TestStatsAnswerCarriesChurnPerMinute(t *testing.T) {
 	t.Parallel()
 
 	s := newServerWithTestRoutes(t)
 
 	rec := httptest.NewRecorder()
-	s.handleStats()(rec,
-		httptest.NewRequestWithContext(t.Context(), http.MethodGet, statsPath, nil))
+
+	synctest.Test(t, func(t *testing.T) {
+		s.handleStats()(rec,
+			httptest.NewRequestWithContext(t.Context(), http.MethodGet, statsPath, nil))
+	})
 
 	if rec.Code != http.StatusOK {
 		t.Fatalf("status %d, want %d; body %s", rec.Code, http.StatusOK, rec.Body)
@@ -309,18 +322,26 @@ func (heldBackHandler) HeldBackCount() int                 { return heldBackMess
 
 // TestStatsAnswerGivesHowManyMessagesAHandlerHoldsBack registers a handler
 // that holds back messages. Its figures in /api/v1/stats, which the status
-// page shows, must give how many.
+// page shows, must give how many. The request runs in a synctest bubble, whose
+// clock is fake, so a stall on the host does not use up the handler's 4-second
+// limit.
 func TestStatsAnswerGivesHowManyMessagesAHandlerHoldsBack(t *testing.T) {
 	t.Parallel()
 
 	s := newServerWithTestRoutes(t)
 	s.streamer.RegisterHandler(heldBackHandler{})
 
+	var answer []byte
+
+	synctest.Test(t, func(t *testing.T) {
+		answer = get(t, s, statsPath).Body.Bytes()
+	})
+
 	var body struct {
 		Data StatsResponse `json:"data"`
 	}
 
-	err := json.Unmarshal(get(t, s, statsPath).Body.Bytes(), &body)
+	err := json.Unmarshal(answer, &body)
 	if err != nil {
 		t.Fatalf("decoding the answer: %v", err)
 	}
@@ -364,7 +385,9 @@ type unitStats struct {
 // names. They used to be strings with the unit in them, such as "1h18m34s" or
 // "1.1 GB" (https://git.eeqj.de/sneak/routewatch/issues/199). The stream has
 // never connected, so the uptime is 0. The memory use in /api/v1/stats is the
-// same number of bytes as its gc.heap_alloc_bytes.
+// same number of bytes as its gc.heap_alloc_bytes. The requests run in a
+// synctest bubble, whose clock is fake, so a stall on the host does not use up
+// the handlers' 4-second limit.
 func TestStatsAnswersGiveUnitsInFieldNames(t *testing.T) {
 	t.Parallel()
 
@@ -374,7 +397,11 @@ func TestStatsAnswersGiveUnitsInFieldNames(t *testing.T) {
 	s.SetASNFetcher(fixedIntervalASNFetcher{interval: fetchInterval})
 
 	for _, path := range []string{statusJSONPath, statsPath} {
-		answer := get(t, s, path).Body.Bytes()
+		var answer []byte
+
+		synctest.Test(t, func(t *testing.T) {
+			answer = get(t, s, path).Body.Bytes()
+		})
 
 		var body struct {
 			Data unitStats `json:"data"`
@@ -415,82 +442,89 @@ func TestStatsAnswersGiveUnitsInFieldNames(t *testing.T) {
 // connection_duration_seconds of /api/v1/stats is null while the stream is not
 // connected, and a whole number of seconds once it is. It used to be the
 // string "disconnected", or a Go duration such as "1h18m34s"
-// (https://git.eeqj.de/sneak/routewatch/issues/199).
+// (https://git.eeqj.de/sneak/routewatch/issues/199). The test runs in a
+// synctest bubble, whose clock is fake, so a stall on the host does not use up
+// the handler's 4-second limit.
 func TestStatsAnswerGivesConnectionDurationInSeconds(t *testing.T) {
 	t.Parallel()
 
 	s := newServerWithTestRoutes(t)
 
-	connectionDuration := func() json.RawMessage {
-		answer := get(t, s, statsPath).Body.Bytes()
+	synctest.Test(t, func(t *testing.T) {
+		connectionDuration := func() json.RawMessage {
+			answer := get(t, s, statsPath).Body.Bytes()
 
-		var body struct {
-			Data map[string]json.RawMessage `json:"data"`
+			var body struct {
+				Data map[string]json.RawMessage `json:"data"`
+			}
+
+			err := json.Unmarshal(answer, &body)
+			if err != nil {
+				t.Fatalf("decoding the answer: %v; answer %s", err, answer)
+			}
+
+			duration, ok := body.Data["connection_duration_seconds"]
+			if !ok {
+				t.Fatalf("no connection_duration_seconds: %s", answer)
+			}
+
+			return duration
 		}
 
-		err := json.Unmarshal(answer, &body)
-		if err != nil {
-			t.Fatalf("decoding the answer: %v; answer %s", err, answer)
+		disconnected := connectionDuration()
+		if string(disconnected) != "null" {
+			t.Errorf("disconnected: connection_duration_seconds = %s, want null",
+				disconnected)
 		}
 
-		duration, ok := body.Data["connection_duration_seconds"]
-		if !ok {
-			t.Fatalf("no connection_duration_seconds: %s", answer)
+		s.streamer.GetMetricsTracker().SetConnected(true)
+
+		var seconds int64
+
+		connected := connectionDuration()
+
+		err := json.Unmarshal(connected, &seconds)
+		if err != nil || seconds != 0 {
+			t.Errorf("just connected: connection_duration_seconds = %s, want 0",
+				connected)
 		}
-
-		return duration
-	}
-
-	disconnected := connectionDuration()
-	if string(disconnected) != "null" {
-		t.Errorf("disconnected: connection_duration_seconds = %s, want null",
-			disconnected)
-	}
-
-	s.streamer.GetMetricsTracker().SetConnected(true)
-
-	var seconds int64
-
-	connected := connectionDuration()
-
-	err := json.Unmarshal(connected, &seconds)
-	if err != nil || seconds != 0 {
-		t.Errorf("just connected: connection_duration_seconds = %s, want 0",
-			connected)
-	}
+	})
 }
 
 // TestStreamDurationsCountSeconds checks that the uptime and the connection
 // duration of a stream that connected 90 seconds ago are both 90. A stream
 // that has never connected has an uptime of 0, and one that is not connected
-// has no connection duration.
+// has no connection duration. The test runs in a synctest bubble, whose clock
+// is fake, so a stall on the host does not add to the 90 seconds.
 func TestStreamDurationsCountSeconds(t *testing.T) {
 	t.Parallel()
 
-	const connectedFor = 90 * time.Second
+	synctest.Test(t, func(t *testing.T) {
+		const connectedFor = 90 * time.Second
 
-	connectedSince := time.Now().Add(-connectedFor)
-	want := int64(connectedFor / time.Second)
+		connectedSince := time.Now().Add(-connectedFor)
+		want := int64(connectedFor / time.Second)
 
-	if got := uptimeSeconds(connectedSince); got != want {
-		t.Errorf("uptimeSeconds = %d, want %d", got, want)
-	}
+		if got := uptimeSeconds(connectedSince); got != want {
+			t.Errorf("uptimeSeconds = %d, want %d", got, want)
+		}
 
-	if got := uptimeSeconds(time.Time{}); got != 0 {
-		t.Errorf("uptimeSeconds before any connection = %d, want 0", got)
-	}
+		if got := uptimeSeconds(time.Time{}); got != 0 {
+			t.Errorf("uptimeSeconds before any connection = %d, want 0", got)
+		}
 
-	switch got := connectionDurationSeconds(true, connectedSince); {
-	case got == nil:
-		t.Errorf("connectionDurationSeconds = nil, want %d", want)
-	case *got != want:
-		t.Errorf("connectionDurationSeconds = %d, want %d", *got, want)
-	}
+		switch got := connectionDurationSeconds(true, connectedSince); {
+		case got == nil:
+			t.Errorf("connectionDurationSeconds = nil, want %d", want)
+		case *got != want:
+			t.Errorf("connectionDurationSeconds = %d, want %d", *got, want)
+		}
 
-	if got := connectionDurationSeconds(false, connectedSince); got != nil {
-		t.Errorf("connectionDurationSeconds while not connected = %d, want nil",
-			*got)
-	}
+		if got := connectionDurationSeconds(false, connectedSince); got != nil {
+			t.Errorf("connectionDurationSeconds while not connected = %d, want nil",
+				*got)
+		}
+	})
 }
 
 // newTestTable returns a routing table that holds a route for testPrefixV4,
@@ -1134,7 +1168,9 @@ func (failingDB) GetPrefixFirstSeen(
 // with the driver's error text. It also sends a prefix that does not parse.
 // No answer may carry the driver's or the prefix parser's text. Before the fix
 // the answers sent it to the client
-// (https://git.eeqj.de/sneak/routewatch/issues/108).
+// (https://git.eeqj.de/sneak/routewatch/issues/108). The requests run in a
+// synctest bubble, whose clock is fake, so a stall on the host does not use up
+// the stats handlers' 4-second limit.
 func TestJSONRoutesDoNotSendErrorDetails(t *testing.T) {
 	t.Parallel()
 
@@ -1155,8 +1191,11 @@ func TestJSONRoutesDoNotSendErrorDetails(t *testing.T) {
 
 	for _, tt := range tests {
 		rec := httptest.NewRecorder()
-		s.router.ServeHTTP(rec, httptest.NewRequestWithContext(
-			t.Context(), http.MethodGet, tt.path, nil))
+
+		synctest.Test(t, func(t *testing.T) {
+			s.router.ServeHTTP(rec, httptest.NewRequestWithContext(
+				t.Context(), http.MethodGet, tt.path, nil))
+		})
 
 		if rec.Code != tt.wantCode {
 			t.Errorf("%s: status %d, want %d; body %s",
@@ -1397,8 +1436,11 @@ func TestIPLookupKeepsRouteWhenPTRLookupDoesNotAnswer(t *testing.T) {
 	s := newServerWithTestRoutes(t)
 	s.resolver = &fakeResolver{ptrNeverAnswers: true}
 
-	// The request's time limit passes after the PTR lookup's.
-	ctx, cancel := context.WithTimeout(t.Context(), 2*ptrLookupTimeout)
+	// The request's time limit passes well after the PTR lookup's, so that a
+	// stall on a busy host does not use up the difference.
+	const requestTimeLimit = ptrLookupTimeout + 15*time.Second
+
+	ctx, cancel := context.WithTimeout(t.Context(), requestTimeLimit)
 	defer cancel()
 
 	rec := httptest.NewRecorder()
@@ -2367,9 +2409,13 @@ func settledGoroutineCount() int {
 	return prev
 }
 
-// waitForGoroutines waits until the goroutine count drops to target or below.
+// waitForGoroutines waits up to 15 seconds for the goroutine count to drop to
+// target or below.
 func waitForGoroutines(target int) bool {
-	for range 100 {
+	const maxWait = 15 * time.Second
+
+	deadline := time.Now().Add(maxWait)
+	for time.Now().Before(deadline) {
 		if runtime.NumGoroutine() <= target {
 			return true
 		}

internal/server/home_internal_test.go

@@ -76,7 +76,9 @@ func asLink(asn int) string {
 }
 
 // TestHomePageCardsShowTheTableFigures fills a routing table and the asns
-// table, works out the cards, and checks that each card shows its figure.
+// table, works out the cards, and checks that each card shows its figure. The
+// cards are worked out in a synctest bubble, whose clock is fake, so a stall on
+// the host does not use up the 4-second limit on their database read.
 func TestHomePageCardsShowTheTableFigures(t *testing.T) {
 	t.Parallel()
 
@@ -95,7 +97,9 @@ func TestHomePageCardsShowTheTableFigures(t *testing.T) {
 		t.Fatalf("GetOrCreateASNBatch: %v", err)
 	}
 
-	s.refreshHomeCards(t.Context())
+	synctest.Test(t, func(t *testing.T) {
+		s.refreshHomeCards(t.Context())
+	})
 
 	page := get(t, s, "/").Body.String()
 
@@ -279,7 +283,7 @@ func TestKeepHomeCardsFreshWorksThemOutEveryInterval(t *testing.T) {
 
 	const (
 		interval = 10 * time.Millisecond
-		maxWait  = 5 * time.Second
+		maxWait  = 15 * time.Second
 	)
 
 	table := emptyTable()
@@ -321,7 +325,7 @@ func TestKeepHomeCardsFreshWorksThemOutEveryInterval(t *testing.T) {
 func TestStartedServerWorksOutTheCards(t *testing.T) {
 	t.Parallel()
 
-	const maxWait = 5 * time.Second
+	const maxWait = 15 * time.Second
 
 	s := newServerWithTable(t, newCardsTable())
 

internal/server/middleware_internal_test.go

@@ -14,6 +14,7 @@ import (
 	"regexp"
 	"strings"
 	"testing"
+	"testing/synctest"
 	"time"
 
 	"git.eeqj.de/sneak/routewatch/internal/config"
@@ -163,6 +164,10 @@ func TestJSONAnswersPutNoUnitInAString(t *testing.T) {
 // router and the middleware write. Before the fix a panic in a handler, and a
 // method /status.json or the health check does not take, answered with an
 // empty body (https://git.eeqj.de/sneak/routewatch/issues/201).
+//
+// The requests run in a synctest bubble, whose clock is fake, so a stall on
+// the host does not use up the 2-second limit of the health check or the
+// 4-second limit of the stats handlers.
 func TestJSONAnswersCarryMeta(t *testing.T) {
 	t.Parallel()
 
@@ -181,6 +186,10 @@ func TestJSONAnswersCarryMeta(t *testing.T) {
 	s.router.Get(panicsPath, JSONValidationMiddleware(http.HandlerFunc(
 		func(http.ResponseWriter, *http.Request) { panic(errDiskIO) })).ServeHTTP)
 
+	failing := New(failingDB{}, newTestTable(),
+		streamer.New(logger.New(), metrics.New()), logger.New(), &config.Config{})
+	failing.resolver = &fakeResolver{}
+
 	tests := []struct {
 		method   string
 		path     string
@@ -216,42 +225,40 @@ func TestJSONAnswersCarryMeta(t *testing.T) {
 		{http.MethodGet, panicsPath, http.StatusInternalServerError},
 	}
 
-	for _, tt := range tests {
-		checkAnswerCarriesMeta(t, s, httptest.NewRequestWithContext(
-			t.Context(), tt.method, tt.path, nil), tt.wantCode)
-	}
+	synctest.Test(t, func(t *testing.T) {
+		for _, tt := range tests {
+			checkAnswerCarriesMeta(t, s, httptest.NewRequestWithContext(
+				t.Context(), tt.method, tt.path, nil), tt.wantCode)
+		}
 
-	// A request whose time limit has already passed answers 504. The handlers
-	// write the answers of the first five routes, and the JSON check on the
-	// route writes the last.
-	pastTimeLimit, cancel := context.WithDeadline(t.Context(), time.Now())
-	defer cancel()
+		// A request whose time limit has already passed answers 504. The
+		// handlers write the answers of the first five routes, and the JSON
+		// check on the route writes the last.
+		pastTimeLimit, cancel := context.WithDeadline(t.Context(), time.Now())
+		defer cancel()
 
-	for _, path := range []string{
-		statusJSONPath, statsPath, "/ip/" + addrInTestPrefixV4,
-		"/api/v1/ip/" + addrInTestPrefixV4, asJSONPath, writesNothingPath,
-	} {
-		checkAnswerCarriesMeta(t, s, httptest.NewRequestWithContext(
-			pastTimeLimit, http.MethodGet, path, nil), http.StatusGatewayTimeout)
-	}
+		for _, path := range []string{
+			statusJSONPath, statsPath, "/ip/" + addrInTestPrefixV4,
+			"/api/v1/ip/" + addrInTestPrefixV4, asJSONPath, writesNothingPath,
+		} {
+			checkAnswerCarriesMeta(t, s, httptest.NewRequestWithContext(
+				pastTimeLimit, http.MethodGet, path, nil), http.StatusGatewayTimeout)
+		}
 
-	// With a store whose reads fail, the health check answers 503, and the
-	// handlers of the other routes 500.
-	failing := New(failingDB{}, newTestTable(),
-		streamer.New(logger.New(), metrics.New()), logger.New(), &config.Config{})
-	failing.resolver = &fakeResolver{}
-
-	checkAnswerCarriesMeta(t, failing, httptest.NewRequestWithContext(
-		t.Context(), http.MethodGet, healthCheckPath, nil),
-		http.StatusServiceUnavailable)
-
-	for _, path := range []string{
-		statusJSONPath, statsPath, asJSONPath,
-		"/api/v1/ip/" + addrInTestPrefixV4, "/ip/" + addrInTestPrefixV4,
-	} {
+		// With a store whose reads fail, the health check answers 503, and
+		// the handlers of the other routes 500.
 		checkAnswerCarriesMeta(t, failing, httptest.NewRequestWithContext(
-			t.Context(), http.MethodGet, path, nil), http.StatusInternalServerError)
-	}
+			t.Context(), http.MethodGet, healthCheckPath, nil),
+			http.StatusServiceUnavailable)
+
+		for _, path := range []string{
+			statusJSONPath, statsPath, asJSONPath,
+			"/api/v1/ip/" + addrInTestPrefixV4, "/ip/" + addrInTestPrefixV4,
+		} {
+			checkAnswerCarriesMeta(t, failing, httptest.NewRequestWithContext(
+				t.Context(), http.MethodGet, path, nil), http.StatusInternalServerError)
+		}
+	})
 }
 
 // checkAnswerCarriesMeta serves req through the server's router, and checks

internal/server/routes_internal_test.go

@@ -5,6 +5,7 @@ import (
 	"net/http"
 	"net/http/httptest"
 	"testing"
+	"testing/synctest"
 )
 
 // TestRoutesAnswerHEAD sends HEAD for a page and JSON routes through the
@@ -12,15 +13,23 @@ import (
 // lookup of the caller's own address, are in the list because chi's GetHead
 // does not reach them. Before the fix every route answered HEAD with 405
 // (https://git.eeqj.de/sneak/routewatch/issues/111).
+//
+// The requests run in a synctest bubble, whose clock is fake, so a stall on
+// the host does not use up the stats handlers' 4-second limit. The resolver
+// is fake because no time limit would cut off a real DNS lookup in a bubble.
 func TestRoutesAnswerHEAD(t *testing.T) {
 	t.Parallel()
 
 	s := newServerWithTestRoutes(t)
+	s.resolver = &fakeResolver{}
 
 	for _, path := range []string{"/", statusJSONPath, statsPath, "/ip", "/ip/"} {
 		rec := httptest.NewRecorder()
-		s.router.ServeHTTP(rec, httptest.NewRequestWithContext(
-			t.Context(), http.MethodHead, path, nil))
+
+		synctest.Test(t, func(t *testing.T) {
+			s.router.ServeHTTP(rec, httptest.NewRequestWithContext(
+				t.Context(), http.MethodHead, path, nil))
+		})
 
 		if rec.Code != http.StatusOK {
 			t.Errorf("HEAD %s: status %d, want %d; body %s",

internal/server/server_internal_test.go

@@ -22,10 +22,10 @@ func TestStopClosesTheConnectionOfARequestStillRunning(t *testing.T) {
 		stopDeadline = 100 * time.Millisecond
 		// waitTimeout is how long the test waits for the request to reach
 		// the handler, and then for the client to see its connection closed.
-		waitTimeout = 2 * time.Second
+		waitTimeout = 15 * time.Second
 		// readHeaderTimeout bounds the test server's read of the request
 		// header, as every http.Server must.
-		readHeaderTimeout = time.Second
+		readHeaderTimeout = waitTimeout
 	)
 
 	release := make(chan struct{})