check / check (push) Waiting to run
The hand-written time limit middleware answered 408 and wrote that answer from its own goroutine while the handler could still be writing. It is replaced by chi's middleware.Timeout, placed after JSONResponseMiddleware so its 504 is not lost behind a 200. When a handler's database read or other lookup fails, it asks deadlinePassed whether the request's time limit passed and, if so, answers 504 instead of its 500 or 404. JSONValidationMiddleware answers 504 with the JSON error body when the limit has passed and the handler wrote nothing. status.json and /api/v1/stats answer 504 when their 4-second database read runs out. Model: opus-5-5
403 lines
14 KiB
Go
403 lines
14 KiB
Go
package server
|
|
|
|
import (
|
|
"context"
|
|
"encoding/json"
|
|
"net/http"
|
|
"net/http/httptest"
|
|
"runtime"
|
|
"slices"
|
|
"testing"
|
|
"time"
|
|
|
|
"git.eeqj.de/sneak/routewatch/internal/config"
|
|
"git.eeqj.de/sneak/routewatch/internal/database"
|
|
"git.eeqj.de/sneak/routewatch/internal/logger"
|
|
"git.eeqj.de/sneak/routewatch/internal/metrics"
|
|
"git.eeqj.de/sneak/routewatch/internal/streamer"
|
|
"github.com/google/uuid"
|
|
)
|
|
|
|
// blockingStatsDB embeds database.Store (left nil) and overrides only
|
|
// GetStatsContext, which blocks until release is closed. The stats handlers
|
|
// call it in a goroutine; every other Store method is unused on the timeout
|
|
// path and would panic if called.
|
|
type blockingStatsDB struct {
|
|
database.Store
|
|
release chan struct{}
|
|
}
|
|
|
|
func (d blockingStatsDB) GetStatsContext(_ context.Context) (database.Stats, error) {
|
|
<-d.release
|
|
|
|
return database.Stats{}, nil
|
|
}
|
|
|
|
// TestStatsHandlersDoNotLeakOnTimeout drives each stats handler repeatedly with
|
|
// a request whose context times out before the database responds, then releases
|
|
// the blocked queries and asserts the goroutine count returns to its starting
|
|
// value. Before the fix the per-request goroutine sent on an unbuffered channel
|
|
// that nothing received once the timeout won, so it blocked forever and every
|
|
// poll leaked one goroutine.
|
|
func TestStatsHandlersDoNotLeakOnTimeout(t *testing.T) {
|
|
release := make(chan struct{})
|
|
db := blockingStatsDB{release: release}
|
|
s := New(db, streamer.New(logger.New(), metrics.New()), logger.New(), &config.Config{})
|
|
|
|
handlers := map[string]http.HandlerFunc{
|
|
"status.json": s.handleStatusJSON(),
|
|
"stats": s.handleStats(),
|
|
}
|
|
|
|
baseline := settledGoroutineCount()
|
|
|
|
const (
|
|
iterations = 20
|
|
requestTimeout = 50 * time.Millisecond
|
|
)
|
|
for _, handler := range handlers {
|
|
for range iterations {
|
|
ctx, cancel := context.WithTimeout(context.Background(), requestTimeout)
|
|
req := httptest.NewRequest(http.MethodGet, "/", nil).WithContext(ctx)
|
|
handler(httptest.NewRecorder(), req)
|
|
cancel()
|
|
}
|
|
}
|
|
|
|
// Let the blocked queries finish; with buffered channels each goroutine's
|
|
// send now succeeds and the goroutine exits.
|
|
close(release)
|
|
|
|
if !waitForGoroutines(baseline) {
|
|
t.Fatalf("goroutines did not return to baseline %d, got %d",
|
|
baseline, runtime.NumGoroutine())
|
|
}
|
|
}
|
|
|
|
// TestStatsHandlersAnswerFromMemory checks that both stats handlers answer 200
|
|
// with the live route counts and the prefix distribution while the database is
|
|
// closed, so that any query would fail: the request path reads them from
|
|
// memory. The prefix distribution query it used to run read every live route
|
|
// and, on a large database, took the whole 4-second deadline, so
|
|
// /api/v1/stats answered 500 (https://git.eeqj.de/sneak/routewatch/issues/30).
|
|
// The oldest and newest route times still come from one-row lookups at the ends
|
|
// of an index; with the database closed they are left out of the answer.
|
|
func TestStatsHandlersAnswerFromMemory(t *testing.T) {
|
|
db, err := database.New(&config.Config{StateDir: t.TempDir()}, logger.New())
|
|
if err != nil {
|
|
t.Fatalf("database.New: %v", err)
|
|
}
|
|
|
|
ts := time.Date(2026, 1, 2, 3, 4, 5, 0, time.UTC)
|
|
if err := db.UpsertLiveRouteBatch([]*database.LiveRoute{
|
|
{
|
|
ID: uuid.New(), Prefix: "198.51.100.0/24", MaskLength: 24, IPVersion: 4,
|
|
OriginASN: 64500, PeerIP: "192.0.2.1", ASPath: []int{64500}, NextHop: "192.0.2.1",
|
|
LastUpdated: ts,
|
|
},
|
|
{
|
|
ID: uuid.New(), Prefix: "2001:db8::/32", MaskLength: 32, IPVersion: 6,
|
|
OriginASN: 64501, PeerIP: "2001:db8::1", ASPath: []int{64501}, NextHop: "2001:db8::1",
|
|
LastUpdated: ts,
|
|
},
|
|
}); err != nil {
|
|
t.Fatalf("UpsertLiveRouteBatch: %v", err)
|
|
}
|
|
if err := db.Close(); err != nil {
|
|
t.Fatalf("Close: %v", err)
|
|
}
|
|
|
|
s := New(db, streamer.New(logger.New(), metrics.New()), logger.New(), &config.Config{})
|
|
handlers := map[string]http.HandlerFunc{
|
|
"status.json": s.handleStatusJSON(),
|
|
"stats": s.handleStats(),
|
|
}
|
|
|
|
for name, handler := range handlers {
|
|
rec := httptest.NewRecorder()
|
|
handler(rec, httptest.NewRequest(http.MethodGet, "/", nil))
|
|
if rec.Code != http.StatusOK {
|
|
t.Errorf("%s: status %d, want %d; body %s", name, rec.Code, http.StatusOK, rec.Body)
|
|
|
|
continue
|
|
}
|
|
|
|
var body struct {
|
|
Data struct {
|
|
IPv4Routes int `json:"ipv4_routes"`
|
|
IPv6Routes int `json:"ipv6_routes"`
|
|
IPv4PrefixDistribution []database.PrefixDistribution `json:"ipv4_prefix_distribution"`
|
|
IPv6PrefixDistribution []database.PrefixDistribution `json:"ipv6_prefix_distribution"`
|
|
} `json:"data"`
|
|
}
|
|
if err := json.Unmarshal(rec.Body.Bytes(), &body); err != nil {
|
|
t.Fatalf("%s: decoding the answer: %v", name, err)
|
|
}
|
|
|
|
if body.Data.IPv4Routes != 1 || body.Data.IPv6Routes != 1 {
|
|
t.Errorf("%s: routes = (v4 %d, v6 %d), want (1, 1)", name, body.Data.IPv4Routes, body.Data.IPv6Routes)
|
|
}
|
|
wantV4 := []database.PrefixDistribution{{MaskLength: 24, Count: 1}}
|
|
if !slices.Equal(body.Data.IPv4PrefixDistribution, wantV4) {
|
|
t.Errorf("%s: IPv4 distribution = %v, want %v", name, body.Data.IPv4PrefixDistribution, wantV4)
|
|
}
|
|
wantV6 := []database.PrefixDistribution{{MaskLength: 32, Count: 1}}
|
|
if !slices.Equal(body.Data.IPv6PrefixDistribution, wantV6) {
|
|
t.Errorf("%s: IPv6 distribution = %v, want %v", name, body.Data.IPv6PrefixDistribution, wantV6)
|
|
}
|
|
}
|
|
}
|
|
|
|
// TestPrefixDetailHandlersParsePrefix checks that both prefix pages find a
|
|
// stored route whatever valid text form the URL writes its prefix in, and
|
|
// answer 400 for a prefix that does not parse. The tables store the form
|
|
// net/netip prints. Before the fix the URL text was looked up as typed, so
|
|
// "2001:DB8:0:0::/32" was not found although "2001:db8::/32" was stored, and
|
|
// "foo/24" answered 500 (https://git.eeqj.de/sneak/routewatch/issues/71).
|
|
func TestPrefixDetailHandlersParsePrefix(t *testing.T) {
|
|
db, err := database.New(&config.Config{StateDir: t.TempDir()}, logger.New())
|
|
if err != nil {
|
|
t.Fatalf("database.New: %v", err)
|
|
}
|
|
t.Cleanup(func() { _ = db.Close() })
|
|
|
|
ts := time.Date(2026, 1, 2, 3, 4, 5, 0, time.UTC)
|
|
if err := db.UpsertLiveRouteBatch([]*database.LiveRoute{
|
|
{
|
|
ID: uuid.New(), Prefix: "192.0.2.0/24", MaskLength: 24, IPVersion: 4,
|
|
OriginASN: 64500, PeerIP: "198.51.100.1", ASPath: []int{64500}, NextHop: "198.51.100.1",
|
|
LastUpdated: ts,
|
|
},
|
|
{
|
|
ID: uuid.New(), Prefix: "2001:db8::/32", MaskLength: 32, IPVersion: 6,
|
|
OriginASN: 64501, PeerIP: "2001:db8::1", ASPath: []int{64501}, NextHop: "2001:db8::1",
|
|
LastUpdated: ts,
|
|
},
|
|
}); err != nil {
|
|
t.Fatalf("UpsertLiveRouteBatch: %v", err)
|
|
}
|
|
|
|
s := New(db, streamer.New(logger.New(), metrics.New()), logger.New(), &config.Config{})
|
|
|
|
tests := []struct {
|
|
path string
|
|
want int
|
|
}{
|
|
{"/api/v1/prefix/foo/24", http.StatusBadRequest},
|
|
{"/prefix/foo/24", http.StatusBadRequest},
|
|
{"/api/v1/prefix/2001:DB8:0:0::/32", http.StatusOK},
|
|
{"/prefix/2001:DB8:0:0::/32", http.StatusOK},
|
|
{"/api/v1/prefix/192.0.2.1/24", http.StatusOK},
|
|
{"/prefix/192.0.2.1/24", http.StatusOK},
|
|
}
|
|
|
|
for _, tt := range tests {
|
|
rec := httptest.NewRecorder()
|
|
s.router.ServeHTTP(rec, httptest.NewRequest(http.MethodGet, tt.path, nil))
|
|
if rec.Code != tt.want {
|
|
t.Errorf("%s: status %d, want %d; body %s", tt.path, rec.Code, tt.want, rec.Body)
|
|
}
|
|
}
|
|
}
|
|
|
|
// shortRequestDeadline is the deadline the tests below give a request. The
|
|
// server's 30-second limit and the stats handlers' 4-second limit inherit it,
|
|
// so the tests do not wait for either.
|
|
const shortRequestDeadline = 50 * time.Millisecond
|
|
|
|
// TestRequestPastTimeLimitAnswers504 sends a request through the server's
|
|
// router to a page and to a JSON route whose handlers wait for the time limit
|
|
// to pass and return without answering. The page answers 504; the JSON route
|
|
// answers 504 with the JSON error body. Before the fix both answered 408,
|
|
// written by the time limit middleware from its own goroutine while the
|
|
// handler could still be writing.
|
|
func TestRequestPastTimeLimitAnswers504(t *testing.T) {
|
|
s := New(nil, streamer.New(logger.New(), metrics.New()), logger.New(), &config.Config{})
|
|
|
|
waitForTimeLimit := func(_ http.ResponseWriter, r *http.Request) {
|
|
<-r.Context().Done()
|
|
}
|
|
// Registered the way setupRoutes registers pages and JSON routes.
|
|
s.router.Get("/slow-page", waitForTimeLimit)
|
|
s.router.Get("/slow.json", JSONValidationMiddleware(http.HandlerFunc(waitForTimeLimit)).ServeHTTP)
|
|
|
|
tests := []struct {
|
|
path string
|
|
wantJSONBody bool
|
|
}{
|
|
{path: "/slow-page"},
|
|
{path: "/slow.json", wantJSONBody: true},
|
|
}
|
|
|
|
for _, tt := range tests {
|
|
ctx, cancel := context.WithTimeout(context.Background(), shortRequestDeadline)
|
|
rec := httptest.NewRecorder()
|
|
s.router.ServeHTTP(rec, httptest.NewRequest(http.MethodGet, tt.path, nil).WithContext(ctx))
|
|
cancel()
|
|
|
|
if rec.Code != http.StatusGatewayTimeout {
|
|
t.Errorf("%s: status %d, want %d; body %s", tt.path, rec.Code, http.StatusGatewayTimeout, rec.Body)
|
|
}
|
|
if tt.wantJSONBody {
|
|
checkJSONErrorCode(t, tt.path, rec, http.StatusGatewayTimeout)
|
|
}
|
|
}
|
|
}
|
|
|
|
// TestStatsHandlersAnswer504WhenDatabaseReadRunsOut calls each stats handler
|
|
// with a store that does not answer before the handler's 4-second limit runs
|
|
// out, and checks that the handler itself answers 504 with the JSON error
|
|
// body. Before the fix status.json answered 408, and /api/v1/stats wrote
|
|
// nothing, which the JSON check on its route turned into 500.
|
|
func TestStatsHandlersAnswer504WhenDatabaseReadRunsOut(t *testing.T) {
|
|
release := make(chan struct{})
|
|
defer close(release)
|
|
db := blockingStatsDB{release: release}
|
|
s := New(db, streamer.New(logger.New(), metrics.New()), logger.New(), &config.Config{})
|
|
|
|
handlers := map[string]http.HandlerFunc{
|
|
"status.json": s.handleStatusJSON(),
|
|
"stats": s.handleStats(),
|
|
}
|
|
|
|
for name, handler := range handlers {
|
|
ctx, cancel := context.WithTimeout(context.Background(), shortRequestDeadline)
|
|
rec := httptest.NewRecorder()
|
|
handler(rec, httptest.NewRequest(http.MethodGet, "/", nil).WithContext(ctx))
|
|
cancel()
|
|
|
|
if rec.Code != http.StatusGatewayTimeout {
|
|
t.Errorf("%s: status %d, want %d; body %s", name, rec.Code, http.StatusGatewayTimeout, rec.Body)
|
|
}
|
|
checkJSONErrorCode(t, name, rec, http.StatusGatewayTimeout)
|
|
}
|
|
}
|
|
|
|
// slowDB embeds database.Store (left nil) and overrides the reads the routes
|
|
// in TestRoutesAnswer504WhenDatabaseReadIsCutOff make. Each read waits until
|
|
// its context ends and returns the context's error, as a slow database read
|
|
// cut off by a time limit does.
|
|
type slowDB struct {
|
|
database.Store
|
|
}
|
|
|
|
func (slowDB) GetStatsContext(ctx context.Context) (database.Stats, error) {
|
|
<-ctx.Done()
|
|
|
|
return database.Stats{}, ctx.Err()
|
|
}
|
|
|
|
func (slowDB) GetIPInfoContext(ctx context.Context, _ string) (*database.IPInfo, error) {
|
|
<-ctx.Done()
|
|
|
|
return nil, ctx.Err()
|
|
}
|
|
|
|
func (slowDB) GetASDetailsContext(ctx context.Context, _ int) (*database.ASN, []database.LiveRoute, error) {
|
|
<-ctx.Done()
|
|
|
|
return nil, nil, ctx.Err()
|
|
}
|
|
|
|
func (slowDB) GetPrefixDetailsContext(ctx context.Context, _ string) ([]database.LiveRoute, error) {
|
|
<-ctx.Done()
|
|
|
|
return nil, ctx.Err()
|
|
}
|
|
|
|
func (slowDB) GetRandomPrefixesByLengthContext(ctx context.Context, _, _, _ int) ([]database.LiveRoute, error) {
|
|
<-ctx.Done()
|
|
|
|
return nil, ctx.Err()
|
|
}
|
|
|
|
// TestRoutesAnswer504WhenDatabaseReadIsCutOff sends a request through the
|
|
// server's router for each route that reads the database, with a store whose
|
|
// reads fail when the request's time limit passes. Each route answers 504, the
|
|
// JSON routes with the JSON error body. Before the fix they answered 408 or,
|
|
// when the handler wrote first, its own error: 500, or 404 on the IP lookups.
|
|
// The health check is left out: it answers 503 when its own 2-second ping runs
|
|
// out.
|
|
func TestRoutesAnswer504WhenDatabaseReadIsCutOff(t *testing.T) {
|
|
s := New(slowDB{}, streamer.New(logger.New(), metrics.New()), logger.New(), &config.Config{})
|
|
|
|
tests := []struct {
|
|
path string
|
|
wantJSONBody bool
|
|
}{
|
|
{path: "/as/64500"},
|
|
{path: "/prefix/192.0.2.0/24"},
|
|
{path: "/prefixlength/24"},
|
|
{path: "/prefixlength6/48"},
|
|
{path: "/status.json", wantJSONBody: true},
|
|
{path: "/ip/192.0.2.1", wantJSONBody: true},
|
|
{path: "/api/v1/stats", wantJSONBody: true},
|
|
{path: "/api/v1/ip/192.0.2.1", wantJSONBody: true},
|
|
{path: "/api/v1/as/64500", wantJSONBody: true},
|
|
{path: "/api/v1/prefix/192.0.2.0/24", wantJSONBody: true},
|
|
}
|
|
|
|
for _, tt := range tests {
|
|
ctx, cancel := context.WithTimeout(context.Background(), shortRequestDeadline)
|
|
rec := httptest.NewRecorder()
|
|
s.router.ServeHTTP(rec, httptest.NewRequest(http.MethodGet, tt.path, nil).WithContext(ctx))
|
|
cancel()
|
|
|
|
if rec.Code != http.StatusGatewayTimeout {
|
|
t.Errorf("%s: status %d, want %d; body %s", tt.path, rec.Code, http.StatusGatewayTimeout, rec.Body)
|
|
}
|
|
if tt.wantJSONBody {
|
|
checkJSONErrorCode(t, tt.path, rec, http.StatusGatewayTimeout)
|
|
}
|
|
}
|
|
}
|
|
|
|
// checkJSONErrorCode checks that rec holds the JSON error body with the given
|
|
// code.
|
|
func checkJSONErrorCode(t *testing.T, name string, rec *httptest.ResponseRecorder, want int) {
|
|
t.Helper()
|
|
|
|
var body struct {
|
|
Status string `json:"status"`
|
|
Error struct {
|
|
Code int `json:"code"`
|
|
} `json:"error"`
|
|
}
|
|
if err := json.Unmarshal(rec.Body.Bytes(), &body); err != nil {
|
|
t.Errorf("%s: decoding the answer %q: %v", name, rec.Body, err)
|
|
|
|
return
|
|
}
|
|
if body.Status != "error" || body.Error.Code != want {
|
|
t.Errorf("%s: answer %s, want status \"error\" and error code %d", name, rec.Body, want)
|
|
}
|
|
}
|
|
|
|
// settledGoroutineCount lets transient goroutines finish, then reports the
|
|
// current count.
|
|
func settledGoroutineCount() int {
|
|
prev := runtime.NumGoroutine()
|
|
for range 20 {
|
|
time.Sleep(10 * time.Millisecond)
|
|
cur := runtime.NumGoroutine()
|
|
if cur == prev {
|
|
return cur
|
|
}
|
|
prev = cur
|
|
}
|
|
|
|
return prev
|
|
}
|
|
|
|
// waitForGoroutines waits until the goroutine count drops to target or below.
|
|
func waitForGoroutines(target int) bool {
|
|
for range 100 {
|
|
if runtime.NumGoroutine() <= target {
|
|
return true
|
|
}
|
|
time.Sleep(10 * time.Millisecond)
|
|
}
|
|
|
|
return false
|
|
}
|