Files
routewatch/internal/server/handlers_test.go
T
sneak 4037a5145c
check / check (push) Canceled after 0s
Answer 504, not 408, when a request outlasts its time limit (closes #70)
The 30-second limit is now chi's middleware.Timeout, which answers 504
and never writes from a second goroutine. It runs after
JSONResponseMiddleware, so a handler that wrote nothing is not sent a
200 first.

One rule covers the handlers: right after each database read or host
name lookup, before looking at what came back, error or not, a handler
asks deadlinePassed whether the time limit has passed and, if so,
answers 504, with the JSON error body on JSON routes. A cut-off read can
return an error, or part of its rows or none without one, so only this
check tells it from a complete read. JSONValidationMiddleware answers
504 with the JSON error body when the limit has passed and the handler
wrote nothing.

Model: opus-5-5
2026-10-19 07:49:34 +00:00

551 lines
19 KiB
Go

package server
import (
"context"
"encoding/json"
"errors"
"html"
"net/http"
"net/http/httptest"
"runtime"
"slices"
"strings"
"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"
"git.eeqj.de/sneak/routewatch/pkg/asinfo"
"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)
}
}
}
// failingASDetailsDB wraps a real store and fails every AS details lookup.
type failingASDetailsDB struct {
database.Store
}
func (failingASDetailsDB) GetASDetailsContext(_ context.Context, _ int) (*database.ASN, []database.LiveRoute, error) {
return nil, nil, errors.New("AS details lookup failed")
}
// TestPrefixDetailShowsOriginNames checks that the prefix page shows each
// origin AS's handle and description without looking up the AS's details,
// which also read every route the AS originates. Before the fix the page did
// that lookup once per origin, so with it failing the names were missing
// (https://git.eeqj.de/sneak/routewatch/issues/67). The AS path column shows
// handles too, so the test looks for the origin list's "(handle)" form.
func TestPrefixDetailShowsOriginNames(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)
origins := []int{15169, 13335}
for _, asn := range origins {
if _, err := db.GetOrCreateASN(asn, ts); err != nil {
t.Fatalf("GetOrCreateASN(%d): %v", asn, err)
}
}
if err := db.UpsertLiveRouteBatch([]*database.LiveRoute{
{
ID: uuid.New(), Prefix: "192.0.2.0/24", MaskLength: 24, IPVersion: 4,
OriginASN: origins[0], PeerIP: "198.51.100.1", ASPath: []int{origins[0]}, NextHop: "198.51.100.1",
LastUpdated: ts,
},
{
ID: uuid.New(), Prefix: "192.0.2.0/24", MaskLength: 24, IPVersion: 4,
OriginASN: origins[1], PeerIP: "198.51.100.2", ASPath: []int{origins[1]}, NextHop: "198.51.100.2",
LastUpdated: ts,
},
}); err != nil {
t.Fatalf("UpsertLiveRouteBatch: %v", err)
}
s := New(failingASDetailsDB{db}, streamer.New(logger.New(), metrics.New()), logger.New(), &config.Config{})
rec := httptest.NewRecorder()
s.router.ServeHTTP(rec, httptest.NewRequest(http.MethodGet, "/prefix/192.0.2.0/24", nil))
if rec.Code != http.StatusOK {
t.Fatalf("status %d, want %d; body %s", rec.Code, http.StatusOK, rec.Body)
}
page := rec.Body.String()
for _, asn := range origins {
info, ok := asinfo.Get(asn)
if !ok {
t.Fatalf("AS%d is not in the AS info data", asn)
}
if want := "(" + html.EscapeString(info.Handle) + ")"; !strings.Contains(page, want) {
t.Errorf("page does not show AS%d's handle %q", asn, want)
}
if want := html.EscapeString(info.Description); !strings.Contains(page, want) {
t.Errorf("page does not show AS%d's description %q", asn, want)
}
}
}
// 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 then answers as the real store does when the time
// limit cuts it off: the IP read with the context's error, the prefix read
// that there is no route, and the others with what they had read, here
// nothing, and no error. Every other Store method is unused and would panic
// if called.
type slowDB struct {
database.Store
}
func (slowDB) GetStatsContext(ctx context.Context) (database.Stats, error) {
<-ctx.Done()
return database.Stats{}, nil
}
func (slowDB) GetIPInfoContext(ctx context.Context, _ string) (*database.IPInfo, error) {
<-ctx.Done()
return nil, ctx.Err()
}
func (slowDB) GetASDetailsContext(ctx context.Context, asn int) (*database.ASN, []database.LiveRoute, error) {
<-ctx.Done()
return &database.ASN{ASN: asn}, nil, nil
}
func (slowDB) GetPrefixDetailsContext(ctx context.Context, _ string) ([]database.LiveRoute, map[int]database.ASN, error) {
<-ctx.Done()
return nil, nil, database.ErrNoRoute
}
func (slowDB) GetRandomPrefixesByLengthContext(ctx context.Context, _, _, _ int) ([]database.LiveRoute, error) {
<-ctx.Done()
return nil, nil
}
// TestRoutesAnswer504WhenDatabaseReadIsCutOff sends a request through the
// server's router for each route that reads the database, with a store whose
// reads are cut off when the request's time limit passes. Each route answers
// 504 with the time limit message. Without its check after the read, a route
// answers with what the cut-off read returned: 500, 404, 200, or, on a page
// that stops before rendering once the request has ended, 504 with an empty
// body. 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 {
checkRouteAnswers504(t, s, tt.path, tt.wantJSONBody)
}
}
// slowSecondReadDB embeds database.Store (left nil) and overrides the reads
// of the routes that read the database twice. The first read answers at once;
// the second, the AS page's peers read or the stats routes' WHOIS read, waits
// until its context ends and then answers with the context's error, as the
// real store does.
type slowSecondReadDB struct {
database.Store
}
func (slowSecondReadDB) GetASDetailsContext(_ context.Context, asn int) (*database.ASN, []database.LiveRoute, error) {
return &database.ASN{ASN: asn}, nil, nil
}
func (slowSecondReadDB) GetASPeersContext(ctx context.Context, _ int) ([]database.ASPeer, error) {
<-ctx.Done()
return nil, ctx.Err()
}
func (slowSecondReadDB) GetStatsContext(_ context.Context) (database.Stats, error) {
return database.Stats{}, nil
}
func (slowSecondReadDB) GetWHOISStats(ctx context.Context, _ time.Duration) (*database.WHOISStats, error) {
<-ctx.Done()
return nil, ctx.Err()
}
// idleASNFetcher is a WHOIS fetcher that does nothing. The stats handlers
// read the WHOIS stats only when the server has a fetcher.
type idleASNFetcher struct{}
func (idleASNFetcher) QueueImmediate(int) {}
func (idleASNFetcher) GetStats() ASNFetcherStats {
return ASNFetcherStats{}
}
// TestRoutesAnswer504WhenSecondDatabaseReadIsCutOff sends a request through
// the server's router for each route that reads the database twice, with a
// store that answers the first read and cuts off the second when the
// request's time limit passes. Each route answers 504 with the time limit
// message. Without the check after the second read, the AS page answers 504
// with an empty body and the stats routes answer 200 without the WHOIS stats.
func TestRoutesAnswer504WhenSecondDatabaseReadIsCutOff(t *testing.T) {
s := New(slowSecondReadDB{}, streamer.New(logger.New(), metrics.New()), logger.New(), &config.Config{})
s.SetASNFetcher(idleASNFetcher{})
tests := []struct {
path string
wantJSONBody bool
}{
{path: "/as/64500"},
{path: "/status.json", wantJSONBody: true},
{path: "/api/v1/stats", wantJSONBody: true},
}
for _, tt := range tests {
checkRouteAnswers504(t, s, tt.path, tt.wantJSONBody)
}
}
// checkRouteAnswers504 sends a request for path through the server's router
// with a short deadline and checks that it answers 504 with the time limit
// message: the JSON error body on JSON routes, the plain message on pages.
func checkRouteAnswers504(t *testing.T, s *Server, path string, wantJSONBody bool) {
t.Helper()
ctx, cancel := context.WithTimeout(context.Background(), shortRequestDeadline)
defer cancel()
rec := httptest.NewRecorder()
s.router.ServeHTTP(rec, httptest.NewRequest(http.MethodGet, path, nil).WithContext(ctx))
if rec.Code != http.StatusGatewayTimeout {
t.Errorf("%s: status %d, want %d; body %s", path, rec.Code, http.StatusGatewayTimeout, rec.Body)
}
if wantJSONBody {
checkJSONErrorCode(t, path, rec, http.StatusGatewayTimeout)
} else if body := strings.TrimSpace(rec.Body.String()); body != requestTimeoutMessage {
t.Errorf("%s: body %q, want %q", path, body, requestTimeoutMessage)
}
}
// 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
}